Codebase list logbook / debian/1.5.3-1 docs / performance.rst

Tree @debian/1.5.3-1 (Download .tar.gz)

performance.rst @debian/1.5.3-1raw · history · blame

Performance Tuning

The more logging calls you add to your application and libraries, the more
overhead will you introduce.  There are a couple things you can do to
remedy this behavior.

Debug-Only Logging

There are debug log calls, and there are debug log calls.  Some debug log
calls would sometimes be interesting in a production environment, others
really only if you are on your local machine fiddling around with the
code.  Logbook internally makes sure to process as little of your logging
call as necessary, but it will still have to walk the current stack to
figure out if there are any active handlers or not.  Depending on the
number of handlers on the stack, the kind of handler etc, there will be
more or less processed.

Generally speaking a not-handled logging call is cheap enough that you
don't have to care about it.  However there is not only your logging call,
there might also be some data you have to process for the record.  This
will always be processed, even if the log record ends up being discarded.

This is where the Python ``__debug__`` feature comes in handy.  This
variable is a special flag that is evaluated at the time where Python
processes your script.  It can eliminate code completely from your script
so that it does not even exist in the compiled bytecode (requires Python
to be run with the ``-O`` switch)::

    if __debug__:
        info = get_wallcalculate_debug_info()
        logger.debug("Call to response() failed.  Reason: {0}", info)

Keep the Fingers Crossed

Do you really need the debug info?  In case you find yourself only looking
at the logfiles when errors occurred it would be an option to put in the
:class:`~logbook.FingersCrossedHandler`.  Logging into memory is always
cheaper than logging on a filesystem.

Keep the Stack Static

Whenever you do a push or pop from one of the stacks you will invalidate
an internal cache that is used by logbook.  This is an implementation
detail, but this is how it works for the moment.  That means that the
first logging call after a push or pop will have a higher impact on the
performance than following calls.  That means you should not attempt to
push or pop from a stack for each logging call.  Make sure to do the
pushing and popping only as needed.  (start/end of application/request)

Disable Introspection

By default Logbook will try to pull in the interpreter frame of the caller
that invoked a logging function.  While this is a fast operation that
usually does not slow down the execution of your script it also means that
for certain Python implementations it invalidates assumptions a JIT
compiler might have made of the function body.  Currently this for example
is the case for applications running on pypy.  If you would be using a
stock logbook setup on pypy, the JIT wouldn't be able to work properly.

In case you don't need the frame based information (name of module,
calling function, filename, line number) you can disable the introspection

    from logbook import Flags

    with Flags(introspection=False):
        # all logging calls here will not use introspection