1
# -*- test-case-name: twisted.test.test_log -*-
2
# Copyright (c) Twisted Matrix Laboratories.
3
# See LICENSE for details.
6
Logging and metrics infrastructure.
9
from __future__ import division, absolute_import
15
from datetime import datetime
17
from zope.interface import Interface
19
from twisted.python.compat import unicode, _PY3
20
from twisted.python import context
21
from twisted.python import reflect
22
from twisted.python import util
23
from twisted.python import failure
24
from twisted.python.threadable import synchronize
25
from twisted.logger import (
26
Logger as NewLogger, LogLevel as NewLogLevel,
27
STDLibLogObserver as NewSTDLibLogObserver,
28
LegacyLogObserverWrapper, LoggingFile, LogPublisher as NewPublisher,
29
globalLogPublisher as newGlobalLogPublisher,
30
globalLogBeginner as newGlobalLogBeginner,
33
from twisted.logger._global import LogBeginner
34
from twisted.logger._legacy import publishToNewObserver as _publishNew
40
Actually, this interface is just a synonym for the dictionary interface,
41
but it serves as a key for the default information in a log.
43
I do not inherit from C{Interface} because the world is a cruel place.
48
class ILogObserver(Interface):
50
An observer which can do something with log events.
52
Given that most log observers are actually bound methods, it's okay to not
53
explicitly declare provision of this interface.
55
def __call__(eventDict):
59
@type eventDict: C{dict} with C{str} keys.
60
@param eventDict: A dictionary with arbitrary keys. However, these
61
keys are often available:
62
- C{message}: A C{tuple} of C{str} containing messages to be
64
- C{system}: A C{str} which indicates the "system" which is
65
generating this event.
66
- C{isError}: A C{bool} indicating whether this event represents
68
- C{failure}: A L{failure.Failure} instance
69
- C{why}: Used as header of the traceback in case of errors.
70
- C{format}: A string format used in place of C{message} to
71
customize the event. The intent is for the observer to format
72
a message by doing something like C{format % eventDict}.
77
context.setDefault(ILogContext,
81
def callWithContext(ctx, func, *args, **kw):
82
newCtx = context.get(ILogContext).copy()
84
return context.call({ILogContext: newCtx}, func, *args, **kw)
88
def callWithLogger(logger, func, *args, **kw):
90
Utility method which wraps a function in a try:/except:, logs a failure if
91
one occurs, and uses the system's logPrefix.
94
lp = logger.logPrefix()
95
except KeyboardInterrupt:
98
lp = '(buggy logPrefix method)'
101
return callWithContext({"system": lp}, func, *args, **kw)
102
except KeyboardInterrupt:
109
def err(_stuff=None, _why=None, **kw):
111
Write a failure to the log.
113
The C{_stuff} and C{_why} parameters use an underscore prefix to lessen
114
the chance of colliding with a keyword argument the application wishes
115
to pass. It is intended that they be supplied with arguments passed
116
positionally, not by keyword.
118
@param _stuff: The failure to log. If C{_stuff} is C{None} a new
119
L{Failure} will be created from the current exception state. If
120
C{_stuff} is an C{Exception} instance it will be wrapped in a
122
@type _stuff: C{NoneType}, C{Exception}, or L{Failure}.
124
@param _why: The source of this failure. This will be logged along with
125
C{_stuff} and should describe the context in which the failure
130
_stuff = failure.Failure()
131
if isinstance(_stuff, failure.Failure):
132
msg(failure=_stuff, why=_why, isError=1, **kw)
133
elif isinstance(_stuff, Exception):
134
msg(failure=failure.Failure(_stuff), why=_why, isError=1, **kw)
136
msg(repr(_stuff), why=_why, isError=1, **kw)
143
This represents a class which may 'own' a log. Used by subclassing.
147
Override this method to insert custom logging behavior. Its
148
return value will be inserted in front of every line. It may
149
be called more times than the number of output lines.
157
Class for singleton log message publishing.
160
synchronized = ['msg']
163
def __init__(self, observerPublisher=None, publishPublisher=None,
164
logBeginner=None, warningsModule=warnings):
165
if publishPublisher is None:
166
publishPublisher = NewPublisher()
167
if observerPublisher is None:
168
observerPublisher = publishPublisher
169
if observerPublisher is None:
170
observerPublisher = NewPublisher()
171
self._observerPublisher = observerPublisher
172
self._publishPublisher = publishPublisher
173
self._legacyObservers = []
174
if logBeginner is None:
175
# This default behavior is really only used for testing.
176
beginnerPublisher = NewPublisher()
177
beginnerPublisher.addObserver(observerPublisher)
178
logBeginner = LogBeginner(beginnerPublisher, NullFile(), sys,
180
self._logBeginner = logBeginner
181
self._warningsModule = warningsModule
182
self._oldshowwarning = warningsModule.showwarning
183
self.showwarning = self._logBeginner.showwarning
189
Property returning all observers registered on this L{LogPublisher}.
191
@return: observers previously added with L{LogPublisher.addObserver}
192
@rtype: L{list} of L{callable}
194
return [x.legacyObserver for x in self._legacyObservers]
197
def _startLogging(self, other, setStdout):
199
Begin logging to the L{LogBeginner} associated with this
202
@param other: the observer to log to.
203
@type other: L{LogBeginner}
205
@param setStdout: if true, send standard I/O to the observer as well.
206
@type setStdout: L{bool}
208
wrapped = LegacyLogObserverWrapper(other)
209
self._legacyObservers.append(wrapped)
210
self._logBeginner.beginLoggingTo([wrapped], True, setStdout)
213
def _stopLogging(self):
215
Clean-up hook for fixing potentially global state. Only for testing of
216
this module itself. If you want less global state, use the new
217
warnings system in L{twisted.logger}.
219
if self._warningsModule.showwarning == self.showwarning:
220
self._warningsModule.showwarning = self._oldshowwarning
223
def addObserver(self, other):
227
@type other: Provider of L{ILogObserver}
228
@param other: A callable object that will be called with each new log
231
wrapped = LegacyLogObserverWrapper(other)
232
self._legacyObservers.append(wrapped)
233
self._observerPublisher.addObserver(wrapped)
236
def removeObserver(self, other):
240
for observer in self._legacyObservers:
241
if observer.legacyObserver == other:
242
self._legacyObservers.remove(observer)
243
self._observerPublisher.removeObserver(observer)
247
def msg(self, *message, **kw):
251
The message should be a native string, i.e. bytes on Python 2 and
252
Unicode on Python 3. For compatibility with both use the native string
253
syntax, for example::
255
>>> log.msg('Hello, world.')
257
You MUST avoid passing in Unicode on Python 2, and the form::
259
>>> log.msg('Hello ', 'world.')
261
This form only works (sometimes) by accident.
263
Keyword arguments will be converted into items in the event
264
dict that is passed to L{ILogObserver} implementations.
265
Each implementation, in turn, can define keys that are used
266
by it specifically, in addition to common keys listed at
267
L{ILogObserver.__call__}.
269
For example, to set the C{system} parameter while logging
272
>>> log.msg('Started', system='Foo')
275
actualEventDict = (context.get(ILogContext) or {}).copy()
276
actualEventDict.update(kw)
277
actualEventDict['message'] = message
278
actualEventDict['time'] = time.time()
279
if "isError" not in actualEventDict:
280
actualEventDict["isError"] = 0
282
_publishNew(self._publishPublisher, actualEventDict, textFromEventDict)
285
synchronize(LogPublisher)
289
if 'theLogPublisher' not in globals():
290
def _actually(something):
292
A decorator that returns its argument rather than the thing it is
295
This allows the documentation generator to see an alias for a method or
296
constant as an object with a docstring and thereby document it and
297
allow references to it statically.
299
@param something: An object to create an alias for.
300
@type something: L{object}
302
@return: a 1-argument callable that returns C{something}
305
def decorate(thingWithADocstring):
309
theLogPublisher = LogPublisher(
310
observerPublisher=newGlobalLogPublisher,
311
publishPublisher=newGlobalLogPublisher,
312
logBeginner=newGlobalLogBeginner,
316
@_actually(theLogPublisher.addObserver)
317
def addObserver(observer):
319
Add a log observer to the global publisher.
321
@see: L{LogPublisher.addObserver}
323
@param observer: a log observer
324
@type observer: L{callable}
328
@_actually(theLogPublisher.removeObserver)
329
def removeObserver(observer):
331
Remove a log observer from the global publisher.
333
@see: L{LogPublisher.removeObserver}
335
@param observer: a log observer previously added with L{addObserver}
336
@type observer: L{callable}
340
@_actually(theLogPublisher.msg)
341
def msg(*message, **event):
343
Publish a message to the global log publisher.
345
@see: L{LogPublisher.msg}
347
@param message: the log message
348
@type message: C{tuple} of L{str} (native string)
350
@param event: fields for the log event
351
@type event: L{dict} mapping L{str} (native string) to L{object}
355
@_actually(theLogPublisher.showwarning)
358
Publish a Python warning through the global log publisher.
360
@see: L{LogPublisher.showwarning}
365
def _safeFormat(fmtString, fmtDict):
367
Try to format a string, swallowing all errors to always return a string.
369
@note: For backward-compatibility reasons, this function ensures that it
370
returns a native string, meaning C{bytes} in Python 2 and C{unicode} in
373
@param fmtString: a C{%}-format string
375
@param fmtDict: string formatting arguments for C{fmtString}
377
@return: A native string, formatted from C{fmtString} and C{fmtDict}.
380
# There's a way we could make this if not safer at least more
381
# informative: perhaps some sort of str/repr wrapper objects
382
# could be wrapped around the things inside of C{fmtDict}. That way
383
# if the event dict contains an object with a bad __repr__, we
384
# can only cry about that individual object instead of the
387
text = fmtString % fmtDict
388
except KeyboardInterrupt:
392
text = ('Invalid format string or unformattable object in '
393
'log message: %r, %s' % (fmtString, fmtDict))
396
text = ('UNFORMATTABLE OBJECT WRITTEN TO LOG with fmt %r, '
397
'MESSAGE LOST' % (fmtString,))
399
text = ('PATHOLOGICAL ERROR IN BOTH FORMAT STRING AND '
400
'MESSAGE DETAILS, MESSAGE LOST')
402
# Return a native string
404
if isinstance(text, bytes):
405
text = text.decode("utf-8")
407
if isinstance(text, unicode):
408
text = text.encode("utf-8")
414
def textFromEventDict(eventDict):
416
Extract text from an event dict passed to a log observer. If it cannot
417
handle the dict, it returns None.
419
The possible keys of eventDict are:
420
- C{message}: by default, it holds the final text. It's required, but can
421
be empty if either C{isError} or C{format} is provided (the first
422
having the priority).
423
- C{isError}: boolean indicating the nature of the event.
424
- C{failure}: L{failure.Failure} instance, required if the event is an
426
- C{why}: if defined, used as header of the traceback in case of errors.
427
- C{format}: string format used in place of C{message} to customize
428
the event. It uses all keys present in C{eventDict} to format
430
Other keys will be used when applying the C{format}, or ignored.
432
edm = eventDict['message']
434
if eventDict['isError'] and 'failure' in eventDict:
435
why = eventDict.get('why')
437
why = reflect.safe_str(why)
439
why = 'Unhandled Error'
441
traceback = eventDict['failure'].getTraceback()
442
except Exception as e:
443
traceback = '(unable to obtain traceback): ' + str(e)
444
text = (why + '\n' + traceback)
445
elif 'format' in eventDict:
446
text = _safeFormat(eventDict['format'], eventDict)
448
# We don't know how to log this
451
text = ' '.join(map(reflect.safe_str, edm))
456
class _GlobalStartStopMixIn:
458
Mix-in for global log observers that can start and stop.
463
Start observing log events.
465
addObserver(self.emit)
470
Stop observing log events.
472
removeObserver(self.emit)
476
class FileLogObserver(_GlobalStartStopMixIn):
478
Log observer that writes to a file-like object.
480
@type timeFormat: C{str} or C{NoneType}
481
@ivar timeFormat: If not C{None}, the format string passed to strftime().
486
def __init__(self, f):
492
def getTimezoneOffset(self, when):
494
Return the current local timezone offset from UTC.
497
@param when: POSIX (ie, UTC) timestamp for which to find the offset.
500
@return: The number of seconds offset from UTC. West is positive,
503
offset = datetime.utcfromtimestamp(when) - datetime.fromtimestamp(when)
504
return offset.days * (60 * 60 * 24) + offset.seconds
507
def formatTime(self, when):
509
Format the given UTC value as a string representing that time in the
512
By default it's formatted as a ISO8601-like string (ISO8601 date and
513
ISO8601 time separated by a space). It can be customized using the
514
C{timeFormat} attribute, which will be used as input for the underlying
515
L{datetime.datetime.strftime} call.
518
@param when: POSIX (ie, UTC) timestamp for which to find the offset.
522
if self.timeFormat is not None:
523
return datetime.fromtimestamp(when).strftime(self.timeFormat)
525
tzOffset = -self.getTimezoneOffset(when)
526
when = datetime.utcfromtimestamp(when + tzOffset)
527
tzHour = abs(int(tzOffset / 60 / 60))
528
tzMin = abs(int(tzOffset / 60 % 60))
533
return '%d-%02d-%02d %02d:%02d:%02d%s%02d%02d' % (
534
when.year, when.month, when.day,
535
when.hour, when.minute, when.second,
536
tzSign, tzHour, tzMin)
539
def emit(self, eventDict):
541
Format the given log event as text and write it to the output file.
543
@param eventDict: a log event
544
@type eventDict: L{dict} mapping L{str} (native string) to L{object}
546
text = textFromEventDict(eventDict)
550
timeStr = self.formatTime(eventDict["time"])
552
"system": eventDict["system"],
553
"text": text.replace("\n", "\n\t")
555
msgStr = _safeFormat("[%(system)s] %(text)s\n", fmtDict)
557
util.untilConcludes(self.write, timeStr + " " + msgStr)
558
util.untilConcludes(self.flush) # Hoorj!
562
class PythonLoggingObserver(_GlobalStartStopMixIn, object):
564
Output twisted messages to Python standard library L{logging} module.
566
WARNING: specific logging configurations (example: network) can lead to
567
a blocking system. Nothing is done here to prevent that, so be sure to not
568
use this: code within Twisted, such as twisted.web, assumes that logging
572
def __init__(self, loggerName="twisted"):
574
@param loggerName: identifier used for getting logger.
575
@type loggerName: C{str}
577
self._newObserver = NewSTDLibLogObserver(loggerName)
580
def emit(self, eventDict):
582
Receive a twisted log entry, format it and bridge it to python.
584
By default the logging level used is info; log.err produces error
585
level, and you can customize the level by using the C{logLevel} key::
587
>>> log.msg('debugging', logLevel=logging.DEBUG)
589
if 'log_format' in eventDict:
590
_publishNew(self._newObserver, eventDict, textFromEventDict)
594
class StdioOnnaStick:
596
Class that pretends to be stdout/err, and turns writes into log messages.
598
@ivar isError: boolean indicating whether this is stderr, in which cases
599
log messages will be logged as errors.
601
@ivar encoding: unicode encoding used to encode any unicode strings
602
written to this object.
608
name = '<stdio (log)>'
610
def __init__(self, isError=0, encoding=None):
611
self.isError = isError
613
encoding = sys.getdefaultencoding()
614
self.encoding = encoding
631
raise IOError("can't read from the log!")
639
def write(self, data):
640
if not _PY3 and isinstance(data, unicode):
641
data = data.encode(self.encoding)
642
d = (self.buf + data).split('\n')
645
for message in messages:
646
msg(message, printed=1, isError=self.isError)
649
def writelines(self, lines):
651
if not _PY3 and isinstance(line, unicode):
652
line = line.encode(self.encoding)
653
msg(line, printed=1, isError=self.isError)
657
def startLogging(file, *a, **kw):
659
Initialize logging to a specified file.
661
@return: A L{FileLogObserver} if a new observer is added, None otherwise.
663
if isinstance(file, LoggingFile):
665
flo = FileLogObserver(file)
666
startLoggingWithObserver(flo.emit, *a, **kw)
671
def startLoggingWithObserver(observer, setStdout=1):
673
Initialize logging to a specified observer. If setStdout is true
674
(defaults to yes), also redirect sys.stdout and sys.stderr
675
to the specified file.
677
theLogPublisher._startLogging(observer, setStdout)
684
A file-like object that discards everything.
694
def write(self, bytes):
699
@type bytes: L{bytes}
718
Discard messages logged via the global C{logfile} object.
725
# Prevent logfile from being erased on reload. This only works in cpython.
726
if 'logfile' not in globals():
727
logfile = LoggingFile(logger=NewLogger(),
728
level=NewLogLevel.info,
729
encoding=getattr(sys.stdout, "encoding", None))
730
logerr = LoggingFile(logger=NewLogger(),
731
level=NewLogLevel.error,
732
encoding=getattr(sys.stderr, "encoding", None))
736
class DefaultObserver(_GlobalStartStopMixIn):
740
Will ignore all non-error messages and send error messages to sys.stderr.
741
Will be removed when startLogging() is called for the first time.
745
def emit(self, eventDict):
749
@param eventDict: an event dict
750
@type eventDict: dict
752
if eventDict["isError"]:
753
text = textFromEventDict(eventDict)
754
self.stderr.write(text)
759
if 'defaultObserver' not in globals():
760
defaultObserver = DefaultObserver()