Repository navigation
Logging's msecs doesn't handle "100ms" well. #102402
Description
Bug report
LogRecord.msecs returns an incorrect value when timestamp (self.ct) value has exactly 100ms.
One liner check:
assert int((1677793338.100_000_0 - int(1677793338.100_000_0)) * 1000) + 0.0 == 100.0The issue is binary representation of "0.1" / floating point error:
>>> # Definition of LogRecord.msecs:
>>> # https://github.com/python/cpython/blob/12011dd8bafa6867f2b4a8a9e8e54cb0fbf006e4/Lib/logging/__init__.py#L343
>>> # int((ct - int(ct)) * 1000) + 0.0
>>> ct = 1677793338.100_000_0
>>> ct
1677793338.1
>>> ct - int(ct)
0.09999990463256836
>>> _ * 1000
99.99990463256836
>>> int(_)
99
>>> _ + 0.0
99.0Your environment
- CPython versions tested on:
- 3.10.9
- 3.11.2
- Operating system and architecture:
- Custom company OS based on Debian Testing
- 64-bit
Discussion
I think switching to time.time_ns when setting the creation time might be one solution.
Activity
vacosti commentedon Mar 3, 2023
I agree with @dougthor42 about the proposed solution, since time library itself suggests to "use time_ns() to avoid the precision loss caused by the float type".
dougthor42 commentedon Mar 3, 2023
I hope to find some time this weekend to implement a fix.
gh-102402: Fix floating point math issue by using `time.time_ns()` in…
pythongh-102402: Fix floating point math issue by using `time.time_ns…
pythongh-102402: Fix logging test_relativeCreated_has_higher_precisio…
gh-102402: Fix logging test_relativeCreated_has_higher_precision() le…
pythongh-102402: Make test_relativeCreated_has_higher_precision less …
gh-102402: Make test_relativeCreated_has_higher_precision less implem…
pythongh-102402: Make test_relativeCreated_has_higher_precision less …