diff options
author | timav <timav@chromium.org> | 2015-10-02 01:26:33 -0700 |
---|---|---|
committer | Commit bot <commit-bot@chromium.org> | 2015-10-02 08:27:24 +0000 |
commit | 1ea2b2ca612e9889a5638b83f355176e7ea2c990 (patch) | |
tree | 7c795f8ed3a9c98f4d20c0bf54ce92ee3d6626c2 | |
parent | 7d78afae216dbb4326bdfbe5c806a3801207ea77 (diff) | |
download | chromium_src-1ea2b2ca612e9889a5638b83f355176e7ea2c990.zip chromium_src-1ea2b2ca612e9889a5638b83f355176e7ea2c990.tar.gz chromium_src-1ea2b2ca612e9889a5638b83f355176e7ea2c990.tar.bz2 |
Added UMA metrics for MediaSourcePlayer and MediaCodecPlayer
Added 4 new histograms:
Media.MSE.LateAudioFrames,
Media.MSE.LateVideoFrames,
Media.MSE.PlaybackDuration,
Media.MSE.Starvations.
Each player holds MediaStatistics object which gathers events
during playback and calculates and reports results after the
playback is stopped.
BUG=407577
Review URL: https://codereview.chromium.org/1367403003
Cr-Commit-Position: refs/heads/master@{#351975}
22 files changed, 437 insertions, 46 deletions
diff --git a/media/base/android/BUILD.gn b/media/base/android/BUILD.gn index 84405c8..78108a6 100644 --- a/media/base/android/BUILD.gn +++ b/media/base/android/BUILD.gn @@ -52,6 +52,8 @@ source_set("android") { "media_resource_getter.h", "media_source_player.cc", "media_source_player.h", + "media_statistics.cc", + "media_statistics.h", "media_task_runner.cc", "media_task_runner.h", "media_url_interceptor.h", diff --git a/media/base/android/audio_decoder_job.cc b/media/base/android/audio_decoder_job.cc index 07b8288..e532103 100644 --- a/media/base/android/audio_decoder_job.cc +++ b/media/base/android/audio_decoder_job.cc @@ -8,6 +8,7 @@ #include "base/lazy_instance.h" #include "base/threading/thread.h" #include "media/base/android/media_codec_bridge.h" +#include "media/base/android/media_statistics.h" #include "media/base/audio_timestamp_helper.h" #include "media/base/timestamp_constants.h" @@ -35,10 +36,12 @@ base::LazyInstance<AudioDecoderThread>::Leaky AudioDecoderJob::AudioDecoderJob( const base::Closure& request_data_cb, - const base::Closure& on_demuxer_config_changed_cb) + const base::Closure& on_demuxer_config_changed_cb, + FrameStatistics* frame_statistics) : MediaDecoderJob(g_audio_decoder_thread.Pointer()->task_runner(), request_data_cb, - on_demuxer_config_changed_cb), + on_demuxer_config_changed_cb, + frame_statistics), audio_codec_(kUnknownAudioCodec), num_channels_(0), config_sampling_rate_(0), @@ -106,14 +109,29 @@ void AudioDecoderJob::ReleaseOutputBuffer( int64 head_position = (static_cast<AudioCodecBridge*>( media_codec_bridge_.get()))->PlayOutputBuffer( output_buffer_index, size, offset); + + base::TimeTicks current_time = base::TimeTicks::Now(); + size_t new_frames_count = size / bytes_per_frame_; frame_count_ += new_frames_count; audio_timestamp_helper_->AddFrames(new_frames_count); int64 frames_to_play = frame_count_ - head_position; DCHECK_GE(frames_to_play, 0); + + const base::TimeDelta last_buffered = + audio_timestamp_helper_->GetTimestamp(); + current_presentation_timestamp = - audio_timestamp_helper_->GetTimestamp() - + last_buffered - audio_timestamp_helper_->GetFrameDuration(frames_to_play); + + if (!next_frame_time_limit_.is_null() && + next_frame_time_limit_ < current_time) { + frame_statistics_->IncrementLateFrameCount(); + } + + next_frame_time_limit_ = + current_time + (last_buffered - current_presentation_timestamp); } else { current_presentation_timestamp = kNoTimestamp(); } diff --git a/media/base/android/audio_decoder_job.h b/media/base/android/audio_decoder_job.h index 0a9849f..baee4a3 100644 --- a/media/base/android/audio_decoder_job.h +++ b/media/base/android/audio_decoder_job.h @@ -24,7 +24,8 @@ class AudioDecoderJob : public MediaDecoderJob { // |on_demuxer_config_changed_cb| - Callback used to inform the caller that // demuxer config has changed. AudioDecoderJob(const base::Closure& request_data_cb, - const base::Closure& on_demuxer_config_changed_cb); + const base::Closure& on_demuxer_config_changed_cb, + FrameStatistics* frame_statistics); ~AudioDecoderJob() override; // MediaDecoderJob implementation. @@ -79,6 +80,9 @@ class AudioDecoderJob : public MediaDecoderJob { // Object to calculate the current audio timestamp for A/V sync. scoped_ptr<AudioTimestampHelper> audio_timestamp_helper_; + // The time limit for the next frame to avoid underrun. + base::TimeTicks next_frame_time_limit_; + DISALLOW_COPY_AND_ASSIGN(AudioDecoderJob); }; diff --git a/media/base/android/media_codec_audio_decoder.cc b/media/base/android/media_codec_audio_decoder.cc index 503fb39..4b8a076 100644 --- a/media/base/android/media_codec_audio_decoder.cc +++ b/media/base/android/media_codec_audio_decoder.cc @@ -7,6 +7,7 @@ #include "base/bind.h" #include "base/logging.h" #include "media/base/android/media_codec_bridge.h" +#include "media/base/android/media_statistics.h" #include "media/base/audio_timestamp_helper.h" #include "media/base/demuxer_stream.h" @@ -21,6 +22,7 @@ namespace media { MediaCodecAudioDecoder::MediaCodecAudioDecoder( const scoped_refptr<base::SingleThreadTaskRunner>& media_task_runner, + FrameStatistics* frame_statistics, const base::Closure& request_data_cb, const base::Closure& starvation_cb, const base::Closure& decoder_drained_cb, @@ -28,14 +30,15 @@ MediaCodecAudioDecoder::MediaCodecAudioDecoder( const base::Closure& waiting_for_decryption_key_cb, const base::Closure& error_cb, const SetTimeCallback& update_current_time_cb) - : MediaCodecDecoder(media_task_runner, + : MediaCodecDecoder("AudioDecoder", + media_task_runner, + frame_statistics, request_data_cb, starvation_cb, decoder_drained_cb, stop_done_cb, waiting_for_decryption_key_cb, - error_cb, - "AudioDecoder"), + error_cb), volume_(-1.0), bytes_per_frame_(0), output_sampling_rate_(0), @@ -207,6 +210,10 @@ void MediaCodecAudioDecoder::Render(int buffer_index, int64 head_position = audio_codec->PlayOutputBuffer(buffer_index, size, offset, postpone); + base::TimeTicks current_time = base::TimeTicks::Now(); + + frame_statistics_->IncrementFrameCount(); + // Reset the base timestamp if we have not started playing. // SetBaseTimestamp() must be called before AddFrames() since it resets the // internal frame count. @@ -240,6 +247,16 @@ void MediaCodecAudioDecoder::Render(int buffer_index, DVLOG(2) << class_name() << "::" << __FUNCTION__ << " pts:" << pts << " will play: [" << now_playing << "," << last_buffered << "]"; + // Statistics + if (!next_frame_time_limit_.is_null() && + next_frame_time_limit_ < current_time) { + DVLOG(2) << class_name() << "::" << __FUNCTION__ << " LATE FRAME delay:" + << current_time - next_frame_time_limit_; + frame_statistics_->IncrementLateFrameCount(); + } + + next_frame_time_limit_ = current_time + (last_buffered - now_playing); + media_task_runner_->PostTask( FROM_HERE, base::Bind(update_current_time_cb_, now_playing, last_buffered, false)); diff --git a/media/base/android/media_codec_audio_decoder.h b/media/base/android/media_codec_audio_decoder.h index 03df46b..3143d56 100644 --- a/media/base/android/media_codec_audio_decoder.h +++ b/media/base/android/media_codec_audio_decoder.h @@ -19,6 +19,7 @@ class MediaCodecAudioDecoder : public MediaCodecDecoder { // Called for each rendered frame. MediaCodecAudioDecoder( const scoped_refptr<base::SingleThreadTaskRunner>& media_runner, + FrameStatistics* frame_statistics, const base::Closure& request_data_cb, const base::Closure& starvation_cb, const base::Closure& decoder_drained_cb, @@ -87,6 +88,9 @@ class MediaCodecAudioDecoder : public MediaCodecDecoder { // Reports current playback time to the callee. SetTimeCallback update_current_time_cb_; + // The time limit for the next frame to avoid underrun. + base::TimeTicks next_frame_time_limit_; + DISALLOW_COPY_AND_ASSIGN(MediaCodecAudioDecoder); }; diff --git a/media/base/android/media_codec_decoder.cc b/media/base/android/media_codec_decoder.cc index 808aa76..c7b9e2a 100644 --- a/media/base/android/media_codec_decoder.cc +++ b/media/base/android/media_codec_decoder.cc @@ -32,16 +32,18 @@ const int kOutputBufferTimeout = 20; } MediaCodecDecoder::MediaCodecDecoder( + const char* decoder_thread_name, const scoped_refptr<base::SingleThreadTaskRunner>& media_task_runner, + FrameStatistics* frame_statistics, const base::Closure& external_request_data_cb, const base::Closure& starvation_cb, const base::Closure& decoder_drained_cb, const base::Closure& stop_done_cb, const base::Closure& waiting_for_decryption_key_cb, - const base::Closure& error_cb, - const char* decoder_thread_name) - : media_task_runner_(media_task_runner), - decoder_thread_(decoder_thread_name), + const base::Closure& error_cb) + : decoder_thread_(decoder_thread_name), + media_task_runner_(media_task_runner), + frame_statistics_(frame_statistics), needs_reconfigure_(false), drain_decoder_(false), always_reconfigure_for_tests_(false), diff --git a/media/base/android/media_codec_decoder.h b/media/base/android/media_codec_decoder.h index 0a3033e..8385d60 100644 --- a/media/base/android/media_codec_decoder.h +++ b/media/base/android/media_codec_decoder.h @@ -19,6 +19,7 @@ namespace media { +struct FrameStatistics; class MediaCodecBridge; // The decoder for MediaCodecPlayer. @@ -137,10 +138,15 @@ class MediaCodecDecoder { // MediaCodecDecoder constructor. // Parameters: + // decoder_thread_name: + // The thread name to be passed to decoder thread constructor. // media_task_runner: // A task runner for the controlling thread. All public methods should be // called on this thread, and callbacks are delivered on this thread. // The MediaCodecPlayer uses a dedicated (Media) thread for this. + // frame_statistics: + // A pointer to FrameStatistics object which gathers playback quality + // related data. // external_request_data_cb: // Called periodically as the amount of internally stored data decreases. // The receiver should call OnDemuxerDataAvailable() with more data. @@ -157,17 +163,17 @@ class MediaCodecDecoder { // error_cb: // Called when a MediaCodec error occurred. If this happens, a player has // to either call ReleaseDecoderResources() or destroy the decoder object. - // decoder_thread_name: - // The thread name to be passed to decoder thread constructor. MediaCodecDecoder( + const char* decoder_thread_name, const scoped_refptr<base::SingleThreadTaskRunner>& media_task_runner, + FrameStatistics* frame_statistics, const base::Closure& external_request_data_cb, const base::Closure& starvation_cb, const base::Closure& decoder_drained_cb, const base::Closure& stop_done_cb, const base::Closure& waiting_for_decryption_key_cb, - const base::Closure& error_cb, - const char* decoder_thread_name); + const base::Closure& error_cb); + virtual ~MediaCodecDecoder(); virtual const char* class_name() const; @@ -310,16 +316,18 @@ class MediaCodecDecoder { // Protected data. + // We call MediaCodecBridge on this thread for both input and output buffers. + base::Thread decoder_thread_; + // Object for posting tasks on Media thread. scoped_refptr<base::SingleThreadTaskRunner> media_task_runner_; + // Statistics for UMA. + FrameStatistics* frame_statistics_; + // Controls Android MediaCodec scoped_ptr<MediaCodecBridge> media_codec_bridge_; - // We call MediaCodecBridge on this thread for both - // input and output buffers. - base::Thread decoder_thread_; - // The queue of access units. AccessUnitQueue au_queue_; diff --git a/media/base/android/media_codec_decoder_unittest.cc b/media/base/android/media_codec_decoder_unittest.cc index 29d7012..a667125 100644 --- a/media/base/android/media_codec_decoder_unittest.cc +++ b/media/base/android/media_codec_decoder_unittest.cc @@ -9,6 +9,7 @@ #include "media/base/android/media_codec_audio_decoder.h" #include "media/base/android/media_codec_bridge.h" #include "media/base/android/media_codec_video_decoder.h" +#include "media/base/android/media_statistics.h" #include "media/base/android/test_data_factory.h" #include "media/base/android/test_statistics.h" #include "media/base/timestamp_constants.h" @@ -227,6 +228,7 @@ class MediaCodecDecoderTest : public testing::Test { base::TimeDelta stop_request_time_; scoped_refptr<base::SingleThreadTaskRunner> task_runner_; + FrameStatistics frame_statistics_; DataAvailableCallback data_available_cb_; scoped_refptr<gfx::SurfaceTexture> surface_texture_; @@ -270,8 +272,9 @@ bool MediaCodecDecoderTest::WaitForCondition(const Predicate& condition, void MediaCodecDecoderTest::CreateAudioDecoder() { decoder_ = scoped_ptr<MediaCodecDecoder>(new MediaCodecAudioDecoder( - task_runner_, base::Bind(&MediaCodecDecoderTest::OnDataRequested, - base::Unretained(this)), + task_runner_, &frame_statistics_, + base::Bind(&MediaCodecDecoderTest::OnDataRequested, + base::Unretained(this)), base::Bind(&MediaCodecDecoderTest::OnStarvation, base::Unretained(this)), base::Bind(&MediaCodecDecoderTest::OnDecoderDrained, base::Unretained(this)), @@ -287,8 +290,9 @@ void MediaCodecDecoderTest::CreateAudioDecoder() { void MediaCodecDecoderTest::CreateVideoDecoder() { decoder_ = scoped_ptr<MediaCodecDecoder>(new MediaCodecVideoDecoder( - task_runner_, base::Bind(&MediaCodecDecoderTest::OnDataRequested, - base::Unretained(this)), + task_runner_, &frame_statistics_, + base::Bind(&MediaCodecDecoderTest::OnDataRequested, + base::Unretained(this)), base::Bind(&MediaCodecDecoderTest::OnStarvation, base::Unretained(this)), base::Bind(&MediaCodecDecoderTest::OnDecoderDrained, base::Unretained(this)), diff --git a/media/base/android/media_codec_player.cc b/media/base/android/media_codec_player.cc index da001e1..2fc8c18 100644 --- a/media/base/android/media_codec_player.cc +++ b/media/base/android/media_codec_player.cc @@ -99,6 +99,8 @@ MediaCodecPlayer::~MediaCodecPlayer() if (audio_decoder_) audio_decoder_->ReleaseDecoderResources(); + media_stat_->StopAndReport(GetInterpolatedTime()); + if (drm_bridge_) { DCHECK(cdm_registration_id_); drm_bridge_->UnregisterPlayer(cdm_registration_id_); @@ -807,6 +809,8 @@ void MediaCodecPlayer::OnStopDone(DemuxerStream::Type type) { return; } + media_stat_->StopAndReport(GetInterpolatedTime()); + // DetachListener to UI thread ui_task_runner_->PostTask(FROM_HERE, detach_listener_cb_); @@ -851,6 +855,8 @@ void MediaCodecPlayer::OnStarvation(DemuxerStream::Type type) { SetState(kStateStopping); RequestToStopDecoders(); SetPendingStart(true); + + media_stat_->AddStarvation(); } void MediaCodecPlayer::OnTimeIntervalUpdate(DemuxerStream::Type type, @@ -1246,6 +1252,10 @@ MediaCodecPlayer::StartStatus MediaCodecPlayer::StartDecoders() { DVLOG(1) << __FUNCTION__ << " current_time:" << current_time; + // At this point decoder threads are either not running at all or their + // message pumps are in the idle state after the preroll is done. + media_stat_->Start(current_time); + if (!AudioFinished()) { if (!audio_decoder_->Start(current_time)) return kStartFailed; @@ -1268,6 +1278,8 @@ void MediaCodecPlayer::StopDecoders() { video_decoder_->SyncStop(); audio_decoder_->SyncStop(); + + media_stat_->StopAndReport(GetInterpolatedTime()); } void MediaCodecPlayer::RequestToStopDecoders() { @@ -1325,6 +1337,8 @@ void MediaCodecPlayer::ReleaseDecoderResources() { // At this point decoder threads should not be running if (interpolator_.interpolating()) interpolator_.StopInterpolating(); + + media_stat_->StopAndReport(GetInterpolatedTime()); } void MediaCodecPlayer::CreateDecoders() { @@ -1333,9 +1347,12 @@ void MediaCodecPlayer::CreateDecoders() { internal_error_cb_ = base::Bind(&MediaCodecPlayer::OnError, media_weak_this_); + media_stat_.reset(new MediaStatistics()); + audio_decoder_.reset(new MediaCodecAudioDecoder( - GetMediaTaskRunner(), base::Bind(&MediaCodecPlayer::RequestDemuxerData, - media_weak_this_, DemuxerStream::AUDIO), + GetMediaTaskRunner(), &media_stat_->audio_frame_stats(), + base::Bind(&MediaCodecPlayer::RequestDemuxerData, media_weak_this_, + DemuxerStream::AUDIO), base::Bind(&MediaCodecPlayer::OnStarvation, media_weak_this_, DemuxerStream::AUDIO), base::Bind(&MediaCodecPlayer::OnDecoderDrained, media_weak_this_, @@ -1349,8 +1366,9 @@ void MediaCodecPlayer::CreateDecoders() { DemuxerStream::AUDIO))); video_decoder_.reset(new MediaCodecVideoDecoder( - GetMediaTaskRunner(), base::Bind(&MediaCodecPlayer::RequestDemuxerData, - media_weak_this_, DemuxerStream::VIDEO), + GetMediaTaskRunner(), &media_stat_->video_frame_stats(), + base::Bind(&MediaCodecPlayer::RequestDemuxerData, media_weak_this_, + DemuxerStream::VIDEO), base::Bind(&MediaCodecPlayer::OnStarvation, media_weak_this_, DemuxerStream::VIDEO), base::Bind(&MediaCodecPlayer::OnDecoderDrained, media_weak_this_, diff --git a/media/base/android/media_codec_player.h b/media/base/android/media_codec_player.h index 3029992..5662055 100644 --- a/media/base/android/media_codec_player.h +++ b/media/base/android/media_codec_player.h @@ -13,6 +13,7 @@ #include "media/base/android/demuxer_android.h" #include "media/base/android/media_drm_bridge.h" #include "media/base/android/media_player_android.h" +#include "media/base/android/media_statistics.h" #include "media/base/demuxer_stream.h" #include "media/base/media_export.h" #include "media/base/time_delta_interpolator.h" @@ -409,6 +410,10 @@ class MEDIA_EXPORT MediaCodecPlayer : public MediaPlayerAndroid, // on starting the playback. bool key_is_added_; + // Gathers and reports playback quality statistics to UMA. + // Use pointer to enable replacement of this object for tests. + scoped_ptr<MediaStatistics> media_stat_; + base::WeakPtr<MediaCodecPlayer> media_weak_this_; // NOTE: Weak pointers must be invalidated before all other member variables. base::WeakPtrFactory<MediaCodecPlayer> media_weak_factory_; diff --git a/media/base/android/media_codec_video_decoder.cc b/media/base/android/media_codec_video_decoder.cc index 08db2a5..930142d 100644 --- a/media/base/android/media_codec_video_decoder.cc +++ b/media/base/android/media_codec_video_decoder.cc @@ -7,6 +7,7 @@ #include "base/bind.h" #include "base/logging.h" #include "media/base/android/media_codec_bridge.h" +#include "media/base/android/media_statistics.h" #include "media/base/demuxer_stream.h" #include "media/base/timestamp_constants.h" @@ -18,6 +19,7 @@ const int kDelayForStandAloneEOS = 2; // milliseconds MediaCodecVideoDecoder::MediaCodecVideoDecoder( const scoped_refptr<base::SingleThreadTaskRunner>& media_task_runner, + FrameStatistics* frame_statistics, const base::Closure& request_data_cb, const base::Closure& starvation_cb, const base::Closure& decoder_drained_cb, @@ -27,14 +29,15 @@ MediaCodecVideoDecoder::MediaCodecVideoDecoder( const SetTimeCallback& update_current_time_cb, const VideoSizeChangedCallback& video_size_changed_cb, const base::Closure& codec_created_cb) - : MediaCodecDecoder(media_task_runner, + : MediaCodecDecoder("VideoDecoder", + media_task_runner, + frame_statistics, request_data_cb, starvation_cb, decoder_drained_cb, stop_done_cb, waiting_for_decryption_key_cb, - error_cb, - "VideoDecoder"), + error_cb), is_protected_surface_required_(false), update_current_time_cb_(update_current_time_cb), video_size_changed_cb_(video_size_changed_cb), @@ -276,7 +279,19 @@ void MediaCodecVideoDecoder::Render(int buffer_index, << " ticks delta:" << (base::TimeTicks::Now() - start_time_ticks_) << " time_to_render:" << time_to_render; + const bool render = (size > 0); + + if (render) + frame_statistics_->IncrementFrameCount(); + if (time_to_render < base::TimeDelta()) { + if (render) { + DVLOG(2) << class_name() << "::" << __FUNCTION__ + << " LATE FRAME delay:" << (-1) * time_to_render; + + frame_statistics_->IncrementLateFrameCount(); + } + // Skip late frames ReleaseOutputBuffer(buffer_index, pts, false, update_time, eos_encountered); return; @@ -284,7 +299,6 @@ void MediaCodecVideoDecoder::Render(int buffer_index, delayed_buffers_.insert(buffer_index); - const bool render = (size > 0); decoder_thread_.task_runner()->PostDelayedTask( FROM_HERE, base::Bind(&MediaCodecVideoDecoder::ReleaseOutputBuffer, base::Unretained(this), buffer_index, pts, render, diff --git a/media/base/android/media_codec_video_decoder.h b/media/base/android/media_codec_video_decoder.h index 557bccd..d247271 100644 --- a/media/base/android/media_codec_video_decoder.h +++ b/media/base/android/media_codec_video_decoder.h @@ -28,6 +28,7 @@ class MediaCodecVideoDecoder : public MediaCodecDecoder { // decoder can use them. MediaCodecVideoDecoder( const scoped_refptr<base::SingleThreadTaskRunner>& media_runner, + FrameStatistics* frame_statistics, const base::Closure& request_data_cb, const base::Closure& starvation_cb, const base::Closure& drained_requested_cb, diff --git a/media/base/android/media_decoder_job.cc b/media/base/android/media_decoder_job.cc index 6a96ccb..855a813 100644 --- a/media/base/android/media_decoder_job.cc +++ b/media/base/android/media_decoder_job.cc @@ -10,6 +10,7 @@ #include "base/thread_task_runner_handle.h" #include "base/trace_event/trace_event.h" #include "media/base/android/media_drm_bridge.h" +#include "media/base/android/media_statistics.h" #include "media/base/bind_to_current_loop.h" #include "media/base/timestamp_constants.h" @@ -23,8 +24,10 @@ static const int kMediaCodecTimeoutInMilliseconds = 250; MediaDecoderJob::MediaDecoderJob( const scoped_refptr<base::SingleThreadTaskRunner>& decoder_task_runner, const base::Closure& request_data_cb, - const base::Closure& config_changed_cb) + const base::Closure& config_changed_cb, + FrameStatistics* frame_statistics) : need_to_reconfig_decoder_job_(false), + frame_statistics_(frame_statistics), ui_task_runner_(base::ThreadTaskRunnerHandle::Get()), decoder_task_runner_(decoder_task_runner), needs_flush_(false), @@ -485,9 +488,19 @@ void MediaDecoderJob::DecodeInternal( (status != MEDIA_CODEC_OUTPUT_END_OF_STREAM || size != 0u); base::TimeDelta time_to_render; DCHECK(!start_time_ticks.is_null()); - if (render_output && ComputeTimeToRender()) { - time_to_render = presentation_timestamp - (base::TimeTicks::Now() - - start_time_ticks + start_presentation_timestamp); + if (render_output) { + frame_statistics_->IncrementFrameCount(); + + if (ComputeTimeToRender()) { + time_to_render = + presentation_timestamp - (base::TimeTicks::Now() - start_time_ticks + + start_presentation_timestamp); + + // ComputeTimeToRender() returns true for video streams only, this is a + // video stream. + if (time_to_render < base::TimeDelta()) + frame_statistics_->IncrementLateFrameCount(); + } } if (time_to_render > base::TimeDelta()) { diff --git a/media/base/android/media_decoder_job.h b/media/base/android/media_decoder_job.h index 2503a42..df7f454 100644 --- a/media/base/android/media_decoder_job.h +++ b/media/base/android/media_decoder_job.h @@ -18,6 +18,7 @@ class SingleThreadTaskRunner; namespace media { +struct FrameStatistics; class MediaDrmBridge; // Class for managing all the decoding tasks. Each decoding task will be posted @@ -117,7 +118,8 @@ class MediaDecoderJob { MediaDecoderJob( const scoped_refptr<base::SingleThreadTaskRunner>& decoder_task_runner, const base::Closure& request_data_cb, - const base::Closure& config_changed_cb); + const base::Closure& config_changed_cb, + FrameStatistics* frame_statistics); // Release the output buffer at index |output_buffer_index| and render it if // |render_output| is true. Upon completion, |callback| will be called. @@ -154,6 +156,8 @@ class MediaDecoderJob { scoped_ptr<MediaCodecBridge> media_codec_bridge_; + FrameStatistics* frame_statistics_; + private: friend class MediaSourcePlayerTest; diff --git a/media/base/android/media_source_player.cc b/media/base/android/media_source_player.cc index 7fbd9c0..92f08cb 100644 --- a/media/base/android/media_source_player.cc +++ b/media/base/android/media_source_player.cc @@ -47,19 +47,24 @@ MediaSourcePlayer::MediaSourcePlayer( is_waiting_for_video_decoder_(false), prerolling_(true), weak_factory_(this) { + media_stat_.reset(new MediaStatistics()); + audio_decoder_job_.reset(new AudioDecoderJob( base::Bind(&DemuxerAndroid::RequestDemuxerData, base::Unretained(demuxer_.get()), DemuxerStream::AUDIO), base::Bind(&MediaSourcePlayer::OnDemuxerConfigsChanged, - weak_factory_.GetWeakPtr()))); + weak_factory_.GetWeakPtr()), + &media_stat_->audio_frame_stats())); video_decoder_job_.reset(new VideoDecoderJob( base::Bind(&DemuxerAndroid::RequestDemuxerData, base::Unretained(demuxer_.get()), DemuxerStream::VIDEO), base::Bind(request_media_resources_cb_, player_id), base::Bind(&MediaSourcePlayer::OnDemuxerConfigsChanged, - weak_factory_.GetWeakPtr()))); + weak_factory_.GetWeakPtr()), + &media_stat_->video_frame_stats())); + demuxer_->Initialize(this); interpolator_.SetUpperBound(base::TimeDelta()); weak_this_ = weak_factory_.GetWeakPtr(); @@ -467,6 +472,7 @@ void MediaSourcePlayer::MediaDecoderCallback( DVLOG(1) << __FUNCTION__ << " : decode error"; Release(); manager()->OnError(player_id(), MEDIA_ERROR_DECODE); + media_stat_->StopAndReport(GetCurrentTime()); return; } @@ -477,6 +483,7 @@ void MediaSourcePlayer::MediaDecoderCallback( // any other pending events only after handling EOS detection. if (IsEventPending(SEEK_EVENT_PENDING)) { ProcessPendingEvents(); + media_stat_->StopAndReport(GetCurrentTime()); return; } @@ -497,13 +504,16 @@ void MediaSourcePlayer::MediaDecoderCallback( return; } - if (status == MEDIA_CODEC_OUTPUT_END_OF_STREAM) + if (status == MEDIA_CODEC_OUTPUT_END_OF_STREAM) { + media_stat_->StopAndReport(GetCurrentTime()); return; + } if (!playing_) { if (is_clock_manager) interpolator_.StopInterpolating(); + media_stat_->StopAndReport(GetCurrentTime()); return; } @@ -514,6 +524,7 @@ void MediaSourcePlayer::MediaDecoderCallback( } else { is_waiting_for_key_ = true; manager()->OnWaitingForDecryptionKey(player_id()); + media_stat_->StopAndReport(GetCurrentTime()); } return; } @@ -531,8 +542,10 @@ void MediaSourcePlayer::MediaDecoderCallback( // If the status is MEDIA_CODEC_ABORT, 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_ABORT) + if (status == MEDIA_CODEC_ABORT) { + media_stat_->StopAndReport(GetCurrentTime()); return; + } if (prerolling_ && IsPrerollFinished(is_audio)) { if (IsPrerollFinished(!is_audio)) { @@ -654,6 +667,8 @@ bool MediaSourcePlayer::VideoFinished() { void MediaSourcePlayer::OnDecoderStarved() { DVLOG(1) << __FUNCTION__; + media_stat_->AddStarvation(); + SetPendingEvent(PREFETCH_REQUEST_EVENT_PENDING); ProcessPendingEvents(); } @@ -720,6 +735,8 @@ void MediaSourcePlayer::OnPrefetchDone() { if (!interpolator_.interpolating()) interpolator_.StartInterpolating(); + media_stat_->Start(start_presentation_timestamp_); + if (!AudioFinished()) DecodeMoreAudio(); diff --git a/media/base/android/media_source_player.h b/media/base/android/media_source_player.h index bfa3935..d7b6715 100644 --- a/media/base/android/media_source_player.h +++ b/media/base/android/media_source_player.h @@ -23,6 +23,7 @@ #include "media/base/android/media_decoder_job.h" #include "media/base/android/media_drm_bridge.h" #include "media/base/android/media_player_android.h" +#include "media/base/android/media_statistics.h" #include "media/base/media_export.h" #include "media/base/time_delta_interpolator.h" @@ -268,6 +269,10 @@ class MEDIA_EXPORT MediaSourcePlayer : public MediaPlayerAndroid, // Whether audio or video decoder is in the process of prerolling. bool prerolling_; + // Gathers and reports playback quality statistics to UMA. + // Use pointer to enable replacement of this object for tests. + scoped_ptr<MediaStatistics> media_stat_; + // Weak pointer passed to media decoder jobs for callbacks. base::WeakPtr<MediaSourcePlayer> weak_this_; // NOTE: Weak pointers must be invalidated before all other member variables. diff --git a/media/base/android/media_statistics.cc b/media/base/android/media_statistics.cc new file mode 100644 index 0000000..19c0298 --- /dev/null +++ b/media/base/android/media_statistics.cc @@ -0,0 +1,119 @@ +// Copyright 2015 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_statistics.h" + +#include "base/logging.h" +#include "base/metrics/histogram_macros.h" +#include "media/base/android/demuxer_stream_player_params.h" + +namespace media { + +// Minimum playback interval to report. +const int kMinDurationInSeconds = 2; + +// Maximum playback interval to report. +const int kMaxDurationInSeconds = 3600; + +// Number of slots in the histogram for playback interval. +const int kNumDurationSlots = 50; + +// For easier reading. +const int kOneMillion = 1000000; + +void FrameStatistics::IncrementLateFrameCount() { + // Do not collect the late frame if this is the first frame after the start. + // Right now we do not want to consider the late video frame which is the + // first after preroll, preroll may be inacurate in this respect. + // The first audio frame cannot be late by definition and by not considering + // it we can simplify audio decoder code. + if (total == 1) + return; + + ++late; +} + +MediaStatistics::MediaStatistics() {} + +MediaStatistics::~MediaStatistics() {} + +void MediaStatistics::Start(base::TimeDelta current_playback_time) { + DVLOG(1) << __FUNCTION__; + + if (start_time_ == kNoTimestamp()) { + Clear(); + start_time_ = current_playback_time; + } +} + +void MediaStatistics::StopAndReport(base::TimeDelta current_playback_time) { + DVLOG(1) << __FUNCTION__; + + if (start_time_ == kNoTimestamp()) + return; // skip if there was no prior Start(). + + base::TimeDelta duration = current_playback_time - start_time_; + + // Reset start time. + start_time_ = kNoTimestamp(); + + if (duration < base::TimeDelta::FromSeconds(kMinDurationInSeconds)) + return; // duration is too short. + + if (duration > base::TimeDelta::FromSeconds(kMaxDurationInSeconds)) + return; // duration is too long. + + Report(duration); +} + +void MediaStatistics::Clear() { + start_time_ = kNoTimestamp(); + audio_frame_stats_.Clear(); + video_frame_stats_.Clear(); + num_starvations_ = 0; +} + +void MediaStatistics::Report(base::TimeDelta duration) { + DVLOG(1) << __FUNCTION__ << " duration:" << duration + << " audio frames:" + << audio_frame_stats_.late << "/" << audio_frame_stats_.total + << " video frames:" + << video_frame_stats_.late << "/" << video_frame_stats_.total + << " starvations:" << num_starvations_; + + // Playback duration is the time interval between the moment playback starts + // and the moment it is interrupted either by stopping or by seeking, changing + // to full screen, minimizing the browser etc. The interval is measured by + // media time. + + UMA_HISTOGRAM_CUSTOM_TIMES( + "Media.MSE.PlaybackDuration", duration, + base::TimeDelta::FromSeconds(kMinDurationInSeconds), + base::TimeDelta::FromSeconds(kMaxDurationInSeconds), kNumDurationSlots); + + // Number of late frames per one million frames. + + if (audio_frame_stats_.total) { + UMA_HISTOGRAM_COUNTS( + "Media.MSE.LateAudioFrames", + kOneMillion * audio_frame_stats_.late / audio_frame_stats_.total); + } + + if (video_frame_stats_.total) { + UMA_HISTOGRAM_COUNTS( + "Media.MSE.LateVideoFrames", + kOneMillion * video_frame_stats_.late / video_frame_stats_.total); + } + + // Number of starvations per one million frames. + + uint32_t total_frames = audio_frame_stats_.total ? audio_frame_stats_.total + : video_frame_stats_.total; + if (total_frames) { + UMA_HISTOGRAM_COUNTS("Media.MSE.Starvations", + kOneMillion * num_starvations_ / total_frames); + } +} + +} // namespace media diff --git a/media/base/android/media_statistics.h b/media/base/android/media_statistics.h new file mode 100644 index 0000000..5b6daab --- /dev/null +++ b/media/base/android/media_statistics.h @@ -0,0 +1,88 @@ +// Copyright 2015 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. + +#ifndef MEDIA_BASE_ANDROID_MEDIA_STATISTICS_H_ +#define MEDIA_BASE_ANDROID_MEDIA_STATISTICS_H_ + +#include <stdint.h> +#include "base/time/time.h" +#include "media/base/demuxer_stream.h" +#include "media/base/timestamp_constants.h" + +namespace media { + +// FrameStatistics struct deals with frames of one stream, i.e. either +// audio or video. +struct FrameStatistics { + // Audio: total number of frames that have been rendered. + // Video: total number of frames that were supposed to be rendered. Late video + // frames might be skipped, but are counted here. + uint32_t total = 0; + + // A number of late frames. Late frames are a subset of the total frames. + // Audio: The frame is late if it might cause an underrun, i.e. comes from + // decoder when audio buffer is already depleted. + // Video: The frame is late if it missed its presentation time as determined + // by PTS when it comes from decoder. The rendering policy (i.e. + // render or skip) does not affect this number. + uint32_t late = 0; + + void Clear() { total = late = 0; } + + // Increments |total| frame count. + void IncrementFrameCount() { ++total; } + + // Increments |late| frame count except it is the first frame after start. + // For each IncrementLateFrameCount() call there should be preceding + // IncrementFrameCount() call. + void IncrementLateFrameCount(); +}; + +// MediaStatistics class gathers and reports playback quality statistics to UMA. +// +// This class is not thread safe. The caller should guarantee that operations +// on FrameStatistics objects does not happen during Start() and +// StopAndReport(). The Start() and StopAndReport() methods need to be called +// sequentially. + +class MediaStatistics { + public: + MediaStatistics(); + ~MediaStatistics(); + + // Returns the frame statistics for audio frames. + FrameStatistics& audio_frame_stats() { return audio_frame_stats_; } + + // Returns the frame statistics for video frames. + FrameStatistics& video_frame_stats() { return video_frame_stats_; } + + // Starts gathering statistics. When called in a row only the firts call will + // take effect. + void Start(base::TimeDelta current_playback_time); + + // Stops gathering statistics, calculate and report results. When called + // in a row only the firts call will take effect. + void StopAndReport(base::TimeDelta current_playback_time); + + // Adds starvation event. Starvation happens when the player interrupts + // the regular playback and asks for more data. + void AddStarvation() { ++num_starvations_; } + + private: + // Resets the data to the initial state. + void Clear(); + + // Calculates relative data based on total frame numbers and reports it and + // the duration to UMA. + void Report(base::TimeDelta duration); + + base::TimeDelta start_time_ = kNoTimestamp(); + FrameStatistics audio_frame_stats_; + FrameStatistics video_frame_stats_; + uint32_t num_starvations_ = 0; +}; + +} // namespace media + +#endif // MEDIA_BASE_ANDROID_MEDIA_STATISTICS_H_ diff --git a/media/base/android/video_decoder_job.cc b/media/base/android/video_decoder_job.cc index 2a29d015..ebb64e1 100644 --- a/media/base/android/video_decoder_job.cc +++ b/media/base/android/video_decoder_job.cc @@ -28,10 +28,12 @@ base::LazyInstance<VideoDecoderThread>::Leaky VideoDecoderJob::VideoDecoderJob( const base::Closure& request_data_cb, const base::Closure& request_resources_cb, - const base::Closure& on_demuxer_config_changed_cb) + const base::Closure& on_demuxer_config_changed_cb, + FrameStatistics* frame_statistics) : MediaDecoderJob(g_video_decoder_thread.Pointer()->task_runner(), request_data_cb, - on_demuxer_config_changed_cb), + on_demuxer_config_changed_cb, + frame_statistics), video_codec_(kUnknownVideoCodec), config_width_(0), config_height_(0), diff --git a/media/base/android/video_decoder_job.h b/media/base/android/video_decoder_job.h index 00a8e6f..7700ee4 100644 --- a/media/base/android/video_decoder_job.h +++ b/media/base/android/video_decoder_job.h @@ -21,10 +21,10 @@ class VideoDecoderJob : public MediaDecoderJob { // |request_resources_cb| - Callback used to request resources. // |on_demuxer_config_changed_cb| - Callback used to inform the caller that // demuxer config has changed. - VideoDecoderJob( - const base::Closure& request_data_cb, - const base::Closure& request_resources_cb, - const base::Closure& on_demuxer_config_changed_cb); + VideoDecoderJob(const base::Closure& request_data_cb, + const base::Closure& request_resources_cb, + const base::Closure& on_demuxer_config_changed_cb, + FrameStatistics* frame_statistics); ~VideoDecoderJob() override; // Passes a java surface object to the codec. Returns true if the surface diff --git a/media/media.gyp b/media/media.gyp index a136093..5a462e6 100644 --- a/media/media.gyp +++ b/media/media.gyp @@ -1865,6 +1865,8 @@ 'base/android/media_resource_getter.h', 'base/android/media_source_player.cc', 'base/android/media_source_player.h', + 'base/android/media_statistics.cc', + 'base/android/media_statistics.h', 'base/android/media_task_runner.cc', 'base/android/media_task_runner.h', 'base/android/media_url_interceptor.h', diff --git a/tools/metrics/histograms/histograms.xml b/tools/metrics/histograms/histograms.xml index 7a83ec9..229413f 100644 --- a/tools/metrics/histograms/histograms.xml +++ b/tools/metrics/histograms/histograms.xml @@ -17748,6 +17748,30 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries. </summary> </histogram> +<histogram name="Media.MSE.LateAudioFrames" + units="late frames per million frames"> + <owner>qinmin@chromium.org</owner> + <owner>timav@chromium.org</owner> + <summary> + Relative number of late audio frames wrt total number of audio frames in MSE + playback, multiplied by one million. The audio frame is considered late if + it might cause an underrun, i.e. comes from decoder when audio buffer is + already depleted. + </summary> +</histogram> + +<histogram name="Media.MSE.LateVideoFrames" + units="late frames per million frames"> + <owner>qinmin@chromium.org</owner> + <owner>timav@chromium.org</owner> + <summary> + Relative number of late video frames wrt total number of video frames in MSE + playback, multiplied by one million. The video frame is late if it missed + its presentation time as determined by PTS when it comes from decoder. The + rendering policy (i.e. render or skip) does not affect it. + </summary> +</histogram> + <histogram name="Media.MSE.NumberOfTracks"> <owner>acolwell@chromium.org</owner> <summary> @@ -17767,6 +17791,26 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries. </summary> </histogram> +<histogram name="Media.MSE.PlaybackDuration" units="seconds"> + <owner>qinmin@chromium.org</owner> + <owner>timav@chromium.org</owner> + <summary> + Duration of an uninterrupted MSE playback. This is the time interval between + the playback starts or resumes and the moment when user stops the playback + by pressing pause, initiating a seek etc. Measured in media time in seconds. + </summary> +</histogram> + +<histogram name="Media.MSE.Starvations" units="starvations per million frames"> + <owner>qinmin@chromium.org</owner> + <owner>timav@chromium.org</owner> + <summary> + Relative number of starvations wrt total number of frames in MSE playback, + multiplied by one million. Starvation happens when the player interrupts the + regular playback and asks for more data, conditions are player-specific. + </summary> +</histogram> + <histogram name="Media.MSE.VideoCodec" enum="MSECodec"> <owner>acolwell@chromium.org</owner> <summary> |