The MicroProfile test fails against Camel 3.1.0-SNAPSHOT

[ppalaga]

The log (JVM mode):

[INFO] Running org.apache.camel.quarkus.component.microprofile.it.metrics.MicroProfileMetricsTest
2020-01-22 14:21:53,254 INFO  [org.apa.cam.mai.BaseMainSupport] (main) Auto-configuration summary:
2020-01-22 14:21:53,256 INFO  [org.apa.cam.mai.BaseMainSupport] (main)  camel.context.name=quarkus-camel-example
2020-01-22 14:21:53,346 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Apache Camel 3.1.0-SNAPSHOT (CamelContext: quarkus-camel-example) is starting
2020-01-22 14:21:53,347 INFO  [org.apa.cam.imp.eng.DefaultManagementStrategy] (main) JMX is disabled
2020-01-22 14:21:53,406 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) StreamCaching is not in use. If using streams then its recommended to enable stream caching. See more details at http://camel.apache.org/stream-caching.html
2020-01-22 14:21:53,414 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: healthyRoute started and consuming from: direct://start
2020-01-22 14:21:53,415 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route1 started and consuming from: direct://counter
2020-01-22 14:21:53,415 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route2 started and consuming from: direct://concurrentGaugeIncrement
2020-01-22 14:21:53,416 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route3 started and consuming from: direct://concurrentGaugeDecrement
2020-01-22 14:21:53,416 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route4 started and consuming from: direct://gauge
2020-01-22 14:21:53,416 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route5 started and consuming from: direct://histogram
2020-01-22 14:21:53,417 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route6 started and consuming from: direct://meter
2020-01-22 14:21:53,417 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Route: route7 started and consuming from: direct://timer
2020-01-22 14:21:53,422 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Total 8 routes, of which 8 are started
2020-01-22 14:21:53,424 INFO  [org.apa.cam.qua.cor.FastCamelContext] (main) Apache Camel 3.1.0-SNAPSHOT (CamelContext: quarkus-camel-example) started in 0.077 seconds
2020-01-22 14:21:53,426 INFO  [io.quarkus] (main) Quarkus 1.2.0.CR1 started in 0.840s. Listening on: http://0.0.0.0:34761
2020-01-22 14:21:53,427 INFO  [io.quarkus] (main) Profile test activated. 
2020-01-22 14:21:53,427 INFO  [io.quarkus] (main) Installed features: [camel-core, camel-direct, camel-log, camel-microprofile-health, camel-microprofile-metrics, camel-support-common, cdi, resteasy, smallrye-health, smallrye-metrics]
2020-01-22 14:21:55,366 INFO  [message] (executor-thread-1) Exchange[ExchangePattern: InOnly, BodyType: String, Body: Test log message]
2020-01-22 14:21:55,469 INFO  [message] (executor-thread-1) Exchange[ExchangePattern: InOnly, BodyType: String, Body: Test log message]
[ERROR] Tests run: 11, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 6.299 s <<< FAILURE! - in org.apache.camel.quarkus.component.microprofile.it.metrics.MicroProfileMetricsTest
[ERROR] org.apache.camel.quarkus.component.microprofile.it.metrics.MicroProfileMetricsTest.testMicroProfileMetricsMessageHistoryFactory  Time elapsed: 0.103 s  <<< ERROR!
java.lang.NullPointerException
        at org.apache.camel.quarkus.component.microprofile.it.metrics.MicroProfileMetricsTest.testMicroProfileMetricsMessageHistoryFactory(MicroProfileMetricsTest.java:107)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:675)
        at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:125)
        at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:132)
        at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:124)
        at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:74)
        at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:104)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:62)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:43)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:35)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:202)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:198)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:135)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:69)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:135)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
        at java.util.ArrayList.forEach(ArrayList.java:1257)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
        at java.util.ArrayList.forEach(ArrayList.java:1257)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
        at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
        at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:229)
        at org.junit.platform.launcher.core.DefaultLauncher.lambda$execute$6(DefaultLauncher.java:197)
        at org.junit.platform.launcher.core.DefaultLauncher.withInterceptedStreams(DefaultLauncher.java:211)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:191)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:128)
        at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:154)
        at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:127)
        at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:377)
        at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:138)
        at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:465)
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:451)

[jamesnetherton]

Perhaps a side effect of CAMEL-14398.

[ppalaga]

@jamesnetherton any quick idea how to fix it?

[jamesnetherton]

@ppalaga Not really without digging into it. History is turned on in CamelMicroProfileMetricsRecorder depending on a boolean config value.

I can take a look later if you want.

[ppalaga]

I can take a look later

That would be nice, thanks!

[jamesnetherton]

Seems to be caused by CamelMain.postProcessCamelContext. The auto configuration stuff is turning off message history on the CamelContext and overriding what the metrics extension previously configured.

[lburgazzoli]

We can probably fix that by moving the registration of the message history metrics at runtime through a MainListener.configure and check that the CamelMicroProfileMetricsConfig.enableMessageHistory and the message history are in a consistent state, otherwise we should log a warning.

This is something to fix also on master as we should hit the same issue by explicitly turning off the message history