BewareMyPower
commented
1 year ago Unfortunately this script cannot reproduce the deadlock in my local env. I started a Pulsar standalone 2.11.1 and installed the Python client 3.1.0 on Ubuntu 22.04 with Python 3.8. Then I just modified the topic name to my-topic and run while true; do python3 repro.py; done. The loop has been running for about 30 minutes and it still worked well.
2023-06-01T19:36:56,301+0800 [pulsar-io-19-11] INFO org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:46530] Created new producer: Producer{topic=PersistentTopic{topic=persistent://public/default/my-topic}, client=/127.0.0.1:46530, producerName=standalone-0-2414, producerId=0}
As you can see the suffix of the automatically generated producer name is 2414 so the script has been executed for 2000+ times.
From the stack you provided, it's stuck at ClientConnection::closeSocket when clearing the connections in the pool. Normally, it should just fail with ConnectError. Could you provide some latest logs when the deadlock happened in your environment so I can see the difference?
Though I think this issue should still exist for the latest code, could you also help verify the 3.2.0 candidate 1? https://dist.apache.org/repos/dist/release/pulsar/pulsar-client-python-3.1.0/
I believe it's because the C++ destructors have done many unnecessary things in the destructors. We should keep the destructors simple. Here is another issue related to the destructor: https://github.com/apache/pulsar-client-python/issues/103
The simplest solution might be adding an option to skip all shutdown calls for these C++ classes. But it would be better if I can reproduce it locally then I can verify if this fix works.
zbentley
merlimat
Context:
Bug description:
It's common practice to clear out global connection cached objects after a
forktakes place. That's typically done via theos.register_at_forkmethod in Python.Callbacks to that method are similar to signal handlers: they shouldn't do anything complicated or IO-ful. However something very common to do in an atfork callback is to wipe out a global connection cache, setting it to
Nonein the child process to indicate that a new connection should be opened if needed.We do that with our Pulsar client connections. Since the Pulsar client isn't fork safe at all, we wipe out our global references to it whenever we fork via
register_at_forkhandlers (and our code runs in tons of our internal services that make heavy use of Python forking; this is an extremely common practice in large Python installs: gunicorn, Celery, multiprocessing, billiard, airflow ... all heavily use fork-based concurrency to encapsulate workloads, share expensive-to-load-and-huge pre-forked memory, and evade the GIL).The most common forking system is
multiprocessing, which provides a "run some work concurrency then wrap up" interface.We observed that arbitrary
multiprocessingworkloads across our fleet occasionally hang. Workloads that very frequently invokemultiprocessingpools after publishing to Pulsar were more likely to hang.After some painful production incidents, we arrived at the below reproduction, which indicates an internal Pulsar client deadlock that occurs when a global connection cache is cleared out, triggering destruction inside the Pulsar-client C++ code.
Note that this occurs on any invocation of
multiprocessingin the presence of a Pulsar connection that is cleared by an atfork hook, regardless of whether the multiprocessing code, or the parent process, will ever use Pulsar again. This is highly unfortunate.Steps to Reproduce
repro.pyfile. Optionally, edit the test topic name to use a topic/namespace/tenant that exist for you locally.while true; do python repro.py; doneto repeatedly invoke it.Snippet:
Expected behavior
The code should continue successfully being invoked over and over after ten minutes.
More to the point all invocations of Pulsar client functionality, including destruction, should be "safe" to perform in all contexts: forks, threads, asyncio coroutines, trio coroutines, multiprocessing, Billiard,
pthread_atforkhooks, signal handlers, etc. "Safe" might mean "works" or it might mean "errors immediately saying 'this is not allowed'". But hanging forever is not safe.Observed behavior
After some number of iterations, usually <1min, the code hangs in a pool-join timeout.
When that happens, the number of
Destroying connectionslog lines andDestroyed connectionslog lines will not match up, indicating that one call toCLIENT = PROD = Noneis blocking.Root cause
When the test code hangs, attaching a
py-spystack printer (with--threads --native) to the hung subprocess indicates that it is stuck in what appears to be code related to the client's destructor. The code in_after_fork_childin the below stack is exactly analogous to theclear_connection_cachecode in the above snippet: