Revert "Bug 15253: (follow-up) Fix qa complaints"
[koha-equinox.git] / C4 / SIP / SIPServer.pm
old mode 100644 (file)
new mode 100755 (executable)
index c6de11e..2b73b98
@@ -1,29 +1,30 @@
-package SIPServer;
+#!/usr/bin/perl
+package C4::SIP::SIPServer;
 
 use strict;
 use warnings;
-# use Exporter;
-use Sys::Syslog qw(syslog);
+use FindBin qw($Bin);
+use lib "$Bin";
 use Net::Server::PreFork;
 use IO::Socket::INET;
 use Socket qw(:DEFAULT :crlf);
-use Data::Dumper;              # For debugging
+use Scalar::Util qw(blessed);
 require UNIVERSAL::require;
 
-#use Sip qw(readline);
-use Sip::Constants qw(:all);
-use Sip::Configuration;
-use Sip::Checksum qw(checksum verify_cksum);
-use Sip::MsgType;
+use C4::Context;
+use C4::SIP::Sip qw(syslog);
+use C4::SIP::Sip::Constants qw(:all);
+use C4::SIP::Sip::Configuration;
+use C4::SIP::Sip::Checksum qw(checksum verify_cksum);
+use C4::SIP::Sip::MsgType qw( handle login_core );
 
-use constant LOG_SIP => "local6"; # Local alias for the logging facility
+use Koha::Logger;
+use C4::SIP::Trapper;
+tie *STDERR, "C4::SIP::Trapper";
 
-use vars qw(@ISA $VERSION);
+use base qw(Net::Server::PreFork);
 
-BEGIN {
-       $VERSION = 1.02;
-       @ISA = qw(Net::Server::PreFork);
-}
+use constant LOG_SIP => "local6"; # Local alias for the logging facility
 
 #
 # Main # not really, since package SIPServer
@@ -32,17 +33,18 @@ BEGIN {
 # A script with no MAIN namespace?
 # A module that takes command line args?
 
+# Set interface to 'sip'
+C4::Context->interface('sip');
+
 my %transports = (
     RAW    => \&raw_transport,
     telnet => \&telnet_transport,
-    # http   => \&http_transport,      # for http just use the OPAC
 );
 
 #
 # Read configuration
 #
-my $config = new Sip::Configuration $ARGV[0];
-print STDERR "SIPServer config: \n" . Dumper($config) . "\nEND SIPServer config.\n";
+my $config = C4::SIP::Sip::Configuration->new( $ARGV[0] );
 my @parms;
 
 #
@@ -74,8 +76,6 @@ if (defined($config->{'server-params'})) {
     }
 }
 
-print scalar(localtime),  " -- startup -- procid:$$\n";
-print "Params for Net::Server::PreFork : \n" . Dumper(\@parms);
 
 #
 # This is the main event.
@@ -85,6 +85,9 @@ __PACKAGE__ ->run(@parms);
 # Child
 #
 
+my $activeSIPServer;
+my $activeLogger;
+
 # process_request is the callback used by Net::Server to handle
 # an incoming connection request.
 
@@ -96,9 +99,24 @@ sub process_request {
 
     $self->{config} = $config;
 
+    $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
+    Log::Log4perl::MDC->put( "accountid", undef );
+    Log::Log4perl::MDC->put( "peeraddr",  undef );
+
     my $sockname = getsockname(STDIN);
-    ($port, $sockaddr) = sockaddr_in($sockname);
-    $sockaddr = inet_ntoa($sockaddr);
+
+    # Check if socket connection is IPv6 before resolving address
+    my $family = Socket::sockaddr_family($sockname);
+    if ($family == AF_INET6) {
+      ($port, $sockaddr) = sockaddr_in6($sockname);
+      $sockaddr = Socket::inet_ntop(AF_INET6, $sockaddr);
+    } else {
+      ($port, $sockaddr) = sockaddr_in($sockname);
+      $sockaddr = inet_ntoa($sockaddr);
+    }
     $proto = $self->{server}->{client}->NS_proto();
 
     $self->{service} = $config->find_service($sockaddr, $port, $proto);
@@ -116,6 +134,7 @@ sub process_request {
     } else {
                &$transport($self);
     }
+    return;
 }
 
 #
