[LON-CAPA-cvs] cvs: loncom / loncnew

foxr lon-capa-cvs@mail.lon-capa.org
Fri, 13 Jun 2003 02:38:44 -0000


foxr		Thu Jun 12 22:38:44 2003 EDT

  Modified files:              
    /loncom	loncnew 
  Log:
  Add logging in 'expected format'
  
  
Index: loncom/loncnew
diff -u loncom/loncnew:1.8 loncom/loncnew:1.9
--- loncom/loncnew:1.8	Tue Jun 10 22:04:35 2003
+++ loncom/loncnew	Thu Jun 12 22:38:43 2003
@@ -2,7 +2,7 @@
 # The LearningOnline Network with CAPA
 # lonc maintains the connections to remote computers
 #
-# $Id: loncnew,v 1.8 2003/06/11 02:04:35 foxr Exp $
+# $Id: loncnew,v 1.9 2003/06/13 02:38:43 foxr Exp $
 #
 # Copyright Michigan State University Board of Trustees
 #
@@ -41,10 +41,14 @@
 #    - Add Configuration file I/O                       (done).
 #    - Add management/status request interface.
 #    - Add deferred request capability.                  (done)
+#    - Detect transmission timeouts.
 #
 
 # Change log:
 #    $Log: loncnew,v $
+#    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
@@ -62,6 +66,7 @@
 use IO::Socket;
 use IO::Socket::INET;
 use IO::Socket::UNIX;
+use IO::File;
 use IO::Handle;
 use Socket;
 use Crypt::IDEA;
@@ -72,7 +77,6 @@
 use LONCAPA::Configuration;
 use LONCAPA::HashIterator;
 
-print "Loncnew starting\n";
 
 #
 #   Disable all signals we might receive from outside for now.
@@ -97,10 +101,10 @@
 my %ChildHash;			# by pid -> host.
 
 
-my $MaxConnectionCount = 5;	# Will get from config later.
+my $MaxConnectionCount = 10;	# Will get from config later.
 my $ClientConnection = 0;	# Uniquifier for client events.
 
-my $DebugLevel = 2;
+my $DebugLevel = 0;
 my $IdleTimeout= 3600;		# Wait an hour before pruning connections.
 
 #
@@ -113,17 +117,72 @@
 my %ActiveTransactions;		# LondTransactions in flight.
 my %ActiveClients;		# Serial numbers of active clients by socket.
 my $WorkQueue       = Queue->new(); # Queue of pending transactions.
-#  my $ClientQueue     = Queue->new(); # Queue of clients causing xactinos.
 my $ConnectionCount = 0;
 my $IdleSeconds     = 0;	# Number of seconds idle.
+my $Status          = "";	# Current status string.
 
-#
-#   This disconnected socket makes posible a bit more regular
-#   code when processing delayed requests:
-#
-my $NullSocket = IO::Socket->new();
 
 #
+#   The hash below gives the HTML format for log messages
+#   given a severity.
+#    
+my %LogFormats;
+
+$LogFormats{"CRITICAL"} = "<font color=red>CRITICAL: %s</font>";
+$LogFormats{"SUCCESS"}  = "<font color=green>SUCCESS: %s</font>";
+$LogFormats{"INFO"}     = "<font color=yellow>INFO: %s</font>";
+$LogFormats{"WARNING"}  = "<font color=blue>WARNING: %s</font>";
+$LogFormats{"DEFAULT"}  = " %s ";
+
+my $lastlog = '';		# Used for status reporting.
+
+=pod
+
+=head2 Log
+
+Logs a message to the log file.
+Parameters:
+
+=item severity
+
+One of CRITICAL, WARNING, INFO, SUCCESS used to select the
+format string used to format the message.  if the severity is
+not a defined severity the Default format string is used.
+
+=item message
+
+The base message.  In addtion to the format string, the message
+will be appended to a string containing the name of our remote
+host and the time will be formatted into the message.
+
+=cut
+
+sub Log {
+    my $severity = shift;
+    my $message  = shift;
+   
+    if(!$LogFormats{$severity}) {
+	$severity = "DEFAULT";
+    }
+
+    my $format = $LogFormats{$severity};
+    
+    #  Put the window dressing in in front of the message format:
+
+    my $now   = time;
+    my $local = localtime($now);
+    my $finalformat = "$local ($$) [$RemoteHost] [$Status] ";
+    my $finalformat = $finalformat.$format."\n";
+
+    # open the file and put the result.
+
+    my $execdir = $perlvar{'lonDaemons'};
+    my $fh      = IO::File->new(">>$execdir/logs/lonc.log");
+    my $msg = sprintf($finalformat, $message);
+    print $fh $msg;
+    
+}
+
 
 =pod
 
