Closed Bug 874546 Opened 6 years ago Closed 6 years ago

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

Categories

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

ARM
Android
defect
Not set

Tracking

()

VERIFIED FIXED
mozilla24
Tracking Status
firefox24 --- verified

People

(Reporter: aaronmt, Assigned: gcp)

References

(Blocks 1 open bug, )

Details

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

Attachments

(2 files, 1 obsolete file)

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?]
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+]
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)
(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.
Attached file 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: nobody → gpascutto
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)
Comment on attachment 756499 [details] [diff] [review]
Patch 1. Detach preview when surface is destroyed

Moving to blassey.
Attachment #756499 - Flags: review?(blassey.bugs)
Cleaned this up a bit.
Attachment #756499 - Attachment is obsolete: true
Attachment #756499 - Flags: review?(blassey.bugs)
Attachment #757295 - Flags: review?(blassey.bugs)
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)
Guys, any idea why the Compositor crashes shortly after the AndroidVideoCapture classes receive surfaceChanged/surfaceCreated/surfaceDestroyed from SurfaceHolder.Callback preview surface?
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.
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.
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)
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 ?? ()
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
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
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)
Attachment #757295 - Attachment is obsolete: false
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
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla24
Keywords: verifyme
QA Contact: jsmith
Status: RESOLVED → VERIFIED
Keywords: verifyme
Blocks: 863290
You need to log in before you can comment on or make changes to this bug.