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

ObjectMapperCustomizer only evaluated at build time if resteasy-reactive-jackson or rest-client-reactive-jackson present #32969

Open
manofthepeace opened this issue Apr 27, 2023 · 19 comments · Fixed by #33189
Labels
area/jackson Issues related to Jackson (JSON library) area/rest area/rest-client kind/bug Something isn't working
Milestone

Comments

@manofthepeace
Copy link
Contributor

Describe the bug

I would like to customize my object mapper depending on a configproperty. When I use the quarkus-jackson dependency it all works well, but if I use or quarkus-resteasy-reactive-jackson or quarkus-rest-client-reactive-jackson , it then make it evaluated only at build time using native, and it does not execute while running the app anymore.

The only workaround I found is to have a basic singleton @Startup bean that re-customizes the Objectmapper.

Expected behavior

ObjectMapperCustomizer should run at runtime event it it ran at buildtime so it can work with configproperty/configmapping.

via logs it should look like this at compile time;
[2/7] Performing analysis... [*******]

and running the app;

MY_VARIABLE=prod ./target/jackson-customize-issue-1.0.0-SNAPSHOT-runner
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2023-04-27 15:55:48,906 INFO  [org.acm.RegisterCustomModuleCustomizer] (main) Customizing objectMapper for prod

Actual behavior

ObjectMapper gets customized at buildtime only;

grallvm build;

