How do I log a Python error with debug information?

Question

I am printing Python exception messages to a log file with logging.error:

import logging
try:
    1/0
except ZeroDivisionError as e:
    logging.error(e)  # ERROR:root:division by zero

Is it possible to print more detailed information about the exception and the code that generated it than just the exception string? Things like line numbers or stack traces would be great.

Fastback

Answer 1

logger.exception will output a stack trace alongside the error message.

For example:

import logging
try:
    1/0
except ZeroDivisionError:
    logging.exception("message")

Output:

ERROR:root:message
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
ZeroDivisionError: integer division or modulo by zero

@Paulo Cheque notes, "be aware that in Python 3 you must call the logging.exception method just inside the except part. If you call this method in an arbitrary place you may get a bizarre exception. The docs alert about that."

Achromat

The exception method simply calls error(message, exc_info=1). As soon as you pass exc_info to any of the logging methods from an exception context, you will get a traceback. – Landlord

You can also set sys.excepthook (see here) to avoid having to wrap all your code in try/except. – Diorama

You could just write except Exception: because you are not using e in any way ;) – Dx

You may very well want to inspect e when attempting to interactively debug your code. :) This is why I always include it. – Shad

This approach produce multiple lines in your log (for one event) file which is not a good practice. You can see my solution here – Lucarne

Why except Exception as e: when e is never used? – Whispering

Correct me if I'm wrong, in this case, there is no real handling of the exception and therefore it make sense to add raise at the end of the except scope. Otherwise, running will continue as if everything was fine. – Rosenquist

@Rosenquist - it depends. In this case, the code is literally designed to force a ZeroDivisionError and log it, so I mean, it's doing its job. – Cavender

If you want to log the long traceback at a different log level, then do logging.error("message"); logging.debug(e, exc_info=True), or whichever level you prefer. – Cavender

@Cavender the exception handling is merely printing the error. Afterward, the program will continue running. If you actually need to break the run, after logging, you need to re-raise the exception. – Rosenquist

@MarcoFerrari, additionally, a bare except will catch SystemExit and KeyboardInterrupt, which may not be intended. except Exception as e won't catch these. docs.python.org/3/library/exceptions.html#exception-hierarchy – Coyotillo

You can also do logging.exception(e) if you can't think of a good thing to pass here. – Algology

IMHO, error(message, exc_info=1) which is equivalent to exception method, is much more readable. – Doublestop

Answer 2

Using exc_info options may be better, to allow you to choose the error level (if you use exception, it will always be at the error level):

try:
    # do something here
except Exception as e:
    logging.critical(e, exc_info=True)  # log exception info at CRITICAL log level

Besant

@CivFan: I didn't actually look at the other edits or the post intro; that intro was also added by a 3rd-party editor. I don't see anywhere in the deleted comments that that was ever the intention, but I may as well undo my edit and remove the comments, it is has been too long for the voting here to have been for anything other than the edited version. – Shrunk

Is logging.fatal a method in the logging library? I only see critical. – Thorough

@Thorough It's an alias to critical, just like warn is to warning. – Activist

If we use exc_info, is there any additional value from also logging the e? – Gine

Answer 3

One nice thing about logging.exception that SiggyF's answer doesn't show is that you can pass in an arbitrary message, and logging will still show the full traceback with all the exception details:

import logging
try:
    1/0
except ZeroDivisionError:
    logging.exception("Deliberate divide by zero traceback")

With the default (in recent versions) logging behaviour of just printing errors to sys.stderr, it looks like this:

>>> import logging
>>> try:
...     1/0
... except ZeroDivisionError:
...     logging.exception("Deliberate divide by zero traceback")
... 
ERROR:root:Deliberate divide by zero traceback
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
ZeroDivisionError: integer division or modulo by zero

Cogitation

Can an exception be logged without providing a message? – Hypoderm

@StevenVascellaro - I'd suggest you pass '' if you really don't want to type a message... the function can't be called without at least one argument, though, so you'll have to give it something. – Lang

