Fix an issue that audio and video may run out of sync

Fix an issue that audio and video may run out of sync

This CL fixes 3 issues:
1. In ProcessPendingEvents(), if there is a non-seek pending event, UpdateTimestamps() will not get called.
 This is probably the number 1 reason that a/v lose sync.
2. MSP use its internal clock to estimate the current presentation time. 
However, hardware may consume data at a different rate. 
Passing the current frame position from AudioTrack to MSP so we get a better estimation of the current time.
3. When config change comes, We don't need to reset the clock if audio decoder is not recreated.

BUG=351722
Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=263754

[qinmin, 2014-03-27 23:18:28]

PTAL

[wolenetz, 2014-04-01 18:15:47]

Thanks for sharing; I'm sorry it took me so long to get first round of CR done.

Here are some nits/comments + some questions on this approach:

I see in http://code.google.com/p/chromium/issues/detail?id=351722 that kitkat
is referenced. Is this approach also viable for jellybean?

I would like to see this work more like desktop pipeline: update max clock time
when data is decoded, and update current time when data is rendered; of course,
maintaining invariant that current time <= max time in both updates. Is this not
possible even in kitkat API?

https://codereview.chromium.org/215783002/diff/20001/media/base/android/java/...
File media/base/android/java/src/org/chromium/media/MediaCodecBridge.java
(right):

https://codereview.chromium.org/215783002/diff/20001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:531: //
TODO(qinmin): return the head position allows us to estimate
nit:s/return/Returning/

https://codereview.chromium.org/215783002/diff/20001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:535: //
convert the java nano time to C++ timestamp.
Why don't we do this?

Also, we should account for long-running streams: Per
http://developer.android.com/reference/android/media/AudioTrack.html#getPlayb...:
"It will wrap (overflow) periodically, for example approximately once every
27:03:11 hours:minutes:seconds at 44.1 kHz"

https://codereview.chromium.org/215783002/diff/20001/media/base/android/media...
File media/base/android/media_source_player.cc (right):

https://codereview.chromium.org/215783002/diff/20001/media/base/android/media...
media/base/android/media_source_player.cc:483: DCHECK(frames_to_play >= 0);
nit: lint: "Consider using DCHECK_GE instead of DCHECK(a >= b)"

[qinmin, 2014-04-01 20:42:34]

https://codereview.chromium.org/215783002/diff/20001/media/base/android/java/...
File media/base/android/java/src/org/chromium/media/MediaCodecBridge.java
(right):

https://codereview.chromium.org/215783002/diff/20001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:531: //
TODO(qinmin): return the head position allows us to estimate
On 2014/04/01 18:15:47, wolenetz wrote:
> nit:s/return/Returning/

Done.

https://codereview.chromium.org/215783002/diff/20001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:535: //
convert the java nano time to C++ timestamp.
This CL fixes the general AV sync issue in both JB and KitKat.
I will do a separate CL for kitkat to use getCurrentTimestamp().
Before this overlows, AudioTimeStampHelper would also overflow. 
Updated the TODO to mention both cases here, and filed bug 358801

On 2014/04/01 18:15:47, wolenetz wrote:
> Why don't we do this?
> 
> Also, we should account for long-running streams: Per
>
http://developer.android.com/reference/android/media/AudioTrack.html#getPlayb...:
> "It will wrap (overflow) periodically, for example approximately once every
> 27:03:11 hours:minutes:seconds at 44.1 kHz"

https://codereview.chromium.org/215783002/diff/20001/media/base/android/media...
File media/base/android/media_source_player.cc (right):

https://codereview.chromium.org/215783002/diff/20001/media/base/android/media...
media/base/android/media_source_player.cc:483: DCHECK(frames_to_play >= 0);
On 2014/04/01 18:15:47, wolenetz wrote:
> nit: lint: "Consider using DCHECK_GE instead of DCHECK(a >= b)"

Done.

[qinmin, 2014-04-01 20:53:35]

This CL intends to solve the AV sync issues for both kitkat and JB, so it
applies to both SDK.
However, I added a TODO in MediaCodecBridge.java to use kitkat only API for more
accurate
presentation timestamp calculation. But that will be in a separate CL.

Because decoder reports to MSP after each AU is decoded, MSP has the same max
clock time as
 the decoder has (althogh MSP gets the information a little late). For the
current time, android 
will only tell us when a particular past frame was rendered. MSP will have to
guess 
the current time information based on the time when a past frame is rendered.


On 2014/04/01 18:15:47, wolenetz wrote:
> Thanks for sharing; I'm sorry it took me so long to get first round of CR
done.
> 
> Here are some nits/comments + some questions on this approach:
> 
> I see in http://code.google.com/p/chromium/issues/detail?id=351722 that kitkat
> is referenced. Is this approach also viable for jellybean?
> 
> I would like to see this work more like desktop pipeline: update max clock
time
> when data is decoded, and update current time when data is rendered; of
course,
> maintaining invariant that current time <= max time in both updates. Is this
not
> possible even in kitkat API?
>

[wolenetz, 2014-04-03 18:14:40]

Looking pretty good.

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
File media/base/android/java/src/org/chromium/media/MediaCodecBridge.java
(right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:526:
private long playOutputBuffer(byte[] buf) {
nit: I'm less familiar with Chromium java coding style, but IMO better
documentation of retval would be good to have.

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:543: //
issue. See crbug.com/358801.
nit: s/crbug.com/http:\/\/crbug.com/

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:546: return
0;
Might we ever call this method when |mAudioTrack| is null? If so, do we
correctly handle a 0 retval in caller (and, in general, do we correctly handle
null mAudioTrack?)

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
File media/base/android/media_codec_bridge.cc (right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_codec_bridge.cc:384: return
Java_MediaCodecBridge_releaseOutputBuffer(
Perhaps I'm confused here, but ILTM like the .java version of this method
returns void, and so does this method. What retval are we trying to return here?

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
File media/base/android/media_source_player.cc (right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player.cc:485: base::TimeDelta
current_presentation_timestamp =
nit: Please document this is guessing the current_presentation_timestamp due to
lack of current info from the renderer. In later CL that uses kitkat support, do
I understand correctly that this code would change (for kitkat) to no longer
guess?

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player.cc:492:
clock_.SetMaxTime(presentation_timestamp);
Is it possible for audio decode+render to report 0 audio output bytes? If so,
would we want so instead use the audio_timestamp_helper_->GetTimestamp() here
(of course, for audio, not video)?

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player.cc:596: int64 audio_head_position,
base::TimeTicks audio_render_time) {
nit: DCHECK that, if |is_audio| is true, that all of these |audio_xxx|
parameters are 0 as required in the ReleaseOutputCallback's comments.

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
File media/base/android/media_source_player_unittest.cc (right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player_unittest.cc:2067:
TEST_F(MediaSourcePlayerTest, CurrentTimeUpdatedWhileDecoderStarved) {
Does this one test cover all 3 items in this CL's description? If not, please
consider adding more coverage.

[qinmin, 2014-04-03 21:59:45]

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
File media/base/android/java/src/org/chromium/media/MediaCodecBridge.java
(right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:526:
private long playOutputBuffer(byte[] buf) {
Done. Java doc added.

On 2014/04/03 18:14:40, wolenetz wrote:
> nit: I'm less familiar with Chromium java coding style, but IMO better
> documentation of retval would be good to have.

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:543: //
issue. See crbug.com/358801.
On 2014/04/03 18:14:40, wolenetz wrote:
> nit: s/crbug.com/http:\/\/crbug.com/

Done.

https://codereview.chromium.org/215783002/diff/40001/media/base/android/java/...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:546: return
0;
This should never happen in our code. The if statement is just to ensure this
will not be misused in the future. We can also change it to an assert.

On 2014/04/03 18:14:40, wolenetz wrote:
> Might we ever call this method when |mAudioTrack| is null? If so, do we
> correctly handle a 0 retval in caller (and, in general, do we correctly handle
> null mAudioTrack?)

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
File media/base/android/media_codec_bridge.cc (right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_codec_bridge.cc:384: return
Java_MediaCodecBridge_releaseOutputBuffer(
added by accident. Removed.

On 2014/04/03 18:14:40, wolenetz wrote:
> Perhaps I'm confused here, but ILTM like the .java version of this method
> returns void, and so does this method. What retval are we trying to return
here?

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
File media/base/android/media_source_player.cc (right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player.cc:485: base::TimeDelta
current_presentation_timestamp =
Comments added.
For kitkat, we still need to do the guess. The kitkat call returns the timestamp
A a particular frame B is rendered in the past. So we still need to calculate
the current presentation time based on the timestamp A and position of frame B.

On 2014/04/03 18:14:40, wolenetz wrote:
> nit: Please document this is guessing the current_presentation_timestamp due
to
> lack of current info from the renderer. In later CL that uses kitkat support,
do
> I understand correctly that this code would change (for kitkat) to no longer
> guess?

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player.cc:492:
clock_.SetMaxTime(presentation_timestamp);
Yes, this is possible. For example, during the preroll phase. Changed the else
statement to else if (!HasAudio()).
If HasAudio() is true and we are not queueing any output to the AudioTrack, just
do nothing and the clock will progress by itself. 

On 2014/04/03 18:14:40, wolenetz wrote:
> Is it possible for audio decode+render to report 0 audio output bytes? If so,
> would we want so instead use the audio_timestamp_helper_->GetTimestamp() here
> (of course, for audio, not video)?

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player.cc:596: int64 audio_head_position,
base::TimeTicks audio_render_time) {
On 2014/04/03 18:14:40, wolenetz wrote:
> nit: DCHECK that, if |is_audio| is true, that all of these |audio_xxx|
> parameters are 0 as required in the ReleaseOutputCallback's comments.

you mean |!is_audio|? Done.

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
File media/base/android/media_source_player_unittest.cc (right):

https://codereview.chromium.org/215783002/diff/40001/media/base/android/media...
media/base/android/media_source_player_unittest.cc:2067:
TEST_F(MediaSourcePlayerTest, CurrentTimeUpdatedWhileDecoderStarved) {
This covers the first item in the description. I added another test to cover
item 3.
For item 2, there is no good way to test it as we need to either mock or read
the AudioTrack object. Since we have lots of DCHECKs in the code and there are
several tests covers the presentation timestamp calculation after preroll, i
think those should provide a good coverage for us now.

On 2014/04/03 18:14:40, wolenetz wrote:
> Does this one test cover all 3 items in this CL's description? If not, please
> consider adding more coverage.

[wolenetz, 2014-04-04 17:27:42]

lgtm % nit. I would like for acolwell@ to also provide CR to at least help
ensure this doesn't diverge further from desktop pipeline. Thanks for sharing!

https://codereview.chromium.org/215783002/diff/60001/media/base/android/media...
File media/base/android/media_source_player_unittest.cc (right):

https://codereview.chromium.org/215783002/diff/60001/media/base/android/media...
media/base/android/media_source_player_unittest.cc:2112: EXPECT_EQ(helper,
GetAudioTimestampHelper());
nit: Is there a better way than pointer comparison to ensure we haven't created
a new helper? I would prefer we don't further proliferate such a check that may
not always catch that the instance has changed, if the memory allocator re-used
the same location for the new instance. There's other locations in other tests
in this file that do this (e.g. to check if decoder job has/hasn't changed) that
I'm also concerned with. File bug + a TODO?

[qinmin, 2014-04-04 17:58:18]

https://codereview.chromium.org/215783002/diff/60001/media/base/android/media...
File media/base/android/media_source_player_unittest.cc (right):

https://codereview.chromium.org/215783002/diff/60001/media/base/android/media...
media/base/android/media_source_player_unittest.cc:2112: EXPECT_EQ(helper,
GetAudioTimestampHelper());
On 2014/04/04 17:27:43, wolenetz wrote:
> nit: Is there a better way than pointer comparison to ensure we haven't
created
> a new helper? I would prefer we don't further proliferate such a check that
may
> not always catch that the instance has changed, if the memory allocator
re-used
> the same location for the new instance. There's other locations in other tests
> in this file that do this (e.g. to check if decoder job has/hasn't changed)
that
> I'm also concerned with. File bug + a TODO?

Done.

[qinmin, 2014-04-04 17:58:57]

ping, acolwell@, would you please take a look at this? Thanks

[acolwell GONE FROM CHROMIUM, 2014-04-04 19:25:58]

https://codereview.chromium.org/215783002/diff/80001/media/base/android/media...
File media/base/android/media_source_player.cc (right):

https://codereview.chromium.org/215783002/diff/80001/media/base/android/media...
media/base/android/media_source_player.cc:493: current_presentation_timestamp =
new_max_time;
It feels like the bulk of this logic should be in the AudioDecoderJob. It seems
like there would be a lot fewer changes if you moved the audio_timestamp_helper_
into AudioDecoderJob and simply posted a task to this thread with a new
current_presentation_timestamp and new_max_time. That would be more in line with
what the pipeline code does and as long as there aren't significant delays on
this thread, it should be pretty accurate.

Am I missing something key about why this couldn't work?

[qinmin, 2014-04-04 19:42:51]

https://codereview.chromium.org/215783002/diff/80001/media/base/android/media...
File media/base/android/media_source_player.cc (right):

https://codereview.chromium.org/215783002/diff/80001/media/base/android/media...
media/base/android/media_source_player.cc:493: current_presentation_timestamp =
new_max_time;
ok， I will move the logic there. 
However, the received presentation timestamp is a past thingy due to the delays
introduced by the posted task. I think we can ignore the delay for now, unless
we found the delays to be too significant to ignore.

On 2014/04/04 19:25:58, acolwell wrote:
> It feels like the bulk of this logic should be in the AudioDecoderJob. It
seems
> like there would be a lot fewer changes if you moved the
audio_timestamp_helper_
> into AudioDecoderJob and simply posted a task to this thread with a new
> current_presentation_timestamp and new_max_time. That would be more in line
with
> what the pipeline code does and as long as there aren't significant delays on
> this thread, it should be pretty accurate.
> 
> Am I missing something key about why this couldn't work?

[qinmin, 2014-04-04 23:09:03]

Done, moved the AudioTimestampHelper to audio_decoder_job.cc
acolwell@, would you please take a look again?

[qinmin, 2014-04-11 17:45:18]

ping. acolwell@, would you please take another look?


On 2014/04/04 23:09:03, qinmin wrote:
> Done, moved the AudioTimestampHelper to audio_decoder_job.cc
> acolwell@, would you please take a look again?

[acolwell GONE FROM CHROMIUM, 2014-04-14 16:00:47]

lgtm

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
File media/base/android/audio_decoder_job.cc (right):

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
media/base/android/audio_decoder_job.cc:86: current_presentation_timestamp =
kNoTimestamp();
nit: Move this to an else so it doesn't get set twice in the course of normal
execution.

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
media/base/android/audio_decoder_job.cc:87: if (size_to_render) {
nit: s/size_to_render/render_output/ here since size_to_render is only used once
below now?

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
media/base/android/audio_decoder_job.cc:89: output_buffer_index,
size_to_render);
nit: s/size_to_render/size/ ?

https://codereview.chromium.org/215783002/diff/140001/media/base/android/java...
File media/base/android/java/src/org/chromium/media/MediaCodecBridge.java
(right):

https://codereview.chromium.org/215783002/diff/140001/media/base/android/java...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:534: if
(mAudioTrack != null) {
nit: reverse condition and return early?

https://codereview.chromium.org/215783002/diff/140001/media/base/android/vide...
File media/base/android/video_decoder_job.cc (right):

https://codereview.chromium.org/215783002/diff/140001/media/base/android/vide...
media/base/android/video_decoder_job.cc:66: base::TimeDelta
current_presentation_timestamp,
It's too bad we have to have this parameter just so we can forward it to the
callback here. :/ Unfortunately I don't have a good alternate proposal right
now.

[qinmin, 2014-04-14 19:01:58]

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
File media/base/android/audio_decoder_job.cc (right):

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
media/base/android/audio_decoder_job.cc:86: current_presentation_timestamp =
kNoTimestamp();
On 2014/04/14 16:00:47, acolwell wrote:
> nit: Move this to an else so it doesn't get set twice in the course of normal
> execution.

Done.

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
media/base/android/audio_decoder_job.cc:87: if (size_to_render) {
On 2014/04/14 16:00:47, acolwell wrote:
> nit: s/size_to_render/render_output/ here since size_to_render is only used
once
> below now?

0u is also a case we need to bypass due to an android bug.
Removed size_to_render variable, but added "render_output= render_output &&
(size != 0u)"

https://codereview.chromium.org/215783002/diff/140001/media/base/android/audi...
media/base/android/audio_decoder_job.cc:89: output_buffer_index,
size_to_render);
On 2014/04/14 16:00:47, acolwell wrote:
> nit: s/size_to_render/size/ ?

Done.

https://codereview.chromium.org/215783002/diff/140001/media/base/android/java...
File media/base/android/java/src/org/chromium/media/MediaCodecBridge.java
(right):

https://codereview.chromium.org/215783002/diff/140001/media/base/android/java...
media/base/android/java/src/org/chromium/media/MediaCodecBridge.java:534: if
(mAudioTrack != null) {
On 2014/04/14 16:00:47, acolwell wrote:
> nit: reverse condition and return early?

Done.

[qinmin, 2014-04-14 19:02:03]

The CQ bit was checked by qinmin@chromium.org

[commit-bot: I haz the power, 2014-04-14 19:03:50]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/qinmin@chromium.org/215783002/160001

[commit-bot: I haz the power, 2014-04-15 00:41:36]

Change committed as 263754

[horo, 2014-04-15 05:45:49]

A revert of this CL has been created in
https://codereview.chromium.org/238053004/ by horo@chromium.org.

The reason for reverting is: Android Tests failed
http://build.chromium.org/p/chromium.linux/builders/Android%20Tests/builds/13105



Note: Google Test filter =
MediaSourcePlayerTest.CurrentTimeUpdatedWhileDecoderStarved
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from MediaSourcePlayerTest
[ RUN      ] MediaSourcePlayerTest.CurrentTimeUpdatedWhileDecoderStarved
../../media/base/android/media_source_player_unittest.cc:2088: Failure
Expected: (current_time.InMillisecondsF()) <
(player_.GetCurrentTime().InMillisecondsF()), actual: 0 vs 0
[  FAILED  ] MediaSourcePlayerTest.CurrentTimeUpdatedWhileDecoderStarved (305
ms)
[----------] 1 test from MediaSourcePlayerTest (305 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (307 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] MediaSourcePlayerTest.CurrentTimeUpdatedWhileDecoderStarved.