Closed Bug 1246555 Opened 4 years ago Closed 4 years ago

Browser hangs after clicking on a specific record in Waterfall

Categories

(DevTools :: Performance Tools (Profiler/Timeline), defect)

defect
Not set

Tracking

(firefox47 fixed)

RESOLVED FIXED
Firefox 47
Tracking Status
firefox47 --- fixed

People

(Reporter: arni2033, Assigned: jsantell)

Details

Attachments

(1 file)

>>>   My Info:   Win7_64, Nightly 46, 32bit, ID 20160207030402
STR:
1. Open   data:text/html,<body></body>   in a new tab
2. Open devtools -> Performance
3. Import attached profile [1]
4. Select the area just like on the screenshot [2]
  (! Make sure that exactly the same records in Waterfall are visible !)
5. Click on the last record (not on the dropmarker)
6. Click on the penultimate item (not on the dropmarker)

AR: Firefox DE 45 [not clean profile] hangs w/o any prompt.
    Nightly [clean profile] allows to stop the script (apparently something improved this part)
ER: No hang

Note:
 I recorded that profile using Firefox DE 45 on https://gaming.youtube.com/ , and managed to create
 similar profile at least 10 times. Now I somehow can't create a profile exposing this issue anymore
 
 I think the goal of this bug is to determine wether profile [1] is valid and if it is,
 then to fix the hang. If the profile is not valid, then, I guess, I'll try
 to find the circumstances under which Profiler can create an invalid profile.

> [1] https://dl.dropboxusercontent.com/s/9ris7cdwtay1vpk/profile%201%20-%20Browser%20hangs%20after%20clicking%20on%20a%20specific%20record%20in%20Waterfall.json?dl=0
> [2] https://dl.dropboxusercontent.com/s/gdlkj80g579dhft/screenshot%201%20-%20Browser%20hangs%20after%20clicking%20on%20a%20specific%20record%20in%20Waterfall.png?dl=0
Confirmed on OSX Nightly 47.0a1 -- great STR! Looks like a hang when clicking the penultimate marker while building stack trace....

Error: Script terminated by timeout at:
DOM.buildStackTrace@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/performance/modules/logic/marker-utils.js:216:12
MarkerDetails.prototype.render@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/performance/modules/widgets/marker-details.js:105:21
WaterfallView<._onMarkerSelected@chrome://devtools/content/performance/views/details-waterfall.js:102:7
EventEmitter_emit@resource://devtools/shared/event-emitter.js:147:11
MarkerView.prototype<._onItemFocus@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/performance/modules/widgets/marker-view.js:268:5
EventEmitter_emit@resource://devtools/shared/event-emitter.js:147:11
AbstractTreeItem.prototype._onFocus@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:579:5
AbstractTreeItem.prototype.focus@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:288:5
AbstractTreeItem.prototype._onClick@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:526:5
EventListener.handleEvent*AbstractTreeItem.prototype._constructTargetNode@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:459:5
AbstractTreeItem.prototype.attachTo@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:261:5
AbstractTreeItem.prototype._appendChildrenBatch@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:414:7
AbstractTreeItem.prototype._showChildren@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:382:7
AbstractTreeItem.prototype._toggleChildren@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:369:7
AbstractTreeItem.prototype.expand@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:301:5
AbstractTreeItem.prototype.attachTo@resource://devtools/client/shared/widgets/AbstractTreeItem.jsm:270:7
WaterfallView<._populateWaterfallTree@chrome://devtools/content/performance/views/details-waterfall.js:223:5
WaterfallView<.render@chrome://devtools/content/performance/views/details-waterfall.js:88:5
DetailsSubview._onOverviewRangeChange/debounced@chrome://devtools/content/performance/views/details-abstract-subview.js:121:11
setNamedTimeout/<@resource://devtools/client/shared/widgets/ViewHelpers.jsm:67:39
setTimeout_timer@resource://gre/modules/Timer.jsm:30:5
Has STR: --- → yes
So, looks like we get some recursion in our stack trace. Somewhere in the stack in question, we get a frame pointing to asyncParent `325` -- and the next order of parents are 335, 345, 355, 365, 375, 385, 395, 405... then back to asyncParent 325, which repeats the process, resulting in an infinite loop.

Tom, I believe you implemented the async stack trace markers, any idea how this can happen or what we can do?
Flags: needinfo?(ttromey)
One weird thing I noticed in here is that the "libs" value is a string whose
contents are json-encoded:

  "profile": {
    "libs": "[{\"start\":3538944 ...

Not relevant to this bug but it seemed strange.
@Tom that was bug 1173695 and we parse it when inflating the profile data[0] -- unfortunately don't know the reasons why

[0] https://github.com/mozilla/gecko-dev/blob/8c574e230b95f7ce4cb2e63de8544fbfa1499d62/devtools/shared/performance/recording-utils.js#L403-L410
I believe there are two possible spots where a circular stack trace could
be created.

1. The SavedFrame code in the js engine.
2. devtools/server/actors/utils/stack.js

I've been over these many times though and I still don't see how it is possible.
Without a reproducer it seems difficult to fix whatever is going wrong
server-side.

Given that this is a version 2 profile, though, perhaps the server side is
just unfixable anyway.


Another oddity in this data set is that frame #227 has an async parent,
frame #237.  But frame #237 doesn't have an asyncCause.  This also should
not be possible.


On the client side I think the best that could be done is to have buildStackTrace
(https://dxr.mozilla.org/mozilla-central/source/devtools/client/performance/modules/logic/marker-utils.js#206)
detect loops and stop.

This patch seems to do the trick.  I haven't looked into writing a test for it.

diff --git a/devtools/client/performance/modules/logic/marker-utils.js b/devtools/client/performance/modules/logic/marker-utils.js
index 53409e4..fc34833 100644
--- a/devtools/client/performance/modules/logic/marker-utils.js
+++ b/devtools/client/performance/modules/logic/marker-utils.js
@@ -212,8 +212,17 @@ const DOM = {
     container.className = "marker-details-stack";
     container.appendChild(labelName);
 
+    // Workaround for profiles that have looping stack traces.  See
+    // bug 1246555.
+    let seen = new Set();
+
     let wasAsyncParent = false;
     while (frameIndex > 0) {
+      if (seen.has(frameIndex)) {
+        break;
+      }
+      seen.add(frameIndex);
+
       let frame = frames[frameIndex];
       let url = frame.source;
       let displayName = frame.functionDisplayName;
Flags: needinfo?(ttromey)
Thanks for looking into this, Tom! Didn't realize it was an older profile, and if it's caused server side, harder to track down, but a fix like this will atleast prevent a hang. I'll check it out and implement your patch -- can probably stub out a unit test for it. Thanks!
Assignee: nobody → jsantell
Status: NEW → ASSIGNED
Attachment #8721720 - Flags: review?(vporof) → review+
https://hg.mozilla.org/integration/fx-team/rev/385e0938172e2c9799de8ab42d0b052ae65495ee
Bug 1246555 - Abort infinite loop when a marker has a recursive stack trace in the marker details view. r=vp
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/385e0938172e
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 47
Fixed on:   Win7_64, Nightly 47, 32bit, ID 20160229030448
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.