1306249 - GC_SLOW_PHASE telemetry is not specific enough

Status: RESOLVED FIXED

(Core :: JavaScript: GC, defect, P3)

Description

[Jon Coppeard (:jonco)]

If you look at the telemetry for this it tells you that the longest phase is most often PHASE_SWEEP (but sometimes PHASE_MARK).  While this may be true, it would be more useful to report the longest sub-phase so that we can actually get an idea of where the problems are.  In other words, it should report the longest leaf phase.

Comment 1

[Steve Fink [:sfink] [:s:]]

You're right, that seems obvious in retrospect.

Though not trivially so. Parent phases don't partition *all* of their processing into leaf phases, so it's possible that the interestingly slow part is in the "other" category.

I *think* it'd be enough to treat all parent phases as having an implicit "other" leaf phase within them and taking the longest leaf phase including all "other"s. Then if one of the "other"s is selected, we'd report that parent phase instead of a leaf.

jonco: do you think it would be ok to reuse the same telemetry key (GC_SLOW_PHASE)? We would be changing semantics across versions, but I don't know if it really matters here.

Comment 2

[Jon Coppeard (:jonco)]

(In reply to Steve Fink [:sfink] [:s:] from comment #1)

Yes I think that would be fine.  The current semantics aren't terribly useful right now.

Comment 3

[Steve Fink [:sfink] [:s:]]

Attachment: GC statistics commenting

Took me some time to get reacquainted with this code. I really ought to explicitly expand the full tree and stop doing this weird position tracking. But for now, comment a bit better so I remember what's going on next time.

Comment 4

[Steve Fink [:sfink] [:s:]]

Attachment: Report phase with longest self time, not longest total time

In profiling terminology, we want the phase with the longest "self" time, as opposed to total time (self+children).

With the weird dag setup, it's a little weird finding all children. I really should just explode the dag into a simple tree during initialization, but that's a bigger change than I want here.

Comment 5

[Steve Fink [:sfink] [:s:]]

Attachment: Optimize SumChildTimes by only iterating children

Small optimization, kind of scary because of the funky data structures: rather than iterating over the entire set of phases looking for children of the given parent, use the (preorder) sequence of phases to start at the first child (if any), and also use the stored depth information to stop iterating when we reach a sibling (or the end of the list, or a multiparented phase that will always have depth 0).

Comment 6

[Jon Coppeard (:jonco)]

Comment on attachment 8796696 [details] [diff] [review]
GC statistics commenting

Review of attachment 8796696 [details] [diff] [review]:
-----------------------------------------------------------------

Thanks for adding comments.  I'm not going to pretend I fully understand this but until we can simplify the code having comments is a big improvement.

Comment 7

[Jon Coppeard (:jonco)]

Comment on attachment 8796725 [details] [diff] [review]
Report phase with longest self time, not longest total time

Review of attachment 8796725 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good.

::: js/src/gc/Statistics.cpp
@@ +933,5 @@
> +            // parent.
> +            for (auto edge : dagChildEdges) {
> +                if (edge.parent == parent) {
> +                    size_t dagSlot = phaseExtra[edge.parent].dagSlot;
> +                    selfTimes[parent] -= times[dagSlot][edge.child];

Can you add an assert that we don't underflow here, and below?

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/6bac3fe84c13
GC statistics commenting, r=jonco
https://hg.mozilla.org/integration/mozilla-inbound/rev/327706b55f4e
Report phase with longest self time, not longest total time, r=jonco
https://hg.mozilla.org/integration/mozilla-inbound/rev/a178818363a7
Optimize SumChildTimes by only iterating children, r=jonco

Comment 9

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3b380b931e81
Backed out changeset 327706b55f4e on a CLOSED TREE

Comment 10

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/6bac3fe84c13
https://hg.mozilla.org/mozilla-central/rev/a178818363a7

Comment 11

[Steve Fink [:sfink] [:s:]]

I had to back out the main change for assertion failures, specifically the assertion I added for review comment 7 that the parent phase's elapsed time is greater than the sum of its children.

Thinking about it, I don't think this simple approach can even work. That assertion is invalid, because these numbers are really measuring work (cpu seconds), not time (seconds). As in, it's possible to have multiple threads accumulating time into a child phase, which could then exceed the elapsed time for the parent phase.

Backing up, what if I just did the initial intent of this bug, which is to report the largest leaf time? The concern is that you might have this nesting of times (pretend this is all time, not work):

10 sec
  2 sec
  8 sec
    1 sec

(This doesn't seem all that unlikely, for an 8 second phase that tends to be expensive, but only one small part of it is easily labelable.) In this case, we will report the 2 second phase.

Which is still way better than what we do now, which is to report the 10 second phase.

The easiest way I can think of to figure out actual self time is to measure it directly: rather than starting a timer when a phase starts and adding up elapsed time when it ends, start a timer when the phase starts, stop and accumulate when a child phase starts, restart the timer when the child phase ends, etc. This would need to be in addition to the overall elapsed time, since you can't compute one from the other. ("What a tangled web we weave, when first we practice to weave with threads.")

I'm going to look at how nasty that would be to implement.

Comment 12

[Steve Fink [:sfink] [:s:]]

The above is incorrect. The units are inconsistent. Leaf phases are always cpu seconds, though most leaf phases are mainthread only so cpu seconds is the same as seconds. Parent phases are always seconds (elapsed time between start and end of the phase, which for a non-leaf will always be on the main thread).

It might make sense to track both, since at the moment we are discarding time waiting for helper threads. We are collecting the total cpu seconds they take, but we do not record how long the main thread had to wait to join with them. The parent time will include this wait time, but we can't know whether it was doing some other processing or just waiting.

Another way to skin this cat would be to collect only self time in the tree, by initializing everything to zero (as we do now), but then having children subtract their *elapsed* time from their parent. (So the parent time would go negative for a while, until all its children are done and it finishes, at which time it would add in the total elapsed time and come up with its self time.) But that would just flip the problem around -- now, we wouldn't be able to find the total time for a parent node, because some of its children might be storing work instead of time.

Probably the right thing is to track both.

Comment 13

[Steve Fink [:sfink] [:s:]]

Attachment: Stop recording total time spent in helper threads

Comment 14

[Jon Coppeard (:jonco)]

Comment on attachment 8800450 [details] [diff] [review]
Stop recording total time spent in helper threads

Review of attachment 8800450 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good for now.

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/07c8f7c80bb7
Stop recording total time spent in helper threads, r=jonco
https://hg.mozilla.org/integration/mozilla-inbound/rev/d50a04c82343
Report phase with longest self time, not longest total time, r=jonco

Comment 16

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Backed out for assertions, at least in tests on Windows XP debug:

https://hg.mozilla.org/integration/mozilla-inbound/rev/44a0d38f40e60ddfc4d9b867d35c8b570f1fa704
https://hg.mozilla.org/integration/mozilla-inbound/rev/fea2dc883057d88fc6ae52b7fadcc07e6ab0e5bd

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=d50a04c82343a9fa10bbbb905170c903dac2a197
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=37707075&repo=mozilla-inbound

17:06:01     INFO -  Assertion failure: selfTimes[parent] >= selfTimes[i], at c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/src/js/src/gc/Statistics.cpp:943
17:06:01     INFO -  TEST-INFO | Main app process: exit 1
17:06:01     INFO -  20 INFO TEST-PASS | dom/presentation/tests/mochitest/test_presentation_mixed_security_contexts.html | navigator.presentation should be available.
17:06:01  WARNING -  TEST-UNEXPECTED-FAIL | dom/presentation/tests/mochitest/test_presentation_mixed_security_contexts.html | application terminated with exit code 1
17:06:01     INFO -  runtests.py | Application ran for: 0:00:38.897000
17:06:01     INFO -  zombiecheck | Reading PID log: c:\docume~1\cltbld~1.t-x\locals~1\temp\tmp6vqa3fpidlog
17:06:01     INFO -  ==> process 2452 launched child process 3080 ("C:\slave\test\build\application\firefox\firefox.exe" -contentproc --channel="2452.0.1192429164\1898630460" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser"  2452 "\\.\pipe\gecko-crash-server-pipe.2452" tab)
17:06:01     INFO -  ==> process 2452 launched child process 3532 ("C:\slave\test\build\application\firefox\firefox.exe" -contentproc --channel="2452.5.1548047172\82609101" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser"  2452 "\\.\pipe\gecko-crash-server-pipe.2452" tab)
17:06:01     INFO -  ==> process 2452 launched child process 3960 ("C:\slave\test\build\application\firefox\firefox.exe" -contentproc --channel="2452.10.1788877668\1943614728" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser"  2452 "\\.\pipe\gecko-crash-server-pipe.2452" tab)
17:06:01     INFO -  zombiecheck | Checking for orphan process with PID: 3080
17:06:01     INFO -  zombiecheck | Checking for orphan process with PID: 3532
17:06:01     INFO -  zombiecheck | Checking for orphan process with PID: 3960
17:06:01     INFO -  mozcrash Copy/paste: C:\slave\test\build\win32-minidump_stackwalk.exe c:\docume~1\cltbld~1.t-x\locals~1\temp\tmpj7bqq4.mozrunner\minidumps\1007327d-df3d-43b9-9e12-f6db0fba4105.dmp C:\slave\test\build\symbols
17:06:15     INFO -  mozcrash Saved minidump as C:\slave\test\build\blobber_upload_dir\1007327d-df3d-43b9-9e12-f6db0fba4105.dmp
17:06:15     INFO -  mozcrash Saved app info as C:\slave\test\build\blobber_upload_dir\1007327d-df3d-43b9-9e12-f6db0fba4105.extra
17:06:15  WARNING -  PROCESS-CRASH | dom/presentation/tests/mochitest/test_presentation_mixed_security_contexts.html | application crashed [@ LongestPhaseSelfTime]
17:06:15     INFO -  Crash dump filename: c:\docume~1\cltbld~1.t-x\locals~1\temp\tmpj7bqq4.mozrunner\minidumps\1007327d-df3d-43b9-9e12-f6db0fba4105.dmp
17:06:15     INFO -  Operating system: Windows NT
17:06:15     INFO -                    5.1.2600 Service Pack 3
17:06:15     INFO -  CPU: x86
17:06:15     INFO -       GenuineIntel family 6 model 30 stepping 5
17:06:15     INFO -       8 CPUs
17:06:15     INFO -  GPU: UNKNOWN
17:06:15     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
17:06:15     INFO -  Crash address: 0x5da70db
17:06:15     INFO -  Process uptime: 39 seconds
17:06:15     INFO -  Thread 0 (crashed)
17:06:15     INFO -   0  xul.dll!LongestPhaseSelfTime [Statistics.cpp:d50a04c82343 : 943 + 0x35]
17:06:15     INFO -      eip = 0x05da70db   esp = 0x0012f444   ebp = 0x0012f64c   ebx = 0x00000054
17:06:15     INFO -      esi = 0x0035cf70   edi = 0x00000000   eax = 0x00000000   ecx = 0x003506ef
17:06:15     INFO -      edx = 0x003f5370   efl = 0x00000216
17:06:15     INFO -      Found by: given as instruction pointer in context
17:06:15     INFO -   1  xul.dll!js::gcstats::Statistics::endSlice() [Statistics.cpp:d50a04c82343 : 1107 + 0x11]
17:06:15     INFO -      eip = 0x05daf989   esp = 0x0012f654   ebp = 0x0012f680
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   2  xul.dll!js::gc::GCRuntime::gcCycle(bool,js::SliceBudget &,JS::gcreason::Reason) [jsgc.cpp:d50a04c82343 : 6202 + 0x14]
17:06:15     INFO -      eip = 0x05d39616   esp = 0x0012f688   ebp = 0x0012f700
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   3  xul.dll!js::gc::GCRuntime::collect(bool,js::SliceBudget,JS::gcreason::Reason) [jsgc.cpp:d50a04c82343 : 6318 + 0x16]
17:06:15     INFO -      eip = 0x05d2c4a6   esp = 0x0012f708   ebp = 0x0012f778
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   4  xul.dll!js::gc::GCRuntime::gcSlice(JS::gcreason::Reason,__int64) [jsgc.cpp:d50a04c82343 : 6405 + 0x21]
17:06:15     INFO -      eip = 0x05d3972f   esp = 0x0012f780   ebp = 0x0012f7ac
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   5  xul.dll!JS::IncrementalGCSlice(JSContext *,JS::gcreason::Reason,__int64) [jsgc.cpp:d50a04c82343 : 7231 + 0x17]
17:06:15     INFO -      eip = 0x05d1177a   esp = 0x0012f7b4   ebp = 0x0012f7c0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   6  xul.dll!nsJSContext::GarbageCollectNow(JS::gcreason::Reason,nsJSContext::IsIncremental,nsJSContext::IsShrinking,__int64) [nsJSEnvironment.cpp:d50a04c82343 : 1201 + 0x14]
17:06:15     INFO -      eip = 0x0403a58b   esp = 0x0012f7c8   ebp = 0x0012f7f0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   7  xul.dll!InterSliceGCTimerFired(nsITimer *,void *) [nsJSEnvironment.cpp:d50a04c82343 : 1723 + 0xf]
17:06:15     INFO -      eip = 0x0403e51d   esp = 0x0012f7f8   ebp = 0x0012f87c
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   8  xul.dll!nsTimerImpl::Fire() [nsTimerImpl.cpp:d50a04c82343 : 480 + 0x9]
17:06:15     INFO -      eip = 0x03350a41   esp = 0x0012f810   ebp = 0x0012f87c
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   9  xul.dll!nsTimerEvent::Run() [TimerThread.cpp:d50a04c82343 : 289 + 0xe]
17:06:15     INFO -      eip = 0x0334ac60   esp = 0x0012f884   ebp = 0x0012f8b4
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  10  xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:d50a04c82343 : 1082 + 0xe]
17:06:15     INFO -      eip = 0x0334798b   esp = 0x0012f8bc   ebp = 0x0012f928
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  11  xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:d50a04c82343 : 290 + 0xd]
17:06:15     INFO -      eip = 0x0336f0b6   esp = 0x0012f930   ebp = 0x0012f93c
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  12  xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [MessagePump.cpp:d50a04c82343 : 124 + 0x8]
17:06:15     INFO -      eip = 0x0371544b   esp = 0x0012f944   ebp = 0x0012f968
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  13  xul.dll!MessageLoop::RunInternal() [message_loop.cc:d50a04c82343 : 232 + 0xf]
17:06:15     INFO -      eip = 0x036f3a46   esp = 0x0012f970   ebp = 0x0012f988
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  14  xul.dll!MessageLoop::RunHandler() [message_loop.cc:d50a04c82343 : 225 + 0x5]
17:06:15     INFO -      eip = 0x036f39fe   esp = 0x0012f990   ebp = 0x0012f9bc
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  15  xul.dll!MessageLoop::Run() [message_loop.cc:d50a04c82343 : 205 + 0x7]
17:06:15     INFO -      eip = 0x036f3749   esp = 0x0012f9c4   ebp = 0x0012f9dc
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  16  xul.dll!nsBaseAppShell::Run() [nsBaseAppShell.cpp:d50a04c82343 : 156 + 0xc]
17:06:15     INFO -      eip = 0x04f9f473   esp = 0x0012f9e4   ebp = 0x0012f9ec
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  17  xul.dll!nsAppShell::Run() [nsAppShell.cpp:d50a04c82343 : 262 + 0x8]
17:06:15     INFO -      eip = 0x04ff40e2   esp = 0x0012f9f4   ebp = 0x0012f9fc
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  18  xul.dll!nsAppStartup::Run() [nsAppStartup.cpp:d50a04c82343 : 283 + 0x12]
17:06:15     INFO -      eip = 0x0574295b   esp = 0x0012fa04   ebp = 0x0012fa10
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  19  xul.dll!XREMain::XRE_mainRun() [nsAppRunner.cpp:d50a04c82343 : 4450 + 0x11]
17:06:15     INFO -      eip = 0x0579eb94   esp = 0x0012fa18   ebp = 0x0012fbf0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  20  xul.dll!XREMain::XRE_main(int,char * * const,nsXREAppData const *) [nsAppRunner.cpp:d50a04c82343 : 4583 + 0x7]
17:06:15     INFO -      eip = 0x0579cc02   esp = 0x0012fbf8   ebp = 0x0012fc20
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  21  xul.dll!XRE_main [nsAppRunner.cpp:d50a04c82343 : 4674 + 0x10]
17:06:15     INFO -      eip = 0x0579f8f8   esp = 0x0012fc28   ebp = 0x0012fd40
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  22  firefox.exe!do_main [nsBrowserApp.cpp:d50a04c82343 : 282 + 0x16]
17:06:15     INFO -      eip = 0x00401cd5   esp = 0x0012fd48   ebp = 0x0012fedc
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  23  firefox.exe!NS_internal_main(int,char * *,char * *) [nsBrowserApp.cpp:d50a04c82343 : 415 + 0xf]
17:06:15     INFO -      eip = 0x00401664   esp = 0x0012fee4   ebp = 0x0012ff38
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  24  firefox.exe!wmain [nsWindowsWMain.cpp:d50a04c82343 : 115 + 0xf]
17:06:15     INFO -      eip = 0x0040208e   esp = 0x0012ff40   ebp = 0x0012ff78
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  25  firefox.exe!__scrt_common_main_seh [exe_common.inl : 253 + 0x1d]
17:06:15     INFO -      eip = 0x00432ba7   esp = 0x0012ff80   ebp = 0x0012ffc0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  26  kernel32.dll!BaseProcessStart + 0x23
17:06:15     INFO -      eip = 0x7c817067   esp = 0x0012ffc8   ebp = 0x0012fff0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -  Thread 1
17:06:15     INFO -   0  ntdll.dll!KiFastSystemCallRet + 0x0
17:06:15     INFO -      eip = 0x7c90e4f4   esp = 0x0178fe74   ebp = 0x0178fea0   ebx = 0x00000000
17:06:15     INFO -      esi = 0x00000000   edi = 0x009280b0   eax = 0xffffffff   ecx = 0x00000000
17:06:15     INFO -      edx = 0x00800044   efl = 0x00000246
17:06:15     INFO -      Found by: given as instruction pointer in context
17:06:15     INFO -   1  ntdll.dll!ZwRemoveIoCompletion + 0xc
17:06:15     INFO -      eip = 0x7c90da2c   esp = 0x0178fe78   ebp = 0x0178fea0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   2  kernel32.dll!GetQueuedCompletionStatus + 0x29
17:06:15     INFO -      eip = 0x7c80a7d6   esp = 0x0178fe7c   ebp = 0x0178fea0
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   3  firefox.exe!sandbox::BrokerServicesBase::TargetEventsThread(void *) [broker_services.cc:d50a04c82343 : 205 + 0x17]
17:06:15     INFO -      eip = 0x0041b537   esp = 0x0178fea8   ebp = 0x0178ffb4
17:06:15     INFO -      Found by: call frame info
17:06:15     INFO -   4  kernel32.dll!BaseThreadStart + 0x37
17:06:15     INFO -      eip = 0x7c80b713   esp = 0x0178ffbc   ebp = 0x0178ffec
17:06:15     INFO -      Found by: call frame info

Comment 17

[Steve Fink [:sfink] [:s:]]

Attachment: Diagnostics on phase times

Jon - here's another patch I never managed to land. When I landed, XP debug had a couple of tests that were still finding child time > parent time in the phase timing tree. This patch adds some diagnostics to print out which phases are involved and what the values are, but I haven't managed to get it to fail with it applied. If I were to be around for a while, I might try talking a sheriff into letting me re-land with the diagnostics, and immediately backing out once the first failure was seen.

Comment 18

[Steve Fink [:sfink] [:s:]]

Attachment: Diagnostics on phase times

This is a temporary diagnostics patch. I've pushed it to try and retriggered 20 times or so, but I cannot get the XP problem to reproduce (that's what this was backed out for.) I plan to re-land and wait for the intermittents.

Comment 19

[Jon Coppeard (:jonco)]

Comment on attachment 8815934 [details] [diff] [review]
Diagnostics on phase times

Review of attachment 8815934 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good.  Hopefully this will shed some light.

::: js/src/gc/Statistics.cpp
@@ +974,5 @@
>                  }
>              }
>          } else if (parent != PHASE_NO_PARENT) {
>              MOZ_ASSERT(selfTimes[parent] >= selfTimes[i]);
> +            CheckSelfTime(parent, Phase(i), times, selfTimes, selfTimes[i]);

I think this wants to go before the assert.

Comment 20

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Steve, could you land the first patch here separately? That way, at worst, only the second patch will be backed out. The first patch is useful by itself, and I don't think it should make anything worse.

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ea9daa6066fd
Stop recording total time spent in helper threads, r=jonco

Comment 22

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/ea9daa6066fd

Comment 23

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/0be0ff95cd92
Report phase with longest self time, not longest total time, r=jonco
https://hg.mozilla.org/integration/mozilla-inbound/rev/74e5e72b3722
Diagnostics on phase times, r=jonco

Comment 24

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/0be0ff95cd92
https://hg.mozilla.org/mozilla-central/rev/74e5e72b3722

Comment 25

[BugBot [:suhaib / :marco/ :calixte]]

The leave-open keyword is there and there is no activity for 6 months.
:sfink, maybe it's time to close this bug?

Comment 26

[Steve Fink [:sfink] [:s:]]

Yes, most of these were invalidated by jonco's rewriting of phase handling (thankfully). The useful remaining bits have landed.