LP#1339190 more multiplex debug logging

Expose the PID in a few more places, since SIP/syslog doesn't log that.
Also log the ILS state if available.

Signed-off-by: Bill Erickson <berick@esilibrary.com>

diff --git a/SIPServer.pm b/SIPServer.pm
index db86454..07b54bc 100755 (executable)
--- a/SIPServer.pm
+++ b/SIPServer.pm
@@ -239,21 +239,32 @@ sub check_pending_connections {
     my $values = $cache->get_multi(@keys);
 
     for my $key (keys %$values) {
+        (my $pid = $key) =~ s/sip_pending_auth_(\d+)/$1/g;
+
         my $VAR1; # for Dump() -> eval;
         eval $values->{$key}; # Data::Dumper->Dump string
 
         my $id = $VAR1->{id};
         $active_connections{$id}{net_server}{$_} = $VAR1->{net_server_parts}{$_}
             for (keys %{$VAR1->{net_server_parts}});
-        delete $active_connections{$id} unless $VAR1->{success};
 
-        # clean up ---
+        if ($VAR1->{success}) {
 
-        (my $pid = $key) =~ s/sip_pending_auth_(\d+)/$1/g;
+            if ($active_connections{$id}{net_server}{state}) {
+                local $Data::Dumper::Indent = 0;
+                syslog('LOG_DEBUG', "multi: pid=$pid id=$id has state: ".
+                    Dumper($active_connections{$id}{net_server}{state}));
+            }
+
+        } else {
+            syslog('LOG_INFO', "Child $pid / $id failed SIP login; removing connection");
+            delete $active_connections{$id};
+        }
+
+        # clean up ---
 
         syslog('LOG_DEBUG', 
             "multi: pending connection for pid=$pid / id=$id resolved");
-
         $cache->delete($key);
         @pending_connections = grep {$_ != $pid} @pending_connections;
     }
@@ -379,6 +390,8 @@ sub mux_input {
                 $self->{login_complete_called} = 1;
             };
 
+            syslog('LOG_DEBUG', "Child $$ / $conn_id kicking of login process");
+
             eval { &$transport($self, $str_fh) };
 
             if ($@) {