search

quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.79k stars 2.68k forks source link

NullPointerException reading mongodb bson date (native image) #11524

Closed nicolinux72 closed 4 years ago

nicolinux72 commented 4 years ago

Hi,

only native image of my application cause a NullPointerException parsing mongodb document with date field.

The error occours both with quarkus 1.6.0.final and 1.7.0.final.

Here the full staktrace:

2020-08-21 15:12:12,711 ERROR [org.jbo.res.res.i18n] (executor-thread-1) RESTEASY002020: Unhandled asynchronous exception, sending back 500: org.jboss.resteasy.spi.ApplicationException: java.lang.NullPointerException
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:180)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:638)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:504)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:454)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:456)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:417)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:391)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:68)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:488)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:259)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:160)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:163)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:245)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:132)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:37)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:94)
    at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at java.lang.Thread.run(Thread.java:834)
    at org.jboss.threads.JBossThread.run(JBossThread.java:479)
    at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:517)
    at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
Caused by: java.lang.NullPointerException
    at java.text.SimpleDateFormat.matchZoneString(SimpleDateFormat.java:1695)
    at java.text.SimpleDateFormat.subParseZoneString(SimpleDateFormat.java:1763)
    at java.text.SimpleDateFormat.subParse(SimpleDateFormat.java:2169)
    at java.text.SimpleDateFormat.parse(SimpleDateFormat.java:1541)
    at org.bson.json.JsonReader.visitISODateTimeConstructor(JsonReader.java:836)
    at org.bson.json.JsonReader.readBsonType(JsonReader.java:225)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:85)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:42)
    at org.bson.codecs.BsonDocumentCodec.readValue(BsonDocumentCodec.java:104)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:87)
    at org.bson.BsonDocument.parse(BsonDocument.java:63)
    at io.quarkus.mongodb.panache.runtime.MongoOperations.executeUpdate(MongoOperations.java:619)
    at io.quarkus.mongodb.panache.runtime.MongoOperations.update(MongoOperations.java:614)
    at it.cineca.model.elaborato.HeartBeat.update(HeartBeat.java)
    at it.cineca.manager.HeartBeatManager.aggiornaBattito(HeartBeatManager.java:64)
    at it.cineca.manager.HeartBeatManager_ClientProxy.aggiornaBattito(HeartBeatManager_ClientProxy.zig:216)
    at it.cineca.web.BeatController.aggiornaBattito(BeatController.java:38)
    at java.lang.reflect.Method.invoke(Method.java:566)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167)
    ... 29 more

I'm compiling native image using maven's quarkus standard configuration with these Resource Configuration File:

{
  "bundles": [  {"name":"sun.util.resources.TimeZoneNames"}   ],
  "resources": [     {       "pattern": "org/joda/time/tz/data/.*/.*$"     },
                            {       "pattern": "org/joda/time/tz/data/.*$"     }   ]
}

Thank you Nicola

quarkusbot commented 4 years ago

/cc @loicmathieu, @evanchooly

gsmet commented 4 years ago

Can you please prepare a small reproducer?

nicolinux72 commented 4 years ago

good morning,

I have prepared a simple test case eventi-testcase.zip with only five files:

├── pom.xml
└── src
    └── main
        ├── java
        │   └── it
        │       └── cineca
        │           ├── BeatController.java
        │           └── HeartBeat.java
        └── resources
            ├── application.properties
            └── resources-config.json

Please note that the only dependencies in the pom file, besides quarkus, are jodatime and lombock.

The mongodb collection we try unsuccessfully to update contains documents like:

// collection: heart_beats
{
    "_id" : "fffff124-615d-40b2-bb08-a7edd9afacd4",
    "interruzione" : false,
    "istante" : ISODate("2019-08-26T17:38:20.917+02:00")
}

This is my version of graalvm and my request command:

> java --version
openjdk 11.0.7 2020-04-14
OpenJDK Runtime Environment GraalVM CE 20.1.0 (build 11.0.7+10-jvmci-20.1-b02)
OpenJDK 64-Bit Server VM GraalVM CE 20.1.0 (build 11.0.7+10-jvmci-20.1-b02, mixed mode, sharing)
> curl --location --request PUT 'http://localhost:8080/v1/beat/ffff5e8a-2b59-4787-8386-fe039e8dd622?idModulo=1525e070-16a5-45c3-a8ed-72a649a03d18'

The stack trace is basically the same as in my previous post. I report it here for completeness:

2020-08-24 11:13:50,591 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-1) HTTP Request to /v1/beat/ffff5e8a-2b59-4787-8386-fe039e8dd622?idModulo=1525e070-16a5-45c3-a8ed-72a649a03d18 failed, error id: f17277fe-c49b-4dcb-928d-75a55f6cf2a0-1: org.jboss.resteasy.spi.UnhandledException: java.lang.NullPointerException
    at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:106)
    at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:372)
    at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:216)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:515)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:259)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:160)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:163)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:245)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:132)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:37)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:94)
    at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at java.lang.Thread.run(Thread.java:834)
    at org.jboss.threads.JBossThread.run(JBossThread.java:479)
    at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:517)
    at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
Caused by: java.lang.NullPointerException
    at java.text.SimpleDateFormat.matchZoneString(SimpleDateFormat.java:1695)
    at java.text.SimpleDateFormat.subParseZoneString(SimpleDateFormat.java:1763)
    at java.text.SimpleDateFormat.subParse(SimpleDateFormat.java:2169)
    at java.text.SimpleDateFormat.parse(SimpleDateFormat.java:1541)
    at org.bson.json.JsonReader.visitISODateTimeConstructor(JsonReader.java:836)
    at org.bson.json.JsonReader.readBsonType(JsonReader.java:225)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:85)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:42)
    at org.bson.codecs.BsonDocumentCodec.readValue(BsonDocumentCodec.java:104)
    at org.bson.codecs.BsonDocumentCodec.decode(BsonDocumentCodec.java:87)
    at org.bson.BsonDocument.parse(BsonDocument.java:63)
    at io.quarkus.mongodb.panache.runtime.MongoOperations.executeUpdate(MongoOperations.java:619)
    at io.quarkus.mongodb.panache.runtime.MongoOperations.update(MongoOperations.java:614)
    at it.cineca.HeartBeat.update(HeartBeat.java)
    at it.cineca.BeatController.aggiornaBattito(BeatController.java:21)
    at java.lang.reflect.Method.invoke(Method.java:566)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:638)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:504)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:454)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:456)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:417)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:391)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:68)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:488)

Thanks you for your attention Nicola

nicolinux72 commented 4 years ago

good morning,

did you find the time to try my test case? Can you reproduce the error?

Is there anything I can do to help?

Nicola

loicmathieu commented 4 years ago

Hi @nicolinux72 the issue is not related to MongoDB but is a native image issue. Apparently there is some issue around time zone data missing on the native image.

@gsmet there is no nativelabel to ping someone for help on native image issue, do you know who can help ?

gsmet commented 4 years ago

/cc @galderz @jaikiran any idea, guys?

nicolinux72 commented 4 years ago

Hi @loicmathieu , @gsmet

for my part I can confirm that the problem occurs only in the native version, compiled with graalvm / native-image.

No problem running on JVM.

galderz commented 4 years ago

I'm looking into it.

galderz commented 4 years ago

@nicolinux72 Couple of questions:

  1. I'm unable to run your reproducer. What is are the exact steps? How do you run it from empty state and get to the reproducing it?

  2. As we try to narrow down the cause, can you for example try with Java time instead of Joda time and see if it works?

nicolinux72 commented 4 years ago

Hello,

after long study, I think I have discovered something interesting. Due to this bug , only the current local is reported in the native version of the application: in my case the current local is it_US.

I noticed, following the stack trace, that the code in org.bson.json.* tries to decode MongoDb dates using the en locale and this determines the NPE because the en locale does not exist in my native version.

To confirm my assumptions, I changed the native-image build parameter from: -J-Duser.language = it to -J-Duser.language = en. By doing so, the native version also works.

This workaround, unfortunately, is insufficient for a production application that must contain at least the local of our customers (Italian) in addition to that required by the MongoDb driver for the dates (English).

Does Quarkus offer a solution to solve this big problem? Thank you Nicola

ps: YodaTime seems to have nothing to do with the problem we are talking about pps: to run my repoducer, simply add mvnw to the root dir then type: ./mvnw compile quarkus:dev or ./mvnw package -Pnative for the native version of the app

loicmathieu commented 4 years ago

Thanks for the analysis, ideally we should include the en local for all native builds that contains the mongodb-client extension.

@galderz is such functionality possible for Quarkus yet ?

galderz commented 4 years ago

@nicolinux72 Thx for the info, this is really useful. I think the problem that you have is that MongoDB is not using the it locale. If it'd do that then, with flag you added to add timezones, it'd work.

There's a bit extra information here to explain why en works:

Until JDK 11.0.8, there was some inconsistencies with how time zone name locales were handled. In essence, English ones were added by the JDK but other languages were left out. I think the different behaviour that you see is due to this discrepancy. More details in JDK-8236548.

Starting with JDK 11.0.9+, no locales are added by default, which we noticed a week or two ago (see https://github.com/graalvm/mandrel/issues/106). We have requested Oracle to add -H:IncludeResourceBundles=sun.util.resources.TimeZoneNames to fix this (see https://github.com/oracle/graal/issues/2776). One of my colleagues, @jerboaa, has been working on this. His reproducer did play around with user.language and that seems to work. In essence, using the same locale at build and runtime should work (I'd add -H:IncludeResourceBundles=sun.util.resources.TimeZoneNames for now until the Oracle issue has been fixed).

galderz commented 4 years ago

@loicmathieu Including en local goes against what JDK-8236548 tries to do, so I'd avoid that. Isn't this an issue of MongoDB assuming en locale?

loicmathieu commented 4 years ago

Isn't this an issue of MongoDB assuming en locale?

Reading your detailed explaination it should be an issue with MongoDB relying on the presence of the en locale, something that changes recently.

MongoDB stores dates as a 64bit number but the driver (and the shell) manage them as text in the ISO format, and this is the code used to parse them:

        String[] patterns = {"yyyy-MM-dd", "yyyy-MM-dd'T'HH:mm:ssz", "yyyy-MM-dd'T'HH:mm:ss.SSSz"};
        SimpleDateFormat format = new SimpleDateFormat(patterns[0], Locale.ENGLISH);

Unfortunatly, they uses some date part pattern that can be letters (HH, z), reading the documentation https://docs.mongodb.com/manual/reference/method/Date/ all examples only contains number-based date part so it should be possible to parse them without specifying a Locale.

If it didn't work anymore due to a change inside the JDK, openning an issue on the MongoDB driver refering JDK-8236548 can be the best way to fix this.

nicolinux72 commented 4 years ago

Graal issue 911 indicates a workaround based on "Features" to make different locales available to applications.

In your opinion, that kind of workaround can be integrated into Quarkus' mongodb-client extension.

If so, how?

galderz commented 4 years ago

I think https://github.com/oracle/graal/issues/911 deals with a different request: when an application needs to handle different locales.

The issue being discussed here is not necessarily that. From my understanding, your app uses a single locale it. Then, MongoDB has hardcoded en locale which causes issues, due to the assumption of GraalVM of native image of a single locale, the en locale.

I don't know what the best approach is here for Quarkus in this particular case, so I'd rather defer to the Quarkus/MongoDB experts here.

loicmathieu commented 4 years ago

I checked the Graal issue and I don't think using the workaround based on @Feature is a good thing to add to Quarkus. You could still add it to your own application as a workaround if needed.

I think the best is to raise this to the MongoDB team, for this the best will be to create a minimal reproducer with only the mongodb-driver as dependency (so no Quarkus) to show that the issue here is that MongoDB hardcoded the use of the en Locale so any attemp to use a different Locale in GraalVM will make the MongoDB ISODate handling broken.

gsmet commented 4 years ago

@galderz is the ROOT locale always included?

If so, can't we add a substitution while we open an issue on the MongoDB side? It won't be pretty as AFAICS they do it in several pretty large methods but probably better than having things failing.

evanchooly commented 4 years ago

I agree with @loicmathieu. I'm not sure we want to be patching upstream bugs like that but perhaps in the short run it might be worth it.

nicolinux72 commented 4 years ago

In summary: for us, developers with a default locale other than en - let's call ourselves the rest of the world :-) -, it is not possible to use native quarkus applications with mongodb.

All due to the combined effect of:

It seems to me a real shame ... :-(

galderz commented 4 years ago

@galderz is the ROOT locale always included?

I think it is, but based on my experiments it makes no difference to use that. Only using the same locale as the one provided when creating the native image works. See output of experiment.

I've found something interesting about testing this. If you look at the JsonReader code for mongo java driver 4.1.0, you see this:

        String[] patterns = {"yyyy-MM-dd", "yyyy-MM-dd'T'HH:mm:ssz", "yyyy-MM-dd'T'HH:mm:ss.SSSz"};

        SimpleDateFormat format = new SimpleDateFormat(patterns[0], Locale.ENGLISH);
        ParsePosition pos = new ParsePosition(0);
        String s = token.getValue(String.class);

        if (s.endsWith("Z")) {
            s = s.substring(0, s.length() - 1) + "GMT-00:00";
        }

        for (final String pattern : patterns) {
            format.applyPattern(pattern);
            format.setLenient(true);
            pos.setIndex(0);

            Date date = format.parse(s, pos);

            if (date != null && pos.getIndex() == s.length()) {
                return date.getTime();
            }
        }

In my experiment, I've made a slight modification to not do the the index/length equality check, e.g.

            if (date != null) {
                System.out.println("Parsed time and timezone:");
                System.out.println(date.getTime());
            }

And looking at the output of my gist, you see that even if they first two options (English and ROOT) encounter an NPE, they both print the same time as the option that uses the CANADA_FRENCH locale (the one given in creation of native image). I've no idea if this is valid code but it's noticeable that if you don't have this check, you compute the time and date earlier, before the NPE arises. Quarkus could substitute such method to do this and see whether things still work at all...

loicmathieu commented 4 years ago

We could substitute as a temporal workaround but this issue should be raised on the MongoDB driver as an issue with GraalVM as I think a sample code without quarkus will experiement the same issue.

I'm pretty sure they can use the default TZ instead of EN but they need to do it on their side.

galderz commented 4 years ago

@loicmathieu I'll create a substitution and see if @nicolinux72 can try.

nicolinux72 commented 4 years ago

certainly @galderz ,

I am waiting for information on how to proceed.

Thanks for your help Nicola

galderz commented 4 years ago

@nicolinux72 I've created a branch with a workaround substitution that should avoid the issue. Could you build it locally and give it a go? It passed the mongo db native tests locally.

The substitution is not pretty, but should do the job until MongoDB address the fixed locale issue. I'll create an issue with them.

If the patch works I'll send a PR.

nicolinux72 commented 4 years ago

Hello,

please forgive the delay in answering but we are under an important deadline at work.

Unfortunately I was not even able to compile my test case with the version provided. This is the stack trace:

[ERROR] Failed to execute goal io.quarkus:quarkus-maven-plugin:1.7.0.Final:build (default) on project eventi: Failed to build quarkus application: io.quarkus.builder.BuildException: Build failure: Build failed due to errors
[ERROR]     [error]: Build step io.quarkus.mongodb.panache.deployment.BasePanacheMongoResourceProcessor#registerJacksonSerDeser threw an exception: java.lang.InstantiationError
[ERROR]     at java.base/jdk.internal.reflect.InstantiationExceptionConstructorAccessorImpl.newInstance(InstantiationExceptionConstructorAccessorImpl.java:48)
[ERROR]     at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
[ERROR]     at io.quarkus.deployment.ExtensionLoader$2.execute(ExtensionLoader.java:906)
[ERROR]     at io.quarkus.builder.BuildContext.run(BuildContext.java:277)
[ERROR]     at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
[ERROR]     at java.base/java.lang.Thread.run(Thread.java:834)
[ERROR]     at org.jboss.threads.JBossThread.run(JBossThread.java:479)
[ERROR] 
[ERROR]     [error]: Build step io.quarkus.mongodb.panache.deployment.BasePanacheMongoResourceProcessor#registerForReflection threw an exception: java.lang.InstantiationError
[ERROR]     at java.base/jdk.internal.reflect.InstantiationExceptionConstructorAccessorImpl.newInstance(InstantiationExceptionConstructorAccessorImpl.java:48)
[ERROR]     at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
[ERROR]     at io.quarkus.deployment.ExtensionLoader$2.execute(ExtensionLoader.java:906)
[ERROR]     at io.quarkus.builder.BuildContext.run(BuildContext.java:277)
[ERROR]     at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
[ERROR]     at java.base/java.lang.Thread.run(Thread.java:834)
[ERROR]     at org.jboss.threads.JBossThread.run(JBossThread.java:479)
[ERROR] 
[ERROR]     [error]: Build step io.quarkus.mongodb.panache.deployment.BasePanacheMongoResourceProcessor#registerJsonbSerDeser threw an exception: java.lang.InstantiationError
[ERROR]     at java.base/jdk.internal.reflect.InstantiationExceptionConstructorAccessorImpl.newInstance(InstantiationExceptionConstructorAccessorImpl.java:48)
[ERROR]     at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
[ERROR]     at io.quarkus.deployment.ExtensionLoader$2.execute(ExtensionLoader.java:906)
[ERROR]     at io.quarkus.builder.BuildContext.run(BuildContext.java:277)
[ERROR]     at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
[ERROR]     at java.base/java.lang.Thread.run(Thread.java:834)
[ERROR]     at org.jboss.threads.JBossThread.run(JBossThread.java:479)
[ERROR] 
[ERROR]     [error]: Build step io.quarkus.mongodb.panache.deployment.BasePanacheMongoResourceProcessor#unremovableClients threw an exception: java.lang.InstantiationError
[ERROR]     at java.base/jdk.internal.reflect.InstantiationExceptionConstructorAccessorImpl.newInstance(InstantiationExceptionConstructorAccessorImpl.java:48)
[ERROR]     at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
[ERROR]     at io.quarkus.deployment.ExtensionLoader$2.execute(ExtensionLoader.java:906)
[ERROR]     at io.quarkus.builder.BuildContext.run(BuildContext.java:277)
[ERROR]     at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
[ERROR]     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
[ERROR]     at java.base/java.lang.Thread.run(Thread.java:834)
[ERROR]     at org.jboss.threads.JBossThread.run(JBossThread.java:479)
[ERROR] -> [Help 1]

I could have done something wrong, in fact I was able to compile and install locally the quarkus branch provided to me (999-SNAPSHOT) but only skipping the tests :-(

galderz commented 4 years ago

The issue might be due to still using Quarkus 1.7 maven plugin there. I can't help much further without seeing your pom.xml, but when I use a Quarkus snapshot, having started from a sample downloaded from code.quarkus.io, I pass in these properties:

-Dquarkus.platform.version=999-SNAPSHOT
-Dquarkus-plugin.version=999-SNAPSHOT
-Dquarkus.platform.artifact-id=quarkus-bom

See an example here and the corresponding pom.xml.

nicolinux72 commented 4 years ago

Good morning,

added the parameters indicated, the build was successful. We still have the same error in SimpleDateFormat class.

2020-09-23 08:55:56,455 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-1) HTTP Request to /v1/beat/ffff5e8a-2b59-4787-8386-fe039e8dd622?idModulo=1525e070-16a5-45c3-a8ed-72a649a03d18 failed, error id: 6365b73f-66a9-4991-977c-4e111faa2961-1: org.jboss.resteasy.spi.UnhandledException: java.lang.NullPointerException
    at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:106)
    at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:372)
    at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:216)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:515)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:259)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:160)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:163)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:245)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:131)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:37)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:94)
    at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at org.jboss.threads.Good morning,
EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at java.lang.Thread.run(Thread.java:834)
    at org.jboss.threads.JBossThread.run(JBossThread.java:479)
    at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:517)
    at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
Caused by: java.lang.NullPointerException
    at java.text.SimpleDateFormat.matchZoneString(SimpleDateFormat.java:1695)
    at java.text.SimpleDateFormat.subParseZoneString(SimpleDateFormat.java:1763)
    at java.text.SimpleDateFormat.subParse(SimpleDateFormat.java:2169)
    at java.text.SimpleDateFormat.parse(SimpleDateFormat.java:1541)
    at org.bson.json.JsonReader.visitISODateTimeConstructor(JsonReader.java:836)
    at org.bson.json.JsonReader.readBsonType(JsonReader.java:225)
    at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:167)
    at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:46)
    at org.bson.codecs.DocumentCodec.readValue(DocumentCodec.java:258)
    at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:169)
    at org.bson.codecs.DocumentCodec.decode(DocumentCodec.java:46)
    at org.bson.Document.parse(Document.java:110)
    at org.bson.Document.parse(Document.java:95)
    at io.quarkus.mongodb.panache.runtime.MongoOperations.executeUpdate(MongoOperations.java:622)
    at io.quarkus.mongodb.panache.runtime.MongoOperations.update(MongoOperations.java:617)
    at it.cineca.HeartBeat.update(HeartBeat.java)
    at it.cineca.BeatController.aggiornaBattito(BeatController.java:22)
    at java.lang.reflect.Method.invoke(Method.java:566)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:638)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:504)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:454)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:456)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:417)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:391)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:68)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:488)
    ... 19 more

