From 2e0062555fd0a092e0f9f25ac46d189b44805108 Mon Sep 17 00:00:00 2001 From: Ivan Alejandro Date: Thu, 5 Jun 2014 15:21:18 -0300 Subject: Reorder logging helpers and handlers. --- src/leap/bitmask/app.py | 105 ++-------------- src/leap/bitmask/backend_app.py | 0 src/leap/bitmask/frontend_app.py | 0 src/leap/bitmask/gui/loggerwindow.py | 2 +- src/leap/bitmask/gui/mainwindow.py | 2 +- src/leap/bitmask/logs/__init__.py | 3 + src/leap/bitmask/logs/leap_log_handler.py | 137 +++++++++++++++++++++ src/leap/bitmask/logs/log_silencer.py | 93 ++++++++++++++ src/leap/bitmask/logs/streamtologger.py | 59 +++++++++ .../bitmask/logs/tests/test_leap_log_handler.py | 120 ++++++++++++++++++ src/leap/bitmask/logs/tests/test_streamtologger.py | 126 +++++++++++++++++++ src/leap/bitmask/logs/utils.py | 92 ++++++++++++++ src/leap/bitmask/util/__init__.py | 5 - src/leap/bitmask/util/leap_log_handler.py | 137 --------------------- src/leap/bitmask/util/log_silencer.py | 93 -------------- src/leap/bitmask/util/streamtologger.py | 59 --------- .../bitmask/util/tests/test_leap_log_handler.py | 120 ------------------ src/leap/bitmask/util/tests/test_streamtologger.py | 126 ------------------- 18 files changed, 641 insertions(+), 638 deletions(-) create mode 100644 src/leap/bitmask/backend_app.py create mode 100644 src/leap/bitmask/frontend_app.py create mode 100644 src/leap/bitmask/logs/__init__.py create mode 100644 src/leap/bitmask/logs/leap_log_handler.py create mode 100644 src/leap/bitmask/logs/log_silencer.py create mode 100644 src/leap/bitmask/logs/streamtologger.py create mode 100644 src/leap/bitmask/logs/tests/test_leap_log_handler.py create mode 100644 src/leap/bitmask/logs/tests/test_streamtologger.py create mode 100644 src/leap/bitmask/logs/utils.py delete mode 100644 src/leap/bitmask/util/leap_log_handler.py delete mode 100644 src/leap/bitmask/util/log_silencer.py delete mode 100644 src/leap/bitmask/util/streamtologger.py delete mode 100644 src/leap/bitmask/util/tests/test_leap_log_handler.py delete mode 100644 src/leap/bitmask/util/tests/test_streamtologger.py diff --git a/src/leap/bitmask/app.py b/src/leap/bitmask/app.py index 05f81f0b..e965604a 100644 --- a/src/leap/bitmask/app.py +++ b/src/leap/bitmask/app.py @@ -39,7 +39,6 @@ # M:::::::::::~NMMM7???7MMMM:::::::::::::::::::::::NMMMI??I7MMMM:::::::::::::M # M::::::::::::::7MMMMMMM+:::::::::::::::::::::::::::?MMMMMMMZ:::::::::::::::M # (thanks to: http://www.glassgiant.com/ascii/) -import logging import signal import sys import os @@ -50,10 +49,7 @@ from PySide import QtCore, QtGui from leap.bitmask import __version__ as VERSION from leap.bitmask.util import leap_argparse -from leap.bitmask.util import log_silencer, LOG_FORMAT -from leap.bitmask.util.leap_log_handler import LeapLogHandler -from leap.bitmask.util.streamtologger import StreamToLogger -from leap.bitmask.platform_init import IS_WIN +from leap.bitmask.logs.utils import get_logger from leap.bitmask.services.mail import plumber from leap.common.events import server as event_server from leap.mail import __version__ as MAIL_VERSION @@ -89,90 +85,6 @@ def sigterm_handler(*args, **kwargs): mainwindow.quit() -def add_logger_handlers(debug=False, logfile=None, replace_stdout=True): - """ - Create the logger and attach the handlers. - - :param debug: the level of the messages that we should log - :type debug: bool - :param logfile: the file name of where we should to save the logs - :type logfile: str - :return: the new logger with the attached handlers. - :rtype: logging.Logger - """ - # TODO: get severity from command line args - if debug: - level = logging.DEBUG - else: - level = logging.WARNING - - # Create logger and formatter - logger = logging.getLogger(name='leap') - logger.setLevel(level) - formatter = logging.Formatter(LOG_FORMAT) - - # Console handler - try: - import coloredlogs - console = coloredlogs.ColoredStreamHandler(level=level) - except ImportError: - console = logging.StreamHandler() - console.setLevel(level) - console.setFormatter(formatter) - using_coloredlog = False - else: - using_coloredlog = True - - if using_coloredlog: - replace_stdout = False - - silencer = log_silencer.SelectiveSilencerFilter() - console.addFilter(silencer) - logger.addHandler(console) - logger.debug('Console handler plugged!') - - # LEAP custom handler - leap_handler = LeapLogHandler() - leap_handler.setLevel(level) - leap_handler.addFilter(silencer) - logger.addHandler(leap_handler) - logger.debug('Leap handler plugged!') - - # File handler - if logfile is not None: - logger.debug('Setting logfile to %s ', logfile) - fileh = logging.FileHandler(logfile) - fileh.setLevel(logging.DEBUG) - fileh.setFormatter(formatter) - fileh.addFilter(silencer) - logger.addHandler(fileh) - logger.debug('File handler plugged!') - - if replace_stdout: - replace_stdout_stderr_with_logging(logger) - - return logger - - -def replace_stdout_stderr_with_logging(logger): - """ - Replace: - - the standard output - - the standard error - - the twisted log output - with a custom one that writes to the logger. - """ - # Disabling this on windows since it breaks ALL THE THINGS - # The issue for this is #4149 - if not IS_WIN: - sys.stdout = StreamToLogger(logger, logging.DEBUG) - sys.stderr = StreamToLogger(logger, logging.ERROR) - - # Replace twisted's logger to use our custom output. - from twisted.python import log - log.startLogging(sys.stdout) - - def do_display_version(opts): """ Display version and exit. @@ -214,6 +126,14 @@ def main(): mail_logfile = opts.mail_log_file start_hidden = opts.start_hidden + replace_stdout = True + if opts.repair or opts.import_maildir: + # We don't want too much clutter on the comand mode + # this could be more generic with a Command class. + replace_stdout = False + + logger = get_logger(debug, logfile, replace_stdout) + ############################################################# # Given how paths and bundling works, we need to delay the imports # of certain parts that depend on this path settings. @@ -232,13 +152,6 @@ def main(): BaseConfig.standalone = standalone - replace_stdout = True - if opts.repair or opts.import_maildir: - # We don't want too much clutter on the comand mode - # this could be more generic with a Command class. - replace_stdout = False - logger = add_logger_handlers(debug, logfile, replace_stdout) - # ok, we got logging in place, we can satisfy mail plumbing requests # and show logs there. it normally will exit there if we got that path. do_mail_plumbing(opts) diff --git a/src/leap/bitmask/backend_app.py b/src/leap/bitmask/backend_app.py new file mode 100644 index 00000000..e69de29b diff --git a/src/leap/bitmask/frontend_app.py b/src/leap/bitmask/frontend_app.py new file mode 100644 index 00000000..e69de29b diff --git a/src/leap/bitmask/gui/loggerwindow.py b/src/leap/bitmask/gui/loggerwindow.py index f19b172f..3a8354b1 100644 --- a/src/leap/bitmask/gui/loggerwindow.py +++ b/src/leap/bitmask/gui/loggerwindow.py @@ -27,7 +27,7 @@ from twisted.internet import threads from ui_loggerwindow import Ui_LoggerWindow from leap.bitmask.util.constants import PASTEBIN_API_DEV_KEY -from leap.bitmask.util.leap_log_handler import LeapLogHandler +from leap.bitmask.logs.leap_log_handler import LeapLogHandler from leap.bitmask.util import pastebin from leap.common.check import leap_assert, leap_assert_type diff --git a/src/leap/bitmask/gui/mainwindow.py b/src/leap/bitmask/gui/mainwindow.py index a3b81fde..c61b7dc9 100644 --- a/src/leap/bitmask/gui/mainwindow.py +++ b/src/leap/bitmask/gui/mainwindow.py @@ -52,7 +52,7 @@ from leap.bitmask.services import EIP_SERVICE, MX_SERVICE from leap.bitmask.util import make_address from leap.bitmask.util.keyring_helpers import has_keyring -from leap.bitmask.util.leap_log_handler import LeapLogHandler +from leap.bitmask.logs.leap_log_handler import LeapLogHandler if IS_WIN: from leap.bitmask.platform_init.locks import WindowsLock diff --git a/src/leap/bitmask/logs/__init__.py b/src/leap/bitmask/logs/__init__.py new file mode 100644 index 00000000..0516b304 --- /dev/null +++ b/src/leap/bitmask/logs/__init__.py @@ -0,0 +1,3 @@ +# levelname length == 8, since 'CRITICAL' is the longest +LOG_FORMAT = ('%(asctime)s - %(levelname)-8s - ' + 'L#%(lineno)-4s : %(name)s:%(funcName)s() - %(message)s') diff --git a/src/leap/bitmask/logs/leap_log_handler.py b/src/leap/bitmask/logs/leap_log_handler.py new file mode 100644 index 00000000..24141638 --- /dev/null +++ b/src/leap/bitmask/logs/leap_log_handler.py @@ -0,0 +1,137 @@ +# -*- coding: utf-8 -*- +# leap_log_handler.py +# Copyright (C) 2013 LEAP +# +# 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 3 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, see . +""" +Custom handler for the logger window. +""" +import logging + +from PySide import QtCore + +from leap.bitmask.logs import LOG_FORMAT + + +class LogHandler(logging.Handler): + """ + This is the custom handler that implements our desired formatting + and also keeps a history of all the logged events. + """ + + MESSAGE_KEY = 'message' + RECORD_KEY = 'record' + + def __init__(self, qtsignal): + """ + LogHander initialization. + Calls parent method and keeps a reference to the qtsignal + that will be used to fire the gui update. + """ + # TODO This is going to eat lots of memory after some time. + # Should be pruned at some moment. + self._log_history = [] + + logging.Handler.__init__(self) + self._qtsignal = qtsignal + + def _get_format(self, logging_level): + """ + Sets the log format depending on the parameter. + It uses html and css to set the colors for the logs. + + :param logging_level: the debug level to define the color. + :type logging_level: str. + """ + formatter = logging.Formatter(LOG_FORMAT) + return formatter + + def emit(self, logRecord): + """ + This method is fired every time that a record is logged by the + logging module. + This method reimplements logging.Handler.emit that is fired + in every logged message. + + :param logRecord: the record emitted by the logging module. + :type logRecord: logging.LogRecord. + """ + self.setFormatter(self._get_format(logRecord.levelname)) + log = self.format(logRecord) + log_item = {self.RECORD_KEY: logRecord, self.MESSAGE_KEY: log} + self._log_history.append(log_item) + self._qtsignal(log_item) + + +class HandlerAdapter(object): + """ + New style class that accesses all attributes from the LogHandler. + + Used as a workaround for a problem with multiple inheritance with Pyside + that surfaced under OSX with pyside 1.1.0. + """ + MESSAGE_KEY = 'message' + RECORD_KEY = 'record' + + def __init__(self, qtsignal): + self._handler = LogHandler(qtsignal=qtsignal) + + def setLevel(self, *args, **kwargs): + return self._handler.setLevel(*args, **kwargs) + + def addFilter(self, *args, **kwargs): + return self._handler.addFilter(*args, **kwargs) + + def handle(self, *args, **kwargs): + return self._handler.handle(*args, **kwargs) + + @property + def level(self): + return self._handler.level + + +class LeapLogHandler(QtCore.QObject, HandlerAdapter): + """ + Custom logging handler. It emits Qt signals so it can be plugged to a gui. + + Its inner handler also stores an history of logs that can be fetched after + having been connected to a gui. + """ + # All dicts returned are of the form + # {'record': LogRecord, 'message': str} + new_log = QtCore.Signal(dict) + + def __init__(self): + """ + LeapLogHandler initialization. + Initializes parent classes. + """ + QtCore.QObject.__init__(self) + HandlerAdapter.__init__(self, qtsignal=self.qtsignal) + + def qtsignal(self, log_item): + # WARNING: the new-style connection does NOT work because PySide + # translates the emit method to self.emit, and that collides with + # the emit method for logging.Handler + # self.new_log.emit(log_item) + QtCore.QObject.emit( + self, + QtCore.SIGNAL('new_log(PyObject)'), log_item) + + @property + def log_history(self): + """ + Returns the history of the logged messages. + """ + return self._handler._log_history diff --git a/src/leap/bitmask/logs/log_silencer.py b/src/leap/bitmask/logs/log_silencer.py new file mode 100644 index 00000000..56b290e4 --- /dev/null +++ b/src/leap/bitmask/logs/log_silencer.py @@ -0,0 +1,93 @@ +# -*- coding: utf-8 -*- +# log_silencer.py +# Copyright (C) 2013 LEAP +# +# 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 3 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, see . +""" +Filter for leap logs. +""" +import logging +import os +import re + +from leap.bitmask.util import get_path_prefix + + +class SelectiveSilencerFilter(logging.Filter): + """ + Configurable filter for root leap logger. + + If you want to ignore components from the logging, just add them, + one by line, to ~/.config/leap/leap.dev.conf + """ + # TODO we can augment this by properly parsing the log-silencer file + # and having different sections: ignore, levels, ... + + # TODO use ConfigParser to unify sections [log-ignore] [log-debug] etc + + CONFIG_NAME = "leap.dev.conf" + + # Components to be completely silenced in the main bitmask logs. + # You probably should think twice before adding a component to + # the tuple below. Only very well tested components should go here, and + # only in those cases in which we gain more from silencing them than from + # having their logs into the main log file that the user will likely send + # to us. + SILENCER_RULES = ( + 'leap.common.events', + 'leap.common.decorators', + ) + + def __init__(self): + """ + Tries to load silencer rules from the default path, + or load from the SILENCER_RULES tuple if not found. + """ + self.rules = None + if os.path.isfile(self._rules_path): + self.rules = self._load_rules() + if not self.rules: + self.rules = self.SILENCER_RULES + + @property + def _rules_path(self): + """ + The configuration file for custom ignore rules. + """ + return os.path.join(get_path_prefix(), "leap", self.CONFIG_NAME) + + def _load_rules(self): + """ + Loads a list of paths to be ignored from the logging. + """ + lines = open(self._rules_path).readlines() + return map(lambda line: re.sub('\s', '', line), + lines) + + def filter(self, record): + """ + Implements the filter functionality for this Filter + + :param record: the record to be examined + :type record: logging.LogRecord + :returns: a bool indicating whether the record should be logged or not. + :rtype: bool + """ + if not self.rules: + return True + logger_path = record.name + for path in self.rules: + if logger_path.startswith(path): + return False + return True diff --git a/src/leap/bitmask/logs/streamtologger.py b/src/leap/bitmask/logs/streamtologger.py new file mode 100644 index 00000000..25a06718 --- /dev/null +++ b/src/leap/bitmask/logs/streamtologger.py @@ -0,0 +1,59 @@ +# -*- coding: utf-8 -*- +# streamtologger.py +# Copyright (C) 2013 LEAP +# +# 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 3 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, see . +""" +Stream object that redirects writes to a logger instance. +""" +import logging + + +class StreamToLogger(object): + """ + Fake file-like stream object that redirects writes to a logger instance. + + Credits to: + http://www.electricmonk.nl/log/2011/08/14/\ + redirect-stdout-and-stderr-to-a-logger-in-python/ + """ + def __init__(self, logger, log_level=logging.INFO): + """ + Constructor, defines the logger and level to use to log messages. + + :param logger: logger object to log messages. + :type logger: logging.Handler + :param log_level: the level to use to log messages through the logger. + :type log_level: int + look at logging-levels in 'logging' docs. + """ + self._logger = logger + self._log_level = log_level + + def write(self, data): + """ + Simulates the 'write' method in a file object. + It writes the data receibed in buf to the logger 'self._logger'. + + :param data: data to write to the 'file' + :type data: str + """ + for line in data.rstrip().splitlines(): + self._logger.log(self._log_level, line.rstrip()) + + def flush(self): + """ + Dummy method. Needed to replace the twisted.log output. + """ + pass diff --git a/src/leap/bitmask/logs/tests/test_leap_log_handler.py b/src/leap/bitmask/logs/tests/test_leap_log_handler.py new file mode 100644 index 00000000..20b09aef --- /dev/null +++ b/src/leap/bitmask/logs/tests/test_leap_log_handler.py @@ -0,0 +1,120 @@ +# -*- coding: utf-8 -*- +# test_leap_log_handler.py +# Copyright (C) 2013 LEAP +# +# 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 3 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, see . +""" +tests for leap_log_handler +""" +try: + import unittest2 as unittest +except ImportError: + import unittest + +import logging + +from leap.bitmask.logs.leap_log_handler import LeapLogHandler +from leap.bitmask.util.pyside_tests_helper import BasicPySlotCase +from leap.common.testing.basetest import BaseLeapTest + +from mock import Mock + + +class LeapLogHandlerTest(BaseLeapTest, BasicPySlotCase): + """ + LeapLogHandlerTest's tests. + """ + def _callback(self, *args): + """ + Simple callback to track if a signal was emitted. + """ + self.called = True + self.emitted_msg = args[0][LeapLogHandler.MESSAGE_KEY] + + def setUp(self): + BasicPySlotCase.setUp(self) + + # Create the logger + level = logging.DEBUG + self.logger = logging.getLogger(name='test') + self.logger.setLevel(level) + + # Create the handler + self.leap_handler = LeapLogHandler() + self.leap_handler.setLevel(level) + self.logger.addHandler(self.leap_handler) + + def tearDown(self): + BasicPySlotCase.tearDown(self) + try: + self.leap_handler.new_log.disconnect() + except Exception: + pass + + def test_history_starts_empty(self): + self.assertEqual(self.leap_handler.log_history, []) + + def test_one_log_captured(self): + self.logger.debug('test') + self.assertEqual(len(self.leap_handler.log_history), 1) + + def test_history_records_order(self): + self.logger.debug('test 01') + self.logger.debug('test 02') + self.logger.debug('test 03') + + logs = [] + for message in self.leap_handler.log_history: + logs.append(message[LeapLogHandler.RECORD_KEY].msg) + + self.assertIn('test 01', logs) + self.assertIn('test 02', logs) + self.assertIn('test 03', logs) + + def test_history_messages_order(self): + self.logger.debug('test 01') + self.logger.debug('test 02') + self.logger.debug('test 03') + + logs = [] + for message in self.leap_handler.log_history: + logs.append(message[LeapLogHandler.MESSAGE_KEY]) + + self.assertIn('test 01', logs[0]) + self.assertIn('test 02', logs[1]) + self.assertIn('test 03', logs[2]) + + def test_emits_signal(self): + log_format = '%(name)s - %(levelname)s - %(message)s' + formatter = logging.Formatter(log_format) + get_format = Mock(return_value=formatter) + self.leap_handler._handler._get_format = get_format + + self.leap_handler.new_log.connect(self._callback) + self.logger.debug('test') + + expected_log_msg = "test - DEBUG - test" + + # signal emitted + self.assertTrue(self.called) + + # emitted message + self.assertEqual(self.emitted_msg, expected_log_msg) + + # Mock called + self.assertTrue(get_format.called) + + +if __name__ == "__main__": + unittest.main() diff --git a/src/leap/bitmask/logs/tests/test_streamtologger.py b/src/leap/bitmask/logs/tests/test_streamtologger.py new file mode 100644 index 00000000..9bbadde8 --- /dev/null +++ b/src/leap/bitmask/logs/tests/test_streamtologger.py @@ -0,0 +1,126 @@ +# -*- coding: utf-8 -*- +# test_streamtologger.py +# Copyright (C) 2013 LEAP +# +# 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 3 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, see . +""" +tests for streamtologger +""" + +try: + import unittest2 as unittest +except ImportError: + import unittest + +import logging +import sys + +from leap.bitmask.logs.streamtologger import StreamToLogger +from leap.common.testing.basetest import BaseLeapTest + + +class SimpleLogHandler(logging.Handler): + """ + The simplest log handler that allows to check if the log was + delivered to the handler correctly. + """ + def __init__(self): + logging.Handler.__init__(self) + self._last_log = "" + self._last_log_level = "" + + def emit(self, record): + self._last_log = record.getMessage() + self._last_log_level = record.levelno + + def get_last_log(self): + """ + Returns the last logged message by this handler. + + :return: the last logged message. + :rtype: str + """ + return self._last_log + + def get_last_log_level(self): + """ + Returns the level of the last logged message by this handler. + + :return: the last logged level. + :rtype: str + """ + return self._last_log_level + + +class StreamToLoggerTest(BaseLeapTest): + """ + StreamToLogger's tests. + + NOTE: we may need to find a way to test the use case that an exception + is raised. I couldn't catch the output of an exception because the + test failed if some exception is raised. + """ + def setUp(self): + # Create the logger + level = logging.DEBUG + self.logger = logging.getLogger(name='test') + self.logger.setLevel(level) + + # Simple log handler + self.handler = SimpleLogHandler() + self.logger.addHandler(self.handler) + + # Preserve original values + self._sys_stdout = sys.stdout + self._sys_stderr = sys.stderr + + # Create the handler + sys.stdout = StreamToLogger(self.logger, logging.DEBUG) + sys.stderr = StreamToLogger(self.logger, logging.ERROR) + + def tearDown(self): + # Restore original values + sys.stdout = self._sys_stdout + sys.stderr = self._sys_stderr + + def test_logger_starts_empty(self): + self.assertEqual(self.handler.get_last_log(), '') + + def test_standard_output(self): + message = 'Test string' + print message + + log = self.handler.get_last_log() + log_level = self.handler.get_last_log_level() + + self.assertEqual(log, message) + self.assertEqual(log_level, logging.DEBUG) + + def test_standard_error(self): + message = 'Test string' + sys.stderr.write(message) + + log_level = self.handler.get_last_log_level() + log = self.handler.get_last_log() + + self.assertEqual(log, message) + self.assertEqual(log_level, logging.ERROR) + + def test_twisted_log(self): + from twisted.python import log + log.startLogging(sys.stdout) + + +if __name__ == "__main__": + unittest.main(verbosity=2) diff --git a/src/leap/bitmask/logs/utils.py b/src/leap/bitmask/logs/utils.py new file mode 100644 index 00000000..06959c45 --- /dev/null +++ b/src/leap/bitmask/logs/utils.py @@ -0,0 +1,92 @@ +import logging +import sys + +from leap.bitmask.logs import LOG_FORMAT +from leap.bitmask.logs.log_silencer import SelectiveSilencerFilter +from leap.bitmask.logs.leap_log_handler import LeapLogHandler +from leap.bitmask.logs.streamtologger import StreamToLogger +from leap.bitmask.platform_init import IS_WIN + + +def get_logger(debug=False, logfile=None, replace_stdout=True): + """ + Create the logger and attach the handlers. + + :param debug: the level of the messages that we should log + :type debug: bool + :param logfile: the file name of where we should to save the logs + :type logfile: str + :return: the new logger with the attached handlers. + :rtype: logging.Logger + """ + # TODO: get severity from command line args + if debug: + level = logging.DEBUG + else: + level = logging.WARNING + + # Create logger and formatter + logger = logging.getLogger(name='leap') + logger.setLevel(level) + formatter = logging.Formatter(LOG_FORMAT) + + # Console handler + try: + import coloredlogs + console = coloredlogs.ColoredStreamHandler(level=level) + except ImportError: + console = logging.StreamHandler() + console.setLevel(level) + console.setFormatter(formatter) + using_coloredlog = False + else: + using_coloredlog = True + + if using_coloredlog: + replace_stdout = False + + silencer = SelectiveSilencerFilter() + console.addFilter(silencer) + logger.addHandler(console) + logger.debug('Console handler plugged!') + + # LEAP custom handler + leap_handler = LeapLogHandler() + leap_handler.setLevel(level) + leap_handler.addFilter(silencer) + logger.addHandler(leap_handler) + logger.debug('Leap handler plugged!') + + # File handler + if logfile is not None: + logger.debug('Setting logfile to %s ', logfile) + fileh = logging.FileHandler(logfile) + fileh.setLevel(logging.DEBUG) + fileh.setFormatter(formatter) + fileh.addFilter(silencer) + logger.addHandler(fileh) + logger.debug('File handler plugged!') + + if replace_stdout: + replace_stdout_stderr_with_logging(logger) + + return logger + + +def replace_stdout_stderr_with_logging(logger): + """ + Replace: + - the standard output + - the standard error + - the twisted log output + with a custom one that writes to the logger. + """ + # Disabling this on windows since it breaks ALL THE THINGS + # The issue for this is #4149 + if not IS_WIN: + sys.stdout = StreamToLogger(logger, logging.DEBUG) + sys.stderr = StreamToLogger(logger, logging.ERROR) + + # Replace twisted's logger to use our custom output. + from twisted.python import log + log.startLogging(sys.stdout) diff --git a/src/leap/bitmask/util/__init__.py b/src/leap/bitmask/util/__init__.py index 2b2cd874..c35be99e 100644 --- a/src/leap/bitmask/util/__init__.py +++ b/src/leap/bitmask/util/__init__.py @@ -28,11 +28,6 @@ from leap.common.config import get_path_prefix as common_get_path_prefix # We'll give your money back if it does not alleviate the eye strain, at least. -# levelname length == 8, since 'CRITICAL' is the longest -LOG_FORMAT = ('%(asctime)s - %(levelname)-8s - ' - 'L#%(lineno)-4s : %(name)s:%(funcName)s() - %(message)s') - - def first(things): """ Return the head of a collection. diff --git a/src/leap/bitmask/util/leap_log_handler.py b/src/leap/bitmask/util/leap_log_handler.py deleted file mode 100644 index 807e53d4..00000000 --- a/src/leap/bitmask/util/leap_log_handler.py +++ /dev/null @@ -1,137 +0,0 @@ -# -*- coding: utf-8 -*- -# leap_log_handler.py -# Copyright (C) 2013 LEAP -# -# 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 3 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, see . -""" -Custom handler for the logger window. -""" -import logging - -from PySide import QtCore - -from leap.bitmask.util import LOG_FORMAT - - -class LogHandler(logging.Handler): - """ - This is the custom handler that implements our desired formatting - and also keeps a history of all the logged events. - """ - - MESSAGE_KEY = 'message' - RECORD_KEY = 'record' - - def __init__(self, qtsignal): - """ - LogHander initialization. - Calls parent method and keeps a reference to the qtsignal - that will be used to fire the gui update. - """ - # TODO This is going to eat lots of memory after some time. - # Should be pruned at some moment. - self._log_history = [] - - logging.Handler.__init__(self) - self._qtsignal = qtsignal - - def _get_format(self, logging_level): - """ - Sets the log format depending on the parameter. - It uses html and css to set the colors for the logs. - - :param logging_level: the debug level to define the color. - :type logging_level: str. - """ - formatter = logging.Formatter(LOG_FORMAT) - return formatter - - def emit(self, logRecord): - """ - This method is fired every time that a record is logged by the - logging module. - This method reimplements logging.Handler.emit that is fired - in every logged message. - - :param logRecord: the record emitted by the logging module. - :type logRecord: logging.LogRecord. - """ - self.setFormatter(self._get_format(logRecord.levelname)) - log = self.format(logRecord) - log_item = {self.RECORD_KEY: logRecord, self.MESSAGE_KEY: log} - self._log_history.append(log_item) - self._qtsignal(log_item) - - -class HandlerAdapter(object): - """ - New style class that accesses all attributes from the LogHandler. - - Used as a workaround for a problem with multiple inheritance with Pyside - that surfaced under OSX with pyside 1.1.0. - """ - MESSAGE_KEY = 'message' - RECORD_KEY = 'record' - - def __init__(self, qtsignal): - self._handler = LogHandler(qtsignal=qtsignal) - - def setLevel(self, *args, **kwargs): - return self._handler.setLevel(*args, **kwargs) - - def addFilter(self, *args, **kwargs): - return self._handler.addFilter(*args, **kwargs) - - def handle(self, *args, **kwargs): - return self._handler.handle(*args, **kwargs) - - @property - def level(self): - return self._handler.level - - -class LeapLogHandler(QtCore.QObject, HandlerAdapter): - """ - Custom logging handler. It emits Qt signals so it can be plugged to a gui. - - Its inner handler also stores an history of logs that can be fetched after - having been connected to a gui. - """ - # All dicts returned are of the form - # {'record': LogRecord, 'message': str} - new_log = QtCore.Signal(dict) - - def __init__(self): - """ - LeapLogHandler initialization. - Initializes parent classes. - """ - QtCore.QObject.__init__(self) - HandlerAdapter.__init__(self, qtsignal=self.qtsignal) - - def qtsignal(self, log_item): - # WARNING: the new-style connection does NOT work because PySide - # translates the emit method to self.emit, and that collides with - # the emit method for logging.Handler - # self.new_log.emit(log_item) - QtCore.QObject.emit( - self, - QtCore.SIGNAL('new_log(PyObject)'), log_item) - - @property - def log_history(self): - """ - Returns the history of the logged messages. - """ - return self._handler._log_history diff --git a/src/leap/bitmask/util/log_silencer.py b/src/leap/bitmask/util/log_silencer.py deleted file mode 100644 index 56b290e4..00000000 --- a/src/leap/bitmask/util/log_silencer.py +++ /dev/null @@ -1,93 +0,0 @@ -# -*- coding: utf-8 -*- -# log_silencer.py -# Copyright (C) 2013 LEAP -# -# 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 3 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, see . -""" -Filter for leap logs. -""" -import logging -import os -import re - -from leap.bitmask.util import get_path_prefix - - -class SelectiveSilencerFilter(logging.Filter): - """ - Configurable filter for root leap logger. - - If you want to ignore components from the logging, just add them, - one by line, to ~/.config/leap/leap.dev.conf - """ - # TODO we can augment this by properly parsing the log-silencer file - # and having different sections: ignore, levels, ... - - # TODO use ConfigParser to unify sections [log-ignore] [log-debug] etc - - CONFIG_NAME = "leap.dev.conf" - - # Components to be completely silenced in the main bitmask logs. - # You probably should think twice before adding a component to - # the tuple below. Only very well tested components should go here, and - # only in those cases in which we gain more from silencing them than from - # having their logs into the main log file that the user will likely send - # to us. - SILENCER_RULES = ( - 'leap.common.events', - 'leap.common.decorators', - ) - - def __init__(self): - """ - Tries to load silencer rules from the default path, - or load from the SILENCER_RULES tuple if not found. - """ - self.rules = None - if os.path.isfile(self._rules_path): - self.rules = self._load_rules() - if not self.rules: - self.rules = self.SILENCER_RULES - - @property - def _rules_path(self): - """ - The configuration file for custom ignore rules. - """ - return os.path.join(get_path_prefix(), "leap", self.CONFIG_NAME) - - def _load_rules(self): - """ - Loads a list of paths to be ignored from the logging. - """ - lines = open(self._rules_path).readlines() - return map(lambda line: re.sub('\s', '', line), - lines) - - def filter(self, record): - """ - Implements the filter functionality for this Filter - - :param record: the record to be examined - :type record: logging.LogRecord - :returns: a bool indicating whether the record should be logged or not. - :rtype: bool - """ - if not self.rules: - return True - logger_path = record.name - for path in self.rules: - if logger_path.startswith(path): - return False - return True diff --git a/src/leap/bitmask/util/streamtologger.py b/src/leap/bitmask/util/streamtologger.py deleted file mode 100644 index 25a06718..00000000 --- a/src/leap/bitmask/util/streamtologger.py +++ /dev/null @@ -1,59 +0,0 @@ -# -*- coding: utf-8 -*- -# streamtologger.py -# Copyright (C) 2013 LEAP -# -# 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 3 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, see . -""" -Stream object that redirects writes to a logger instance. -""" -import logging - - -class StreamToLogger(object): - """ - Fake file-like stream object that redirects writes to a logger instance. - - Credits to: - http://www.electricmonk.nl/log/2011/08/14/\ - redirect-stdout-and-stderr-to-a-logger-in-python/ - """ - def __init__(self, logger, log_level=logging.INFO): - """ - Constructor, defines the logger and level to use to log messages. - - :param logger: logger object to log messages. - :type logger: logging.Handler - :param log_level: the level to use to log messages through the logger. - :type log_level: int - look at logging-levels in 'logging' docs. - """ - self._logger = logger - self._log_level = log_level - - def write(self, data): - """ - Simulates the 'write' method in a file object. - It writes the data receibed in buf to the logger 'self._logger'. - - :param data: data to write to the 'file' - :type data: str - """ - for line in data.rstrip().splitlines(): - self._logger.log(self._log_level, line.rstrip()) - - def flush(self): - """ - Dummy method. Needed to replace the twisted.log output. - """ - pass diff --git a/src/leap/bitmask/util/tests/test_leap_log_handler.py b/src/leap/bitmask/util/tests/test_leap_log_handler.py deleted file mode 100644 index 518fd35b..00000000 --- a/src/leap/bitmask/util/tests/test_leap_log_handler.py +++ /dev/null @@ -1,120 +0,0 @@ -# -*- coding: utf-8 -*- -# test_leap_log_handler.py -# Copyright (C) 2013 LEAP -# -# 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 3 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, see . -""" -tests for leap_log_handler -""" -try: - import unittest2 as unittest -except ImportError: - import unittest - -import logging - -from leap.bitmask.util.leap_log_handler import LeapLogHandler -from leap.bitmask.util.pyside_tests_helper import BasicPySlotCase -from leap.common.testing.basetest import BaseLeapTest - -from mock import Mock - - -class LeapLogHandlerTest(BaseLeapTest, BasicPySlotCase): - """ - LeapLogHandlerTest's tests. - """ - def _callback(self, *args): - """ - Simple callback to track if a signal was emitted. - """ - self.called = True - self.emitted_msg = args[0][LeapLogHandler.MESSAGE_KEY] - - def setUp(self): - BasicPySlotCase.setUp(self) - - # Create the logger - level = logging.DEBUG - self.logger = logging.getLogger(name='test') - self.logger.setLevel(level) - - # Create the handler - self.leap_handler = LeapLogHandler() - self.leap_handler.setLevel(level) - self.logger.addHandler(self.leap_handler) - - def tearDown(self): - BasicPySlotCase.tearDown(self) - try: - self.leap_handler.new_log.disconnect() - except Exception: - pass - - def test_history_starts_empty(self): - self.assertEqual(self.leap_handler.log_history, []) - - def test_one_log_captured(self): - self.logger.debug('test') - self.assertEqual(len(self.leap_handler.log_history), 1) - - def test_history_records_order(self): - self.logger.debug('test 01') - self.logger.debug('test 02') - self.logger.debug('test 03') - - logs = [] - for message in self.leap_handler.log_history: - logs.append(message[LeapLogHandler.RECORD_KEY].msg) - - self.assertIn('test 01', logs) - self.assertIn('test 02', logs) - self.assertIn('test 03', logs) - - def test_history_messages_order(self): - self.logger.debug('test 01') - self.logger.debug('test 02') - self.logger.debug('test 03') - - logs = [] - for message in self.leap_handler.log_history: - logs.append(message[LeapLogHandler.MESSAGE_KEY]) - - self.assertIn('test 01', logs[0]) - self.assertIn('test 02', logs[1]) - self.assertIn('test 03', logs[2]) - - def test_emits_signal(self): - log_format = '%(name)s - %(levelname)s - %(message)s' - formatter = logging.Formatter(log_format) - get_format = Mock(return_value=formatter) - self.leap_handler._handler._get_format = get_format - - self.leap_handler.new_log.connect(self._callback) - self.logger.debug('test') - - expected_log_msg = "test - DEBUG - test" - - # signal emitted - self.assertTrue(self.called) - - # emitted message - self.assertEqual(self.emitted_msg, expected_log_msg) - - # Mock called - self.assertTrue(get_format.called) - - -if __name__ == "__main__": - unittest.main() diff --git a/src/leap/bitmask/util/tests/test_streamtologger.py b/src/leap/bitmask/util/tests/test_streamtologger.py deleted file mode 100644 index fc97b794..00000000 --- a/src/leap/bitmask/util/tests/test_streamtologger.py +++ /dev/null @@ -1,126 +0,0 @@ -# -*- coding: utf-8 -*- -# test_streamtologger.py -# Copyright (C) 2013 LEAP -# -# 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 3 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, see . -""" -tests for streamtologger -""" - -try: - import unittest2 as unittest -except ImportError: - import unittest - -import logging -import sys - -from leap.bitmask.util.streamtologger import StreamToLogger -from leap.common.testing.basetest import BaseLeapTest - - -class SimpleLogHandler(logging.Handler): - """ - The simplest log handler that allows to check if the log was - delivered to the handler correctly. - """ - def __init__(self): - logging.Handler.__init__(self) - self._last_log = "" - self._last_log_level = "" - - def emit(self, record): - self._last_log = record.getMessage() - self._last_log_level = record.levelno - - def get_last_log(self): - """ - Returns the last logged message by this handler. - - :return: the last logged message. - :rtype: str - """ - return self._last_log - - def get_last_log_level(self): - """ - Returns the level of the last logged message by this handler. - - :return: the last logged level. - :rtype: str - """ - return self._last_log_level - - -class StreamToLoggerTest(BaseLeapTest): - """ - StreamToLogger's tests. - - NOTE: we may need to find a way to test the use case that an exception - is raised. I couldn't catch the output of an exception because the - test failed if some exception is raised. - """ - def setUp(self): - # Create the logger - level = logging.DEBUG - self.logger = logging.getLogger(name='test') - self.logger.setLevel(level) - - # Simple log handler - self.handler = SimpleLogHandler() - self.logger.addHandler(self.handler) - - # Preserve original values - self._sys_stdout = sys.stdout - self._sys_stderr = sys.stderr - - # Create the handler - sys.stdout = StreamToLogger(self.logger, logging.DEBUG) - sys.stderr = StreamToLogger(self.logger, logging.ERROR) - - def tearDown(self): - # Restore original values - sys.stdout = self._sys_stdout - sys.stderr = self._sys_stderr - - def test_logger_starts_empty(self): - self.assertEqual(self.handler.get_last_log(), '') - - def test_standard_output(self): - message = 'Test string' - print message - - log = self.handler.get_last_log() - log_level = self.handler.get_last_log_level() - - self.assertEqual(log, message) - self.assertEqual(log_level, logging.DEBUG) - - def test_standard_error(self): - message = 'Test string' - sys.stderr.write(message) - - log_level = self.handler.get_last_log_level() - log = self.handler.get_last_log() - - self.assertEqual(log, message) - self.assertEqual(log_level, logging.ERROR) - - def test_twisted_log(self): - from twisted.python import log - log.startLogging(sys.stdout) - - -if __name__ == "__main__": - unittest.main(verbosity=2) -- cgit v1.2.3