getUserMedia - Video playback does not resume when browser returns to being the foreground activity

VERIFIED FIXED in Firefox 24

Status

()

Core
WebRTC: Audio/Video
VERIFIED FIXED
5 years ago
5 years ago

People

(Reporter: aaronmt, Assigned: gcp)

Tracking

(Blocks: 1 bug)

Trunk
mozilla24
ARM
Android
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox24 verified)

Details

(Whiteboard: [getUserMedia][android-gum+], URL)

Attachments

(2 attachments, 1 obsolete attachment)

(Reporter)

Description

5 years ago
Currently when the browser is paused and sent into the background; video playback suspends/ When the browser is brought up onto the foreground and resumed video playback does not continue. However, audio playback continues. I would have expected video playback to continue when the browser is foreground activity.

Steps:

i) http://mozilla.github.io/webrtc-landing/gum_test.html
ii) Tap 'Video'
iii) Hit the device home-button
iv) Restore the browser to the foreground activity

ER: Video resumes playback
AR: Video suspended

--
HTC One (Android 4.1, Nightly 05/21)
LG Nexus 4 (Android 4.2.2, Nightly 05/21)
roc: is this the video element?  Audio restarts, so I imagine video should be trying to; perhaps the video element isn't restoring the Play state?

Aaron: can you get logs from a debug build with mediamanager:5,signaling:5,mediastreamgraph:6 logging?  Note: the MSG logging will generate a lot of logs; if that chokes logcat you may need to drop to :5.
Flags: needinfo?(roc)
Flags: needinfo?(aaron.train)
Whiteboard: [getUserMedia][blocking-gum-][android-gum?]

Updated

5 years ago
Blocks: 750010
I'm calling blocker on this one mainly because audio and video can get out of sync as a result of this bug, which will be bad if someone is trying to do an audio/video call with someone else.
Whiteboard: [getUserMedia][blocking-gum-][android-gum?] → [getUserMedia][blocking-gum-][android-gum+]

Updated

5 years ago
Component: WebRTC → WebRTC: Audio/Video
Try replacing the use of getUserMedia with a MediaStream obtained from a video element loading a video resource and mozCaptureStream(). If that's broken, it's a video playback problem, otherwise it's a getUserMedia problem.
Flags: needinfo?(roc)
(Reporter)

Comment 4

