CloudWatchLogHandler deadlocks when used with PYTHONBREAKPOINT=ipdb.set_trace #197
Comments
|
Thanks for your proposed solution! I am definitely interested in setting timeouts and implementing it as you describe. |
|
The queue wait timeout was implemented in ebf368f and released in v3.2.0. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Versions:
Reproduction
The following script will hang when run with
PYTHONBREAKPOINT=ipdb.set_traceThe running process has the following stacktraces:
What is going on?
The top thread is the handler thread dequeuing messages
And the bottom is the main thread.
The main thread is waiting for the queue to be emptied,
And the handler thread is waiting to acquire the global lock in the
logging, which is already held byDictConfigurator.configurein the main thread.The handler thread has to acquire the global lock in
Logger.isEnabledForbecause importingipdbas a side effect callsLogger.setLevel(…)which invalidates the enabled level cache of allLoggerinstances, and then callslogging.config.dictConfigwhich tries to shutdown all existing handlers.This can also be reproduced if
breakpoint()is replaced by:This is results in a pretty straightforward deadlock, the handler thread is not able to actually send the logs to cloudwatch so it's never able to empty the queue.
Solutions?
The current behavior of
flushis that it waits for the queue to be empty usingqueue.Queue.joinThis doesn't take a timeout, however it is implemented as:
and
queue.Queue.all_tasks_doneis athreading.Conditionandthreading.Condition.waitdoes take a timeout. So it is possible to implement ajointhat does timeout as well.flushcould also be modified to send(self.FLUSH, flush_condition)for each queue, and then wait on then callflush_condition.wait(timeout)to wait for the specific flush message to have been processed.This changes the behavior of
flushunder load though, from waiting until the queue is empty to waiting until a specific flush is processed, if you have a system where flush is called from multiple threads each would only wait until it's flush message was processed and then proceed.But this might be the more straightforward behavior as it is could be counter intuitive given a queue state of:
msg1, msg2, msg3, flush, msg4, msg5forflushto block untilmsg5is delivered.Once
flush/closeare able to timeout at all, they could also be taught to check ifself.sequence_tokens[log_stream_name]has changed in the timeout case, allowing them to wait as long as batches are still able to be submitted.The text was updated successfully, but these errors were encountered: