line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
1
|
|
|
|
|
|
|
package DBI::Log; |
2
|
|
|
|
|
|
|
|
3
|
1
|
|
|
1
|
|
93681
|
use 5.006; |
|
1
|
|
|
|
|
4
|
|
4
|
1
|
|
|
1
|
|
4
|
no strict; |
|
1
|
|
|
|
|
2
|
|
|
1
|
|
|
|
|
71
|
|
5
|
1
|
|
|
1
|
|
6
|
no warnings; |
|
1
|
|
|
|
|
2
|
|
|
1
|
|
|
|
|
37
|
|
6
|
1
|
|
|
1
|
|
5
|
use DBI; |
|
1
|
|
|
|
|
1
|
|
|
1
|
|
|
|
|
30
|
|
7
|
1
|
|
|
1
|
|
510
|
use Time::HiRes; |
|
1
|
|
|
|
|
1661
|
|
|
1
|
|
|
|
|
5
|
|
8
|
|
|
|
|
|
|
|
9
|
|
|
|
|
|
|
our $VERSION = "0.11"; |
10
|
|
|
|
|
|
|
our %opts = ( |
11
|
|
|
|
|
|
|
file => $file, |
12
|
|
|
|
|
|
|
trace => 0, |
13
|
|
|
|
|
|
|
timing => 0, |
14
|
|
|
|
|
|
|
replace_placeholders => 1, |
15
|
|
|
|
|
|
|
fh => undef, |
16
|
|
|
|
|
|
|
exclude => undef, |
17
|
|
|
|
|
|
|
format => "sql", |
18
|
|
|
|
|
|
|
); |
19
|
|
|
|
|
|
|
|
20
|
|
|
|
|
|
|
my $orig_execute = \&DBI::st::execute; |
21
|
|
|
|
|
|
|
*DBI::st::execute = sub { |
22
|
4
|
|
|
4
|
|
14630
|
my ($sth, @args) = @_; |
23
|
4
|
|
|
|
|
55
|
my $log = pre_query("execute", $sth->{Database}, $sth, $sth->{Statement}, \@args); |
24
|
4
|
|
|
|
|
28587
|
my $retval = $orig_execute->($sth, @args); |
25
|
4
|
|
|
|
|
62
|
post_query($log); |
26
|
4
|
|
|
|
|
23
|
return $retval; |
27
|
|
|
|
|
|
|
}; |
28
|
|
|
|
|
|
|
|
29
|
|
|
|
|
|
|
my $orig_selectall_arrayref = \&DBI::db::selectall_arrayref; |
30
|
|
|
|
|
|
|
*DBI::db::selectall_arrayref = sub { |
31
|
1
|
|
|
1
|
|
5260
|
my ($dbh, $query, $yup, @args) = @_; |
32
|
1
|
|
|
|
|
23
|
my $log = pre_query("selectall_arrayref", $dbh, undef, $query, \@args); |
33
|
1
|
|
|
|
|
59
|
my $retval = $orig_selectall_arrayref->($dbh, $query, $yup, @args); |
34
|
1
|
|
|
|
|
203
|
post_query($log); |
35
|
1
|
|
|
|
|
10
|
return $retval; |
36
|
|
|
|
|
|
|
}; |
37
|
|
|
|
|
|
|
|
38
|
|
|
|
|
|
|
my $orig_selectcol_arrayref = \&DBI::db::selectcol_arrayref; |
39
|
|
|
|
|
|
|
*DBI::db::selectcol_arrayref = sub { |
40
|
1
|
|
|
1
|
|
5652
|
my ($dbh, $query, $yup, @args) = @_; |
41
|
1
|
|
|
|
|
29
|
my $log = pre_query("selectcol_arrayref", $dbh, undef, $query, \@args); |
42
|
1
|
|
|
|
|
71
|
my $retval = $orig_selectcol_arrayref->($dbh, $query, $yup, @args); |
43
|
1
|
|
|
|
|
117
|
post_query($log); |
44
|
1
|
|
|
|
|
7
|
return $retval; |
45
|
|
|
|
|
|
|
}; |
46
|
|
|
|
|
|
|
|
47
|
|
|
|
|
|
|
my $orig_selectall_hashref = \&DBI::db::selectall_hashref; |
48
|
|
|
|
|
|
|
*DBI::db::selectall_hashref = sub { |
49
|
0
|
|
|
0
|
|
0
|
my ($dbh, $query, $yup, @args) = @_; |
50
|
0
|
|
|
|
|
0
|
my $log = pre_query("selectall_hashref", $dbh, undef, $query, \@args); |
51
|
0
|
|
|
|
|
0
|
my $retval = $orig_selectall_hashref->($dbh, $query, $yup, @args); |
52
|
0
|
|
|
|
|
0
|
post_query($log); |
53
|
0
|
|
|
|
|
0
|
return $retval; |
54
|
|
|
|
|
|
|
}; |
55
|
|
|
|
|
|
|
|
56
|
|
|
|
|
|
|
my $orig_selectrow_arrayref = \&DBI::db::selectrow_arrayref; |
57
|
|
|
|
|
|
|
*DBI::db::selectrow_arrayref = sub { |
58
|
0
|
|
|
0
|
|
0
|
my ($dbh, $query, $yup, @args) = @_; |
59
|
0
|
|
|
|
|
0
|
my $log = pre_query("selectrow_arrayref", $dbh, $sth, $query, \@args); |
60
|
0
|
|
|
|
|
0
|
my $retval = $orig_selectrow_arrayref->($dbh, $query, $yup, @args); |
61
|
0
|
|
|
|
|
0
|
post_query($log); |
62
|
0
|
|
|
|
|
0
|
return $retval; |
63
|
|
|
|
|
|
|
}; |
64
|
|
|
|
|
|
|
|
65
|
|
|
|
|
|
|
my $orig_selectrow_array = \&DBI::db::selectrow_array; |
66
|
|
|
|
|
|
|
*DBI::db::selectrow_array = sub { |
67
|
0
|
|
|
0
|
|
0
|
my ($dbh, $query, $yup, @args) = @_; |
68
|
0
|
|
|
|
|
0
|
my $log = pre_query("selectrow_array", $dbh, undef, $query, \@args); |
69
|
0
|
|
|
|
|
0
|
my $retval = $orig_selectrow_array->($dbh, $query, $yup, @args); |
70
|
0
|
|
|
|
|
0
|
post_query($log); |
71
|
0
|
|
|
|
|
0
|
return $retval; |
72
|
|
|
|
|
|
|
}; |
73
|
|
|
|
|
|
|
|
74
|
|
|
|
|
|
|
my $orig_selectrow_hashref = \&DBI::db::selectrow_hashref; |
75
|
|
|
|
|
|
|
*DBI::db::selectrow_hashref = sub { |
76
|
0
|
|
|
0
|
|
0
|
my ($dbh, $query, $yup, @args) = @_; |
77
|
0
|
|
|
|
|
0
|
my $log = pre_query("selectrow_hashref", $dbh, undef, $query, \@args); |
78
|
0
|
|
|
|
|
0
|
my $retval = $orig_selectrow_hashref->($dbh, $query, $yup, @args); |
79
|
0
|
|
|
|
|
0
|
post_query($log); |
80
|
0
|
|
|
|
|
0
|
return $retval; |
81
|
|
|
|
|
|
|
}; |
82
|
|
|
|
|
|
|
|
83
|
|
|
|
|
|
|
my $orig_do = \&DBI::db::do; |
84
|
|
|
|
|
|
|
*DBI::db::do = sub { |
85
|
3
|
|
|
3
|
|
9411
|
my ($dbh, $query, $yup, @args) = @_; |
86
|
3
|
|
|
|
|
40
|
my $log = pre_query("do", $dbh, undef, $query, \@args); |
87
|
3
|
|
|
|
|
57
|
my $retval = $orig_do->($dbh, $query, $yup, @args); |
88
|
2
|
|
|
|
|
10344
|
post_query($log); |
89
|
2
|
|
|
|
|
18
|
return $retval; |
90
|
|
|
|
|
|
|
}; |
91
|
|
|
|
|
|
|
|
92
|
|
|
|
|
|
|
|
93
|
|
|
|
|
|
|
sub import { |
94
|
2
|
|
|
2
|
|
3693
|
my ($package, %args) = @_; |
95
|
2
|
|
|
|
|
16
|
for my $key (keys %args) { |
96
|
3
|
|
|
|
|
25
|
$opts{$key} = $args{$key}; |
97
|
|
|
|
|
|
|
} |
98
|
2
|
50
|
|
|
|
8
|
if (!$opts{file}) { |
99
|
0
|
|
|
|
|
0
|
$opts{fh} = \*STDERR; |
100
|
|
|
|
|
|
|
} |
101
|
|
|
|
|
|
|
else { |
102
|
2
|
|
|
|
|
4
|
my $file2 = $opts{file}; |
103
|
2
|
50
|
|
|
|
18
|
if ($file2 =~ m{^~/}) { |
104
|
0
|
|
0
|
|
|
0
|
my $home = $ENV{HOME} || (getpwuid($<))[7]; |
105
|
0
|
|
|
|
|
0
|
$file2 =~ s{^~/}{$home/}; |
106
|
|
|
|
|
|
|
} |
107
|
2
|
50
|
|
|
|
2027
|
open $opts{fh}, ">>", $file2 or die "Can't open $opts{file}: $!\n"; |
108
|
|
|
|
|
|
|
} |
109
|
|
|
|
|
|
|
} |
110
|
|
|
|
|
|
|
|
111
|
|
|
|
|
|
|
sub pre_query { |
112
|
9
|
|
|
9
|
0
|
109
|
my ($name, $dbh, $sth, $query, $args) = @_; |
113
|
9
|
|
|
|
|
23
|
my $log = {}; |
114
|
9
|
|
|
|
|
17
|
my $mcount = 0; |
115
|
|
|
|
|
|
|
|
116
|
|
|
|
|
|
|
# Some DBI functions are composed of other DBI functions, so make sure we |
117
|
|
|
|
|
|
|
# are only logging the top level one. For example $dbh->do() will call |
118
|
|
|
|
|
|
|
# $dbh->execute() internally, so we need to make sure a DBI::Log function |
119
|
|
|
|
|
|
|
# logs the $dbh->do() and not the internal $dbh->execute(). If multiple |
120
|
|
|
|
|
|
|
# functions were called, we return and flag this log entry to be skipped in |
121
|
|
|
|
|
|
|
# the post_query() part. |
122
|
9
|
|
|
|
|
142
|
for (my $i = 0; my @caller = caller($i); $i++) { |
123
|
22
|
|
|
|
|
73
|
my ($package, $file, $line, $sub) = @caller; |
124
|
22
|
100
|
|
|
|
87
|
if ($package eq "DBI::Log") { |
125
|
12
|
|
|
|
|
14
|
$mcount++; |
126
|
12
|
100
|
|
|
|
122
|
if ($mcount > 1) { |
127
|
3
|
|
|
|
|
19
|
$log->{skip} = 1; |
128
|
3
|
|
|
|
|
25
|
return $log; |
129
|
|
|
|
|
|
|
} |
130
|
|
|
|
|
|
|
} |
131
|
|
|
|
|
|
|
} |
132
|
6
|
|
|
|
|
8
|
my @callers; |
133
|
6
|
|
|
|
|
35
|
for (my $i = 0; my @caller = caller($i); $i++) { |
134
|
13
|
|
|
|
|
87
|
push @callers, \@caller; |
135
|
|
|
|
|
|
|
} |
136
|
|
|
|
|
|
|
|
137
|
|
|
|
|
|
|
# Order the call stack based on the highest level calls first, then the |
138
|
|
|
|
|
|
|
# lower level calls. Once you reach a package that is excluded, do not show |
139
|
|
|
|
|
|
|
# any more lines in the stack trace. By default, it will exclude anything |
140
|
|
|
|
|
|
|
# past the DBI::Log package, but if user provides an exclude option, it will |
141
|
|
|
|
|
|
|
# stop there. |
142
|
6
|
|
|
|
|
10
|
my @filtered_callers; |
143
|
6
|
|
|
|
|
14
|
CALLER: for my $caller (reverse @callers) { |
144
|
13
|
|
|
|
|
25
|
my ($package, $file, $line, $long_sub) = @$caller; |
145
|
13
|
100
|
|
|
|
27
|
if ($package eq "DBI::Log") { |
146
|
6
|
|
|
|
|
16
|
last CALLER; |
147
|
|
|
|
|
|
|
} |
148
|
7
|
50
|
|
|
|
19
|
if ($opts{exclude}) { |
149
|
0
|
|
|
|
|
0
|
for my $item (@{$opts{exclude}}) { |
|
0
|
|
|
|
|
0
|
|
150
|
0
|
0
|
|
|
|
0
|
if ($package =~ /^$item(::|$)/) { |
151
|
0
|
|
|
|
|
0
|
last CALLER; |
152
|
|
|
|
|
|
|
} |
153
|
|
|
|
|
|
|
} |
154
|
|
|
|
|
|
|
} |
155
|
7
|
|
|
|
|
34
|
push @filtered_callers, $caller; |
156
|
|
|
|
|
|
|
|
157
|
|
|
|
|
|
|
} |
158
|
6
|
50
|
|
|
|
16
|
if (!$opts{trace}) { |
159
|
6
|
|
|
|
|
27
|
@filtered_callers = ($filtered_callers[-1]); |
160
|
|
|
|
|
|
|
} |
161
|
|
|
|
|
|
|
|
162
|
6
|
|
|
|
|
7
|
my @stack; |
163
|
6
|
|
|
|
|
23
|
for my $caller (@filtered_callers) { |
164
|
6
|
|
|
|
|
13
|
my ($package, $file, $line, $long_sub) = @$caller; |
165
|
6
|
|
|
|
|
8
|
my $sub = $long_sub; |
166
|
6
|
|
|
|
|
87
|
$sub =~ s/.*:://; |
167
|
6
|
50
|
|
|
|
55
|
$sub = $name if $long_sub =~ /^DBI::Log::__ANON__/; |
168
|
6
|
|
|
|
|
104
|
push @stack, { |
169
|
|
|
|
|
|
|
sub => $sub, |
170
|
|
|
|
|
|
|
file => $file, |
171
|
|
|
|
|
|
|
line => $line, |
172
|
|
|
|
|
|
|
}; |
173
|
|
|
|
|
|
|
} |
174
|
|
|
|
|
|
|
|
175
|
6
|
100
|
66
|
|
|
32
|
if (ref($query) && ref($query) eq "DBI::st") { |
176
|
1
|
|
|
|
|
6
|
$sth = $query; |
177
|
1
|
|
|
|
|
26
|
$query = $query->{Statement}; |
178
|
|
|
|
|
|
|
} |
179
|
|
|
|
|
|
|
|
180
|
6
|
50
|
33
|
|
|
53
|
if ($dbh && $opts{replace_placeholders}) { |
181
|
|
|
|
|
|
|
# When you use $sth->bind_param(1, "value") the params can be found in |
182
|
|
|
|
|
|
|
# $sth->{ParamValues} and they override arguments sent in to |
183
|
|
|
|
|
|
|
# $sth->execute() |
184
|
|
|
|
|
|
|
|
185
|
6
|
|
|
|
|
15
|
my @args_copy = @$args; |
186
|
6
|
|
|
|
|
9
|
my %values; |
187
|
6
|
50
|
66
|
|
|
40
|
if ($sth && $sth->{ParamValues}) { |
188
|
2
|
|
|
|
|
4
|
%values = %{$sth->{ParamValues}}; |
|
2
|
|
|
|
|
18
|
|
189
|
|
|
|
|
|
|
} |
190
|
6
|
|
|
|
|
24
|
for my $key (keys %values) { |
191
|
0
|
0
|
0
|
|
|
0
|
if (defined $key && $key =~ /^\d+$/) { |
192
|
0
|
|
|
|
|
0
|
$args_copy[$key - 1] = $values{$key}; |
193
|
|
|
|
|
|
|
} |
194
|
|
|
|
|
|
|
} |
195
|
|
|
|
|
|
|
|
196
|
6
|
|
|
|
|
31
|
for my $i (0 .. @args_copy - 1) { |
197
|
4
|
|
|
|
|
20
|
my $value = $args_copy[$i]; |
198
|
4
|
|
|
|
|
88
|
$value = $dbh->quote($value); |
199
|
4
|
|
|
|
|
75
|
$query =~ s{\?}{$value}e; |
|
4
|
|
|
|
|
19
|
|
200
|
|
|
|
|
|
|
} |
201
|
|
|
|
|
|
|
} |
202
|
|
|
|
|
|
|
|
203
|
6
|
|
|
|
|
94
|
$query =~ s/^\s*\n|\s*$//g; |
204
|
6
|
|
|
|
|
47
|
$log->{time_started} = Time::HiRes::time(); |
205
|
6
|
|
|
|
|
11
|
$log->{query} = $query; |
206
|
6
|
|
|
|
|
13
|
$log->{stack} = \@stack; |
207
|
6
|
100
|
|
|
|
20
|
if ($opts{format} eq "json") { |
208
|
|
|
|
|
|
|
# For JSON output we don't want to output anything yet, so post_query() |
209
|
|
|
|
|
|
|
# can emit the whole JSON object, just remember them. |
210
|
|
|
|
|
|
|
} |
211
|
|
|
|
|
|
|
else { |
212
|
5
|
|
|
|
|
6
|
my $mesg; |
213
|
5
|
|
|
|
|
248
|
$mesg .= "-- " . scalar(localtime()) . "\n"; |
214
|
5
|
|
|
|
|
35
|
for my $caller (@stack) { |
215
|
5
|
|
|
|
|
27
|
$mesg .= "-- $caller->{sub} $caller->{file} $caller->{line}\n"; |
216
|
|
|
|
|
|
|
} |
217
|
5
|
|
|
|
|
10
|
$mesg .= "$query\n"; |
218
|
5
|
|
|
|
|
6
|
print {$opts{fh}} $mesg; |
|
5
|
|
|
|
|
44
|
|
219
|
|
|
|
|
|
|
} |
220
|
|
|
|
|
|
|
|
221
|
6
|
|
|
|
|
37
|
return $log; |
222
|
|
|
|
|
|
|
} |
223
|
|
|
|
|
|
|
|
224
|
|
|
|
|
|
|
sub post_query { |
225
|
8
|
|
|
8
|
0
|
23
|
my ($log) = @_; |
226
|
8
|
100
|
|
|
|
30
|
return if $log->{skip}; |
227
|
5
|
|
|
|
|
40
|
$log->{time_ended} = Time::HiRes::time(); |
228
|
5
|
|
|
|
|
91
|
$log->{time_taken} = sprintf "%.3f", $log->{time_ended} - $log->{time_started}; |
229
|
|
|
|
|
|
|
|
230
|
5
|
100
|
|
|
|
23
|
if ($opts{format} eq "json") { |
231
|
|
|
|
|
|
|
# print all the info as JSON |
232
|
1
|
|
|
|
|
7
|
print {$opts{fh}} to_json($log) . "\n"; |
|
1
|
|
|
|
|
17
|
|
233
|
|
|
|
|
|
|
} |
234
|
|
|
|
|
|
|
else { |
235
|
|
|
|
|
|
|
# For SQL output format, pre_query already printed most of the info, we |
236
|
|
|
|
|
|
|
# just need to add the time taken - and that only if we're doing |
237
|
|
|
|
|
|
|
# timings... |
238
|
4
|
50
|
|
|
|
13
|
if ($opts{timing}) { |
239
|
0
|
|
|
|
|
0
|
print {$opts{fh}} "-- $log->{time_taken}s\n"; |
|
0
|
|
|
|
|
0
|
|
240
|
|
|
|
|
|
|
} |
241
|
4
|
|
|
|
|
6
|
print {$opts{fh}} "\n"; |
|
4
|
|
|
|
|
17
|
|
242
|
|
|
|
|
|
|
} |
243
|
|
|
|
|
|
|
} |
244
|
|
|
|
|
|
|
|
245
|
|
|
|
|
|
|
sub to_json { |
246
|
10
|
|
|
10
|
0
|
22
|
my ($val, $depth) = @_; |
247
|
10
|
|
100
|
|
|
31
|
$depth ||= 0; |
248
|
10
|
|
|
|
|
12
|
my $pretty = 0; |
249
|
|
|
|
|
|
|
|
250
|
10
|
|
|
|
|
14
|
my $out; |
251
|
10
|
50
|
|
|
|
97
|
if (!defined $val) { |
|
|
100
|
|
|
|
|
|
|
|
100
|
|
|
|
|
|
|
|
100
|
|
|
|
|
|
252
|
0
|
|
|
|
|
0
|
$out = "null"; |
253
|
|
|
|
|
|
|
} |
254
|
|
|
|
|
|
|
elsif (ref $val eq "HASH") { |
255
|
2
|
|
|
|
|
5
|
$out = "{"; |
256
|
2
|
50
|
|
|
|
5
|
$out .= "\n" if $pretty; |
257
|
2
|
|
|
|
|
2
|
my $i = 0; |
258
|
2
|
|
|
|
|
62
|
for my $key (sort keys %$val) { |
259
|
8
|
|
|
|
|
14
|
my $val2 = $val->{$key}; |
260
|
8
|
100
|
|
|
|
18
|
if ($i) { |
261
|
6
|
50
|
|
|
|
17
|
$out .= $pretty ? ",\n" : ", "; |
262
|
|
|
|
|
|
|
} |
263
|
8
|
50
|
|
|
|
16
|
$out .= " " x ($depth + 1) if $pretty; |
264
|
8
|
|
|
|
|
54
|
$out .= "\"$key\": " . to_json($val2, $depth + 1); |
265
|
8
|
|
|
|
|
15
|
$i++; |
266
|
|
|
|
|
|
|
} |
267
|
2
|
50
|
|
|
|
15
|
$out .= "\n" if $pretty; |
268
|
2
|
50
|
|
|
|
10
|
$out .= " " x ($depth) if $pretty; |
269
|
2
|
|
|
|
|
4
|
$out .= "}"; |
270
|
|
|
|
|
|
|
} |
271
|
|
|
|
|
|
|
elsif (ref $val eq "ARRAY") { |
272
|
1
|
|
|
|
|
6
|
$out = "["; |
273
|
1
|
50
|
|
|
|
5
|
$out .= "\n" if $pretty; |
274
|
1
|
|
|
|
|
9
|
for my $i (0 .. @$val - 1) { |
275
|
1
|
|
|
|
|
4
|
my $val2 = $val->[$i]; |
276
|
1
|
50
|
|
|
|
3
|
if ($i) { |
277
|
0
|
0
|
|
|
|
0
|
$out .= $pretty ? ",\n" : ", "; |
278
|
|
|
|
|
|
|
} |
279
|
1
|
50
|
|
|
|
11
|
$out .= " " x ($depth + 1) if $pretty; |
280
|
1
|
|
|
|
|
6
|
$out .= to_json($val2, $depth + 1); |
281
|
|
|
|
|
|
|
} |
282
|
1
|
50
|
|
|
|
8
|
$out .= "\n" if $pretty; |
283
|
1
|
50
|
|
|
|
3
|
$out .= " " x ($depth) if $pretty; |
284
|
1
|
|
|
|
|
6
|
$out .= "]"; |
285
|
|
|
|
|
|
|
} |
286
|
|
|
|
|
|
|
elsif ($val =~ /^(-?\d+(\.\d*)?(e[+-]?\d+)?)$/i) { |
287
|
4
|
|
|
|
|
12
|
$out = $val; |
288
|
|
|
|
|
|
|
} |
289
|
|
|
|
|
|
|
else { |
290
|
3
|
|
|
|
|
19
|
$val =~ s/"/\"/g; |
291
|
3
|
|
|
|
|
8
|
$out = "\"$val\""; |
292
|
|
|
|
|
|
|
} |
293
|
|
|
|
|
|
|
|
294
|
10
|
|
|
|
|
56
|
return $out; |
295
|
|
|
|
|
|
|
} |
296
|
|
|
|
|
|
|
|
297
|
|
|
|
|
|
|
1; |
298
|
|
|
|
|
|
|
|
299
|
|
|
|
|
|
|
__END__ |