Merge "FastWatchedFileHandler class was added"

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. '

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()

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:

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'])

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