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