tz_offset and datetime.now(utc) don't interact correctly

[firesock]

When debugging logging timestamps inside freezegun, noticed odd behaviour around calling datetime.now(timezone.utc) when freeze_time is active with a tz_offset set:

import datetime
import freezegun
import logging
import sys
import time

def log_times(name):
    logger = logging.getLogger(name)
    logger.setLevel(logging.INFO)
    handler=logging.StreamHandler(stream=sys.stdout)
    handler.setFormatter(
        logging.Formatter(
            fmt=f"%(name)s %(asctime)s - %(message)s",
            datefmt="%Y-%m-%dT%H:%M:%S%z",
        )
    )
    logger.addHandler(handler)

    logger.info("now(): %s", datetime.datetime.now().isoformat(timespec='seconds'))
    logger.info("utcnow(): %s", datetime.datetime.utcnow().isoformat(timespec='seconds'))
    logger.info("now(utc): %s", datetime.datetime.now(datetime.timezone.utc).isoformat(timespec='seconds'))
    logger.info("now(local): %s", datetime.datetime.now().astimezone().isoformat(timespec='seconds'))
    logger.info("time.time(): %s", time.strftime("%Y-%m-%dT%H:%M:%S%z", time.localtime(time.time())))


print(sys.version)
print(freezegun.__version__)

log_times("native")

with freezegun.freeze_time(datetime.datetime.now(tz=datetime.timezone.utc).replace(microsecond=0), tz_offset=0):
    log_times("offset0")


with freezegun.freeze_time(datetime.datetime.now(tz=datetime.timezone.utc).replace(microsecond=0), tz_offset=1):
    log_times("offset1")

Output:

3.7.7 (default, Mar 10 2020, 15:43:33)
[Clang 11.0.0 (clang-1100.0.33.17)]
0.3.15
native 2020-05-01T15:59:53+0100 - now(): 2020-05-01T15:59:53
native 2020-05-01T15:59:53+0100 - utcnow(): 2020-05-01T14:59:53
native 2020-05-01T15:59:53+0100 - now(utc): 2020-05-01T14:59:53+00:00
native 2020-05-01T15:59:53+0100 - now(local): 2020-05-01T15:59:53+01:00
native 2020-05-01T15:59:53+0100 - time.time(): 2020-05-01T15:59:53+0100
offset0 2020-05-01T15:59:53+0100 - now(): 2020-05-01T14:59:53
offset0 2020-05-01T15:59:53+0100 - utcnow(): 2020-05-01T14:59:53
offset0 2020-05-01T15:59:53+0100 - now(utc): 2020-05-01T14:59:53+00:00
offset0 2020-05-01T15:59:53+0100 - now(local): 2020-05-01T14:59:53+01:00
offset0 2020-05-01T15:59:53+0100 - time.time(): 2020-05-01T15:59:53+0100
offset1 2020-05-01T15:59:53+0100 - now(): 2020-05-01T15:59:53
offset1 2020-05-01T15:59:53+0100 - utcnow(): 2020-05-01T14:59:53
offset1 2020-05-01T15:59:53+0100 - now(utc): 2020-05-01T15:59:53+00:00
offset1 2020-05-01T15:59:53+0100 - now(local): 2020-05-01T15:59:53+01:00
offset1 2020-05-01T15:59:53+0100 - time.time(): 2020-05-01T15:59:53+0100

Because of https://github.com/spulec/freezegun/issues/204, the logtimes are always localtime, which is currently +0100, correctly reflected in 'native'.

My understanding is that 'offset0' (tz_offset=0) should be reflecting a frozen time on the UTC timezone, barring existing bugs that attempt to load system timezone, reflected in the time.time() line.

I believe 'offset1'(tz_offset=1) then should be a frozen time on a timezone with the same delta from UTC (+0100), which is correct except for the now(utc) line? Which should just be the same line as utcnow() but with a +0000 timezone attached, as seen on 'native'.

Not sure if this is the same as other bugs reflecting that the system timezone leaks into the freeze if unspecified, but I'm specifying an explicit timezone during the freeze, which doesn't seem exactly the same.

[spulec]

Now that I am looking at it, is this commit and test just wrong: https://github.com/spulec/freezegun/commit/7236d4cb3eb6c26d9c4be0bee84b068a559d663a

The tz_offset passed into the decorator should basically be ignored for everything in that test, right?

[firesock]

Right, that test looks like it's attempting to assert that freeze_time accepts the time at the provided tz_offset instead of the UTC time to freeze, which is what I would expect based on https://github.com/spulec/freezegun#timezones

[spumer]

i'm encountered the same issue:

When default timezone is UTC

with freeze_time('2017-11-24T10:54:36.762+05:00', tz_offset=5):
    print(datetime.datetime.now().astimezone())
2017-11-24 10:54:36.762000+00:00

I expect output should be 2017-11-24 05:54:36.762000+00:00

[spumer]

In my case of course i should not use tz_offset argument. But i think it will be great respect tz_offset at parsing time (in __init__). Then we will have correct _time_to_freeze() value in local (naive) format. And then can rewrite method now

https://github.com/spulec/freezegun/blob/6cfbc48b762368d18e330874f8ff4a742819372b/freezegun/api.py#L355

like this:

