Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Python] Handle py::call_method error without mutating internal state #11840

Merged

Conversation

BewareMyPower
Copy link
Contributor

@BewareMyPower BewareMyPower commented Aug 30, 2021

Fixes #11823

Motivation

When the Python logger is customized with underlying LoggerWrapper objects, sometimes async Python functions may return an incorrect value like None. It's because there's a bug (or feature?) of Boost-python that py::call_method will fail in C++ object's destructor. See boostorg/python#374 for details.

For the code example in #11823, it's because in ConsumerImpl's destructor, the logger for AckGroupingTrackerEnabled will be created again because the logger is thread local and will be created in new threads. In this case, py::call_method in LoggerWrapper#_updateCurrentPythonLogLevel will fail, and PyErr_Print will be called and the error indicator will be cleared, which leads to the result that async functions' result became None.

Modifications

  • Reduce unnecessary Logger.getEffectiveLevel calls to get Python log level , just get the log level when the logger factory is initialized and pass the same level to all loggers.
  • Remove the PyErr_Print calls in LoggerWrapper related code. In the cases when py::call_method failed, use the fallback logger to print logs.
  • Add a dependent test for custom logger test because once the LoggerFactory was set all other tests would be affected.

Verifying this change

  • Make sure that the change passes the CI checks.

This change added test CustomLoggingTest. Since asyncio module was introduced from Python 3.3 while CI is based on Python 2.7, this test cannot be tested by CI unless Python3 based CI was added.

@BewareMyPower BewareMyPower self-assigned this Aug 30, 2021
@BewareMyPower BewareMyPower added component/python type/bug The PR fixed a bug or issue reported a bug labels Aug 30, 2021
@BewareMyPower BewareMyPower added this to the 2.9.0 milestone Aug 30, 2021
@BewareMyPower BewareMyPower modified the milestone: 2.9.0 Aug 30, 2021
@BewareMyPower
Copy link
Contributor Author

It looks like asyncio module was not supported in Python 2.7, I think we should improve the CI to have Python3 test as well. In this PR I'll remove the test at the moment.

@BewareMyPower BewareMyPower merged commit 9153e71 into apache:master Aug 31, 2021
@BewareMyPower BewareMyPower deleted the bewaremypowe/fix-python-logger branch August 31, 2021 16:48
codelipenghui pushed a commit that referenced this pull request Sep 9, 2021
…#11840)

Fixes #11823

When the Python logger is customized with underlying `LoggerWrapper` objects, sometimes `async` Python functions may return an incorrect value like `None`. It's because there's a bug (or feature?) of Boost-python that `py::call_method` will fail in C++ object's destructor. See boostorg/python#374 for details.

For the code example in #11823, it's because in `ConsumerImpl`'s destructor, the logger for `AckGroupingTrackerEnabled` will be created again because the logger is thread local and will be created in new threads. In this case, `py::call_method` in `LoggerWrapper#_updateCurrentPythonLogLevel` will fail, and `PyErr_Print` will be called and the error indicator will be cleared, which leads to the result that `async` functions' result became `None`.

- Reduce unnecessary `Logger.getEffectiveLevel` calls to get Python log level , just get the log level when the logger factory is initialized and pass the same level to all loggers.
- Remove the `PyErr_Print` calls in `LoggerWrapper` related code. In the cases when `py::call_method` failed, use the fallback logger to print logs.
- Add a dependent test for custom logger test because once the `LoggerFactory` was set all other tests would be affected.

- [x] Make sure that the change passes the CI checks.

This change added test `CustomLoggingTest`. Since `asyncio` module was introduced from Python 3.3 while CI is based on Python 2.7, this test cannot be tested by CI unless Python3 based CI was added.

(cherry picked from commit 9153e71)
@codelipenghui codelipenghui added the cherry-picked/branch-2.8 Archived: 2.8 is end of life label Sep 9, 2021
bharanic-dev pushed a commit to bharanic-dev/pulsar that referenced this pull request Mar 18, 2022
…apache#11840)

Fixes apache#11823

### Motivation

When the Python logger is customized with underlying `LoggerWrapper` objects, sometimes `async` Python functions may return an incorrect value like `None`. It's because there's a bug (or feature?) of Boost-python that `py::call_method` will fail in C++ object's destructor. See boostorg/python#374 for details.

For the code example in apache#11823, it's because in `ConsumerImpl`'s destructor, the logger for `AckGroupingTrackerEnabled` will be created again because the logger is thread local and will be created in new threads. In this case, `py::call_method` in `LoggerWrapper#_updateCurrentPythonLogLevel` will fail, and `PyErr_Print` will be called and the error indicator will be cleared, which leads to the result that `async` functions' result became `None`.

### Modifications

- Reduce unnecessary `Logger.getEffectiveLevel` calls to get Python log level , just get the log level when the logger factory is initialized and pass the same level to all loggers.
- Remove the `PyErr_Print` calls in `LoggerWrapper` related code. In the cases when `py::call_method` failed, use the fallback logger to print logs.
- Add a dependent test for custom logger test because once the `LoggerFactory` was set all other tests would be affected.

### Verifying this change

- [x] Make sure that the change passes the CI checks.

This change added test `CustomLoggingTest`. Since `asyncio` module was introduced from Python 3.3 while CI is based on Python 2.7, this test cannot be tested by CI unless Python3 based CI was added.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
cherry-picked/branch-2.8 Archived: 2.8 is end of life doc-not-needed Your PR changes do not impact docs release/2.8.2 release/2.9.0 type/bug The PR fixed a bug or issue reported a bug
Projects
None yet
4 participants