Logging: logging the place where a class is instantiated

Question

I wnat to log all file write operations across scripts, and I want the info of which method/class made the write operation. For example, I have this code

import logging

logger = logging.getLogger('root')
#FORMAT = "[%(filename)s:%(funcName)20s() ] %(message)s"
#logging.basicConfig(format=FORMAT)
logger.setLevel(logging.DEBUG)


class FileWrite:
    def __init__(self,filename):
        self.filename = filename
        self.f = open(filename,'w')

    def __enter__(self):
        return self.f

    def __exit__(self):
        self.f.close()
        logger.debug("Write to: {}".format(self.filename))

I want to be able to also log which method made the write operation, when I run code like this

class A:
    def a():
        with FileWrite("file.txt") as f:
            f.write("something")

It should be logged that "file.txt" was written by method A.a

Still, this http://stackoverflow.com/questions/5067604/determine-function-name-from-within-that-function-without-using-traceback might help you. — pavel_form, Oct 22 '14 at 17:51

abarnert · Accepted Answer · 2014-10-22T18:47:40.880

This is one of those things that you normally shouldn't do… but occasionally it makes sense. I'm not sure whether your case qualifies or not, but I'll show you how to do it.

What you're looking for is information about the function that called the current frame. The interpreter stack in the inspect docs shows how you can get this information:

frame = inspect.currentframe()
caller = frame.f_back
name = caller.f_code.co_name

A few things to notice:

This gives you the name of the code object, which is the name used as def time, which may not be the same as the name the function was called as. Importantly, in your case, at def time this is just a function, a, not a method, A.a, so you're not going to get the latter. (Notice that tracebacks print bare function names the same way—that's because they have the same information you have here.)
You can also get things like the filename and line number (again, those will be as of the def statement), and armed with that info the inspect module can get even more information.
In some cases, the "frame record" returned by inspect.stack(1)[1] might have more "run-time-y" rather than define-time information, but not in general. (Much of the info is pulled straight from the frame attributes, but some of it is overridden by information pulled out of the source, if available. See getframeinfo for details.) For example, you could look at inspect.stack(1)[2][4] to get the source line my_A_instance.a(), which you might find interesting.
This requires Python 3.4. If you're using 3.3 or earlier, as long as you only care about CPython, caller = sys._getframe(1) can effectively replace the first two lines.
If your app is multithreaded (or green-threaded), you may want to explicitly del or .clear() the frame objects before calling anything slow/blocking, like logger.debug.

Logging: logging the place where a class is instantiated

1 Answers1