diff options
| -rw-r--r-- | Doc/library/logging.rst | 73 | ||||
| -rw-r--r-- | Lib/logging/__init__.py | 59 | ||||
| -rw-r--r-- | Misc/NEWS | 2 |
3 files changed, 113 insertions, 21 deletions
diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst index 98c6bbf..1850cbb 100644 --- a/Doc/library/logging.rst +++ b/Doc/library/logging.rst @@ -757,13 +757,31 @@ functions. *msg* using the string formatting operator. (Note that this means that you can use keywords in the format string, together with a single dictionary argument.) - There are two keyword arguments in *kwargs* which are inspected: *exc_info* + There are three keyword arguments in *kwargs* which are inspected: *exc_info* which, if it does not evaluate as false, causes exception information to be added to the logging message. If an exception tuple (in the format returned by :func:`sys.exc_info`) is provided, it is used; otherwise, :func:`sys.exc_info` is called to get the exception information. - The other optional keyword argument is *extra* which can be used to pass a + The second optional keyword argument is *stack_info*, which defaults to + False. If specified as True, stack information is added to the logging + message, including the actual logging call. Note that this is not the same + stack information as that displayed through specifying *exc_info*: The + former is stack frames from the bottom of the stack up to the logging call + in the current thread, whereas the latter is information about stack frames + which have been unwound, following an exception, while searching for + exception handlers. + + You can specify *stack_info* independently of *exc_info*, e.g. to just show + how you got to a certain point in your code, even when no exceptions were + raised. The stack frames are printed following a header line which says:: + + Stack (most recent call last): + + This mimics the `Traceback (most recent call last):` which is used when + displaying exception frames. + + The third optional keyword argument is *extra* which can be used to pass a dictionary which is used to populate the __dict__ of the LogRecord created for the logging event with user-defined attributes. These custom attributes can then be used as you like. For example, they could be incorporated into logged @@ -796,6 +814,8 @@ functions. above example). In such circumstances, it is likely that specialized :class:`Formatter`\ s would be used with particular :class:`Handler`\ s. + .. versionadded:: 3.2 + The *stack_info* parameter was added. .. function:: info(msg, *args, **kwargs) @@ -1038,13 +1058,31 @@ instantiated directly, but always through the module-level function *msg* using the string formatting operator. (Note that this means that you can use keywords in the format string, together with a single dictionary argument.) - There are two keyword arguments in *kwargs* which are inspected: *exc_info* + There are three keyword arguments in *kwargs* which are inspected: *exc_info* which, if it does not evaluate as false, causes exception information to be added to the logging message. If an exception tuple (in the format returned by :func:`sys.exc_info`) is provided, it is used; otherwise, :func:`sys.exc_info` is called to get the exception information. - The other optional keyword argument is *extra* which can be used to pass a + The second optional keyword argument is *stack_info*, which defaults to + False. If specified as True, stack information is added to the logging + message, including the actual logging call. Note that this is not the same + stack information as that displayed through specifying *exc_info*: The + former is stack frames from the bottom of the stack up to the logging call + in the current thread, whereas the latter is information about stack frames + which have been unwound, following an exception, while searching for + exception handlers. + + You can specify *stack_info* independently of *exc_info*, e.g. to just show + how you got to a certain point in your code, even when no exceptions were + raised. The stack frames are printed following a header line which says:: + + Stack (most recent call last): + + This mimics the `Traceback (most recent call last):` which is used when + displaying exception frames. + + The third keyword argument is *extra* which can be used to pass a dictionary which is used to populate the __dict__ of the LogRecord created for the logging event with user-defined attributes. These custom attributes can then be used as you like. For example, they could be incorporated into logged @@ -1078,6 +1116,9 @@ instantiated directly, but always through the module-level function above example). In such circumstances, it is likely that specialized :class:`Formatter`\ s would be used with particular :class:`Handler`\ s. + .. versionadded:: 3.2 + The *stack_info* parameter was added. + .. method:: Logger.info(msg, *args, **kwargs) @@ -1142,10 +1183,11 @@ instantiated directly, but always through the module-level function Removes the specified handler *hdlr* from this logger. -.. method:: Logger.findCaller() +.. method:: Logger.findCaller(stack_info=False) Finds the caller's source filename and line number. Returns the filename, line - number and function name as a 3-element tuple. + number, function name and stack information as a 4-element tuple. The stack + information is returned as *None* unless *stack_info* is *True*. .. method:: Logger.handle(record) @@ -1156,7 +1198,7 @@ instantiated directly, but always through the module-level function Logger-level filtering is applied using :meth:`~Logger.filter`. -.. method:: Logger.makeRecord(name, lvl, fn, lno, msg, args, exc_info, func=None, extra=None) +.. method:: Logger.makeRecord(name, lvl, fn, lno, msg, args, exc_info, func=None, extra=None, sinfo=None) This is a factory method which can be overridden in subclasses to create specialized :class:`LogRecord` instances. @@ -3043,6 +3085,9 @@ Currently, the useful mapping keys in a :class:`LogRecord` are: formatter to handle the event doesn't use the cached value but recalculates it afresh. + If stack information is available, it's appended after the exception + information, using :meth:`formatStack` to transform it if necessary. + .. method:: formatTime(record, datefmt=None) @@ -3062,6 +3107,12 @@ Currently, the useful mapping keys in a :class:`LogRecord` are: just uses :func:`traceback.print_exception`. The resulting string is returned. + .. method:: formatStack(stack_info) + + Formats the specified stack information (a string as returned by + :func:`traceback.print_stack`, but with the last newline removed) as a + string. This default implementation just returns the input value. + .. _filter: Filter Objects @@ -3131,7 +3182,7 @@ every time something is logged, and can be created manually via wire). -.. class:: LogRecord(name, lvl, pathname, lineno, msg, args, exc_info, func=None) +.. class:: LogRecord(name, lvl, pathname, lineno, msg, args, exc_info, func=None, sinfo=None) Contains all the information pertinent to the event being logged. @@ -3178,6 +3229,12 @@ wire). Absolute pathname of the source file of origin. + .. attribute:: stack_info + + Stack frame information (where available) from the bottom of the stack + in the current thread, up to and including the stack frame of the + logging call which resulted in the creation of this record. + .. method:: getMessage() Returns the message for this :class:`LogRecord` instance after merging any diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index f03d9f2..c4229e9 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -238,7 +238,7 @@ class LogRecord(object): information to be logged. """ def __init__(self, name, level, pathname, lineno, - msg, args, exc_info, func=None): + msg, args, exc_info, func=None, sinfo=None): """ Initialize a logging record with interesting information. """ @@ -272,6 +272,7 @@ class LogRecord(object): self.module = "Unknown module" self.exc_info = exc_info self.exc_text = None # used to cache the traceback text + self.stack_info = sinfo self.lineno = lineno self.funcName = func self.created = ct @@ -515,6 +516,19 @@ class Formatter(object): def formatMessage(self, record): return self._style.format(record) + def formatStack(self, stack_info): + """ + This method is provided as an extension point for specialized + formatting of stack information. + + The input data is a string as returned from a call to + :func:`traceback.print_stack`, but with the last trailing newline + removed. + + The base implementation just returns the value passed in. + """ + return stack_info + def format(self, record): """ Format the specified record as text. @@ -541,6 +555,10 @@ class Formatter(object): if s[-1:] != "\n": s = s + "\n" s = s + record.exc_text + if record.stack_info: + if s[-1:] != "\n": + s = s + "\n" + s = s + self.formatStack(record.stack_info) return s # @@ -1213,11 +1231,12 @@ class Logger(Filterer): if self.isEnabledFor(ERROR): self._log(ERROR, msg, args, **kwargs) - def exception(self, msg, *args): + def exception(self, msg, *args, **kwargs): """ Convenience method for logging an ERROR with exception information. """ - self.error(msg, exc_info=1, *args) + kwargs['exc_info'] = True + self.error(msg, *args, **kwargs) def critical(self, msg, *args, **kwargs): """ @@ -1250,7 +1269,7 @@ class Logger(Filterer): if self.isEnabledFor(level): self._log(level, msg, args, **kwargs) - def findCaller(self): + def findCaller(self, stack_info=False): """ Find the stack frame of the caller so that we can note the source file name, line number and function name. @@ -1260,23 +1279,34 @@ class Logger(Filterer): #IronPython isn't run with -X:Frames. if f is not None: f = f.f_back - rv = "(unknown file)", 0, "(unknown function)" + rv = "(unknown file)", 0, "(unknown function)", None while hasattr(f, "f_code"): co = f.f_code filename = os.path.normcase(co.co_filename) if filename == _srcfile: f = f.f_back continue - rv = (co.co_filename, f.f_lineno, co.co_name) + sinfo = None + if stack_info: + sio = io.StringIO() + sio.write('Stack (most recent call last):\n') + traceback.print_stack(f, file=sio) + sinfo = sio.getvalue() + if sinfo[-1] == '\n': + sinfo = sinfo[:-1] + sio.close() + rv = (co.co_filename, f.f_lineno, co.co_name, sinfo) break return rv - def makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=None, extra=None): + def makeRecord(self, name, level, fn, lno, msg, args, exc_info, + func=None, extra=None, sinfo=None): """ A factory method which can be overridden in subclasses to create specialized LogRecords. """ - rv = _logRecordClass(name, level, fn, lno, msg, args, exc_info, func) + rv = _logRecordClass(name, level, fn, lno, msg, args, exc_info, func, + sinfo) if extra is not None: for key in extra: if (key in ["message", "asctime"]) or (key in rv.__dict__): @@ -1284,17 +1314,18 @@ class Logger(Filterer): rv.__dict__[key] = extra[key] return rv - def _log(self, level, msg, args, exc_info=None, extra=None): + def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False): """ Low-level logging routine which creates a LogRecord and then calls all the handlers of this logger to handle the record. """ + sinfo = None if _srcfile: #IronPython doesn't track Python frames, so findCaller throws an #exception on some versions of IronPython. We trap it here so that #IronPython can use logging. try: - fn, lno, func = self.findCaller() + fn, lno, func, sinfo = self.findCaller(stack_info) except ValueError: fn, lno, func = "(unknown file)", 0, "(unknown function)" else: @@ -1302,7 +1333,8 @@ class Logger(Filterer): if exc_info: if not isinstance(exc_info, tuple): exc_info = sys.exc_info() - record = self.makeRecord(self.name, level, fn, lno, msg, args, exc_info, func, extra) + record = self.makeRecord(self.name, level, fn, lno, msg, args, + exc_info, func, extra, sinfo) self.handle(record) def handle(self, record): @@ -1657,12 +1689,13 @@ def error(msg, *args, **kwargs): basicConfig() root.error(msg, *args, **kwargs) -def exception(msg, *args): +def exception(msg, *args, **kwargs): """ Log a message with severity 'ERROR' on the root logger, with exception information. """ - error(msg, exc_info=1, *args) + kwargs['exc_info'] = True + error(msg, *args, **kwargs) def warning(msg, *args, **kwargs): """ @@ -63,6 +63,8 @@ Core and Builtins Library ------- +- Issue #1553375: logging: Added stack_info kwarg to display stack information. + - Issue #5111: IPv6 Host in the Header is wrapped inside [ ]. Patch by Chandru. - Fix Fraction.__hash__ so that Fraction.__hash__(-1) is -2. (See also issue |