Fix the problem with inconsistent thread times that otherwise will occur for e.g. threads sitting in wait() for long enough time when createSnapshot() is invoked.

Author: thurka

visualvm/libs.profiler/lib.profiler/src/org/graalvm/visualvm/lib/jfluid/results/cpu/CPUCallGraphBuilder.java

@@ -160,9 +160,7 @@ public CPUCCTContainer[] createPresentationCCTs(CPUResultsSnapshot cpuSnapshot)
 
                 // Fix the problem with inconsistent thread times that otherwise will occur for e.g. threads sitting in wait()
                 // for long enough time when "get results" is pressed
-                /* not in use any longer
-                   ti.applyDiffAtGetResultsMoment();
-                 */
+                applyDiffAtGetResultsMoment(ti);
                 double[] activeTimes = calculateThreadActiveTimes(ti);
 
                 TimedCPUCCTNode rootNode = ti.stack[0];
@@ -173,6 +171,7 @@ public CPUCCTContainer[] createPresentationCCTs(CPUResultsSnapshot cpuSnapshot)
                 if ((cct.rootNode != null) && (cct.rootNode.getNChildren() > 0)) {
                     ccts.add(cct);
                 }
+                undoDiffAtGetResultsMoment(ti);
             }
 
             return (CPUCCTContainer[]) ccts.toArray(new CPUCCTContainer[0]);
@@ -189,6 +188,17 @@ protected boolean isCollectingTwoTimeStamps() {
         return status.collectingTwoTimeStamps();
     }
 
+    /** See the comment to ThreadInfo.diffAtGetResultsMoment field. */
+    protected void applyDiffAtGetResultsMoment(ThreadInfo ti) {
+    }
+
+    /**
+     * See the comment to ThreadInfo.diffAtGetResultsMoment field. When we resume data processing for the given thread,
+     * we need to undo the effect of applyDiffAtGetResultsMoment.
+     */
+    protected void undoDiffAtGetResultsMoment(ThreadInfo ti) {
+    }
+
     protected long getDumpAbsTimeStamp() {
         return status.dumpAbsTimeStamp;
     }

visualvm/libs.profiler/lib.profiler/src/org/graalvm/visualvm/lib/jfluid/results/cpu/StackTraceSnapshotBuilder.java

@@ -57,6 +57,8 @@
 import org.graalvm.visualvm.lib.jfluid.global.CommonConstants;
 import org.graalvm.visualvm.lib.jfluid.global.ProfilingSessionStatus;
 import org.graalvm.visualvm.lib.jfluid.results.RuntimeCCTNode;
+import org.graalvm.visualvm.lib.jfluid.results.cpu.cct.nodes.MethodCPUCCTNode;
+import org.graalvm.visualvm.lib.jfluid.results.cpu.cct.nodes.TimedCPUCCTNode;
 
 /**
  *
@@ -626,7 +628,6 @@ public final CPUResultsSnapshot createSnapshot(
                 instrMethodSigs[counter] = "";
                 counter++;
             }
-            addStacktrace(new java.lang.management.ThreadInfo[0], currentDumpTimeStamp+1);
             return new CPUResultsSnapshot(since, System.currentTimeMillis(), ccgb, ccgb.isCollectingTwoTimeStamps(), instrMethodClasses, instrMethodNames, instrMethodSigs, miCount);
         }
     }
@@ -690,6 +691,36 @@ protected long getDumpAbsTimeStamp() {
             }
         }
 
-    }
+        @Override
+        protected void applyDiffAtGetResultsMoment(ThreadInfo ti) {
+            long time0 = getDumpAbsTimeStamp();
+            long diff = time0 - ti.topMethodEntryTime0;
+
+            applyDiffToTopNode(ti, diff);
+            ti.diffAtGetResultsMoment = diff;
+        }
+
+        @Override
+        protected void undoDiffAtGetResultsMoment(ThreadInfo ti) {
+            applyDiffToTopNode(ti, -ti.diffAtGetResultsMoment);
+            ti.diffAtGetResultsMoment = 0;
+        }
+
+        private void applyDiffToTopNode(ThreadInfo ti, long diff) {
+            if (diff>0) {
+                TimedCPUCCTNode top = ti.peek();
 
+                if (top instanceof MethodCPUCCTNode) {
+                    top.addNetTime0(diff);
+                    if (isCollectingTwoTimeStamps()) {
+                        SampledThreadInfo sti = lastStackTrace.get().get(Long.valueOf(ti.threadId));
+
+                        if (sti!=null && sti.getThreadState() == Thread.State.RUNNABLE) {
+                            top.addNetTime1(diff);
+                        }
+                    }
+                }
+            }
+        }
+    }
 }

visualvm/libs.profiler/lib.profiler/src/org/graalvm/visualvm/lib/jfluid/results/cpu/ThreadInfo.java

@@ -50,9 +50,9 @@ public class ThreadInfo {
     // moment user hits "get results" and the timestamp for the method entry into the top stack method. To present
     // results consistenly, we add this value to the TimedCPUCCTNode for the top-stack method. However, when
     // processing of data is resumed, we need to subtract this value back from that node.
-    // this is effectively the self time for the last invocation of the top method on stack - if we would not keep
+    // This is effectively the self time for the last invocation of the top method on stack - if we would not keep
     // it separately, it would not be reported
-    // private long diffAtGetResultsMoment; // diff between last methodEntry and current moment timestamp -
+    long diffAtGetResultsMoment; // diff between last methodEntry and current moment timestamp -
     //  we will have to compensate for the processing time
 
     //~ Instance fields ------------------------------------------------------------------------------------------------------