Skip to content

Commit 1918059

Browse files
authored
Merge pull request #1594 from rabbiveesh/mojo-log-subtests
Mojo::Log tests now use subtests
2 parents 3a18dbc + 8e66df3 commit 1918059

File tree

1 file changed

+155
-138
lines changed

1 file changed

+155
-138
lines changed

t/mojo/log.t

+155-138
Original file line numberDiff line numberDiff line change
@@ -6,55 +6,59 @@ use Mojo::Log;
66
use Mojo::Util qw(decode);
77
use Time::HiRes qw(time);
88

9-
# Logging to file
109
my $dir = tempdir;
1110
my $path = $dir->child('test.log');
12-
my $log = Mojo::Log->new(level => 'error', path => $path);
13-
$log->error('Works');
14-
$log->fatal('I ♥ Mojolicious');
15-
$log->error(sub {'This too'});
16-
$log->debug('Does not work');
17-
$log->debug(sub { return 'And this', 'too' });
18-
undef $log;
19-
my $content = decode 'UTF-8', path($path)->slurp;
20-
like $content, qr/\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{5}] \[\d+\] \[error\] Works/, 'right error message';
21-
like $content, qr/\[.*\] \[\d+\] \[fatal\] I ♥ Mojolicious/, 'right fatal message';
22-
like $content, qr/\[.*\] \[\d+\] \[error\] This too/, 'right error message';
23-
unlike $content, qr/\[.*\] \[\d+\] \[debug\] Does not work/, 'no debug message';
24-
unlike $content, qr/\[.*\] \[\d+\] \[debug\] And this\ntoo\n/, 'right debug message';
2511

26-
# Logging to STDERR
27-
my $buffer = '';
28-
{
29-
open my $handle, '>', \$buffer;
30-
local *STDERR = $handle;
31-
my $log = Mojo::Log->new;
32-
$log->error('Just works');
12+
subtest 'Logging to file' => sub {
13+
my $log = Mojo::Log->new(level => 'error', path => $path);
14+
$log->error('Works');
3315
$log->fatal('I ♥ Mojolicious');
34-
$log->debug('Works too');
16+
$log->error(sub {'This too'});
17+
$log->debug('Does not work');
3518
$log->debug(sub { return 'And this', 'too' });
36-
}
37-
$content = decode 'UTF-8', $buffer;
38-
like $content, qr/\[.*\] \[error\] Just works\n/, 'right error message';
39-
like $content, qr/\[.*\] \[fatal\] I ♥ Mojolicious\n/, 'right fatal message';
40-
like $content, qr/\[.*\] \[debug\] Works too\n/, 'right debug message';
41-
like $content, qr/\[.*\] \[debug\] And this\ntoo\n/, 'right debug message';
19+
undef $log;
20+
my $content = decode 'UTF-8', path($path)->slurp;
21+
like $content, qr/\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{5}] \[\d+\] \[error\] Works/, 'right error message';
22+
like $content, qr/\[.*\] \[\d+\] \[fatal\] I ♥ Mojolicious/, 'right fatal message';
23+
like $content, qr/\[.*\] \[\d+\] \[error\] This too/, 'right error message';
24+
unlike $content, qr/\[.*\] \[\d+\] \[debug\] Does not work/, 'no debug message';
25+
unlike $content, qr/\[.*\] \[\d+\] \[debug\] And this\ntoo\n/, 'right debug message';
26+
};
4227

43-
# Formatting
44-
$log = Mojo::Log->new;
45-
like $log->format->(time, 'debug', 'Test 123'), qr/^\[.*\] \[debug\] Test 123\n$/, 'right format';
46-
like $log->format->(time, 'debug', qw(Test 1 2 3)), qr/^\[.*\] \[debug\] Test\n1\n2\n3\n$/, 'right format';
47-
like $log->format->(time, 'error', 'I ♥ Mojolicious'), qr/^\[.*\] \[error\] I ♥ Mojolicious\n$/, 'right format';
48-
like $log->format->(CORE::time, 'error', 'I ♥ Mojolicious'), qr/^\[.*\] \[error\] I ♥ Mojolicious\n$/, 'right format';
49-
$log->format(sub {
50-
my ($time, $level, @lines) = @_;
51-
return join ':', $level, $time, @lines;
52-
});
53-
like $log->format->(time, 'debug', qw(Test 1 2 3)), qr/^debug:[0-9.]+:Test:1:2:3$/, 'right format';
28+
subtest 'Logging to STDERR' => sub {
29+
my $log = Mojo::Log->new(level => 'error', path => $path);
30+
my $buffer = '';
31+
{
32+
open my $handle, '>', \$buffer;
33+
local *STDERR = $handle;
34+
my $log = Mojo::Log->new;
35+
$log->error('Just works');
36+
$log->fatal('I ♥ Mojolicious');
37+
$log->debug('Works too');
38+
$log->debug(sub { return 'And this', 'too' });
39+
}
40+
my $content = decode 'UTF-8', $buffer;
41+
like $content, qr/\[.*\] \[error\] Just works\n/, 'right error message';
42+
like $content, qr/\[.*\] \[fatal\] I ♥ Mojolicious\n/, 'right fatal message';
43+
like $content, qr/\[.*\] \[debug\] Works too\n/, 'right debug message';
44+
like $content, qr/\[.*\] \[debug\] And this\ntoo\n/, 'right debug message';
45+
};
5446

