Bug 38365: Add default log4perl configuration

This patch adds the default configuration to log4perl.conf.

Note we are passing a non-standard interface 'csp' to Koha::Logger. This is to
avoid log entries from propagating up to api-error.log.

To test:
1. prove t/db_dependent/api/v1/public/csp_reports.t

Signed-off-by: David Cook <dcook@prosentient.com.au>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Koha/REST/V1/CSPReports.pm

@@ -51,7 +51,7 @@ sub add {
     # CSP reports come wrapped in a 'csp-report' key
     my $csp_report = $report->{'csp-report'} // $report;
 
-    my $logger = Koha::Logger->get( { interface => 'api', category => 'csp' } );
+    my $logger = Koha::Logger->get( { interface => 'csp' } );
 
     # Extract key fields for logging
     my $document_uri  = $csp_report->{'document-uri'}       // 'unknown';

debian/templates/log4perl-site.conf.in

@@ -76,3 +76,19 @@ log4perl.appender.EDI.mode=append
 log4perl.appender.EDI.layout=PatternLayout
 log4perl.appender.EDI.layout.ConversionPattern=[%d] [%P] [%p] %X{accountid}@%X{peeraddr}: %m %l%n
 log4perl.appender.EDI.utf8=1
+
+log4perl.logger.csp = WARN, CSP
+log4perl.appender.CSP=Log::Log4perl::Appender::File
+log4perl.appender.CSP.filename=__LOG_DIR__/csp-violations.log
+log4perl.appender.CSP.mode=append
+log4perl.appender.CSP.layout=PatternLayout
+log4perl.appender.CSP.layout.ConversionPattern=[%d] %m%n
+log4perl.appender.CSP.utf8=1
+
+log4perl.logger.plack-csp = WARN, PLACKCSP
+log4perl.appender.PLACKCSP=Log::Log4perl::Appender::File
+log4perl.appender.PLACKCSP.filename=__LOG_DIR__/plack-csp-violations.log
+log4perl.appender.PLACKCSP.mode=append
+log4perl.appender.PLACKCSP.layout=PatternLayout
+log4perl.appender.PLACKCSP.layout.ConversionPattern=[%d] %m%n
+log4perl.appender.PLACKCSP.utf8=1

etc/log4perl.conf

@@ -76,3 +76,19 @@ log4perl.appender.EDI.mode=append
 log4perl.appender.EDI.layout=PatternLayout
 log4perl.appender.EDI.layout.ConversionPattern=[%d] [%P] [%p] %X{accountid}@%X{peeraddr}: %m %l%n
 log4perl.appender.EDI.utf8=1
+
+log4perl.logger.csp = WARN, CSP
+log4perl.appender.CSP=Log::Log4perl::Appender::File
+log4perl.appender.CSP.filename=__LOG_DIR__/csp-violations.log
+log4perl.appender.CSP.mode=append
+log4perl.appender.CSP.layout=PatternLayout
+log4perl.appender.CSP.layout.ConversionPattern=[%d] %m%n
+log4perl.appender.CSP.utf8=1
+
+log4perl.logger.plack-csp = WARN, PLACKCSP
+log4perl.appender.PLACKCSP=Log::Log4perl::Appender::File
+log4perl.appender.PLACKCSP.filename=__LOG_DIR__/plack-csp-violations.log
+log4perl.appender.PLACKCSP.mode=append
+log4perl.appender.PLACKCSP.layout=PatternLayout
+log4perl.appender.PLACKCSP.layout.ConversionPattern=[%d] %m%n
+log4perl.appender.PLACKCSP.utf8=1

t/db_dependent/api/v1/public/csp_reports.t

@@ -22,6 +22,9 @@ use Test::More tests => 2;
 use Test::Mojo;
 use Test::Warn;
 
+use Carp qw( carp );
+use Log::Log4perl;
+
 use t::lib::Mocks;
 
 use Koha::Database;
@@ -33,7 +36,7 @@ t::lib::Mocks::mock_preference( 'RESTBasicAuth', 1 );
 
 subtest 'add() tests' => sub {
 
-    plan tests => 6;
+    plan tests => 7;
 
     $schema->storage->txn_begin;
 
@@ -74,6 +77,93 @@ subtest 'add() tests' => sub {
     $t->post_ok( '/api/v1/public/csp-reports' => json => $minimal_report )
         ->status_is( 204, 'Minimal CSP report accepted' );
 
+    subtest 'make sure log entries are being written' => sub {
+        plan tests => 17;
+
+        my $log4perl_conf_file = C4::Context->config('intranetdir') . '/etc/log4perl.conf';
+        open my $fh, '<:encoding(UTF-8)', $log4perl_conf_file or do {
+            carp "Cannot read $log4perl_conf_file: $!";
+            return;
+        };
+        my $log4perl_conf_content = "";
+        while (<$fh>) {
+            my $line = $_;
+            next unless $line =~ /^(log4perl.logger.(plack-)?csp)|(log4perl.appender.(PLACK)?CSP)/;
+            $log4perl_conf_content .= "$line";
+        }
+        close $fh;
+        like( $log4perl_conf_content, qr/__LOG_DIR__\/csp-violations\.log/, 'csp-violations.log is defined' );
+        like(
+            $log4perl_conf_content, qr/__LOG_DIR__\/plack-csp-violations\.log/,
+            'plack-csp-violations.log is defined'
+        );
+        like(
+            $log4perl_conf_content, qr/log4perl.appender.CSP=Log::Log4perl::Appender::File/,
+            'CSP: File appender exists'
+        );
+        like(
+            $log4perl_conf_content, qr/log4perl.appender.PLACKCSP=Log::Log4perl::Appender::File/,
+            'PLACKCSP: File appender exists'
+        );
+        $log4perl_conf_content =~ s/Log::Log4perl::Appender::File/Log::Log4perl::Appender::TestBuffer/g;
+        Log::Log4perl::init( \$log4perl_conf_content );
+        my $appenders     = Log::Log4perl->appenders;
+        my $appender      = Log::Log4perl->appenders->{CSP};
+        my $appenderplack = Log::Log4perl->appenders->{PLACKCSP};
+
+        is( $appender->buffer,      '', 'Nothing in log buffer yet' );
+        is( $appenderplack->buffer, '', 'Nothing in plack log buffer yet' );
+
+        $t->post_ok(
+            '/api/v1/public/csp-reports' => { 'Content-Type' => 'application/csp-report' } => json => $csp_report )
+            ->status_is( 204, 'CSP report accepted' );
+
+        my $expected_log_entry = sprintf(
+            "CSP violation: '%s' blocked '%s' on page '%s'%s",
+            $csp_report->{'csp-report'}->{'violated-directive'},
+            $csp_report->{'csp-report'}->{'blocked-uri'},
+            $csp_report->{'csp-report'}->{'document-uri'},
+            ' at '
+                . $csp_report->{'csp-report'}->{'source-file'} . ':'
+                . $csp_report->{'csp-report'}->{'line-number'} . ':'
+                . $csp_report->{'csp-report'}->{'column-number'}
+        );
+
+        like(
+            $appender->buffer, qr/$expected_log_entry/
+            ,                  'Log contains expected log entry'
+        );
+        is( $appenderplack->buffer, '', 'Nothing in plack log buffer yet' );
+        $appender->clear();
+
+        $ENV{'plack.is.enabled.for.this.test'} = 1;    # tricking C4::Context->psgi_env
+        $t->post_ok(
+            '/api/v1/public/csp-reports' => { 'Content-Type' => 'application/csp-report' } => json => $csp_report )
+            ->status_is( 204, 'CSP report accepted' );
+        like(
+            $appenderplack->buffer, qr/$expected_log_entry/
+            ,                       'Plack log contains expected log entry'
+        );
+        is( $appender->buffer, '', 'Nothing in log buffer yet' );
+
+        Log::Log4perl::init(
+            \<<"HERE"
+log4perl.logger.api = WARN, API
+log4perl.appender.API=Log::Log4perl::Appender::TestBuffer
+log4perl.appender.API.mode=append
+log4perl.appender.API.layout=PatternLayout
+log4perl.appender.API.layout.ConversionPattern=[%d] [%p] %m %l%n
+log4perl.appender.API.utf8=1
+HERE
+        );
+        $appender = Log::Log4perl->appenders()->{API};
+        $t->post_ok(
+            '/api/v1/public/csp-reports' => { 'Content-Type' => 'application/csp-report' } => json => $csp_report )
+            ->status_is( 204, 'CSP report returns 204 even when no CSP loggers are defined' );
+        is( $appender->buffer, '', 'Nothing in the only defined log buffer, because it is unrelated to CSP' );
+
+    };
+
     $schema->storage->txn_rollback;
 };