Source code for openmdao.util.log

This is just a wrapper for the logging module.
Messages can be routed to the console via enable_console().
If the file logger.cfg exists, it can be used to configure logging.
See the Python documentation for `logging.config` for details.
The example below is equivalent to calling enable_console():

.. parsed-literal::






    format=%(levelname)s %(name)s: %(message)s


#public symbols
__all__ = ['logger', 'getLogger', 'enable_console', 'disable_console',
           'TRACER', 'enable_trace', 'disable_trace',
           'Logger', 'NullLogger',

import atexit
import logging.config
import logging.handlers
import os.path
import select
import socket
import SocketServer
import sys
import threading
import datetime

from cPickle import loads
from struct import unpack

LOG_DEBUG    = logging.DEBUG
LOG_INFO     = logging.INFO
LOG_ERROR    = logging.ERROR

LOG_DEBUG2 = logging.DEBUG - 2  # Protocol debug, etc.
LOG_DEBUG3 = logging.DEBUG - 3  # Even lower-level stuff.

# Compress level names.
logging.addLevelName(logging.NOTSET,   'N')
logging.addLevelName(logging.DEBUG,    'D')
logging.addLevelName(logging.INFO,     'I')
logging.addLevelName(logging.WARNING,  'W')
logging.addLevelName(logging.ERROR,    'E')
logging.addLevelName(logging.CRITICAL, 'C')

logging.addLevelName(LOG_DEBUG2, 'D2')
logging.addLevelName(LOG_DEBUG3, 'D3')

def _configure_root():
    """ Configure root logger with a rotating file handler. """
    mode = 'a'  # Avoid mangling by subprocesses.
    filename = 'openmdao_log.txt'
    # Ensure we can write to the log file.
        tmplog = open(filename, mode)
    except IOError:
        filename = 'openmdao_log_%d.txt' % os.getpid()
        tmplog.write('\n\n*********** BEGIN NEW LOG ************** (%s)'
                     ' PID=%s\n\n' % (, os.getpid()))

    msg_fmt = '%(asctime)s %(levelname)s %(name)s: %(message)s'
    date_fmt = '%b %d %H:%M:%S'
    formatter = logging.Formatter(msg_fmt, date_fmt)

    handler = logging.handlers.RotatingFileHandler(filename)
    handler.setLevel(0)  # Handle anything sent to us.


# If the root logger hasn't been configured, do it now.
    logger = logging.getLogger()
    if not logger.handlers:

# If a logging config file exists, use it.
if os.path.exists('logging.cfg'):

[docs]def getLogger(name): """ Return the named logger. """ return logging.getLogger(name) # Optional handler which writes messages to sys.stderr
[docs]def enable_console(level=logging.WARNING): """ Configure logging to receive log messages at the console. """ global CONSOLE if CONSOLE is None: # define a Handler which writes messages to sys.stderr CONSOLE = logging.StreamHandler() # set a format which is simpler for console use formatter = logging.Formatter('%(levelname)s %(name)s: %(message)s') # tell the handler to use this format CONSOLE.setFormatter(formatter) CONSOLE.setLevel(level) logger.addHandler(CONSOLE)
[docs]def disable_console(): """ Stop receiving log messages at the console. """ logger.removeHandler(CONSOLE)
if int(os.environ.get('OPENMDAO_ENABLE_CONSOLE', '0')): enable_console() # Optional logger for iteration coordinates. TRACER = None
[docs]def enable_trace(stream=None): """ Enable iteration tracing. stream: file or string File object or filename for trace output. Only used on first enable, default ``sys.stderr``. """ global TRACER if TRACER is None: TRACER = logging.getLogger('TRACER') TRACER.propagate = False formatter = logging.Formatter('%(message)s') if stream is None: stream = sys.stderr elif isinstance(stream, basestring): stream = open(stream, 'w') handler = logging.StreamHandler(stream) handler.setFormatter(formatter) TRACER.addHandler(handler) TRACER.setLevel(logging.DEBUG)
[docs]def disable_trace(): """ Disable iteration tracing. """ if TRACER is not None: TRACER.setLevel(logging.CRITICAL)
if int(os.environ.get('OPENMDAO_ENABLE_TRACE', '0')): enable_trace()
[docs]class Logger(object): """ Pickle-able logger. Mostly a pass-through to a real logger.""" def __init__(self, name, level=None): self._name = name self._logger = logging.getLogger(name) self._level = None if level is None: self.level = self._logger.getEffectiveLevel() else: self.level = level def __eq__(self, other): try: if self._name == other._name and self._logger == other._logger and \ self._level == other._level: return True except AttributeError: pass return False def __ne__(self, other): return not self.__eq__(other) def __getstate__(self): """ Return dict representing this Logger's state. """ state = self.__dict__.copy() state['_logger'] = None # Contains an unpickleable lock. return state def __setstate__(self, state): """ Restore this Logger's state. """ self.__dict__ = state self._logger = logging.getLogger(self._name) self.level = self._level def _get_level(self): """ Return our level. """ return self._level def _set_level(self, level): """ Set our level. """ self._level = level self._logger.setLevel(level) level = property(_get_level, _set_level, doc='Logging message level.')
[docs] def rename(self, name): """ Change name reported in log. """ self._name = name self._logger = logging.getLogger(name) self._logger.setLevel(self._level)
[docs] def debug(self, msg, *args, **kwargs): """ Log a debug message. """ self._logger.debug(msg, *args, **kwargs)
[docs] def info(self, msg, *args, **kwargs): """ Log an information message. """, *args, **kwargs)
[docs] def warning(self, msg, *args, **kwargs): """ Log a warning message. """ self._logger.warning(msg, *args, **kwargs)
[docs] def error(self, msg, *args, **kwargs): """ Log an error message. """ self._logger.error(msg, *args, **kwargs)
[docs] def exception(self, msg, *args, **kwargs): """ Log an exception. """ self._logger.exception(msg, *args, **kwargs)
[docs] def critical(self, msg, *args, **kwargs): """ Log a critical message. """ self._logger.critical(msg, *args, **kwargs)
[docs] def log(self, level, msg, *args, **kwargs): """ Log a message at a specified level. """ self._logger.log(level, msg, *args, **kwargs)
[docs]class NullLogger(object): """ Can be useful when no logger has been supplied to a routine. It produces no output. """
[docs] def debug(self, msg, *args, **kwargs): """ Log a debug message. """ pass
[docs] def info(self, msg, *args, **kwargs): """ Log an information message. """ pass
[docs] def warning(self, msg, *args, **kwargs): """ Log a warning message. """ pass
[docs] def error(self, msg, *args, **kwargs): """ Log an error message. """ pass
[docs] def exception(self, msg, *args, **kwargs): """ Log an exception. """ pass
[docs] def critical(self, msg, *args, **kwargs): """ Log a critical message. """ pass
[docs] def log(self, level, msg, *args, **kwargs): """ Log a message at a specified level. """ pass # Remote logging support. # Note that a process fork will 'inherit' existing global data. # To avoid child processes from using parent process data, # the process' PID is used in dictionary keys.
_REMOTE_HANDLERS = {} # Logging handler(s) installed by the process. # Called by the remote process. def install_remote_handler(host, port, prefix=None): # pragma no cover """ Installs a handler for logging to `host` on `port` with `prefix`. Returns True if connecting to the remote host was successful. host: string Host to send log requests to. port: int Port on `host` to send log requests to. prefix: string Added to the log record for use on `host`. The default prefix is ``pid@hostname``. """ if prefix is None: prefix = '%s@%s' % (os.getpid(), socket.gethostname()) try: sock = socket.create_connection((host, port)) except Exception as exc: logging.error("Can't connect to logging server at %s:%s: %s", host, port, exc) return False sock.close() handler = _RemoteHandler(host, port, prefix) root = logging.getLogger() root.addHandler(handler) my_pid = os.getpid() if my_pid not in _REMOTE_HANDLERS: # Remove any handlers from our parent process due to a fork. for pid, handlers in _REMOTE_HANDLERS.items(): for handler in handlers: try: root.removeHandler(handler) handler.close() except KeyError: # Apparently it's not there anymore. pass except Exception as exc: logging.warning("Can't remove inherited remote log handler:" " %s", str(exc) or repr(exc)) del _REMOTE_HANDLERS[pid] _REMOTE_HANDLERS[my_pid] = [] _REMOTE_HANDLERS[my_pid].append(handler) return True # Called by the remote process. def remove_remote_handlers(): # pragma no cover """ Removes all installed remote handlers. """ root = logging.getLogger() for pid, handlers in _REMOTE_HANDLERS.items(): if pid == os.getpid(): for handler in handlers: root.removeHandler(handler) handler.close() del _REMOTE_HANDLERS[pid] # Used by the remote process. class _RemoteHandler(logging.handlers.SocketHandler): # pragma no cover """ Handler which adds a ``prefix`` attribute to the log record. """ def __init__(self, host, port, prefix): self.prefix = prefix logging.handlers.SocketHandler.__init__(self, host, port) def handle(self, record): """ Add ``prefix`` attribute to `record` and format locally to avoid problems with object types which may not be handled well at the remote end. """ record.prefix = self.prefix record.msg = record.getMessage() record.args = None logging.handlers.SocketHandler.handle(self, record) def logging_port(server_host, client_host): """ Return port to use to send log messages to `server_host`. Registers `client_host` as a legal host to receive from. """ return _LogListener.server_port(server_host, client_host) class _LogListener(object): """ Maintains :class:`_LogServer` threads. """ _lock = threading.Lock() # server_port() may be called by multiple threads. _listeners = {} # _LogListeners keyed by hostname. def __init__(self, hostname): self._server = None self._port = None self._started = threading.Event() # Signals listener has started. self._thread = threading.Thread(name=hostname+'-log-listener', target=self._listen, args=(hostname,)) self._thread.daemon = True self._thread.start() self._started.wait(10) if self._port is None: raise RuntimeError('Timeout starting thread for %s' % hostname) @property def port(self): """ Port server is listening on. """ return self._port def _listen(self, hostname): """ Listen for log messages. """ self._server = _LogServer((hostname, 0), _LogHandler) self._port = self._server.server_address[1]'Listening for log messages at %s:%s', hostname, self._port) atexit.register(self._stop, os.getpid()) self._started.set() self._server.service_loop() def _stop(self, pid): """ Stop listening. """ if os.getpid() == pid and self._thread.is_alive(): self._server.stop() self._thread.join(2) @staticmethod def server_port(server_host, client_host): """ Return port to use to send log messages to `server_host`. Registers `client_host` as a legal host to receive from. """ with _LogListener._lock: # Ensure server thread running. listener = _LogListener._listeners.get(server_host, None) if listener is None: listener = _LogListener(server_host) _LogListener._listeners[server_host] = listener port = listener.port # Ensure client in allowed hosts. _LogServer.add_client(client_host) return port class _LogServer(SocketServer.ThreadingTCPServer): """ Server for remote logging requests. """ # Default is False, which would keep this process running until # all remote connections are closed. That could be problematic. daemon_threads = True _hosts = set() # Hosts we allow connections from. @staticmethod def add_client(hostname): """ Add `hostname` as a legal client host. """ client_addr = socket.gethostbyname(hostname) _LogServer._hosts.add(client_addr) # Some machines register and then use for localhost. if client_addr.startswith('127.') and \ '' not in _LogServer._hosts: _LogServer._hosts.add('') def verify_request(self, request, client_address): """ Returns True if the client at `client_address` is on a legal host. request: string Request message. client_address: ``(host, port)`` Source of client request. """ host, port = client_address if host in self._hosts: return True logging.warning('Rejecting connection from %s: allowed hosts %s', host, self._hosts) return False def service_loop(self): """ Loop waiting for connections. """ self._is_shut_down = threading.Event() self._shutdown_request = False fd = self.socket.fileno() try: while not self._shutdown_request: rd, wr, ex =[fd], [], [], 0.5) if fd in rd: self._handle_request_noblock() finally: self._is_shut_down.set() def stop(self): """ Stop server loop. """ self._shutdown_request = True self._is_shut_down.wait(2) class _LogHandler(SocketServer.StreamRequestHandler): """ Handler for a stream of logging requests. """ def handle(self): """ Handle log requests until connection closed. """ # An initial 'unused' connection will be made by the client to see # if it can connect. We reduce logging noise by ignoring these. makeLogRecord = logging.makeLogRecord logger = logging.getLogger('remote') conn = self.connection recv = conn.recv peer = None while True: try: data = recv(4) except Exception: return # Typically [Errno 10054] on Windows. if len(data) < 4: break if peer is None: host, port = conn.getpeername() try: host, aliases, addrs = socket.gethostbyaddr(host) except Exception as exc: logger.debug('gethostbyaddr(%s) failed: %s', host, str(exc) or repr(exc)) peer = '%s:%s' % (host, port)'New logging connection from %s', peer) slen = unpack('>L', data)[0] data = recv(slen) slen -= len(data) msg = data while slen: data = recv(slen) slen -= len(data) msg = ''.join((msg, data)) try: obj = loads(msg) record = makeLogRecord(obj) except Exception as exc: logger.exception("Can't process log request from %s: %s", peer, exc) else: prefix = record.prefix name = if name != prefix: = '[%s] %s' % (prefix, name) else: = '[%s]' % prefix logger.handle(record) conn.close() if peer is not None:'Logging connection from %s closed', peer)
OpenMDAO Home