Independent logging in multithreaded applications

Question

I'm currently debugging a multithreaded application (pthread under Linux ia64, ARM). valgrind, helgrind, and gdb are my currently used tools.

There are some synchronizing issues and for later analysis, I want to log thread execution to one or more files.

Naive implementation would do some write/fprintf which might (depending on the libc implementation) lock some internal mutex. That would in turn influence the program's behaviour (I would call it 'locking by accident') and is therefore not acceptable.

Searching the internet yields only to the inverse solution, i.e. how to synchronize threads resp. how to log. NB: Third-party logging libraries tend to garuantee multithread-safety but not the opposite as described above.

So I came up with unsynchronized caching the log entries in memory, on a per-thread basis, and flushing that to a file on program exit.

I guess that this is a general problem for many developers and I wonder whether there is a better approach. Any suggestions?

Answer 1

Modern multi-thread safe high performance loggers normally:

• Provide a separate logging buffer for each thread, so that there is no locking involved when a thread writes a log message into the buffer (single-producer-single-consumer wait-free buffer).
• The log messages are binary, no snprintf or any other formatting happens in the thread that emits a log message. E.g. a log message is a copy of the format string and the arguments (the format string can be shallow-copied).
• Have a separate I/O thread that reads the binary logging messages from other threads, formats them and writes into the log file(s).
• The I/O thread does periodic polling on the logging buffers, so that no cross-thread messaging is required when emitting a log message. With an option for the message producer to notify the I/O thread to start writing out the log messages to the log file immediately (e.g. the logging buffer free space is getting low).