2015-12-07 02:40:13 +01:00
|
|
|
"""
|
|
|
|
log.py - PyLink logging module.
|
|
|
|
|
|
|
|
This module contains the logging portion of the PyLink framework. Plugins can
|
|
|
|
access the global logger object by importing "log" from this module
|
|
|
|
(from log import log).
|
|
|
|
"""
|
|
|
|
|
2015-07-05 22:22:17 +02:00
|
|
|
import logging
|
2016-08-18 06:39:46 +02:00
|
|
|
import logging.handlers
|
2015-07-19 05:11:29 +02:00
|
|
|
import os
|
|
|
|
|
2016-08-18 07:00:22 +02:00
|
|
|
from . import world, conf
|
2015-07-07 21:14:55 +02:00
|
|
|
|
2016-08-18 06:39:46 +02:00
|
|
|
# Stores a list of active file loggers.
|
|
|
|
fileloggers = []
|
|
|
|
|
2016-06-21 03:23:05 +02:00
|
|
|
logdir = os.path.join(os.getcwd(), 'log')
|
2015-07-19 05:11:29 +02:00
|
|
|
os.makedirs(logdir, exist_ok=True)
|
|
|
|
|
2017-01-07 09:10:47 +01:00
|
|
|
# TODO: perhaps make this format configurable?
|
2015-07-19 05:11:29 +02:00
|
|
|
_format = '%(asctime)s [%(levelname)s] %(message)s'
|
2016-01-25 03:29:30 +01:00
|
|
|
logformatter = logging.Formatter(_format)
|
2016-03-25 23:45:26 +01:00
|
|
|
|
2017-06-02 17:42:32 +02:00
|
|
|
def getConsoleLogLevel():
|
2017-01-07 09:10:47 +01:00
|
|
|
"""
|
2017-06-02 17:42:32 +02:00
|
|
|
Returns the configured console log level.
|
2017-01-07 09:10:47 +01:00
|
|
|
"""
|
2017-06-02 17:42:32 +02:00
|
|
|
logconf = conf.conf['logging']
|
|
|
|
return logconf.get('console', logconf.get('stdout')) or 'INFO'
|
2017-01-07 09:10:47 +01:00
|
|
|
|
2016-03-25 23:45:26 +01:00
|
|
|
# Set up logging to STDERR
|
2017-06-02 17:42:32 +02:00
|
|
|
world.console_handler = logging.StreamHandler()
|
|
|
|
world.console_handler.setFormatter(logformatter)
|
|
|
|
world.console_handler.setLevel(getConsoleLogLevel())
|
2015-07-05 22:22:17 +02:00
|
|
|
|
2016-01-25 03:29:30 +01:00
|
|
|
# Get the main logger object; plugins can import this variable for convenience.
|
2015-07-05 22:22:17 +02:00
|
|
|
log = logging.getLogger()
|
2017-06-02 17:42:32 +02:00
|
|
|
log.addHandler(world.console_handler)
|
2016-03-25 23:45:26 +01:00
|
|
|
|
|
|
|
# This is confusing, but we have to set the root logger to accept all events. Only this way
|
|
|
|
# can other loggers filter out events on their own, instead of having everything dropped by
|
|
|
|
# the root logger. https://stackoverflow.com/questions/16624695
|
|
|
|
log.setLevel(1)
|
2016-01-25 03:29:30 +01:00
|
|
|
|
|
|
|
def makeFileLogger(filename, level=None):
|
|
|
|
"""
|
|
|
|
Initializes a file logging target with the given filename and level.
|
|
|
|
"""
|
|
|
|
# Use log names specific to the current instance, to prevent multiple
|
|
|
|
# PyLink instances from overwriting each others' log files.
|
2016-08-18 07:00:22 +02:00
|
|
|
target = os.path.join(logdir, '%s-%s.log' % (conf.confname, filename))
|
2016-01-25 03:29:30 +01:00
|
|
|
|
2016-08-18 07:00:42 +02:00
|
|
|
logrotconf = conf.conf.get('logging', {}).get('filerotation', {})
|
|
|
|
|
|
|
|
# Max amount of bytes per file, before rotation is done. Defaults to 50 MiB.
|
|
|
|
maxbytes = logrotconf.get('max_bytes', 52428800)
|
|
|
|
|
|
|
|
# Amount of backups to make (e.g. pylink-debug.log, pylink-debug.log.1, pylink-debug.log.2, ...)
|
|
|
|
# Defaults to 5.
|
|
|
|
backups = logrotconf.get('backup_count', 5)
|
|
|
|
|
|
|
|
filelogger = logging.handlers.RotatingFileHandler(target, maxBytes=maxbytes, backupCount=backups)
|
2016-01-25 03:29:30 +01:00
|
|
|
filelogger.setFormatter(logformatter)
|
|
|
|
|
2017-06-02 17:42:32 +02:00
|
|
|
# If no log level is specified, use the same one as the console logger.
|
|
|
|
level = level or getConsoleLogLevel()
|
2016-03-25 23:45:26 +01:00
|
|
|
filelogger.setLevel(level)
|
2016-01-25 03:29:30 +01:00
|
|
|
|
|
|
|
log.addHandler(filelogger)
|
2016-08-18 06:39:46 +02:00
|
|
|
global fileloggers
|
|
|
|
fileloggers.append(filelogger)
|
2016-01-25 03:29:30 +01:00
|
|
|
|
|
|
|
return filelogger
|
|
|
|
|
2016-08-18 06:39:46 +02:00
|
|
|
def stopFileLoggers():
|
|
|
|
"""
|
|
|
|
De-initializes all file loggers.
|
|
|
|
"""
|
|
|
|
global fileloggers
|
|
|
|
for handler in fileloggers.copy():
|
|
|
|
handler.close()
|
|
|
|
log.removeHandler(handler)
|
|
|
|
fileloggers.remove(handler)
|
|
|
|
|
2016-01-25 03:29:30 +01:00
|
|
|
# Set up file logging now, creating a file logger for each block.
|
2016-08-18 07:00:22 +02:00
|
|
|
files = conf.conf['logging'].get('files')
|
2016-01-25 03:29:30 +01:00
|
|
|
if files:
|
|
|
|
for filename, config in files.items():
|
|
|
|
makeFileLogger(filename, config.get('loglevel'))
|
2016-01-23 22:13:38 +01:00
|
|
|
|
2017-07-20 15:16:44 +02:00
|
|
|
log.debug("log: Emptying _log_queue")
|
2017-06-02 17:39:49 +02:00
|
|
|
# Process and empty the log queue
|
2017-07-20 15:16:44 +02:00
|
|
|
while world._log_queue:
|
|
|
|
level, text = world._log_queue.popleft()
|
2017-06-02 17:39:49 +02:00
|
|
|
log.log(level, text)
|
2017-07-20 15:16:44 +02:00
|
|
|
log.debug("log: Emptied _log_queue")
|
2017-06-02 17:39:49 +02:00
|
|
|
|
2016-01-23 22:13:38 +01:00
|
|
|
class PyLinkChannelLogger(logging.Handler):
|
|
|
|
"""
|
|
|
|
Log handler to log to channels in PyLink.
|
|
|
|
"""
|
2016-01-31 08:33:03 +01:00
|
|
|
def __init__(self, irc, channel, level=None):
|
2016-01-23 22:13:38 +01:00
|
|
|
super(PyLinkChannelLogger, self).__init__()
|
|
|
|
self.irc = irc
|
2016-01-31 08:33:03 +01:00
|
|
|
self.channel = channel
|
2016-01-23 22:13:38 +01:00
|
|
|
|
2016-02-21 04:28:45 +01:00
|
|
|
# Set whether we've been called already. This is used to prevent recursive
|
|
|
|
# loops when logging.
|
|
|
|
self.called = False
|
|
|
|
|
2016-01-23 22:13:38 +01:00
|
|
|
# Use a slightly simpler message formatter - logging to IRC doesn't need
|
|
|
|
# logging the time.
|
|
|
|
formatter = logging.Formatter('[%(levelname)s] %(message)s')
|
|
|
|
self.setFormatter(formatter)
|
|
|
|
|
2016-01-31 08:33:03 +01:00
|
|
|
# HACK: Use setLevel twice to first coerse string log levels to ints,
|
|
|
|
# for easier comparison.
|
|
|
|
level = level or log.getEffectiveLevel()
|
|
|
|
self.setLevel(level)
|
|
|
|
|
2016-01-23 22:13:38 +01:00
|
|
|
# Log level has to be at least 20 (INFO) to prevent loops due
|
|
|
|
# to outgoing messages being logged
|
2016-01-31 08:33:03 +01:00
|
|
|
loglevel = max(self.level, 20)
|
2016-01-23 22:13:38 +01:00
|
|
|
self.setLevel(loglevel)
|
|
|
|
|
|
|
|
def emit(self, record):
|
|
|
|
"""
|
|
|
|
Logs a record to the configured channels for the network given.
|
|
|
|
"""
|
2016-02-21 04:28:45 +01:00
|
|
|
# Only start logging if we're finished bursting, and our main client is in
|
|
|
|
# a stable condition.
|
|
|
|
# 1) irc.pseudoclient must be initialized already
|
|
|
|
# 2) IRC object must be finished bursting
|
|
|
|
# 3) Target channel must exist
|
|
|
|
# 4) Main PyLink client must be in this target channel
|
|
|
|
# 5) This function hasn't been called already (prevents recursive loops).
|
2016-05-14 22:52:21 +02:00
|
|
|
if self.irc.pseudoclient and self.irc.connected.is_set() \
|
2016-02-21 04:28:45 +01:00
|
|
|
and self.channel in self.irc.channels and self.irc.pseudoclient.uid in \
|
|
|
|
self.irc.channels[self.channel].users and not self.called:
|
|
|
|
|
|
|
|
self.called = True
|
2016-01-23 22:13:38 +01:00
|
|
|
msg = self.format(record)
|
2016-02-21 04:28:45 +01:00
|
|
|
|
|
|
|
# Send the message. If this fails, abort. No more messages will be
|
|
|
|
# sent from this logger until the next sending succeeds.
|
2016-03-16 23:38:07 +01:00
|
|
|
for line in msg.splitlines():
|
|
|
|
try:
|
|
|
|
self.irc.msg(self.channel, line)
|
|
|
|
except:
|
|
|
|
return
|
|
|
|
else:
|
|
|
|
self.called = False
|
2016-01-23 22:13:38 +01:00
|
|
|
|