From c0fd2e990772228385042aacb86cd2baf8316192 Mon Sep 17 00:00:00 2001
From: Enrico Faulhaber <enrico.faulhaber@frm2.tum.de>
Date: Tue, 16 May 2017 18:15:56 +0200
Subject: [PATCH] Use mlzlog for better logging

Change-Id: Ic82ca0d7b43a906cb9c7d3f1350287e7082afc45
---
 bin/secop-console          |   4 +-
 bin/secop-gui              |   7 +-
 bin/secop-server           |   6 +-
 requirements.txt           |   2 +
 secop/client/__init__.py   |   8 +-
 secop/client/baseclient.py |   5 +-
 secop/loggers/__init__.py  | 348 -------------------------------------
 secop/loggers/colors.py    |  65 -------
 secop/server.py            |   3 -
 9 files changed, 19 insertions(+), 429 deletions(-)
 delete mode 100644 secop/loggers/__init__.py
 delete mode 100644 secop/loggers/colors.py

diff --git a/bin/secop-console b/bin/secop-console
index 6fd9b55..dc7ec7d 100755
--- a/bin/secop-console
+++ b/bin/secop-console
@@ -36,7 +36,7 @@ log_path = path.join(basepath, 'log')
 sys.path[0] = basepath
 
 # do not move above!
-import loggers
+import mlzlog
 from secop.client import ClientConsole
 
 
@@ -62,7 +62,7 @@ def main(argv=None):
     args = parseArgv(argv[1:])
 
     loglevel = 'debug' if args.verbose else ('error' if args.quiet else 'info')
-    loggers.initLogging('console', loglevel, log_path)
+    mlzlog.initLogging('console', loglevel, log_path)
 
     console = ClientConsole(args.name, basepath)
 
diff --git a/bin/secop-gui b/bin/secop-gui
index 9215c72..d2e67e0 100755
--- a/bin/secop-gui
+++ b/bin/secop-gui
@@ -29,7 +29,8 @@ from os import path
 sys.path.insert(0, path.abspath(path.join(path.dirname(__file__), '..')))
 
 from secop.gui.mainwindow import MainWindow
-from secop import loggers
+
+import mlzlog
 
 from PyQt4.QtGui import QApplication
 
@@ -39,9 +40,9 @@ def main(argv=None):
         argv = sys.argv
 
     if '-d' in argv:
-        loggers.initLogging('gui', 'debug')
+        mlzlog.initLogging('gui', 'debug')
     else:
-        loggers.initLogging('gui', 'info')
+        mlzlog.initLogging('gui', 'info')
 
     app = QApplication(argv)
 
diff --git a/bin/secop-server b/bin/secop-server
index 84b1917..8bb170f 100755
--- a/bin/secop-server
+++ b/bin/secop-server
@@ -36,7 +36,7 @@ log_path = path.join(basepath, 'log')
 #sys.path[0] = path.join(basepath, 'src')
 sys.path[0] = basepath
 
-from secop import loggers
+import mlzlog
 from secop.server import Server
 
 
@@ -67,9 +67,9 @@ def main(argv=None):
     args = parseArgv(argv[1:])
 
     loglevel = 'debug' if args.verbose else ('error' if args.quiet else 'info')
-    loggers.initLogging('secop', loglevel, log_path)
+    mlzlog.initLogging('secop', loglevel, log_path)
 
-    srv = Server(args.name, basepath)
+    srv = Server(args.name, basepath, mlzlog.log)
 
     if args.daemonize:
         srv.start()
diff --git a/requirements.txt b/requirements.txt
index 46d5f15..1e2eaaf 100644
--- a/requirements.txt
+++ b/requirements.txt
@@ -1,3 +1,5 @@
+#--extra-index-url https://forge.frm2.tum.de/simple
+mlzlog >=0.2.0
 # for generating docu
 markdown>=2.6
 # daemonizing
diff --git a/secop/client/__init__.py b/secop/client/__init__.py
index 8fc92ad..0805b31 100644
--- a/secop/client/__init__.py
+++ b/secop/client/__init__.py
@@ -89,7 +89,9 @@ class ClientConsole(object):
 import socket
 import threading
 from collections import deque
