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

Unexpected behavior when using absl-py with python's native logging library #148

Closed
kqyang opened this issue Aug 6, 2020 · 5 comments
Closed

Comments

@kqyang
Copy link

kqyang commented Aug 6, 2020

I am seeing unexpected behaviors when using absl-py with a python library that uses python's native logging library.

Here is a minimal reproduce script:

from absl import app
import logging


def main(argv):
  logger = logging.getLogger('test_logger')
  logger.setLevel(logging.DEBUG)
  ch = logging.StreamHandler()
  ch.setLevel(logging.DEBUG)
  logger.addHandler(ch)

  logger.info('My test message.')


if __name__ == '__main__':
  app.run(main)

Here is the output from the above script:

My test message.
I0806 13:54:58.868444 140734895885760 python_test.py:11] My test message.

The message is somehow duplicated, one with timestamp, and one without timestamp.

I don't have control on the third_party python library (that uses python's native logging library), so I cannot switch that library to use absl-py logging.

Is there anyway to fix or workaround the problem without updating the logging library in the third party python library?

@yilei
Copy link
Contributor

yilei commented Aug 6, 2020

It depends on how your third_party python library is using native logging and how much control you have to customize its behavior.

app.run(main) calls absl.logging.use_absl_handler(), which removes stderr stream handlers if any, then adds the absl handler to the native root logger. So the duplicated message comes from 1) the absl handler on root logger, and 2) the StreamHandler you created on the test_logger

Some possibilities:

  1. If the library is adding a stderr stream handler to the root logger (instead of the 'test_logger' in your code), moving that before app.run(main) should have the duplicated handler removed
  2. If you have access to logging.getLogger('test_logger'):
    1. Set logging.getLogger('test_logger').propagate = False, so that the logs from this logger won't be propagated to root and logged again by the absl handler
    2. Remove logging.getLogger('test_logger').handlers

Does this help?

@kqyang
Copy link
Author

kqyang commented Aug 6, 2020

Thanks for the quick reply.

If the library is adding a stderr stream handler to the root logger (instead of the 'test_logger' in your code)

I don't think so. The third-party library I mentioned above is Qiling. Here is their code: https://github.com/qilingframework/qiling/blob/3bf8cfb06160df27d17d7072294d951189871d81/qiling/utils.py#L162.

I'll use the method 2i temporarily.

@kqyang
Copy link
Author

kqyang commented Aug 6, 2020

Btw, is there any way to remove the one without timestamp and keep the one with the timestamp?

@yilei
Copy link
Contributor

yilei commented Aug 6, 2020

Based on 2i works, you have access to the logger, to remove the handlers:

for handler in logger.handlers:
  logger.removeHandler(handler)

@kqyang
Copy link
Author

kqyang commented Aug 6, 2020

Great. Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants