--- loncom/loncnew 2003/12/11 23:18:37 1.34 +++ loncom/loncnew 2004/02/09 10:58:03 1.40 @@ -2,7 +2,7 @@ # The LearningOnline Network with CAPA # lonc maintains the connections to remote computers # -# $Id: loncnew,v 1.34 2003/12/11 23:18:37 albertel Exp $ +# $Id: loncnew,v 1.40 2004/02/09 10:58:03 foxr Exp $ # # Copyright Michigan State University Board of Trustees # @@ -35,12 +35,12 @@ # - Add ability to create/negotiate lond connections (done). # - Add general logic for dispatching requests and timeouts. (done). # - Add support for the lonc/lond requests. (done). -# - Add logging/status monitoring. -# - Add Signal handling - HUP restarts. USR1 status report. +# - Add logging/status monitoring. (done) +# - Add Signal handling - HUP restarts. USR1 status report. (done) # - Add Configuration file I/O (done). -# - Add management/status request interface. +# - Add management/status request interface. (done) # - Add deferred request capability. (done) -# - Detect transmission timeouts. +# - Detect transmission timeouts. (done) # use strict; @@ -63,11 +63,6 @@ use LONCAPA::Configuration; use LONCAPA::HashIterator; -# -# Disable all signals we might receive from outside for now. -# - - # Read the httpd configuration file to get perl variables # normally set in apache modules: @@ -89,6 +84,8 @@ my $DebugLevel = 0; my $NextDebugLevel= 2; # So Sigint can toggle this. my $IdleTimeout= 3600; # Wait an hour before pruning connections. +my $LogTransactions = 0; # When True, all transactions/replies get logged. + # # The variables below are only used by the child processes. # @@ -105,6 +102,7 @@ my $Status = ""; # Current stat my $RecentLogEntry = ""; my $ConnectionRetries=2; # Number of connection retries allowed. my $ConnectionRetriesLeft=2; # Number of connection retries remaining. +my $LondVersion = "unknown"; # Version of lond we talk with. # # The hash below gives the HTML format for log messages @@ -210,7 +208,6 @@ sub GetPeername { return $peerfile; } } -#----------------------------- Timer management ------------------------ =pod =head2 Debug @@ -262,11 +259,14 @@ sub ShowStatus { =cut sub SocketTimeout { my $Socket = shift; - + Log("WARNING", "A socket timeout was detected"); + Debug(0, " SocketTimeout called: "); + $Socket->Dump(); KillSocket($Socket); # A transaction timeout also counts as # a connection failure: $ConnectionRetriesLeft--; } +#----------------------------- Timer management ------------------------ =pod @@ -301,14 +301,10 @@ sub Tick { # # For each inflight transaction, tick down its timeout counter. # - foreach my $item (keys %ActiveTransactions) { - my $Socket = $ActiveTransactions{$item}->getServer(); - $Socket->Tick(); - } + foreach my $item (keys %ActiveConnections) { my $State = $ActiveConnections{$item}->data->GetState(); - if ($State ne 'Idle' && $State ne 'SendingRequest' && - $State ne 'ReceivingReply') { + if ($State ne 'Idle') { Debug(5,"Ticking Socket $State $item"); $ActiveConnections{$item}->data->Tick(); } @@ -515,6 +511,9 @@ sub CompleteTransaction { if (!$Transaction->isDeferred()) { # Normal transaction my $data = $Socket->GetReply(); # Data to send. + if($LogTransactions) { + Log("SUCCESS", "Reply from lond: '$data'"); + } StartClientReply($Transaction, $data); } else { # Delete deferred transaction file. Log("SUCCESS", "A delayed transaction was completed"); @@ -659,9 +658,9 @@ sub KillSocket { } if(exists($ActiveConnections{$Socket})) { delete($ActiveConnections{$Socket}); + $ConnectionCount--; + if ($ConnectionCount < 0) { $ConnectionCount = 0; } } - $ConnectionCount--; - # If the connection count has gone to zero and there is work in the # work queue, the work all gets failed with con_lost. # @@ -692,6 +691,17 @@ The connection must echo the challenge b The challenge has been replied to. The we are receiveing the 'ok' from the partner. +=head3 State=ReadingVersionString + +We have requested the lond version and are reading the +version back. Upon completion, we'll store the version away +for future use(?). + +=head3 State=HostSet + +We have selected the domain name of our peer (multhomed hosts) +and are getting the reply (presumably ok) back. + =head3 State=RequestingKey The ok has been received and we need to send the request for @@ -730,96 +740,119 @@ transaction is in progress, the socket a sub LondReadable { - my $Event = shift; - my $Watcher = $Event->w; - my $Socket = $Watcher->data; - my $client = undef; - - &Debug(6,"LondReadable called state = ".$Socket->GetState()); + my $Event = shift; + my $Watcher = $Event->w; + my $Socket = $Watcher->data; + my $client = undef; + + &Debug(6,"LondReadable called state = ".$Socket->GetState()); + + + my $State = $Socket->GetState(); # All action depends on the state. + + SocketDump(6, $Socket); + my $status = $Socket->Readable(); + + &Debug(2, "Socket->Readable returned: $status"); + + if($status != 0) { + # bad return from socket read. Currently this means that + # The socket has become disconnected. We fail the transaction. + + Log("WARNING", + "Lond connection lost."); + if(exists($ActiveTransactions{$Socket})) { + FailTransaction($ActiveTransactions{$Socket}); + } + $Watcher->cancel(); + KillSocket($Socket); + $ConnectionRetriesLeft--; # Counts as connection failure + return; + } + SocketDump(6,$Socket); - - my $State = $Socket->GetState(); # All action depends on the state. - - SocketDump(6, $Socket); - my $status = $Socket->Readable(); - - &Debug(2, "Socket->Readable returned: $status"); - - if($status != 0) { - # bad return from socket read. Currently this means that - # The socket has become disconnected. We fail the transaction. - - Log("WARNING", - "Lond connection lost."); - if(exists($ActiveTransactions{$Socket})) { - FailTransaction($ActiveTransactions{$Socket}); - } - $Watcher->cancel(); - KillSocket($Socket); - $ConnectionRetriesLeft--; # Counts as connection failure - return; - } - SocketDump(6,$Socket); - - $State = $Socket->GetState(); # Update in case of transition. - &Debug(6, "After read, state is ".$State); + $State = $Socket->GetState(); # Update in case of transition. + &Debug(6, "After read, state is ".$State); if($State eq "Initialized") { - } elsif ($State eq "ChallengeReceived") { + } elsif ($State eq "ChallengeReceived") { # The challenge must be echoed back; The state machine # in the connection takes care of setting that up. Just # need to transition to writable: - $Watcher->cb(\&LondWritable); - $Watcher->poll("w"); - - } elsif ($State eq "ChallengeReplied") { + $Watcher->cb(\&LondWritable); + $Watcher->poll("w"); + } elsif ($State eq "ChallengeReplied") { - } elsif ($State eq "RequestingKey") { + } elsif ($State eq "RequestingVersion") { + # Need to ask for the version... that is writiability: + + $Watcher->cb(\&LondWritable); + $Watcher->poll("w"); + + } elsif ($State eq "ReadingVersionString") { + # Read the rest of the version string... + } elsif ($State eq "SetHost") { + # Need to request the actual domain get set... + + $Watcher->cb(\&LondWritable); + $Watcher->poll("w"); + } elsif ($State eq "HostSet") { + # Reading the 'ok' from the peer. + + } elsif ($State eq "RequestingKey") { # The ok was received. Now we need to request the key # That requires us to be writable: - $Watcher->cb(\&LondWritable); - $Watcher->poll("w"); + $Watcher->cb(\&LondWritable); + $Watcher->poll("w"); - } elsif ($State eq "ReceivingKey") { + } elsif ($State eq "ReceivingKey") { - } elsif ($State eq "Idle") { + } elsif ($State eq "Idle") { + + # This is as good a spot as any to get the peer version + # string: + + if($LondVersion eq "unknown") { + $LondVersion = $Socket->PeerVersion(); + Log("INFO", "Connected to lond version: $LondVersion"); + } # If necessary, complete a transaction and then go into the # idle queue. # Note that a trasition to idle indicates a live lond # on the other end so reset the connection retries. # - $ConnectionRetriesLeft = $ConnectionRetries; # success resets the count - $Watcher->cancel(); - if(exists($ActiveTransactions{$Socket})) { - Debug(5,"Completing transaction!!"); - CompleteTransaction($Socket, - $ActiveTransactions{$Socket}); - } else { - Log("SUCCESS", "Connection ".$ConnectionCount." to " - .$RemoteHost." now ready for action"); - } - ServerToIdle($Socket); # Next work unit or idle. + $ConnectionRetriesLeft = $ConnectionRetries; # success resets the count + $Watcher->cancel(); + if(exists($ActiveTransactions{$Socket})) { + Debug(5,"Completing transaction!!"); + CompleteTransaction($Socket, + $ActiveTransactions{$Socket}); + } else { + Log("SUCCESS", "Connection ".$ConnectionCount." to " + .$RemoteHost." now ready for action"); + } + ServerToIdle($Socket); # Next work unit or idle. - } elsif ($State eq "SendingRequest") { + } elsif ($State eq "SendingRequest") { # We need to be writable for this and probably don't belong # here inthe first place. - Deubg(6, "SendingRequest state encountered in readable"); - $Watcher->poll("w"); - $Watcher->cb(\&LondWritable); + Deubg(6, "SendingRequest state encountered in readable"); + $Watcher->poll("w"); + $Watcher->cb(\&LondWritable); - } elsif ($State eq "ReceivingReply") { + } elsif ($State eq "ReceivingReply") { - } else { + } else { # Invalid state. - Debug(4, "Invalid state in LondReadable"); - } + Debug(4, "Invalid state in LondReadable"); + } } =pod @@ -899,100 +932,131 @@ sub LondWritable { SocketDump(6,$Socket); - if ($State eq "Connected") { - - if ($Socket->Writable() != 0) { - # The write resulted in an error. - # We'll treat this as if the socket got disconnected: - Log("WARNING", "Connection to ".$RemoteHost. - " has been disconnected"); - FailTransaction($ActiveTransactions{$Socket}); - $Watcher->cancel(); - KillSocket($Socket); - return; - } - # "init" is being sent... + if ($State eq "Connected") { - - } elsif ($State eq "Initialized") { + if ($Socket->Writable() != 0) { + # The write resulted in an error. + # We'll treat this as if the socket got disconnected: + Log("WARNING", "Connection to ".$RemoteHost. + " has been disconnected"); + FailTransaction($ActiveTransactions{$Socket}); + $Watcher->cancel(); + KillSocket($Socket); + return; + } + + # "init" is being sent... + + } elsif ($State eq "Initialized") { - # Now that init was sent, we switch - # to watching for readability: + # Now that init was sent, we switch + # to watching for readability: - $Watcher->cb(\&LondReadable); - $Watcher->poll("r"); + $Watcher->cb(\&LondReadable); + $Watcher->poll("r"); - } elsif ($State eq "ChallengeReceived") { - # We received the challenge, now we - # are echoing it back. This is a no-op, - # we're waiting for the state to change + } elsif ($State eq "ChallengeReceived") { + # We received the challenge, now we + # are echoing it back. This is a no-op, + # we're waiting for the state to change - if($Socket->Writable() != 0) { + if($Socket->Writable() != 0) { - $Watcher->cancel(); - KillSocket($Socket); - return; - } + $Watcher->cancel(); + KillSocket($Socket); + return; + } - } elsif ($State eq "ChallengeReplied") { - # The echo was sent back, so we switch - # to watching readability. - - $Watcher->cb(\&LondReadable); - $Watcher->poll("r"); - - } elsif ($State eq "RequestingKey") { - # At this time we're requesting the key. - # again, this is essentially a no-op. - # we'll write the next chunk until the - # state changes. + } elsif ($State eq "ChallengeReplied") { + # The echo was sent back, so we switch + # to watching readability. + + $Watcher->cb(\&LondReadable); + $Watcher->poll("r"); + } elsif ($State eq "RequestingVersion") { + # Sending the peer a version request... + + if($Socket->Writable() != 0) { + $Watcher->cancel(); + KillSocket($Socket); + return; + } + } elsif ($State eq "ReadingVersionString") { + # Transition to read since we have sent the + # version command and now just need to read the + # version string from the peer: + + $Watcher->cb(\&LondReadable); + $Watcher->poll("r"); + + } elsif ($State eq "SetHost") { + # Setting the remote domain... + + if($Socket->Writable() != 0) { + $Watcher->cancel(); + KillSocket($Socket); + return; + } + } elsif ($State eq "HostSet") { + # Back to readable to get the ok. + + $Watcher->cb(\&LondReadable); + $Watcher->poll("r"); + + + } elsif ($State eq "RequestingKey") { + # At this time we're requesting the key. + # again, this is essentially a no-op. + # we'll write the next chunk until the + # state changes. + + if($Socket->Writable() != 0) { + # Write resulted in an error. + + $Watcher->cancel(); + KillSocket($Socket); + return; + + } + } elsif ($State eq "ReceivingKey") { + # Now we need to wait for the key + # to come back from the peer: - if($Socket->Writable() != 0) { - # Write resulted in an error. + $Watcher->cb(\&LondReadable); + $Watcher->poll("r"); - $Watcher->cancel(); - KillSocket($Socket); - return; - - } - } elsif ($State eq "ReceivingKey") { - # Now we need to wait for the key - # to come back from the peer: - - $Watcher->cb(\&LondReadable); - $Watcher->poll("r"); - - } elsif ($State eq "SendingRequest") { - # At this time we are sending a request to the + } elsif ($State eq "SendingRequest") { + + # At this time we are sending a request to the # peer... write the next chunk: - if($Socket->Writable() != 0) { + if($Socket->Writable() != 0) { - if(exists($ActiveTransactions{$Socket})) { - Debug(3, "Lond connection lost, failing transactions"); - FailTransaction($ActiveTransactions{$Socket}); - } - $Watcher->cancel(); - KillSocket($Socket); - return; + if(exists($ActiveTransactions{$Socket})) { + Debug(3, "Lond connection lost, failing transactions"); + FailTransaction($ActiveTransactions{$Socket}); + } + $Watcher->cancel(); + KillSocket($Socket); + return; - } - - } elsif ($State eq "ReceivingReply") { - # The send has completed. Wait for the - # data to come in for a reply. - Debug(8,"Writable sent request/receiving reply"); - $Watcher->cb(\&LondReadable); - $Watcher->poll("r"); + } - } else { - # Control only passes here on an error: - # the socket state does not match any - # of the known states... so an error - # must be logged. + } elsif ($State eq "ReceivingReply") { + # The send has completed. Wait for the + # data to come in for a reply. + Debug(8,"Writable sent request/receiving reply"); + $Watcher->cb(\&LondReadable); + $Watcher->poll("r"); + + } else { + # Control only passes here on an error: + # the socket state does not match any + # of the known states... so an error + # must be logged. - &Debug(4, "Invalid socket state ".$State."\n"); - } + &Debug(4, "Invalid socket state ".$State."\n"); + } } =pod @@ -1219,6 +1283,9 @@ sub ClientRequest { exit; } Debug(8, "Complete transaction received: ".$data); + if($LogTransactions) { + Log("SUCCESS", "Transaction: '$data'"); # Transaction has \n. + } my $Transaction = LondTransaction->new($data); $Transaction->SetClient($socket); QueueTransaction($Transaction); @@ -1327,6 +1394,24 @@ sub SetupLoncListener { fd => $socket); } +# +# Toggle transaction logging. +# Implicit inputs: +# LogTransactions +# Implicit Outputs: +# LogTransactions +sub ToggleTransactionLogging { + print STDERR "Toggle transaction logging...\n"; + if(!$LogTransactions) { + $LogTransactions = 1; + } else { + $LogTransactions = 0; + } + + + Log("SUCCESS", "Toggled transaction logging: $LogTransactions \n"); +} + =pod =head2 ChildStatus @@ -1346,6 +1431,20 @@ sub ChildStatus { my $fh = IO::File->new(">>$docdir/lon-status/loncstatus.txt"); print $fh $$."\t".$RemoteHost."\t".$Status."\t". $RecentLogEntry."\n"; + # + # Write out information about each of the connections: + # + print $fh "Active connection statuses: \n"; + my $i = 1; + print STDERR "================================= Socket Status Dump:\n"; + foreach my $item (keys %ActiveConnections) { + my $Socket = $ActiveConnections{$item}->data; + my $state = $Socket->GetState(); + print $fh "Connection $i State: $state\n"; + print STDERR "---------------------- Connection $i \n"; + $Socket->Dump(); + $i++; + } $ConnectionRetriesLeft = $ConnectionRetries; } @@ -1410,6 +1509,8 @@ sub ChildProcess { Event->signal(signal => "USR1", cb => \&ChildStatus, data => "USR1"); + Event->signal(signal => "USR2", + cb => \&ToggleTransactionLogging); Event->signal(signal => "INT", cb => \&ToggleDebug, data => "INT");