Bug 142675

Summary: GCTimer should know keep track of nested GC phases
Product: WebKit Reporter: Mark Hahnenberg <mhahnenb>
Component: JavaScriptCoreAssignee: Mark Hahnenberg <mhahnenb>
Status: RESOLVED FIXED    
Severity: Normal CC: commit-queue, fpizlo, ggaren, kling, rniwa
Priority: P2    
Version: 528+ (Nightly build)   
Hardware: Unspecified   
OS: Unspecified   
Bug Depends on:    
Bug Blocks: 140774    
Attachments:
Description Flags
Patch
none
Patch
none
Patch
none
Patch none

Description Mark Hahnenberg 2015-03-13 11:47:13 PDT
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.
Comment 1 Mark Hahnenberg 2015-03-13 11:51:54 PDT
Created attachment 248594 [details]
Patch
Comment 2 Mark Hahnenberg 2015-03-13 11:52:45 PDT
Created attachment 248595 [details]
Patch
Comment 3 Mark Hahnenberg 2015-03-13 11:55:00 PDT
What license should I put on the python script?
Comment 4 Mark Hahnenberg 2015-03-13 11:57:05 PDT
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%
Comment 5 Mark Lam 2015-03-13 12:21:44 PDT
Comment on attachment 248595 [details]
Patch

r=me
Comment 6 Mark Hahnenberg 2015-03-17 18:55:26 PDT
Created attachment 248898 [details]
Patch
Comment 7 Mark Hahnenberg 2015-03-17 18:55:53 PDT
Added license.
Comment 8 Darin Adler 2015-03-18 10:10:18 PDT
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.
Comment 9 Mark Hahnenberg 2015-03-18 11:29:04 PDT
Created attachment 248944 [details]
Patch
Comment 10 Mark Hahnenberg 2015-03-18 11:29:35 PDT
Fixed up all the GCTimer/GCCounter related structs w/ Darin's suggestions.
Comment 11 WebKit Commit Bot 2015-03-20 19:03:23 PDT
Comment on attachment 248944 [details]
Patch

Clearing flags on attachment: 248944

Committed r181821: <http://trac.webkit.org/changeset/181821>
Comment 12 WebKit Commit Bot 2015-03-20 19:03:29 PDT
All reviewed patches have been landed.  Closing bug.