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