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 447-455 sub renew { Link Here
447
		my $count = scalar @{$patron->{items}};
452
		my $count = scalar @{$patron->{items}};
448
		foreach my $i (@{$patron->{items}}) {
453
		foreach my $i (@{$patron->{items}}) {
449
            unless (defined $i->{barcode}) {    # FIXME: using data instead of objects may violate the abstraction layer
454
            unless (defined $i->{barcode}) {    # FIXME: using data instead of objects may violate the abstraction layer
455
                C4::SIP::SIPServer::get_logger()->error("No barcode for item " . $j+1 . " of $count: $item_id");
450
                syslog("LOG_ERR", "No barcode for item %s of %s: $item_id", $j+1, $count);
456
                syslog("LOG_ERR", "No barcode for item %s of %s: $item_id", $j+1, $count);
451
                next;
457
                next;
452
            }
458
            }
459
            C4::SIP::SIPServer::get_logger()->debug("checking item ". $j + 1 . " of $count: $item_id vs. $i->{barcode} " );
453
            syslog("LOG_DEBUG", "checking item %s of %s: $item_id vs. %s", ++$j, $count, $i->{barcode});
460
            syslog("LOG_DEBUG", "checking item %s of %s: $item_id vs. %s", ++$j, $count, $i->{barcode});
454
            if ($i->{barcode} eq $item_id) {
461
            if ($i->{barcode} eq $item_id) {
455
				# We have it checked out
462
				# We have it checked out
Lines 484-491 sub renew_all { Link Here
484
491
485
    $trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));
492
    $trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));
486
    if (defined $patron) {
493
    if (defined $patron) {
494
        C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: patron '$patron->name': renew_ok: $patron->renew_ok");
487
        syslog("LOG_DEBUG", "ILS::renew_all: patron '%s': renew_ok: %s", $patron->name, $patron->renew_ok);
495
        syslog("LOG_DEBUG", "ILS::renew_all: patron '%s': renew_ok: %s", $patron->name, $patron->renew_ok);
488
    } else {
496
    } else {
497
        C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: Invalid patron id: '$patron_id'");
489
        syslog("LOG_DEBUG", "ILS::renew_all: Invalid patron id: '%s'", $patron_id);
498
        syslog("LOG_DEBUG", "ILS::renew_all: Invalid patron id: '%s'", $patron_id);
490
    }
499
    }
491
500
(-)a/C4/SIP/ILS/Item.pm (+4 lines)
Lines 12-17 use warnings; Link Here
12
use Sys::Syslog qw(syslog);
12
use Sys::Syslog qw(syslog);
13
use Carp;
13
use Carp;
14
14
15
use C4::SIP::SIPServer;
15
use C4::SIP::ILS::Transaction;
16
use C4::SIP::ILS::Transaction;
16
17
17
use C4::Debug;
18
use C4::Debug;
Lines 78-83 sub new { Link Here
78
    my $itemnumber = GetItemnumberFromBarcode($item_id);
79
    my $itemnumber = GetItemnumberFromBarcode($item_id);
79
	my $item = GetBiblioFromItemNumber($itemnumber);    # actually biblio.*, biblioitems.* AND items.*  (overkill)
80
	my $item = GetBiblioFromItemNumber($itemnumber);    # actually biblio.*, biblioitems.* AND items.*  (overkill)
80
	if (! $item) {
81
	if (! $item) {
82
                C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): not found");
81
		syslog("LOG_DEBUG", "new ILS::Item('%s'): not found", $item_id);
83
		syslog("LOG_DEBUG", "new ILS::Item('%s'): not found", $item_id);
82
		warn "new ILS::Item($item_id) : No item '$item_id'.";
84
		warn "new ILS::Item($item_id) : No item '$item_id'.";
83
        return;
85
        return;
Lines 106-111 sub new { Link Here
106
	$self = $item;
108
	$self = $item;
107
	bless $self, $type;
109
	bless $self, $type;
108
110
111
    C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): found with title '$self->{title}'");
109
    syslog("LOG_DEBUG", "new ILS::Item('%s'): found with title '%s'",
112
    syslog("LOG_DEBUG", "new ILS::Item('%s'): found with title '%s'",
110
	   $item_id, $self->{title});
113
	   $item_id, $self->{title});
111
114
Lines 169-174 sub hold_patron_name { Link Here
169
    my $borrowernumber = (@_ ? shift: $self->hold_patron_id()) or return;
172
    my $borrowernumber = (@_ ? shift: $self->hold_patron_id()) or return;
170
    my $holder = GetMember(borrowernumber=>$borrowernumber);
173
    my $holder = GetMember(borrowernumber=>$borrowernumber);
171
    unless ($holder) {
174
    unless ($holder) {
175
        C4::SIP::SIPServer::get_logger()->debug("While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
172
        syslog("LOG_ERR", "While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
176
        syslog("LOG_ERR", "While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
173
        return;
177
        return;
174
    }
178
    }
(-)a/C4/SIP/ILS/Patron.pm (+4 lines)
Lines 34-39 sub new { Link Here
34
    $kp = GetMember(cardnumber=>$patron_id) || GetMember(userid=>$patron_id);
34
    $kp = GetMember(cardnumber=>$patron_id) || GetMember(userid=>$patron_id);
35
    $debug and warn "new Patron (GetMember): " . Dumper($kp);
35
    $debug and warn "new Patron (GetMember): " . Dumper($kp);
36
    unless (defined $kp) {
36
    unless (defined $kp) {
37
        C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): no such patron");
37
        syslog("LOG_DEBUG", "new ILS::Patron(%s): no such patron", $patron_id);
38
        syslog("LOG_DEBUG", "new ILS::Patron(%s): no such patron", $patron_id);
38
        return;
39
        return;
39
    }
40
    }
Lines 122-127 sub new { Link Here
122
    $ilspatron{items} = GetPendingIssues($kp->{borrowernumber});
123
    $ilspatron{items} = GetPendingIssues($kp->{borrowernumber});
123
    $self = \%ilspatron;
124
    $self = \%ilspatron;
124
    $debug and warn Dumper($self);
125
    $debug and warn Dumper($self);
126
    C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): found patron '$self->{id}'");
125
    syslog("LOG_DEBUG", "new ILS::Patron(%s): found patron '%s'", $patron_id,$self->{id});
127
    syslog("LOG_DEBUG", "new ILS::Patron(%s): found patron '%s'", $patron_id,$self->{id});
126
    bless $self, $type;
128
    bless $self, $type;
127
    return $self;
129
    return $self;
Lines 357-362 sub enable { Link Here
357
    foreach my $field ('charge_ok', 'renew_ok', 'recall_ok', 'hold_ok', 'inet') {
359
    foreach my $field ('charge_ok', 'renew_ok', 'recall_ok', 'hold_ok', 'inet') {
358
        $self->{$field} = 1;
360
        $self->{$field} = 1;
359
    }
361
    }
362
    C4::SIP::SIPServer::get_logger()->debug("Patron($self->{id})->enable: charge: $self->{charge_ok}, ".
363
                                            "renew:$self->{renew_ok}, recall:$self->{recall_ok}, hold:$self->{hold_ok}");
360
    syslog("LOG_DEBUG", "Patron(%s)->enable: charge: %s, renew:%s, recall:%s, hold:%s",
364
    syslog("LOG_DEBUG", "Patron(%s)->enable: charge: %s, renew:%s, recall:%s, hold:%s",
361
       $self->{id}, $self->{charge_ok}, $self->{renew_ok},
365
       $self->{id}, $self->{charge_ok}, $self->{renew_ok},
362
       $self->{recall_ok}, $self->{hold_ok});
366
       $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 752-769 sub handle_sc_status { Link Here
752
    } elsif ( $sc_protocol_version =~ /^2\./ ) {
765
    } elsif ( $sc_protocol_version =~ /^2\./ ) {
753
        $new_proto = 2;
766
        $new_proto = 2;
754
    } else {
767
    } else {
768
        C4::SIP::SIPServer::get_logger()->warn("Unrecognized protocol revision '$sc_protocol_version', falling back to '1'");
755
        syslog( "LOG_WARNING", "Unrecognized protocol revision '%s', falling back to '1'", $sc_protocol_version );
769
        syslog( "LOG_WARNING", "Unrecognized protocol revision '%s', falling back to '1'", $sc_protocol_version );
756
        $new_proto = 1;
770
        $new_proto = 1;
757
    }
771
    }
758
772
759
    if ( $new_proto != $protocol_version ) {
773
    if ( $new_proto != $protocol_version ) {
774
        C4::SIP::SIPServer::get_logger()->info("Setting protocol level to $new_proto");
760
        syslog( "LOG_INFO", "Setting protocol level to $new_proto" );
775
        syslog( "LOG_INFO", "Setting protocol level to $new_proto" );
761
        $protocol_version = $new_proto;
776
        $protocol_version = $new_proto;
762
    }
777
    }
763
778
764
    if ( $status == SC_STATUS_PAPER ) {
779
    if ( $status == SC_STATUS_PAPER ) {
780
        C4::SIP::SIPServer::get_logger()->warn("Self-Check unit '$self->{account}->{id}@$self->{account}->{institution}' out of paper");
765
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' out of paper", $self->{account}->{id}, $self->{account}->{institution} );
781
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' out of paper", $self->{account}->{id}, $self->{account}->{institution} );
766
    } elsif ( $status == SC_STATUS_SHUTDOWN ) {
782
    } elsif ( $status == SC_STATUS_SHUTDOWN ) {
783
        C4::SIP::SIPServer::get_logger()->warn("Self-Check unit '$self->{account}->{id}@$self->{account}->{institution}' shutting down");
767
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' shutting down", $self->{account}->{id}, $self->{account}->{institution} );
784
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' shutting down", $self->{account}->{id}, $self->{account}->{institution} );
768
    }
785
    }
769
786
Lines 804-812 sub login_core { Link Here
804
    my $pwd    = shift;
821
    my $pwd    = shift;
805
    my $status = 1;                 # Assume it all works
822
    my $status = 1;                 # Assume it all works
806
    if ( !exists( $server->{config}->{accounts}->{$uid} ) ) {
823
    if ( !exists( $server->{config}->{accounts}->{$uid} ) ) {
824
        C4::SIP::SIPServer::get_logger()->warn("MsgType::login_core: Unknown login '$uid'");
807
        syslog( "LOG_WARNING", "MsgType::login_core: Unknown login '$uid'" );
825
        syslog( "LOG_WARNING", "MsgType::login_core: Unknown login '$uid'" );
808
        $status = 0;
826
        $status = 0;
809
    } elsif ( $server->{config}->{accounts}->{$uid}->{password} ne $pwd ) {
827
    } elsif ( $server->{config}->{accounts}->{$uid}->{password} ne $pwd ) {
828
        C4::SIP::SIPServer::get_logger()->warn("MsgType::login_core: Invalid password for login '$uid'");
810
        syslog( "LOG_WARNING", "MsgType::login_core: Invalid password for login '$uid'" );
829
        syslog( "LOG_WARNING", "MsgType::login_core: Invalid password for login '$uid'" );
811
        $status = 0;
830
        $status = 0;
812
    } else {
831
    } else {
Lines 821-835 sub login_core { Link Here
821
840
822
        my $auth_status = api_auth( $uid, $pwd, $inst );
841
        my $auth_status = api_auth( $uid, $pwd, $inst );
823
        if ( !$auth_status or $auth_status !~ /^ok$/i ) {
842
        if ( !$auth_status or $auth_status !~ /^ok$/i ) {
843
            C4::SIP::SIPServer::get_logger()->warn("api_auth failed for SIP terminal '$uid' of '$inst': " . ($auth_status||'unknown') );
824
            syslog( "LOG_WARNING", "api_auth failed for SIP terminal '%s' of '%s': %s", $uid, $inst, ( $auth_status || 'unknown' ) );
844
            syslog( "LOG_WARNING", "api_auth failed for SIP terminal '%s' of '%s': %s", $uid, $inst, ( $auth_status || 'unknown' ) );
825
            $status = 0;
845
            $status = 0;
826
        } else {
846
        } else {
847
            C4::SIP::SIPServer::get_logger()->info("Successful login/auth for '$server->{account}->{id}' of '$inst'");
827
            syslog( "LOG_INFO", "Successful login/auth for '%s' of '%s'", $server->{account}->{id}, $inst );
848
            syslog( "LOG_INFO", "Successful login/auth for '%s' of '%s'", $server->{account}->{id}, $inst );
828
849
829
            #
850
            #
830
            # initialize connection to ILS
851
            # initialize connection to ILS
831
            #
852
            #
832
            my $module = $server->{config}->{institutions}->{$inst}->{implementation};
853
            my $module = $server->{config}->{institutions}->{$inst}->{implementation};
854
            C4::SIP::SIPServer::get_logger()->debug("login_core: " . Dumper($module) );
833
            syslog( "LOG_DEBUG", 'login_core: ' . Dumper($module) );
855
            syslog( "LOG_DEBUG", 'login_core: ' . Dumper($module) );
834
856
835
            # Suspect this is always ILS but so we don't break any eccentic install (for now)
857
            # Suspect this is always ILS but so we don't break any eccentic install (for now)
Lines 838-843 sub login_core { Link Here
838
            }
860
            }
839
            $module->use;
861
            $module->use;
840
            if ($@) {
862
            if ($@) {
863
                C4::SIP::SIPServer::get_logger()->error("$server->{service}: Loading ILS implementation '$module' for institution '$inst' failed");
841
                syslog( "LOG_ERR", "%s: Loading ILS implementation '%s' for institution '%s' failed", $server->{service}, $module, $inst );
864
                syslog( "LOG_ERR", "%s: Loading ILS implementation '%s' for institution '%s' failed", $server->{service}, $module, $inst );
842
                die("Failed to load ILS implementation '$module' for $inst");
865
                die("Failed to load ILS implementation '$module' for $inst");
843
            }
866
            }
Lines 845-850 sub login_core { Link Here
845
            # like   ILS->new(), I think.
868
            # like   ILS->new(), I think.
846
            $server->{ils} = $module->new( $server->{institution}, $server->{account} );
869
            $server->{ils} = $module->new( $server->{institution}, $server->{account} );
847
            if ( !$server->{ils} ) {
870
            if ( !$server->{ils} ) {
871
                C4::SIP::SIPServer::get_logger()->error("$server->{service}: ILS connection to '$inst' failed");
848
                syslog( "LOG_ERR", "%s: ILS connection to '%s' failed", $server->{service}, $inst );
872
                syslog( "LOG_ERR", "%s: ILS connection to '%s' failed", $server->{service}, $inst );
849
                die("Unable to connect to ILS '$inst'");
873
                die("Unable to connect to ILS '$inst'");
850
            }
874
            }
Lines 868-873 sub handle_login { Link Here
868
    $pwd = $fields->{ (FID_LOGIN_PWD) };    # Terminal PWD, not patron PWD.
892
    $pwd = $fields->{ (FID_LOGIN_PWD) };    # Terminal PWD, not patron PWD.
869
893
870
    if ( $uid_algorithm || $pwd_algorithm ) {
894
    if ( $uid_algorithm || $pwd_algorithm ) {
895
        C4::SIP::SIPServer::get_logger()->error("LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm");
871
        syslog( "LOG_ERR", "LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm" );
896
        syslog( "LOG_ERR", "LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm" );
872
        $status = 0;
897
        $status = 0;
873
    } else {
898
    } else {
Lines 907-918 sub summary_info { Link Here
907
        return '';    # No detailed information required
932
        return '';    # No detailed information required
908
    }
933
    }
909
934
935
    C4::SIP::SIPServer::get_logger()->debug("Summary_info: index == '$summary_type', field '$summary_map[$summary_type]->{fid}'");
910
    syslog( "LOG_DEBUG", "Summary_info: index == '%d', field '%s'", $summary_type, $summary_map[$summary_type]->{fid} );
936
    syslog( "LOG_DEBUG", "Summary_info: index == '%d', field '%s'", $summary_type, $summary_map[$summary_type]->{fid} );
911
937
912
    my $func     = $summary_map[$summary_type]->{func};
938
    my $func     = $summary_map[$summary_type]->{func};
913
    my $fid      = $summary_map[$summary_type]->{fid};
939
    my $fid      = $summary_map[$summary_type]->{fid};
914
    my $itemlist = &$func( $patron, $start, $end, $server );
940
    my $itemlist = &$func( $patron, $start, $end, $server );
915
941
942
    C4::SIP::SIPServer::get_logger()->debug("summary_info: list = (" . join(", ", @{$itemlist}) . ")");
916
    syslog( "LOG_DEBUG", "summary_info: list = (%s)", join( ", ", @{$itemlist} ) );
943
    syslog( "LOG_DEBUG", "summary_info: list = (%s)", join( ", ", @{$itemlist} ) );
917
    foreach my $i ( @{$itemlist} ) {
944
    foreach my $i ( @{$itemlist} ) {
918
        $resp .= add_field( $fid, $i->{barcode} );
945
        $resp .= add_field( $fid, $i->{barcode} );
Lines 1179-1184 sub handle_item_status_update { Link Here
1179
    $item_props = $fields->{ (FID_ITEM_PROPS) };
1206
    $item_props = $fields->{ (FID_ITEM_PROPS) };
1180
1207
1181
    if ( !defined($item_id) ) {
1208
    if ( !defined($item_id) ) {
1209
        C4::SIP::SIPServer::get_logger()->warn("handle_item_status: received message without Item ID field");
1182
        syslog( "LOG_WARNING", "handle_item_status: received message without Item ID field" );
1210
        syslog( "LOG_WARNING", "handle_item_status: received message without Item ID field" );
1183
    } else {
1211
    } else {
1184
        $item = $ils->find_item($item_id);
1212
        $item = $ils->find_item($item_id);
Lines 1224-1229 sub handle_patron_enable { Link Here
1224
    $patron_id  = $fields->{ (FID_PATRON_ID) };
1252
    $patron_id  = $fields->{ (FID_PATRON_ID) };
1225
    $patron_pwd = $fields->{ (FID_PATRON_PWD) };
1253
    $patron_pwd = $fields->{ (FID_PATRON_PWD) };
1226
1254
1255
    C4::SIP::SIPServer::get_logger()->debug("handle_patron_enable: patron_id: '$patron_id', patron_pwd: '$patron_pwd'");
1227
    syslog( "LOG_DEBUG", "handle_patron_enable: patron_id: '%s', patron_pwd: '%s'", $patron_id, $patron_pwd );
1256
    syslog( "LOG_DEBUG", "handle_patron_enable: patron_id: '%s', patron_pwd: '%s'", $patron_id, $patron_pwd );
1228
1257
1229
    $patron = $ils->find_patron($patron_id);
1258
    $patron = $ils->find_patron($patron_id);
Lines 1294-1299 sub handle_hold { Link Here
1294
    } elsif ( $hold_mode eq '*' ) {
1323
    } elsif ( $hold_mode eq '*' ) {
1295
        $status = $ils->alter_hold( $patron_id, $patron_pwd, $item_id, $title_id, $expiry_date, $pickup_locn, $hold_type, $fee_ack );
1324
        $status = $ils->alter_hold( $patron_id, $patron_pwd, $item_id, $title_id, $expiry_date, $pickup_locn, $hold_type, $fee_ack );
1296
    } else {
1325
    } else {
1326
        C4::SIP::SIPServer::get_logger()->warn("handle_hold: Unrecognized hold mode '$hold_mode' from terminal '$server->{account}->{id}'");
1297
        syslog( "LOG_WARNING", "handle_hold: Unrecognized hold mode '%s' from terminal '%s'", $hold_mode, $server->{account}->{id} );
1327
        syslog( "LOG_WARNING", "handle_hold: Unrecognized hold mode '%s' from terminal '%s'", $hold_mode, $server->{account}->{id} );
1298
        $status = $ils->Transaction::Hold;    # new?
1328
        $status = $ils->Transaction::Hold;    # new?
1299
        $status->screen_msg("System error. Please contact library staff.");
1329
        $status->screen_msg("System error. Please contact library staff.");
Lines 1342-1347 sub handle_renew { Link Here
1342
    $ils->check_inst_id( $fields->{ (FID_INST_ID) }, "handle_renew" );
1372
    $ils->check_inst_id( $fields->{ (FID_INST_ID) }, "handle_renew" );
1343
1373
1344
    if ( $no_block eq 'Y' ) {
1374
    if ( $no_block eq 'Y' ) {
1375
        C4::SIP::SIPServer::get_logger()->warn("handle_renew: received 'no block' renewal from terminal '$server->{account}->{id}'");
1345
        syslog( "LOG_WARNING", "handle_renew: received 'no block' renewal from terminal '%s'", $server->{account}->{id} );
1376
        syslog( "LOG_WARNING", "handle_renew: received 'no block' renewal from terminal '%s'", $server->{account}->{id} );
1346
    }
1377
    }
1347
1378
Lines 1509-1514 sub send_acs_status { Link Here
1509
    $retries            = sprintf( "%03d", $policy->{retries} );
1540
    $retries            = sprintf( "%03d", $policy->{retries} );
1510
1541
1511
    if ( length($retries) != 3 ) {
1542
    if ( length($retries) != 3 ) {
1543
        C4::SIP::SIPServer::get_logger()->error("handle_acs_status: timeout field wrong size: '$timeout'");
1512
        syslog( "LOG_ERR", "handle_acs_status: retries field wrong size: '%s'", $retries );
1544
        syslog( "LOG_ERR", "handle_acs_status: retries field wrong size: '%s'", $retries );
1513
        $retries = '000';
1545
        $retries = '000';
1514
    }
1546
    }
Lines 1522-1527 sub send_acs_status { Link Here
1522
    } elsif ( $protocol_version == 2 ) {
1554
    } elsif ( $protocol_version == 2 ) {
1523
        $msg .= '2.00';
1555
        $msg .= '2.00';
1524
    } else {
1556
    } else {
1557
        C4::SIP::SIPServer::get_logger()->error("Bad setting for \$protocol_version, '$protocol_version' in send_acs_status");
1525
        syslog( "LOG_ERR", 'Bad setting for $protocol_version, "%s" in send_acs_status', $protocol_version );
1558
        syslog( "LOG_ERR", 'Bad setting for $protocol_version, "%s" in send_acs_status', $protocol_version );
1526
        $msg .= '1.00';
1559
        $msg .= '1.00';
1527
    }
1560
    }
Lines 1542-1547 sub send_acs_status { Link Here
1542
            }
1575
            }
1543
        }
1576
        }
1544
        if ( length($supported_msgs) < 16 ) {
1577
        if ( length($supported_msgs) < 16 ) {
1578
            C4::SIP::SIPServer::get_logger()->error("send_acs_status: supported messages '$supported_msgs' too short");
1545
            syslog( "LOG_ERR", 'send_acs_status: supported messages "%s" too short', $supported_msgs );
1579
            syslog( "LOG_ERR", 'send_acs_status: supported messages "%s" too short', $supported_msgs );
1546
        }
1580
        }
1547
        $msg .= add_field( FID_SUPPORTED_MSGS, $supported_msgs );
1581
        $msg .= add_field( FID_SUPPORTED_MSGS, $supported_msgs );
Lines 1552-1557 sub send_acs_status { Link Here
1552
    if (   defined( $account->{print_width} )
1586
    if (   defined( $account->{print_width} )
1553
        && defined($print_line)
1587
        && defined($print_line)
1554
        && $account->{print_width} < length($print_line) ) {
1588
        && $account->{print_width} < length($print_line) ) {
1589
        C4::SIP::SIPServer::get_logger()->warn("send_acs_status: print line '$print_line' too long.  Truncating");
1555
        syslog( "LOG_WARNING", "send_acs_status: print line '%s' too long.  Truncating", $print_line );
1590
        syslog( "LOG_WARNING", "send_acs_status: print line '%s' too long.  Truncating", $print_line );
1556
        $print_line = substr( $print_line, 0, $account->{print_width} );
1591
        $print_line = substr( $print_line, 0, $account->{print_width} );
1557
    }
1592
    }
Lines 1572-1577 sub patron_status_string { Link Here
1572
    my $patron = shift;
1607
    my $patron = shift;
1573
    my $patron_status;
1608
    my $patron_status;
1574
1609
1610
    C4::SIP::SIPServer::get_logger()->debug("patron_status_string: $patron->id charge_ok: $patron->charge_ok");
1575
    syslog( "LOG_DEBUG", "patron_status_string: %s charge_ok: %s", $patron->id, $patron->charge_ok );
1611
    syslog( "LOG_DEBUG", "patron_status_string: %s charge_ok: %s", $patron->id, $patron->charge_ok );
1576
    $patron_status = sprintf(
1612
    $patron_status = sprintf(
1577
        '%s%s%s%s%s%s%s%s%s%s%s%s%s%s',
1613
        '%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