840154 - [B2G][Video] [Inari] Video app crashes after playing a video that is at least 30 seconds long

Status: VERIFIED FIXED

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

Description

[Chris Kreinbring [:CKreinbring]]

Attachment: Logcat logs

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:18.0) Gecko/20100101 Firefox/18.0
Build ID: 20130201065344

Steps to reproduce:

Unagi version: 20130211070202
Gaia: 21cedfd1787f4aff26721fc0f160e771db5cd67d
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/59fbbbbba801
Kernel: Dec 5

1. From the homescreen select the Video app.
2. Select a video in the list that has a length of at least 30 seconds.
3. Observe the state of the app after the video finishes.


Actual results:

The Video app crashes.

Note: If the video is less than 30 seconds long, the app returns to the video list but the play length of the videos are not visible.


Expected results:

The app returns to the list of videos with no errors.

Comment 1

[Scoobidiver (away)]

> 02-11 10:03:00.024: I/Gecko(618): ###!!! [Parent][AsyncChannel] Error: Channel error: 
> cannot send/recv
It looks like bug 839849.

Comment 2

[Jason Smith [:jsmith]]

David - Is this a dupe of bug 839849?

Comment 3

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

We need to start backing things out.

Comment 4

[David Flanagan [:djf]]

(In reply to Jason Smith [:jsmith] from comment #2)
> David - Is this a dupe of bug 839849?

I don't know. The message in comment 1 looks like the same message. But this app doesn't write to DeviceStorage as was happening in that other bug. But it does seem like there might be one common issue underlying both bugs.

The video app tries to keep a thumbnail of the current spot in the video, so if you stop playing in the middle, it will save a thumbnail of the current frame to IndexedDB.  So there is some I/O going on when the video stops. I don't know if that is what triggers the crash.

[e-mail]: here are some more questions for you about this crash.

1) when does the crash occur? Exactly at the 30 second mark?  Or when the video is done playing?  Does it happen if you press the back button while the video is playing to go back to the list of videos?

2) What kind of videos does this happen for?  Videos from the camera?  Or the sample videos like meetthecubs.webm?  Or both?

3) Is 30 seconds an exact number or approximate? Have you tried recording a 29s and a 31s video with the camera and verified that one crashes and the other doesn't?

Comment 5

[Chris Kreinbring [:CKreinbring]]

1. The crash occurs after the video finishes playing.  Pressing the back button does not cause the video to crash, but it does make the videos' time length disappear.

2. It happens with videos from the camera.  I also tried YouTube videos but none of them caused a crash.  One of my coworkers had videos (mainly movie trailers) that she downloaded to her device and none of them caused a crash.  Also, that meetthecubs.webm link is no good.

3. The 30 seconds was an approximation.  Checking further, I've seen it happen with 20 second videos.  I haven't seen it with any smaller videos, though.

Comment 6

[Marcia Knous [:marcia]]

I haven't been able to reproduce this yet on my phone with any existing videos. Will keep trying.

Comment 7

[Sotaro Ikeda [:sotaro]]

> 02-11 10:02:59.003: A/OMXCodec(1366): frameworks/base/media/libstagefright/OMXCodec.cpp:5234 CHECK_EQ( (int)mPortStatus[kPortIndexOutput],(int)ENABLED) failed: 4 vs. 0

This log seems an actual cause of the crash. OMXCodec kills app's process by calling abort, because gralloc buffer is returned after OMXCodec shutdown. We fixed same crash in the past, but it seems that there is still another rout to the crash.

Comment 8

[Sotaro Ikeda [:sotaro]]

I confirmed the crash happened on unagi phone. I am going to investigate the bug. Can I take the bug?

Comment 9

[Lukas Blakk [:lsblakk] use ?needinfo]

Tracking, not blocking, since this seems to be intermittent and not 100% reproducible.

Comment 10

[Sotaro Ikeda [:sotaro]]

I manually added the logs to OMXCodec and OmxDecoder classed. The crash happened when MedaBuffer is returned to OmxDecoder during seeking. Bug 812756 already fixed some parts of the seek & crash problem. But there is still a route to crash.

Comment 11

[Scoobidiver (away)]

I'm adding the matching crash signature assumed in bug 823324 comment 41.

It's #2 top crasher in B2G 18.0.
See https://crash-stats.mozilla.com/report/list?signature=__libc_android_abort+|+__android_log_assert+|+android%3A%3AOMXCodec%3A%3AsignalBufferReturned

Comment 12

[David Flanagan [:djf]]

Sotaro,

When the video app stops playing a video (because the user stops it or because it reaches the end) it takes a screenshot of the video by using a canvas drawImage() call on the <video> element.

