Bug 142675 – GCTimer should know keep track of nested GC phases

• Status: RESOLVED
• Resolution: FIXED
• Component: JavaScriptCore

[Mark Hahnenberg]

This would improve the GC phase timing output in Heap.cpp by linking phases nested inside other phases together, allowing tools to compute how much time we're spending in various nested phases.

[Mark Hahnenberg]

Created attachment 248594 [details]
Patch

[Mark Hahnenberg]

Created attachment 248595 [details]
Patch

[Mark Hahnenberg]

What license should I put on the python script?

[Mark Hahnenberg]

Example output:

mhahnenberg-mbp:WebKit mhahnenberg$ cat ~/gc_timings2.txt | ~/gc_timing_parser.py
Collect - All total: 987.99, avg: 12.05 - 100.00%
     MarkRoots - All total: 479.16, avg: 5.84 - 48.50%
          VisitingLiveWeakHandles - All total: 112.62, avg: 1.37 - 23.50%
          VisitConservativeRoots - All total: 97.95, avg: 1.19 - 20.44%
          VisitStrongHandles - All total: 78.15, avg: 0.95 - 16.31%
          Convergence - All total: 76.83, avg: 0.94 - 16.03%
          VisitProtectedObjects - All total: 52.80, avg: 0.64 - 11.02%
          GatherStackRoots - All total: 19.24, avg: 0.23 - 4.02%
          TraceCodeBlocksAndJITStubRoutines - All total: 5.81, avg: 0.07 - 1.21%
          ClearLivenessData - All total: 4.91, avg: 0.06 - 1.02%
          ClearRememberedSet - All total: 2.16, avg: 0.03 - 0.45%
          VisitSmallStrings - All total: 0.31, avg: 0.00 - 0.06%
          GatherScratchBufferRoots - All total: 0.07, avg: 0.00 - 0.01%
          VisitHandleStack - All total: 0.04, avg: 0.00 - 0.01%
          VisitTempSortVectors - All total: 0.02, avg: 0.00 - 0.00%
          MarkingArgumentBuffers - All total: 0.02, avg: 0.00 - 0.00%
          MarkingException - All total: 0.01, avg: 0.00 - 0.00%
     FinalizeUnconditionalFinalizers - All total: 231.55, avg: 2.82 - 23.44%
     DeleteCodeBlocks - All total: 186.24, avg: 2.27 - 18.85%
          ClearUnmarkedExecutables - All total: 13.83, avg: 0.17 - 7.43%
     ReapingWeakHandles - All total: 27.50, avg: 0.34 - 2.78%
     StopAllocation - All total: 20.96, avg: 0.26 - 2.12%
     CopyBackingStores - All total: 19.07, avg: 0.23 - 1.93%
     DeleteSourceProviderCaches - All total: 12.12, avg: 0.15 - 1.23%
     PruningStaleEntriesFromWeakGCMaps - All total: 7.12, avg: 0.09 - 0.72%
     NotifyIncrementalSweeper - All total: 1.38, avg: 0.02 - 0.14%
     SnapshotMarkedSpace - All total: 1.07, avg: 0.01 - 0.11%
     ResetAllocators - All total: 0.55, avg: 0.01 - 0.06%
     FinalizeDFGWorklists - All total: 0.24, avg: 0.00 - 0.02%
     ResumeCompilerThreads - All total: 0.15, avg: 0.00 - 0.02%
     FlushWriteBarrierBuffer - All total: 0.14, avg: 0.00 - 0.01%
     RememberCurrentlyExecutingCodeBlocks - All total: 0.06, avg: 0.00 - 0.01%
     UpdateAllocationLimits - All total: 0.05, avg: 0.00 - 0.01%
     SweepingArrayBuffers - All total: 0.04, avg: 0.00 - 0.00%
     FinishingCollection - All total: 0.04, avg: 0.00 - 0.00%
     FlushOldStructureIDTables - All total: 0.02, avg: 0.00 - 0.00%
     DeleteOldCode - All total: 0.00, avg: 0.00 - 0.00%
StartingCollection - All total: 1.03, avg: 0.01 - 100.00%
SuspendCompilerThreads - All total: 0.75, avg: 0.01 - 100.00%

