Closed Bug 1112412 Opened 9 years ago Closed 6 years ago

[Video] Repeatedly pausing and playing video gives "Another app is currently using the video player" error

Categories

(Firefox OS Graveyard :: Gaia::Video, defect)

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(tracking-b2g:backlog, b2g-v2.0 unaffected, b2g-v2.1 affected, b2g-v2.2 affected)

RESOLVED WONTFIX
tracking-b2g backlog
Tracking Status
b2g-v2.0 --- unaffected
b2g-v2.1 --- affected
b2g-v2.2 --- affected

People

(Reporter: bzumwalt, Unassigned)

References

()

Details

(Keywords: regression, Whiteboard: [2.2-exploratory-2][priority])

Attachments

(3 files)

Attached file Logcat
Description:
When user plays a video in video app, pressing play and pause repeatedly causes error message "Another app is currently using the video player". The player must close the app in card view to continue using video player. This occurs on all tested file types (webm, mp4, and 3gp), but appears to occur quicker on webm files.
   
Repro Steps:
1) Update a Flame device to BuildID: 20141216040205
2) Launch video app and play webm file
3) Repeatedly press play/pause button (doesn't need to be super-fast presses)
  
Actual:
Error "Another app is currently using the video player" is displayed.
  
Expected: 
Video plays/pauses as expected.
  
Environmental Variables:
Device: Flame 2.2 Master (319mb)(Kitkat Base)(Full Flash)
BuildID: 20141216040205
Gaia: af3d2f89f391c92667e04676fc0ac971e6021bb7
Gecko: a3030140d5df
Gonk: e5c6b275d77ca95fb0f2051c3d2242e6e0d0e442
Version: 37.0a1 (2.2 Master)
Firmware: V188-1
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0

Repro frequency: 3/3, 100%
See attached: Youtube video clip & logcat
Youtube Link: http://youtu.be/Z48g0tpmQvM
Issue does NOT reproduce on Flame 2.0 or Flame 2.1

Actual results: Video freezes and cannot be resumed when user plays/pauses multiple times. User can press back button and select the same/another video to play. 

Device: Flame 2.0 (319mb)(Kitkat Base)(Full Flash)
Build ID: 20141216000202
Gaia: f3b9806f687fbbd7eba6b0e1f6ebb8bde09840ea
Gecko: 12aea1649f5a
Gonk: e5c6b275d77ca95fb0f2051c3d2242e6e0d0e442
Version: 32.0 (2.0)
Firmware Version: v188-1
User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0

Device: Flame 2.1 (319mb)(Kitkat Base)(Full Flash)
Build ID: 20141216001202
Gaia: 79286eafe67707d1330966c1b1413b2d0de595d9
Gecko: 222a62b532db
Gonk: e5c6b275d77ca95fb0f2051c3d2242e6e0d0e442
Version: 34.0 (2.1)
Firmware Version: v188-1
User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(dharris)
Keywords: regression
[Blocking Requested - why for this release]:

Nominating to block on 2.2. This is an incorrect error message and confusing to the end user. Also a regression
blocking-b2g: --- → 2.2?
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(dharris)
I was able to repro this bug on 2.1, but not on 2.0. Marking 2.1 as affected. Working on getting the window now.
QA Contact: pcheng
b2g-inbound regression window:

Last Working Environmental Variables:
Device: Flame
BuildID: 20141103181418
Gaia: 1f621c11282161cc47870ab2c8d046103270dc71
Gecko: 87f031a85885
Version: 36.0a1 (2.2 Master)
Firmware: V188-1
User Agent: Mozilla/5.0 (Mobile; rv:36.0) Gecko/36.0 Firefox/36.0

First Broken Environmental Variables:
Device: Flame
BuildID: 20141103184819
Gaia: 7bac3bc2379453196a95117e72670009a4d856e0
Gecko: 4d04012eb8a0
Version: 36.0a1 (2.2 Master)
Firmware: V188-1
User Agent: Mozilla/5.0 (Mobile; rv:36.0) Gecko/36.0 Firefox/36.0

First Broken Gaia & Last Working Gecko - issue DOES repro
Gaia: 7bac3bc2379453196a95117e72670009a4d856e0
Gecko: 87f031a85885

First Broken Gecko & Last Working Gaia - issue does NOT repro
Gaia: 1f621c11282161cc47870ab2c8d046103270dc71
Gecko: 4d04012eb8a0

Gaia pushlog:
https://github.com/mozilla-b2g/gaia/compare/1f621c11282161cc47870ab2c8d046103270dc71...7bac3bc2379453196a95117e72670009a4d856e0

Caused by Bug 1079519
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(jmitchell)
Caused by patch to Bug 1079519 - can you take a look Russ?
Blocks: 1079519
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(jmitchell) → needinfo?(rnicoletti)
QA Contact: pcheng
Correct fix might need Bug 1093283.
See Also: → 1093283
(In reply to Sotaro Ikeda [:sotaro PTO Dec/24-Jan/6] from comment #6)
> Correct fix might need Bug 1093283.

Yes, the behavior described by this bug, which I can reproduce, is caused by the fix for bug 1079519. A better fix for bug 1079519 would be for the video element to indicate when it can't play because the hardware codec is in use (bug 1093283). If the video element could indicate that it can't play because it is in use the bug 1079519 patch can be made much simpler and the result would be that this bug would not occur.

In terms of how the fix for bug 1079519 is causing this bug, the code change displays the "in use" dialog when a video is played and the video app does not receive a 'timeupdate' event within one second. From my investigation, when playing and pausing a video repeatedly, sometimes the video app does not get a 'timeupdate' event for as many as four seconds and sometimes not at all. I reviewed the code and added console logs to determine if a timing issue in the bug 1079519 patch was causing the 'timeupdate' event listener to be removed, such that the event was being sent but the video app was not acting on it, but I could not find any evidence to support that theory.

Sotaro, can you investigate the theory that when playing and pausing a video repeatedly the 'timeupdate' event is either delayed or never sent?
Flags: needinfo?(rnicoletti) → needinfo?(sotaro.ikeda.g)
Okey, I am going to investigate about it today, from tomorrow I will be in PTO.
Flags: needinfo?(sotaro.ikeda.g)
I seems to understand what is happening in gecko media.

'timeupdate' event is sent by the following call sequence. In AdvanceFrame(), if media time update is detected, it is sent.

MediaDecoderStateMachine::AdvanceFrame()
->if (t > GetMediaTime()) { // if media time is updated
 ->MediaDecoderStateMachine::UpdatePlaybackPosition()
  ->NS_DispatchToMainThread(event);
// on main thread
->MediaDecoder::PlaybackPositionChanged()
 ->MediaDecoder::FireTimeUpdate()
  ->HTMLMediaElement::FireTimeUpdate()
    ->DispatchAsyncEvent(NS_LITERAL_STRING("timeupdate"));

http://dxr.mozilla.org/mozilla-central/source/dom/media/MediaDecoderStateMachine.cpp#3019
When the problem happened, AudioSink::GetPosition() is not updated after playback start.

AudioSink::StartPlayback() was already called, but AudioSink::AudioLoop() did not start audio playback.
AudioSink did not have audio buffer to playback. AudioSink::WaitForAudioToPlay() continued to wait audio buffers to receive.

http://dxr.mozilla.org/mozilla-central/source/dom/media/AudioSink.cpp#263
Audio decoding is done by OmxDecoder::ReadAudio(). In attachment 8540905 [details], when the problem happened, OmxDecoder::ReadAudio() does not completed very long time.

When AudioSink::StartPlayback() is called, if AudioSink does not have a buffer to playback, it can not start audio playback.
Audio decoding became very slow, when the problem happened. I assume it is caused by "pressing play and pause repeatedly".

UI task is done on app's main thread. And tapping event handling is also done on b2g main thread. When "pressing play and pause repeatedly" is done, these main thread becomes very busy.

And gecko media also uses b2g main thread and application's main thread to deliver Movie data for playback. It is caused from gecko ipc's limitation. When data read becomes slow, video and audio decoding also becomes slow. Bug 1026312 and Bug 999743 are similar bugs.
Bug 1013756 is a bug to fix gecko media's main thread usage problem. It assume to use PBackground. This bug is not trivial to address. I do not think we could fix this bug until b2g v2.2.

But b2g v3 should address this problem, I think.
Therefore, on b2g v2.1 and v2.0, we could not fix slow audio decoding problem during pressing play and pause repeatedly.
FYI, the following has some diagrams related to gecko media.
   https://github.com/sotaroikeda/firefox-diagrams/wiki/Firefox-Diagrams#media
Per comments 14/15 - moving to priority queue for post 2.2 release
blocking-b2g: 2.2? → backlog
Whiteboard: [2.2-exploratory-2] → [2.2-exploratory-2][priority]
blocking-b2g: backlog → ---
Firefox OS is not being worked on
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: