Delay starting OkHttp, default to 1 second

Author: mcculls

dd-java-agent/agent-bootstrap/src/main/java/datadog/trace/bootstrap/Agent.java

@@ -78,6 +78,8 @@ public class Agent {
   private static final String AGENT_INSTALLER_CLASS_NAME =
       "datadog.trace.agent.tooling.AgentInstaller";
 
+  private static final int DEFAULT_OKHTTP_DELAY = 1; // seconds
+
   private static final int DEFAULT_JMX_START_DELAY = 15; // seconds
 
   private static final Logger log;
@@ -329,7 +331,7 @@ public void run() {
       if (appUsingCustomJMXBuilder) {
         log.debug("Custom JMX builder detected. Delaying JMXFetch initialization.");
         registerMBeanServerBuilderCallback(new StartJmxCallback(jmxStartDelay));
-        // one minute fail-safe in case nothing touches JMX and and callback isn't triggered
+        // one minute fail-safe in case nothing touches JMX and callback isn't triggered
         scheduleJmxStart(60 + jmxStartDelay);
       } else if (appUsingCustomLogManager) {
         log.debug("Custom logger detected. Delaying JMXFetch initialization.");
@@ -339,20 +341,23 @@ public void run() {
       }
     }
 
-    boolean delayOkHttp = appUsingCustomLogManager && okHttpMayIndirectlyLoadJUL();
+    boolean waitForJUL = appUsingCustomLogManager && okHttpMayIndirectlyLoadJUL();
 
     /*
      * Similar thing happens with DatadogTracer 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. Likewise on IBM JDKs OkHttp may indirectly load 'IBMSASL' which in turn loads LogManager.
      */
+    int okHttpStartDelay = getOkHttpStartDelay();
     InstallDatadogTracerCallback installDatadogTracerCallback =
-        new InstallDatadogTracerCallback(initTelemetry, inst, delayOkHttp);
-    if (delayOkHttp) {
+        new InstallDatadogTracerCallback(initTelemetry, inst, okHttpStartDelay);
+    if (waitForJUL) {
       log.debug("Custom logger detected. Delaying Datadog Tracer initialization.");
       registerLogManagerCallback(installDatadogTracerCallback);
+    } else if (okHttpStartDelay > 0) {
+      installDatadogTracerCallback.run(); // start OkHttp on separate thread
     } else {
-      installDatadogTracerCallback.execute();
+      installDatadogTracerCallback.execute(); // start OkHttp on this thread
     }
 
     /*
@@ -362,7 +367,7 @@ public void run() {
     if (profilingEnabled && !isOracleJDK8()) {
       StaticEventLogger.begin("Profiling");
 
-      if (delayOkHttp) {
+      if (waitForJUL) {
         log.debug("Custom logger detected. Delaying Profiling initialization.");
         registerLogManagerCallback(new StartProfilingAgentCallback(inst));
       } else {
@@ -499,18 +504,18 @@ protected static class InstallDatadogTracerCallback extends ClassLoadCallBack {
     private final Instrumentation instrumentation;
     private final Object sco;
     private final Class<?> scoClass;
-    private final boolean delayOkHttp;
+    private final int okHttpStartDelay;
 
     public InstallDatadogTracerCallback(
         InitializationTelemetry initTelemetry,
         Instrumentation instrumentation,
-        boolean delayOkHttp) {
-      this.delayOkHttp = delayOkHttp;
+        int okHttpStartDelay) {
+      this.okHttpStartDelay = okHttpStartDelay;
       this.instrumentation = instrumentation;
       try {
         scoClass =
             AGENT_CLASSLOADER.loadClass("datadog.communication.ddagent.SharedCommunicationObjects");
-        sco = scoClass.getConstructor(boolean.class).newInstance(delayOkHttp);
+        sco = scoClass.getConstructor(boolean.class).newInstance(okHttpStartDelay > 0);
       } catch (ClassNotFoundException
           | NoSuchMethodException
           | InstantiationException
@@ -530,7 +535,7 @@ public AgentThread agentThread() {
 
     @Override
     public void execute() {
-      if (delayOkHttp) {
+      if (okHttpStartDelay > 0) {
         resumeRemoteComponents();
       }
 
@@ -550,7 +555,7 @@ private void resumeRemoteComponents() {
       try {
         // remote components were paused for custom log-manager/jmx-builder
         // add small delay before resuming remote I/O to help stabilization
-        Thread.sleep(1_000);
+        Thread.sleep(okHttpStartDelay * 1_000L);
         scoClass.getMethod("resume").invoke(sco);
       } catch (InterruptedException ignore) {
       } catch (Throwable e) {
@@ -1244,6 +1249,19 @@ private static String getNullIfEmpty(final String value) {
     return value;
   }
 
+  /** @return configured OkHttp start delay in seconds */
+  private static int getOkHttpStartDelay() {
+    String startDelay = ddGetProperty("dd.okhttp.start-delay");
+    if (startDelay != null) {
+      try {
+        return Integer.parseInt(startDelay);
+      } catch (NumberFormatException e) {
+        // fall back to default delay
+      }
+    }
+    return DEFAULT_OKHTTP_DELAY;
+  }
+
   /** @return configured JMX start delay in seconds */
   private static int getJmxStartDelay() {
     String startDelay = ddGetProperty("dd.dogstatsd.start-delay");

dd-trace-api/src/main/java/datadog/trace/api/ConfigDefaults.java

@@ -90,6 +90,8 @@ public final class ConfigDefaults {
 
   static final boolean DEFAULT_TRACE_PROPAGATION_EXTRACT_FIRST = false;
 
+  static final int DEFAULT_OKHTTP_START_DELAY = 1; // seconds
+
   static final boolean DEFAULT_JMX_FETCH_MULTIPLE_RUNTIME_SERVICES_ENABLED = false;
   static final int DEFAULT_JMX_FETCH_MULTIPLE_RUNTIME_SERVICES_LIMIT = 10;
 

dd-trace-api/src/main/java/datadog/trace/api/config/GeneralConfig.java

@@ -37,6 +37,8 @@ public final class GeneralConfig {
 
   public static final String STARTUP_LOGS_ENABLED = "trace.startup.logs";
 
+  public static final String OKHTTP_START_DELAY = "okhttp.start-delay";
+
   public static final String DOGSTATSD_START_DELAY = "dogstatsd.start-delay";
   public static final String DOGSTATSD_HOST = "dogstatsd.host";
   public static final String DOGSTATSD_PORT = "dogstatsd.port";

internal-api/src/main/java/datadog/trace/api/Config.java

@@ -191,6 +191,7 @@ public static String getHostName() {
   private final boolean tracePropagationExtractFirst;
   private final int clockSyncPeriod;
   private final boolean logsInjectionEnabled;
+  private final int okHttpStartDelay;
 
   private final String dogStatsDNamedPipe;
   private final int dogStatsDStartDelay;
@@ -1005,6 +1006,8 @@ private Config(final ConfigProvider configProvider, final InstrumenterConfig ins
         configProvider.getBoolean(
             LOGS_INJECTION_ENABLED, DEFAULT_LOGS_INJECTION_ENABLED, LOGS_INJECTION);
 
+    okHttpStartDelay = configProvider.getInteger(OKHTTP_START_DELAY, DEFAULT_OKHTTP_START_DELAY);
+
     dogStatsDNamedPipe = configProvider.getString(DOGSTATSD_NAMED_PIPE);
 
     dogStatsDStartDelay =
@@ -2220,6 +2223,10 @@ public int getClockSyncPeriod() {
     return clockSyncPeriod;
   }
 
+  public int getOkHttpStartDelay() {
+    return okHttpStartDelay;
+  }
+
   public String getDogStatsDNamedPipe() {
     return dogStatsDNamedPipe;
   }
@@ -4345,6 +4352,8 @@ public String toString() {
         + tracePropagationExtractFirst
         + ", clockSyncPeriod="
         + clockSyncPeriod
+        + ", okHttpStartDelay="
+        + okHttpStartDelay
         + ", jmxFetchEnabled="
         + jmxFetchEnabled
         + ", dogStatsDStartDelay="