974250 - [Tarako]: Video/Audio got stucks when playing some mpeg4 files

Status: RESOLVED FIXED

(Core :: Audio/Video, defect)

Description

[Vincent Liu[:vliu]]

When I tried to get some media files to play it, video/audio both got stuck.

Comment 1

[Wayne Chen [:xwaynec]]

Attachment: Firefox Flicks 2013- Beyond the Limit.mp4

Comment 2

[Wayne Chen [:xwaynec]]

Attachment: demo.mp4

Comment 3

[Wayne Chen [:xwaynec]]

Attachment 8378042 [details] came to a halt after one second when starting play. Attachment 8378043 [details] is ok. The difference between two files is the audio sample rate, attachment 8378042 [details] is AAC 44.1Khz and attachment 8378043 [details] is AAC 48Khz.

Comment 4

[Wayne Chen [:xwaynec]]

When file came to a halt, the log has "drainOneOutputBuffer" message. 


12-31 20:52:30.250 I/SPRDAVCDecoder(   87): onQueueFilled, get outQueue buffer, return, count=1, queue_size=1
12-31 20:52:30.250 I/SPRDAVCDecoder(   87): onQueueFilled, get outQueue buffer, return, count=1, queue_size=1
12-31 20:52:33.250 E/OMXCodec(  438): [OMX.sprd.h264.decoder] Timed out waiting for output buffers: 0/3
12-31 20:52:33.550 I/Gecko   (   82):  xxxxx unknow android format 33
12-31 20:52:33.550 I/SprdSimpleOMXComponent(   87): fillThisBuffer, buffer: 0x3040b0, header: 0x303d38, iRefCount: 0
12-31 20:52:33.550 I/SPRDAVCDecoder(   87): onQueueFilled, 725, outHeader:0x303d38, inHeader: 0x303288, len: 2903, nOffset: 0, time: 21040000, EOS: 0
12-31 20:52:33.550 I/VSP     (   87): H264Dec_SetCurRecPic, 57, picId: 101
12-31 20:52:33.550 I/VSP     (   87): H264Dec_init_picture, 573, dec_picture_ptr->mPicId: 101, imgY: 41c03000
12-31 20:52:33.560 I/VSP     (   87): H264Dec_Picture_Level_Sync, 296, polling PREVIOUS cqm
12-31 20:52:33.560 I/SPRDAVCDecoder(   87): VSP_bind_cb, ref frame: 0x303658, 303d38; iRefCount=0
12-31 20:52:33.560 I/SPRDAVCDecoder(   87): VSP_unbind_cb, ref frame: 0x305910, 303580; iRefCount=1
12-31 20:52:33.560 I/VSP     (   87): out poc: 30, effective: 1	
12-31 20:52:33.560 I/SPRDAVCDecoder(   87): onQueueFilled, 810, decRet: 0, dataLen: 0, dec_out.frameEffective: 1, mDecoderSwFlag: 0
12-31 20:52:33.560 I/SPRDAVCDecoder(   87): handlePortSettingChangeEvent, 872, picWidth: 640, picHeight: 368, numRef: 1, profile: 0x42
12-31 20:52:33.560 I/SPRDAVCDecoder(   87): drainOneOutputBuffer, 933, outHeader: 303580, outHeader->pBuffer: 305910, outHeader->nOffset: 0, outHeader->nFlags: 16, outHeader->nTimeStamp: 21000000
12-31 20:52:33.570 I/SPRDAVCDecoder(   87): onQueueFilled, get outQueue buffer, return, count=1, queue_size=1
12-31 20:52:33.570 I/SPRDAVCDecoder(   87): onQueueFilled, get outQueue buffer, return, count=1, queue_size=1

Comment 5

[cheng.luo]

Attachment: FirefoxFlicks2013-Beyond_the_Limit_track1.mp4

video track

Comment 6

[cheng.luo]

Attachment: FirefoxFlicks2013-Beyond_the_Limit_track2.mp4

audio track

Comment 7

[cheng.luo]

the specific video files played normally in stagefright player(the same gonk version with FFOS).
I try extract the video file to video track(Comment 5) and auido track(Comment 6). The both tracks could play normally in video app and music app（FFOS）.Maybe it is not as good as Android on A/V sync.

Comment 8

