Intermittent failure in browser_dbg_script-switching.js | The correct script was loaded initially. | The first script is displayed.

RESOLVED FIXED in Firefox 14

Status

()

Firefox
Developer Tools: Debugger
P3
normal
RESOLVED FIXED
6 years ago
5 years ago

People

(Reporter: emorley, Assigned: msucan)

Tracking

({intermittent-failure})

Trunk
Firefox 14
intermittent-failure
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox13 affected)

Details

(Whiteboard: [fixed-in-fx-team])

Attachments

(2 attachments)

Rev3 WINNT 6.1 mozilla-inbound pgo test mochitest-other
https://hg.mozilla.org/integration/mozilla-inbound/rev/81c166bac966

https://tbpl.mozilla.org/?tree=Mozilla-Inbound&rev=81c166bac966
https://tbpl.mozilla.org/php/getParsedLog.php?id=9472387&tree=Mozilla-Inbound

Similar to bug 728830; marking dependent on that.

{
TEST-INFO | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | Console message: [JavaScript Warning: "XUL box for span element contained an inline #text child, forcing all its children to be wrapped in a block." {file: "chrome://browser/content/debugger.xul" line: 0}]
DBG-SERVER: Got: {
  "to": "conn17.context4",
  "type": "scripts"
}
TEST-INFO | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | Console message: [JavaScript Warning: "XUL box for span element contained an inline #text child, forcing all its children to be wrapped in a block." {file: "chrome://browser/content/debugger.xul" line: 0}]
DBG-SERVER: Got: {
  "from": "conn17.context4",
  "scripts": [
    {
      "url": "http://example.com/browser/browser/devtools/debugger/test/test-script-switching-01.js",
      "startLine": 5,
      "lineCount": 1
    },
    {
      "url": "http://example.com/browser/browser/devtools/debugger/test/test-script-switching-02.js",
      "startLine": 6,
      "lineCount": 1
    }
  ]
}
TEST-PASS | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | Should only be getting stack frames while paused.
TEST-PASS | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | Found the expected number of scripts.
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | The correct script was loaded initially.
Stack trace:
    JS frame :: chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js :: <TOP_LEVEL> :: line 44

TEST-PASS | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | The second script is no longer displayed.
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | The first script is displayed.
Stack trace:
    JS frame :: chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js :: testSwitchPaused :: line 66
    JS frame :: chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js :: onChange :: line 50
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 157
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 3691
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 7596
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 7425
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 157
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 1763
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 1911
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 7582
    JS frame :: chrome://browser/content/orion.js :: <TOP_LEVEL> :: line 4262
    JS frame :: resource:///modules/source-editor-orion.jsm :: SE_setText :: line 708
    JS frame :: chrome://browser/content/debugger.js :: SS_showScript :: line 548
    JS frame :: chrome://browser/content/debugger.js :: SS_onChange :: line 490

DBG-SERVER: Got: {
  "to": "conn17.context4",
  "type": "resume"
}
DBG-SERVER: Got: {
  "from": "conn17.context4",
  "type": "resumed"
}
TEST-PASS | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | The second script is displayed again.
TEST-PASS | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | The first script is no longer displayed.
TEST-INFO | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | Console message: [JavaScript Warning: "XUL box for div element contained an inline #text child, forcing all its children to be wrapped in a block." {file: "chrome://browser/content/debugger.xul" line: 0}]
INFO TEST-END | chrome://mochitests/content/browser/browser/devtools/debugger/test/browser_dbg_script-switching.js | finished in 509ms
}
(Reporter)

Comment 1

6 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=9442187&tree=Fx-Team
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Priority: -- → P3
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Assignee: nobody → vporof
Status: NEW → ASSIGNED
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Created attachment 611404 [details] [diff] [review]
v1