-from secop import loggers
+
+import mlzlog
+
 from secop.protocol.encoding import ENCODERS
 from secop.protocol.framing import FRAMERS
 from secop.protocol.messages import *
@@ -97,7 +99,7 @@ from secop.protocol.messages import *
 
 class TCPConnection(object):
     def __init__(self, connect, port, encoding, framing, **kwds):
-        self.log = loggers.log.getChild('connection', False)
+        self.log = mlzlog.log.getChild('connection', False)
         self.encoder = ENCODERS[encoding]()
         self.framer = FRAMERS[framing]()
         self.connection = socket.create_connection((connect, port), 3)
@@ -163,7 +165,7 @@ class TCPConnection(object):
 
 class Client(object):
     def __init__(self, opts):
-        self.log = loggers.log.getChild('client', True)
+        self.log = mlzlog.log.getChild('client', True)
         self._cache = dict()
         self.connection = TCPConnection(**opts)
         self.connection.register_callback(self.handle_async)
diff --git a/secop/client/baseclient.py b/secop/client/baseclient.py
index 4eeaa89..7ace750 100644
--- a/secop/client/baseclient.py
+++ b/secop/client/baseclient.py
@@ -28,7 +28,8 @@ from select import select
 import threading
 import Queue
 
-from secop import loggers
+import mlzlog
+
 from secop.validators import validator_from_str
 from secop.lib import mkthread
 from secop.lib.parsing import parse_time, format_time
@@ -150,7 +151,7 @@ class Client(object):
     stopflag = False
 
     def __init__(self, opts, autoconnect=True):
-        self.log = loggers.log.getChild('client', True)
+        self.log = mlzlog.log.getChild('client', True)
         self._cache = dict()
         if 'device' in opts:
             # serial port
