Date: Fri, 17 Dec 2021 11:21:13 -0600
From: Justin Pryzby <pryzby@telsasoft.com>
To: Daniel Gustafsson <daniel@yesql.se>
Cc: Peter Eisentraut <peter.eisentraut@enterprisedb.com>,
	Michael Paquier <michael@paquier.xyz>,
	Andrew Dunstan <andrew@dunslane.net>,
	Bruce Momjian <bruce@momjian.us>, Tom Lane <tgl@sss.pgh.pa.us>,
	pgsql-hackers@lists.postgresql.org
Subject: Re: pg_upgrade should truncate/remove its logs before running
Message-ID: <20211217172113.GL17618@telsasoft.com>
References: <20211212025017.GN17618@telsasoft.com>
 <20211215210916.GC4440@momjian.us>
 <711370.1639603043@sss.pgh.pa.us>
 <20211215212343.GE4440@momjian.us>
 <a89d6602-0fad-c6cc-10cc-20105c4c01ad@dunslane.net>
 <20211215221310.GU17618@telsasoft.com>
 <YbqYuQkoXm8IytZ0@paquier.xyz>
 <c7615cf3-621a-7fc4-79ec-6b2554cd5b68@enterprisedb.com>
 <E66B93B0-8579-48BC-9CA4-4C6E3A97408D@yesql.se>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="ZJdw2tg8ohM/A8db"
Content-Disposition: inline
In-Reply-To: <E66B93B0-8579-48BC-9CA4-4C6E3A97408D@yesql.se>
User-Agent: Mutt/1.9.4 (2018-02-28)
Archived-At: 
 <https://www.postgresql.org/message-id/20211217172113.GL17618%40telsasoft.com>
Precedence: bulk


--ZJdw2tg8ohM/A8db
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

On Thu, Dec 16, 2021 at 12:23:08PM +0100, Daniel Gustafsson wrote:
> > On 16 Dec 2021, at 12:11, Peter Eisentraut <peter.eisentraut@enterprisedb.com> wrote:
> 
> > Could we make it write just one log file?  Is having multiple log files better?
> 
> Having individual <checkname>.txt files from checks with additional information
> on how to handle the error are quite convenient when writing wrappers around
> pg_upgrade (speaking from experience of having written multiple pg_upgraade
> frontends).  Parsing a single logfile is more work, and will break existing
> scripts.
> 
> I'm in favor of a predictable by default logpath, with a parameter to override,
> as mentioned upthread.

I put this together in the simplest way, prefixing all the filenames with the
configured path..

Another options is to chdir() into the given path.  But, pg_upgrade takes (and
requires) a bunch of other paths, like -d -D -b -B, and those are traditionally
interpretted relative to CWD.  I could getcwd() and prefix all the -[dDbB] with
that, but prefixing a handful of binary/data paths is hardly better than
prefixing a handful of dump/logfile paths.  I suppose that openat() isn't
portable.  I don't think this it's worth prohibiting relative paths, so I can't
think of any less-naive way to do this.

I didn't move the delete-old-cluster.sh, since that's intended to stay around
even after a successful upgrade, as opposed to the other logs, which are
typically removed at that point.

-- 
Justin

--ZJdw2tg8ohM/A8db
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="0001-pg_upgrade-write-logfiles-and-dumps-in-subdir.patch"

From 7b608a415645682a9853bb4fbfde54caa6ccc137 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryzbyj@telsasoft.com>
Date: Sat, 11 Dec 2021 19:19:50 -0600
Subject: [PATCH] pg_upgrade: write logfiles and dumps in subdir..

The subdir must not exist when pg_upgrade is started.
This avoids appending the logfiles which have pre-existing errors in them.
And allows cleaning up after pg_upgrade more easily.
---
 src/bin/pg_upgrade/check.c      | 10 ++---
 src/bin/pg_upgrade/dump.c       |  8 ++--
 src/bin/pg_upgrade/exec.c       |  5 ++-
 src/bin/pg_upgrade/function.c   |  3 +-
 src/bin/pg_upgrade/option.c     | 21 +++++++++--
 src/bin/pg_upgrade/pg_upgrade.c | 65 +++++++++++++++++++++------------
 src/bin/pg_upgrade/pg_upgrade.h |  1 +
 src/bin/pg_upgrade/server.c     |  4 +-
 8 files changed, 77 insertions(+), 40 deletions(-)

