From a834e6a10c433d20934de01c2c4cfe38e386968a Mon Sep 17 00:00:00 2001 From: Marian Horban Date: Fri, 28 Aug 2015 13:15:58 -0400 Subject: [PATCH] FastWatchedFileHandler class was added If one program opens file(in our case log file) and this file is moved or removed by other program, the first program still works with opened file descriptor. If we use WatchedFileHandler it allows to recreate file only after first emitting of WatchedFileHandler. It means that deleted files still consumes disk space. Class FastWatchedFileHandler is designed to observe file system. If log file is moved or removed FastWatchedFileHandler instantaneously closes old file descriptor and creates new file with specified name. Config option watch-log-file was added. If this option is set FastWatchedFileHandler handler will be used. Option watch-log-file brings effect for Linux platform only. DocImpact Closes-Bug: #1437444 Change-Id: Ie70c70ad2d8cf198a8fd72488a43fb1bd71c57be --- oslo_log/_options.py | 7 +++ oslo_log/handlers.py | 89 +++++++++++++++++++++++++++++++++ oslo_log/log.py | 8 ++- oslo_log/tests/unit/test_log.py | 51 +++++++++++++++++++ requirements.txt | 1 + 5 files changed, 155 insertions(+), 1 deletion(-) diff --git a/oslo_log/_options.py b/oslo_log/_options.py index 2463b19e..8fce56be 100644 --- a/oslo_log/_options.py +++ b/oslo_log/_options.py @@ -63,6 +63,13 @@ logging_cli_opts = [ deprecated_name='logdir', help='(Optional) The base directory used for relative ' '--log-file paths.'), + cfg.BoolOpt('watch-log-file', + default=False, + help='(Optional) Uses logging handler designed to watch file ' + 'system. When log file is moved or removed this handler ' + 'will open a new log file with specified path ' + 'instantaneously. It makes sense only if log-file option ' + 'is specified and Linux platform is used.'), cfg.BoolOpt('use-syslog', default=False, help='Use syslog for logging. ' diff --git a/oslo_log/handlers.py b/oslo_log/handlers.py index 9ecbcd69..e6500640 100644 --- a/oslo_log/handlers.py +++ b/oslo_log/handlers.py @@ -10,11 +10,15 @@ # License for the specific language governing permissions and limitations # under the License. +import errno import inspect import logging import logging.config import logging.handlers import os +import pyinotify +import stat +import time try: import syslog except ImportError: @@ -115,3 +119,88 @@ class ColorHandler(logging.StreamHandler): def format(self, record): record.color = self.LEVEL_COLORS[record.levelno] return logging.StreamHandler.format(self, record) + + +class FileKeeper(pyinotify.ProcessEvent): + def my_init(self, watched_handler, watched_file): + self._watched_handler = watched_handler + self._watched_file = watched_file + + def process_default(self, event): + if event.name == self._watched_file: + self._watched_handler.reopen_file() + + +class EventletThreadedNotifier(pyinotify.ThreadedNotifier): + + def loop(self): + """Eventlet friendly ThreadedNotifier + + EventletFriendlyThreadedNotifier contains additional time.sleep() + call insude loop to allow switching to other thread when eventlet + is used. + It can be used with eventlet and native threads as well. + """ + + while not self._stop_event.is_set(): + self.process_events() + time.sleep(0) + ref_time = time.time() + if self.check_events(): + self._sleep(ref_time) + self.read_events() + + +class FastWatchedFileHandler(logging.handlers.WatchedFileHandler, object): + """Frequency of reading events. + + Watching thread sleeps max(0, READ_FREQ - (TIMEOUT / 1000)) seconds. + """ + READ_FREQ = 1 + + """Poll timeout in milliseconds. + + See https://docs.python.org/2/library/select.html#select.poll.poll""" + TIMEOUT = 500 + + def __init__(self, logpath, *args, **kwargs): + self._log_file = os.path.basename(logpath) + self._log_dir = os.path.dirname(logpath) + super(FastWatchedFileHandler, self).__init__(logpath, *args, **kwargs) + self._watch_file() + + def _watch_file(self): + mask = pyinotify.IN_MOVED_FROM | pyinotify.IN_DELETE + watch_manager = pyinotify.WatchManager() + handler = FileKeeper(watched_handler=self, + watched_file=self._log_file) + notifier = EventletThreadedNotifier( + watch_manager, + default_proc_fun=handler, + read_freq=FastWatchedFileHandler.READ_FREQ, + timeout=FastWatchedFileHandler.TIMEOUT) + notifier.daemon = True + watch_manager.add_watch(self._log_dir, mask) + notifier.start() + + def reopen_file(self): + try: + # stat the file by path, checking for existence + sres = os.stat(self.baseFilename) + except OSError as err: + if err.errno == errno.ENOENT: + sres = None + else: + raise + # compare file system stat with that of our stream file handle + if (not sres or + sres[stat.ST_DEV] != self.dev or + sres[stat.ST_INO] != self.ino): + if self.stream is not None: + # we have an open file handle, clean it up + self.stream.flush() + self.stream.close() + self.stream = None + # open a new file handle and get new stat info from that fd + self.stream = self._open() + self._statstream() diff --git a/oslo_log/log.py b/oslo_log/log.py index e062614a..a95baaf6 100644 --- a/oslo_log/log.py +++ b/oslo_log/log.py @@ -31,6 +31,7 @@ import logging import logging.config import logging.handlers import os +import platform import sys try: import syslog @@ -311,7 +312,12 @@ def _setup_logging_from_conf(conf, project, version): logpath = _get_log_file_path(conf) if logpath: - filelog = logging.handlers.WatchedFileHandler(logpath) + if conf.watch_log_file and platform.system() == 'Linux': + file_handler = handlers.FastWatchedFileHandler + else: + file_handler = logging.handlers.WatchedFileHandler + + filelog = file_handler(logpath) log_root.addHandler(filelog) if conf.use_stderr: diff --git a/oslo_log/tests/unit/test_log.py b/oslo_log/tests/unit/test_log.py index 016b64b6..217edc26 100644 --- a/oslo_log/tests/unit/test_log.py +++ b/oslo_log/tests/unit/test_log.py @@ -16,12 +16,14 @@ import logging import os +import platform import sys try: import syslog except ImportError: syslog = None import tempfile +import time import mock from oslo_config import cfg @@ -117,6 +119,7 @@ class BaseTestCase(test_base.BaseTestCase): self.config = self.config_fixture.config self.CONF = self.config_fixture.conf log.register_options(self.CONF) + log.setup(self.CONF, 'base') class LogTestBase(BaseTestCase): @@ -660,6 +663,53 @@ class SetDefaultsTestCase(BaseTestCase): self.assertEqual(None, self.conf.log_file) +@testtools.skipIf(platform.system() != 'Linux', + 'pyinotify library works on Linux platform only.') +class FastWatchedFileHandlerTestCase(BaseTestCase): + + def setUp(self): + super(FastWatchedFileHandlerTestCase, self).setUp() + + def _config(self): + os_level, log_path = tempfile.mkstemp() + log_dir_path = os.path.dirname(log_path) + log_file_path = os.path.basename(log_path) + self.CONF(['--log-dir', log_dir_path, '--log-file', log_file_path]) + self.config(use_stderr=False) + self.config(watch_log_file=True) + log.setup(self.CONF, 'test', 'test') + return log_path + + def test_instantiate(self): + self._config() + logger = log._loggers[None].logger + self.assertEqual(1, len(logger.handlers)) + self.assertIsInstance(logger.handlers[0], + handlers.FastWatchedFileHandler) + + def test_log(self): + log_path = self._config() + logger = log._loggers[None].logger + text = 'Hello World!' + logger.info(text) + with open(log_path, 'r') as f: + file_content = f.read() + self.assertTrue(text in file_content) + + def test_move(self): + log_path = self._config() + os_level_dst, log_path_dst = tempfile.mkstemp() + os.rename(log_path, log_path_dst) + time.sleep(2) + self.assertTrue(os.path.exists(log_path)) + + def test_remove(self): + log_path = self._config() + os.remove(log_path) + time.sleep(2) + self.assertTrue(os.path.exists(log_path)) + + class LogConfigOptsTestCase(BaseTestCase): def setUp(self): @@ -673,6 +723,7 @@ class LogConfigOptsTestCase(BaseTestCase): self.assertTrue('verbose' in f.getvalue()) self.assertTrue('log-config' in f.getvalue()) self.assertTrue('log-format' in f.getvalue()) + self.assertTrue('watch-log-file' in f.getvalue()) def test_debug_verbose(self): self.CONF(['--debug', '--verbose']) diff --git a/requirements.txt b/requirements.txt index 1faa606b..e9baa94e 100644 --- a/requirements.txt +++ b/requirements.txt @@ -12,3 +12,4 @@ oslo.i18n>=1.5.0 # Apache-2.0 oslo.utils>=1.9.0 # Apache-2.0 oslo.serialization>=1.4.0 # Apache-2.0 debtcollector>=0.3.0 # Apache-2.0 +pyinotify>=0.9.6 # MIT