def now(cls, tz=None):
    now = cls._time_to_freeze() or real_datetime.now()
    if tz:
        result = now.astimezone(tz)
    else:
        result = now

    return datetime_to_fakedatetime(result)

May be i wrong and don't know about real tz_offset mission :)

[spumer]

My final workaround for .astimezone():

conftest.py

def patched_freezgun_astimezone(self, tz=None):
    from freezegun.api import datetime_to_fakedatetime
    from freezegun.api import real_datetime

    if tz is None:
        from freezegun.api import tzlocal

        tz = tzlocal()

    real = self
    if real.tzinfo is None:
        # we work with naive UTC date time
        # to correct converting make it aware
        mytz = datetime.timezone(self._tz_offset())
        real = self.replace(tzinfo=mytz)

    return datetime_to_fakedatetime(real_datetime.astimezone(real, tz))


freezegun.api.FakeDatetime.astimezone = patched_freezgun_astimezone

Works fine with/without tz_offset:

System TZ is UTC+5

for tz_offset in (0, 5):
    with freeze_time('2017-11-24T10:54:36.762+05:00', tz_offset=tz_offset):
        assert datetime.datetime.now().astimezone().isoformat() == '2017-11-24T10:54:36.762000+05:00'

System TZ is UTC

for tz_offset in (0, 5):
    with freeze_time('2017-11-24T10:54:36.762+05:00', tz_offset=tz_offset):
        assert datetime.datetime.now().astimezone().isoformat() == '2017-11-24T05:54:36.762000+00:00'

[spumer]

And we can workaround .now() by using .astimezone():

def patched_freezegun_now(cls, tz=None):
    from freezegun.api import datetime_to_fakedatetime
    from freezegun.api import real_datetime

    now = cls._time_to_freeze() or real_datetime.now()

    result = now + cls._tz_offset()
    result = datetime_to_fakedatetime(result)

    if tz:
        result = cls.astimezone(result, tz)

    return result

freezegun.api.FakeDatetime.astimezone = patched_freezgun_astimezone  # make sure you patch `astimezone`
freezegun.api.FakeDatetime.now = classmethod(patched_freezegun_now)

Output:

log_times("native")
native 2020-08-16T22:23:39+0500 - now(): 2020-08-16T22:23:39
native 2020-08-16T22:23:39+0500 - utcnow(): 2020-08-16T17:23:39
native 2020-08-16T22:23:39+0500 - now(utc): 2020-08-16T17:23:39+00:00
native 2020-08-16T22:23:39+0500 - now(local): 2020-08-16T22:23:39+05:00
native 2020-08-16T22:23:39+0500 - time.time(): 2020-08-16T22:23:39+0500
with freezegun.freeze_time(datetime.datetime.now(tz=datetime.timezone.utc).replace(microsecond=0), tz_offset=0):
...     log_times("offset0")
... 
offset0 2020-08-16T22:23:56+0500 - now(): 2020-08-16T17:23:56
offset0 2020-08-16T22:23:56+0500 - utcnow(): 2020-08-16T17:23:56
offset0 2020-08-16T22:23:56+0500 - now(utc): 2020-08-16T17:23:56+00:00
offset0 2020-08-16T22:23:56+0500 - now(local): 2020-08-16T22:23:56+05:00
offset0 2020-08-16T22:23:56+0500 - time.time(): 2020-08-16T22:23:56+0500
with freezegun.freeze_time(datetime.datetime.now(tz=datetime.timezone.utc).replace(microsecond=0), tz_offset=1):
...     log_times("offset1")
... 
offset1 2020-08-16T22:24:17+0500 - now(): 2020-08-16T18:24:17
offset1 2020-08-16T22:24:17+0500 - utcnow(): 2020-08-16T17:24:17
offset1 2020-08-16T22:24:17+0500 - now(utc): 2020-08-16T17:24:17+00:00
offset1 2020-08-16T22:24:17+0500 - now(local): 2020-08-16T22:24:17+05:00
offset1 2020-08-16T22:24:17+0500 - time.time(): 2020-08-16T22:24:17+0500

[orsinium]

My final workaround for .astimezone():

This patch works for me! This is the test case:

@pytest.mark.parametrize("tz_offset", [
    timedelta(hours=1),
    timedelta(hours=0),
    timedelta(hours=-2),
    # ... and so on. Must work for any offset, actually
])
def test_freezegun_offset(tz_offset):
    with freezegun.freeze_time("2015-10-21 07:28", tz_offset=tz_offset):
        now = datetime.now()
        delta = now.replace(tzinfo=timezone.utc) - now.astimezone(timezone.utc)
        assert delta == tz_offset

[spumer]

@boxed so, we have patch and tests in this Issue, may be it's time to integrate it into main codebase? ;)

[boxed]

@spumer we do? I can't find a PR?

[spumer]

Nope. I saw your last activity in commits and offer fix this issue cause here (in this issue) have problematic code example (test suite) and fix (my workaround)

[tamird]

Hello, this has been open for 3 years. Now that python 3.11 has deprecated datetime.utcnow() this is sorely needed - it is not possible to get correct datetime.now(datetime.timezone.utc) behavior in the presence of freeze_time(..., tz_offset=<non-zero>).

[boxed]

@tamird You might want to try to switch to time-machine. It's much faster and I've found it more solid.