55-
# Short log messages (systemd)
56-
{
57-
$log = Mojo::Log->new;
47+
subtest 'Formatting' => sub {
48+
my $log = Mojo::Log->new;
49+
like $log->format->(time, 'debug', 'Test 123'), qr/^\[.*\] \[debug\] Test 123\n$/, 'right format';
50+
like $log->format->(time, 'debug', qw(Test 1 2 3)), qr/^\[.*\] \[debug\] Test\n1\n2\n3\n$/, 'right format';
51+
like $log->format->(time, 'error', 'I ♥ Mojolicious'), qr/^\[.*\] \[error\] I ♥ Mojolicious\n$/, 'right format';
52+
like $log->format->(CORE::time, 'error', 'I ♥ Mojolicious'), qr/^\[.*\] \[error\] I ♥ Mojolicious\n$/, 'right format';
53+
$log->format(sub {
54+
my ($time, $level, @lines) = @_;
55+
return join ':', $level, $time, @lines;
56+
});
57+
like $log->format->(time, 'debug', qw(Test 1 2 3)), qr/^debug:[0-9.]+:Test:1:2:3$/, 'right format';
58+
};
59+
60+
subtest 'Short log messages (systemd)' => sub {
61+
my $log = Mojo::Log->new;
5862
ok !$log->short, 'long messages';
5963
like $log->format->(time, 'debug', 'Test 123'), qr/^\[.*\] \[debug\] Test 123\n$/, 'right format';
6064
local $ENV{MOJO_LOG_SHORT} = 1;
@@ -69,109 +73,122 @@ like $log->format->(time, 'debug', qw(Test 1 2 3)), qr/^debug:[0-9.]+:Test:1:2:3
6973
like $log->format->(time, 'fatal', 'Test 123'), qr/^<2>\[\d+\] \[f\] Test 123\n$/, 'right format';
7074
like $log->format->(time, 'debug', 'Test', '1', '2', '3'), qr/^<7>\[\d+\] \[d\] Test\n<7>1\n<7>2\n<7>3\n$/,
7175
'right format';
72-
}
73-
74-
# Events
75-
$log = Mojo::Log->new;
76-
my $msgs = [];
77-
$log->unsubscribe('message')->on(
78-
message => sub {
79-
my ($log, $level, @lines) = @_;
80-
push @$msgs, $level, @lines;
81-
}
82-
);
83-
$log->debug('Test', 1, 2, 3);
84-
is_deeply $msgs, [qw(debug Test 1 2 3)], 'right message';
85-
$msgs = [];
86-
$log->info('Test', 1, 2, 3);
87-
is_deeply $msgs, [qw(info Test 1 2 3)], 'right message';
88-
$msgs = [];
89-
$log->warn('Test', 1, 2, 3);
90-
is_deeply $msgs, [qw(warn Test 1 2 3)], 'right message';
91-
$msgs = [];
92-
$log->error('Test', 1, 2, 3);
93-
is_deeply $msgs, [qw(error Test 1 2 3)], 'right message';
94-
$msgs = [];
95-
$log->fatal('Test', 1, 2, 3);
96-
is_deeply $msgs, [qw(fatal Test 1 2 3)], 'right message';
76+
};
9777

98-
# History
99-
$buffer = '';
100-
my $history;
101-
{
102-
open my $handle, '>', \$buffer;
103-
local *STDERR = $handle;
104-
my $log = Mojo::Log->new->max_history_size(2)->level('info');
105-
$log->error('First');
106-
$log->fatal('Second');
107-
$log->debug('Third');
108-
$log->info('Fourth', 'Fifth');
109-
$history = $log->history;
110-
}
111-
$content = decode 'UTF-8', $buffer;
112-
like $content, qr/\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{5}\] \[$$\] \[error\] First\n/, 'right error message';
113-
like $content, qr/\[.*\] \[info\] Fourth\nFifth\n/, 'right info message';
114-
unlike $content, qr/debug/, 'no debug message';
115-
like $history->[0][0], qr/^[0-9.]+$/, 'right epoch time';
116-
is $history->[0][1], 'fatal', 'right level';
117-
is $history->[0][2], 'Second', 'right message';
118-
is $history->[1][1], 'info', 'right level';
119-
is $history->[1][2], 'Fourth', 'right message';
120-
is $history->[1][3], 'Fifth', 'right message';
121-
ok !$history->[2], 'no more messages';
78+
subtest 'Events' => sub {
79+
my $log = Mojo::Log->new;
80+
my $msgs = [];
81+
$log->unsubscribe('message')->on(
82+
message => sub {
83+
my ($log, $level, @lines) = @_;
84+
push @$msgs, $level, @lines;
85+
}
86+
);
87+
$log->debug('Test', 1, 2, 3);
88+
is_deeply $msgs, [qw(debug Test 1 2 3)], 'right message';
89+
$msgs = [];
90+
$log->info('Test', 1, 2, 3);
91+
is_deeply $msgs, [qw(info Test 1 2 3)], 'right message';
92+
$msgs = [];
93+
$log->warn('Test', 1, 2, 3);
94+
is_deeply $msgs, [qw(warn Test 1 2 3)], 'right message';
95+
$msgs = [];
96+
$log->error('Test', 1, 2, 3);
97+
is_deeply $msgs, [qw(error Test 1 2 3)], 'right message';
98+
$msgs = [];
99+
$log->fatal('Test', 1, 2, 3);
100+
is_deeply $msgs, [qw(fatal Test 1 2 3)], 'right message';
101+
};
122102

123-
# "debug"
124-
is $log->level('debug')->level, 'debug', 'right level';
125-
ok $log->is_level('debug'), '"debug" log level is active';
126-
ok $log->is_level('info'), '"info" log level is active';
127-
ok $log->is_level('warn'), '"warn" log level is active';
128-
ok $log->is_level('error'), '"error" log level is active';
103+
subtest 'History' => sub {
104+
my $buffer = '';
105+
my $history;
106+
{
107+
open my $handle, '>', \$buffer;
108+
local *STDERR = $handle;
109+
my $log = Mojo::Log->new->max_history_size(2)->level('info');
110+
$log->error('First');
111+
$log->fatal('Second');
112+
$log->debug('Third');
113+
$log->info('Fourth', 'Fifth');
114+
$history = $log->history;
115+
}
116+
my $content = decode 'UTF-8', $buffer;
117+
like $content, qr/\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{5}\] \[$$\] \[error\] First\n/, 'right error message';
118+
like $content, qr/\[.*\] \[info\] Fourth\nFifth\n/, 'right info message';
119+
unlike $content, qr/debug/, 'no debug message';
120+
like $history->[0][0], qr/^[0-9.]+$/, 'right epoch time';
121+
is $history->[0][1], 'fatal', 'right level';
122+
is $history->[0][2], 'Second', 'right message';
123+
is $history->[1][1], 'info', 'right level';
124+
is $history->[1][2], 'Fourth', 'right message';
125+
is $history->[1][3], 'Fifth', 'right message';
126+
ok !$history->[2], 'no more messages';
127+
};
129128

130-
# "info"
131-
is $log->level('info')->level, 'info', 'right level';
132-
ok !$log->is_level('debug'), '"debug" log level is inactive';
133-
ok $log->is_level('info'), '"info" log level is active';
134-
ok $log->is_level('warn'), '"warn" log level is active';
135-
ok $log->is_level('error'), '"error" log level is active';
129+
subtest '"debug"' => sub {
130+
my $log = Mojo::Log->new;
131+
is $log->level('debug')->level, 'debug', 'right level';
132+
ok $log->is_level('debug'), '"debug" log level is active';
133+
ok $log->is_level('info'), '"info" log level is active';
134+
ok $log->is_level('warn'), '"warn" log level is active';
135+
ok $log->is_level('error'), '"error" log level is active';
136+
};
136137

