Skip to content
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

Wrong timestamps from MySQL via Hibernate ORM #44413

Open
neon-dev opened this issue Nov 11, 2024 · 7 comments
Open

Wrong timestamps from MySQL via Hibernate ORM #44413

neon-dev opened this issue Nov 11, 2024 · 7 comments
Labels
area/hibernate-orm Hibernate ORM kind/bug Something isn't working triage/needs-feedback We are waiting for feedback. triage/upstream Used for issues which are caused by issues in upstream projects/dependency

Comments

@neon-dev
Copy link
Contributor

Describe the bug

I'm not sure if this problem is specific to Quarkus or if it is a bug in Hibernate:

Instant entity fields give wrong times if querying in a time zone other than UTC+0. Timestamp entity fields, however, work as expected.
I didn't test the other types Hibernate ORM supports.

Expected behavior

Instant entity fields should have the same time as Timestamp fields, given the same SQL timestamp.

Actual behavior

Instant entity fields can differ from Timestamp fields, depending on the time zone setting.

How to Reproduce?

Reproducer: reproducer.zip

It contains a test class to demonstrate the issue.
I also tested the reproducer with a H2 database, where there was no problem using the same configuration. It looks like quarkus.hibernate-orm.jdbc.timezone is partly ignored with MySQL.

Output of uname -a or ver

No response

Output of java -version

No response

Quarkus version or git rev

3.16.2

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

No response

@neon-dev neon-dev added the kind/bug Something isn't working label Nov 11, 2024
@quarkus-bot quarkus-bot bot added the area/hibernate-orm Hibernate ORM label Nov 11, 2024
Copy link

quarkus-bot bot commented Nov 11, 2024

/cc @gsmet (hibernate-orm), @yrodiere (hibernate-orm)

@yrodiere
Copy link
Member

Hello,

I'm not sure if this problem is specific to Quarkus or if it is a bug in Hibernate:

This is very, very likely to be a problem in Hibernate, or something in the MySQL JDBC driver that Hibernate does not successfully work around. Or simply an expected behavior in Hibernate.

My bet would be on Hibernate ORM's Instant type handling simply being different from Timestamp 's, most likely for historical reasons: we can't really change the behavior once it's there, since it would lead to already-persisted data being interpreted differently.
When you're storing now() into both columns of your table in your import.sql, you're not actually storing the same value, since Hibernate will interpret/decode it differently for each column (mapped to a different type).
So, everything is most likely fine when you're both writing and reading using Hibernate OM, but not so much once you start accessing the database directly.

Regardless, if you want a change/fix here, it's probably worth creating a reproducer based on https://github.com/hibernate/hibernate-test-case-templates/blob/main/orm/hibernate-orm-6/src/test/java/org/hibernate/bugs/QuarkusLikeORMUnitTestCase.java and report to the Hibernate ORM project instead.

@yrodiere yrodiere added the triage/upstream Used for issues which are caused by issues in upstream projects/dependency label Nov 13, 2024
@yrodiere
Copy link
Member

As to why you're fine with H2... each DB and JDBC driver works differently, so even with the same input, you get different results. It's a mess.

@yrodiere yrodiere added the triage/needs-feedback We are waiting for feedback. label Nov 13, 2024
@yrodiere
Copy link
Member

yrodiere commented Nov 13, 2024

By the way, I did see similar behavior when running your reproducer:

[ERROR]   MyEntityTest.testTimestamps:18 expected: <2024-11-13T12:06:51Z> but was: <2024-11-13T13:06:51Z>

Actual time was 2024-11-13T14:06:51+01:00 (CET), so I'm guessing @now in the import script led MySQL to store 2024-11-13T13:06:51 (implicit timezone CET) in the DB, which Hibernate "corrected" back to 2024-11-13T12:06:51 for Timestamp, but didn't for Instant.

Which makes me think the value for Instant is actually the correct one... ?

@neon-dev
Copy link
Contributor Author

neon-dev commented Nov 13, 2024

When you're storing now() into both columns of your table in your import.sql, you're not actually storing the same value, since Hibernate will interpret/decode it differently for each column (mapped to a different type).