@@ -184,6 +243,8 @@
 sub ShowStatus {
     my $status = shift;
     $0 =  "lonc: ".$status;
+    $Status  = $status;		# Make available for logging.
+
 }
 
 =pod
@@ -404,9 +465,7 @@
 	my $data   = $Socket->GetReply(); # Data to send.
 	StartClientReply($Transaction, $data);
     } else {			# Delete deferred transaction file.
-	&Debug(4, "Deferred transaction complete: ".$Transaction->getFile().
-	       " request: ".$Transaction->getRequest().
-	       " answer: ".$Socket->GetReply());
+	Log("SUCCESS", "A delayed transaction was completed");
 	unlink $Transaction->getFile();
     }
 }
@@ -492,6 +551,20 @@
 
 =pod
 
+=head2 CloseAllLondConnections
+
+Close all connections open on lond prior to exit e.g.
+
+=cut
+sub CloseAllLondConnections {
+    foreach $Socket (keys %ActiveConnections) {
+	KillSocket($Socket);
+    }
+}
+=cut
+
+=pod
+
 =head2 KillSocket
  
 Destroys a socket.  This function can be called either when a socket
@@ -515,6 +588,8 @@
 sub KillSocket {
     my $Socket = shift;
 
+    $Socket->Shutdown();
+
     #  If the socket came from the active connection set,
     #  delete its transaction... note that FailTransaction should
     #  already have been called!!!
@@ -657,6 +732,9 @@
 	    Debug(8,"Completing transaction!!");
 	    CompleteTransaction($Socket, 
 				$ActiveTransactions{$Socket});
+	} else {
+	    Log("SUCCESS", "Connection ".$ConnectionCount." to "
+		.$RemoteHost." now ready for action");
 	}
 	ServerToIdle($Socket);	# Next work unit or idle.
 	
@@ -759,7 +837,8 @@
 	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;
@@ -898,7 +977,7 @@
 					 &GetServerPort());
 
     if($Connection == undef) {	# Needs to be more robust later.
-	Debug(0,"Failed to make a connection with lond.");
+	Log("CRITICAL","Failed to make a connection with lond.");
     }  else {
 	# The connection needs to have writability 
 	# monitored in order to send the init sequence
@@ -925,6 +1004,8 @@
 	if($ConnectionCount == 1) { # First Connection:
 	    QueueDelayed;
 	}
+	Log("SUCESS", "Created connection ".$ConnectionCount
+	    ." to host ".GetServerHost());
     }
     
 }
@@ -1052,6 +1133,12 @@
     $data = $data.$thisread;	# Append new data.
     $watcher->data($data);
     if($data =~ /(.*\n)/) {	# Request entirely read.
+	if($data == "close_connection_exit\n") {
+	    Log("CRITICAL",
+		"Request Close Connection ... exiting");
+	    CloseAllLondConnections();
+	    exit;
+	}
 	Debug(8, "Complete transaction received: ".$data);
 	my $Transaction = LondTransaction->new($data);
 	$Transaction->SetClient($socket);
@@ -1171,7 +1258,6 @@
 
 sub ChildProcess {
 
-    print "Loncnew\n";
 
     # For now turn off signals.
     
@@ -1210,8 +1296,7 @@
 sub CreateChild {
     my $host = shift;
     $RemoteHost = $host;
-    Debug(3, "Forking off child for ".$RemoteHost);
-    sleep(5);
+    Log("CRITICAL", "Forking server for ".$host);
     $pid          = fork;
     if($pid) {			# Parent
 	$ChildHash{$pid} = $RemoteHost;
@@ -1264,6 +1349,8 @@
 
 ShowStatus("Forking node servers");
 
+Log("CRITICAL", "--------------- Starting children ---------------");
+
 my $HostIterator = LondConnection::GetHostIterator;
 while (! $HostIterator->end()) {
 
@@ -1281,8 +1368,9 @@
     if(exists $ChildHash{$deadchild}) {	# need to restart.
 	$deadhost = $ChildHash{$deadchild};
 	delete($ChildHash{$deadchild});
-	Debug(4,"Lost child pid= ".$deadchild.
+	Log("WARNING","Lost child pid= ".$deadchild.
 	      "Connected to host ".$deadhost);
+	Log("INFO", "Restarting child procesing ".$deadhost);
 	CreateChild($deadhost);
     }
 }