[Twisted-Python] Persuading Python's Logging to use twisted.logger

[Daniel Sutcliffe]

Thanks for all the hints and suggestions guys, this was far simpler
than I thought it would be and the results are exactly what I imagined
without too much effort.

Jeff: Have to admit I started with your code and had it working with
in my scenario in no time at all, this was a great bump start, but I
couldn't help tweaking...

Glyph: The code below is I'm sure far from perfect, and it doesn't
take your advice and convert the msg into a twisted format string, it
takes the simpler approach of letting the Logging record pre-format
using the getMessage() method. I'm sure there are loads of edge cases
it could cope with better with maybe it is a start of something that
could be included in Twisted.

Kevin: I appreciate your input and understand the need to always be
aware of what you are call/using may be blocking for various reasons -
I will eventually want to redirect to syslog so will need to deal with
this later. I still think it makes sense to have a relatively easy
option of redirecting STDLib logging from used modules to
twisted.logger available, as well as the opposite. When twistd is
handling most of logging setup it seems the simpler path to have
everything using twisted.logger.

Burak: Your code was especially helpful - it goes much further than I
even considered is useful so I just borrowed what I thought was
essential for the needs of this first pass. Will be glad to hear of
any cases you think will break this code to help make it even more
general.

So here's the code I dropped into a logfudger.py in my test dir. All
feedback encouraged as I really am just finding my way around Python,
and appreciate all critique of what I could do better:

from twisted.logger import Logger, LogLevel
import logging
LEVEL_SYS2TWISTED = {
    logging.DEBUG: LogLevel.debug,
    logging.INFO: LogLevel.info,
    logging.WARN: LogLevel.warn,
    logging.ERROR: LogLevel.error,
    logging.CRITICAL: LogLevel.critical,
}
class TwistedLoggerHandler(logging.Handler):
    def __init__(self):
        self._log = Logger()
        logging.Handler.__init__(self)
    def flush(self):
        pass
    def emit(self, record):
        try:
            self._log.namespace=record.name
            self._log.source=record.pathname
            self._log.emit(
                LEVEL_SYS2TWISTED[record.levelno],
                record.getMessage(),
                lineno=record.lineno, args=record.args)
        except:
            self.handleError(record)

When I use this with pymodbus I then just need to include this with my code:

import logging
from logfudger import TwistedLoggerHandler
sysliblog = logging.getLogger("pymodbus")
sysliblog.addHandler(TwistedLoggerHandler())
sysliblog.setLevel(logging.DEBUG)
from twisted.logger import Logger, globalLogBeginner, textFileLogObserver
import sys
globalLogBeginner.beginLoggingTo([textFileLogObserver(sys.stderr)])

Which gives me a stderr output like:

2016-05-10T18:48:52-0400 [pymodbus#info] Informational
2016-05-10T18:48:52-0400 [__main__.MBClientFactory#info] Starting
factory <__main__.MBClientFactory instance at 0x0000000001212ae0>
2016-05-10T18:48:52-0400 [__main__.MBClientProtocol#debug] Protocol
connectionMade
2016-05-10T18:48:52-0400 [pymodbus.client.async#debug] Client
connected to modbus server
2016-05-10T18:48:52-0400 [pymodbus.transaction#debug] adding transaction 1

I don't deal with exceptions logged through the STDLib logging at all,
and the log_namespace, log_source could probably be set in ways that
cover more use cases.
But hopefully this all makes sense and this can be a start of
something much more generically useful.

Cheers
/dan
-- 
Daniel Sutcliffe <dansut at gmail.com>