OddThinking

This is the official page for the NonBlockingLogHandler Python Package.

Latest Version

The latest version of the package is available from PyPI.

You can download it from there, but if you have easy_install available, you can use:
easy_install nonblockingloghandler

If you prefer PIP, you can use
pip install nonblockingloghandler

Why would I use it?

You would only need it if:

• you are a Python programmer,
• you are writing a real-time system (i.e. one where a late response is a wrong response), AND
• you are using the inbuilt Python logging function to produce log messages that take some time to emit – for example, to send emails.

If all three apply to you, you may find that your thread is suspended indefinitely while waiting for the log message to be emitted. In this way, the logging system can cause disruption to your code’s performance.

This component attempts to overcome such issues.

What Does It Look Like?

The package offers a NonblockingLogHandler class consistent with the Python logging subsystem.

This handler acts as a proxy for the another log handler that may be slow to execute: e.g. the SMTPHandler, SocketHandler, SysLogHandler – especially when they are talking to remote servers.

The slow log handler is passed as a parameter to the constructor of NonblockingLogHandler. The resulting instance is intended to be a drop-in replacement (see provisos below) for the proxied handler. The class returns quickly, and executes the actually logging in the background, in a separate thread.

Provisos

While there has been every effort to make the new instance act as transparently as possible for the normal case, the logging module is highly customisable, and it is possible that some customisations will conflict with the NonblockingLogHandler.

__str__() methods

If you pass objects to the logging functions (such as info() or error(), be aware that their __str__() methods should be fast. I/O bound str() calls are outside the scope of this module.

Execution of str() functions on message parameters and string formatting is done immediately, in the calling thread. This is to guarantee both thread-safety of the logged objects and also that the log shows the object’s values at the time of the call, not the time of the emit.

This means, slow __str__() methods will affect the performance of the calling code.

Subclassed Filter

Most people do not need to subclass from the Filter class. If you do subclass it, be aware that they should be fast. I/O-bound filters are outside of the scope of this module.

Subclassed Formatter

Most people do not need to subclass from the Formatter class. If you do subclass it, note that it will not have the user parameters from the logging call passed to it. It will only receive the resulting message string already formatted according to the client’s wishes. The new subclass can still successfully format dates, threadnames, levels, etc.

The format() and emit() Methods

The NonblockingLogHandler class provides format()S and emit() methods for internal-use only. Clients should not directly call them. Consider them “private”.

Separate Levels and Filter States

Once the NonblockingLogHandler handler is initialised, any further calls to setLevel(), addFilter() and removeFilter() made on the delegated handler are ignored by the proxy handler. Conversely, the delegated handler is not informed of calls made on the NonblockingLogHandler instance.

Best practice is to only update the NonblockingLogHandler handler, and not use the values stored in the delegated handler.

Example Usage

nonblocking_email_handler = nonblockingloghandler.NonblockingLogHandler(
logging.SMTPHandler("localhost", "logging_system", "admin", "Log message")
)
db_logger = logging.getLogger("database")
db_logger.addHandler(nonblocking_email_handler)

db_logger.critical("Database corrupted") # This operation will return immediately, before email is sent.

nonblocking_email_handler.close()


Future Versions

As of Version 1.1.2, there are the following known deficiencies:

• It is only tested on Python 2.7.2, on Windows and Ubuntu. If there is demand, I can widen that.
• There is a rare and intermittent shut-down race condition. It only occurs on Windows.
  • All that happens is, sometimes when your program shuts down immediately after emitting a log message, the Python Runtime emits a warning: “Exception in thread NonblockingLogHandler.[…] (most likely raised during interpreter shutdown)”
  • I suspect it is the same root cause as a bug that was fixed in the Python 3.2 codebase, but was not backported to Python 2.7. I do not have any strong evidence of this conjecture.
• The automated tests require manual inspection to confirm they have run successfully. They should be further automated.
• The tests require editing on Ubuntu – to set the explicit path to Python. This should be transparent.

Version History

1.1.2 – Official release 20-Apr-2013. Identifies, but doesn’t fix, intermittent shut-down bug. Better handling/clarification of appropriate close() behaviour, which is believed to have been interfering with use in daemons on Ubuntu. Better adherence to PEP8 and PEP 396 standards.
1.0.1 – Official release – 6-Jun-2011.
0.3 – First version to be released – works, except performance and stability may fail if called in repeatedly and rapidly, due to thread resource usage.