From f8f40252e4cd9ab997b0ae66bddfff42abc127d8 Mon Sep 17 00:00:00 2001 From: Kyle M Hall Date: Tue, 12 May 2020 07:11:12 -0400 Subject: [PATCH] Bug 25464 - Add ability to specify client IP and SIP account used in SIP2 logging Bug 15253 originally had the ability to specify the incoming IP address used for a given log statement via SIP, as well as the SIP2 account that was in use at the time. This data is very helpful for debugging purposes, and should be brought back. Test Plan: 1) Apply this patch 2) Update you SIP ConversionPattern to "[%d] [%p] %X{accountid}@%X{peeraddr}: %m %l %n" 3) Restart SIP 4) Use the SIP cli tester to make some SIP requests 5) View the SIP2 log, note the account id and client ip address show in the log! --- C4/SIP/SIPServer.pm | 8 +++++++ Koha/Logger.pm | 29 ++++++++++++++++++++++++++ debian/koha-common.postinst | 2 +- debian/templates/log4perl-site.conf.in | 2 +- etc/log4perl.conf | 2 +- t/Logger.t | 12 +++++++++-- 6 files changed, 50 insertions(+), 5 deletions(-) diff --git a/C4/SIP/SIPServer.pm b/C4/SIP/SIPServer.pm index 7af355465d..3533bdf680 100755 --- a/C4/SIP/SIPServer.pm +++ b/C4/SIP/SIPServer.pm @@ -105,6 +105,10 @@ sub process_request { $self->{account} = undef; # Clear out the account from the last request, it may be different $self->{logger} = set_logger( Koha::Logger->get( { interface => 'sip' } ) ); + # Flush previous MDCs to prevent accidentally leaking incorrect MDC-entries + Koha::Logger->put_mdc( "accountid", undef ); + Koha::Logger->put_mdc( "peeraddr", undef ); + my $sockname = getsockname(STDIN); # Check if socket connection is IPv6 before resolving address @@ -179,6 +183,10 @@ sub raw_transport { ) ); + # Set MDCs after properly authenticating + Koha::Logger->put_mdc( "accountid", $self->{account}->{id} ); + Koha::Logger->put_mdc( "peeraddr", $self->{server}->{peeraddr} ); + siplog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'", $self->{account}->{id}, $self->{account}->{institution}); diff --git a/Koha/Logger.pm b/Koha/Logger.pm index 2751bf189b..f5965e1efb 100644 --- a/Koha/Logger.pm +++ b/Koha/Logger.pm @@ -71,6 +71,35 @@ sub get { return $self; } +=head2 put_mdc + +my $foo = $logger->put_mdc('foo', $foo ); + +put_mdc sets global thread specific data that can be access later when generating log lines +via the "%X{key}" placeholder in Log::Log4perl::Layout::PatternLayouts. + +=cut + +sub put_mdc { + my ( $self, $key, $value ) = @_; + + Log::Log4perl::MDC->put( $key, $value ); +} + +=head2 get_mdc + +my $foo = $logger->get_mdc('foo'); + +Retrieves the stored mdc value from the stored map + +=cut + +sub get_mdc { + my ( $self, $key ) = @_; + + return Log::Log4perl::MDC->get( $key ); +} + =head1 INTERNALS =head2 AUTOLOAD diff --git a/debian/koha-common.postinst b/debian/koha-common.postinst index 46bc087d2b..173f700aba 100644 --- a/debian/koha-common.postinst +++ b/debian/koha-common.postinst @@ -182,7 +182,7 @@ log4perl.appender.SIP=Log::Log4perl::Appender::File log4perl.appender.SIP.filename=/var/log/koha/$site/sip.log log4perl.appender.SIP.mode=append log4perl.appender.SIP.layout=PatternLayout -log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %m %l %n +log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %X{accountid}@%X{peeraddr}: %m %l %n log4perl.appender.SIP.utf8=1 EOF diff --git a/debian/templates/log4perl-site.conf.in b/debian/templates/log4perl-site.conf.in index df61c9a9ec..e43797314c 100644 --- a/debian/templates/log4perl-site.conf.in +++ b/debian/templates/log4perl-site.conf.in @@ -35,5 +35,5 @@ log4perl.appender.SIP=Log::Log4perl::Appender::File log4perl.appender.SIP.filename=__LOG_DIR__/sip.log log4perl.appender.SIP.mode=append log4perl.appender.SIP.layout=PatternLayout -log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %m %l %n +log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %X{accountid}@%X{peeraddr}: %m %l %n log4perl.appender.SIP.utf8=1 diff --git a/etc/log4perl.conf b/etc/log4perl.conf index df61c9a9ec..e43797314c 100644 --- a/etc/log4perl.conf +++ b/etc/log4perl.conf @@ -35,5 +35,5 @@ log4perl.appender.SIP=Log::Log4perl::Appender::File log4perl.appender.SIP.filename=__LOG_DIR__/sip.log log4perl.appender.SIP.mode=append log4perl.appender.SIP.layout=PatternLayout -log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %m %l %n +log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %X{accountid}@%X{peeraddr}: %m %l %n log4perl.appender.SIP.utf8=1 diff --git a/t/Logger.t b/t/Logger.t index a2a0cc58b8..caf48a76fb 100644 --- a/t/Logger.t +++ b/t/Logger.t @@ -26,7 +26,7 @@ use Test::More tests => 1; use Test::Warn; subtest 'Test01 -- Simple tests for Koha::Logger' => sub { - plan tests => 6; + plan tests => 9; my $ret; t::lib::Mocks::mock_config('log4perl_conf', undef); @@ -52,7 +52,7 @@ HERE ok( $@, 'Logger did not init correctly without permission'); system("chmod 700 $log"); - my $logger= Koha::Logger->get({ interface => 'intranet' }); + my $logger = Koha::Logger->get( { interface => 'intranet' } ); is( exists $logger->{logger}, 1, 'Log4perl config found'); is( $logger->warn('Message 1'), 1, '->warn returned a value' ); warning_is { $ret = $logger->catastrophe } @@ -60,6 +60,14 @@ HERE "Undefined method raises warning"; is( $ret, undef, "'catastrophe' method undefined"); + Koha::Logger->put_mdc( 'foo', 'bar' ); + is( Koha::Logger->get_mdc('foo'), 'bar', "MDC value via put is correct" ); + + Koha::Logger->put_mdc( 'foo', 'baz' ); + is( Koha::Logger->get_mdc('foo'), 'baz', "Updated MDC value via put is correct" ); + + Koha::Logger->put_mdc( 'foo', undef ); + is( Koha::Logger->get_mdc('foo'), undef, "Updated MDC value to undefined via put is correct" ); }; sub mytempfile { -- 2.24.2 (Apple Git-127)