From 3d481f8b687c8cc96b59d23b0716308d039b4a95 Mon Sep 17 00:00:00 2001 From: Alexey Stepanov Date: Wed, 31 Aug 2016 13:52:20 +0300 Subject: [PATCH] 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 --- fuelweb_test/__init__.py | 153 ++++++++++++++++++++++++++------------- 1 file changed, 102 insertions(+), 51 deletions(-) diff --git a/fuelweb_test/__init__.py b/fuelweb_test/__init__.py index 22bf1095b..6a7c155a6 100644 --- a/fuelweb_test/__init__.py +++ b/fuelweb_test/__init__.py @@ -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') - -console = logging.StreamHandler() -console.setLevel(logging.INFO) -formatter = logging.Formatter('%(asctime)s - %(levelname)s %(filename)s:' - '%(lineno)d -- %(message)s') -console.setFormatter(formatter) +_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'}, + } +} -logger = logging.getLogger(__name__) -logger.addHandler(console) +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('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 @@ def __init__(self, upper_log_level=logging.WARNING): 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)