Is chronological order of logging messages guaranteed?

Question

I'm using the logging module to log messages from an application server. More specifically, I use a StreamHandler to log messages to stdout/stderr, and use Supervisord to log those messages to files (since the server process is monitored by Supervisord).

My main question is, does the order of messages in the log file always truthfully reflect the order of execution of the code? For example, if a message A: this is log msg A appears before message B: this is log msg B in a log file, then can we be 100% certain that the line of code that logs message A was executed before the line of the code that logs message B, even if the timestamps of the two messages in the log file are the same?

Answer 1

You can't be be 100% sure, I'm pretty sure.

Although the logging module locks the output file before writing to it, if you're running multiple threads or processes there's no guarantee that your code that called logging.warning("A") or whatever actually acquires the lock if several other threads are trying to do the same at around the same time.

See also the docs for logging and also its source. We see that it uses threading.RLock, about which the docs say:

If more than one thread is blocked waiting until the lock is unlocked, only one at a time will be able to grab ownership of the lock. There is no return value in this case.

We can't be entirely certain of which thread gets the lock first, which is the problem.