Collect - Eden total: 434.29, avg: 6.39 - 100.00%
     MarkRoots - Eden total: 217.62, avg: 3.20 - 50.11%
          VisitConservativeRoots - Eden total: 70.45, avg: 1.04 - 32.37%
          VisitingLiveWeakHandles - Eden total: 48.12, avg: 0.71 - 22.11%
          VisitStrongHandles - Eden total: 25.56, avg: 0.38 - 11.75%
          GatherStackRoots - Eden total: 17.19, avg: 0.25 - 7.90%
          Convergence - Eden total: 15.43, avg: 0.23 - 7.09%
          VisitProtectedObjects - Eden total: 9.62, avg: 0.14 - 4.42%
          TraceCodeBlocksAndJITStubRoutines - Eden total: 4.70, avg: 0.07 - 2.16%
          ClearRememberedSet - Eden total: 2.16, avg: 0.03 - 0.99%
          ClearLivenessData - Eden total: 1.29, avg: 0.02 - 0.59%
          GatherScratchBufferRoots - Eden total: 0.06, avg: 0.00 - 0.03%
          VisitHandleStack - Eden total: 0.03, avg: 0.00 - 0.01%
          VisitSmallStrings - Eden total: 0.02, avg: 0.00 - 0.01%
          VisitTempSortVectors - Eden total: 0.02, avg: 0.00 - 0.01%
          MarkingArgumentBuffers - Eden total: 0.02, avg: 0.00 - 0.01%
          MarkingException - Eden total: 0.01, avg: 0.00 - 0.00%
     FinalizeUnconditionalFinalizers - Eden total: 105.18, avg: 1.55 - 24.22%
     DeleteCodeBlocks - Eden total: 48.44, avg: 0.71 - 11.15%
          ClearUnmarkedExecutables - Eden total: 6.07, avg: 0.09 - 12.53%
     StopAllocation - Eden total: 18.28, avg: 0.27 - 4.21%
     CopyBackingStores - Eden total: 18.00, avg: 0.26 - 4.14%
     ReapingWeakHandles - Eden total: 12.96, avg: 0.19 - 2.98%
     DeleteSourceProviderCaches - Eden total: 10.93, avg: 0.16 - 2.52%
     NotifyIncrementalSweeper - Eden total: 1.23, avg: 0.02 - 0.28%
     ResetAllocators - Eden total: 0.45, avg: 0.01 - 0.10%
     FinalizeDFGWorklists - Eden total: 0.16, avg: 0.00 - 0.04%
     SnapshotMarkedSpace - Eden total: 0.14, avg: 0.00 - 0.03%
     FlushWriteBarrierBuffer - Eden total: 0.13, avg: 0.00 - 0.03%
     RememberCurrentlyExecutingCodeBlocks - Eden total: 0.05, avg: 0.00 - 0.01%
     UpdateAllocationLimits - Eden total: 0.05, avg: 0.00 - 0.01%
     SweepingArrayBuffers - Eden total: 0.03, avg: 0.00 - 0.01%
     FlushOldStructureIDTables - Eden total: 0.02, avg: 0.00 - 0.00%
     FinishingCollection - Eden total: 0.02, avg: 0.00 - 0.00%
     PruningStaleEntriesFromWeakGCMaps - Eden total: 0.01, avg: 0.00 - 0.00%
     DeleteOldCode - Eden total: 0.00, avg: nan - 0.00%
     ResumeCompilerThreads - Eden total: 0.00, avg: nan - 0.00%
SuspendCompilerThreads - Eden total: 0.00, avg: nan - 100.00%
StartingCollection - Eden total: 0.00, avg: nan - 100.00%

