Running test_datetime twice fails with: module 'datetime' has no attribute '_divide_and_round'

[vstinner]

BPO	40058
Nosy	@birkenfeld, @abalkin, @vstinner, @ericsnowcurrently, @serhiy-storchaka, @pganssle, @corona10, @shihai1991
PRs	bpo-40058: Fix failed test_divide_and_round of test_datetime when run more than … #19213

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2021-10-01.07:09:47.786>
created_at = <Date 2020-03-25.01:54:39.990>
labels = ['tests', '3.9']
title = "Running test_datetime twice fails with: module 'datetime' has no attribute '_divide_and_round'"
updated_at = <Date 2021-10-01.07:09:47.780>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2021-10-01.07:09:47.780>
actor = 'serhiy.storchaka'
assignee = 'none'
closed = True
closed_date = <Date 2021-10-01.07:09:47.786>
closer = 'serhiy.storchaka'
components = ['Tests']
creation = <Date 2020-03-25.01:54:39.990>
creator = 'vstinner'
dependencies = []
files = []
hgrepos = []
issue_num = 40058
keywords = ['patch']
message_count = 10.0
messages = ['364970', '364993', '365012', '365018', '365020', '365248', '368273', '372340', '372414', '402994']
nosy_count = 8.0
nosy_names = ['georg.brandl', 'belopolsky', 'vstinner', 'eric.snow', 'serhiy.storchaka', 'p-ganssle', 'corona10', 'shihai1991']
pr_nums = ['19213']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue40058'
versions = ['Python 3.9']

[vstinner]

vstinner@apu$ ./python -m test -v test_datetime test_datetime -m test_divide_and_round
== CPython 3.9.0a5+ (heads/pr/19122:0ac3031a80, Mar 25 2020, 02:25:19) [GCC 9.2.1 20190827 (Red Hat 9.2.1-1)]
== Linux-5.5.9-200.fc31.x86_64-x86_64-with-glibc2.30 little-endian
== cwd: /home/vstinner/python/master/build/test_python_233006
== CPU count: 8
== encodings: locale=UTF-8, FS=utf-8
0:00:00 load avg: 0.82 Run tests sequentially
0:00:00 load avg: 0.82 [1/2] test_datetime
test_divide_and_round (test.datetimetester.TestModule_Pure) ... ok
test_divide_and_round (test.datetimetester.TestModule_Fast) ... skipped 'Only run for Pure Python implementation'

----------------------------------------------------------------------

Ran 2 tests in 0.002s

OK (skipped=1)
0:00:00 load avg: 0.82 [2/2] test_datetime
test_divide_and_round (test.datetimetester.TestModule_Pure) ... ERROR
test_divide_and_round (test.datetimetester.TestModule_Fast) ... skipped 'Only run for Pure Python implementation'

======================================================================
ERROR: test_divide_and_round (test.datetimetester.TestModule_Pure)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/vstinner/python/master/Lib/test/datetimetester.py", line 87, in test_divide_and_round
    dar = datetime_module._divide_and_round
AttributeError: module 'datetime' has no attribute '_divide_and_round'

---

Ran 2 tests in 0.006s

FAILED (errors=1, skipped=1)
test test_datetime failed
test_datetime failed

== Tests result: FAILURE ==

1 test OK.

1 test failed:
test_datetime

Total duration: 448 ms
Tests result: FAILURE

[shihai1991]

_divide_and_round() would be deleted in https://github.com/python/cpython/blob/master/Lib/datetime.py#L2516.

if it's removed L2516 of datetime.py, test_name_cleanup() would be failed.Looks like it's a planed behavior~

[shihai1991]

add a pdb point in L11 of test_datetime.py

8 try:
9 pure_tests = import_fresh_module(TESTS, fresh=['datetime', '_strptime'],
10 blocked=['_datetime'])
11 import pdb;pdb.set_trace()
12 -> fast_tests = import_fresh_module(TESTS, fresh=['datetime',
13 '_datetime', '_strptime'])

and run ./python -m test test_datetime test_datetime:
the first iteration:
(Pdb) pure_tests.datetime_module._divide_and_round
<function _divide_and_round at 0x7f694df8e7e0>
the second iteration(_datetime not blocked?):
(Pdb) pure_tests.datetime_module._divide_and_round
*** AttributeError: module 'datetime' has no attribute '_divide_and_round'

[pganssle]

This isn't exactly "working as intended", but I believe it's a known problem with either import_fresh_module or datetime, as you can see from these comments:

cpython/Lib/test/test_datetime.py

Lines 14 to 23 in 302e5a8

	# XXX: import_fresh_module() is supposed to leave sys.module cache untouched,
	# XXX: but it does not, so we have to cleanup ourselves.
	for modname in ['datetime', '_datetime', '_strptime']:
	sys.modules.pop(modname, None)
	test_modules = [pure_tests, fast_tests]
	test_suffixes = ["_Pure", "_Fast"]
	# XXX(gb) First run all the _Pure tests, then all the _Fast tests. You might
	# not believe this, but in spite of all the sys.modules trickery running a _Pure
	# test last will leave a mix of pure and native datetime stuff lying around.
	all_test_classes = []

Based on the git blame, those TODO comments are from Georg Brandl, so I'm adding him to the nosy list in case he has some insight.

[birkenfeld]

Sorry, it seems that was far too long ago for me to remember anything :)

[shihai1991]

I believe it's a known problem with either import_fresh_module or datetime
after removed the cleanup operation of sys.modules in PR19213, the testcases is successed in my local vm(I am not sure there have any other potential risks).

[ericsnowcurrently]

FYI, with the following additions in Lib/test/test_datetime.py...

   before = set(sys.modules)
   try:
       pure_tests = import_fresh_module(TESTS, fresh=['datetime', '_strptime'],
                                     blocked=['_datetime'])
       _pure = set(sys.modules)
       fast_tests = import_fresh_module(TESTS, fresh=['datetime',
                                                      '_datetime', '_strptime'])
       _fast = set(sys.modules)
       print(f'added (pure): {sorted(_pure-before)}')
       print(f'added (fast): {sorted(_fast-before)}')
       print('---')
   finally:
      ...

I get the following output running "./python -m test test_datetime test_datetime":

0:00:00 load avg: 0.52 Run tests sequentially
0:00:00 load avg: 0.52 [1/2] test_datetime
added (pure): ['_decimal', '_strptime', '_testcapi', 'decimal', 'numbers', 'test.datetimetester']
added (fast): ['_decimal', '_strptime', '_testcapi', 'decimal', 'numbers', 'test.datetimetester']
---
0:00:05 load avg: 0.52 [2/2] test_datetime
added (pure): ['_datetime', '_strptime', 'datetime']
added (fast): ['_datetime', '_strptime', 'datetime']
---
[snipped]

That definitely tells a story. :) Unfortunately, for now I don't have any more time to investigate. Sorry.

[vstinner]

My PR of bpo-40799 fix this issue.

[shihai1991]

My PR of bpo-40799 fix this issue.
Thanks victor for your work, I closed my PR ;)

[serhiy-storchaka]

Fixed in bpo-40173.