Log4J Context Data Instrumentation Classloading Race Condition

[jskrt]

Describe the bug

The Log4J context data instrumentation seems to have been built with the assumption that Log4J initialization would take place after the OTel agent is initialized. If, for example, there is another agent whose premain is called before the OTel agent's and that premain uses Log4J, it will cause Log4J to initialize, load all available ContextDataProviders. As a result, the classloading of the OTel ContextDataProvider that the OTel agent might do is wasted.

Steps to reproduce

I cannot provide the exact steps due to the environment I'm dealing with being internal to my company. The general steps to reproduce would be to have a different agent run before the OTel agent and have that agent invoke Log4J. If you dump the ThreadContext during processing of requests, you will not see any trace context in it. I've tried this with an always_on sampler locally. In this case, if you include the Log4J instrumentation as a direct dependency of the application, everything will work again - likely because the Log4J service loader picks up the OTel CDP regardless of when the OTel agent is initialized.

Expected behavior

The ThreadContext should have trace context within it regardless of the environment in which the OTel agent was used.

Actual behavior

The ThreadContext contains no trace context.

Javaagent or library instrumentation version

Log4j-context-data-2.17

Environment

JDK: 8+
OS: Amazon Linux 2

Additional context

No response

[trask]

hi @jskrt, what if you list the otel -javaagent jvm option before the other -javaagent so that the otel java agent loads first?

[jskrt]

Unfortunately, that isn't possible on my end due to the integration steps for the other agent (it also performs compile-time instrumentation). Apologies that I can't share more details about that agent due to it being internal information.

[laurit]

The Log4J context data instrumentation seems to have been built with the assumption that Log4J initialization would take place after the OTel agent is initialized.

To me this feels like a reasonable assumption.

If, for example, there is another agent whose premain is called before the OTel agent's and that premain uses Log4J, it will cause Log4J to initialize, load all available ContextDataProviders.

This isn't common. A reasonable agent can't include log4j without shading. If log4j in the agent is shaded then the instrumenation won't apply to it. If an agent contains unshaded log4j then it is unlikely that it is a mainstream agent. There isn't too much incentive to introduce additional complexity to deal with this.

In this case, if you include the Log4J instrumentation as a direct dependency of the application, everything will work again

Seems like you already have found a workaround. Also based on your description it seems like your application is using the log4j that is bundled in the agent. If you shaded the log4j in the agent or used child first class loading in your application then it would probably work without any changes.

[github-actions]

This has been automatically marked as stale because it has been marked as needing author feedback and has not had any activity for 7 days. It will be closed automatically if there is no response from the author within 7 additional days from this comment.