View | Details | Raw Unified | Return to bug 15253
Collapse All | Expand All

(-)a/C4/SIP/ILS.pm (+9 lines)
Lines 47-52 sub new { Link Here
47
    my $type = ref($class) || $class;
47
    my $type = ref($class) || $class;
48
    my $self = {};
48
    my $self = {};
49
	$debug and warn "new ILS: INSTITUTION: " . Dumper($institution);
49
	$debug and warn "new ILS: INSTITUTION: " . Dumper($institution);
50
    C4::SIP::SIPServer::get_logger()->debug("new ILS $institution->{id}");
50
    syslog("LOG_DEBUG", "new ILS '%s'", $institution->{id});
51
    syslog("LOG_DEBUG", "new ILS '%s'", $institution->{id});
51
    $self->{institution} = $institution;
52
    $self->{institution} = $institution;
52
    return bless $self, $type;
53
    return bless $self, $type;
Lines 82-87 sub supports { Link Here
82
sub check_inst_id {
83
sub check_inst_id {
83
    my ($self, $id, $whence) = @_;
84
    my ($self, $id, $whence) = @_;
84
    if ($id ne $self->{institution}->{id}) {
85
    if ($id ne $self->{institution}->{id}) {
86
        C4::SIP::SIPServer::get_logger()->warn("$whence: received institution '$id', expected '$self->{institution}->{id}'");
85
        syslog("LOG_WARNING", "%s: received institution '%s', expected '%s'", $whence, $id, $self->{institution}->{id});
87
        syslog("LOG_WARNING", "%s: received institution '%s', expected '%s'", $whence, $id, $self->{institution}->{id});
86
        # Just an FYI check, we don't expect the user to change location from that in SIPconfig.xml
88
        # Just an FYI check, we don't expect the user to change location from that in SIPconfig.xml
87
    }
89
    }
Lines 173-178 sub checkout { Link Here
173
            );
175
            );
174
        }
176
        }
175
        else {
177
        else {
178
            C4::SIP::SIPServer::get_logger()->debug("ILS::Checkout: patron $patron_id has checked out " . join(', ', @{$patron->{items}}) );
176
            syslog( "LOG_ERR", "ILS::Checkout Issue failed" );
179
            syslog( "LOG_ERR", "ILS::Checkout Issue failed" );
177
        }
180
        }
178
    }
181
    }
