Rework logger

1. Use flexible config based on dictConfig
2. debug decorator wan not used for a years -> dropped
3. Hardcode logger to fuel-qa.__name__ from __name__ due to not root package for now
4. Due to different behavior between labs, override devops logger to act as QA.
5. Capture all propagated to root logger with warning+ level at file only.
6. Do not propagate py.warnings due to a lot of useless warnings from packages

Blueprint: fuel-qa-join-helpers

Change-Id: I0e66909caf11fd98988b601b5054ed1fa9e1aaa9
This commit is contained in:
Alexey Stepanov 2016-08-31 13:52:20 +03:00
parent fe02b053a7
commit 88ae37563a
1 changed files with 102 additions and 51 deletions

View File

@ -1,4 +1,4 @@
# Copyright 2014 Mirantis, Inc.
# Copyright 2016 Mirantis, Inc.
#
# Licensed under the Apache License, Version 2.0 (the "License"); you may
# not use this file except in compliance with the License. You may obtain
@ -11,66 +11,116 @@
# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
# License for the specific language governing permissions and limitations
# under the License.
from __future__ import unicode_literals
import functools
import logging
import traceback
import logging.config
import os
import traceback
import warnings
from fuelweb_test.settings import LOGS_DIR
if not os.path.exists(LOGS_DIR):
os.makedirs(LOGS_DIR)
logging.basicConfig(level=logging.DEBUG,
format='%(asctime)s - %(levelname)s %(filename)s:'
'%(lineno)d -- %(message)s',
filename=os.path.join(LOGS_DIR, 'sys_test.log'),
filemode='w')
_log_config = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'default': {
'format': '%(asctime)s - %(levelname)s %(filename)s:'
'%(lineno)d -- %(message)s',
'datefmt': '%Y-%m-%d %H:%M:%S'
},
},
'handlers': {
'console': {
'level': 'INFO',
'class': 'logging.StreamHandler',
'formatter': 'default'
},
'tests_log': {
'level': 'DEBUG',
'class': 'logging.FileHandler',
'formatter': 'default',
'filename': os.path.join(LOGS_DIR, 'sys_test.log'),
'mode': 'w',
'encoding': 'utf8',
},
'devops_log': {
'level': 'DEBUG',
'class': 'logging.FileHandler',
'formatter': 'default',
'filename': os.path.join(LOGS_DIR, 'devops.log'),
'mode': 'w',
'encoding': 'utf8',
},
'null': {
'level': 'CRITICAL',
'class': 'logging.NullHandler',
},
},
'loggers': {
# Log all to log file , but by default only warnings.
'': {
'handlers': ['tests_log'],
'level': 'WARNING',
},
'fuel-qa': {
'handlers': ['console'],
'level': 'DEBUG',
'propagate': True
},
'devops': {
'handlers': ['console', 'devops_log'],
'level': 'DEBUG',
'propagate': True # Test log too
},
# py.warnings is changed by Django -> do not propagate
'py.warnings': {
'handlers': ['console', 'tests_log'],
'level': 'WARNING',
'propagate': False
},
'paramiko': {'level': 'WARNING'},
'iso8601': {'level': 'WARNING'},
'keystoneauth': {'level': 'WARNING'},
}
}
console = logging.StreamHandler()
console.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(levelname)s %(filename)s:'
'%(lineno)d -- %(message)s')
console.setFormatter(formatter)
logging.config.dictConfig(_log_config)
logging.captureWarnings(True) # Log warnings
# Filter deprecation warnings: log only when deletion announced
warnings.filterwarnings(
'default',
message=r'.*(drop|remove)+.*',
category=DeprecationWarning)
logger = logging.getLogger(__name__)
logger.addHandler(console)
logger = logging.getLogger('fuel-qa.{}'.format(__name__))
# suppress iso8601 and paramiko debug logging
class NoDebugMessageFilter(logging.Filter):
def filter(self, record):
return not record.levelno <= logging.DEBUG
logging.getLogger('paramiko.transport').setLevel(logging.WARNING)
logging.getLogger('paramiko.hostkeys').setLevel(logging.WARNING)
logging.getLogger('iso8601.iso8601').addFilter(NoDebugMessageFilter())
logging.getLogger('keystoneauth.session').setLevel(logging.WARNING)
def debug(logger):
def wrapper(func):
@functools.wraps(func)
def wrapped(*args, **kwargs):
logger.debug(
"Calling: {} with args: {} {}".format(
func.__name__, args, kwargs
)
def logwrap(func):
@functools.wraps(func)
def wrapped(*args, **kwargs):
logger.debug(
"Calling: {} with args: {} {}".format(
func.__name__, args, kwargs
)
try:
result = func(*args, **kwargs)
logger.debug(
"Done: {} with result: {}".format(func.__name__, result))
except BaseException as e:
logger.error(
'{func} raised: {exc!r}\n'
'Traceback: {tb!s}'.format(
func=func.__name__, exc=e, tb=traceback.format_exc()))
raise
return result
return wrapped
return wrapper
logwrap = debug(logger)
)
try:
result = func(*args, **kwargs)
logger.debug(
"Done: {} with result: {}".format(func.__name__, result))
except BaseException as e:
logger.error(
'{func} raised: {exc!r}\n'
'Traceback: {tb!s}'.format(
func=func.__name__, exc=e, tb=traceback.format_exc()))
raise
return result
return wrapped
class QuietLogger(object):
@ -81,8 +131,9 @@ class QuietLogger(object):
self.storage = None
def __enter__(self):
console = logging.StreamHandler()
self.storage = console.level
console.setLevel(self.log_level + 1)
def __exit__(self, exp_type, exp_value, traceback):
console.setLevel(self.storage)
def __exit__(self, exc_type, exc_value, exc_tb):
logging.StreamHandler().setLevel(self.storage)