Feedback-ID: ic6394509:Fastmail
MIME-Version: 1.0
Date: Mon, 28 Oct 2024 14:38:12 +0200
From: "Joel Jacobson" <joel@compiler.org>
To: pgsql-hackers@lists.postgresql.org
Message-Id: <49f7e64a-b9be-4a90-a9fe-210a7740405e@app.fastmail.com>
Subject: Inconsistent output handling in 002_pg_upgrade.pl test logs
Content-Type: text/plain
Content-Transfer-Encoding: 7bit
Archived-At: 
 <https://www.postgresql.org/message-id/49f7e64a-b9be-4a90-a9fe-210a7740405e%40app.fastmail.com>
Precedence: bulk

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