Nullpointer Exception using otel agent 2.6.0

[holiday-sunrise]

java.lang.NullPointerException: Transaction for fccd37e0-d27c-11ef-89f6-9ef2042a1fb3_339736059_2072247449/authorize:\soapkit-config cannot be null

at java.util.Objects.requireNonNull(Objects.java:235) at com.avioconsulting.mule.opentelemetry.internal.processor.MuleNotificationProcessor.handleFlowEndEvent(MuleNotificationProcessor.java:404) at com.avioconsulting.mule.opentelemetry.internal.notifications.listeners.MulePipelineMessageNotificationListener.onNotification(MulePipelineMessageNotificationListener.java:39) at com.avioconsulting.mule.opentelemetry.internal.notifications.listeners.MulePipelineMessageNotificationListener.onNotification(MulePipelineMessageNotificationListener.java:12) at org.mule.runtime.core.api.context.notification.ServerNotificationManager.lambda$fireNotification$2(ServerNotificationManager.java:208) at org.mule.runtime.core.internal.context.notification.Sender.dispatch(Sender.java:28) at org.mule.runtime.core.internal.context.notification.Policy.dispatchToSenders(Policy.java:145) at org.mule.runtime.core.internal.context.notification.Policy.doDispatch(Policy.java:120) at org.mule.runtime.core.internal.context.notification.Policy.dispatch(Policy.java:106) at org.mule.runtime.core.api.context.notification.ServerNotificationManager.notifyListeners(ServerNotificationManager.java:226) at org.mule.runtime.core.api.context.notification.ServerNotificationManager.fireNotification(ServerNotificationManager.java:208) at org.mule.runtime.core.internal.context.notification.DefaultNotificationDispatcher.dispatch(DefaultNotificationDispatcher.java:40) at org.mule.runtime.core.internal.construct.AbstractPipeline.fireCompleteNotification(AbstractPipeline.java:494) at org.mule.runtime.core.internal.construct.AbstractPipeline.lambda$beforeProcessors$25(AbstractPipeline.java:478) at org.mule.runtime.core.internal.event.AbstractEventContext.signalConsumerSilently(AbstractEventContext.java:284) at org.mule.runtime.core.internal.event.AbstractEventContext.tryComplete(AbstractEventContext.java:235) at org.mule.runtime.core.internal.event.AbstractEventContext.responseDone(AbstractEventContext.java:214) at org.mule.runtime.core.internal.event.AbstractEventContext.success(AbstractEventContext.java:161) at org.mule.runtime.core.internal.construct.AbstractPipeline.lambda$afterProcessors$27(AbstractPipeline.java:503) at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.onNext(FluxPeekFuseable.java:840) at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onNext(FluxMap.java:224) at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onNext(FluxPeekFuseable.java:503) at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onNext(FluxPeekFuseable.java:503) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxCreate$BufferAsyncSink.drain(FluxCreate.java:814) at reactor.core.publisher.FluxCreate$BufferAsyncSink.next(FluxCreate.java:739) at reactor.core.publisher.FluxCreate$SerializedFluxSink.next(FluxCreate.java:161) at org.mule.runtime.core.internal.rx.FluxSinkRecorder$DirectDelegate.next(FluxSinkRecorder.java:199) at org.mule.runtime.core.internal.rx.FluxSinkRecorder.next(FluxSinkRecorder.java:71) at org.mule.runtime.core.privileged.processor.chain.AbstractMessageProcessorChain.lambda$apply$11(AbstractMessageProcessorChain.java:278) at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:283) at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onNext(FluxPeekFuseable.java:503) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onNext(FluxPeekFuseable.java:503) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onNext(FluxMap.java:224) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.onNext(FluxPeekFuseable.java:854) at org.mule.runtime.core.privileged.processor.chain.AbstractMessageProcessorChain$2.onNext(AbstractMessageProcessorChain.java:628) at org.mule.runtime.core.privileged.processor.chain.AbstractMessageProcessorChain$2.onNext(AbstractMessageProcessorChain.java:623) at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.onNext(FluxPeekFuseable.java:854) at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onNext(FluxMap.java:224) at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onNext(FluxPeekFuseable.java:503) at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onNext(FluxPeekFuseable.java:503) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.FluxCreate$BufferAsyncSink.drain(FluxCreate.java:814)

[manikmagar]

Thanks for sharing it @holiday-sunrise. Could you share more details about processing that flow /authorize:\soapkit-config for this trace? Possibly a few related logs prior to this error so we can understand what was happening and if there are steps to reproduce this. Was there a failure in message processing with that flow?

[holiday-sunrise]

hi @manikmagar thx for your feedback. Please find attached more information and an explanation of what we are doing.

