diff --git a/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/AgentInstaller.java b/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/AgentInstaller.java index c57bb097f665..5f9983150c7d 100644 --- a/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/AgentInstaller.java +++ b/javaagent-tooling/src/main/java/io/opentelemetry/javaagent/tooling/AgentInstaller.java @@ -5,6 +5,8 @@ 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.matcher.GlobalIgnoresMatcher.globalIgnoresMatcher; import static net.bytebuddy.matcher.ElementMatchers.any; @@ -13,7 +15,6 @@ import io.opentelemetry.instrumentation.api.config.Config; 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.internal.BootstrapPackagePrefixesHolder; 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 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 // don't ignore libraries that we actually attempt to instrument. It means either the list is // wrong or a type matcher is. @@ -171,28 +179,30 @@ private static void installComponentsBeforeByteBuddy( private static void installComponentsAfterByteBuddy( Iterable componentInstallers, Config config) { - /* - * java.util.logging.LogManager maintains a final static LogManager, which is created during class initialization. - * - * JMXFetch uses jre bootstrap classes which touch this class. This means applications which require a custom log - * manager may not have a chance to set the global log manager if jmxfetch runs first. JMXFetch will incorrectly - * set the global log manager in cases where the app sets the log manager system property or when the log manager - * class is not on the system classpath. - * - * Our solution is to delay the initialization of jmxfetch when we detect a custom log manager being used. - * - * Once we see the LogManager class loading, it's safe to start jmxfetch because the application is already setting - * the global log manager and jmxfetch won't be able to touch it due to classloader locking. - */ - - /* - * Similar thing happens with AgentTracer on (at least) zulu-8 because it uses OkHttp which indirectly loads JFR - * events which in turn loads LogManager. This is not a problem on newer JDKs because there JFR uses different - * logging facility. - */ - boolean appUsingCustomLogManager = isAppUsingCustomLogManager(); - if (isJavaBefore9WithJfr() && appUsingCustomLogManager) { - log.debug("Custom logger detected. Delaying Agent Tracer initialization."); + // java.util.logging.LogManager maintains a final static LogManager, which is created during + // class initialization. Some ComponentInstaller implementations may use JRE bootstrap classes + // which touch this class (e.g. JFR classes or some MBeans). + // It is worth noting that starting from Java 9 (JEP 264) Java platform classes no longer use + // JUL directly, but instead they use a new System.Logger interface, so the LogManager issue + // applies mainly to Java 8. + // 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 + // 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 + // classpath. + // 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 + // global LogManager and ComponentInstaller won't be able to touch it due to classloader + // locking. + boolean shouldForceSynchronousComponentInstallerCalls = + Config.get().getBooleanProperty(FORCE_SYNCHRONOUS_COMPONENT_INSTALLER_CONFIG, false); + if (!shouldForceSynchronousComponentInstallerCalls + && isJavaBefore9() + && isAppUsingCustomLogManager()) { + log.debug( + "Custom JUL LogManager detected: delaying ComponentInstaller#afterByteBuddyAgent() calls"); registerClassLoadCallback( "java.util.logging.LogManager", new InstallComponentAfterByteBuddyCallback(config, componentInstallers)); @@ -390,32 +400,16 @@ public static void registerClassLoadCallback(String className, Runnable callback } } - protected static class InstallComponentAfterByteBuddyCallback extends ClassLoadCallBack { - + private static class InstallComponentAfterByteBuddyCallback implements Runnable { private final Iterable componentInstallers; private final Config config; - protected InstallComponentAfterByteBuddyCallback( + private InstallComponentAfterByteBuddyCallback( Config config, Iterable componentInstallers) { this.componentInstallers = componentInstallers; 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 public void run() { /* @@ -423,26 +417,21 @@ public void run() { * to load classes being transformed. To avoid this we start a thread here that calls the callback. * This seems to resolve this problem. */ - Thread thread = - new Thread( - 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 thread = new Thread(this::runComponentInstallers); + thread.setName("agent-component-installers"); thread.setDaemon(true); thread.start(); } - public abstract String getName(); - - public abstract void execute(); + private void runComponentInstallers() { + for (ComponentInstaller componentInstaller : componentInstallers) { + try { + componentInstaller.afterByteBuddyAgent(config); + } catch (Exception e) { + log.error("Failed to execute {}", componentInstaller.getClass().getName(), e); + } + } + } } private static class ClassLoadListener implements AgentBuilder.Listener { @@ -512,63 +501,41 @@ private static boolean isIgnored(Class c) { } } - /** - * 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. - */ + /** Detect if the instrumented application is using a custom JUL LogManager. */ 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"); 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. // Originally we were checking for the presence of a jboss class, // 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. return true; } - String logManagerProp = System.getProperty("java.util.logging.manager"); - if (logManagerProp != null) { + String customLogManager = System.getProperty("java.util.logging.manager"); + if (customLogManager != null) { + log.debug( + "Detected custom LogManager configuration: java.util.logging.manager={}", + customLogManager); boolean onSysClasspath = - ClassLoader.getSystemResource(logManagerProp.replaceAll("\\.", "/") + ".class") != null; - log.debug("Prop - logging.manager: " + logManagerProp); - log.debug("logging.manager on system classpath: " + onSysClasspath); + ClassLoader.getSystemResource(getResourceName(customLogManager)) != null; + log.debug( + "Class {} is on system classpath: {}delaying ComponentInstaller#afterByteBuddyAgent()", + customLogManager, + onSysClasspath ? "not " : ""); // 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. - // 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 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() { VersionLogger.logAllVersions(); log.debug(