--- loncom/loncnew 2003/06/13 02:38:43 1.9 +++ loncom/loncnew 2003/07/02 01:12:35 1.12 @@ -2,7 +2,7 @@ # The LearningOnline Network with CAPA # lonc maintains the connections to remote computers # -# $Id: loncnew,v 1.9 2003/06/13 02:38:43 foxr Exp $ +# $Id: loncnew,v 1.12 2003/07/02 01:12:35 foxr Exp $ # # Copyright Michigan State University Board of Trustees # @@ -46,6 +46,19 @@ # Change log: # $Log: loncnew,v $ +# Revision 1.12 2003/07/02 01:12:35 foxr +# - Add some debugging to killthemall +# - Add better error handling to LondReadable +# - Remove tick logging in the timer handler. +# +# Revision 1.11 2003/06/25 01:54:44 foxr +# Fix more problems with transaction failure. +# +# Revision 1.10 2003/06/24 02:46:04 foxr +# Put a limit on the number of times we'll retry a connection. +# Start getting the signal stuff put in as well...note that need to get signals +# going or else 6the client will permanently give up on dead servers. +# # Revision 1.9 2003/06/13 02:38:43 foxr # Add logging in 'expected format' # @@ -63,6 +76,7 @@ use lib "/home/httpd/lib/perl/"; use lib "/home/foxr/newloncapa/types"; use Event qw(:DEFAULT ); use POSIX qw(:signal_h); +use POSIX; use IO::Socket; use IO::Socket::INET; use IO::Socket::UNIX; @@ -120,7 +134,8 @@ my $WorkQueue = Queue->new(); # Qu my $ConnectionCount = 0; my $IdleSeconds = 0; # Number of seconds idle. my $Status = ""; # Current status string. - +my $ConnectionRetries=5; # Number of connection retries allowed. +my $ConnectionRetriesLeft=5; # Number of connection retries remaining. # # The hash below gives the HTML format for log messages @@ -134,7 +149,23 @@ $LogFormats{"INFO"} = "new(">>$execdir/logs/lonnet.perm.log"); + print $fh "$now:$message:$local\n"; +} =pod @@ -181,6 +212,7 @@ sub Log { my $msg = sprintf($finalformat, $message); print $fh $msg; + } @@ -238,13 +270,15 @@ sub SocketDump { =head2 ShowStatus Place some text as our pid status. + and as what we return in a SIGUSR1 =cut sub ShowStatus { - my $status = shift; - $0 = "lonc: ".$status; - $Status = $status; # Make available for logging. - + my $state = shift; + my $now = time; + my $local = localtime($now); + $Status = $local.": ".$state; + $0='lonc: '.$state.' '.$local; } =pod @@ -259,11 +293,7 @@ Invoked each timer tick. sub Tick { my $client; ShowStatus(GetServerHost()." Connection count: ".$ConnectionCount); - Debug(6, "Tick"); - Debug(6, " Current connection count: ".$ConnectionCount); - foreach $client (keys %ActiveClients) { - Debug(7, " Have client: with id: ".$ActiveClients{$client}); - } + # Is it time to prune connection count: @@ -283,12 +313,17 @@ sub Tick { # my $Requests = $WorkQueue->Count(); - if (($ConnectionCount == 0) && ($Requests > 0)) { - my $Connections = ($Requests <= $MaxConnectionCount) ? - $Requests : $MaxConnectionCount; - Debug(1,"Work but no connections, starting ".$Connections." of them"); - for ($i =0; $i < $Connections; $i++) { - MakeLondConnection(); + if (($ConnectionCount == 0) && ($Requests > 0)) { + if ($ConnectionRetriesLeft > 0) { + my $Connections = ($Requests <= $MaxConnectionCount) ? + $Requests : $MaxConnectionCount; + Debug(1,"Work but no connections, start ".$Connections." of them"); + for ($i =0; $i < $Connections; $i++) { + MakeLondConnection(); + } + } else { + Debug(1,"Work in queue, but gave up on connections..flushing\n"); + EmptyQueue(); # Connections can't be established. } } @@ -466,6 +501,7 @@ sub CompleteTransaction { StartClientReply($Transaction, $data); } else { # Delete deferred transaction file. Log("SUCCESS", "A delayed transaction was completed"); + LogPerm("S:$Client:".$Transaction->getRequest()); unlink $Transaction->getFile(); } } @@ -489,6 +525,7 @@ sub StartClientReply { my $Transaction = shift; my $data = shift; + my $Client = $Transaction->getClient(); &Debug(8," Reply was: ".$data); @@ -525,13 +562,12 @@ Parameters: sub FailTransaction { my $transaction = shift; - my $Lond = $transaction->getServer(); - if (!$client->isDeferred()) { # If the transaction is deferred we'll get to it. - my $client = $transcation->getClient(); - StartClientReply($client, "con_lost"); + Debug(1, "Failing transaction: ".$transaction->getRequest()); + if (!$transaction->isDeferred()) { # If the transaction is deferred we'll get to it. + my $client = $transaction->getClient(); + Debug(1," Replying con_lost to ".$transaction->getRequest()); + StartClientReply($transaction, "con_lost\n"); } -# not needed, done elsewhere if active. -# delete $ActiveTransactions{$Lond}; } @@ -544,7 +580,7 @@ sub FailTransaction { =cut sub EmptyQueue { while($WorkQueue->Count()) { - my $request = $Workqueue->dequeue(); # This is a transaction + my $request = $WorkQueue->dequeue(); # This is a transaction FailTransaction($request); } } @@ -683,8 +719,10 @@ sub LondReadable { my $State = $Socket->GetState(); # All action depends on the state. SocketDump(6, $Socket); + my $status = $Socket->Readable(); + &Debug(2, "Socket->Readable returned: $status"); - if($Socket->Readable() != 0) { + if($status != 0) { # bad return from socket read. Currently this means that # The socket has become disconnected. We fail the transaction. @@ -949,7 +987,7 @@ sub QueueDelayed { my $Handle = IO::File->new($reqfile); my $cmd = <$Handle>; chomp $cmd; # There may or may not be a newline... - $cmd = $cmd."\ny"; # now for sure there's exactly one newline. + $cmd = $cmd."\n"; # now for sure there's exactly one newline. my $Transaction = LondTransaction->new($cmd); $Transaction->SetDeferred($reqfile); QueueTransaction($Transaction); @@ -978,7 +1016,10 @@ sub MakeLondConnection { if($Connection == undef) { # Needs to be more robust later. Log("CRITICAL","Failed to make a connection with lond."); + $ConnectionRetriesLeft--; + return 0; # Failure. } else { + $ConnectionRetriesLeft = $ConnectionRetries; # success resets the count # The connection needs to have writability # monitored in order to send the init sequence # that starts the whole authentication/key @@ -1006,6 +1047,7 @@ sub MakeLondConnection { } Log("SUCESS", "Created connection ".$ConnectionCount ." to host ".GetServerHost()); + return 1; # Return success. } } @@ -1103,7 +1145,6 @@ sub QueueTransaction { =pod =head2 ClientRequest - Callback that is called when data can be read from the UNIX domain socket connecting us with an apache server process. @@ -1128,12 +1169,13 @@ sub ClientRequest { close($socket); $watcher->cancel(); delete($ActiveClients{$socket}); + return; } Debug(8,"Data: ".$data." this read: ".$thisread); $data = $data.$thisread; # Append new data. $watcher->data($data); if($data =~ /(.*\n)/) { # Request entirely read. - if($data == "close_connection_exit\n") { + if($data eq "close_connection_exit\n") { Log("CRITICAL", "Request Close Connection ... exiting"); CloseAllLondConnections(); @@ -1250,6 +1292,25 @@ sub SetupLoncListener { =pod +=head2 SignalledToDeath + +Called in response to a signal that causes a chid process to die. + +=cut + + +sub SignalledToDeath { + Debug(2,"Signalled to death!"); + my ($signal) = @_; + chomp($signal); + Log("CRITICAL", "Abnormal exit. Child $$ for $RemoteHost " + ."died through "."\"$signal\""); + LogPerm("F:lonc: $$ on $RemoteHost signalled to death: " + ."\"$signal\""); + die("Signal abnormal end"); + exit 0; + +} =head2 ChildProcess This sub implements a child process for a single lonc daemon. @@ -1261,12 +1322,12 @@ sub ChildProcess { # For now turn off signals. - $SIG{QUIT} = IGNORE; + $SIG{QUIT} = \&SignalledToDeath; $SIG{HUP} = IGNORE; $SIG{USR1} = IGNORE; - $SIG{INT} = IGNORE; + $SIG{INT} = DEFAULT; $SIG{CHLD} = IGNORE; - $SIG{__DIE__} = IGNORE; + $SIG{__DIE__} = \&SignalledToDeath; SetupTimer(); @@ -1278,12 +1339,9 @@ sub ChildProcess { # Setup the initial server connection: - &MakeLondConnection(); + # &MakeLondConnection(); // let first work requirest do it. + - if($ConnectionCount == 0) { - Debug(1,"Could not make initial connection..\n"); - Debug(1,"Will retry when there's work to do\n"); - } Debug(9,"Entering event loop"); my $ret = Event::loop(); # Start the main event loop. @@ -1294,15 +1352,21 @@ sub ChildProcess { # Create a new child for host passed in: sub CreateChild { + my $sigset = POSIX::SigSet->new(SIGINT); + sigprocmask(SIG_BLOCK, $sigset); my $host = shift; $RemoteHost = $host; Log("CRITICAL", "Forking server for ".$host); $pid = fork; if($pid) { # Parent $ChildHash{$pid} = $RemoteHost; + sigprocmask(SIG_UNBLOCK, $sigset); + } else { # child. ShowStatus("Connected to ".$RemoteHost); - ChildProcess; + $SIG{INT} = DEFAULT; + sigprocmask(SIG_UNBLOCK, $sigset); + ChildProcess; # Does not return. } } @@ -1358,11 +1422,20 @@ while (! $HostIterator->end()) { CreateChild($hostentryref->[0]); $HostIterator->next(); } +$RemoteHost = "Parent Server"; # Maintain the population: ShowStatus("Parent keeping the flock"); +# +# Set up parent signals: +# + +$SIG{INT} = \&KillThemAll; +$SIG{TERM} = \&KillThemAll; + + while(1) { $deadchild = wait(); if(exists $ChildHash{$deadchild}) { # need to restart. @@ -1375,6 +1448,31 @@ while(1) { } } +=pod + +=head1 KillThemAll + +Signal handler that kills all children by sending them a +SIGINT. Responds to sigint and sigterm. + +=cut + +sub KillThemAll { + Debug(2, "Kill them all!!"); + local($SIG{CHLD}) = 'IGNORE'; # Our children >will< die. + foreach $pid (keys %ChildHash) { + my $serving = $ChildHash{$pid}; + Debug(2, "Killing lonc for $serving pid = $pid"); + ShowStatus("Killing lonc for $serving pid = $pid"); + Log("CRITICAL", "Killing lonc for $serving pid = $pid"); + kill('INT', $pid); + } + Log("CRITICAL", "Killing the master process."); + exit +} + +=pod + =head1 Theory The event class is used to build this as a single process with an