@@ -124,44 +143,61 @@ sub process_request {
 
 sub raw_transport {
     my $self = shift;
-    my ($input);
+    my $input;
     my $service = $self->{service};
-    my $strikes = 3;
+    # If using Net::Server::PreFork you may already have account set from a previous session
+    # Ensure you dont
+    if ($self->{account}) {
+        delete $self->{account};
+    }
 
-    eval {
-               local $SIG{ALRM} = sub { die "raw_transport Timed Out!\n"; };
-               syslog("LOG_DEBUG", "raw_transport: timeout is %d", $service->{timeout});
-               while ($strikes--) {
-                   alarm $service->{timeout};
-                   $input = Sip::read_SIP_packet(*STDIN);
-                   alarm 0;
-                       if (!$input) {
-                               # EOF on the socket
-                               syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
-                               return;
-                   }
-                   $input =~ s/[\r\n]+$//sm;   # Strip off trailing line terminator(s)
-                   last if Sip::MsgType::handle($input, $self, LOGIN);
-               }
-       };
-
-    if (length $@) {
-               syslog("LOG_ERR", "raw_transport: LOGIN ERROR: '$@'");
-               die "raw_transport: login error (timeout? $@), exiting";
-    } elsif (!$self->{account}) {
-               syslog("LOG_ERR", "raw_transport: LOGIN FAILED");
-               die "raw_transport: Login failed (no account), exiting";
+    # Timeout the while loop if we get stuck in it
+    # In practice it should only iterate once but be prepared
+    local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };
+    my $timeout = $self->get_timeout({ transport => 1 });
+    syslog('LOG_DEBUG', "raw_transport: timeout is $timeout");
+    alarm $timeout;
+    while (!$self->{account}) {
+        $input = read_request();
+        if (!$input) {
+            # EOF on the socket
+            syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
+            return;
+        }
+        $input =~ s/[\r\n]+$//sm; # Strip off trailing line terminator(s)
+        my $reg = qr/^${\(LOGIN)}/;
+        last if $input !~ $reg ||
+            C4::SIP::Sip::MsgType::handle($input, $self, LOGIN);
     }
+    alarm 0;
+
+    $self->{logger} = _set_logger(
+        Koha::Logger->get(
+            {
+                interface => 'sip',
+                category  => $self->{account}->{id}, # Add id to namespace
+            }
+        )
+    );
+
+    # Set MDCs after properly authenticating
+    Log::Log4perl::MDC->put( "accountid", $self->{account}->{id} );
+    Log::Log4perl::MDC->put( "peeraddr",  $self->{server}->{peeraddr} );
 
     syslog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'",
-          $self->{account}->{id},
-          $self->{account}->{institution});
+        $self->{account}->{id},
+        $self->{account}->{institution});
+    if (! $self->{account}->{id}) {
+        syslog("LOG_ERR","Login failed shutting down");
+        return;
+    }
 
     $self->sip_protocol_loop();
     syslog("LOG_INFO", "raw_transport: shutting down");
+    return;
 }
 
