use real time threshold for queue times

richardstartin · richardstartin · commit 78012cfa5d51 · 2024-04-30T20:07:24.000+01:00
diff --git a/dd-java-agent/agent-profiling/profiling-ddprof/src/main/java/com/datadog/profiling/ddprof/DatadogProfiler.java b/dd-java-agent/agent-profiling/profiling-ddprof/src/main/java/com/datadog/profiling/ddprof/DatadogProfiler.java
@@ -29,7 +29,6 @@
 
 import com.datadog.profiling.controller.OngoingRecording;
 import com.datadog.profiling.utils.ProfilingMode;
-import com.datadog.profiling.utils.Timestamper;
 import com.datadoghq.profiler.ContextSetter;
 import com.datadoghq.profiler.JavaProfiler;
 import datadog.trace.api.profiling.RecordingData;
@@ -97,7 +96,7 @@ public static DatadogProfiler newInstance(ConfigProvider configProvider) {
 
   private final List<String> orderedContextAttributes;
 
-  private final double queueTimeThresholdNanos;
+  private final long queueTimeThresholdMillis;
 
   private DatadogProfiler(ConfigProvider configProvider) {
     this(configProvider, getContextAttributes(configProvider));
@@ -134,11 +133,10 @@ private DatadogProfiler(ConfigProvider configProvider) {
       orderedContextAttributes.add(RESOURCE);
     }
     this.contextSetter = new ContextSetter(profiler, orderedContextAttributes);
-    this.queueTimeThresholdNanos =
-        1_000_000D
-            * configProvider.getLong(
-                PROFILING_QUEUEING_TIME_THRESHOLD_MILLIS,
-                PROFILING_QUEUEING_TIME_THRESHOLD_MILLIS_DEFAULT);
+    this.queueTimeThresholdMillis =
+        configProvider.getLong(
+            PROFILING_QUEUEING_TIME_THRESHOLD_MILLIS,
+            PROFILING_QUEUEING_TIME_THRESHOLD_MILLIS_DEFAULT);
   }
 
   void addThread() {
@@ -377,34 +375,21 @@ public void recordSetting(String name, String value, String unit) {
   }
 
   public QueueTimeTracker newQueueTimeTracker() {
-    return new QueueTimeTracker(this, timestamper().timestamp());
+    return new QueueTimeTracker(this, profiler.getCurrentTicks());
   }
 
-  void recordQueueTimeEvent(long startTicks, Object task, Class<?> scheduler, Thread origin) {
+  void recordQueueTimeEvent(
+      long startMillis, long startTicks, Object task, Class<?> scheduler, Thread origin) {
     if (profiler != null) {
-      Timestamper timestamper = timestamper();
-      long endTicks = timestamper.timestamp();
-      double durationNanos = timestamper.toNanosConversionFactor() * (endTicks - startTicks);
-      if (durationNanos >= queueTimeThresholdNanos) {
+      if (System.currentTimeMillis() - startMillis >= queueTimeThresholdMillis) {
         // note: because this type traversal can update secondary_super_cache (see JDK-8180450)
         // we avoid doing this unless we are absolutely certain we will record the event
         Class<?> taskType = TaskWrapper.getUnwrappedType(task);
         if (taskType != null) {
+          long endTicks = profiler.getCurrentTicks();
           profiler.recordQueueTime(startTicks, endTicks, taskType, scheduler, origin);
         }
       }
     }
   }
-
-  private Timestamper timestamper() {
-    // FIXME intended to be injectable, but still a singleton for currently pragmatic reasons.
-    //  We need a way to make the Controller responsible for creating the context integration
-    //  for the tracer, which also allows the context integration to be constant in the tracer,
-    //  as well as allowing for the various late initialisation needs for JFR on certain JDK
-    // versions
-    // note that this access does not risk using the default version so long as queue time is
-    // guarded
-    // by checking if JFR is ready (this currently happens in QueueTimeHelper, so this is safe)
-    return Timestamper.timestamper();
-  }
 }
diff --git a/dd-java-agent/agent-profiling/profiling-ddprof/src/main/java/com/datadog/profiling/ddprof/QueueTimeTracker.java b/dd-java-agent/agent-profiling/profiling-ddprof/src/main/java/com/datadog/profiling/ddprof/QueueTimeTracker.java
@@ -8,6 +8,7 @@ public class QueueTimeTracker implements QueueTiming {
   private final DatadogProfiler profiler;
   private final Thread origin;
   private final long startTicks;
+  private final long startMillis;
   private WeakReference<Object> weakTask;
   // FIXME this can be eliminated by altering the instrumentation
   //  since it is known when the item is polled from the queue
@@ -16,8 +17,8 @@ public class QueueTimeTracker implements QueueTiming {
   public QueueTimeTracker(DatadogProfiler profiler, long startTicks) {
     this.profiler = profiler;
     this.origin = Thread.currentThread();
-    // TODO get this from JFR if available instead of making a JNI call
     this.startTicks = startTicks;
+    this.startMillis = System.currentTimeMillis();
   }
 
   @Override
@@ -36,7 +37,7 @@ public void close() {
     Object task = this.weakTask.get();
     if (task != null) {
       // indirection reduces shallow size of the tracker instance
-      profiler.recordQueueTimeEvent(startTicks, task, scheduler, origin);
+      profiler.recordQueueTimeEvent(startMillis, startTicks, task, scheduler, origin);
     }
   }
 }

Original file line number	Diff line number	Diff line change
`@@ -8,6 +8,7 @@ public class QueueTimeTracker implements QueueTiming {`
`8`	`8`	`private final DatadogProfiler profiler;`
`9`	`9`	`private final Thread origin;`
`10`	`10`	`private final long startTicks;`
	`11`	`+ private final long startMillis;`
`11`	`12`	`private WeakReference<Object> weakTask;`
`12`	`13`	`// FIXME this can be eliminated by altering the instrumentation`
`13`	`14`	`// since it is known when the item is polled from the queue`
`@@ -16,8 +17,8 @@ public class QueueTimeTracker implements QueueTiming {`
`16`	`17`	`public QueueTimeTracker(DatadogProfiler profiler, long startTicks) {`
`17`	`18`	`this.profiler = profiler;`
`18`	`19`	`this.origin = Thread.currentThread();`
`19`		`- // TODO get this from JFR if available instead of making a JNI call`
`20`	`20`	`this.startTicks = startTicks;`
	`21`	`+ this.startMillis = System.currentTimeMillis();`
`21`	`22`	`}`
`22`	`23`
`23`	`24`	`@Override`
`@@ -36,7 +37,7 @@ public void close() {`
`36`	`37`	`Object task = this.weakTask.get();`
`37`	`38`	`if (task != null) {`
`38`	`39`	`// indirection reduces shallow size of the tracker instance`
`39`		`- profiler.recordQueueTimeEvent(startTicks, task, scheduler, origin);`
	`40`	`+ profiler.recordQueueTimeEvent(startMillis, startTicks, task, scheduler, origin);`
`40`	`41`	`}`
`41`	`42`	`}`
`42`	`43`	`}`