@Cogitation can you please suggest the solution for the following question: #68169256 – Carcinomatosis

Answer 4

Quoting

What if your application does logging some other way – not using the logging module?

Now, traceback could be used here.

import traceback

def log_traceback(ex, ex_traceback=None):
    if ex_traceback is None:
        ex_traceback = ex.__traceback__
    tb_lines = [ line.rstrip('\n') for line in
                 traceback.format_exception(ex.__class__, ex, ex_traceback)]
    exception_logger.log(tb_lines)

• Use it in Python 2:

  try:
      # your function call is here
  except Exception as ex:
      _, _, ex_traceback = sys.exc_info()
      log_traceback(ex, ex_traceback)
  

• Use it in Python 3:

  try:
      x = get_number()
  except Exception as ex:
      log_traceback(ex)
  

Announce

Why did you place "_, _, ex_traceback = sys.exc_info()" outside the function log_traceback and then pass it as an argument? Why not use it directly inside the function? – Reduplication

@BasilMusa, to answer your question, in short, to compatible with Python 3, because the ex_traceback is from ex.__traceback__ under Python 3, but ex_traceback is from sys.exc_info() under Python 2. – Announce

Why not using traceback.format_exc() rather than traceback.format_exception(...)? – Workout

Answer 5

You can log the stack trace without an exception.

https://docs.python.org/3/library/logging.html#logging.Logger.debug

The second optional keyword argument is stack_info, which defaults to False. If 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.

Example:

>>> import logging
>>> logging.basicConfig(level=logging.DEBUG)
>>> logging.getLogger().info('This prints the stack', stack_info=True)
INFO:root:This prints the stack
Stack (most recent call last):
  File "<stdin>", line 1, in <module>
>>>

Muffle

Answer 6

If you use plain logs - all your log records should correspond this rule: one record = one line. Following this rule you can use grep and other tools to process your log files.

But traceback information is multi-line. So my answer is an extended version of solution proposed by zangw above in this thread. The problem is that traceback lines could have \n inside, so we need to do an extra work to get rid of this line endings:

import logging


logger = logging.getLogger('your_logger_here')

def log_app_error(e: BaseException, level=logging.ERROR) -> None:
    e_traceback = traceback.format_exception(e.__class__, e, e.__traceback__)
    traceback_lines = []
    for line in [line.rstrip('\n') for line in e_traceback]:
        traceback_lines.extend(line.splitlines())
    logger.log(level, traceback_lines.__str__())