[2/7] Performing analysis... [15:44:59,592 INFO [org.acm.RegisterCustomModuleCustomizer] Customizing objectMapper for default

app log;
nothing gets logged from the customizer

How to Reproduce?

Reproduce: https://github.com/manofthepeace/quarkus-jackson-buildtime-issue

Steps to reproduce

  1. mvn clean package -Pnative
  2. ./target/jackson-customize-issue-1.0.0-SNAPSHOT-runner (should print default at runtime)
  3. MY_VARIABLE=prod ./target/jackson-customize-issue-1.0.0-SNAPSHOT-runner (should print prod at runtime)
  4. Modify the pom.xml, remove the quarkus-jackson dependency and uncomment one or both of the resteasy-reactive ones
  5. recompile via mvn clean package -Pnative
  6. observes the log at build time during the graalvm processing phase
  7. rerun step 2 and 3, will not print, and default is always actually used

Output of uname -a or ver

Darwin Kernel Version 21.6.0

Output of java -version

OpenJDK Runtime Environment Temurin-17.0.7+7 (build 17.0.7+7)

GraalVM version (if different from Java)

21.3.1

Quarkus version or git rev

2.16.6

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

Apache Maven 3.8.7

Additional information

No response

@manofthepeace manofthepeace added the kind/bug Something isn't working label Apr 27, 2023
@quarkus-bot quarkus-bot bot added area/jackson Issues related to Jackson (JSON library) area/rest-client area/rest labels Apr 27, 2023
@quarkus-bot
Copy link

quarkus-bot bot commented Apr 27, 2023

/cc @FroMage (resteasy-reactive), @Sgitario (rest-client,resteasy-reactive), @cescoffier (rest-client), @geoand (jackson,rest-client,resteasy-reactive), @gsmet (jackson), @stuartwdouglas (resteasy-reactive)

@geoand
Copy link
Contributor

geoand commented Apr 28, 2023

Does this problem only happen in native mode?

@manofthepeace
Copy link
Contributor Author

Yes this only happens in native mode. In Jvm mode I do not see the log at built time, only at runtime, with the right value

@geoand
Copy link
Contributor

geoand commented Apr 28, 2023

Understood, thanks

@geoand
Copy link
Contributor

geoand commented May 8, 2023

#33189 takes care of it

geoand added a commit to geoand/quarkus that referenced this issue May 8, 2023
geoand added a commit to geoand/quarkus that referenced this issue May 8, 2023
geoand added a commit to geoand/quarkus that referenced this issue May 9, 2023
geoand added a commit to geoand/quarkus that referenced this issue May 10, 2023
geoand added a commit that referenced this issue May 10, 2023
Ensure that ObjectMapperCustomizer impls are used in runtime init
@quarkus-bot quarkus-bot bot added this to the 3.1 - main milestone May 10, 2023
michelle-purcell pushed a commit to michelle-purcell/quarkus that referenced this issue May 11, 2023
manofthepeace pushed a commit to manofthepeace/quarkus that referenced this issue May 16, 2023
@manofthepeace
Copy link
Contributor Author

@geoand I dont understand how yet, but this is not fixed in my application. I have tried on the reproducer, and the fix indeed works, but in my main app I still see the class being initialized at build time and not at runtime. I have added the following --trace-object-instantiation=org.acme.MyClass in the native build param, but whatever class I put there I do not see any extra log printing while building. Would you have any idea how I could determine the culprit?

I have also tried to add al pom dependencies from may app to the reproducer, and enhance a little the reproducer but the reproducer still works fine, the main app doesn't.

@geoand
Copy link
Contributor

geoand commented Jun 5, 2023

Would you have any idea how I could determine the culprit?

Not off hand unfortunately

@manofthepeace
Copy link
Contributor Author

@geoand sorry for the ping again. Does that help? Still unsure how to have a reproducer for it but was able to get that stacktrace;

Error: Classes that should be initialized at run time got initialized during image building:
 org.acme.ObjectMapperConfigurator the class was requested to be initialized at run time (from command line with 'org.acme.ObjectMapperConfigurator'). io.quarkus.runner.ApplicationImpl caused initialization of this class with the following trace:
    at org.acme.ObjectMapperConfigurator.<clinit>(ObjectMapperConfigurator.java:14)
    at org.acme.ObjectMapperConfigurator_Bean.doCreate(Unknown Source)
    at org.acme.ObjectMapperConfigurator_Bean.create(Unknown Source)
    at org.acme.ObjectMapperConfigurator_Bean.create(Unknown Source)
    at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:113)
    at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:37)
    at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:34)
    at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:26)
    at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
    at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:34)
    at org.acme.ObjectMapperConfigurator_Bean.get(Unknown Source)
    at org.acme.ObjectMapperConfigurator_Bean.get(Unknown Source)
    at io.quarkus.arc.impl.Instances.getBeanInstance(Instances.java:115)
    at io.quarkus.arc.impl.Instances.listOf(Instances.java:75)
    at io.quarkus.arc.impl.ListProvider.get(ListProvider.java:50)
    at io.quarkus.arc.impl.ListProvider.get(ListProvider.java:15)
    at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.doCreate(Unknown Source)
    at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.create(Unknown Source)
    at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.create(Unknown Source)
    at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:113)
    at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:37)
    at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:34)
    at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:26)
    at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
    at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:34)
    at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.get(Unknown Source)
    at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.get(Unknown Source)
    at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.FullyFeaturedServerJacksonMessageBodyWriter_Bean.doCreate(Unknown Source)
    at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.FullyFeaturedServerJacksonMessageBodyWriter_Bean.create(Unknown Source)
    at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.FullyFeaturedServerJacksonMessageBodyWriter_Bean.get(Unknown Source)
    at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.FullyFeaturedServerJacksonMessageBodyWriter_Bean.get(Unknown Source)
    at io.quarkus.arc.impl.ArcContainerImpl.beanInstanceHandle(ArcContainerImpl.java:499)
    at io.quarkus.arc.impl.ArcContainerImpl.beanInstanceHandle(ArcContainerImpl.java:479)
    at io.quarkus.arc.impl.ArcContainerImpl.beanInstanceHandle(ArcContainerImpl.java:512)
    at io.quarkus.arc.impl.ArcContainerImpl$2.get(ArcContainerImpl.java:287)
    at io.quarkus.arc.impl.ArcContainerImpl$2.get(ArcContainerImpl.java:284)
    at io.quarkus.arc.runtime.BeanContainerImpl$1.create(BeanContainerImpl.java:46)
    at io.quarkus.resteasy.reactive.common.runtime.ArcBeanFactory.createInstance(ArcBeanFactory.java:27)
    at org.jboss.resteasy.reactive.common.model.ResourceWriter.instance(ResourceWriter.java:80)
    at org.jboss.resteasy.reactive.common.core.Serialisers.toMessageBodyWriters(Serialisers.java:203)
    at org.jboss.resteasy.reactive.common.core.Serialisers.findBuildTimeWriters(Serialisers.java:157)
    at org.jboss.resteasy.reactive.server.core.startup.RuntimeResourceDeployment.buildResourceMethod(RuntimeResourceDeployment.java:422)
    at org.jboss.resteasy.reactive.server.core.startup.RuntimeDeploymentManager.deploy(RuntimeDeploymentManager.java:122)
    at io.quarkus.resteasy.reactive.server.runtime.ResteasyReactiveRecorder.createDeployment(ResteasyReactiveRecorder.java:184)
    at io.quarkus.deployment.steps.ResteasyReactiveProcessor$setupDeployment1637929001.deploy_3(Unknown Source)
    at io.quarkus.deployment.steps.ResteasyReactiveProcessor$setupDeployment1637929001.deploy(Unknown Source)
    at io.quarkus.runner.ApplicationImpl.<clinit>(Unknown Source)

