Inconsistent output handling in 002_pg_upgrade.pl test logs
Hi hackers,
I've noticed some inconsistency in 002_pg_upgrade.pl in how it handles output
during test failures. Currently, it uses note to print the header:
note "=== contents of $log ===\n";
but print for the log content and footer:
print slurp_file($log);
print "=== EOF ===\n";
This results in the header appearing in the TAP test output, while the actual
log content and the EOF-footer are directed to
./build/testrun/pg_upgrade/002_pg_upgrade/log/regress_log_002_pg_upgrade
This split means the log content is separate from its header and footer,
making it harder to interpret during test failures.
Example of current behavior:
In the console output:
# executing test in ./build/testrun/pg_upgrade/002_pg_upgrade group pg_upgrade test 002_pg_upgrade
...omitted...
not ok 15 - pg_upgrade_output.d/ removed after pg_upgrade success
# === contents of ./build/testrun/pg_upgrade/002_pg_upgrade/data/t_002_pg_upgrade_new_node_data/pgdata/pg_upgrade_output.d/20241028T140145.267/log/pg_upgrade_dump_5.log ===
# === contents of ./build/testrun/pg_upgrade/002_pg_upgrade/data/t_002_pg_upgrade_new_node_data/pgdata/pg_upgrade_output.d/20241028T140145.267/log/pg_upgrade_dump_1.log ===
But the actual log content and footers are only visible in regress_log_002_pg_upgrade.
Suggested solutions:
Option 1: Keep output together using note
If we want all messages (header, content, and footer) to be in the TAP output
for easier readability, we could replace print with note for both the content
and footer:
foreach my $log (@log_files)
{
note "=== contents of $log ===\n";
note slurp_file($log);
note "=== EOF ===\n";
}
Option 2: Adjust header message for separate logs
If we intentionally want the log content to remain in the separate regression
log for brevity, we could clarify the header message to indicate where
the actual content can be found, and ensure the "=== contents of $log ===\n"
message goes into the same file as the content:
foreach my $log (@log_files)
{
note "=== contents of $log logged to $path_to_regress_log_002_pg_upgrade ===\n";
print "=== contents of $log ===\n";
print slurp_file($log);
print "=== EOF ===\n";
}
Thoughts on these options?
/Joel
On 28 Oct 2024, at 13:38, Joel Jacobson <joel@compiler.org> wrote:
Hi hackers,
I've noticed some inconsistency in 002_pg_upgrade.pl in how it handles output
during test failures. Currently, it uses note to print the header:note "=== contents of $log ===\n";
but print for the log content and footer:
print slurp_file($log);
print "=== EOF ===\n";
Ugh, nice catch.
Option 1: Keep output together using note
Option 2: Adjust header message for separate logs
Thoughts on these options?
I would prefer to output this to the log only and not the TAP output, to avoid
the risk of not seeing the test output for all the log output on the screen.
--
Daniel Gustafsson
On Mon, Oct 28, 2024, at 13:44, Daniel Gustafsson wrote:
On 28 Oct 2024, at 13:38, Joel Jacobson <joel@compiler.org> wrote:
Hi hackers,
I've noticed some inconsistency in 002_pg_upgrade.pl in how it handles output
during test failures. Currently, it uses note to print the header:note "=== contents of $log ===\n";
but print for the log content and footer:
print slurp_file($log);
print "=== EOF ===\n";Ugh, nice catch.
Option 1: Keep output together using note
Option 2: Adjust header message for separate logs
Thoughts on these options?
I would prefer to output this to the log only and not the TAP output, to avoid
the risk of not seeing the test output for all the log output on the screen.
I also think that's best, and in line with what we do in other parts of the same script.
Patch attached.
/Joel
Attachments:
0001-Fix-inconsistent-output-handling-in-002_pg_upgrade.p.patchapplication/octet-stream; name="=?UTF-8?Q?0001-Fix-inconsistent-output-handling-in-002=5Fpg=5Fupgrade.p.?= =?UTF-8?Q?patch?="Download
From 45f44e32e7ba46923c4df167a448ba20fccece26 Mon Sep 17 00:00:00 2001
From: Joel Jacobson <joel@compiler.org>
Date: Mon, 28 Oct 2024 16:38:21 +0100
Subject: [PATCH] Fix inconsistent output handling in 002_pg_upgrade.pl test
logs.
Ensure that both log headers and contents are appended to the dedicated test
logfile instead of splitting between TAP output and the logfile.
When pg_upgrade logs are found, notify the user of the logfile location.
---
src/bin/pg_upgrade/t/002_pg_upgrade.pl | 7 ++++++-
1 file changed, 6 insertions(+), 1 deletion(-)
diff --git a/src/bin/pg_upgrade/t/002_pg_upgrade.pl b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
index 17af2ce61e..78bd776f5b 100644
--- a/src/bin/pg_upgrade/t/002_pg_upgrade.pl
+++ b/src/bin/pg_upgrade/t/002_pg_upgrade.pl
@@ -475,9 +475,14 @@ if (-d $log_path)
if $File::Find::name =~ m/.*\.log/;
},
$newnode->data_dir . "/pg_upgrade_output.d");
+
+ my $test_logfile = $PostgreSQL::Test::Utils::test_logfile;
+
+ note "=== pg_upgrade logs found - appending to $test_logfile ===\n";
foreach my $log (@log_files)
{
- note "=== contents of $log ===\n";
+ note "=== appending $log ===\n";
+ print "=== contents of $log ===\n";
print slurp_file($log);
print "=== EOF ===\n";
}
--
2.45.1
On Mon, Oct 28, 2024 at 04:44:48PM +0100, Joel Jacobson wrote:
On Mon, Oct 28, 2024, at 13:44, Daniel Gustafsson wrote:
On 28 Oct 2024, at 13:38, Joel Jacobson <joel@compiler.org> wrote:
Option 1: Keep output together using noteOption 2: Adjust header message for separate logs
Thoughts on these options?
I would prefer to output this to the log only and not the TAP output, to avoid
the risk of not seeing the test output for all the log output on the screen.
My apologies for the late reply, this comes from 73db8f4d17ed so
this confision is on me.
The contents of the logs could be very long depending on the dump
used for the upgrade test, so agreed to print() the contents of the
logs as in option 2, without using note() everywhere.
I also think that's best, and in line with what we do in other parts
of the same script.
+ my $test_logfile = $PostgreSQL::Test::Utils::test_logfile;
+
+ note "=== pg_upgrade logs found - appending to $test_logfile ===\n";
foreach my $log (@log_files)
{
- note "=== contents of $log ===\n";
+ note "=== appending $log ===\n";
+ print "=== contents of $log ===\n";
print slurp_file($log);
print "=== EOF ===\n";
}That's a clear improvement, thanks for the report. I'll see about a
backpatch, as well.
--
Michael