lbenc135 opened a new pull request #10981:
URL: https://github.com/apache/pulsar/pull/10981
### Motivation
In some cases, the Python client would crash when using the new `logger`
option. This happens when a Pulsar message is sent asynchronously, but soon
after the program exits (and even then, not always).
For example, when doing Django migrations which include sending a message:
```
...
[2021-06-19 06:53:57.691] [INFO]: Created connection for
pulsar://localhost:6650
[2021-06-19 06:53:57.693] [INFO]: [127.0.0.1:36536 -> 127.0.0.1:6650]
Connected to broker
[2021-06-19 06:53:57.695] [INFO]:
[persistent://public/default/dashboard-global_context-emit, ] Getting
connection from pool
[2021-06-19 06:53:57.707] [INFO]:
[persistent://public/default/dashboard-global_context-emit, ] Created producer
on broker [127.0.0.1:36536 -> 127.0.0.1:6650]
...
[2021-06-19 06:53:57.728] [DEBUG]: Sending message to topic .....
Applying dashboard.0001_initial... OK
Applying templating.0001_initial... OK
Error in sys.excepthook:
Original exception was:
Failed to migrate dashboard! Return code was: -6
```
This happens because Pulsar tries to log messages after Python already
started finalizing, so the client can't get a GIL lock, which crashes the whole
client.
### Modifications
Following the instructions at
https://docs.python.org/3/c-api/init.html#c.PyGILState_Ensure, I added a check
for when Python is finalizing, and if it is, we fallback to the default console
logger (the log level is still respected correctly).
Now it looks like this:
```
...
[2021-06-19 06:45:15.561] [INFO]: Created connection for
pulsar://localhost:6650
[2021-06-19 06:45:15.563] [INFO]: [127.0.0.1:35930 -> 127.0.0.1:6650]
Connected to broker
[2021-06-19 06:45:15.568] [INFO]:
[persistent://public/default/dashboard-global_context-emit, ] Getting
connection from pool
[2021-06-19 06:45:15.586] [INFO]:
[persistent://public/default/zaba-dashboard-global_context-emit, ] Created
producer on broker [127.0.0.1:35930 -> 127.0.0.1:6650]
...
[2021-06-19 06:45:15.604] [DEBUG]: Sending message to topic .....
Applying dashboard.0001_initial... OK
Applying templating.0001_initial... OK
2021-06-19 06:45:16.200 INFO [139853253269312] ClientConnection:1446 |
[127.0.0.1:35930 -> 127.0.0.1:6650] Connection closed
2021-06-19 06:45:16.200 ERROR [139853099652672] ClientConnection:531 |
[127.0.0.1:35930 -> 127.0.0.1:6650] Read failed: Operation canceled
2021-06-19 06:45:16.201 INFO [139853253269312] ClientConnection:261 |
[127.0.0.1:35930 -> 127.0.0.1:6650] Destroyed connection
2021-06-19 06:45:16.201 INFO [139853253269312] ProducerImpl:561 | Producer
- [persistent://public/default/dashboard-global_context-emit, standalone-0-120]
, [batchMessageContainer = { BatchMessageContainer [size = 0] [bytes = 0]
[maxSize = 1000] [maxBytes = 131072] [topicName =
persistent://public/default/dashboard-global_context-emit]
[numberOfBatchesSent_ = 1] [averageBatchSize_ = 1] }]
Successfully migrated dashboard
```
### Verifying this change
- [ ] Make sure that the change passes the CI checks.
It's very hard to write a test for this, or at least I have no idea how to
do it.
### Does this pull request potentially affect one of the following parts:
Doesn't affect anything.
### Documentation
No documentation needed, it's a bugfix.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
[email protected]
