Closed Bug 918523 Opened 6 years ago Closed 6 years ago

getUserMedia audio streams will be released after a period of time while running in a background app

Categories

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

26 Branch
ARM
Gonk (Firefox OS)
defect
Not set

Tracking

()

VERIFIED FIXED
mozilla27
blocking-b2g koi+
Tracking Status
firefox25 --- wontfix
firefox26 --- fixed
firefox27 --- fixed
b2g-v1.2 --- fixed

People

(Reporter: jsmith, Assigned: schien)

References

Details

(Whiteboard: [getusermedia])

Attachments

(2 files, 2 obsolete files)

Build: Master 9/17/2013
Device: Buri

STR

1. Go to http://mozilla.github.io/webrtc-landing/gum_test.html
2. Select Audio
3. Accept permissions
4. Hit the home button
5. Wait for a while
6. Launch the browser

Expected

The getUserMedia audio stream should still be active when I check playback in the browser.

Actual

If you wait long enough (~30 seconds), then you'll notice playback has stopped of the getUserMedia audio stream. This implies that the gUM audio stream was released while the app was running in the background.
Blocks: 894848
blocking-b2g: --- → koi?
Logs with timestamp,getusermedia:5,mediamanager:5,mediastreamgraph:5 please.
Thanks
Whiteboard: [getusermedia]
Blocks: b2g-getusermedia
No longer blocks: 894848
(In reply to Randell Jesup [:jesup] from comment #1)
> Logs with timestamp,getusermedia:5,mediamanager:5,mediastreamgraph:5 please.
> Thanks

When trying to run the steps at https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging#Firefox_OS_phones, I'm seeing the nspr file being created, but nothing is being written to it when running the gum test page. So no luck so far getting NSPR logs. I'm also seeing running b2g.sh failing:

root@android:/ # /system/bin/b2g.sh
/system/bin/b2g.sh
-*- RadioInterfaceLayer: 1 interfaces
###################################### forms.js loaded
############################### browserElementPanning.js loaded
######################## BrowserElementChildPreload.js loaded
RIL Worker[0]: ICC I/O Error code RequestNotSupported EF id = 6fc5 command = b2
RIL Worker[0]: ICC I/O Error code RequestNotSupported EF id = 6fc6 command = b2
XXX FIXME : Got a mozContentEvent: system-message-listener-ready
Unable to create nspr log file '/data/nspr.txt'
RIL Worker[0]: DateTimeZone string 13/09/20,18:25:37-28,01
XXX FIXME : Got a mozContentEvent: accessibility-screenreader

mwu - Why is NSPR logging failing on 1.2 builds right now? Any ideas?
Flags: needinfo?(mwu)
Attached file Logcat
Logcat shows nothing I'm afraid (was this a debug build?)
(In reply to Randell Jesup [:jesup] from comment #4)
> Logcat shows nothing I'm afraid (was this a debug build?)

Nope, it's a production build.

https://pvtbuilds.mozilla.org/pvt/mozilla.org/b2gotoro/nightly/mozilla-aurora-hamachi/latest/
The ready queue seems starved since I saw the following error is occur after resuming browser app.
http://dxr.mozilla.org/mozilla-central/source/media/webrtc/trunk/webrtc/modules/audio_device/audio_device_opensles.cc#l1451
(In reply to Jason Smith [:jsmith] from comment #2)
> mwu - Why is NSPR logging failing on 1.2 builds right now? Any ideas?

/data/ isn't a good location to put log files. See the note on the mdn page that says: "On Firefox OS, child processes are only allowed to open files in /data/local/tmp, so you must be sure to set NSPR_LOG_FILE to a file in that directory; otherwise, the child processes won't be able to write their log files."
Flags: needinfo?(mwu)
Okay. I'll take another shot at getting the logs this time the right way.
Flags: needinfo?(jsmith)
This time I got a generated log file, but the log file has no output when this bug reproduces.
Flags: needinfo?(jsmith)
I tested this also with the basic HTTP logging (timestamp,nsHttp:5,nsSocketTransport:5,nsHostResolver:5) included on the MDN page and in that case, I'm getting lots of output in the NSPR logging. So I'm not sure why the nspr log modules suggested above are not generating output.
Now I know the root cause of this bug.
The Rec thread will be blocked for a while after switching background app to foreground, therefore, all the 16 audio buffer will be push to rec_voe_audio_queue. The rec_queue/queue_itf will become empty and RecorderSimpleBufferQueueCallbackHandler will not be invoked afterward [1].
Even after Rec thread wake up and flush all the audio buffer to rec_voe_ready_queue, the rec_queue cannot be reload since the Enqueue is invoked in RecorderSimpleBufferQueueCallbackHandler [2] (which is not going to happened).

@jesup, do you have any suggestion that we can stop moving audio buffer from rec_queue to rec_voe_audio_queue before draining rec_queue?

[1] https://www.codeaurora.org/cgit/quic/la/platform/system/media/tree/wilhelm/src/android/AudioRecorder_to_android.cpp?h=ics_chocolate_rb4.2#n225
[2] http://dxr.mozilla.org/mozilla-central/source/media/webrtc/trunk/webrtc/modules/audio_device/audio_device_opensles.cc#l1464
Flags: needinfo?(rjesup)
Attached patch WIP - prevent rec_queue overrun (obsolete) — Splinter Review
Discarding the latest audio frame before we break the balance between audio_queue and ready_queue.
Attachment #809777 - Flags: feedback?(rjesup)
Assignee: nobody → schien
blocking-b2g: koi? → koi+
Comment on attachment 809777 [details] [diff] [review]
WIP - prevent rec_queue overrun

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

::: media/webrtc/trunk/webrtc/modules/audio_device/audio_device_opensles.cc
@@ +1464,3 @@
>      } else {
> +      // discard the latest audio frame
> +      memset(audio, 0, total_bytes);

the memset is irrelevant
Add a comment that the audio buffer will just be recycled (to OpenSL Enqueue()) instead of sent to the recthread
Attachment #809777 - Flags: feedback?(rjesup) → feedback+
Attached patch prevent-rec-queue-overrun.patch (obsolete) — Splinter Review
Update with feedback comment addressed.
Attachment #809777 - Attachment is obsolete: true
Attachment #811156 - Flags: review?(rjesup)
Comment on attachment 811156 [details] [diff] [review]
prevent-rec-queue-overrun.patch

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

r=me with the timer Set()

::: media/webrtc/trunk/webrtc/modules/audio_device/audio_device_opensles.cc
@@ +1464,2 @@
>      } else {
> +      // the audio frame will be recycled instead of sending to rec thread.

Probably should call rec_timer_.Set() here, just to make sure the rec thread wakes up to process the data queued for it.  Might not be strictly needed, but I don't think it can hurt, and it provides a bit of belt-and-suspenders
Attachment #811156 - Flags: review?(rjesup) → review+
update according to review comment, carry r+.
https://tbpl.mozilla.org/?tree=Try&rev=c96a48471a01
Attachment #811156 - Attachment is obsolete: true
Attachment #811491 - Flags: review+
https://hg.mozilla.org/mozilla-central/rev/8be7c8f3da4b
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla27
Keywords: verifyme
QA Contact: jsmith
lgtm - tested with a 5 minute gUM audio request running in the background and returning it to the foreground
Keywords: verifyme
Status: RESOLVED → VERIFIED
You need to log in before you can comment on or make changes to this bug.