DateTimeField does not return correct timezone

Using Django Mystery Errors
1

Hi,

while debugging test failures in our CI, which do not happen locally, I came across the following behavior: With django 4.0 (or 3.2, or 3.1), psycopg2 >=2.8.4 (up to current), postgres 13 (no other versions tested), a DateTimeField does not retrieve the same value it was given initially:

posted = timezone.now()
p1 = Post.objects.create(posted=posted)
p2 = Post.objects.get(pk=p1.pk)
print(p1.posted)
print(p2.posted)
print("equal", p1.posted == p2.posted)

yields

2022-02-01 12:23:52.952457+00:00
2022-02-01 13:23:52.952457+00:00
equal False

I expected the two values to be exactly same, or to be the same after you take time zones into account. Instead, they differ by one hour.

Relevant settings:

TIME_ZONE = 'Europe/Berlin'
USE_I18N = True
USE_TZ = True

After more investigation I noticed that this only happens when the app server time zone (Europe/Berlin) differs from the postgresql timezones (in this case, Etc/UTC). Changing either the timezone in postgres or forcing the connection onto the same one resolves the issue.

While this is a feasible workaround, the behavior still is very odd to me.

Feel free to try it yourself in this small demo:

$ git clone https://github.com/luto/django_tztest
$ cd django_tztest
$ ./demo.sh
(...)
2022-02-01 12:23:52.952457+00:00
2022-02-01 13:23:52.952457+00:00
equal False

Note that you will need docker/docker-compose, which contains the postgres instance. You can also use bring your own (make sure its time zone is Etc/UTC!) by adapting the django config accordingly.

I already had another dev try this on their machine, which shows the same behavior. I expect it to show similar behavior on any dev machine (or app server) that’s not UTC.

Any hints? :slight_smile: Thank you for taking a look!

2 Likes
2

Could you print the tzinfo associated with each of them?

3

Thanks for your reply! of course:

2022-02-01 13:37:21.716847+00:00
UTC
2022-02-01 14:37:21.716847+00:00
UTC
equal False

relevant commit.

4

I think printing the instance rather than the string representation would be more helpful. You could do so by running the test logic in a shell.

p1.posted
> datetime.datetime(year=..., ..., tzinfo=...)
5

That makes sense.

From the docs:

When USE_TZ is False , this is the time zone in which Django will store all datetimes. When USE_TZ is True , this is the default time zone that Django will use to display datetimes in templates and to interpret datetimes entered in forms.

So with USE_TZ=True, it’s going to use the system’s time zone, and for the operations you are performing, the TIME_ZONE setting isn’t involved.

My conjecture would be that if you change USE_TZ to False, that you would also get correct values.

Also see: Time zones | Django documentation | Django

(Also, what operating systems are involved here for both the app server and the database?)

6

of course. Fixed the code and tried in a shell:

>>> from tztestapp.models import Post
>>> from django.utils import timezone
>>> posted = timezone.now()
>>> p1 = Post.objects.create(posted=posted)
>>> p2 = Post.objects.get(pk=p1.pk)
>>> p1.posted
datetime.datetime(2022, 2, 1, 14, 59, 15, 259712, tzinfo=datetime.timezone.utc)
>>> p1.posted.tzinfo
datetime.timezone.utc
>>> p2.posted
datetime.datetime(2022, 2, 1, 15, 59, 15, 259712, tzinfo=datetime.timezone.utc)
>>> p2.posted.tzinfo
datetime.timezone.utc
7

My conjecture would be that if you change USE_TZ to False , that you would also get correct values.

That works. Presumably, because they just flow through Django without any processing, sidestepping this behavior. The resulting datetime objects are naive:

p1: datetime.datetime(2022, 2, 1, 16, 5, 55, 911792)
p2: datetime.datetime(2022, 2, 1, 16, 5, 55, 911792)

Additionally, I am failing to find any mention of the system timezone in the docs you linked, or in others I read in preparation for this post.

Regardless of system timezones, Django should never read a wrong value from the database, shouldn’t it? If I give it a value, save it to the DB, and read simply fetch it again, I’d expect to always get the same (or equivalent) value back.

I am happy to change the code or configure Django differently, if you give me a pointer on what to change :confused:

(Also, what operating systems are involved here for both the app server and the database?)

OS: Arch Linux
DB: official docker image, which is based on Debian

Thank you!

8

Generally, the best recommendation I always make is that your system time should be set to UTC, universally. This avoids this type of confusion when sending timestamps between systems.

Failing that, I’d ensure that the PostgreSQL connection is configured with the same time zone as the app server.

My conjecture at this point is that there’s something at one of the lower layers of the stack that is converting the time.

It appears the database is working with the sent time as if it were sent as UTC+1 instead of UTC, and so converting it to UTC.

I don’t believe that’s what’s happening.

I’m guessing that the change is being made on the save, and not on the get.
You can verify this by checking the actual value stored in the database.

If you’re running PostgreSQL on the same physical system, is that docker image aware that the host is running on a different timezone setting?

If the system clock is set to UTC+1, and the docker container thinks its reading UTC, that could create problems. A docker container by default assumes that the hardware clock is UTC.

9

I agree! However, I think things should not break in the way that they seem to do, if the time zones do not match.

The value before save and in the DB is equivalent:

>>> p1
datetime.datetime(2022, 2, 1, 16, 25, 17, 395312, tzinfo=datetime.timezone.utc)

marvin=# SELECT posted FROM tztestapp_post ORDER BY id DESC LIMIT 1;
2022-02-01 17:25:17.395312+01

Upon reading, I think timezone is dropped leading to a different point in time?

p2: datetime.datetime(2022, 2, 1, 17, 25, 17, 395312, tzinfo=datetime.timezone.utc)
10

To me, the next step would be to try and determine whether this is being caused by something inside or outside of Django.

I’d suggest trying to save / read this data directly from a Python script using psycopg2.
If you see the same behavior, then the likely explanation is that Django is not a contributing factor.
However, if your Python script works as expected, then you will have demonstrated that it’s likely a problem within Django.
(I’d try it myself, but I don’t have an environment that replicates this issue.)

11

Thanks for your guidance!

Based on the SQL statements django sends to the DB I wrote demo_psycopg2.py (same repo). It makes makes use of psycopg2 directly. As far as I can tell, the script manages to fetch an equivalent value from the DB, as expected:

2022-02-02 00:25:59.256973+00:00
2022-02-02 01:25:59.256973+01:00

Please let me know if I can contribute anything else or if I made a mistake somewhere.