gh-102567: Add -X importtime=2 for logging an importtime message for already-loaded modules #118655

noahbkim · 2024-05-06T15:40:44Z

As mentioned in the issue:

While -X importtime is incredibly useful for analyzing module import times, by design, it doesn't log anything if an imported module has already been loaded. -X importtime=2 would provide additional output for every module that's already been loaded:

The updated example (-Ximporttime=2):

>>> import uuid
import time: cached    | cached     | builtins
import time: cached    | cached     | linecache
import time: cached    | cached     |   _io
import time: cached    | cached     |   os
import time: cached    | cached     |   sys
import time: cached    | cached     |   enum
import time:       594 |        594 |   _uuid
import time:      2428 |       3022 | uuid

With -Ximporttime:

>>> import uuid
import time:       351 |        351 |   _uuid
import time:       843 |       1194 | uuid

Discussion: https://discuss.python.org/t/x-importtrace-to-supplement-x-importtime-for-loaded-modules/23882/5
Prior email chain: https://mail.python.org/archives/list/python-ideas@python.org/thread/GEISYQ5BXWGKT33RWF77EOSOMMMFUBUS/

Issue: Add -X importtime=2 for additional logging when an imported module is already loaded #102567

Eclips4 · 2024-05-06T17:22:33Z

Hello!
This PR needs to add:

A NEWS entry
A whatsnew entry
A new paragraph in the Doc/cmdline for the -X option.
New test case in the Lib/test/test_cmd_line

noahbkim · 2024-05-06T18:32:13Z

Hello! This PR needs to add:

A NEWS entry

A whatsnew entry

A new paragraph in the Doc/cmdline for the -X option.

New test case in the Lib/test/test_cmd_line

Thanks for the quick feedback. I've committed a first pass of 1-3. As for tests: there appear to be no importtime tests (likely due to the fact that any simple implementation would be super noisy as other parts of the interpreter change). Would it be sufficient to do some rudimentary check i.e. import foo then ensure a corresponding foo row appears in the output?

Thanks again!

Eclips4 · 2024-05-06T19:34:47Z

Hello! This PR needs to add:

A NEWS entry

A whatsnew entry

A new paragraph in the Doc/cmdline for the -X option.

New test case in the Lib/test/test_cmd_line

Thanks for the quick feedback. I've committed a first pass of 1-3. As for tests: there appear to be no importtime tests (likely due to the fact that any simple implementation would be super noisy as other parts of the interpreter change). Would it be sufficient to do some rudimentary check i.e. import foo then ensure a corresponding foo row appears in the output?

Thanks again!

Yes, it would be sufficient :)

Eclips4 · 2024-05-06T19:51:26Z

Also, there's a merge conflict. Can you resolve it? (I can do it myself, but it seems like you have turned off this option)

noahbkim · 2024-05-07T17:43:11Z

Also, there's a merge conflict. Can you resolve it? (I can do it myself, but it seems like you have turned off this option)

Done, just added tests as well

noahbkim · 2024-05-28T18:09:29Z

@Eclips4 who should I ping to get final review? Is it alright if I @ the blamed reviewers?

Eclips4 · 2024-05-28T18:51:19Z

@Eclips4 who should I ping to get final review? Is it alright if I @ the blamed reviewers?

I guess @vstinner is the right person to review this 😄
However, you should move your changes from whatsnew/3.13.rst to whatsnew/3.14.rst since 3.13 branch is in feature-freeze mode, and this feature will appear only in the 3.14 version.

Eclips4 · 2024-05-28T20:09:25Z

However, you should move your changes from whatsnew/3.13.rst to whatsnew/3.14.rst since 3.13 branch is in feature-freeze mode, and this feature will appear only in the 3.14 version.

The same applies for the versionchanged directives.

noahbkim · 2025-05-01T19:22:36Z

I think I've messed up my branch, I'm going to attempt to squash everything so I can overwrite my commit email correctly.

AA-Turner · 2025-05-01T20:20:45Z

Ok, please ping for a review when you've sorted the branch out! If it's easier, feel free to just open a new PR, but a force push here should also work.

A

noahbkim · 2025-05-01T20:29:14Z

@AA-Turner I've squashed my changes and given everything a second pass.