5 years ago
(In reply to Randell Jesup [:jesup] from comment #1)
> Aaron: can you get logs from a debug build with
> mediamanager:5,signaling:5,mediastreamgraph:6 logging?  Note: the MSG
> logging will generate a lot of logs; if that chokes logcat you may need to
> drop to :5.

I'm not familiar with this logging. Can you upload to your people account a debug build with this enabled and I'll more than gladly capture some output to attach to this bug?
Flags: needinfo?(aaron.train)
(In reply to Aaron Train [:aaronmt] from comment #4)
> (In reply to Randell Jesup [:jesup] from comment #1)
> > Aaron: can you get logs from a debug build with
> > mediamanager:5,signaling:5,mediastreamgraph:6 logging?  Note: the MSG
> > logging will generate a lot of logs; if that chokes logcat you may need to
> > drop to :5.
> 
> I'm not familiar with this logging. Can you upload to your people account a
> debug build with this enabled and I'll more than gladly capture some output
> to attach to this bug?

He's talking about NSPR logging.

I think the docs are here - https://wiki.mozilla.org/Mobile/Fennec/Android#PR_Logging.

I'd imagine you would probably want to run:

 adb shell am start -a android.activity.MAIN -n org.mozilla.fennec_$USER/.App --es env0 NSPR_LOG_MODULES=mediamanager:5,signaling:5,mediastreamgraph:6

And you should see NSPR logging comments under the title of PRLog.
(Reporter)

Comment 6

5 years ago
Created attachment 754532 [details]
log

With logging enabled I get a SIGSEV in the compositor thread unfortunately on attempt to resume the browser activity as mentioned in my comment #0. I have attached what I can capture that happens when I attempt to make the browser resume as the foreground activity.
(Assignee)

Updated

5 years ago
Assignee: nobody → gpascutto
(Assignee)

Comment 7

5 years ago
Created attachment 756499 [details] [diff] [review]
Patch 1. Detach preview when surface is destroyed
Attachment #756499 - Flags: review?(rjesup)
Comment on attachment 756499 [details] [diff] [review]
Patch 1. Detach preview when surface is destroyed

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

I'm afraid I know nothing of this layer or the Android calls it's making, so I can't provide any sort of reasonable review.  Someone who at least knows Android/Java would be a better choice, even if they don't know webrtc or media.
Attachment #756499 - Flags: review?(rjesup)
(Assignee)

Comment 9

5 years ago
Comment on attachment 756499 [details] [diff] [review]
Patch 1. Detach preview when surface is destroyed

Moving to blassey.
Attachment #756499 - Flags: review?(blassey.bugs)
(Assignee)

Comment 10

5 years ago
Created attachment 757295 [details] [diff] [review]
Patch 1 v2. Detach preview when surface is destroyed

Cleaned this up a bit.
Attachment #756499 - Attachment is obsolete: true
Attachment #756499 - Flags: review?(blassey.bugs)
Attachment #757295 - Flags: review?(blassey.bugs)
(Assignee)

Comment 11

5 years ago
Comment on attachment 757295 [details] [diff] [review]
Patch 1 v2. Detach preview when surface is destroyed

These patches don't actually fix the bug. It's just not 100% reproducible, sometimes crashes on backgrounding, sometimes on foregrounding again.

Combined with the patches in bug 874572 I can still get a crash even if all WebRTC Camera stuff is disabled, so this is a bit suspicious in that the crash might be due to interaction with non WebRTC parts.

I see bugs like bug 771189, bug 759162, bug 772672 and bug 844275 talking about Compositor crashes when receiving surfaceChanged/surfaceCreated/surfaceChanged events, and that's exactly what's happening here...
Attachment #757295 - Attachment is obsolete: true
Attachment #757295 - Flags: review?(blassey.bugs)
(Assignee)

Comment 12

5 years ago
Guys, any idea why the Compositor crashes shortly after the AndroidVideoCapture classes receive surfaceChanged/surfaceCreated/surfaceDestroyed from SurfaceHolder.Callback preview surface?
(Assignee)

Comment 13

5 years ago
My wild theory is that due to things like this:
http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/GeckoApp.java#1237
http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/gfx/LayerView.java#108

The LayerView might be misinterpreting surfaceXXXX messages meant for the cameraView that's in there as being meant for the LayerView it's intended to act upon.
(Assignee)

Comment 14

5 years ago
After reading a bit more what that code does, that doesn't really look possible. It seems more likely that it just happens that both the camera preview surface and the main surface Gecko is rendering to both get a surfaceXXXX message, and it's being mishandled on the Gecko/GFX/Rendering side of things.
(Assignee)

Comment 15

5 years ago
I added logging to check the above:

D/GeckoLayerView(31802): SurfaceListener::surfaceDestroyed
D/GeckoGLController(31802): GLController::surfaceDestroyed
D/GeckoAppShell(31802): Gecko event sync taking too long: 100ms
D/GeckoAppShell(31802): Gecko event sync taking too long: 201ms
I/Gecko   (31802): WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file /home/morbo/hg/mozilla-central/xpcom/threads/nsThread.cpp, line 446
I/Gecko   (31802): AndroidBridge::AcknowledgeEvent
D/WEBRTC-JC(31802): VideoCaptureAndroid::surfaceDestroyed
D/GeckoMemoryMonitor(31802): onTrimMemory() notification received with level 20
F/MOZ_Assert(31802): Assertion failure: IsCurrent(), at ../../../dist/include/GLContext.h:1441
F/libc    (31802): Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1), thread 31936 (Compositor)
(Assignee)

Comment 16

5 years ago
Backtrace:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 4621]
0x7c524d3a in mozilla::gl::GLContext::BeforeGLCall (this=0x85c0a400, 
    glFunction=0x7ea36444 <mozilla::gl::GLContext::fActiveTexture(unsigned int)::__PRETTY_FUNCTION__> "")
    at ../../../dist/include/GLContext.h:1441
1441	        MOZ_ASSERT(IsCurrent());
    at ../../../dist/include/GLContext.h:1641
#2  0x7d86ee9e in mozilla::gl::GLContext::UploadSurfaceToTexture (this=0x85c0a400, aSurface=0x8040a940, 
    aDstRegion=..., aTexture=@0x83cde6c8: 248, aOverwrite=false, aSrcPoint=..., aPixelBuffer=false, 
    aTextureUnit=33984) at /home/morbo/hg/mozilla-central/gfx/gl/GLContext.cpp:1945
#3  0x7d87651a in mozilla::gl::BasicTextureImage::DirectUpdate (this=0x83cde6a0, aSurf=0x8040a940, 
    aRegion=..., aFrom=...) at /home/morbo/hg/mozilla-central/gfx/gl/GLTextureImage.cpp:165
#4  0x7d8510c8 in mozilla::layers::YCbCrTextureHostOGL::UpdateImpl (this=0x8040a700, aImage=..., 
    aRegion=0x0, aOffset=0x0) at /home/morbo/hg/mozilla-central/gfx/layers/opengl/TextureHostOGL.cpp:533
