Weird datetime.utcnow() bug-CodePudding

Consider this simple Python script:

$ cat test_utc.py
from datetime import datetime

for i in range(10_000_000):
    first = datetime.utcnow()
    second = datetime.utcnow()

    assert first <= second, f"{first=} {second=} {i=}"

When I run it from the shell like python test_utc.py it finishes w/o errors, just as expected. However, when I run it in a Docker container the assertion fails:

$ docker run -it --rm -v "$PWD":/code -w /code python:3.10.4 python test_utc.py
Traceback (most recent call last):
  File "/code/test_utc.py", line 7, in <module>
    assert first <= second, f"{first=} {second=} {i=}"
AssertionError: first=datetime.datetime(2022, 5, 24, 19, 5, 1, 861308) second=datetime.datetime(2022, 5, 24, 19, 5, 1, 818270) i=1818860

How is it possible?

P.S. a colleague has reported that increasing the range parameter to 100_000_000 makes it fail in the shell on their mac as well (but not for me).

CodePudding user response：

utcnow refers to now refers to today refers to fromtimestamp refers to time, which says:

While this function normally returns non-decreasing values, it can return a lower value than a previous call if the system clock has been set back between the two calls.

The utcnow code also shows its usage of time:

def utcnow(cls):
    "Construct a UTC datetime from time.time()."
    t = _time.time()
    return cls.utcfromtimestamp(t)

Such system clock updates are also why monotonic exists, which says:

Return the value (in fractional seconds) of a monotonic clock, i.e. a clock that cannot go backwards. The clock is not affected by system clock updates.

And utcnow has no such guarantee.

Your computer doesn't have a perfect clock, every now and then it synchronizes via the internet with more accurate clocks, possibly adjusting it backwards. See for example answers here.

And looks like Docker makes it worse, see for example Addressing Time Drift in Docker Desktop for Mac from the Docker blog. Excerpt:

macOS doesn’t have native container support. The helper VM has its own internal clock, separate from the host’s clock. When the two clocks drift apart then suddenly commands which rely on the time, or on file timestamps, may start to behave differently

Lastly, you can increase your chance to catch a backwards update when one occurs. If one occurs not between getting first and second but between second and the next first, you'll miss it! Below code fixes that issue and is also micro-optimized (including removing the utcnow middle man) so it checks faster / more frequently:

import time
from itertools import repeat

def function():
    n = 10_000_000
    reps = repeat(1, n)
    now = time.time
    first = now()
    for _ in reps:
        second = now()
        assert first <= second, f"{first=} {second=} i={n - sum(reps)}"
        first = second
function()