Bug 35907: Add ability to log all custom report runs with or without query

Because of the way Koha::Logger has been used to log to different categories based on the interface and caller, it can be extremely hard to log all of a particular log statement to one place.

For custom report runs, the category is plack-intranet.C4::Reports::Guided when run from the web interface, cron.C4::Reports::Guided when run from runreport.pl, and plack-intranet.C4::Auth when run from svc/report.

We should add a more standardized report run log, both with and without the full query, so that administrators can log all report runs to a centralized location. If an administrator were to need the "point of entry" for reports, it is easy to include via parameters in PatternLayout.

Test Plan:
1) Apply this patch
2) Modify your log4perl file, add the following:

log4perl.logger.reports.execute.time = INFO, REPORTTIME
log4perl.appender.REPORTTIME=Log::Log4perl::Appender::File
log4perl.appender.REPORTTIME.filename=/tmp/report-time.log
log4perl.appender.REPORTTIME.mode=append
log4perl.appender.REPORTTIME.layout=PatternLayout
log4perl.appender.REPORTTIME.layout.ConversionPattern=[%d] [%p] [%P] %m%n
log4perl.appender.REPORTTIME.utf8=1

log4perl.logger.reports.execute.query = INFO, REPORTQUERY
log4perl.appender.REPORTQUERY=Log::Log4perl::Appender::File
log4perl.appender.REPORTQUERY.filename=/tmp/report-query.log
log4perl.appender.REPORTQUERY.mode=append
log4perl.appender.REPORTQUERY.layout=PatternLayout
log4perl.appender.REPORTQUERY.layout.ConversionPattern=[%d] [%p] [%P] %m%n
log4perl.appender.REPORTQUERY.utf8=1

3) Restart all the things!
4) Run a report somehow:
   CLI: ./misc/cronjobs/runreport.pl 1
   API: /cgi-bin/koha/svc/report?id=1
   Web: /cgi-bin/koha/reports/guided_reports.pl?reports=1&phase=Run this report
5) Note the report runs are logged to /tmp/report-time.log and /tmp/report-query.log

Signed-off-by: Brendan Lawlor <blawlor@clamsnet.org>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Katrin Fischer <katrin.fischer@bsz-bw.de>

C4/Reports/Guided.pm

@@ -18,6 +18,7 @@ package C4::Reports::Guided;
 # along with Koha; if not, see <http://www.gnu.org/licenses>.
 
 use Modern::Perl;
+
 use CGI qw ( -utf8 );
 use Carp qw( carp croak );
 use JSON qw( from_json );
@@ -609,12 +610,20 @@ sub execute_query {
 
     $dbh->do( 'UPDATE saved_sql SET last_run = NOW() WHERE id = ?', undef, $report_id ) if $report_id;
 
+    Koha::Logger->get( { prefix => 0, interface => 'reports', category => 'execute.query' } )
+        ->info("Report $report_id : $sql, $offset, $limit") if $report_id;
+    Koha::Logger->get( { prefix => 0, interface => 'reports', category => 'execute.time.start' } )
+        ->info("Report starting: $report_id") if $report_id;
+
     my $sth = $dbh->prepare($sql);
     eval {
         $sth->execute(@$sql_params, $offset, $limit);
     };
     warn $@ if $@;
 
+    Koha::Logger->get( { prefix => 0, interface => 'reports', category => 'execute.time.end' } )
+        ->info("Report finished: $report_id") if $report_id;
+
     return ( $sth, { queryerr => $sth->errstr } ) if ($sth->err);
     return ( $sth );
 }

Koha/Logger.pm

@@ -51,13 +51,16 @@ BEGIN {
     Normally, the category should follow the current package and the interface
     should be set correctly via C4::Context.
 
+    If the category should not be prefixed if plack, set the param 'prefix' to 0.
 =cut
 
 sub get {
     my ( $class, $params ) = @_;
     my $interface = $params ? ( $params->{interface} || C4::Context->interface ) : C4::Context->interface;
     my $category = $params ? ( $params->{category} || caller ) : caller;
-    my $l4pcat = ( C4::Context->psgi_env ? 'plack-' : q{} ) . $interface . '.' . $category;
+    my $prefix = $params->{prefix} // 1;
+
+    my $l4pcat = ( ( $prefix && C4::Context->psgi_env ) ? 'plack-' : q{} ) . $interface . '.' . $category;
 
     my $init = _init();
     my $self = {};

t/Logger.t

@@ -27,7 +27,7 @@ use Test::Warn;
 use Test::Exception;
 
 subtest 'Test01 -- Simple tests for Koha::Logger' => sub {
-    plan tests => 10;
+    plan tests => 13;
 
     my $ret;
     t::lib::Mocks::mock_config('log4perl_conf', undef);
@@ -76,6 +76,21 @@ HERE
 
     Koha::Logger->clear_mdc();
     is( Koha::Logger->get_mdc( 'foo' ), undef, "MDC value was cleared by clear_mdc" );
+
+    is(
+        Koha::Logger->get( { interface => 'cli', category => 'Test.Category' } )->category(), "cli.Test.Category",
+        "Category is cli.Test.Category"
+    );
+    $ENV{'PLACK_ENV'} = 1;
+    is(
+        Koha::Logger->get( { interface => 'cli', category => 'Test.Category' } )->category(),
+        "plack-cli.Test.Category", "Category under plack is is plack-cli.Test.Category"
+    );
+    is(
+        Koha::Logger->get( { interface => 'cli', category => 'Test.Category', prefix => 0 } )->category(),
+        "cli.Test.Category", "Category under plack with prefixing disabled is is cli.Test.Category"
+    );
+    delete $ENV{'PLACK_ENV'};
 };
 
 sub mytempfile {