[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[minion-cvs] Common: Add rudimentry logging system. Still needs doc...



Update of /home/minion/cvsroot/src/minion/lib/mixminion
In directory moria.seul.org:/tmp/cvs-serv4675

Modified Files:
	Common.py HashLog.py MMTPServer.py Queue.py __init__.py 
Log Message:
Common: Add rudimentry logging system.  Still needs docs, testing, 
    and configurability.
HashLog: Add warning if we have to fall back to dumbdbm.
Queue, MMTPServer: Use new logging system instead of print statements.
__init__.py: import mixminion.Foo, not import Foo.



Index: Common.py
===================================================================
RCS file: /home/minion/cvsroot/src/minion/lib/mixminion/Common.py,v
retrieving revision 1.6
retrieving revision 1.7
diff -u -d -r1.6 -r1.7
--- Common.py	1 Jul 2002 18:03:05 -0000	1.6
+++ Common.py	5 Jul 2002 19:50:27 -0000	1.7
@@ -7,11 +7,13 @@
 
 __all__ = [ 'MixError', 'MixFatalError', 'onReset', 'onTerminate',
             'installSignalHandlers', 'secureDelete', 'secureRename',
-            'ceilDiv', 'floorDiv', 'log', 'debug' ]
+            'ceilDiv', 'floorDiv', 'debug', 'warn', 'info', 'error',
+            'fatal' ]
 
 import os
 import signal
 import sys
+import time
 from types import StringType
 
 class MixError(Exception):
@@ -56,9 +58,7 @@
 _SHRED_CMD = "/usr/bin/shred"
 
 if not os.path.exists(_SHRED_CMD):
-    # XXXX use real logging
-    log("Warning: %s not found. Files will not be securely deleted." %
-        _SHRED_CMD)
+    warn("%s not found. Files will not be securely deleted.", _SHRED_CMD)
     _SHRED_CMD = None
 
 def secureDelete(fnames, blocking=0):
@@ -97,10 +97,80 @@
 
 #----------------------------------------------------------------------
 # Logging
+#
+# I'm trying to make this interface look like a subset of the one in
+# the draft PEP-0282 (http://www.python.org/peps/pep-0282.html).
 
-# XXXX Placeholder for a real logging mechanism
-def log(s):
-    print s
+#XXXX XXXX DOC DOC DOCDOC
+
+def _logtime():
+    #XXXX Is this guaranteed to work?
+    return time.strftime("%b %d %H:%m:%S")
+
+class FileLogTarget:
+    def __init__(self, fname):
+        self.file = None
+        self.fname = fname
+        self.reset()
+    def reset(self):
+        if self.file is not None:
+            self.file.close()
+        self.file = open(self.fname, 'a')
+    def close(self):
+        self.file.close()
+    def write(self, severity, message):
+        print >> self.file, "%s [%s] %s" % (_logtime(), severity, message)
+        
+class ConsoleLogTarget: 
+    def __init__(self, file):
+        self.file = file 
+    def reset(self): pass
+    def close(self): pass
+    def write(self, severity, message):
+        print >> self.file, "%s [%s] %s" % (_logtime(), severity, message)
+
+class Log:
+    def __init__(self, minSeverity):
+        self.handlers = []
+
+    def addHandler(self, handler):
+        self.handlers.append(handler)
+
+    def reset(self):
+        for h in self.handlers:
+            h.reset()
+
+    def close(self):
+        for h in self.handlers:
+            h.close()
+        
+    def log(self, severity, message, *args):
+        # Check that severity is okay.
+        for h in self.handlers:
+            h.write(severity, message % args)
+
+    def debug(self, message, *args):
+        # Need a means to filter messages
+        self.log("DEBUG", message, *args)
+    def info(self, message, *args):
+        self.log("INFO", message, *args)
+    def warn(self, message, *args):
+        self.log("WARN", message, *args)
+    def error(self, message, *args):
+        self.log("ERROR", message, *args)
+    def fatal(self, message, *args):
+        self.log("FATAL", message, *args)
+
+_theLog = Log('DEBUG')
+_theLog.addHandler(ConsoleLogTarget(sys.stderr))
+# XXXX Configure the log for real
+
+log = _theLog.log
+debug = _theLog.debug
+info = _theLog.info
+warn = _theLog.warn
+error = _theLog.error
+fatal = _theLog.fatal
 
 #----------------------------------------------------------------------
 # Signal handling

