How can I include the caller in debug logging from Python constructors?

Question

I have a class C which is instantiated all over the place in a large program. C.__init__() contains debug logging, giving the parameters passed in to the new instance.

It's often useful for these log entries to include the name of the function that instantiated the C. This can be done using traceback. But arguments to debug log statements should never have side-effects, because in practice they're almost always no-ops. How then can this be achieved?

Answer 1

It can be done with a singleton object whose representation is the name of its caller (or its caller's caller, or...):

   logger.debug("new C instance, with a=%d, b=%d, called from %s",
        a, b, show_caller)

There is then the problem of how far to search back up the call stack: we will have to bypass several layers of calls within the logging library, and the constructor which called us.

I have solved this by assuming that show_caller's class lives in a package with a name similar to the package of the caller. For example, it could be wombat.spong.C calling wombat.util.ShowCaller. The variable DEPTH gives how many names the two should share.

This is not a very satisfactory solution, but it works.

So we have:

import os

class _ShowCaller:
    """
    Singleton class whose representation names the caller of the caller.

    The object of this class does nothing in particular most of the time.
    But when you use it in the parameters of a logging statement, thus:

    ```
        logger.debug("ready; was called from %s", show_caller)
    ```

    it returns a string giving the name, filename, and line number
    of the caller of the method containing the logging statement.

    If this was done using a function call, the call would take place
    every time the logging statement was executed, even in production
    where it would be a no-op.

    Attributes:
        DEPTH (`int`): how many levels of directory we should consider
            to be part of our package, rather than being library modules.
    """

    DEPTH = 1

    def __init__(self):
        self.prefix = os.path.sep.join(
                __file__.split(os.path.sep)[:-self.DEPTH]
        )

    def __repr__(self):
        import traceback

        stack = reversed(list(enumerate(traceback.extract_stack()[:-1])))

        for i, caller in stack:
            if caller.filename.startswith(self.prefix):
                break

        try:
            i, caller = next(stack)
            return '%s (%s:%s)' % (
                    caller.name,
                    caller.filename[len(self.prefix)+1:],
                    caller.lineno,
                    )
        except StopIteration:
            return '???'

show_caller = _ShowCaller()