diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/bci/ElasticApmAgent.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/bci/ElasticApmAgent.java index 5374ca2eca..dd1ed83c47 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/bci/ElasticApmAgent.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/bci/ElasticApmAgent.java @@ -102,8 +102,9 @@ public class ElasticApmAgent { - // Don't init logger as a static field, logging needs to be initialized first see also issue #593 - // private static final Logger doNotUseThisLogger = LoggerFactory.getLogger(ElasticApmAgent.class); + // Don't eagerly create logger. Logging needs to be initialized first based on configuration. See also issue #593 + @Nullable + private static Logger logger; private static final ConcurrentMap matcherTimers = new ConcurrentHashMap<>(); @Nullable @@ -161,6 +162,7 @@ private static synchronized void initInstrumentation(final ElasticApmTracer trac if (!tracer.getConfig(CoreConfiguration.class).isEnabled()) { return; } + GlobalTracer.set(tracer); Runtime.getRuntime().addShutdownHook(new Thread(ThreadUtils.addElasticApmThreadPrefix("init-instrumentation-shutdown-hook")) { @Override public void run() { @@ -169,12 +171,11 @@ public void run() { } }); matcherTimers.clear(); - final Logger logger = LoggerFactory.getLogger(ElasticApmAgent.class); + Logger logger = getLogger(); if (ElasticApmAgent.instrumentation != null) { logger.warn("Instrumentation has already been initialized"); return; } - GlobalTracer.set(tracer); // POOL_ONLY because we don't want to cause eager linking on startup as the class path may not be complete yet AgentBuilder agentBuilder = initAgentBuilder(tracer, instrumentation, instrumentations, logger, AgentBuilder.DescriptionStrategy.Default.POOL_ONLY, premain); resettableClassFileTransformer = agentBuilder.installOn(ElasticApmAgent.instrumentation); @@ -199,7 +200,7 @@ public static synchronized Future reInitInstrumentation() { return executor.submit(new Runnable() { @Override public void run() { - doReInitInstrumentation(loadInstrumentations(tracer), tracer); + doReInitInstrumentation(loadInstrumentations(tracer)); } }); } finally { @@ -207,10 +208,10 @@ public void run() { } } - static synchronized void doReInitInstrumentation(Iterable instrumentations, ElasticApmTracer tracer) { - final Logger logger = LoggerFactory.getLogger(ElasticApmAgent.class); + static synchronized void doReInitInstrumentation(Iterable instrumentations) { + Logger logger = getLogger(); logger.info("Re initializing instrumentation"); - AgentBuilder agentBuilder = initAgentBuilder(tracer, instrumentation, instrumentations, logger, AgentBuilder.DescriptionStrategy.Default.POOL_ONLY, false); + AgentBuilder agentBuilder = initAgentBuilder(GlobalTracer.requireTracerImpl(), instrumentation, instrumentations, logger, AgentBuilder.DescriptionStrategy.Default.POOL_ONLY, false); resettableClassFileTransformer = agentBuilder.patchOn(instrumentation, resettableClassFileTransformer); } @@ -259,7 +260,7 @@ private static boolean isInstrumentationEnabled(ElasticApmInstrumentation advice private static AgentBuilder applyAdvice(final ElasticApmTracer tracer, final AgentBuilder agentBuilder, final ElasticApmInstrumentation instrumentation, final ElementMatcher typeMatcher) { - final Logger logger = LoggerFactory.getLogger(ElasticApmAgent.class); + final Logger logger = getLogger(); logger.debug("Applying instrumentation {}", instrumentation.getClass().getName()); final boolean classLoadingMatchingPreFilter = tracer.getConfig(CoreConfiguration.class).isClassLoadingMatchingPreFilter(); final boolean typeMatchingWithNamePreFilter = tracer.getConfig(CoreConfiguration.class).isTypeMatchingWithNamePreFilter(); @@ -315,6 +316,19 @@ public DynamicType.Builder transform(DynamicType.Builder builder, TypeDesc }); } + private static Logger getLogger() { + if (logger == null) { + // lazily init logger to allow the tracer builder to init the logging config first + GlobalTracer.requireTracerImpl(); + logger = LoggerFactory.getLogger(ElasticApmAgent.class); + } + // re-using an existing logger avoids running into a JVM bug that leads to a segfault + // this happens when StackWalker runs concurrently to class redefinitions + // see https://bugs.openjdk.java.net/browse/JDK-8210457 + // this crash could only be reproduced in tests so far + return logger; + } + private static AgentBuilder.Transformer.ForAdvice getTransformer(final ElasticApmInstrumentation instrumentation, final Logger logger, final ElementMatcher methodMatcher) { Advice.WithCustomMapping withCustomMapping = Advice .withCustomMapping() diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/bci/InstrumentationTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/bci/InstrumentationTest.java index 3b01a3d8d5..46934abf53 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/bci/InstrumentationTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/bci/InstrumentationTest.java @@ -30,7 +30,6 @@ import co.elastic.apm.agent.configuration.CoreConfiguration; import co.elastic.apm.agent.configuration.SpyConfiguration; import co.elastic.apm.agent.impl.ElasticApmTracer; -import co.elastic.apm.agent.impl.ElasticApmTracerBuilder; import co.elastic.apm.agent.impl.transaction.AbstractSpan; import co.elastic.apm.agent.impl.transaction.Span; import co.elastic.apm.agent.matcher.WildcardMatcher; @@ -49,6 +48,7 @@ import org.apache.commons.pool2.impl.CallStackUtils; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Disabled; import org.junit.jupiter.api.Test; import org.slf4j.event.SubstituteLoggingEvent; import org.stagemonitor.configuration.ConfigurationRegistry; @@ -92,20 +92,20 @@ void reset() { @Test void testIntercept() { - init(configurationRegistry, List.of(new TestInstrumentation())); + init(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEqualTo("intercepted"); } @Test void testFieldAccess() { - init(configurationRegistry, List.of(new FieldAccessInstrumentation())); + init(List.of(new FieldAccessInstrumentation())); assignToField("@AssignToField"); assertThat(privateString).isEqualTo("@AssignToField"); } @Test void testFieldAccessArray() { - init(configurationRegistry, List.of(new FieldAccessArrayInstrumentation())); + init(List.of(new FieldAccessArrayInstrumentation())); assignToField("@AssignToField"); assertThat(privateString).isEqualTo("@AssignToField"); } @@ -115,7 +115,7 @@ public void assignToField(String s) { @Test void testAssignToArgument() { - init(configurationRegistry, List.of(new AssignToArgumentInstrumentation())); + init(List.of(new AssignToArgumentInstrumentation())); assertThat(assignToArgument("foo")).isEqualTo("foo@AssignToArgument"); } @@ -125,7 +125,7 @@ public String assignToArgument(String s) { @Test void testAssignToArgumentArray() { - init(configurationRegistry, List.of(new AssignToArgumentsInstrumentation())); + init(List.of(new AssignToArgumentsInstrumentation())); assertThat(assignToArguments("foo", "bar")).isEqualTo("barfoo"); } @@ -135,7 +135,7 @@ public String assignToArguments(String foo, String bar) { @Test void testAssignToReturnArray() { - init(configurationRegistry, List.of(new AssignToReturnArrayInstrumentation())); + init(List.of(new AssignToReturnArrayInstrumentation())); assertThat(assignToReturn("foo", "bar")).isEqualTo("foobar"); } @@ -147,13 +147,13 @@ public String assignToReturn(String foo, String bar) { @Test void testDisabled() { doReturn(Collections.singletonList("test")).when(coreConfig).getDisabledInstrumentations(); - init(configurationRegistry, List.of(new TestInstrumentation())); + init(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @Test void testEnsureInstrumented() { - init(configurationRegistry, List.of()); + init(List.of()); assertThat(interceptMe()).isEmpty(); ElasticApmAgent.ensureInstrumented(getClass(), List.of(TestInstrumentation.class)); assertThat(interceptMe()).isEqualTo("intercepted"); @@ -162,21 +162,21 @@ void testEnsureInstrumented() { @Test void testReInitEnableOneInstrumentation() { doReturn(Collections.singletonList("test")).when(coreConfig).getDisabledInstrumentations(); - init(configurationRegistry, List.of(new TestInstrumentation())); + init(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); doReturn(List.of()).when(coreConfig).getDisabledInstrumentations(); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEqualTo("intercepted"); } @Test void testDefaultDisabledInstrumentation() { - init(configurationRegistry, List.of(new TestInstrumentation())); + init(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEqualTo("intercepted"); doReturn(Collections.singletonList("experimental")).when(coreConfig).getDisabledInstrumentations(); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @@ -184,8 +184,8 @@ void testDefaultDisabledInstrumentation() { void testExcludedClassesFromInstrumentation() { doReturn(List.of(WildcardMatcher.valueOf("co.elastic.apm.agent.bci.InstrumentationTest"))) .when(coreConfig).getClassesExcludedFromInstrumentation(); - init(configurationRegistry, List.of(new TestInstrumentation())); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + init(List.of(new TestInstrumentation())); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @@ -193,8 +193,8 @@ void testExcludedClassesFromInstrumentation() { void testExcludedPackageFromInstrumentation() { doReturn(List.of(WildcardMatcher.valueOf("co.elastic.apm.agent.bci.*"))) .when(coreConfig).getClassesExcludedFromInstrumentation(); - init(configurationRegistry, List.of(new TestInstrumentation())); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + init(List.of(new TestInstrumentation())); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @@ -202,8 +202,8 @@ void testExcludedPackageFromInstrumentation() { void testExcludedDefaultClassesFromInstrumentation() { doReturn(List.of(WildcardMatcher.valueOf("co.elastic.apm.agent.bci.InstrumentationTest"))) .when(coreConfig).getDefaultClassesExcludedFromInstrumentation(); - init(configurationRegistry, List.of(new TestInstrumentation())); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + init(List.of(new TestInstrumentation())); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @@ -211,28 +211,28 @@ void testExcludedDefaultClassesFromInstrumentation() { void testExcludedDefaultPackageFromInstrumentation() { doReturn(List.of(WildcardMatcher.valueOf("co.elastic.apm.agent.bci.*"))) .when(coreConfig).getDefaultClassesExcludedFromInstrumentation(); - init(configurationRegistry, List.of(new TestInstrumentation())); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + init(List.of(new TestInstrumentation())); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @Test void testLegacyDefaultDisabledInstrumentation() { - init(configurationRegistry, List.of(new TestInstrumentation())); + init(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEqualTo("intercepted"); doReturn(Collections.singletonList("incubating")).when(coreConfig).getDisabledInstrumentations(); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @Test void testReInitDisableAllInstrumentations() { - init(configurationRegistry, List.of(new TestInstrumentation())); + init(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEqualTo("intercepted"); doReturn(false).when(coreConfig).isInstrument(); - ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation()), tracer); + ElasticApmAgent.doReInitInstrumentation(List.of(new TestInstrumentation())); assertThat(interceptMe()).isEmpty(); } @@ -455,10 +455,7 @@ public ClassLoader getPluginClassLoader() { return null; } - private void init(ConfigurationRegistry config, List instrumentations) { - ElasticApmTracer tracer = new ElasticApmTracerBuilder() - .configurationRegistry(config) - .build(); + private void init(List instrumentations) { ElasticApmAgent.initInstrumentation(tracer, ByteBuddyAgent.install(), instrumentations); }