957467 - [Flatfish][Video] Video paused when playing MP4 file, happened intermittently

Status: RESOLVED WONTFIX

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

Description

[Eric Chang [:ericcc] [:echang]]

Gaia      45860a3651eb9f860c59f2273028f921f2ef338b  │  
Gecko     e393d46c9defba72337a71bb6ea81f60fd79749c  │  
BuildID   20140108064521             
Version   29.0a1                     
ro.build.version.incremental=20140108               │  
ro.build.date=Wed Jan  8 06:52:15 CST 2014 

1. Put 2 files onto devices, and start playing a MP4 file.
2. Video playing okay.
3. Put 20 files onto devices, and start playing a MP4 file.
4. Video played intermittently.

Comment 1

[u459114]

Hi Macro, is there anyone in your team can check this bug first?

Comment 2

[Marco Chen [:mchen]]

Hi Blake,

Could you check this bug with John together?

As I know that the MP4 file can be decoded only by HW decoder, so once a video is playing the background thumbnail extracting should be paused. Under this behavior, it should not be effected.

Comment 3

[John Hu [:johnhu][:johu][:醬糊小弟]]

In the tablet version, our code makes all thumbnails generated before first usage. So, in the eric's test case, we won't create thumbnail while video is playing.

Comment 4

[Vincent Liu[:vliu]]

Please make sure "Enable hardware composer" is disable in Settings app before start investigating this issue. Please refers to bug 956265 for more detail.

Comment 5

[Marco Chen [:mchen]]

