Closed Bug 1294605 Opened 4 years ago Closed 3 years ago

Cloning a stopped track causes gUM capture to remain on until GC.

Categories

(Core :: WebRTC: Audio/Video, defect, P1)

50 Branch
Unspecified
macOS
defect

Tracking

()

RESOLVED FIXED
mozilla52
Tracking Status
firefox49 --- unaffected
firefox50 --- fixed
firefox51 --- fixed
firefox52 --- fixed

People

(Reporter: jib, Assigned: pehrsons)

References

Details

(Keywords: regression)

Attachments

(6 files)

STR (in 50 to avoid bug 1294576):

1. Open http://jsfiddle.net/jib1/6rLd2gr1/ and share selected devices.
2. Observe that "gUM is left off" and camera indicator disappears.
3. Uncomment this line: // stream.getTracks()[0].stop();
4. Hit "Run" to re-run fiddle, and share share selected devices.

Expected result: 
- "gUM is left off" and camera indicator disappears.

Actual result:
- "gUM is left on" and indicator turns into a microphone indicator that stays on for several seconds (GC).
Assignee: nobody → pehrson
Rank: 18
Priority: -- → P1
Status: NEW → ASSIGNED
This is from cloning an ended track, more specifically how SetReadyState() overrides the readyState but forgets to notify the source.
Blocks: 1208373
Depends on: 1295352
Comment on attachment 8783847 [details]
Bug 1294605 - Add explicit test case.

https://reviewboard.mozilla.org/r/73500/#review71760

lgtm.

