| FazBrowse GitHub Viewer | Trending | | Home |
| Tools: [Download Repo ZIP] [Original HTTPS Page] |
|
Unfortunately the lazy import fails when trying to test logging during shutdown: ======================================================================
FAIL: test_logging_at_shutdown (test.test_logging.ModuleLevelMiscTest.test_logging_at_shutdown)
----------------------------------------------------------------------
Traceback (most recent call last):
File "/Users/runner/work/cpython/cpython/Lib/test/test_logging.py", line 5259, in test_logging_at_shutdown
self.assertIn("exception in __del__", err)
~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: 'exception in __del__' not found in '--- Logging error ---\nException ignored while calling deallocator <function A.__del__ at 0x20002d3e8d0>:\nTraceback (most recent call last):\n File "<string>", line 9, in __del__\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 2194, in exception\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 2186, in error\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1553, in error\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1669, in _log\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1685, in handle\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1741, in callHandlers\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1031, in handle\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1163, in emit\n File "/Users/runner/work/cpython/cpython/Lib/logging/__init__.py", line 1080, in handleError\nImportError: sys.meta_path is None, Python is likely shutting down\n' |
Sorry, something went wrong.
|
We can fix the test by adding atexit.register(lambda: traceback) in __init__.py, which guarantees traceback will be imported before the interpreter cleans up. But sadly, the wall-clock time will still be unoptimized in that case. |
Sorry, something went wrong.
|
I would prefer that we do not overcomplicate atexit callbacks in this case. |
Sorry, something went wrong.
|
I see your performance improvement figure in the issue - why is a few ms at application start time an issue? How much time do you practically save in a realistic application? |
Sorry, something went wrong.
|
It helps for CLIs, and especially for --help which should usually be a no-op. Some report 50ms delays can be noticeable, and 10-20ms sometimes be distinguished from 5ms or lower, when it comes to interactivity. https://danluu.com/term-latency/ More conservatively, 100ms is often cited as a response time limit https://www.nngroup.com/articles/response-times-3-important-limits/ CLI tools are sometimes (re-)written in languages like Rust or Go rather than Python or Node because of these lower millisecond times. Slicing off 13ms here doesn't necessarily improve things on its own, but it's a fair chunk of 100ms, and it all adds up. And especially as logging is so widely used, so if we can save here, then it benefits many. Another use case is serverless computing, which can be billed by the millisecond. @ByteFlowing1337 What OS did you use for the charts in #150072? Are they from debug or optimised builds of Python. |
Sorry, something went wrong.
Exactly! That's why I wanna optimize it. The figure showed in the issue was tested on the debug builds of python on Linux (WSL2). On Linux (WSL2), with an optimized Python build, we obtained the following results:
As a result, this optimization shaves off roughly only 6ms. Before #149318 was merged, importing logging is much slower than the current main branch, as _colorize is eagerly imported in traceback. Tested on official Windows release of python 3.14.4:
|
Sorry, something went wrong.
I think 6ms saving would be good if was just a matter of adding lazy but the shutdown issue complicates it (and I had already tried it and prioritised other things for this reason :)
Yeah, the traceback improvement was partly motivated by indirectly improving logging. |
Sorry, something went wrong.
|
See also my previous (unsuccessful) attempt at this and the discussion in #112995 |
Sorry, something went wrong.
|
Instead of lazily importing it, what happens if you remove the import at the top of the module and just import it normally in the suites where it's referenced? Is it the same error on shutdown? |
Sorry, something went wrong.
That what I did in #112995 and it doesn't work. Ultimately, inlining the imports into the functions is basically equivalent of having a lazy import at the top. I don't see a way around this TBH. I am actually in general surprised/worried that we don't see more issues at interpreter shutdown given that we now make more and more imports lazy in stdlib. |
Sorry, something went wrong.
|
Would lazy importing re within the logging module be a safer alternative? |
Sorry, something went wrong.
|
logging eagerly imports traceback which eagerly imports re, so it ends up reified anyway. Lazily importing traceback in logging fails test_logging_at_shutdown. |
Sorry, something went wrong.
| Back | FazBrowse Home | New Git URL |
Uh oh!
There was an error while loading. Please reload this page.
Sorry, something went wrong.
Uh oh!
There was an error while loading. Please reload this page.