(In reply to John Hu [:johnhu] from comment #3)
> In the tablet version, our code makes all thumbnails generated before first
> usage. So, in the eric's test case, we won't create thumbnail while video is
> playing.

Interesting. Based on John's comment, there should be no difference between putting 2 or 20 files into storage.

Hi Eric,

Could you help to double confirm this bug? Thanks.

Comment 6

[Eric Chang [:ericcc] [:echang]]

Actually, I also don't think the number of files is the factor here, but it looks vaguely like that this way, I will try to find out the key that causes it. But the video does lag, and it is very easy to reproduce.

Comment 7

[Eric Chang [:ericcc] [:echang]]

Attachment: VideoPaused-1.log

Comment 8

[Eric Chang [:ericcc] [:echang]]

1. Number of file on device is not relevant to this case.
2. At the time the video paused, the following info shown in adb logcat -> see attachment for more.
 
Something like this --> E/OMXCodec( 1754): [OMX.google.aac.decoder] Timed out waiting for output buffers: 4/0

------------------------------------------------------------------------------------
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=3 buf=0x440eb650 flags=0x1
V/GonkBufferQueue( 1754): requestBuffer: slot=3
D/omx_vdec( 1270):  set state command, cmd = 0, cmddata = 3.
I/SoftAAC2( 1754): Reconfiguring decoder: 44100 Hz, 2 channels
I/GeckoDump( 1754): Warning: no stats have been recorded. Make sure start() has been called
I/GeckoDump( 1754): Warning: no stats have been recorded. Make sure start() has been called
I/Gecko   ( 1754): [SharedSurface_Gralloc 0x43f6b680] destroyed
E/OMXCodec( 1754): [OMX.allwinner.video.decoder.avc] called start in the unexpected state: 4
W/AudioFlinger( 1270): Thread AudioOut_2 cannot connect to the power manager service
V/codec_audio_pad( 1270): in normal mode, headset or speaker on,****LINE:54,FUNC:set_normal_path
V/GonkBufferQueue( 1754): cancelBuffer: slot=0
V/GonkBufferQueue( 1754): dequeueBuffer: w=1920 h=1080 fmt=0x32315659 usage=0x2100
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=0 buf=0x44087d30 flags=0
V/GonkBufferQueue( 1754): cancelBuffer: slot=1
V/GonkBufferQueue( 1754): dequeueBuffer: w=1920 h=1080 fmt=0x32315659 usage=0x2100
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=1 buf=0x440eb470 flags=0
V/GonkBufferQueue( 1754): cancelBuffer: slot=2
V/GonkBufferQueue( 1754): dequeueBuffer: w=1920 h=1080 fmt=0x32315659 usage=0x2100
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=2 buf=0x440eb4c0 flags=0
E/Sensors ( 1275): tiger LightSensor: readEvents
E/Sensors ( 1275): ***tiger LightSensor: start (type=3, code=40 ,count = 16,event->value = 0xf)
E/Sensors ( 1275): ***tiger LightSensor type == EV_ABS
E/Sensors ( 1275): mPendingEvent.light = 320.000000
E/Sensors ( 1275): ***tiger LightSensor: start (type=0, code=0 ,count = 16,event->value = 0x0)
E/Sensors ( 1275): ***tiger LightSensor type == EV_SYN
E/Sensors ( 1275): mEnabled = 0 ,mPendingEvent.light = 320.000000, mEventsSinceEnable = 5
E/OMXCodec( 1754): [OMX.google.aac.decoder] Timed out waiting for output buffers: 4/0
V/GonkBufferQueue( 1754): cancelBuffer: slot=3
V/GonkBufferQueue( 1754): dequeueBuffer: w=1920 h=1080 fmt=0x32315659 usage=0x2100
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=3 buf=0x440eb650 flags=0
E/Sensors ( 1275): tiger LightSensor: readEvents
E/Sensors ( 1275): ***tiger LightSensor: start (type=3, code=40 ,count = 16,event->value = 0xd)
E/Sensors ( 1275): ***tiger LightSensor type == EV_ABS
E/Sensors ( 1275): mPendingEvent.light = 320.000000
E/Sensors ( 1275): ***tiger LightSensor: start (type=0, code=0 ,count = 16,event->value = 0x0)
E/Sensors ( 1275): ***tiger LightSensor type == EV_SYN
E/Sensors ( 1275): mEnabled = 0 ,mPendingEvent.light = 320.000000, mEventsSinceEnable = 5
I/Gecko   ( 1754): [SharedSurface_Gralloc 0x43244f00] destroyed
E/OMXCodec( 1754): [OMX.google.aac.decoder] Timed out waiting for output buffers: 4/0
V/GonkBufferQueue( 1754): cancelBuffer: slot=0
V/GonkBufferQueue( 1754): dequeueBuffer: w=1920 h=1080 fmt=0x32315659 usage=0x2100
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=0 buf=0x44087d30 flags=0
E/OMXCodec( 1754): [OMX.google.aac.decoder] Timed out waiting for output buffers: 4/0
V/GonkBufferQueue( 1754): cancelBuffer: slot=1
V/GonkBufferQueue( 1754): dequeueBuffer: w=1920 h=1080 fmt=0x32315659 usage=0x2100
V/GonkBufferQueue( 1754): dequeueBuffer: returning slot=1 buf=0x440eb470 flags=0

Comment 9

[Eric Chang [:ericcc] [:echang]]

Attachment: VideoPaused-2.log

Comment 10

[Vincent Liu[:vliu]]

Do you have a stable way to reproduce this issue? I tried many times but not seeing it paused on my device. Thanks.

Comment 11

[Eric Chang [:ericcc] [:echang]]

"Reset Phone", most likely to happen for the first time the video is launched and starts to play.

Comment 12

[John Hu [:johnhu][:johu][:醬糊小弟]]

Does this bug related the the profile type of h.264?? I found lots high profile with high resolution videos in eric's device.

Comment 13

[Blake Wu [:bwu][:blakewu]]

Hi Eric and Vincent, 
Could you help use "adb logcat -v threadtime" to attach the logs again? 
By using "-v threadtime", we can know the timestamp of each log to narrow down the possible time-consuming part. 
Thanks.

Comment 14

[Eric Chang [:ericcc] [:echang]]

Attachment: VideoPaused-logcat-threadtime-3.log

1. Start logcat
2. Start playing a video
3. Video paused at 00:01
4. Stop logcat after a while.

Comment 15

[John Hu [:johnhu][:johu][:醬糊小弟]]

Attachment: video for reproducing

I can reproduce the same issue with the attached video, which is recorded by the flatfish.

1. remove all video files
2. put this video file in
3. open video app
4. play it and found it stops at 00:01

The similar messages with eric's logcat can be found at logcat:
[OMX.google.aac.decoder] Timed out waiting for output buffers: 4/0
[OMX.allwinner.video.decoder.avc] Timed out waiting for output buffers: 2/1

Comment 16

[Sotaro Ikeda [:sotaro]]

Does the flatfish's gonk already have the following change? And is OMXCodec::Pause() modified?
https://github.com/mozilla-b2g/platform_frameworks_av/commit/29e73ecbf09a29114862a62dd3d9b3c5749dc7fb

Comment 17

[Vincent Liu[:vliu]]

(In reply to Sotaro Ikeda [:sotaro] from comment #16)
> Does the flatfish's gonk already have the following change? And is
> OMXCodec::Pause() modified?
> https://github.com/mozilla-b2g/platform_frameworks_av/commit/
> 29e73ecbf09a29114862a62dd3d9b3c5749dc7fb

Thanks for your suggestion. I found the patch for OMXCodec::Pause() didn't modify in flatfish's platform. After adding modification on OMXCodec::Pause(), it works for the issue on Comment 15.

Hi Eric,

I need your help to confirm the case you saw for this bug. You can find me to sync with the modification for OMXCodec::Pause().

Comment 18

[Eric Chang [:ericcc] [:echang]]

The modified "libstagefright.so" works well.

Comment 19

[Vincent Liu[:vliu]]

(In reply to Eric Chang [:ericcc] [:echang] from comment #18)
> The modified "libstagefright.so" works well.

Thanks. Eric.

Comment 20

[Vincent Liu[:vliu]]

Hi Jeff, 

I think this is the missing part Flatfish should fixed as Sotaro said in Comment 16. Because the code is in AOSP so I need your help to fix it in your side.

Comment 21

[Jeff Chuang]

Just checked the code base, the patches have been applied to Flashfish

Comment 22

[Jeff Chuang]

The issues will be reproduced easily in the follow 2 conditions:
1.Just after the files are pushed, the playback is intermittent. After reboot flatfish, the flutter of playback seems gone. I wonder shall we restart MP4 decoder after generated thumbnails?

2.Every time scrolling the thumbnail list, video playback intermittently

I did not find any error messages yet when the intermittent playback happens.

Comment 23

[Sotaro Ikeda [:sotaro]]

Flatfish's OMXCodec seems not have following changes. Without them causes problem to video/audio decoding.

https://github.com/mozilla-b2g/platform_frameworks_av/commit/b4d0c2011d517cb697c6d9fca927d27d0ba3f65d
https://github.com/mozilla-b2g/platform_frameworks_av/commit/29e73ecbf09a29114862a62dd3d9b3c5749dc7fb

Comment 24

[Joe Young]

According to Comment #23
flatfish AOSP OMXCodec::pause() is not correct.
Need to apply the patch.

Comment 25

[Armen [:armenzg]]

Closing all intermittent test failures for Firefox OS (since we're not focusing on it anymore).

Please reopen if my search included your bug by mistake.

Comment 26

[BMO Automation]

Firefox OS is not being worked on