Collect - Full total: 553.69, avg: 39.55 - 100.00%
     MarkRoots - Full total: 261.54, avg: 18.68 - 47.24%
          VisitingLiveWeakHandles - Full total: 64.49, avg: 4.61 - 24.66%
          Convergence - Full total: 61.40, avg: 4.39 - 23.48%
          VisitStrongHandles - Full total: 52.59, avg: 3.76 - 20.11%
          VisitProtectedObjects - Full total: 43.19, avg: 3.08 - 16.51%
          VisitConservativeRoots - Full total: 27.49, avg: 1.96 - 10.51%
          ClearLivenessData - Full total: 3.62, avg: 0.26 - 1.38%
          GatherStackRoots - Full total: 2.05, avg: 0.15 - 0.78%
          TraceCodeBlocksAndJITStubRoutines - Full total: 1.11, avg: 0.08 - 0.42%
          VisitSmallStrings - Full total: 0.30, avg: 0.02 - 0.11%
          GatherScratchBufferRoots - Full total: 0.01, avg: 0.00 - 0.00%
          VisitHandleStack - Full total: 0.01, avg: 0.00 - 0.00%
          VisitTempSortVectors - Full total: 0.00, avg: 0.00 - 0.00%
          MarkingArgumentBuffers - Full total: 0.00, avg: 0.00 - 0.00%
          MarkingException - Full total: 0.00, avg: 0.00 - 0.00%
          ClearRememberedSet - Full total: 0.00, avg: 0.00 - 0.00%
     DeleteCodeBlocks - Full total: 137.79, avg: 9.84 - 24.89%
          ClearUnmarkedExecutables - Full total: 7.76, avg: 0.55 - 5.63%
     FinalizeUnconditionalFinalizers - Full total: 126.37, avg: 9.03 - 22.82%
     ReapingWeakHandles - Full total: 14.54, avg: 1.04 - 2.63%
     PruningStaleEntriesFromWeakGCMaps - Full total: 7.11, avg: 0.51 - 1.28%
     StopAllocation - Full total: 2.68, avg: 0.19 - 0.48%
     DeleteSourceProviderCaches - Full total: 1.18, avg: 0.08 - 0.21%
     CopyBackingStores - Full total: 1.07, avg: 0.08 - 0.19%
     SnapshotMarkedSpace - Full total: 0.92, avg: 0.07 - 0.17%
     NotifyIncrementalSweeper - Full total: 0.15, avg: 0.01 - 0.03%
     ResumeCompilerThreads - Full total: 0.15, avg: 0.00 - 0.03%
     ResetAllocators - Full total: 0.10, avg: 0.01 - 0.02%
     FinalizeDFGWorklists - Full total: 0.08, avg: 0.01 - 0.01%
     SweepingArrayBuffers - Full total: 0.01, avg: 0.00 - 0.00%
     RememberCurrentlyExecutingCodeBlocks - Full total: 0.01, avg: 0.00 - 0.00%
     FinishingCollection - Full total: 0.01, avg: 0.00 - 0.00%
     DeleteOldCode - Full total: 0.00, avg: 0.00 - 0.00%
     FlushOldStructureIDTables - Full total: 0.00, avg: 0.00 - 0.00%
     FlushWriteBarrierBuffer - Full total: 0.00, avg: 0.00 - 0.00%
     UpdateAllocationLimits - Full total: 0.00, avg: 0.00 - 0.00%
StartingCollection - Full total: 1.03, avg: 0.01 - 100.00%
SuspendCompilerThreads - Full total: 0.75, avg: 0.01 - 100.00%

[Mark Lam]

Comment on attachment 248595 [details]
Patch

r=me

[Mark Hahnenberg]

Created attachment 248898 [details]
Patch

[Mark Hahnenberg]

Added license.

[Darin Adler]

Comment on attachment 248898 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=248898&action=review

> Source/JavaScriptCore/heap/Heap.cpp:84
> +        , m_parent(nullptr)

In new code it’s better to initialize these things at their declaration site:

    GCTimer* m_parent { nullptr };

Better than listing in the constructor(s) when the type is a neutral value like nullptr.
    
Also, struct members should not have "m_" prefixes on them. In WebKit coding style, private class members should, but for structs it’s not helpful.

> Source/JavaScriptCore/heap/Heap.cpp:98
> +        if (!m_parent)
> +            m_parent = parent;
> +        ASSERT(m_parent == parent);

This seems strange. What exactly does the if (!m_parent) protect against?

Given that this is a struct, I’m not sure it’s helpful to have this set function for this one particular member.

> Source/JavaScriptCore/heap/Heap.cpp:159
>      GCTimerScope(GCTimer* timer, HeapOperation collectionType)

GCTimer argument should be a reference, I think, not a pointer.

> Source/JavaScriptCore/heap/Heap.cpp:177
>      GCTimer* m_timer;
>      double m_start;
>      HeapOperation m_collectionType;
> +    GCTimer* m_previousGlobalTimer;

Again, if this is a struct, then I don’t think we should have m_ prefixes on these.

Doesn’t make sense that we need both GCTimer::m_parent and GCTimerScope::m_previousGlobalTimer. I suggest we just use m_timer->m_parent instead of m_previousGlobalTimer.

[Mark Hahnenberg]

Created attachment 248944 [details]
Patch

[Mark Hahnenberg]

Fixed up all the GCTimer/GCCounter related structs w/ Darin's suggestions.

[WebKit Commit Bot]

Comment on attachment 248944 [details]
Patch

Clearing flags on attachment: 248944

Committed r181821: <http://trac.webkit.org/changeset/181821>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.