I just got a bug report from EnterpriseDB saying pg_upgrade generates a file share violation on PG 9.2. I was initially confused because I know we fixed this in a May commit. Well, it turns out that this commit re-added the same failure:
commit 4741e9afb93f0d769655b2d18c2b73b86f281010 Author: Alvaro Herrera <alvhe...@alvh.no-ip.org> Date: Thu Jun 28 23:27:00 2012 -0400 Make the pg_upgrade log files contain actual commands Now the log file not only contains the output from commands executed by system(), but also what command it was in the first place. This arrangement makes debugging a lot simpler. The commit was certainly a good idea, but exec_prog's log_file specification was designed as for use in an error string, meaning that the creation on an error string at one call sight would cause pg_upgrade to erroneously create a log file named "file1 or file2" on Windows. The bigger problem is that the log file was opened at the start of the function (with no error return check), and kept open until the end, causing the file to be opened while the command string was run --- this was causing the share violation. I have applied the attached patch to head and 9.2 to fix all these issues. -- 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/check.c b/contrib/pg_upgrade/check.c new file mode 100644 index 71d8f75..aa896b5 *** a/contrib/pg_upgrade/check.c --- b/contrib/pg_upgrade/check.c *************** issue_warnings(char *sequence_script_fil *** 183,189 **** if (sequence_script_file_name) { prep_status("Adjusting sequences"); ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/psql\" --echo-queries " "--set ON_ERROR_STOP=on " "--no-psqlrc --port %d --username \"%s\" " --- 183,189 ---- if (sequence_script_file_name) { prep_status("Adjusting sequences"); ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/psql\" --echo-queries " "--set ON_ERROR_STOP=on " "--no-psqlrc --port %d --username \"%s\" " diff --git a/contrib/pg_upgrade/dump.c b/contrib/pg_upgrade/dump.c new file mode 100644 index 571792b..07a3b54 *** a/contrib/pg_upgrade/dump.c --- b/contrib/pg_upgrade/dump.c *************** generate_old_dump(void) *** 23,29 **** * --binary-upgrade records the width of dropped columns in pg_class, and * restores the frozenid's for databases and relations. */ ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/pg_dumpall\" --port %d --username \"%s\" " "--schema-only --binary-upgrade %s > \"%s\" 2>> \"%s\"" SYSTEMQUOTE, new_cluster.bindir, old_cluster.port, os_info.user, --- 23,29 ---- * --binary-upgrade records the width of dropped columns in pg_class, and * restores the frozenid's for databases and relations. */ ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/pg_dumpall\" --port %d --username \"%s\" " "--schema-only --binary-upgrade %s > \"%s\" 2>> \"%s\"" SYSTEMQUOTE, new_cluster.bindir, old_cluster.port, os_info.user, diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c new file mode 100644 index 0d6fb8d..6f993df *** a/contrib/pg_upgrade/exec.c --- b/contrib/pg_upgrade/exec.c *************** static int win32_check_directory_write_p *** 33,50 **** * line to be executed is saved to the specified log file. * * If throw_error is TRUE, this function will throw a PG_FATAL error ! * instead of returning should an error occur. */ int ! exec_prog(bool throw_error, bool is_priv, ! const char *log_file, const char *fmt,...) { va_list args; int result; int retval; char cmd[MAXPGPATH]; mode_t old_umask = 0; ! FILE *log = fopen(log_file, "a+"); if (is_priv) old_umask = umask(S_IRWXG | S_IRWXO); --- 33,51 ---- * line to be executed is saved to the specified log file. * * If throw_error is TRUE, this function will throw a PG_FATAL error ! * instead of returning should an error occur. The command it appended ! * to log_file; opt_log_file is used in error messages. */ int ! exec_prog(bool throw_error, bool is_priv, const char *log_file, ! const char *opt_log_file, const char *fmt,...) { va_list args; int result; int retval; char cmd[MAXPGPATH]; mode_t old_umask = 0; ! FILE *log; if (is_priv) old_umask = umask(S_IRWXG | S_IRWXO); *************** exec_prog(bool throw_error, bool is_priv *** 53,61 **** vsnprintf(cmd, MAXPGPATH, fmt, args); va_end(args); pg_log(PG_VERBOSE, "%s\n", cmd); fprintf(log, "command: %s\n", cmd); ! fflush(log); result = system(cmd); --- 54,68 ---- vsnprintf(cmd, MAXPGPATH, fmt, args); va_end(args); + if ((log = fopen_priv(log_file, "a+")) == NULL) + pg_log(PG_FATAL, "cannot write to log file %s\n", log_file); pg_log(PG_VERBOSE, "%s\n", cmd); fprintf(log, "command: %s\n", cmd); ! /* ! * In Windows, we must close then reopen the log file so the file is ! * not open while the command is running, or we get a share violation. ! */ ! fclose(log); result = system(cmd); *************** exec_prog(bool throw_error, bool is_priv *** 64,81 **** if (result != 0) { report_status(PG_REPORT, "*failure*"); fflush(stdout); pg_log(PG_VERBOSE, "There were problems executing \"%s\"\n", cmd); pg_log(throw_error ? PG_FATAL : PG_REPORT, ! "Consult the last few lines of \"%s\" for\n" "the probable cause of the failure.\n", ! log_file); retval = 1; } else retval = 0; fprintf(log, "\n\n"); fclose(log); --- 71,98 ---- if (result != 0) { + char opt_string[MAXPGPATH]; + + /* Create string for optional second log file */ + if (opt_log_file) + snprintf(opt_string, sizeof(opt_string), " or \"%s\"", opt_log_file); + else + opt_string[0] = '\0'; + report_status(PG_REPORT, "*failure*"); fflush(stdout); pg_log(PG_VERBOSE, "There were problems executing \"%s\"\n", cmd); pg_log(throw_error ? PG_FATAL : PG_REPORT, ! "Consult the last few lines of \"%s\"%s for\n" "the probable cause of the failure.\n", ! log_file, opt_string); retval = 1; } else retval = 0; + if ((log = fopen_priv(log_file, "a+")) == NULL) + pg_log(PG_FATAL, "cannot write to log file %s\n", log_file); fprintf(log, "\n\n"); fclose(log); diff --git a/contrib/pg_upgrade/pg_upgrade.c b/contrib/pg_upgrade/pg_upgrade.c new file mode 100644 index 9d26b8c..eff1a08 *** a/contrib/pg_upgrade/pg_upgrade.c --- b/contrib/pg_upgrade/pg_upgrade.c *************** main(int argc, char **argv) *** 140,146 **** * because there is no need to have the schema load use new oids. */ prep_status("Setting next OID for new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/pg_resetxlog\" -o %u \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, old_cluster.controldata.chkpnt_nxtoid, --- 140,146 ---- * because there is no need to have the schema load use new oids. */ prep_status("Setting next OID for new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/pg_resetxlog\" -o %u \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, old_cluster.controldata.chkpnt_nxtoid, *************** prepare_new_cluster(void) *** 211,217 **** * --analyze so autovacuum doesn't update statistics later */ prep_status("Analyzing all rows in the new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/vacuumdb\" --port %d --username \"%s\" " "--all --analyze %s >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, new_cluster.port, os_info.user, --- 211,217 ---- * --analyze so autovacuum doesn't update statistics later */ prep_status("Analyzing all rows in the new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/vacuumdb\" --port %d --username \"%s\" " "--all --analyze %s >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, new_cluster.port, os_info.user, *************** prepare_new_cluster(void) *** 225,231 **** * later. */ prep_status("Freezing all rows on the new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/vacuumdb\" --port %d --username \"%s\" " "--all --freeze %s >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, new_cluster.port, os_info.user, --- 225,231 ---- * later. */ prep_status("Freezing all rows on the new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/vacuumdb\" --port %d --username \"%s\" " "--all --freeze %s >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, new_cluster.port, os_info.user, *************** prepare_new_databases(void) *** 263,269 **** * support functions in template1 but pg_dumpall creates database using * the template0 template. */ ! exec_prog(true, true, RESTORE_LOG_FILE, SYSTEMQUOTE "\"%s/psql\" --echo-queries " "--set ON_ERROR_STOP=on " /* --no-psqlrc prevents AUTOCOMMIT=off */ --- 263,269 ---- * support functions in template1 but pg_dumpall creates database using * the template0 template. */ ! exec_prog(true, true, RESTORE_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/psql\" --echo-queries " "--set ON_ERROR_STOP=on " /* --no-psqlrc prevents AUTOCOMMIT=off */ *************** create_new_objects(void) *** 296,302 **** check_ok(); prep_status("Restoring database schema to new cluster"); ! exec_prog(true, true, RESTORE_LOG_FILE, SYSTEMQUOTE "\"%s/psql\" --echo-queries " "--set ON_ERROR_STOP=on " "--no-psqlrc --port %d --username \"%s\" " --- 296,302 ---- check_ok(); prep_status("Restoring database schema to new cluster"); ! exec_prog(true, true, RESTORE_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/psql\" --echo-queries " "--set ON_ERROR_STOP=on " "--no-psqlrc --port %d --username \"%s\" " *************** copy_subdir_files(char *subdir) *** 331,337 **** prep_status("Copying old %s to new server", subdir); ! exec_prog(true, false, UTILITY_LOG_FILE, #ifndef WIN32 SYSTEMQUOTE "%s \"%s\" \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, "cp -Rf", --- 331,337 ---- prep_status("Copying old %s to new server", subdir); ! exec_prog(true, false, UTILITY_LOG_FILE, NULL, #ifndef WIN32 SYSTEMQUOTE "%s \"%s\" \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, "cp -Rf", *************** copy_clog_xlog_xid(void) *** 353,359 **** /* set the next transaction id of the new cluster */ prep_status("Setting next transaction ID for new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/pg_resetxlog\" -f -x %u \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, --- 353,359 ---- /* set the next transaction id of the new cluster */ prep_status("Setting next transaction ID for new cluster"); ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/pg_resetxlog\" -f -x %u \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, *************** copy_clog_xlog_xid(void) *** 363,369 **** /* now reset the wal archives in the new cluster */ prep_status("Resetting WAL archives"); ! exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/pg_resetxlog\" -l %s \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, --- 363,369 ---- /* now reset the wal archives in the new cluster */ prep_status("Resetting WAL archives"); ! exec_prog(true, true, UTILITY_LOG_FILE, NULL, SYSTEMQUOTE "\"%s/pg_resetxlog\" -l %s \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, diff --git a/contrib/pg_upgrade/pg_upgrade.h b/contrib/pg_upgrade/pg_upgrade.h new file mode 100644 index 9a23176..affee7a *** a/contrib/pg_upgrade/pg_upgrade.h --- b/contrib/pg_upgrade/pg_upgrade.h *************** void split_old_dump(void); *** 317,325 **** /* exec.c */ int ! exec_prog(bool throw_error, bool is_priv, ! const char *log_file, const char *cmd,...) ! __attribute__((format(PG_PRINTF_ATTRIBUTE, 4, 5))); void verify_directories(void); bool is_server_running(const char *datadir); --- 317,325 ---- /* exec.c */ int ! exec_prog(bool throw_error, bool is_priv, const char *log_file, ! const char *opt_log_file, const char *cmd,...) ! __attribute__((format(PG_PRINTF_ATTRIBUTE, 5, 6))); void verify_directories(void); bool is_server_running(const char *datadir); diff --git a/contrib/pg_upgrade/server.c b/contrib/pg_upgrade/server.c new file mode 100644 index 57f09d4..e94a897 *** a/contrib/pg_upgrade/server.c --- b/contrib/pg_upgrade/server.c *************** start_postmaster(ClusterInfo *cluster) *** 171,181 **** * Don't throw an error right away, let connecting throw the error because * it might supply a reason for the failure. */ ! pg_ctl_return = exec_prog(false, true, /* pass both file names if the differ */ ! (strcmp(SERVER_LOG_FILE, SERVER_START_LOG_FILE) == 0) ? ! SERVER_LOG_FILE : ! SERVER_LOG_FILE " or " SERVER_START_LOG_FILE, "%s", cmd); /* Check to see if we can connect to the server; if not, report it. */ --- 171,180 ---- * Don't throw an error right away, let connecting throw the error because * it might supply a reason for the failure. */ ! pg_ctl_return = exec_prog(false, true, SERVER_START_LOG_FILE, /* pass both file names if the differ */ ! (strcmp(SERVER_LOG_FILE, SERVER_START_LOG_FILE) != 0) ? ! SERVER_LOG_FILE : NULL, "%s", cmd); /* Check to see if we can connect to the server; if not, report it. */ *************** stop_postmaster(bool fast) *** 220,226 **** cluster->pgopts ? cluster->pgopts : "", fast ? "-m fast" : "", SERVER_STOP_LOG_FILE); ! exec_prog(fast ? false : true, true, SERVER_STOP_LOG_FILE, "%s", cmd); os_info.running_cluster = NULL; } --- 219,225 ---- cluster->pgopts ? cluster->pgopts : "", fast ? "-m fast" : "", SERVER_STOP_LOG_FILE); ! exec_prog(fast ? false : true, true, SERVER_STOP_LOG_FILE, NULL, "%s", cmd); os_info.running_cluster = NULL; }
-- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers