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

Hibernate ORM graphql panache test fails if time zone is west of GMT #37659

Closed
dmlloyd opened this issue Dec 11, 2023 · 9 comments · Fixed by #37719
Closed

Hibernate ORM graphql panache test fails if time zone is west of GMT #37659

dmlloyd opened this issue Dec 11, 2023 · 9 comments · Fixed by #37719
Labels
Milestone

Comments

@dmlloyd
Copy link
Member

dmlloyd commented Dec 11, 2023

Describe the bug

Test fails if time zone is west of GMT:

[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 3.879 s <<< FAILURE! -- in io.quarkus.it.hibertnate.orm.graphql.panache.HibernateOrmGraphQLPanacheTest
[ERROR] io.quarkus.it.hibertnate.orm.graphql.panache.HibernateOrmGraphQLPanacheTest.testEndpoint -- Time elapsed: 0.947 s <<< FAILURE!
java.lang.AssertionError: 
1 expectation failed.
JSON path data.authors.dob doesn't match.
Expected: iterable containing ["1821-11-11"]
  Actual: <[1821-11-10]>

	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
	at org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:73)
	at org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrapNoCoerce.callConstructor(ConstructorSite.java:108)
	at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:57)
	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:263)
	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:277)
	at io.restassured.internal.ResponseSpecificationImpl$HamcrestAssertionClosure.validate(ResponseSpecificationImpl.groovy:512)
	at io.restassured.internal.ResponseSpecificationImpl$HamcrestAssertionClosure$validate$1.call(Unknown Source)
	at io.restassured.internal.ResponseSpecificationImpl.validateResponseIfRequired(ResponseSpecificationImpl.groovy:696)
	at io.restassured.internal.ResponseSpecificationImpl.this$2$validateResponseIfRequired(ResponseSpecificationImpl.groovy)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.codehaus.groovy.runtime.callsite.PlainObjectMetaMethodSite.doInvoke(PlainObjectMetaMethodSite.java:43)
	at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:198)
	at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.callCurrent(PogoMetaMethodSite.java:62)
	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:185)
	at io.restassured.internal.ResponseSpecificationImpl.body(ResponseSpecificationImpl.groovy:270)
	at io.restassured.specification.ResponseSpecification$body$1.callCurrent(Unknown Source)
	at io.restassured.internal.ResponseSpecificationImpl.body(ResponseSpecificationImpl.groovy:117)
	at io.restassured.internal.ValidatableResponseOptionsImpl.body(ValidatableResponseOptionsImpl.java:244)
	at io.quarkus.it.hibertnate.orm.graphql.panache.HibernateOrmGraphQLPanacheTest.testEndpoint(HibernateOrmGraphQLPanacheTest.java:63)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at io.quarkus.test.junit.QuarkusTestExtension.runExtensionMethod(QuarkusTestExtension.java:1013)
	at io.quarkus.test.junit.QuarkusTestExtension.interceptTestMethod(QuarkusTestExtension.java:827)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)

Setting e.g. TZ=Europe/Zurich makes the problem go away.

Expected behavior

Test should pass in all local time zones.

Actual behavior

The date is not mapped correctly, presumably because it is taking a ZonedDateTime from the local zone and then getting the date after mapping it to GMT.

How to Reproduce?

Run TZ=America/Chicago mvn install -rf :quarkus-integration-test-hibernate-orm-graphql-panache after a clean build e.g. mvn clean && mvn install -DskipTests.

Output of uname -a or ver

Darwin xxxx 23.1.0 Darwin Kernel Version 23.1.0: Mon Oct 9 21:28:45 PDT 2023; root:xnu-10002.41.9~6/RELEASE_ARM64_T6020 arm64

Output of java -version

openjdk 17.0.9 2023-10-17 OpenJDK Runtime Environment Temurin-17.0.9+9 (build 17.0.9+9) OpenJDK 64-Bit Server VM Temurin-17.0.9+9 (build 17.0.9+9, mixed mode)

Quarkus version or git rev

0d90b7c

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

Apache Maven 3.9.5 (57804ffe001d7215b5e7bcb531cf83df38f93546) Maven home: /Users/david/local/apache-maven Java version: 17.0.9, vendor: Eclipse Adoptium, runtime: /Library/Java/JavaVirtualMachines/temurin-17.jdk/Contents/Home Default locale: en_US, platform encoding: UTF-8 OS name: "mac os x", version: "14.1.2", arch: "aarch64", family: "mac"

Additional information

No response

@dmlloyd dmlloyd added the kind/bug Something isn't working label Dec 11, 2023
Copy link

quarkus-bot bot commented Dec 11, 2023

/cc @FroMage (panache), @Sanne (hibernate-orm), @gsmet (hibernate-orm), @jmartisk (graphql), @loicmathieu (panache), @phillip-kruger (graphql), @yrodiere (hibernate-orm)

@yrodiere
Copy link
Member

yrodiere commented Dec 11, 2023

FWIW java.time types are a nightmare to map to/from JDBC for values before 1900, because JDBC uses java.util/java.sql dates, which have different timezones than java.time before 1900. It's even worse before 1582 as the internal calendar itself is different.