Index: HashLog.py
===================================================================
RCS file: /home/minion/cvsroot/src/minion/lib/mixminion/HashLog.py,v
retrieving revision 1.7
retrieving revision 1.8
diff -u -d -r1.7 -r1.8
--- HashLog.py	1 Jul 2002 18:03:05 -0000	1.7
+++ HashLog.py	5 Jul 2002 19:50:27 -0000	1.8
@@ -5,8 +5,8 @@
 
    Persistant memory for the hashed secrets we've seen."""
 
-import anydbm
-from mixminion.Common import MixFatalError
+import anydbm, dumbdbm
+from mixminion.Common import MixFatalError, warn
 
 __all__ = [ 'HashLog' ]
 
@@ -38,7 +38,8 @@
         """Create a new HashLog to store data in 'filename' for the key
            'keyid'."""
         self.log = anydbm.open(filename, 'c')
-        #FFFF Warn if we're using dumbdbm
+        if isinstance(self.log, dumbdbm._Database):
+            warn("Warning: logging packet digests to a flat file.")
         try:
             if self.log["KEYID"] != keyid:
                 raise MixFatalError("Log KEYID does not match current KEYID")

Index: MMTPServer.py
===================================================================
RCS file: /home/minion/cvsroot/src/minion/lib/mixminion/MMTPServer.py,v
retrieving revision 1.4
retrieving revision 1.5
diff -u -d -r1.4 -r1.5
--- MMTPServer.py	1 Jul 2002 18:03:05 -0000	1.4
+++ MMTPServer.py	5 Jul 2002 19:50:27 -0000	1.5
@@ -29,16 +29,17 @@
 import re
 import mixminion._minionlib as _ml
 from types import StringType
-from mixminion.Common import MixError, MixFatalError, log
+from mixminion.Common import MixError, MixFatalError, info, warn, error, \
+     log, debug
 from mixminion.Crypto import sha1
 from mixminion.Packet import MESSAGE_LEN, DIGEST_LEN
 
 __all__ = [ 'AsyncServer', 'ListenConnection', 'MMTPServerConnection',
             'MMTPClientConnection' ]
 
-def debug(s):
-    '''placeholder; all calls should go away.'''
-    #print s
+# Suppress trace-debugging
+def trace(x):
+    #log("TRACE", x)
     pass
 
 class AsyncServer:
@@ -62,7 +63,7 @@
            If we receive an unblocked signal, return immediately.
            """
 
-        debug("%s readers, %s writers" % (len(self.readers),
+        trace("%s readers, %s writers" % (len(self.readers),
                                           len(self.writers)))
         
         readfds = self.readers.keys()
@@ -76,13 +77,13 @@
                 raise e
         
         for fd in readfds:
-            debug("Got a read on "+str(fd))
+            trace("Got a read on "+str(fd))
             self.readers[fd].handleRead()
         for fd in writefds:
-            debug("Got a write on"+str(fd))
+            trace("Got a write on"+str(fd))
             self.writers[fd].handleWrite()
         for fd in exfds:
-            debug("Got an exception on"+str(fd))
+            trace("Got an exception on"+str(fd))
             if self.readers.has_key(fd): del self.readers[fd]
             if self.writers.has_key(fd): del self.writers[fd]
 
@@ -109,7 +110,6 @@
            called as appropriate.
         """ 
         fd = connection.fileno()
-        #self.p.register(fd, select.POLLIN | select.POLLOUT)
         self.readers[fd] = self.writers[fd] = connection
 
     def unregister(self, connection):
@@ -117,8 +117,6 @@
         fd = connection.fileno()
         w = self.writers.has_key(fd)
         r = self.readers.has_key(fd)
-        #if r or w:
-        #    self.p.unregister(fd)
         if r: del self.readers[fd]
         if w: del self.writers[fd]
 
@@ -151,8 +149,8 @@
         self.sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
         self.sock.bind((self.ip, self.port))
         self.sock.listen(backlog)
-        # FFFF LOG
         self.connectionFactory = connectionFactory
+        info("Listening at %s on port %s", ip, port)
 
     def register(self, server):
         server.registerReader(self)
