"""
Schrodinger logging utilities, including configuration.
To get a logger for a python script output, call::
import schrodinger.utils.log as log
logger = log.get_output_logger(name)
You can send messages to that logger as follows::
logger.info("text")
logger.warning("text")
logger.error("text")
logger.critical("text")
logger.debug("text")
Use setLevel() method to specify the minimum level of messages that need to
be logged. For example, if you want to include debugging messages; do::
self.logger.setLevel(logging.DEBUG)
Copyright Schrodinger, LLC. All rights reserved.
"""
#Contributors: Mike Beachy
import io
import logging
import logging.config
import os
import sys
from typing import Optional
import pymmlibs
######## Global variables ########
default_format = "%(asctime)s:%(levelname)s:%(name)s - %(message)s"
# Constants from logging module. Implemented here to prevent user from
# importing the loggin module in addition to schrodinger.util.log:
CRITICAL = logging.CRITICAL
ERROR = logging.ERROR
WARNING = logging.WARNING
INFO = logging.INFO
DEBUG = logging.DEBUG
# This stream handler is defined for use by all output loggers, to allow a
# single handler to be overridden for testing purposes. (PYTHON-2042)
_stdout_stream_handler = None
# Display width line separators
SINGLE_LINE = "-" * 80
DOUBLE_LINE = "=" * 80
######## Module functions ########
[docs]def get_environ_log_level():
"""
Returns the logging level requested by the user via the
SCHRODINGER_PYTHON_DEBUG environment variable as an integer.
Possible return values::
CRITICAL (50)
ERROR (40)
WARNING (30)
INFO (20)
DEBUG (10)
If SCHRODINGER_PYTHON_DEBUG is not set, returns WARNING.
"""
level = logging.WARNING
env_level = os.environ.get("SCHRODINGER_PYTHON_DEBUG", None)
if env_level is not None:
try:
level = int(getattr(logging, env_level))
except:
try:
level = int(env_level)
except:
pass
return level
[docs]def get_logger(name: Optional[str] = None) -> logging.Logger:
"""
A convenience function to call default_logging_config and return a logger
object.
"""
default_logging_config()
return logging.getLogger(name)
[docs]def get_output_logger_handler() -> logging.Handler:
"""
Get the common handler used for output loggers.
"""
global _stdout_stream_handler
if _stdout_stream_handler is None:
_stdout_stream_handler = logging.StreamHandler(sys.stdout)
_stdout_stream_handler.setFormatter(logging.Formatter("%(message)s"))
return _stdout_stream_handler
[docs]def get_output_logger(name: str) -> logging.Logger:
"""
Use this function to get a standard Schrodinger logger that prints
logging messages to stdout.
The default level for the logger is INFO.
The logger returned will not propagate upward, so messages sent to it
will not appear in the standard python log.
"""
logger = get_logger(name)
logger.setLevel(logging.INFO)
logger.propagate = False
# Make sure that multiple handlers are never defined for an output
# logger, whose purpose is only to print things for users.
if not logger.handlers:
logger.addHandler(get_output_logger_handler())
return logger
[docs]def remove_handlers(logger: logging.Logger):
"""
Remove all handlers of a logger.
"""
for handler in logger.handlers[:]:
logger.removeHandler(handler)
[docs]def file_config(config_file: str, root: Optional[logging.Logger] = None):
"""
Configure logging from a file, but don't disable existing loggers.
The logging.config.fileConfig() function has the (IMO) odd behavior of
disabling all existing loggers. This function is a wrapper that
re-enables loggers after calling fileConfig.
Note that the overall goal of logging.config.fileConfig() is to reset
any previous logging configuration, so don't attempt to use this
function incrementally. It's recommended to call it once from your
program as early as possible.
"""
# Google 'fileConfig disabled' to find some messages on the
# logging.config.fileConfig behavior. I guess the point is that
# fileConfig is not meant for 'incremental configuration' and presumably
# will be called only from a main program before loggers are created.
if root is None:
root = logging.getLogger()
# This is a workaround for a bug that's present in the 2.4 fileConfig
# function. Clear out existing handlers now or they will raise some
# bizarro KeyError in the atexit call to logging.shutdown().
#
logging.shutdown()
loggers = [root]
loggers.extend(list(root.manager.loggerDict.values()))
for logger in loggers:
remove_handlers(logger)
existing_loggers = {}
for name, placeholder in root.manager.loggerDict.items():
existing_loggers[name] = getattr(placeholder, 'disabled', 0)
logging.config.fileConfig(config_file)
for name, disabled in existing_loggers.items():
root.manager.loggerDict[name].disabled = disabled
return
[docs]def default_logging_config():
"""
A centrally configurable logging config function to call from library
modules.
If logging is used and a handler is not provided, a message like 'No
handlers could be found for logger "root"' will be printed to stderr. To
avoid this, each module that uses logging should call this method.
Scripts can explicitly call logging_config to override this default
configuration.
Users can modify the default logging behavior by creating a
configuration file at ~/.schrodinger/python_logging.conf
The logging level of this function can also be modified through the
SCHRODINGER_PYTHON_DEBUG environment variable. It can be set to any of
the logging level names (i.e. DEBUG, INFO, WARN (or WARNING), ERROR, or
CRITICAL (or FATAL)) or an integer value between 0 and 50. The
environment variable will be ignored if a python_logging.conf file is
present.
"""
root = logging.getLogger()
# Don't reconfigure if there are handlers already specified.
if root.handlers:
return
# Normally we would use fileutils.get_directory_path for this, but
# mmfile_get_directory_paths must be used instead due to dependency issues.
appdata_dir = pymmlibs.mmfile_get_directory_path(
pymmlibs.DirectoryName_MMFILE_APPDATA)
if not appdata_dir:
raise RuntimeError("Could not determine the Schrodinger "
"application data directory.")
# Use file based configuration if it is present.
config_file = os.path.join(appdata_dir, "python_logging.conf")
if os.path.exists(config_file):
# Since this function is meant for initial configuration and since
# it may be called after loggers have been instantiated, we don't
# want it to disable existing loggers. Use the file_config function
# from this module to take care of this.
file_config(config_file, root)
return
level = get_environ_log_level()
if level > 50:
level = 50
elif level < 0:
level = 0
root.setLevel(level)
# If SCHRODINGER_PYTHON_DEBUG is not defined, default to the
# NullHandler.
if "SCHRODINGER_PYTHON_DEBUG" in os.environ:
hdlr = logging.StreamHandler()
fmt = logging.Formatter(default_format)
hdlr.setFormatter(fmt)
else:
hdlr = logging.NullHandler()
root.addHandler(hdlr)
return
[docs]def logging_config(level: int = logging.WARN,
file: Optional[str] = None,
filemode: str = 'a',
format: Optional[str] = None,
append: bool = False,
stream: io.IOBase = None):
"""
A flexible but simple root handler configuration that is similar to
logging.basicConfig(), but wipes out existing handlers by default.
To log to a file, specify file; to log to a stream, specify stream;
otherwise, stderr will be used. If both a file and stream are specified,
the file will be used.
The default file mode is append, user can change different mode.
The default format has a timestamp, the level, and the logger name,
followed by the logging mesage.
Unless append is true, it wipes out existing handlers. This is so
modules can call default_logging_config() to provide a fallback stderr
handler, but a script can easily override the default.
"""
root = logging.getLogger()
root.setLevel(level)
if not append:
while root.handlers:
last_handler = root.handlers[-1]
if isinstance(last_handler, logging.FileHandler):
last_handler.close()
root.removeHandler(last_handler)
if file:
hdlr = logging.FileHandler(file, filemode)
elif stream:
hdlr = logging.StreamHandler(stream)
else:
hdlr = logging.StreamHandler()
if format is None:
format = default_format
fmt = logging.Formatter(format)
hdlr.setFormatter(fmt)
root.addHandler(hdlr)
return
[docs]def get_stream_handler(
stream: io.IOBase,
format_string: str = '%(asctime)s %(levelname)s: %(message)s'
) -> logging.StreamHandler:
"""
Return a stream handler with a given formatter.
"""
handler = logging.StreamHandler(stream)
handler.setFormatter(logging.Formatter(format_string))
return handler