diff --git a/oslo_log/_options.py b/oslo_log/_options.py index 05338ba4..dd7b59ca 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 6905d6a8..7ec89be8 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 5159decd..99c87775 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 3767e5df..b5fe3cb8 100644 --- a/requirements.txt +++ b/requirements.txt @@ -12,3 +12,4 @@ oslo.i18n>=1.5.0 # Apache-2.0 oslo.utils>=2.0.0 # Apache-2.0 oslo.serialization>=1.4.0 # Apache-2.0 debtcollector>=0.3.0 # Apache-2.0 +pyinotify>=0.9.6 # MIT