@manofthepeace
Copy link
Contributor Author

I have updated the previous reproducer here; https://github.com/manofthepeace/quarkus-jackson-buildtime-issue

To reproduce you can follow steps in OP.

Thank you

@geoand
Copy link
Contributor

geoand commented Jun 6, 2023

I'll have a look in a few days

@geoand
Copy link
Contributor

geoand commented Jun 6, 2023

I am not sure what I am supposed to be looking at to see the updated problem in action.

@manofthepeace
Copy link
Contributor Author

Sorry for the lack of information. Problem is only for native but lets compare;

If you run this way (not native)
java -jar target/quarkus-app/quarkus-run.jar you will see a log
Customizing objectMapper for default
and this MY_VARIABLE=prod java -jar target/quarkus-app/quarkus-run.jar will show this;
Customizing objectMapper for prod

in native while building this log is shown
[2/7] Performing analysis... [09:28:55,774 INFO [org.acm.RegisterCustomModuleCustomizer] Customizing objectMapper for default at runtime this is not re-initialized so running the all like this ./target/jackson-customize-issue-1.0.0-SNAPSHOT-runner or MY_VARIABLE=prod ./target/jackson-customize-issue-1.0.0-SNAPSHOT-runner, wont show the log, and use the default config.

when using
mvn clean package -DskipTests -Pnative -Dquarkus.native.additional-build-args="--initialize-at-run-time=org.acme.RegisterCustomModuleCustomizer,--trace-class-initialization=org.acme.RegisterCustomModuleCustomizer"

The following exception is thrown (please note the exception I had pasted above (with my main app) is using FullyFeaturedServerJacksonMessageBodyWriter and the reproducer this one BasicServerJacksonMessageBodyWriter) but the outcome seems similar

com.oracle.svm.core.util.UserError$UserException: Classes that should be initialized at run time got initialized during image building:
 org.acme.RegisterCustomModuleCustomizer the class was requested to be initialized at run time (from command line with 'org.acme.RegisterCustomModuleCustomizer'). io.quarkus.runner.ApplicationImpl caused initialization of this class with the following trace:
	at org.acme.RegisterCustomModuleCustomizer.<clinit>(RegisterCustomModuleCustomizer.java)
	at org.acme.RegisterCustomModuleCustomizer_Bean.doCreate(Unknown Source)
	at org.acme.RegisterCustomModuleCustomizer_Bean.create(Unknown Source)
	at org.acme.RegisterCustomModuleCustomizer_Bean.create(Unknown Source)
	at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:113)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:37)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:34)
	at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:26)
	at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
	at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:34)
	at org.acme.RegisterCustomModuleCustomizer_Bean.get(Unknown Source)
	at org.acme.RegisterCustomModuleCustomizer_Bean.get(Unknown Source)
	at io.quarkus.arc.impl.Instances.getBeanInstance(Instances.java:115)
	at io.quarkus.arc.impl.Instances.listOf(Instances.java:75)
	at io.quarkus.arc.impl.ListProvider.get(ListProvider.java:50)
	at io.quarkus.arc.impl.ListProvider.get(ListProvider.java:15)
	at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.doCreate(Unknown Source)
	at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.create(Unknown Source)
	at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.create(Unknown Source)
	at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:113)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:37)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:34)
	at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:26)
	at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
	at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:34)
	at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.get(Unknown Source)
	at io.quarkus.jackson.runtime.ObjectMapperProducer_ProducerMethod_objectMapper_d2925203309586fa5cde23a83b2025591c2d3832_Bean.get(Unknown Source)
	at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.BasicServerJacksonMessageBodyWriter_Bean.doCreate(Unknown Source)
	at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.BasicServerJacksonMessageBodyWriter_Bean.create(Unknown Source)
	at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.BasicServerJacksonMessageBodyWriter_Bean.get(Unknown Source)
	at io.quarkus.resteasy.reactive.jackson.runtime.serialisers.BasicServerJacksonMessageBodyWriter_Bean.get(Unknown Source)
	at io.quarkus.arc.impl.ArcContainerImpl.beanInstanceHandle(ArcContainerImpl.java:499)
	at io.quarkus.arc.impl.ArcContainerImpl.beanInstanceHandle(ArcContainerImpl.java:479)
	at io.quarkus.arc.impl.ArcContainerImpl.beanInstanceHandle(ArcContainerImpl.java:512)
	at io.quarkus.arc.impl.ArcContainerImpl$2.get(ArcContainerImpl.java:287)
	at io.quarkus.arc.impl.ArcContainerImpl$2.get(ArcContainerImpl.java:284)
	at io.quarkus.arc.runtime.BeanContainerImpl$1.create(BeanContainerImpl.java:46)
	at io.quarkus.resteasy.reactive.common.runtime.ArcBeanFactory.createInstance(ArcBeanFactory.java:27)
	at org.jboss.resteasy.reactive.common.model.ResourceWriter.instance(ResourceWriter.java:80)
	at org.jboss.resteasy.reactive.common.core.Serialisers.toMessageBodyWriters(Serialisers.java:203)
	at org.jboss.resteasy.reactive.common.core.Serialisers.findBuildTimeWriters(Serialisers.java:157)
	at org.jboss.resteasy.reactive.server.core.startup.RuntimeResourceDeployment.buildResourceMethod(RuntimeResourceDeployment.java:422)
	at org.jboss.resteasy.reactive.server.core.startup.RuntimeDeploymentManager.deploy(RuntimeDeploymentManager.java:122)
	at io.quarkus.resteasy.reactive.server.runtime.ResteasyReactiveRecorder.createDeployment(ResteasyReactiveRecorder.java:184)
	at io.quarkus.deployment.steps.ResteasyReactiveProcessor$setupDeployment1637929001.deploy_0(Unknown Source)
	at io.quarkus.deployment.steps.ResteasyReactiveProcessor$setupDeployment1637929001.deploy(Unknown Source)
	at io.quarkus.runner.ApplicationImpl.<clinit>(Unknown Source)

