C4/SIP/SIPServer.pm

   1 #!/usr/bin/perl
   2 package C4::SIP::SIPServer;
   3
   4 use strict;
   5 use warnings;
   6 use FindBin qw($Bin);
   7 use lib "$Bin";
   8 use Net::Server::PreFork;
   9 use IO::Socket::INET;
  10 use Socket qw(:DEFAULT :crlf);
  11 use Scalar::Util qw(blessed);
  12 require UNIVERSAL::require;
  13
  14 use C4::Context;
  15 use C4::SIP::Sip qw(syslog);
  16 use C4::SIP::Sip::Constants qw(:all);
  17 use C4::SIP::Sip::Configuration;
  18 use C4::SIP::Sip::Checksum qw(checksum verify_cksum);
  19 use C4::SIP::Sip::MsgType qw( handle login_core );
  20 use Koha::Caches;
  21
  22 use Koha::Logger;
  23 use C4::SIP::Trapper;
  24 tie *STDERR, "C4::SIP::Trapper";
  25
  26 use base qw(Net::Server::PreFork);
  27
  28 use constant LOG_SIP => "local6"; # Local alias for the logging facility
  29
  30 #
  31 # Main  # not really, since package SIPServer
  32 #
  33 # FIXME: Is this a module or a script?
  34 # A script with no MAIN namespace?
  35 # A module that takes command line args?
  36
  37 # Set interface to 'sip'
  38 C4::Context->interface('sip');
  39
  40 my %transports = (
  41     RAW    => \&raw_transport,
  42     telnet => \&telnet_transport,
  43 );
  44
  45 #
  46 # Read configuration
  47 #
  48 my $config = C4::SIP::Sip::Configuration->new( $ARGV[0] );
  49 my @parms;
  50
  51 #
  52 # Ports to bind
  53 #
  54 foreach my $svc (keys %{$config->{listeners}}) {
  55     push @parms, "port=" . $svc;
  56 }
  57
  58 #
  59 # Logging
  60 #
  61 # Log lines look like this:
  62 # Jun 16 21:21:31 server08 steve_sip[19305]: ILS::Transaction::Checkout performing checkout...
  63 # [  TIMESTAMP  ] [ HOST ] [ IDENT ]  PID  : Message...
  64 #
  65 # The IDENT is determined by config file 'server-params' arguments
  66
  67
  68 #
  69 # Server Management: set parameters for the Net::Server::PreFork
  70 # module.  The module silently ignores parameters that it doesn't
  71 # recognize, and complains about invalid values for parameters
  72 # that it does.
  73 #
  74 if (defined($config->{'server-params'})) {
  75     while (my ($key, $val) = each %{$config->{'server-params'}}) {
  76                 push @parms, $key . '=' . $val;
  77     }
  78 }
  79
  80
  81 #
  82 # This is the main event.
  83 __PACKAGE__ ->run(@parms);
  84
  85 #
  86 # Child
  87 #
  88
  89 my $activeSIPServer;
  90 my $activeLogger;
  91
  92 # process_request is the callback used by Net::Server to handle
  93 # an incoming connection request.
  94
  95 sub process_request {
  96     my $self = shift;
  97     my $service;
  98     my ($sockaddr, $port, $proto);
  99     my $transport;
 100
 101     $self->{config} = $config;
 102
 103     # Flushing L1 to make sure the request will be processed using the correct data
 104     Koha::Caches->flush_L1_caches();
 105
 106     $self->{account} = undef;  # Clear out the account from the last request, it may be different
 107     $self->{logger} = _set_logger( Koha::Logger->get( { interface => 'sip' } ) );
 108
 109     # Flush previous MDCs to prevent accidentally leaking incorrect MDC-entries
 110     Log::Log4perl::MDC->put( "accountid", undef );
 111     Log::Log4perl::MDC->put( "peeraddr",  undef );
 112
 113     my $sockname = getsockname(STDIN);
 114
 115     # Check if socket connection is IPv6 before resolving address
 116     my $family = Socket::sockaddr_family($sockname);
 117     if ($family == AF_INET6) {
 118       ($port, $sockaddr) = sockaddr_in6($sockname);
 119       $sockaddr = Socket::inet_ntop(AF_INET6, $sockaddr);
 120     } else {
 121       ($port, $sockaddr) = sockaddr_in($sockname);
 122       $sockaddr = inet_ntoa($sockaddr);
 123     }
 124     $proto = $self->{server}->{client}->NS_proto();
 125
 126     $self->{service} = $config->find_service($sockaddr, $port, $proto);
 127
 128     if (!defined($self->{service})) {
 129                 syslog("LOG_ERR", "process_request: Unknown recognized server connection: %s:%s/%s", $sockaddr, $port, $proto);
 130                 die "process_request: Bad server connection";
 131     }
 132
 133     $transport = $transports{$self->{service}->{transport}};
 134
 135     if (!defined($transport)) {
 136                 syslog("LOG_WARNING", "Unknown transport '%s', dropping", $service->{transport});
 137                 return;
 138     } else {
 139                 &$transport($self);
 140     }
 141     return;
 142 }
 143
 144 #
 145 # Transports
 146 #
 147
 148 sub raw_transport {
 149     my $self = shift;
 150     my $input;
 151     my $service = $self->{service};
 152     # If using Net::Server::PreFork you may already have account set from a previous session
 153     # Ensure you dont
 154     if ($self->{account}) {
 155         delete $self->{account};
 156     }
 157
 158     # Timeout the while loop if we get stuck in it
 159     # In practice it should only iterate once but be prepared
 160     local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };
 161     my $timeout = $self->get_timeout({ transport => 1 });
 162     syslog('LOG_DEBUG', "raw_transport: timeout is $timeout");
 163     alarm $timeout;
 164     while (!$self->{account}) {
 165         $input = read_request();
 166         if (!$input) {
 167             # EOF on the socket
 168             syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
 169             return;
 170         }
 171         $input =~ s/[\r\n]+$//sm; # Strip off trailing line terminator(s)
 172         my $reg = qr/^${\(LOGIN)}/;
 173         last if $input !~ $reg ||
 174             C4::SIP::Sip::MsgType::handle($input, $self, LOGIN);
 175     }
 176     alarm 0;
 177
 178     $self->{logger} = _set_logger(
 179         Koha::Logger->get(
 180             {
 181                 interface => 'sip',
 182                 category  => $self->{account}->{id}, # Add id to namespace
 183             }
 184         )
 185     );
 186
 187     # Set MDCs after properly authenticating
 188     Log::Log4perl::MDC->put( "accountid", $self->{account}->{id} );
 189     Log::Log4perl::MDC->put( "peeraddr",  $self->{server}->{peeraddr} );
 190
 191     syslog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'",
 192         $self->{account}->{id},
 193         $self->{account}->{institution});
 194     if (! $self->{account}->{id}) {
 195         syslog("LOG_ERR","Login failed shutting down");
 196         return;
 197     }
 198
 199     $self->sip_protocol_loop();
 200     syslog("LOG_INFO", "raw_transport: shutting down");
 201     return;
 202 }
 203
 204 sub get_clean_string {
 205         my $string = shift;
 206         if (defined $string) {
 207                 syslog("LOG_DEBUG", "get_clean_string  pre-clean(length %s): %s", length($string), $string);
 208                 chomp($string);
 209                 $string =~ s/^[^A-z0-9]+//;
 210                 $string =~ s/[^A-z0-9]+$//;
 211                 syslog("LOG_DEBUG", "get_clean_string post-clean(length %s): %s", length($string), $string);
 212         } else {
 213                 syslog("LOG_INFO", "get_clean_string called on undefined");
 214         }
 215         return $string;
 216 }
 217
 218 sub get_clean_input {
 219         local $/ = "\012";
 220         my $in = <STDIN>;
 221         $in = get_clean_string($in);
 222         while (my $extra = <STDIN>){
 223                 syslog("LOG_ERR", "get_clean_input got extra lines: %s", $extra);
 224         }
 225         return $in;
 226 }
 227
 228 sub telnet_transport {
 229     my $self = shift;
 230     my ($uid, $pwd);
 231     my $strikes = 3;
 232     my $account = undef;
 233     my $input;
 234     my $config  = $self->{config};
 235     my $timeout = $self->get_timeout({ transport => 1 });
 236     syslog("LOG_DEBUG", "telnet_transport: timeout is $timeout");
 237
 238     eval {
 239         local $SIG{ALRM} = sub { die "telnet_transport: Timed Out ($timeout seconds)!\n"; };
 240         local $| = 1;                   # Unbuffered output
 241         $/ = "\015";            # Internet Record Separator (lax version)
 242     # Until the terminal has logged in, we don't trust it
 243     # so use a timeout to protect ourselves from hanging.
 244
 245         while ($strikes--) {
 246             print "login: ";
 247                 alarm $timeout;
 248                 # $uid = &get_clean_input;
 249                 $uid = <STDIN>;
 250             print "password: ";
 251             # $pwd = &get_clean_input || '';
 252                 $pwd = <STDIN>;
 253                 alarm 0;
 254
 255                 syslog("LOG_DEBUG", "telnet_transport 1: uid length %s, pwd length %s", length($uid), length($pwd));
 256                 $uid = get_clean_string ($uid);
 257                 $pwd = get_clean_string ($pwd);
 258                 syslog("LOG_DEBUG", "telnet_transport 2: uid length %s, pwd length %s", length($uid), length($pwd));
 259
 260             if (exists ($config->{accounts}->{$uid})
 261                 && ($pwd eq $config->{accounts}->{$uid}->{password})) {
 262                         $account = $config->{accounts}->{$uid};
 263                         if ( C4::SIP::Sip::MsgType::login_core($self,$uid,$pwd) ) {
 264                 last;
 265             }
 266             }
 267                 syslog("LOG_WARNING", "Invalid login attempt: '%s'", ($uid||''));
 268                 print("Invalid login$CRLF");
 269         }
 270     }; # End of eval
 271
 272     if ($@) {
 273                 syslog("LOG_ERR", "telnet_transport: Login timed out");
 274                 die "Telnet Login Timed out";
 275     } elsif (!defined($account)) {
 276                 syslog("LOG_ERR", "telnet_transport: Login Failed");
 277                 die "Login Failure";
 278     } else {
 279                 print "Login OK.  Initiating SIP$CRLF";
 280     }
 281
 282     $self->{account} = $account;
 283     syslog("LOG_DEBUG", "telnet_transport: uname/inst: '%s/%s'", $account->{id}, $account->{institution});
 284     $self->sip_protocol_loop();
 285     syslog("LOG_INFO", "telnet_transport: shutting down");
 286     return;
 287 }
 288
 289 #
 290 # The terminal has logged in, using either the SIP login process
 291 # over a raw socket, or via the pseudo-unix login provided by the
 292 # telnet transport.  From that point on, both the raw and the telnet
 293 # processes are the same:
 294 sub sip_protocol_loop {
 295     my $self = shift;
 296     my $service = $self->{service};
 297     my $config  = $self->{config};
 298     my $timeout = $self->get_timeout({ client => 1 });
 299
 300     # The spec says the first message will be:
 301     #     SIP v1: SC_STATUS
 302     #     SIP v2: LOGIN (or SC_STATUS via telnet?)
 303     # But it might be SC_REQUEST_RESEND.  As long as we get
 304     # SC_REQUEST_RESEND, we keep waiting.
 305
 306     # Comprise reports that no other ILS actually enforces this
 307     # constraint, so we'll relax about it too.
 308     # Using the SIP "raw" login process, rather than telnet,
 309     # requires the LOGIN message and forces SIP 2.00.  In that
 310     # case, the LOGIN message has already been processed (above).
 311
 312     # In short, we'll take any valid message here.
 313     eval {
 314         local $SIG{ALRM} = sub {
 315             syslog( 'LOG_DEBUG', 'Inactive: timed out' );
 316             die "Timed Out!\n";
 317         };
 318         my $previous_alarm = alarm($timeout);
 319
 320         while ( my $inputbuf = read_request() ) {
 321             if ( !defined $inputbuf ) {
 322                 return;    #EOF
 323             }
 324             alarm($timeout);
 325
 326             unless ($inputbuf) {
 327                 syslog( "LOG_ERR", "sip_protocol_loop: empty input skipped" );
 328                 print("96$CR");
 329                 next;
 330             }
 331
 332             my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );
 333             if ( !$status ) {
 334                 syslog(
 335                     "LOG_ERR",
 336                     "sip_protocol_loop: failed to handle %s",
 337                     substr( $inputbuf, 0, 2 )
 338                 );
 339             }
 340             next if $status eq REQUEST_ACS_RESEND;
 341         }
 342         alarm($previous_alarm);
 343         return;
 344     };
 345     if ( $@ =~ m/timed out/i ) {
 346         return;
 347     }
 348     return;
 349 }
 350
 351 sub read_request {
 352       my $raw_length;
 353       local $/ = "\015";
 354
 355     # proper SPEC: (octal) \015 = (hex) x0D = (dec) 13 = (ascii) carriage return
 356       my $buffer = <STDIN>;
 357       if ( defined $buffer ) {
 358           STDIN->flush();    # clear an extra linefeed
 359           chomp $buffer;
 360           $raw_length = length $buffer;
 361           $buffer =~ s/^\s*[^A-z0-9]+//s;
 362 # Every line must start with a "real" character.  Not whitespace, control chars, etc.
 363           $buffer =~ s/[^A-z0-9]+$//s;
 364
 365 # Same for the end.  Note this catches the problem some clients have sending empty fields at the end, like |||
 366           $buffer =~ s/\015?\012//g;    # Extra line breaks must die
 367           $buffer =~ s/\015?\012//s;    # Extra line breaks must die
 368           $buffer =~ s/\015*\012*$//s;
 369
 370     # treat as one line to include the extra linebreaks we are trying to remove!
 371       }
 372       else {
 373           syslog( 'LOG_DEBUG', 'EOF returned on read' );
 374           return;
 375       }
 376       my $len = length $buffer;
 377       if ( $len != $raw_length ) {
 378           my $trim = $raw_length - $len;
 379           syslog( 'LOG_DEBUG', "read_request trimmed $trim character(s) " );
 380       }
 381
 382       syslog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
 383       return $buffer;
 384 }
 385
 386 # $server->get_timeout({ $type => 1, fallback => $fallback });
 387 #     where $type is transport | client | policy
 388 #
 389 # Centralizes all timeout logic.
 390 # Transport refers to login process, client to active connections.
 391 # Policy timeout is transaction timeout (used in ACS status message).
 392 #
 393 # Fallback is optional. If you do not pass transport, client or policy,
 394 # you will get fallback or hardcoded default.
 395
 396 sub get_timeout {
 397     my ( $server, $params ) = @_;
 398     my $fallback = $params->{fallback} || 30;
 399     my $service = $server->{service} // {};
 400     my $config = $server->{config} // {};
 401
 402     if( $params->{transport} ||
 403         ( $params->{client} && !exists $service->{client_timeout} )) {
 404         # We do not allow zero values here.
 405         # Note: config/timeout seems to be deprecated.
 406         return $service->{timeout} || $config->{timeout} || $fallback;
 407
 408     } elsif( $params->{client} ) {
 409         # We know that client_timeout exists now.
 410         # We do allow zero values here to indicate no timeout.
 411         return 0 if $service->{client_timeout} =~ /^0+$|\D/;
 412         return $service->{client_timeout};
 413
 414     } elsif( $params->{policy} ) {
 415         my $policy = $server->{policy} // {};
 416         my $rv = sprintf( "%03d", $policy->{timeout} // 0 );
 417         if( length($rv) != 3 ) {
 418             syslog( "LOG_ERR", "Policy timeout has wrong size: '%s'", $rv );
 419             return '000';
 420         }
 421         return $rv;
 422
 423     } else {
 424         return $fallback;
 425     }
 426 }
 427
 428 =head2 get_SIPServer
 429
 430     my $sipServer = C4::SIP::SIPServer::get_SIPServer()
 431
 432 @RETURNS C4::SIP::SIPServer, the current server's child-process used to handle this SIP-transaction
 433
 434 =cut
 435
 436 sub get_SIPServer {
 437     unless($activeSIPServer) {
 438         my @cc = caller(1);
 439         die "$cc[3]() asks for \$activeSIPServer, but he is not defined yet";
 440     }
 441     return $activeSIPServer;
 442 }
 443
 444 sub _set_SIPServer {
 445     my ($sipServer) = @_;
 446     unless (blessed($sipServer) && $sipServer->isa('C4::SIP::SIPServer')) {
 447         my @cc = caller(0);
 448         die "$cc[3]():> \$sipServer '$sipServer' is not a C4::SIP::SIPServer-object";
 449     }
 450     $activeSIPServer = $sipServer;
 451     return $activeSIPServer;
 452 }
 453
 454 =head2 get_logger
 455
 456     my $logger = C4::SIP::SIPServer::get_logger()
 457
 458 @RETURNS Koha::Logger, the logger used to log this SIP-transaction
 459
 460 =cut
 461
 462 sub get_logger {
 463     unless($activeLogger) {
 464         my @cc = caller(1);
 465         die "$cc[3]() asks for \$activeLogger, but he is not defined yet";
 466     }
 467     return $activeLogger;
 468 }
 469
 470 sub _set_logger {
 471     my ($logger) = @_;
 472     unless (blessed($logger) && $logger->isa('Koha::Logger')) {
 473         my @cc = caller(0);
 474         die "$cc[3]():> \$logger '$logger' is not a Koha::Logger-object";
 475     }
 476     $activeLogger = $logger;
 477     return $activeLogger;
 478 }
 479
 480 1;
 481
 482 __END__