logging via SocketHandler and TCPserver

[Vinay Sajip]

On Jul 13, 9:25 pm, Larry Bates <larry.ba... at websafe.com`> wrote:
> Every time I look at theloggingmodule (up until now) I've given up and
> continue to use my home-grown logger that I've been using for years.   I'm not
> giving up this time ;-)
>
> I find that I REALLY need to be able to monitor LOTS of running
> programs/processes and thought it would be nice to have them use SocketHandlerloggingand then I would write TCPServer to accept the log messages for
> real-time monitoring.  I Googled (is that now a verb?) for several hours and
> came up with some code that I've turned in to something that works, but I can't
> figure out how to disconnect the server once it is connected  The goal is to be
> able to start TCPServer, monitor the log messages sent via SocketHandler logger,
> disconnect, and move to the next application.  Eventually I would like to wrap a
> GUI around all of this for monitoring a complex web application.
>
> Everything works, it just appears that I get into the while loop in
> LogRecordStreamHandler.handle and it never breaks out (until I kill the client).
> I can't seem to do anything with the LogRecordSocketReceiver.abort attribute to
> make it quit.
>
> I'm sure it is something simple (stupid?), but I've spent about 4 hours and I'm
> not getting anywhere.
>
> Thanks in advance for any assistance.
>
> Regards,
> Larry
>
> Below is my code:
>
> import sys
> import time
> importlogging
>
> if sys.argv[1] == 'client':
>      importlogging.config
>
>      logging.config.fileConfig("logging.conf")
>
>      #create logger
>      logger =logging.getLogger("VESconsole")
>
>      while 1:
>          logger.debug("debug message")
>          logger.info("info message")
>          logger.warn("warn message")
>          logger.error("error message")
>          logger.critical("critical message")
>          time.sleep(2)
>
> elif sys.argv[1] == 'server':
>      import cPickle
>      importlogging.handlers
>      import SocketServer
>      import struct
>      import signal
>
>      class LogRecordStreamHandler(SocketServer.StreamRequestHandler):
>          """Handler for a streamingloggingrequest.
>
>          This basically logs the record using whateverloggingpolicy is
>          configured locally.
>          """
>
>          def handle(self):
>              """
>              Handle multiple requests - each expected to be a 4-byte length,
>              followed by the LogRecord in pickle format. Logs the record
>              according to whatever policy is configured locally.
>              """
>              while 1:
>                  chunk = self.connection.recv(4)
>                  if len(chunk) < 4:
>                      break
>
>                  slen = struct.unpack(">L", chunk)[0]
>                  chunk = self.connection.recv(slen)
>                  while len(chunk) < slen:
>                      chunk = chunk + self.connection.recv(slen - len(chunk))
>
>                  obj = self.unPickle(chunk)
>                  record =logging.makeLogRecord(obj)
>                  self.handleLogRecord(record)
>
>          def unPickle(self, data):
>              return cPickle.loads(data)
>
>          def handleLogRecord(self, record):
>              t = time.strftime('%a, %d %b %y %H:%M:%S',
>                                time.localtime(record.created))
>
>              print "%s %s" % (t, record.getMessage())
>
>      class LogRecordSocketReceiver(SocketServer.ThreadingTCPServer):
>          """simple TCP socket-basedloggingreceiver suitable for testing.
>          """
>
>          allow_reuse_address = 1
>
>          def __init__(self, host='localhost',
>                       port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
>                       handler=LogRecordStreamHandler):
>
>              SocketServer.ThreadingTCPServer.__init__(self,
>                                                       (host, port),
>                                                       handler)
>              self.abort = 0
>              self.timeout = 1
>              self.logname = None
>
>          def serve_until_stopped(self):
>              import select
>              abort = 0
>              while not abort:
>                  rd, wr, ex = select.select([self.socket.fileno()],
>                                             [], [],
>                                             self.timeout)
>                  if rd:
>                      self.handle_request()
>
>                  abort = self.abort
>
>              print "serve_until_stopped exiting"
>
>      #
>      # Start ThreadingTCPServer instance to accept SocketHandler log
>      # messages from client.
>      #
>      tcpserver = LogRecordSocketReceiver()
>      print "Starting ThreadingTCPServer..."
>      tcpserver.serve_until_stopped()
>
> '''
> #-----logging.conf-----
> [loggers]
> keys=root
>
> [handlers]
> keys=socketHandler
>
> [formatters]
> keys=simpleFormatter
>
> [logger_root]
> level=DEBUG
> handlers=socketHandler
>
> [handler_socketHandler]
> class=handlers.SocketHandler
> level=DEBUG
> args=('localhost', handlers.DEFAULT_TCP_LOGGING_PORT)
> host=localhost
> port=DEFAULT_TCP_LOGGING_PORT
>
> [formatter_simpleFormatter]
> format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
> datefmt=
> '''

Hi Larry,

You can make the server quit (set abort to True) by changing the logic
of the server appropriately. In your script (as in the example at
http://docs.python.org/lib/network-logging.html), nothing sets
server.abort, so the server never quits. If you were to insert a line
"self.server.abort = True" before the break in the check "if
len(chunk) < 4:", then the server will quit whenever a message shorter
than 4 bytes is received; ordinarily, a SocketHandler will always send
a 4-byte length followed by content. You can test this easily as
follows:

Run the server after modifying the script as described above.
Run the client and observe some messages printed by the server.
Kill the client. The server should still be waiting for events from
clients, though it might quit if, when you kill the client, a
truncated message is sent.
Run "telnet localhost 9020" and type a character.
The server should quit. If you make the "quitting" message a
raw_input() call, then you can see that the server has exited normally
via the abort flag.

Don't forget, the receiver can receive events from several
applications. You don't need to disconnect and reconnect. Simply have
each event sent by an app identify the app in some way - e.g. the
logger name could be "VESconsole.app1" for one app and
"VESconsole.app2" in another. In your server's handleRecord code, you
can get the logger name, decode the sending app from that and route
the event appropriately.

Another approach is to subclass SocketHandler and override the
makePickle method. This determines the wire format of the event sent
to the server, and if you change the wire format and modify the server
end to suit, then you can have any amount of flexibility in the
communications between the applications generating the events and the
server collating them.

I'm not sure why you've had so much trouble with logging in the past,
or why it took several hours of Googling to find a solution relating
to logging events across a network. I Googled for "python network
logging" and the link in the Python docs which I referenced earlier
was the first result, and hence also available via the "I'm Feeling
Lucky" button ;-)

Best regards,

Vinay