I wonder if that is what is happening here. When a <video> reaches the end, does it automatically release the hardware decoder?  If so, maybe there is a race condition because the app is immediately trying to use the <video> element again as soon as it stops playing.

I'm not sure what a video element does with the currentTime property when it reaches the end of the video. If it resets it to zero, then the Video app is first going to try to seek a ways into the video before capturing a screenshot.  So as soon as the video send out its 'ended' event the app may immediately seek on the video and then grab a frame.  

If this sounds like it might be related, you could try adding these two lines at video.js:538

  completeHidingPlayer();
  return;

Adding those lines should prevent the screenshot when playing ends.

Comment 13

[Sotaro Ikeda [:sotaro]]

Even when <video> reaches the end, nsHTMLMediaElement keeps hw decoder. The hw decoder is released only if nsHTMLMediaElement destruction, load another resource, and error cases. During it is in the end of the video, if the currentTime property is set to zero, it tries to seek to zero.

The crash happens like following sequence
[1] <video> reaches the end
[2] In playerEnded(), <video>'s currentTime property is set to zero.(seek trigger)
[3] In playerEnded(), document.mozCancelFullScreen() is called.
[4] In mozfullscreenchange event handler, hidePlayer() is called.
[5] In hidePlayer(), captureFrame() is called.
     but <video> is in seeking stage. Wait seek completion.
[6] Actual Seeking start in OMXCodec
     During seeking, OMXCodec's input and putput are set to SHUTTING_DOWN.
[7] Video rendering is updated at ImageContainer. Old image is released.
[8] MediaBuffer is released and returned to OMXCodec.
    And OMXCodec::signalBufferReturned() is called.

but OMXCodec's input and putput are still set to SHUTTING_DOWN. OMXCodec calls abort. 

In the above STR, it is not reached to even drawImage() call.

Comment 14

[Sotaro Ikeda [:sotaro]]

