heap: Ignore v8 references flushing time in speed computation

Incremental marking can get steps that are entirely consumed by
flushing of v8 references. This steps contribute to time spend
processing worklists on the main thread, but don't contribute
any marked bytes. This thus affects our marking speed computation
and results in lower than actual marking speed. The lower speed
leads to longer step duration which causes marking to do more
work than actually needed on the mutator thread. Step duration
for minimum steps (i.e. step meant to mark just 64kb) could reach
over 0.5ms due to this and similar issues.

Ignoring flushing time in the speed computation prevents these
uncontrolled false drops in marking speed and maintains a mostly
consistent minimum step duration.

Bug: 986235
Change-Id: I23132d65680ef19bedad8d8efffd0b92d439af1e
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2297500
Commit-Queue: Omer Katz <omerkatz@chromium.org>
Reviewed-by: Anton Bikineev <bikineev@chromium.org>
Reviewed-by: Michael Lippautz <mlippautz@chromium.org>
Reviewed-by: Ulan Degenbaev <ulan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#790355}

third_party/blink/renderer/platform/heap/heap_stats_collector.cc

@@ -161,6 +161,11 @@ ThreadHeapStatsCollector::Event::worklist_processing_time_foreground() const {
   return scope_data[kMarkProcessWorklists];
 }
 
+base::TimeDelta ThreadHeapStatsCollector::Event::flushing_v8_references_time()
+    const {
+  return scope_data[kMarkFlushV8References];
+}
+
 base::TimeDelta ThreadHeapStatsCollector::Event::atomic_marking_time() const {
   return scope_data[kAtomicPauseMarkPrologue] +
          scope_data[kAtomicPauseMarkRoots] +
@@ -238,6 +243,10 @@ base::TimeDelta ThreadHeapStatsCollector::worklist_processing_time_foreground()
   return current_.worklist_processing_time_foreground();
 }
 
+base::TimeDelta ThreadHeapStatsCollector::flushing_v8_references_time() const {
+  return current_.flushing_v8_references_time();
+}
+
 size_t ThreadHeapStatsCollector::allocated_space_bytes() const {
   return allocated_space_bytes_;
 }

third_party/blink/renderer/platform/heap/heap_stats_collector.h

