Fix plugin logging

Fix logging of debug, info and warning levels.
Also configuration parameter VERBOSE is working again.

fixes problems:
* VERBOSE parameter can be changed at runtime
* Initial log level was unset, then there was nothing logged lower than
exception level. (for example configuration dump was not logged)
* Initial VERBOSE was set to True, then it was too much verbose. And
this flag was mean to be used for debugging problems.

NOTE: real log level is driven by collectd configuration, not by plugin
config.

Change-Id: Ia7048ccb74f27a5d5885b9c0bda17d6fba603e9b
Closes-Bug: #1664973
This commit is contained in:
Jaroslav Safka 2017-02-16 09:23:54 +00:00 committed by Emma Foley
parent 0aa39651ee
commit f903de3f10
12 changed files with 45 additions and 37 deletions

View File

@ -39,10 +39,9 @@ def register_plugin(collectd):
config = Config.instance()
# Setup loggging
log_handler = CollectdLogHandler(collectd=collectd)
log_handler.cfg = config
log_handler = CollectdLogHandler(collectd=collectd, config=config)
ROOT_LOGGER.addHandler(log_handler)
ROOT_LOGGER.setLevel(logging.NOTSET)
ROOT_LOGGER.setLevel(logging.DEBUG)
# Creates collectd plugin instance
instance = Plugin(collectd=collectd, config=config)

View File

@ -39,10 +39,9 @@ def register_plugin(collectd):
config = Config.instance()
# Setup loggging
log_handler = CollectdLogHandler(collectd=collectd)
log_handler.cfg = config
log_handler = CollectdLogHandler(collectd=collectd, config=config)
ROOT_LOGGER.addHandler(log_handler)
ROOT_LOGGER.setLevel(logging.NOTSET)
ROOT_LOGGER.setLevel(logging.DEBUG)
# Creates collectd plugin instance
instance = Plugin(collectd=collectd, config=config)

View File

@ -24,10 +24,9 @@ class CollectdLogHandler(logging.Handler):
# messages longer than this size have to be split
max_message_length = 1023
verbose = False
def __init__(self, collectd, level=logging.NOTSET):
def __init__(self, collectd, config, level=logging.NOTSET):
super(CollectdLogHandler, self).__init__(level=level)
self.cfg = config
self.priority_map = {
logging.DEBUG: collectd.debug,
logging.INFO: collectd.info,
@ -51,7 +50,7 @@ class CollectdLogHandler(logging.Handler):
level=logging.ERROR)
def emit_message(self, message, level):
if self.verbose and level == logging.DEBUG:
if self.cfg.VERBOSE and level == logging.DEBUG:
level = logging.INFO
elif level not in self.priority_map:
level = logging.ERROR

View File

@ -38,10 +38,9 @@ def register_plugin(collectd):
config = Config.instance()
# Setup loggging
log_handler = CollectdLogHandler(collectd=collectd)
log_handler.cfg = config
log_handler = CollectdLogHandler(collectd=collectd, config=config)
ROOT_LOGGER.addHandler(log_handler)
ROOT_LOGGER.setLevel(logging.NOTSET)
ROOT_LOGGER.setLevel(logging.DEBUG)
# Creates collectd plugin instance
instance = Plugin(collectd=collectd, config=config)

View File

