Subject: Re: Rewriting the test of pg_upgrade as a TAP test - take three - remastered set

From: Michael Paquier <[email-masked]>
Date: Thu, 31 Mar 2022 13:10:43 +0900

On Thu, Mar 03, 2022 at 02:03:38PM +0900, Michael Paquier wrote:
> Indeed.  I have reworked the whole, rather than just those three
> sentences.

So, any particular feelings about this patch?  This has been around
for a couple of months/years now, so it could be a good time to do the
switch now rather than wait an extra year, or even the beginning of
the next release cycle.  And the buildfarm is already able to handle
that in its code based on the last release, by skipping the upgrade
check if it finds a pg_upgrade/t/ subdirectory.
--
Michael

---

From: Tom Lane <[email-masked]>
Date: Thu, 31 Mar 2022 01:00:14 -0400

> check if it finds a pg_upgrade/t/ subdirectory.

There's still about a third of the buildfarm running older
client releases --- I count

      2 REL_8
      2 REL_10
     13 REL_11
      6 REL_12
     16 REL_13.1
     89 REL_14

How well does this patch work with pre-14 buildfarm clients?

			regards, tom lane

---

From: Tom Lane <[email-masked]>
Date: Thu, 31 Mar 2022 01:25:17 -0400

>      89 REL_14

Wait a minute ... actually, what's most relevant here is
the population running TAP tests, which seems to be

      2 REL_8
      4 REL_11
      1 REL_12
      7 REL_13.1
     53 REL_14

So there are still some people we'd have to nag if it doesn't
work pre-v14, but fewer than I thought --- specifically,
the owners of

butterflyfish
copperhead
eelpout
elver
halibut
kittiwake
mantid
marabou
massasauga
myna
snakefly
snapper
spurfowl
tadarida

			regards, tom lane

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 22:36:16 -0700

> How well does this patch work with pre-14 buildfarm clients?

Looks to me like it'll just run the test twice, once via TestUpgrade, once via
taptest. It's possible that there could be trouble somehow due to duplicated
log files or something?

---

From: Michael Paquier <[email-masked]>
Date: Thu, 31 Mar 2022 16:56:36 +0900

> taptest. It's possible that there could be trouble somehow due to duplicated

Hmm.  TestUpgrade.pm also uses tmp_check/, and the TAP tests would
remove this path before running.  Still, all the contents of the logs
would be printed out before moving to the next tests at the end of
check-pg_upgrade.  It does not seem like this double run is going to
be an issue on this side. 
--
Michael

---

From: Tom Lane <[email-masked]>
Date: Thu, 31 Mar 2022 09:49:50 -0400

> be an issue on this side. 

Well, let's go ahead with it and see what happens.  If it's too
much of a mess we can always revert.

			regards, tom lane

---

From: Michael Paquier <[email-masked]>
Date: Fri, 1 Apr 2022 10:16:48 +0900

> much of a mess we can always revert.

Okay, done after an extra round of self-review.  I have finished by
tweaking a couple of comments, and adjusted further TESTING to explain
what needs to be done to have a dump compatible with the test.  Let's
now see what goes wrong.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Fri, 1 Apr 2022 12:54:32 +0900

> what needs to be done to have a dump compatible with the test.  Let's

So, the first reports are published, and the buildfarm is rather cool
on the matter.  wrasse is the only buildfarm member that has reported
a failure, complaining that the dumps generated do not match.  I am
not completely sure what's going on there, so I have applied an extra
patch to get more information from the logs on failures, and switched
the test to use File::Compare::compare() to check if the dumps match.
This last part feels safer in the long run, anyway.  There should be a
diff command as previous runs used test.sh, so perhaps this is an
issue with its perl.  The next report should tell more.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Fri, 1 Apr 2022 13:00:20 +0900

