Open Bug 1334752 Opened 7 years ago Updated 2 months ago

Intermittent browser/base/content/test/webrtc/browser_devices_get_user_media_unprompted_access_tear_off_tab.js | Test timed out -

Categories

(Core :: WebRTC, defect, P4)

Product:
Core
Component:
WebRTC
Type:
defect

Tracking

()

Status:
REOPENED
Tracking Flags:
Tracking Status
firefox52 --- unaffected
firefox53 --- disabled
firefox54 --- disabled
Blocking Flags:
backlog tech-debt

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug, Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled])

Attachments

(2 files, 1 obsolete file)

Bug 1334752 - Fix Intermittent browser_devices_get_user_media_unprompted_access_tear_off_tab.js;
59 bytes, text/x-review-board-request
florian
: review+
Details
temporarily disable test win8
1.15 KB, patch
florian
: review+
Details | Diff | Splinter Review
Blocks: 1332516
status-firefox52: --- → unaffected
status-firefox53: --- → affected
status-firefox54: --- → affected
Flags: needinfo?(mchiang)
backlog: --- → tech-debt
Rank: 30
Priority: -- → P3
Assignee: nobody → mchiang
Flags: needinfo?(mchiang)
Florian,

From the log[1], I found the callback eventCallback[2] is never called after we call chromeDoc.defaultView.PopupNotifications.show[3]. Then mochitest timed out while waiting for the event getUserMedia:response:allow. Any idea?

[1] https://treeherder.mozilla.org/logviewer.html#?job_id=74669822&repo=try&lineNumber=9200

[2] http://searchfox.org/mozilla-central/rev/b1aadb3572eaf7d2c70e19a2ba5413809d9ac698/browser/modules/webrtcUI.jsm#460