It looks like I caused some kind of regression in test_embed.py, but none of the expected invariants make sense to me (I'm not sure why we expect import_time to be set to 1 in any of the listed circumstances). Looking through the blame was not particularly illuminating. My suspicion is that these tests have been migrated/updated several times without regard for what they're actually testing (or perhaps implicit behavior surrounding -Ximporttime has changed since the test suite's addition?).

Zeroing import_time in said cases returns everything to passing, but a second pair of eyes on that particular bit would be greatly appreciated.

I have about 6 tests failing locally, one of which prevents me from compiling with --enable-optimizations (test_json) but I can't imagine those are related. I'll check if my merge base is behind + fix the CI lint issue.

Lib/_pyrepl/unix_console.py

…ded modules

chris-eibl · 2025-05-03T04:02:09Z

Lib/_pyrepl/windows_console.py

-        import nt
-        return nt._supports_virtual_terminal()
-    except (ImportError, AttributeError):
+        nt._supports_virtual_terminal()


Suggested change

nt._supports_virtual_terminal()

return nt._supports_virtual_terminal()

This is missing a return and would never enable virtual terminal anymore.

AA-Turner · 2025-05-03T06:33:57Z

@noahbkim I've pushed a series of commits to the 3.14-importtime=2 branch on my fork. I've created a PR to HRT's fork (hudson-trading#1), which if merged will automatically update this PR with those commits. Please review them and let me know what you think. In short:

Fixed an issue where the header was appearing after the first import:

.\python.bat -SX importtime=2 -c 'import os; import os'
Running Debug|x64 interpreter...
import time: cached    | cached     | builtins
import time: self [us] | cumulative | imported package
import time:       325 |        325 | winreg

Minor style changes to the pyrepl changes this PR introduces, and also the issue @chris-eibl noted.
Simplify initalisation for config.import_time & fix a bug where explicit setting of the member was overridden (see changes to test_embed).
Add some more test cases
Update documentation, including the man page & adding you to Misc/ACKS.

When these changes are addressed, we can run the buildbots on this PR and check that everything looks alright. Thanks!

A

AA-Turner · 2025-05-05T09:31:35Z

ping @noahbkim (feature freeze is tomorrow)

@AA-Turner

`-X importtime=2` feedback (Thanks so much, @AA-Turner)

noahbkim · 2025-05-05T15:31:26Z

@AA-Turner I am incredibly grateful for the work you've done to get this over the finish line. Thanks again, I'll have an eye on Github/my email all day in case you need anything else.

bedevere-bot · 2025-05-05T15:33:59Z

🤖 New build scheduled with the buildbot fleet by @AA-Turner for commit 6d50b0c 🤖

Results will be shown at:

https://buildbot.python.org/all/#/grid?branch=refs%2Fpull%2F118655%2Fmerge

If you want to schedule another build, you need to add the 🔨 test-with-buildbots label again.

AA-Turner · 2025-05-06T00:03:09Z

Buildbots show leaks in test_datetime which seem unrelated.

AA-Turner

Thanks!

A

hugovk · 2025-07-07T16:48:26Z

Python/initconfig.c

+-X importtime[=2]: show how long each import takes; use -X importtime=2 to\
+         log imports of already-loaded modules; also PYTHONPROFILEIMPORTTIME\n\


This is missing a newline:

Suggested change

-X importtime[=2]: show how long each import takes; use -X importtime=2 to\

log imports of already-loaded modules; also PYTHONPROFILEIMPORTTIME\n\

-X importtime[=2]: show how long each import takes; use -X importtime=2 to\n\

log imports of already-loaded modules; also PYTHONPROFILEIMPORTTIME\n\

$ python3.14 --help-all ... -X frozen_modules=[on|off]: whether to use frozen modules; the default is "on" for installed Python and "off" for a local build; also PYTHON_FROZEN_MODULES -X importtime[=2]: show how long each import takes; use -X importtime=2 to log imports of already-loaded modules; also PYTHONPROFILEIMPORTTIME -X int_max_str_digits=N: limit the size of int<->str conversions; 0 disables the limit; also PYTHONINTMAXSTRDIGITS -X no_debug_ranges: don't include extra location information in code objects; also PYTHONNODEBUGRANGES -X perf: support the Linux "perf" profiler; also PYTHONPERFSUPPORT=1 ...

Please see PR #136391 for a fix.

…e for already-loaded modules (python#118655) Co-authored-by: Adam Turner <9087854+aa-turner@users.noreply.github.com>

noahbkim requested review from kumaraditya303 and ericsnowcurrently as code owners May 6, 2024 15:40

bedevere-app bot added the awaiting review label May 6, 2024

bedevere-app bot mentioned this pull request May 6, 2024

Add -X importtime=2 for additional logging when an imported module is already loaded #102567

Closed

noahbkim requested review from sethmlarson, brettcannon, freakboy3742, erlend-aasland, jaraco, barneygale, a team, corona10, ethanfurman, JelleZijlstra, AlexWaygood, terryjreedy, pfmoore, pradyunsg, ericvsmith, rhettinger and encukou as code owners July 11, 2024 16:26

noahbkim force-pushed the feature/import-cache-2 branch from e53dea1 to 0ed040c Compare May 1, 2025 20:24

noahbkim force-pushed the feature/import-cache-2 branch from 0ed040c to 62d09cd Compare May 1, 2025 20:31

chris-eibl reviewed May 2, 2025

View reviewed changes

Lib/_pyrepl/unix_console.py Outdated Show resolved Hide resolved

Add -X importtime=2 for logging an importtime message for already-loa…

58d07be

…ded modules

noahbkim force-pushed the feature/import-cache-2 branch from 62d09cd to 58d07be Compare May 2, 2025 14:41

chris-eibl reviewed May 3, 2025

View reviewed changes

AA-Turner added 5 commits May 4, 2025 03:04

Print importtime header before first cached import

b081980

_pyrepl style changes

ee7a4a0

Simplify config->import_time initialisation

0226aa1

Update tests, add a few more cases

0b0c56d

Documentation

f9c07ce

AA-Turner mentioned this pull request May 5, 2025

gh-102567: Add -X importtime=2 for logging an importtime message for already-loaded modules #133443

Closed

Merge pull request #1 from AA-Turner/3.14-importtime=2

6d50b0c

`-X importtime=2` feedback (Thanks so much, @AA-Turner)

noahbkim force-pushed the feature/import-cache-2 branch from c0d3c1f to 6d50b0c Compare May 5, 2025 15:30

AA-Turner added the 🔨 test-with-buildbots Test PR w/ buildbots; report in status section label May 5, 2025

bedevere-bot removed the 🔨 test-with-buildbots Test PR w/ buildbots; report in status section label May 5, 2025

AA-Turner approved these changes May 6, 2025

View reviewed changes

AA-Turner merged commit c4bcc6a into python:main May 6, 2025
107 of 120 checks passed

bedevere-app bot removed the awaiting merge label May 6, 2025

hugovk mentioned this pull request Jul 7, 2025

gh-102567: Add missing newline to --help-all #136391

Merged

hugovk reviewed Jul 7, 2025

View reviewed changes

	nt._supports_virtual_terminal()
	return nt._supports_virtual_terminal()

		-X importtime[=2]: show how long each import takes; use -X importtime=2 to\
		log imports of already-loaded modules; also PYTHONPROFILEIMPORTTIME\n\

Uh oh!

gh-102567: Add -X importtime=2 for logging an importtime message for already-loaded modules #118655

gh-102567: Add -X importtime=2 for logging an importtime message for already-loaded modules #118655

Uh oh!

Conversation

noahbkim commented May 6, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Eclips4 commented May 6, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

noahbkim commented May 6, 2024

Uh oh!

Eclips4 commented May 6, 2024

Uh oh!

Eclips4 commented May 6, 2024

Uh oh!

noahbkim commented May 7, 2024

Uh oh!

noahbkim commented May 28, 2024

Uh oh!

Eclips4 commented May 28, 2024

Uh oh!

Eclips4 commented May 28, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

noahbkim commented May 1, 2025

Uh oh!

AA-Turner commented May 1, 2025

Uh oh!

noahbkim commented May 1, 2025

Uh oh!

Uh oh!

chris-eibl May 3, 2025

Choose a reason for hiding this comment

Uh oh!

AA-Turner commented May 3, 2025

Uh oh!

AA-Turner commented May 5, 2025

Uh oh!

noahbkim commented May 5, 2025

Uh oh!

bedevere-bot commented May 5, 2025

Uh oh!

AA-Turner commented May 6, 2025

Uh oh!

AA-Turner left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

hugovk Jul 7, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

noahbkim commented May 6, 2024 •

edited

Loading

Eclips4 commented May 6, 2024 •

edited

Loading

Eclips4 commented May 28, 2024 •

edited

Loading