On Thu, Mar 31, 2022 at 08:42:41PM -0700, Noah Misch wrote:
> The failure looked like this:
> 
> # Running: diff -q /export/home/nm/farm/studio64v12_6/HEAD/pgsql.build/src/bin/pg_upgrade/tmp_check/tmp_test_lPFv/dump1.sql /export/home/nm/farm/studio64v12_6/HEAD/pgsql.build/src/bin/pg_upgrade/tmp_check/tmp_test_lPFv/dump2.sql
> /usr/bin/diff: illegal option -- q
> usage: diff [-bitw] [-c | -e | -f | -h | -n | -u] file1 file2
>        diff [-bitw] [-C number | -U number] file1 file2
>        diff [-bitw] [-D string] file1 file2
>        diff [-bitw] [-c | -e | -f | -h | -n | -u] [-l] [-r] [-s] [-S name] directory1 directory2
> not ok 4 - old and new dump match after pg_upgrade

Ah, thanks for the information!  So the problem was that the first
commit of the patch took the diff command from the MSVC scripts, and
there is no -q on Solaris 11.3.  Using File::Compare should be enough
to fix the problem, then.  Hopefully.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Fri, 1 Apr 2022 15:01:38 +0900

On Thu, Mar 31, 2022 at 10:51:59PM -0500, Justin Pryzby wrote:
> Is diff -q defined somewhere ?  I can't find it in postgres sources nor in
> sources for bf client.

322becb has added such a call, at the end of 002_pg_upgrade.pl.
vcregress.pl also has one before this commit.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Fri, 1 Apr 2022 20:53:10 +0900

> vcregress.pl also has one before this commit.

The Windows animals seem to be in good shape, except hamerkop that
dies on "vcregress upgradecheck" when the TAP tests are disabled
causing the buildfarm client to stop.  My idea to use upgradecheck
leads to more code than just moving the test to bincheck so let's
reuse the suggestion from Andres upthread and disable completely
upgradecheck, keeping the target around only for compatibility.  The
attached does that, and the test of pg_upgrade would go through
bincheck instead.

It is late here, I'll try to get that patched up tomorrow.
--
Michael
diff --git a/doc/src/sgml/install-windows.sgml b/doc/src/sgml/install-windows.sgml
index 43d05bde4e..18101e7a70 100644
--- a/doc/src/sgml/install-windows.sgml
+++ b/doc/src/sgml/install-windows.sgml
@@ -470,7 +470,6 @@ $ENV{CONFIG}="Debug";
 <userinput>vcregress isolationcheck</userinput>
 <userinput>vcregress bincheck</userinput>
 <userinput>vcregress recoverycheck</userinput>
-<userinput>vcregress upgradecheck</userinput>
 </screen>
 
    To change the schedule used (default is parallel), append it to the
diff --git a/src/tools/msvc/vcregress.pl b/src/tools/msvc/vcregress.pl
index e896820ac5..fbfc781508 100644
--- a/src/tools/msvc/vcregress.pl
+++ b/src/tools/msvc/vcregress.pl
@@ -106,7 +106,7 @@ my %command = (
 	ISOLATIONCHECK => \&isolationcheck,
 	BINCHECK       => \&bincheck,
 	RECOVERYCHECK  => \&recoverycheck,
-	UPGRADECHECK   => \&upgradecheck,
+	UPGRADECHECK   => \&upgradecheck, # no-op
 	TAPTEST        => \&taptest,);
 
 my $proc = $command{$what};
@@ -286,9 +286,6 @@ sub bincheck
 	foreach my $dir (@bin_dirs)
 	{
 		next unless -d "$dir/t";
-		# Do not consider pg_upgrade, as it is handled by
-		# upgradecheck.
-		next if ($dir =~ "/pg_upgrade/");
 
 		my $status = tap_check($dir);
 		$mstat ||= $status;
@@ -520,9 +517,9 @@ sub generate_db
 
 sub upgradecheck
 {
-	InstallTemp();
-	my $mstat = tap_check("$topdir/src/bin/pg_upgrade");
-	exit $mstat if $mstat;
+	# pg_upgrade is now handled by bincheck, but keep this
+	# target for backward compatibility.
+	print "upgradecheck disabled\n";
 	return;
 }

---

From: Michael Paquier <[email-masked]>
Date: Sat, 2 Apr 2022 12:10:49 +0900

On Fri, Apr 01, 2022 at 08:34:34AM -0500, Justin Pryzby wrote:
> If you do that, should also remove upgradecheck from .cirrus.yaml, which
> currently runs the upgradecheck target.

Indeed.  It makes no sense to keep that.  I have removed this part and
applied the patch, after one extra run through the CI.

> An alternative to your patch to have the buildfarm client avoid calling
> upgradecheck if tap tests are disabled.  Under your patch, upgrade check is a
> NOP, so it should stop calling upgradecheck anyway.  So maybe this is a better
> option ?

Yeah, there is an extra issue with the buildfarm client here.  The
animals that have TAP enabled are now running the tests of pg_upgrade
twice: once per the optional module TestUpgrade and once in
run_bin_tests()@run_build.pl.  This is something that needs to be
changed in the client code itself, and maybe the best fix is to
disable TestUpgrade.pm when running with v15~ or a newer version.  A
fix with this approach would become much easier once REL_15_STABLE is
created, though.  I am pretty sure that it should also be possible to
change the list of optional modules depending on the branch running,
but I have not dug into that..
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Mon, 2 May 2022 16:00:53 +0900

On Sun, May 01, 2022 at 09:27:18PM -0700, Noah Misch wrote:
> commit 322becb wrote:

Thanks, Noah.  I am out this week, but I should be able to address all
your points at the beginning of next week.  I have added an open item
for now.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Mon, 9 May 2022 12:18:39 +0900

On Sun, May 01, 2022 at 09:27:18PM -0700, Noah Misch wrote:
> Nothing checks the command result, so the test file passes even if each of
> these createdb calls fails.  Other run_log() calls in this file have the same
> problem.  This particular one should be command_ok() or similar.

All of them could rely on command_ok(), as they should never fail, so
switched this way.

> --host and --port are redundant in a PostgreSQL::Test::Cluster::run_log call,
> because that call puts equivalent configuration in the environment.  Other
> calls in the file have the same redundant operands.  (No other test file has
> redundant --host or --port.)

Right.  Removed all that.

>> +	# Grab any regression options that may be passed down by caller.
>> +	my $extra_opts_val = $ENV{EXTRA_REGRESS_OPT} || "";
> 
> Typo: s/_OPT/_OPTS/

Oops, fixed.

>> +	my @extra_opts     = split(/\s+/, $extra_opts_val);
> 
> src/test/recovery/t/027_stream_regress.pl and the makefiles treat
> EXTRA_REGRESS_OPTS as a shell fragment.  To be compatible, use the
> src/test/recovery/t/027_stream_regress.pl approach.  Affected usage patetrns
> are not very important, but since the tree has code for it, you may as well
> borrow that code.  These examples witness the difference:

So the pattern of EXTRA_REGRESS_OPTS being used in the Makefiles is
the decision point here.  Makes sense.

>> -# Create databases with names covering the ASCII bytes other than NUL, BEL,
>> -# LF, or CR.  BEL would ring the terminal bell in the course of this test, and
>> -# it is not otherwise a special case.  PostgreSQL doesn't support the rest.
>> -dbname1=`awk 'BEGIN { for (i= 1; i < 46; i++)
>> -	if (i != 7 && i != 10 && i != 13) printf "%c", i }' </dev/null`
>> -# Exercise backslashes adjacent to double quotes, a Windows special case.
>> -dbname1='\"\'$dbname1'\\"\\\'
> 
> This rewrite dropped the exercise of backslashes adjacent to double quotes.

Damn, thanks.  If I am reading that right, this could be done with the
following addition in generate_db(), adding double quotes surrounded
by backslashes before and after the database name: 
$dbname = '\\"\\' . $dbname . '\\"\\';

All these fixes lead me to the attached patch.  Does that look fine to
you?

Thanks,
--
Michael
diff --git a/src/bin/pg_upgrade/t/002_pg_upgrade.pl b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
index 05bf161843..4002982dc0 100644
--- a/src/bin/pg_upgrade/t/002_pg_upgrade.pl
+++ b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
@@ -21,9 +21,11 @@ sub generate_db
 		next if $i == 7 || $i == 10 || $i == 13;    # skip BEL, LF, and CR
 		$dbname = $dbname . sprintf('%c', $i);
 	}
-	$node->run_log(
-		[ 'createdb', '--host', $node->host, '--port', $node->port, $dbname ]
-	);
+
+	# Exercise backslashes adjacent to double quotes, a Windows special
+	# case.
+	$dbname = '\\"\\' . $dbname . '\\"\\';
+	$node->command_ok([ 'createdb', $dbname ]);
 }
 
 # The test of pg_upgrade requires two clusters, an old one and a new one
@@ -70,12 +72,7 @@ if (defined($ENV{olddump}))
 
 	# Load the dump using the "postgres" database as "regression" does
 	# not exist yet, and we are done here.
-	$oldnode->command_ok(
-		[
-			'psql',   '-X',           '-f',     $olddumpfile,
-			'--port', $oldnode->port, '--host', $oldnode->host,
-			'postgres'
-		]);
+	$oldnode->command_ok([ 'psql', '-X', '-f', $olddumpfile, 'postgres' ]);
 }
 else
 {
@@ -87,8 +84,7 @@ else
 	generate_db($oldnode, 91, 127);
 
 	# Grab any regression options that may be passed down by caller.
-	my $extra_opts_val = $ENV{EXTRA_REGRESS_OPT} || "";
-	my @extra_opts     = split(/\s+/, $extra_opts_val);
+	my $extra_opts = $ENV{EXTRA_REGRESS_OPTS} || "";
 
 	# --dlpath is needed to be able to find the location of regress.so
 	# and any libraries the regression tests require.
@@ -100,19 +96,19 @@ else
 	# --inputdir points to the path of the input files.
 	my $inputdir = "$srcdir/src/test/regress";
 
-	my @regress_command = [
-		$ENV{PG_REGRESS},                             @extra_opts,
-		'--dlpath',                                   $dlpath,
-		'--max-concurrent-tests',                     '20',
-		'--bindir=',                                  '--host',
-		$oldnode->host,                               '--port',
-		$oldnode->port,                               '--schedule',
-		"$srcdir/src/test/regress/parallel_schedule", '--outputdir',
-		$outputdir,                                   '--inputdir',
-		$inputdir
-	];
-
-	my $rc = run_log(@regress_command);
+	my $rc =
+	  system($ENV{PG_REGRESS}
+		  . "$extra_opts "
+		  . "--dlpath=\"$dlpath\" "
+		  . "--bindir= "
+		  . "--host="
+		  . $oldnode->host . " "
+		  . "--port="
+		  . $oldnode->port . " "
+		  . "--schedule=$srcdir/src/test/regress/parallel_schedule "
+		  . "--max-concurrent-tests=20 "
+		  . "--inputdir=\"$inputdir\" "
+		  . "--outputdir=\"$outputdir\"");
 	if ($rc != 0)
 	{
 		# Dump out the regression diffs file, if there is one
@@ -133,12 +129,10 @@ if (defined($ENV{oldinstall}))
 {
 	# Note that upgrade_adapt.sql from the new version is used, to
 	# cope with an upgrade to this version.
-	$oldnode->run_log(
+	$oldnode->command_ok(
 		[
-			'psql',   '-X',
-			'-f',     "$srcdir/src/bin/pg_upgrade/upgrade_adapt.sql",
-			'--port', $oldnode->port,
-			'--host', $oldnode->host,
+			'psql', '-X',
+			'-f',   "$srcdir/src/bin/pg_upgrade/upgrade_adapt.sql",
 			'regression'
 		]);
 }
@@ -232,7 +226,7 @@ if (-d $log_path)
 }
 
 # Second dump from the upgraded instance.
-$newnode->run_log(
+$newnode->command_ok(
 	[
 		'pg_dumpall', '--no-sync',
 		'-d',         $newnode->connstr('postgres'),

---

From: Michael Paquier <[email-masked]>
Date: Wed, 11 May 2022 10:29:44 +0900

On Mon, May 09, 2022 at 12:18:39PM +0900, Michael Paquier wrote:
> All these fixes lead me to the attached patch.

I have applied this stuff as of 7dd3ee5, in time for beta1, and closed
the open item.  One difference is that I've added one backslash
surrounding the double quote at the beginning *and* the end of the
database name in the patch.  However, the original case was different,
with:
- At the beginning of the database name, one backslash before and
after the double quote.
- At the end of the database name, two backslaces before the double
quote and three after the double quote.
--
Michael

---

From: Noah Misch <[email-masked]>
Date: Tue, 10 May 2022 22:32:55 -0700

> quote and three after the double quote.

Why did you discontinue testing the longstanding test database name?

---

From: Michael Paquier <[email-masked]>
Date: Thu, 12 May 2022 14:27:30 +0900

> Why did you discontinue testing the longstanding test database name?

I am not sure what you mean here.  Are you saying that the test should
be changed to prefix each database name by "regression", as it was the
case in test.sh?  Or do you mean that the backslash/double-quote
business should only apply to the first database name and not the
other two, implying that the new generate_db() in 002_pg_upgrade.pl
had better have a $prefix and a $suffix like it was originally
written?
--
Michael

---

From: Noah Misch <[email-masked]>
Date: Sat, 14 May 2022 01:27:28 -0700

> > > quote and three after the double quote.

Here, you describe differences between test.sh and your rewrite of test.sh.

> I am not sure what you mean here.

Here, I requested the rationale for the differences you had just described.
You made a choice to stop testing one list of database names and start testing
a different list of database names.  Why?

> Are you saying that the test should

No, I wasn't saying any of those.  (Later, I may say one or more of those.)

---

From: Michael Paquier <[email-masked]>
Date: Mon, 16 May 2022 14:30:00 +0900

> a different list of database names.  Why?

Because the shape of the new names does not change the test coverage
("regression" prefix or the addition of the double quotes with
backslashes for all the database names), while keeping the code a bit
simpler.  If you think that the older names are more adapted, I have
no objections to use them, FWIW, which is something like the patch
attached would achieve.

This uses the same convention as vcregress.pl before 322becb, but not
the one of test.sh where "regression" was appended to the database
names.
--
Michael
diff --git a/src/bin/pg_upgrade/t/002_pg_upgrade.pl b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
index 8372a85e6e..33a75991d8 100644
--- a/src/bin/pg_upgrade/t/002_pg_upgrade.pl
+++ b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
@@ -13,18 +13,16 @@ use Test::More;
 # Generate a database with a name made of a range of ASCII characters.
 sub generate_db
 {
-	my ($node, $from_char, $to_char) = @_;
+	my ($node, $prefix, $from_char, $to_char, $suffix) = @_;
 
-	my $dbname = '';
+	my $dbname = $prefix;
 	for my $i ($from_char .. $to_char)
 	{
 		next if $i == 7 || $i == 10 || $i == 13;    # skip BEL, LF, and CR
 		$dbname = $dbname . sprintf('%c', $i);
 	}
 
-	# Exercise backslashes adjacent to double quotes, a Windows special
-	# case.
-	$dbname = '\\"\\' . $dbname . '\\\\"\\\\\\';
+	$dbname .= $suffix;
 	$node->command_ok([ 'createdb', $dbname ]);
 }
 
@@ -79,10 +77,12 @@ else
 {
 	# Default is to use pg_regress to set up the old instance.
 
-	# Create databases with names covering most ASCII bytes
-	generate_db($oldnode, 1,  45);
-	generate_db($oldnode, 46, 90);
-	generate_db($oldnode, 91, 127);
+	# Create databases with names covering most ASCII bytes.  The
+	# first name exercises backslashes adjacent to double quotes, a
+	# Windows special case.
+	generate_db($oldnode, "\\\"\\", 1,  45,  "\\\\\"\\\\\\");
+	generate_db($oldnode, '',       46, 90,  '');
+	generate_db($oldnode, '',       91, 127, '');
 
 	# Grab any regression options that may be passed down by caller.
 	my $extra_opts = $ENV{EXTRA_REGRESS_OPTS} || "";

---

From: Noah Misch <[email-masked]>
Date: Wed, 18 May 2022 01:03:15 -0700

> the one of test.sh where "regression" was appended to the database

I would have picked the test.sh names, both because test.sh was the senior
implementation and because doing so avoids warnings under
-DENFORCE_REGRESSION_TEST_NAME_RESTRICTIONS.  See the warnings here:
https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=longfin&dt=2022-05-18%2000%3A59%3A35&stg=pg_upgrade-check

More-notable line from that same log:
sh: /Users/buildfarm/bf-data/HEAD/pgsql.build/src/bin/pg_upgrade/../../../src/test/regress/pg_regress--port=5678: No such file or directory

Commit 7dd3ee5 adopted much of the 027_stream_regress.pl approach to running
pg_regress, but it didn't grab the "is($rc, 0, 'regression tests pass')"
needed to make defects like that report a failure.

> +	generate_db($oldnode, '',       91, 127, '');

Does this pass on Windows?  I'm 65% confident that released IPC::Run can't
handle this input due to https://github.com/toddr/IPC-Run/issues/142.  If it's
passing for you on Windows, then disregard.

---

From: Michael Paquier <[email-masked]>
Date: Wed, 18 May 2022 18:20:08 +0900

> https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=longfin&dt=2022-05-18%2000%3A59%3A35&stg=pg_upgrade-check

Yes, I saw that.  This did not bother me much as the TAP tests run in
isolation, but I am fine to stick to your option and silence these.

> sh: /Users/buildfarm/bf-data/HEAD/pgsql.build/src/bin/pg_upgrade/../../../src/test/regress/pg_regress--port=5678: No such file or directory

So you are using EXTRA_REGRESS_OPTS, then, and a space is missing from
the first argument of the command used to make that work properly.

> needed to make defects like that report a failure.

Okay, added this one.

> passing for you on Windows, then disregard.

Hmm.  The CI has been passing for me with this name pattern in place,
as of https://github.com/michaelpq/postgres/tree/upgrade_tap_fixes.

Attached is an updated patch to address your concerns.
--
Michael
diff --git a/src/bin/pg_upgrade/t/002_pg_upgrade.pl b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
index 8372a85e6e..86fe1b4d09 100644
--- a/src/bin/pg_upgrade/t/002_pg_upgrade.pl
+++ b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
@@ -13,18 +13,16 @@ use Test::More;
 # Generate a database with a name made of a range of ASCII characters.
 sub generate_db
 {
-	my ($node, $from_char, $to_char) = @_;
+	my ($node, $prefix, $from_char, $to_char, $suffix) = @_;
 
-	my $dbname = '';
+	my $dbname = $prefix;

@@ -79,10 +77,12 @@ else
 {
 
-	# Create databases with names covering most ASCII bytes
-	generate_db($oldnode, 1,  45);
-	generate_db($oldnode, 46, 90);
-	generate_db($oldnode, 91, 127);
+	# Create databases with names covering most ASCII bytes.  The
+	# first name exercises backslashes adjacent to double quotes, a
+	# Windows special case.
+	generate_db($oldnode, 'regression\\"\\', 1,  45,   '\\\\"\\\\\\');
+	generate_db($oldnode, 'regression',      46, 90,  '');
+	generate_db($oldnode, 'regression',      91, 127, '');
 
@@ -99,7 +99,7 @@ else
 
 	my $rc =
 	  system($ENV{PG_REGRESS}
-		  . "$extra_opts "
+		  . " $extra_opts "
 		  . "--dlpath=\"$dlpath\" "
 		  . "--bindir= "
 		  . "--host="
@@ -121,6 +121,7 @@ else
 			print "=== EOF ===\n";
 		}
 	}
+	is($rc, 0, 'regression tests pass');
 }
 
 # Before dumping, get rid of objects not existing or not supported in later

---

From: Noah Misch <[email-masked]>
Date: Fri, 20 May 2022 18:28:01 -0700

> Attached is an updated patch to address your concerns.

Looks successful.

---

From: Michael Paquier <[email-masked]>
Date: Sat, 21 May 2022 12:03:55 +0900

> Looks successful.

Thanks a lot for confirming.  I have applied that on HEAD, then.
--
Michael

---

From: Andres Freund <[email-masked]>
Date: Fri, 3 Jun 2022 12:53:18 -0700

Hi,

I just saw a pg_upgrade failure on my aio branch [1]. Not sure what caused it
yet. The reason I'm writing in this thread is that I looked at the
regress_log_* for the failure, and found it to be 14.95MiB (which crashed the
browser on my phone...).

https://api.cirrus-ci.com/v1/artifact/task/5167740683026432/log/src/bin/pg_upgrade/tmp_check/log/regress_log_002_pg_upgrade

That seems way beyond reasonable.

regress_log_002_pg_upgrade.log includes all of 002_pg_upgrade_old_node.log and
002_pg_upgrade_new_node.log. The old node's log includes all pg_dump queries.

Followed by many MB of diff due to

=== diff of /Users/admin/pgsql/src/bin/pg_upgrade/tmp_check/tmp_test_Q7GQ/dump1.sql and /Users/admin/pgsql/src/bin/pg_upgrade/tmp_check/tmp_test_Q7GQ/dump2.sql
=== stdout ===

Greetings,

Andres Freund

[1] https://cirrus-ci.com/task/5167740683026432

---

From: Michael Paquier <[email-masked]>
Date: Sat, 4 Jun 2022 12:35:45 +0900

On Fri, Jun 03, 2022 at 12:53:18PM -0700, Andres Freund wrote:
> [...]

TRAP: FailedAssertion("AmIoWorkerProcess()", File: "xlog.c", Line:
4860, PID: 35325)

> 002_pg_upgrade_new_node.log. The old node's log includes all pg_dump queries.

log_statement = all is the part biting here.  It does not seem like
we'd lose a lot of context even if this is made less verbose.

> === diff of /Users/admin/pgsql/src/bin/pg_upgrade/tmp_check/tmp_test_Q7GQ/dump1.sql and /Users/admin/pgsql/src/bin/pg_upgrade/tmp_check/tmp_test_Q7GQ/dump2.sql

Something like 80~85% of the bloat comes from the diffs in your case.
Well, it is always possible to limit that to an arbitrary amount of
characters (say 50k~100k?) to still give some context, and dump the
whole in a different file outside the log/ path (aka tmp_check/), so
that the buildfarm would show a minimum amount of information, while
local failures would still have an access to everything.

Do you have any preferences?
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Mon, 6 Jun 2022 13:58:40 +0900

> local failures would still have an access to everything.

After looking a bit around that.  Something like the attached, where
the characters are limited at 10k, would limit the output generated..
--
Michael
diff --git a/src/bin/pg_upgrade/t/002_pg_upgrade.pl b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
index 55c7354ba2..4581ddc915 100644
--- a/src/bin/pg_upgrade/t/002_pg_upgrade.pl
+++ b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
@@ -223,6 +223,9 @@ command_ok(
 	'run of pg_upgrade for new instance');
 $newnode->start;
 
+# Limit all contents to 10k characters.
+my $report_max_chars = 10000;
+
 # Check if there are any logs coming from pg_upgrade, that would only be
 # retained on failure.
 my $log_path = $newnode->data_dir . "/pg_upgrade_output.d/log";
@@ -231,7 +234,8 @@ if (-d $log_path)
 	foreach my $log (glob("$log_path/*"))
 	{
 		note "=== contents of $log ===\n";
-		print slurp_file($log);
+		my $contents = slurp_file($log);
+		print substr($contents, 0, $report_max_chars);
 		print "=== EOF ===\n";
 	}
 }
@@ -256,9 +260,9 @@ if ($compare_res != 0)
 	  run_command([ 'diff', "$tempdir/dump1.sql", "$tempdir/dump2.sql" ]);
 	print "=== diff of $tempdir/dump1.sql and $tempdir/dump2.sql\n";
 	print "=== stdout ===\n";
-	print $stdout;
+	print substr($stdout, 0, $report_max_chars);
 	print "=== stderr ===\n";
-	print $stderr;
+	print substr($stderr, 0, $report_max_chars);
 	print "=== EOF ===\n";
 }