Rewrite gc::Statistics to materialize a simple tree

RESOLVED FIXED in Firefox 55

Status

()

RESOLVED FIXED
2 years ago
a year ago

People

(Reporter: sfink, Assigned: jonco, NeedInfo)

Tracking

unspecified
mozilla55
Points:
---

Firefox Tracking Flags

(firefox55 fixed)

Details

Attachments

(1 attachment, 3 obsolete attachments)

(Reporter)

Description

2 years ago
Currently, the GC statistics encode a restricted dag into a pair of data structures: one is a basic tree, with single parent pointers on each node (phases[].parent). Then for every node that has multiple parents in the dag, phases[i].parent is set to PHASE_MULTI_PARENTS and a separate dagChildEdges table is consulted, which just has a simple list of <parent,child> tuples.

That wouldn't be so bad, but the timings are stored in a set of parallel arrays. Index 0 is for the "main" tree. Index i > 0 is used for the descendants of one of the multi-parented subtrees (dagChildEdges gives you which index to use.) This is a waste of space and a source of substantial complexity. It would be much better to give up on simple static initialization, and instead materialize the whole tree. For some purposes, we would still need to collapse time spent in a given phase that shows up multiple places in the tree, so we would need a way to look those up. But that's much simpler than the current scheme.
(Assignee)

Updated

2 years ago
Assignee: nobody → jcoppeard
(Assignee)

Comment 1

2 years ago
Created attachment 8866844 [details] [diff] [review]
bug1361458-stats-phases

This turned out to be a larger project that I realised.

Declaring tree-like data structures in C++ turns out to be really annoying so I wrote a python script to generate all the data at compile time (expressing the phase graph in python is much more natural).

With this patch with have parallel Phase and ExpandedPhase enums, with the former being used for the API and the latter used internally.  There is an info table for expanded phases which is constant data so there's no need to create this on initialisation.  This contains the navigation structure for the expanded tree so you can iterate children, all expanded phases with the same phase, etc.

There are a couple of improvements I'd like to make to this but I thought I'd post it to get your thoughts first.

One big thing is that the names are now quite clunky having 'expanded' everywhere.  I was considering changing Phase to PhaseId and ExpandedPhase to just Phase but any suggestions would be welcome.

We can abstract the iteration over phase children etc too to tidy this up a bit.
Attachment #8866844 - Flags: feedback?(sphink)
(Reporter)

Comment 2

a year ago
Comment on attachment 8866844 [details] [diff] [review]
bug1361458-stats-phases

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

I think this will work, and I like having it data-driven rather than forcing it into what can be done with static C++ initializers or whatever.

ExpandedPhase is pretty long. Maybe PhaseSpec or PhaseType for the current Phase, and Phase for ExpandedPhase?

::: js/src/gc/GenerateStatsPhases.py
@@ +4,5 @@
> +
> +# Generate graph structures for GC statistics recording.
> +#
> +# Stats phases are nested and form a directed acyclic graph starting
> +# from a set of root phases. Importantly, a phe a phase may appear under

s/a phe //

@@ +5,5 @@
> +# Generate graph structures for GC statistics recording.
> +#
> +# Stats phases are nested and form a directed acyclic graph starting
> +# from a set of root phases. Importantly, a phe a phase may appear under
> +# more that one parent phase.

*than

@@ +34,5 @@
> +#       |       |         |      |         |
> +#       v       v         v      v         v
> +#     +---+   +---+     +---+  +---+     +---+
> +#     | B |   | D |     | E |  | I |     | I'|
> +#     +---+   +---+     +---+  +---+     +---+

Hm. The canonical example I would expect is more like

A -> B
A -> C
A -> D
C -> E
D -> E

@@ +157,5 @@
> +    return phases
> +
> +AllPhases = findAllPhases()
> +
> +# Expand the DAG is into a tree, duplicating phases which have more than

s/ is//

@@ +206,5 @@
> +    if len(expandedPhases) == 1:
> +        expandedPhases[0].name = "EXPANDED_%s" % phase.name
> +    else:
> +        for index, xphase in enumerate(expandedPhases):
> +            xphase.name = "EXPANDED_%s_%d" % (phase.name, index + 1)

What are these names used for? Would it be better to name these by the full path from the root, maybe with double underscores or something between them? (Or do we need them at all?)

@@ +214,5 @@
> +def writeList(out, items):
> +    length = len(items)
> +    for index, item in enumerate(items):
> +        separator = "," if index < length - 1 else ""
> +        out.write("    %s%s\n" % (item, separator))

Totally doesn't matter, but I usually do this with

    if items:
        out.write("  " + ",\n  ".join(items) + "\n")

or if the indenting part seems too clever or redundant

    if items:
        out.write(",\n".join("  " + item for item in items) + "\n")

::: js/src/gc/Statistics.cpp
@@ +884,3 @@
>      }
>      runtime->addTelemetry(JS_TELEMETRY_GC_MARK_ROOTS_MS, t(markRootsTotal));
> +    runtime->addTelemetry(JS_TELEMETRY_GC_MARK_GRAY_MS, t(phaseTimes[EXPANDED_PHASE_SWEEP_MARK_GRAY]));