(In reply to David Flanagan [:djf] from comment #12)
> If this sounds like it might be related, you could try adding these two
> lines at video.js:538
> 
>   completeHidingPlayer();
>   return;

I tried the above. it works for the crash. When applying it, [7] did not happen during seeking. Then crash is prevented.

Comment 15

[Sotaro Ikeda [:sotaro]]

Attachment: patch: do not release MediaBuffer during OMXCodec is seeking

The patch is for b2g18. Can not apply it for m-c/m-i.

If VideoGraphicBuffer::Unlock() is called during OMXCodec is in seeking state, OmxDecoder hold a MediaBuffer and call MediaBuffer::release() after seeking complete.

I confirmed on Unagi that the crash do no happen.

Comment 16

[David Flanagan [:djf]]

Sotaro,

Do you recommend any related changes in the Video app?

And did you mean to request r? from someone on the patch?

Comment 17

[Sotaro Ikeda [:sotaro]]

(In reply to David Flanagan [:djf] from comment #16)
> Sotaro,
> 
> Do you recommend any related changes in the Video app?
> And did you mean to request r? from someone on the patch?

djf, a change of the Video app is not necessary for the bug. The bug just shows the defect of OmxDecoder. And it could be fixed by attachment 713688 [details] [diff] [review]. After making a patch for m-i, I am going to request cdouble to review the patch.

Comment 18

[Sotaro Ikeda [:sotaro]]

Attachment: patch for m-i:do not release MediaBuffer during OMXCodec is seeking

A patch for m-i made from  attachment 713688 [details] [diff] [review]. Just a name of "mIsSeeking" is changed to "mIsVideoSeeking".

Comment 19

[Sotaro Ikeda [:sotaro]]

Comment on attachment 713790 [details] [diff] [review]
patch for m-i:do not release MediaBuffer during OMXCodec is seeking

doublec, can you review the patch?

Comment 20

[Marcia Knous [:marcia]]

I am hitting this crash on the Inari device: https://crash-stats.mozilla.com/report/index/a946f76c-e886-4d83-a05e-b9f662130214.

Gecko 
Gaia   ecca2ee860825547d5e1109436b50b74dfe9261e
BuildID 20130211165958
Version 18.0

Adding [MWCDemo2013] to the whiteboard.

Comment 21

[Tony Chung [:tchung]]

I get a different crash when playing back a self-recorded video: 

B2G 18.0 Crash Report [@ libstagefright.so@0x11dacf ] 
https://crash-stats.mozilla.com/report/index/1f3e7034-ee96-4c59-af5b-2fbdd2130214

Gecko 
Gaia   ecca2ee860825547d5e1109436b50b74dfe9261e
BuildID 20130214102004
Version 18.0

Comment 22

[Tony Chung [:tchung]]

(In reply to Tony Chung [:tchung] from comment #21)
> I get a different crash when playing back a self-recorded video: 
> 
> B2G 18.0 Crash Report [@ libstagefright.so@0x11dacf ] 
> https://crash-stats.mozilla.com/report/index/1f3e7034-ee96-4c59-af5b-
> 2fbdd2130214
> 
> Gecko 
> Gaia   ecca2ee860825547d5e1109436b50b74dfe9261e
> BuildID 20130214102004
> Version 18.0

here's another log posted at the same time.  not sure which is it; but it's different than the last 2 posted.

B2G 18.0 Crash Report [@ libxul.so@0xef7b2a | libxul.so@0xa803b3 | __android_log_vprint ] 

https://crash-stats.mozilla.com/report/index/1b07114c-78bc-45ca-8096-59ee02130214

Comment 23

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

FYI, since we don't have crash symbols for the inari device, I'm not sure how useful the stacks are at this point.

Comment 24

[cajbir (:cajbir)]

Comment on attachment 713790 [details] [diff] [review]
patch for m-i:do not release MediaBuffer during OMXCodec is seeking

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

Mostly minor comments. r+ with those fixed.

::: content/media/omx/OmxDecoder.cpp
@@ +628,5 @@
>  
>    return true;
>  }
> +
> +bool OmxDecoder::ReleaseVideoBuffer(MediaBuffer *aBuffer) {

Function opening '{' style in this file is to have it at the beginning of the next line. Same comment for ReleaseAllPendingVideoBuffersLocked.

@@ +645,5 @@
> +}
> +
> +void OmxDecoder::ReleaseAllPendingVideoBuffersLocked() {
> +  int size = mPendingVideoBuffers.size();
> +  for (int i; i < size; i++) {

'i' is uninitialized here. Set to 0.

::: content/media/omx/OmxDecoder.h
@@ +105,5 @@
>    MediaBuffer *mAudioBuffer;
>  
> +  Vector<MediaBuffer *> mPendingVideoBuffers;
> +  bool mIsVideoSeeking;
> +  Mutex mSeekLock;

Add a comment explaining what these are for. In particular what mSeekLock protects, and any rules regarding when it should or should not be held.

@@ +112,5 @@
>    bool mAudioMetadataRead;
>  
>    void ReleaseVideoBuffer();
>    void ReleaseAudioBuffer();
> +  void ReleaseAllPendingVideoBuffersLocked();

Does this need mSeekLock held? If so add a comment to this affect. If possible assert on this in the function implementation.

Comment 25

[Sotaro Ikeda [:sotaro]]

Attachment: patch v2 for m-i:do not release MediaBuffer during OMXCodec is seeking

Carry "chris.double: review+"

Apply all comments except following. android::Mutex do not provide an information for it.
> If possible assert on this in the function implementation.

Comment 26

[Sotaro Ikeda [:sotaro]]

https://tbpl.mozilla.org/?tree=Try&rev=1cf1a7c986f2

Comment 27

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/5271482ec7cc

Comment 28

[Sotaro Ikeda [:sotaro]]

Attachment: patch v2 for b2g18:do not release MediaBuffer during OMXCodec is seeking

patch for b2g18 made from attachment 714226 [details] [diff] [review].

Comment 29

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/5271482ec7cc

Comment 30

[Sotaro Ikeda [:sotaro]]

Comment on attachment 714226 [details] [diff] [review]
patch v2 for m-i:do not release MediaBuffer during OMXCodec is seeking

NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): N/A
User impact if declined: Video app sometimes crashes at the end of video playback or during video seeking.
Testing completed: Tested in Unagui phone.
Risk to taking this patch (and alternatives if risky): low risk
String or UUID changes made by this patch: none

Comment 31

[Lukas Blakk [:lsblakk] use ?needinfo]

Comment on attachment 714226 [details] [diff] [review]
patch v2 for m-i:do not release MediaBuffer during OMXCodec is seeking

For consistency we'll mark this as a blocker now so it can be uplifted to v1.0.1 as well as v1-train.

Comment 32

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g18/rev/9e25bd41032f
https://hg.mozilla.org/releases/mozilla-b2g18_v1_0_1/rev/effe37a77f18

Comment 33

[Chris Kreinbring [:CKreinbring]]

Fix verified in Unagi build 20130222070201
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18_v1_0_1/rev/9df4d6efd664
Gaia: 5691a16fff8e1403c75ed9d6f3a443b7e58198c6
Kernel Date: Dec 5