Lines 217-226 sub checkin { Link Here
217
    # It's ok to check it in if it exists, and if it was checked out
220
    # It's ok to check it in if it exists, and if it was checked out
218
    # or it was not checked out but the checked_in_ok flag was set
221
    # or it was not checked out but the checked_in_ok flag was set
219
    $circ->ok( ( $checked_in_ok && $item ) || ( $item && $item->{patron} ) );
222
    $circ->ok( ( $checked_in_ok && $item ) || ( $item && $item->{patron} ) );
223
    C4::SIP::SIPServer::get_logger()->debug("C4::SIP::ILS::checkin - using checked_in_ok") if $checked_in_ok;
220
    syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - using checked_in_ok") if $checked_in_ok;
224
    syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - using checked_in_ok") if $checked_in_ok;
221
225
222
    if ( !defined( $item->{patron} ) ) {
226
    if ( !defined( $item->{patron} ) ) {
223
        $circ->screen_msg("Item not checked out") unless $checked_in_ok;
227
        $circ->screen_msg("Item not checked out") unless $checked_in_ok;
228
        C4::SIP::SIPServer::get_logger()->debug("C4::SIP::ILS::checkin - item not checked out");
224
	syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - item not checked out");
229
	syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - item not checked out");
225
    }
230
    }
226
    else {
231
    else {
Lines 444-452 sub renew { Link Here
444
		my $count = scalar @{$patron->{items}};
449
		my $count = scalar @{$patron->{items}};
445
		foreach my $i (@{$patron->{items}}) {
450
		foreach my $i (@{$patron->{items}}) {
446
            unless (defined $i->{barcode}) {    # FIXME: using data instead of objects may violate the abstraction layer
451
            unless (defined $i->{barcode}) {    # FIXME: using data instead of objects may violate the abstraction layer
452
                C4::SIP::SIPServer::get_logger()->error("No barcode for item " . $j+1 . " of $count: $item_id");
447
                syslog("LOG_ERR", "No barcode for item %s of %s: $item_id", $j+1, $count);
453
                syslog("LOG_ERR", "No barcode for item %s of %s: $item_id", $j+1, $count);
448
                next;
454
                next;
449
            }
455
            }
456
            C4::SIP::SIPServer::get_logger()->debug("checking item ". $j + 1 . " of $count: $item_id vs. $i->{barcode} " );
450
            syslog("LOG_DEBUG", "checking item %s of %s: $item_id vs. %s", ++$j, $count, $i->{barcode});
457
            syslog("LOG_DEBUG", "checking item %s of %s: $item_id vs. %s", ++$j, $count, $i->{barcode});
451
            if ($i->{barcode} eq $item_id) {
458
            if ($i->{barcode} eq $item_id) {
452
				# We have it checked out
459
				# We have it checked out
Lines 481-488 sub renew_all { Link Here
481
488
482
    $trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));
489
    $trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));
483
    if (defined $patron) {
490
    if (defined $patron) {
491
        C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: patron '$patron->name': renew_ok: $patron->renew_ok");
484
        syslog("LOG_DEBUG", "ILS::renew_all: patron '%s': renew_ok: %s", $patron->name, $patron->renew_ok);
492
        syslog("LOG_DEBUG", "ILS::renew_all: patron '%s': renew_ok: %s", $patron->name, $patron->renew_ok);
485
    } else {
493
    } else {
494
        C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: Invalid patron id: '$patron_id'");
486
        syslog("LOG_DEBUG", "ILS::renew_all: Invalid patron id: '%s'", $patron_id);
495
        syslog("LOG_DEBUG", "ILS::renew_all: Invalid patron id: '%s'", $patron_id);
487
    }
496
    }
488
497
(-)a/C4/SIP/ILS/Item.pm (-5 / +11 lines)
Lines 13-18 use Sys::Syslog qw(syslog); Link Here
13
use Carp;
13
use Carp;
14
use Template;
14
use Template;
15
15
16
use C4::SIP::SIPServer;
16
use C4::SIP::ILS::Transaction;
17
use C4::SIP::ILS::Transaction;
17
18
18
use C4::Debug;
19
use C4::Debug;
Lines 71-84 use Koha::Items; Link Here
71
=cut
72
=cut
72
73
73
sub new {
74
sub new {
74
	my ($class, $item_id) = @_;
75
    my ($class, $item_id) = @_;
75
	my $type = ref($class) || $class;
76
    my $type = ref($class) || $class;
76
    my $item = Koha::Items->find( { barcode => $item_id } );
77
    my $item = Koha::Items->find( { barcode => $item_id } );
78
77
    unless ( $item ) {
79
    unless ( $item ) {
78
		syslog("LOG_DEBUG", "new ILS::Item('%s'): not found", $item_id);
80
        C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): not found");
79
		warn "new ILS::Item($item_id) : No item '$item_id'.";
81
        syslog("LOG_DEBUG", "new ILS::Item('%s'): not found", $item_id);
82
        warn "new ILS::Item($item_id) : No item '$item_id'.";
80
        return;
83
        return;
81
	}
84
    }
85
82
    my $self = $item->unblessed;
86
    my $self = $item->unblessed;
83
    $self->{      'id'       } = $item->barcode;     # to SIP, the barcode IS the id.
87
    $self->{      'id'       } = $item->barcode;     # to SIP, the barcode IS the id.
84
    $self->{permanent_location}= $item->homebranch;
88
    $self->{permanent_location}= $item->homebranch;
Lines 103-108 sub new { Link Here
103
    $self->{pending_queue} = [( grep {(! defined $_->{found}) or  $_->{found} ne 'W' } @{$self->{hold_queue}} )];
107
    $self->{pending_queue} = [( grep {(! defined $_->{found}) or  $_->{found} ne 'W' } @{$self->{hold_queue}} )];
104
	bless $self, $type;
108
	bless $self, $type;
105
109
110
    C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): found with title '$self->{title}'");
106
    syslog("LOG_DEBUG", "new ILS::Item('%s'): found with title '%s'",
111
    syslog("LOG_DEBUG", "new ILS::Item('%s'): found with title '%s'",
107
	   $item_id, $self->{title});
112
	   $item_id, $self->{title});
108
113
Lines 177-182 sub hold_patron_name { Link Here
177
182
178
    my $holder = Koha::Patrons->find( $borrowernumber );
183
    my $holder = Koha::Patrons->find( $borrowernumber );
179
    unless ($holder) {
184
    unless ($holder) {
185
        C4::SIP::SIPServer::get_logger()->debug("While checking hold, failed to retrieve the patron with borrowernumber '$borrowernumber'");
180
        syslog("LOG_ERR", "While checking hold, failed to retrieve the patron with borrowernumber '$borrowernumber'");
186
        syslog("LOG_ERR", "While checking hold, failed to retrieve the patron with borrowernumber '$borrowernumber'");
181
        return;
187
        return;
182
    }
188
    }
(-)a/C4/SIP/ILS/Patron.pm (+4 lines)
Lines 36-41 sub new { Link Here
36
      or Koha::Patrons->find( { userid => $patron_id } );
36
      or Koha::Patrons->find( { userid => $patron_id } );
37
    $debug and warn "new Patron: " . Dumper($kp->unblessed) if $kp;
37
    $debug and warn "new Patron: " . Dumper($kp->unblessed) if $kp;
38
    unless ($kp) {
38
    unless ($kp) {
39
        C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): no such patron");
39
        syslog("LOG_DEBUG", "new ILS::Patron(%s): no such patron", $patron_id);
40
        syslog("LOG_DEBUG", "new ILS::Patron(%s): no such patron", $patron_id);
40
        return;
41
        return;
41
    }
42
    }
Lines 123-128 sub new { Link Here
123
    $ilspatron{items} = GetPendingIssues($kp->{borrowernumber});
124
    $ilspatron{items} = GetPendingIssues($kp->{borrowernumber});
124
    $self = \%ilspatron;
125
    $self = \%ilspatron;
125
    $debug and warn Dumper($self);
126
    $debug and warn Dumper($self);
127
    C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): found patron '$self->{id}'");
126
    syslog("LOG_DEBUG", "new ILS::Patron(%s): found patron '%s'", $patron_id,$self->{id});
128
    syslog("LOG_DEBUG", "new ILS::Patron(%s): found patron '%s'", $patron_id,$self->{id});
127
    bless $self, $type;
129
    bless $self, $type;
128
    return $self;
130
    return $self;
Lines 378-383 sub enable { Link Here
378
    foreach my $field ('charge_ok', 'renew_ok', 'recall_ok', 'hold_ok', 'inet') {
380
    foreach my $field ('charge_ok', 'renew_ok', 'recall_ok', 'hold_ok', 'inet') {
379
        $self->{$field} = 1;
381
        $self->{$field} = 1;
380
    }
382
    }
383
    C4::SIP::SIPServer::get_logger()->debug("Patron($self->{id})->enable: charge: $self->{charge_ok}, ".
384
                                            "renew:$self->{renew_ok}, recall:$self->{recall_ok}, hold:$self->{hold_ok}");
381
    syslog("LOG_DEBUG", "Patron(%s)->enable: charge: %s, renew:%s, recall:%s, hold:%s",
385
    syslog("LOG_DEBUG", "Patron(%s)->enable: charge: %s, renew:%s, recall:%s, hold:%s",
382
       $self->{id}, $self->{charge_ok}, $self->{renew_ok},
386
       $self->{id}, $self->{charge_ok}, $self->{renew_ok},
383
       $self->{recall_ok}, $self->{hold_ok});
387
       $self->{recall_ok}, $self->{hold_ok});
(-)a/C4/SIP/ILS/Transaction/Checkout.pm (+2 lines)
Lines 47-52 sub new { Link Here
47
47
48
sub do_checkout {
48
sub do_checkout {
49
	my $self = shift;
49
	my $self = shift;
50
	C4::SIP::SIPServer::get_logger()->debug("ILS::Transaction::Checkout performing checkout...");
50
	syslog('LOG_DEBUG', "ILS::Transaction::Checkout performing checkout...");
51
	syslog('LOG_DEBUG', "ILS::Transaction::Checkout performing checkout...");
51
	my $pending        = $self->{item}->pending_queue;
52
	my $pending        = $self->{item}->pending_queue;
52
	my $shelf          = $self->{item}->hold_shelf;
53
	my $shelf          = $self->{item}->hold_shelf;
Lines 98-103 sub do_checkout { Link Here
98
            } else {
99
            } else {
99
                $self->screen_msg($needsconfirmation->{$confirmation});
100
                $self->screen_msg($needsconfirmation->{$confirmation});
100
                $noerror = 0;
101
                $noerror = 0;
102
                C4::SIP::SIPServer::get_logger()->debug("Blocking checkout Reason:$confirmation");
101
                syslog('LOG_DEBUG', "Blocking checkout Reason:$confirmation");
103
                syslog('LOG_DEBUG', "Blocking checkout Reason:$confirmation");
102
            }
104
            }
103
        }
105
        }
(-)a/C4/SIP/ILS/Transaction/RenewAll.pm (+1 lines)
Lines 42-47 sub do_renew_all { Link Here
42
        my $item_id = $itemx->{barcode};
42
        my $item_id = $itemx->{barcode};
43
        my $item    = C4::SIP::ILS::Item->new($item_id);
43
        my $item    = C4::SIP::ILS::Item->new($item_id);
44
        if ( !defined($item) ) {
44
        if ( !defined($item) ) {
45
            C4::SIP::SIPServer::get_logger()->debug("renew_all: Invalid item id '$item_id' associated with patron '$patron->id'");
45
            syslog(
46
            syslog(
46
                'LOG_WARNING',
47
                'LOG_WARNING',
47
                q|renew_all: Invalid item id '%s' associated with patron '%s'|,
48
                q|renew_all: Invalid item id '%s' associated with patron '%s'|,
(-)a/C4/SIP/SIPServer.pm (-1 / +97 lines)
Lines 9-14 use Sys::Syslog qw(syslog); Link Here
9
use Net::Server::PreFork;
9
use Net::Server::PreFork;
10
use IO::Socket::INET;
10
use IO::Socket::INET;
11
use Socket qw(:DEFAULT :crlf);
11
use Socket qw(:DEFAULT :crlf);
12
use Scalar::Util qw(blessed);
12
require UNIVERSAL::require;
13
require UNIVERSAL::require;
13
14
14
use C4::SIP::Sip::Constants qw(:all);
15
use C4::SIP::Sip::Constants qw(:all);
Lines 16-21 use C4::SIP::Sip::Configuration; Link Here
16
use C4::SIP::Sip::Checksum qw(checksum verify_cksum);
17
use C4::SIP::Sip::Checksum qw(checksum verify_cksum);
17
use C4::SIP::Sip::MsgType qw( handle login_core );
18
use C4::SIP::Sip::MsgType qw( handle login_core );
18
19
20
use Koha::Logger;
21
19
use base qw(Net::Server::PreFork);
22
use base qw(Net::Server::PreFork);
20
23
21
use constant LOG_SIP => "local6"; # Local alias for the logging facility
24
use constant LOG_SIP => "local6"; # Local alias for the logging facility
Lines 76-92 __PACKAGE__ ->run(@parms); Link Here
76
# Child
79
# Child
77
#
80
#
78
81
82
my $activeSIPServer;
83
my $activeLogger;
84
79
# process_request is the callback used by Net::Server to handle
85
# process_request is the callback used by Net::Server to handle
80
# an incoming connection request.
86
# an incoming connection request.
81
87
82
sub process_request {
88
sub process_request {
83
    my $self = shift;
89
    my $self = _set_SIPServer(shift);
84
    my $service;
90
    my $service;
85
    my ($sockaddr, $port, $proto);
91
    my ($sockaddr, $port, $proto);
86
    my $transport;
92
    my $transport;
87
93
88
    $self->{config} = $config;
94
    $self->{config} = $config;
89
95
96
    $self->{account} = undef; # Clear out the account from the last request, it may be different
97
    $self->{logger} = _set_logger( Koha::Logger->get({ interface => 'sip' }) );
98
    #Flush previous MDCs to prevent accidentally leaking incorrect MDC-entries
99
    Log::Log4perl::MDC->put("accountid", undef);
100
    Log::Log4perl::MDC->put("peeraddr", undef);
101
90
    my $sockname = getsockname(STDIN);
102
    my $sockname = getsockname(STDIN);
91
103
92
    # Check if socket connection is IPv6 before resolving address
104
    # Check if socket connection is IPv6 before resolving address
Lines 103-108 sub process_request { Link Here
103
    $self->{service} = $config->find_service($sockaddr, $port, $proto);
115
    $self->{service} = $config->find_service($sockaddr, $port, $proto);
104
116
105
    if (!defined($self->{service})) {
117
    if (!defined($self->{service})) {
118
                C4::SIP::SIPServer::get_logger()->error("process_request: Unknown recognized server connection: $sockaddr:$port/$proto");
106
		syslog("LOG_ERR", "process_request: Unknown recognized server connection: %s:%s/%s", $sockaddr, $port, $proto);
119
		syslog("LOG_ERR", "process_request: Unknown recognized server connection: %s:%s/%s", $sockaddr, $port, $proto);
107
		die "process_request: Bad server connection";
120
		die "process_request: Bad server connection";
108
    }
121
    }
Lines 110-115 sub process_request { Link Here
110
    $transport = $transports{$self->{service}->{transport}};
123
    $transport = $transports{$self->{service}->{transport}};
111
124
112
    if (!defined($transport)) {
125
    if (!defined($transport)) {
126
                C4::SIP::SIPServer::get_logger()->warn("Unknown transport '$service->{transport}', dropping");
113
		syslog("LOG_WARNING", "Unknown transport '%s', dropping", $service->{transport});
127
		syslog("LOG_WARNING", "Unknown transport '%s', dropping", $service->{transport});
114
		return;
128
		return;
115
    } else {
129
    } else {
Lines 136-147 sub raw_transport { Link Here
136
    # In practice it should only iterate once but be prepared
150
    # In practice it should only iterate once but be prepared
137
    local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };
151
    local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };
138
    my $timeout = $self->get_timeout({ transport => 1 });
152
    my $timeout = $self->get_timeout({ transport => 1 });
153
    C4::SIP::SIPServer::get_logger()->debug("raw_transport: timeout is $service->{timeout}");
139
    syslog('LOG_DEBUG', "raw_transport: timeout is $timeout");
154
    syslog('LOG_DEBUG', "raw_transport: timeout is $timeout");
140
    alarm $timeout;
155
    alarm $timeout;
141
    while (!$self->{account}) {
156
    while (!$self->{account}) {
142
        $input = read_request();
157
        $input = read_request();
143
        if (!$input) {
158
        if (!$input) {
144
            # EOF on the socket
159
            # EOF on the socket
160
            C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down: EOF during login");
145
            syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
161
            syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
146
            return;
162
            return;
147
        }
163
        }
Lines 152-157 sub raw_transport { Link Here
152
    }
168
    }
153
    alarm 0;
169
    alarm 0;
154
170
171
    $self->{logger} = _set_logger( Koha::Logger->get( { interface => 'sip', category => $self->{account}->{id} } ) ); # Add id to namespace
172
    #Set MDCs after properly authenticating
173
    Log::Log4perl::MDC->put("accountid", $self->{account}->{id});
174
    Log::Log4perl::MDC->put("peeraddr", $self->{server}->{peeraddr});
175
176
    C4::SIP::SIPServer::get_logger()->debug("raw_transport: uname/inst: '$self->{account}->{id}/$self->{account}->{institution}'");
155
    syslog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'",
177
    syslog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'",
156
        $self->{account}->{id},
178
        $self->{account}->{id},
157
        $self->{account}->{institution});
179
        $self->{account}->{institution});
Lines 161-166 sub raw_transport { Link Here
161
    }
183
    }
162
184
163
    $self->sip_protocol_loop();
185
    $self->sip_protocol_loop();
186
187
    C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down");
164
    syslog("LOG_INFO", "raw_transport: shutting down");
188
    syslog("LOG_INFO", "raw_transport: shutting down");
165
    return;
189
    return;
166
}
190
}
Lines 168-179 sub raw_transport { Link Here
168
sub get_clean_string {
192
sub get_clean_string {
169
	my $string = shift;
193
	my $string = shift;
170
	if (defined $string) {
194
	if (defined $string) {
195
                C4::SIP::SIPServer::get_logger()->debug("get_clean_string  pre-clean(length " . length($string) . "): $string");
171
		syslog("LOG_DEBUG", "get_clean_string  pre-clean(length %s): %s", length($string), $string);
196
		syslog("LOG_DEBUG", "get_clean_string  pre-clean(length %s): %s", length($string), $string);
172
		chomp($string);
197
		chomp($string);
173
		$string =~ s/^[^A-z0-9]+//;
198
		$string =~ s/^[^A-z0-9]+//;
174
		$string =~ s/[^A-z0-9]+$//;
199
		$string =~ s/[^A-z0-9]+$//;
200
                C4::SIP::SIPServer::get_logger()->debug("get_clean_string post-clean(length " . length($string) . "): $string)");
175
		syslog("LOG_DEBUG", "get_clean_string post-clean(length %s): %s", length($string), $string);
201
		syslog("LOG_DEBUG", "get_clean_string post-clean(length %s): %s", length($string), $string);
176
	} else {
202
	} else {
203
                C4::SIP::SIPServer::get_logger()->info("get_clean_string called on undefined");
177
		syslog("LOG_INFO", "get_clean_string called on undefined");
204
		syslog("LOG_INFO", "get_clean_string called on undefined");
178
	}
205
	}
179
	return $string;
206
	return $string;
Lines 184-189 sub get_clean_input { Link Here
184
	my $in = <STDIN>;
211
	my $in = <STDIN>;
185
	$in = get_clean_string($in);
212
	$in = get_clean_string($in);
186
	while (my $extra = <STDIN>){
213
	while (my $extra = <STDIN>){
214
                C4::SIP::SIPServer::get_logger()->error("get_clean_input got extra lines: $extra");
187
		syslog("LOG_ERR", "get_clean_input got extra lines: %s", $extra);
215
		syslog("LOG_ERR", "get_clean_input got extra lines: %s", $extra);
188
	}
216
	}
189
	return $in;
217
	return $in;
Lines 197-202 sub telnet_transport { Link Here
197
    my $input;
225
    my $input;
198
    my $config  = $self->{config};
226
    my $config  = $self->{config};
199
    my $timeout = $self->get_timeout({ transport => 1 });
227
    my $timeout = $self->get_timeout({ transport => 1 });
228
    C4::SIP::SIPServer::get_logger()->debug("telnet_transport: timeout is $timeout");
200
    syslog("LOG_DEBUG", "telnet_transport: timeout is $timeout");
229
    syslog("LOG_DEBUG", "telnet_transport: timeout is $timeout");
201
230
202
    eval {
231
    eval {
Lines 216-224 sub telnet_transport { Link Here
216
		$pwd = <STDIN>;
245
		$pwd = <STDIN>;
217
		alarm 0;
246
		alarm 0;
218
247
248
                C4::SIP::SIPServer::get_logger()->debug("telnet_transport 1: uid length " . length($uid) . ", pwd length " . length($pwd));
219
		syslog("LOG_DEBUG", "telnet_transport 1: uid length %s, pwd length %s", length($uid), length($pwd));
249
		syslog("LOG_DEBUG", "telnet_transport 1: uid length %s, pwd length %s", length($uid), length($pwd));
220
		$uid = get_clean_string ($uid);
250
		$uid = get_clean_string ($uid);
221
		$pwd = get_clean_string ($pwd);
251
		$pwd = get_clean_string ($pwd);
252
                C4::SIP::SIPServer::get_logger()->debug("telnet_transport 2: uid length " . length($uid) . ", pwd length " . length($pwd));
222
		syslog("LOG_DEBUG", "telnet_transport 2: uid length %s, pwd length %s", length($uid), length($pwd));
253
		syslog("LOG_DEBUG", "telnet_transport 2: uid length %s, pwd length %s", length($uid), length($pwd));
223
254
224
	    if (exists ($config->{accounts}->{$uid})
255
	    if (exists ($config->{accounts}->{$uid})
Lines 228-242 sub telnet_transport { Link Here
228
                last;
259
                last;
229
            }
260
            }
230
	    }
261
	    }
262
		C4::SIP::SIPServer::get_logger()->warn("Invalid login attempt: ' . ($uid||'')  . '");
231
		syslog("LOG_WARNING", "Invalid login attempt: '%s'", ($uid||''));
263
		syslog("LOG_WARNING", "Invalid login attempt: '%s'", ($uid||''));
232
		print("Invalid login$CRLF");
264
		print("Invalid login$CRLF");
233
	}
265
	}
234
    }; # End of eval
266
    }; # End of eval
235
267
236
    if ($@) {
268
    if ($@) {
269
		C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login timed out");
237
		syslog("LOG_ERR", "telnet_transport: Login timed out");
270
		syslog("LOG_ERR", "telnet_transport: Login timed out");
238
		die "Telnet Login Timed out";
271
		die "Telnet Login Timed out";
239
    } elsif (!defined($account)) {
272
    } elsif (!defined($account)) {
273
		C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login Failed");
240
		syslog("LOG_ERR", "telnet_transport: Login Failed");
274
		syslog("LOG_ERR", "telnet_transport: Login Failed");
241
		die "Login Failure";
275
		die "Login Failure";
242
    } else {
276
    } else {
Lines 244-251 sub telnet_transport { Link Here
244
    }
278
    }
245
279
246
    $self->{account} = $account;
280
    $self->{account} = $account;
281
    $self->{logger} = _set_logger( Koha::Logger->get( { interface => 'sip', category => $self->{account}->{id} } ) ); # Add id to namespace
282
    C4::SIP::SIPServer::get_logger()->debug("telnet_transport: uname/inst: '$account->{id}/$account->{institution}'");
247
    syslog("LOG_DEBUG", "telnet_transport: uname/inst: '%s/%s'", $account->{id}, $account->{institution});
283
    syslog("LOG_DEBUG", "telnet_transport: uname/inst: '%s/%s'", $account->{id}, $account->{institution});
248
    $self->sip_protocol_loop();
284
    $self->sip_protocol_loop();
285
    C4::SIP::SIPServer::get_logger()->info("telnet_transport: shutting down");
249
    syslog("LOG_INFO", "telnet_transport: shutting down");
286
    syslog("LOG_INFO", "telnet_transport: shutting down");
250
    return;
287
    return;
251
}
288
}
Lines 276-281 sub sip_protocol_loop { Link Here
276
    # In short, we'll take any valid message here.
313
    # In short, we'll take any valid message here.
277
    eval {
314
    eval {
278
        local $SIG{ALRM} = sub {
315
        local $SIG{ALRM} = sub {
316
            C4::SIP::SIPServer::get_logger()->debug("Inactive: timed out");
279
            syslog( 'LOG_DEBUG', 'Inactive: timed out' );
317
            syslog( 'LOG_DEBUG', 'Inactive: timed out' );
280
            die "Timed Out!\n";
318
            die "Timed Out!\n";
281
        };
319
        };
Lines 288-293 sub sip_protocol_loop { Link Here
288
            alarm($timeout);
326
            alarm($timeout);
289
327
290
            unless ($inputbuf) {
328
            unless ($inputbuf) {
329
                C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: empty input skipped");
291
                syslog( "LOG_ERR", "sip_protocol_loop: empty input skipped" );
330
                syslog( "LOG_ERR", "sip_protocol_loop: empty input skipped" );
292
                print("96$CR");
331
                print("96$CR");
293
                next;
332
                next;
Lines 295-300 sub sip_protocol_loop { Link Here
295
334
296
            my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );
335
            my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );
297
            if ( !$status ) {
336
            if ( !$status ) {
337
                C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: failed to handle " . substr( $inputbuf, 0, 2 ) );
298
                syslog(
338
                syslog(
299
                    "LOG_ERR",
339
                    "LOG_ERR",
300
                    "sip_protocol_loop: failed to handle %s",
340
                    "sip_protocol_loop: failed to handle %s",
Lines 334-348 sub read_request { Link Here
334
    # treat as one line to include the extra linebreaks we are trying to remove!
374
    # treat as one line to include the extra linebreaks we are trying to remove!
335
      }
375
      }
336
      else {
376
      else {
377
          C4::SIP::SIPServer::get_logger()->debug('EOF returned on read');
337
          syslog( 'LOG_DEBUG', 'EOF returned on read' );
378
          syslog( 'LOG_DEBUG', 'EOF returned on read' );
338
          return;
379
          return;
339
      }
380
      }
340
      my $len = length $buffer;
381
      my $len = length $buffer;
341
      if ( $len != $raw_length ) {
382
      if ( $len != $raw_length ) {
342
          my $trim = $raw_length - $len;
383
          my $trim = $raw_length - $len;
384
          C4::SIP::SIPServer::get_logger()->debug("read_request trimmed $trim character(s) ");
343
          syslog( 'LOG_DEBUG', "read_request trimmed $trim character(s) " );
385
          syslog( 'LOG_DEBUG', "read_request trimmed $trim character(s) " );
344
      }
386
      }
345
387
388
      C4::SIP::SIPServer::get_logger()->info("INPUT MSG: '$buffer'");
346
      syslog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
389
      syslog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
347
      return $buffer;
390
      return $buffer;
348
}
391
}
Lines 379-384 sub get_timeout { Link Here
379
        my $policy = $server->{policy} // {};
422
        my $policy = $server->{policy} // {};
380
        my $rv = sprintf( "%03d", $policy->{timeout} // 0 );
423
        my $rv = sprintf( "%03d", $policy->{timeout} // 0 );
381
        if( length($rv) != 3 ) {
424
        if( length($rv) != 3 ) {
425
            C4::SIP::SIPServer::get_logger()->error("LOG_ERR", "Policy timeout has wrong size: '$rv'");
382
            syslog( "LOG_ERR", "Policy timeout has wrong size: '%s'", $rv );
426
            syslog( "LOG_ERR", "Policy timeout has wrong size: '%s'", $rv );
383
            return '000';
427
            return '000';
384
        }
428
        }
Lines 389-394 sub get_timeout { Link Here
389
    }
433
    }
390
}
434
}
391
435
436
=head2 get_SIPServer
437
438
    my $sipServer = C4::SIP::SIPServer::get_SIPServer()
439
440
@RETURNS C4::SIP::SIPServer, the current server's child-process used to handle this SIP-transaction
441
442
=cut
443
444
sub get_SIPServer {
445
    unless($activeSIPServer) {
446
        my @cc = caller(1);
447
        die "$cc[3]() asks for \$activeSIPServer, but he is not defined yet";
448
    }
449
    return $activeSIPServer;
450
}
451
452
sub _set_SIPServer {
453
    my ($sipServer) = @_;
454
    unless (blessed($sipServer) && $sipServer->isa('C4::SIP::SIPServer')) {
455
        my @cc = caller(0);
456
        die "$cc[3]():> \$sipServer '$sipServer' is not a C4::SIP::SIPServer-object";
457
    }
458
    $activeSIPServer = $sipServer;
459
    return $activeSIPServer;
460
}
461
462
=head2 get_logger
463
464
    my $logger = C4::SIP::SIPServer::get_logger()
465
466
@RETURNS Koha::Logger, the logger used to log this SIP-transaction
467
468
=cut
469
470
sub get_logger {
471
    unless($activeLogger) {
472
        my @cc = caller(1);
473
        die "$cc[3]() asks for \$activeLogger, but he is not defined yet";
474
    }
475
    return $activeLogger;
476
}
477
478
sub _set_logger {
479
    my ($logger) = @_;
480
    unless (blessed($logger) && $logger->isa('Koha::Logger')) {
481
        my @cc = caller(0);
482
        die "$cc[3]():> \$logger '$logger' is not a Koha::Logger-object";
483
    }
484
    $activeLogger = $logger;
485
    return $activeLogger;
486
}
487
392
1;
488
1;
393
489
394
__END__
490
__END__
(-)a/C4/SIP/Sip.pm (+3 lines)
Lines 61-66 sub add_field { Link Here
61
    my ($i, $ent);
61
    my ($i, $ent);
62
62
63
    if (!defined($value)) {
63
    if (!defined($value)) {
64
        C4::SIP::SIPServer::get_logger()->debug("add_field: Undefined value being added to '$field_id'");
64
	syslog("LOG_DEBUG", "add_field: Undefined value being added to '%s'",
65
	syslog("LOG_DEBUG", "add_field: Undefined value being added to '%s'",
65
	       $field_id);
66
	       $field_id);
66
		$value = '';
67
		$value = '';
Lines 116-121 sub add_count { Link Here
116
117
117
    $count = sprintf("%04d", $count);
118
    $count = sprintf("%04d", $count);
118
    if (length($count) != 4) {
119
    if (length($count) != 4) {
120
		C4::SIP::SIPServer::get_logger()->debug("handle_patron_info: $label wrong size: '$count'");
119
		syslog("LOG_WARNING", "handle_patron_info: %s wrong size: '%s'",
121
		syslog("LOG_WARNING", "handle_patron_info: %s wrong size: '%s'",
120
	       $label, $count);
122
	       $label, $count);
121
		$count = ' ' x 4;
123
		$count = ' ' x 4;
Lines 187-192 sub write_msg { Link Here
187
    } else {
189
    } else {
188
        STDOUT->autoflush(1);
190
        STDOUT->autoflush(1);
189
        print $msg, $terminator;
191
        print $msg, $terminator;
192
        C4::SIP::SIPServer::get_logger()->info("OUTPUT MSG: '$msg'");
190
        syslog("LOG_INFO", "OUTPUT MSG: '$msg'");
193
        syslog("LOG_INFO", "OUTPUT MSG: '$msg'");
191
    }
194
    }
192
195
(-)a/C4/SIP/Sip/Configuration.pm (+1 lines)
Lines 63-68 sub find_service { Link Here
63
    my $portstr;
63
    my $portstr;
64
    foreach my $addr ( '', '*:', "$sockaddr:", "[$sockaddr]:" ) {
64
    foreach my $addr ( '', '*:', "$sockaddr:", "[$sockaddr]:" ) {
65
        $portstr = sprintf( "%s%s/%s", $addr, $port, lc $proto );
65
        $portstr = sprintf( "%s%s/%s", $addr, $port, lc $proto );
66
        C4::SIP::SIPServer::get_logger()->debug("Configuration::find_service: Trying $portstr");
66
        Sys::Syslog::syslog( "LOG_DEBUG",
67
        Sys::Syslog::syslog( "LOG_DEBUG",
67
            "Configuration::find_service: Trying $portstr" );
68
            "Configuration::find_service: Trying $portstr" );
68
        last if ( exists( ( $self->{listeners} )->{$portstr} ) );
69
        last if ( exists( ( $self->{listeners} )->{$portstr} ) );
(-)a/C4/SIP/Sip/MsgType.pm (+36 lines)
Lines 264-276 sub new { Link Here
264
        # it's using the 2.00 login process, so it must support 2.00.
264
        # it's using the 2.00 login process, so it must support 2.00.
265
        $protocol_version = 2;
265
        $protocol_version = 2;
266
    }
266
    }
267
    C4::SIP::SIPServer::get_logger()->debug("Sip::MsgType::new('$class', '".
268
                                             substr($msg, 0, 10).
269
                                            "...', '$msgtag'): seq.no '$seqno', protocol $protocol_version");
267
    syslog( "LOG_DEBUG", "Sip::MsgType::new('%s', '%s...', '%s'): seq.no '%s', protocol %s", $class, substr( $msg, 0, 10 ), $msgtag, $seqno, $protocol_version );
270
    syslog( "LOG_DEBUG", "Sip::MsgType::new('%s', '%s...', '%s'): seq.no '%s', protocol %s", $class, substr( $msg, 0, 10 ), $msgtag, $seqno, $protocol_version );
268
271
269
    # warn "SIP PROTOCOL: $protocol_version";
272
    # warn "SIP PROTOCOL: $protocol_version";
270
    if ( !exists( $handlers{$msgtag} ) ) {
273
    if ( !exists( $handlers{$msgtag} ) ) {
274
        C4::SIP::SIPServer::get_logger()->warn("new Sip::MsgType: Skipping message of unknown type '$msgtag' in '$msg'");
271
        syslog( "LOG_WARNING", "new Sip::MsgType: Skipping message of unknown type '%s' in '%s'", $msgtag, $msg );
275
        syslog( "LOG_WARNING", "new Sip::MsgType: Skipping message of unknown type '%s' in '%s'", $msgtag, $msg );
272
        return;
276
        return;
273
    } elsif ( !exists( $handlers{$msgtag}->{protocol}->{$protocol_version} ) ) {
277
    } elsif ( !exists( $handlers{$msgtag}->{protocol}->{$protocol_version} ) ) {
278
        C4::SIP::SIPServer::get_logger()->warn("new Sip::MsgType: Skipping message '$msgtag' unsupported by protocol rev. '$protocol_version'");
274
        syslog( "LOG_WARNING", "new Sip::MsgType: Skipping message '%s' unsupported by protocol rev. '%d'", $msgtag, $protocol_version );
279
        syslog( "LOG_WARNING", "new Sip::MsgType: Skipping message '%s' unsupported by protocol rev. '%d'", $msgtag, $protocol_version );
275
        return;
280
        return;
276
    }
281
    }
Lines 303-308 sub _initialize { Link Here
303
        $self->{fields}->{$field} = undef;
308
        $self->{fields}->{$field} = undef;
304
    }
309
    }
305
310
311
    C4::SIP::SIPServer::get_logger()->debug("Sip::MsgType::_initialize('$self->{name}', '$msg', '$proto->{template}', '$proto->{template_len}', ...)");
306
    syslog( "LOG_DEBUG", "Sip::MsgType::_initialize('%s', '%s', '%s', '%s', ...)", $self->{name}, $msg, $proto->{template}, $proto->{template_len} );
312
    syslog( "LOG_DEBUG", "Sip::MsgType::_initialize('%s', '%s', '%s', '%s', ...)", $self->{name}, $msg, $proto->{template}, $proto->{template_len} );
307
313
308
    $self->{fixed_fields} = [ unpack( $proto->{template}, $msg ) ];    # see http://perldoc.perl.org/5.8.8/functions/unpack.html
314
    $self->{fixed_fields} = [ unpack( $proto->{template}, $msg ) ];    # see http://perldoc.perl.org/5.8.8/functions/unpack.html
Lines 313-320 sub _initialize { Link Here
313
        $fn = substr( $field, 0, 2 );
319
        $fn = substr( $field, 0, 2 );
314
320
315
        if ( !exists( $self->{fields}->{$fn} ) ) {
321
        if ( !exists( $self->{fields}->{$fn} ) ) {
322
            C4::SIP::SIPServer::get_logger()->warn("Unsupported field '$fn' in $self->{name}, message '$msg'");
316
            syslog( "LOG_WARNING", "Unsupported field '%s' in %s message '%s'", $fn, $self->{name}, $msg );
323
            syslog( "LOG_WARNING", "Unsupported field '%s' in %s message '%s'", $fn, $self->{name}, $msg );
317
        } elsif ( defined( $self->{fields}->{$fn} ) ) {
324
        } elsif ( defined( $self->{fields}->{$fn} ) ) {
325
            C4::SIP::SIPServer::get_logger()->warn("Duplicate field '$fn' (previous value '$self->{fields}->{$fn}') in $self->{name} message '$msg'");
318
            syslog( "LOG_WARNING", "Duplicate field '%s' (previous value '%s') in %s message '%s'", $fn, $self->{fields}->{$fn}, $self->{name}, $msg );
326
            syslog( "LOG_WARNING", "Duplicate field '%s' (previous value '%s') in %s message '%s'", $fn, $self->{fields}->{$fn}, $self->{name}, $msg );
319
        } else {
327
        } else {
320
            $self->{fields}->{$fn} = substr( $field, 2 );
328
            $self->{fields}->{$fn} = substr( $field, 2 );
Lines 351-356 sub handle { Link Here
351
        $error_detection = 1;
359
        $error_detection = 1;
352
360
353
        if ( !verify_cksum($msg) ) {
361
        if ( !verify_cksum($msg) ) {
362
            C4::SIP::SIPServer::get_logger()->warn("Checksum failed on message '$msg'");
354
            syslog( "LOG_WARNING", "Checksum failed on message '%s'", $msg );
363
            syslog( "LOG_WARNING", "Checksum failed on message '%s'", $msg );
355
364
356
            # REQUEST_SC_RESEND with error detection
365
            # REQUEST_SC_RESEND with error detection
Lines 367-372 sub handle { Link Here
367
376
368
        # We received a non-ED message when ED is supposed to be active.
377
        # We received a non-ED message when ED is supposed to be active.
369
        # Warn about this problem, then process the message anyway.
378
        # Warn about this problem, then process the message anyway.
379
        C4::SIP::SIPServer::get_logger()->warn("Received message without error detection: '$msg'");
370
        syslog( "LOG_WARNING", "Received message without error detection: '%s'", $msg );
380
        syslog( "LOG_WARNING", "Received message without error detection: '%s'", $msg );
371
        $error_detection = 0;
381
        $error_detection = 0;
372
        $self = C4::SIP::Sip::MsgType->new( $msg, 0 );
382
        $self = C4::SIP::Sip::MsgType->new( $msg, 0 );
Lines 380-385 sub handle { Link Here
380
        return substr( $msg, 0, 2 );
390
        return substr( $msg, 0, 2 );
381
    }
391
    }
382
    unless ( $self->{handler} ) {
392
    unless ( $self->{handler} ) {
393
        C4::SIP::SIPServer::get_logger()->warn("No handler defined for '$msg'");
383
        syslog( "LOG_WARNING", "No handler defined for '%s'", $msg );
394
        syslog( "LOG_WARNING", "No handler defined for '%s'", $msg );
384
        $last_response = REQUEST_SC_RESEND;
395
        $last_response = REQUEST_SC_RESEND;
385
        print("$last_response\r");
396
        print("$last_response\r");
Lines 503-508 sub handle_checkout { Link Here
503
514
504
        # Off-line transactions need to be recorded, but there's
515
        # Off-line transactions need to be recorded, but there's
505
        # not a lot we can do about it
516
        # not a lot we can do about it
517
        C4::SIP::SIPServer::get_logger()->warn("received no-block checkout from terminal '$account->{id}'");
506
        syslog( "LOG_WARNING", "received no-block checkout from terminal '%s'", $account->{id} );
518
        syslog( "LOG_WARNING", "received no-block checkout from terminal '%s'", $account->{id} );
507
519
508
        $status = $ils->checkout_no_block( $patron_id, $item_id, $sc_renewal_policy, $trans_date, $nb_due_date );
520
        $status = $ils->checkout_no_block( $patron_id, $item_id, $sc_renewal_policy, $trans_date, $nb_due_date );
Lines 630-635 sub handle_checkin { Link Here
630
    if ( $no_block eq 'Y' ) {
642
    if ( $no_block eq 'Y' ) {
631
643
632
        # Off-line transactions, ick.
644
        # Off-line transactions, ick.
645
        C4::SIP::SIPServer::get_logger()->warn("received no-block checkin from terminal '$account->{id}'");
633
        syslog( "LOG_WARNING", "received no-block checkin from terminal '%s'", $account->{id} );
646
        syslog( "LOG_WARNING", "received no-block checkin from terminal '%s'", $account->{id} );
634
        $status = $ils->checkin_no_block( $item_id, $trans_date, $return_date, $item_props, $cancel );
647
        $status = $ils->checkin_no_block( $item_id, $trans_date, $return_date, $item_props, $cancel );
635
    } else {
648
    } else {
Lines 744-761 sub handle_sc_status { Link Here
744
    } elsif ( $sc_protocol_version =~ /^2\./ ) {
757
    } elsif ( $sc_protocol_version =~ /^2\./ ) {
745
        $new_proto = 2;
758
        $new_proto = 2;
746
    } else {
759
    } else {
760
        C4::SIP::SIPServer::get_logger()->warn("Unrecognized protocol revision '$sc_protocol_version', falling back to '1'");
747
        syslog( "LOG_WARNING", "Unrecognized protocol revision '%s', falling back to '1'", $sc_protocol_version );
761
        syslog( "LOG_WARNING", "Unrecognized protocol revision '%s', falling back to '1'", $sc_protocol_version );
748
        $new_proto = 1;
762
        $new_proto = 1;
749
    }
763
    }
750
764
751
    if ( $new_proto != $protocol_version ) {
765
    if ( $new_proto != $protocol_version ) {
766
        C4::SIP::SIPServer::get_logger()->info("Setting protocol level to $new_proto");
752
        syslog( "LOG_INFO", "Setting protocol level to $new_proto" );
767
        syslog( "LOG_INFO", "Setting protocol level to $new_proto" );
753
        $protocol_version = $new_proto;
768
        $protocol_version = $new_proto;
754
    }
769
    }
755
770
756
    if ( $status == SC_STATUS_PAPER ) {
771
    if ( $status == SC_STATUS_PAPER ) {
772
        C4::SIP::SIPServer::get_logger()->warn("Self-Check unit '$self->{account}->{id}@$self->{account}->{institution}' out of paper");
757
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' out of paper", $self->{account}->{id}, $self->{account}->{institution} );
773
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' out of paper", $self->{account}->{id}, $self->{account}->{institution} );
758
    } elsif ( $status == SC_STATUS_SHUTDOWN ) {
774
    } elsif ( $status == SC_STATUS_SHUTDOWN ) {
775
        C4::SIP::SIPServer::get_logger()->warn("Self-Check unit '$self->{account}->{id}@$self->{account}->{institution}' shutting down");
759
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' shutting down", $self->{account}->{id}, $self->{account}->{institution} );
776
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' shutting down", $self->{account}->{id}, $self->{account}->{institution} );
760
    }
777
    }
761
778
Lines 796-804 sub login_core { Link Here
796
    my $pwd    = shift;
813
    my $pwd    = shift;
797
    my $status = 1;                 # Assume it all works
814
    my $status = 1;                 # Assume it all works
798
    if ( !exists( $server->{config}->{accounts}->{$uid} ) ) {
815
    if ( !exists( $server->{config}->{accounts}->{$uid} ) ) {
816
        C4::SIP::SIPServer::get_logger()->warn("MsgType::login_core: Unknown login '$uid'");
799
        syslog( "LOG_WARNING", "MsgType::login_core: Unknown login '$uid'" );
817
        syslog( "LOG_WARNING", "MsgType::login_core: Unknown login '$uid'" );
800
        $status = 0;
818
        $status = 0;
801
    } elsif ( $server->{config}->{accounts}->{$uid}->{password} ne $pwd ) {
819
    } elsif ( $server->{config}->{accounts}->{$uid}->{password} ne $pwd ) {
820
        C4::SIP::SIPServer::get_logger()->warn("MsgType::login_core: Invalid password for login '$uid'");
802
        syslog( "LOG_WARNING", "MsgType::login_core: Invalid password for login '$uid'" );
821
        syslog( "LOG_WARNING", "MsgType::login_core: Invalid password for login '$uid'" );
803
        $status = 0;
822
        $status = 0;
804
    } else {
823
    } else {
Lines 813-827 sub login_core { Link Here
813
832
814
        my $auth_status = api_auth( $uid, $pwd, $inst );
833
        my $auth_status = api_auth( $uid, $pwd, $inst );
815
        if ( !$auth_status or $auth_status !~ /^ok$/i ) {
834
        if ( !$auth_status or $auth_status !~ /^ok$/i ) {
835
            C4::SIP::SIPServer::get_logger()->warn("api_auth failed for SIP terminal '$uid' of '$inst': " . ($auth_status||'unknown') );
816
            syslog( "LOG_WARNING", "api_auth failed for SIP terminal '%s' of '%s': %s", $uid, $inst, ( $auth_status || 'unknown' ) );
836
            syslog( "LOG_WARNING", "api_auth failed for SIP terminal '%s' of '%s': %s", $uid, $inst, ( $auth_status || 'unknown' ) );
817
            $status = 0;
837
            $status = 0;
818
        } else {
838
        } else {
839
            C4::SIP::SIPServer::get_logger()->info("Successful login/auth for '$server->{account}->{id}' of '$inst'");
819
            syslog( "LOG_INFO", "Successful login/auth for '%s' of '%s'", $server->{account}->{id}, $inst );
840
            syslog( "LOG_INFO", "Successful login/auth for '%s' of '%s'", $server->{account}->{id}, $inst );
820
841
821
            #
842
            #
822
            # initialize connection to ILS
843
            # initialize connection to ILS
823
            #
844
            #
824
            my $module = $server->{config}->{institutions}->{$inst}->{implementation};
845
            my $module = $server->{config}->{institutions}->{$inst}->{implementation};
846
            C4::SIP::SIPServer::get_logger()->debug("login_core: " . Dumper($module) );
825
            syslog( "LOG_DEBUG", 'login_core: ' . Dumper($module) );
847
            syslog( "LOG_DEBUG", 'login_core: ' . Dumper($module) );
826
848
827
            # Suspect this is always ILS but so we don't break any eccentic install (for now)
849
            # Suspect this is always ILS but so we don't break any eccentic install (for now)
Lines 830-835 sub login_core { Link Here
830
            }
852
            }
831
            $module->use;
853
            $module->use;
832
            if ($@) {
854
            if ($@) {
855
                C4::SIP::SIPServer::get_logger()->error("$server->{service}: Loading ILS implementation '$module' for institution '$inst' failed");
833
                syslog( "LOG_ERR", "%s: Loading ILS implementation '%s' for institution '%s' failed", $server->{service}, $module, $inst );
856
                syslog( "LOG_ERR", "%s: Loading ILS implementation '%s' for institution '%s' failed", $server->{service}, $module, $inst );
834
                die("Failed to load ILS implementation '$module' for $inst");
857
                die("Failed to load ILS implementation '$module' for $inst");
835
            }
858
            }
Lines 837-842 sub login_core { Link Here
837
            # like   ILS->new(), I think.
860
            # like   ILS->new(), I think.
838
            $server->{ils} = $module->new( $server->{institution}, $server->{account} );
861
            $server->{ils} = $module->new( $server->{institution}, $server->{account} );
839
            if ( !$server->{ils} ) {
862
            if ( !$server->{ils} ) {
863
                C4::SIP::SIPServer::get_logger()->error("$server->{service}: ILS connection to '$inst' failed");
840
                syslog( "LOG_ERR", "%s: ILS connection to '%s' failed", $server->{service}, $inst );
864
                syslog( "LOG_ERR", "%s: ILS connection to '%s' failed", $server->{service}, $inst );
841
                die("Unable to connect to ILS '$inst'");
865
                die("Unable to connect to ILS '$inst'");
842
            }
866
            }
Lines 860-865 sub handle_login { Link Here
860
    $pwd = $fields->{ (FID_LOGIN_PWD) };    # Terminal PWD, not patron PWD.
884
    $pwd = $fields->{ (FID_LOGIN_PWD) };    # Terminal PWD, not patron PWD.
861
885
862
    if ( $uid_algorithm || $pwd_algorithm ) {
886
    if ( $uid_algorithm || $pwd_algorithm ) {
887
        C4::SIP::SIPServer::get_logger()->error("LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm");
863
        syslog( "LOG_ERR", "LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm" );
888
        syslog( "LOG_ERR", "LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm" );
864
        $status = 0;
889
        $status = 0;
865
    } else {
890
    } else {
Lines 899-910 sub summary_info { Link Here
899
        return '';    # No detailed information required
924
        return '';    # No detailed information required
900
    }
925
    }
901
926
927
    C4::SIP::SIPServer::get_logger()->debug("Summary_info: index == '$summary_type', field '$summary_map[$summary_type]->{fid}'");
902
    syslog( "LOG_DEBUG", "Summary_info: index == '%d', field '%s'", $summary_type, $summary_map[$summary_type]->{fid} );
928
    syslog( "LOG_DEBUG", "Summary_info: index == '%d', field '%s'", $summary_type, $summary_map[$summary_type]->{fid} );
903
929
904
    my $func     = $summary_map[$summary_type]->{func};
930
    my $func     = $summary_map[$summary_type]->{func};
905
    my $fid      = $summary_map[$summary_type]->{fid};
931
    my $fid      = $summary_map[$summary_type]->{fid};
906
    my $itemlist = &$func( $patron, $start, $end, $server );
932
    my $itemlist = &$func( $patron, $start, $end, $server );
907
933
934
    C4::SIP::SIPServer::get_logger()->debug("summary_info: list = (" . join(", ", @{$itemlist}) . ")");
908
    syslog( "LOG_DEBUG", "summary_info: list = (%s)", join( ", ", @{$itemlist} ) );
935
    syslog( "LOG_DEBUG", "summary_info: list = (%s)", join( ", ", @{$itemlist} ) );
909
    foreach my $i ( @{$itemlist} ) {
936
    foreach my $i ( @{$itemlist} ) {
910
        $resp .= add_field( $fid, $i->{barcode} );
937
        $resp .= add_field( $fid, $i->{barcode} );
Lines 1177-1182 sub handle_item_status_update { Link Here
1177
    $item_props = $fields->{ (FID_ITEM_PROPS) };
1204
    $item_props = $fields->{ (FID_ITEM_PROPS) };
1178
1205
1179
    if ( !defined($item_id) ) {
1206
    if ( !defined($item_id) ) {
1207
        C4::SIP::SIPServer::get_logger()->warn("handle_item_status: received message without Item ID field");
1180
        syslog( "LOG_WARNING", "handle_item_status: received message without Item ID field" );
1208
        syslog( "LOG_WARNING", "handle_item_status: received message without Item ID field" );
1181
    } else {
1209
    } else {
1182
        $item = $ils->find_item($item_id);
1210
        $item = $ils->find_item($item_id);
Lines 1222-1227 sub handle_patron_enable { Link Here
1222
    $patron_id  = $fields->{ (FID_PATRON_ID) };
1250
    $patron_id  = $fields->{ (FID_PATRON_ID) };
1223
    $patron_pwd = $fields->{ (FID_PATRON_PWD) };
1251
    $patron_pwd = $fields->{ (FID_PATRON_PWD) };
1224
1252
1253
    C4::SIP::SIPServer::get_logger()->debug("handle_patron_enable: patron_id: '$patron_id', patron_pwd: '$patron_pwd'");
1225
    syslog( "LOG_DEBUG", "handle_patron_enable: patron_id: '%s', patron_pwd: '%s'", $patron_id, $patron_pwd );
1254
    syslog( "LOG_DEBUG", "handle_patron_enable: patron_id: '%s', patron_pwd: '%s'", $patron_id, $patron_pwd );
1226
1255
1227
    $patron = $ils->find_patron($patron_id);
1256
    $patron = $ils->find_patron($patron_id);
Lines 1292-1297 sub handle_hold { Link Here
1292
    } elsif ( $hold_mode eq '*' ) {
1321
    } elsif ( $hold_mode eq '*' ) {
1293
        $status = $ils->alter_hold( $patron_id, $patron_pwd, $item_id, $title_id, $expiry_date, $pickup_locn, $hold_type, $fee_ack );
1322
        $status = $ils->alter_hold( $patron_id, $patron_pwd, $item_id, $title_id, $expiry_date, $pickup_locn, $hold_type, $fee_ack );
1294
    } else {
1323
    } else {
1324
        C4::SIP::SIPServer::get_logger()->warn("handle_hold: Unrecognized hold mode '$hold_mode' from terminal '$server->{account}->{id}'");
1295
        syslog( "LOG_WARNING", "handle_hold: Unrecognized hold mode '%s' from terminal '%s'", $hold_mode, $server->{account}->{id} );
1325
        syslog( "LOG_WARNING", "handle_hold: Unrecognized hold mode '%s' from terminal '%s'", $hold_mode, $server->{account}->{id} );
1296
        $status = $ils->Transaction::Hold;    # new?
1326
        $status = $ils->Transaction::Hold;    # new?
1297
        $status->screen_msg("System error. Please contact library staff.");
1327
        $status->screen_msg("System error. Please contact library staff.");
Lines 1340-1345 sub handle_renew { Link Here
1340
    $ils->check_inst_id( $fields->{ (FID_INST_ID) }, "handle_renew" );
1370
    $ils->check_inst_id( $fields->{ (FID_INST_ID) }, "handle_renew" );
1341
1371
1342
    if ( $no_block eq 'Y' ) {
1372
    if ( $no_block eq 'Y' ) {
1373
        C4::SIP::SIPServer::get_logger()->warn("handle_renew: received 'no block' renewal from terminal '$server->{account}->{id}'");
1343
        syslog( "LOG_WARNING", "handle_renew: received 'no block' renewal from terminal '%s'", $server->{account}->{id} );
1374
        syslog( "LOG_WARNING", "handle_renew: received 'no block' renewal from terminal '%s'", $server->{account}->{id} );
1344
    }
1375
    }
1345
1376
Lines 1507-1512 sub send_acs_status { Link Here
1507
    $retries            = sprintf( "%03d", $policy->{retries} );
1538
    $retries            = sprintf( "%03d", $policy->{retries} );
1508
1539
1509
    if ( length($retries) != 3 ) {
1540
    if ( length($retries) != 3 ) {
1541
        C4::SIP::SIPServer::get_logger()->error("handle_acs_status: timeout field wrong size: '$timeout'");
1510
        syslog( "LOG_ERR", "handle_acs_status: retries field wrong size: '%s'", $retries );
1542
        syslog( "LOG_ERR", "handle_acs_status: retries field wrong size: '%s'", $retries );
1511
        $retries = '000';
1543
        $retries = '000';
1512
    }
1544
    }
Lines 1520-1525 sub send_acs_status { Link Here
1520
    } elsif ( $protocol_version == 2 ) {
1552
    } elsif ( $protocol_version == 2 ) {
1521
        $msg .= '2.00';
1553
        $msg .= '2.00';
1522
    } else {
1554
    } else {
1555
        C4::SIP::SIPServer::get_logger()->error("Bad setting for \$protocol_version, '$protocol_version' in send_acs_status");
1523
        syslog( "LOG_ERR", 'Bad setting for $protocol_version, "%s" in send_acs_status', $protocol_version );
1556
        syslog( "LOG_ERR", 'Bad setting for $protocol_version, "%s" in send_acs_status', $protocol_version );
1524
        $msg .= '1.00';
1557
        $msg .= '1.00';
1525
    }
1558
    }
Lines 1540-1545 sub send_acs_status { Link Here
1540
            }
1573
            }
1541
        }
1574
        }
1542
        if ( length($supported_msgs) < 16 ) {
1575
        if ( length($supported_msgs) < 16 ) {
1576
            C4::SIP::SIPServer::get_logger()->error("send_acs_status: supported messages '$supported_msgs' too short");
1543
            syslog( "LOG_ERR", 'send_acs_status: supported messages "%s" too short', $supported_msgs );
1577
            syslog( "LOG_ERR", 'send_acs_status: supported messages "%s" too short', $supported_msgs );
1544
        }
1578
        }
1545
        $msg .= add_field( FID_SUPPORTED_MSGS, $supported_msgs );
1579
        $msg .= add_field( FID_SUPPORTED_MSGS, $supported_msgs );
Lines 1550-1555 sub send_acs_status { Link Here
1550
    if (   defined( $account->{print_width} )
1584
    if (   defined( $account->{print_width} )
1551
        && defined($print_line)
1585
        && defined($print_line)
1552
        && $account->{print_width} < length($print_line) ) {
1586
        && $account->{print_width} < length($print_line) ) {
1587
        C4::SIP::SIPServer::get_logger()->warn("send_acs_status: print line '$print_line' too long.  Truncating");
1553
        syslog( "LOG_WARNING", "send_acs_status: print line '%s' too long.  Truncating", $print_line );
1588
        syslog( "LOG_WARNING", "send_acs_status: print line '%s' too long.  Truncating", $print_line );
1554
        $print_line = substr( $print_line, 0, $account->{print_width} );
1589
        $print_line = substr( $print_line, 0, $account->{print_width} );
1555
    }
1590
    }
Lines 1570-1575 sub patron_status_string { Link Here
1570
    my $patron = shift;
1605
    my $patron = shift;
1571
    my $patron_status;
1606
    my $patron_status;
1572
1607
1608
    C4::SIP::SIPServer::get_logger()->debug("patron_status_string: $patron->id charge_ok: $patron->charge_ok");
1573
    syslog( "LOG_DEBUG", "patron_status_string: %s charge_ok: %s", $patron->id, $patron->charge_ok );
1609
    syslog( "LOG_DEBUG", "patron_status_string: %s charge_ok: %s", $patron->id, $patron->charge_ok );
1574
    $patron_status = sprintf(
1610
    $patron_status = sprintf(
1575
        '%s%s%s%s%s%s%s%s%s%s%s%s%s%s',
1611
        '%s%s%s%s%s%s%s%s%s%s%s%s%s%s',
(-)a/Koha/Logger.pm (+1 lines)
Lines 118-123 sub DESTROY { } Link Here
118
118
119
sub _init {
119
sub _init {
120
    my $rv;
120
    my $rv;
121
    $ENV{"LOG4PERL_CONF"} = C4::Context->config("log4perl_conf"); #Supercharge Koha::Log to skip unnecessary configuration file checking on each log attempt
121
    if ( exists $ENV{"LOG4PERL_CONF"} and $ENV{'LOG4PERL_CONF'} and -s $ENV{"LOG4PERL_CONF"} ) {
122
    if ( exists $ENV{"LOG4PERL_CONF"} and $ENV{'LOG4PERL_CONF'} and -s $ENV{"LOG4PERL_CONF"} ) {
122
123
123
        # Check for web server level configuration first
124
        # Check for web server level configuration first
(-)a/etc/log4perl.conf (-1 / +16 lines)
Lines 2-7 log4perl.logger.intranet = WARN, INTRANET Link Here
2
log4perl.appender.INTRANET=Log::Log4perl::Appender::File
2
log4perl.appender.INTRANET=Log::Log4perl::Appender::File
3
log4perl.appender.INTRANET.filename=__LOG_DIR__/intranet-error.log
3
log4perl.appender.INTRANET.filename=__LOG_DIR__/intranet-error.log
4
log4perl.appender.INTRANET.mode=append
4
log4perl.appender.INTRANET.mode=append
5
log4perl.appender.INTRANET.create_at_logtime=true
6
log4perl.appender.INTRANET.syswrite=true
7
log4perl.appender.INTRANET.recreate=true
5
log4perl.appender.INTRANET.layout=PatternLayout
8
log4perl.appender.INTRANET.layout=PatternLayout
6
log4perl.appender.INTRANET.layout.ConversionPattern=[%d] [%p] %m %l %n
9
log4perl.appender.INTRANET.layout.ConversionPattern=[%d] [%p] %m %l %n
7
10
Lines 9-13 log4perl.logger.opac = WARN, OPAC Link Here
9
log4perl.appender.OPAC=Log::Log4perl::Appender::File
12
log4perl.appender.OPAC=Log::Log4perl::Appender::File
10
log4perl.appender.OPAC.filename=__LOG_DIR__/opac-error.log
13
log4perl.appender.OPAC.filename=__LOG_DIR__/opac-error.log
11
log4perl.appender.OPAC.mode=append
14
log4perl.appender.OPAC.mode=append
15
log4perl.appender.OPAC.create_at_logtime=true
16
log4perl.appender.OPAC.syswrite=true
17
log4perl.appender.OPAC.recreate=true
12
log4perl.appender.OPAC.layout=PatternLayout
18
log4perl.appender.OPAC.layout=PatternLayout
13
log4perl.appender.OPAC.layout.ConversionPattern=[%d] [%p] %m %l %n
19
log4perl.appender.OPAC.layout.ConversionPattern=[%d] [%p] %m %l %n
14
- 
20
21
log4perl.logger.sip = DEBUG, SIP
22
log4perl.appender.SIP=Log::Log4perl::Appender::File
23
log4perl.appender.SIP.filename=__LOG_DIR__/sip2.log
24
log4perl.appender.SIP.mode=append
25
log4perl.appender.SIP.create_at_logtime=true
26
log4perl.appender.SIP.syswrite=true
27
log4perl.appender.SIP.recreate=true
28
log4perl.appender.SIP.layout=PatternLayout
29
log4perl.appender.SIP.layout.ConversionPattern=[%d] [%p] %X{accountid}@%X{peeraddr}: %m %l %n

Return to bug 15253