@ -182,7 +182,7 @@ class TestPlugin(unittest.TestCase):
# Logger handler is set up
ROOT_LOGGER.addHandler.assert_called_once_with(
CollectdLogHandler.return_value)
ROOT_LOGGER.setLevel.assert_called_once_with(logging.NOTSET)
ROOT_LOGGER.setLevel.assert_called_once_with(logging.DEBUG)
# It creates a plugin
Plugin.assert_called_once_with(

View File

@ -130,7 +130,7 @@ class TestPlugin(unittest.TestCase):
# Logger handler is set up
ROOT_LOGGER.addHandler.assert_called_once_with(
CollectdLogHandler.return_value)
ROOT_LOGGER.setLevel.assert_called_once_with(logging.NOTSET)
ROOT_LOGGER.setLevel.assert_called_once_with(logging.DEBUG)
# It create a plugin
Plugin.assert_called_once_with(

View File

@ -17,7 +17,7 @@ import unittest
import mock
from collectd_ceilometer.common.logger import CollectdLogHandler
from collectd_ceilometer.common.settings import Config
from collectd_ceilometer.tests.mocking import patch_class
@ -48,11 +48,16 @@ def make_record(
class TestCollectdLogHandler(unittest.TestCase):
def __init__(self, *args, **kwargs):
"""Declare additional class attributes"""
super(TestCollectdLogHandler, self).__init__(*args, **kwargs)
self.config = Config.instance()
@patch_class(MockedCollectd)
def test_registered_hooks_when_init(self, collectd):
# When CollectdLogHandler is created
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
# Then collectd logging hooks are registered
# pylint: disable=protected-access
@ -68,7 +73,7 @@ class TestCollectdLogHandler(unittest.TestCase):
def test_debug_when_emit(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
record = make_record(msg="message", level=logging.DEBUG)
# When a debug record is emitted
@ -80,8 +85,8 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_verbose_debug_when_emit(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler.verbose = True
handler = CollectdLogHandler(collectd=collectd, config=self.config)
self.config.VERBOSE = True
record = make_record(msg="message", level=logging.DEBUG)
# When an info record is emitted
@ -93,7 +98,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_info_when_emit(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
record = make_record(msg="message", level=logging.INFO)
# When an info record is emitted
@ -105,7 +110,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_warning_when_emit(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
record = make_record(msg="message", level=logging.WARNING)
# When a warning record is emitted
@ -117,7 +122,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_error_when_emit(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
record = make_record(msg="message", level=logging.ERROR)
# When an error record is emitted
@ -129,7 +134,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_fatal_when_emit(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
record = make_record(msg="message", level=logging.FATAL)
# When a fatal record is emitted
@ -142,7 +147,7 @@ class TestCollectdLogHandler(unittest.TestCase):
def test_long_message_when_emit(self, collectd):
# Given
long_message = "LONG " * 20 + "MESSAGE."
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
handler.max_message_length = 10
record = make_record(msg=long_message)
@ -157,11 +162,12 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_when_logger_debug(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
logger = logging.Logger('some_logger')
logger.addHandler(handler)
# When debug is called
self.config.VERBOSE = False
logger.debug('Say cheese: %s %d', 'string', 10)
# Then debug hook is called
@ -171,12 +177,12 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_verbose_when_logger_info(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler.verbose = True
handler = CollectdLogHandler(collectd=collectd, config=self.config)
logger = logging.Logger('some_logger')
logger.addHandler(handler)
# When debug is called
self.config.VERBOSE = True
logger.debug('Say cheese: %s %d', 'string', 10)
# Then info hook is called
@ -186,7 +192,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_non_verbose_when_logger_info(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
handler.verbose = False
logger = logging.Logger('some_logger')
logger.addHandler(handler)
@ -201,7 +207,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_info_from_logger(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
logger = logging.Logger('some_logger')
logger.addHandler(handler)
@ -214,7 +220,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_warning_from_logger(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
logger = logging.Logger('some_logger')
logger.addHandler(handler)
@ -227,7 +233,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_error_from_logger(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
logger = logging.Logger('some_logger')
logger.addHandler(handler)
@ -240,7 +246,7 @@ class TestCollectdLogHandler(unittest.TestCase):
@patch_class(MockedCollectd)
def test_fatal_from_logger(self, collectd):
# Given
handler = CollectdLogHandler(collectd=collectd)
handler = CollectdLogHandler(collectd=collectd, config=self.config)
logger = logging.Logger('some_logger')
logger.addHandler(handler)

View File

@ -127,7 +127,7 @@ class TestPlugin(unittest.TestCase):
# Logger handler is set up
ROOT_LOGGER.addHandler.assert_called_once_with(
CollectdLogHandler.return_value)
ROOT_LOGGER.setLevel.assert_called_once_with(logging.NOTSET)
ROOT_LOGGER.setLevel.assert_called_once_with(logging.DEBUG)
# It create a plugin
Plugin.assert_called_once_with(

View File

@ -27,5 +27,5 @@ CEILOMETER_BACKEND=mysql
enable_plugin collectd-ceilometer https://github.com/openstack/collectd-ceilometer-plugin
COLLECTD_INSTALL=True
COLLECTD_CEILOMETER_VERBOSE=True
COLLECTD_CEILOMETER_VERBOSE=False
COLLECTD_CEILOMETER_ENABLED=True

View File

@ -11,7 +11,7 @@
<Module "collectd_ceilometer.gnocchi.plugin">
# Verbosity True|False
VERBOSE True
VERBOSE False
# Batch size
BATCH_SIZE "1"

View File

@ -15,5 +15,5 @@ enable_plugin "ceilometer" "${GIT_BASE:-https://git.openstack.org}/openstack/cei
# Setup collectd-ceilometer plugin
COLLECTD_INSTALL=True
COLLECTD_CEILOMETER_VERBOSE=True
COLLECTD_CEILOMETER_VERBOSE=False
enable_plugin "collectd-ceilometer-plugin" "${GIT_BASE:-https://git.openstack.org}/openstack/collectd-ceilometer-plugin.git"

View File

@ -0,0 +1,6 @@
---
fixes:
- Fixes bug 'https://launchpad.net/bugs/1664973'
VERBOSE parameter is read and used again
Initial log level was fixed, so configuration is properly logged.
Initial VERBOSE changed to False, to avoid too much verbosity.