Closed Bug 1126639 Opened 5 years ago Closed 4 years ago

browser_responsiveruleview.js permafails when app.update.channel is set to beta

Categories

(DevTools :: Responsive Design Mode, defect, major)

defect
Not set
major

Tracking

(firefox42 wontfix, firefox43 wontfix, firefox44 wontfix, firefox45 fixed, firefox46 fixed, firefox-esr38 disabled)

RESOLVED FIXED
Firefox 46
Tracking Status
firefox42 --- wontfix
firefox43 --- wontfix
firefox44 --- wontfix
firefox45 --- fixed
firefox46 --- fixed
firefox-esr38 --- disabled

People

(Reporter: RyanVM, Assigned: RyanVM)

References

Details

Attachments

(1 file, 1 obsolete file)

[Tracking Requested - why for this release]: Test failures when Gecko 38 is uplifted to beta.

Happens on opt and debug builds across all platforms.

https://treeherder.mozilla.org/logviewer.html#?job_id=4503081&repo=try

12:00:12 INFO - 4593 INFO TEST-START | browser/devtools/responsivedesign/test/browser_responsiveruleview.js
12:00:12 INFO - console.error:
12:00:12 INFO - Message: TypeError: can't access dead object
12:00:12 INFO - Stack:
12:00:12 INFO - CanvasFrameAnonymousContentHelper.prototype.destroy@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/actors/highlighter.js:440:7
12:00:12 INFO - BoxModelHighlighter.prototype<.destroy@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/actors/highlighter.js:949:5
12:00:12 INFO - exports.HighlighterActor<._destroyHighlighter@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/actors/highlighter.js:125:7
12:00:12 INFO - exports.HighlighterActor<.destroy@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/actors/highlighter.js:145:5
12:00:12 INFO - Pool<.destroy@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:813:9
12:00:12 INFO - Actor<.destroy@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:885:5
12:00:12 INFO - Pool<.cleanup@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:827:5
12:00:12 INFO - DSC_onClosed/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/main.js:1539:40
12:00:12 INFO - DSC_onClosed@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/main.js:1539:5
12:00:12 INFO - LocalDebuggerTransport.prototype.close@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:636:9
12:00:12 INFO - LocalDebuggerTransport.prototype.close@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:632:7
12:00:12 INFO - DebuggerClient.prototype.close/detachClients@resource://gre/modules/devtools/dbg-client.jsm:436:9
12:00:12 INFO - DebuggerClient.requester/</<@resource://gre/modules/devtools/dbg-client.jsm:352:9
12:00:12 INFO - makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:82:14
12:00:12 INFO - emit@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/commonjs/sdk/event/core.js:97:9
12:00:12 INFO - Request.prototype.emit@resource://gre/modules/devtools/dbg-client.jsm:1115:29
12:00:12 INFO - DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:955:7
12:00:12 INFO - LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
12:00:12 INFO - makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:82:14
12:00:12 INFO - makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:82:14 
12:00:35 INFO - 1422388835159 Browser.Experiments.Experiments TRACE Experiments #0::enabled=true, true
12:00:35 INFO - 1422388835162 Browser.Experiments.Experiments TRACE Experiments #0::Registering instance with Addon Manager.
12:00:35 INFO - 1422388835164 Browser.Experiments.Experiments TRACE Experiments #0::Registering previous experiment add-on provider.
12:00:35 INFO - 1422388835166 Browser.Experiments.Experiments TRACE PreviousExperimentProvider #0::startup()
12:00:35 INFO - 1422388835168 Browser.Experiments.Experiments TRACE Experiments #0::_loadFromCache
12:00:35 INFO - 1422388835183 Browser.Experiments.Experiments TRACE Experiments #0::_loadTask finished ok
12:00:35 INFO - 1422388835185 Browser.Experiments.Experiments TRACE Experiments #0::_run
12:00:35 INFO - 1422388835186 Browser.Experiments.Experiments TRACE Experiments #0::_main iteration
12:00:35 INFO - 1422388835187 Browser.Experiments.Experiments TRACE Experiments #0::_evaluateExperiments
12:00:35 INFO - 1422388835192 Browser.Experiments.Experiments TRACE Experiments #0::_main finished, scheduling next run
12:01:42 INFO - Xlib: extension "RANDR" missing on display ":0".
12:01:44 INFO - TEST-INFO | screentopng: exit 0
12:01:44 INFO - 4594 INFO checking window state
12:01:44 INFO - 4595 INFO Console message: [JavaScript Warning: "Selector expected. Ruleset ignored due to bad selector." {file: "data:text/html;charset=utf-8,<html><style>div%20{%20%20width:%20500px;%20%20height:%2010px;%20%20background:%20purple;}%20@media%20screen%20and%20(max-width:%20200px)%20{%20%20div%20{%20%20%20%20%20width:%20100px;%20%20}};</style><div></div></html>" line: 1 column: 125 source: "div { width: 500px; height: 10px; background: purple;} @media screen and (max-width: 200px) { div { width: 100px; }};"}]
12:01:44 INFO - 4596 INFO Console message: [JavaScript Warning: "Unexpected end of file while searching for closing } of invalid rule set." {file: "data:text/html;charset=utf-8,<html><style>div%20{%20%20width:%20500px;%20%20height:%2010px;%20%20background:%20purple;}%20@media%20screen%20and%20(max-width:%20200px)%20{%20%20div%20{%20%20%20%20%20width:%20100px;%20%20}};</style><div></div></html>" line: 1 column: 126 source: "div { width: 500px; height: 10px; background: purple;} @media screen and (max-width: 200px) { div { width: 100px; }};"}]
12:01:44 INFO - 4597 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | instance of the module is attached to the tab.
12:01:44 INFO - 4598 INFO Opening the inspector
12:01:44 INFO - 4599 INFO Opening the toolbox
12:01:44 INFO - 4600 INFO Making sure that the toolbox's frame is focused
12:01:44 INFO - 4601 INFO Waiting for the inspector to update
12:01:44 INFO - 4602 INFO Selecting the ruleview sidebar
12:01:44 INFO - 4603 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Got inspector instance
12:01:44 INFO - 4604 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Should have two rules initially.
12:01:44 INFO - 4605 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Should have three rules after shrinking.
12:01:44 INFO - 4606 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Should have two rules after growing.
12:01:44 INFO - 4607 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | menu checked
12:01:44 INFO - 4608 INFO TEST-PASS | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Console is not split. 
12:01:44 INFO - 4609 INFO Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key="c" modifiers="accel,alt"" {file: "chrome://mochikit/content/tests/SimpleTest/specialpowersAPI.js" line: 154}]
12:01:44 INFO - 4610 INFO Console message: 1422388835159 Browser.Experiments.Experiments TRACE Experiments #0::enabled=true, true
12:01:44 INFO - 4611 INFO Console message: 1422388835162 Browser.Experiments.Experiments TRACE Experiments #0::Registering instance with Addon Manager.
12:01:44 INFO - 4612 INFO Console message: 1422388835164 Browser.Experiments.Experiments TRACE Experiments #0::Registering previous experiment add-on provider.
12:01:44 INFO - 4613 INFO Console message: 1422388835166 Browser.Experiments.Experiments TRACE PreviousExperimentProvider #0::startup()
12:01:44 INFO - 4614 INFO Console message: 1422388835168 Browser.Experiments.Experiments TRACE Experiments #0::_loadFromCache
12:01:44 INFO - 4615 INFO Console message: 1422388835183 Browser.Experiments.Experiments TRACE Experiments #0::_loadTask finished ok
12:01:44 INFO - 4616 INFO Console message: 1422388835185 Browser.Experiments.Experiments TRACE Experiments #0::_run
12:01:44 INFO - 4617 INFO Console message: 1422388835186 Browser.Experiments.Experiments TRACE Experiments #0::_main iteration
12:01:44 INFO - 4618 INFO Console message: 1422388835187 Browser.Experiments.Experiments TRACE Experiments #0::_evaluateExperiments
12:01:44 INFO - 4619 INFO Console message: 1422388835192 Browser.Experiments.Experiments TRACE Experiments #0::_main finished, scheduling next run
12:01:44 INFO - 4620 INFO Console message: 1422388866628 Services.HealthReport.HealthReporter WARN Saved state file does not exist.
12:01:44 INFO - 4621 INFO Console message: 1422388866628 Services.HealthReport.HealthReporter WARN No prefs data found.
12:01:44 INFO - 4622 INFO TEST-UNEXPECTED-FAIL | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Test timed out - expected PASS
12:01:44 INFO - 4623 INFO MEMORY STAT vsize after test: 596684800
12:01:44 INFO - 4624 INFO MEMORY STAT residentFast after test: 159023104
12:01:44 INFO - 4625 INFO MEMORY STAT heapAllocated after test: 62784044
12:01:44 INFO - 4626 INFO TEST-OK | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | took 90095ms
12:01:44 INFO - 4627 INFO TEST-UNEXPECTED-FAIL | browser/devtools/responsivedesign/test/browser_responsiveruleview.js | Found a tab after previous test timed out: data:text/html;charset=utf-8,<html><style>div%20{%20%20width:%20500px;%20%20height:%2010px;%20%20background:%20purple;}%20@media%20screen%20and%20(max-width:%20200px)%20{%20%20div%20{%20%20%20%20%20width:%20100px;%20%20}};</style><div></div></html> - expected PASS
Flags: needinfo?(paul)
No activity in a week now. Joe, can you please help me find an owner for this?
Flags: needinfo?(jwalker)
Mike, Patrick, any idea why this is failing?

Relevant part:

12:00:12 INFO - CanvasFrameAnonymousContentHelper.prototype.destroy@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/actors/highlighter.js:440:7
Flags: needinfo?(paul)
Flags: needinfo?(pbrosset)
Flags: needinfo?(mratcliffe)
We're on it, thanks Ryan.
Flags: needinfo?(jwalker)
I don't think the CanvasFrameAnonymousContentHelper is related at all to the test timeout. We've had this error in the logs for a couple of weeks (I think) and it's not responsible for test failures as far as I know.
It happens when the page is reloaded or navigated away from, which causes the highlighter to not be able to remove its DOM because the canvasFrame it was inserted into doesn't exist anymore.
It's not a problem, and I think when I implemented it first, it use to silently fail. I'll file a separate bug to take care of this one.

I'll take a look at why this particular test times out now.
Assignee: nobody → pbrosset
Flags: needinfo?(pbrosset)
So, the test times out here:

    inspector._toolbox.once("split-console", function() {
      mgr.once("off", function() {executeSoon(finishUp)});
      mgr.toggle(window, gBrowser.selectedTab);
    });
    EventUtils.synthesizeKey("VK_ESCAPE", {});

Either the ESC key never gets synthesized somehow, or the "split-console" event never gets emitted.

When this happens, I see this in the logs:
Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key="c" modifiers="accel,alt"" {file: "chrome://mochikit/content/tests/SimpleTest/specialpowersAPI.js" line: 154}]