After that (when you'll be analyzing your logs) you could copy / paste required traceback lines from your log file and do this:

ex_traceback = ['line 1', 'line 2', ...]
for line in ex_traceback:
    print(line)

Profit!

Lucarne

Answer 7

This answer builds up from the above excellent ones.

In most applications, you won't be calling logging.exception(e) directly. Most likely you have defined a custom logger specific for your application or module like this:

# Set the name of the app or module
my_logger = logging.getLogger('NEM Sequencer')
# Set the log level
my_logger.setLevel(logging.INFO)

# Let's say we want to be fancy and log to a graylog2 log server
graylog_handler = graypy.GELFHandler('some_server_ip', 12201)
graylog_handler.setLevel(logging.INFO)
my_logger.addHandler(graylog_handler)

In this case, just use the logger to call the exception(e) like this:

try:
    1/0
except ZeroDivisionError, e:
    my_logger.exception(e)

Plenty

This is a useful finish touch indeed if you want a dedicated logger just for exceptions. – Whilst

Answer 8

If "debugging information" means the values present when exception was raised, then logging.exception(...) won't help. So you'll need a tool that logs all variable values along with the traceback lines automatically.

Out of the box you'll get log like

2020-03-30 18:24:31 main ERROR   File "./temp.py", line 13, in get_ratio
2020-03-30 18:24:31 main ERROR     return height / width
2020-03-30 18:24:31 main ERROR       height = 300
2020-03-30 18:24:31 main ERROR       width = 0
2020-03-30 18:24:31 main ERROR builtins.ZeroDivisionError: division by zero

Have a look at some pypi tools, I'd name:

• tbvaccine
• traceback-with-variables
• better-exceptions

Some of them give you pretty crash messages:

But you might find some more on pypi

Revetment

Answer 9

A little bit of decorator treatment (very loosely inspired by the Maybe monad and lifting). You can safely remove Python 3.6 type annotations and use an older message formatting style.

fallible.py

from functools import wraps
from typing import Callable, TypeVar, Optional
import logging


A = TypeVar('A')


def fallible(*exceptions, logger=None) \
        -> Callable[[Callable[..., A]], Callable[..., Optional[A]]]:
    """
    :param exceptions: a list of exceptions to catch
    :param logger: pass a custom logger; None means the default logger, 
                   False disables logging altogether.
    """
    def fwrap(f: Callable[..., A]) -> Callable[..., Optional[A]]:

        @wraps(f)
        def wrapped(*args, **kwargs):
            try:
                return f(*args, **kwargs)
            except exceptions:
                message = f'called {f} with *args={args} and **kwargs={kwargs}'
                if logger:
                    logger.exception(message)
                if logger is None:
                    logging.exception(message)
                return None

        return wrapped

    return fwrap

Demo:

In [1] from fallible import fallible

In [2]: @fallible(ArithmeticError)
    ...: def div(a, b):
    ...:     return a / b
    ...: 
    ...: 

In [3]: div(1, 2)
Out[3]: 0.5

In [4]: res = div(1, 0)
ERROR:root:called <function div at 0x10d3c6ae8> with *args=(1, 0) and **kwargs={}
Traceback (most recent call last):
  File "/Users/user/fallible.py", line 17, in wrapped
    return f(*args, **kwargs)
  File "<ipython-input-17-e056bd886b5c>", line 3, in div
    return a / b

In [5]: repr(res)
'None'

You can also modify this solution to return something a bit more meaningful than None from the except part (or even make the solution generic, by specifying this return value in fallible's arguments).

Waterproof

Answer 10

Since Python 3.5, it's possible to explicitly specify the exception in the logging function:

try:
    1/0
except Exception as ex:
    logging.error("Error occurred", exc_info = ex)

The logging.exception function still works but must be called only within the except block and does not allow specifying log level.

Wismar

This is the best answer. It works on all log levels and also if the logging happens somewhere else, outside of the except-block. – Cockatoo

Answer 11

In your logging module(if custom module) just enable stack_info.

api_logger.exceptionLog("*Input your Custom error message*",stack_info=True)

Lloyd

Answer 12

If you look at the this code example (which works for Python 2 and 3) you'll see the function definition below which can extract

• method
• line number
• code context
• file path

for an entire stack trace, whether or not there has been an exception:

def sentry_friendly_trace(get_last_exception=True):
    try:
        current_call = list(map(frame_trans, traceback.extract_stack()))
        alert_frame = current_call[-4]
        before_call = current_call[:-4]

        err_type, err, tb = sys.exc_info() if get_last_exception else (None, None, None)
        after_call = [alert_frame] if err_type is None else extract_all_sentry_frames_from_exception(tb)

        return before_call + after_call, err, alert_frame
    except:
        return None, None, None

Of course, this function depends on the entire gist linked above, and in particular extract_all_sentry_frames_from_exception() and frame_trans() but the exception info extraction totals less than around 60 lines.

Hope that helps!

Attar

Answer 13

I wrap all functions around my custom designed logger:

import json
import timeit
import traceback
import sys
import unidecode

def main_writer(f,argument):
  try:
    f.write(str(argument))
  except UnicodeEncodeError:
    f.write(unidecode.unidecode(argument))


def logger(*argv,logfile="log.txt",singleLine = False):
  """
  Writes Logs to LogFile
  """
  with open(logfile, 'a+') as f:
    for arg in argv:
      if arg == "{}":
        continue
      if type(arg) == dict and len(arg)!=0:
        json_object = json.dumps(arg, indent=4, default=str)
        f.write(str(json_object))
        f.flush()
        """
        for key,val in arg.items():
          f.write(str(key) + " : "+ str(val))
          f.flush()
        """
      elif type(arg) == list and len(arg)!=0:
        for each in arg:
          main_writer(f,each)
          f.write("\n")
          f.flush()
      else:
        main_writer(f,arg)
        f.flush()
      if singleLine==False:
        f.write("\n")
    if singleLine==True:
      f.write("\n")

def tryFunc(func, func_name=None, *args, **kwargs):
  """
  Time for Successfull Runs
  Exception Traceback for Unsuccessful Runs
  """
  stack = traceback.extract_stack()
  filename, codeline, funcName, text = stack[-2]
  func_name = func.__name__ if func_name is None else func_name # sys._getframe().f_code.co_name # func.__name__
  start = timeit.default_timer()
  x = None
  try:
    x = func(*args, **kwargs)
    stop = timeit.default_timer()
    # logger("Time to Run {} : {}".format(func_name, stop - start))
  except Exception as e:
    logger("Exception Occurred for {} :".format(func_name))
    logger("Basic Error Info :",e)
    logger("Full Error TraceBack :")
    # logger(e.message, e.args)
    logger(traceback.format_exc())
  return x

def bad_func():
  return 'a'+ 7

if __name__ == '__main__':
    logger(234)
    logger([1,2,3])
    logger(['a','b','c'])
    logger({'a':7,'b':8,'c':9})
    tryFunc(bad_func)

Tracitracie

Answer 14

My approach was to create a context manager, to log and raise Exceptions:

import logging
from contextlib import AbstractContextManager


class LogError(AbstractContextManager):

    def __init__(self, logger=None):
        self.logger = logger.name if isinstance(logger, logging.Logger) else logger

    def __exit__(self, exc_type, exc_value, traceback):
        if exc_value is not None:
            logging.getLogger(self.logger).exception(exc_value)


with LogError():
    1/0

You can either pass a logger name or a logger instance to LogError(). By default it will use the base logger (by passing None to logging.getLogger). One could also simply add a switch for raising the error or just logging it.

Descendent

this answer is out of the question scope/. – Vicechairman

Answer 15

The best and minimal library for doing this is loguru, which shows an in-baked traceback and provides debug info:

import sys
from loguru import logger
logger.add(sys.stdout, level="TRACE")

try:
    a = 1/0
except Exception as err:
    logger.exception(str(err), backtrace=True, diagnose=True)

Outputs:

2023-08-09 10:46:53.669 | ERROR    | __main__:<module>:8 - division by zero
Traceback (most recent call last):

> File "new.py", line 6, in <module>
    a = 1/0

ZeroDivisionError: division by zero

Tracitracie

Answer 16

If you can cope with the extra dependency then use twisted.log, you don't have to explicitly log errors and also it returns the entire traceback and time to the file or stream.

Octopus

Perhaps twisted is a good recommendation, but this answer doesn't really contribute much. It doesn't say how to use twisted.log, nor what advantages it has over the logging module from the standard library, nor explain what's meant by "you don't have to explicitly log errors". – Shedevil

Answer 17

A clean way to do it is using format_exc() and then parse the output to get the relevant part:

from traceback import format_exc

try:
    1/0
except Exception:
    print 'the relevant part is: '+format_exc().split('\n')[-2]

Regards

Darken

Huh? Why is that "the relevant part"? All the .split('\n')[-2] does is throw away the line number and traceback from the result of format_exc() - useful information you normally want! What's more, it doesn't even do a good job of that; if your exception message contains a newline, then this approach will only print the final line of the exception message - meaning that you lose the exception class and most of the exception message on top of losing the traceback. -1. – Shedevil