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.

Sign up for GitHub

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

Jump to bottom

Startup fails when also using Open Telemetry extension #335

Open
Kitt3120 opened this issue Jan 20, 2025 · 3 comments
Open

Startup fails when also using Open Telemetry extension #335

Kitt3120 opened this issue Jan 20, 2025 · 3 comments

Comments

@Kitt3120
Copy link

Hey everyone,

Context

I have an existing Quarkus application and want to add the ability to resolve Azure Keyvault variables through the Azure Services extension to the project. However, when following the guide at https://docs.quarkiverse.io/quarkus-azure-services/dev/quarkus-azure-key-vault.html, the application crashes at startup.

To be more specific, I do not inject a SecretClient. Instead, I want to use the resolution of Keyvault variables right in the application.properties file using the special ${kv//} syntax. I inject a config property using the @ConfigProperty annotation in our code, just like usually done for config properties. As soon as the variable is used at runtime, dependency injection kicks in, starts resolving the variable, and initializes the Azure Keyvault client. This is where the error happens.

Error

The error in question is the following:

Caused by: java.lang.IllegalStateException: GlobalOpenTelemetry.set has already been called. GlobalOpenTelemetry.set must be called only once before any calls to GlobalOpenTelemetry.get. If you are using the OpenTelemetrySdk, use OpenTelemetrySdkBuilder.buildAndRegisterGlobal instead. Previous invocation set to cause of this exception.

Somehow, my application tries to initialize OpenTelemtry multiple times.

I attached the full log below, but from my understanding, this is the important part:

at com.azure.core.util.tracing.DefaultTracerProvider.createFallbackTracer(DefaultTracerProvider.java:36)
at com.azure.core.util.tracing.DefaultTracerProvider.<clinit>(DefaultTracerProvider.java:26)
at com.azure.core.util.tracing.TracerProvider.getDefaultProvider(TracerProvider.java:64)
at com.azure.security.keyvault.secrets.SecretClientBuilder.buildInnerClient(SecretClientBuilder.java:235)
at com.azure.security.keyvault.secrets.SecretClientBuilder.buildClient(SecretClientBuilder.java:156)

My guess is that somewhere in createFallbackTracer, initialization of OpenTelemetry is triggered, even though it was already initialized. Reading the logs, I can see that Quarkus' autoconfigure feature is used here. I don't know if the error is in the way Azure Services uses the autoconfigure feature, or Open Telemetrie's implementation of an autoconfigure provider, or even within Quarkus itself.

The workaround

I ended up reading the Quarkus Open Telemetry docs (https://quarkus.io/guides/opentelemetry) again and stumbled upon the config property quarkus.otel.sdk.disabled. Setting this to truedisabled usage of the Open Telemetry SDK at runtime, and thus it is not used when the Keyvault client does it's autoconfiguring, preventing the error.

I don't know what side effects this causes, but I didn't notice any so far.

Dependencies used

gradle.properties

quarkusPlatformArtifactId=quarkus-bom
quarkusPlatformGroupId=io.quarkus.platform
quarkusPlatformVersion=3.17.6
quarkusPluginId=io.quarkus
quarkusPluginVersion=3.17.6

build.gradle

implementation 'io.quarkiverse.azureservices:quarkus-azure-keyvault:1.1.0'
implementation enforcedPlatform("${quarkusPlatformGroupId}:${quarkusPlatformArtifactId}:${quarkusPlatformVersion}")
implementation 'io.quarkus:quarkus-rest-jackson'
implementation 'io.quarkus:quarkus-rest-client-jackson'
implementation 'io.quarkus:quarkus-arc'
implementation 'io.quarkus:quarkus-smallrye-health'
implementation 'io.quarkus:quarkus-smallrye-openapi'
implementation 'io.quarkus:quarkus-smallrye-jwt'
implementation 'io.quarkus:quarkus-smallrye-jwt-build'
implementation 'io.quarkus:quarkus-oidc-client'
implementation 'io.quarkus:quarkus-logging-json'
implementation 'io.quarkus:quarkus-hibernate-validator'
implementation 'io.quarkus:quarkus-opentelemetry'
implementation 'com.azure:azure-storage-blob:12.29.0'
implementation 'com.azure:azure-core-tracing-opentelemetry:1.0.0-beta.52'
implementation 'org.apache.commons:commons-lang3'

compileOnly 'io.quarkiverse.openapi.generator:quarkus-openapi-generator:2.6.0'

testImplementation 'io.quarkus:quarkus-junit5'
testImplementation 'io.quarkus:quarkus-junit5-mockito'
testImplementation 'io.rest-assured:rest-assured'

Full log

ERROR traceId=, parentId=, spanId=, sampled= [io.qu.ru.Application] (Quarkus Main Thread) Failed to start application: java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
        at io.quarkus.runtime.Application.start(Application.java:101)
        at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:121)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:124)
        at io.quarkus.runner.GeneratedMain.main(Unknown Source)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at io.quarkus.runner.bootstrap.StartupActionImpl$1.run(StartupActionImpl.java:116)
        at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: jakarta.enterprise.inject.CreationException: Error creating synthetic bean [Le6zQbzkojAYO_OiKIQWJf4lGa4]: io.opentelemetry.sdk.autoconfigure.spi.ConfigurationException: Unexpected configuration error
        at io.opentelemetry.api.OpenTelemetry_Le6zQbzkojAYO_OiKIQWJf4lGa4_Synthetic_Bean.doCreate(Unknown Source)
        at io.opentelemetry.api.OpenTelemetry_Le6zQbzkojAYO_OiKIQWJf4lGa4_Synthetic_Bean.create(Unknown Source)
        at io.opentelemetry.api.OpenTelemetry_Le6zQbzkojAYO_OiKIQWJf4lGa4_Synthetic_Bean.create(Unknown Source)
        at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:119)
        at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:38)
        at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:35)
        at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:32)
        at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
        at io.quarkus.arc.impl.ComputingCacheContextInstances.computeIfAbsent(ComputingCacheContextInstances.java:19)
        at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:35)
        at io.opentelemetry.api.OpenTelemetry_Le6zQbzkojAYO_OiKIQWJf4lGa4_Synthetic_Bean.get(Unknown Source)
        at io.opentelemetry.api.OpenTelemetry_Le6zQbzkojAYO_OiKIQWJf4lGa4_Synthetic_Bean.get(Unknown Source)
        at io.quarkus.arc.impl.InstanceImpl.getBeanInstance(InstanceImpl.java:325)
        at io.quarkus.arc.impl.InstanceImpl.getInternal(InstanceImpl.java:309)
        at io.quarkus.arc.impl.InstanceImpl.get(InstanceImpl.java:190)
        at io.quarkus.arc.runtime.BeanContainerImpl.beanInstance(BeanContainerImpl.java:26)
        at io.quarkus.opentelemetry.runtime.tracing.intrumentation.InstrumentationRecorder.setupVertxTracer(InstrumentationRecorder.java:59)
        at io.quarkus.deployment.steps.OpenTelemetryProcessor$setupVertx1012958309.deploy_0(Unknown Source)
        at io.quarkus.deployment.steps.OpenTelemetryProcessor$setupVertx1012958309.deploy(Unknown Source)
        ... 11 more
