2014-05-20 12:17:01 +02:00
|
|
|
# File: SQLiteLogger
|
|
|
|
#
|
|
|
|
# Purpose: Logs SQLite trace messages to Logger.pm with profiling of elapsed
|
|
|
|
# time between messages.
|
|
|
|
|
2017-03-05 22:33:31 +01:00
|
|
|
# This Source Code Form is subject to the terms of the Mozilla Public
|
|
|
|
# License, v. 2.0. If a copy of the MPL was not distributed with this
|
|
|
|
# file, You can obtain one at http://mozilla.org/MPL/2.0/.
|
|
|
|
|
2014-05-20 12:17:01 +02:00
|
|
|
package PBot::SQLiteLogger;
|
|
|
|
|
2021-06-19 06:23:34 +02:00
|
|
|
use PBot::Imports;
|
2019-07-11 03:40:53 +02:00
|
|
|
|
2014-05-20 12:17:01 +02:00
|
|
|
use Time::HiRes qw(gettimeofday);
|
|
|
|
|
2020-02-08 20:04:13 +01:00
|
|
|
sub new {
|
2021-06-19 06:23:34 +02:00
|
|
|
my ($class, %args) = @_;
|
|
|
|
|
|
|
|
my $self = {
|
|
|
|
pbot => $args{pbot},
|
|
|
|
buf => '',
|
|
|
|
timestamp => scalar gettimeofday,
|
|
|
|
};
|
|
|
|
|
2020-02-15 23:38:32 +01:00
|
|
|
return bless $self, $class;
|
2014-05-20 12:17:01 +02:00
|
|
|
}
|
|
|
|
|
2020-02-08 20:04:13 +01:00
|
|
|
sub log {
|
2020-02-15 23:38:32 +01:00
|
|
|
my $self = shift;
|
2021-06-19 06:23:34 +02:00
|
|
|
|
2020-02-15 23:38:32 +01:00
|
|
|
$self->{buf} .= shift;
|
|
|
|
|
|
|
|
# DBI feeds us pieces at a time, so accumulate a complete line
|
|
|
|
# before outputing
|
|
|
|
if ($self->{buf} =~ tr/\n//) {
|
|
|
|
$self->log_message;
|
|
|
|
$self->{buf} = '';
|
|
|
|
}
|
2014-05-20 12:17:01 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
sub log_message {
|
2021-06-19 06:23:34 +02:00
|
|
|
my ($self) = @_;
|
|
|
|
|
2020-02-15 23:38:32 +01:00
|
|
|
my $now = gettimeofday;
|
|
|
|
my $elapsed = $now - $self->{timestamp};
|
2021-06-19 06:23:34 +02:00
|
|
|
|
|
|
|
# log SQL statements that take more than 100ms since the last log
|
2020-02-15 23:38:32 +01:00
|
|
|
if ($elapsed >= 0.100) { $self->{pbot}->{logger}->log("^^^ SLOW SQL ^^^\n"); }
|
2021-06-19 06:23:34 +02:00
|
|
|
|
|
|
|
# log SQL statement and elapsed duration since last statement
|
2020-02-15 23:38:32 +01:00
|
|
|
$elapsed = sprintf '%10.3f', $elapsed;
|
|
|
|
$self->{pbot}->{logger}->log("$elapsed : $self->{buf}");
|
2021-06-19 06:23:34 +02:00
|
|
|
|
|
|
|
# update timestamp
|
2020-02-15 23:38:32 +01:00
|
|
|
$self->{timestamp} = $now;
|
2014-05-20 12:17:01 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
sub close {
|
2021-06-19 06:23:34 +02:00
|
|
|
my ($self) = @_;
|
|
|
|
|
|
|
|
# log anything left in buf when closing
|
2020-02-15 23:38:32 +01:00
|
|
|
if ($self->{buf}) {
|
|
|
|
$self->log_message;
|
|
|
|
$self->{buf} = '';
|
|
|
|
}
|
2014-05-20 12:17:01 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
1;
|