Please Note: I'm using the same test case I posted earlier this month, building with the command: ./mvnw package -Pnative -DskipTests -Dquarkus.platform.version=999-SNAPSHOT -Dquarkus-plugin.version=999-SNAPSHOT -Dquarkus.platform.artifact-id=quarkus-bom

galderz commented 4 years ago

@nicolinux72 That stacktrace would not appear to be right, in the sense that JsonReader.visitISODateTimeConstructor does not appear substituted. If substitution is applied correctly, you should see this method impl being executed. Maybe you're not building the right branch in my repo? You can try to load the branch up in the IDE and use a debugger to make sure it gets executed...etc

nicolinux72 commented 4 years ago

Hello,

I apologize for the oversight and confirm that your substitution fixes the problem: thank you.

Will this change end in an upcoming official release? How will we be able to use it in production?

Nicola

gsmet commented 4 years ago

I don't understand why we closed this issue.

For me, the problem is important enough that:

2/ is required to do 1/, I don't want to have a workaround forever.

galderz commented 4 years ago

@nicolinux72 Glad to hear the substitution works. I'll work to send a PR for it.

@gsmet I probably close it by mistake 😊

Indeed we should open an issue in MongoDB driver tracker, I've been meaning to do that, but I first wanted to double check that the workaround worked for @nicolinux72. I'll open it shortly.

