From 31ca2331d296cfaae1e853e91f5dbc2c42d96ce9 Mon Sep 17 00:00:00 2001
From: Kevin O'Connor <kevin@koconnor.net>
Date: Mon, 1 May 2017 13:44:06 -0400
Subject: [PATCH] queuelogger: Add critical information to each logfile on
rollover
When the log file does a rollover, start the top of the log with
critical system information (eg, software versions).
Signed-off-by: Kevin O'Connor <kevin@koconnor.net>
---
klippy/klippy.py | 35 ++++++++++++++++++++++-------------
klippy/mcu.py | 11 +++++++++++
klippy/queuelogger.py | 42 +++++++++++++++++++++++++++---------------
3 files changed, 60 insertions(+), 28 deletions(-)
diff --git a/klippy/klippy.py b/klippy/klippy.py
index 685d4d618..73819f621 100644
--- a/klippy/klippy.py
+++ b/klippy/klippy.py
@@ -107,19 +107,25 @@ class ConfigWrapper:
return ConfigWrapper(self.printer, section)
class ConfigLogger():
- def __init__(self, cfg):
- logging.info("===== Config file =====")
+ def __init__(self, cfg, bglogger):
+ self.lines = ["===== Config file ====="]
cfg.write(self)
- logging.info("=======================")
+ self.lines.append("=======================")
+ data = "\n".join(self.lines)
+ logging.info(data)
+ bglogger.set_rollover_info("config", data)
def write(self, data):
- logging.info(data.strip())
+ self.lines.append(data.strip())
class Printer:
def __init__(self, conffile, input_fd, startup_state
- , is_fileinput=False, version="?"):
+ , is_fileinput=False, version="?", bglogger=None):
self.conffile = conffile
self.startup_state = startup_state
self.software_version = version
+ self.bglogger = bglogger
+ if bglogger is not None:
+ bglogger.set_rollover_info("config", None)
self.reactor = reactor.Reactor()
self.objects = {}
self.gcode = gcode.GCodeParser(self, input_fd, is_fileinput)
@@ -159,8 +165,8 @@ class Printer:
if not res:
raise ConfigParser.Error("Unable to open config file %s" % (
self.conffile,))
- if self.debugoutput is None:
- ConfigLogger(self.fileconfig)
+ if self.bglogger is not None:
+ ConfigLogger(self.fileconfig, self.bglogger)
self.mcu = mcu.MCU(self, ConfigWrapper(self, 'mcu'))
if self.debugoutput is not None:
self.mcu.connect_file(self.debugoutput, self.dictionary)
@@ -308,18 +314,21 @@ def main():
logging.basicConfig(level=debuglevel)
logging.info("Starting Klippy...")
software_version = util.get_git_version()
- if debugoutput is None:
- logging.info("Args: %s" % (sys.argv,))
- logging.info("Git version: %s" % (repr(software_version),))
- logging.info("CPU: %s" % (util.get_cpu_info(),))
- logging.info("Python: %s" % (repr(sys.version),))
+ if bglogger is not None:
+ lines = ["Args: %s" % (sys.argv,),
+ "Git version: %s" % (repr(software_version),),
+ "CPU: %s" % (util.get_cpu_info(),),
+ "Python: %s" % (repr(sys.version),)]
+ lines = "\n".join(lines)
+ logging.info(lines)
+ bglogger.set_rollover_info('versions', lines)
# Start firmware
res = 'startup'
while 1:
is_fileinput = debuginput is not None
printer = Printer(
- conffile, input_fd, res, is_fileinput, software_version)
+ conffile, input_fd, res, is_fileinput, software_version, bglogger)
if debugoutput:
proto_dict = read_dictionary(options.read_dictionary)
printer.set_fileoutput(debugoutput, proto_dict)
diff --git a/klippy/mcu.py b/klippy/mcu.py
index 87aa59e6d..7f5e11fc6 100644
--- a/klippy/mcu.py
+++ b/klippy/mcu.py
@@ -385,6 +385,8 @@ class MCU:
self._restart_method = config.getchoice(
'restart_method', rmethods, 'arduino')
# Config building
+ if printer.bglogger is not None:
+ printer.bglogger.set_rollover_info("mcu", None)
self._config_error = config.error
self._emergency_stop_cmd = self._reset_cmd = None
self._oids = []
@@ -575,6 +577,15 @@ class MCU:
raise error("Printer CRC does not match config")
move_count = config_params['move_count']
logging.info("Configured (%d moves)" % (move_count,))
+ if self._printer.bglogger is not None:
+ msgparser = self.serial.msgparser
+ info = [
+ "Configured (%d moves)" % (move_count,),
+ "Loaded %d commands (%s)" % (
+ len(msgparser.messages_by_id), msgparser.version),
+ "MCU config: %s" % (" ".join(
+ ["%s=%s" % (k, v) for k, v in msgparser.config.items()]))]
+ self._printer.bglogger.set_rollover_info("mcu", "\n".join(info))
stepqueues = tuple(s._stepqueue for s in self._steppers)
self._steppersync = self._ffi_lib.steppersync_alloc(
self.serial.serialqueue, stepqueues, len(stepqueues), move_count)
diff --git a/klippy/queuelogger.py b/klippy/queuelogger.py
index 38a3d4239..32cb125db 100644
--- a/klippy/queuelogger.py
+++ b/klippy/queuelogger.py
@@ -3,7 +3,7 @@
# Copyright (C) 2016,2017 Kevin O'Connor <kevin@koconnor.net>
#
# This file may be distributed under the terms of the GNU GPLv3 license.
-import logging, logging.handlers, threading, Queue
+import logging, logging.handlers, threading, Queue, time
# Class to forward all messages through a queue to a background thread
class QueueHandler(logging.Handler):
@@ -21,27 +21,39 @@ class QueueHandler(logging.Handler):
self.handleError(record)
# Class to poll a queue in a background thread and log each message
-class QueueListener(object):
- def __init__(self, handler):
- self.handler = handler
- self.queue = Queue.Queue()
- self.thread = threading.Thread(target=self._bg_thread)
- self.thread.start()
+class QueueListener(logging.handlers.TimedRotatingFileHandler):
+ def __init__(self, filename):
+ logging.handlers.TimedRotatingFileHandler.__init__(
+ self, filename, when='midnight', backupCount=5)
+ self.bg_queue = Queue.Queue()
+ self.bg_thread = threading.Thread(target=self._bg_thread)
+ self.bg_thread.start()
+ self.rollover_info = {}
def _bg_thread(self):
while 1:
- record = self.queue.get(True)
+ record = self.bg_queue.get(True)
if record is None:
break
- self.handler.handle(record)
+ self.handle(record)
def stop(self):
- self.queue.put_nowait(None)
- self.thread.join()
+ self.bg_queue.put_nowait(None)
+ self.bg_thread.join()
+ def set_rollover_info(self, name, info):
+ self.rollover_info[name] = info
+ def doRollover(self):
+ logging.handlers.TimedRotatingFileHandler.doRollover(self)
+ lines = [self.rollover_info[name]
+ for name in sorted(self.rollover_info)
+ if self.rollover_info[name]]
+ lines.append(
+ "=============== Log rollover at %s ===============" % (
+ time.asctime(),))
+ self.emit(logging.makeLogRecord(
+ {'msg': "\n".join(lines), 'level': logging.INFO}))
def setup_bg_logging(filename, debuglevel):
- handler = logging.handlers.TimedRotatingFileHandler(
- filename, when='midnight', backupCount=5)
- ql = QueueListener(handler)
- qh = QueueHandler(ql.queue)
+ ql = QueueListener(filename)
+ qh = QueueHandler(ql.bg_queue)
root = logging.getLogger()
root.addHandler(qh)
root.setLevel(debuglevel)