Skip to content

Log4j Exporter - Initialization order conflic on OpenTelemetryContextDataProvider #16506

@krinosx

Description

@krinosx

Describe the bug

Context: Application using Log4j and library instrumentation modules. (not the agent)

While initializing an application, if a static Logger is declared before the actual OpenTelemetry SDK registration - GlobalOpenTelemetry.set() - the GlobalOpenTelemetry will be initialized with a NoOp instance by the OpenTelemetryContextDataProvider. That way when trying to register the actual OpenTelemetry SDK configured by the user, an exception will be thrown.

As far as I could investigate, the OpenTelemetryContextDataProvider initializes an static variable that calls GlobalOpenTelemetry.get() what makes a NoOp sdk to be set for the GlobalOpenTelemetry.

Here is the code from io.opentelemetry.instrumentation.log4j.contextdata.v2_17.OpenTelemetryContextDataProvider.java.

private static final boolean BAGGAGE_ENABLED =
      DeclarativeConfigUtil.getInstrumentationConfig(
              GlobalOpenTelemetry.get(), "log4j_context_data")
          .getBoolean(
              "add_baggage",
              ConfigPropertiesUtil.getBoolean(
                  "otel.instrumentation.log4j-context-data.add-baggage", false));

I believe we should consider either using 'GlobalOpenTelemetry.getOrNoOp()' to avoid setting the global sdk instance as a NoOp - but it will still give a false 'BAGGAGE_ENABLED' value;
or, we should implement the 'BAGGAGE_ENABLED' attribute as a lazy loaded one in the method supplyContextData() from the same class.

Steps to reproduce

1 - Run the given application (check the source code)
2 - Uncomment the Logger before the main() method and run again

The minimal source code used to reproduce and the gradle dependencies can be seen below.

build.gradle.kts

plugins {
    id("java")
    id("application")
}
description = "OpenTelemetry Log Appender Example - Initialization Bug"
group = "com.krinosx.logging"
version = "1.0-SNAPSHOT"

repositories {
    mavenCentral()
}

dependencies {
    implementation(platform("io.opentelemetry.instrumentation:opentelemetry-instrumentation-bom-alpha:2.25.0-alpha"))

    // Log4j
    implementation(platform("org.apache.logging.log4j:log4j-bom:2.25.3"))
    implementation("org.apache.logging.log4j:log4j-api")
    implementation("org.apache.logging.log4j:log4j-core")

    // OpenTelemetry core
    implementation("io.opentelemetry:opentelemetry-sdk")
    implementation("io.opentelemetry:opentelemetry-exporter-otlp")
    implementation("io.opentelemetry.semconv:opentelemetry-semconv")

    // OpenTelemetry log4j / logback appenders
    implementation("io.opentelemetry.instrumentation:opentelemetry-log4j-appender-2.17")
    implementation("io.opentelemetry:opentelemetry-exporter-logging-otlp:1.59.0")
}

java {
    toolchain {
        languageVersion.set(JavaLanguageVersion.of(21))
    }
}

application {
    mainClass = "com.krinosx.logging.Main"
}

Main.java

package com.krinosx.logging;

import io.opentelemetry.api.GlobalOpenTelemetry;
import io.opentelemetry.api.OpenTelemetry;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.context.Scope;
import io.opentelemetry.sdk.OpenTelemetrySdk;
import io.opentelemetry.sdk.trace.SdkTracerProvider;
import io.opentelemetry.sdk.trace.samplers.Sampler;
import org.apache.logging.log4j.LogManager;

public class Main {

// uncomment this logger to trigger the exception
//    static final org.apache.logging.log4j.Logger log4jLogger =
//            LogManager.getLogger("log4j-logger");
    public static void main(String[] args) {

        OpenTelemetry openTelemetry = initializeOpenTelemetry();
        // Install OpenTelemetry in log4j appender
        io.opentelemetry.instrumentation.log4j.appender.v2_17.OpenTelemetryAppender.install(openTelemetry);


        Span span = GlobalOpenTelemetry.getTracer("my-tracer").spanBuilder("my-span").startSpan();
        try (Scope unused = span.makeCurrent()) {
            System.out.println("Current -> TraceId: " + span.getSpanContext().getTraceId() + " spanId: " + span.getSpanContext().getSpanId());
        } finally {
            span.end();
        }
    }


    private static OpenTelemetry initializeOpenTelemetry() {

        SdkTracerProvider tracerProvider = SdkTracerProvider.builder()
                .setSampler(Sampler.alwaysOn()).build();

        OpenTelemetrySdk sdk =
                OpenTelemetrySdk.builder()
                        .setTracerProvider(tracerProvider)
                        .buildAndRegisterGlobal();

        // Add hook to close SDK, which flushes logs
        Runtime.getRuntime().addShutdownHook(new Thread(sdk::close));
        return sdk;
    }
}

Expected behavior

I would expect that dynamic loaded classes, loaded by the log4j logging framework would not set the default GlobalTelemetry SDK.

Actual behavior

The dynamic loaded class, loaded by the log4j logging framework is setting the GlobalTelemetry SDK as NoOp, preventing initialization by the developer.

Javaagent or library instrumentation version

2.25.0-alpha

Environment

JDK:
openjdk 21.0.2 2024-01-16 LTS
OpenJDK Runtime Environment Zulu21.32+17-CA (build 21.0.2+13-LTS)
OpenJDK 64-Bit Server VM Zulu21.32+17-CA (build 21.0.2+13-LTS, mixed mode, sharing)

OS:
Windows 11

Additional context

My goal was to use the OpenTelemetry Appender for Log4j, and I realised the traceIds and spanIds always being null while checking the example app provided here - https://github.com/open-telemetry/opentelemetry-java-examples/blob/main/log-appender/src/main/java/io/opentelemetry/example/logappender/Application.java.

Once this bug is fixed it will also be necessary to make amends in the example application as it's not registering the OpenTelmetry SDK properly in the GlobalTelemetry.

I can work on both tasks if it would be acceptable.

Tip

React with 👍 to help prioritize this issue. Please use comments to provide useful context, avoiding +1 or me too, to help us triage it. Learn more here.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingneeds triageNew issue that requires triage

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions