1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
|
use strict;
use warnings;
use PostgresNode;
use TestLib;
use Test::More tests => 5;
use Time::HiRes qw(usleep);
# Set up node with logging collector
my $node = get_new_node('primary');
$node->init();
$node->append_conf(
'postgresql.conf', qq(
logging_collector = on
# these ensure stability of test results:
log_rotation_age = 0
lc_messages = 'C'
));
$node->start();
# Verify that log output gets to the file
$node->psql('postgres', 'SELECT 1/0');
# might need to retry if logging collector process is slow...
my $max_attempts = 180 * 10;
my $current_logfiles;
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
{
eval {
$current_logfiles = slurp_file($node->data_dir . '/current_logfiles');
};
last unless $@;
usleep(100_000);
}
die $@ if $@;
note "current_logfiles = $current_logfiles";
like(
$current_logfiles,
qr|^stderr log/postgresql-.*log$|,
'current_logfiles is sane');
my $lfname = $current_logfiles;
$lfname =~ s/^stderr //;
chomp $lfname;
my $first_logfile;
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
{
$first_logfile = slurp_file($node->data_dir . '/' . $lfname);
last if $first_logfile =~ m/division by zero/;
usleep(100_000);
}
like($first_logfile, qr/division by zero/, 'found expected log file content');
# While we're at it, test pg_current_logfile() function
is($node->safe_psql('postgres', "SELECT pg_current_logfile('stderr')"),
$lfname, 'pg_current_logfile() gives correct answer');
# Sleep 2 seconds and ask for log rotation; this should result in
# output into a different log file name.
sleep(2);
$node->logrotate();
# pg_ctl logrotate doesn't wait for rotation request to be completed.
# Allow a bit of time for it to happen.
my $new_current_logfiles;
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
{
$new_current_logfiles = slurp_file($node->data_dir . '/current_logfiles');
last if $new_current_logfiles ne $current_logfiles;
usleep(100_000);
}
note "now current_logfiles = $new_current_logfiles";
like(
$new_current_logfiles,
qr|^stderr log/postgresql-.*log$|,
'new current_logfiles is sane');
$lfname = $new_current_logfiles;
$lfname =~ s/^stderr //;
chomp $lfname;
# Verify that log output gets to this file, too
$node->psql('postgres', 'fee fi fo fum');
my $second_logfile;
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
{
$second_logfile = slurp_file($node->data_dir . '/' . $lfname);
last if $second_logfile =~ m/syntax error/;
usleep(100_000);
}
like(
$second_logfile,
qr/syntax error/,
'found expected log file content in new log file');
$node->stop();
|
