994015 - [tarako]some mp4 video plays not smoothly

Status: RESOLVED FIXED

(Core :: Audio/Video, defect)

Description

[Ming]

DEVICE:tarako 
gecko:v1.3

when playing the video, it's lag at some point.


I had made some basic analysis.
The rootcause is the in the decode thread, for the video and audio are decode in the same thread one by one .
And there are tow things make it more worsely, first when decoding video,it will loop for a long time in MediaOmxReader::DecodeVideoFrame if the subsequent frames need to be droped.And so it blocks the audio decoding for a long time.
The second is there is mVideoSource->read often can't get a buffer intime, this makes the every call of MediaOmxReader::DecodeVideoFrame takes more time.

Bug 979104 will be helpful for this case, so if possible ,pls merge it to V1.3.
 

In the same time,t tried to close the skipping frames in MediaOmxReader::DecodeVideoFrame and increase the buffers, then it played okay.

Here are the log datas i got:
the datas are the wait times in the audio loop,in us.
1.got on the current version
365808
323021
160294
133949
120182
110541
90147
89795
88338
75074
72680
70553
69077
65912
63596
57937
57907
54189
52477
51440

2.only add one buffer


308459
250271
136611
105242
99067
82021
79697
78548
77906
73341
71269
70855
68728
65492
63454
61745
60362
60179
59047
58563

3.only set skipToNextKeyframe to false always in decode loop
224983  //this one is because read is blocked by waiting for buffers.
49153
44612
43174
42159
41856
39758
37791
37097
36789
36410
35283
35278
35131
33863
33486
33235
32307
32151
32103

4.add a buffer ,and set skipToNextKeyframe to false always in decode loop
94423
71336
71078
65419
59561
58453
52402
50722
50630
49988
47460
45639
45163
44601
41052
40935
40678
39776
39105
39065




So, i'll do a commit to add a buffer in sprd's code. Pls someone take this and make a possible resolution in gecko.

Comment 1

[Ming]

type error ,not v1.3 , it is V1.3t

Comment 2

[Ming]

Attachment: H264_High10 1.1_480X320_V1500_V25_AAC_A272_A48_stereo_Carly Rae Jepsen-Call Me Maybe.mp4

Comment 3

[Ming]

hi brsun ,have a look

Comment 4

[Anthony Jones (:ajones, :kentuckyfriedtakahe, :k17e)]