The import.sql is not at fault here and is, afaik, executed natively. Also I made sure the values are identical in the database. In my real world usecase I didn't even have two different columns but simply changed an existing entity Timestamp field to Instant, because it would have been more convenient to use. But suddenly, all queried times were off by an hour.

Which makes me think the value for Instant is actually the correct one... ?

I was unsure too at first, but if you connect to the db using a different client and inspect the values, you'll see that they are equal and that Instant values are read incorrectly. They somehow show local time as the UTC time, which does not make sense at all and I didn't even find a way to change this behavior.

Edit: I just ran it again at 15:06 local time (CET):
Image

Expected :2024-11-13T14:06:14Z
Actual   :2024-11-13T15:06:14Z

14:06Z is the correct time in this case, which is the Timestamp value. The Instant value somehow is one hour in the future on my machine.

@yrodiere
Copy link
Member

yrodiere commented Nov 13, 2024

When you're storing now() into both columns of your table in your import.sql, you're not actually storing the same value, since Hibernate will interpret/decode it differently for each column (mapped to a different type).

The import.sql is not at fault here and is, afaik, executed natively. Also I made sure the values are identical in the database.

I'm not saying it's at fault. I'm saying the same value in the DB has a different interpretation in Hibernate ORM depending on the column (and the type of the JPA attribute mapped to the column), and thus is not, in practice, the same.

Yes I know, it's confusing.

In my real world usecase I didn't even have two different columns but simply changed an existing entity Timestamp field to Instant, because it would have been more convenient to use. But suddenly, all queried times were off by an hour.

Yeah I can see how that would happen. Like I said, different types, different interpretations of the stored data.

Which makes me think the value for Instant is actually the correct one... ?

I was unsure too at first, but if you connect to the db using a different client and inspect the values, you'll see that they are equal and that Instant values are read incorrectly. They somehow show local time as the UTC time, which does not make sense at all and I didn't even find a way to change this behavior.

Yeah I wouldn't take what clients show for granted... It's complicated. From what I see in the docs though, the datetime type used on the DB side should be independent from the DB server's timezone... So I'm wondering why you even had to use quarkus.hibernate-orm.jdbc.timezone.

It's really looking like something that should be brought up in the Hibernate ORM tracker instead of here though :)

Edit: I just ran it again at 15:06 local time (CET):

Expected :2024-11-13T14:06:14Z
Actual   :2024-11-13T15:06:14Z

14:06Z is the correct time in this case, which is the Timestamp value. The Instant value somehow is one hour in the future on my machine.

When you report to Hibernate ORM, can you also tell what the timezone of your application and DB is? Depending on the environment, Docker and similar might force it to UTC, so it's worth checking.

@neon-dev
Copy link
Contributor Author

Yeah I can see how that would happen. Like I said, different types, different interpretations of the stored data.

Yeah, I know. I just hope this is not intended behavior, because it is not only unintuitive in this case, it feels completely wrong.

From what I see in the docs though, the datetime type used on the DB side should be independent from the DB server's timezone... So I'm wondering why you even had to use quarkus.hibernate-orm.jdbc.timezone.

I didn't have to for my reproducer to show the issue on my machine. But I tried setting it to other timezones and the times of the Timestamp field changed accordingly, so I set it to my machine's time zone for it to work identically on other machines. Also, if you set it to UTC, the test will pass on my machine, because then the Timestamp value also is one hour in the future.
I agree the docs indicate datetime should be independent of the server's time zone, but it isn't. It behaves the same as a timestamp column in this regard. In fact, my original bug happened with a timestamp column, but the reproducer uses datetime columns.

It's really looking like something that should be brought up in the Hibernate ORM tracker instead of here though :)

Will do. Thanks for your feedback. Unfortunately Hibernate ORM doesn't use GitHub issue tracking, so I'll have to create an account first. I will post a link here once I get around to it.

When you report to Hibernate ORM, can you also tell what the timezone of your application and DB is? Depending on the environment, Docker and similar might force it to UTC, so it's worth checking.

Yeah, good point. In my case it's all CET on server and client (connection) side. This usually avoids problems like here.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/hibernate-orm Hibernate ORM kind/bug Something isn't working triage/needs-feedback We are waiting for feedback. triage/upstream Used for issues which are caused by issues in upstream projects/dependency
Projects
None yet
Development

No branches or pull requests

2 participants