| line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
|
1
|
|
|
|
|
|
|
package PAGI::Middleware::AccessLog; |
|
2
|
|
|
|
|
|
|
|
|
3
|
1
|
|
|
1
|
|
206640
|
use strict; |
|
|
1
|
|
|
|
|
1
|
|
|
|
1
|
|
|
|
|
33
|
|
|
4
|
1
|
|
|
1
|
|
4
|
use warnings; |
|
|
1
|
|
|
|
|
4
|
|
|
|
1
|
|
|
|
|
48
|
|
|
5
|
1
|
|
|
1
|
|
318
|
use parent 'PAGI::Middleware'; |
|
|
1
|
|
|
|
|
317
|
|
|
|
1
|
|
|
|
|
6
|
|
|
6
|
1
|
|
|
1
|
|
54
|
use Future::AsyncAwait; |
|
|
1
|
|
|
|
|
1
|
|
|
|
1
|
|
|
|
|
3
|
|
|
7
|
1
|
|
|
1
|
|
45
|
use Time::HiRes qw(time); |
|
|
1
|
|
|
|
|
1
|
|
|
|
1
|
|
|
|
|
6
|
|
|
8
|
1
|
|
|
1
|
|
83
|
use POSIX qw(strftime); |
|
|
1
|
|
|
|
|
1
|
|
|
|
1
|
|
|
|
|
7
|
|
|
9
|
|
|
|
|
|
|
|
|
10
|
|
|
|
|
|
|
=head1 NAME |
|
11
|
|
|
|
|
|
|
|
|
12
|
|
|
|
|
|
|
PAGI::Middleware::AccessLog - Request logging middleware |
|
13
|
|
|
|
|
|
|
|
|
14
|
|
|
|
|
|
|
=head1 SYNOPSIS |
|
15
|
|
|
|
|
|
|
|
|
16
|
|
|
|
|
|
|
use PAGI::Middleware::Builder; |
|
17
|
|
|
|
|
|
|
|
|
18
|
|
|
|
|
|
|
my $app = builder { |
|
19
|
|
|
|
|
|
|
enable 'AccessLog', |
|
20
|
|
|
|
|
|
|
logger => sub { print STDERR @_ }, |
|
21
|
|
|
|
|
|
|
format => 'combined'; |
|
22
|
|
|
|
|
|
|
$my_app; |
|
23
|
|
|
|
|
|
|
}; |
|
24
|
|
|
|
|
|
|
|
|
25
|
|
|
|
|
|
|
=head1 DESCRIPTION |
|
26
|
|
|
|
|
|
|
|
|
27
|
|
|
|
|
|
|
PAGI::Middleware::AccessLog logs HTTP requests in configurable formats. |
|
28
|
|
|
|
|
|
|
It captures client IP, method, path, status, response size, and timing. |
|
29
|
|
|
|
|
|
|
|
|
30
|
|
|
|
|
|
|
=head1 CONFIGURATION |
|
31
|
|
|
|
|
|
|
|
|
32
|
|
|
|
|
|
|
=over 4 |
|
33
|
|
|
|
|
|
|
|
|
34
|
|
|
|
|
|
|
=item * logger (default: warns to STDERR) |
|
35
|
|
|
|
|
|
|
|
|
36
|
|
|
|
|
|
|
A coderef that receives the formatted log line. |
|
37
|
|
|
|
|
|
|
|
|
38
|
|
|
|
|
|
|
=item * format (default: 'combined') |
|
39
|
|
|
|
|
|
|
|
|
40
|
|
|
|
|
|
|
Log format: 'combined', 'common', or 'tiny'. |
|
41
|
|
|
|
|
|
|
|
|
42
|
|
|
|
|
|
|
=back |
|
43
|
|
|
|
|
|
|
|
|
44
|
|
|
|
|
|
|
=cut |
|
45
|
|
|
|
|
|
|
|
|
46
|
|
|
|
|
|
|
sub _init { |
|
47
|
4
|
|
|
4
|
|
8
|
my ($self, $config) = @_; |
|
48
|
|
|
|
|
|
|
|
|
49
|
4
|
|
33
|
0
|
|
12
|
$self->{logger} = $config->{logger} // sub { warn @_ }; |
|
|
0
|
|
|
|
|
0
|
|
|
50
|
4
|
|
100
|
|
|
15
|
$self->{format} = $config->{format} // 'combined'; |
|
51
|
|
|
|
|
|
|
} |
|
52
|
|
|
|
|
|
|
|
|
53
|
|
|
|
|
|
|
sub wrap { |
|
54
|
4
|
|
|
4
|
1
|
25
|
my ($self, $app) = @_; |
|
55
|
|
|
|
|
|
|
|
|
56
|
4
|
|
|
4
|
|
82
|
return async sub { |
|
57
|
4
|
|
|
|
|
5
|
my ($scope, $receive, $send) = @_; |
|
58
|
|
|
|
|
|
|
# Only log HTTP requests |
|
59
|
4
|
100
|
|
|
|
72
|
if ($scope->{type} ne 'http') { |
|
60
|
1
|
|
|
|
|
3
|
await $app->($scope, $receive, $send); |
|
61
|
1
|
|
|
|
|
66
|
return; |
|
62
|
|
|
|
|
|
|
} |
|
63
|
|
|
|
|
|
|
|
|
64
|
3
|
|
|
|
|
7
|
my $start_time = time(); |
|
65
|
3
|
|
|
|
|
4
|
my $status; |
|
66
|
3
|
|
|
|
|
3
|
my $response_size = 0; |
|
67
|
|
|
|
|
|
|
|
|
68
|
|
|
|
|
|
|
# Intercept send to capture response info |
|
69
|
6
|
|
|
|
|
259
|
my $wrapped_send = async sub { |
|
70
|
6
|
|
|
|
|
30
|
my ($event) = @_; |
|
71
|
6
|
100
|
|
|
|
49
|
if ($event->{type} eq 'http.response.start') { |
|
|
|
50
|
|
|
|
|
|
|
72
|
3
|
|
|
|
|
5
|
$status = $event->{status}; |
|
73
|
|
|
|
|
|
|
} elsif ($event->{type} eq 'http.response.body') { |
|
74
|
3
|
|
50
|
|
|
12
|
$response_size += length($event->{body} // ''); |
|
75
|
|
|
|
|
|
|
} |
|
76
|
6
|
|
|
|
|
10
|
await $send->($event); |
|
77
|
3
|
|
|
|
|
13
|
}; |
|
78
|
|
|
|
|
|
|
|
|
79
|
|
|
|
|
|
|
# Run the inner app |
|
80
|
|
|
|
|
|
|
eval { |
|
81
|
3
|
|
|
|
|
6
|
await $app->($scope, $receive, $wrapped_send); |
|
82
|
3
|
|
|
|
|
213
|
1; |
|
83
|
3
|
50
|
|
|
|
3
|
} or do { |
|
84
|
0
|
|
|
|
|
0
|
my $error = $@; |
|
85
|
0
|
|
0
|
|
|
0
|
$status //= 500; |
|
86
|
0
|
|
|
|
|
0
|
$self->_log_request($scope, $status, $response_size, $start_time); |
|
87
|
0
|
|
|
|
|
0
|
die $error; |
|
88
|
|
|
|
|
|
|
}; |
|
89
|
|
|
|
|
|
|
|
|
90
|
|
|
|
|
|
|
# Log the request |
|
91
|
3
|
|
|
|
|
10
|
$self->_log_request($scope, $status, $response_size, $start_time); |
|
92
|
4
|
|
|
|
|
18
|
}; |
|
93
|
|
|
|
|
|
|
} |
|
94
|
|
|
|
|
|
|
|
|
95
|
|
|
|
|
|
|
sub _log_request { |
|
96
|
3
|
|
|
3
|
|
7
|
my ($self, $scope, $status, $size, $start_time) = @_; |
|
97
|
|
|
|
|
|
|
|
|
98
|
3
|
|
|
|
|
6
|
my $duration = time() - $start_time; |
|
99
|
3
|
|
|
|
|
7
|
my $line = $self->_format_log($scope, $status, $size, $duration); |
|
100
|
3
|
|
|
|
|
10
|
$self->{logger}->($line); |
|
101
|
|
|
|
|
|
|
} |
|
102
|
|
|
|
|
|
|
|
|
103
|
|
|
|
|
|
|
sub _format_log { |
|
104
|
3
|
|
|
3
|
|
4
|
my ($self, $scope, $status, $size, $duration) = @_; |
|
105
|
|
|
|
|
|
|
|
|
106
|
3
|
|
|
|
|
7
|
my $format = $self->{format}; |
|
107
|
|
|
|
|
|
|
|
|
108
|
|
|
|
|
|
|
# Extract info from scope |
|
109
|
3
|
50
|
50
|
|
|
9
|
my $client_ip = exists $scope->{client} ? ($scope->{client}[0] // '-') : '-'; |
|
110
|
3
|
|
50
|
|
|
8
|
my $method = $scope->{method} // '-'; |
|
111
|
3
|
|
50
|
|
|
4
|
my $path = $scope->{path} // '/'; |
|
112
|
3
|
|
|
|
|
4
|
my $query = $scope->{query_string}; |
|
113
|
3
|
100
|
66
|
|
|
12
|
my $full_path = defined $query && $query ne '' ? "$path?$query" : $path; |
|
114
|
3
|
|
100
|
|
|
12
|
my $protocol = 'HTTP/' . ($scope->{http_version} // '1.1'); |
|
115
|
|
|
|
|
|
|
|
|
116
|
|
|
|
|
|
|
# Get headers |
|
117
|
3
|
|
|
|
|
4
|
my $referer = '-'; |
|
118
|
3
|
|
|
|
|
4
|
my $user_agent = '-'; |
|
119
|
3
|
|
50
|
|
|
3
|
for my $h (@{$scope->{headers} // []}) { |
|
|
3
|
|
|
|
|
9
|
|
|
120
|
2
|
|
|
|
|
4
|
my $name = lc($h->[0]); |
|
121
|
2
|
100
|
|
|
|
6
|
if ($name eq 'referer') { |
|
|
|
50
|
|
|
|
|
|
|
122
|
1
|
|
|
|
|
2
|
$referer = $h->[1]; |
|
123
|
|
|
|
|
|
|
} elsif ($name eq 'user-agent') { |
|
124
|
1
|
|
|
|
|
1
|
$user_agent = $h->[1]; |
|
125
|
|
|
|
|
|
|
} |
|
126
|
|
|
|
|
|
|
} |
|
127
|
|
|
|
|
|
|
|
|
128
|
|
|
|
|
|
|
# Format timestamp |
|
129
|
3
|
|
|
|
|
141
|
my $timestamp = strftime('%d/%b/%Y:%H:%M:%S %z', localtime()); |
|
130
|
|
|
|
|
|
|
|
|
131
|
3
|
|
50
|
|
|
9
|
$status //= 0; |
|
132
|
3
|
|
50
|
|
|
6
|
$size //= 0; |
|
133
|
|
|
|
|
|
|
|
|
134
|
3
|
100
|
|
|
|
10
|
if ($format eq 'combined') { |
|
|
|
100
|
|
|
|
|
|
|
135
|
|
|
|
|
|
|
# Combined Log Format (Apache/nginx style) |
|
136
|
1
|
|
|
|
|
14
|
return sprintf( |
|
137
|
|
|
|
|
|
|
qq{%s - - [%s] "%s %s %s" %d %d "%s" "%s" %.3fs\n}, |
|
138
|
|
|
|
|
|
|
$client_ip, $timestamp, $method, $full_path, $protocol, |
|
139
|
|
|
|
|
|
|
$status, $size, $referer, $user_agent, $duration |
|
140
|
|
|
|
|
|
|
); |
|
141
|
|
|
|
|
|
|
} elsif ($format eq 'common') { |
|
142
|
|
|
|
|
|
|
# Common Log Format |
|
143
|
1
|
|
|
|
|
7
|
return sprintf( |
|
144
|
|
|
|
|
|
|
qq{%s - - [%s] "%s %s %s" %d %d\n}, |
|
145
|
|
|
|
|
|
|
$client_ip, $timestamp, $method, $full_path, $protocol, |
|
146
|
|
|
|
|
|
|
$status, $size |
|
147
|
|
|
|
|
|
|
); |
|
148
|
|
|
|
|
|
|
} else { |
|
149
|
|
|
|
|
|
|
# Tiny format |
|
150
|
1
|
|
|
|
|
11
|
return sprintf( |
|
151
|
|
|
|
|
|
|
"%s %s %d %.3fs\n", |
|
152
|
|
|
|
|
|
|
$method, $full_path, $status, $duration |
|
153
|
|
|
|
|
|
|
); |
|
154
|
|
|
|
|
|
|
} |
|
155
|
|
|
|
|
|
|
} |
|
156
|
|
|
|
|
|
|
|
|
157
|
|
|
|
|
|
|
1; |
|
158
|
|
|
|
|
|
|
|
|
159
|
|
|
|
|
|
|
__END__ |