# -*- coding: utf-8 -*-
"""The :class:`Logger` is the application developer's primary
interface to using Lithoxyl. It is used to conveniently create
:class:`Actions <Action>` and publish them to :class:`sinks <Sink>`.
"""
import sys
import time
import itertools
from collections import deque
from threading import RLock
from boltons.funcutils import wraps
from lithoxyl.context import get_context
from lithoxyl.common import DEBUG, INFO, CRITICAL
from lithoxyl.action import Action, BeginEvent, EndEvent, CommentEvent
QUEUE_LIMIT = 10000
_LOG_ID_ITER = itertools.count()
def _get_previous_frame(frame):
try:
return frame.f_back
except AttributeError:
raise ValueError('reached topmost frame in stack')
# TODO: should all sys._getframes be converted to use this?
# TODO: could precalculate offsets based on which methods are overridden
# TODO: also precalculation could happen in a metaclass
def get_frame_excluding_subtypes(target_type, offset=0):
"""
`offset` is the number of additional frames to look up after
reaching the outside of a class (in the event of a factory
function or some such.
"""
frame = sys._getframe(1)
args = frame.f_code.co_varnames[:frame.f_code.co_argcount]
first_arg_name = args[0] if args else ''
i = 0
while 1:
i += 1
first_arg = frame.f_locals.get(first_arg_name)
if i > 10000:
raise ValueError('could not get frame')
if isinstance(first_arg, target_type):
frame = _get_previous_frame(frame)
elif isinstance(first_arg, type) and issubclass(first_arg, target_type):
frame = _get_previous_frame(frame)
else:
break
for i in range(offset):
frame = _get_previous_frame(frame)
return frame
[docs]class Logger(object):
"""The ``Logger`` is one of three core Lithoxyl types, and the main
entrypoint to creating :class:`~lithoxyl.action.Action` instances,
and publishing those :term:`actions <action>` to :term:`sinks
<sink>`.
Args:
name (str): Name of this Logger.
sinks (list): A list of :term:`sink` objects to be attached to
the Logger. Defaults to ``[]``. Sinks can be added later
with :meth:`Logger.add_sink`.
module (str): Name of the module where the new Logger instance
will be stored. Defaults to the module of the caller.
Most Logger methods and attributes fal into three categories:
:class:`~lithoxyl.action.Action` creation, Sink registration, and
Event handling.
"""
action_type = Action
"Override *action_type* in subtypes for custom Action behavior."
def __init__(self, name, sinks=None, **kwargs):
self.logger_id = next(_LOG_ID_ITER)
self.context = kwargs.pop('context', None) or get_context()
self.context.add_logger(self)
# TODO context-configurable
self.event_queue = deque(maxlen=QUEUE_LIMIT)
self.async_mode = kwargs.pop('async', self.context.async_mode)
self.async_lock = RLock()
self.preflush_hooks = []
self.last_flush = time.time()
self.module = kwargs.pop('module', None)
self._module_offset = kwargs.pop('module_offset', 0)
if self.module is None:
frame = get_frame_excluding_subtypes(target_type=Logger,
offset=self._module_offset)
self.module = frame.f_globals.get('__name__', '<module>')
if kwargs:
raise TypeError('unexpected keyword arguments: %r' % kwargs)
self.name = name or self.module
self.set_sinks(sinks)
def set_async(self, enabled):
self.async_mode = enabled
def flush(self):
# only one flush allowed to run at a time
# ensures that actions are delivered to sinks in order
with self.async_lock:
for preflush_hook in self.preflush_hooks:
try:
preflush_hook(self)
except Exception as e:
self.context.note('preflush', 'hook %r got exception %r',
preflush_hook, e)
queue = self.event_queue
while queue:
ev_type, ev = queue.popleft()
if ev_type == 'begin':
for begin_hook in self._begin_hooks:
begin_hook(ev)
elif ev_type == 'end':
for end_hook in self._end_hooks:
end_hook(ev)
elif ev_type == 'warn':
for warn_hook in self._warn_hooks:
warn_hook(ev)
elif ev_type == 'comment':
for comment_hook in self._comment_hooks:
comment_hook(ev)
else:
self.context.note('flush', 'unknown event type: %r %r',
ev_type, ev)
self.last_flush = time.time()
return
@property
def sinks(self):
"""A copy of all sinks set on this Logger.
Set sinks with :meth:`Logger.set_sinks`.
"""
return list(self._all_sinks)
[docs] def set_sinks(self, sinks):
"Replace this Logger's sinks with *sinks*."
sinks = sinks or []
self._all_sinks = []
self._begin_hooks = []
self._warn_hooks = []
self._end_hooks = []
self._exc_hooks = []
self._comment_hooks = []
for s in sinks:
self.add_sink(s)
[docs] def clear_sinks(self):
"Clear this Logger's sinks."
self.set_sinks([])
[docs] def add_sink(self, sink):
"""Add *sink* to this Logger's sinks. Does nothing if *sink* is
already in this Logger's sinks.
"""
# TODO: check signatures?
if sink in self._all_sinks:
return
begin_hook = getattr(sink, 'on_begin', None)
if callable(begin_hook):
self._begin_hooks.append(begin_hook)
warn_hook = getattr(sink, 'on_warn', None)
if callable(warn_hook):
self._warn_hooks.append(warn_hook)
end_hook = getattr(sink, 'on_end', None)
if callable(end_hook):
self._end_hooks.append(end_hook)
exc_hook = getattr(sink, 'on_exception', None)
if callable(exc_hook):
self._exc_hooks.append(exc_hook)
comment_hook = getattr(sink, 'on_comment', None)
if callable(comment_hook):
self._comment_hooks.append(comment_hook)
# TODO: also pull flush methods?
self._all_sinks.append(sink)
[docs] def on_end(self, end_event):
"Publish *end_event* to all sinks with ``on_end()`` hooks."
if self.async_mode:
self.event_queue.append(('end', end_event))
else:
for end_hook in self._end_hooks:
end_hook(end_event)
return
[docs] def on_begin(self, begin_event):
"Publish *begin_event* to all sinks with ``on_begin()`` hooks."
if self.async_mode:
self.event_queue.append(('begin', begin_event))
else:
for begin_hook in self._begin_hooks:
begin_hook(begin_event)
return
[docs] def on_warn(self, warn_event):
"Publish *warn_event* to all sinks with ``on_warn()`` hooks."
if self.async_mode:
self.event_queue.append(('warn', warn_event))
else:
for warn_hook in self._warn_hooks:
warn_hook(warn_event)
return
[docs] def on_exception(self, exc_event, exc_type, exc_obj, exc_tb):
"Publish *exc_event* to all sinks with ``on_exception()`` hooks."
# async handling doesn't make sense here
for exc_hook in self._exc_hooks:
exc_hook(exc_event, exc_type, exc_obj, exc_tb)
return
def comment(self, message, *a, **kw):
# Comment actions are not enterable, they're not
# returned. They are always critical level, and always finish
# with success. In fact, comment actions, as well as begin and
# end events, along with their respective messages aren't to
# be used directly, they're implemented for compatibility
# reasons. They are not enqueued like other events. Only the
# CommentEvent and its message are intended to be accessed
# directly (e.g., through the event_message sensible formatter
# field.
act_type = self.action_type
act = act_type(logger=self, level=CRITICAL, name='_comment',
data=kw, parent=kw.pop('parent_action', None))
cur_time = time.time()
act.begin_event = BeginEvent(act, cur_time,
message + ' (begin comment)', a)
act.end_event = EndEvent(act, cur_time,
message + ' (end comment)', a, 'success')
event = CommentEvent(act, cur_time, message, a)
if self.async_mode:
self.event_queue.append(('comment', event))
else:
for comment_hook in self._comment_hooks:
comment_hook(event)
return
[docs] def debug(self, action_name, **kw):
"Returns a new :data:`DEBUG`-level :class:`Action` named *name*."
return self.action_type(logger=self, level=DEBUG, name=action_name,
data=kw, reraise=kw.pop('reraise', None),
parent=kw.pop('parent_action', None),
frame=sys._getframe(1))
[docs] def info(self, action_name, **kw):
"Returns a new :data:`INFO`-level :class:`Action` named *name*."
return self.action_type(logger=self, level=INFO, name=action_name,
data=kw, reraise=kw.pop('reraise', None),
parent=kw.pop('parent_action', None),
frame=sys._getframe(1))
[docs] def critical(self, action_name, **kw):
"Returns a new :data:`CRITICAL`-level :class:`Action` named *name*."
return self.action_type(logger=self, level=CRITICAL, name=action_name,
data=kw, reraise=kw.pop('reraise', None),
parent=kw.pop('parent_action', None),
frame=sys._getframe(1))
[docs] def action(self, level, action_name, **kw):
"Return a new :class:`Action` named *name* classified as *level*."
return self.action_type(logger=self, level=level, name=action_name,
data=kw, reraise=kw.pop('reraise', None),
parent=kw.pop('parent_action', None),
frame=sys._getframe(1))
def wrap(self, level, action_name=None,
inject_as=None, enable_wrap=True, **kw):
action_kwargs = kw
def action_wrapper(func_to_log,
_enable=enable_wrap,
_name=action_name,
_action_kwargs=action_kwargs):
if not _enable:
return func_to_log
if _name is None: # wooo nonlocal
_name = func_to_log.__name__
@wraps(func_to_log, injected=inject_as)
def logged_func(*a, **kw):
act = self.action(level, _name, **action_kwargs)
if inject_as:
kw[inject_as] = act
with act:
return func_to_log(*a, **kw)
wrapping_info = (self, level, action_name, func_to_log)
logged_func.__lithoxyl_wrapped__ = wrapping_info
return logged_func
return action_wrapper
def __repr__(self):
cn = self.__class__.__name__
try:
return '<%s name=%r sinks=%r>' % (cn, self.name, self.sinks)
except Exception:
return object.__repr__(self)