Caused by: io.opentelemetry.sdk.autoconfigure.spi.ConfigurationException: Unexpected configuration error
        at io.opentelemetry.sdk.autoconfigure.AutoConfiguredOpenTelemetrySdkBuilder.build(AutoConfiguredOpenTelemetrySdkBuilder.java:525)
        at io.quarkus.opentelemetry.runtime.OpenTelemetryRecorder$1.apply(OpenTelemetryRecorder.java:81)
        at io.quarkus.opentelemetry.runtime.OpenTelemetryRecorder$1.apply(OpenTelemetryRecorder.java:54)
        at io.opentelemetry.api.OpenTelemetry_Le6zQbzkojAYO_OiKIQWJf4lGa4_Synthetic_Bean.createSynthetic(Unknown Source)
        ... 30 more
Caused by: java.lang.IllegalStateException: GlobalOpenTelemetry.set has already been called. GlobalOpenTelemetry.set must be called only once before any calls to GlobalOpenTelemetry.get. If you are using the OpenTelemetrySdk, use OpenTelemetrySdkBuilder.buildAndRegisterGlobal instead. Previous invocation set to cause of this exception.
        at io.opentelemetry.api.GlobalOpenTelemetry.set(GlobalOpenTelemetry.java:107)
        at io.opentelemetry.sdk.autoconfigure.AutoConfiguredOpenTelemetrySdkBuilder.maybeSetAsGlobal(AutoConfiguredOpenTelemetrySdkBuilder.java:589)
        at io.opentelemetry.sdk.autoconfigure.AutoConfiguredOpenTelemetrySdkBuilder.build(AutoConfiguredOpenTelemetrySdkBuilder.java:506)
        ... 33 more
