Source code for cocotb.log

# Copyright (c) 2013, 2018 Potential Ventures Ltd
# Copyright (c) 2013 SolarFlare Communications Inc
# All rights reserved.
#
# Redistribution and use in source and binary forms, with or without
# modification, are permitted provided that the following conditions are met:
#     * Redistributions of source code must retain the above copyright
#       notice, this list of conditions and the following disclaimer.
#     * Redistributions in binary form must reproduce the above copyright
#       notice, this list of conditions and the following disclaimer in the
#       documentation and/or other materials provided with the distribution.
#     * Neither the name of Potential Ventures Ltd,
#       SolarFlare Communications Inc nor the
#       names of its contributors may be used to endorse or promote products
#       derived from this software without specific prior written permission.
#
# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND
# ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
# WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
# DISCLAIMED. IN NO EVENT SHALL POTENTIAL VENTURES LTD BE LIABLE FOR ANY
# DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
# (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
# LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
# ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
# (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
# SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

"""
Everything related to logging
"""

import os
import sys
import logging
import warnings

from cocotb.utils import (
    get_sim_time, get_time_from_sim_steps, want_color_output
)

import cocotb.ANSI as ANSI

if "COCOTB_REDUCED_LOG_FMT" in os.environ:
    _suppress = True
else:
    _suppress = False

# Column alignment
_LEVEL_CHARS    = len("CRITICAL")  # noqa
_RECORD_CHARS   = 35  # noqa
_FILENAME_CHARS = 20  # noqa
_LINENO_CHARS   = 4  # noqa
_FUNCNAME_CHARS = 31  # noqa

# Default log level if not overwritten by the user.
_COCOTB_LOG_LEVEL_DEFAULT = "INFO"


[docs]def default_config(): """ Apply the default cocotb log formatting to the root logger. This hooks up the logger to write to stdout, using either :class:`SimColourLogFormatter` or :class:`SimLogFormatter` depending on whether colored output is requested. It also adds a :class:`SimTimeContextFilter` filter so that :attr:`~logging.LogRecord.created_sim_time` is available to the formatter. The logging level for cocotb logs is set based on the :envvar:`COCOTB_LOG_LEVEL` environment variable, which defaults to ``INFO``. If desired, this logging configuration can be overwritten by calling ``logging.basicConfig(..., force=True)`` (in Python 3.8 onwards), or by manually resetting the root logger instance. An example of this can be found in the section on :ref:`rotating-logger`. .. versionadded:: 1.4 """ # construct an appropriate handler hdlr = logging.StreamHandler(sys.stdout) hdlr.addFilter(SimTimeContextFilter()) if want_color_output(): hdlr.setFormatter(SimColourLogFormatter()) else: hdlr.setFormatter(SimLogFormatter()) logging.setLoggerClass(SimBaseLog) # For backwards compatibility logging.basicConfig() logging.getLogger().handlers = [hdlr] # overwrite default handlers # apply level settings for cocotb log = logging.getLogger('cocotb') try: # All log levels are upper case, convert the user input for convenience. level = os.environ["COCOTB_LOG_LEVEL"].upper() except KeyError: level = _COCOTB_LOG_LEVEL_DEFAULT try: log.setLevel(level) except ValueError: valid_levels = ('CRITICAL', 'ERROR', 'WARNING', 'INFO', 'DEBUG') raise ValueError("Invalid log level %r passed through the " "COCOTB_LOG_LEVEL environment variable. Valid log " "levels: %s" % (level, ', '.join(valid_levels))) # Notify GPI of log level, which it uses as an optimization to avoid # calling into Python. from cocotb import simulator simulator.log_level(log.getEffectiveLevel())
class SimBaseLog(logging.getLoggerClass()): """ This class only exists for backwards compatibility """ @property def logger(self): warnings.warn( "the .logger attribute should not be used now that `SimLog` " "returns a native logger instance directly.", DeprecationWarning, stacklevel=2) return self @property def colour(self): warnings.warn( "the .colour attribute may be removed in future, use the " "equivalent `cocotb.utils.want_color_output()` instead", DeprecationWarning, stacklevel=2) return want_color_output() # this used to be a class, hence the unusual capitalization def SimLog(name, ident=None): """ Like logging.getLogger, but append a numeric identifier to the name """ if ident is not None: name = "%s.0x%x" % (name, ident) return logging.getLogger(name)
[docs]class SimTimeContextFilter(logging.Filter): """ A filter to inject simulator times into the log records. This uses the approach described in the :ref:`Python logging cookbook <python:filters-contextual>`. This adds the :attr:`~logging.LogRecord.created_sim_time` attribute. .. versionadded:: 1.4 """ # needed to make our docs render well def __init__(self): """""" super().__init__() def filter(self, record): try: record.created_sim_time = get_sim_time() except RecursionError: # get_sim_time may try to log - if that happens, we can't # attach a simulator time to this message. record.created_sim_time = None return True
[docs]class SimLogFormatter(logging.Formatter): """Log formatter to provide consistent log message handling. This will only add simulator timestamps if the handler object this formatter is attached to has a :class:`SimTimeContextFilter` filter attached, which cocotb ensures by default. """ # Removes the arguments from the base class. Docstring needed to make # sphinx happy. def __init__(self): """ Takes no arguments. """ super().__init__() # Justify and truncate @staticmethod def ljust(string, chars): if len(string) > chars: return ".." + string[(chars - 2) * -1:] return string.ljust(chars) @staticmethod def rjust(string, chars): if len(string) > chars: return ".." + string[(chars - 2) * -1:] return string.rjust(chars) def _format(self, level, record, msg, coloured=False): sim_time = getattr(record, 'created_sim_time', None) if sim_time is None: sim_time_str = " -.--ns" else: time_ns = get_time_from_sim_steps(sim_time, 'ns') sim_time_str = "{:6.2f}ns".format(time_ns) prefix = sim_time_str.rjust(11) + ' ' + level + ' ' if not _suppress: prefix += self.ljust(record.name, _RECORD_CHARS) + \ self.rjust(os.path.split(record.filename)[1], _FILENAME_CHARS) + \ ':' + self.ljust(str(record.lineno), _LINENO_CHARS) + \ ' in ' + self.ljust(str(record.funcName), _FUNCNAME_CHARS) + ' ' # these lines are copied from the builtin logger if record.exc_info: # Cache the traceback text to avoid converting it multiple times # (it's constant anyway) if not record.exc_text: record.exc_text = self.formatException(record.exc_info) if record.exc_text: if msg[-1:] != "\n": msg = msg + "\n" msg = msg + record.exc_text prefix_len = len(prefix) if coloured: prefix_len -= (len(level) - _LEVEL_CHARS) pad = "\n" + " " * (prefix_len) return prefix + pad.join(msg.split('\n')) def format(self, record): """Prettify the log output, annotate with simulation time""" msg = record.getMessage() level = record.levelname.ljust(_LEVEL_CHARS) return self._format(level, record, msg)
[docs]class SimColourLogFormatter(SimLogFormatter): """Log formatter to provide consistent log message handling.""" loglevel2colour = { logging.DEBUG : "%s", logging.INFO : ANSI.COLOR_INFO + "%s" + ANSI.COLOR_DEFAULT, logging.WARNING : ANSI.COLOR_WARNING + "%s" + ANSI.COLOR_DEFAULT, logging.ERROR : ANSI.COLOR_ERROR + "%s" + ANSI.COLOR_DEFAULT, logging.CRITICAL: ANSI.COLOR_CRITICAL + "%s" + ANSI.COLOR_DEFAULT, } def format(self, record): """Prettify the log output, annotate with simulation time""" msg = record.getMessage() # Need to colour each line in case coloring is applied in the message msg = '\n'.join([SimColourLogFormatter.loglevel2colour.get(record.levelno,"%s") % line for line in msg.split('\n')]) level = (SimColourLogFormatter.loglevel2colour.get(record.levelno, "%s") % record.levelname.ljust(_LEVEL_CHARS)) return self._format(level, record, msg, coloured=True)
def _filter_from_c(logger_name, level): return logging.getLogger(logger_name).isEnabledFor(level) def _log_from_c(logger_name, level, filename, lineno, msg, function_name): """ This is for use from the C world, and allows us to insert C stack information. """ logger = logging.getLogger(logger_name) if logger.isEnabledFor(level): record = logger.makeRecord( logger.name, level, filename, lineno, msg, None, None, function_name ) logger.handle(record)