We are currently testing the version with a high load - 1000 requests per minute - so that we can assess whether the stability of the module is sufficiently high for productive use.

We always use the module in a main flow (rest- api kit or soap api kit). Both API's then forward your requests to a backend. It does not seem to disturb the process itself but we find the exceptions in the APM log of the ELK

In both cases we see the same exception.

java.lang.NullPointerException: Transaction for 1d36d2f0-d27a-11ef-8459-6e045a98ed3f_1550114304_571909302/post:\tokens:com-security-dapi-config cannot be null

at java.util.Objects.requireNonNull(Objects.java:235)
at com.avioconsulting.mule.opentelemetry.internal.processor.MuleNotificationProcessor.handleFlowEndEvent(MuleNotificationProcessor.java:404)
at com.avioconsulting.mule.opentelemetry.internal.notifications.listeners.MulePipelineMessageNotificationListener.onNotification(MulePipelineMessageNotificationListener.java:39)
at com.avioconsulting.mule.opentelemetry.internal.notifications.listeners.MulePipelineMessageNotificationListener.onNotification(MulePipelineMessageNotificationListener.java:12)
at org.mule.runtime.core.api.context.notification.ServerNotificationManager.lambda$fireNotification$2(ServerNotificationManager.java:208)
at org.mule.runtime.core.internal.context.notification.Sender.dispatch(Sender.java:28)
at org.mule.runtime.core.internal.context.notification.Policy.dispatchToSenders(Policy.java:145)
at org.mule.runtime.core.internal.context.notification.Policy.doDispatch(Policy.java:120)
at org.mule.runtime.core.internal.context.notification.Policy.dispatch(Policy.java:106)
at org.mule.runtime.core.api.context.notification.ServerNotificationManager.notifyListeners(ServerNotificationManager.java:226)

or

java.lang.NullPointerException: Transaction for 2ccb06b0-d27e-11ef-8459-6e045a98ed3f_540565535_1782487265/get:\claims\(authorize-for):com-security-dapi-config cannot be null

at java.util.Objects.requireNonNull(Objects.java:235)
at com.avioconsulting.mule.opentelemetry.internal.processor.MuleNotificationProcessor.handleFlowEndEvent(MuleNotificationProcessor.java:404)
at com.avioconsulting.mule.opentelemetry.internal.notifications.listeners.MulePipelineMessageNotificationListener.onNotification(MulePipelineMessageNotificationListener.java:39)
at com.avioconsulting.mule.opentelemetry.internal.notifications.listeners.MulePipelineMessageNotificationListener.onNotification(MulePipelineMessageNotificationListener.java:12)
at org.mule.runtime.core.api.context.notification.ServerNotificationManager.lambda$fireNotification$2(ServerNotificationManager.java:208)
at org.mule.runtime.core.internal.context.notification.Sender.dispatch(Sender.java:28)
at org.mule.runtime.core.internal.context.notification.Policy.dispatchToSenders(Policy.java:145)

i cant share the api itself. please ask witch infos will help you.

[holiday-sunrise]

in the related testframe we can see a lot of OOM Metaspace if OTel is enabled. Could it be a correlation between the Exceptions.

[manikmagar]

Thank you, @holiday-sunrise, for sharing details.

I presume you are using the latest version of the library.

We always use the module in a main flow (rest- api kit or soap api kit). Both API's then forward your requests to a backend. It does not seem to disturb the process itself, but we find the exceptions in the APM log of the ELK.

As this data capture is async to the main process, it is correct that it won't affect your request processing.

java.lang.NullPointerException: Transaction for 1d36d2f0-d27a-11ef-8459-6e045a98ed3f_1550114304_571909302/post:\tokens:com-security-dapi-config cannot be null

1d36d2f0-d27a-11ef-8459-6e045a98ed3f should be a correlation ID. From the logs, do you see when that correlation ID's flow processing may have ended, in case you are logging anything at the end of the flows? OR, looking at the trace of the corresponding request, what time did the trace/span end vs. the time of this exception in the logs?

I don't think Metaspace OOM is related to this exception. It may just be the load is exhausting the resources.

[holiday-sunrise]

hi @manikmagar

I presume you are using the latest version of the library.
yes that right.

1d36d2f0-d27a-11ef-8459-6e045a98ed3f should be a correlation ID.

in which field should it be stored ?

com.avioconsulting.mule.opentelemetry.internal.processor.MuleNotificationProcessor. Line 404 which value is null ?!?

Objects.requireNonNull(transactionMeta,
"Transaction for " + traceComponent.contextScopedLocation() + " cannot be null"),
notification.getResourceIdentifier(),
notification.getException());

[holiday-sunrise]

maybe related log