Please let me know if anything and thank you for your time.

@geoand
Copy link
Contributor

geoand commented Jun 7, 2023

Gotcha, thanks

@geoand
Copy link
Contributor

geoand commented Jun 7, 2023

This seems to be caused by the presence of the prometheus metrics extension, but I still haven't dug deep enough to know what we can do about it.

@manofthepeace
Copy link
Contributor Author

I tried removing the extension from the reproducer and the same happens. I was more under the impression it was in resteasy somewhere since it started to happen in the reproducer once I did an api that took or returned a jackson entity, returning or taking a String for example did not cause the issue as I recall.

@manofthepeace
Copy link
Contributor Author

can this be reopened?

@geoand geoand reopened this Jun 21, 2023
@manofthepeace
Copy link
Contributor Author

@geoand do you think this could have another look?

I have updated the reproduce here: https://github.com/manofthepeace/quarkus-jackson-buildtime-issue to use latest quarkus 3.17 and removed a bunch of extensions.

To recap. ObjectMapperCustomizer does not get evaluated at run time when using native. During my lasts tests it led to the classes FullyFeaturedServerJacksonMessageBodyWriter and BasicServerJacksonMessageBodyWriter

the reproducer was able to reproduce the "basic" bodywrittrer issues, while my real app gets the "fully" unsure what triggers that, but cause seem to be similar.

graal used: Running Quarkus native-image plugin on GRAALVM 23.1 JDK 21.0.2+13-LTS-jvmci-23.1-b30

when running ./mvnw clean package -DskipTests -Pnative -Dquarkus.native.additional-build-args="--initialize-at-run-time=org.acme.RegisterCustomModuleCustomizer,--trace-class-initialization=org.acme.RegisterCustomModuleCustomizer" I do not seem to see the culprit anymore.

I find this is kind of risky when getting this bug as jvm behaviour differs from native without much indications.

@geoand
Copy link
Contributor

geoand commented Dec 11, 2024

Hopefully some time next week

@geoand
Copy link
Contributor

geoand commented Dec 13, 2024

Looked into it really briefly but didn't find anything worthwhile, so this needs more time

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/jackson Issues related to Jackson (JSON library) area/rest area/rest-client kind/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants