--- loncom/loncnew 2004/03/02 16:25:17 1.44 +++ loncom/loncnew 2004/09/22 10:34:44 1.58 @@ -2,7 +2,7 @@ # The LearningOnline Network with CAPA # lonc maintains the connections to remote computers # -# $Id: loncnew,v 1.44 2004/03/02 16:25:17 albertel Exp $ +# $Id: loncnew,v 1.58 2004/09/22 10:34:44 foxr Exp $ # # Copyright Michigan State University Board of Trustees # @@ -82,7 +82,7 @@ my $ClientConnection = 0; # Uniquifier f my $DebugLevel = 0; my $NextDebugLevel= 2; # So Sigint can toggle this. -my $IdleTimeout= 3600; # Wait an hour before pruning connections. +my $IdleTimeout= 600; # Wait 10 minutes before pruning connections. my $LogTransactions = 0; # When True, all transactions/replies get logged. @@ -103,6 +103,10 @@ 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. +my $KeyMode = ""; # e.g. ssl, local, insecure from last connect. +my $LondConnecting = 0; # True when a connection is being built. + +my $DieWhenIdle = 0; # When true children die when trimmed -> 0. # # The hash below gives the HTML format for log messages @@ -110,13 +114,27 @@ my $LondVersion = "unknown"; # Versi # my %LogFormats; -$LogFormats{"CRITICAL"} = "CRITICAL: %s"; -$LogFormats{"SUCCESS"} = "SUCCESS: %s"; -$LogFormats{"INFO"} = "INFO: %s"; -$LogFormats{"WARNING"} = "WARNING: %s"; +$LogFormats{"CRITICAL"} = "CRITICAL: %s"; +$LogFormats{"SUCCESS"} = "SUCCESS: %s"; +$LogFormats{"INFO"} = "INFO: %s"; +$LogFormats{"WARNING"} = "WARNING: %s"; $LogFormats{"DEFAULT"} = " %s "; +# UpdateStatus; +# Update the idle status display to show how many connections +# are left, retries and other stuff. +# +sub UpdateStatus { + if ($ConnectionRetriesLeft > 0) { + ShowStatus(GetServerHost()." Connection count: ".$ConnectionCount + ." Retries remaining: ".$ConnectionRetriesLeft + ." ($KeyMode)"); + } else { + ShowStatus(GetServerHost()." >> DEAD <<"); + } +} + =pod @@ -156,9 +174,9 @@ host and the time will be formatted into =cut sub Log { - my $severity = shift; - my $message = shift; - + + my ($severity, $message) = @_; + if(!$LogFormats{$severity}) { $severity = "DEFAULT"; } @@ -193,8 +211,10 @@ Returns the name of the host that a sock =cut sub GetPeername { - my $connection = shift; - my $AdrFamily = shift; + + + my ($connection, $AdrFamily) = @_; + my $peer = $connection->peername(); my $peerport; my $peerip; @@ -217,18 +237,20 @@ Invoked to issue a debug message. =cut sub Debug { - my $level = shift; - my $message = shift; + + my ($level, $message) = @_; + if ($level <= $DebugLevel) { Log("INFO", "-Debug- $message host = $RemoteHost"); } } sub SocketDump { - my $level = shift; - my $socket= shift; + + my ($level, $socket) = @_; + if($level <= $DebugLevel) { - $socket->Dump(); + $socket->Dump(-1); # Ensure it will get dumped. } } @@ -260,8 +282,8 @@ sub ShowStatus { sub SocketTimeout { my $Socket = shift; Log("WARNING", "A socket timeout was detected"); - Debug(0, " SocketTimeout called: "); - $Socket->Dump(); + Debug(5, " SocketTimeout called: "); + $Socket->Dump(0); if(exists($ActiveTransactions{$Socket})) { FailTransaction($ActiveTransactions{$Socket}); } @@ -269,7 +291,8 @@ sub SocketTimeout { # a connection failure: $ConnectionRetriesLeft--; if($ConnectionRetriesLeft <= 0) { - Log("CRITICAL", "Host marked dead: ".GetServerHost()); + Log("CRITICAL", "Host marked DEAD: ".GetServerHost()); + $LondConnecting = 0; } } @@ -285,13 +308,12 @@ Invoked each timer tick. sub Tick { + my ($Event) = @_; + my $clock_watcher = $Event->w; + my $client; - if($ConnectionRetriesLeft > 0) { - ShowStatus(GetServerHost()." Connection count: ".$ConnectionCount - ." Retries remaining: ".$ConnectionRetriesLeft); - } else { - ShowStatus(GetServerHost()." >> DEAD <<"); - } + UpdateStatus(); + # Is it time to prune connection count: @@ -301,6 +323,22 @@ sub Tick { if($IdleSeconds > $IdleTimeout) { # Prune a connection... my $Socket = $IdleConnections->pop(); KillSocket($Socket); + $IdleSeconds = 0; # Otherwise all connections get trimmed to fast. + UpdateStatus(); + if(($ConnectionCount == 0) && $DieWhenIdle) { + # + # Create a lock file since there will be a time window + # between our exit and the parent's picking up the listen + # during which no listens will be done on the + # lonnet client socket. + # + my $lock_file = GetLoncSocketPath().".lock"; + open(LOCK,">$lock_file"); + print LOCK "Contents not important"; + close(LOCK); + + exit(0); + } } } else { $IdleSeconds = 0; # Reset idle count if not idle. @@ -319,23 +357,21 @@ sub 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. # - + # Note this code is dead now... + # my $Requests = $WorkQueue->Count(); - if (($ConnectionCount == 0) && ($Requests > 0)) { + if (($ConnectionCount == 0) && ($Requests > 0) && (!$LondConnecting)) { if ($ConnectionRetriesLeft > 0) { - my $Connections = ($Requests <= $MaxConnectionCount) ? - $Requests : $MaxConnectionCount; - 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 but no connections, Make a new one"); + my $success; + $success = &MakeLondConnection; + if($success == 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 { + $LondConnecting = 0; ShowStatus(GetServerHost()." >>> DEAD!!! <<<"); Debug(5,"Work in queue, but gave up on connections..flushing\n"); EmptyQueue(); # Connections can't be established. @@ -343,6 +379,10 @@ sub Tick { } } + if ($ConnectionCount == 0) { + $KeyMode = ""; + $clock_watcher->cancel(); + } } =pod @@ -383,6 +423,7 @@ long enough, it will be shut down and re sub ServerToIdle { my $Socket = shift; # Get the socket. + $KeyMode = $Socket->{AuthenticationMode}; delete($ActiveTransactions{$Socket}); # Server has no transaction &Debug(5, "Server to idle"); @@ -462,7 +503,7 @@ 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!"); + # Log("INFO", "lonc pipe client hung up on us!"); $Watcher->cancel; $Socket->shutdown(2); $Socket->close(); @@ -515,8 +556,8 @@ The transaction that is being completed. sub CompleteTransaction { &Debug(5,"Complete transaction"); - my $Socket = shift; - my $Transaction = shift; + + my ($Socket, $Transaction) = @_; if (!$Transaction->isDeferred()) { # Normal transaction my $data = $Socket->GetReply(); # Data to send. @@ -550,9 +591,8 @@ sub CompleteTransaction { =cut sub StartClientReply { - my $Transaction = shift; - my $data = shift; + my ($Transaction, $data) = @_; my $Client = $Transaction->getClient(); @@ -591,7 +631,13 @@ Parameters: sub FailTransaction { my $transaction = shift; - Log("WARNING", "Failing transaction ".$transaction->getRequest()); + + # If the socket is dead, that's already logged. + + if ($ConnectionRetriesLeft > 0) { + 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(); @@ -778,6 +824,11 @@ sub LondReadable { "Lond connection lost."); if(exists($ActiveTransactions{$Socket})) { FailTransaction($ActiveTransactions{$Socket}); + } else { + # Socket is connecting and failed... need to mark + # no longer connecting. + + $LondConnecting = 0; } $Watcher->cancel(); KillSocket($Socket); @@ -852,6 +903,10 @@ sub LondReadable { .$RemoteHost." now ready for action"); } ServerToIdle($Socket); # Next work unit or idle. + + # + $LondConnecting = 0; # Best spot I can think of for this. + # } elsif ($State eq "SendingRequest") { # We need to be writable for this and probably don't belong @@ -965,6 +1020,10 @@ sub LondWritable { " has been disconnected"); if(exists($ActiveTransactions{$Socket})) { FailTransaction($ActiveTransactions{$Socket}); + } else { + # In the process of conneting, so need to turn that off. + + $LondConnecting = 0; } $Watcher->cancel(); KillSocket($Socket); @@ -1125,7 +1184,9 @@ sub MakeLondConnection { data => $Connection, desc => 'Connection to lond server'); $ActiveConnections{$Connection} = $event; - + if ($ConnectionCount == 0) { + &SetupTimer; # Need to handle timeouts with connections... + } $ConnectionCount++; Debug(4, "Connection count = ".$ConnectionCount); if($ConnectionCount == 1) { # First Connection: @@ -1133,6 +1194,7 @@ sub MakeLondConnection { } Log("SUCESS", "Created connection ".$ConnectionCount ." to host ".GetServerHost()); + $LondConnecting = 1; # Connection in progress. return 1; # Return success. } @@ -1164,8 +1226,8 @@ The text of the request to send. =cut sub StartRequest { - my $Lond = shift; - my $Request = shift; # This is a LondTransaction. + + my ($Lond, $Request) = @_; Debug(6, "StartRequest: ".$Request->getRequest()); @@ -1216,15 +1278,18 @@ sub QueueTransaction { if(!defined $LondSocket) { # Need to queue request. Debug(5,"Must queue..."); $WorkQueue->enqueue($requestData); - if($ConnectionCount < $MaxConnectionCount) { + Debug(5, "Queue Transaction startnew $ConnectionCount $LondConnecting"); + if(($ConnectionCount < $MaxConnectionCount) && (! $LondConnecting)) { + if($ConnectionRetriesLeft > 0) { Debug(5,"Starting additional lond connection"); - if(MakeLondConnection() == 0) { + if(&MakeLondConnection() == 0) { EmptyQueue(); # Fail transactions, can't make connection. CloseAllLondConnections; # Should all be closed but... } } else { ShowStatus(GetServerHost()." >>> DEAD !!!! <<<"); + $LondConnecting = 0; EmptyQueue(); # It's worse than that ... he's dead Jim. CloseAllLondConnections; # Should all be closed but.. } @@ -1330,10 +1395,20 @@ sub NewClient { Returns the name of the UNIX socket on which to listen for client connections. +=head2 Parameters: + + host (optional) - Name of the host socket to return.. defaults to + the return from GetServerHost(). + =cut sub GetLoncSocketPath { - return $UnixSocketDir."/".GetServerHost(); + + my $host = GetServerHost(); # Default host. + if (@_) { + ($host) = @_; # Override if supplied. + } + return $UnixSocketDir."/".$host; } =pod @@ -1370,15 +1445,24 @@ connection. The event handler establish (creating a communcations channel), that int turn will establish another event handler to subess requests. +=head2 Parameters: + + host (optional) Name of the host to set up a unix socket to. + =cut sub SetupLoncListener { + my $host = GetServerHost(); # Default host. + if (@_) { + ($host) = @_ # Override host with parameter. + } + my $socket; - my $SocketName = GetLoncSocketPath(); + my $SocketName = GetLoncSocketPath($host); unlink($SocketName); unless ($socket =IO::Socket::UNIX->new(Local => $SocketName, - Listen => 10, + Listen => 250, Type => SOCK_STREAM)) { die "Failed to create a lonc listner socket"; } @@ -1416,6 +1500,7 @@ 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; @@ -1428,16 +1513,18 @@ sub ChildStatus { # # 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++; + if ($DebugLevel > 2) { + 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(-1); # Ensure it gets dumped.. + $i++; + } } $ConnectionRetriesLeft = $ConnectionRetries; } @@ -1509,7 +1596,6 @@ sub ChildProcess { cb => \&ToggleDebug, data => "INT"); - SetupTimer(); SetupLoncListener(); @@ -1532,9 +1618,10 @@ sub ChildProcess { # Create a new child for host passed in: sub CreateChild { + my $host = shift; + my $sigset = POSIX::SigSet->new(SIGINT); sigprocmask(SIG_BLOCK, $sigset); - my $host = shift; $RemoteHost = $host; Log("CRITICAL", "Forking server for ".$host); my $pid = fork; @@ -1805,17 +1892,33 @@ sub KillThemAll { 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"); + ShowStatus("Nicely Killing lonc for $serving pid = $pid"); + Log("CRITICAL", "Nicely Killing lonc for $serving pid = $pid"); kill 'QUIT' => $pid; - delete($ChildHash{$pid}); } - my $execdir = $perlvar{'lonDaemons'}; - unlink("$execdir/logs/lonc.pid"); + } + +# +# Kill all children via KILL. Just in case the +# first shot didn't get them. + +sub really_kill_them_all_dammit +{ + Debug(2, "Kill them all Dammit"); + local($SIG{CHLD} = 'IGNORE'); # In case some purist reenabled them. + foreach my $pid (keys %ChildHash) { + my $serving = $ChildHash{$pid}; + &ShowStatus("Nastily killing lonc for $serving pid = $pid"); + Log("CRITICAL", "Nastily killing lonc for $serving pid = $pid"); + kill 'KILL' => $pid; + delete($ChildHash{$pid}); + my $execdir = $perlvar{'lonDaemons'}; + unlink("$execdir/logs/lonc.pid"); + } +} =pod =head1 Terminate @@ -1825,7 +1928,15 @@ Terminate the system. =cut sub Terminate { - KillThemAll; + &Log("CRITICAL", "Asked to kill children.. first be nice..."); + &KillThemAll; + # + # By now they really should all be dead.. but just in case + # send them all SIGKILL's after a bit of waiting: + + sleep(4); + &Log("CRITICAL", "Now kill children nasty"); + &really_kill_them_all_dammit; Log("CRITICAL","Master process exiting"); exit 0; 500 Internal Server Error

Internal Server Error

The server encountered an internal error or misconfiguration and was unable to complete your request.

Please contact the server administrator at root@localhost to inform them of the time this error occurred, and the actions you performed just before this error.

More information about this error may be available in the server error log.