@@ -160,14 +158,16 @@
 
     def handleRead(self):
         con, addr = self.sock.accept()
-        debug("Accepted connection from "+str(addr)+" on "+str(con.fileno()))
+        debug("Accepted connection from %s", addr)
         rw = self.connectionFactory(con)
         rw.register(self.server)
 
     def shutdown(self):
+        debug("Closing server connection")
         self.server.unregister(self)
         del self.server
         self.sock.close()
+        info("Server connection closed")
 
     def fileno(self):
         return self.sock.fileno()
@@ -272,25 +272,25 @@
         """Hook to implement shutdown."""
         r = self.__con.shutdown() #may throw want*
         if r == 1:
-            debug("Got a 1 on shutdown")
+            trace("Got a 1 on shutdown")
             self.__server.unregister(self)
             self.__state = None
             self.__sock.close()
             self.shutdownFinished()
         else:
-            debug("Got a 0 on shutdown")
+            trace("Got a 0 on shutdown")
 
     def __readFn(self):
         """Hook to implement read"""
         while 1:
             r = self.__con.read(1024) #may throw want*
             if r == 0:
-                debug("read returned 0.")
+                trace("read returned 0.")
                 self.shutdown()
                 return
             else:
                 assert isinstance(r, StringType)
-                debug("read got %s bytes" % len(r))
+                trace("read got %s bytes" % len(r))
                 self.__inbuf.append(r)
                 self.__inbuflen += len(r)
                 if not self.__con.pending():
@@ -300,17 +300,17 @@
             self.__inbuf = ["".join(self.__inbuf)]
 
         if self.__expectReadLen and self.__inbuflen > self.__expectReadLen:
-            debug("Read got too much.")
+            warn("Protocol violation: too much data. Closing connection.")
             self.shutdown(err=1)
             return
          
         if self.__terminator and self.__inbuf[0].find(self.__terminator) > -1:
-            debug("read found terminator")
+            trace("read found terminator")
             self.__server.unregister(self)
             self.finished()
 
         if self.__expectReadLen and (self.__inbuflen == self.__expectReadLen):
-            debug("read got enough.")
+            trace("read got enough.")
             self.__server.unregister(self)
             self.finished()
 
@@ -354,10 +354,10 @@
             self.__server.registerReader(self)
         except _ml.TLSError:
             if self.__state != self.__shutdownFn:
-                debug("Unexpected error: closing connection.")
+                warn("Unexpected error: closing connection.")
                 self.shutdown(1)
             else:
-                debug("Error while shutting down: closing connection.")
+                warn("Error while shutting down: closing connection.")
                 self.__server.unregister(self)
         else:
             # We are in no state at all.
@@ -417,15 +417,15 @@
         """Called once we're done reading the protocol string.  Either
            rejects, or sends our response.
         """
-        debug("done w/ client sendproto")
+        trace("done w/ client sendproto")
         inp = self.getInput()
         m = PROTOCOL_RE.match(inp)
         protocols = m.group(1).split(",")
         if "1.0" not in protocols:
-            debug("proto bad. Dying.")
+            warn("Unsupported protocol list.  Closing connection.")
             self.shutdown(err=1); return #XXXX
         else:
-            debug("proto ok.")
+            trace("proto ok.")
             self.finished = self.__sentProtocol
             self.beginWrite(PROTOCOL_STRING)
 
@@ -433,7 +433,7 @@
         """Called once we're done sending our protocol response.  Begins
            reading a packet from the line.
         """
-        debug("done w/ server sendproto")
+        trace("done w/ server sendproto")
         self.finished = self.__receivedMessage
         self.expectRead(SEND_RECORD_LEN)
 
@@ -446,10 +446,10 @@
 
         if (not (data.startswith(SEND_CONTROL) and
                  sha1(msg+"SEND") == digest)):
-            debug("Data is bad.")
+            warn("Invalid checksum. Closing connection.")
             self.shutdown(err=1)
         else:
-            debug("Data is ok.")
+            debug("Packet received; Checksum valid.")
             self.finished = self.__sentAck
             self.beginWrite(RECEIVED_CONTROL+sha1(msg+"RECEIVED"))
             self.messageConsumer(msg)
@@ -457,7 +457,7 @@
     def __sentAck(self):
         """Called once we're done sending an ACK.  Begins reading a new
            message."""
-        debug("done w/ send ack")
+        trace("done w/ send ack")
         #XXXX Rehandshake
         self.finished = self.__receivedMessage
         self.expectRead(SEND_RECORD_LEN)
@@ -467,7 +467,7 @@
 class MMTPClientConnection(SimpleTLSConnection):
     def __init__(self, context, ip, port, keyID, messageList,
                  sentCallback=None):
-        debug("CLIENT CON")
+        trace("CLIENT CON")
         sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
         sock.setblocking(0)
         self.keyID = keyID
@@ -506,7 +506,9 @@
         """
         inp = self.getInput()
         if inp != PROTOCOL_STRING:
-            self.shutdown(err=1); return
+            warn("Invalid protocol.  Closing connection")
+            self.shutdown(err=1)
+            return
 
         self.beginNextMessage()
 
@@ -526,7 +528,7 @@
         """Called when we're done sending a message.  Begins reading the
            server's ACK."""
 
-        debug("message sent")
+        trace("message sent")
         self.finished = self.__receivedAck
         self.expectRead(RECEIVED_RECORD_LEN)
 
@@ -539,14 +541,14 @@
           If there are more messages to send, begins sending the next.
           Otherwise, begins shutting down.
        """
-       debug("received ack")
+       trace("received ack")
        #XXXX Rehandshake
        inp = self.getInput()
        if inp != (RECEIVED_CONTROL+self.expectedDigest):
            self.shutdown(1)
            return
 
-       debug("ack ok")
+       debug("Received valid ACK for message.")
        del self.messageList[0]
        if self.sentCallback is not None:
            self.sentCallback()

Index: Queue.py
===================================================================
RCS file: /home/minion/cvsroot/src/minion/lib/mixminion/Queue.py,v
retrieving revision 1.3
retrieving revision 1.4
diff -u -d -r1.3 -r1.4
--- Queue.py	1 Jul 2002 18:03:05 -0000	1.3
+++ Queue.py	5 Jul 2002 19:50:27 -0000	1.4
@@ -11,7 +11,7 @@
 import time
 import stat
 
-from mixminion.Common import MixError, MixFatalError, secureDelete
+from mixminion.Common import MixError, MixFatalError, secureDelete, warn
 from mixminion.Crypto import AESCounterPRNG
 
 __all__ = [ 'Queue' ]
@@ -65,8 +65,7 @@
         self.dir = location
 
         if not os.path.isabs(location):
-            #FFFF Need a warning mechanism.
-            print "Warning: queue path '%s' isn't absolute"%location
+            warn("Queue path %s isn't absolute.", location)
 
         if os.path.exists(location) and not os.path.isdir(location):
             raise MixFatalError("%s is not a directory" % location)
@@ -81,8 +80,7 @@
         mode = os.stat(location)[stat.ST_MODE]
         if mode & 0077:
             # FFFF be more Draconian.
-            # FFFF Need a warning mechanism.
-            print "Worrisome mode %o on directory %s" % (mode, location)
+            warn("Worrisome more %o on directory %s", mode, location)
 
         if scrub:
             self.cleanQueue(1)

Index: __init__.py
===================================================================
RCS file: /home/minion/cvsroot/src/minion/lib/mixminion/__init__.py,v
retrieving revision 1.3
retrieving revision 1.4
diff -u -d -r1.3 -r1.4
--- __init__.py	1 Jul 2002 18:03:05 -0000	1.3
+++ __init__.py	5 Jul 2002 19:50:27 -0000	1.4
@@ -10,17 +10,17 @@
 __version__ = "0.1"
 __all__ = [ "BuildMessage", "MMTPClient" ]
 
-import BuildMessage
-import Crypto
-import MMTPServer
-import PacketHandler
-import Common
-import HashLog
-import Modules
-import Queue
-import Config
-import MMTPClient
-import Packet
-import ServerInfo
+import mixminion.BuildMessage
+import mixminion.Crypto
+import mixminion.MMTPServer
+import mixminion.PacketHandler
+import mixminion.Common
+import mixminion.HashLog
+import mixminion.Modules
+import mixminion.Queue
+import mixminion.Config
+import mixminion.MMTPClient
+import mixminion.Packet
+import mixminion.ServerInfo