Caused by: java.lang.Throwable
        at io.opentelemetry.api.GlobalOpenTelemetry.set(GlobalOpenTelemetry.java:115)
        at io.opentelemetry.api.GlobalOpenTelemetry.get(GlobalOpenTelemetry.java:85)
        at io.opentelemetry.api.GlobalOpenTelemetry.getTracerProvider(GlobalOpenTelemetry.java:121)
        at com.azure.core.tracing.opentelemetry.OpenTelemetryTracer.getTracerProvider(OpenTelemetryTracer.java:522)
        at com.azure.core.tracing.opentelemetry.OpenTelemetryTracer.<init>(OpenTelemetryTracer.java:106)
        at com.azure.core.tracing.opentelemetry.OpenTelemetryTracer.<init>(OpenTelemetryTracer.java:96)
        at java.base/jdk.internal.reflect.DirectConstructorHandleAccessor.newInstance(DirectConstructorHandleAccessor.java:62)
        at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)
        at java.base/java.util.ServiceLoader$ProviderImpl.newInstance(ServiceLoader.java:789)
        at java.base/java.util.ServiceLoader$ProviderImpl.get(ServiceLoader.java:729)
        at java.base/java.util.ServiceLoader$3.next(ServiceLoader.java:1403)
        at com.azure.core.util.tracing.DefaultTracerProvider.createFallbackTracer(DefaultTracerProvider.java:36)
        at com.azure.core.util.tracing.DefaultTracerProvider.<clinit>(DefaultTracerProvider.java:26)
        at com.azure.core.util.tracing.TracerProvider.getDefaultProvider(TracerProvider.java:64)
        at com.azure.security.keyvault.secrets.SecretClientBuilder.buildInnerClient(SecretClientBuilder.java:235)
        at com.azure.security.keyvault.secrets.SecretClientBuilder.buildClient(SecretClientBuilder.java:156)
        at io.quarkiverse.azure.keyvault.secret.runtime.config.KeyVaultSecretConfigSource.createClient(KeyVaultSecretConfigSource.java:38)
        at io.quarkiverse.azure.keyvault.secret.runtime.config.KeyVaultSecretConfigSource.getValue(KeyVaultSecretConfigSource.java:73)
        at io.smallrye.config.SmallRyeConfigSources$ConfigValueConfigSourceWrapper.getConfigValue(SmallRyeConfigSources.java:94)
        at io.smallrye.config.SmallRyeConfigSources.getValue(SmallRyeConfigSources.java:37)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.SecretKeysConfigSourceInterceptor.getValue(SecretKeysConfigSourceInterceptor.java:26)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.RelocateConfigSourceInterceptor.getValue(RelocateConfigSourceInterceptor.java:25)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.RelocateConfigSourceInterceptor.getValue(RelocateConfigSourceInterceptor.java:25)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.RelocateConfigSourceInterceptor.getValue(RelocateConfigSourceInterceptor.java:25)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.ProfileConfigSourceInterceptor.getValue(ProfileConfigSourceInterceptor.java:50)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.LoggingConfigSourceInterceptor.getValue(LoggingConfigSourceInterceptor.java:26)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.RelocateConfigSourceInterceptor.getValue(RelocateConfigSourceInterceptor.java:25)
        at io.quarkus.smallrye.openapi.runtime.OpenApiConfigMapping.getValue(OpenApiConfigMapping.java:32)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.ExpressionConfigSourceInterceptor.getValue(ExpressionConfigSourceInterceptor.java:53)
        at io.smallrye.config.ExpressionConfigSourceInterceptor$1.accept(ExpressionConfigSourceInterceptor.java:84)
        at io.smallrye.config.ExpressionConfigSourceInterceptor$1.accept(ExpressionConfigSourceInterceptor.java:71)
        at io.smallrye.common.expression.ExpressionNode.emit(ExpressionNode.java:22)
        at io.smallrye.common.expression.Expression.evaluateException(Expression.java:56)
        at io.smallrye.common.expression.Expression.evaluate(Expression.java:70)
        at io.smallrye.config.ExpressionConfigSourceInterceptor.getValue(ExpressionConfigSourceInterceptor.java:71)
        at io.smallrye.config.ExpressionConfigSourceInterceptor.getValue(ExpressionConfigSourceInterceptor.java:45)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.quarkus.restclient.config.AbstractRestClientConfigBuilder$Fallbacks.getValue(AbstractRestClientConfigBuilder.java:192)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.FallbackConfigSourceInterceptor.getValue(FallbackConfigSourceInterceptor.java:24)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.quarkus.restclient.config.AbstractRestClientConfigBuilder$Fallbacks.getValue(AbstractRestClientConfigBuilder.java:192)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.FallbackConfigSourceInterceptor.getValue(FallbackConfigSourceInterceptor.java:24)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.quarkus.opentelemetry.runtime.config.MpTelemetryRelocateConfigSourceInterceptor$1.getValue(MpTelemetryRelocateConfigSourceInterceptor.java:26)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.quarkus.restclient.config.AbstractRestClientConfigBuilder$Relocates.getValue(AbstractRestClientConfigBuilder.java:334)
        at io.smallrye.config.SmallRyeConfig$SmallRyeConfigSourceInterceptorContext.proceed(SmallRyeConfig.java:1154)
        at io.smallrye.config.SmallRyeConfig.getConfigValue(SmallRyeConfig.java:489)
        at io.smallrye.config.inject.ConfigProducerUtil.lambda$getConfigValue$2(ConfigProducerUtil.java:155)
        at io.smallrye.config.SecretKeys.doUnlocked(SecretKeys.java:28)
        at io.smallrye.config.inject.ConfigProducerUtil.getConfigValue(ConfigProducerUtil.java:155)
        at io.smallrye.config.inject.ConfigProducerUtil.getValue(ConfigProducerUtil.java:91)
        at io.quarkus.arc.runtime.ConfigRecorder.validateConfigProperties(ConfigRecorder.java:60)
        at io.quarkus.deployment.steps.ConfigBuildStep$validateRuntimeConfigProperty1282080724.deploy_0(Unknown Source)
        at io.quarkus.deployment.steps.ConfigBuildStep$validateRuntimeConfigProperty1282080724.deploy(Unknown Source)
        ... 11 more
