| import logging |
| import os |
| import sys |
| import time |
| from autotest_lib.client.common_lib import utils |
| |
| # Set up a simple catchall configuration for use during import time. Some code |
| # may log messages at import time and we don't want those to get completely |
| # thrown away. We'll clear this out when actual configuration takes place. |
| logging.basicConfig(level=logging.DEBUG) |
| |
| |
| class AllowBelowSeverity(logging.Filter): |
| """ |
| Allows only records less severe than a given level (the opposite of what |
| the normal logging level filtering does. |
| """ |
| |
| def __init__(self, level): |
| self.level = level |
| |
| def filter(self, record): |
| return record.levelno < self.level |
| |
| |
| class VarLogMessageFormatter(logging.Formatter): |
| """ |
| Respews logging.* strings on the DUT to /var/log/messages for easier |
| correlation of user mode test activity with kernel messages. |
| """ |
| _should_respew = True |
| |
| def format(self, record): |
| s = super(VarLogMessageFormatter, self).format(record) |
| # On Brillo the logger binary is not available. Disable after error. |
| if self._should_respew: |
| try: |
| if isinstance(s, unicode): |
| s = s.encode('utf8') |
| os.system('logger -t "autotest" "%s"' % utils.sh_escape(s)) |
| except OSError: |
| self._should_respew = False |
| return s |
| |
| |
| class LoggingConfig(object): |
| global_level = logging.DEBUG |
| stdout_level = logging.INFO |
| stderr_level = logging.ERROR |
| |
| FILE_FORMAT = ('%(asctime)s.%(msecs)03d %(levelname)-5.5s|%(module)18.18s:' |
| '%(lineno)4.4d| %(message)s') |
| FILE_FORMAT_WITH_THREADNAME = ( |
| '%(asctime)s.%(msecs)03d %(levelname)-5.5s|%(module)18.18s:' |
| '%(lineno)4.4d| %(threadName)16.16s| %(message)s') |
| DATE_FORMAT = '%m/%d %H:%M:%S' |
| |
| file_formatter = logging.Formatter(fmt=FILE_FORMAT, datefmt=DATE_FORMAT) |
| |
| CONSOLE_FORMAT = '%(asctime)s %(levelname)-5.5s| %(message)s' |
| |
| console_formatter = logging.Formatter(fmt=CONSOLE_FORMAT, |
| datefmt='%H:%M:%S') |
| |
| system_formatter = VarLogMessageFormatter(fmt=FILE_FORMAT, |
| datefmt='%H:%M:%S') |
| |
| def __init__(self, use_console=True): |
| self.logger = logging.getLogger() |
| self.global_level = logging.DEBUG |
| self.use_console = use_console |
| |
| @classmethod |
| def get_timestamped_log_name(cls, base_name): |
| return '%s.log.%s' % (base_name, time.strftime('%Y-%m-%d-%H.%M.%S')) |
| |
| @classmethod |
| def get_autotest_root(cls): |
| common_lib_dir = os.path.dirname(__file__) |
| return os.path.abspath(os.path.join(common_lib_dir, '..', '..')) |
| |
| @classmethod |
| def get_server_log_dir(cls): |
| return os.path.join(cls.get_autotest_root(), 'logs') |
| |
| def add_stream_handler(self, stream, level=logging.DEBUG, datefmt=None): |
| handler = logging.StreamHandler(stream) |
| handler.setLevel(level) |
| formatter = self.console_formatter |
| if datefmt: |
| formatter = logging.Formatter(fmt=self.CONSOLE_FORMAT, |
| datefmt=datefmt) |
| handler.setFormatter(formatter) |
| self.logger.addHandler(handler) |
| return handler |
| |
| def add_console_handlers(self, datefmt=None): |
| stdout_handler = self.add_stream_handler(sys.stdout, |
| level=self.stdout_level, |
| datefmt=datefmt) |
| # only pass records *below* STDERR_LEVEL to stdout, to avoid duplication |
| stdout_handler.addFilter(AllowBelowSeverity(self.stderr_level)) |
| |
| self.add_stream_handler(sys.stderr, self.stderr_level, datefmt) |
| |
| def add_file_handler(self, |
| file_path, |
| level=logging.DEBUG, |
| log_dir=None, |
| datefmt=None): |
| if log_dir: |
| file_path = os.path.join(log_dir, file_path) |
| handler = logging.FileHandler(file_path) |
| handler.setLevel(level) |
| formatter = self.file_formatter |
| if datefmt: |
| formatter = logging.Formatter(fmt=self.FILE_FORMAT, datefmt=datefmt) |
| # Respew the content of the selected file to /var/log/messages. |
| if file_path == '/usr/local/autotest/results/default/debug/client.0.WARNING': |
| formatter = self.system_formatter |
| handler.setFormatter(formatter) |
| self.logger.addHandler(handler) |
| return handler |
| |
| def _add_file_handlers_for_all_levels(self, log_dir, log_name): |
| for level in (logging.DEBUG, logging.INFO, logging.WARNING, |
| logging.ERROR): |
| file_name = '%s.%s' % (log_name, logging.getLevelName(level)) |
| self.add_file_handler(file_name, level=level, log_dir=log_dir) |
| |
| def add_debug_file_handlers(self, log_dir, log_name=None): |
| raise NotImplementedError |
| |
| def _clear_all_handlers(self): |
| for handler in list(self.logger.handlers): |
| self.logger.removeHandler(handler) |
| # Attempt to close the handler. If it's already closed a KeyError |
| # will be generated. http://bugs.python.org/issue8581 |
| try: |
| handler.close() |
| except KeyError: |
| pass |
| |
| def configure_logging(self, use_console=True, verbose=False, datefmt=None): |
| self._clear_all_handlers() # see comment at top of file |
| self.logger.setLevel(self.global_level) |
| |
| if verbose: |
| self.stdout_level = logging.DEBUG |
| if use_console: |
| self.add_console_handlers(datefmt) |
| |
| |
| class TestingConfig(LoggingConfig): |
| |
| def add_stream_handler(self, *args, **kwargs): |
| pass |
| |
| def add_file_handler(self, *args, **kwargs): |
| pass |
| |
| def configure_logging(self, **kwargs): |
| pass |
| |
| |
| def add_threadname_in_log(): |
| """Change logging formatter to include thread name. |
| |
| This is to help logs from each thread runs to include its thread name. |
| """ |
| log = logging.getLogger() |
| for handler in logging.getLogger().handlers: |
| if isinstance(handler, logging.FileHandler): |
| log.removeHandler(handler) |
| handler.setFormatter(logging.Formatter( |
| LoggingConfig.FILE_FORMAT_WITH_THREADNAME, |
| LoggingConfig.DATE_FORMAT)) |
| log.addHandler(handler) |
| logging.debug('Logging handler\'s format updated with thread name.') |