-sub get_clean_string ($) {
+sub get_clean_string {
        my $string = shift;
        if (defined $string) {
                syslog("LOG_DEBUG", "get_clean_string  pre-clean(length %s): %s", length($string), $string);
@@ -192,8 +228,8 @@ sub telnet_transport {
     my $account = undef;
     my $input;
     my $config  = $self->{config};
-       my $timeout = $self->{service}->{timeout} || $config->{timeout} || 30;
-       syslog("LOG_DEBUG", "telnet_transport: timeout is %s", $timeout);
+    my $timeout = $self->get_timeout({ transport => 1 });
+    syslog("LOG_DEBUG", "telnet_transport: timeout is $timeout");
 
     eval {
        local $SIG{ALRM} = sub { die "telnet_transport: Timed Out ($timeout seconds)!\n"; };
@@ -218,9 +254,11 @@ sub telnet_transport {
                syslog("LOG_DEBUG", "telnet_transport 2: uid length %s, pwd length %s", length($uid), length($pwd));
 
            if (exists ($config->{accounts}->{$uid})
-               && ($pwd eq $config->{accounts}->{$uid}->password())) {
+               && ($pwd eq $config->{accounts}->{$uid}->{password})) {
                        $account = $config->{accounts}->{$uid};
-                       Sip::MsgType::login_core($self,$uid,$pwd) and last;
+                       if ( C4::SIP::Sip::MsgType::login_core($self,$uid,$pwd) ) {
+                last;
+            }
            }
                syslog("LOG_WARNING", "Invalid login attempt: '%s'", ($uid||''));
                print("Invalid login$CRLF");
@@ -241,6 +279,7 @@ sub telnet_transport {
     syslog("LOG_DEBUG", "telnet_transport: uname/inst: '%s/%s'", $account->{id}, $account->{institution});
     $self->sip_protocol_loop();
     syslog("LOG_INFO", "telnet_transport: shutting down");
+    return;
 }
 
 #
@@ -249,14 +288,14 @@ sub telnet_transport {
 # telnet transport.  From that point on, both the raw and the telnet
 # processes are the same:
 sub sip_protocol_loop {
-       my $self = shift;
-       my $service = $self->{service};
-       my $config  = $self->{config};
-       my $input;
+    my $self = shift;
+    my $service = $self->{service};
+    my $config  = $self->{config};
+    my $timeout = $self->get_timeout({ client => 1 });
 
     # The spec says the first message will be:
-       #       SIP v1: SC_STATUS
-       #       SIP v2: LOGIN (or SC_STATUS via telnet?)
+    #     SIP v1: SC_STATUS
+    #     SIP v2: LOGIN (or SC_STATUS via telnet?)
     # But it might be SC_REQUEST_RESEND.  As long as we get
     # SC_REQUEST_RESEND, we keep waiting.
 
@@ -264,42 +303,176 @@ sub sip_protocol_loop {
     # constraint, so we'll relax about it too.
     # Using the SIP "raw" login process, rather than telnet,
     # requires the LOGIN message and forces SIP 2.00.  In that
-       # case, the LOGIN message has already been processed (above).
-       # 
-       # In short, we'll take any valid message here.
-       #my $expect = SC_STATUS;
-    my $expect = '';
-    my $strikes = 3;
-    while ($input = Sip::read_SIP_packet(*STDIN)) {
-               # begin input hacks ...  a cheap stand in for better Telnet layer
-               $input =~ s/^[^A-z0-9]+//s;     # Kill leading bad characters... like Telnet handshakers
-               $input =~ s/[^A-z0-9]+$//s;     # Same on the end, should get DOSsy ^M line-endings too.
-               while (chomp($input)) {warn "Extra line ending on input";}
-               unless ($input) {
-                       if ($strikes--) {
-                               syslog("LOG_ERR", "sip_protocol_loop: empty input skipped");
-                               next;
-                       } else {
-                               syslog("LOG_ERR", "sip_protocol_loop: quitting after too many errors");
-                               die "sip_protocol_loop: quitting after too many errors";
-                       }
-               }
-               # end cheap input hacks
-               my $status = Sip::MsgType::handle($input, $self, $expect);
-               if (!$status) {
-                       syslog("LOG_ERR", "sip_protocol_loop: failed to handle %s",substr($input,0,2));
-                       die "sip_protocol_loop: failed Sip::MsgType::handle('$input', $self, '$expect')";
-               }
-               next if $status eq REQUEST_ACS_RESEND;
-               if ($expect && ($status ne $expect)) {
-                       # We received a non-"RESEND" that wasn't what we were expecting.
-                   syslog("LOG_ERR", "sip_protocol_loop: expected %s, received %s, exiting", $expect, $input);
-                       die "sip_protocol_loop: exiting: expected '$expect', received '$status'";
-               }
-               # We successfully received and processed what we were expecting
-               $expect = '';
-       }
+    # case, the LOGIN message has already been processed (above).
+
+    # In short, we'll take any valid message here.
+    eval {
+        local $SIG{ALRM} = sub {
+            syslog( 'LOG_DEBUG', 'Inactive: timed out' );
+            die "Timed Out!\n";
+        };
+        my $previous_alarm = alarm($timeout);
+
+        while ( my $inputbuf = read_request() ) {
+            if ( !defined $inputbuf ) {
+                return;    #EOF
+            }
+            alarm($timeout);
+
+            unless ($inputbuf) {
+                syslog( "LOG_ERR", "sip_protocol_loop: empty input skipped" );
+                print("96$CR");
+                next;
+            }
+
+            my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );
+            if ( !$status ) {
+                syslog(
+                    "LOG_ERR",
+                    "sip_protocol_loop: failed to handle %s",
+                    substr( $inputbuf, 0, 2 )
+                );
+            }
+            next if $status eq REQUEST_ACS_RESEND;
+        }
+        alarm($previous_alarm);
+        return;
+    };
+    if ( $@ =~ m/timed out/i ) {
+        return;
+    }
+    return;
+}
+
+sub read_request {
+      my $raw_length;
+      local $/ = "\015";
+
+    # proper SPEC: (octal) \015 = (hex) x0D = (dec) 13 = (ascii) carriage return
+      my $buffer = <STDIN>;
+      if ( defined $buffer ) {
+          STDIN->flush();    # clear an extra linefeed
+          chomp $buffer;
+          $raw_length = length $buffer;
+          $buffer =~ s/^\s*[^A-z0-9]+//s;
+# Every line must start with a "real" character.  Not whitespace, control chars, etc.
+          $buffer =~ s/[^A-z0-9]+$//s;
+
+# Same for the end.  Note this catches the problem some clients have sending empty fields at the end, like |||
+          $buffer =~ s/\015?\012//g;    # Extra line breaks must die
+          $buffer =~ s/\015?\012//s;    # Extra line breaks must die
+          $buffer =~ s/\015*\012*$//s;
+
+    # treat as one line to include the extra linebreaks we are trying to remove!
+      }
+      else {
+          syslog( 'LOG_DEBUG', 'EOF returned on read' );
+          return;
+      }
+      my $len = length $buffer;
+      if ( $len != $raw_length ) {
+          my $trim = $raw_length - $len;
+          syslog( 'LOG_DEBUG', "read_request trimmed $trim character(s) " );
+      }
+
+      syslog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
+      return $buffer;
+}
+
+# $server->get_timeout({ $type => 1, fallback => $fallback });
+#     where $type is transport | client | policy
+#
+# Centralizes all timeout logic.
+# Transport refers to login process, client to active connections.
+# Policy timeout is transaction timeout (used in ACS status message).
+#
+# Fallback is optional. If you do not pass transport, client or policy,
+# you will get fallback or hardcoded default.
+
+sub get_timeout {
+    my ( $server, $params ) = @_;
+    my $fallback = $params->{fallback} || 30;
+    my $service = $server->{service} // {};
+    my $config = $server->{config} // {};
+
+    if( $params->{transport} ||
+        ( $params->{client} && !exists $service->{client_timeout} )) {
+        # We do not allow zero values here.
+        # Note: config/timeout seems to be deprecated.
+        return $service->{timeout} || $config->{timeout} || $fallback;
+
+    } elsif( $params->{client} ) {
+        # We know that client_timeout exists now.
+        # We do allow zero values here to indicate no timeout.
+        return 0 if $service->{client_timeout} =~ /^0+$|\D/;
+        return $service->{client_timeout};
+
+    } elsif( $params->{policy} ) {
+        my $policy = $server->{policy} // {};
+        my $rv = sprintf( "%03d", $policy->{timeout} // 0 );
+        if( length($rv) != 3 ) {
+            syslog( "LOG_ERR", "Policy timeout has wrong size: '%s'", $rv );
+            return '000';
+        }
+        return $rv;
+
+    } else {
+        return $fallback;
+    }
+}
+
+=head2 get_SIPServer
+
+    my $sipServer = C4::SIP::SIPServer::get_SIPServer()
+
+@RETURNS C4::SIP::SIPServer, the current server's child-process used to handle this SIP-transaction
+
+=cut
+
+sub get_SIPServer {
+    unless($activeSIPServer) {
+        my @cc = caller(1);
+        die "$cc[3]() asks for \$activeSIPServer, but he is not defined yet";
+    }
+    return $activeSIPServer;
+}
+
+sub _set_SIPServer {
+    my ($sipServer) = @_;
+    unless (blessed($sipServer) && $sipServer->isa('C4::SIP::SIPServer')) {
+        my @cc = caller(0);
+        die "$cc[3]():> \$sipServer '$sipServer' is not a C4::SIP::SIPServer-object";
+    }
+    $activeSIPServer = $sipServer;
+    return $activeSIPServer;
+}
+
+=head2 get_logger
+
+    my $logger = C4::SIP::SIPServer::get_logger()
+
+@RETURNS Koha::Logger, the logger used to log this SIP-transaction
+
+=cut
+
+sub get_logger {
+    unless($activeLogger) {
+        my @cc = caller(1);
+        die "$cc[3]() asks for \$activeLogger, but he is not defined yet";
+    }
+    return $activeLogger;
+}
+
+sub _set_logger {
+    my ($logger) = @_;
+    unless (blessed($logger) && $logger->isa('Koha::Logger')) {
+        my @cc = caller(0);
+        die "$cc[3]():> \$logger '$logger' is not a Koha::Logger-object";
+    }
+    $activeLogger = $logger;
+    return $activeLogger;
 }
 
 1;
+
 __END__