[3] http://searchfox.org/mozilla-central/rev/b1aadb3572eaf7d2c70e19a2ba5413809d9ac698/browser/modules/webrtcUI.jsm#818-823
Flags: needinfo?(florian)
(In reply to Munro Mengjue Chiang [:mchiang] from comment #8)
> Florian,
> 
> From the log[1], I found the callback eventCallback[2] is never called after
> we call chromeDoc.defaultView.PopupNotifications.show[3].

I'm not sure that's relevant.

> Then mochitest
> timed out while waiting for the event getUserMedia:response:allow. Any idea?

How do you know if we timeout waiting for "getUserMedia:response:allow", or "recording-device-events", or both? (But I would also guess it's getUserMedia:response:allow)

I wonder if it would be possible that in the case where we don't show the prompt, the "getUserMedia:response:allow" notification would sometime be sent before we return from 'yield promiseObserverCalled("getUserMedia:request")' (which requires an exchange of asynchronous messages between the parent and child processes).

Seeing that this failure started happening after we resolved bug 1332516, I'm tempted to say there was an issue with that patch.

I would revert the patch from bug 1332516 and try this:

promise = promiseObserverCalled("getUserMedia:response:allow");
yield promiseRequestDevice(true, true, null, null, win.gBrowser.selectedBrowser);
yield promiseObserverCalled("getUserMedia:request");
yield promiseNoPopupNotification("webRTC-shareDevices");
yield promise;
yield expectObserverCalled("recording-device-events");


For your next try run, please limit the tests to browser/base/content/test/webrtc using:
 --try-test-paths browser-chrome:browser/base/content/test/webrtc
Flags: needinfo?(florian)
(In reply to Florian Quèze [:florian] [:flo] from comment #10)
> How do you know if we timeout waiting for "getUserMedia:response:allow", or
> "recording-device-events", or both? (But I would also guess it's
> getUserMedia:response:allow)

We are waiting for both.
I put some logs [1] to debug this issue.
In normal case, we got these logs

20:02:40     INFO - Munro: MediaManager call getUserMedia:request
20:02:40     INFO - console.log: Munro: prompt 1
20:02:40     INFO - console.log: Munro: eventCallback: aTopic: showing
20:02:40     INFO - console.log: Munro: aRequest.secure: true
20:02:40     INFO - console.log: Munro: there is an active camera
20:02:40     INFO - console.log: Munro: there is an active mic
20:02:40     INFO - console.log: Munro: send webrtc:Allow
20:02:40     INFO - console.log: Munro: eventCallback: aTopic: removed

In the abnormal case, we only got
20:02:49     INFO - Munro: MediaManager call getUserMedia:request
20:02:49     INFO - console.log: Munro: prompt 1

Without sending webrtc:Allow, the test definitely would fail.

> I wonder if it would be possible that in the case where we don't show the
> prompt, the "getUserMedia:response:allow" notification would sometime be
> sent before we return from 'yield
> promiseObserverCalled("getUserMedia:request")' (which requires an exchange
> of asynchronous messages between the parent and child processes).
> 
> Seeing that this failure started happening after we resolved bug 1332516,
> I'm tempted to say there was an issue with that patch.
> 
> I would revert the patch from bug 1332516 and try this:
> 
> promise = promiseObserverCalled("getUserMedia:response:allow");
> yield promiseRequestDevice(true, true, null, null,
> win.gBrowser.selectedBrowser);
> yield promiseObserverCalled("getUserMedia:request");
> yield promiseNoPopupNotification("webRTC-shareDevices");
> yield promise;
> yield expectObserverCalled("recording-device-events");
After modifying the mochitest, the test result [2] still shows the same symptom.

[1] https://hg.mozilla.org/try/rev/4987c35ea2abc9651cf47d4188c8caac3a319de9
[2] https://treeherder.mozilla.org/#/jobs?repo=try&revision=4987c35ea2abc9651cf47d4188c8caac3a319de9&selectedJob=76197470
(In reply to Munro Mengjue Chiang [:mchiang] from comment #12)

> After modifying the mochitest, the test result [2] still shows the same
> symptom.

The results seem very different to me.

On your previous try push, you had 7 failures out of 20 runs without e10s, and 0 failure with e10s (not completely sure my count is right, because there's the browser_verify_content_about_newtab.js failure that adds noise to these results).

On the new push, you have 0 failure out of 107 runs without e10s, and 1 failure out of 147 runs with e10s.

So that's 1 failure out of 250+ runs; probably below the threshold where we would start investing time in debugging.
Your logs are difficult to read because you used console.log instead of info(), so your logging wasn't buffered, while the rest of the test output was buffered. You may want to use SimpleTest.requestCompleteLog()

But indeed, the popupnotification doesn't seem to show up in the one failure that remains. One possible reason could be that the window is not focused (yet?).

When looking at other tests that call replaceTabWithWindow, I found:
http://searchfox.org/mozilla-central/rev/afcf40f3eafd895611a839017730debb58a342a6/browser/base/content/test/plugins/browser_CTP_drag_drop.js#62 doing a promiseWaitForFocus call before continuing. This function is defined at http://searchfox.org/mozilla-central/rev/afcf40f3eafd895611a839017730debb58a342a6/browser/base/content/test/plugins/head.js#310

Some popupnotification tests do a waitForWindowReadyForPopupNotifications call:
http://searchfox.org/mozilla-central/source/browser/base/content/test/popupNotifications/browser_popupNotification_4.js#143
That's defined at http://searchfox.org/mozilla-central/rev/afcf40f3eafd895611a839017730debb58a342a6/browser/base/content/test/popupNotifications/head.js#34 and also waits for the window to be selected.
Comment on attachment 8836586 [details]
Bug 1334752 - Fix Intermittent browser_devices_get_user_media_unprompted_access_tear_off_tab.js;

https://reviewboard.mozilla.org/r/111982/#review113262

Straight forward, and try is green, so let's land this and see what happens :-), r=me.
Attachment #8836586 - Flags: review?(florian) → review+
Pushed by cbook@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/3a166ded7d98
Fix Intermittent browser_devices_get_user_media_unprompted_access_tear_off_tab.js; r=florian
Keywords: checkin-needed
Attached patch temporarily disable test win8 (obsolete) — — Splinter Review 
to reduce the impact on developers lets disable this on win8 for now until pto is over and we can do another try here.
Attachment #8840424 - Flags: review?(gbrown)
Comment on attachment 8840424 [details] [diff] [review]
temporarily disable test win8

This is disabling an unrelated test.
Attachment #8840424 - Flags: review?(gbrown) → review-
oh, I see the flaws of my error- similar names but I missed the unprompted_access part of the test :(
Attached patch temporarily disable test win8 — — Splinter Review 
ok, this is for the real test.
Attachment #8840424 - Attachment is obsolete: true
Attachment #8840559 - Flags: review?(florian)
Attachment #8840559 - Flags: review?(florian) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e4f60215a489
Intermittent browser/base/content/test/webrtc/browser_devices_get_user_media_unprompted_access_tear_off_tab.js. r=gbrown
Whiteboard: [stockwell disabled]
Mass change P3->P4 to align with new Mozilla triage process.
Priority: P3 → P4
Keywords: regression

The failures were fixed by this backout: https://hg.mozilla.org/integration/autoland/rev/c4dc5740defdf2888d7aadd20ceaf8b6dcb80ace

Flags: needinfo?(mconley)
Whiteboard: [stockwell disabled][retriggered][stockwell needswork:owner] → [stockwell disabled]
Has Regression Range: --- → yes

The bug assignee didn't login in Bugzilla in the last 7 months.
:mjf, could you have a look please?
For more information, please visit auto_nag documentation.

Assignee: bonchiang → nobody
Flags: needinfo?(mfroman)

It appears this hasn't happened in 2 years and was low priority. Comment 101 says this was fixed by a backout. I'm going to close this until we see it happen again.

Status: NEW → RESOLVED
Closed: 2 years ago
Flags: needinfo?(mfroman)
Resolution: --- → INACTIVE
Status: RESOLVED → REOPENED
Resolution: INACTIVE → ---
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.