#5  0x7d7f6b96 in mozilla::layers::TextureHost::SwapTexturesImpl (this=0x8040a700, aImage=..., 
    aRegion=0x0) at ../../dist/include/mozilla/layers/TextureHost.h:328
#6  0x7d84e2d0 in mozilla::layers::TextureHost::SwapTextures (this=0x8040a700, aImage=..., 
    aResult=0x860ff7c4, aRegion=0x0)
    at /home/morbo/hg/mozilla-central/gfx/layers/composite/TextureHost.cpp:103
#7  0x7d82f34a in mozilla::layers::ImageHostBuffered::Update (this=0x85028d00, aImage=..., 
    aResult=0x860ff7c4) at /home/morbo/hg/mozilla-central/gfx/layers/composite/ImageHost.cpp:164
#8  0x7d80bc1a in mozilla::layers::CompositableParentManager::ReceiveCompositableUpdate (
    this=0x8300b9a8, aEdit=..., replyv=...)
    at /home/morbo/hg/mozilla-central/gfx/layers/ipc/CompositableTransactionParent.cpp:98
#9  0x7d82ad38 in mozilla::layers::ImageBridgeParent::RecvUpdate (this=0x8300b7e0, aEdits=..., 
    aReply=0x860ffa60) at /home/morbo/hg/mozilla-central/gfx/layers/ipc/ImageBridgeParent.cpp:52
#10 0x7d2b195a in mozilla::layers::PImageBridgeParent::OnMessageReceived (this=0x8300b7e0, __msg=..., 
    __reply=@0x860ffbc4: 0x0)
    at /home/morbo/hg/mozilla-central/objdir-android/ipc/ipdl/PImageBridgeParent.cpp:510
#11 0x7d13a7ac in mozilla::ipc::SyncChannel::OnDispatchMessage (this=0x8300b7f0, msg=...)
    at /home/morbo/hg/mozilla-central/ipc/glue/SyncChannel.cpp:145
#12 0x7d134c72 in mozilla::ipc::RPCChannel::OnMaybeDequeueOne (this=0x8300b7f0)
    at /home/morbo/hg/mozilla-central/ipc/glue/RPCChannel.cpp:400
#13 0x7d0236ee in DispatchToMethod<ThumbnailRunnable, tag_nsresult (ThumbnailRunnable::*)()> (
    obj=0x8300b7f0, method=
    (tag_nsresult (ThumbnailRunnable::*)(ThumbnailRunnable * const)) 0x7d134ac9 <mozilla::ipc::RPCChannel::OnMaybeDequeueOne()>, arg=...) at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/tuple.h:383
#14 0x7d023660 in RunnableMethod<ThumbnailRunnable, tag_nsresult (ThumbnailRunnable::*)(), Tuple0>::Run (
    this=0x85ee52c0) at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/task.h:307
#15 0x7d13379c in mozilla::ipc::RPCChannel::RefCountedTask::Run (this=0x85efb250)
    at ../../dist/include/mozilla/ipc/RPCChannel.h:425
#16 0x7d133880 in mozilla::ipc::RPCChannel::DequeueTask::Run (this=0x804f3aa0)
    at ../../dist/include/mozilla/ipc/RPCChannel.h:448
#17 0x7d755464 in MessageLoop::RunTask (this=0x860ffddc, task=0x804f3aa0)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_loop.cc:337
#18 0x7d7554c0 in MessageLoop::DeferOrRunPendingTask (this=0x860ffddc, pending_task=...)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_loop.cc:345
#19 0x7d75580c in MessageLoop::DoWork (this=0x860ffddc)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_loop.cc:445
#20 0x7d75924a in base::MessagePumpDefault::Run (this=0x85cc0060, delegate=0x860ffddc)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_pump_default.cc:23
#21 0x7d755004 in MessageLoop::RunInternal (this=0x860ffddc)
---Type <return> to continue, or q <return> to quit---
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_loop.cc:219
#22 0x7d754f9e in MessageLoop::RunHandler (this=0x860ffddc)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_loop.cc:212
#23 0x7d754f46 in MessageLoop::Run (this=0x860ffddc)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/message_loop.cc:186
#24 0x7d77158c in base::Thread::ThreadMain (this=0x8590f160)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/thread.cc:160
#25 0x7d78296a in ThreadFunc (closure=0x8590f160)
    at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/platform_thread_posix.cc:39
#26 0x402743dc in __thread_entry ()
   from /home/morbo/jimdb/moz-gdb/lib/00658c727e962a43/system/lib/libc.so
