From b6fa9a44267d5cf292a81d2c0b98e0f5f13141f6 Mon Sep 17 00:00:00 2001 From: Michael Hanselmann Date: Mon, 31 Jan 2011 13:52:39 +0100 Subject: [PATCH] Introduce re-openable log record handler This patch adds a new log handler class based on the standard library's BaseRotatingHandler. This new class allows the log file to be re-opened, e.g. upon receiving a SIGHUP signal. The latter will be implemented in forthcoming patches. The patch does not change the behaviour regarding writing to /dev/console. Quite a bit of code had to be changed to unittest the log handlers. Signed-off-by: Michael Hanselmann Reviewed-by: Iustin Pop --- Makefile.am | 1 + lib/utils/log.py | 110 +++++++++++++++++++----- test/ganeti.utils.log_unittest.py | 137 ++++++++++++++++++++++++++++++ 3 files changed, 227 insertions(+), 21 deletions(-) create mode 100755 test/ganeti.utils.log_unittest.py diff --git a/Makefile.am b/Makefile.am index 226135a12..baf8d93ed 100644 --- a/Makefile.am +++ b/Makefile.am @@ -504,6 +504,7 @@ python_tests = \ test/ganeti.utils.filelock_unittest.py \ test/ganeti.utils.hash_unittest.py \ test/ganeti.utils.io_unittest.py \ + test/ganeti.utils.log_unittest.py \ test/ganeti.utils.mlock_unittest.py \ test/ganeti.utils.nodesetup_unittest.py \ test/ganeti.utils.process_unittest.py \ diff --git a/lib/utils/log.py b/lib/utils/log.py index 58fc8e41e..829e7438f 100644 --- a/lib/utils/log.py +++ b/lib/utils/log.py @@ -28,38 +28,105 @@ import logging.handlers from ganeti import constants -class LogFileHandler(logging.FileHandler): - """Log handler that doesn't fallback to stderr. +class _ReopenableLogHandler(logging.handlers.BaseRotatingHandler): + """Log handler with ability to reopen log file on request. - When an error occurs while writing on the logfile, logging.FileHandler tries - to log on stderr. This doesn't work in ganeti since stderr is redirected to - the logfile. This class avoids failures reporting errors to /dev/console. + In combination with a SIGHUP handler this class can reopen the log file on + user request. """ - def __init__(self, filename, mode="a", encoding=None): - """Open the specified file and use it as the stream for logging. + def __init__(self, filename): + """Initializes this class. - Also open /dev/console to report errors while logging. + @type filename: string + @param filename: Path to logfile """ - logging.FileHandler.__init__(self, filename, mode, encoding) - self.console = open(constants.DEV_CONSOLE, "a") + logging.handlers.BaseRotatingHandler.__init__(self, filename, "a") - def handleError(self, record): # pylint: disable-msg=C0103 - """Handle errors which occur during an emit() call. + assert self.encoding is None, "Encoding not supported for logging" + assert not hasattr(self, "_reopen"), "Base class has '_reopen' attribute" - Try to handle errors with FileHandler method, if it fails write to + self._reopen = False + + def shouldRollover(self, _): # pylint: disable-msg=C0103 + """Determine whether log file should be reopened. + + """ + return self._reopen or not self.stream + + def doRollover(self): # pylint: disable-msg=C0103 + """Reopens the log file. + + """ + if self.stream: + self.stream.flush() + self.stream.close() + self.stream = None + + # Reopen file + # TODO: Handle errors? + self.stream = open(self.baseFilename, "a") + + def RequestReopen(self): + """Register a request to reopen the file. + + The file will be reopened before writing the next log record. + + """ + self._reopen = True + + +def _LogErrorsToConsole(base): + """Create wrapper class writing errors to console. + + This needs to be in a function for unittesting. + + """ + class wrapped(base): # pylint: disable-msg=C0103 + """Log handler that doesn't fallback to stderr. + + When an error occurs while writing on the logfile, logging.FileHandler + tries to log on stderr. This doesn't work in Ganeti since stderr is + redirected to a logfile. This class avoids failures by reporting errors to /dev/console. """ - try: - logging.FileHandler.handleError(self, record) - except Exception: # pylint: disable-msg=W0703 + def __init__(self, console, *args, **kwargs): + """Initializes this class. + + @type console: file-like object or None + @param console: Open file-like object for console + + """ + base.__init__(self, *args, **kwargs) + assert not hasattr(self, "_console") + self._console = console + + def handleError(self, record): # pylint: disable-msg=C0103 + """Handle errors which occur during an emit() call. + + Try to handle errors with FileHandler method, if it fails write to + /dev/console. + + """ try: - self.console.write("Cannot log message:\n%s\n" % self.format(record)) + base.handleError(record) except Exception: # pylint: disable-msg=W0703 - # Log handler tried everything it could, now just give up - pass + if self._console: + try: + # Ignore warning about "self.format", pylint: disable-msg=E1101 + self._console.write("Cannot log message:\n%s\n" % + self.format(record)) + except Exception: # pylint: disable-msg=W0703 + # Log handler tried everything it could, now just give up + pass + + return wrapped + + +#: Custom log handler for writing to console with a reopenable handler +_LogHandler = _LogErrorsToConsole(_ReopenableLogHandler) def SetupLogging(logfile, debug=0, stderr_logging=False, program="", @@ -138,9 +205,10 @@ def SetupLogging(logfile, debug=0, stderr_logging=False, program="", # exception since otherwise we could run but without any logs at all try: if console_logging: - logfile_handler = LogFileHandler(logfile) + logfile_handler = _LogHandler(open(constants.DEV_CONSOLE, "a"), logfile) else: - logfile_handler = logging.FileHandler(logfile) + logfile_handler = _ReopenableLogHandler(logfile) + logfile_handler.setFormatter(formatter) if debug: logfile_handler.setLevel(logging.DEBUG) diff --git a/test/ganeti.utils.log_unittest.py b/test/ganeti.utils.log_unittest.py new file mode 100755 index 000000000..cb1af432d --- /dev/null +++ b/test/ganeti.utils.log_unittest.py @@ -0,0 +1,137 @@ +#!/usr/bin/python +# + +# Copyright (C) 2011 Google Inc. +# +# 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., 51 Franklin Street, Fifth Floor, Boston, MA +# 02110-1301, USA. + + +"""Script for testing ganeti.utils.log""" + +import os +import unittest +import logging +import tempfile + +from ganeti import constants +from ganeti import errors +from ganeti import utils + +import testutils + + +class TestLogHandler(unittest.TestCase): + def test(self): + tmpfile = tempfile.NamedTemporaryFile() + + handler = utils.log._ReopenableLogHandler(tmpfile.name) + handler.setFormatter(logging.Formatter("%(asctime)s: %(message)s")) + + logger = logging.Logger("TestLogger") + logger.addHandler(handler) + self.assertEqual(len(logger.handlers), 1) + + logger.error("Test message ERROR") + logger.info("Test message INFO") + + logger.removeHandler(handler) + self.assertFalse(logger.handlers) + handler.close() + + self.assertEqual(len(utils.ReadFile(tmpfile.name).splitlines()), 2) + + def testReopen(self): + tmpfile = tempfile.NamedTemporaryFile() + tmpfile2 = tempfile.NamedTemporaryFile() + + handler = utils.log._ReopenableLogHandler(tmpfile.name) + + self.assertFalse(utils.ReadFile(tmpfile.name)) + self.assertFalse(utils.ReadFile(tmpfile2.name)) + + logger = logging.Logger("TestLoggerReopen") + logger.addHandler(handler) + + for _ in range(3): + logger.error("Test message ERROR") + handler.flush() + self.assertEqual(len(utils.ReadFile(tmpfile.name).splitlines()), 3) + before_id = utils.GetFileID(tmpfile.name) + + handler.RequestReopen() + self.assertTrue(handler._reopen) + self.assertTrue(utils.VerifyFileID(utils.GetFileID(tmpfile.name), + before_id)) + + # Rename only after requesting reopen + os.rename(tmpfile.name, tmpfile2.name) + assert not os.path.exists(tmpfile.name) + + # Write another message, should reopen + for _ in range(4): + logger.info("Test message INFO") + self.assertFalse(utils.VerifyFileID(utils.GetFileID(tmpfile.name), + before_id)) + + logger.removeHandler(handler) + self.assertFalse(logger.handlers) + handler.close() + + self.assertEqual(len(utils.ReadFile(tmpfile.name).splitlines()), 4) + self.assertEqual(len(utils.ReadFile(tmpfile2.name).splitlines()), 3) + + def testConsole(self): + for (console, check) in [(None, False), + (tempfile.NamedTemporaryFile(), True), + (self._FailingFile(os.devnull), False)]: + # Create a handler which will fail when handling errors + cls = utils.log._LogErrorsToConsole(self._FailingHandler) + + # Instantiate handler with file which will fail when writing, + # provoking a write to the console + handler = cls(console, self._FailingFile(os.devnull)) + + logger = logging.Logger("TestLogger") + logger.addHandler(handler) + self.assertEqual(len(logger.handlers), 1) + + # Provoke write + logger.error("Test message ERROR") + + # Take everything apart + logger.removeHandler(handler) + self.assertFalse(logger.handlers) + handler.close() + + if console and check: + console.flush() + + # Check console output + consout = utils.ReadFile(console.name) + self.assertTrue("Cannot log message" in consout) + self.assertTrue("Test message ERROR" in consout) + + class _FailingFile(file): + def write(self, _): + raise Exception + + class _FailingHandler(logging.StreamHandler): + def handleError(self, _): + raise Exception + + +if __name__ == "__main__": + testutils.GanetiTestProgram() -- GitLab