See the note in https://docs.jboss.org/hibernate/search/7.0/reference/en-US/html_single/#mapping-legacy-date-time-apis (it's not specific to Hibernate Search).

Bottom line: if someone wants to fix this without getting an urge to knock their head against a wall, I'd advise to start by using a date after 1900 and seeing if it fixes the problem. Only try to see what's going on if this doesn't fix the problem...

@dmlloyd
Copy link
Member Author

dmlloyd commented Dec 11, 2023

I changed the date from 1821 to 1921 and it did indeed "fix" it. So I guess the issue would be that h2 does not store local dates as LocalDate, or perhaps that we read the date as a java.sql.Date (i.e. a timestamp at "midnight") without accounting for the calendrical differences between the two systems.

Is there some way that we could specify that the time zone of the stored value is UTC?

@dmlloyd
Copy link
Member Author

dmlloyd commented Dec 11, 2023

I'm also trying to create an isolated "scratch" test to see if I can reproduce the issue outside of h2. AFAICT, the test creates and populates the table using the local time zone, so I should in theory be able to create a java.sql.Date with the desired date and then get it back as a LocalDate with the wrong date. However so far I haven't been able to reproduce the failure: I think that I'm creating the java.sql.Date in a different way than h2 does. Still looking into it.

@yrodiere
Copy link
Member

yrodiere commented Dec 11, 2023

that we read the date as a java.sql.Date (i.e. a timestamp at "midnight") without accounting for the calendrical differences between the two systems

We do to some extent IIRC, but as I said this conversion is complex and IMO impossible to get right.

But more importantly, there's probably always been a drift when Hibernate ORM stores the value using JDBC; happily the drift occurs the other way when reading back. So the value stored in DB will not reflect exactly what you wrote.

This is important because here you're using import.sql to store your value, bypassing Hibernate ORM's and JDBC's type conversions, so you're storing the exact value you want. Hibernate ORM will probably apply some drift to it when reading it.

Is there some way that we could specify that the time zone of the stored value is UTC?

Not for LocalDate, I don't think.

AFAICT, the test creates and populates the table using the local time zone, so I should in theory be able to create a java.sql.Date with the desired date and then get it back as a LocalDate with the wrong date

No no, if you write and read through Hibernate ORM all's fine. It's just that your import.sql script doesn't use Hibernate ORM + JDBC parameter binding, and thus "transforms" dates differently (i.e. not at all, as opposed to what Hibernate ORM + JDBC parameter binding would do).

Still looking into it.

As you wish, but you've been warned :)

@dmlloyd
Copy link
Member Author

dmlloyd commented Dec 11, 2023

OK, I traced through all of the date conversion code in Hibernate. It appears that the bug is wholly in h2. By the time we select out the date, it's already incorrect (even if you don't account for LocalTime at all: the result of java.sql.Date.toString() is 1821-11-10).

So the next step is to find the problem on the h2 side...

@yrodiere
Copy link
Member

FWIW JDBC drivers have quite a few bugs like this (just look at that), so we generally consider ourselves happy when the bug when reading compensates the one when writing :)

@dmlloyd
Copy link
Member Author

dmlloyd commented Dec 11, 2023

I think I've found the problem. Deep within the bowels of h2, there is a utility method like this which is used when a ValueDate (their internal date representation, which encodes the date as "year:month:day" in a packed integer) is converted into a java.sql.Date:

    public static long getMillis(CastDataProvider provider, TimeZone tz, long dateValue, long timeNanos) {
        return (tz == null ? provider != null ? provider.currentTimeZone() : DateTimeUtils.getTimeZone()
                : TimeZoneProvider.ofId(tz.getID())).getEpochSecondsFromLocal(dateValue, timeNanos) * 1_000
                + timeNanos / 1_000_000 % 1_000;
    }

This here is where we end up in the wrong calendar system.

However, we could potentially avoid this problem within Hibernate. If our output type is LocalDate, instead of extracting the value as a java.sql.Date, we could extract it as a LocalDate using ResultSet#getObject(xxx,Class<T>) using LocalDate.class as the type. The code in h2 to extract a LocalDate in this way is correct and would yield the right answer. Looking at the code in Hibernate (which is unfamiliar to me) through the debugger, it seems like this would be decided by the extractor which is in turn determined by magic that I couldn't track down.

I guess this approach isn't universally supported by all JDBC drivers, but we should use it whenever it is supported to avoid this problem.

Edit: just to clarify, the problem is fully on the select side. On insert, the date is added correctly in h2's internal packed form; it only becomes wrong once we select it out as a java.sql.Date instead of as a java.time.LocalDate.

dmlloyd added a commit to dmlloyd/quarkus that referenced this issue Dec 13, 2023
Fixes quarkusio#37659. A follow-up issue will be filed to revert this commit once ORM 7.x is integrated.
@dmlloyd
Copy link
Member Author

dmlloyd commented Dec 13, 2023

Note for posterity: to reproduce this issue, I believe that the current time in the time zone of the system must have a different day than UTC. As such the test may only fail at certain times of the day.

In any event, the fix is to provide ad-hoc direct support for LocalDate, which is likely to become the standard behavior starting in Hibernate ORM 7.0. See the linked PR and issue #37720 for more information.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants