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

[noahbkim]

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/[email protected]/thread/GEISYQ5BXWGKT33RWF77EOSOMMMFUBUS/

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

[Eclips4]

Hello!
This PR needs to add:

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

[noahbkim]

Hello! This PR needs to add:

1. A NEWS entry
2. A whatsnew entry
3. A new paragraph in the Doc/cmdline for the -X option.
4. 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]

Hello! This PR needs to add:

1. A NEWS entry
2. A whatsnew entry
3. A new paragraph in the Doc/cmdline for the -X option.
4. 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]

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]

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]

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

[Eclips4]

@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]

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]

@AA-Turner merged your changes, happy to do anything else necessary, apologies for the inconvenience of the organization branch. Not sure where your comment went (I saw it in my email), but thanks for helping push this through.

[AA-Turner]

Thanks @noahbkim, no worries! Are you able to make the changes to config_set_import_time etc to reserve values >=2?

We also recently changed our CLA bot, please can you click on the red 'not signed' and ensure everything is up to date?

A

[noahbkim]

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]

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]

@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.

[chris-eibl]

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]

@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]

ping @noahbkim (feature freeze is tomorrow)

[noahbkim]

@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]

🤖 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]

Buildbots show leaks in test_datetime which seem unrelated.

[AA-Turner]

Thanks!

A