galderz commented 4 years ago

I've just created JAVA-3851 in MongoDB's jira.

galderz commented 4 years ago

Sent PR 👆

jyemin commented 4 years ago

@nicolinux72 when I try to parse the example document that you provided:

{
    "_id" : "fffff124-615d-40b2-bb08-a7edd9afacd4",
    "interruzione" : false,
    "istante" : ISODate("2019-08-26T17:38:20.917+02:00")
}

using the Java driver in OpenJDK, it fails, as the JsonReader throws org.bson.json.JsonParseException: Invalid date format.

Could you try using the Relaxed Extended JSON format instead, which is specified here? The document would like this this:

{
    "_id" : "fffff124-615d-40b2-bb08-a7edd9afacd4",
    "interruzione" : false,
    "istante" : {  "$date": "2019-08-26T17:38:20.917+02:00"}
}

The method that parses relaxed extended JSON depends on java.time.format.DateTimeFormatter#ISO_OFFSET_DATE_TIME rather than SimpleDateFormat, which I think will be immune to the issue you're encountering. It also correctly parses the date format that you're using.

nicolinux72 commented 4 years ago

good morning @jyemin,

I think I don't understand your suggestion: in all the tests I've done, since the beginning of this case, the non-natively compiled version of the application, the one that runs on the openJDK, has always worked correctly.

You can check it yourself using the test case I sent in early September, just like I did this morning, just to be careful.

Incidentally, the collection documents you are referring to were created with Quarkus, using this line of code that you could use to complete the test round.

hb = new HeartBeat(12345, new Date(), false);
HeartBeat.persist(hb);

In addition, even using Spring Boot it is possible to read that collection (so the ISODATE() date format) without special care.

Am I missing something?

As always, thanks for your help. Nicola

jyemin commented 4 years ago

Hi @nicolinux72, sorry for the confusion. I'm still getting acquainted with Quarkus so I'm getting my bearings.

My misunderstanding stemmed from the sample document you provided, which does indeed use an ISODate format that the driver is not able to parse. But now I see that the ISODate format is something different, and is actually generated by Quarkus itself, right here. This code will generate ISODate strings in the format yyyy-MM-dd'T'HH:mm:ss.SSS'Z', which is parseable by JsonReader.

So I agree that you can't fix this in your own code, but I think my suggestion could be applied to Quarkus itself: instead of using the shell syntax in CommonQueryBinder, it could use the extended JSON syntax. I created a branch to show the idea: https://github.com/jyemin/quarkus/commit/13154e00db53b9e3b5ff1f0c44b0c89baaf69488.

@galderz does this look like a reasonable avenue to pursue?

galderz commented 4 years ago

@jyemin That sounds good to me, though I'm not an expert on MongoDB itself. Best might be to send a PR with that fix and see if CI agrees and you can feedback from developers. Judging from git blame, it's @loicmathieu that added them to fix https://github.com/quarkusio/quarkus/commit/8b3d76af5e8f056334cc6ca39b78b90eedd8136a.

galderz commented 4 years ago

Actually, @loicmathieu might have just fixed something there, the use of ISODate predates that commit.

galderz commented 4 years ago

Though seems @loicmathieu did the original work too, see https://github.com/quarkusio/quarkus/commit/1946498698eef487ddb5a7635e4818de8c6fe105.

loicmathieu commented 4 years ago

@jyemin You can open a PR so we can discuss this.

This would fix the issue for PanacheQL but not for native query as it should be valid to make such query. So this is a workaround, MongoDB still has an issue with date parsing in native.