I've found something interesting I think. I started adding some logging statements in my controller to see if the span was still populated. I added these two lines:
.doOnNext(__ -> log.info(
"Elastic span in service: {}", ElasticApm.currentSpan().getId()))
.doOnNext(__ -> log.info("OTel span in service: {}", Span.current()))
What I noticed was that both were giving the correct information, but also that the OTel instrumentation was loaded just before that log line was printed:
2023-05-09 13:39:29.844 INFO 64681 --- [actor-tcp-nio-2] [default] i.h.r.service.PatientService : Elastic span in service: e9f4a6bb93e3904f
2023-05-09 13:39:29,845 [reactor-tcp-nio-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation ContextStorageInstrumentation: name(equals(io.opentelemetry.context.ContextStorage)) matches interface io.opentelemetry.context.ContextStorage
2023-05-09 13:39:29,847 [reactor-tcp-nio-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation ContextStorageInstrumentation: (name(equals(get)) and returns(erasure(name(equals(io.opentelemetry.context.ContextStorage)))) and not(isAbstract())) matches public static io.opentelemetry.context.ContextStorage io.opentelemetry.context.ContextStorage.get()
2023-05-09 13:39:29,852 [reactor-tcp-nio-2] DEBUG co.elastic.apm.agent.bci.IndyPluginClassLoaderFactory - Creating plugin class loader for jdk.internal.loader.ClassLoaders$AppClassLoader@2aae9190 containing [co.elastic.apm.agent.opentelemetry.GlobalOpenTelemetryInstrumentation, co.elastic.apm.agent.opentelemetry.tracing.OTelTracerProvider, co.elastic.apm.agent.opentelemetry.tracing.OTelSpan$1, co.elastic.apm.agent.opentelemetry.tracing.OTelSpan, co.elastic.apm.agent.opentelemetry.tracing.OTelTracer, co.elastic.apm.agent.opentelemetry.tracing.BehavioralAttributes, co.elastic.apm.agent.opentelemetry.tracing.package-info, co.elastic.apm.agent.opentelemetry.tracing.OTelBridgeContext, co.elastic.apm.agent.opentelemetry.tracing.OTelSpanBuilder, co.elastic.apm.agent.opentelemetry.tracing.OTelSpanContext, co.elastic.apm.agent.opentelemetry.ContextStorageInstrumentation$ContextStorageAdvice, co.elastic.apm.agent.opentelemetry.global.ElasticOpenTelemetry, co.elastic.apm.agent.opentelemetry.global.ElasticOpenTelemetryWithMetrics, co.elastic.apm.agent.opentelemetry.ArrayBasedContextInstrumentation$RootAdvice, co.elastic.apm.agent.opentelemetry.package-info, co.elastic.apm.agent.opentelemetry.metrics.bridge.BridgedElement, co.elastic.apm.agent.opentelemetry.metrics.bridge.BridgeFactoryLatest, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeLongGaugeBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeDoubleGaugeBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeDoubleCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeDoubleUpDownCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeBatchCallback, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeLongCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeLongUpDownCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.latest.BridgeMeter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleUpDownCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeMeterProvider, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleHistogram, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableLongGauge, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongGaugeBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableDoubleMeasurement, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleGaugeBuilder$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleCounterBuilder$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongCounterBuilder$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleGaugeBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongHistogram, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleUpDownCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongGaugeBuilder$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableLongUpDownCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableDoubleGauge, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleHistogramBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableLongMeasurement, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableDoubleUpDownCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableDoubleCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongUpDownCounterBuilder$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongUpDownCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongUpDownCounterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeObservableLongCounter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeMeterBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeMeter, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeLongHistogramBuilder, co.elastic.apm.agent.opentelemetry.metrics.bridge.v1_14.BridgeDoubleUpDownCounterBuilder$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.AbstractBridgedElement, co.elastic.apm.agent.opentelemetry.metrics.bridge.BridgeFactoryV1_14$1, co.elastic.apm.agent.opentelemetry.metrics.bridge.BridgeFactory, co.elastic.apm.agent.opentelemetry.metrics.bridge.BridgeFactoryV1_14, co.elastic.apm.agent.opentelemetry.metrics.bridge.OtelMetricsBridge, co.elastic.apm.agent.opentelemetry.ArrayBasedContextInstrumentation, co.elastic.apm.agent.opentelemetry.context.OTelContextStorage, co.elastic.apm.agent.opentelemetry.context.package-info, co.elastic.apm.agent.opentelemetry.GlobalOpenTelemetryInstrumentation$GlobalOpenTelemetryAdvice, co.elastic.apm.agent.opentelemetry.ContextStorageInstrumentation, co.elastic.apm.agent.opentelemetry.AbstractOpenTelemetryInstrumentation, co.elastic.apm.agent.bci.classloading.LookupExposer]
2023-05-09 13:39:29,878 [reactor-tcp-nio-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation ArrayBasedContextInstrumentation: name(equals(io.opentelemetry.context.ArrayBasedContext)) matches class io.opentelemetry.context.ArrayBasedContext
2023-05-09 13:39:29,879 [reactor-tcp-nio-2] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation ArrayBasedContextInstrumentation: (name(equals(root)) and isStatic() and returns(erasure(hasSuperType(erasure(name(equals(io.opentelemetry.context.Context)))))) and hasParameter(ofSize(0)) and not(isAbstract())) matches static io.opentelemetry.context.Context io.opentelemetry.context.ArrayBasedContext.root()
2023-05-09 13:39:29,881 [reactor-tcp-nio-2] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to 'PatientRestController#getAllPatients' 00-21953cf40dec8b5df38075eb71c14d1a-e9f4a6bb93e3904f-01 (4f86b41e) (88)
2023-05-09 13:39:29.882 INFO 64681 --- [actor-tcp-nio-2] [default] i.h.r.service.PatientService : OTel span in service: OtelSpan['PatientRestController#getAllPatients' 00-21953cf40dec8b5df38075eb71c14d1a-e9f4a6bb93e3904f-01 (4f86b41e)]
Which triggered me, so I tried to add a line where I accessed the OTel span at the very start of my controller method and the plugin is working as expected again! It looks like since 1.37 the OTel instrumentation isn't loaded anymore when a plugin is in use. But because the plugins depend on OTel those instrumentations should be loaded I think.
Edit:
Just checked when this instrumentation was loaded in 1.36:
2023-05-09 13:48:22.505 DEBUG 65716 --- [actor-tcp-nio-1] [] h.a.a.r.p.R2dbcPostgresqlInstrumentation : Creating R2DBC span
2023-05-09 13:48:22.507 DEBUG 65716 --- [actor-tcp-nio-1] [] h.a.a.r.p.R2dbcPostgresqlInstrumentation : Found signature SHOW
2023-05-09 13:48:22,507 [reactor-tcp-nio-1] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Type match for instrumentation GlobalOpenTelemetryInstrumentation: name(equals(io.opentelemetry.api.GlobalOpenTelemetry)) matches class io.opentelemetry.api.GlobalOpenTelemetry
2023-05-09 13:48:22,508 [reactor-tcp-nio-1] DEBUG co.elastic.apm.agent.bci.ElasticApmAgent - Method match for instrumentation GlobalOpenTelemetryInstrumentation: (name(equals(get)) and not(isAbstract())) matches public static io.opentelemetry.api.OpenTelemetry io.opentelemetry.api.GlobalOpenTelemetry.get()
2023-05-09 13:48:22,514 [reactor-tcp-nio-1] DEBUG co.elastic.apm.agent.bci.IndyPluginClassLoaderFactory - Creating plugin class loader for IndyPluginClassLoader{ parent=DiscriminatingMultiParentClassLoader{agentClassLoader = ExternalPluginClassLoader{pluginJar=/Users/svenrienstra/Documents/workspaces/h4h/apm-r2-plugin/target/apm-r2dbc-postgresql-plugin-1.1.0-SNAPSHOT.jar, parent =ShadedClassLoader{parent=ShadedClassLoader{parent=jdk.internal.loader.ClassLoaders$PlatformClassLoader@426ebfb9, customPrefix='cached-lookup-key/', manifest=java.util.jar.Manifest@694cf4bb, jarUrl=file:/private/var/folders/ds/xbpb_l816b73hbp9825k7jfw0000gn/T/elastic-apm-agent-6bb636343d7b71ccaa9fd7321da5cc2d-3be90268557494f88fe252caf6358d41.jar}, customPrefix='agent/', manifest=java.util.jar.Manifest@694cf4bb, jarUrl=file:/private/var/folders/ds/xbpb_l816b73hbp9825k7jfw0000gn/T/elastic-apm-agent-6bb636343d7b71ccaa9fd7321da5cc2d-3be90268557494f88fe252caf6358d41.jar}} discriminator = (not(co.elastic.apm.agent.bci.classloading.IndyPluginClassLoader$StartsWithElementMatcher@3c5bf071) and not(co.elastic.apm.agent.bci.classloading.IndyPluginClassLoader$StartsWithElementMatcher@3d66cb0a) and not(co.elastic.apm.agent.bci.classloading.IndyPluginClassLoader$StartsWithElementMatcher@1861ef52)), targetClassLoader =jdk.internal.loader.ClassLoaders$AppClassLoader@2aae9190 discriminator = true}} containing [co.elastic.apm.agent.opentelemetry.package-info, co.elastic.apm.agent.opentelemetry.sdk.package-info, co.elastic.apm.agent.opentelemetry.sdk.OTelBridgeContext, co.elastic.apm.agent.opentelemetry.sdk.OTelSpanBuilder, co.elastic.apm.agent.opentelemetry.sdk.OTelSpanContext, co.elastic.apm.agent.opentelemetry.sdk.OTelTracerProvider, co.elastic.apm.agent.opentelemetry.sdk.OTelSpan$1, co.elastic.apm.agent.opentelemetry.sdk.OTelSpan, co.elastic.apm.agent.opentelemetry.sdk.BehavioralAttributes, co.elastic.apm.agent.opentelemetry.sdk.OTelTracer, co.elastic.apm.agent.opentelemetry.sdk.ElasticOpenTelemetry, co.elastic.apm.agent.opentelemetry.ArrayBasedContextInstrumentation, co.elastic.apm.agent.opentelemetry.ContextStorageInstrumentation$ContextStorageAdvice, co.elastic.apm.agent.opentelemetry.ContextStorageInstrumentation, co.elastic.apm.agent.opentelemetry.ArrayBasedContextInstrumentation$RootAdvice, co.elastic.apm.agent.opentelemetry.GlobalOpenTelemetryInstrumentation$GlobalOpenTelemetryAdvice, co.elastic.apm.agent.opentelemetry.AbstractOpenTelemetryInstrumentation, co.elastic.apm.agent.opentelemetry.context.package-info, co.elastic.apm.agent.opentelemetry.context.OTelContextStorage, co.elastic.apm.agent.opentelemetry.GlobalOpenTelemetryInstrumentation, co.elastic.apm.agent.bci.classloading.LookupExposer]
It's loaded just after the first time the plugin triggered, I guess I just never noticed the first call to the service was missing some information. So the difference is that since 1.37 the OTel instrumentation isn't loaded based on activity by the plugin anymore.