Debugging and Logging#

Changed in version 1.4.0: Ophyd’s use of Python’s logging framework has been completely reworked to follow Python’s documented best practices for libraries.

Ophyd uses Python’s logging framework, which enables sophisticated log management. For common simple cases, including viewing logs in the terminal or writing them to a file, the next section illustrates streamlined, copy/paste-able examples. Users who are familiar with that framework or who need to route logs to multiple destinations may wish to skip ahead to Ophyd’s Logging-Related API.

Useful Snippets#

Log warnings#

This is the recommended standard setup.

from ophyd.log import config_ophyd_logging
config_ophyd_logging()

It will display 'ophyd' log records of WARNING level or higher in the terminal (standard out) with a format tailored to ophyd.

Maximum verbosity#

If operations are “hanging,” running slowly, or repeatedly encountering an error, increasing the logging verbosity can help identify the underlying issue.

from ophyd.log import config_ophyd_logging
config_ophyd_logging(level='DEBUG')

Log to a file#

This will direct all log messages to a file instead of the terminal (standard out).

from ophyd.log import config_ophyd_logging
config_ophyd_logging(file='/tmp/ophyd.log', level='DEBUG')

Ophyd’s Logging-Related API#

Logger Names#

Here are the primary loggers used by ophyd.

'ophyd' — the logger to which all ophyd log records propagate
'ophyd.objects' — logs records from all devices and signals (that is, OphydObject subclasses)
'ophyd.control_layer' — logs requests issued to the underlying control layer (e.g. pyepics, caproto)
'ophyd.event_dispatcher' — issues regular summaries of the backlog of updates from the control layer that are being processed on background threads

There are also many module-level loggers for specific features.

Formatter#

class ophyd.log.LogFormatter(fmt='%(color)s[%(levelname)1.1s %(asctime)s %(module)s:%(lineno)d]%(end_color)s %(message)s', datefmt='%y%m%d %H:%M:%S', style='%', color=True, colors={10: 4, 20: 2, 30: 3, 40: 1})#

Log formatter used in Tornado, modified for Python3-only ophyd.

Key features of this formatter are:

Color support when logging to a terminal that supports it.
Timestamps on every log line.
Robust against str/bytes encoding problems.

This formatter is enabled automatically by tornado.options.parse_command_line or tornado.options.parse_config_file (unless --logging=none is used). Color support on Windows versions that do not support ANSI color codes is enabled by use of the colorama library. Applications that wish to use this must first initialize colorama with a call to colorama.init. See the colorama documentation for details.

Changed in version 4.5: Added support for colorama. Changed the constructor signature to be compatible with logging.config.dictConfig.

Parameters:

color (bool) – Enables color support.
fmt (str) – Log message format. It will be applied to the attributes dict of log records. The text between %(color)s and %(end_color)s will be colored depending on the level if color support is on.
colors (dict) – color mappings from logging level to terminal color code
datefmt (str) – Datetime format. Used for formatting (asctime) placeholder in prefix_fmt.

Changed in version 3.2: Added fmt and datefmt arguments.

Global Handler#

Following Python’s recommendation, ophyd does not install any handlers at import time, but it provides a function to set up a basic useful configuration in one line, similar to Python’s logging.basicConfig() but with some additional options—and scoped to the 'ophyd' logger with ophyd’s ophyd.log.LogFormatter. It streamlines common use cases without interfering with more sophisticated use cases.

We recommend that facilities using ophyd leave this function for users and configure any standardized, facility-managed logging handlers separately, as described in the next section.

ophyd.log.config_ophyd_logging(file=<colorama.ansitowin32.StreamWrapper object>, datefmt='%H:%M:%S', color=True, level='WARNING')#

Set a new handler on the logging.getLogger('ophyd') logger. If this is called more than once, the handler from the previous invocation is removed (if still present) and replaced.

Parameters:

fileobject with write method or filename string: Default is sys.stdout.
datefmtstring: Date format. Default is '%H:%M:%S'.
colorboolean: Use ANSI color codes. True by default.
levelstr or int: Python logging level, given as string or corresponding integer. Default is ‘WARNING’.
Returns
——-
handlerlogging.Handler: The handler, which has already been added to the ‘ophyd’ logger.
Examples
——–
Log to a file.
>>> config_ophyd_logging(file=’/tmp/what_is_happening.txt’)
Include the date along with the time. (The log messages will always include
microseconds, which are configured separately, not as part of ‘datefmt’.)
>>> config_ophyd_logging(datefmt=”%Y-%m-%d %H:%M:%S”)
Turn off ANSI color codes.
>>> config_ophyd_logging(color=False)
Increase verbosity: show level DEBUG or higher.
>>> config_ophyd_logging(level=’DEBUG’)

ophyd.log.get_handler()#: Return the handler configured by the most recent call to config_ophyd_logging(). If config_ophyd_logging() has not yet been called, this returns None.

Advanced Example#

The flow of log event information in loggers and handlers is illustrated in the following diagram:

https://docs.python.org/3/_images/logging_flow.png

For further reference, see the Python 3 logging howto: https://docs.python.org/3/howto/logging.html#logging-flow

As an illustrative example, we will set up two handlers using the Python logging framework directly, ignoring ophyd’s convenience function.

Suppose we set up a handler aimed at a file:

import logging
file_handler = logging.FileHandler('ophyd.log')

And another aimed at Logstash:

import logstash  # requires python-logstash package
logstash_handler = logstash.TCPLogstashHandler(<host>, <port>, version=1)

We can attach the handlers to the ophyd logger, to which all log records created by ophyd propagate:

logger = logging.getLogger('ophyd')
logger.addHandler(logstash_handler)
logger.addHandler(file_filter)

We can set the verbosity of each handler. Suppose want maximum verbosity in the file but only medium verbosity in logstash.

logstash_handler.setLevel('INFO')
file_handler.setLevel('DEBUG')

Finally, ensure that “effective level” of logger is at least as verbose as the most verbose handler—in this case, 'DEBUG'. By default, at import, its level is not set

In [1]: logging.getLevelName(logger.level)

In [2]: 'NOTSET'

and so it inherits the level of Python’s default “handler of last resort,” logging.lastResort, which is 'WARNING'.

In [3]: logging.getLevelName(logger.getEffectiveLevel())

In [4]: 'WARNING'

In this case we should set it to 'DEBUG', to match the most verbose level of the handler we have added.

logger.setLevel('DEBUG')

This makes DEBUG-level records available to all handlers. Our logstash handler, set to 'INFO', will filter out DEBUG-level records.

To globally disable the generation of any log records at or below a certain verbosity, which may be helpful for optimizing performance, Python provides logging.disable().