Attachment #58573 for bug #15253

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





use warnings;
use strict;
use Sys::Syslog qw(syslog);
use Data::Dumper;

use C4::SIP::ILS::Item;

    my $self = {};
	$debug and warn "new ILS: INSTITUTION: " . Dumper($institution);
    C4::SIP::SIPServer::get_logger()->debug("new ILS $institution->{id}");
    syslog("LOG_DEBUG", "new ILS '%s'", $institution->{id});
    $self->{institution} = $institution;
    return bless $self, $type;
}

    my ($self, $id, $whence) = @_;
    if ($id ne $self->{institution}->{id}) {
        C4::SIP::SIPServer::get_logger()->warn("$whence: received institution '$id', expected '$self->{institution}->{id}'");
        syslog("LOG_WARNING", "%s: received institution '%s', expected '%s'", $whence, $id, $self->{institution}->{id});
        # Just an FYI check, we don't expect the user to change location from that in SIPconfig.xml
    }
}

            push( @{ $patron->{items} }, $item_id );
            $circ->desensitize( !$item->magnetic_media );

            C4::SIP::SIPServer::get_logger()->debug("ILS::Checkout: patron '$patron_id' has checked out '".
                                                     join( ', ', @{ $patron->{items} } ).
                                                    "' items");
            );
        }
        else {
            C4::SIP::SIPServer::get_logger()->error("ILS::Checkout Issue failed");
            syslog( "LOG_ERR", "ILS::Checkout Issue failed" );
        }
    }


    # or it was not checked out but the checked_in_ok flag was set
    $circ->ok( ( $checked_in_ok && $item ) || ( $item && $item->{patron} ) );
    C4::SIP::SIPServer::get_logger()->debug("C4::SIP::ILS::checkin - using checked_in_ok") if $checked_in_ok;
    syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - using checked_in_ok") if $checked_in_ok;

    if ( !defined( $item->{patron} ) ) {
        $circ->screen_msg("Item not checked out") unless $checked_in_ok;
        C4::SIP::SIPServer::get_logger()->debug("C4::SIP::ILS::checkin - item not checked out");
	syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - item not checked out");
    }
    else {
        if ( $circ->ok ) {

		foreach my $i (@{$patron->{items}}) {
            unless (defined $i->{barcode}) {    # FIXME: using data instead of objects may violate the abstraction layer
                C4::SIP::SIPServer::get_logger()->error("No barcode for item " . $j+1 . " of $count: $item_id");
                syslog("LOG_ERR", "No barcode for item %s of %s: $item_id", $j+1, $count);
                next;
            }
            C4::SIP::SIPServer::get_logger()->debug("checking item ". $j + 1 . " of $count: $item_id vs. $i->{barcode} " );
            syslog("LOG_DEBUG", "checking item %s of %s: $item_id vs. %s", ++$j, $count, $i->{barcode});
            if ($i->{barcode} eq $item_id) {
				# We have it checked out
				$item = C4::SIP::ILS::Item->new( $item_id );

    $trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));
    if (defined $patron) {
        C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: patron '$patron->name': renew_ok: $patron->renew_ok");
        syslog("LOG_DEBUG", "ILS::renew_all: patron '%s': renew_ok: %s", $patron->name, $patron->renew_ok);
    } else {
        C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: Invalid patron id: '$patron_id'");
        syslog("LOG_DEBUG", "ILS::renew_all: Invalid patron id: '%s'", $patron_id);
    }

    if (!defined($patron)) {




use strict;
use warnings;

use Sys::Syslog qw(syslog);
use Carp;

use C4::SIP::SIPServer;

	my $item = GetBiblioFromItemNumber($itemnumber);    # actually biblio.*, biblioitems.* AND items.*  (overkill)
	if (! $item) {
                C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): not found");
		syslog("LOG_DEBUG", "new ILS::Item('%s'): not found", $item_id);
		warn "new ILS::Item($item_id) : No item '$item_id'.";
        return;
	}

	bless $self, $type;

    C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): found with title '$self->{title}'");
    syslog("LOG_DEBUG", "new ILS::Item('%s'): found with title '%s'",
	   $item_id, $self->{title});

    return $self;

    my $holder = GetMember(borrowernumber=>$borrowernumber);
    unless ($holder) {
        C4::SIP::SIPServer::get_logger()->debug("While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
        syslog("LOG_ERR", "While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
        return;
    }
    my $email = $holder->{email} || '';




use Exporter;
use Carp;

use Sys::Syslog qw(syslog);
use Data::Dumper;

use C4::Debug;

    $debug and warn "new Patron (GetMember): " . Dumper($kp);
    unless (defined $kp) {
        C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): no such patron");
        syslog("LOG_DEBUG", "new ILS::Patron(%s): no such patron", $patron_id);
        return;
    }
    $kp = GetMemberDetails($kp->{borrowernumber});

    $self = \%ilspatron;
    $debug and warn Dumper($self);
    C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): found patron '$self->{id}'");
    syslog("LOG_DEBUG", "new ILS::Patron(%s): found patron '%s'", $patron_id,$self->{id});
    bless $self, $type;
    return $self;
}

    }
    C4::SIP::SIPServer::get_logger()->debug("Patron($self->{id})->enable: charge: $self->{charge_ok}, ".
                                            "renew:$self->{renew_ok}, recall:$self->{recall_ok}, hold:$self->{hold_ok}");
    syslog("LOG_DEBUG", "Patron(%s)->enable: charge: %s, renew:%s, recall:%s, hold:%s",
       $self->{id}, $self->{charge_ok}, $self->{renew_ok},
       $self->{recall_ok}, $self->{hold_ok});
    $self->{screen_msg} = "Enable feature not implemented."; # "All privileges restored.";   # TODO: not really affecting patron record
    return $self;
}




use strict;

use POSIX qw(strftime);
use Sys::Syslog qw(syslog);
use Data::Dumper;
use CGI qw ( -utf8 );


sub do_checkout {
	my $self = shift;
	C4::SIP::SIPServer::get_logger()->debug("ILS::Transaction::Checkout performing checkout...");
	syslog('LOG_DEBUG', "ILS::Transaction::Checkout performing checkout...");
	my $pending        = $self->{item}->pending_queue;
	my $shelf          = $self->{item}->hold_shelf;
	my $barcode        = $self->{item}->id;

                $self->screen_msg($needsconfirmation->{$confirmation});
                $noerror = 0;
                C4::SIP::SIPServer::get_logger()->debug("Blocking checkout Reason:$confirmation");
                syslog('LOG_DEBUG', "Blocking checkout Reason:$confirmation");
            }
        }
    }




use strict;
use warnings;

use Sys::Syslog qw(syslog);

use C4::SIP::ILS::Item;