[Vincent Liu[:vliu]]

From the log message in Comment 4, it always print |Timed out waiting for output buffers| 

12-31 20:52:33.250 E/OMXCodec(  438): [OMX.sprd.h264.decoder] Timed out waiting for output buffers: 0/3
12-31 20:52:33.550 I/Gecko   (   82):  xxxxx unknow android format 33

Two possible reasons:
1. Decoder doesn't send FILL_BUFFER_DONE message to tell OMXCodec the frame is done decoding before timeout happens.

2. There is no input data send to decoder by calling emptyBuffer().

Comment 9

[Wayne Chen [:xwaynec]]

I manually remove libstagefright_sprd_h264dec.so, the playback of video works fine.

Comment 10

[Ming]

We find that the decoder can't get a buffer to fill the decoded data and then queue it for user continuously.
It seems the user do not release the buffer on time.
If we increase the count of buffers in the decoder output port ,then the playback will be fine.

Comment 11

[James Zhang (Spreadtrum)]

(In reply to Ming from comment #10)
> We find that the decoder can't get a buffer to fill the decoded data and
> then queue it for user continuously.
> It seems the user do not release the buffer on time.
> If we increase the count of buffers in the decoder output port ,then the
> playback will be fine.

We have a quick patch, change OMX.sprd.h264.decoder buffer number from 3 to 4, it works fine.

Comment 12

[James Ho]

James, given your comment 11, could we close this bug now?

Comment 13

[James Zhang (Spreadtrum)]

(In reply to James Ho from comment #12)
> James, given your comment 11, could we close this bug now?

OK. We alloc more buffer for this issue.
Please see this commit in frameworks/base repo.

commit 0568d5246417a95289eca7c47c4cee674ce0f8cc
Author: james.zhang <[e-mail]>
Date:   Tue Mar 4 11:55:44 2014 +0800

    Bug#281874 - [FFOS v1.3][6821][7710]Video/Audio got stucks when playing some mpeg4 files
    
    Change-Id: I653b01fe97628e5f0aa4c1e0d37aae5ecb7fda8c

diff --git a/media/libstagefright/codecs/avc_sprd/7710/dec/SPRDAVCDecoder.cpp b/media/libstagefright/codecs/avc_sprd/7710/dec/SPRDAVCDecoder.cpp
index d8c743f..000c230 100644
--- a/media/libstagefright/codecs/avc_sprd/7710/dec/SPRDAVCDecoder.cpp
+++ b/media/libstagefright/codecs/avc_sprd/7710/dec/SPRDAVCDecoder.cpp
@@ -877,7 +877,7 @@ bool SPRDAVCDecoder::handlePortSettingChangeEvent(const H264SwDecInfo *info) {
     }
 
     OMX_PARAM_PORTDEFINITIONTYPE *def = &editPortInfo(kOutputPortIndex)->mDef;
-    if (mWidth != info->picWidth || mHeight != info->picHeight || info->numRefFrames > def->nBufferCountActual-(2+1+info->has_b_frames)) {
+    if (mWidth != info->picWidth || mHeight != info->picHeight || info->numRefFrames > def->nBufferCountActual-(3+1+info->has_b_frames)) {
         mWidth  = info->picWidth;
         mHeight = info->picHeight;
         mPictureSize = mWidth * mHeight * 3 / 2;
@@ -885,7 +885,7 @@ bool SPRDAVCDecoder::handlePortSettingChangeEvent(const H264SwDecInfo *info) {
             __FUNCTION__, __LINE__,mWidth, mHeight, info->numRefFrames, info->profile);
         mCropWidth = mWidth;
         mCropHeight = mHeight;
-        def->nBufferCountActual = info->numRefFrames + (2+1+info->has_b_frames);
+        def->nBufferCountActual = info->numRefFrames + (3+1+info->has_b_frames);
         ALOGI("%s, %d, info->numRefFrames: %d, info->has_b_frames: %d, def->nBufferCountActual: %d", __FUNCTION__, __LINE__, info->numRefFrames, info->has_b_frames, def->nBuffer
 
         updatePortDefinitions();

Comment 14

[Chris Pearce [:cpearce (Not reading bugmail)]]

I still get this bug on my tarako when thumbnailing MP4 videos in the B2G Video App. I have updated my libomx* and libstage* to include 0568d5246417a95289eca7c47c4cee674ce0f8cc. I don't think this bug is fixed.

I am trying to thumbnail these videos
http://people.mozilla.org/~cpearce/small_video/

Comment 15

[James Zhang (Spreadtrum)]

Ming, do you update omx code library in vendor/sprd, these file is not opensource, you should update the library to mozilla.

Comment 16

[Ming]

This bug need to be reopen, the rootcause should be found.

As far as now , i found that the audio's clock time problely is wrong.

In MediaDecoderStateMachine::AdvanceFrame()

When the next frame's frame->mTime is 3875000 microsecs, in the later 3 secs, the audio's clock time is as below:
So the frame is waiting allways when the audio's clock time is less than the frame->mTime;
And all buffers are in the queue , so the decoder couldn't get a buffer intime.

10-03 16:16:00.190   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3834875
10-03 16:16:00.260   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3817029
10-03 16:16:00.330   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3813990
10-03 16:16:00.400   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3811950
10-03 16:16:00.480   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3809931
10-03 16:16:00.550   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3806893
10-03 16:16:00.630   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3804852
10-03 16:16:00.710   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3801814
10-03 16:16:00.800   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3835782
10-03 16:16:00.850   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3796757
10-03 16:16:00.940   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3794716
10-03 16:16:01.030   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3828684
10-03 16:16:01.080   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3825646
10-03 16:16:01.140   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3862653
10-03 16:16:01.170   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3823628
10-03 16:16:01.230   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3820589
10-03 16:16:01.290   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3857573
10-03 16:16:01.320   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3818548
10-03 16:16:01.390   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3816508
10-03 16:16:01.460   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3813492
10-03 16:16:01.530   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3811451
10-03 16:16:01.610   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3808412
10-03 16:16:01.690   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3806371
10-03 16:16:01.770   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3803356
10-03 16:16:01.850   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3837301
10-03 16:16:01.900   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3799274
10-03 16:16:01.990   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3832245
10-03 16:16:02.040   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3869251
10-03 16:16:02.060   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3869251
10-03 16:16:02.080   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3830204
10-03 16:16:02.130   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3866213
10-03 16:16:02.150   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3828185
10-03 16:16:02.210   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3825147
10-03 16:16:02.270   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3861133
10-03 16:16:02.290   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3823106
10-03 16:16:02.360   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3820068
10-03 16:16:02.420   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3856077
10-03 16:16:02.450   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3818050
10-03 16:16:02.520   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3815011
10-03 16:16:02.590   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3812970
10-03 16:16:02.660   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3809931
10-03 16:16:02.740   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3807913
10-03 16:16:02.810   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3805873
10-03 16:16:02.890   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3802834
10-03 16:16:02.980   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3836802
10-03 16:16:03.030   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3797777
10-03 16:16:03.120   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3831723
10-03 16:16:03.170   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3867732
10-03 16:16:03.190   401   512 I ming.li ==>: MediaDecoderStateMachine::AdvanceFrame clock_time = 3829705

Comment 17

[Ming]

As i'm a newer to audio/video, so pls anyguy take this and try to find out why

Comment 18

[Vincent Liu[:vliu]]

Hi Bruce,

Can you please have a quick look for this? Thanks.

Comment 19

[Bruce Sun [:brsun]]

(In reply to Ming from comment #16)
> This bug need to be reopen, the rootcause should be found.
> 
> As far as now , i found that the audio's clock time problely is wrong.
> 
> In MediaDecoderStateMachine::AdvanceFrame()
> 
> When the next frame's frame->mTime is 3875000 microsecs, in the later 3
> secs, the audio's clock time is as below:
> So the frame is waiting allways when the audio's clock time is less than the
> frame->mTime;
> And all buffers are in the queue , so the decoder couldn't get a buffer
> intime.
> 

Hi Ming, what video clip did you test under this scenario?

Comment 20

[Ming]

(In reply to Bruce Sun [:brsun] from comment #19)

> Hi Ming, what video clip did you test under this scenario?

It's Firefox Flicks 2013- Beyond the Limit.mp4

Comment 21

[Bruce Sun [:brsun]]

(In reply to Ming from comment #20)
> (In reply to Bruce Sun [:brsun] from comment #19)
> 
> > Hi Ming, what video clip did you test under this scenario?
> 
> It's Firefox Flicks 2013- Beyond the Limit.mp4

The playback of this video and the files on comment 14 seems ok on my environment by using the latest codes:
 - follow the steps on https://bugzilla.mozilla.org/show_bug.cgi?id=956631#c25
 - flash boot.img, system.img, userdata.img
  ---> Gaia: 5d12b1bd33b457fdfa563953a9942096c6da138a
  ---> Gecko: 57625761da9e5c35d1ddd516221ce274a3575d15
  ---> framework/base: 985a870e1b28b9eb0bc008cdfe0b2517f483ea46

Hi Ming, what's your testing environment?

Comment 22

[Ming]

(In reply to Bruce Sun [:brsun] from comment #21)

> Hi Ming, what's your testing environment?

Pls revert the commit :0568d5246417a95289eca7c47c4cee674ce0f8cc in frameworks/base/ repository.

We inscreased the buffer numbers which makes this issue won't be reproduced.
But we don't know why, the rootcause hasn't found out.

Comment 23

[Bruce Sun [:brsun]]

Attachment: log_mediaserver_crash.txt

Hi Ming,
After I reset framework/base to af287128e2072a36ee7fdd03b5ee748693cd1c82, I always encounter SIGSEGV in /system/bin/mediaserver when loading "Firefox Flicks 2013- Beyond the Limit.mp4".

Comment 24

[Ming]

(In reply to Bruce Sun [:brsun] from comment #23)
> Created attachment 8396217 [details]
> log_mediaserver_crash.txt
> 
> Hi Ming,
> After I reset framework/base to af287128e2072a36ee7fdd03b5ee748693cd1c82, I
> always encounter SIGSEGV in /system/bin/mediaserver when loading "Firefox
> Flicks 2013- Beyond the Limit.mp4".

Hi,bruce , pls just revert the only commit 0568d5246417a95289eca7c47c4cee674ce0f8cc, donot reset .

There are some commit to resolve some mem lack crash issue after that. 
Also i will check on the latest update.

Comment 25

[Ming]

I checked on the latest update , just revert that only commit, this issue can be reproduced

Comment 26

[Bruce Sun [:brsun]]

Hi Ming,

There seems two problems under this scenario:
1. OMXCodec::read() usually timeout with "E OMXCodec: [OMX.sprd.h264.decoder] Timed out waiting for output buffers: 0/3" message.
 - This issue can be solved by 0568d5246417a95289eca7c47c4cee674ce0f8cc commit.
2. clock_time misbehaves, but this situation is caused by one strange behavior. The position get from SLPlayItf_::GetPosition() is not sync with the amount of accumulated data we sent by SLBufferQueueItf_::Enqueue().
 - Because gecko always appends enough silent audio data if there is not enough data available when slBufferQueueCallback (which is registered though SLBufferQueueItf_::RegisterCallback()) is called, the value get from SLPlayItf_::GetPosition() minus the amount of accumulated silent data would be the reference clock for gecko.
 - But somehow the increasing speed of SLPlayItf_::GetPosition() is slower then the speed of the accumulated amount of data by SLBufferQueueItf_::Enqueue() in this case. So clock_time becomes smaller and smaller.

I don't know why there is such strange behavior inside opensles. Please kindly share your comments if any.

BTW, the buffer starvation issue of problem 1 still needs to be fixed first. I don't see any relevance between the clock_time issue and the starvation issue.

Comment 27

[Ming]

(In reply to Bruce Sun [:brsun] from comment #26)

Tks ,bruce.

I found the clock_time issue is cause by the audio decoding. 
While it is getting stuck, the audio loop thread is waiting switch by "mon.Wait()" , as the AudioQueue's size is zero. So, it's obviously we need to look into the decode thread.

I think the clock issue cause the starvation issue, as i write in the comment 16.

Comment 28

[Ming]

Finaly ,i got why there is a starvation issue.

Could we config the preference of "media.video-queue.default-size"  to 2 ?
For while it is in starvation, 2 buffers are in the VideoQueue.
Code in the consturctor of MediaDecoderStateMachine:
mAmpleVideoFrames = Preferences::GetUint("media.video-queue.default-size", 3);

Comment 29

[Sotaro Ikeda [:sotaro]]

We can not change it to 2. In stead HWCodec needs to allocate more buffers. In early day's of b2g it was temporarily reduced. But it is back to 3 by Bug 863441.

Comment 30

[Ming]

(In reply to Sotaro Ikeda [:sotaro] from comment #29)
for bug 863441, The comment there is so long . I will read it later .

1.For our android platform on the same device to Tarako,  video work well with only 4 buffers.I will verify this with android guys, why it's ok for android. I will find the diff.

2.The hw buffers number is hard code , so isn't the buffer not enough for the case that  mPlaybackRate is bigger than 1?

Because code in MediaDecoderStateMachine::HaveEnoughDecodedVideo:

  if (static_cast<uint32_t>(mReader->VideoQueue().GetSize()) < GetAmpleVideoFrames() * mPlaybackRate) {
    return false;
  }

3.Could we seperate the decode thread to two threads :video decode thread ,audio decode thread? If ok, the starvation issue will gone.

another wold , the mem resource on tarako is lack, we should reduce the cost of mem.

Comment 31

[Sotaro Ikeda [:sotaro]]

Necessity of "media.video-queue.default-size=3" is mainly comes from implementation of nsMediaCache. nsMediaCache uses fix size of AnonymousTemporaryFile for all videos within application. In current b2g set to 4MB. The size is fixed, therefore video encoded data is not always prepared for OMXCodec decoding. Therefore, b2g needs more decoded video frames for HTTP video streaming.

Android uses different strategy for caching. It is implemented by NuCachedSource2. It caches continuous video data from 4MB-20MB per video. Encoded video data is always prepared for hw video codec, therefore number of decoded video frame could be fewer than b2g. But uses more cache RAMs.

FYI: you can see nsMediaCache related class in the following diagram.
https://github.com/sotaroikeda/firefox-diagrams/blob/master/media/content_media_ChannelMediaResource_FirefoxOS_1_01.pdf?raw=true

Comment 32

[Sotaro Ikeda [:sotaro]]

(In reply to Ming from comment #30)
> 3.Could we seperate the decode thread to two threads :video decode thread
> ,audio decode thread? If ok, the starvation issue will gone.

I could not understand the above explanation. Can you explain more about it? Why by using different threadb the problem is gone?

Comment 33

[Chris Pearce [:cpearce (Not reading bugmail)]]

(In reply to Ming from comment #30)
> 3.Could we seperate the decode thread to two threads :video decode thread
> ,audio decode thread? If ok, the starvation issue will gone.

I am working on separating MediaDecoderStateMachine video and audio decode calls to be asynchronous in bug 979104. Then we need to change MediaOmxReader to support async interface. Then MediaOmxReader will be able to run its audio and video decode on separate threads.

Bug 979104 should land in time for B2G 1.5. It will require risky changes, so we will not back-port it to B2G 1.4 or 1.3.

Comment 34

[Ming]

(In reply to Sotaro Ikeda [:sotaro] from comment #32)
> I could not understand the above explanation. Can you explain more about it?
> Why by using different threadb the problem is gone?

The starvation on video buffer makes the decode thread blocked, as audio decode is at behind, so it is also blocked. Thus ,there is no chance to get a audio frame to feet the conditions in AdvanceFrame to pop the videoqueue , render it to display, release the video buffer.  It seems like a round.

Comment 35

[Ming]

Left few questions :

Dear bruce:
1.It seems the clock_time misbehaves could cause some potential problems. 
.

2.Add more video buffers seems a resolution. But how many buffers will be enough?

Dear james:
pls have a look.

Comment 36

[Bruce Sun [:brsun]]

(In reply to Ming from comment #27)
> (In reply to Bruce Sun [:brsun] from comment #26)
> 
> Tks ,bruce.
> 
> I found the clock_time issue is cause by the audio decoding. 
> While it is getting stuck, the audio loop thread is waiting switch by
> "mon.Wait()" , as the AudioQueue's size is zero. So, it's obviously we need
> to look into the decode thread.
> 
> I think the clock issue cause the starvation issue, as i write in the
> comment 16.

Hi Ming,

Indeed the buffer starvation issue blocks the decoding threading, and both AudioQueue and VideoQueue becomes empty easily. But this blocking issue should not cause any effects to clock_time. OpenSL/ES library has its own thread to drive SLBufferQueueItf_::Enqueue() to fill data from AudioStream::DataCallback(), which is called from bufferqueue_callback() inside cubeb_opensl.c.

If there is not enough data in AudioQueue, AudioStream will append enough silent data to OpenSL/ES library to ensure the audio backend works properly. So normally speaking, SLPlayItf_::GetPosition() should keep increasing no matter how the decoding thread blocks in MediaDecoderStateMachine.

In order to have a correct clock reference, we have to accumulate how many fake silent data has been delivered to the audio backend. And if audio backend works properly, we can have a correct clock reference by subtracting the accumulated count of silent data from the value of SLPlayItf_::GetPosition(). Since AudioQueue is empty in this case, the increasing amount of SLPlayItf_::GetPosition() should be roughly equal to the increasing amount of accumulated silent data. Supposedly we should get a roughly fixed value for clock reference all the time by subtracting these two values.

That's why I need your input for the behavior of OpenSL/ES library.

Comment 37

[Ming]

(In reply to Bruce Sun [:brsun] from comment #36)
Thanks bruce.
I find i even don't know about  OpenSL/ES library. 
Is there any help can i do ?

Comment 38

[Star Cheng [:scheng]]

Hi, Ming

Maybe you can check the value of "mCblk->server" in AudioTrack. Because the getPosition() returns "mCblk->server" position.

mCblk->server : read position in shared buffer.
mCblk->user : write position in shared buffer.

Comment 39

[Ming]

(In reply to Star Cheng [:scheng] from comment #38)
> Hi, Ming
> 
> Maybe you can check the value of "mCblk->server" in AudioTrack. Because the
> getPosition() returns "mCblk->server" position.
> 
> mCblk->server : read position in shared buffer.
> mCblk->user : write position in shared buffer.
Ok
BTW ,shall we new a bug to track this?

Comment 40

[James Zhang (Spreadtrum)]

(In reply to Ming from comment #35)
> Left few questions :
> 
> Dear bruce:
> 1.It seems the clock_time misbehaves could cause some potential problems. 
> .
> 
> 2.Add more video buffers seems a resolution. But how many buffers will be
> enough?
> 
> Dear james:
> pls have a look.

Add buffer for workaround first and wait a patch of two thread for video/audio codec.

Comment 41

[Bruce Sun [:brsun]]

(In reply to James Zhang from comment #40)
> (In reply to Ming from comment #35)
> > Left few questions :
> > 
> > Dear bruce:
> > 1.It seems the clock_time misbehaves could cause some potential problems. 
> > .
> > 
> > 2.Add more video buffers seems a resolution. But how many buffers will be
> > enough?
> > 
> > Dear james:
> > pls have a look.
> 
> Add buffer for workaround first and wait a patch of two thread for
> video/audio codec.

Hi James,
Probably using two threads for video/audio codec doesn't help on this buffer starvation issue much. The blocking thread won't become non-blocking by doing this.

Comment 42

[Ming]

(In reply to Bruce Sun [:brsun] from comment #41)
> Probably using two threads for video/audio codec doesn't help on this buffer
> starvation issue much. The blocking thread won't become non-blocking by
> doing this.

Hi bruce,I'm puzzled . The cause is obviously.

BTW could i call your number?  There is nobody answer my call...

Comment 43

[Bruce Sun [:brsun]]

(In reply to Ming from comment #42)
> (In reply to Bruce Sun [:brsun] from comment #41)
> > Probably using two threads for video/audio codec doesn't help on this buffer
> > starvation issue much. The blocking thread won't become non-blocking by
> > doing this.
> 
> Hi bruce,I'm puzzled . The cause is obviously.
> 
> BTW could i call your number?  There is nobody answer my call...

Hi Ming,

Thanks for your calling. Now I understand that separate two threads could ease the buffer starvation issue in some cases.

When gecko plays more real audio data, clock_time increases. And the queued video data in VideoQueue can be popped and be rendered if the timestamps of it is smaller than clock_time. If the buffer starvation is caused due to gecko holds too many video buffers in VideoQueue at the same time, using separate threads for video/audio decoding to make clock_time increase continuously could ease this problem.