openstack/oslo.log
Code Issues Proposed changes

FastWatchedFileHandler class was added

Browse Source 
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
This commit is contained in:
Marian Horban 2015-08-28 13:15:58 -04:00
parent f464d9f2e1
commit a834e6a10c
5 changed files with 155 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

7
oslo_log/_options.py
View File

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

89
oslo_log/handlers.py
View File

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

8
oslo_log/log.py
View File

@ -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:

51
oslo_log/tests/unit/test_log.py
View File

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

1
requirements.txt
View File

@ -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