137-
# "warn"
138-
is $log->level('warn')->level, 'warn', 'right level';
139-
ok !$log->is_level('debug'), '"debug" log level is inactive';
140-
ok !$log->is_level('info'), '"info" log level is inactive';
141-
ok $log->is_level('warn'), '"warn" log level is active';
142-
ok $log->is_level('error'), '"error" log level is active';
138+
subtest '"info"' => sub {
139+
my $log = Mojo::Log->new;
140+
is $log->level('info')->level, 'info', 'right level';
141+
ok !$log->is_level('debug'), '"debug" log level is inactive';
142+
ok $log->is_level('info'), '"info" log level is active';
143+
ok $log->is_level('warn'), '"warn" log level is active';
144+
ok $log->is_level('error'), '"error" log level is active';
145+
};
143146

144-
# "error"
145-
is $log->level('error')->level, 'error', 'right level';
146-
ok !$log->is_level('debug'), '"debug" log level is inactive';
147-
ok !$log->is_level('info'), '"info" log level is inactive';
148-
ok !$log->is_level('warn'), '"warn" log level is inactive';
149-
ok $log->is_level('error'), '"error" log level is active';
147+
subtest '"warn"' => sub {
148+
my $log = Mojo::Log->new;
149+
is $log->level('warn')->level, 'warn', 'right level';
150+
ok !$log->is_level('debug'), '"debug" log level is inactive';
151+
ok !$log->is_level('info'), '"info" log level is inactive';
152+
ok $log->is_level('warn'), '"warn" log level is active';
153+
ok $log->is_level('error'), '"error" log level is active';
154+
};
150155

151-
# "fatal"
152-
is $log->level('fatal')->level, 'fatal', 'right level';
153-
ok !$log->is_level('debug'), '"debug" log level is inactive';
154-
ok !$log->is_level('info'), '"info" log level is inactive';
155-
ok !$log->is_level('warn'), '"warn" log level is inactive';
156-
ok !$log->is_level('error'), '"error" log level is inactive';
156+
subtest '"error"' => sub {
157+
my $log = Mojo::Log->new;
158+
is $log->level('error')->level, 'error', 'right level';
159+
ok !$log->is_level('debug'), '"debug" log level is inactive';
160+
ok !$log->is_level('info'), '"info" log level is inactive';
161+
ok !$log->is_level('warn'), '"warn" log level is inactive';
162+
ok $log->is_level('error'), '"error" log level is active';
163+
};
157164

158-
# Context
159-
$log = Mojo::Log->new(level => 'warn');
160-
my $context = $log->context('[123]');
161-
is $context->level, 'warn';
162-
$buffer = '';
163-
{
164-
open my $handle, '>', \$buffer;
165-
local *STDERR = $handle;
165+
subtest '"fatal"' => sub {
166166
my $log = Mojo::Log->new;
167-
$context->debug('Fail');
168-
$context->error('Just works');
169-
$log->warn('No context');
170-
$context->fatal('Mojolicious rocks');
171-
}
172-
unlike $buffer, qr/\[debug\]/, 'no debug message';
173-
like $buffer, qr/\[.*\] \[error\] \[123\] Just works\n/, 'right error message';
174-
like $buffer, qr/\[.*\] \[warn\] No context\n/, 'right warn message';
175-
like $buffer, qr/\[.*\] \[fatal\] \[123\] Mojolicious rocks\n/, 'right fatal message';
167+
is $log->level('fatal')->level, 'fatal', 'right level';
168+
ok !$log->is_level('debug'), '"debug" log level is inactive';
169+
ok !$log->is_level('info'), '"info" log level is inactive';
170+
ok !$log->is_level('warn'), '"warn" log level is inactive';
171+
ok !$log->is_level('error'), '"error" log level is inactive';
172+
};
173+
174+
subtest 'Context' => sub {
175+
my $log = Mojo::Log->new(level => 'warn');
176+
my $context = $log->context('[123]');
177+
is $context->level, 'warn';
178+
my $buffer = '';
179+
{
180+
open my $handle, '>', \$buffer;
181+
local *STDERR = $handle;
182+
my $log = Mojo::Log->new;
183+
$context->debug('Fail');
184+
$context->error('Just works');
185+
$log->warn('No context');
186+
$context->fatal('Mojolicious rocks');
187+
}
188+
unlike $buffer, qr/\[debug\]/, 'no debug message';
189+
like $buffer, qr/\[.*\] \[error\] \[123\] Just works\n/, 'right error message';
190+
like $buffer, qr/\[.*\] \[warn\] No context\n/, 'right warn message';
191+
like $buffer, qr/\[.*\] \[fatal\] \[123\] Mojolicious rocks\n/, 'right fatal message';
192+
};
176193

177194
done_testing();

0 commit comments

Comments
 (0)