@@ -242,6 +242,9 @@ class PLATFORM_EXPORT ThreadHeapStatsCollector {
     // Time spent processing worklist in the foreground thread.
     base::TimeDelta worklist_processing_time_foreground() const;
 
+    // Time spent flushing v8 references (this is done only in the foreground)
+    base::TimeDelta flushing_v8_references_time() const;
+
     // Time spent in foreground tasks marking the heap.
     base::TimeDelta foreground_marking_time() const;
 
@@ -330,6 +333,8 @@ class PLATFORM_EXPORT ThreadHeapStatsCollector {
 
   base::TimeDelta worklist_processing_time_foreground() const;
 
+  base::TimeDelta flushing_v8_references_time() const;
+
   int64_t allocated_bytes_since_prev_gc() const;
 
   size_t allocated_space_bytes() const;

third_party/blink/renderer/platform/heap/marking_scheduling_oracle.cc

@@ -18,9 +18,15 @@ MarkingSchedulingOracle::MarkingSchedulingOracle()
 
 void MarkingSchedulingOracle::UpdateIncrementalMarkingStats(
     size_t overall_marked_bytes,
-    base::TimeDelta overall_marking_time) {
+    base::TimeDelta overall_marking_time,
+    base::TimeDelta non_contributing_time) {
   incrementally_marked_bytes_ = overall_marked_bytes;
-  incremental_marking_time_so_far_ = overall_marking_time;
+  // |non_contributing_time| is time spent during |overall_marking_time| which
+  // does not contribute to |overall_marked_bytes| and is thus ignored so that
+  // it doesn't affect the marking speed.
+  DCHECK_LE(non_contributing_time, overall_marking_time);
+  incremental_marking_time_so_far_ =
+      overall_marking_time - non_contributing_time;
 }
 
 void MarkingSchedulingOracle::AddConcurrentlyMarkedBytes(size_t marked_bytes) {

third_party/blink/renderer/platform/heap/marking_scheduling_oracle.h

@@ -32,7 +32,7 @@ class PLATFORM_EXPORT MarkingSchedulingOracle {
 
   explicit MarkingSchedulingOracle();
 
-  void UpdateIncrementalMarkingStats(size_t, base::TimeDelta);
+  void UpdateIncrementalMarkingStats(size_t, base::TimeDelta, base::TimeDelta);
   void AddConcurrentlyMarkedBytes(size_t);
 
   size_t GetOverallMarkedBytes();

third_party/blink/renderer/platform/heap/test/marking_scheduling_oracle_test.cc

@@ -31,7 +31,8 @@ TEST_F(MarkingSchedulingOracleTest, NoTimePassedReturnsMinimumDuration) {
   // Add incrementally marked bytes to tell oracle this is not the first step.
   oracle.UpdateIncrementalMarkingStats(
       MarkingSchedulingOracle::kMinimumMarkedBytesInStep,
-      base::TimeDelta::FromMilliseconds(1));
+      base::TimeDelta::FromMilliseconds(1),
+      base::TimeDelta::FromMilliseconds(0));
   oracle.SetElapsedTimeForTesting(0);
   // Given marking speed set above, Minimum duration should be 1ms.
   EXPECT_EQ(1, oracle.GetNextIncrementalStepDurationForTask(kObjectSize)
@@ -42,8 +43,10 @@ TEST_F(MarkingSchedulingOracleTest, OracleDoesntExccedMaximumStepDuration) {
   MarkingSchedulingOracle oracle;
   // Add incrementally marked bytes to tell oracle this is not the first step.
   oracle.UpdateIncrementalMarkingStats(
-      1, base::TimeDelta::FromMilliseconds(
-             MarkingSchedulingOracle::kEstimatedMarkingTimeMs));
+      1,
+      base::TimeDelta::FromMilliseconds(
+          MarkingSchedulingOracle::kEstimatedMarkingTimeMs),
+      base::TimeDelta::FromMilliseconds(0));
   oracle.SetElapsedTimeForTesting(
       MarkingSchedulingOracle::kEstimatedMarkingTimeMs);
   EXPECT_EQ(MarkingSchedulingOracle::kMaximumIncrementalMarkingStepDuration,
@@ -55,7 +58,8 @@ TEST_F(MarkingSchedulingOracleTest, AheadOfScheduleReturnsMinimumDuration) {
   // Add incrementally marked bytes to tell oracle this is not the first step.
   oracle.UpdateIncrementalMarkingStats(
       MarkingSchedulingOracle::kMinimumMarkedBytesInStep,
-      base::TimeDelta::FromMilliseconds(1));
+      base::TimeDelta::FromMilliseconds(1),
+      base::TimeDelta::FromMilliseconds(0));
   oracle.AddConcurrentlyMarkedBytes(0.6 * kObjectSize);
   oracle.SetElapsedTimeForTesting(
       0.5 * MarkingSchedulingOracle::kEstimatedMarkingTimeMs);
@@ -69,7 +73,8 @@ TEST_F(MarkingSchedulingOracleTest, BehindScheduleReturnsCorrectDuration) {
   MarkingSchedulingOracle oracle;
   oracle.UpdateIncrementalMarkingStats(
       0.1 * kObjectSize,
-      base::TimeDelta::FromMilliseconds(kForegoundMarkingTime));
+      base::TimeDelta::FromMilliseconds(kForegoundMarkingTime),
+      base::TimeDelta::FromMilliseconds(0));
   oracle.AddConcurrentlyMarkedBytes(0.25 * kObjectSize);
   oracle.SetElapsedTimeForTesting(
       0.5 * MarkingSchedulingOracle::kEstimatedMarkingTimeMs);

third_party/blink/renderer/platform/heap/thread_state.cc

@@ -1611,7 +1611,8 @@ bool ThreadState::MarkPhaseAdvanceMarking(
   // the object graph, this is fine.
   marking_scheduling_->UpdateIncrementalMarkingStats(
       visitor->marked_bytes(),
-      Heap().stats_collector()->worklist_processing_time_foreground());
+      Heap().stats_collector()->worklist_processing_time_foreground(),
+      Heap().stats_collector()->flushing_v8_references_time());
   return finished;
 }