--- loncom/loncnew 2003/06/25 01:54:44 1.11 +++ loncom/loncnew 2004/02/17 09:43:21 1.42 @@ -2,13 +2,12 @@ # The LearningOnline Network with CAPA # lonc maintains the connections to remote computers # -# $Id: loncnew,v 1.11 2003/06/25 01:54:44 foxr Exp $ +# $Id: loncnew,v 1.42 2004/02/17 09:43:21 foxr Exp $ # # Copyright Michigan State University Board of Trustees # # This file is part of the LearningOnline Network with CAPA (LON-CAPA). -# -# LON-CAPA is free software; you can redistribute it and/or modify +## LON-CAPA is free software; you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by # the Free Software Foundation; either version 2 of the License, or # (at your option) any later version. @@ -27,7 +26,7 @@ # http://www.lon-capa.org/ # # -# new lonc handles n requestors spread out bver m connections to londs. +# new lonc handles n request out bver m connections to londs. # This module is based on the Event class. # Development iterations: # - Setup basic event loop. (done) @@ -36,41 +35,19 @@ # - 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. -# - -# Change log: -# $Log: loncnew,v $ -# 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' -# -# Revision 1.8 2003/06/11 02:04:35 foxr -# Support delayed transactions... this is done uniformly by encapsulating -# transactions in an object ... a LondTransaction that is implemented by -# LondTransaction.pm -# -# Revision 1.7 2003/06/03 01:59:39 foxr -# complete coding to support deferred transactions. -# +# - Detect transmission timeouts. (done) # +use strict; 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; @@ -86,17 +63,6 @@ use LONCAPA::Configuration; use LONCAPA::HashIterator; -# -# Disable all signals we might receive from outside for now. -# -$SIG{QUIT} = IGNORE; -$SIG{HUP} = IGNORE; -$SIG{USR1} = IGNORE; -$SIG{INT} = IGNORE; -$SIG{CHLD} = IGNORE; -$SIG{__DIE__} = IGNORE; - - # Read the httpd configuration file to get perl variables # normally set in apache modules: @@ -107,19 +73,24 @@ my %perlvar = %{$perlvarref}; # parent and shared variables. my %ChildHash; # by pid -> host. +my %HostToPid; # By host -> pid. +my %HostHash; # by loncapaname -> IP. my $MaxConnectionCount = 10; # Will get from config later. my $ClientConnection = 0; # Uniquifier for client events. 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. # my $RemoteHost; # Name of host child is talking to. -my $UnixSocketDir= "/home/httpd/sockets"; +my $UnixSocketDir= $perlvar{'lonSockDir'}; my $IdleConnections = Stack->new(); # Set of idle connections my %ActiveConnections; # Connections to the remote lond. my %ActiveTransactions; # LondTransactions in flight. @@ -128,8 +99,10 @@ 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. +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 @@ -204,6 +177,7 @@ sub Log { my $execdir = $perlvar{'lonDaemons'}; my $fh = IO::File->new(">>$execdir/logs/lonc.log"); my $msg = sprintf($finalformat, $message); + $RecentLogEntry = $msg; print $fh $msg; @@ -226,7 +200,7 @@ sub GetPeername { my $peerip; if($AdrFamily == AF_INET) { ($peerport, $peerip) = sockaddr_in($peer); - my $peername = gethostbyaddr($iaddr, $AdrFamily); + my $peername = gethostbyaddr($peerip, $AdrFamily); return $peername; } elsif ($AdrFamily == AF_UNIX) { my $peerfile; @@ -234,7 +208,6 @@ sub GetPeername { return $peerfile; } } -#----------------------------- Timer management ------------------------ =pod =head2 Debug @@ -247,7 +220,7 @@ sub Debug { my $level = shift; my $message = shift; if ($level <= $DebugLevel) { - print $message." host = ".$RemoteHost."\n"; + Log("INFO", "-Debug- $message host = $RemoteHost"); } } @@ -277,6 +250,33 @@ sub ShowStatus { =pod +=head 2 SocketTimeout + + Called when an action on the socket times out. The socket is + destroyed and any active transaction is failed. + + +=cut +sub SocketTimeout { + my $Socket = shift; + Log("WARNING", "A socket timeout was detected"); + Debug(0, " SocketTimeout called: "); + $Socket->Dump(); + if(exists($ActiveTransactions{$Socket})) { + FailTransaction($ActiveTransactions{$Socket}); + } + KillSocket($Socket); # A transaction timeout also counts as + # a connection failure: + $ConnectionRetriesLeft--; + if($ConnectionRetriesLeft <= 0) { + Log("CRITICAL", "Host marked dead: ".GetServerHost()); + } + +} +#----------------------------- Timer management ------------------------ + +=pod + =head2 Tick Invoked each timer tick. @@ -286,11 +286,11 @@ Invoked each timer tick. sub Tick { my $client; - ShowStatus(GetServerHost()." Connection count: ".$ConnectionCount); - Debug(10,"Tick"); - Debug(10," Current connection count: ".$ConnectionCount); - foreach $client (keys %ActiveClients) { - Debug(10," Have client: with id: ".$ActiveClients{$client}); + if($ConnectionRetriesLeft > 0) { + ShowStatus(GetServerHost()." Connection count: ".$ConnectionCount + ." Retries remaining: ".$ConnectionRetriesLeft); + } else { + ShowStatus(GetServerHost()." >> DEAD <<"); } # Is it time to prune connection count: @@ -299,13 +299,23 @@ sub Tick { ($WorkQueue->Count() == 0)) { # Idle connections and nothing to do? $IdleSeconds++; if($IdleSeconds > $IdleTimeout) { # Prune a connection... - $Socket = $IdleConnections->pop(); + my $Socket = $IdleConnections->pop(); KillSocket($Socket); } } else { $IdleSeconds = 0; # Reset idle count if not idle. } + # + # For each inflight transaction, tick down its timeout counter. + # + foreach my $item (keys %ActiveConnections) { + my $State = $ActiveConnections{$item}->data->GetState(); + if ($State ne 'Idle') { + Debug(5,"Ticking Socket $State $item"); + $ActiveConnections{$item}->data->Tick(); + } + } # Do we have work in the queue, but no connections to service them? # If so, try to make some new connections to get things going again. # @@ -315,13 +325,21 @@ sub Tick { 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(); + Debug(5,"Work but no connections, start ".$Connections." of them"); + my $successCount = 0; + for (my $i =0; $i < $Connections; $i++) { + $successCount += MakeLondConnection(); + } + if($successCount == 0) { # All connections failed: + Debug(5,"Work in queue failed to make any connectiouns\n"); + EmptyQueue(); # Fail pending transactions with con_lost. + CloseAllLondConnections(); # Should all be closed but.... } } else { - Debug(1,"Work in queue, but gave up on connections..flushing\n"); + ShowStatus(GetServerHost()." >>> DEAD!!! <<<"); + Debug(5,"Work in queue, but gave up on connections..flushing\n"); EmptyQueue(); # Connections can't be established. + CloseAllLondConnections(); # Should all already be closed but... } } @@ -345,7 +363,7 @@ Trigger disconnections of idle sockets. sub SetupTimer { Debug(6, "SetupTimer"); - Event->timer(interval => 1, debug => 1, cb => \&Tick ); + Event->timer(interval => 1, cb => \&Tick ); } =pod @@ -367,19 +385,19 @@ sub ServerToIdle { my $Socket = shift; # Get the socket. delete($ActiveTransactions{$Socket}); # Server has no transaction - &Debug(6, "Server to idle"); + &Debug(5, "Server to idle"); # If there's work to do, start the transaction: - $reqdata = $WorkQueue->dequeue(); # This is a LondTransaction - unless($reqdata eq undef) { - Debug(9, "Queue gave request data: ".$reqdata->getRequest()); + my $reqdata = $WorkQueue->dequeue(); # This is a LondTransaction + if ($reqdata ne undef) { + Debug(5, "Queue gave request data: ".$reqdata->getRequest()); &StartRequest($Socket, $reqdata); } else { # There's no work waiting, so push the server to idle list. - &Debug(8, "No new work requests, server connection going idle"); + &Debug(5, "No new work requests, server connection going idle"); $IdleConnections->push($Socket); } } @@ -425,7 +443,7 @@ sub ClientWritable { # request. &Debug(9,"Send result is ".$result." Defined: ".defined($result)); - if(defined($result)) { + if($result ne undef) { &Debug(9, "send result was defined"); if($result == length($Data)) { # Entire string sent. &Debug(9, "ClientWritable data all written"); @@ -443,6 +461,12 @@ sub ClientWritable { } else { # Partial string sent. $Watcher->data(substr($Data, $result)); + if($result == 0) { # client hung up on us!! + Log("INFO", "lonc pipe client hung up on us!"); + $Watcher->cancel; + $Socket->shutdown(2); + $Socket->close(); + } } } else { # Error of some sort... @@ -490,20 +514,25 @@ The transaction that is being completed. =cut sub CompleteTransaction { - &Debug(6,"Complete transaction"); + &Debug(5,"Complete transaction"); my $Socket = shift; my $Transaction = shift; 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"); - LogPerm("S:$Client:".$Transaction->getRequest()); + LogPerm("S:$Transaction->getClient() :".$Transaction->getRequest()); unlink $Transaction->getFile(); } } + =pod + =head1 StartClientReply Initiates a reply to a client where the reply data is a parameter. @@ -519,16 +548,17 @@ sub CompleteTransaction { The data to send to apached client. =cut + sub StartClientReply { my $Transaction = shift; my $data = shift; + my $Client = $Transaction->getClient(); &Debug(8," Reply was: ".$data); my $Serial = $ActiveClients{$Client}; my $desc = sprintf("Connection to lonc client %d", - $Serial); Event->io(fd => $Client, poll => "w", @@ -536,7 +566,9 @@ sub StartClientReply { cb => \&ClientWritable, data => $data); } + =pod + =head2 FailTransaction Finishes a transaction with failure because the associated lond socket @@ -546,8 +578,7 @@ sub StartClientReply { - The transaction is 'live' in which case we initiate the sending of "con_lost" to the client. -Deleting the transaction means killing it from the -%ActiveTransactions hash. +Deleting the transaction means killing it from the %ActiveTransactions hash. Parameters: @@ -555,10 +586,12 @@ Parameters: The LondTransaction we are failing. + =cut sub FailTransaction { my $transaction = shift; + Log("WARNING", "Failing transaction ".$transaction->getRequest()); Debug(1, "Failing transaction: ".$transaction->getRequest()); if (!$transaction->isDeferred()) { # If the transaction is deferred we'll get to it. my $client = $transaction->getClient(); @@ -576,6 +609,7 @@ sub FailTransaction { =cut sub EmptyQueue { + $ConnectionRetriesLeft--; # Counts as connection failure too. while($WorkQueue->Count()) { my $request = $WorkQueue->dequeue(); # This is a transaction FailTransaction($request); @@ -590,8 +624,11 @@ Close all connections open on lond prior =cut sub CloseAllLondConnections { - foreach $Socket (keys %ActiveConnections) { - KillSocket($Socket); + foreach my $Socket (keys %ActiveConnections) { + if(exists($ActiveTransactions{$Socket})) { + FailTransaction($ActiveTransactions{$Socket}); + } + KillSocket($Socket); } } =cut @@ -621,6 +658,7 @@ nonzero if we are allowed to create a ne sub KillSocket { my $Socket = shift; + Log("WARNING", "Shutting down a socket"); $Socket->Shutdown(); # If the socket came from the active connection set, @@ -634,14 +672,15 @@ 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. # if($ConnectionCount == 0) { - EmptyQueue; + EmptyQueue(); + CloseAllLondConnections; # Should all already be closed but... } } @@ -667,6 +706,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 @@ -710,23 +760,28 @@ sub LondReadable { my $Socket = $Watcher->data; my $client = undef; - &Debug(6,"LondReadable called state = ".$State); + &Debug(6,"LondReadable called state = ".$Socket->GetState()); my $State = $Socket->GetState(); # All action depends on the state. SocketDump(6, $Socket); + my $status = $Socket->Readable(); - if($Socket->Readable() != 0) { - # bad return from socket read. Currently this means that + &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})) { - Debug(3,"Lond connection lost failing transaction"); FailTransaction($ActiveTransactions{$Socket}); } $Watcher->cancel(); KillSocket($Socket); + $ConnectionRetriesLeft--; # Counts as connection failure return; } SocketDump(6,$Socket); @@ -734,19 +789,34 @@ sub LondReadable { $State = $Socket->GetState(); # Update in case of transition. &Debug(6, "After read, state is ".$State); - if($State eq "Initialized") { + if($State eq "Initialized") { } 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") { + } 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 @@ -758,11 +828,23 @@ sub LondReadable { } elsif ($State eq "ReceivingKey") { } 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(8,"Completing transaction!!"); + Debug(5,"Completing transaction!!"); CompleteTransaction($Socket, $ActiveTransactions{$Socket}); } else { @@ -783,7 +865,7 @@ sub LondReadable { } else { - # Invalid state. + # Invalid state. Debug(4, "Invalid state in LondReadable"); } } @@ -865,20 +947,36 @@ sub LondWritable { SocketDump(6,$Socket); + # If the socket is writable, we must always write. + # Only by writing will we undergo state transitions. + # Old logic wrote in state specific code below, however + # That forces us at least through another invocation of + # this function after writability is possible again. + # This logic also factors out common code for handling + # write failures... in all cases, write failures + # Kill the socket. + # This logic makes the branches of the >big< if below + # so that the writing states are actually NO-OPs. + + 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"); + if(exists($ActiveTransactions{$Socket})) { + FailTransaction($ActiveTransactions{$Socket}); + } + $Watcher->cancel(); + KillSocket($Socket); + return; + } + + + 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"); - $Watcher->cancel(); - KillSocket($Socket); - return; - } # "init" is being sent... - - + } elsif ($State eq "Initialized") { # Now that init was sent, we switch @@ -886,40 +984,43 @@ sub LondWritable { $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 - if($Socket->Writable() != 0) { - - $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 "RequestingVersion") { + # Sending the peer a version request... + + } 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... + + } 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: @@ -928,20 +1029,10 @@ sub LondWritable { $Watcher->poll("r"); } elsif ($State eq "SendingRequest") { + # At this time we are sending a request to the # peer... write the next chunk: - if($Socket->Writable() != 0) { - - 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 @@ -971,8 +1062,7 @@ sub QueueDelayed { Debug(4, "Delayed path: ".$path); opendir(DIRHANDLE, $path); - @alldelayed = grep /\.$RemoteHost$/, readdir DIRHANDLE; - Debug(4, "Got ".$alldelayed." delayed files"); + my @alldelayed = grep /\.$RemoteHost$/, readdir DIRHANDLE; closedir(DIRHANDLE); my $dfname; my $reqfile; @@ -982,7 +1072,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); @@ -1009,26 +1099,27 @@ sub MakeLondConnection { my $Connection = LondConnection->new(&GetServerHost(), &GetServerPort()); - if($Connection == undef) { # Needs to be more robust later. + if($Connection eq 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 # exchange underway. # my $Socket = $Connection->GetSocket(); - if($Socket == undef) { + if($Socket eq undef) { die "did not get a socket from the connection"; } else { &Debug(9,"MakeLondConnection got socket: ".$Socket); } - - $event = Event->io(fd => $Socket, + $Connection->SetTimeoutCallback(\&SocketTimeout); + + my $event = Event->io(fd => $Socket, poll => 'w', cb => \&LondWritable, data => $Connection, @@ -1084,7 +1175,7 @@ sub StartRequest { $ActiveTransactions{$Lond} = $Request; $Lond->InitiateTransaction($Request->getRequest()); - $event = Event->io(fd => $Socket, + my $event = Event->io(fd => $Socket, poll => "w", cb => \&LondWritable, data => $Lond, @@ -1123,11 +1214,20 @@ sub QueueTransaction { my $LondSocket = $IdleConnections->pop(); if(!defined $LondSocket) { # Need to queue request. - Debug(8,"Must queue..."); + Debug(5,"Must queue..."); $WorkQueue->enqueue($requestData); if($ConnectionCount < $MaxConnectionCount) { - Debug(4,"Starting additional lond connection"); - MakeLondConnection(); + if($ConnectionRetriesLeft > 0) { + Debug(5,"Starting additional lond connection"); + if(MakeLondConnection() == 0) { + EmptyQueue(); # Fail transactions, can't make connection. + CloseAllLondConnections; # Should all be closed but... + } + } else { + ShowStatus(GetServerHost()." >>> DEAD !!!! <<<"); + EmptyQueue(); # It's worse than that ... he's dead Jim. + CloseAllLondConnections; # Should all be closed but.. + } } } else { # Can start the request: Debug(8,"Can start..."); @@ -1158,7 +1258,7 @@ sub ClientRequest { my $rv = $socket->recv($thisread, POSIX::BUFSIZ, 0); Debug(8, "rcv: data length = ".length($thisread) ." read =".$thisread); - unless (defined $rv && length($thisread)) { + unless (defined $rv && length($thisread)) { # Likely eof on socket. Debug(5,"Client Socket closed on lonc for ".$RemoteHost); close($socket); @@ -1177,6 +1277,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); @@ -1285,6 +1388,60 @@ 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 + +Child USR1 signal handler to report the most recent status +into the status file. + +We also use this to reset the retries count in order to allow the +client to retry connections with a previously dead server. +=cut +sub ChildStatus { + my $event = shift; + my $watcher = $event->w; + + Debug(2, "Reporting child status because : ".$watcher->data); + my $docdir = $perlvar{'lonDocRoot'}; + 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; +} + =pod =head2 SignalledToDeath @@ -1293,18 +1450,37 @@ Called in response to a signal that caus =cut -=pod sub SignalledToDeath { - my ($signal) = @_; + my $event = shift; + my $watcher= $event->w; + + Debug(2,"Signalled to death! via ".$watcher->data); + my ($signal) = $watcher->data; 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 ToggleDebug + +This sub toggles trace debugging on and off. + +=cut + +sub ToggleDebug { + my $Current = $DebugLevel; + $DebugLevel = $NextDebugLevel; + $NextDebugLevel = $Current; + + Log("SUCCESS", "New debugging level for $RemoteHost now $DebugLevel"); } + =head2 ChildProcess This sub implements a child process for a single lonc daemon. @@ -1314,14 +1490,24 @@ This sub implements a child process for sub ChildProcess { - # For now turn off signals. - - $SIG{QUIT} = \&SignalledToDeath; - $SIG{HUP} = IGNORE; - $SIG{USR1} = IGNORE; - $SIG{INT} = IGNORE; - $SIG{CHLD} = IGNORE; - $SIG{__DIE__} = \&SignalledToDeath; + # + # Signals must be handled by the Event framework... +# + + Event->signal(signal => "QUIT", + cb => \&SignalledToDeath, + data => "QUIT"); + Event->signal(signal => "HUP", + cb => \&ChildStatus, + data => "HUP"); + Event->signal(signal => "USR1", + cb => \&ChildStatus, + data => "USR1"); + Event->signal(signal => "USR2", + cb => \&ToggleTransactionLogging); + Event->signal(signal => "INT", + cb => \&ToggleDebug, + data => "INT"); SetupTimer(); @@ -1333,7 +1519,7 @@ sub ChildProcess { # Setup the initial server connection: - # &MakeLondConnection(); // let first work requirest do it. + # &MakeLondConnection(); // let first work requirest do it. Debug(9,"Entering event loop"); @@ -1346,15 +1532,23 @@ 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; + my $pid = fork; if($pid) { # Parent - $ChildHash{$pid} = $RemoteHost; + $RemoteHost = "Parent"; + $ChildHash{$pid} = $host; + $HostToPid{$host}= $pid; + sigprocmask(SIG_UNBLOCK, $sigset); + } else { # child. ShowStatus("Connected to ".$RemoteHost); - ChildProcess; + $SIG{INT} = 'DEFAULT'; + sigprocmask(SIG_UNBLOCK, $sigset); + ChildProcess; # Does not return. } } @@ -1389,11 +1583,13 @@ if ($childpid != 0) { # ShowStatus("Parent writing pid file:"); -$execdir = $perlvar{'lonDaemons'}; +my $execdir = $perlvar{'lonDaemons'}; open (PIDSAVE, ">$execdir/logs/lonc.pid"); print PIDSAVE "$$\n"; close(PIDSAVE); + + if (POSIX::setsid() < 0) { print "Could not create new session\n"; exit -1; @@ -1403,13 +1599,16 @@ ShowStatus("Forking node servers"); Log("CRITICAL", "--------------- Starting children ---------------"); +LondConnection::ReadConfig; # Read standard config files. my $HostIterator = LondConnection::GetHostIterator; while (! $HostIterator->end()) { - $hostentryref = $HostIterator->get(); + my $hostentryref = $HostIterator->get(); CreateChild($hostentryref->[0]); + $HostHash{$hostentryref->[0]} = $hostentryref->[4]; $HostIterator->next(); } +$RemoteHost = "Parent Server"; # Maintain the population: @@ -1418,13 +1617,18 @@ ShowStatus("Parent keeping the flock"); # # Set up parent signals: # -$SIG{INT} = &KillThemAll; -$SIG{TERM} = &KillThemAll; + +$SIG{INT} = \&Terminate; +$SIG{TERM} = \&Terminate; +$SIG{HUP} = \&Restart; +$SIG{USR1} = \&CheckKids; +$SIG{USR2} = \&UpdateKids; # LonManage update request. while(1) { - $deadchild = wait(); + my $deadchild = wait(); if(exists $ChildHash{$deadchild}) { # need to restart. - $deadhost = $ChildHash{$deadchild}; + my $deadhost = $ChildHash{$deadchild}; + delete($HostToPid{$deadhost}); delete($ChildHash{$deadchild}); Log("WARNING","Lost child pid= ".$deadchild. "Connected to host ".$deadhost); @@ -1432,9 +1636,202 @@ while(1) { CreateChild($deadhost); } } + + + +=pod + +=head1 CheckKids + + Since kids do not die as easily in this implementation +as the previous one, there is no need to restart the +dead ones (all dead kids get restarted when they die!!) +The only thing this function does is to pass USR1 to the +kids so that they report their status. + +=cut + +sub CheckKids { + Debug(2, "Checking status of children"); + my $docdir = $perlvar{'lonDocRoot'}; + my $fh = IO::File->new(">$docdir/lon-status/loncstatus.txt"); + my $now=time; + my $local=localtime($now); + print $fh "LONC status $local - parent $$ \n\n"; + foreach my $pid (keys %ChildHash) { + Debug(2, "Sending USR1 -> $pid"); + kill 'USR1' => $pid; # Tell Child to report status. + sleep 1; # Wait so file doesn't intermix. + } +} + +=pod + +=head1 UpdateKids + +parent's SIGUSR2 handler. This handler: + +=item + +Rereads the hosts file. + +=item + +Kills off (via sigint) children for hosts that have disappeared. + +=item + +QUITs children for hosts that already exist (this just forces a status display +and resets the connection retry count for that host. + +=item + +Starts new children for hosts that have been added to the hosts.tab file since +the start of the master program and maintains them. + +=cut + +sub UpdateKids { + + Log("INFO", "Updating connections via SIGUSR2"); + + # Just in case we need to kill our own lonc, we wait a few seconds to + # give it a chance to receive and relay lond's response to the + # re-init command. + # + + sleep(2); # Wait a couple of seconds. + + my %hosts; # Indexed by loncapa hostname, value=ip. + + # Need to re-read the host table: + + + LondConnection::ReadConfig(); + my $I = LondConnection::GetHostIterator; + while (! $I->end()) { + my $item = $I->get(); + $hosts{$item->[0]} = $item->[4]; + $I->next(); + } + + # The logic below is written for clarity not for efficiency. + # Since I anticipate that this function is only rarely called, that's + # appropriate. There are certainly ways to combine the loops below, + # and anyone wishing to obscure the logic is welcome to go for it. + # Note that we don't re-direct sigchild. Instead we do what's needed + # to the data structures that keep track of children to ensure that + # when sigchild is honored, no new child is born. + # + + # For each existing child; if it's host doesn't exist, kill the child. + + foreach my $child (keys %ChildHash) { + my $oldhost = $ChildHash{$child}; + if (!(exists $hosts{$oldhost})) { + Log("CRITICAL", "Killing child for $oldhost host no longer exists"); + delete $ChildHash{$child}; + delete $HostToPid{$oldhost}; + kill 'QUIT' => $child; + } + } + # For each remaining existing child; if it's host's ip has changed, + # Restart the child on the new IP. + + foreach my $child (keys %ChildHash) { + my $oldhost = $ChildHash{$child}; + my $oldip = $HostHash{$oldhost}; + if ($hosts{$oldhost} ne $oldip) { + + # kill the old child. + + Log("CRITICAL", "Killing child for $oldhost host ip has changed..."); + delete $ChildHash{$child}; + delete $HostToPid{$oldhost}; + kill 'QUIT' => $child; + + # Do the book-keeping needed to start a new child on the + # new ip. + + $HostHash{$oldhost} = $hosts{$oldhost}; + CreateChild($oldhost); + } + } + # Finally, for each new host, not in the host hash, create a + # enter the host and create a new child. + # Force a status display of any existing process. + + foreach my $host (keys %hosts) { + if(!(exists $HostHash{$host})) { + Log("INFO", "New host $host discovered in hosts.tab..."); + $HostHash{$host} = $hosts{$host}; + CreateChild($host); + } else { + kill 'HUP' => $HostToPid{$host}; # status display. + } + } +} + + +=pod + +=head1 Restart + +Signal handler for HUP... all children are killed and +we self restart. This is an el-cheapo way to re read +the config file. + +=cut + +sub Restart { + &KillThemAll; # First kill all the children. + Log("CRITICAL", "Restarting"); + my $execdir = $perlvar{'lonDaemons'}; + unlink("$execdir/logs/lonc.pid"); + exec("$execdir/loncnew"); +} + +=pod + +=head1 KillThemAll + +Signal handler that kills all children by sending them a +SIGHUP. Responds to sigint and sigterm. + +=cut + sub KillThemAll { + Debug(2, "Kill them all!!"); + local($SIG{CHLD}) = 'IGNORE'; # Our children >will< die. + foreach my $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 'QUIT' => $pid; + delete($ChildHash{$pid}); + } + my $execdir = $perlvar{'lonDaemons'}; + unlink("$execdir/logs/lonc.pid"); + } +=pod + +=head1 Terminate + +Terminate the system. + +=cut + +sub Terminate { + KillThemAll; + Log("CRITICAL","Master process exiting"); + exit 0; + +} +=pod + =head1 Theory The event class is used to build this as a single process with an