From 717f6d60859cc2d1d7dfd57520531a50bd78df9c Mon Sep 17 00:00:00 2001 From: Bruce Momjian Date: Mon, 12 Mar 2012 19:47:54 -0400 Subject: [PATCH] In pg_upgrade, add various logging improvements: add ability to control permissions of created files have psql echo its queries for easier debugging output four separate log files, and delete them on success add -r/--retain option to keep log files after success make logs file append-only remove -g/-G/-l logging options sugggest tailing appropriate log file on failure enhance -v/--verbose behavior --- contrib/pg_upgrade/check.c | 26 +++---- contrib/pg_upgrade/controldata.c | 4 +- contrib/pg_upgrade/dump.c | 20 +++-- contrib/pg_upgrade/exec.c | 23 ++++-- contrib/pg_upgrade/file.c | 16 ++++ contrib/pg_upgrade/function.c | 5 +- contrib/pg_upgrade/info.c | 20 +++-- contrib/pg_upgrade/option.c | 100 ++++++++---------------- contrib/pg_upgrade/pg_upgrade.c | 112 +++++++++++++++++---------- contrib/pg_upgrade/pg_upgrade.h | 60 ++++++++------ contrib/pg_upgrade/relfilenode.c | 4 +- contrib/pg_upgrade/server.c | 19 +++-- contrib/pg_upgrade/util.c | 16 ++-- contrib/pg_upgrade/version.c | 5 +- contrib/pg_upgrade/version_old_8_3.c | 34 ++++---- doc/src/sgml/pgupgrade.sgml | 27 ++----- 16 files changed, 257 insertions(+), 234 deletions(-) diff --git a/contrib/pg_upgrade/check.c b/contrib/pg_upgrade/check.c index a5f63eb6c8..cf4338400d 100644 --- a/contrib/pg_upgrade/check.c +++ b/contrib/pg_upgrade/check.c @@ -165,12 +165,13 @@ issue_warnings(char *sequence_script_file_name) if (sequence_script_file_name) { prep_status("Adjusting sequences"); - exec_prog(true, - SYSTEMQUOTE "\"%s/psql\" --set ON_ERROR_STOP=on " + exec_prog(true, true, UTILITY_LOG_FILE, + SYSTEMQUOTE "\"%s/psql\" --echo-queries " + "--set ON_ERROR_STOP=on " "--no-psqlrc --port %d --username \"%s\" " - "-f \"%s\" --dbname template1 >> \"%s\"" SYSTEMQUOTE, + "-f \"%s\" --dbname template1 >> \"%s\" 2>&1" SYSTEMQUOTE, new_cluster.bindir, new_cluster.port, os_info.user, - sequence_script_file_name, log_opts.filename2); + sequence_script_file_name, UTILITY_LOG_FILE); unlink(sequence_script_file_name); check_ok(); } @@ -393,10 +394,10 @@ create_script_for_old_cluster_deletion(char **deletion_script_file_name) prep_status("Creating script to delete old cluster"); - snprintf(*deletion_script_file_name, MAXPGPATH, "%s/delete_old_cluster.%s", - os_info.cwd, SCRIPT_EXT); + snprintf(*deletion_script_file_name, MAXPGPATH, "delete_old_cluster.%s", + SCRIPT_EXT); - if ((script = fopen(*deletion_script_file_name, "w")) == NULL) + if ((script = fopen_priv(*deletion_script_file_name, "w")) == NULL) pg_log(PG_FATAL, "Could not open file \"%s\": %s\n", *deletion_script_file_name, getErrorText(errno)); @@ -541,8 +542,8 @@ check_for_isn_and_int8_passing_mismatch(ClusterInfo *cluster) return; } - snprintf(output_path, sizeof(output_path), "%s/contrib_isn_and_int8_pass_by_value.txt", - os_info.cwd); + snprintf(output_path, sizeof(output_path), + "contrib_isn_and_int8_pass_by_value.txt"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -569,7 +570,7 @@ check_for_isn_and_int8_passing_mismatch(ClusterInfo *cluster) for (rowno = 0; rowno < ntups; rowno++) { found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "Could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) @@ -628,8 +629,7 @@ check_for_reg_data_type_usage(ClusterInfo *cluster) prep_status("Checking for reg* system OID user data types"); - snprintf(output_path, sizeof(output_path), "%s/tables_using_reg.txt", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "tables_using_reg.txt"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -675,7 +675,7 @@ check_for_reg_data_type_usage(ClusterInfo *cluster) for (rowno = 0; rowno < ntups; rowno++) { found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "Could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) diff --git a/contrib/pg_upgrade/controldata.c b/contrib/pg_upgrade/controldata.c index 5239601dc6..e01280db9e 100644 --- a/contrib/pg_upgrade/controldata.c +++ b/contrib/pg_upgrade/controldata.c @@ -126,11 +126,9 @@ get_control_data(ClusterInfo *cluster, bool live_check) /* we have the result of cmd in "output". so parse it line by line now */ while (fgets(bufin, sizeof(bufin), output)) { - if (log_opts.debug) - fputs(bufin, log_opts.debug_fd); + pg_log(PG_VERBOSE, "%s", bufin); #ifdef WIN32 - /* * Due to an installer bug, LANG=C doesn't work for PG 8.3.3, but does * work 8.2.6 and 8.3.7, so check for non-ASCII output and suggest a diff --git a/contrib/pg_upgrade/dump.c b/contrib/pg_upgrade/dump.c index 772ca37e8d..571792b1d4 100644 --- a/contrib/pg_upgrade/dump.c +++ b/contrib/pg_upgrade/dump.c @@ -11,6 +11,7 @@ #include "pg_upgrade.h" +#include void generate_old_dump(void) @@ -22,10 +23,12 @@ generate_old_dump(void) * --binary-upgrade records the width of dropped columns in pg_class, and * restores the frozenid's for databases and relations. */ - exec_prog(true, + exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/pg_dumpall\" --port %d --username \"%s\" " - "--schema-only --binary-upgrade > \"%s/" ALL_DUMP_FILE "\"" - SYSTEMQUOTE, new_cluster.bindir, old_cluster.port, os_info.user, os_info.cwd); + "--schema-only --binary-upgrade %s > \"%s\" 2>> \"%s\"" + SYSTEMQUOTE, new_cluster.bindir, old_cluster.port, os_info.user, + log_opts.verbose ? "--verbose" : "", + ALL_DUMP_FILE, UTILITY_LOG_FILE); check_ok(); } @@ -56,15 +59,16 @@ split_old_dump(void) char filename[MAXPGPATH]; bool suppressed_username = false; - snprintf(filename, sizeof(filename), "%s/%s", os_info.cwd, ALL_DUMP_FILE); + snprintf(filename, sizeof(filename), "%s", ALL_DUMP_FILE); if ((all_dump = fopen(filename, "r")) == NULL) pg_log(PG_FATAL, "Could not open dump file \"%s\": %s\n", filename, getErrorText(errno)); - snprintf(filename, sizeof(filename), "%s/%s", os_info.cwd, GLOBALS_DUMP_FILE); - if ((globals_dump = fopen(filename, "w")) == NULL) + snprintf(filename, sizeof(filename), "%s", GLOBALS_DUMP_FILE); + if ((globals_dump = fopen_priv(filename, "w")) == NULL) pg_log(PG_FATAL, "Could not write to dump file \"%s\": %s\n", filename, getErrorText(errno)); - snprintf(filename, sizeof(filename), "%s/%s", os_info.cwd, DB_DUMP_FILE); - if ((db_dump = fopen(filename, "w")) == NULL) + snprintf(filename, sizeof(filename), "%s", DB_DUMP_FILE); + if ((db_dump = fopen_priv(filename, "w")) == NULL) pg_log(PG_FATAL, "Could not write to dump file \"%s\": %s\n", filename, getErrorText(errno)); + current_output = globals_dump; /* patterns used to prevent our own username from being recreated */ diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c index b870deda79..42c5c0fff4 100644 --- a/contrib/pg_upgrade/exec.c +++ b/contrib/pg_upgrade/exec.c @@ -13,7 +13,7 @@ #include #include - +#include static void check_data_dir(const char *pg_data); static void check_bin_dir(ClusterInfo *cluster); @@ -34,24 +34,37 @@ static int win32_check_directory_write_permissions(void); * instead of returning should an error occur. */ int -exec_prog(bool throw_error, const char *fmt,...) +exec_prog(bool throw_error, bool is_priv, + const char *log_file, const char *fmt,...) { va_list args; int result; char cmd[MAXPGPATH]; + mode_t old_umask; + + if (is_priv) + old_umask = umask(S_IRWXG | S_IRWXO); va_start(args, fmt); vsnprintf(cmd, MAXPGPATH, fmt, args); va_end(args); - pg_log(PG_INFO, "%s\n", cmd); + pg_log(PG_VERBOSE, "%s\n", cmd); result = system(cmd); + if (is_priv) + umask(old_umask); + if (result != 0) { - pg_log(throw_error ? PG_FATAL : PG_INFO, - "There were problems executing \"%s\"\n", cmd); + 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); return 1; } diff --git a/contrib/pg_upgrade/file.c b/contrib/pg_upgrade/file.c index fcf1c440a7..0276636e03 100644 --- a/contrib/pg_upgrade/file.c +++ b/contrib/pg_upgrade/file.c @@ -316,3 +316,19 @@ win32_pghardlink(const char *src, const char *dst) } #endif + + +/* fopen() file with no group/other permissions */ +FILE * +fopen_priv(const char *path, const char *mode) +{ + mode_t old_umask = umask(S_IRWXG | S_IRWXO); + FILE *fp; + + fp = fopen(path, mode); + umask(old_umask); + + return fp; +} + + diff --git a/contrib/pg_upgrade/function.c b/contrib/pg_upgrade/function.c index 267f29143d..322503946e 100644 --- a/contrib/pg_upgrade/function.c +++ b/contrib/pg_upgrade/function.c @@ -218,8 +218,7 @@ check_loadable_libraries(void) prep_status("Checking for presence of required libraries"); - snprintf(output_path, sizeof(output_path), "%s/loadable_libraries.txt", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "loadable_libraries.txt"); for (libnum = 0; libnum < os_info.num_libraries; libnum++) { @@ -257,7 +256,7 @@ check_loadable_libraries(void) if (PQresultStatus(res) != PGRES_COMMAND_OK) { found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "Could not open file \"%s\": %s\n", output_path, getErrorText(errno)); fprintf(script, "Could not load library \"%s\"\n%s\n", diff --git a/contrib/pg_upgrade/info.c b/contrib/pg_upgrade/info.c index 692cdc2e62..36683fa15e 100644 --- a/contrib/pg_upgrade/info.c +++ b/contrib/pg_upgrade/info.c @@ -132,19 +132,19 @@ create_rel_filename_map(const char *old_data, const char *new_data, void print_maps(FileNameMap *maps, int n_maps, const char *db_name) { - if (log_opts.debug) + if (log_opts.verbose) { int mapnum; - pg_log(PG_DEBUG, "mappings for database \"%s\":\n", db_name); + pg_log(PG_VERBOSE, "mappings for database \"%s\":\n", db_name); for (mapnum = 0; mapnum < n_maps; mapnum++) - pg_log(PG_DEBUG, "%s.%s: %u to %u\n", + pg_log(PG_VERBOSE, "%s.%s: %u to %u\n", maps[mapnum].nspname, maps[mapnum].relname, maps[mapnum].old_relfilenode, maps[mapnum].new_relfilenode); - pg_log(PG_DEBUG, "\n\n"); + pg_log(PG_VERBOSE, "\n\n"); } } @@ -168,11 +168,9 @@ get_db_and_rel_infos(ClusterInfo *cluster) for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) get_rel_infos(cluster, &cluster->dbarr.dbs[dbnum]); - if (log_opts.debug) - { - pg_log(PG_DEBUG, "\n%s databases:\n", CLUSTER_NAME(cluster)); + pg_log(PG_VERBOSE, "\n%s databases:\n", CLUSTER_NAME(cluster)); + if (log_opts.verbose) print_db_infos(&cluster->dbarr); - } } @@ -368,9 +366,9 @@ print_db_infos(DbInfoArr *db_arr) for (dbnum = 0; dbnum < db_arr->ndbs; dbnum++) { - pg_log(PG_DEBUG, "Database: %s\n", db_arr->dbs[dbnum].db_name); + pg_log(PG_VERBOSE, "Database: %s\n", db_arr->dbs[dbnum].db_name); print_rel_infos(&db_arr->dbs[dbnum].rel_arr); - pg_log(PG_DEBUG, "\n\n"); + pg_log(PG_VERBOSE, "\n\n"); } } @@ -381,7 +379,7 @@ print_rel_infos(RelInfoArr *arr) int relnum; for (relnum = 0; relnum < arr->nrels; relnum++) - pg_log(PG_DEBUG, "relname: %s.%s: reloid: %u reltblspace: %s\n", + pg_log(PG_VERBOSE, "relname: %s.%s: reloid: %u reltblspace: %s\n", arr->rels[relnum].nspname, arr->rels[relnum].relname, arr->rels[relnum].reloid, arr->rels[relnum].tablespace); } diff --git a/contrib/pg_upgrade/option.c b/contrib/pg_upgrade/option.c index 0a105efec7..a97be28d92 100644 --- a/contrib/pg_upgrade/option.c +++ b/contrib/pg_upgrade/option.c @@ -11,8 +11,10 @@ #include "pg_upgrade.h" -#include "getopt_long.h" - +#include +#include +#include +#include #ifdef WIN32 #include #endif @@ -46,18 +48,18 @@ parseCommandLine(int argc, char *argv[]) {"user", required_argument, NULL, 'u'}, {"check", no_argument, NULL, 'c'}, - {"debug", no_argument, NULL, 'g'}, - {"debugfile", required_argument, NULL, 'G'}, {"link", no_argument, NULL, 'k'}, - {"logfile", required_argument, NULL, 'l'}, + {"retain", no_argument, NULL, 'r'}, {"verbose", no_argument, NULL, 'v'}, {NULL, 0, NULL, 0} }; int option; /* Command line option */ int optindex = 0; /* used by getopt_long */ int os_user_effective_id; - char *return_buf; - + FILE *fp; + int i; + time_t run_time = time(NULL); + user_opts.transfer_mode = TRANSFER_MODE_COPY; os_info.progname = get_progname(argv[0]); @@ -94,11 +96,10 @@ parseCommandLine(int argc, char *argv[]) if (os_user_effective_id == 0) pg_log(PG_FATAL, "%s: cannot be run as root\n", os_info.progname); - return_buf = getcwd(os_info.cwd, MAXPGPATH); - if (return_buf == NULL) - pg_log(PG_FATAL, "Could not access current working directory: %s\n", getErrorText(errno)); + if ((log_opts.internal = fopen_priv(INTERNAL_LOG_FILE, "a")) == NULL) + pg_log(PG_FATAL, "cannot write to log file %s\n", INTERNAL_LOG_FILE); - while ((option = getopt_long(argc, argv, "d:D:b:B:cgG:kl:o:O:p:P:u:v", + while ((option = getopt_long(argc, argv, "d:D:b:B:cko:O:p:P:ru:v", long_options, &optindex)) != -1) { switch (option) @@ -125,27 +126,10 @@ parseCommandLine(int argc, char *argv[]) new_cluster.pgconfig = pg_strdup(optarg); break; - case 'g': - pg_log(PG_REPORT, "Running in debug mode\n"); - log_opts.debug = true; - break; - - case 'G': - if ((log_opts.debug_fd = fopen(optarg, "w")) == NULL) - { - pg_log(PG_FATAL, "cannot open debug file\n"); - exit(1); - } - break; - case 'k': user_opts.transfer_mode = TRANSFER_MODE_LINK; break; - case 'l': - log_opts.filename = pg_strdup(optarg); - break; - case 'o': old_cluster.pgopts = pg_strdup(optarg); break; @@ -175,6 +159,10 @@ parseCommandLine(int argc, char *argv[]) } break; + case 'r': + log_opts.retain = true; + break; + case 'u': pg_free(os_info.user); os_info.user = pg_strdup(optarg); @@ -199,36 +187,18 @@ parseCommandLine(int argc, char *argv[]) } } - if (log_opts.filename != NULL) + /* label start of upgrade in logfiles */ + for (i = 0; i < NUM_LOG_FILES; i++) { - /* - * We must use append mode so output generated by child processes via - * ">>" will not be overwritten, and we want the file truncated on - * start. - */ - /* truncate */ - if ((log_opts.fd = fopen(log_opts.filename, "w")) == NULL) - pg_log(PG_FATAL, "cannot write to log file %s\n", log_opts.filename); - fclose(log_opts.fd); - if ((log_opts.fd = fopen(log_opts.filename, "a")) == NULL) - pg_log(PG_FATAL, "cannot write to log file %s\n", log_opts.filename); - } - else - log_opts.filename = pg_strdup(DEVNULL); - - /* WIN32 files do not accept writes from multiple processes */ -#ifndef WIN32 - log_opts.filename2 = pg_strdup(log_opts.filename); -#else - log_opts.filename2 = pg_strdup(DEVNULL); -#endif - - /* if no debug file name, output to the terminal */ - if (log_opts.debug && !log_opts.debug_fd) - { - log_opts.debug_fd = fopen(DEVTTY, "w"); - if (!log_opts.debug_fd) - pg_log(PG_FATAL, "cannot write to terminal\n"); + 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" + "-----------------------------------------------------------------\n\n", + ctime(&run_time)); + fclose(fp); } /* Get values from env if not already set */ @@ -256,16 +226,14 @@ Options:\n\ -c, --check check clusters only, don't change any data\n\ -d, --old-datadir=OLDDATADIR old cluster data directory\n\ -D, --new-datadir=NEWDATADIR new cluster data directory\n\ - -g, --debug enable debugging\n\ - -G, --debugfile=FILENAME output debugging activity to file\n\ -k, --link link instead of copying files to new cluster\n\ - -l, --logfile=FILENAME log internal activity to file\n\ -o, --old-options=OPTIONS old cluster options to pass to the server\n\ -O, --new-options=OPTIONS new cluster options to pass to the server\n\ -p, --old-port=OLDPORT old cluster port number (default %d)\n\ -P, --new-port=NEWPORT new cluster port number (default %d)\n\ + -r, --retain retain SQL and log files after success\n\ -u, --user=NAME cluster superuser (default \"%s\")\n\ - -v, --verbose enable verbose output\n\ + -v, --verbose enable verbose internal logging\n\ -V, --version display version information, then exit\n\ -h, --help show this help, then exit\n\ \n\ @@ -354,19 +322,19 @@ adjust_data_dir(ClusterInfo *cluster) { char filename[MAXPGPATH]; char cmd[MAXPGPATH], cmd_output[MAX_STRING]; - FILE *fd, *output; + FILE *fp, *output; /* If there is no postgresql.conf, it can't be a config-only dir */ snprintf(filename, sizeof(filename), "%s/postgresql.conf", cluster->pgconfig); - if ((fd = fopen(filename, "r")) == NULL) + if ((fp = fopen(filename, "r")) == NULL) return; - fclose(fd); + fclose(fp); /* If PG_VERSION exists, it can't be a config-only dir */ snprintf(filename, sizeof(filename), "%s/PG_VERSION", cluster->pgconfig); - if ((fd = fopen(filename, "r")) != NULL) + if ((fp = fopen(filename, "r")) != NULL) { - fclose(fd); + fclose(fp); return; } diff --git a/contrib/pg_upgrade/pg_upgrade.c b/contrib/pg_upgrade/pg_upgrade.c index 3078bcd4cd..269f8adeb1 100644 --- a/contrib/pg_upgrade/pg_upgrade.c +++ b/contrib/pg_upgrade/pg_upgrade.c @@ -55,6 +55,14 @@ ClusterInfo old_cluster, new_cluster; OSInfo os_info; +char *output_files[NUM_LOG_FILES] = { + SERVER_LOG_FILE, + RESTORE_LOG_FILE, + UTILITY_LOG_FILE, + INTERNAL_LOG_FILE +}; + + int main(int argc, char **argv) { @@ -127,9 +135,11 @@ main(int argc, char **argv) * because there is no need to have the schema load use new oids. */ prep_status("Setting next OID for new cluster"); - exec_prog(true, SYSTEMQUOTE "\"%s/pg_resetxlog\" -o %u \"%s\" > " - DEVNULL SYSTEMQUOTE, - new_cluster.bindir, old_cluster.controldata.chkpnt_nxtoid, new_cluster.pgdata); + 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, + new_cluster.pgdata, UTILITY_LOG_FILE); check_ok(); create_script_for_old_cluster_deletion(&deletion_script_file_name); @@ -193,10 +203,11 @@ prepare_new_cluster(void) * --analyze so autovacuum doesn't update statistics later */ prep_status("Analyzing all rows in the new cluster"); - exec_prog(true, + exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/vacuumdb\" --port %d --username \"%s\" " - "--all --analyze >> \"%s\" 2>&1" SYSTEMQUOTE, - new_cluster.bindir, new_cluster.port, os_info.user, log_opts.filename2); + "--all --analyze %s >> \"%s\" 2>&1" SYSTEMQUOTE, + new_cluster.bindir, new_cluster.port, os_info.user, + log_opts.verbose ? "--verbose" : "", UTILITY_LOG_FILE); check_ok(); /* @@ -206,10 +217,11 @@ prepare_new_cluster(void) * later. */ prep_status("Freezing all rows on the new cluster"); - exec_prog(true, + exec_prog(true, true, UTILITY_LOG_FILE, SYSTEMQUOTE "\"%s/vacuumdb\" --port %d --username \"%s\" " - "--all --freeze >> \"%s\" 2>&1" SYSTEMQUOTE, - new_cluster.bindir, new_cluster.port, os_info.user, log_opts.filename2); + "--all --freeze %s >> \"%s\" 2>&1" SYSTEMQUOTE, + new_cluster.bindir, new_cluster.port, os_info.user, + log_opts.verbose ? "--verbose" : "", UTILITY_LOG_FILE); check_ok(); get_pg_database_relfilenode(&new_cluster); @@ -243,13 +255,14 @@ prepare_new_databases(void) * support functions in template1 but pg_dumpall creates database using * the template0 template. */ - exec_prog(true, - SYSTEMQUOTE "\"%s/psql\" --set ON_ERROR_STOP=on " - /* --no-psqlrc prevents AUTOCOMMIT=off */ + exec_prog(true, true, RESTORE_LOG_FILE, + SYSTEMQUOTE "\"%s/psql\" --echo-queries " + "--set ON_ERROR_STOP=on " + /* --no-psqlrc prevents AUTOCOMMIT=off */ "--no-psqlrc --port %d --username \"%s\" " - "-f \"%s/%s\" --dbname template1 >> \"%s\"" SYSTEMQUOTE, - new_cluster.bindir, new_cluster.port, os_info.user, os_info.cwd, - GLOBALS_DUMP_FILE, log_opts.filename2); + "-f \"%s\" --dbname template1 >> \"%s\" 2>&1" SYSTEMQUOTE, + new_cluster.bindir, new_cluster.port, os_info.user, + GLOBALS_DUMP_FILE, RESTORE_LOG_FILE); check_ok(); /* we load this to get a current list of databases */ @@ -275,12 +288,13 @@ create_new_objects(void) check_ok(); prep_status("Restoring database schema to new cluster"); - exec_prog(true, - SYSTEMQUOTE "\"%s/psql\" --set ON_ERROR_STOP=on " + exec_prog(true, true, RESTORE_LOG_FILE, + SYSTEMQUOTE "\"%s/psql\" --echo-queries " + "--set ON_ERROR_STOP=on " "--no-psqlrc --port %d --username \"%s\" " - "-f \"%s/%s\" --dbname template1 >> \"%s\"" SYSTEMQUOTE, - new_cluster.bindir, new_cluster.port, os_info.user, os_info.cwd, - DB_DUMP_FILE, log_opts.filename2); + "-f \"%s\" --dbname template1 >> \"%s\" 2>&1" SYSTEMQUOTE, + new_cluster.bindir, new_cluster.port, os_info.user, + DB_DUMP_FILE, RESTORE_LOG_FILE); check_ok(); /* regenerate now that we have objects in the databases */ @@ -306,29 +320,38 @@ copy_clog_xlog_xid(void) check_ok(); prep_status("Copying old commit clogs to new server"); + exec_prog(true, false, UTILITY_LOG_FILE, #ifndef WIN32 - exec_prog(true, SYSTEMQUOTE "%s \"%s\" \"%s\"" SYSTEMQUOTE, + SYSTEMQUOTE "%s \"%s\" \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, "cp -Rf", #else /* flags: everything, no confirm, quiet, overwrite read-only */ - exec_prog(true, SYSTEMQUOTE "%s \"%s\" \"%s\\\"" SYSTEMQUOTE, + SYSTEMQUOTE "%s \"%s\" \"%s\\\" >> \"%s\" 2>&1" SYSTEMQUOTE, "xcopy /e /y /q /r", #endif - old_clog_path, new_clog_path); + old_clog_path, new_clog_path, UTILITY_LOG_FILE); check_ok(); /* set the next transaction id of the new cluster */ prep_status("Setting next transaction ID for new cluster"); - exec_prog(true, SYSTEMQUOTE "\"%s/pg_resetxlog\" -f -x %u \"%s\" > " DEVNULL SYSTEMQUOTE, - new_cluster.bindir, old_cluster.controldata.chkpnt_nxtxid, new_cluster.pgdata); + exec_prog(true, true, UTILITY_LOG_FILE, + SYSTEMQUOTE + "\"%s/pg_resetxlog\" -f -x %u \"%s\" >> \"%s\" 2>&1" + SYSTEMQUOTE, new_cluster.bindir, + old_cluster.controldata.chkpnt_nxtxid, + new_cluster.pgdata, UTILITY_LOG_FILE); check_ok(); /* now reset the wal archives in the new cluster */ prep_status("Resetting WAL archives"); - exec_prog(true, SYSTEMQUOTE "\"%s/pg_resetxlog\" -l %u,%u,%u \"%s\" >> \"%s\" 2>&1" SYSTEMQUOTE, - new_cluster.bindir, old_cluster.controldata.chkpnt_tli, - old_cluster.controldata.logid, old_cluster.controldata.nxtlogseg, - new_cluster.pgdata, log_opts.filename2); + exec_prog(true, true, UTILITY_LOG_FILE, + SYSTEMQUOTE + "\"%s/pg_resetxlog\" -l %u,%u,%u \"%s\" >> \"%s\" 2>&1" + SYSTEMQUOTE, new_cluster.bindir, + old_cluster.controldata.chkpnt_tli, + old_cluster.controldata.logid, + old_cluster.controldata.nxtlogseg, + new_cluster.pgdata, UTILITY_LOG_FILE); check_ok(); } @@ -421,18 +444,27 @@ set_frozenxids(void) static void cleanup(void) { - char filename[MAXPGPATH]; + + fclose(log_opts.internal); - if (log_opts.fd) - fclose(log_opts.fd); + /* Remove dump and log files? */ + if (!log_opts.retain) + { + char filename[MAXPGPATH]; + int i; - if (log_opts.debug_fd) - fclose(log_opts.debug_fd); + for (i = 0; i < NUM_LOG_FILES; i++) + { + snprintf(filename, sizeof(filename), "%s", output_files[i]); + unlink(filename); + } - snprintf(filename, sizeof(filename), "%s/%s", os_info.cwd, ALL_DUMP_FILE); - unlink(filename); - snprintf(filename, sizeof(filename), "%s/%s", os_info.cwd, GLOBALS_DUMP_FILE); - unlink(filename); - snprintf(filename, sizeof(filename), "%s/%s", os_info.cwd, DB_DUMP_FILE); - 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); + } } diff --git a/contrib/pg_upgrade/pg_upgrade.h b/contrib/pg_upgrade/pg_upgrade.h index a95481509d..46f9169d0c 100644 --- a/contrib/pg_upgrade/pg_upgrade.h +++ b/contrib/pg_upgrade/pg_upgrade.h @@ -35,6 +35,34 @@ #define GLOBALS_DUMP_FILE "pg_upgrade_dump_globals.sql" #define DB_DUMP_FILE "pg_upgrade_dump_db.sql" +#define SERVER_LOG_FILE "pg_upgrade_server.log" +#define RESTORE_LOG_FILE "pg_upgrade_restore.log" +#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[]; + +/* + * WIN32 files do not accept writes from multiple processes + * + * 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 + * we just avoid it and log a little differently on Windows; we adjust + * the error message appropriately. + */ +#ifndef WIN32 +#define SERVER_LOG_FILE2 SERVER_LOG_FILE +#else +#define SERVER_LOG_FILE2 UTILITY_LOG_FILE +#endif + #ifndef WIN32 #define pg_copy_file copy_file #define pg_mv_file rename @@ -166,11 +194,10 @@ typedef enum */ typedef enum { - PG_INFO, + PG_VERBOSE, PG_REPORT, PG_WARNING, - PG_FATAL, - PG_DEBUG + PG_FATAL } eLogType; @@ -204,25 +231,9 @@ typedef struct */ typedef struct { - char *filename; /* name of log file (may be /dev/null) */ - /* - * WIN32 files do not accept writes from multiple processes - * - * 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 we have to send all - * other output to 'nul'. Therefore, we set this to DEVNULL on Win32, and - * it equals 'filename' on all other platforms. - * - * 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 - * we just avoid it and log a little less on Windows. - */ - char *filename2; - FILE *fd; /* log FILE */ - bool debug; /* TRUE -> log more information */ - FILE *debug_fd; /* debug-level log FILE */ + FILE *internal; /* internal log FILE */ bool verbose; /* TRUE -> be verbose in messages */ + bool retain; /* retain log files on success */ } LogOpts; @@ -245,7 +256,6 @@ typedef struct const char *progname; /* complete pathname for this program */ char *exec_path; /* full path to my executable */ char *user; /* username for clusters */ - char cwd[MAXPGPATH]; /* current working directory, used for output */ char **tablespaces; /* tablespaces */ int num_tablespaces; char **libraries; /* loadable libraries */ @@ -294,8 +304,9 @@ void split_old_dump(void); /* exec.c */ -int exec_prog(bool throw_error, const char *cmd, ...) - __attribute__((format(PG_PRINTF_ATTRIBUTE, 2, 3))); +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); @@ -339,6 +350,7 @@ const char *linkAndUpdateFile(pageCnvCtx *pageConverter, const char *src, const char *dst); void check_hard_link(void); +FILE *fopen_priv(const char *path, const char *mode); /* function.c */ diff --git a/contrib/pg_upgrade/relfilenode.c b/contrib/pg_upgrade/relfilenode.c index a1e30b1f0c..45d6c5415b 100644 --- a/contrib/pg_upgrade/relfilenode.c +++ b/contrib/pg_upgrade/relfilenode.c @@ -267,7 +267,7 @@ transfer_relfile(pageCnvCtx *pageConverter, const char *old_file, if (user_opts.transfer_mode == TRANSFER_MODE_COPY) { - pg_log(PG_INFO, "copying \"%s\" to \"%s\"\n", old_file, new_file); + pg_log(PG_VERBOSE, "copying \"%s\" to \"%s\"\n", old_file, new_file); if ((msg = copyAndUpdateFile(pageConverter, old_file, new_file, true)) != NULL) pg_log(PG_FATAL, "error while copying relation \"%s.%s\" (\"%s\" to \"%s\"): %s\n", @@ -275,7 +275,7 @@ transfer_relfile(pageCnvCtx *pageConverter, const char *old_file, } else { - pg_log(PG_INFO, "linking \"%s\" to \"%s\"\n", old_file, new_file); + pg_log(PG_VERBOSE, "linking \"%s\" to \"%s\"\n", old_file, new_file); if ((msg = linkAndUpdateFile(pageConverter, old_file, new_file)) != NULL) pg_log(PG_FATAL, diff --git a/contrib/pg_upgrade/server.c b/contrib/pg_upgrade/server.c index 989af63a78..b515e0504c 100644 --- a/contrib/pg_upgrade/server.c +++ b/contrib/pg_upgrade/server.c @@ -80,7 +80,7 @@ executeQueryOrDie(PGconn *conn, const char *fmt,...) vsnprintf(command, sizeof(command), fmt, args); va_end(args); - pg_log(PG_DEBUG, "executing: %s\n", command); + pg_log(PG_VERBOSE, "executing: %s\n", command); result = PQexec(conn, command); status = PQresultStatus(result); @@ -161,17 +161,22 @@ start_postmaster(ClusterInfo *cluster) snprintf(cmd, sizeof(cmd), SYSTEMQUOTE "\"%s/pg_ctl\" -w -l \"%s\" -D \"%s\" " "-o \"-p %d %s %s\" start >> \"%s\" 2>&1" SYSTEMQUOTE, - cluster->bindir, log_opts.filename2, cluster->pgconfig, cluster->port, + cluster->bindir, SERVER_LOG_FILE, cluster->pgconfig, cluster->port, (cluster->controldata.cat_ver >= BINARY_UPGRADE_SERVER_FLAG_CAT_VER) ? "-b" : "-c autovacuum=off -c autovacuum_freeze_max_age=2000000000", - cluster->pgopts ? cluster->pgopts : "", log_opts.filename2); + cluster->pgopts ? cluster->pgopts : "", SERVER_LOG_FILE2); /* * 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, "%s", cmd); + pg_ctl_return = exec_prog(false, true, + /* pass both file names if the differ */ + (strcmp(SERVER_LOG_FILE, SERVER_LOG_FILE2) == 0) ? + SERVER_LOG_FILE : + SERVER_LOG_FILE " or " SERVER_LOG_FILE2, + "%s", cmd); /* Check to see if we can connect to the server; if not, report it. */ if ((conn = get_db_conn(cluster, "template1")) == NULL || @@ -211,11 +216,11 @@ stop_postmaster(bool fast) snprintf(cmd, sizeof(cmd), SYSTEMQUOTE "\"%s/pg_ctl\" -w -l \"%s\" -D \"%s\" -o \"%s\" " "%s stop >> \"%s\" 2>&1" SYSTEMQUOTE, - cluster->bindir, log_opts.filename2, cluster->pgconfig, + cluster->bindir, SERVER_LOG_FILE2, cluster->pgconfig, cluster->pgopts ? cluster->pgopts : "", - fast ? "-m fast" : "", log_opts.filename2); + fast ? "-m fast" : "", SERVER_LOG_FILE2); - exec_prog(fast ? false : true, "%s", cmd); + exec_prog(fast ? false : true, true, SERVER_LOG_FILE2, "%s", cmd); os_info.running_cluster = NULL; } diff --git a/contrib/pg_upgrade/util.c b/contrib/pg_upgrade/util.c index 94eaa189b0..6977663b63 100644 --- a/contrib/pg_upgrade/util.c +++ b/contrib/pg_upgrade/util.c @@ -77,18 +77,19 @@ pg_log(eLogType type, char *fmt,...) vsnprintf(message, sizeof(message), fmt, args); va_end(args); - if (log_opts.fd != NULL) + /* PG_VERBOSE is only output in verbose mode */ + if (type != PG_VERBOSE || log_opts.verbose) { - fwrite(message, strlen(message), 1, log_opts.fd); + fwrite(message, strlen(message), 1, log_opts.internal); /* if we are using OVERWRITE_MESSAGE, add newline */ if (strchr(message, '\r') != NULL) - fwrite("\n", 1, 1, log_opts.fd); - fflush(log_opts.fd); + fwrite("\n", 1, 1, log_opts.internal); + fflush(log_opts.internal); } switch (type) { - case PG_INFO: + case PG_VERBOSE: if (log_opts.verbose) printf("%s", _(message)); break; @@ -104,11 +105,6 @@ pg_log(eLogType type, char *fmt,...) exit(1); break; - case PG_DEBUG: - if (log_opts.debug) - fprintf(log_opts.debug_fd, "%s\n", _(message)); - break; - default: break; } diff --git a/contrib/pg_upgrade/version.c b/contrib/pg_upgrade/version.c index e8799a4085..5d790a0803 100644 --- a/contrib/pg_upgrade/version.c +++ b/contrib/pg_upgrade/version.c @@ -28,8 +28,7 @@ new_9_0_populate_pg_largeobject_metadata(ClusterInfo *cluster, bool check_mode) prep_status("Checking for large objects"); - snprintf(output_path, sizeof(output_path), "%s/pg_largeobject.sql", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "pg_largeobject.sql"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -49,7 +48,7 @@ new_9_0_populate_pg_largeobject_metadata(ClusterInfo *cluster, bool check_mode) found = true; if (!check_mode) { - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); fprintf(script, "\\connect %s\n", quote_identifier(active_db->db_name)); diff --git a/contrib/pg_upgrade/version_old_8_3.c b/contrib/pg_upgrade/version_old_8_3.c index a8641076aa..c60374ee9b 100644 --- a/contrib/pg_upgrade/version_old_8_3.c +++ b/contrib/pg_upgrade/version_old_8_3.c @@ -30,8 +30,7 @@ old_8_3_check_for_name_data_type_usage(ClusterInfo *cluster) prep_status("Checking for invalid \"name\" user columns"); - snprintf(output_path, sizeof(output_path), "%s/tables_using_name.txt", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "tables_using_name.txt"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -73,7 +72,7 @@ old_8_3_check_for_name_data_type_usage(ClusterInfo *cluster) for (rowno = 0; rowno < ntups; rowno++) { found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) { @@ -126,8 +125,7 @@ old_8_3_check_for_tsquery_usage(ClusterInfo *cluster) prep_status("Checking for tsquery user columns"); - snprintf(output_path, sizeof(output_path), "%s/tables_using_tsquery.txt", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "tables_using_tsquery.txt"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -164,7 +162,7 @@ old_8_3_check_for_tsquery_usage(ClusterInfo *cluster) for (rowno = 0; rowno < ntups; rowno++) { found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) { @@ -216,8 +214,7 @@ old_8_3_check_ltree_usage(ClusterInfo *cluster) prep_status("Checking for contrib/ltree"); - snprintf(output_path, sizeof(output_path), "%s/contrib_ltree.txt", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "contrib_ltree.txt"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -244,7 +241,7 @@ old_8_3_check_ltree_usage(ClusterInfo *cluster) for (rowno = 0; rowno < ntups; rowno++) { found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "Could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) @@ -304,8 +301,7 @@ old_8_3_rebuild_tsvector_tables(ClusterInfo *cluster, bool check_mode) prep_status("Checking for tsvector user columns"); - snprintf(output_path, sizeof(output_path), "%s/rebuild_tsvector_tables.sql", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "rebuild_tsvector_tables.sql"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -364,7 +360,7 @@ old_8_3_rebuild_tsvector_tables(ClusterInfo *cluster, bool check_mode) found = true; if (!check_mode) { - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) { @@ -446,8 +442,7 @@ old_8_3_invalidate_hash_gin_indexes(ClusterInfo *cluster, bool check_mode) prep_status("Checking for hash and GIN indexes"); - snprintf(output_path, sizeof(output_path), "%s/reindex_hash_and_gin.sql", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "reindex_hash_and_gin.sql"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -481,7 +476,7 @@ old_8_3_invalidate_hash_gin_indexes(ClusterInfo *cluster, bool check_mode) found = true; if (!check_mode) { - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) { @@ -556,8 +551,7 @@ old_8_3_invalidate_bpchar_pattern_ops_indexes(ClusterInfo *cluster, prep_status("Checking for bpchar_pattern_ops indexes"); - snprintf(output_path, sizeof(output_path), "%s/reindex_bpchar_ops.sql", - os_info.cwd); + snprintf(output_path, sizeof(output_path), "reindex_bpchar_ops.sql"); for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++) { @@ -601,7 +595,7 @@ old_8_3_invalidate_bpchar_pattern_ops_indexes(ClusterInfo *cluster, found = true; if (!check_mode) { - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) { @@ -683,7 +677,7 @@ old_8_3_create_sequence_script(ClusterInfo *cluster) bool found = false; char *output_path = pg_malloc(MAXPGPATH); - snprintf(output_path, MAXPGPATH, "%s/adjust_sequences.sql", os_info.cwd); + snprintf(output_path, MAXPGPATH, "adjust_sequences.sql"); prep_status("Creating script to adjust sequences"); @@ -723,7 +717,7 @@ old_8_3_create_sequence_script(ClusterInfo *cluster) found = true; - if (script == NULL && (script = fopen(output_path, "w")) == NULL) + if (script == NULL && (script = fopen_priv(output_path, "w")) == NULL) pg_log(PG_FATAL, "could not open file \"%s\": %s\n", output_path, getErrorText(errno)); if (!db_used) { diff --git a/doc/src/sgml/pgupgrade.sgml b/doc/src/sgml/pgupgrade.sgml index 4f263fe672..6ecdfda671 100644 --- a/doc/src/sgml/pgupgrade.sgml +++ b/doc/src/sgml/pgupgrade.sgml @@ -90,30 +90,12 @@ variable PGDATANEW - - - - enable debugging - - - - debug_filename - debug_filename - output debugging activity to file - - use hard links instead of copying files to the new cluster - - log_filename - log_filename - log internal activity to file - - options options @@ -142,6 +124,13 @@ variable PGPORTNEW + + + + retain SQL and log files even after successful completion + + + user_name user_name @@ -152,7 +141,7 @@ - enable verbose output + enable verbose internal logging