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
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
|
# Copyright (c) 2021-2022, PostgreSQL Global Development Group
use strict;
use warnings;
use PostgreSQL::Test::Cluster;
use PostgreSQL::Test::Utils;
use Test::More;
use Time::HiRes qw(usleep);
# Extract the file name of a $format from the contents of
# current_logfiles.
sub fetch_file_name
{
my $logfiles = shift;
my $format = shift;
my @lines = split(/\n/, $logfiles);
my $filename = undef;
foreach my $line (@lines)
{
if ($line =~ /$format (.*)$/gm)
{
$filename = $1;
}
}
return $filename;
}
# Check for a pattern in the logs associated to one format.
sub check_log_pattern
{
local $Test::Builder::Level = $Test::Builder::Level + 1;
my $format = shift;
my $logfiles = shift;
my $pattern = shift;
my $node = shift;
my $lfname = fetch_file_name($logfiles, $format);
my $max_attempts = 10 * $PostgreSQL::Test::Utils::timeout_default;
my $logcontents;
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
{
$logcontents = slurp_file($node->data_dir . '/' . $lfname);
last if $logcontents =~ m/$pattern/;
usleep(100_000);
}
like($logcontents, qr/$pattern/,
"found expected log file content for $format");
# While we're at it, test pg_current_logfile() function
is( $node->safe_psql('postgres', "SELECT pg_current_logfile('$format')"),
$lfname,
"pg_current_logfile() gives correct answer with $format");
return;
}
# Set up node with logging collector
my $node = PostgreSQL::Test::Cluster->new('primary');
$node->init();
$node->append_conf(
'postgresql.conf', qq(
logging_collector = on
log_destination = 'stderr, csvlog, jsonlog'
# 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 = 10 * $PostgreSQL::Test::Utils::timeout_default;
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
csvlog log/postgresql-.*csv
jsonlog log/postgresql-.*json$|,
'current_logfiles is sane');
check_log_pattern('stderr', $current_logfiles, 'division by zero', $node);
check_log_pattern('csvlog', $current_logfiles, 'division by zero', $node);
check_log_pattern('jsonlog', $current_logfiles, 'division by zero', $node);
# 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
csvlog log/postgresql-.*csv
jsonlog log/postgresql-.*json$|,
'new current_logfiles is sane');
# Verify that log output gets to this file, too
$node->psql('postgres', 'fee fi fo fum');
check_log_pattern('stderr', $new_current_logfiles, 'syntax error', $node);
check_log_pattern('csvlog', $new_current_logfiles, 'syntax error', $node);
check_log_pattern('jsonlog', $new_current_logfiles, 'syntax error', $node);
$node->stop();
done_testing();
|
