Managing logs/warnings in Python extensions

Question

TL;DR version: What do you use for configurable (and preferably captured) logging inside your C++ bits in a Python project? Details follow.

Say you have a a few compiled .so modules that may need to do some error checking and warn user of (partially) incorrect data. Currently I'm having a pretty simplistic setup where I'm using logging framework from Python code and log4cxx library from C/C++. log4cxx log level is defined in a file (log4cxx.properties) and is currently fixed and I'm thinking how to make it more flexible. Couple of choices that I see:

1. One way to control it would be to have a module-wide configuration call.

   # foo/__init__.py
   import sys
   from _foo import import bar, baz, configure_log
   configure_log(sys.stdout, WARNING)
   
   
   # tests/test_foo.py
   def test_foo():
       # Maybe a custom context to change the logfile for 
       # the module and restore it at the end.
       with CaptureLog(foo) as log:
           assert foo.bar() == 5
           assert log.read() == "124.24 - foo - INFO - Bar returning 5"
   

2. Have every compiled function that does logging accept optional log parameters.

   # foo.c
   int bar(PyObject* x, PyObject* logfile, PyObject* loglevel) {
       LoggerPtr logger = default_logger("foo");
       if (logfile != Py_None)
           logger = file_logger(logfile, loglevel);
       ...
   }
   
   
   # tests/test_foo.py
   def test_foo():
       with TemporaryFile() as logfile:
           assert foo.bar(logfile=logfile, loglevel=DEBUG) == 5
           assert logfile.read() == "124.24 - foo - INFO - Bar returning 5"
   

3. Some other way?

Second one seems to be somewhat cleaner, but it requires function signature alteration (or using kwargs and parsing them). First one is.. probably somewhat awkward but sets up entire module in one go and removes logic from each individual function.

What are your thoughts on this? I'm all ears to alternative solutions as well.

Thanks,

Answer 1

I'm a big believer in having as much work happen in Python as possible, leaving only the work that has to happen in C in C. So I like #2 better than #1, but you are right, it clutters up all your function signatures.

I'd create a module-level object to handle the logging, sort of like a callback. The Python code could create the object any way it likes, then assign it to the module object. The C code can simply use the global object to do its logging:

# Python:

import my_compiled_module

def log_it(level, msg):
    print "%s: Oh, look: %s" % (level, msg)

my_compiled_module.logger = log_it

# C

static void log_it(unsigned int level, char * msg)
{
    PyObject * args = Py_BuildValue("(Is)", level, msg);
    PyObject_Call(log_it, args, NULL);
    Py_DECREF(args);
}

Now you can simply call the C log_it function throughout your code, and not worry about how the Python code gets it done. Of course, your Python log_it function would be richer than this one, and it would let you get all of your logging integrated into one Python logger.