diff --git a/src/bin/pg_upgrade/check.c b/src/bin/pg_upgrade/check.c
index 1b8ef79242..9bc4e106dd 100644
--- a/src/bin/pg_upgrade/check.c
+++ b/src/bin/pg_upgrade/check.c
@@ -552,7 +552,7 @@ create_script_for_old_cluster_deletion(char **deletion_script_file_name)
 
 	prep_status("Creating script to delete old cluster");
 
-	if ((script = fopen_priv(*deletion_script_file_name, "w")) == NULL)
+	if ((script = fopen_priv(*deletion_script_file_name, "w")) == NULL) // OK ?
 		pg_fatal("could not open file \"%s\": %s\n",
 				 *deletion_script_file_name, strerror(errno));
 
@@ -784,7 +784,7 @@ check_for_isn_and_int8_passing_mismatch(ClusterInfo *cluster)
 		return;
 	}
 
-	snprintf(output_path, sizeof(output_path),
+	snprintf(output_path, sizeof(output_path), "%s/%s", log_opts.basedir,
 			 "contrib_isn_and_int8_pass_by_value.txt");
 
 	for (dbnum = 0; dbnum < cluster->dbarr.ndbs; dbnum++)
@@ -861,7 +861,7 @@ check_for_user_defined_postfix_ops(ClusterInfo *cluster)
 
 	prep_status("Checking for user-defined postfix operators");
 
-	snprintf(output_path, sizeof(output_path),
+	snprintf(output_path, sizeof(output_path), "%s/%s", log_opts.basedir,
 			 "postfix_ops.txt");
 
 	/* Find any user defined postfix operators */
@@ -960,7 +960,7 @@ check_for_tables_with_oids(ClusterInfo *cluster)
 
 	prep_status("Checking for tables WITH OIDS");
 
-	snprintf(output_path, sizeof(output_path),
+	snprintf(output_path, sizeof(output_path), "%s/%s", log_opts.basedir,
 			 "tables_with_oids.txt");
 
 	/* Find any tables declared WITH OIDS */
@@ -1215,7 +1215,7 @@ check_for_user_defined_encoding_conversions(ClusterInfo *cluster)
 
 	prep_status("Checking for user-defined encoding conversions");
 
-	snprintf(output_path, sizeof(output_path),
+	snprintf(output_path, sizeof(output_path), "%s/%s", log_opts.basedir,
 			 "encoding_conversions.txt");
 
 	/* Find any user defined encoding conversions */
diff --git a/src/bin/pg_upgrade/dump.c b/src/bin/pg_upgrade/dump.c
index 90060d0f8e..fe979e0df4 100644
--- a/src/bin/pg_upgrade/dump.c
+++ b/src/bin/pg_upgrade/dump.c
@@ -22,10 +22,10 @@ generate_old_dump(void)
 	/* run new pg_dumpall binary for globals */
 	exec_prog(UTILITY_LOG_FILE, NULL, true, true,
 			  "\"%s/pg_dumpall\" %s --globals-only --quote-all-identifiers "
-			  "--binary-upgrade %s -f %s",
+			  "--binary-upgrade %s -f %s/%s",
 			  new_cluster.bindir, cluster_conn_opts(&old_cluster),
 			  log_opts.verbose ? "--verbose" : "",
-			  GLOBALS_DUMP_FILE);
+			  log_opts.basedir, GLOBALS_DUMP_FILE);
 	check_ok();
 
 	prep_status("Creating dump of database schemas\n");
@@ -52,10 +52,10 @@ generate_old_dump(void)
 
 		parallel_exec_prog(log_file_name, NULL,
 						   "\"%s/pg_dump\" %s --schema-only --quote-all-identifiers "
-						   "--binary-upgrade --format=custom %s --file=\"%s\" %s",
+						   "--binary-upgrade --format=custom %s --file=\"%s/%s\" %s",
 						   new_cluster.bindir, cluster_conn_opts(&old_cluster),
 						   log_opts.verbose ? "--verbose" : "",
-						   sql_file_name, escaped_connstr.data);
+						   log_opts.basedir, sql_file_name, escaped_connstr.data);
 
 		termPQExpBuffer(&escaped_connstr);
 	}
diff --git a/src/bin/pg_upgrade/exec.c b/src/bin/pg_upgrade/exec.c
index 19cc06e0c3..6b70c20cf7 100644
--- a/src/bin/pg_upgrade/exec.c
+++ b/src/bin/pg_upgrade/exec.c
@@ -78,11 +78,12 @@ get_bin_version(ClusterInfo *cluster)
  * The code requires it be called first from the primary thread on Windows.
  */
 bool
-exec_prog(const char *log_file, const char *opt_log_file,
+exec_prog(const char *log_filename, const char *opt_log_file,
 		  bool report_error, bool exit_on_error, const char *fmt,...)
 {
 	int			result = 0;
 	int			written;
+	char		log_file[MAXPGPATH];
 
 #define MAXCMDLEN (2 * MAXPGPATH)
 	char		cmd[MAXCMDLEN];
@@ -97,6 +98,8 @@ exec_prog(const char *log_file, const char *opt_log_file,
 		mainThreadId = GetCurrentThreadId();
 #endif
 
+	snprintf(log_file, MAXPGPATH, "%s/%s", log_opts.basedir, log_filename);
+
 	written = 0;
 	va_start(ap, fmt);
 	written += vsnprintf(cmd + written, MAXCMDLEN - written, fmt, ap);
diff --git a/src/bin/pg_upgrade/function.c b/src/bin/pg_upgrade/function.c
index 627ec0ce28..9e16df3203 100644
--- a/src/bin/pg_upgrade/function.c
+++ b/src/bin/pg_upgrade/function.c
@@ -128,7 +128,8 @@ check_loadable_libraries(void)
 
 	prep_status("Checking for presence of required libraries");
 
-	snprintf(output_path, sizeof(output_path), "loadable_libraries.txt");
+	snprintf(output_path, sizeof(output_path), "%s/%s",
+			log_opts.basedir, "loadable_libraries.txt");
 
 	/*
 	 * Now we want to sort the library names into order.  This avoids multiple
diff --git a/src/bin/pg_upgrade/option.c b/src/bin/pg_upgrade/option.c
index 2d92294d9d..2c293205ee 100644
--- a/src/bin/pg_upgrade/option.c
+++ b/src/bin/pg_upgrade/option.c
@@ -65,6 +65,7 @@ parseCommandLine(int argc, char *argv[])
 	FILE	   *fp;
 	char	  **filename;
 	time_t		run_time = time(NULL);
+	char		filename_path[MAXPGPATH];
 
 	user_opts.transfer_mode = TRANSFER_MODE_COPY;
 
@@ -202,8 +203,18 @@ parseCommandLine(int argc, char *argv[])
 	if (optind < argc)
 		pg_fatal("too many command-line arguments (first is \"%s\")\n", argv[optind]);
 
-	if ((log_opts.internal = fopen_priv(INTERNAL_LOG_FILE, "a")) == NULL)
-		pg_fatal("could not open log file \"%s\": %m\n", INTERNAL_LOG_FILE);
+	log_opts.basedir = getenv("PG_UPGRADE_LOGDIR");
+	if (log_opts.basedir != NULL)
+		log_opts.basedir = strdup(log_opts.basedir);
+	else
+		log_opts.basedir = "pg_upgrade_log.d";
+
+	if (mkdir(log_opts.basedir, 00700))
+		pg_fatal("could not create log directory \"%s\": %m\n", log_opts.basedir);
+
+	snprintf(filename_path, sizeof(filename_path), "%s/%s", log_opts.basedir, INTERNAL_LOG_FILE);
+	if ((log_opts.internal = fopen_priv(filename_path, "a")) == NULL)
+		pg_fatal("could not open log file \"%s\": %m\n", filename_path);
 
 	if (log_opts.verbose)
 		pg_log(PG_REPORT, "Running in verbose mode\n");
@@ -211,8 +222,10 @@ parseCommandLine(int argc, char *argv[])
 	/* label start of upgrade in logfiles */
 	for (filename = output_files; *filename != NULL; filename++)
 	{
-		if ((fp = fopen_priv(*filename, "a")) == NULL)
-			pg_fatal("could not write to log file \"%s\": %m\n", *filename);
+		snprintf(filename_path, sizeof(filename_path), "%s/%s",
+				log_opts.basedir, *filename);
+		if ((fp = fopen_priv(filename_path, "a")) == NULL)
+			pg_fatal("could not write to log file \"%s\": %m\n", filename_path);
 
 		/* Start with newline because we might be appending to a file. */
 		fprintf(fp, "\n"
diff --git a/src/bin/pg_upgrade/pg_upgrade.c b/src/bin/pg_upgrade/pg_upgrade.c
index 3628bd74a7..9f1b17fc15 100644
--- a/src/bin/pg_upgrade/pg_upgrade.c
+++ b/src/bin/pg_upgrade/pg_upgrade.c
@@ -302,9 +302,9 @@ prepare_new_globals(void)
 	prep_status("Restoring global objects in the new cluster");
 
 	exec_prog(UTILITY_LOG_FILE, NULL, true, true,
-			  "\"%s/psql\" " EXEC_PSQL_ARGS " %s -f \"%s\"",
+			  "\"%s/psql\" " EXEC_PSQL_ARGS " %s -f \"%s/%s\"",
 			  new_cluster.bindir, cluster_conn_opts(&new_cluster),
-			  GLOBALS_DUMP_FILE);
+			  log_opts.basedir, GLOBALS_DUMP_FILE);
 	check_ok();
 }
 
@@ -348,10 +348,11 @@ create_new_objects(void)
 				  true,
 				  true,
 				  "\"%s/pg_restore\" %s %s --exit-on-error --verbose "
-				  "--dbname postgres \"%s\"",
+				  "--dbname postgres \"%s/%s\"",
 				  new_cluster.bindir,
 				  cluster_conn_opts(&new_cluster),
 				  create_opts,
+				  log_opts.basedir,
 				  sql_file_name);
 
 		break;					/* done once we've processed template1 */
@@ -385,10 +386,11 @@ create_new_objects(void)
 		parallel_exec_prog(log_file_name,
 						   NULL,
 						   "\"%s/pg_restore\" %s %s --exit-on-error --verbose "
-						   "--dbname template1 \"%s\"",
+						   "--dbname template1 \"%s/%s\"",
 						   new_cluster.bindir,
 						   cluster_conn_opts(&new_cluster),
 						   create_opts,
+						   log_opts.basedir,
 						   sql_file_name);
 	}
 
@@ -681,32 +683,49 @@ set_frozenxids(bool minmxid_only)
 static void
 cleanup(void)
 {
+	int			dbnum;
+	char	  **filename;
+	char		filename_path[MAXPGPATH];
+
 	fclose(log_opts.internal);
 
 	/* Remove dump and log files? */
-	if (!log_opts.retain)
-	{
-		int			dbnum;
-		char	  **filename;
+	if (log_opts.retain)
+		return;
 
-		for (filename = output_files; *filename != NULL; filename++)
-			unlink(*filename);
+	for (filename = output_files; *filename != NULL; filename++)
+	{
+		snprintf(filename_path, sizeof(filename_path), "%s/%s",
+			log_opts.basedir, *filename);
+		if (unlink(filename_path))
+			pg_log(PG_WARNING, "failed to unlink: %s: %m\n",
+			filename_path);
+	}
 
-		/* remove dump files */
-		unlink(GLOBALS_DUMP_FILE);
+	/* remove dump files */
+	snprintf(filename_path, sizeof(filename_path), "%s/%s",
+		log_opts.basedir, GLOBALS_DUMP_FILE);
+	if (unlink(filename_path))
+		pg_log(PG_WARNING, "failed to unlink: %s: %m\n", filename_path);
 
-		if (old_cluster.dbarr.dbs)
-			for (dbnum = 0; dbnum < old_cluster.dbarr.ndbs; dbnum++)
-			{
-				char		sql_file_name[MAXPGPATH],
-							log_file_name[MAXPGPATH];
-				DbInfo	   *old_db = &old_cluster.dbarr.dbs[dbnum];
+	if (old_cluster.dbarr.dbs)
+	{
+		char *start = filename_path + strlen(log_opts.basedir) + 1;
+		int remaining = sizeof(filename_path) - strlen(log_opts.basedir) - 1;
+		for (dbnum = 0; dbnum < old_cluster.dbarr.ndbs; dbnum++)
+		{
+			DbInfo	   *old_db = &old_cluster.dbarr.dbs[dbnum];
 
-				snprintf(sql_file_name, sizeof(sql_file_name), DB_DUMP_FILE_MASK, old_db->db_oid);
-				unlink(sql_file_name);
+			snprintf(start, remaining, DB_DUMP_FILE_MASK, old_db->db_oid);
+			if (unlink(filename_path))
+				pg_log(PG_WARNING, "failed to unlink: %s: %m\n", filename_path);
 
-				snprintf(log_file_name, sizeof(log_file_name), DB_DUMP_LOG_FILE_MASK, old_db->db_oid);
-				unlink(log_file_name);
-			}
+			snprintf(start, remaining, DB_DUMP_LOG_FILE_MASK, old_db->db_oid);
+			if (unlink(filename_path))
+				pg_log(PG_WARNING, "failed to unlink: %s: %m\n", filename_path);
+		}
 	}
+
+	if (rmdir(log_opts.basedir))
+			pg_log(PG_WARNING, "failed to rmdir: %s: %m\n", log_opts.basedir);
 }
diff --git a/src/bin/pg_upgrade/pg_upgrade.h b/src/bin/pg_upgrade/pg_upgrade.h
index 235a770026..4383a56afd 100644
--- a/src/bin/pg_upgrade/pg_upgrade.h
+++ b/src/bin/pg_upgrade/pg_upgrade.h
@@ -269,6 +269,7 @@ typedef struct
 	FILE	   *internal;		/* internal log FILE */
 	bool		verbose;		/* true -> be verbose in messages */
 	bool		retain;			/* retain log files on success */
+	char		*basedir;		/* Dir to create logfiles */
 } LogOpts;
 
 
diff --git a/src/bin/pg_upgrade/server.c b/src/bin/pg_upgrade/server.c
index 442a345173..328c19ce59 100644
--- a/src/bin/pg_upgrade/server.c
+++ b/src/bin/pg_upgrade/server.c
@@ -238,8 +238,8 @@ start_postmaster(ClusterInfo *cluster, bool report_and_exit_on_error)
 	 * vacuumdb --freeze actually freezes the tuples.
 	 */
 	snprintf(cmd, sizeof(cmd),
-			 "\"%s/pg_ctl\" -w -l \"%s\" -D \"%s\" -o \"-p %d -b%s %s%s\" start",
-			 cluster->bindir, SERVER_LOG_FILE, cluster->pgconfig, cluster->port,
+			 "\"%s/pg_ctl\" -w -l \"%s/%s\" -D \"%s\" -o \"-p %d -b%s %s%s\" start",
+			 cluster->bindir, log_opts.basedir, SERVER_LOG_FILE, cluster->pgconfig, cluster->port,
 			 (cluster == &new_cluster) ?
 			 " -c synchronous_commit=off -c fsync=off -c full_page_writes=off -c vacuum_defer_cleanup_age=0" : "",
 			 cluster->pgopts ? cluster->pgopts : "", socket_string);
-- 
2.17.0


--ZJdw2tg8ohM/A8db--