I think this should fix things.
Attachment #611404 - Flags: review?(past)
(In reply to Victor Porof from comment #31)
> Created attachment 611404 [details] [diff] [review]
> v1
> 
> I think this should fix things.

https://tbpl.mozilla.org/?tree=Try&rev=a629ba3ff59a
(In reply to Victor Porof from comment #31)
> Created attachment 611404 [details] [diff] [review]
> v1
> 
> I think this should fix things.

I probably shouldn't be looking at this after a long day, but can you explain a bit the logic behind this patch? I can't make sense of it as it is. You add an extra flag to signal an empty script list, and in the comment you mention it's faster than checking the item count, but we didn't seem to make any check before, right? There was just a straight assignment to selectedItem as far as I can see.
(In reply to Panos Astithas [:past] from comment #33)
> (In reply to Victor Porof from comment #31)
> > Created attachment 611404 [details] [diff] [review]
> > v1
> > 
> > I think this should fix things.
> 
> I probably shouldn't be looking at this after a long day, but can you
> explain a bit the logic behind this patch? I can't make sense of it as it
> is. You add an extra flag to signal an empty script list, and in the comment
> you mention it's faster than checking the item count, but we didn't seem to
> make any check before, right? There was just a straight assignment to
> selectedItem as far as I can see.

Ok, so, here's what I think triggers the orange (and in bug 740751):
* the order in which scripts are added to the menulist is reliable, but the selected item (and thus editor text content) outcome at a particular point is not!
* this happens because each time we add an item in that menulist (in other words, each time we called addScript() in the debugger-view), we were changing this._scripts.selectedItem = script;
* thus, on each added script, the selected item was changed to the most recent added script, the onChange event was fired and the editor text contents were changed as well
* at the end of adding all the scripts in the menulist, we can't possibly be sure which is the selected item, because there's no guarantee the DOM has updated to the changes, and there's even less guarantee that the editor text contents were up to date (they would be, eventually, but not exactly at the certain time this test was relying on)
* most of the times, this was fast enough, and by the time we reached the debugger; call, the scripts were loaded and everything was ok. some times, however, this was not the case, and the menulist was still updating.
* this is exactly the same problem we experienced during the work week, where we saw the incorrect selected script when starting the debugger, and inherently the same issue causing loading a large number of scripts very slow
* the extra flag to signal an empty script list is not something that fixes this bug, but just a way of avoiding checking for itemCount (which may cause a reflow, i'm not sure)
* the straight assignment to selectedItem we were doing previously is exactly what was causing this orange: continuously update the menulist current selection and text contents with the most recently added item while loading scripts, causing uncontrollable DOM mutations, race conditions, spiraling out of control in another dimension.
Comment on attachment 611404 [details] [diff] [review]
v1

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

OK, it all makes sense now, thanks!
Attachment #611404 - Flags: review?(past) → review+
Whiteboard: [orange] → [orange][land-inf-fx-team]
Whiteboard: [orange][land-inf-fx-team] → [orange][land-in-fx-team]
https://hg.mozilla.org/integration/fx-team/rev/b00af9fa37be
Whiteboard: [orange][land-in-fx-team] → [orange][fixed-in-fx-team]
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
https://hg.mozilla.org/integration/fx-team/rev/811fcd591b18
Whiteboard: [orange][fixed-in-fx-team] → [orange][backed-out]
Comment hidden (Treeherder Robot)
(In reply to Victor Porof from comment #31)
> Created attachment 611404 [details] [diff] [review]
> v1
> 
> I think this should fix things.

nooooope!

https://tbpl.mozilla.org/?tree=Fx-Team&rev=b00af9fa37be
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(In reply to Rob Campbell [:rc] (:robcee) from comment #42)
> (In reply to Victor Porof from comment #31)
> > Created attachment 611404 [details] [diff] [review]
> > v1
> > 
> > I think this should fix things.
> 
> nooooope!
> 
> https://tbpl.mozilla.org/?tree=Fx-Team&rev=b00af9fa37be

I don't get it. Try was green.

(In reply to Victor Porof from comment #32)
> https://tbpl.mozilla.org/?tree=Try&rev=a629ba3ff59a
(Assignee)

Comment 51

5 years ago
Created attachment 612518 [details] [diff] [review]
[in-fx-team] alternate fix proposal

Same approach as I have for Bug 728830.

Try push:
https://tbpl.mozilla.org/?tree=Try&rev=5fb80104b607
Attachment #612518 - Flags: review?(rcampbell)
(Assignee)

Comment 52

5 years ago
Forgot to mention: the patch I just submitted should also fix bug 740751.
Comment hidden (Treeherder Robot)
Comment on attachment 612518 [details] [diff] [review]
[in-fx-team] alternate fix proposal

how could you forget to mention that this will also fix 740751?!?!

r++++++++++!!!!!∞
Attachment #612518 - Flags: review?(rcampbell) → review+
Comment hidden (Treeherder Robot)
(Assignee)

Comment 56

5 years ago
Thank you Rob!

(this is now landable. green results on multiple try runs)
Assignee: vporof → mihai.sucan
No longer depends on: 728830
Whiteboard: [orange][backed-out] → [orange][land-in-fx-team]
(Assignee)

Updated

5 years ago
Blocks: 740751
(Assignee)

Comment 57

5 years ago
Comment on attachment 612518 [details] [diff] [review]
[in-fx-team] alternate fix proposal

Landed:
https://hg.mozilla.org/integration/fx-team/rev/5d654a428c97
Attachment #612518 - Attachment description: alternate fix proposal → [in-fx-team] alternate fix proposal
(Assignee)

Updated

5 years ago
Whiteboard: [orange][land-in-fx-team] → [orange][fixed-in-fx-team]
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
https://hg.mozilla.org/mozilla-central/rev/5d654a428c97
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 14
https://tbpl.mozilla.org/php/getParsedLog.php?id=10762345&tree=Mozilla-Aurora
status-firefox13: --- → affected
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Keywords: intermittent-failure
Whiteboard: [orange][fixed-in-fx-team] → [fixed-in-fx-team]
You need to log in before you can comment on or make changes to this bug.