I have no idea if this is related, but I'm not seeing this warning locally, where the test passes fine.
So this patch adds logs to the test, and gets rid of the CanvasFrameAnonymousContentHelper error in the logs by destroying the toolbox, and (and I hope that's the fix that will make it pass on beta) adds the correct window argument to the synthesizeKey function call.

Now, how can I test this?
If I understand correctly, if this test only fails after m-c is uplifted to beta, it's got to do with something that is release-dependent. I have no idea what could be causing this. And this test doesn't even seem to be intermittently failing on m-c at all. So there is something with beta that makes it fail.

Ryan: what would be the best way for me to test this?
Flags: needinfo?(ryanvm)
Clearing this needinfo flag as Mike is on PTO this week.
Flags: needinfo?(mratcliffe)
(In reply to Patrick Brosset [:pbrosset] [:patrick] from comment #6)
> Ryan: what would be the best way for me to test this?

Setting the version to 38.0 should suffice for this. That'll make it so that RELEASE_BUILD is set and NIGHTLY_BUILD isn't.
http://hg.mozilla.org/mozilla-central/file/58ce6051edf5/browser/config/version.txt

If that doesn't work, let me know and I can share with you the exact patch I use in the Try runs.
Flags: needinfo?(ryanvm)
(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #8)
> (In reply to Patrick Brosset [:pbrosset] [:patrick] from comment #6)
> > Ryan: what would be the best way for me to test this?
> 
> Setting the version to 38.0 should suffice for this. That'll make it so that
> RELEASE_BUILD is set and NIGHTLY_BUILD isn't.
> http://hg.mozilla.org/mozilla-central/file/58ce6051edf5/browser/config/
> version.txt
> 
> If that doesn't work, let me know and I can share with you the exact patch I
> use in the Try runs.
I finally had some time today to test this, but unfortunately, that didn't seem to work as expected. I changed the version in that file to 38.0 and did a clobber build just in case, but the test is still passing fine for me locally.
Could you share that patch with me please?
Flags: needinfo?(ryanvm)
Sorry for the delay here but I haven't been very successful at finding a fix for this bug yet.

- When I apply the "trunk-as-beta-rollup" patch locally, the test still pass fine for me.
- If I apply it and then run the test on try, it does time out as in comment 0.
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=06bef619589b
- And if I apply my fix on top, it still times out, and the logs don't help at all.
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=25777535b3e7

Also, to my knowledge, the "trunk-as-beta-rollup" patch doesn't contain anything special that should cause the ESC key not to be synthesized correctly during the test.
I still haven't been able to progress.

I've tried to fix the test in 2 ways:
- make sure the toolbox is really focused before simulating ESCAPE (I used to do this by clicking in the markup-view but I know of 1 bug that may make this fail, so I've changed it to focus in the toolbox window instead)
- reverse the test order by testing first the ESCAPE thing, and then only the responsiveview shrink/grow tests, as I was suspecting it might impact the rest of the test.

Nothing worked so far.
Here's my last try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=38b31d28ab53
The test still times out at the same stage.

For info, here's the screenshot of the browser when the test fails:
http://mozilla-releng-blobs.s3.amazonaws.com/blobs/try/sha512/c29e3b497c9ea838a5c5f92fe8dc153e91cc15fb454514c45cafa795330c764917fe69248571b2c11606c14e4015ea8eabea1157b1f16081234f73a03d7c68fa
And here's probably the bug that started this problem: bug 1067145.

Finally, I'm still seeing this warning right when simulating the ESCAPE key:
06:50:05     INFO -  4822 INFO Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key="c" modifiers="accel,alt"" {file: "chrome://mochikit/content/tests/SimpleTest/specialpowersAPI.js" line: 154}]
But that doesn't seem related, and searching the logs, it seems to also happen for at least 1 other test that doesn't fail.

Paul, please tell me this rings a bell somehow, because I just don't know what could cause this.
Flags: needinfo?(paul)
Paul won't have time to look at this.
At this stage, any fix I can think about is going to make the test weird (like waiting and then trying to synthesize the key again, or not synthesizing the key at all and calling the callback directly).
So I'd rather disable the test altogether.
Can we disable a test only on beta/release?
Flags: needinfo?(paul) → needinfo?(ryanvm)
Yeah, but it'll have to wait until after the merge. We can't conditionally do it in the manifest.
Flags: needinfo?(ryanvm)
Ah I see, of course, we can disable the test once it's in beta. Thanks.
Actually, there's another failure below that, so it appears there's a bad state propagating through other tests. I'm going to skip the entire directory rather than playing whack-a-mole.
Fun observation - this failure is still lingering around on Beta uplift simulations, but not on the actual uplifts to Beta. Curious! Except, we were recently tipped off in bug 1239504 about one crucial difference between the simulation builds and the CI builds. On mozilla-beta, in CI, builds are currently set to an update channel (app.update.channel) of "default" while our release builds are "beta". Simulation runs also use "beta". It turns out we have code that looks at that value when deciding what do and hilarity sometimes ensues!

And sure enough, dropping that change from the uplift simulation is enough to make the failures go away:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=815cd2f3e18a&group_state=expanded

So this is an example of us not testing what we're actually shipping, yay! So at this point, you might be asking yourself, why do we care? Release Promotion is why. In the nearish future, our CI builds on mozilla-beta will start having their update channel set to "beta", in which time this will become permafail in places besides uplift simulation runs.

So if you're looking to investigate this further, you might try applying the opposite of this patch - https://hg.mozilla.org/try/rev/815cd2f3e18a - and see if it happens for you then. And assuming it does, start looking at code that makes use of app.update.channel or MOZ_UPDATE_CHANNEL as a good first suspect.
Flags: needinfo?(pbrosset)
Summary: browser_responsiveruleview.js is going to permafail when Gecko 38 merges to beta → browser_responsiveruleview.js permafails when app.update.channel is set to beta
https://treeherder.mozilla.org/#/jobs?repo=try&revision=158f20c5f57f&group_state=expanded proves my theory (ignoring the StringBuffer leaks as those are another issue apparently). See 10.10 dt1 and XP dt4. That push is on top of mozilla-central tip and does nothing but set the update channel to beta.
This is kinda wallpaperish in that it's basically just working around whatever underlying problem we're hitting, but it's not outlandish either and probably the only realistic patch we're going to see here.

Effectively, this patch is basically a no-op for our CI builds currently since devtools.js is already setting the pref to false for anything that doesn't have beta as a release channel (which, as pointed out in comment 19, is currently true for all channels). So this patch basically just makes the simulation runs happy and ensures that we won't have permafails lurking when the Release Promotion work eventually dictates that our CI builds also have their release channel set to beta instead of default.
Assignee: pbrosset → ryanvm
Attachment #8559669 - Attachment is obsolete: true
Status: NEW → ASSIGNED
Attachment #8711348 - Flags: review?(pbrosset)
https://hg.mozilla.org/mozilla-central/rev/177dae17c653
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 46
(In reply to Ryan VanderMeulen [:RyanVM] (Away 24-Jan to 31-Jan) from comment #19)
> So if you're looking to investigate this further, you might try applying the
> opposite of this patch - https://hg.mozilla.org/try/rev/815cd2f3e18a - and
> see if it happens for you then. And assuming it does, start looking at code
> that makes use of app.update.channel or MOZ_UPDATE_CHANNEL as a good first
> suspect.
Ah, very good catch Ryan! It happens that we have a special first-time user mode that only exists on beta:
https://dxr.mozilla.org/mozilla-central/source/devtools/client/preferences/devtools.js#11
Here, we read the value of MOZ_UPDATE_CHANNEL, and if it's beta, then we set the following pref to true: devtools.devedition.promo.enabled
This pref is then used to display a sort of welcome message the first time a user opens the console:
https://dxr.mozilla.org/mozilla-central/source/devtools/client/shared/doorhanger.js#29

This test fails on beta because it simulates pressing ESCAPE, but that only gets rid of the welcome message, rather than close the split console as we expect!

So, setting the pref to false when the test starts should fix it.
Comment on attachment 8711348 [details] [diff] [review]
ensure that devtools.devedition.promo.enabled is set to false in the test harness

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

This fix is fine. Sorry for the delay in reviewing. But I see you've pushed that already anyway.
According to my last comment, this is effectively fixing the root cause of the test failure, and I agree that we should set this pref to false whenever testing devtools (unless we're testing the beta welcome message thing, but those tests should set the pref themselves anyway).
Attachment #8711348 - Flags: review?(pbrosset) → review+
[bugday-20160323]

Status: RESOLVED,FIXED -> UNVERIFIED

Comments:
STR: Developer specific testing

Component: 
Name 			Firefox
Version 		46.0b4
Build ID 		20160322075646
Update Channel 	        beta
User Agent 		Mozilla/5.0 (Windows NT 6.1; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0
OS                      Windows 7 SP1 x86_64
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.