[Media] Record time it takes to start rendering audio and video

media/renderers/video_renderer_impl.cc

 // Copyright 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/renderers/video_renderer_impl.h"
 
 #include <utility>
 
 #include "base/bind.h"
 #include "base/callback.h"
@@ skipping 111 matching lines @@
   DVLOG(1) << __func__ << "(" << timestamp.InMicroseconds() << ")";
   DCHECK(task_runner_->BelongsToCurrentThread());
   base::AutoLock auto_lock(lock_);
   DCHECK_EQ(state_, kFlushed);
   DCHECK(!pending_read_);
   DCHECK_EQ(buffering_state_, BUFFERING_HAVE_NOTHING);
 
   state_ = kPlaying;
   start_timestamp_ = timestamp;
   painted_first_frame_ = false;
+  start_rendering_time_ = tick_clock_->NowTicks();
   AttemptRead_Locked();
 }
 
 void VideoRendererImpl::Initialize(
     DemuxerStream* stream,
     CdmContext* cdm_context,
     RendererClient* client,
     const TimeSource::WallClockTimeCB& wall_clock_time_cb,
     const PipelineStatusCB& init_cb) {
   DCHECK(task_runner_->BelongsToCurrentThread());
@@ skipping 61 matching lines @@
   }
 
   // We don't count dropped frames in the background to avoid skewing the count
   // and impacting JavaScript visible metrics used by web developers.
   //
   // Just after resuming from background rendering, we also don't count the
   // dropped frames since they are likely just dropped due to being too old.
   if (!background_rendering && !was_background_rendering_)
     frames_dropped_ += frames_dropped;
   UpdateStats_Locked();
+
   was_background_rendering_ = background_rendering;
 
   // Always post this task, it will acquire new frames if necessary and since it
   // happens on another thread, even if we don't have room in the queue now, by
   // the time it runs (may be delayed up to 50ms for complex decodes!) we might.
   task_runner_->PostTask(
       FROM_HERE,
       base::Bind(&VideoRendererImpl::AttemptReadAndCheckForMetadataChanges,
                  weak_factory_.GetWeakPtr(), result->format(),
                  result->natural_size()));
@@ skipping 192 matching lines @@
     // prerolling frames before the actual start time that will be dropped.
     if (algorithm_->frames_queued() > 1 || received_end_of_stream_ ||
         frame->timestamp() >= start_timestamp_ || low_delay_ ||
         !video_frame_stream_->CanReadWithoutStalling()) {
       scoped_refptr<VideoFrame> first_frame =
           algorithm_->Render(base::TimeTicks(), base::TimeTicks(), nullptr);
       CheckForMetadataChanges(first_frame->format(),
                               first_frame->natural_size());
       sink_->PaintSingleFrame(first_frame);
       painted_first_frame_ = true;
+
+      if (!start_rendering_time_.is_null()) {
+        UMA_HISTOGRAM_MEDIUM_TIMES(
+            "Media.Video.FirstRenderTime",
+            tick_clock_->NowTicks() - start_rendering_time_);
+        start_rendering_time_ = base::TimeTicks();
+      }
     }
   }
 
   // Signal buffering state if we've met our conditions.
   if (buffering_state_ == BUFFERING_HAVE_NOTHING && HaveEnoughData_Locked())
     TransitionToHaveEnough_Locked();
 
   // Always request more decoded video if we have capacity.
   AttemptRead_Locked();
 }
@@ skipping 275 matching lines @@
 
 void VideoRendererImpl::AttemptReadAndCheckForMetadataChanges(
     VideoPixelFormat pixel_format,
     const gfx::Size& natural_size) {
   base::AutoLock auto_lock(lock_);
   CheckForMetadataChanges(pixel_format, natural_size);
   AttemptRead_Locked();
 }
 
 }  // namespace media