use C4::Members qw( GetMember );

        my $item    = C4::SIP::ILS::Item->new($item_id);
        if ( !defined($item) ) {
            C4::SIP::SIPServer::get_logger()->debug("renew_all: Invalid item id '$item_id' associated with patron '$patron->id'");
            syslog(
                'LOG_WARNING',
                q|renew_all: Invalid item id '%s' associated with patron '%s'|,
                $item_id,
                $patron->id
            );

            # $all_ok = 0; Do net set as still ok
            push @{ $self->unrenewed }, $item_id;





LOGGING

By default, SIPServer uses syslog via log4perl for status and debugging messages.
All syslog messages are logged using the syslog facility 'local6'.
If you need to change this, because something else on your system
is already using that facililty, just change the definition of
'ident' and/or 'facility' in the SIP section of file log4perl.conf.
 
Make sure to update your syslog configuration to capture facility
'local6' and record it.

See the log4perl documenation for logging to a file or other services.




use warnings;
use FindBin qw($Bin);
use lib "$Bin";
use Sys::Syslog qw(syslog);
use Net::Server::PreFork;
use IO::Socket::INET;
use Socket qw(:DEFAULT :crlf);


    if (!defined($self->{service})) {
                C4::SIP::SIPServer::get_logger()->error("process_request: Unknown recognized server connection: $sockaddr:$port/$proto");
		syslog("LOG_ERR", "process_request: Unknown recognized server connection: %s:%s/%s", $sockaddr, $port, $proto);
		die "process_request: Bad server connection";
    }



    if (!defined($transport)) {
                C4::SIP::SIPServer::get_logger()->warn("Unknown transport '$service->{transport}', dropping");
		syslog("LOG_WARNING", "Unknown transport '%s', dropping", $service->{transport});
		return;
    } else {
		&$transport($self);

    local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };
    my $timeout = $self->get_timeout({ transport => 1 });
    C4::SIP::SIPServer::get_logger()->debug("raw_transport: timeout is $service->{timeout}");
    syslog('LOG_DEBUG', "raw_transport: timeout is $timeout");
    alarm $timeout;
    while (!$self->{account}) {
        $input = read_request();
        if (!$input) {
            # EOF on the socket
            C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down: EOF during login");
            syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
            return;
        }
        $input =~ s/[\r\n]+$//sm; # Strip off trailing line terminator(s)

    Log::Log4perl::MDC->put("peeraddr", $self->{server}->{peeraddr});

    C4::SIP::SIPServer::get_logger()->debug("raw_transport: uname/inst: '$self->{account}->{id}/$self->{account}->{institution}'");
    syslog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'",
        $self->{account}->{id},
        $self->{account}->{institution});
    if (! $self->{account}->{id}) {
        C4::SIP::SIPServer::get_logger()->error("Login failed shutting down");
        return;
    }

    $self->sip_protocol_loop();

    C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down");
    syslog("LOG_INFO", "raw_transport: shutting down");
    return;
}


	my $string = shift;
	if (defined $string) {
                C4::SIP::SIPServer::get_logger()->debug("get_clean_string  pre-clean(length " . length($string) . "): $string");
		syslog("LOG_DEBUG", "get_clean_string  pre-clean(length %s): %s", length($string), $string);
		chomp($string);
		$string =~ s/^[^A-z0-9]+//;
		$string =~ s/[^A-z0-9]+$//;
                C4::SIP::SIPServer::get_logger()->debug("get_clean_string post-clean(length " . length($string) . "): $string)");
		syslog("LOG_DEBUG", "get_clean_string post-clean(length %s): %s", length($string), $string);
	} else {
                C4::SIP::SIPServer::get_logger()->info("get_clean_string called on undefined");
		syslog("LOG_INFO", "get_clean_string called on undefined");
	}
	return $string;
}

	$in = get_clean_string($in);
	while (my $extra = <STDIN>){
                C4::SIP::SIPServer::get_logger()->error("get_clean_input got extra lines: $extra");
		syslog("LOG_ERR", "get_clean_input got extra lines: %s", $extra);
	}
	return $in;
}

    my $config  = $self->{config};
    my $timeout = $self->get_timeout({ transport => 1 });
    C4::SIP::SIPServer::get_logger()->debug("telnet_transport: timeout is $timeout");
    syslog("LOG_DEBUG", "telnet_transport: timeout is $timeout");

    eval {
	local $SIG{ALRM} = sub { die "telnet_transport: Timed Out ($timeout seconds)!\n"; };

		alarm 0;

                C4::SIP::SIPServer::get_logger()->debug("telnet_transport 1: uid length " . length($uid) . ", pwd length " . length($pwd));
		syslog("LOG_DEBUG", "telnet_transport 1: uid length %s, pwd length %s", length($uid), length($pwd));
		$uid = get_clean_string ($uid);
		$pwd = get_clean_string ($pwd);
                C4::SIP::SIPServer::get_logger()->debug("telnet_transport 2: uid length " . length($uid) . ", pwd length " . length($pwd));
		syslog("LOG_DEBUG", "telnet_transport 2: uid length %s, pwd length %s", length($uid), length($pwd));

	    if (exists ($config->{accounts}->{$uid})
		&& ($pwd eq $config->{accounts}->{$uid}->{password})) {

            }
	    }
		C4::SIP::SIPServer::get_logger()->warn("Invalid login attempt: ' . ($uid||'')  . '");
		syslog("LOG_WARNING", "Invalid login attempt: '%s'", ($uid||''));
		print("Invalid login$CRLF");
	}
    }; # End of eval

    if ($@) {
		C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login timed out");
		syslog("LOG_ERR", "telnet_transport: Login timed out");
		die "Telnet Login Timed out";
    } elsif (!defined($account)) {
		C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login Failed");
		syslog("LOG_ERR", "telnet_transport: Login Failed");
		die "Login Failure";
    } else {
		print "Login OK.  Initiating SIP$CRLF";

    $self->{account} = $account;
    $self->{logger} = _set_logger( Koha::Logger->get( { interface => 'sip', category => $self->{account}->{id} } ) ); # Add id to namespace
    C4::SIP::SIPServer::get_logger()->debug("telnet_transport: uname/inst: '$account->{id}/$account->{institution}'");
    syslog("LOG_DEBUG", "telnet_transport: uname/inst: '%s/%s'", $account->{id}, $account->{institution});
    $self->sip_protocol_loop();
    C4::SIP::SIPServer::get_logger()->info("telnet_transport: shutting down");
    syslog("LOG_INFO", "telnet_transport: shutting down");
    return;
}


    eval {
        local $SIG{ALRM} = sub {
            C4::SIP::SIPServer::get_logger()->debug("Inactive: timed out");
            syslog( 'LOG_DEBUG', 'Inactive: timed out' );
            die "Timed Out!\n";
        };
        my $previous_alarm = alarm($timeout);


            unless ($inputbuf) {
                C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: empty input skipped");
                syslog( "LOG_ERR", "sip_protocol_loop: empty input skipped" );
                print("96$CR");
                next;
            }

            my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );
            if ( !$status ) {
                C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: failed to handle " . substr( $inputbuf, 0, 2 ) );
                syslog(
                    "LOG_ERR",
                    "sip_protocol_loop: failed to handle %s",
                    substr( $inputbuf, 0, 2 )
                );
            }
            next if $status eq REQUEST_ACS_RESEND;
        }

      }
      else {
          C4::SIP::SIPServer::get_logger()->debug('EOF returned on read');
          syslog( 'LOG_DEBUG', 'EOF returned on read' );
          return;
      }
      my $len = length $buffer;
      if ( $len != $raw_length ) {
          my $trim = $raw_length - $len;
          C4::SIP::SIPServer::get_logger()->debug("read_request trimmed $trim character(s) ");
          syslog( 'LOG_DEBUG', "read_request trimmed $trim character(s) " );
      }

      C4::SIP::SIPServer::get_logger()->info("INPUT MSG: '$buffer'");
      syslog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
      return $buffer;
}


        my $rv = sprintf( "%03d", $policy->{timeout} // 0 );
        if( length($rv) != 3 ) {
            C4::SIP::SIPServer::get_logger()->error("LOG_ERR", "Policy timeout has wrong size: '$rv'");
            syslog( "LOG_ERR", "Policy timeout has wrong size: '%s'", $rv );
            return '000';
        }
        return $rv;




use warnings;
use Exporter;
use Encode;
use Sys::Syslog qw(syslog);
use POSIX qw(strftime);
use Socket qw(:crlf);
use IO::Handle;


    if (!defined($value)) {
        C4::SIP::SIPServer::get_logger()->debug("add_field: Undefined value being added to '$field_id'");
	syslog("LOG_DEBUG", "add_field: Undefined value being added to '%s'",
	       $field_id);
		$value = '';
    }
    $value=~s/\r/ /g; # CR terminates a sip message
                      # Protect against them in sip text fields

    $count = sprintf("%04d", $count);
    if (length($count) != 4) {
		C4::SIP::SIPServer::get_logger()->debug("handle_patron_info: $label wrong size: '$count'");
		syslog("LOG_WARNING", "handle_patron_info: %s wrong size: '%s'",
	       $label, $count);
		$count = ' ' x 4;
    }
    return $count;

        STDOUT->autoflush(1);
        print $msg, $terminator;
        C4::SIP::SIPServer::get_logger()->info("OUTPUT MSG: '$msg'");
        syslog("LOG_INFO", "OUTPUT MSG: '$msg'");
    }

    $last_response = $msg;

Lines 64-71 sub find_service { Link Here

(-)a/C4/SIP/Sip/Configuration.pm (-2 lines)
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	C4::SIP::SIPServer::get_logger()->debug("Configuration::find_service: Trying $portstr");
67	Sys::Syslog::syslog( "LOG_DEBUG",
68	"Configuration::find_service: Trying $portstr" );
69	last if ( exists( ( $self->{listeners} )->{$portstr} ) );	67	last if ( exists( ( $self->{listeners} )->{$portstr} ) );
70	}	68	}
71	return $self->{listeners}->{$portstr};	69	return $self->{listeners}->{$portstr};




use strict;
use warnings;
use Exporter;
use Sys::Syslog qw(syslog);

use C4::SIP::Sip qw(:all);
use C4::SIP::Sip::Constants qw(:all);

    C4::SIP::SIPServer::get_logger()->debug("Sip::MsgType::new('$class', '".
                                             substr($msg, 0, 10).
                                            "...', '$msgtag'): seq.no '$seqno', protocol $protocol_version");
    syslog( "LOG_DEBUG", "Sip::MsgType::new('%s', '%s...', '%s'): seq.no '%s', protocol %s", $class, substr( $msg, 0, 10 ), $msgtag, $seqno, $protocol_version );

    # warn "SIP PROTOCOL: $protocol_version";
    if ( !exists( $handlers{$msgtag} ) ) {
        C4::SIP::SIPServer::get_logger()->warn("new Sip::MsgType: Skipping message of unknown type '$msgtag' in '$msg'");
        syslog( "LOG_WARNING", "new Sip::MsgType: Skipping message of unknown type '%s' in '%s'", $msgtag, $msg );
        return;
    } elsif ( !exists( $handlers{$msgtag}->{protocol}->{$protocol_version} ) ) {
        C4::SIP::SIPServer::get_logger()->warn("new Sip::MsgType: Skipping message '$msgtag' unsupported by protocol rev. '$protocol_version'");
        syslog( "LOG_WARNING", "new Sip::MsgType: Skipping message '%s' unsupported by protocol rev. '%d'", $msgtag, $protocol_version );
        return;
    }


    }

    C4::SIP::SIPServer::get_logger()->debug("Sip::MsgType::_initialize('$self->{name}', '$msg', '$proto->{template}', '$proto->{template_len}', ...)");
    syslog( "LOG_DEBUG", "Sip::MsgType::_initialize('%s', '%s', '%s', '%s', ...)", $self->{name}, $msg, $proto->{template}, $proto->{template_len} );

    $self->{fixed_fields} = [ unpack( $proto->{template}, $msg ) ];    # see http://perldoc.perl.org/5.8.8/functions/unpack.html



        if ( !exists( $self->{fields}->{$fn} ) ) {
            C4::SIP::SIPServer::get_logger()->warn("Unsupported field '$fn' in $self->{name}, message '$msg'");
            syslog( "LOG_WARNING", "Unsupported field '%s' in %s message '%s'", $fn, $self->{name}, $msg );
        } elsif ( defined( $self->{fields}->{$fn} ) ) {
            C4::SIP::SIPServer::get_logger()->warn("Duplicate field '$fn' (previous value '$self->{fields}->{$fn}') in $self->{name} message '$msg'");
            syslog( "LOG_WARNING", "Duplicate field '%s' (previous value '%s') in %s message '%s'", $fn, $self->{fields}->{$fn}, $self->{name}, $msg );
        } else {
            $self->{fields}->{$fn} = substr( $field, 2 );
        }


        if ( !verify_cksum($msg) ) {
            C4::SIP::SIPServer::get_logger()->warn("Checksum failed on message '$msg'");
            syslog( "LOG_WARNING", "Checksum failed on message '%s'", $msg );

            # REQUEST_SC_RESEND with error detection
            $last_response = REQUEST_SC_RESEND_CKSUM;

        # We received a non-ED message when ED is supposed to be active.
        # Warn about this problem, then process the message anyway.
        C4::SIP::SIPServer::get_logger()->warn("Received message without error detection: '$msg'");
        syslog( "LOG_WARNING", "Received message without error detection: '%s'", $msg );
        $error_detection = 0;
        $self = C4::SIP::Sip::MsgType->new( $msg, 0 );
    } else {

    }
    unless ( $self->{handler} ) {
        C4::SIP::SIPServer::get_logger()->warn("No handler defined for '$msg'");
        syslog( "LOG_WARNING", "No handler defined for '%s'", $msg );
        $last_response = REQUEST_SC_RESEND;
        print("$last_response\r");
        return REQUEST_ACS_RESEND;

        # Off-line transactions need to be recorded, but there's
        # not a lot we can do about it
        C4::SIP::SIPServer::get_logger()->warn("received no-block checkout from terminal '$account->{id}'");
        syslog( "LOG_WARNING", "received no-block checkout from terminal '%s'", $account->{id} );

        $status = $ils->checkout_no_block( $patron_id, $item_id, $sc_renewal_policy, $trans_date, $nb_due_date );
    } else {


        # Off-line transactions, ick.
        C4::SIP::SIPServer::get_logger()->warn("received no-block checkin from terminal '$account->{id}'");
        syslog( "LOG_WARNING", "received no-block checkin from terminal '%s'", $account->{id} );
        $status = $ils->checkin_no_block( $item_id, $trans_date, $return_date, $item_props, $cancel );
    } else {
        $status = $ils->checkin( $item_id, $trans_date, $return_date, $my_branch, $item_props, $cancel, $account->{checked_in_ok} );

        $new_proto = 2;
    } else {
        C4::SIP::SIPServer::get_logger()->warn("Unrecognized protocol revision '$sc_protocol_version', falling back to '1'");
        syslog( "LOG_WARNING", "Unrecognized protocol revision '%s', falling back to '1'", $sc_protocol_version );
        $new_proto = 1;
    }

    if ( $new_proto != $protocol_version ) {
        C4::SIP::SIPServer::get_logger()->info("Setting protocol level to $new_proto");
        syslog( "LOG_INFO", "Setting protocol level to $new_proto" );
        $protocol_version = $new_proto;
    }

    if ( $status == SC_STATUS_PAPER ) {
        C4::SIP::SIPServer::get_logger()->warn("Self-Check unit '$self->{account}->{id}@$self->{account}->{institution}' out of paper");
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' out of paper", $self->{account}->{id}, $self->{account}->{institution} );
    } elsif ( $status == SC_STATUS_SHUTDOWN ) {
        C4::SIP::SIPServer::get_logger()->warn("Self-Check unit '$self->{account}->{id}@$self->{account}->{institution}' shutting down");
        syslog( "LOG_WARNING", "Self-Check unit '%s@%s' shutting down", $self->{account}->{id}, $self->{account}->{institution} );
    }

    $self->{account}->{print_width} = $print_width;

    my $status = 1;                 # Assume it all works
    if ( !exists( $server->{config}->{accounts}->{$uid} ) ) {
        C4::SIP::SIPServer::get_logger()->warn("MsgType::login_core: Unknown login '$uid'");
        syslog( "LOG_WARNING", "MsgType::login_core: Unknown login '$uid'" );
        $status = 0;
    } elsif ( $server->{config}->{accounts}->{$uid}->{password} ne $pwd ) {
        C4::SIP::SIPServer::get_logger()->warn("MsgType::login_core: Invalid password for login '$uid'");
        syslog( "LOG_WARNING", "MsgType::login_core: Invalid password for login '$uid'" );
        $status = 0;
    } else {


        my $auth_status = api_auth( $uid, $pwd, $inst );
        if ( !$auth_status or $auth_status !~ /^ok$/i ) {
            C4::SIP::SIPServer::get_logger()->warn("api_auth failed for SIP terminal '$uid' of '$inst': " . ($auth_status||'unknown') );
            syslog( "LOG_WARNING", "api_auth failed for SIP terminal '%s' of '%s': %s", $uid, $inst, ( $auth_status || 'unknown' ) );
            $status = 0;
        } else {
            C4::SIP::SIPServer::get_logger()->info("Successful login/auth for '$server->{account}->{id}' of '$inst'");
            syslog( "LOG_INFO", "Successful login/auth for '%s' of '%s'", $server->{account}->{id}, $inst );

            #
            # initialize connection to ILS
            #
            my $module = $server->{config}->{institutions}->{$inst}->{implementation};
            C4::SIP::SIPServer::get_logger()->debug("login_core: " . Dumper($module) );
            syslog( "LOG_DEBUG", 'login_core: ' . Dumper($module) );

            # Suspect this is always ILS but so we don't break any eccentic install (for now)
            if ( $module eq 'ILS' ) {

            $module->use;
            if ($@) {
                C4::SIP::SIPServer::get_logger()->error("$server->{service}: Loading ILS implementation '$module' for institution '$inst' failed");
                syslog( "LOG_ERR", "%s: Loading ILS implementation '%s' for institution '%s' failed", $server->{service}, $module, $inst );
                die("Failed to load ILS implementation '$module' for $inst");
            }


            $server->{ils} = $module->new( $server->{institution}, $server->{account} );
            if ( !$server->{ils} ) {
                C4::SIP::SIPServer::get_logger()->error("$server->{service}: ILS connection to '$inst' failed");
                syslog( "LOG_ERR", "%s: ILS connection to '%s' failed", $server->{service}, $inst );
                die("Unable to connect to ILS '$inst'");
            }
        }


    if ( $uid_algorithm || $pwd_algorithm ) {
        C4::SIP::SIPServer::get_logger()->error("LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm");
        syslog( "LOG_ERR", "LOGIN: Unsupported non-zero encryption method(s): uid = $uid_algorithm, pwd = $pwd_algorithm" );
        $status = 0;
    } else {
        $status = login_core( $server, $uid, $pwd );

    }

    C4::SIP::SIPServer::get_logger()->debug("Summary_info: index == '$summary_type', field '$summary_map[$summary_type]->{fid}'");
    syslog( "LOG_DEBUG", "Summary_info: index == '%d', field '%s'", $summary_type, $summary_map[$summary_type]->{fid} );

    my $func     = $summary_map[$summary_type]->{func};
    my $fid      = $summary_map[$summary_type]->{fid};
    my $itemlist = &$func( $patron, $start, $end, $server );

    C4::SIP::SIPServer::get_logger()->debug("summary_info: list = (" . join(", ", @{$itemlist}) . ")");
    syslog( "LOG_DEBUG", "summary_info: list = (%s)", join( ", ", @{$itemlist} ) );
    foreach my $i ( @{$itemlist} ) {
        $resp .= add_field( $fid, $i->{barcode} );
    }


    if ( !defined($item_id) ) {
        C4::SIP::SIPServer::get_logger()->warn("handle_item_status: received message without Item ID field");
        syslog( "LOG_WARNING", "handle_item_status: received message without Item ID field" );
    } else {
        $item = $ils->find_item($item_id);
    }

    $patron_pwd = $fields->{ (FID_PATRON_PWD) };

    C4::SIP::SIPServer::get_logger()->debug("handle_patron_enable: patron_id: '$patron_id', patron_pwd: '$patron_pwd'");
    syslog( "LOG_DEBUG", "handle_patron_enable: patron_id: '%s', patron_pwd: '%s'", $patron_id, $patron_pwd );

    $patron = $ils->find_patron($patron_id);


        $status = $ils->alter_hold( $patron_id, $patron_pwd, $item_id, $title_id, $expiry_date, $pickup_locn, $hold_type, $fee_ack );
    } else {
        C4::SIP::SIPServer::get_logger()->warn("handle_hold: Unrecognized hold mode '$hold_mode' from terminal '$server->{account}->{id}'");
        syslog( "LOG_WARNING", "handle_hold: Unrecognized hold mode '%s' from terminal '%s'", $hold_mode, $server->{account}->{id} );
        $status = $ils->Transaction::Hold;    # new?
        $status->screen_msg("System error. Please contact library staff.");
    }


    if ( $no_block eq 'Y' ) {
        C4::SIP::SIPServer::get_logger()->warn("handle_renew: received 'no block' renewal from terminal '$server->{account}->{id}'");
        syslog( "LOG_WARNING", "handle_renew: received 'no block' renewal from terminal '%s'", $server->{account}->{id} );
    }

    $patron_id  = $fields->{ (FID_PATRON_ID) };


    if ( length($retries) != 3 ) {
        C4::SIP::SIPServer::get_logger()->error("handle_acs_status: timeout field wrong size: '$timeout'");
        syslog( "LOG_ERR", "handle_acs_status: retries field wrong size: '%s'", $retries );
        $retries = '000';
    }


        $msg .= '2.00';
    } else {
        C4::SIP::SIPServer::get_logger()->error("Bad setting for \$protocol_version, '$protocol_version' in send_acs_status");
        syslog( "LOG_ERR", 'Bad setting for $protocol_version, "%s" in send_acs_status', $protocol_version );
        $msg .= '1.00';
    }


        }
        if ( length($supported_msgs) < 16 ) {
            C4::SIP::SIPServer::get_logger()->error("send_acs_status: supported messages '$supported_msgs' too short");
            syslog( "LOG_ERR", 'send_acs_status: supported messages "%s" too short', $supported_msgs );
        }
        $msg .= add_field( FID_SUPPORTED_MSGS, $supported_msgs );
    }

        && defined($print_line)
        && $account->{print_width} < length($print_line) ) {
        C4::SIP::SIPServer::get_logger()->warn("send_acs_status: print line '$print_line' too long.  Truncating");
        syslog( "LOG_WARNING", "send_acs_status: print line '%s' too long.  Truncating", $print_line );
        $print_line = substr( $print_line, 0, $account->{print_width} );
    }


    my $patron_status;

    C4::SIP::SIPServer::get_logger()->debug("patron_status_string: $patron->id charge_ok: $patron->charge_ok");
    syslog( "LOG_DEBUG", "patron_status_string: %s charge_ok: %s", $patron->id, $patron->charge_ok );
    $patron_status = sprintf(
        '%s%s%s%s%s%s%s%s%s%s%s%s%s%s',
        denied( $patron->charge_ok ),

Lines 10-18 Link Here

(-)a/etc/SIPconfig.xml (-4 lines)
10	<server-params	10	<server-params
11	min_servers='1'	11	min_servers='1'
12	min_spare_servers='0'	12	min_spare_servers='0'
13	log_file='Sys::Syslog'
14	syslog_ident='koha_sip'
15	syslog_facility='local6'
16	/>	13	/>
17		14
18	<listeners>	15	<listeners>
19	-

Return to bug 15253

Lines 6-12 package C4::SIP::ILS; Link Here

(-)a/C4/SIP/ILS.pm (-15 / +4 lines)
6		6
7	use warnings;	7	use warnings;
8	use strict;	8	use strict;
9	use Sys::Syslog qw(syslog);
10	use Data::Dumper;	9	use Data::Dumper;
11		10
12	use C4::SIP::ILS::Item;	11	use C4::SIP::ILS::Item;
Lines 48-54 sub new { Link Here
48	my $self = {};	47	my $self = {};
49	$debug and warn "new ILS: INSTITUTION: " . Dumper($institution);	48	$debug and warn "new ILS: INSTITUTION: " . Dumper($institution);
50	C4::SIP::SIPServer::get_logger()->debug("new ILS $institution->{id}");	49	C4::SIP::SIPServer::get_logger()->debug("new ILS $institution->{id}");
51	syslog("LOG_DEBUG", "new ILS '%s'", $institution->{id});
52	$self->{institution} = $institution;	50	$self->{institution} = $institution;
53	return bless $self, $type;	51	return bless $self, $type;
54	}	52	}
Lines 84-90 sub check_inst_id { Link Here
84	my ($self, $id, $whence) = @_;	82	my ($self, $id, $whence) = @_;
85	if ($id ne $self->{institution}->{id}) {	83	if ($id ne $self->{institution}->{id}) {
86	C4::SIP::SIPServer::get_logger()->warn("$whence: received institution '$id', expected '$self->{institution}->{id}'");	84	C4::SIP::SIPServer::get_logger()->warn("$whence: received institution '$id', expected '$self->{institution}->{id}'");
87	syslog("LOG_WARNING", "%s: received institution '%s', expected '%s'", $whence, $id, $self->{institution}->{id});
88	# Just an FYI check, we don't expect the user to change location from that in SIPconfig.xml	85	# Just an FYI check, we don't expect the user to change location from that in SIPconfig.xml
89	}	86	}
90	}	87	}
Lines 169-182 sub checkout { Link Here
169	push( @{ $patron->{items} }, $item_id );	166	push( @{ $patron->{items} }, $item_id );
170	$circ->desensitize( !$item->magnetic_media );	167	$circ->desensitize( !$item->magnetic_media );
171		168
172	syslog(	169	C4::SIP::SIPServer::get_logger()->debug("ILS::Checkout: patron '$patron_id' has checked out '".
173	"LOG_DEBUG", "ILS::Checkout: patron %s has checked out %s",	170	join( ', ', @{ $patron->{items} } ).
174	$patron_id, join( ', ', @{ $patron->{items} } )	171	"' items");
175	);
176	}	172	}
177	else {	173	else {
178	C4::SIP::SIPServer::get_logger()->debug("ILS::Checkout: patron $patron_id has checked out " . join(', ', @{$patron->{items}}) );	174	C4::SIP::SIPServer::get_logger()->error("ILS::Checkout Issue failed");
179	syslog( "LOG_ERR", "ILS::Checkout Issue failed" );
180	}	175	}
181	}	176	}
182		177
Lines 221-232 sub checkin { Link Here
221	# or it was not checked out but the checked_in_ok flag was set	216	# or it was not checked out but the checked_in_ok flag was set
222	$circ->ok( ( $checked_in_ok && $item ) \|\| ( $item && $item->{patron} ) );	217	$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;	218	C4::SIP::SIPServer::get_logger()->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;
225		219
226	if ( !defined( $item->{patron} ) ) {	220	if ( !defined( $item->{patron} ) ) {
227	$circ->screen_msg("Item not checked out") unless $checked_in_ok;	221	$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");	222	C4::SIP::SIPServer::get_logger()->debug("C4::SIP::ILS::checkin - item not checked out");
229	syslog("LOG_DEBUG", "C4::SIP::ILS::checkin - item not checked out");
230	}	223	}
231	else {	224	else {
232	if ( $circ->ok ) {	225	if ( $circ->ok ) {
Lines 453-463 sub renew { Link Here
453	foreach my $i (@{$patron->{items}}) {	446	foreach my $i (@{$patron->{items}}) {
454	unless (defined $i->{barcode}) { # FIXME: using data instead of objects may violate the abstraction layer	447	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");	448	C4::SIP::SIPServer::get_logger()->error("No barcode for item " . $j+1 . " of $count: $item_id");
456	syslog("LOG_ERR", "No barcode for item %s of %s: $item_id", $j+1, $count);
457	next;	449	next;
458	}	450	}
459	C4::SIP::SIPServer::get_logger()->debug("checking item ". $j + 1 . " of $count: $item_id vs. $i->{barcode} " );	451	C4::SIP::SIPServer::get_logger()->debug("checking item ". $j + 1 . " of $count: $item_id vs. $i->{barcode} " );
460	syslog("LOG_DEBUG", "checking item %s of %s: $item_id vs. %s", ++$j, $count, $i->{barcode});
461	if ($i->{barcode} eq $item_id) {	452	if ($i->{barcode} eq $item_id) {
462	# We have it checked out	453	# We have it checked out
463	$item = C4::SIP::ILS::Item->new( $item_id );	454	$item = C4::SIP::ILS::Item->new( $item_id );
Lines 492-501 sub renew_all { Link Here
492	$trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));	483	$trans->patron($patron = C4::SIP::ILS::Patron->new( $patron_id ));
493	if (defined $patron) {	484	if (defined $patron) {
494	C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: patron '$patron->name': renew_ok: $patron->renew_ok");	485	C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: patron '$patron->name': renew_ok: $patron->renew_ok");
495	syslog("LOG_DEBUG", "ILS::renew_all: patron '%s': renew_ok: %s", $patron->name, $patron->renew_ok);
496	} else {	486	} else {
497	C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: Invalid patron id: '$patron_id'");	487	C4::SIP::SIPServer::get_logger()->debug("ILS::renew_all: Invalid patron id: '$patron_id'");
498	syslog("LOG_DEBUG", "ILS::renew_all: Invalid patron id: '%s'", $patron_id);
499	}	488	}
500		489
501	if (!defined($patron)) {	490	if (!defined($patron)) {

Lines 5-11 use strict; Link Here

(-)a/C4/SIP/SIPServer.pm (-33 / +1 lines)
5	use warnings;	5	use warnings;
6	use FindBin qw($Bin);	6	use FindBin qw($Bin);
7	use lib "$Bin";	7	use lib "$Bin";
8	use Sys::Syslog qw(syslog);
9	use Net::Server::PreFork;	8	use Net::Server::PreFork;
10	use IO::Socket::INET;	9	use IO::Socket::INET;
11	use Socket qw(:DEFAULT :crlf);	10	use Socket qw(:DEFAULT :crlf);
Lines 118-124 sub process_request { Link Here
118		117
119	if (!defined($self->{service})) {	118	if (!defined($self->{service})) {
120	C4::SIP::SIPServer::get_logger()->error("process_request: Unknown recognized server connection: $sockaddr:$port/$proto");	119	C4::SIP::SIPServer::get_logger()->error("process_request: Unknown recognized server connection: $sockaddr:$port/$proto");
121	syslog("LOG_ERR", "process_request: Unknown recognized server connection: %s:%s/%s", $sockaddr, $port, $proto);
122	die "process_request: Bad server connection";	120	die "process_request: Bad server connection";
123	}	121	}
124		122
Lines 126-132 sub process_request { Link Here
126		124
127	if (!defined($transport)) {	125	if (!defined($transport)) {
128	C4::SIP::SIPServer::get_logger()->warn("Unknown transport '$service->{transport}', dropping");	126	C4::SIP::SIPServer::get_logger()->warn("Unknown transport '$service->{transport}', dropping");
129	syslog("LOG_WARNING", "Unknown transport '%s', dropping", $service->{transport});
130	return;	127	return;
131	} else {	128	} else {
132	&$transport($self);	129	&$transport($self);
Lines 153-166 sub raw_transport { Link Here
153	local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };	150	local $SIG{ALRM} = sub { die 'raw transport Timed Out!' };
154	my $timeout = $self->get_timeout({ transport => 1 });	151	my $timeout = $self->get_timeout({ transport => 1 });
155	C4::SIP::SIPServer::get_logger()->debug("raw_transport: timeout is $service->{timeout}");	152	C4::SIP::SIPServer::get_logger()->debug("raw_transport: timeout is $service->{timeout}");
156	syslog('LOG_DEBUG', "raw_transport: timeout is $timeout");
157	alarm $timeout;	153	alarm $timeout;
158	while (!$self->{account}) {	154	while (!$self->{account}) {
159	$input = read_request();	155	$input = read_request();
160	if (!$input) {	156	if (!$input) {
161	# EOF on the socket	157	# EOF on the socket
162	C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down: EOF during login");	158	C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down: EOF during login");
163	syslog("LOG_INFO", "raw_transport: shutting down: EOF during login");
164	return;	159	return;
165	}	160	}
166	$input =~ s/[\r\n]+$//sm; # Strip off trailing line terminator(s)	161	$input =~ s/[\r\n]+$//sm; # Strip off trailing line terminator(s)
Lines 176-193 sub raw_transport { Link Here
176	Log::Log4perl::MDC->put("peeraddr", $self->{server}->{peeraddr});	171	Log::Log4perl::MDC->put("peeraddr", $self->{server}->{peeraddr});
177		172
178	C4::SIP::SIPServer::get_logger()->debug("raw_transport: uname/inst: '$self->{account}->{id}/$self->{account}->{institution}'");	173	C4::SIP::SIPServer::get_logger()->debug("raw_transport: uname/inst: '$self->{account}->{id}/$self->{account}->{institution}'");
179	syslog("LOG_DEBUG", "raw_transport: uname/inst: '%s/%s'",
180	$self->{account}->{id},
181	$self->{account}->{institution});
182	if (! $self->{account}->{id}) {	174	if (! $self->{account}->{id}) {
183	syslog("LOG_ERR","Login failed shutting down");	175	C4::SIP::SIPServer::get_logger()->error("Login failed shutting down");
184	return;	176	return;
185	}	177	}
186		178
187	$self->sip_protocol_loop();	179	$self->sip_protocol_loop();
188		180
189	C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down");	181	C4::SIP::SIPServer::get_logger()->info("raw_transport: shutting down");
190	syslog("LOG_INFO", "raw_transport: shutting down");
191	return;	182	return;
192	}	183	}
193		184
Lines 195-209 sub get_clean_string { Link Here
195	my $string = shift;	186	my $string = shift;
196	if (defined $string) {	187	if (defined $string) {
197	C4::SIP::SIPServer::get_logger()->debug("get_clean_string pre-clean(length " . length($string) . "): $string");	188	C4::SIP::SIPServer::get_logger()->debug("get_clean_string pre-clean(length " . length($string) . "): $string");
198	syslog("LOG_DEBUG", "get_clean_string pre-clean(length %s): %s", length($string), $string);
199	chomp($string);	189	chomp($string);
200	$string =~ s/^[^A-z0-9]+//;	190	$string =~ s/^[^A-z0-9]+//;
201	$string =~ s/[^A-z0-9]+$//;	191	$string =~ s/[^A-z0-9]+$//;
202	C4::SIP::SIPServer::get_logger()->debug("get_clean_string post-clean(length " . length($string) . "): $string)");	192	C4::SIP::SIPServer::get_logger()->debug("get_clean_string post-clean(length " . length($string) . "): $string)");
203	syslog("LOG_DEBUG", "get_clean_string post-clean(length %s): %s", length($string), $string);
204	} else {	193	} else {
205	C4::SIP::SIPServer::get_logger()->info("get_clean_string called on undefined");	194	C4::SIP::SIPServer::get_logger()->info("get_clean_string called on undefined");
206	syslog("LOG_INFO", "get_clean_string called on undefined");
207	}	195	}
208	return $string;	196	return $string;
209	}	197	}
Lines 214-220 sub get_clean_input { Link Here
214	$in = get_clean_string($in);	202	$in = get_clean_string($in);
215	while (my $extra = <STDIN>){	203	while (my $extra = <STDIN>){
216	C4::SIP::SIPServer::get_logger()->error("get_clean_input got extra lines: $extra");	204	C4::SIP::SIPServer::get_logger()->error("get_clean_input got extra lines: $extra");
217	syslog("LOG_ERR", "get_clean_input got extra lines: %s", $extra);
218	}	205	}
219	return $in;	206	return $in;
220	}	207	}
Lines 228-234 sub telnet_transport { Link Here
228	my $config = $self->{config};	215	my $config = $self->{config};
229	my $timeout = $self->get_timeout({ transport => 1 });	216	my $timeout = $self->get_timeout({ transport => 1 });
230	C4::SIP::SIPServer::get_logger()->debug("telnet_transport: timeout is $timeout");	217	C4::SIP::SIPServer::get_logger()->debug("telnet_transport: timeout is $timeout");
231	syslog("LOG_DEBUG", "telnet_transport: timeout is $timeout");
232		218
233	eval {	219	eval {
234	local $SIG{ALRM} = sub { die "telnet_transport: Timed Out ($timeout seconds)!\n"; };	220	local $SIG{ALRM} = sub { die "telnet_transport: Timed Out ($timeout seconds)!\n"; };
Lines 248-258 sub telnet_transport { Link Here
248	alarm 0;	234	alarm 0;
249		235
250	C4::SIP::SIPServer::get_logger()->debug("telnet_transport 1: uid length " . length($uid) . ", pwd length " . length($pwd));	236	C4::SIP::SIPServer::get_logger()->debug("telnet_transport 1: uid length " . length($uid) . ", pwd length " . length($pwd));
251	syslog("LOG_DEBUG", "telnet_transport 1: uid length %s, pwd length %s", length($uid), length($pwd));
252	$uid = get_clean_string ($uid);	237	$uid = get_clean_string ($uid);
253	$pwd = get_clean_string ($pwd);	238	$pwd = get_clean_string ($pwd);
254	C4::SIP::SIPServer::get_logger()->debug("telnet_transport 2: uid length " . length($uid) . ", pwd length " . length($pwd));	239	C4::SIP::SIPServer::get_logger()->debug("telnet_transport 2: uid length " . length($uid) . ", pwd length " . length($pwd));
255	syslog("LOG_DEBUG", "telnet_transport 2: uid length %s, pwd length %s", length($uid), length($pwd));
256		240
257	if (exists ($config->{accounts}->{$uid})	241	if (exists ($config->{accounts}->{$uid})
258	&& ($pwd eq $config->{accounts}->{$uid}->{password})) {	242	&& ($pwd eq $config->{accounts}->{$uid}->{password})) {
Lines 262-279 sub telnet_transport { Link Here
262	}	246	}
263	}	247	}
264	C4::SIP::SIPServer::get_logger()->warn("Invalid login attempt: ' . ($uid\|\|'') . '");	248	C4::SIP::SIPServer::get_logger()->warn("Invalid login attempt: ' . ($uid\|\|'') . '");
265	syslog("LOG_WARNING", "Invalid login attempt: '%s'", ($uid\|\|''));
266	print("Invalid login$CRLF");	249	print("Invalid login$CRLF");
267	}	250	}
268	}; # End of eval	251	}; # End of eval
269		252
270	if ($@) {	253	if ($@) {
271	C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login timed out");	254	C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login timed out");
272	syslog("LOG_ERR", "telnet_transport: Login timed out");
273	die "Telnet Login Timed out";	255	die "Telnet Login Timed out";
274	} elsif (!defined($account)) {	256	} elsif (!defined($account)) {
275	C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login Failed");	257	C4::SIP::SIPServer::get_logger()->error("telnet_transport: Login Failed");
276	syslog("LOG_ERR", "telnet_transport: Login Failed");
277	die "Login Failure";	258	die "Login Failure";
278	} else {	259	} else {
279	print "Login OK. Initiating SIP$CRLF";	260	print "Login OK. Initiating SIP$CRLF";
Lines 282-291 sub telnet_transport { Link Here
282	$self->{account} = $account;	263	$self->{account} = $account;
283	$self->{logger} = _set_logger( Koha::Logger->get( { interface => 'sip', category => $self->{account}->{id} } ) ); # Add id to namespace	264	$self->{logger} = _set_logger( Koha::Logger->get( { interface => 'sip', category => $self->{account}->{id} } ) ); # Add id to namespace
284	C4::SIP::SIPServer::get_logger()->debug("telnet_transport: uname/inst: '$account->{id}/$account->{institution}'");	265	C4::SIP::SIPServer::get_logger()->debug("telnet_transport: uname/inst: '$account->{id}/$account->{institution}'");
285	syslog("LOG_DEBUG", "telnet_transport: uname/inst: '%s/%s'", $account->{id}, $account->{institution});
286	$self->sip_protocol_loop();	266	$self->sip_protocol_loop();
287	C4::SIP::SIPServer::get_logger()->info("telnet_transport: shutting down");	267	C4::SIP::SIPServer::get_logger()->info("telnet_transport: shutting down");
288	syslog("LOG_INFO", "telnet_transport: shutting down");
289	return;	268	return;
290	}	269	}
291		270
Lines 316-322 sub sip_protocol_loop { Link Here
316	eval {	295	eval {
317	local $SIG{ALRM} = sub {	296	local $SIG{ALRM} = sub {
318	C4::SIP::SIPServer::get_logger()->debug("Inactive: timed out");	297	C4::SIP::SIPServer::get_logger()->debug("Inactive: timed out");
319	syslog( 'LOG_DEBUG', 'Inactive: timed out' );
320	die "Timed Out!\n";	298	die "Timed Out!\n";
321	};	299	};
322	my $previous_alarm = alarm($timeout);	300	my $previous_alarm = alarm($timeout);
Lines 329-335 sub sip_protocol_loop { Link Here
329		307
330	unless ($inputbuf) {	308	unless ($inputbuf) {
331	C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: empty input skipped");	309	C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: empty input skipped");
332	syslog( "LOG_ERR", "sip_protocol_loop: empty input skipped" );
333	print("96$CR");	310	print("96$CR");
334	next;	311	next;
335	}	312	}
Lines 337-347 sub sip_protocol_loop { Link Here
337	my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );	314	my $status = C4::SIP::Sip::MsgType::handle( $inputbuf, $self, q{} );
338	if ( !$status ) {	315	if ( !$status ) {
339	C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: failed to handle " . substr( $inputbuf, 0, 2 ) );	316	C4::SIP::SIPServer::get_logger()->error("sip_protocol_loop: failed to handle " . substr( $inputbuf, 0, 2 ) );
340	syslog(
341	"LOG_ERR",
342	"sip_protocol_loop: failed to handle %s",
343	substr( $inputbuf, 0, 2 )
344	);
345	}	317	}
346	next if $status eq REQUEST_ACS_RESEND;	318	next if $status eq REQUEST_ACS_RESEND;
347	}	319	}
Lines 377-394 sub read_request { Link Here
377	}	349	}
378	else {	350	else {
379	C4::SIP::SIPServer::get_logger()->debug('EOF returned on read');	351	C4::SIP::SIPServer::get_logger()->debug('EOF returned on read');
380	syslog( 'LOG_DEBUG', 'EOF returned on read' );
381	return;	352	return;
382	}	353	}
383	my $len = length $buffer;	354	my $len = length $buffer;
384	if ( $len != $raw_length ) {	355	if ( $len != $raw_length ) {
385	my $trim = $raw_length - $len;	356	my $trim = $raw_length - $len;
386	C4::SIP::SIPServer::get_logger()->debug("read_request trimmed $trim character(s) ");	357	C4::SIP::SIPServer::get_logger()->debug("read_request trimmed $trim character(s) ");
387	syslog( 'LOG_DEBUG', "read_request trimmed $trim character(s) " );
388	}	358	}
389		359
390	C4::SIP::SIPServer::get_logger()->info("INPUT MSG: '$buffer'");	360	C4::SIP::SIPServer::get_logger()->info("INPUT MSG: '$buffer'");
391	syslog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
392	return $buffer;	361	return $buffer;
393	}	362	}
394		363
Lines 425-431 sub get_timeout { Link Here
425	my $rv = sprintf( "%03d", $policy->{timeout} // 0 );	394	my $rv = sprintf( "%03d", $policy->{timeout} // 0 );
426	if( length($rv) != 3 ) {	395	if( length($rv) != 3 ) {
427	C4::SIP::SIPServer::get_logger()->error("LOG_ERR", "Policy timeout has wrong size: '$rv'");	396	C4::SIP::SIPServer::get_logger()->error("LOG_ERR", "Policy timeout has wrong size: '$rv'");
428	syslog( "LOG_ERR", "Policy timeout has wrong size: '%s'", $rv );
429	return '000';	397	return '000';
430	}	398	}
431	return $rv;	399	return $rv;

Lines 9-15 package C4::SIP::ILS::Item; Link Here

(-)a/C4/SIP/ILS/Item.pm (-4 lines)
9	use strict;	9	use strict;
10	use warnings;	10	use warnings;
11		11
12	use Sys::Syslog qw(syslog);
13	use Carp;	12	use Carp;
14		13
15	use C4::SIP::SIPServer;	14	use C4::SIP::SIPServer;
Lines 80-86 sub new { Link Here
80	my $item = GetBiblioFromItemNumber($itemnumber); # actually biblio., biblioitems. AND items.* (overkill)	79	my $item = GetBiblioFromItemNumber($itemnumber); # actually biblio., biblioitems. AND items.* (overkill)
81	if (! $item) {	80	if (! $item) {
82	C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): not found");	81	C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): not found");
83	syslog("LOG_DEBUG", "new ILS::Item('%s'): not found", $item_id);
84	warn "new ILS::Item($item_id) : No item '$item_id'.";	82	warn "new ILS::Item($item_id) : No item '$item_id'.";
85	return;	83	return;
86	}	84	}
Lines 109-115 sub new { Link Here
109	bless $self, $type;	107	bless $self, $type;
110		108
111	C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): found with title '$self->{title}'");	109	C4::SIP::SIPServer::get_logger()->debug("new ILS::Item('$item_id'): found with title '$self->{title}'");
112	syslog("LOG_DEBUG", "new ILS::Item('%s'): found with title '%s'",
113	$item_id, $self->{title});	110	$item_id, $self->{title});
114		111
115	return $self;	112	return $self;
Lines 173-179 sub hold_patron_name { Link Here
173	my $holder = GetMember(borrowernumber=>$borrowernumber);	170	my $holder = GetMember(borrowernumber=>$borrowernumber);
174	unless ($holder) {	171	unless ($holder) {
175	C4::SIP::SIPServer::get_logger()->debug("While checking hold, GetMember failed for borrowernumber '$borrowernumber'");	172	C4::SIP::SIPServer::get_logger()->debug("While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
176	syslog("LOG_ERR", "While checking hold, GetMember failed for borrowernumber '$borrowernumber'");
177	return;	173	return;
178	}	174	}
179	my $email = $holder->{email} \|\| '';	175	my $email = $holder->{email} \|\| '';

Lines 12-18 use warnings; Link Here

(-)a/C4/SIP/ILS/Patron.pm (-6 lines)
12	use Exporter;	12	use Exporter;
13	use Carp;	13	use Carp;
14		14
15	use Sys::Syslog qw(syslog);
16	use Data::Dumper;	15	use Data::Dumper;
17		16
18	use C4::Debug;	17	use C4::Debug;
Lines 35-41 sub new { Link Here
35	$debug and warn "new Patron (GetMember): " . Dumper($kp);	34	$debug and warn "new Patron (GetMember): " . Dumper($kp);
36	unless (defined $kp) {	35	unless (defined $kp) {
37	C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): no such patron");	36	C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): no such patron");
38	syslog("LOG_DEBUG", "new ILS::Patron(%s): no such patron", $patron_id);
39	return;	37	return;
40	}	38	}
41	$kp = GetMemberDetails($kp->{borrowernumber});	39	$kp = GetMemberDetails($kp->{borrowernumber});
Lines 124-130 sub new { Link Here
124	$self = \%ilspatron;	122	$self = \%ilspatron;
125	$debug and warn Dumper($self);	123	$debug and warn Dumper($self);
126	C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): found patron '$self->{id}'");	124	C4::SIP::SIPServer::get_logger()->debug("new ILS::Patron($patron_id): found patron '$self->{id}'");
127	syslog("LOG_DEBUG", "new ILS::Patron(%s): found patron '%s'", $patron_id,$self->{id});
128	bless $self, $type;	125	bless $self, $type;
129	return $self;	126	return $self;
130	}	127	}
Lines 361-369 sub enable { Link Here
361	}	358	}
362	C4::SIP::SIPServer::get_logger()->debug("Patron($self->{id})->enable: charge: $self->{charge_ok}, ".	359	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	"renew:$self->{renew_ok}, recall:$self->{recall_ok}, hold:$self->{hold_ok}");
364	syslog("LOG_DEBUG", "Patron(%s)->enable: charge: %s, renew:%s, recall:%s, hold:%s",
365	$self->{id}, $self->{charge_ok}, $self->{renew_ok},
366	$self->{recall_ok}, $self->{hold_ok});
367	$self->{screen_msg} = "Enable feature not implemented."; # "All privileges restored."; # TODO: not really affecting patron record	361	$self->{screen_msg} = "Enable feature not implemented."; # "All privileges restored."; # TODO: not really affecting patron record
368	return $self;	362	return $self;
369	}	363	}

Lines 8-14 use warnings; Link Here

(-)a/C4/SIP/ILS/Transaction/Checkout.pm (-3 lines)
8	use strict;	8	use strict;
9		9
10	use POSIX qw(strftime);	10	use POSIX qw(strftime);
11	use Sys::Syslog qw(syslog);
12	use Data::Dumper;	11	use Data::Dumper;
13	use CGI qw ( -utf8 );	12	use CGI qw ( -utf8 );
14		13
Lines 48-54 sub new { Link Here
48	sub do_checkout {	47	sub do_checkout {
49	my $self = shift;	48	my $self = shift;
50	C4::SIP::SIPServer::get_logger()->debug("ILS::Transaction::Checkout performing checkout...");	49	C4::SIP::SIPServer::get_logger()->debug("ILS::Transaction::Checkout performing checkout...");
51	syslog('LOG_DEBUG', "ILS::Transaction::Checkout performing checkout...");
52	my $pending = $self->{item}->pending_queue;	50	my $pending = $self->{item}->pending_queue;
53	my $shelf = $self->{item}->hold_shelf;	51	my $shelf = $self->{item}->hold_shelf;
54	my $barcode = $self->{item}->id;	52	my $barcode = $self->{item}->id;
Lines 100-106 sub do_checkout { Link Here
100	$self->screen_msg($needsconfirmation->{$confirmation});	98	$self->screen_msg($needsconfirmation->{$confirmation});
101	$noerror = 0;	99	$noerror = 0;
102	C4::SIP::SIPServer::get_logger()->debug("Blocking checkout Reason:$confirmation");	100	C4::SIP::SIPServer::get_logger()->debug("Blocking checkout Reason:$confirmation");
103	syslog('LOG_DEBUG', "Blocking checkout Reason:$confirmation");
104	}	101	}
105	}	102	}
106	}	103	}

Lines 6-13 package C4::SIP::ILS::Transaction::RenewAll; Link Here

(-)a/C4/SIP/ILS/Transaction/RenewAll.pm (-8 lines)
6	use strict;	6	use strict;
7	use warnings;	7	use warnings;
8		8
9	use Sys::Syslog qw(syslog);
10
11	use C4::SIP::ILS::Item;	9	use C4::SIP::ILS::Item;
12		10
13	use C4::Members qw( GetMember );	11	use C4::Members qw( GetMember );
Lines 43-54 sub do_renew_all { Link Here
43	my $item = C4::SIP::ILS::Item->new($item_id);	41	my $item = C4::SIP::ILS::Item->new($item_id);
44	if ( !defined($item) ) {	42	if ( !defined($item) ) {
45	C4::SIP::SIPServer::get_logger()->debug("renew_all: Invalid item id '$item_id' associated with patron '$patron->id'");	43	C4::SIP::SIPServer::get_logger()->debug("renew_all: Invalid item id '$item_id' associated with patron '$patron->id'");
46	syslog(
47	'LOG_WARNING',
48	q\|renew_all: Invalid item id '%s' associated with patron '%s'\|,
49	$item_id,
50	$patron->id
51	);
52		44
53	# $all_ok = 0; Do net set as still ok	45	# $all_ok = 0; Do net set as still ok
54	push @{ $self->unrenewed }, $item_id;	46	push @{ $self->unrenewed }, $item_id;

Lines 14-24 perl modules to run: Link Here

(-)a/C4/SIP/README (-4 / +6 lines)
14		14
15	LOGGING	15	LOGGING
16		16
17	SIPServer uses syslog() for status and debugging messages. All	17	By default, SIPServer uses syslog via log4perl for status and debugging messages.
18	syslog messages are logged using the syslog facility 'local6'.	18	All syslog messages are logged using the syslog facility 'local6'.
19	If you need to change this, because something else on your system	19	If you need to change this, because something else on your system
20	is already using that facililty, just change the definition of	20	is already using that facililty, just change the definition of
21	'LOG_SIP' at the top of the file SIPServer.pm	21	'ident' and/or 'facility' in the SIP section of file log4perl.conf.
22		22
23	Make sure to update your syslog configuration to capture facility	23	Make sure to update your syslog configuration to capture facility
24	'local6' and record it.	24	'local6' and record it.
		25
		26	See the log4perl documenation for logging to a file or other services.

Lines 8-14 use strict; Link Here

(-)a/C4/SIP/Sip.pm (-7 lines)
8	use warnings;	8	use warnings;
9	use Exporter;	9	use Exporter;
10	use Encode;	10	use Encode;
11	use Sys::Syslog qw(syslog);
12	use POSIX qw(strftime);	11	use POSIX qw(strftime);
13	use Socket qw(:crlf);	12	use Socket qw(:crlf);
14	use IO::Handle;	13	use IO::Handle;
Lines 62-70 sub add_field { Link Here
62		61
63	if (!defined($value)) {	62	if (!defined($value)) {
64	C4::SIP::SIPServer::get_logger()->debug("add_field: Undefined value being added to '$field_id'");	63	C4::SIP::SIPServer::get_logger()->debug("add_field: Undefined value being added to '$field_id'");
65	syslog("LOG_DEBUG", "add_field: Undefined value being added to '%s'",
66	$field_id);
67	$value = '';
68	}	64	}
69	$value=~s/\r/ /g; # CR terminates a sip message	65	$value=~s/\r/ /g; # CR terminates a sip message
70	# Protect against them in sip text fields	66	# Protect against them in sip text fields
Lines 118-125 sub add_count { Link Here
118	$count = sprintf("%04d", $count);	114	$count = sprintf("%04d", $count);
119	if (length($count) != 4) {	115	if (length($count) != 4) {
120	C4::SIP::SIPServer::get_logger()->debug("handle_patron_info: $label wrong size: '$count'");	116	C4::SIP::SIPServer::get_logger()->debug("handle_patron_info: $label wrong size: '$count'");
121	syslog("LOG_WARNING", "handle_patron_info: %s wrong size: '%s'",
122	$label, $count);
123	$count = ' ' x 4;	117	$count = ' ' x 4;
124	}	118	}
125	return $count;	119	return $count;
Lines 190-196 sub write_msg { Link Here
190	STDOUT->autoflush(1);	184	STDOUT->autoflush(1);
191	print $msg, $terminator;	185	print $msg, $terminator;
192	C4::SIP::SIPServer::get_logger()->info("OUTPUT MSG: '$msg'");	186	C4::SIP::SIPServer::get_logger()->info("OUTPUT MSG: '$msg'");
193	syslog("LOG_INFO", "OUTPUT MSG: '$msg'");
194	}	187	}
195		188
196	$last_response = $msg;	189	$last_response = $msg;