For this patch, this is fine, but what should we be reporting here? Should we be reported the gray marking under barriers?
Attachment #8866844 - Flags: feedback?(sphink) → feedback+
(Assignee)

Comment 3

a year ago
(In reply to Steve Fink [:sfink] [:s:] from comment #2)
Thanks for the feedback.

> What are these names used for? Would it be better to name these by the full
> path from the root, maybe with double underscores or something between them?
> (Or do we need them at all?)

There are a couple of places we refer to the expanded phases, e.g. EXPANDED_PHASE_SWEEP in Statistics::endGC so we need some fairly simple name for these.

> Totally doesn't matter, but I usually do this with
> ...
>     if items:
>         out.write(",\n".join("  " + item for item in items) + "\n")

Thanks, that's much nicer.

> For this patch, this is fine, but what should we be reporting here? Should
> we be reported the gray marking under barriers?

It would be good to report that too, but separately I think.
(Assignee)

Comment 4

a year ago
Created attachment 8867649 [details] [diff] [review]
bug1361458-stats-phases v2

Here's the updated patch with review feedback applied.  Renaming to follow in a separate patch.
Attachment #8866844 - Attachment is obsolete: true
Attachment #8867649 - Flags: review?(sphink)
(Assignee)

Comment 5

a year ago
Created attachment 8867651 [details] [diff] [review]
bug1361458-stats-rename

Rename Phase to PhaseKind and make it an enum class.
Rename ExpandedPhase to Phase and make that an enum class too.

I'll squash these together when landing.
Attachment #8867651 - Flags: review?(sphink)
(Reporter)

Comment 6

a year ago
Comment on attachment 8867649 [details] [diff] [review]
bug1361458-stats-phases v2

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

Excellent! Thanks for doing this.

::: js/src/gc/GenerateStatsPhases.py
@@ +59,5 @@
> +        self.bucket = bucket
> +        self.children = children
> +
> +# The root marking phase appears in several places in the graph.
> +MarkRootsPhase = Phase("PHASE_MARK_ROOTS", "Mark Roots", 48, [

For better or for worse, we can now add more common subtrees to the graph. And even nest them. I don't know whether it's a good idea, though.

::: js/src/gc/Statistics.cpp
@@ +128,2 @@
>  {
> +    return phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : EXPANDED_PHASE_NONE;

This would be so much nicer as phaseStack.empty() ? EXPANDED_PHASE_NONE : phaseStack.back()

@@ +145,3 @@
>  
> +ExpandedPhase
> +Statistics::expandedPhase(Phase phase) const

Hm. Maybe this could be called expandedChildPhase()? (And eventually just childPhase()).

Interestingly, this shows up a remaining limitation of the tree structure -- you can't have multiple copies of a phase (and its subtree, if any) underneath one phase kind. But that seems like a good thing.

This is really a multipart key lookup. If you wanted to make this constant time, you could make this into a two-level table lookup. Something like:

  if nextInPhase == EXPANDED_PHASE_NONE
    return firstExpandedPhase
  else
    return multiparented[phases[currentExpandedPhase()].phase][phase];

or something. (They could go the other way around, too.) With asserts in place so you only have to allocate the needed tables.

Or you could go really crazy and generate a perfect hash in the Python code, a la gperf. Then this would be something like

  if nextInPhase == EXPANDED_PHASE_NONE
    return firstExpandedPhase
  else
    return perfect_table[hash(phases[currentExpandedPhase()].phase, phase];

I wonder if the compiler would do anything fancy like that with a 2-level switch statement? Probably not.

@@ +215,5 @@
>      }
>  
>      char* joined = js_pod_malloc<char>(length + 1);
> +    if (!joined)
> +        return UniqueChars();

Oops!

@@ +1021,5 @@
> +        auto mutatorTime = phaseTimes[EXPANDED_PHASE_MUTATOR];
> +        PodZero(&phaseStartTimes);
> +        PodZero(&phaseTimes);
> +        phaseStartTimes[EXPANDED_PHASE_MUTATOR] = mutatorStartTime;
> +        phaseTimes[EXPANDED_PHASE_MUTATOR] = mutatorTime;

Hah! Nice way to sidestep the complexity.

::: js/src/gc/Statistics.h
@@ +305,1 @@
>      size_t phaseNestingDepth;

Doesn't have to be this patch, but maybe file a bug for changing this to

  Vector<ExpandedPhase, MAX_NESTING, DummyAllocatorThatAlwaysAsserts> phaseStack;

Or just let the allocator be anything, and assert length < MAX_NESTING after pushing.

And MAX_NESTING should be generated by your python script.

@@ +315,1 @@
>      size_t suspended;

More complexity that it would be nice to eliminate. I guess it could at least be an array/vector of the phaseStack type from above, and then we'd copy the old stack over.

Hm, I guess we could even use a move constructor to copy away the stack, then allocate a new empty stack and move it into phaseStack? Then it would be cheap. Or we could make phaseStack into phaseStacks and normally look at the top stack of stacks.

@@ +345,5 @@
>      ProfileDurations totalTimes_;
>      uint64_t sliceCount_;
>  
> +    ExpandedPhase currentExpandedPhase() const;
> +    ExpandedPhase expandedPhase(Phase phase) const;

expandedPhase(Phase) is a very weird function that obscures the data model (what? you can get from a Phase to an ExpandedPhase?) and does not look like it would consult state info (currentPhase). It should be renamed and commented.
Attachment #8867649 - Flags: review?(sphink) → review+
(Reporter)

Updated

a year ago
Attachment #8867651 - Flags: review?(sphink) → review+
(Reporter)

Comment 7

a year ago
Comment on attachment 8867649 [details] [diff] [review]
bug1361458-stats-phases v2

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

::: js/src/gc/GenerateStatsPhases.py
@@ +59,5 @@
> +        self.bucket = bucket
> +        self.children = children
> +
> +# The root marking phase appears in several places in the graph.
> +MarkRootsPhase = Phase("PHASE_MARK_ROOTS", "Mark Roots", 48, [

Oops, forgot to go back and update this comment now that I know how you're doing the child phase lookup. You still can't nest them. Oh well.
(Assignee)

Comment 8

a year ago
(In reply to Steve Fink [:sfink] [:s:] from comment #6)
> ::: js/src/gc/Statistics.cpp
> @@ +128,2 @@
> >  {
> > +    return phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : EXPANDED_PHASE_NONE;
> 
> This would be so much nicer as phaseStack.empty() ? EXPANDED_PHASE_NONE :
> phaseStack.back()

Filed followup bug 1365539.

> Hm. Maybe this could be called expandedChildPhase()? (And eventually just
> childPhase()).

You're right it's a weird name.  I'll call it lookupChildPhase in the final version.

> This is really a multipart key lookup. If you wanted to make this constant
> time, you could make this into a two-level table lookup.

I considered doing this originally but it ended up more complicated of the extra tables that need to be generated.  We could still do this if you think it's worth it.
(Assignee)

Comment 9

a year ago
Created attachment 8868468 [details] [diff] [review]
bug1361458-stats-phases v3

Updated combined patch.
Attachment #8867649 - Attachment is obsolete: true
Attachment #8867651 - Attachment is obsolete: true
Attachment #8868468 - Flags: review+

Comment 10

a year ago
Pushed by jcoppeard@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/36f2908f6650
Generate the phase tree for GC statistics recording ahead of time r=sfink
Backed out for crashing [@ js::GCMarker::drainMarkStack], e.g. in devtools' devtools/client/debugger/new/test/mochitest/browser_dbg-sourcemaps.js:

https://hg.mozilla.org/integration/mozilla-inbound/rev/1627485da92e28dcb2513f631eaedf44826574a2

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=36f2908f6650129ababf0665d8d5be185d31f5b2&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=99727001&repo=mozilla-inbound

[task 2017-05-17T10:32:55.737106Z] 10:32:55     INFO - Console message: [JavaScript Warning: "Unknown property ‘user-select’.  Declaration dropped." {file: "resource://devtools/client/debugger/new/debugger.css" line: 2372 column: 13 source: "  user-select: none;"}]
[task 2017-05-17T10:32:55.737887Z] 10:32:55     INFO - Console message: [JavaScript Warning: "Unknown property ‘user-select’.  Declaration dropped." {file: "resource://devtools/client/debugger/new/debugger.css" line: 2390 column: 13 source: "  user-select: none;"}]
[task 2017-05-17T10:32:55.738507Z] 10:32:55     INFO - Console message: [JavaScript Warning: "Unknown property ‘user-select’.  Declaration dropped." {file: "resource://devtools/client/debugger/new/debugger.css" line: 2428 column: 13 source: "  user-select: none;"}]
[task 2017-05-17T10:32:55.739312Z] 10:32:55     INFO - Buffered messages finished
[task 2017-05-17T10:32:55.739930Z] 10:32:55    ERROR - TEST-UNEXPECTED-FAIL | devtools/client/debugger/new/test/mochitest/browser_dbg-sources.js | application terminated with exit code 11
[task 2017-05-17T10:32:55.740861Z] 10:32:55     INFO - runtests.py | Application ran for: 0:01:24.748561
[task 2017-05-17T10:32:55.741493Z] 10:32:55     INFO - zombiecheck | Reading PID log: /tmp/tmpKWGvPwpidlog
[task 2017-05-17T10:32:55.742256Z] 10:32:55     INFO - ==> process 1950 launched child process 1972
[task 2017-05-17T10:32:55.743232Z] 10:32:55     INFO - zombiecheck | Checking for orphan process with PID: 1972
[task 2017-05-17T10:32:55.744023Z] 10:32:55     INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/M3ewPd9HTdGpySQ4zsuUhQ/artifacts/public/build/target.crashreporter-symbols.zip
[task 2017-05-17T10:33:00.866976Z] 10:33:00     INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpBXQWrU.mozrunner/minidumps/44c23ce4-2c05-c476-7cf4-5c44ca911619.dmp /tmp/tmpkZ5jop
[task 2017-05-17T10:33:06.897683Z] 10:33:06     INFO - mozcrash Saved minidump as /home/worker/workspace/build/blobber_upload_dir/44c23ce4-2c05-c476-7cf4-5c44ca911619.dmp
[task 2017-05-17T10:33:06.898799Z] 10:33:06     INFO - mozcrash Saved app info as /home/worker/workspace/build/blobber_upload_dir/44c23ce4-2c05-c476-7cf4-5c44ca911619.extra
[task 2017-05-17T10:33:07.383640Z] 10:33:07     INFO - PROCESS-CRASH | devtools/client/debugger/new/test/mochitest/browser_dbg-sources.js | application crashed [@ mozilla::CycleCollectedJSRuntime::OnGC]
[task 2017-05-17T10:33:07.384863Z] 10:33:07     INFO - Crash dump filename: /tmp/tmpBXQWrU.mozrunner/minidumps/44c23ce4-2c05-c476-7cf4-5c44ca911619.dmp
[task 2017-05-17T10:33:07.385741Z] 10:33:07     INFO - Operating system: Linux
[task 2017-05-17T10:33:07.386343Z] 10:33:07     INFO -                   0.0.0 Linux 3.13.0-112-generic #159-Ubuntu SMP Fri Mar 3 15:26:07 UTC 2017 x86_64
[task 2017-05-17T10:33:07.386935Z] 10:33:07     INFO - CPU: amd64
[task 2017-05-17T10:33:07.387605Z] 10:33:07     INFO -      family 6 model 62 stepping 4
[task 2017-05-17T10:33:07.388103Z] 10:33:07     INFO -      2 CPUs
[task 2017-05-17T10:33:07.388731Z] 10:33:07     INFO - 
[task 2017-05-17T10:33:07.389291Z] 10:33:07     INFO - GPU: UNKNOWN
[task 2017-05-17T10:33:07.389898Z] 10:33:07     INFO - 
[task 2017-05-17T10:33:07.390473Z] 10:33:07     INFO - Crash reason:  SIGSEGV
[task 2017-05-17T10:33:07.391040Z] 10:33:07     INFO - Crash address: 0x7f84a719f034
[task 2017-05-17T10:33:07.391626Z] 10:33:07     INFO - Process uptime: not available
[task 2017-05-17T10:33:07.392211Z] 10:33:07     INFO - 
[task 2017-05-17T10:33:07.392827Z] 10:33:07     INFO - Thread 0 (crashed)
[task 2017-05-17T10:33:07.393480Z] 10:33:07     INFO -  0  libxul.so!mozilla::CycleCollectedJSRuntime::OnGC [CycleCollectedJSRuntime.cpp:36f2908f6650 : 1436 + 0x0]
[task 2017-05-17T10:33:07.394207Z] 10:33:07     INFO -     rax = 0x00007f8489b6d000   rdx = 0x0000000000000001
[task 2017-05-17T10:33:07.394836Z] 10:33:07     INFO -     rcx = 0x0000000000000000   rbx = 0x00007f84a719ef7c
[task 2017-05-17T10:33:07.395532Z] 10:33:07     INFO -     rsi = 0x00007f8489b6d000   rdi = 0x00007f84a719ef7c
[task 2017-05-17T10:33:07.396164Z] 10:33:07     INFO -     rbp = 0x00007fffda0dc5b0   rsp = 0x00007fffda0dc590
[task 2017-05-17T10:33:07.396885Z] 10:33:07     INFO -      r8 = 0x0000000000000000    r9 = 0x00007f8435511000
[task 2017-05-17T10:33:07.397439Z] 10:33:07     INFO -     r10 = 0x0000000000000008   r11 = 0x0000000000000246
[task 2017-05-17T10:33:07.398045Z] 10:33:07     INFO -     r12 = 0x0000000000000001   r13 = 0x00007f8491445340
[task 2017-05-17T10:33:07.398637Z] 10:33:07     INFO -     r14 = 0x0000000000000000   r15 = 0x00007f8489b65468
[task 2017-05-17T10:33:07.399200Z] 10:33:07     INFO -     rip = 0x00007f848e628fd1
[task 2017-05-17T10:33:07.399753Z] 10:33:07     INFO -     Found by: given as instruction pointer in context
[task 2017-05-17T10:33:07.400320Z] 10:33:07     INFO -  1  libxul.so!js::gc::GCRuntime::gcCycle [jsgc.cpp:36f2908f6650 : 1461 + 0xe]
[task 2017-05-17T10:33:07.400912Z] 10:33:07     INFO -     rbx = 0x00007f84a719ef7c   rbp = 0x00007fffda0dc6a0
[task 2017-05-17T10:33:07.401505Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc5c0   r12 = 0x00007f848e62906c
[task 2017-05-17T10:33:07.402259Z] 10:33:07     INFO -     r13 = 0x00007f8491445340   r14 = 0x0000000000000000
[task 2017-05-17T10:33:07.402867Z] 10:33:07     INFO -     r15 = 0x00007f8489b65468   rip = 0x00007f8490a61091
[task 2017-05-17T10:33:07.403454Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.404059Z] 10:33:07     INFO -  2  libxul.so!js::gc::GCRuntime::collect [jsgc.cpp:36f2908f6650 : 6656 + 0xb]
[task 2017-05-17T10:33:07.404656Z] 10:33:07     INFO -     rbx = 0x00007f8489b65410   rbp = 0x00007fffda0dc750
[task 2017-05-17T10:33:07.405249Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc6b0   r12 = 0x0000000000000000
[task 2017-05-17T10:33:07.405875Z] 10:33:07     INFO -     r13 = 0x00007f8489b65000   r14 = 0x00007fffda0dc6e0
[task 2017-05-17T10:33:07.406516Z] 10:33:07     INFO -     r15 = 0x0000000000000000   rip = 0x00007f8490a6150c
[task 2017-05-17T10:33:07.407110Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.407760Z] 10:33:07     INFO -  3  libxul.so!js::gc::GCRuntime::finishGC [jsgc.cpp:36f2908f6650 : 6761 + 0x11]
[task 2017-05-17T10:33:07.408471Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dc7a0
[task 2017-05-17T10:33:07.409172Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc760   r12 = 0x00007f8489b6d000
[task 2017-05-17T10:33:07.409833Z] 10:33:07     INFO -     r13 = 0x00007f8490b16b10   r14 = 0x00007f843e5af800
[task 2017-05-17T10:33:07.410520Z] 10:33:07     INFO -     r15 = 0x00007f8489b65000   rip = 0x00007f8490a617f1
[task 2017-05-17T10:33:07.411211Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.411833Z] 10:33:07     INFO -  4  libxul.so!js::gc::FinishGC [jsgc.cpp:36f2908f6650 : 7592 + 0x15]
[task 2017-05-17T10:33:07.412414Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dc7e0
[task 2017-05-17T10:33:07.413029Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc7b0   r12 = 0x00007f8489b6d000
[task 2017-05-17T10:33:07.413776Z] 10:33:07     INFO -     r13 = 0x00007f8490b16b10   r14 = 0x00007f843e5af800
[task 2017-05-17T10:33:07.414384Z] 10:33:07     INFO -     r15 = 0x00007f8489b65000   rip = 0x00007f8490a61847
[task 2017-05-17T10:33:07.415045Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.415731Z] 10:33:07     INFO -  5  libxul.so!js::gc::AutoPrepareForTracing::AutoPrepareForTracing [jsgc.cpp:36f2908f6650 : 6955 + 0x8]
[task 2017-05-17T10:33:07.416362Z] 10:33:07     INFO -     rbx = 0x00007fffda0dc850   rbp = 0x00007fffda0dc810
[task 2017-05-17T10:33:07.417001Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc7f0   r12 = 0x00007f8489b6d000
[task 2017-05-17T10:33:07.417664Z] 10:33:07     INFO -     r13 = 0x00007f8490b16b10   r14 = 0x00007f843e5af800
[task 2017-05-17T10:33:07.418303Z] 10:33:07     INFO -     r15 = 0x00007f8489b65000   rip = 0x00007f8490a6191f
[task 2017-05-17T10:33:07.418894Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.419503Z] 10:33:07     INFO -  6  libxul.so!js::IterateScripts [Iteration.cpp:36f2908f6650 : 89 + 0x1e]
[task 2017-05-17T10:33:07.420228Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dc950
[task 2017-05-17T10:33:07.420876Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc820   r12 = 0x00007fffda0dca40
[task 2017-05-17T10:33:07.421607Z] 10:33:07     INFO -     r13 = 0x00007f8490b16b10   r14 = 0x00007f843e5af800
[task 2017-05-17T10:33:07.422309Z] 10:33:07     INFO -     r15 = 0x00007f8489b65000   rip = 0x00007f8490d4140d
[task 2017-05-17T10:33:07.423002Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.423489Z] 10:33:07     INFO -  7  libxul.so!js::Debugger::ScriptQuery::findScripts [Debugger.cpp:36f2908f6650 : 4374 + 0x8]
[task 2017-05-17T10:33:07.428549Z] 10:33:07     INFO -     rbx = 0x00007f846088a600   rbp = 0x00007fffda0dc9c0
[task 2017-05-17T10:33:07.429700Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc960   r12 = 0x00007fffda0dca40
[task 2017-05-17T10:33:07.430592Z] 10:33:07     INFO -     r13 = 0x00007f846088a600   r14 = 0x00007f84414dc800
[task 2017-05-17T10:33:07.431315Z] 10:33:07     INFO -     r15 = 0x00007f8489b65000   rip = 0x00007f8490b23f34
[task 2017-05-17T10:33:07.431963Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.432672Z] 10:33:07     INFO -  8  libxul.so!js::Debugger::findScripts [Debugger.cpp:36f2908f6650 : 4678 + 0x8]
[task 2017-05-17T10:33:07.433366Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dcbc0
[task 2017-05-17T10:33:07.434086Z] 10:33:07     INFO -     rsp = 0x00007fffda0dc9d0   r12 = 0x00007fffda0dca40
[task 2017-05-17T10:33:07.434787Z] 10:33:07     INFO -     r13 = 0x00007f8489b65000   r14 = 0x00007f84414dc800
[task 2017-05-17T10:33:07.435537Z] 10:33:07     INFO -     r15 = 0x00007f8489b65000   rip = 0x00007f8490b4dff9
[task 2017-05-17T10:33:07.436160Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.437279Z] 10:33:07     INFO -  9  libxul.so!js::InternalCallOrConstruct [jscntxtinlines.h:36f2908f6650 : 293 + 0x6]
[task 2017-05-17T10:33:07.438014Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dcc80
[task 2017-05-17T10:33:07.438661Z] 10:33:07     INFO -     rsp = 0x00007fffda0dcbd0   r12 = 0x00007f8489b65000
[task 2017-05-17T10:33:07.439662Z] 10:33:07     INFO -     r13 = 0x00007fffda0dcd60   r14 = 0x00007fffda0dcc10
[task 2017-05-17T10:33:07.440399Z] 10:33:07     INFO -     r15 = 0x00007f8490b4dc60   rip = 0x00007f8490738dfe
[task 2017-05-17T10:33:07.441041Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.441756Z] 10:33:07     INFO - 10  libxul.so!js::Call [Interpreter.cpp:36f2908f6650 : 534 + 0x5]
[task 2017-05-17T10:33:07.442526Z] 10:33:07     INFO -     rbx = 0x00007fffda0dcd60   rbp = 0x00007fffda0dcca0
[task 2017-05-17T10:33:07.443168Z] 10:33:07     INFO -     rsp = 0x00007fffda0dcc90   r12 = 0x00007fffda0dd2e0
[task 2017-05-17T10:33:07.444161Z] 10:33:07     INFO -     r13 = 0x00007fffda0dcd60   r14 = 0x00007fffda0dcce0
[task 2017-05-17T10:33:07.444909Z] 10:33:07     INFO -     r15 = 0x0000000000000000   rip = 0x00007f8490739419
[task 2017-05-17T10:33:07.445546Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.446696Z] 10:33:07     INFO - 11  libxul.so!js::Wrapper::call [Wrapper.cpp:36f2908f6650 : 166 + 0x9]
[task 2017-05-17T10:33:07.447521Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dce20
[task 2017-05-17T10:33:07.448308Z] 10:33:07     INFO -     rsp = 0x00007fffda0dccb0   r12 = 0x00007fffda0dcea0
[task 2017-05-17T10:33:07.449095Z] 10:33:07     INFO -     r13 = 0x00007fffda0dcd60   r14 = 0x00007fffda0dcce0
[task 2017-05-17T10:33:07.449904Z] 10:33:07     INFO -     r15 = 0x0000000000000000   rip = 0x00007f8490ab465f
[task 2017-05-17T10:33:07.450702Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.451533Z] 10:33:07     INFO - 12  libxul.so!js::CrossCompartmentWrapper::call [CrossCompartmentWrapper.cpp:36f2908f6650 : 353 + 0x12]
[task 2017-05-17T10:33:07.452300Z] 10:33:07     INFO -     rbx = 0x0000000000000000   rbp = 0x00007fffda0dce90
[task 2017-05-17T10:33:07.453077Z] 10:33:07     INFO -     rsp = 0x00007fffda0dce30   r12 = 0x00007f8489b6d000
[task 2017-05-17T10:33:07.453914Z] 10:33:07     INFO -     r13 = 0x00007fffda0dcef0   r14 = 0x00007f846c575000
[task 2017-05-17T10:33:07.454712Z] 10:33:07     INFO -     r15 = 0x00007fffda0dcea0   rip = 0x00007f8490aa69da
[task 2017-05-17T10:33:07.455481Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.456296Z] 10:33:07     INFO - 13  libxul.so!js::proxy_Call [Proxy.cpp:36f2908f6650 : 479 + 0x18]
[task 2017-05-17T10:33:07.457100Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dcf20
[task 2017-05-17T10:33:07.457914Z] 10:33:07     INFO -     rsp = 0x00007fffda0dcea0   r12 = 0x00007fffda0dcee0
[task 2017-05-17T10:33:07.458709Z] 10:33:07     INFO -     r13 = 0x00007fffda0dced0   r14 = 0x00007f84924e3b10
[task 2017-05-17T10:33:07.459487Z] 10:33:07     INFO -     r15 = 0x00007f8490aacc30   rip = 0x00007f8490aacd04
[task 2017-05-17T10:33:07.460289Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.461103Z] 10:33:07     INFO - 14  libxul.so!js::InternalCallOrConstruct [jscntxtinlines.h:36f2908f6650 : 293 + 0x6]
[task 2017-05-17T10:33:07.461907Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dcfe0
[task 2017-05-17T10:33:07.462709Z] 10:33:07     INFO -     rsp = 0x00007fffda0dcf30   r12 = 0x00007f8489b65000
[task 2017-05-17T10:33:07.463514Z] 10:33:07     INFO -     r13 = 0x00007fffda0dd090   r14 = 0x00007fffda0dcf70
[task 2017-05-17T10:33:07.464311Z] 10:33:07     INFO -     r15 = 0x00007f8490aacc30   rip = 0x00007f8490738fb5
[task 2017-05-17T10:33:07.465090Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.465934Z] 10:33:07     INFO - 15  libxul.so!js::jit::DoCallFallback [BaselineIC.cpp:36f2908f6650 : 2447 + 0xf]
[task 2017-05-17T10:33:07.466739Z] 10:33:07     INFO -     rbx = 0x0000000000000000   rbp = 0x00007fffda0dd270
[task 2017-05-17T10:33:07.467545Z] 10:33:07     INFO -     rsp = 0x00007fffda0dcff0   r12 = 0x00007fffda0dd2e0
[task 2017-05-17T10:33:07.468355Z] 10:33:07     INFO -     r13 = 0x00007fffda0dd0e0   r14 = 0x00007f8489b6d000
[task 2017-05-17T10:33:07.469124Z] 10:33:07     INFO -     r15 = 0x0000000000000001   rip = 0x00007f84907e50f1
[task 2017-05-17T10:33:07.469929Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.470735Z] 10:33:07     INFO - 16  0xce4de7382d3
[task 2017-05-17T10:33:07.471541Z] 10:33:07     INFO -     rbx = 0xfffe7f844e056fc0   rbp = 0x00007fffda0dd2f0
[task 2017-05-17T10:33:07.472323Z] 10:33:07     INFO -     rsp = 0x00007fffda0dd280   r12 = 0x0000000000000008
[task 2017-05-17T10:33:07.473132Z] 10:33:07     INFO -     r13 = 0x00007f8486f9c090   r14 = 0x00007f844e056fc0
[task 2017-05-17T10:33:07.473973Z] 10:33:07     INFO -     r15 = 0x00000ce4de72d760   rip = 0x00000ce4de7382d3
[task 2017-05-17T10:33:07.474758Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.475496Z] 10:33:07     INFO - 17  0x7f844dd8d250
[task 2017-05-17T10:33:07.476246Z] 10:33:07     INFO -     rbp = 0x00007fffda0dd378   rsp = 0x00007fffda0dd300
[task 2017-05-17T10:33:07.477027Z] 10:33:07     INFO -     rip = 0x00007f844dd8d250
[task 2017-05-17T10:33:07.477831Z] 10:33:07     INFO -     Found by: previous frame's frame pointer
[task 2017-05-17T10:33:07.478564Z] 10:33:07     INFO - 18  0xce4de72d8a6
[task 2017-05-17T10:33:07.479304Z] 10:33:07     INFO -     rbp = 0x00007fffda0dd3e0   rsp = 0x00007fffda0dd388
[task 2017-05-17T10:33:07.480066Z] 10:33:07     INFO -     rip = 0x00000ce4de72d8a6
[task 2017-05-17T10:33:07.480849Z] 10:33:07     INFO -     Found by: previous frame's frame pointer
[task 2017-05-17T10:33:07.481640Z] 10:33:07     INFO - 19  libxul.so!EnterBaseline [BaselineJIT.cpp:36f2908f6650 : 162 + 0x7]
[task 2017-05-17T10:33:07.482490Z] 10:33:07     INFO -     rbp = 0x00007fffda0dd520   rsp = 0x00007fffda0dd3f0
[task 2017-05-17T10:33:07.483259Z] 10:33:07     INFO -     rip = 0x00007f84907c0934
[task 2017-05-17T10:33:07.484056Z] 10:33:07     INFO -     Found by: previous frame's frame pointer
[task 2017-05-17T10:33:07.484859Z] 10:33:07     INFO - 20  libxul.so!js::jit::EnterBaselineMethod [BaselineJIT.cpp:36f2908f6650 : 200 + 0xb]
[task 2017-05-17T10:33:07.485649Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0dd600
[task 2017-05-17T10:33:07.486472Z] 10:33:07     INFO -     rsp = 0x00007fffda0dd530   r12 = 0x00007fffda0dd570
[task 2017-05-17T10:33:07.487268Z] 10:33:07     INFO -     r13 = 0x00007fffda0ddeb0   r14 = 0x0000000000000001
[task 2017-05-17T10:33:07.488062Z] 10:33:07     INFO -     r15 = 0x00007fffda0de130   rip = 0x00007f84907c5b2b
[task 2017-05-17T10:33:07.488824Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.489590Z] 10:33:07     INFO - 21  libxul.so!Interpret [Interpreter.cpp:36f2908f6650 : 3073 + 0xb]
[task 2017-05-17T10:33:07.490314Z] 10:33:07     INFO -     rbx = 0x00007f8492495240   rbp = 0x00007fffda0ddfc0
[task 2017-05-17T10:33:07.491163Z] 10:33:07     INFO -     rsp = 0x00007fffda0dd610   r12 = 0x00007f8489b6d020
[task 2017-05-17T10:33:07.491954Z] 10:33:07     INFO -     r13 = 0x00007fffda0ddeb0   r14 = 0x00007f8489b6d000
[task 2017-05-17T10:33:07.492738Z] 10:33:07     INFO -     r15 = 0x00007fffda0de130   rip = 0x00007f8490734328
[task 2017-05-17T10:33:07.493500Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.494298Z] 10:33:07     INFO - 22  libxul.so!js::RunScript [Interpreter.cpp:36f2908f6650 : 410 + 0xb]
[task 2017-05-17T10:33:07.495067Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0de0e0
[task 2017-05-17T10:33:07.495862Z] 10:33:07     INFO -     rsp = 0x00007fffda0ddfd0   r12 = 0x00007fffda0de020
[task 2017-05-17T10:33:07.496648Z] 10:33:07     INFO -     r13 = 0x00007fffda0de130   r14 = 0x00007fffda0de010
[task 2017-05-17T10:33:07.497430Z] 10:33:07     INFO -     r15 = 0x00007fffffffffff   rip = 0x00007f84907387c0
[task 2017-05-17T10:33:07.498203Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.499073Z] 10:33:07     INFO - 23  libxul.so!js::InternalCallOrConstruct [Interpreter.cpp:36f2908f6650 : 488 + 0x5]
[task 2017-05-17T10:33:07.499843Z] 10:33:07     INFO -     rbx = 0x00007f8492613b70   rbp = 0x00007fffda0de1a0
[task 2017-05-17T10:33:07.500630Z] 10:33:07     INFO -     rsp = 0x00007fffda0de0f0   r12 = 0x00007f8489b65000
[task 2017-05-17T10:33:07.501420Z] 10:33:07     INFO -     r13 = 0x00007fffda0de2f0   r14 = 0x00007fffda0de130
[task 2017-05-17T10:33:07.502226Z] 10:33:07     INFO -     r15 = 0x00007fffda0de230   rip = 0x00007f8490738f07
[task 2017-05-17T10:33:07.503002Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.503796Z] 10:33:07     INFO - 24  libxul.so!js::Call [Interpreter.cpp:36f2908f6650 : 534 + 0x5]
[task 2017-05-17T10:33:07.504585Z] 10:33:07     INFO -     rbx = 0x00007fffda0de2f0   rbp = 0x00007fffda0de1c0
[task 2017-05-17T10:33:07.505363Z] 10:33:07     INFO -     rsp = 0x00007fffda0de1b0   r12 = 0x00007fffda0de3d0
[task 2017-05-17T10:33:07.506136Z] 10:33:07     INFO -     r13 = 0x00007fffda0de2f0   r14 = 0x0000000000000002
[task 2017-05-17T10:33:07.506873Z] 10:33:07     INFO -     r15 = 0x00007fffda0de230   rip = 0x00007f8490739419
[task 2017-05-17T10:33:07.507604Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.508399Z] 10:33:07     INFO - 25  libxul.so!js::jit::InvokeFunction [VMFunctions.cpp:36f2908f6650 : 114 + 0xb]
[task 2017-05-17T10:33:07.509150Z] 10:33:07     INFO -     rbx = 0x00007f8489b6d000   rbp = 0x00007fffda0de3b0
[task 2017-05-17T10:33:07.509884Z] 10:33:07     INFO -     rsp = 0x00007fffda0de1d0   r12 = 0x00007fffda0de420
[task 2017-05-17T10:33:07.510645Z] 10:33:07     INFO -     r13 = 0x00007fffda0de2f0   r14 = 0x0000000000000002
[task 2017-05-17T10:33:07.512370Z] 10:33:07     INFO -     r15 = 0x00007fffda0de230   rip = 0x00007f8490964830
[task 2017-05-17T10:33:07.513056Z] 10:33:07     INFO -     Found by: call frame info
[task 2017-05-17T10:33:07.513888Z] 10:33:07     INFO - 26  0xce4de736688
[task 2017-05-17T10:33:07.514677Z] 10:33:07     INFO -     rbx = 0x0000000000000000   rbp = 0x000000000001fffc
[task 2017-05-17T10:33:07.515402Z] 10:33:07     INFO -     rsp = 0x00007fffda0de3c0   r12 = 0x0000000000000000
[task 2017-05-17T10:33:07.516153Z] 10:33:07     INFO -     r13 = 0x00007fffda0deb80   r14 = 0x0000000000000000
[task 2017-05-17T10:33:07.520768Z] 10:33:07     INFO -     r15 = 0x00007f846879b4e0   rip = 0x00000ce4de736688
[task 2017-05-17T10:33:07.520827Z] 10:33:07     INFO -     Found by: call frame info
Flags: needinfo?(jcoppeard)

Comment 12

a year ago
Pushed by jcoppeard@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b2eb05d5fad2
Generate the phase tree for GC statistics recording ahead of time r=sfink

Comment 13

a year ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/b2eb05d5fad2
Status: NEW → RESOLVED
Last Resolved: a year ago
status-firefox55: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Depends on: 1366217
You need to log in before you can comment on or make changes to this bug.