File:  [LON-CAPA] / loncom / loncnew
Revision 1.53: download - view: text, annotated - select for diffs
Mon Sep 20 09:34:31 2004 UTC (19 years, 7 months ago) by foxr
Branches: MAIN
CVS tags: HEAD
  Fix the issue where loncnew would rapidly oscillate connections. The problem
was that once it started trimmning connections. they'd all get trimmed out
at the rate of one/sec, rather than at the rate of one /idle timeout
period... needed to reset the idle timeout each time a connection got
trimmed.

    1: #!/usr/bin/perl
    2: # The LearningOnline Network with CAPA
    3: # lonc maintains the connections to remote computers
    4: #
    5: # $Id: loncnew,v 1.53 2004/09/20 09:34:31 foxr Exp $
    6: #
    7: # Copyright Michigan State University Board of Trustees
    8: #
    9: # This file is part of the LearningOnline Network with CAPA (LON-CAPA).
   10: ## LON-CAPA is free software; you can redistribute it and/or modify
   11: # it under the terms of the GNU General Public License as published by
   12: # the Free Software Foundation; either version 2 of the License, or
   13: # (at your option) any later version.
   14: #
   15: # LON-CAPA is distributed in the hope that it will be useful,
   16: # but WITHOUT ANY WARRANTY; without even the implied warranty of
   17: # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
   18: # GNU General Public License for more details.
   19: #
   20: # You should have received a copy of the GNU General Public License
   21: # along with LON-CAPA; if not, write to the Free Software
   22: # Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
   23: #
   24: # /home/httpd/html/adm/gpl.txt
   25: #
   26: # http://www.lon-capa.org/
   27: #
   28: #
   29: # new lonc handles n request out bver m connections to londs.
   30: # This module is based on the Event class.
   31: #   Development iterations:
   32: #    - Setup basic event loop.   (done)
   33: #    - Add timer dispatch.       (done)
   34: #    - Add ability to accept lonc UNIX domain sockets.  (done)
   35: #    - Add ability to create/negotiate lond connections (done).
   36: #    - Add general logic for dispatching requests and timeouts. (done).
   37: #    - Add support for the lonc/lond requests.          (done).
   38: #    - Add logging/status monitoring.                    (done)
   39: #    - Add Signal handling - HUP restarts. USR1 status report. (done)
   40: #    - Add Configuration file I/O                       (done).
   41: #    - Add management/status request interface.         (done)
   42: #    - Add deferred request capability.                  (done)
   43: #    - Detect transmission timeouts.                     (done)
   44: #
   45: 
   46: use strict;
   47: use lib "/home/httpd/lib/perl/";
   48: use Event qw(:DEFAULT );
   49: use POSIX qw(:signal_h);
   50: use POSIX;
   51: use IO::Socket;
   52: use IO::Socket::INET;
   53: use IO::Socket::UNIX;
   54: use IO::File;
   55: use IO::Handle;
   56: use Socket;
   57: use Crypt::IDEA;
   58: use LONCAPA::Queue;
   59: use LONCAPA::Stack;
   60: use LONCAPA::LondConnection;
   61: use LONCAPA::LondTransaction;
   62: use LONCAPA::Configuration;
   63: use LONCAPA::HashIterator;
   64: 
   65: 
   66: # Read the httpd configuration file to get perl variables
   67: # normally set in apache modules:
   68: 
   69: my $perlvarref = LONCAPA::Configuration::read_conf('loncapa.conf');
   70: my %perlvar    = %{$perlvarref};
   71: 
   72: #
   73: #  parent and shared variables.
   74: 
   75: my %ChildHash;			# by pid -> host.
   76: my %HostToPid;			# By host -> pid.
   77: my %HostHash;			# by loncapaname -> IP.
   78: 
   79: 
   80: my $MaxConnectionCount = 10;	# Will get from config later.
   81: my $ClientConnection = 0;	# Uniquifier for client events.
   82: 
   83: my $DebugLevel = 0;
   84: my $NextDebugLevel= 2;		# So Sigint can toggle this.
   85: my $IdleTimeout= 600;		# Wait 10 minutes before pruning connections.
   86: 
   87: my $LogTransactions = 0;	# When True, all transactions/replies get logged.
   88: 
   89: #
   90: #  The variables below are only used by the child processes.
   91: #
   92: my $RemoteHost;			# Name of host child is talking to.
   93: my $UnixSocketDir= $perlvar{'lonSockDir'};
   94: my $IdleConnections = Stack->new(); # Set of idle connections
   95: my %ActiveConnections;		# Connections to the remote lond.
   96: my %ActiveTransactions;		# LondTransactions in flight.
   97: my %ActiveClients;		# Serial numbers of active clients by socket.
   98: my $WorkQueue       = Queue->new(); # Queue of pending transactions.
   99: my $ConnectionCount = 0;
  100: my $IdleSeconds     = 0;	# Number of seconds idle.
  101: my $Status          = "";	# Current status string.
  102: my $RecentLogEntry  = "";
  103: my $ConnectionRetries=2;	# Number of connection retries allowed.
  104: my $ConnectionRetriesLeft=2;	# Number of connection retries remaining.
  105: my $LondVersion     = "unknown"; # Version of lond we talk with.
  106: my $KeyMode         = "";       # e.g. ssl, local, insecure from last connect.
  107: 
  108: #
  109: #   The hash below gives the HTML format for log messages
  110: #   given a severity.
  111: #    
  112: my %LogFormats;
  113: 
  114: $LogFormats{"CRITICAL"} = "<font color='red'>CRITICAL: %s</font>";
  115: $LogFormats{"SUCCESS"}  = "<font color='green'>SUCCESS: %s</font>";
  116: $LogFormats{"INFO"}     = "<font color='yellow'>INFO: %s</font>";
  117: $LogFormats{"WARNING"}  = "<font color='blue'>WARNING: %s</font>";
  118: $LogFormats{"DEFAULT"}  = " %s ";
  119: 
  120: 
  121: 
  122: =pod
  123: 
  124: =head2 LogPerm
  125: 
  126: Makes an entry into the permanent log file.
  127: 
  128: =cut
  129: sub LogPerm {
  130:     my $message=shift;
  131:     my $execdir=$perlvar{'lonDaemons'};
  132:     my $now=time;
  133:     my $local=localtime($now);
  134:     my $fh=IO::File->new(">>$execdir/logs/lonnet.perm.log");
  135:     print $fh "$now:$message:$local\n";
  136: }
  137: 
  138: =pod
  139: 
  140: =head2 Log
  141: 
  142: Logs a message to the log file.
  143: Parameters:
  144: 
  145: =item severity
  146: 
  147: One of CRITICAL, WARNING, INFO, SUCCESS used to select the
  148: format string used to format the message.  if the severity is
  149: not a defined severity the Default format string is used.
  150: 
  151: =item message
  152: 
  153: The base message.  In addtion to the format string, the message
  154: will be appended to a string containing the name of our remote
  155: host and the time will be formatted into the message.
  156: 
  157: =cut
  158: 
  159: sub Log {
  160: 
  161:     my ($severity, $message) = @_;
  162: 
  163:     if(!$LogFormats{$severity}) {
  164: 	$severity = "DEFAULT";
  165:     }
  166: 
  167:     my $format = $LogFormats{$severity};
  168:     
  169:     #  Put the window dressing in in front of the message format:
  170: 
  171:     my $now   = time;
  172:     my $local = localtime($now);
  173:     my $finalformat = "$local ($$) [$RemoteHost] [$Status] ";
  174:     my $finalformat = $finalformat.$format."\n";
  175: 
  176:     # open the file and put the result.
  177: 
  178:     my $execdir = $perlvar{'lonDaemons'};
  179:     my $fh      = IO::File->new(">>$execdir/logs/lonc.log");
  180:     my $msg = sprintf($finalformat, $message);
  181:     $RecentLogEntry = $msg;
  182:     print $fh $msg;
  183:     
  184:     
  185: }
  186: 
  187: 
  188: =pod
  189: 
  190: =head2 GetPeerName
  191: 
  192: Returns the name of the host that a socket object is connected to.
  193: 
  194: =cut
  195: 
  196: sub GetPeername {
  197: 
  198: 
  199:     my ($connection, $AdrFamily) = @_;
  200: 
  201:     my $peer       = $connection->peername();
  202:     my $peerport;
  203:     my $peerip;
  204:     if($AdrFamily == AF_INET) {
  205: 	($peerport, $peerip) = sockaddr_in($peer);
  206: 	my $peername    = gethostbyaddr($peerip, $AdrFamily);
  207: 	return $peername;
  208:     } elsif ($AdrFamily == AF_UNIX) {
  209: 	my $peerfile;
  210: 	($peerfile) = sockaddr_un($peer);
  211: 	return $peerfile;
  212:     }
  213: }
  214: =pod
  215: 
  216: =head2 Debug
  217: 
  218: Invoked to issue a debug message.
  219: 
  220: =cut
  221: 
  222: sub Debug {
  223: 
  224:     my ($level, $message) = @_;
  225: 
  226:     if ($level <= $DebugLevel) {
  227: 	Log("INFO", "-Debug- $message host = $RemoteHost");
  228:     }
  229: }
  230: 
  231: sub SocketDump {
  232: 
  233:     my ($level, $socket) = @_;
  234: 
  235:     if($level <= $DebugLevel) {
  236: 	$socket->Dump(-1);	# Ensure it will get dumped.
  237:     }
  238: }
  239: 
  240: =pod
  241: 
  242: =head2 ShowStatus
  243: 
  244:  Place some text as our pid status.
  245:  and as what we return in a SIGUSR1
  246: 
  247: =cut
  248: sub ShowStatus {
  249:     my $state = shift;
  250:     my $now = time;
  251:     my $local = localtime($now);
  252:     $Status   = $local.": ".$state;
  253:     $0='lonc: '.$state.' '.$local;
  254: }
  255: 
  256: =pod
  257: 
  258: =head 2 SocketTimeout
  259: 
  260:     Called when an action on the socket times out.  The socket is 
  261:    destroyed and any active transaction is failed.
  262: 
  263: 
  264: =cut
  265: sub SocketTimeout {
  266:     my $Socket = shift;
  267:     Log("WARNING", "A socket timeout was detected");
  268:     Debug(5, " SocketTimeout called: ");
  269:     $Socket->Dump(0);
  270:     if(exists($ActiveTransactions{$Socket})) {
  271: 	FailTransaction($ActiveTransactions{$Socket});
  272:     }
  273:     KillSocket($Socket);	# A transaction timeout also counts as
  274:                                 # a connection failure:
  275:     $ConnectionRetriesLeft--;
  276:     if($ConnectionRetriesLeft <= 0) {
  277: 	Log("CRITICAL", "Host marked DEAD: ".GetServerHost());
  278:     }
  279: 
  280: }
  281: #----------------------------- Timer management ------------------------
  282: 
  283: =pod
  284: 
  285: =head2 Tick
  286: 
  287: Invoked  each timer tick.
  288: 
  289: =cut
  290: 
  291: 
  292: sub Tick {
  293:     my ($Event)       = @_;
  294:     my $clock_watcher = $Event->w;
  295: 
  296:     my $client;
  297:     if($ConnectionRetriesLeft > 0) {
  298: 	ShowStatus(GetServerHost()." Connection count: ".$ConnectionCount
  299: 		   ." Retries remaining: ".$ConnectionRetriesLeft
  300: 		   ." ($KeyMode)");
  301:     } else {
  302: 	ShowStatus(GetServerHost()." >> DEAD <<");
  303:     }
  304:     # Is it time to prune connection count:
  305: 
  306: 
  307:     if($IdleConnections->Count()  && 
  308:        ($WorkQueue->Count() == 0)) { # Idle connections and nothing to do?
  309: 	$IdleSeconds++;
  310: 	if($IdleSeconds > $IdleTimeout) { # Prune a connection...
  311: 	    my $Socket = $IdleConnections->pop();
  312: 	    KillSocket($Socket);
  313: 	    IdleSeconds = 0;	# Otherwise all connections get trimmed to fast.
  314: 	}
  315:     } else {
  316: 	$IdleSeconds = 0;	# Reset idle count if not idle.
  317:     }
  318:     #
  319:     #  For each inflight transaction, tick down its timeout counter.
  320:     #
  321: 
  322:     foreach my $item (keys %ActiveConnections) {
  323: 	my $State = $ActiveConnections{$item}->data->GetState();
  324: 	if ($State ne 'Idle') {
  325: 	    Debug(5,"Ticking Socket $State $item");
  326: 	    $ActiveConnections{$item}->data->Tick();
  327: 	}
  328:     }
  329:     # Do we have work in the queue, but no connections to service them?
  330:     # If so, try to make some new connections to get things going again.
  331:     #
  332:     
  333:     my $Requests = $WorkQueue->Count();
  334:     if (($ConnectionCount == 0)  && ($Requests > 0)) { 
  335: 	if ($ConnectionRetriesLeft > 0) {
  336: 	    my $Connections = ($Requests <= $MaxConnectionCount) ?
  337: 		$Requests : $MaxConnectionCount;
  338: 	    Debug(5,"Work but no connections, start ".$Connections." of them");
  339: 	    my $successCount = 0;
  340: 	    for (my $i =0; $i < $Connections; $i++) {
  341: 		$successCount += MakeLondConnection();
  342: 	    }
  343: 	    if($successCount == 0) { # All connections failed:
  344: 		Debug(5,"Work in queue failed to make any connectiouns\n");
  345: 		EmptyQueue();	# Fail pending transactions with con_lost.
  346: 		CloseAllLondConnections(); # Should all be closed but....
  347: 	    }
  348: 	} else {
  349: 	    ShowStatus(GetServerHost()." >>> DEAD!!! <<<");
  350: 	    Debug(5,"Work in queue, but gave up on connections..flushing\n");
  351: 	    EmptyQueue();	# Connections can't be established.
  352: 	    CloseAllLondConnections(); # Should all already be closed but...
  353: 	}
  354:        
  355:     }
  356:     if ($ConnectionCount == 0) {
  357: 	$KeyMode = ""; 
  358: 	$clock_watcher->cancel();
  359:     }
  360: }
  361: 
  362: =pod
  363: 
  364: =head2 SetupTimer
  365: 
  366: Sets up a 1 per sec recurring timer event.  The event handler is used to:
  367: 
  368: =item
  369: 
  370: Trigger timeouts on communications along active sockets.
  371: 
  372: =item
  373: 
  374: Trigger disconnections of idle sockets.
  375: 
  376: =cut
  377: 
  378: sub SetupTimer {
  379:     Debug(6, "SetupTimer");
  380:     Event->timer(interval => 1, cb => \&Tick );
  381: }
  382: 
  383: =pod
  384: 
  385: =head2 ServerToIdle
  386: 
  387: This function is called when a connection to the server is
  388: ready for more work.
  389: 
  390: If there is work in the Work queue the top element is dequeued
  391: and the connection will start to work on it.  If the work queue is
  392: empty, the connection is pushed on the idle connection stack where
  393: it will either get another work unit, or alternatively, if it sits there
  394: long enough, it will be shut down and released.
  395: 
  396: =cut
  397: 
  398: sub ServerToIdle {
  399:     my $Socket   = shift;	# Get the socket.
  400:     $KeyMode = $Socket->{AuthenticationMode};
  401:     delete($ActiveTransactions{$Socket}); # Server has no transaction
  402: 
  403:     &Debug(5, "Server to idle");
  404: 
  405:     #  If there's work to do, start the transaction:
  406: 
  407:     my $reqdata = $WorkQueue->dequeue(); # This is a LondTransaction
  408:     if ($reqdata ne undef)  {
  409: 	Debug(5, "Queue gave request data: ".$reqdata->getRequest());
  410: 	&StartRequest($Socket,  $reqdata);
  411: 
  412:     } else {
  413: 	
  414:     #  There's no work waiting, so push the server to idle list.
  415: 	&Debug(5, "No new work requests, server connection going idle");
  416: 	$IdleConnections->push($Socket);
  417:     }
  418: }
  419: 
  420: =pod
  421: 
  422: =head2 ClientWritable
  423: 
  424: Event callback for when a client socket is writable.
  425: 
  426: This callback is established when a transaction reponse is
  427: avaiable from lond.  The response is forwarded to the unix socket
  428: as it becomes writable in this sub.
  429: 
  430: Parameters:
  431: 
  432: =item Event
  433: 
  434: The event that has been triggered. Event->w->data is
  435: the data and Event->w->fd is the socket to write.
  436: 
  437: =cut
  438: 
  439: sub ClientWritable {
  440:     my $Event    = shift;
  441:     my $Watcher  = $Event->w;
  442:     my $Data     = $Watcher->data;
  443:     my $Socket   = $Watcher->fd;
  444: 
  445:     # Try to send the data:
  446: 
  447:     &Debug(6, "ClientWritable writing".$Data);
  448:     &Debug(9, "Socket is: ".$Socket);
  449: 
  450:     if($Socket->connected) {
  451: 	my $result = $Socket->send($Data, 0);
  452: 	
  453: 	# $result undefined: the write failed.
  454: 	# otherwise $result is the number of bytes written.
  455: 	# Remove that preceding string from the data.
  456: 	# If the resulting data is empty, destroy the watcher
  457: 	# and set up a read event handler to accept the next
  458: 	# request.
  459: 	
  460: 	&Debug(9,"Send result is ".$result." Defined: ".defined($result));
  461: 	if($result ne undef) {
  462: 	    &Debug(9, "send result was defined");
  463: 	    if($result == length($Data)) { # Entire string sent.
  464: 		&Debug(9, "ClientWritable data all written");
  465: 		$Watcher->cancel();
  466: 		#
  467: 		#  Set up to read next request from socket:
  468: 		
  469: 		my $descr     = sprintf("Connection to lonc client %d",
  470: 					$ActiveClients{$Socket});
  471: 		Event->io(cb    => \&ClientRequest,
  472: 			  poll  => 'r',
  473: 			  desc  => $descr,
  474: 			  data  => "",
  475: 			  fd    => $Socket);
  476: 		
  477: 	    } else {		# Partial string sent.
  478: 		$Watcher->data(substr($Data, $result));
  479: 		if($result == 0) {    # client hung up on us!!
  480: 		    # Log("INFO", "lonc pipe client hung up on us!");
  481: 		    $Watcher->cancel;
  482: 		    $Socket->shutdown(2);
  483: 		    $Socket->close();
  484: 		}
  485: 	    }
  486: 	    
  487: 	} else {			# Error of some sort...
  488: 	    
  489: 	    # Some errnos are possible:
  490: 	    my $errno = $!;
  491: 	    if($errno == POSIX::EWOULDBLOCK   ||
  492: 	       $errno == POSIX::EAGAIN        ||
  493: 	       $errno == POSIX::EINTR) {
  494: 		# No action taken?
  495: 	    } else {		# Unanticipated errno.
  496: 		&Debug(5,"ClientWritable error or peer shutdown".$RemoteHost);
  497: 		$Watcher->cancel;	# Stop the watcher.
  498: 		$Socket->shutdown(2); # Kill connection
  499: 		$Socket->close();	# Close the socket.
  500: 	    }
  501: 	    
  502: 	}
  503:     } else {
  504: 	$Watcher->cancel();	# A delayed request...just cancel.
  505:     }
  506: }
  507: 
  508: =pod
  509: 
  510: =head2 CompleteTransaction
  511: 
  512: Called when the reply data has been received for a lond 
  513: transaction.   The reply data must now be sent to the
  514: ultimate client on the other end of the Unix socket.  This is
  515: done by setting up a writable event for the socket with the
  516: data the reply data.
  517: 
  518: Parameters:
  519: 
  520: =item Socket
  521: 
  522: Socket on which the lond transaction occured.  This is a
  523: LondConnection. The data received is in the TransactionReply member.
  524: 
  525: =item Transaction
  526: 
  527: The transaction that is being completed.
  528: 
  529: =cut
  530: 
  531: sub CompleteTransaction {
  532:     &Debug(5,"Complete transaction");
  533: 
  534:     my ($Socket, $Transaction) = @_;
  535: 
  536:     if (!$Transaction->isDeferred()) { # Normal transaction
  537: 	my $data   = $Socket->GetReply(); # Data to send.
  538: 	if($LogTransactions) {
  539: 	    Log("SUCCESS", "Reply from lond: '$data'");
  540: 	}
  541: 	StartClientReply($Transaction, $data);
  542:     } else {			# Delete deferred transaction file.
  543: 	Log("SUCCESS", "A delayed transaction was completed");
  544: 	LogPerm("S:$Transaction->getClient() :".$Transaction->getRequest());
  545: 	unlink $Transaction->getFile();
  546:     }
  547: }
  548: 
  549: =pod
  550: 
  551: =head1 StartClientReply
  552: 
  553:    Initiates a reply to a client where the reply data is a parameter.
  554: 
  555: =head2  parameters:
  556: 
  557: =item Transaction
  558: 
  559:     The transaction for which we are responding to the client.
  560: 
  561: =item data
  562: 
  563:     The data to send to apached client.
  564: 
  565: =cut
  566: 
  567: sub StartClientReply {
  568: 
  569:     my ($Transaction, $data) = @_;
  570: 
  571:     my $Client   = $Transaction->getClient();
  572: 
  573:     &Debug(8," Reply was: ".$data);
  574:     my $Serial         = $ActiveClients{$Client};
  575:     my $desc           = sprintf("Connection to lonc client %d",
  576: 				 $Serial);
  577:     Event->io(fd       => $Client,
  578: 	      poll     => "w",
  579: 	      desc     => $desc,
  580: 	      cb       => \&ClientWritable,
  581: 	      data     => $data);
  582: }
  583: 
  584: =pod
  585: 
  586: =head2 FailTransaction
  587: 
  588:   Finishes a transaction with failure because the associated lond socket
  589:   disconnected.  There are two possibilities:
  590:   - The transaction is deferred: in which case we just quietly
  591:     delete the transaction since there is no client connection.
  592:   - The transaction is 'live' in which case we initiate the sending
  593:     of "con_lost" to the client.
  594: 
  595: Deleting the transaction means killing it from the %ActiveTransactions hash.
  596: 
  597: Parameters:
  598: 
  599: =item client  
  600:  
  601:    The LondTransaction we are failing.
  602:  
  603: 
  604: =cut
  605: 
  606: sub FailTransaction {
  607:     my $transaction = shift;
  608:     
  609:     #  If the socket is dead, that's already logged.
  610: 
  611:     if ($ConnectionRetriesLeft > 0) {
  612: 	Log("WARNING", "Failing transaction "
  613: 	    .$transaction->getRequest());
  614:     }
  615:     Debug(1, "Failing transaction: ".$transaction->getRequest());
  616:     if (!$transaction->isDeferred()) { # If the transaction is deferred we'll get to it.
  617: 	my $client  = $transaction->getClient();
  618: 	Debug(1," Replying con_lost to ".$transaction->getRequest());
  619: 	StartClientReply($transaction, "con_lost\n");
  620:     }
  621: 
  622: }
  623: 
  624: =pod
  625: =head1  EmptyQueue
  626: 
  627:   Fails all items in the work queue with con_lost.
  628:   Note that each item in the work queue is a transaction.
  629: 
  630: =cut
  631: sub EmptyQueue {
  632:     $ConnectionRetriesLeft--;	# Counts as connection failure too.
  633:     while($WorkQueue->Count()) {
  634: 	my $request = $WorkQueue->dequeue(); # This is a transaction
  635: 	FailTransaction($request);
  636:     }
  637: }
  638: 
  639: =pod
  640: 
  641: =head2 CloseAllLondConnections
  642: 
  643: Close all connections open on lond prior to exit e.g.
  644: 
  645: =cut
  646: sub CloseAllLondConnections {
  647:     foreach my $Socket (keys %ActiveConnections) {
  648:       if(exists($ActiveTransactions{$Socket})) {
  649: 	FailTransaction($ActiveTransactions{$Socket});
  650:       }
  651:       KillSocket($Socket);
  652:     }
  653: }
  654: =cut
  655: 
  656: =pod
  657: 
  658: =head2 KillSocket
  659:  
  660: Destroys a socket.  This function can be called either when a socket
  661: has died of 'natural' causes or because a socket needs to be pruned due to
  662: idleness.  If the socket has died naturally, if there are no longer any 
  663: live connections a new connection is created (in case there are transactions
  664: in the queue).  If the socket has been pruned, it is never re-created.
  665: 
  666: Parameters:
  667: 
  668: =item Socket
  669:  
  670:   The socket to kill off.
  671: 
  672: =item Restart
  673: 
  674: nonzero if we are allowed to create a new connection.
  675: 
  676: 
  677: =cut
  678: sub KillSocket {
  679:     my $Socket = shift;
  680: 
  681:     Log("WARNING", "Shutting down a socket");
  682:     $Socket->Shutdown();
  683: 
  684:     #  If the socket came from the active connection set,
  685:     #  delete its transaction... note that FailTransaction should
  686:     #  already have been called!!!
  687:     #  otherwise it came from the idle set.
  688:     #  
  689:     
  690:     if(exists($ActiveTransactions{$Socket})) {
  691: 	delete ($ActiveTransactions{$Socket});
  692:     }
  693:     if(exists($ActiveConnections{$Socket})) {
  694: 	delete($ActiveConnections{$Socket});
  695: 	$ConnectionCount--;
  696: 	if ($ConnectionCount < 0) { $ConnectionCount = 0; }
  697:     }
  698:     #  If the connection count has gone to zero and there is work in the
  699:     #  work queue, the work all gets failed with con_lost.
  700:     #
  701:     if($ConnectionCount == 0) {
  702: 	EmptyQueue();
  703: 	CloseAllLondConnections; # Should all already be closed but...
  704:     }
  705: }
  706: 
  707: =pod
  708: 
  709: =head2 LondReadable
  710: 
  711: This function is called whenever a lond connection
  712: is readable.  The action is state dependent:
  713: 
  714: =head3 State=Initialized
  715: 
  716: We''re waiting for the challenge, this is a no-op until the
  717: state changes.
  718: 
  719: =head3 State=Challenged 
  720: 
  721: The challenge has arrived we need to transition to Writable.
  722: The connection must echo the challenge back.
  723: 
  724: =head3 State=ChallengeReplied
  725: 
  726: The challenge has been replied to.  The we are receiveing the 
  727: 'ok' from the partner.
  728: 
  729: =head3  State=ReadingVersionString
  730: 
  731: We have requested the lond version and are reading the
  732: version back.  Upon completion, we'll store the version away
  733: for future use(?).
  734: 
  735: =head3 State=HostSet
  736: 
  737: We have selected the domain name of our peer (multhomed hosts)
  738: and are getting the reply (presumably ok) back.
  739: 
  740: =head3 State=RequestingKey
  741: 
  742: The ok has been received and we need to send the request for
  743: an encryption key.  Transition to writable for that.
  744: 
  745: =head3 State=ReceivingKey
  746: 
  747: The the key has been requested, now we are reading the new key.
  748: 
  749: =head3 State=Idle 
  750: 
  751: The encryption key has been negotiated or we have finished 
  752: reading data from the a transaction.   If the callback data has
  753: a client as well as the socket iformation, then we are 
  754: doing a transaction and the data received is relayed to the client
  755: before the socket is put on the idle list.
  756: 
  757: =head3 State=SendingRequest
  758: 
  759: I do not think this state can be received here, but if it is,
  760: the appropriate thing to do is to transition to writable, and send
  761: the request.
  762: 
  763: =head3 State=ReceivingReply
  764: 
  765: We finished sending the request to the server and now transition
  766: to readable to receive the reply. 
  767: 
  768: The parameter to this function are:
  769: 
  770: The event. Implicit in this is the watcher and its data.  The data 
  771: contains at least the lond connection object and, if a 
  772: transaction is in progress, the socket attached to the local client.
  773: 
  774: =cut
  775: 
  776: sub LondReadable {
  777: 
  778:     my $Event      = shift;
  779:     my $Watcher    = $Event->w;
  780:     my $Socket     = $Watcher->data;
  781:     my $client     = undef;
  782: 
  783:     &Debug(6,"LondReadable called state = ".$Socket->GetState());
  784: 
  785: 
  786:     my $State = $Socket->GetState(); # All action depends on the state.
  787: 
  788:     SocketDump(6, $Socket);
  789:     my $status = $Socket->Readable();
  790: 
  791:     &Debug(2, "Socket->Readable returned: $status");
  792: 
  793:     if($status != 0) {
  794: 	# bad return from socket read. Currently this means that
  795: 	# The socket has become disconnected. We fail the transaction.
  796: 
  797: 	Log("WARNING",
  798: 	    "Lond connection lost.");
  799: 	if(exists($ActiveTransactions{$Socket})) {
  800: 	    FailTransaction($ActiveTransactions{$Socket});
  801: 	}
  802: 	$Watcher->cancel();
  803: 	KillSocket($Socket);
  804: 	$ConnectionRetriesLeft--;       # Counts as connection failure
  805: 	return;
  806:     }
  807:     SocketDump(6,$Socket);
  808: 
  809:     $State = $Socket->GetState(); # Update in case of transition.
  810:     &Debug(6, "After read, state is ".$State);
  811: 
  812:     if($State eq "Initialized") {
  813: 
  814: 
  815:     } elsif ($State eq "ChallengeReceived") {
  816: 	#  The challenge must be echoed back;  The state machine
  817: 	# in the connection takes care of setting that up.  Just
  818: 	# need to transition to writable:
  819: 	
  820: 	$Watcher->cb(\&LondWritable);
  821: 	$Watcher->poll("w");
  822: 
  823:     } elsif ($State eq "ChallengeReplied") {
  824: 
  825:     } elsif ($State eq "RequestingVersion") {
  826: 	# Need to ask for the version... that is writiability:
  827: 
  828: 	$Watcher->cb(\&LondWritable);
  829: 	$Watcher->poll("w");
  830: 
  831:     } elsif ($State eq "ReadingVersionString") {
  832: 	# Read the rest of the version string... 
  833:     } elsif ($State eq "SetHost") {
  834: 	# Need to request the actual domain get set...
  835: 
  836: 	$Watcher->cb(\&LondWritable);
  837: 	$Watcher->poll("w");
  838:     } elsif ($State eq "HostSet") {
  839: 	# Reading the 'ok' from the peer.
  840: 
  841:     } elsif ($State eq "RequestingKey") {
  842: 	#  The ok was received.  Now we need to request the key
  843: 	#  That requires us to be writable:
  844: 
  845: 	$Watcher->cb(\&LondWritable);
  846: 	$Watcher->poll("w");
  847: 
  848:     } elsif ($State eq "ReceivingKey") {
  849: 
  850:     } elsif ($State eq "Idle") {
  851:    
  852: 	# This is as good a spot as any to get the peer version
  853: 	# string:
  854:    
  855: 	if($LondVersion eq "unknown") {
  856: 	    $LondVersion = $Socket->PeerVersion();
  857: 	    Log("INFO", "Connected to lond version: $LondVersion");
  858: 	}
  859: 	# If necessary, complete a transaction and then go into the
  860: 	# idle queue.
  861: 	#  Note that a trasition to idle indicates a live lond
  862: 	# on the other end so reset the connection retries.
  863: 	#
  864: 	$ConnectionRetriesLeft = $ConnectionRetries; # success resets the count
  865: 	$Watcher->cancel();
  866: 	if(exists($ActiveTransactions{$Socket})) {
  867: 	    Debug(5,"Completing transaction!!");
  868: 	    CompleteTransaction($Socket, 
  869: 				$ActiveTransactions{$Socket});
  870: 	} else {
  871: 	    Log("SUCCESS", "Connection ".$ConnectionCount." to "
  872: 		.$RemoteHost." now ready for action");
  873: 	}
  874: 	ServerToIdle($Socket);	# Next work unit or idle.
  875: 	
  876:     } elsif ($State eq "SendingRequest") {
  877: 	#  We need to be writable for this and probably don't belong
  878: 	#  here inthe first place.
  879: 
  880: 	Deubg(6, "SendingRequest state encountered in readable");
  881: 	$Watcher->poll("w");
  882: 	$Watcher->cb(\&LondWritable);
  883: 
  884:     } elsif ($State eq "ReceivingReply") {
  885: 
  886: 
  887:     } else {
  888: 	# Invalid state.
  889: 	Debug(4, "Invalid state in LondReadable");
  890:     }
  891: }
  892: 
  893: =pod
  894: 
  895: =head2 LondWritable
  896: 
  897: This function is called whenever a lond connection
  898: becomes writable while there is a writeable monitoring
  899: event.  The action taken is very state dependent:
  900: 
  901: =head3 State = Connected 
  902: 
  903: The connection is in the process of sending the 'init' hailing to the
  904: lond on the remote end.  The connection object''s Writable member is
  905: called.  On error, ConnectionError is called to destroy the connection
  906: and remove it from the ActiveConnections hash
  907: 
  908: =head3 Initialized
  909: 
  910: 'init' has been sent, writability monitoring is removed and
  911: readability monitoring is started with LondReadable as the callback.
  912: 
  913: =head3 ChallengeReceived
  914: 
  915: The connection has received the who are you challenge from the remote
  916: system, and is in the process of sending the challenge
  917: response. Writable is called.
  918: 
  919: =head3 ChallengeReplied
  920: 
  921: The connection has replied to the initial challenge The we switch to
  922: monitoring readability looking for the server to reply with 'ok'.
  923: 
  924: =head3 RequestingKey
  925: 
  926: The connection is in the process of requesting its encryption key.
  927: Writable is called.
  928: 
  929: =head3 ReceivingKey
  930: 
  931: The connection has sent the request for a key.  Switch to readability
  932: monitoring to accept the key
  933: 
  934: =head3 SendingRequest
  935: 
  936: The connection is in the process of sending a request to the server.
  937: This request is part of a client transaction.  All the states until
  938: now represent the client setup protocol. Writable is called.
  939: 
  940: =head3 ReceivingReply
  941: 
  942: The connection has sent a request.  Now it must receive a reply.
  943: Readability monitoring is requested.
  944: 
  945: This function is an event handler and therefore receives as
  946: a parameter the event that has fired.  The data for the watcher
  947: of this event is a reference to a list of one or two elements,
  948: depending on state. The first (and possibly only) element is the
  949: socket.  The second (present only if a request is in progress)
  950: is the socket on which to return a reply to the caller.
  951: 
  952: =cut
  953: 
  954: sub LondWritable {
  955:     my $Event   = shift;
  956:     my $Watcher = $Event->w;
  957:     my $Socket  = $Watcher->data;
  958:     my $State   = $Socket->GetState();
  959: 
  960:     Debug(6,"LondWritable State = ".$State."\n");
  961: 
  962:  
  963:     #  Figure out what to do depending on the state of the socket:
  964:     
  965: 
  966: 
  967: 
  968:     SocketDump(6,$Socket);
  969: 
  970:     #  If the socket is writable, we must always write.
  971:     # Only by writing will we undergo state transitions.
  972:     # Old logic wrote in state specific code below, however
  973:     # That forces us at least through another invocation of
  974:     # this function after writability is possible again.
  975:     # This logic also factors out common code for handling
  976:     # write failures... in all cases, write failures 
  977:     # Kill the socket.
  978:     #  This logic makes the branches of the >big< if below
  979:     # so that the writing states are actually NO-OPs.
  980: 
  981:     if ($Socket->Writable() != 0) {
  982: 	#  The write resulted in an error.
  983: 	# We'll treat this as if the socket got disconnected:
  984: 	Log("WARNING", "Connection to ".$RemoteHost.
  985: 	    " has been disconnected");
  986: 	if(exists($ActiveTransactions{$Socket})) {
  987: 	    FailTransaction($ActiveTransactions{$Socket});
  988: 	}
  989: 	$Watcher->cancel();
  990: 	KillSocket($Socket);
  991: 	return;
  992:     }
  993: 
  994: 
  995: 
  996:     if      ($State eq "Connected")         {
  997: 
  998: 	#  "init" is being sent...
  999:  
 1000:     } elsif ($State eq "Initialized")       {
 1001: 
 1002: 	# Now that init was sent, we switch 
 1003: 	# to watching for readability:
 1004: 
 1005: 	$Watcher->cb(\&LondReadable);
 1006: 	$Watcher->poll("r");
 1007: 	
 1008:     } elsif ($State eq "ChallengeReceived") {
 1009: 	# We received the challenge, now we 
 1010: 	# are echoing it back. This is a no-op,
 1011: 	# we're waiting for the state to change
 1012: 	
 1013:     } elsif ($State eq "ChallengeReplied")  {
 1014: 	# The echo was sent back, so we switch
 1015: 	# to watching readability.
 1016: 
 1017: 	$Watcher->cb(\&LondReadable);
 1018: 	$Watcher->poll("r");
 1019:     } elsif ($State eq "RequestingVersion") {
 1020: 	# Sending the peer a version request...
 1021: 
 1022:     } elsif ($State eq "ReadingVersionString") {
 1023: 	# Transition to read since we have sent the
 1024: 	# version command and now just need to read the
 1025: 	# version string from the peer:
 1026:       
 1027: 	$Watcher->cb(\&LondReadable);
 1028: 	$Watcher->poll("r");
 1029:       
 1030:     } elsif ($State eq "SetHost") {
 1031: 	#  Setting the remote domain...
 1032: 
 1033:     } elsif ($State eq "HostSet") {
 1034: 	# Back to readable to get the ok.
 1035:       
 1036: 	$Watcher->cb(\&LondReadable);
 1037: 	$Watcher->poll("r");
 1038:       
 1039: 
 1040:     } elsif ($State eq "RequestingKey")     {
 1041: 	# At this time we're requesting the key.
 1042: 	# again, this is essentially a no-op.
 1043: 
 1044:     } elsif ($State eq "ReceivingKey")      {
 1045: 	# Now we need to wait for the key
 1046: 	# to come back from the peer:
 1047: 
 1048: 	$Watcher->cb(\&LondReadable);
 1049: 	$Watcher->poll("r");
 1050: 
 1051:     } elsif ($State eq "SendingRequest")    {
 1052:  
 1053: 	# At this time we are sending a request to the
 1054: 	# peer... write the next chunk:
 1055: 
 1056: 
 1057:     } elsif ($State eq "ReceivingReply")    {
 1058: 	# The send has completed.  Wait for the
 1059: 	# data to come in for a reply.
 1060: 	Debug(8,"Writable sent request/receiving reply");
 1061: 	$Watcher->cb(\&LondReadable);
 1062: 	$Watcher->poll("r");
 1063: 
 1064:     } else {
 1065: 	#  Control only passes here on an error: 
 1066: 	#  the socket state does not match any
 1067: 	#  of the known states... so an error
 1068: 	#  must be logged.
 1069: 
 1070: 	&Debug(4, "Invalid socket state ".$State."\n");
 1071:     }
 1072:     
 1073: }
 1074: =pod
 1075:     
 1076: =cut
 1077: sub QueueDelayed {
 1078:     Debug(3,"QueueDelayed called");
 1079: 
 1080:     my $path = "$perlvar{'lonSockDir'}/delayed";
 1081: 
 1082:     Debug(4, "Delayed path: ".$path);
 1083:     opendir(DIRHANDLE, $path);
 1084:     
 1085:     my @alldelayed = grep /\.$RemoteHost$/, readdir DIRHANDLE;
 1086:     closedir(DIRHANDLE);
 1087:     my $dfname;
 1088:     my $reqfile;
 1089:     foreach $dfname (sort  @alldelayed) {
 1090: 	$reqfile = "$path/$dfname";
 1091: 	Debug(4, "queueing ".$reqfile);
 1092: 	my $Handle = IO::File->new($reqfile);
 1093: 	my $cmd    = <$Handle>;
 1094: 	chomp $cmd;		# There may or may not be a newline...
 1095: 	$cmd = $cmd."\n";	# now for sure there's exactly one newline.
 1096: 	my $Transaction = LondTransaction->new($cmd);
 1097: 	$Transaction->SetDeferred($reqfile);
 1098: 	QueueTransaction($Transaction);
 1099:     }
 1100:     
 1101: }
 1102: 
 1103: =pod
 1104: 
 1105: =head2 MakeLondConnection
 1106: 
 1107: Create a new lond connection object, and start it towards its initial
 1108: idleness.  Once idle, it becomes elligible to receive transactions
 1109: from the work queue.  If the work queue is not empty when the
 1110: connection is completed and becomes idle, it will dequeue an entry and
 1111: start off on it.
 1112: 
 1113: =cut
 1114: 
 1115: sub MakeLondConnection {     
 1116:     Debug(4,"MakeLondConnection to ".GetServerHost()." on port "
 1117: 	  .GetServerPort());
 1118: 
 1119:     my $Connection = LondConnection->new(&GetServerHost(),
 1120: 					 &GetServerPort());
 1121: 
 1122:     if($Connection eq undef) {	# Needs to be more robust later.
 1123: 	Log("CRITICAL","Failed to make a connection with lond.");
 1124: 	$ConnectionRetriesLeft--;
 1125: 	return 0;		# Failure.
 1126:     }  else {
 1127: 
 1128: 	# The connection needs to have writability 
 1129: 	# monitored in order to send the init sequence
 1130: 	# that starts the whole authentication/key
 1131: 	# exchange underway.
 1132: 	#
 1133: 	my $Socket = $Connection->GetSocket();
 1134: 	if($Socket eq undef) {
 1135: 	    die "did not get a socket from the connection";
 1136: 	} else {
 1137: 	    &Debug(9,"MakeLondConnection got socket: ".$Socket);
 1138: 	}
 1139: 	
 1140: 	$Connection->SetTimeoutCallback(\&SocketTimeout);
 1141: 
 1142: 	my $event = Event->io(fd       => $Socket,
 1143: 			   poll     => 'w',
 1144: 			   cb       => \&LondWritable,
 1145: 			   data     => $Connection,
 1146: 			   desc => 'Connection to lond server');
 1147: 	$ActiveConnections{$Connection} = $event;
 1148: 	if ($ConnectionCount == 0) {
 1149: 	    &SetupTimer;	# Need to handle timeouts with connections...
 1150: 	}
 1151: 	$ConnectionCount++;
 1152: 	Debug(4, "Connection count = ".$ConnectionCount);
 1153: 	if($ConnectionCount == 1) { # First Connection:
 1154: 	    QueueDelayed;
 1155: 	}
 1156: 	Log("SUCESS", "Created connection ".$ConnectionCount
 1157: 	    ." to host ".GetServerHost());
 1158: 	return 1;		# Return success.
 1159:     }
 1160:     
 1161: }
 1162: 
 1163: =pod
 1164: 
 1165: =head2 StartRequest
 1166: 
 1167: Starts a lond request going on a specified lond connection.
 1168: parameters are:
 1169: 
 1170: =item $Lond
 1171: 
 1172: Connection to the lond that will send the transaction and receive the
 1173: reply.
 1174: 
 1175: =item $Client
 1176: 
 1177: Connection to the client that is making this request We got the
 1178: request from this socket, and when the request has been relayed to
 1179: lond and we get a reply back from lond it will get sent to this
 1180: socket.
 1181: 
 1182: =item $Request
 1183: 
 1184: The text of the request to send.
 1185: 
 1186: =cut
 1187: 
 1188: sub StartRequest {
 1189: 
 1190:     my ($Lond, $Request) = @_;
 1191:     
 1192:     Debug(6, "StartRequest: ".$Request->getRequest());
 1193: 
 1194:     my $Socket = $Lond->GetSocket();
 1195:     
 1196:     $Request->Activate($Lond);
 1197:     $ActiveTransactions{$Lond} = $Request;
 1198: 
 1199:     $Lond->InitiateTransaction($Request->getRequest());
 1200:     my $event = Event->io(fd      => $Socket,
 1201: 		       poll    => "w",
 1202: 		       cb      => \&LondWritable,
 1203: 		       data    => $Lond,
 1204: 		       desc    => "lond transaction connection");
 1205:     $ActiveConnections{$Lond} = $event;
 1206:     Debug(8," Start Request made watcher data with ".$event->data."\n");
 1207: }
 1208: 
 1209: =pod
 1210: 
 1211: =head2 QueueTransaction
 1212: 
 1213: If there is an idle lond connection, it is put to work doing this
 1214: transaction.  Otherwise, the transaction is placed in the work queue.
 1215: If placed in the work queue and the maximum number of connections has
 1216: not yet been created, a new connection will be started.  Our goal is
 1217: to eventually have a sufficient number of connections that the work
 1218: queue will typically be empty.  parameters are:
 1219: 
 1220: =item Socket
 1221: 
 1222: open on the lonc client.
 1223: 
 1224: =item Request
 1225: 
 1226: data to send to the lond.
 1227: 
 1228: =cut
 1229: 
 1230: sub QueueTransaction {
 1231: 
 1232:     my $requestData   = shift;	# This is a LondTransaction.
 1233:     my $cmd           = $requestData->getRequest();
 1234: 
 1235:     Debug(6,"QueueTransaction: ".$cmd);
 1236: 
 1237:     my $LondSocket    = $IdleConnections->pop();
 1238:     if(!defined $LondSocket) {	# Need to queue request.
 1239: 	Debug(5,"Must queue...");
 1240: 	$WorkQueue->enqueue($requestData);
 1241: 	if($ConnectionCount < $MaxConnectionCount) {
 1242: 	    if($ConnectionRetriesLeft > 0) {
 1243: 		Debug(5,"Starting additional lond connection");
 1244: 		if(MakeLondConnection() == 0) {
 1245: 		    EmptyQueue();	# Fail transactions, can't make connection.
 1246: 		    CloseAllLondConnections; # Should all be closed but...
 1247: 		}
 1248: 	    } else {
 1249: 		ShowStatus(GetServerHost()." >>> DEAD !!!! <<<");
 1250: 		EmptyQueue();	# It's worse than that ... he's dead Jim.
 1251: 		CloseAllLondConnections; # Should all be closed but..
 1252: 	    }
 1253: 	}
 1254:     } else {			# Can start the request:
 1255: 	Debug(8,"Can start...");
 1256: 	StartRequest($LondSocket,  $requestData);
 1257:     }
 1258: }
 1259: 
 1260: #-------------------------- Lonc UNIX socket handling ---------------------
 1261: 
 1262: =pod
 1263: 
 1264: =head2 ClientRequest
 1265: Callback that is called when data can be read from the UNIX domain
 1266: socket connecting us with an apache server process.
 1267: 
 1268: =cut
 1269: 
 1270: sub ClientRequest {
 1271:     Debug(6, "ClientRequest");
 1272:     my $event   = shift;
 1273:     my $watcher = $event->w;
 1274:     my $socket  = $watcher->fd;
 1275:     my $data    = $watcher->data;
 1276:     my $thisread;
 1277: 
 1278:     Debug(9, "  Watcher named: ".$watcher->desc);
 1279: 
 1280:     my $rv = $socket->recv($thisread, POSIX::BUFSIZ, 0);
 1281:     Debug(8, "rcv:  data length = ".length($thisread)
 1282: 	  ." read =".$thisread);
 1283:     unless (defined $rv  && length($thisread)) {
 1284: 	 # Likely eof on socket.
 1285: 	Debug(5,"Client Socket closed on lonc for ".$RemoteHost);
 1286: 	close($socket);
 1287: 	$watcher->cancel();
 1288: 	delete($ActiveClients{$socket});
 1289: 	return;
 1290:     }
 1291:     Debug(8,"Data: ".$data." this read: ".$thisread);
 1292:     $data = $data.$thisread;	# Append new data.
 1293:     $watcher->data($data);
 1294:     if($data =~ /\n$/) {	# Request entirely read.
 1295: 	if($data eq "close_connection_exit\n") {
 1296: 	    Log("CRITICAL",
 1297: 		"Request Close Connection ... exiting");
 1298: 	    CloseAllLondConnections();
 1299: 	    exit;
 1300: 	}
 1301: 	Debug(8, "Complete transaction received: ".$data);
 1302: 	if($LogTransactions) {
 1303: 	    Log("SUCCESS", "Transaction: '$data'"); # Transaction has \n.
 1304: 	}
 1305: 	my $Transaction = LondTransaction->new($data);
 1306: 	$Transaction->SetClient($socket);
 1307: 	QueueTransaction($Transaction);
 1308: 	$watcher->cancel();	# Done looking for input data.
 1309:     }
 1310: 
 1311: }
 1312: 
 1313: 
 1314: =pod
 1315: 
 1316: =head2  NewClient
 1317: 
 1318: Callback that is called when a connection is received on the unix
 1319: socket for a new client of lonc.  The callback is parameterized by the
 1320: event.. which is a-priori assumed to be an io event, and therefore has
 1321: an fd member that is the Listener socket.  We Accept the connection
 1322: and register a new event on the readability of that socket:
 1323: 
 1324: =cut
 1325: 
 1326: sub NewClient {
 1327:     Debug(6, "NewClient");
 1328:     my $event      = shift;		# Get the event parameters.
 1329:     my $watcher    = $event->w; 
 1330:     my $socket     = $watcher->fd;	# Get the event' socket.
 1331:     my $connection = $socket->accept();	# Accept the client connection.
 1332:     Debug(8,"Connection request accepted from "
 1333: 	  .GetPeername($connection, AF_UNIX));
 1334: 
 1335: 
 1336:     my $description = sprintf("Connection to lonc client %d",
 1337: 			      $ClientConnection);
 1338:     Debug(9, "Creating event named: ".$description);
 1339:     Event->io(cb      => \&ClientRequest,
 1340: 	      poll    => 'r',
 1341: 	      desc    => $description,
 1342: 	      data    => "",
 1343: 	      fd      => $connection);
 1344:     $ActiveClients{$connection} = $ClientConnection;
 1345:     $ClientConnection++;
 1346: }
 1347: 
 1348: =pod
 1349: 
 1350: =head2 GetLoncSocketPath
 1351: 
 1352: Returns the name of the UNIX socket on which to listen for client
 1353: connections.
 1354: 
 1355: =cut
 1356: 
 1357: sub GetLoncSocketPath {
 1358:     return $UnixSocketDir."/".GetServerHost();
 1359: }
 1360: 
 1361: =pod
 1362: 
 1363: =head2 GetServerHost
 1364: 
 1365: Returns the host whose lond we talk with.
 1366: 
 1367: =cut
 1368: 
 1369: sub GetServerHost {
 1370:     return $RemoteHost;		# Setup by the fork.
 1371: }
 1372: 
 1373: =pod
 1374: 
 1375: =head2 GetServerPort
 1376: 
 1377: Returns the lond port number.
 1378: 
 1379: =cut
 1380: 
 1381: sub GetServerPort {
 1382:     return $perlvar{londPort};
 1383: }
 1384: 
 1385: =pod
 1386: 
 1387: =head2 SetupLoncListener
 1388: 
 1389: Setup a lonc listener event.  The event is called when the socket
 1390: becomes readable.. that corresponds to the receipt of a new
 1391: connection.  The event handler established will accept the connection
 1392: (creating a communcations channel), that int turn will establish
 1393: another event handler to subess requests.
 1394: 
 1395: =cut
 1396: 
 1397: sub SetupLoncListener {
 1398: 
 1399:     my $socket;
 1400:     my $SocketName = GetLoncSocketPath();
 1401:     unlink($SocketName);
 1402:     unless ($socket =IO::Socket::UNIX->new(Local  => $SocketName,
 1403: 					    Listen => 10, 
 1404: 					    Type   => SOCK_STREAM)) {
 1405: 	die "Failed to create a lonc listner socket";
 1406:     }
 1407:     Event->io(cb     => \&NewClient,
 1408: 	      poll   => 'r',
 1409: 	      desc   => 'Lonc listener Unix Socket',
 1410: 	      fd     => $socket);
 1411: }
 1412: 
 1413: #
 1414: #   Toggle transaction logging.
 1415: #  Implicit inputs:  
 1416: #     LogTransactions
 1417: #  Implicit Outputs:
 1418: #     LogTransactions
 1419: sub ToggleTransactionLogging {
 1420:     print STDERR "Toggle transaction logging...\n";
 1421:     if(!$LogTransactions) {
 1422: 	$LogTransactions = 1;
 1423:     } else {
 1424: 	$LogTransactions = 0;
 1425:     }
 1426: 
 1427: 
 1428:     Log("SUCCESS", "Toggled transaction logging: $LogTransactions \n");
 1429: }
 1430: 
 1431: =pod 
 1432: 
 1433: =head2 ChildStatus
 1434:  
 1435: Child USR1 signal handler to report the most recent status
 1436: into the status file.
 1437: 
 1438: We also use this to reset the retries count in order to allow the
 1439: client to retry connections with a previously dead server.
 1440: =cut
 1441: 
 1442: sub ChildStatus {
 1443:     my $event = shift;
 1444:     my $watcher = $event->w;
 1445: 
 1446:     Debug(2, "Reporting child status because : ".$watcher->data);
 1447:     my $docdir = $perlvar{'lonDocRoot'};
 1448:     my $fh = IO::File->new(">>$docdir/lon-status/loncstatus.txt");
 1449:     print $fh $$."\t".$RemoteHost."\t".$Status."\t".
 1450: 	$RecentLogEntry."\n";
 1451:     #
 1452:     #  Write out information about each of the connections:
 1453:     #
 1454:     if ($DebugLevel > 2) {
 1455: 	print $fh "Active connection statuses: \n";
 1456: 	my $i = 1;
 1457: 	print STDERR  "================================= Socket Status Dump:\n";
 1458: 	foreach my $item (keys %ActiveConnections) {
 1459: 	    my $Socket = $ActiveConnections{$item}->data;
 1460: 	    my $state  = $Socket->GetState();
 1461: 	    print $fh "Connection $i State: $state\n";
 1462: 	    print STDERR "---------------------- Connection $i \n";
 1463: 	    $Socket->Dump(-1);	# Ensure it gets dumped..
 1464: 	    $i++;	
 1465: 	}
 1466:     }
 1467:     $ConnectionRetriesLeft = $ConnectionRetries;
 1468: }
 1469: 
 1470: =pod
 1471: 
 1472: =head2 SignalledToDeath
 1473: 
 1474: Called in response to a signal that causes a chid process to die.
 1475: 
 1476: =cut
 1477: 
 1478: 
 1479: sub SignalledToDeath {
 1480:     my $event  = shift;
 1481:     my $watcher= $event->w;
 1482: 
 1483:     Debug(2,"Signalled to death! via ".$watcher->data);
 1484:     my ($signal) = $watcher->data;
 1485:     chomp($signal);
 1486:     Log("CRITICAL", "Abnormal exit.  Child $$ for $RemoteHost "
 1487: 	."died through "."\"$signal\"");
 1488:     LogPerm("F:lonc: $$ on $RemoteHost signalled to death: "
 1489: 	    ."\"$signal\"");
 1490:     exit 0;
 1491: 
 1492: }
 1493: 
 1494: =head2 ToggleDebug
 1495: 
 1496: This sub toggles trace debugging on and off.
 1497: 
 1498: =cut
 1499: 
 1500: sub ToggleDebug {
 1501:     my $Current    = $DebugLevel;
 1502:        $DebugLevel = $NextDebugLevel;
 1503:        $NextDebugLevel = $Current;
 1504: 
 1505:     Log("SUCCESS", "New debugging level for $RemoteHost now $DebugLevel");
 1506: 
 1507: }
 1508: 
 1509: =head2 ChildProcess
 1510: 
 1511: This sub implements a child process for a single lonc daemon.
 1512: 
 1513: =cut
 1514: 
 1515: sub ChildProcess {
 1516: 
 1517: 
 1518:     #
 1519:     #  Signals must be handled by the Event framework...
 1520: #
 1521: 
 1522:     Event->signal(signal   => "QUIT",
 1523: 		  cb       => \&SignalledToDeath,
 1524: 		  data     => "QUIT");
 1525:     Event->signal(signal   => "HUP",
 1526: 		  cb       => \&ChildStatus,
 1527: 		  data     => "HUP");
 1528:     Event->signal(signal   => "USR1",
 1529: 		  cb       => \&ChildStatus,
 1530: 		  data     => "USR1");
 1531:     Event->signal(signal   => "USR2",
 1532: 		  cb       => \&ToggleTransactionLogging);
 1533:     Event->signal(signal   => "INT",
 1534: 		  cb       => \&ToggleDebug,
 1535: 		  data     => "INT");
 1536: 
 1537:     
 1538:     SetupLoncListener();
 1539:     
 1540:     $Event::Debuglevel = $DebugLevel;
 1541:     
 1542:     Debug(9, "Making initial lond connection for ".$RemoteHost);
 1543: 
 1544: # Setup the initial server connection:
 1545:     
 1546:      # &MakeLondConnection(); // let first work requirest do it.
 1547: 
 1548: 
 1549:     Debug(9,"Entering event loop");
 1550:     my $ret = Event::loop();		#  Start the main event loop.
 1551:     
 1552:     
 1553:     die "Main event loop exited!!!";
 1554: }
 1555: 
 1556: #  Create a new child for host passed in:
 1557: 
 1558: sub CreateChild {
 1559:     my $host = shift;
 1560: 
 1561:     my $sigset = POSIX::SigSet->new(SIGINT);
 1562:     sigprocmask(SIG_BLOCK, $sigset);
 1563:     $RemoteHost = $host;
 1564:     Log("CRITICAL", "Forking server for ".$host);
 1565:     my $pid          = fork;
 1566:     if($pid) {			# Parent
 1567: 	$RemoteHost = "Parent";
 1568: 	$ChildHash{$pid} = $host;
 1569: 	$HostToPid{$host}= $pid;
 1570: 	sigprocmask(SIG_UNBLOCK, $sigset);
 1571: 
 1572:     } else {			# child.
 1573: 	ShowStatus("Connected to ".$RemoteHost);
 1574: 	$SIG{INT} = 'DEFAULT';
 1575: 	sigprocmask(SIG_UNBLOCK, $sigset);
 1576: 	ChildProcess;		# Does not return.
 1577:     }
 1578: 
 1579: }
 1580: #
 1581: #  Parent process logic pass 1:
 1582: #   For each entry in the hosts table, we will
 1583: #  fork off an instance of ChildProcess to service the transactions
 1584: #  to that host.  Each pid will be entered in a global hash
 1585: #  with the value of the key, the host.
 1586: #  The parent will then enter a loop to wait for process exits.
 1587: #  Each exit gets logged and the child gets restarted.
 1588: #
 1589: 
 1590: #
 1591: #   Fork and start in new session so hang-up isn't going to 
 1592: #   happen without intent.
 1593: #
 1594: 
 1595: 
 1596: 
 1597: 
 1598: 
 1599: 
 1600: ShowStatus("Forming new session");
 1601: my $childpid = fork;
 1602: if ($childpid != 0) {
 1603:     sleep 4;			# Give child a chacne to break to
 1604:     exit 0;			# a new sesion.
 1605: }
 1606: #
 1607: #   Write my pid into the pid file so I can be located
 1608: #
 1609: 
 1610: ShowStatus("Parent writing pid file:");
 1611: my $execdir = $perlvar{'lonDaemons'};
 1612: open (PIDSAVE, ">$execdir/logs/lonc.pid");
 1613: print PIDSAVE "$$\n";
 1614: close(PIDSAVE);
 1615: 
 1616: 
 1617: 
 1618: if (POSIX::setsid() < 0) {
 1619:     print "Could not create new session\n";
 1620:     exit -1;
 1621: }
 1622: 
 1623: ShowStatus("Forking node servers");
 1624: 
 1625: Log("CRITICAL", "--------------- Starting children ---------------");
 1626: 
 1627: LondConnection::ReadConfig;               # Read standard config files.
 1628: my $HostIterator = LondConnection::GetHostIterator;
 1629: while (! $HostIterator->end()) {
 1630: 
 1631:     my $hostentryref = $HostIterator->get();
 1632:     CreateChild($hostentryref->[0]);
 1633:     $HostHash{$hostentryref->[0]} = $hostentryref->[4];
 1634:     $HostIterator->next();
 1635: }
 1636: $RemoteHost = "Parent Server";
 1637: 
 1638: # Maintain the population:
 1639: 
 1640: ShowStatus("Parent keeping the flock");
 1641: 
 1642: #
 1643: #   Set up parent signals:
 1644: #
 1645: 
 1646: $SIG{INT}  = \&Terminate;
 1647: $SIG{TERM} = \&Terminate; 
 1648: $SIG{HUP}  = \&Restart;
 1649: $SIG{USR1} = \&CheckKids; 
 1650: $SIG{USR2} = \&UpdateKids;	# LonManage update request.
 1651: 
 1652: while(1) {
 1653:     my $deadchild = wait();
 1654:     if(exists $ChildHash{$deadchild}) {	# need to restart.
 1655: 	my $deadhost = $ChildHash{$deadchild};
 1656: 	delete($HostToPid{$deadhost});
 1657: 	delete($ChildHash{$deadchild});
 1658: 	Log("WARNING","Lost child pid= ".$deadchild.
 1659: 	      "Connected to host ".$deadhost);
 1660: 	Log("INFO", "Restarting child procesing ".$deadhost);
 1661: 	CreateChild($deadhost);
 1662:     }
 1663: }
 1664: 
 1665: 
 1666: 
 1667: =pod
 1668: 
 1669: =head1 CheckKids
 1670: 
 1671:   Since kids do not die as easily in this implementation
 1672: as the previous one, there  is no need to restart the
 1673: dead ones (all dead kids get restarted when they die!!)
 1674: The only thing this function does is to pass USR1 to the
 1675: kids so that they report their status.
 1676: 
 1677: =cut
 1678: 
 1679: sub CheckKids {
 1680:     Debug(2, "Checking status of children");
 1681:     my $docdir = $perlvar{'lonDocRoot'};
 1682:     my $fh = IO::File->new(">$docdir/lon-status/loncstatus.txt");
 1683:     my $now=time;
 1684:     my $local=localtime($now);
 1685:     print $fh "LONC status $local - parent $$ \n\n";
 1686:     foreach my $pid (keys %ChildHash) {
 1687: 	Debug(2, "Sending USR1 -> $pid");
 1688: 	kill 'USR1' => $pid;	# Tell Child to report status.
 1689: 	sleep 1;		# Wait so file doesn't intermix.
 1690:     }
 1691: }
 1692: 
 1693: =pod
 1694: 
 1695: =head1  UpdateKids
 1696: 
 1697: parent's SIGUSR2 handler.  This handler:
 1698: 
 1699: =item
 1700: 
 1701: Rereads the hosts file.
 1702: 
 1703: =item
 1704:  
 1705: Kills off (via sigint) children for hosts that have disappeared.
 1706: 
 1707: =item
 1708: 
 1709: QUITs  children for hosts that already exist (this just forces a status display
 1710: and resets the connection retry count for that host.
 1711: 
 1712: =item
 1713: 
 1714: Starts new children for hosts that have been added to the hosts.tab file since
 1715: the start of the master program and maintains them.
 1716: 
 1717: =cut
 1718: 
 1719: sub UpdateKids {
 1720: 
 1721:     Log("INFO", "Updating connections via SIGUSR2");
 1722: 
 1723:     #  Just in case we need to kill our own lonc, we wait a few seconds to
 1724:     #  give it a chance to receive and relay lond's response to the 
 1725:     #  re-init command.
 1726:     #
 1727: 
 1728:     sleep(2);			# Wait a couple of seconds.
 1729: 
 1730:     my %hosts;                   # Indexed by loncapa hostname, value=ip.
 1731:     
 1732:     # Need to re-read  the host table:
 1733:     
 1734:     
 1735:     LondConnection::ReadConfig();
 1736:     my $I = LondConnection::GetHostIterator;
 1737:     while (! $I->end()) {
 1738: 	my $item = $I->get();
 1739: 	$hosts{$item->[0]} = $item->[4];
 1740: 	$I->next();
 1741:     }
 1742: 
 1743:     #  The logic below is written for clarity not for efficiency.
 1744:     #  Since I anticipate that this function is only rarely called, that's
 1745:     #  appropriate.  There are certainly ways to combine the loops below,
 1746:     #  and anyone wishing to obscure the logic is welcome to go for it.
 1747:     #  Note that we don't re-direct sigchild.  Instead we do what's needed
 1748:     #  to the data structures that keep track of children to ensure that
 1749:     #  when sigchild is honored, no new child is born.
 1750:     #
 1751: 
 1752:     #  For each existing child; if it's host doesn't exist, kill the child.
 1753: 
 1754:     foreach my $child (keys %ChildHash) {
 1755: 	my $oldhost = $ChildHash{$child};
 1756: 	if (!(exists $hosts{$oldhost})) {
 1757: 	    Log("CRITICAL", "Killing child for $oldhost  host no longer exists");
 1758: 	    delete $ChildHash{$child};
 1759: 	    delete $HostToPid{$oldhost};
 1760: 	    kill 'QUIT' => $child;
 1761: 	}
 1762:     }
 1763:     # For each remaining existing child; if it's host's ip has changed,
 1764:     # Restart the child on the new IP.
 1765: 
 1766:     foreach my $child (keys %ChildHash) {
 1767: 	my $oldhost = $ChildHash{$child};
 1768: 	my $oldip   = $HostHash{$oldhost};
 1769: 	if ($hosts{$oldhost} ne $oldip) {
 1770: 
 1771: 	    # kill the old child.
 1772: 
 1773: 	    Log("CRITICAL", "Killing child for $oldhost host ip has changed...");
 1774: 	    delete $ChildHash{$child};
 1775: 	    delete $HostToPid{$oldhost};
 1776: 	    kill 'QUIT' => $child;
 1777: 
 1778: 	    # Do the book-keeping needed to start a new child on the
 1779: 	    # new ip.
 1780: 
 1781: 	    $HostHash{$oldhost} = $hosts{$oldhost};
 1782: 	    CreateChild($oldhost);
 1783: 	}
 1784:     }
 1785:     # Finally, for each new host, not in the host hash, create a
 1786:     # enter the host and create a new child.
 1787:     # Force a status display of any existing process.
 1788: 
 1789:     foreach my $host (keys %hosts) {
 1790: 	if(!(exists $HostHash{$host})) {
 1791: 	    Log("INFO", "New host $host discovered in hosts.tab...");
 1792: 	    $HostHash{$host} = $hosts{$host};
 1793: 	    CreateChild($host);
 1794: 	} else {
 1795: 	    kill 'HUP' => $HostToPid{$host};    # status display.
 1796: 	}
 1797:     }
 1798: }
 1799: 
 1800: 
 1801: =pod
 1802: 
 1803: =head1 Restart
 1804: 
 1805: Signal handler for HUP... all children are killed and
 1806: we self restart.  This is an el-cheapo way to re read
 1807: the config file.
 1808: 
 1809: =cut
 1810: 
 1811: sub Restart {
 1812:     &KillThemAll;		# First kill all the children.
 1813:     Log("CRITICAL", "Restarting");
 1814:     my $execdir = $perlvar{'lonDaemons'};
 1815:     unlink("$execdir/logs/lonc.pid");
 1816:     exec("$execdir/loncnew");
 1817: }
 1818: 
 1819: =pod
 1820: 
 1821: =head1 KillThemAll
 1822: 
 1823: Signal handler that kills all children by sending them a 
 1824: SIGHUP.  Responds to sigint and sigterm.
 1825: 
 1826: =cut
 1827: 
 1828: sub KillThemAll {
 1829:     Debug(2, "Kill them all!!");
 1830:     local($SIG{CHLD}) = 'IGNORE';      # Our children >will< die.
 1831:     foreach my $pid (keys %ChildHash) {
 1832: 	my $serving = $ChildHash{$pid};
 1833: 	ShowStatus("Nicely Killing lonc for $serving pid = $pid");
 1834: 	Log("CRITICAL", "Nicely Killing lonc for $serving pid = $pid");
 1835: 	kill 'QUIT' => $pid;
 1836:     }
 1837: 
 1838: 
 1839: }
 1840: 
 1841: 
 1842: #
 1843: #  Kill all children via KILL.  Just in case the
 1844: #  first shot didn't get them.
 1845: 
 1846: sub really_kill_them_all_dammit
 1847: {
 1848:     Debug(2, "Kill them all Dammit");
 1849:     local($SIG{CHLD} = 'IGNORE'); # In case some purist reenabled them.
 1850:     foreach my $pid (keys %ChildHash) {
 1851: 	my $serving = $ChildHash{$pid};
 1852: 	&ShowStatus("Nastily killing lonc for $serving pid = $pid");
 1853: 	Log("CRITICAL", "Nastily killing lonc for $serving pid = $pid");
 1854: 	kill 'KILL' => $pid;
 1855: 	delete($ChildHash{$pid});
 1856: 	my $execdir = $perlvar{'lonDaemons'};
 1857: 	unlink("$execdir/logs/lonc.pid");
 1858:     }
 1859: }
 1860: =pod
 1861: 
 1862: =head1 Terminate
 1863:  
 1864: Terminate the system.
 1865: 
 1866: =cut
 1867: 
 1868: sub Terminate {
 1869:     &Log("CRITICAL", "Asked to kill children.. first be nice...");
 1870:     &KillThemAll;
 1871:     #
 1872:     #  By now they really should all be dead.. but just in case 
 1873:     #  send them all SIGKILL's after a bit of waiting:
 1874: 
 1875:     sleep(4);
 1876:     &Log("CRITICAL", "Now kill children nasty");
 1877:     &really_kill_them_all_dammit;
 1878:     Log("CRITICAL","Master process exiting");
 1879:     exit 0;
 1880: 
 1881: }
 1882: =pod
 1883: 
 1884: =head1 Theory
 1885: 
 1886: The event class is used to build this as a single process with an
 1887: event driven model.  The following events are handled:
 1888: 
 1889: =item UNIX Socket connection Received
 1890: 
 1891: =item Request data arrives on UNIX data transfer socket.
 1892: 
 1893: =item lond connection becomes writable.
 1894: 
 1895: =item timer fires at 1 second intervals.
 1896: 
 1897: All sockets are run in non-blocking mode.  Timeouts managed by the timer
 1898: handler prevents hung connections.
 1899: 
 1900: Key data structures:
 1901: 
 1902: =item RequestQueue
 1903: 
 1904: A queue of requests received from UNIX sockets that are
 1905: waiting for a chance to be forwarded on a lond connection socket.
 1906: 
 1907: =item ActiveConnections
 1908: 
 1909: A hash of lond connections that have transactions in process that are
 1910: available to be timed out.
 1911: 
 1912: =item ActiveTransactions
 1913: 
 1914: A hash indexed by lond connections that contain the client reply
 1915: socket for each connection that has an active transaction on it.
 1916: 
 1917: =item IdleConnections
 1918: 
 1919: A hash of lond connections that have no work to do.  These connections
 1920: can be closed if they are idle for a long enough time.
 1921: 
 1922: =cut

FreeBSD-CVSweb <freebsd-cvsweb@FreeBSD.org>