-
-
Notifications
You must be signed in to change notification settings - Fork 32.2k
gh-102402: Make test_relativeCreated_has_higher_precision less implementation dependent #118062
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
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -4598,25 +4598,55 @@ def test_msecs_has_no_floating_point_precision_loss(self): | |
self.assertEqual(record.msecs, want) | ||
self.assertEqual(record.created, ns / 1e9) | ||
|
||
# The test overrides a private attribute | ||
@support.cpython_only | ||
def test_relativeCreated_has_higher_precision(self): | ||
# See issue gh-102402 | ||
ns = 1_677_903_920_000_998_503 # approx. 2023-03-04 04:25:20 UTC | ||
# See issue gh-102402. | ||
# Run the code in the subprocess, because the time module should | ||
# be patched before the first import of the logging package. | ||
# Temporary unloading and re-importing the logging package has | ||
# side effects (including registering the atexit callback and | ||
# references leak). | ||
start_ns = 1_677_903_920_000_998_503 # approx. 2023-03-04 04:25:20 UTC | ||
offsets_ns = (200, 500, 12_354, 99_999, 1_677_903_456_999_123_456) | ||
code = textwrap.dedent(f""" | ||
start_ns = {start_ns!r} | ||
offsets_ns = {offsets_ns!r} | ||
start_monotonic_ns = start_ns - 1 | ||
|
||
import time | ||
# Only time.time_ns needs to be patched for the current | ||
# implementation, but patch also other functions to make | ||
# the test less implementation depending. | ||
old_time_ns = time.time_ns | ||
old_time = time.time | ||
old_monotonic_ns = time.monotonic_ns | ||
old_monotonic = time.monotonic | ||
time_ns_result = start_ns | ||
time.time_ns = lambda: time_ns_result | ||
time.time = lambda: time.time_ns()/1e9 | ||
time.monotonic_ns = lambda: time_ns_result - start_monotonic_ns | ||
time.monotonic = lambda: time.monotonic_ns()/1e9 | ||
try: | ||
import logging | ||
|
||
with (patch("time.time_ns") as time_ns_mock, | ||
support.swap_attr(logging, '_startTime', ns)): | ||
for offset_ns in offsets_ns: | ||
# mock for log record creation | ||
new_ns = ns + offset_ns | ||
time_ns_mock.return_value = new_ns | ||
|
||
record = logging.makeLogRecord({'msg': 'test'}) | ||
self.assertAlmostEqual(record.created, new_ns / 1e9, places=6) | ||
|
||
for offset_ns in offsets_ns: | ||
# mock for log record creation | ||
time_ns_result = start_ns + offset_ns | ||
record = logging.makeLogRecord({{'msg': 'test'}}) | ||
print(record.created, record.relativeCreated) | ||
finally: | ||
time.time_ns = old_time_ns | ||
time.time = old_time | ||
time.monotonic_ns = old_monotonic_ns | ||
time.monotonic = old_monotonic | ||
""") | ||
rc, out, err = assert_python_ok("-c", code) | ||
out = out.decode() | ||
for offset_ns, line in zip(offsets_ns, out.splitlines(), strict=True): | ||
with self.subTest(offset_ns=offset_ns): | ||
created, relativeCreated = map(float, line.split()) | ||
self.assertAlmostEqual(created, (start_ns + offset_ns) / 1e9, places=6) | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. You could implement these checks in the child process (in "code"). There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. How? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Maybe write a test case and call unittest.main(). But I'm fine with your code. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. It will add unpredicable complexity. What if We need also a way to translate the result from the subprocess and translate it to the outer TestCase. Much complex work for no gain. I prefer if we pass a raw data from a subprocess. It is not always possible if the data is too large or complex. Thank you for your review @vstinner. |
||
# After PR gh-102412, precision (places) increases from 3 to 7 | ||
self.assertAlmostEqual(record.relativeCreated, offset_ns / 1e6, places=7) | ||
self.assertAlmostEqual(relativeCreated, offset_ns / 1e6, places=7) | ||
|
||
|
||
class TestBufferingFormatter(logging.BufferingFormatter): | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Add maybe a comment explaining why you spawn a subprocess? In short, I understood that it's hard to avoid side effects of re-importing the logging module, such as reference leaks.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done.