(In reply to Ming from comment #0)
> Bug 979104 will be helpful for this case, so if possible ,pls merge it to
> V1.3.

This would be a risky thing to do. 979104 depends on 973408 which makes extensive changes (9 patches) and also 962385 (3 patches). If we need to uplift these fixes then it would be least risky to uplift all the changes to content/media since the 1.3T fork.

Given the risk we shouldn't do that unless this issue is a blocking issue and we're prepared to risk holding up the release for it.

Comment 5

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

Hi Ming, 
What is the HW capability of video codec on Taroko? 
Would it be possible that this codec have not much power to decode this high profible h.264? 
Besides, I think this should not be a block issue since the profile of recorded video file by Taroko is simple profile and users most of time play the files he or she recorded on the phone.

Comment 6

[Ming]

(In reply to Blake Wu [:bwu] from comment #5)
> Hi Ming, 
> What is the HW capability of video codec on Taroko? 
Now tarako uses soft decoder.
> Would it be possible that this codec have not much power to decode this high
> profible h.264? 
No,in fact the decoding is fast enough . Most of the cost is at waiting for buffers. And it is most likely caused by skiping video frames. 

log data like this: 
 187 04-09 14:53:33.660 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 72695
 188 04-09 14:53:33.710 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 49894
 189 04-09 14:53:33.760 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 42910
 190 04-09 14:53:33.850 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 89429
 191 04-09 14:53:33.860 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 9902
 192 04-09 14:53:33.890 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 29543
 193 04-09 14:53:33.920 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 28724
 194 04-09 14:53:33.960 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 40548
 195 04-09 14:53:33.960 440 456 I ming.li ==>: decode loop video 364775
 196 04-09 14:53:33.960 440 456 I ming.li ==>: decode loop audio 1511
 197 04-09 14:53:33.960 440 465 I ming.li ==>: audio loop -wait ==> 365808
 198 04-09 14:53:33.990 440 465 I ming.li ==>: audio loop -wait ==> 34105
 199 04-09 14:53:34.010 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 51105
 200 04-09 14:53:34.050 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 37293
 201 04-09 14:53:34.080 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 34891
 202 04-09 14:53:34.120 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 40337
 203 04-09 14:53:34.160 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 36699
 204 04-09 14:53:34.190 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 32908
 205 04-09 14:53:34.230 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 33593
 206 04-09 14:53:34.270 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 45440
 207 04-09 14:53:34.310 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 41781
 208 04-09 14:53:34.310 440 456 I ming.li ==>: decode loop video 355178
 209 04-09 14:53:34.310 440 456 I ming.li ==>: decode loop audio 1931
 210 04-09 14:53:34.320 440 465 I ming.li ==>: audio loop -wait ==> 323021
 211 04-09 14:53:34.320 440 465 I ming.li ==>: audio loop -wait ==> 6231
 212 04-09 14:53:34.350 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 38251
 213 04-09 14:53:34.390 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 31840
 214 04-09 14:53:34.420 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 31594
 215 04-09 14:53:34.450 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 30746
 216 04-09 14:53:34.480 440 456 I ming.li ==>: 0x43607100 waitforbuffers cost 30680
 217 04-09 14:53:34.480 440 456 I ming.li ==>: decode loop video 163808

Comment 7

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

(In reply to Ming from comment #6)
> (In reply to Blake Wu [:bwu] from comment #5)
> > Hi Ming, 
> > What is the HW capability of video codec on Taroko? 
> Now tarako uses soft decoder.
> > Would it be possible that this codec have not much power to decode this high
> > profible h.264? 
> No,in fact the decoding is fast enough . Most of the cost is at waiting for
How do you know the decoding is fast enough? 
A software decoder may be not capable of decoding a high profile h.264 file. 
Could you check how long for this decoder to decode one keyframe? 
For logs, could you attach the codes you added the logs?  
> buffers. And it is most likely caused by skiping video frames. 
skipping video frames is probably because video frames comes too late. 
> 
> log data like this: 
>  187 04-09 14:53:33.660 440 456 I ming.li ==>: 0x43607100 waitforbuffers
> cost 72695

Comment 8

[Ming]

(In reply to Blake Wu [:bwu] from comment #7)
Ok, && i will attach the logs
1.in MediaDecoderStateMachine::AudioLoop
1121         struct timeval t_start,t_end;                                                                             
1122         gettimeofday(&t_start, NULL);                                                                             
1123         if (!IsPlaying() && !mAudioStream->IsPaused()) {                                                          
1124           mAudioStream->Pause();                                                                                  
1125         }                                                                                                         
1126         mon.Wait();                                                                                               
1127         gettimeofday(&t_end, NULL);                                                                               
1128         MINGLOG("audio loop -wait ==> %ld",t_end.tv_usec - t_start.tv_usec); 


2.in MediaDecoderStateMachine::DecodeLoop
 921         struct timeval t_start,t_end;
 922         gettimeofday(&t_start, NULL);
 923         //MINGLOG("decode loop video - b");
 924         videoPlaying = mReader->DecodeVideoFrame(skipToNextKeyframe, currentTime);
 925         //MINGLOG("decode loop video - e");
 926         gettimeofday(&t_end, NULL);
 927         MINGLOG("decode loop video %ld",t_end.tv_usec - t_start.tv_usec);

3.in MediaDecoderStateMachine::DecodeLoop
 957       struct timeval t_start,t_end;
 958       gettimeofday(&t_start, NULL);
 959       audioPlaying = mReader->DecodeAudioData();
 960       gettimeofday(&t_end, NULL);
 961       MINGLOG("decode loop audio %ld",t_end.tv_usec - t_start.tv_usec);

4.in OMXCodec::waitForBufferFilled_l

3510     struct timeval t_start,t_end;
3511     gettimeofday(&t_start, NULL);
3512 
3513     status_t err = mBufferFilled.waitRelative(mLock, kBufferFilledEventTimeOutNs);
3514 
3515     gettimeofday(&t_end, NULL);
3516     MINGLOG("%p waitforbuffers cost %ld",this,t_end.tv_usec-t_start.tv_usec);

5:in OMXCodec::OMXCodec
MINGLOG("OMXCodec %p %s",this,mime);

Comment 9

[Ming]

Attachment: logs got without modifing the code

Comment 10

[Ming]

Attachment: logs got with adding a buffer and always setting the skipToNextKeyframe to false

Comment 11

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

Thanks for your attachment. 
After you closed the skip the skipping frames as comment 1, did you notice any av unsync problem?

Comment 12

[Ming]

(In reply to Blake Wu [:bwu] from comment #11)
Not yet.But no test for this.

But i think the needed to be skipped frames can be droped in AdvanceFrames. Here now it won't block any ning.

Comment 13

[Ming]

And that why i closed the skipping frames in decode loop as i tried.

Comment 14

[Ming]

So ,i suggest that we close the skipping frames in decode loop in v1.3T. Onece bug 979104 is ready to be merged in , we turn this feature on.

Comment 15

[Ming]

Attachment: 994015.patch

Comment 16

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

The problem is that we spend too much time in MediaOmxReader::DecodeVideoFrame() when aKeyframeSkip==true.

This is because MediaOmxReader::DecodeVideoFrame() tries to decode all frames up to the next keyframe when aKeyframeSkip==true.

When aKeyframeSkip==true DecodeVideoFrame() is supposed to seek to the next keyframe after aTimeThreshold and decode video frames from there. MediaOmxReader does not do that because on some devices that causes problems (bug 812756).

We can make MediaOmxReader::DecodeVideoFrame() exit sooner by changing MAX_VIDEO_DECODE_SECONDS in MediaOmxReader.cpp:22.

Ming: Please try changing MAX_VIDEO_DECODE_SECONDS to 0.1 and test if that helps.

Comment 17

[Ming]

Ok,i will try later .

It seems bug 812756 hasn't been merged into v1.3t. So should we merge it in?

Comment 18

[[:fabrice] Fabrice Desré]

(In reply to Ming from comment #17)
> Ok,i will try later .
> 
> It seems bug 812756 hasn't been merged into v1.3t. So should we merge it in?

This bug landed more than a year ago...

Comment 19

[Ming]

Attachment: MediaOmxReader.cpp

here is the code i see, pls help to verify it

Comment 20

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

Comment on attachment 8405111 [details] [diff] [review]
994015.patch

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

Try pushing http://people.mozilla.org/~cpearce/video/facebook-paper.webm onto /sdcard/Videos and play it with Video App. With this patch, audio stutters. Without this patch, audio is smooth.

I still get stutter if I set aSkipToKeyframe=false in MediaOmxReader::DecodeVideoFrame(), so I don't think the fix is as simple as this. I will look into it more on Monday, GTG now.

Comment 21

[Ming]

(In reply to Ming from comment #19)
It seems i made a mistake. ignore this...

Comment 22

[Ming]

(In reply to Chris Pearce (:cpearce) from comment #16)
> Ming: Please try changing MAX_VIDEO_DECODE_SECONDS to 0.1 and test if that
> helps.
I tried.  more or less better . 
The upper limit of cost of the waiting in audio loop is smaller.
Before changed ,i got 
220944
204354
155317
103922
after changed , i got
128257
116029
92949
82030

Comment 23

[Ming]

Attachment: 994015-2.patch

This also can help to reduce block times  in every decoding of video.

Comment 24

[Joe Cheng [:jcheng] (please needinfo)]

triage: let's not block on this. when the patch is review+, lets dicsuss uplifting. thanks

Comment 25

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

Changing MAX_VIDEO_DECODE_SECONDS to 0.1 may not be helpful, since the bottleneck is ReadVideo() in OmxDecoder which sometimes takes long time. That's why I still can observe the playback is not smooth on my Tarako. And if i disable the skipToNextKeyFrame, I can still feel unsmooth.  

Hi Ming, 
Could you add the logs to check how long for decoder to decode one keyframe? I think sw decoder may not be powerful to decode this high profile.

Comment 26

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

Comment on attachment 8405256 [details] [diff] [review]
994015-2.patch

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

You could also try increasing AMPLE_AUDIO_USECS. This causes us to buffer more decoded audio data. But as bwu says, the Tarako CPU is probably too slow to decode this HD video, so until we have async decoding, there's not much we can do.

Comment 27

[Joe Cheng [:jcheng] (please needinfo)]

triage: taking this for tarako as the risk seems low. thanks

Comment 28

[thomas tsai]

how about tarako android performance to play this mp4?

Comment 29

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/b2a9790f3753

Comment 30

[James Zhang (Spreadtrum)]

(In reply to thomas tsai from comment #28)
> how about tarako android performance to play this mp4?

Android works fine.

Comment 31

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/b2a9790f3753

Comment 32

[[:fabrice] Fabrice Desré]

https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/8f5c4787868f

Comment 33

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

(In reply to James Zhang from comment #30)
> (In reply to thomas tsai from comment #28)
> > how about tarako android performance to play this mp4?
> 
> Android works fine.

I'd guess Android probably decodes audio and video on separate threads. I'm working on that in bug 962385, but I think will be too risky to uplift that to v1.3t.

Comment 34

[James Zhang (Spreadtrum)]

(In reply to Chris Pearce (:cpearce) from comment #33)
> (In reply to James Zhang from comment #30)
> > (In reply to thomas tsai from comment #28)
> > > how about tarako android performance to play this mp4?
> > 
> > Android works fine.
> 
> I'd guess Android probably decodes audio and video on separate threads. I'm
> working on that in bug 962385, but I think will be too risky to uplift that
> to v1.3t.

yes, android use two thread. we can revert this patch if it cause some issue.