On Wed, May 23, 2012 at 03:20:30PM +0200, Magnus Hagander wrote:
> On Wed, May 23, 2012 at 5:50 AM, Edmund Horner <ejr...@gmail.com> wrote:
> > On 22 May 2012 18:49, Craig Ringer <ring...@ringerc.id.au> wrote:
> >> When you shut down the 9.1.3 cluster did you make absolutely certain there
> >> were no postgres.exe processes lurking around when you tested? Given the
> >> incredible thouroughness of your report I imagine you did, but it's worth
> >> checking, as a lingering `postgres.exe' could (I imagine) cause such an
> >> issue. Not that it should ever happen.
> >
> > Yes, I ensured there were no postgres.exe processes running before
> > running up_upgrade.  On a related note, postgres.exe processes DO
> > remaining running after pg_upgrade fails with this error.  Not sure if
> > they're from the old or new binaries.  I generally terminate them and
> > recreate the destination cluster between retries.  Additionally, the
> > old cluster needs to be cycled: start it, and then stop it; because
> > the next pg_upgrade run thinks a postgres.exe could still be using it.
> >  pg_ctl start also prints a warning about this but starts anyway.
> >
> >> Do you have the option of re-trying with your AV disabled or removed?
> >
> > At work I can't tamper with the AV, but I can run pg_upgrade in a
> > directory that is excluded from AV (the c:\ccviews directory used by
> > Clearcase!).
> >
> > The log files are created there, and there is no AV activity on them
> > according to Filemon.  There is still a SHARING VIOLATION on
> > pg_upgrade_utility.log, though:
> 
> This certainly looks like both pg_ctl and whatever is running under
> cmd are both accessing the same logfile. This won't work. We can make
> pg_ctl open it in sharing mode, but I'm pretty sure there is nothing
> we can do about CMD - I assume that's coming from a shell redirect
> somewhere?
> 
> > 142     3:47:47 p.m.    pg_ctl.exe:98832        WRITE
> >        C:\ccviews\pg_upgrade_utility.log       SUCCESS Offset: 396 Length: 
> > 16
> > 183     3:48:01 p.m.    cmd.exe:99396   OPEN    
> > C:\ccviews\pg_upgrade_utility.log       SHARING
> > VIOLATION       Options: Open  Access: 0012019F
> 
> We probably need to send these to different logfiles. Bruce?

I have applied the attached patch which should fix the problem.   How
can we get Edmund a copy of a new binary for testing?  Does he have to
wait for beta2?

In pre-9.2, pg_ctl output was sent to /dev/null to avoid this problem,
but that was to avoid sending pg_ctl -l output and stdout output to the
same file.  With 9.2, now that we have multiple output files, I sent the
pg_ctl stdout to the utility file.  One would think that doing:

        pg_ctl -l file1 > file2
        vacuumedb > file2

would not be a problem, but Edmund is reporting he is getting a file
share error.  It sounds like even though pg_ctl has finished, it still
has the file open, perhaps by the still-running postmaster.  I am
unclear if the 'pg_ctl.exe' reported by the tool above is really pg_ctl
or the postmaster.

Anyway, I am pretty sure this patch fixes the problem, and I added a C
comment explaining what I think is happening, but it isn't totally clear
to me yet.  It would be interesting to see the kept log files if
pg_upgrade is run with the --retain flag.  (Edmund, you can email those
to me privately.)  That would tell me what stage is causing the problem.
The pg_upgrade output reported seems to indicate it is pg_dumpall:

            Creating catalog dump                                       The
        process cannot access the file because it is being used by another
        process.
            *failure*

which supports my idea that it is really the postmaster who has that
file kept open and causing the share violation.

In pre-9.2, we only output one log file, but now that we output 4,
outputting one more on Windows for pg_ctl isn't a problem.  My patch
also adjusts the output file array now that is of variable size.

-- 
  Bruce Momjian  <br...@momjian.us>        http://momjian.us
  EnterpriseDB                             http://enterprisedb.com

  + It's impossible for everything to be true. +
diff --git a/contrib/pg_upgrade/option.c b/contrib/pg_upgrade/option.c
new file mode 100644
index 06af6d4..66a70ca
*** a/contrib/pg_upgrade/option.c
--- b/contrib/pg_upgrade/option.c
*************** parseCommandLine(int argc, char *argv[])
*** 57,63 ****
  	int			optindex = 0;	/* used by getopt_long */
  	int			os_user_effective_id;
  	FILE		*fp;
! 	int			i;
  	time_t		run_time = time(NULL);
  	
  	user_opts.transfer_mode = TRANSFER_MODE_COPY;
--- 57,63 ----
  	int			optindex = 0;	/* used by getopt_long */
  	int			os_user_effective_id;
  	FILE		*fp;
! 	char		**filename;
  	time_t		run_time = time(NULL);
  	
  	user_opts.transfer_mode = TRANSFER_MODE_COPY;
*************** parseCommandLine(int argc, char *argv[])
*** 188,198 ****
  	}
  
  	/* label start of upgrade in logfiles */
! 	for (i = 0; i < NUM_LOG_FILES; i++)
  	{
! 		if ((fp = fopen_priv(output_files[i], "a")) == NULL)
! 			pg_log(PG_FATAL, "cannot write to log file %s\n",
! 				   output_files[i]);
  		fprintf(fp, "\n"
  		"-----------------------------------------------------------------\n"
  		"  pg_upgrade run on %s"
--- 188,199 ----
  	}
  
  	/* label start of upgrade in logfiles */
! 	for (filename = output_files; *filename != NULL; filename++)
  	{
! 		if ((fp = fopen_priv(*filename, "a")) == NULL)
! 			pg_log(PG_FATAL, "cannot write to log file %s\n", *filename);
! 
! 		/* Start with newline because we might be appending to a file. */
  		fprintf(fp, "\n"
  		"-----------------------------------------------------------------\n"
  		"  pg_upgrade run on %s"
diff --git a/contrib/pg_upgrade/pg_upgrade.c b/contrib/pg_upgrade/pg_upgrade.c
new file mode 100644
index cc74f11..7297efd
*** a/contrib/pg_upgrade/pg_upgrade.c
--- b/contrib/pg_upgrade/pg_upgrade.c
*************** ClusterInfo old_cluster,
*** 55,65 ****
  			new_cluster;
  OSInfo		os_info;
  
! char *output_files[NUM_LOG_FILES] = {
  	SERVER_LOG_FILE,
  	RESTORE_LOG_FILE,
  	UTILITY_LOG_FILE,
! 	INTERNAL_LOG_FILE
  };
  
  
--- 55,70 ----
  			new_cluster;
  OSInfo		os_info;
  
! char *output_files[] = {
  	SERVER_LOG_FILE,
+ #ifdef WIN32
+ 	/* file is unique on Win32 */
+ 	SERVER_LOG_FILE2,
+ #endif
  	RESTORE_LOG_FILE,
  	UTILITY_LOG_FILE,
! 	INTERNAL_LOG_FILE,
! 	NULL
  };
  
  
*************** cleanup(void)
*** 454,474 ****
  	/* Remove dump and log files? */
  	if (!log_opts.retain)
  	{
! 		char		filename[MAXPGPATH];
! 		int i;
  
! 		for (i = 0; i < NUM_LOG_FILES; i++)
! 		{
! 			snprintf(filename, sizeof(filename), "%s", output_files[i]);
! 			unlink(filename);
! 		}
  
  		/* remove SQL files */
! 		snprintf(filename, sizeof(filename), "%s", ALL_DUMP_FILE);
! 		unlink(filename);
! 		snprintf(filename, sizeof(filename), "%s", GLOBALS_DUMP_FILE);
! 		unlink(filename);
! 		snprintf(filename, sizeof(filename), "%s", DB_DUMP_FILE);
! 		unlink(filename);
  	}
  }
--- 459,472 ----
  	/* Remove dump and log files? */
  	if (!log_opts.retain)
  	{
! 		char		**filename;
  
! 		for (filename = output_files; *filename != NULL; filename++)
! 			unlink(*filename);
  
  		/* remove SQL files */
! 		unlink(ALL_DUMP_FILE);
! 		unlink(GLOBALS_DUMP_FILE);
! 		unlink(DB_DUMP_FILE);
  	}
  }
diff --git a/contrib/pg_upgrade/pg_upgrade.h b/contrib/pg_upgrade/pg_upgrade.h
new file mode 100644
index 6dcb1a5..0d6269a
*** a/contrib/pg_upgrade/pg_upgrade.h
--- b/contrib/pg_upgrade/pg_upgrade.h
***************
*** 40,46 ****
  #define UTILITY_LOG_FILE	"pg_upgrade_utility.log"
  #define INTERNAL_LOG_FILE	"pg_upgrade_internal.log"
  
- #define NUM_LOG_FILES		4
  extern char *output_files[];
  
  /*
--- 40,45 ----
*************** extern char *output_files[];
*** 49,56 ****
   * On Win32, we can't send both pg_upgrade output and command output to the
   * same file because we get the error: "The process cannot access the file
   * because it is being used by another process." so send the pg_ctl
!  * command-line output to the utility log file on Windows, rather than
!  * into the server log file.
   *
   * We could use the Windows pgwin32_open() flags to allow shared file
   * writes but is unclear how all other tools would use those flags, so
--- 48,57 ----
   * On Win32, we can't send both pg_upgrade output and command output to the
   * same file because we get the error: "The process cannot access the file
   * because it is being used by another process." so send the pg_ctl
!  * command-line output to a new file, rather than into the server log file.
!  * Ideally we could use UTILITY_LOG_FILE for this, but some Windows platforms
!  * keep the pg_ctl output file open even after pg_ctl exits, perhaps by the
!  * running postmaster.
   *
   * We could use the Windows pgwin32_open() flags to allow shared file
   * writes but is unclear how all other tools would use those flags, so
*************** extern char *output_files[];
*** 60,66 ****
  #ifndef WIN32
  #define SERVER_LOG_FILE2	SERVER_LOG_FILE
  #else
! #define SERVER_LOG_FILE2	UTILITY_LOG_FILE
  #endif
  
  
--- 61,67 ----
  #ifndef WIN32
  #define SERVER_LOG_FILE2	SERVER_LOG_FILE
  #else
! #define SERVER_LOG_FILE2	"pg_upgrade_server2.log"
  #endif
  
  
-- 
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

Reply via email to