Race condition: CLPLogLevelTimeout and the logging handler may concurrently write to the underlying output stream. #55
Description
Bug
In the current implementation, both CLPLogLevelTimeout and CLP logging handlers could write to the underlying stream concurrently without locking the stream. The write operation involves the stream's write and flush methods. The potential types of streams are Python built-in byte IO stream and zstdandard's streaming compressor writer.
This is problematic because the underlying write operation may release the GIL. For example:
- In Python's file stream: https://github.com/python/cpython/blob/cdcacec79f7a216c3c988baa4dc31ce4e76c97ac/Python/fileutils.c#L1963
- In zstd's streaming compressor: https://github.com/indygreg/python-zstandard/blob/12a80fac558820adf43e6f16206120685b9eb880/c-ext/compressionwriter.c#L95
The bug was first triggered in a dev branch when supporting serializing key-value pair log events into CLP key-value pair IR streams. Both the logging handler and the timeout handler attempt to write into the zstd stream, causing a race condition that leads to a segfault. It's been verified that the bug will be resolved by removing the above liens from Python and zstd's source code, or by adding a lock to ensure mutually exclusive access to the stream.
To conclude, our engineering decision through the offline discussion is to add a lock for mutual exclusion.
Python clp-logging version
Environment
This bug should exist in any platform/environment we currently support.
Reproduction steps
There are no specific steps to reproduce this bug since it is triggered in a dev branch with some code that won't be merged.
However, we've collected enough evidence that race conditions could happen and we should lock the timeout handler properly.