@Kitt3120
Copy link
Author

This seems to be a related issue in the underlying Azure SDK for Java: Azure/azure-sdk-for-java#42861

@majguo
Copy link
Contributor

majguo commented Jan 20, 2025 •
edited
Loading

FYI @Kitt3120 - similar to your workaround by setting quarkus.otel.sdk.disabled=true, I tried https://docs.quarkiverse.io/quarkus-azure-services/dev/quarkus-azure-key-vault.html with io.quarkus:quarkus-opentelemetry but without com.azure:azure-core-tracing-opentelemetry, no issue is observed either when running in dev mode mvn clean package quarkus:dev.

Added the following dependencies into pom.xml:

<dependency>
    <groupId>io.quarkus</groupId>
    <artifactId>quarkus-opentelemetry</artifactId>
</dependency>
<!-- for local testing in dev mode -->
<dependency>
    <groupId>io.opentelemetry</groupId>
    <artifactId>opentelemetry-exporter-logging</artifactId>
</dependency>

Added the following configurations into application.properties:

quarkus.otel.logs.enabled=true
%dev.quarkus.otel.logs.exporter=logging
%dev.quarkus.otel.traces.exporter=logging

@Kitt3120
Copy link
Author

Kitt3120 commented Jan 20, 2025 •
edited
Loading

I'll try that as soon as I can, thank you :)

Edit: You're right, it works without the com.azure:azure-core-tracing-opentelemetry dependency. I lose out on a bit of OpenTelemetry logging regarding the Azure Storage Container I use, but that's better than doing some weird workaround that could potentially mess up other things.

Thank you! :)

@majguo majguo mentioned this issue Jan 21, 2025
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@majguo @Kitt3120