diff --git a/secop/loggers/__init__.py b/secop/loggers/__init__.py
deleted file mode 100644
index bdbead1..0000000
--- a/secop/loggers/__init__.py
+++ /dev/null
@@ -1,348 +0,0 @@
-# *****************************************************************************
-#
-# This program is free software; you can redistribute it and/or modify it under
-# the terms of the GNU General Public License as published by the Free Software
-# Foundation; either version 2 of the License, or (at your option) any later
-# version.
-#
-# This program is distributed in the hope that it will be useful, but WITHOUT
-# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
-# FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
-# details.
-#
-# You should have received a copy of the GNU General Public License along with
-# this program; if not, write to the Free Software Foundation, Inc.,
-# 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
-#
-# Module authors:
-#   Alexander Lenz <alexander.lenz@posteo.de>
-#   Georg Brandl <georg@python.org>
-#
-# *****************************************************************************
-
-import os
-import sys
-import time
-import linecache
-import traceback
-import logging
-
-from os import path
-from logging import Logger, Formatter, Handler, DEBUG, INFO, WARNING, ERROR, \
-    setLoggerClass
-
-from . import colors
-
-LOGFMT = '%(asctime)s : %(levelname)-7s : %(name)-15s: %(message)s'
-DATEFMT = '%H:%M:%S'
-DATESTAMP_FMT = '%Y-%m-%d'
-SECONDS_PER_DAY = 60 * 60 * 24
-
-LOGLEVELS = {'debug': DEBUG, 'info': INFO, 'warning': WARNING, 'error': ERROR}
-INVLOGLEVELS = {value: key for key, value in LOGLEVELS.items()}
-
-log = None
-
-
-def initLogging(rootname='secop', rootlevel='info', logdir='/tmp/log'):
-    global log
-    setLoggerClass(SecopLogger)
-    log = SecopLogger(rootname)
-    log.setLevel(LOGLEVELS[rootlevel])
-
-    # console logging for fg process
-    log.addHandler(ColoredConsoleHandler())
-
-    # logfile for fg and bg process
-    if logdir.startswith('/var/log'):
-        log.addHandler(LogfileHandler(logdir, rootname))
-    else:
-        log.addHandler(LogfileHandler(logdir, ''))
-
-
-def getLogger(name, subdir=False):
-    global log
-    return log.getChild(name, subdir)
-
-
-class SecopLogger(Logger):
-    maxLogNameLength = 0
-
-    def __init__(self, *args, **kwargs):
-        Logger.__init__(self, *args, **kwargs)
-        SecopLogger._storeLoggerNameLength(self)
-
-    def getChild(self, suffix, ownDir=False):
-        child = Logger.getChild(self, suffix)
-        child.setLevel(self.getEffectiveLevel())
-
-        for handler in self._collectHandlers():
-            if ownDir and isinstance(handler, LogfileHandler):
-                handler = handler.getChild(suffix)
-            child.addHandler(handler)
-
-        child.propagate = False
-
-        return child
-
-    def getLogfileStreams(self):
-        result = []
-        for entry in self._collectHandlers():
-            if isinstance(entry, LogfileHandler):
-                result.append(entry.stream)
-        return result
-
-    def _collectHandlers(self):
-        result = []
-
-        log = self
-        while log is not None:
-            result += log.handlers
-            log = log.parent
-
-        return result
-
-    @staticmethod
-    def _storeLoggerNameLength(logObj):
-        # store max logger name length for formatting
-        if len(logObj.name) > SecopLogger.maxLogNameLength:
-            SecopLogger.maxLogNameLength = len(logObj.name)
-
-
-class ConsoleFormatter(Formatter):
-    """
-    A lightweight formatter for the interactive console, with optional
-    colored output.
-    """
-
-    def __init__(self, fmt=None, datefmt=None, colorize=None):
-        Formatter.__init__(self, fmt, datefmt)
-        if colorize:
-            self.colorize = colorize
-        else:
-            self.colorize = lambda c, s: s
-
-    def formatException(self, exc_info):
-        return traceback.format_exception_only(*exc_info[0:2])[-1]
-
-    def formatTime(self, record, datefmt=None):
-        return time.strftime(datefmt or DATEFMT,
-                             self.converter(record.created))
-
-    def format(self, record):
-        record.message = record.getMessage()
-        levelno = record.levelno
-        datefmt = self.colorize('lightgray', '[%(asctime)s] ')
-        namefmt = '%(name)-' + str(SecopLogger.maxLogNameLength) + 's: '
-        if levelno <= DEBUG:
-            fmtstr = self.colorize('darkgray', '%s%%(message)s' % namefmt)
-        elif levelno <= INFO:
-            fmtstr = '%s%%(message)s' % namefmt
-        elif levelno <= WARNING:
-            fmtstr = self.colorize('fuchsia',
-                                   '%s%%(levelname)s: %%(message)s' % namefmt)
-        else:
-            # Add exception type to error (if caused by exception)
-            msgPrefix = ''
-            if record.exc_info:
-                msgPrefix = '%s: ' % record.exc_info[0].__name__
-
-            fmtstr = self.colorize('red', '%s%%(levelname)s: %s%%(message)s' %
-                                   (namefmt, msgPrefix))
-        fmtstr = datefmt + fmtstr
-        if not getattr(record, 'nonl', False):
-            fmtstr += '\n'
-        record.asctime = self.formatTime(record, self.datefmt)
-        s = fmtstr % record.__dict__
-        # never output more exception info -- the exception message is already
-        # part of the log message because of our special logger behavior
-        # if record.exc_info:
-        #    # *not* caching exception text on the record, since it's
-        #    # only a short version
-        #    s += self.formatException(record.exc_info)
-        return s
-
-
-def format_extended_frame(frame):
-    ret = []
-    for key, value in frame.f_locals.items():
-        try:
-            valstr = repr(value)[:256]
-        except Exception:
-            valstr = '<cannot be displayed>'
-        ret.append('        %-20s = %s\n' % (key, valstr))
-    ret.append('\n')
-    return ret
-
-
-def format_extended_traceback(etype, value, tb):
-    ret = ['Traceback (most recent call last):\n']
-    while tb is not None:
-        frame = tb.tb_frame
-        filename = frame.f_code.co_filename
-        item = '  File "%s", line %d, in %s\n' % (filename, tb.tb_lineno,
-                                                  frame.f_code.co_name)
-        linecache.checkcache(filename)
-        line = linecache.getline(filename, tb.tb_lineno, frame.f_globals)
-        if line:
-            item = item + '    %s\n' % line.strip()
-        ret.append(item)
-        if filename != '<script>':
-            ret += format_extended_frame(tb.tb_frame)
-        tb = tb.tb_next
-    ret += traceback.format_exception_only(etype, value)
-    return ''.join(ret).rstrip('\n')
-
-
-class LogfileFormatter(Formatter):
-    """
-    The standard Formatter does not support milliseconds with an explicit
-    datestamp format.  It also doesn't show the full traceback for exceptions.
-    """
-
-    extended_traceback = True
-
-    def formatException(self, ei):
-        if self.extended_traceback:
-            s = format_extended_traceback(*ei)
-        else:
-            s = ''.join(
-                traceback.format_exception(ei[0], ei[1], ei[2], sys.maxsize))
-            if s.endswith('\n'):
-                s = s[:-1]
-        return s
-
-    def formatTime(self, record, datefmt=None):
-        res = time.strftime(DATEFMT, self.converter(record.created))
-        res += ',%03d' % record.msecs
-        return res
-
-
-class StreamHandler(Handler):
-    """Reimplemented from logging: remove cruft, remove bare excepts."""
-
-    def __init__(self, stream=None):
-        Handler.__init__(self)
-        self.stream = stream
-
-    def flush(self):
-        self.acquire()
-        try:
-            if self.stream and hasattr(self.stream, 'flush'):
-                self.stream.flush()
-        finally:
-            self.release()
-
-    def emit(self, record):
-        try:
-            msg = self.format(record)
-            try:
-                self.stream.write('%s\n' % msg)
-            except UnicodeEncodeError:
-                self.stream.write('%s\n' % msg.encode('utf-8'))
-            self.flush()
-        except Exception:
-            self.handleError(record)
-
-
-class LogfileHandler(StreamHandler):
-    """
-    Logs to log files with a date stamp appended, and rollover on midnight.
-    """
-
-    def __init__(self, directory, filenameprefix, dayfmt=DATESTAMP_FMT):
-        self._directory = path.join(directory, filenameprefix)
-        if not path.isdir(self._directory):
-            os.makedirs(self._directory)
-        self._currentsymlink = path.join(self._directory, 'current')
-        self._filenameprefix = filenameprefix
-        self._pathnameprefix = path.join(self._directory, filenameprefix)
-        self._dayfmt = dayfmt
-        # today's logfile name
-        basefn = self._pathnameprefix + '-' + time.strftime(dayfmt) + '.log'
-        self.baseFilename = path.abspath(basefn)
-        self.mode = 'a'
-        StreamHandler.__init__(self)
-        # determine time of first midnight from now on
-        t = time.localtime()
-        self.rollover_at = time.mktime(
-            (t[0], t[1], t[2], 0, 0, 0, t[6], t[7], t[8])) + SECONDS_PER_DAY
-        self.setFormatter(LogfileFormatter(LOGFMT, DATEFMT))
-        self.disabled = False
-
-    def getChild(self, name):
-        return LogfileHandler(self._directory, name)
-
-    def filter(self, record):
-        return not self.disabled
-
-    def emit(self, record):
-        try:
-            t = int(time.time())
-            if t >= self.rollover_at:
-                self.doRollover()
-            if self.stream is None:
-                self.stream = self._open()
-            StreamHandler.emit(self, record)
-        except Exception:
-            self.handleError(record)
-
-    def enable(self, enabled):
-        if enabled:
-            self.disabled = False
-            self.stream.close()
-            self.stream = self._open()
-        else:
-            self.disabled = True
-
-    def close(self):
-        self.acquire()
-        try:
-            if self.stream:
-                self.flush()
-                if hasattr(self.stream, 'close'):
-                    self.stream.close()
-                StreamHandler.close(self)
-                self.stream = None
-        finally:
-            self.release()
-
-    def doRollover(self):
-        self.stream.close()
-        self.baseFilename = self._pathnameprefix + '-' + \
-            time.strftime(self._dayfmt) + '.log'
-        self.stream = self._open()
-        self.rollover_at += SECONDS_PER_DAY
-
-    def _open(self):
-        # update 'current' symlink upon open
-        try:
-            os.remove(self._currentsymlink)
-        except OSError:
-            # if the symlink does not (yet) exist, OSError is raised.
-            # should happen at most once per installation....
-            pass
-        if hasattr(os, 'symlink'):
-            os.symlink(path.basename(self.baseFilename), self._currentsymlink)
-        # finally open the new logfile....
-        return open(self.baseFilename, self.mode)
-
-
-class ColoredConsoleHandler(StreamHandler):
-    """
-    A handler class that writes colorized records to standard output.
-    """
-
-    def __init__(self):
-        StreamHandler.__init__(self, sys.stdout)
-        self.setFormatter(
-            ConsoleFormatter(
-                datefmt=DATEFMT, colorize=colors.colorize))
-
-    def emit(self, record):
-        msg = self.format(record)
-        try:
-            self.stream.write(msg)
-        except UnicodeEncodeError:
-            self.stream.write(msg.encode('utf-8'))
-        self.stream.flush()
diff --git a/secop/loggers/colors.py b/secop/loggers/colors.py
deleted file mode 100644
index 03cad23..0000000
--- a/secop/loggers/colors.py
+++ /dev/null
@@ -1,65 +0,0 @@
-#  -*- coding: utf-8 -*-
-# *****************************************************************************
-#
-# This program is free software; you can redistribute it and/or modify it under
-# the terms of the GNU General Public License as published by the Free Software
-# Foundation; either version 2 of the License, or (at your option) any later
-# version.
-#
-# This program is distributed in the hope that it will be useful, but WITHOUT
-# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
-# FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
-# details.
-#
-# You should have received a copy of the GNU General Public License along with
-# this program; if not, write to the Free Software Foundation, Inc.,
-# 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
-#
-# Module authors:
-#   Alexander Lenz <alexander.lenz@posteo.de>
-#   Georg Brandl <georg@python.org>
-#
-# *****************************************************************************
-"""Console coloring handlers."""
-
-_codes = {}
-
-_attrs = {
-    'reset': '39;49;00m',
-    'bold': '01m',
-    'faint': '02m',
-    'standout': '03m',
-    'underline': '04m',
-    'blink': '05m',
-}
-
-for _name, _value in _attrs.items():
-    _codes[_name] = '\x1b[' + _value
-
-_colors = [
-    ('black', 'darkgray'),
-    ('darkred', 'red'),
-    ('darkgreen', 'green'),
-    ('brown', 'yellow'),
-    ('darkblue', 'blue'),
-    ('purple', 'fuchsia'),
-    ('turquoise', 'teal'),
-    ('lightgray', 'white'),
-]
-
-for _i, (_dark, _light) in enumerate(_colors):
-    _codes[_dark] = '\x1b[%im' % (_i + 30)
-    _codes[_light] = '\x1b[%i;01m' % (_i + 30)
-
-
-def colorize(name, text):
-    return _codes.get(name, '') + text + _codes.get('reset', '')
-
-
-def colorcode(name):
-    return _codes.get(name, '')
-
-
-def nocolor():
-    for key in list(_codes):
-        _codes[key] = ''
diff --git a/secop/server.py b/secop/server.py
index 703ba21..40e48df 100644
--- a/secop/server.py
+++ b/secop/server.py
@@ -30,7 +30,6 @@ import ConfigParser
 from daemon import DaemonContext
 from daemon.pidfile import TimeoutPIDLockFile
 
-import loggers
 from secop.lib import get_class
 from secop.protocol.dispatcher import Dispatcher
 from secop.protocol.interface import INTERFACES
@@ -44,8 +43,6 @@ class Server(object):
         self._name = name
         self._workdir = workdir
 
-        if parentLogger is None:
-            parentLogger = loggers.log
         self.log = parentLogger.getChild(name, True)
 
         self._pidfile = os.path.join(workdir, 'pid', name + '.pid')