2011-10-29 15:06:45 +02:00
|
|
|
# Copyright (C) 2007 Red Hat, Inc.
|
|
|
|
#
|
|
|
|
# This library is free software; you can redistribute it and/or
|
|
|
|
# modify it under the terms of the GNU Lesser General Public
|
|
|
|
# License as published by the Free Software Foundation; either
|
|
|
|
# version 2 of the License, or (at your option) any later version.
|
|
|
|
#
|
|
|
|
# This library is distributed in the hope that it will be useful,
|
|
|
|
# but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
|
|
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
|
|
|
|
# Lesser General Public License for more details.
|
|
|
|
#
|
|
|
|
# You should have received a copy of the GNU Lesser General Public
|
|
|
|
# License along with this library; if not, write to the
|
|
|
|
# Free Software Foundation, Inc., 59 Temple Place - Suite 330,
|
|
|
|
# Boston, MA 02111-1307, USA.
|
|
|
|
|
|
|
|
"""Logging service setup.
|
|
|
|
|
|
|
|
STABLE.
|
|
|
|
"""
|
|
|
|
|
|
|
|
import array
|
|
|
|
import collections
|
|
|
|
import errno
|
|
|
|
import logging
|
|
|
|
import sys
|
|
|
|
import os
|
|
|
|
import repr as repr_
|
|
|
|
import decorator
|
2012-12-10 17:41:58 +01:00
|
|
|
import time
|
2011-10-29 15:06:45 +02:00
|
|
|
|
|
|
|
# Let's keep this module self contained so that it can be easily
|
|
|
|
# pasted in external sugar service like the datastore.
|
|
|
|
|
|
|
|
# traces function calls, use SUGAR_LOGGER_LEVEL=trace to enable
|
|
|
|
TRACE = 5
|
|
|
|
_LEVELS = {
|
|
|
|
'error': logging.ERROR,
|
|
|
|
'warning': logging.WARNING,
|
|
|
|
'debug': logging.DEBUG,
|
|
|
|
'info': logging.INFO,
|
|
|
|
'trace': TRACE,
|
|
|
|
'all': 0,
|
|
|
|
}
|
|
|
|
logging.addLevelName(TRACE, 'TRACE')
|
|
|
|
|
|
|
|
|
|
|
|
def get_logs_dir():
|
|
|
|
profile = os.environ.get('SUGAR_PROFILE', 'default')
|
|
|
|
logs_dir = os.environ.get('SUGAR_LOGS_DIR',
|
|
|
|
os.path.join(os.path.expanduser('~'),
|
|
|
|
'.sugar', profile, 'logs'))
|
|
|
|
return logs_dir
|
|
|
|
|
|
|
|
|
|
|
|
def set_level(level):
|
|
|
|
if level in _LEVELS:
|
|
|
|
logging.getLogger('').setLevel(_LEVELS[level])
|
|
|
|
return
|
|
|
|
|
|
|
|
try:
|
|
|
|
logging.getLogger('').setLevel(int(level))
|
|
|
|
except ValueError:
|
|
|
|
logging.warning('Invalid log level: %r', level)
|
|
|
|
|
|
|
|
|
|
|
|
# pylint: disable-msg=E1101,F0401
|
|
|
|
def _except_hook(exctype, value, traceback):
|
|
|
|
# Attempt to provide verbose IPython tracebacks.
|
|
|
|
# Importing IPython is slow, so we import it lazily.
|
|
|
|
try:
|
|
|
|
from IPython.ultraTB import AutoFormattedTB
|
|
|
|
sys.excepthook = AutoFormattedTB(mode='Verbose',
|
|
|
|
color_scheme='NoColor')
|
|
|
|
except ImportError:
|
|
|
|
sys.excepthook = sys.__excepthook__
|
|
|
|
|
|
|
|
sys.excepthook(exctype, value, traceback)
|
|
|
|
|
|
|
|
|
2012-12-10 17:41:58 +01:00
|
|
|
def cleanup():
|
|
|
|
"""Clean up the log directory, moving old logs into a numbered backup
|
|
|
|
directory. We only keep `_MAX_BACKUP_DIRS` of these backup directories
|
|
|
|
around; the rest are removed."""
|
|
|
|
logs_dir = get_logs_dir()
|
|
|
|
|
|
|
|
if not os.path.isdir(logs_dir):
|
|
|
|
os.makedirs(logs_dir)
|
|
|
|
|
|
|
|
backup_logs = []
|
|
|
|
backup_dirs = []
|
|
|
|
for f in os.listdir(logs_dir):
|
|
|
|
path = os.path.join(logs_dir, f)
|
|
|
|
if os.path.isfile(path):
|
|
|
|
backup_logs.append(f)
|
|
|
|
elif os.path.isdir(path):
|
|
|
|
backup_dirs.append(path)
|
|
|
|
|
|
|
|
if len(backup_dirs) > 3:
|
|
|
|
backup_dirs.sort()
|
|
|
|
root = backup_dirs[0]
|
|
|
|
|
|
|
|
try:
|
|
|
|
for f in os.listdir(root):
|
|
|
|
os.remove(os.path.join(root, f))
|
|
|
|
os.rmdir(root)
|
|
|
|
except OSError, e:
|
|
|
|
print "Could not remove old logs filesi %s" % e
|
|
|
|
|
|
|
|
if len(backup_logs) > 0:
|
|
|
|
name = str(int(time.time()))
|
|
|
|
backup_dir = os.path.join(logs_dir, name)
|
|
|
|
os.mkdir(backup_dir)
|
|
|
|
for log in backup_logs:
|
|
|
|
source_path = os.path.join(logs_dir, log)
|
|
|
|
dest_path = os.path.join(backup_dir, log)
|
|
|
|
os.rename(source_path, dest_path)
|
|
|
|
|
|
|
|
|
2011-10-29 15:06:45 +02:00
|
|
|
def start(log_filename=None):
|
|
|
|
# remove existing handlers, or logging.basicConfig() won't have no effect.
|
|
|
|
root_logger = logging.getLogger('')
|
|
|
|
for handler in root_logger.handlers:
|
|
|
|
root_logger.removeHandler(handler)
|
|
|
|
|
|
|
|
class SafeLogWrapper(object):
|
|
|
|
"""Small file-like wrapper to gracefully handle ENOSPC errors when
|
|
|
|
logging."""
|
|
|
|
|
|
|
|
def __init__(self, stream):
|
|
|
|
self._stream = stream
|
|
|
|
|
|
|
|
def write(self, s):
|
|
|
|
try:
|
|
|
|
self._stream.write(s)
|
|
|
|
except IOError, e:
|
|
|
|
# gracefully deal w/ disk full
|
|
|
|
if e.errno != errno.ENOSPC:
|
|
|
|
raise e
|
|
|
|
|
|
|
|
def flush(self):
|
|
|
|
try:
|
|
|
|
self._stream.flush()
|
|
|
|
except IOError, e:
|
|
|
|
# gracefully deal w/ disk full
|
|
|
|
if e.errno != errno.ENOSPC:
|
|
|
|
raise e
|
|
|
|
|
|
|
|
logging.basicConfig(level=logging.WARNING,
|
|
|
|
format="%(created)f %(levelname)s %(name)s: %(message)s",
|
|
|
|
stream=SafeLogWrapper(sys.stderr))
|
|
|
|
|
|
|
|
if 'SUGAR_LOGGER_LEVEL' in os.environ:
|
|
|
|
set_level(os.environ['SUGAR_LOGGER_LEVEL'])
|
|
|
|
|
|
|
|
if log_filename:
|
|
|
|
try:
|
|
|
|
log_path = os.path.join(get_logs_dir(), log_filename + '.log')
|
|
|
|
|
|
|
|
log_fd = os.open(log_path, os.O_WRONLY | os.O_CREAT)
|
|
|
|
os.dup2(log_fd, sys.stdout.fileno())
|
|
|
|
os.dup2(log_fd, sys.stderr.fileno())
|
|
|
|
os.close(log_fd)
|
|
|
|
|
|
|
|
sys.stdout = SafeLogWrapper(sys.stdout)
|
|
|
|
sys.stderr = SafeLogWrapper(sys.stderr)
|
|
|
|
except OSError, e:
|
|
|
|
# if we're out of space, just continue
|
|
|
|
if e.errno != errno.ENOSPC:
|
|
|
|
raise e
|
|
|
|
|
|
|
|
sys.excepthook = _except_hook
|
|
|
|
|
|
|
|
|
|
|
|
class TraceRepr(repr_.Repr):
|
|
|
|
|
|
|
|
# better handling of subclasses of basic types, e.g. for DBus
|
|
|
|
_TYPES = [int, long, bool, tuple, list, array.array, set, frozenset,
|
|
|
|
collections.deque, dict, str]
|
|
|
|
|
|
|
|
def repr1(self, x, level):
|
|
|
|
for t in self._TYPES:
|
|
|
|
if isinstance(x, t):
|
|
|
|
return getattr(self, 'repr_'+t.__name__)(x, level)
|
|
|
|
|
|
|
|
return repr_.Repr.repr1(self, x, level)
|
|
|
|
|
|
|
|
def repr_int(self, x, level):
|
|
|
|
return repr(x)
|
|
|
|
|
|
|
|
def repr_bool(self, x, level):
|
|
|
|
return repr(x)
|
|
|
|
|
|
|
|
|
|
|
|
def trace(logger=None, logger_name=None, skip_args=None, skip_kwargs=None,
|
|
|
|
maxsize_list=30, maxsize_dict=30, maxsize_string=300):
|
|
|
|
|
|
|
|
if skip_args is None:
|
|
|
|
skip_args = []
|
|
|
|
|
|
|
|
if skip_kwargs is None:
|
|
|
|
skip_kwargs = []
|
|
|
|
|
|
|
|
# size-limit repr()
|
|
|
|
trace_repr = TraceRepr()
|
|
|
|
trace_repr.maxlist = maxsize_list
|
|
|
|
trace_repr.maxdict = maxsize_dict
|
|
|
|
trace_repr.maxstring = maxsize_string
|
|
|
|
trace_repr.maxother = maxsize_string
|
|
|
|
trace_logger = logger or logging.getLogger(logger_name)
|
|
|
|
|
|
|
|
def _trace(f, *args, **kwargs):
|
|
|
|
# don't do expensive formatting if loglevel TRACE is not enabled
|
|
|
|
enabled = trace_logger.isEnabledFor(TRACE)
|
|
|
|
if not enabled:
|
|
|
|
return f(*args, **kwargs)
|
|
|
|
|
|
|
|
params_formatted = ", ".join(
|
|
|
|
[trace_repr.repr(a)
|
|
|
|
for (idx, a) in enumerate(args) if idx not in skip_args] + \
|
|
|
|
['%s=%s' % (k, trace_repr.repr(v))
|
|
|
|
for (k, v) in kwargs.items() if k not in skip_kwargs])
|
|
|
|
|
|
|
|
trace_logger.log(TRACE, "%s(%s) invoked", f.__name__,
|
|
|
|
params_formatted)
|
|
|
|
|
|
|
|
try:
|
|
|
|
res = f(*args, **kwargs)
|
|
|
|
except:
|
|
|
|
trace_logger.exception("Exception occured in %s", f.__name__)
|
|
|
|
raise
|
|
|
|
|
|
|
|
trace_logger.log(TRACE, "%s(%s) returned %s", f.__name__,
|
|
|
|
params_formatted, trace_repr.repr(res))
|
|
|
|
|
|
|
|
return res
|
|
|
|
|
|
|
|
return decorator.decorator(_trace)
|