open-telemetry
/
opentelemetry-java-instrumentation
mirror of https://github.com/open-telemetry/opentelemetry-java-instrumentation.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

ComponentInstallers should run after LogManager if a custom one is detected (#2592) 

* ComponentInstallers should run after LogManager if a custom one is detected

* Limit to Java 8
This commit is contained in:
Mateusz Rzeszutek 2021-03-18 13:10:22 +01:00 committed by GitHub
parent 811259376e
commit 9fff4a3b47
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
1 changed files with 62 additions and 95 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

157
javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/AgentInstaller.java
View File

@ -5,6 +5,8 @@
package io.opentelemetry.javaagent.tooling; package io.opentelemetry.javaagent.tooling;
import static io.opentelemetry.javaagent.bootstrap.AgentInitializer.isJavaBefore9;
import static io.opentelemetry.javaagent.tooling.Utils.getResourceName;
import static io.opentelemetry.javaagent.tooling.bytebuddy.matcher.NameMatchers.namedOneOf; import static io.opentelemetry.javaagent.tooling.bytebuddy.matcher.NameMatchers.namedOneOf;
import static io.opentelemetry.javaagent.tooling.matcher.GlobalIgnoresMatcher.globalIgnoresMatcher; import static io.opentelemetry.javaagent.tooling.matcher.GlobalIgnoresMatcher.globalIgnoresMatcher;
import static net.bytebuddy.matcher.ElementMatchers.any; import static net.bytebuddy.matcher.ElementMatchers.any;
@ -13,7 +15,6 @@ import static net.bytebuddy.matcher.ElementMatchers.none;
import io.opentelemetry.instrumentation.api.config.Config; import io.opentelemetry.instrumentation.api.config.Config;
import io.opentelemetry.javaagent.bootstrap.AgentClassLoader; import io.opentelemetry.javaagent.bootstrap.AgentClassLoader;
import io.opentelemetry.javaagent.bootstrap.AgentInitializer;
import io.opentelemetry.javaagent.instrumentation.api.SafeServiceLoader; import io.opentelemetry.javaagent.instrumentation.api.SafeServiceLoader;
import io.opentelemetry.javaagent.instrumentation.api.internal.BootstrapPackagePrefixesHolder; import io.opentelemetry.javaagent.instrumentation.api.internal.BootstrapPackagePrefixesHolder;
import io.opentelemetry.javaagent.spi.BootstrapPackagesProvider; import io.opentelemetry.javaagent.spi.BootstrapPackagesProvider;
@ -53,6 +54,13 @@ public class AgentInstaller {
private static final String JAVAAGENT_ENABLED_CONFIG = "otel.javaagent.enabled"; private static final String JAVAAGENT_ENABLED_CONFIG = "otel.javaagent.enabled";
private static final String EXCLUDED_CLASSES_CONFIG = "otel.javaagent.exclude-classes"; private static final String EXCLUDED_CLASSES_CONFIG = "otel.javaagent.exclude-classes";
// This property may be set to force synchronous ComponentInstaller#afterByteBuddyAgent()
// execution: the condition for delaying the ComponentInstaller initialization is pretty broad
// and in case it covers too much javaagent users can file a bug, force sync execution by setting
// this property to true and continue using the javaagent
private static final String FORCE_SYNCHRONOUS_COMPONENT_INSTALLER_CONFIG =
"otel.javaagent.experimental.force-synchronous-component-installers";
// We set this system property when running the agent with unit tests to allow verifying that we // We set this system property when running the agent with unit tests to allow verifying that we
// don't ignore libraries that we actually attempt to instrument. It means either the list is // don't ignore libraries that we actually attempt to instrument. It means either the list is
// wrong or a type matcher is. // wrong or a type matcher is.
@ -171,28 +179,30 @@ public class AgentInstaller {
private static void installComponentsAfterByteBuddy( private static void installComponentsAfterByteBuddy(
Iterable<ComponentInstaller> componentInstallers, Config config) { Iterable<ComponentInstaller> componentInstallers, Config config) {
/* // java.util.logging.LogManager maintains a final static LogManager, which is created during
* java.util.logging.LogManager maintains a final static LogManager, which is created during class initialization. // class initialization. Some ComponentInstaller implementations may use JRE bootstrap classes
* // which touch this class (e.g. JFR classes or some MBeans).
* JMXFetch uses jre bootstrap classes which touch this class. This means applications which require a custom log // It is worth noting that starting from Java 9 (JEP 264) Java platform classes no longer use
* manager may not have a chance to set the global log manager if jmxfetch runs first. JMXFetch will incorrectly // JUL directly, but instead they use a new System.Logger interface, so the LogManager issue
* set the global log manager in cases where the app sets the log manager system property or when the log manager // applies mainly to Java 8.
* class is not on the system classpath. // This means applications which require a custom LogManager may not have a chance to set the
* // global LogManager if one of those ComponentInstallers runs first: it will incorrectly
* Our solution is to delay the initialization of jmxfetch when we detect a custom log manager being used. // set the global LogManager to the default JVM one in cases where the instrumented application
* // sets the LogManager system property or when the custom LogManager class is not on the system
* Once we see the LogManager class loading, it's safe to start jmxfetch because the application is already setting // classpath.
* the global log manager and jmxfetch won't be able to touch it due to classloader locking. // Our solution is to delay the initialization of ComponentInstallers when we detect a custom
*/ // log manager being used.
// Once we see the LogManager class loading, it's safe to run
/* // ComponentInstaller#afterByteBuddyAgent() because the application is already setting the
* Similar thing happens with AgentTracer on (at least) zulu-8 because it uses OkHttp which indirectly loads JFR // global LogManager and ComponentInstaller won't be able to touch it due to classloader
* events which in turn loads LogManager. This is not a problem on newer JDKs because there JFR uses different // locking.
* logging facility. boolean shouldForceSynchronousComponentInstallerCalls =
*/ Config.get().getBooleanProperty(FORCE_SYNCHRONOUS_COMPONENT_INSTALLER_CONFIG, false);
boolean appUsingCustomLogManager = isAppUsingCustomLogManager(); if (!shouldForceSynchronousComponentInstallerCalls
if (isJavaBefore9WithJfr() && appUsingCustomLogManager) { && isJavaBefore9()
log.debug("Custom logger detected. Delaying Agent Tracer initialization."); && isAppUsingCustomLogManager()) {
log.debug(
"Custom JUL LogManager detected: delaying ComponentInstaller#afterByteBuddyAgent() calls");
registerClassLoadCallback( registerClassLoadCallback(
"java.util.logging.LogManager", "java.util.logging.LogManager",
new InstallComponentAfterByteBuddyCallback(config, componentInstallers)); new InstallComponentAfterByteBuddyCallback(config, componentInstallers));
@ -390,32 +400,16 @@ public class AgentInstaller {
} }
} }
protected static class InstallComponentAfterByteBuddyCallback extends ClassLoadCallBack { private static class InstallComponentAfterByteBuddyCallback implements Runnable {
private final Iterable<ComponentInstaller> componentInstallers; private final Iterable<ComponentInstaller> componentInstallers;
private final Config config; private final Config config;
protected InstallComponentAfterByteBuddyCallback( private InstallComponentAfterByteBuddyCallback(
Config config, Iterable<ComponentInstaller> componentInstallers) { Config config, Iterable<ComponentInstaller> componentInstallers) {
this.componentInstallers = componentInstallers; this.componentInstallers = componentInstallers;
this.config = config; this.config = config;
} }
@Override
public String getName() {
return componentInstallers.getClass().getName();
}
@Override
public void execute() {
for (ComponentInstaller componentInstaller : componentInstallers) {
componentInstaller.afterByteBuddyAgent(config);
}
}
}
protected abstract static class ClassLoadCallBack implements Runnable {
@Override @Override
public void run() { public void run() {
/* /*
@ -423,26 +417,21 @@ public class AgentInstaller {
* to load classes being transformed. To avoid this we start a thread here that calls the callback. * to load classes being transformed. To avoid this we start a thread here that calls the callback.
* This seems to resolve this problem. * This seems to resolve this problem.
*/ */
Thread thread = Thread thread = new Thread(this::runComponentInstallers);
new Thread( thread.setName("agent-component-installers");
new Runnable() {
@Override
public void run() {
try {
execute();
} catch (Exception e) {
log.error("Failed to run class loader callback {}", getName(), e);
}
}
});
thread.setName("agent-startup-" + getName());
thread.setDaemon(true); thread.setDaemon(true);
thread.start(); thread.start();
} }
public abstract String getName(); private void runComponentInstallers() {
for (ComponentInstaller componentInstaller : componentInstallers) {
public abstract void execute(); try {
componentInstaller.afterByteBuddyAgent(config);
} catch (Exception e) {
log.error("Failed to execute {}", componentInstaller.getClass().getName(), e);
}
}
}
} }
private static class ClassLoadListener implements AgentBuilder.Listener { private static class ClassLoadListener implements AgentBuilder.Listener {
@ -512,63 +501,41 @@ public class AgentInstaller {
} }
} }
/** /** Detect if the instrumented application is using a custom JUL LogManager. */
* Search for java or agent-tracer sysprops which indicate that a custom log manager will be used.
* Also search for any app classes known to set a custom log manager.
*
* @return true if we detect a custom log manager being used.
*/
private static boolean isAppUsingCustomLogManager() { private static boolean isAppUsingCustomLogManager() {
String tracerCustomLogManSysprop = "otel.app.customlogmanager";
String customLogManagerProp = System.getProperty(tracerCustomLogManSysprop);
String customLogManagerEnv =
System.getenv(tracerCustomLogManSysprop.replace('.', '_').toUpperCase());
if (customLogManagerProp != null || customLogManagerEnv != null) {
log.debug("Prop - customlogmanager: " + customLogManagerProp);
log.debug("Env - customlogmanager: " + customLogManagerEnv);
// Allow setting to skip these automatic checks:
return Boolean.parseBoolean(customLogManagerProp)
|| Boolean.parseBoolean(customLogManagerEnv);
}
String jbossHome = System.getenv("JBOSS_HOME"); String jbossHome = System.getenv("JBOSS_HOME");
if (jbossHome != null) { if (jbossHome != null) {
log.debug("Env - jboss: " + jbossHome); log.debug("Found JBoss: {}; assuming app is using custom LogManager", jbossHome);
// JBoss/Wildfly is known to set a custom log manager after startup. // JBoss/Wildfly is known to set a custom log manager after startup.
// Originally we were checking for the presence of a jboss class, // Originally we were checking for the presence of a jboss class,
// but it seems some non-jboss applications have jboss classes on the classpath. // but it seems some non-jboss applications have jboss classes on the classpath.
// This would cause jmxfetch initialization to be delayed indefinitely. // This would cause ComponentInstaller initialization to be delayed indefinitely.
// Checking for an environment variable required by jboss instead. // Checking for an environment variable required by jboss instead.
return true; return true;
} }
String logManagerProp = System.getProperty("java.util.logging.manager"); String customLogManager = System.getProperty("java.util.logging.manager");
if (logManagerProp != null) { if (customLogManager != null) {
log.debug(
"Detected custom LogManager configuration: java.util.logging.manager={}",
customLogManager);
boolean onSysClasspath = boolean onSysClasspath =
ClassLoader.getSystemResource(logManagerProp.replaceAll("\\.", "/") + ".class") != null; ClassLoader.getSystemResource(getResourceName(customLogManager)) != null;
log.debug("Prop - logging.manager: " + logManagerProp); log.debug(
log.debug("logging.manager on system classpath: " + onSysClasspath); "Class {} is on system classpath: {}delaying ComponentInstaller#afterByteBuddyAgent()",
customLogManager,
onSysClasspath ? "not " : "");
// Some applications set java.util.logging.manager but never actually initialize the logger. // Some applications set java.util.logging.manager but never actually initialize the logger.
// Check to see if the configured manager is on the system classpath. // Check to see if the configured manager is on the system classpath.
// If so, it should be safe to initialize jmxfetch which will setup the log manager. // If so, it should be safe to initialize ComponentInstaller which will setup the log manager:
// LogManager tries to load the implementation first using system CL, then falls back to
// current context CL
return !onSysClasspath; return !onSysClasspath;
} }
return false; return false;
} }
private static boolean isJavaBefore9WithJfr() {
if (!AgentInitializer.isJavaBefore9()) {
return false;
}
// FIXME: this is quite a hack because there maybe jfr classes on classpath somehow that have
// nothing to do with JDK but this should be safe because only thing this does is to delay
// tracer install
String jfrClassResourceName = "jdk.jfr.Recording".replace('.', '/') + ".class";
return Thread.currentThread().getContextClassLoader().getResource(jfrClassResourceName) != null;
}
private static void logVersionInfo() { private static void logVersionInfo() {
VersionLogger.logAllVersions(); VersionLogger.logAllVersions();
log.debug( log.debug(