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

media/base/android/media_source_player.cc

 // Copyright (c) 2013 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/base/android/media_source_player.h"
 
 #include <limits>
 
 #include "base/android/jni_android.h"
 #include "base/android/jni_string.h"
 #include "base/barrier_closure.h"
 #include "base/basictypes.h"
 #include "base/bind.h"
 #include "base/callback_helpers.h"
 #include "base/debug/trace_event.h"
 #include "base/logging.h"
 #include "base/strings/string_number_conversions.h"
 #include "media/base/android/audio_decoder_job.h"
 #include "media/base/android/media_drm_bridge.h"
 #include "media/base/android/media_player_manager.h"
 #include "media/base/android/video_decoder_job.h"
-#include "media/base/audio_timestamp_helper.h"
 #include "media/base/buffers.h"
 
-namespace {
-
-// Use 16bit PCM for audio output. Keep this value in sync with the output
-// format we passed to AudioTrack in MediaCodecBridge.
-const int kBytesPerAudioOutputSample = 2;
-}
-
 namespace media {
 
 MediaSourcePlayer::MediaSourcePlayer(
     int player_id,
     MediaPlayerManager* manager,
     const RequestMediaResourcesCB& request_media_resources_cb,
     const ReleaseMediaResourcesCB& release_media_resources_cb,
     scoped_ptr<DemuxerAndroid> demuxer)
     : MediaPlayerAndroid(player_id,
                          manager,
@@ skipping 68 matching lines @@
 }
 
 void MediaSourcePlayer::ScheduleSeekEventAndStopDecoding(
     base::TimeDelta seek_time) {
   DVLOG(1) << __FUNCTION__ << "(" << seek_time.InSecondsF() << ")";
   DCHECK(!IsEventPending(SEEK_EVENT_PENDING));
 
   pending_seek_ = false;
 
   clock_.SetTime(seek_time, seek_time);
-  if (audio_timestamp_helper_)
-    audio_timestamp_helper_->SetBaseTimestamp(seek_time);
 
   if (audio_decoder_job_ && audio_decoder_job_->is_decoding())
     audio_decoder_job_->StopDecode();
   if (video_decoder_job_ && video_decoder_job_->is_decoding())
     video_decoder_job_->StopDecode();
 
   SetPendingEvent(SEEK_EVENT_PENDING);
   ProcessPendingEvents();
 }
 
@@ skipping 176 matching lines @@
     const DemuxerConfigs& configs) {
   DVLOG(1) << __FUNCTION__;
   duration_ = base::TimeDelta::FromMilliseconds(configs.duration_ms);
   clock_.SetDuration(duration_);
 
   audio_codec_ = configs.audio_codec;
   num_channels_ = configs.audio_channels;
   sampling_rate_ = configs.audio_sampling_rate;
   is_audio_encrypted_ = configs.is_audio_encrypted;
   audio_extra_data_ = configs.audio_extra_data;
-  if (HasAudio()) {
-    DCHECK_GT(num_channels_, 0);
-    audio_timestamp_helper_.reset(new AudioTimestampHelper(sampling_rate_));
-    audio_timestamp_helper_->SetBaseTimestamp(GetCurrentTime());
-  } else {
-    audio_timestamp_helper_.reset();
-  }
-
   video_codec_ = configs.video_codec;
   width_ = configs.video_size.width();
   height_ = configs.video_size.height();
   is_video_encrypted_ = configs.is_video_encrypted;
 
   manager()->OnMediaMetadataChanged(
       player_id(), duration_, width_, height_, true);
 
   if (IsEventPending(CONFIG_CHANGE_EVENT_PENDING)) {
     if (reconfig_audio_decoder_)
@@ skipping 101 matching lines @@
   // player clock to the actual seek target.
   if (doing_browser_seek_) {
     DCHECK(actual_browser_seek_time != kNoTimestamp());
     base::TimeDelta seek_time = actual_browser_seek_time;
     // A browser seek must not jump into the past. Ideally, it seeks to the
     // requested time, but it might jump into the future.
     DCHECK(seek_time >= GetCurrentTime());
     DVLOG(1) << __FUNCTION__ << " : setting clock to actual browser seek time: "
              << seek_time.InSecondsF();
     clock_.SetTime(seek_time, seek_time);
-    if (audio_timestamp_helper_)
-      audio_timestamp_helper_->SetBaseTimestamp(seek_time);
+    if (audio_decoder_job_)
+      audio_decoder_job_->SetBaseTimestamp(seek_time);
   } else {
     DCHECK(actual_browser_seek_time == kNoTimestamp());
   }
 
   reached_audio_eos_ = false;
   reached_video_eos_ = false;
 
   base::TimeDelta current_time = GetCurrentTime();
   // TODO(qinmin): Simplify the logic by using |start_presentation_timestamp_|
   // to preroll media decoder jobs. Currently |start_presentation_timestamp_|
   // is calculated from decoder output, while preroll relies on the access
   // unit's timestamp. There are some differences between the two.
   preroll_timestamp_ = current_time;
   if (audio_decoder_job_)
     audio_decoder_job_->BeginPrerolling(preroll_timestamp_);
   if (video_decoder_job_)
     video_decoder_job_->BeginPrerolling(preroll_timestamp_);
 
   if (!doing_browser_seek_)
     manager()->OnSeekComplete(player_id(), current_time);
 
   ProcessPendingEvents();
 }
 
 void MediaSourcePlayer::UpdateTimestamps(
-    base::TimeDelta presentation_timestamp, size_t audio_output_bytes) {
-  base::TimeDelta new_max_time = presentation_timestamp;
+    base::TimeDelta current_presentation_timestamp,
+    base::TimeDelta max_presentation_timestamp) {
+  clock_.SetTime(current_presentation_timestamp, max_presentation_timestamp);
 
-  if (audio_output_bytes > 0) {
-    audio_timestamp_helper_->AddFrames(
-        audio_output_bytes / (kBytesPerAudioOutputSample * num_channels_));
-    new_max_time = audio_timestamp_helper_->GetTimestamp();
-  }
-
-  clock_.SetMaxTime(new_max_time);
   manager()->OnTimeUpdate(player_id(), GetCurrentTime());
 }
 
 void MediaSourcePlayer::ProcessPendingEvents() {
   DVLOG(1) << __FUNCTION__ << " : 0x" << std::hex << pending_event_;
   // Wait for all the decoding jobs to finish before processing pending tasks.
   if (video_decoder_job_ && video_decoder_job_->is_decoding()) {
     DVLOG(1) << __FUNCTION__ << " : A video job is still decoding.";
     return;
   }
 
   if (audio_decoder_job_ && audio_decoder_job_->is_decoding()) {
     DVLOG(1) << __FUNCTION__ << " : An audio job is still decoding.";
     return;
   }
 
   if (has_pending_audio_data_request_ || has_pending_video_data_request_) {
     DVLOG(1) << __FUNCTION__ << " : has pending data request.";
     return;
   }
 
   if (IsEventPending(PREFETCH_DONE_EVENT_PENDING)) {
     DVLOG(1) << __FUNCTION__ << " : PREFETCH_DONE still pending.";
     return;
   }
 
   if (IsEventPending(SEEK_EVENT_PENDING)) {
     DVLOG(1) << __FUNCTION__ << " : Handling SEEK_EVENT";
     ClearDecodingData();
+    if (audio_decoder_job_)
+      audio_decoder_job_->SetBaseTimestamp(GetCurrentTime());
     demuxer_->RequestDemuxerSeek(GetCurrentTime(), doing_browser_seek_);
     return;
   }
 
   start_time_ticks_ = base::TimeTicks();
   if (IsEventPending(CONFIG_CHANGE_EVENT_PENDING)) {
     DVLOG(1) << __FUNCTION__ << " : Handling CONFIG_CHANGE_EVENT.";
     DCHECK(reconfig_audio_decoder_ || reconfig_video_decoder_);
     demuxer_->RequestDemuxerConfigs();
     return;
@@ skipping 51 matching lines @@
   DCHECK_EQ(pending_event_, NO_EVENT_PENDING);
 
   // Now that all pending events have been handled, resume decoding if we are
   // still playing.
   if (playing_)
     StartInternal();
 }
 
 void MediaSourcePlayer::MediaDecoderCallback(
     bool is_audio, MediaCodecStatus status,
-    base::TimeDelta presentation_timestamp, size_t audio_output_bytes) {
+    base::TimeDelta current_presentation_timestamp,
+    base::TimeDelta max_presentation_timestamp) {
   DVLOG(1) << __FUNCTION__ << ": " << is_audio << ", " << status;
 
   // TODO(xhwang): Drop IntToString() when http://crbug.com/303899 is fixed.
   if (is_audio) {
     TRACE_EVENT_ASYNC_END1("media",
                            "MediaSourcePlayer::DecodeMoreAudio",
                            audio_decoder_job_.get(),
                            "MediaCodecStatus",
                            base::IntToString(status));
   } else {
@@ skipping 23 matching lines @@
   DCHECK(!IsEventPending(PREFETCH_DONE_EVENT_PENDING));
 
   // Let |SEEK_EVENT_PENDING| (the highest priority event outside of
   // |PREFETCH_DONE_EVENT_PENDING|) preempt output EOS detection here. Process
   // any other pending events only after handling EOS detection.
   if (IsEventPending(SEEK_EVENT_PENDING)) {
     ProcessPendingEvents();
     return;
   }
 
+  if (status == MEDIA_CODEC_OK && is_clock_manager &&
+      current_presentation_timestamp != kNoTimestamp()) {
+    UpdateTimestamps(
+        current_presentation_timestamp, max_presentation_timestamp);
+  }
+
   if (status == MEDIA_CODEC_OUTPUT_END_OF_STREAM)
     PlaybackCompleted(is_audio);
 
   if (pending_event_ != NO_EVENT_PENDING) {
     ProcessPendingEvents();
     return;
   }
 
   if (status == MEDIA_CODEC_OUTPUT_END_OF_STREAM)
     return;
 
-  if (status == MEDIA_CODEC_OK && is_clock_manager &&
-      presentation_timestamp != kNoTimestamp()) {
-    UpdateTimestamps(presentation_timestamp, audio_output_bytes);
-  }
-
   if (!playing_) {
     if (is_clock_manager)
       clock_.Pause();
     return;
   }
 
   if (status == MEDIA_CODEC_NO_KEY) {
     is_waiting_for_key_ = true;
     return;
   }
 
   // If the status is MEDIA_CODEC_STOPPED, stop decoding new data. The player is
   // in the middle of a seek or stop event and needs to wait for the IPCs to
   // come.
   if (status == MEDIA_CODEC_STOPPED)
     return;
 
   if (is_clock_manager) {
     // If we have a valid timestamp, start the starvation callback. Otherwise,
     // reset the |start_time_ticks_| so that the next frame will not suffer
     // from the decoding delay caused by the current frame.
-    if (presentation_timestamp != kNoTimestamp())
-      StartStarvationCallback(presentation_timestamp);
+    if (current_presentation_timestamp != kNoTimestamp())
+      StartStarvationCallback(current_presentation_timestamp,
+                              max_presentation_timestamp);
     else
       start_time_ticks_ = base::TimeTicks::Now();
   }
 
   if (is_audio) {
     DecodeMoreAudio();
     return;
   }
 
   DecodeMoreVideo();
@@ skipping 127 matching lines @@
   ResetAudioDecoderJob();
   DVLOG(1) << __FUNCTION__ << " : creating new audio decoder job";
   audio_decoder_job_.reset(AudioDecoderJob::Create(
       audio_codec_, sampling_rate_, num_channels_, &audio_extra_data_[0],
       audio_extra_data_.size(), media_crypto.obj(),
       base::Bind(&DemuxerAndroid::RequestDemuxerData,
                  base::Unretained(demuxer_.get()), DemuxerStream::AUDIO)));
 
   if (audio_decoder_job_) {
     SetVolumeInternal();
+    // Need to reset the base timestamp in |audio_decoder_job_|.
+    // TODO(qinmin): When reconfiguring the |audio_decoder_job_|, there might
+    // still be some audio frames in the decoder or in AudioTrack. Therefore,
+    // we are losing some time here. http://crbug.com/357726.
+    base::TimeDelta current_time = GetCurrentTime();
+    audio_decoder_job_->SetBaseTimestamp(current_time);
+    clock_.SetTime(current_time, current_time);
     audio_decoder_job_->BeginPrerolling(preroll_timestamp_);
     reconfig_audio_decoder_ =  false;
   }
 }
 
 void MediaSourcePlayer::ResetVideoDecoderJob() {
   if (video_decoder_job_) {
     has_pending_video_data_request_ =
         video_decoder_job_->is_requesting_demuxer_data();
   }
@@ skipping 81 matching lines @@
       player_id(), duration_, width_, height_, true);
 }
 
 void MediaSourcePlayer::OnDecoderStarved() {
   DVLOG(1) << __FUNCTION__;
   SetPendingEvent(PREFETCH_REQUEST_EVENT_PENDING);
   ProcessPendingEvents();
 }
 
 void MediaSourcePlayer::StartStarvationCallback(
-    base::TimeDelta presentation_timestamp) {
+    base::TimeDelta current_presentation_timestamp,
+    base::TimeDelta max_presentation_timestamp) {
   // 20ms was chosen because it is the typical size of a compressed audio frame.
   // Anything smaller than this would likely cause unnecessary cycling in and
   // out of the prefetch state.
   const base::TimeDelta kMinStarvationTimeout =
       base::TimeDelta::FromMilliseconds(20);
 
   base::TimeDelta current_timestamp = GetCurrentTime();
   base::TimeDelta timeout;
   if (HasAudio()) {
-    timeout = audio_timestamp_helper_->GetTimestamp() - current_timestamp;
+    timeout = max_presentation_timestamp - current_timestamp;
   } else {
-    DCHECK(current_timestamp <= presentation_timestamp);
+    DCHECK(current_timestamp <= current_presentation_timestamp);
 
     // For video only streams, fps can be estimated from the difference
     // between the previous and current presentation timestamps. The
     // previous presentation timestamp is equal to current_timestamp.
     // TODO(qinmin): determine whether 2 is a good coefficient for estimating
     // video frame timeout.
-    timeout = 2 * (presentation_timestamp - current_timestamp);
+    timeout = 2 * (current_presentation_timestamp - current_timestamp);
   }
 
   timeout = std::max(timeout, kMinStarvationTimeout);
 
   decoder_starvation_callback_.Reset(base::Bind(
       &MediaSourcePlayer::OnDecoderStarved, weak_factory_.GetWeakPtr()));
   base::MessageLoop::current()->PostDelayedTask(
       FROM_HERE, decoder_starvation_callback_.callback(), timeout);
 }
 
@@ skipping 74 matching lines @@
 
 void MediaSourcePlayer::ClearPendingEvent(PendingEventFlags event) {
   DVLOG(1) << __FUNCTION__ << "(" << GetEventName(event) << ")";
   DCHECK_NE(event, NO_EVENT_PENDING);
   DCHECK(IsEventPending(event)) << GetEventName(event);
 
   pending_event_ &= ~event;
 }
 
 }  // namespace media