#27 0x40273ac8 in pthread_create ()
   from /home/morbo/jimdb/moz-gdb/lib/00658c727e962a43/system/lib/libc.so
#28 0x00000000 in ?? ()
(Assignee)

Comment 17

5 years ago
I'm testing this a bit on other devices that produce different/more log output. On my Galaxy Tab 10.1, I get a stream of Surface errors on the gum test page. If I apply the patch that was here, those go away. So the patch is indeed useful in that it will stop Android from trying to capture frames from a nonexistent surface, and the gum test works fine. (Or I'm lucky)

The mobile WebRTC demo page still produces Surface errors, though, and seems to show Gecko locking up:

V/WEBRTC-JC(14605): preview frame length 460800 context1859031040
E/TODmobile(10554): hour : 10    minute : 51
D/GeckoLayerView(14605): SurfaceListener::surfaceDestroyed
D/GeckoGLController(14605): GLController::surfaceDestroyed
D/GeckoAppShell(14605): Gecko event sync taking too long: 100ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 201ms
V/NvOmxCamera(  244): disableMsgType => 0x10
D/GeckoAppShell(14605): Gecko event sync taking too long: 301ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 402ms
W/AudioFlinger(  244): RecordThread: buffer overflow
D/GeckoAppShell(14605): Gecko event sync taking too long: 502ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 602ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 703ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 803ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 903ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1004ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1104ms
V/WindowOrientationListener(  303): rotation : 0   Angle: 353   tilt: 39
D/GeckoAppShell(14605): Gecko event sync taking too long: 1205ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1305ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1407ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1508ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1608ms
D/GeckoAppShell(14605): Gecko event sync taking too long: 1708ms
I/Gecko   (14605): WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file /home/morbo/hg/mozilla-central/xpcom/threads/nsThread.cpp, line 446
I/Gecko   (14605): AndroidBridge::AcknowledgeEvent
I/SurfaceFlinger(  241): id=122 Removed SurfaceView idx=3 Map Size=5
I/SurfaceFlinger(  241): id=122 Removed SurfaceView idx=-2 Map Size=5
D/WEBRTC-JC(14605): VideoCaptureAndroid::surfaceDestroyed
V/NvOmxCamera(  244): disableMsgType => 0x10
D/SecCameraHardwareInterface(  244): virtual void android::SecCameraHardwareInterface::stopPreview():stop IT Policy checking thread
F/MOZ_Assert(14605): Assertion failure: IsCurrent(), at ../../../dist/include/GLContext.h:1441
I/DEBUG   (  240): debuggerd committing suicide to free the zombie!
I/DEBUG   (15460): debuggerd: Dec  9 2011 16:50:15
(Assignee)

Comment 18

5 years ago
If I'm reading the backtraces correctly, this is happening when we try to snap a thumbnail of the tab?

#13 0x7d0236ee in DispatchToMethod<ThumbnailRunnable, tag_nsresult (ThumbnailRunnable::*)()> (
    obj=0x8300b7f0, method=
    (tag_nsresult (ThumbnailRunnable::*)(ThumbnailRunnable * const)) 0x7d134ac9 <mozilla::ipc::RPCChannel::OnMaybeDequeueOne()>, arg=...) at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/tuple.h:383
#14 0x7d023660 in RunnableMethod<ThumbnailRunnable, tag_nsresult (ThumbnailRunnable::*)(), Tuple0>::Run (
    this=0x85ee52c0) at /home/morbo/hg/mozilla-central/ipc/chromium/src/base/task.h:307
(Assignee)

Comment 19

5 years ago
Comment on attachment 757295 [details] [diff] [review]
Patch 1 v2. Detach preview when surface is destroyed

Okay, I have proof that the crash is due to <video>, and not WebRTC specific. Let's take this patch, which will fix the WebRTC side of things, and I'm going to file the Compositor crash separately.
Attachment #757295 - Flags: review?(blassey.bugs)
(Assignee)

Updated

5 years ago
Attachment #757295 - Attachment is obsolete: false

Updated

5 years ago
Whiteboard: [getUserMedia][blocking-gum-][android-gum+] → [getUserMedia][android-gum+]
Attachment #757295 - Flags: review?(blassey.bugs) → review+
https://hg.mozilla.org/mozilla-central/rev/e243e1b099f3
Status: NEW → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla24

Updated

5 years ago
Keywords: verifyme
QA Contact: jsmith
(Reporter)

Updated

5 years ago
Status: RESOLVED → VERIFIED
status-firefox24: --- → verified
Keywords: verifyme

Updated

5 years ago
Blocks: 863290
You need to log in before you can comment on or make changes to this bug.