8000 Improve logging of TAP tests. · postgres/postgres@fa4a4df · GitHub
[go: up one dir, main page]
Skip to content

Commit fa4a4df

Browse files
adunstanadunstan
committed
Improve logging of TAP tests.
Create a log file for each test run. Stdout and stderr of the test script, as well as any subprocesses run as part of the test, are redirected to the log file. This makes it a lot easier to debug test failures. Also print the test output (ok 12 - ... messages) to the log file, and the command line of any external programs executed with the system_or_bail and run_log functions. This makes it a lot easier to debug failing tests. Modify some of the pg_ctl and other command invocations to not use 'silent' or 'quiet' options, and don't redirect output to /dev/null, so that you get all the information in the log instead. In the passing, construct some command lines in a way that works if $tempdir contains quote-characters. I haven't systematically gone through all of them or tested that, so I don't know if this is enough to make that work. pg_rewind tests had a custom mechanism for creating a similar log file. Use the new generic facility instead. Michael Paquier and Heikki Linnakangas. This is a backpatch of Heikki's commit 1ea0620.
1 parent beebb25 commit fa4a4df

File tree

14 files changed

+143
-85
lines changed
  • test

    • 14 files changed

    +143
    -85
    lines changed

    ‎src/Makefile.global.in

    Lines changed: 1 addition & 0 deletions
    Original file line numberDiff line numberDiff line change
    @@ -338,6 +338,7 @@ cd $(srcdir) && TESTDIR='$(CURDIR)' PATH="$(bindir):$$PATH" PGPORT='6$(DEF_PGPOR
    338338
    endef
    339339

    340340
    define prove_check
    341+
    rm -rf $(srcdir)/tmp_check/log
    341342
    cd $(srcdir) && TESTDIR='$(CURDIR)' $(with_temp_install) PGPORT='6$(DEF_PGPORT)' top_builddir='$(CURDIR)/$(top_builddir)' $(PROVE) $(PG_PROVE_FLAGS) $(PROVE_FLAGS) t/*.pl
    342343
    endef
    343344

    ‎src/bin/pg_basebackup/t/010_pg_basebackup.pl

    Lines changed: 1 addition & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -30,7 +30,7 @@
    3030
    print HBA "host replication all 127.0.0.1/32 trust\n";
    3131
    print HBA "host replication all ::1/128 trust\n";
    3232
    close HBA;
    33-
    system_or_bail 'pg_ctl', '-s', '-D', "$tempdir/pgdata", 'reload';
    33+
    system_or_bail 'pg_ctl', '-D', "$tempdir/pgdata", 'reload';
    3434

    3535
    command_fails(
    3636
    [ 'pg_basebackup', '-D', "$tempdir/backup" ],

    ‎src/bin/pg_controldata/t/001_pg_controldata.pl

    Lines changed: 1 addition & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -11,6 +11,6 @@
    1111
    command_fails(['pg_controldata'], 'pg_controldata without arguments fails');
    1212
    command_fails([ 'pg_controldata', 'nonexistent' ],
    1313
    'pg_controldata with nonexistent directory fails');
    14-
    system_or_bail "initdb -D '$tempdir'/data -A trust >/dev/null";
    14+
    system_or_bail 'initdb', '-D', "$tempdir/data", '-A', 'trust';
    1515
    command_like([ 'pg_controldata', "$tempdir/data" ],
    1616
    qr/checkpoint/, 'pg_controldata produces output');

    ‎src/bin/pg_ctl/t/001_start_stop.pl

    Lines changed: 1 addition & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -36,4 +36,4 @@
    3636
    command_ok([ 'pg_ctl', 'restart', '-D', "$tempdir/data", '-w', '-m', 'fast' ],
    3737
    'pg_ctl restart with server running');
    3838

    39-
    system_or_bail 'pg_ctl', '-s', 'stop', '-D', "$tempdir/data", '-m', 'fast';
    39+
    system_or_bail 'pg_ctl', 'stop', '-D', "$tempdir/data", '-m', 'fast';

    ‎src/bin/pg_ctl/t/002_status.pl

    Lines changed: 2 additions & 2 deletions
    Original file line numberDiff line numberDiff line change
    @@ -18,9 +18,9 @@
    1818
    command_exit_is([ 'pg_ctl', 'status', '-D', "$tempdir/data" ],
    1919
    3, 'pg_ctl status with server not running');
    2020

    21-
    system_or_bail 'pg_ctl', '-s', '-l', "$tempdir/logfile", '-D',
    21+
    system_or_bail 'pg_ctl', '-l', "$tempdir/logfile", '-D',
    2222
    "$tempdir/data", '-w', 'start';
    2323
    command_exit_is([ 'pg_ctl', 'status', '-D', "$tempdir/data" ],
    2424
    0, 'pg_ctl status with server running');
    2525

    26-
    system_or_bail 'pg_ctl', '-s', 'stop', '-D', "$tempdir/data", '-m', 'fast';
    26+
    system_or_bail 'pg_ctl', 'stop', '-D', "$tempdir/data", '-m', 'fast';

    ‎src/bin/pg_rewind/.gitignore

    Lines changed: 0 additions & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -4,4 +4,3 @@
    44

    55
    # Generated by test suite
    66
    /tmp_check/
    7-
    /regress_log/

    ‎src/bin/pg_rewind/Makefile

    Lines changed: 1 addition & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -45,7 +45,7 @@ uninstall:
    4545

    4646
    clean distclean maintainer-clean:
    4747
    rm -f pg_rewind$(X) $(OBJS) xlogreader.c
    48-
    rm -rf tmp_check regress_log
    48+
    rm -rf tmp_check
    4949

    5050
    check:
    5151
    $(prove_check)

    ‎src/bin/pg_rewind/RewindTest.pm

    Lines changed: 32 additions & 53 deletions
    Original file line numberDiff line numberDiff line change
    @@ -79,7 +79,6 @@ mkdir "regress_log";
    7979
    my $port_master = $ENV{PGPORT};
    8080
    my $port_standby = $port_master + 1;
    8181

    82-
    my $log_path;
    8382
    my $tempdir_short;
    8483

    8584
    my $connstr_master = "port=$port_master";
    @@ -91,14 +90,16 @@ sub master_psql
    9190
    {
    9291
    my $cmd = shift;
    9392

    94-
    system_or_bail("psql -q --no-psqlrc -d $connstr_master -c \"$cmd\"");
    93+
    system_or_bail 'psql', '-q', '--no-psqlrc', '-d', $connstr_master,
    94+
    '-c', "$cmd";
    9595
    }
    9696

    9797
    sub standby_psql
    9898
    {
    9999
    my $cmd = shift;
    100100

    101-
    system_or_bail("psql -q --no-psqlrc -d $connstr_standby -c \"$cmd\"");
    101+
    system_or_bail 'psql', '-q', '--no-psqlrc', '-d', $connstr_standby,
    102+
    '-c', "$cmd";
    102103
    }
    103104

    104105
    # Run a query against the master, and check that the output matches what's
    @@ -171,16 +172,6 @@ sub append_to_file
    171172
    close $fh;
    172173
    }
    173174

    174-
    sub init_rewind_test
    175-
    {
    176-
    my $testname = shift;
    177-
    my $test_mode = shift;
    178-
    179-
    $log_path = "regress_log/pg_rewind_log_${testname}_${test_mode}";
    180-
    181-
    remove_tree $log_path;
    182-
    }
    183-
    184175
    sub setup_cluster
    185176
    {
    186177
    $tempdir_short = tempdir_short;
    @@ -209,9 +200,10 @@ max_connections = 10
    209200
    local replication all trust
    210201
    ));
    211202

    212-
    system_or_bail(
    213-
    "pg_ctl -w -D $test_master_datadir -o \"-k $tempdir_short --listen-addresses='' -p $port_master\" start >>$log_path 2>&1"
    214-
    );
    203+
    system_or_bail('pg_ctl' , '-w',
    204+
    '-D' , $test_master_datadir,
    205+
    "-o", "-k $tempdir_short --listen-addresses='' -p $port_master",
    206+
    'start');
    215207

    216208
    #### Now run the test-specific parts to initialize the master before setting
    217209
    # up standby
    @@ -225,8 +217,8 @@ sub create_standby
    225217
    remove_tree $test_standby_datadir;
    226218

    227219
    # Base backup is taken with xlog files included
    228-
    system_or_bail(
    229-
    "pg_basebackup -D $test_standby_datadir -p $port_master -x >>$log_path 2>&1");
    220+
    system_or_bail('pg_basebackup', '-D', $test_standby_datadir,
    221+
    '-p', $port_master, '-x');
    230222
    append_to_file(
    231223
    "$test_standby_datadir/recovery.conf", qq(
    232224
    primary_conninfo='$connstr_master application_name=rewind_standby'
    @@ -235,9 +227,9 @@ recovery_target_timeline='latest'
    235227
    ));
    236228

    237229
    # Start standby
    238-
    system_or_bail(
    239-
    "pg_ctl -w -D $test_standby_datadir -o \"-k $tempdir_short --listen-addresses='' -p $port_standby\" start >>$log_path 2>&1"
    240-
    );
    230+
    system_or_bail('pg_ctl', '-w', '-D', $test_standby_datadir,
    231+
    '-o', "-k $tempdir_short --listen-addresses='' -p $port_standby",
    232+
    'start');
    241233

    242234
    # Wait until the standby has caught up with the primary, by polling
    243235
    # pg_stat_replication.
    @@ -255,8 +247,7 @@ sub promote_standby
    255247
    # Now promote slave and insert some new data on master, this will put
    256248
    # the master out-of-sync with the standby. Wait until the standby is
    257249
    # out of recovery mode, and is ready to accept read-write connections.
    258-
    system_or_bail(
    259-
    "pg_ctl -w -D $test_standby_datadir promote >>$log_path 2>&1");
    250+
    system_or_bail('pg_ctl', '-w', '-D', $test_standby_datadir, 'promote');
    260251
    poll_query_until("SELECT NOT pg_is_in_recovery()", $connstr_standby)
    261252
    or die "Timed out while waiting for promotion of standby";
    262253

    @@ -274,8 +265,7 @@ sub run_pg_rewind
    274265
    my $test_mode = shift;
    275266

    276267
    # Stop the master and be ready to perform the rewind
    277-
    system_or_bail(
    278-
    "pg_ctl -w -D $test_master_datadir stop -m fast >>$log_path 2>&1");
    268+
    system_or_bail('pg_ctl', '-D', $test_master_datadir, 'stop', '-m', 'fast');
    279269

    280270
    # At this point, the rewind processing is ready to run.
    281271
    # We now have a very simple scenario with a few diverged WAL record.
    @@ -291,35 +281,24 @@ sub run_pg_rewind
    291281
    # Now run pg_rewind
    292282
    if ($test_mode eq "local")
    293283
    {
    294-
    295284
    # Do rewind using a local pgdata as source
    296285
    # Stop the master and be ready to perform the rewind
    297-
    system_or_bail(
    298-
    "pg_ctl -w -D $test_standby_datadir stop -m fast >>$log_path 2>&1"
    299-
    );
    300-
    my $result = run(
    301-
    [ 'pg_rewind',
    302-
    "--debug",
    303-
    "--source-pgdata=$test_standby_datadir",
    304-
    "--target-pgdata=$test_master_datadir" ],
    305-
    '>>',
    306-
    $log_path,
    307-
    '2>&1');
    308-
    ok($result, 'pg_rewind local');
    286+
    system_or_bail('pg_ctl', '-D', $test_standby_datadir, 'stop',
    287+
    '-m', 'fast');
    CDAC
    288+
    command_ok(['pg_rewind',
    289+
    "--debug",
    290+
    "--source-pgdata=$test_standby_datadir",
    291+
    "--target-pgdata=$test_master_datadir"],
    292+
    'pg_rewind local');
    309293
    }
    310294
    elsif ($test_mode eq "remote")
    311295
    {
    312-
    313296
    # Do rewind using a remote connection as source
    314-
    my $result = run(
    315-
    [ 'pg_rewind',
    316-
    "--source-server",
    317-
    "port=$port_standby dbname=postgres",
    318-
    "--target-pgdata=$test_master_datadir" ],
    319-
    '>>',
    320-
    $log_path,
    321-
    '2>&1');
    322-
    ok($result, 'pg_rewind remote');
    297+
    command_ok(['pg_rewind',
    298+
    "--source-server",
    299+
    "port=$port_standby dbname=postgres",
    300+
    "--target-pgdata=$test_master_datadir"],
    301+
    'pg_rewind remote');
    323302
    }
    324303
    else
    325304
    {
    @@ -342,9 +321,9 @@ recovery_target_timeline='latest'
    342321
    ));
    343322

    344323
    # Restart the master to check that rewind went correctly
    345-
    system_or_bail(
    346-
    "pg_ctl -w -D $test_master_datadir -o \"-k $tempdir_short --listen-addresses='' -p $port_master\" start >>$log_path 2>&1"
    347-
    );
    324+
    system_or_bail('pg_ctl', '-w', '-D', $test_master_datadir,
    325+
    '-o', "-k $tempdir_short --listen-addresses='' -p $port_master",
    326+
    'start');
    348327

    349328
    #### Now run the test-specific parts to check the result
    350329
    }
    @@ -355,12 +334,12 @@ sub clean_rewind_test
    355334
    if ($test_master_datadir)
    356335
    {
    357336
    system
    358-
    "pg_ctl -D $test_master_datadir -s -m immediate stop 2> /dev/null";
    337+
    'pg_ctl', '-D', $test_master_datadir, '-m', 'immediate', 'stop';
    359338
    }
    360339
    if ($test_standby_datadir)
    361340
    {
    362341
    system
    363-
    "pg_ctl -D $test_standby_datadir -s -m immediate stop 2> /dev/null";
    342+
    'pg_ctl', '-D', $test_standby_datadir, '-m', 'immediate', 'stop';
    364343
    }
    365344
    }
    366345

    ‎src/bin/pg_rewind/t/001_basic.pl

    Lines changed: 0 additions & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -9,7 +9,6 @@ sub run_test
    99
    {
    1010
    my $test_mode = shift;
    1111

    12-
    RewindTest::init_rewind_test('basic', $test_mode);
    1312
    RewindTest::setup_cluster();
    1413

    1514
    # Create a test table and insert a row in master.

    ‎src/bin/pg_rewind/t/002_databases.pl

    Lines changed: 0 additions & 1 deletion
    Original file line numberDiff line numberDiff line change
    @@ -9,7 +9,6 @@ sub run_test
    99
    {
    1010
    my $test_mode = shift;
    1111

    12-
    RewindTest::init_rewind_test('databases', $test_mode);
    1312
    RewindTest::setup_cluster();
    1413

    1514
    # Create a database in master.

    0 commit comments

    Comments
     (0)
    0