::: dom/media/tests/mochitest/test_getUserMedia_trackCloneCleanup.html:12
(Diff revision 1)
> +<pre id="test">
> +<script type="application/javascript">
> +  "use strict";
> +
> +  createHTML({
> +    title: "Stopping a MediaStreamTrack and its clones should deallocated the device",

deallocate

::: dom/media/tests/mochitest/test_getUserMedia_trackCloneCleanup.html:24
(Diff revision 1)
> +    stream.clone().getTracks().forEach(t => stream.addTrack(t));
> +    is(stream.getTracks().filter(t => t.readyState == "live").length, 0,
> +       "Cloning ended tracks should make them ended");
> +    [...stream.getTracks(), ...clone.getTracks()].forEach(t => t.stop());
> +
> +    // Better to be explicit about noGum here wrt future refactoring.

Maybe add "bug 1295352" to this comment to remind us?
Attachment #8783847 - Flags: review?(jib) → review+
Comment on attachment 8783848 [details]
Bug 1294605 - Enable test code waiting for this bug.

https://reviewboard.mozilla.org/r/73502/#review71912
Attachment #8783848 - Flags: review?(jib) → review+
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

https://reviewboard.mozilla.org/r/73504/#review71914
Attachment #8783849 - Flags: review?(jib) → review+
Patches lgtm, but try seems plagued by ASSERTION: Track not found: 'Error'
(In reply to Jan-Ivar Bruaroey [:jib] from comment #8)
> Patches lgtm, but try seems plagued by ASSERTION: Track not found: 'Error'

The patch for that is ready to go on bug 1295352 :-)
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/4cfa56c2c97b
Add explicit test case. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/631047fcb5af
Enable test code waiting for this bug. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/8e71a7a64910
Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

Approval Request Comment
[Feature/regressing bug #]: bug 1208373
[User impact if declined]: Sometimes we keep devices (camera, microphone) open even though all tracks have been stopped - typically seen by the user as a camera light staying on when it shouldn't.
[Describe test coverage new/current, TreeHerder]: Mochitest added to m-c for this case.
[Risks and why]: Low risk. Code doesn't change any logic, just adds an extra step when cloning an ended track.
[String/UUID change made/needed]: None
Attachment #8783849 - Flags: approval-mozilla-aurora?
Sorry had to back out for Mochitest Media failures, e.g., https://treeherder.mozilla.org/logviewer.html#?job_id=34747845&repo=mozilla-inbound#L5288
Flags: needinfo?(pehrson)
Backout by ihsiao@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/25b4534dfbe5
Backed out changeset 8e71a7a64910 for Mochitest Media failures
https://hg.mozilla.org/integration/mozilla-inbound/rev/e0e9afd23bcb
Backed out changeset 631047fcb5af 
https://hg.mozilla.org/integration/mozilla-inbound/rev/aa3b176ed29a
Backed out changeset 4cfa56c2c97b
Flags: needinfo?(pehrson)
Comment on attachment 8785967 [details]
Bug 1294605 - Media element captureStream() streams shouldn't keep devices alive.

https://reviewboard.mozilla.org/r/74978/#review72840
Attachment #8785967 - Flags: review?(jib) → review+
Comment on attachment 8785968 [details]
Bug 1294605 - Notify MediaStreamTrackSource when track is notified of ended on main thread.

https://reviewboard.mozilla.org/r/74980/#review72844

::: dom/media/MediaStreamTrack.cpp:417
(Diff revision 1)
> +  MOZ_ASSERT(mSource);
> +  if (mSource) {
> +    mSource->UnregisterSink(this);
> +  }

Calling UnregisterSink twice seems safe.

A similar assert check in MediaStreamTrack::Stop() includes a bailout return in opt build as well. Should this one do the same?
Attachment #8785968 - Flags: review?(jib) → review+
Comment on attachment 8785968 [details]
Bug 1294605 - Notify MediaStreamTrackSource when track is notified of ended on main thread.

https://reviewboard.mozilla.org/r/74980/#review72844

> Calling UnregisterSink twice seems safe.
> 
> A similar assert check in MediaStreamTrack::Stop() includes a bailout return in opt build as well. Should this one do the same?

Sounds good to be consistent.
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2e6134a7093b
Add explicit test case. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/8a1756ac9539
Enable test code waiting for this bug. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/b6b24b4aa2f6
Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/1028b87b029e
Media element captureStream() streams shouldn't keep devices alive. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/7a14eea64c2a
Notify MediaStreamTrackSource when track is notified of ended on main thread. r=jib
Had to back this out to get no failing hunks on the backout of bug 1295352.
Flags: needinfo?(pehrson)
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

Please renominate once this lands and stabilizes on mozilla-central.
Attachment #8783849 - Flags: approval-mozilla-aurora?
We are finally getting close to relanding this.
Flags: needinfo?(pehrson)
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/1978000eae5e
Add explicit test case. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/eb930799bd15
Enable test code waiting for this bug. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/0593feead369
Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/443a94083e00
Media element captureStream() streams shouldn't keep devices alive. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/c0c023815311
Notify MediaStreamTrackSource when track is notified of ended on main thread. r=jib
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

Approval Request Comment
[Feature/regressing bug #]: Bug 1208373
[User impact if declined]: Stopping a track -- the preferred way of stopping audio/video device capture -- will not stop said capture immediately. It would take until the next garbage collection to get stopped. This affects the camera light indicator visible to users.
[Describe test coverage new/current, TreeHerder]: All webrtc mochitests on m-c now test this.
[Risks and why]: Low. The fix is very simple, but landed with plenty other patches that caused some fallout on m-c. Note that this fallout consisted only of test failures due to timing and false positives. There is a low risk that this patch causes something like that but it's very unlikely to affect functionality.
[String/UUID change made/needed]: None.

This request applies only to this patch.
Attachment #8783849 - Flags: approval-mozilla-beta?
Attachment #8783849 - Flags: approval-mozilla-aurora?
Sorry, backed bug 1295352 and bug 1294605 out for frequently failing mda test test_getUserMedia_trackEnded.html on Linux x64 debug:

Bug 1295352:
https://hg.mozilla.org/integration/mozilla-inbound/rev/4693d5445f6755dea29f763a5568c456cbf3d8cb
https://hg.mozilla.org/integration/mozilla-inbound/rev/0d2f0fcf7185290db6623557c66959e32b552c59
https://hg.mozilla.org/integration/mozilla-inbound/rev/eecba1a05d03f27cb3966948effe04a1c9bfec83
https://hg.mozilla.org/integration/mozilla-inbound/rev/aee84ca17a022f97e4544bd07e6dc54690020640
https://hg.mozilla.org/integration/mozilla-inbound/rev/60e3863206b89848720257e56b0a51fc454ec225
https://hg.mozilla.org/integration/mozilla-inbound/rev/051a29aa9419a32d6295f9e79362ceb3611b53a5
https://hg.mozilla.org/integration/mozilla-inbound/rev/be887787de62889d8761e4402b320f351d571d23

Bug 1294605:
https://hg.mozilla.org/integration/mozilla-inbound/rev/45b00bb6727a744bdc733578297418df6c9b1b58
https://hg.mozilla.org/integration/mozilla-inbound/rev/5a542246049e4ff7fc0c49234fdb49605047a8e2
https://hg.mozilla.org/integration/mozilla-inbound/rev/387012235302ccb073180d17ecea6e0d794dfcb3
https://hg.mozilla.org/integration/mozilla-inbound/rev/b82347df2602f07c7b190f0fbf7a6991d6022044
https://hg.mozilla.org/integration/mozilla-inbound/rev/40fb588cb1bc706a9c86dd5a27442714bd236afb

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=37972477&repo=mozilla-inbound

[task 2016-10-20T12:34:21.266367Z] 12:34:21     INFO -  2086 INFO TEST-PASS | dom/media/tests/mochitest/test_getUserMedia_trackEnded.html | Non-ended track should have readyState 'live'
[task 2016-10-20T12:34:21.267194Z] 12:34:21     INFO -  2087 INFO TEST-PASS | dom/media/tests/mochitest/test_getUserMedia_trackEnded.html | Non-ended track should have readyState 'live'
[task 2016-10-20T12:34:21.268021Z] 12:34:21     INFO -  2088 INFO iframe has been reset. Waiting for tracks to end.
[task 2016-10-20T12:34:21.268976Z] 12:34:21     INFO -  2089 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_getUserMedia_trackEnded.html | ended event never raised for track {27e92ba5-bd15-4636-bd27-50b7d180feba}
[task 2016-10-20T12:34:21.269789Z] 12:34:21     INFO -      allTracksEnded</<@dom/media/tests/mochitest/test_getUserMedia_trackEnded.html:44:25
[task 2016-10-20T12:34:21.270735Z] 12:34:21     INFO -      Async*allTracksEnded<@dom/media/tests/mochitest/test_getUserMedia_trackEnded.html:39:18
[task 2016-10-20T12:34:21.271640Z] 12:34:21     INFO -      @dom/media/tests/mochitest/test_getUserMedia_trackEnded.html:37:42
[task 2016-10-20T12:34:21.272537Z] 12:34:21     INFO -      Async*@dom/media/tests/mochitest/test_getUserMedia_trackEnded.html:28:12
[task 2016-10-20T12:34:21.273341Z] 12:34:21     INFO -      runTestWhenReady/<@dom/media/tests/mochitest/head.js:359:41
[task 2016-10-20T12:34:21.274221Z] 12:34:21     INFO -      Async*runTestWhenReady@dom/media/tests/mochitest/head.js:359:10
[task 2016-10-20T12:34:21.275018Z] 12:34:21     INFO -      runTest/<@dom/media/tests/mochitest/mediaStreamPlayback.js:274:15
[task 2016-10-20T12:34:21.275898Z] 12:34:21     INFO -      Async*runTest@dom/media/tests/mochitest/mediaStreamPlayback.js:273:31
[task 2016-10-20T12:34:21.276656Z] 12:34:21     INFO -      @dom/media/tests/mochitest/test_getUserMedia_trackEnded.html:22:3
Status: RESOLVED → REOPENED
Flags: needinfo?(pehrson)
Resolution: FIXED → ---
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

Please renominate once test failures are addressed and this gets landed on m-c.
Attachment #8783849 - Flags: approval-mozilla-beta?
Attachment #8783849 - Flags: approval-mozilla-aurora?
I think we failed here because it took us so long to bounce to MSG thread (remove the listener) and back to main thread (listener removed, ok  that the slightly-too-aggressive timeout of 5 seconds timed out.

[1] is a run with a 50 second timeout and MediaStream,MediaStreamTrack,MediaManager logs.


[1] https://treeherder.mozilla.org/#/jobs?repo=try&revision=3fb6ec098fdf
Flags: needinfo?(pehrson)
Comment on attachment 8803337 [details]
Bug 1294605 - Increase 'ended' timeout in test_gUM_trackEnded.html.

https://reviewboard.mozilla.org/r/87654/#review86590
Attachment #8803337 - Flags: review?(jib) → review+
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/77a7f70e04f5
Add explicit test case. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/ba9fd44ecdcf
Enable test code waiting for this bug. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/d7cc714009d4
Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/aec40f5bbff7
Media element captureStream() streams shouldn't keep devices alive. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/316fdba6ea47
Notify MediaStreamTrackSource when track is notified of ended on main thread. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/f6811b39af13
Increase 'ended' timeout in test_gUM_trackEnded.html. r=jib
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

Approval Request Comment

See comment 33.


Filing this already now since I'll be away next week. I think it will stick.
Attachment #8783849 - Flags: approval-mozilla-beta?
Attachment #8783849 - Flags: approval-mozilla-aurora?
Comment on attachment 8783849 [details]
Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden.

This seems like a core scenario and a recent regression in 50, Aurora51+, Beta50+
Attachment #8783849 - Flags: approval-mozilla-beta?
Attachment #8783849 - Flags: approval-mozilla-beta+
Attachment #8783849 - Flags: approval-mozilla-aurora?
Attachment #8783849 - Flags: approval-mozilla-aurora+
Hello Jan-Ivar, could you please verify this issue is fixed as expected on a latest Nightly build? Thanks!
Flags: needinfo?(jib)
The second patch is hitting conflicts applying to aurora. Could we get rebased patches?
Flags: needinfo?(pehrson)
The issue still happens for me with the reproduce steps in comment 0. :-( Andreas, thoughts on what's up?
Flags: needinfo?(jib)
Until we resolve why we're not seeing it fixed on Nightly, let's hold on the uplifts.  Thanks
Here's a fiddle showing that something got fixed: https://jsfiddle.net/jib1/fy289gca/

When run, it ends with "gUM is on" in 49 and "gUM is off" in Nightly. This fiddle more closely resembles the mochitest, which explains why it passes.

I'm looking into the difference between this fiddle and the one in comment 0.
Agree with Randell that we hold off any uplifts.  As you can see in Comment 55, I've asked Jan-Ivar to look into why the fix didn't work for him (Jan-Ivar) since Andreas is at an offsite until Friday.
Depends on: 1312833
No longer depends on: 1312833
Mystery solved! It's not fixed because the code isn't on central.

Bad merge: https://hg.mozilla.org/mozilla-central/rev/806054dd12bd

(Comment 55 was a red herring, pilot error on my part, as there seems to be a timing component).
Status: RESOLVED → REOPENED
Flags: needinfo?(ryanvm)
Resolution: FIXED → ---
Pushed by rjesup@wgate.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f6927a9b3488
Notify MediaStreamTrackSource when track is notified of ended on main thread. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/8e21afb88dbb
Media element captureStream() streams shouldn't keep devices alive. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/7545f9159a1b
Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/7511487c9b5e
Add explicit test case. r=jib
The other two patches (1st (f6811b39af13) and 5th (ba9fd44ecdcf)) weren't backed out accidentally, so didn't need re-landing.
Flags: needinfo?(pehrson)
Sorry had to back out this for mda bustage and failures, such as https://treeherder.mozilla.org/logviewer.html#?job_id=38240587&repo=mozilla-inbound#L13086
Flags: needinfo?(rjesup)
Why was I ni? here? I just did the inbound->central merge. You're saying something broke in the process of doing that?
Flags: needinfo?(ryanvm) → needinfo?(jib)
Ryan, if you follow the hg link in comment 59 and search for e.g.

  dom/media/tests/mochitest/test_getUserMedia_trackCloneCleanup.html

you'll see your merge 806054dd12bd erased at least the four patches in this bug that had already landed on central in comment 49 and that jesup just attempted to re-land in comment 60. There may be other fallout that I'm not aware of, so you might want to doublecheck that that merge didn't erase anything else as well. FYI.

> | o    806054dd12bd  | 2016-10-21 11:08:45 -0400 | ryanvm: Merge m-c to inbound. a=merge
> | |\
> | | o  f6811b39af13  | 2016-10-21 15:46:17 +0200 | pehrsons: Bug 1294605 - Increase 'ended' timeout in test_gUM_trackEnded.html. r=jib
> | | |
> | | o  316fdba6ea47  | 2016-08-29 16:34:27 +0200 | pehrsons: Bug 1294605 - Notify MediaStreamTrackSource when track is notified of ended on main thread. r=jib
> | | |
> | | o  aec40f5bbff7  | 2016-08-29 16:27:11 +0200 | pehrsons: Bug 1294605 - Media element captureStream() streams shouldn't keep devices alive. r=jib
> | | |
> | | o  d7cc714009d4  | 2016-08-22 18:28:10 +0200 | pehrsons: Bug 1294605 - Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
> | | |
> | | o  ba9fd44ecdcf  | 2016-08-22 18:27:38 +0200 | pehrsons: Bug 1294605 - Enable test code waiting for this bug. r=jib
> | | |
> | | o  77a7f70e04f5  | 2016-08-30 14:24:33 +0200 | pehrsons: Bug 1294605 - Add explicit test case. r=jib
> | | |
> | | o  57f7b75e5a62  | 2016-08-30 14:17:59 +0200 | pehrsons: Bug 1295352 - Release MediaEngineTabVideoSource main-thread-only members on main thread. r=jesup
> | | |
> | | o  907d83f36492  | 2016-08-29 16:37:16 +0200 | pehrsons: Bug 1295352 - Update mediaElementCapture tests to stop all tracks before finishing. r=jib
> | | |
> | | o  f3dae14842ec  | 2016-08-25 12:25:06 +0200 | pehrsons: Bug 1295352 - Use mState in MediaEngineTabVideoSource. r=jesup
> | | |
> | | o  a7c8bab2624a  | 2016-08-23 10:45:09 +0200 | pehrsons: Bug 1295352 - Check state in MediaEngines' NotifyPull(). r=jesup
> | | |
> | | o  572f17fd9e60  | 2016-08-12 15:18:51 -0400 | jib: Bug 1295352 - Fix media mochitests to not end with active gUM. r=pehrsons
> | | |
> | | o  f5e778110195  | 2016-08-12 16:43:16 -0400 | jib: Bug 1295352 - Changed default MediaStreamPlayback.playMedia() to stop tracks afterwards. r=pehrsons
> | | |
> | | o  c827628cdf72  | 2016-08-05 00:46:25 -0400 | jib: Bug 1295352 - Check that there is no active gUM after each runTest test. r=pehrsons
> | | |
Flags: needinfo?(jib) → needinfo?(ryanvm)
In fact the mda bustage in comment 62 suggests more patches I list in comment 65 were erased too, specifically from Bug 1295352 which added the noGum code this test I mention in comment 65 depends on:

TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_getUserMedia_trackCloneCleanup.html | Error executing test: ReferenceError: noGum is not defined @http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_trackCloneCleanup.html:25:5 ... Async*@http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_trackCloneCleanup.html:16:17
In other words, you landed those in Bug 1295352 comment 48 and they're not on central either.
I've been going through the rest of that merge and these two bugs are literally the only two that seem to show a discrepancy with what landed vs. what's currently on m-c tip. I'm at a loss, here.
Flags: needinfo?(ryanvm)
Pushed by rjesup@wgate.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/0323c3a47285
Add explicit test case. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/e20bc37dc490
Enable test code waiting for this bug. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/8e92a1d742e6
Notify MediaStreamTrackSource when ReadyState is overriden. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/90aeec6ac062
Media element captureStream() streams shouldn't keep devices alive. r=jib
https://hg.mozilla.org/integration/mozilla-inbound/rev/2f89f1ef242e
Notify MediaStreamTrackSource when track is notified of ended on main thread. r=jib
Wes, we're only looking for uplift of a single patch, the third patch (Notify MediaStreamTrackSource when ReadyState is overriden) to aurora, and it applies cleanly for me.
And beta. I just tested pehrsons lone patch in both beta and aurora, and it works.
Flags: needinfo?(rjesup)
You need to log in before you can comment on or make changes to this bug.