[Video and Image Capture] Add trace events

Adds trace event category "video_and_image_capture", and adds code
for emitting trace events from various key locations in the video and
image capture stack.

Besides allowing us to investigate performance issues with these stacks, this
can also be very helpful for allowing us to better diagnose issues reported by
users who are able to submit trace logs, especially for cases where we cannot
reproduce the issues in the lab.

Bug: 890923
Change-Id: Ib81ef4ec079c8ece37d909a993dea63292a31f2d
Reviewed-on: https://chromium-review.googlesource.com/c/1405541
Reviewed-by: Primiano Tucci <primiano@chromium.org>
Reviewed-by: Miguel Casas <mcasas@chromium.org>
Reviewed-by: Emircan Uysaler <emircan@chromium.org>
Commit-Queue: Christian Fremerey <chfremer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#625005}

base/trace_event/builtin_categories.h

@@ -207,6 +207,7 @@
   X(TRACE_DISABLED_BY_DEFAULT("v8.runtime"))                             \
   X(TRACE_DISABLED_BY_DEFAULT("v8.runtime_stats"))                       \
   X(TRACE_DISABLED_BY_DEFAULT("v8.runtime_stats_sampling"))              \
+  X(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"))                \
   X(TRACE_DISABLED_BY_DEFAULT("viz.debug.overlay_planes"))               \
   X(TRACE_DISABLED_BY_DEFAULT("viz.hit_testing_flow"))                   \
   X(TRACE_DISABLED_BY_DEFAULT("viz.overdraw"))                           \

content/browser/image_capture/image_capture_impl.cc

@@ -58,6 +58,9 @@ void TakePhotoOnIOThread(const std::string& source_id,
                          MediaStreamManager* media_stream_manager,
                          ImageCaptureImpl::TakePhotoCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "image_capture_impl.cc::TakePhotoOnIOThread",
+                       TRACE_EVENT_SCOPE_PROCESS);
 
   const int session_id =
       media_stream_manager->VideoDeviceIdToSessionId(source_id);
@@ -87,6 +90,9 @@ void ImageCaptureImpl::Create(
 void ImageCaptureImpl::GetPhotoState(const std::string& source_id,
                                      GetPhotoStateCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "ImageCaptureImpl::GetPhotoState",
+                       TRACE_EVENT_SCOPE_PROCESS);
 
   GetPhotoStateCallback scoped_callback =
       mojo::WrapCallbackWithDefaultInvokeIfNotRun(
@@ -103,6 +109,9 @@ void ImageCaptureImpl::SetOptions(const std::string& source_id,
                                   media::mojom::PhotoSettingsPtr settings,
                                   SetOptionsCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "ImageCaptureImpl::SetOptions",
+                       TRACE_EVENT_SCOPE_PROCESS);
 
   SetOptionsCallback scoped_callback =
       mojo::WrapCallbackWithDefaultInvokeIfNotRun(
@@ -117,6 +126,9 @@ void ImageCaptureImpl::SetOptions(const std::string& source_id,
 void ImageCaptureImpl::TakePhoto(const std::string& source_id,
                                  TakePhotoCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "ImageCaptureImpl::TakePhoto",
+                       TRACE_EVENT_SCOPE_PROCESS);
 
   TakePhotoCallback scoped_callback =
       mojo::WrapCallbackWithDefaultInvokeIfNotRun(

content/browser/renderer_host/media/in_process_launched_video_capture_device.cc

@@ -75,6 +75,10 @@ void InProcessLaunchedVideoCaptureDevice::SetPhotoOptions(
 void InProcessLaunchedVideoCaptureDevice::TakePhoto(
     media::VideoCaptureDevice::TakePhotoCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "InProcessLaunchedVideoCaptureDevice::TakePhoto",
+                       TRACE_EVENT_SCOPE_PROCESS);
+
   // Unretained() is safe to use here because |device| would be null if it
   // was scheduled for shutdown and destruction, and because this task is
   // guaranteed to run before the task that destroys the |device|.

content/browser/renderer_host/media/service_launched_video_capture_device.cc

@@ -43,6 +43,9 @@ void ServiceLaunchedVideoCaptureDevice::SetPhotoOptions(
 void ServiceLaunchedVideoCaptureDevice::TakePhoto(
     media::VideoCaptureDevice::TakePhotoCallback callback) {
   DCHECK(sequence_checker_.CalledOnValidSequence());
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "ServiceLaunchedVideoCaptureDevice::TakePhoto",
+                       TRACE_EVENT_SCOPE_PROCESS);
   device_->TakePhoto(
       base::BindOnce(&ServiceLaunchedVideoCaptureDevice::OnTakePhotoResponse,
                      base::Unretained(this), std::move(callback)));

content/browser/renderer_host/media/video_capture_controller.cc

@@ -492,6 +492,8 @@ void VideoCaptureController::OnFrameReadyInBuffer(
     media::mojom::VideoFrameInfoPtr frame_info) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
   DCHECK_NE(buffer_id, media::VideoCaptureBufferPool::kInvalidId);
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+               "VideoCaptureController::OnFrameReadyInBuffer");
 
   frame_drop_log_state_ = FrameDropLogState();
 
@@ -578,6 +580,8 @@ void VideoCaptureController::OnError(media::VideoCaptureError error) {
 
 void VideoCaptureController::OnFrameDropped(
     media::VideoCaptureFrameDropReason reason) {
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+               "VideoCaptureController::OnFrameDropped");
   if (reason == frame_drop_log_state_.drop_reason) {
     if (frame_drop_log_state_.max_log_count_exceeded)
       return;
@@ -664,6 +668,8 @@ void VideoCaptureController::CreateAndStartDeviceAsync(
     VideoCaptureDeviceLaunchObserver* observer,
     base::OnceClosure done_cb) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+               "VideoCaptureController::CreateAndStartDeviceAsync");
   std::ostringstream string_stream;
   string_stream
       << "VideoCaptureController::CreateAndStartDeviceAsync: serial_id = "
@@ -680,6 +686,8 @@ void VideoCaptureController::CreateAndStartDeviceAsync(
 
 void VideoCaptureController::ReleaseDeviceAsync(base::OnceClosure done_cb) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+               "VideoCaptureController::ReleaseDeviceAsync");
   std::ostringstream string_stream;
   string_stream << "VideoCaptureController::ReleaseDeviceAsync: serial_id = "
                 << serial_id() << ", device_id = " << device_id();
@@ -715,6 +723,9 @@ void VideoCaptureController::TakePhoto(
     media::VideoCaptureDevice::TakePhotoCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
   DCHECK(launched_device_);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureController::TakePhoto",
+                       TRACE_EVENT_SCOPE_PROCESS);
   launched_device_->TakePhoto(std::move(callback));
 }
 

content/browser/renderer_host/media/video_capture_manager.cc

@@ -149,6 +149,8 @@ void VideoCaptureManager::EnumerateDevices(
 
 int VideoCaptureManager::Open(const blink::MediaStreamDevice& device) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::Open", TRACE_EVENT_SCOPE_PROCESS);
 
   // Generate a new id for the session being opened.
   const media::VideoCaptureSessionId capture_session_id =
@@ -175,6 +177,9 @@ int VideoCaptureManager::Open(const blink::MediaStreamDevice& device) {
 
 void VideoCaptureManager::Close(int capture_session_id) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::Close", TRACE_EVENT_SCOPE_PROCESS);
+
   std::ostringstream string_stream;
   string_stream << "VideoCaptureManager::Close, capture_session_id = "
                 << capture_session_id;
@@ -218,6 +223,9 @@ void VideoCaptureManager::QueueStartDevice(
 
 void VideoCaptureManager::DoStopDevice(VideoCaptureController* controller) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::DoStopDevice",
+                       TRACE_EVENT_SCOPE_PROCESS);
   // TODO(mcasas): use a helper function https://crbug.com/624854.
   DCHECK(std::find_if(
              controllers_.begin(), controllers_.end(),
@@ -258,6 +266,9 @@ void VideoCaptureManager::DoStopDevice(VideoCaptureController* controller) {
 
 void VideoCaptureManager::ProcessDeviceStartRequestQueue() {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::ProcessDeviceStartRequestQueue",
+                       TRACE_EVENT_SCOPE_PROCESS);
   auto request = device_start_request_queue_.begin();
   if (request == device_start_request_queue_.end())
     return;
@@ -371,6 +382,9 @@ void VideoCaptureManager::ConnectClient(
     VideoCaptureControllerEventHandler* client_handler,
     const DoneCB& done_cb) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::ConnectClient",
+                       TRACE_EVENT_SCOPE_PROCESS);
   {
     std::ostringstream string_stream;
     string_stream << "ConnectClient: session_id = " << session_id
@@ -411,6 +425,9 @@ void VideoCaptureManager::DisconnectClient(
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
   DCHECK(controller);
   DCHECK(client_handler);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::DisconnectClient",
+                       TRACE_EVENT_SCOPE_PROCESS);
 
   if (!IsControllerPointerValid(controller)) {
     NOTREACHED();
@@ -661,6 +678,9 @@ void VideoCaptureManager::TakePhoto(
     int session_id,
     media::VideoCaptureDevice::TakePhotoCallback callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::TakePhoto",
+                       TRACE_EVENT_SCOPE_PROCESS);
 
   VideoCaptureController* controller = LookupControllerBySessionId(session_id);
   if (!controller)
@@ -670,6 +690,9 @@ void VideoCaptureManager::TakePhoto(
     return;
   }
   // Queue up a request for later.
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::TakePhoto enqueuing request",
+                       TRACE_EVENT_SCOPE_PROCESS);
   photo_request_queue_.emplace_back(
       session_id,
       base::Bind(&VideoCaptureController::TakePhoto,
@@ -697,6 +720,10 @@ void VideoCaptureManager::OnDeviceInfosReceived(
     EnumerationCallback client_callback,
     const std::vector<media::VideoCaptureDeviceInfo>& device_infos) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("video_and_image_capture"),
+                       "VideoCaptureManager::OnDeviceInfosReceived",
+                       TRACE_EVENT_SCOPE_PROCESS);
+
   UMA_HISTOGRAM_TIMES(
       "Media.VideoCaptureManager.GetAvailableDevicesInfoOnDeviceThreadTime",
       timer->Elapsed());