[Media Router] Add route creation logs to Cast Media Route Provider

Log route creation results in CastMediaRouteProvider and
CastActivityManager using media_router::LoggerImpl.

Add two methods to the MediaRouter Mojo interface. GetLogger() is used
by components like CastMediaRouteProvider to obtain a Mojo pointer to
the logger. GetLogsAsString() is used by the component extension to get
logs to attach to feedback reports.

LoggerImpl was added by crrev.com/c/2079535.

Bug: 687380, b/154273698
Change-Id: Ifbfbd512783b49d3bfe1c4a894709380b10ebd13
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2259493
Commit-Queue: Takumi Fujimoto <takumif@chromium.org>
Reviewed-by: mark a. foltz <mfoltz@chromium.org>
Reviewed-by: Daniel Cheng <dcheng@chromium.org>
Cr-Commit-Position: refs/heads/master@{#782671}

chrome/browser/media/router/BUILD.gn

@@ -206,6 +206,8 @@ static_library("test_support") {
       "test/media_router_mojo_test.h",
       "test/mock_dns_sd_registry.cc",
       "test/mock_dns_sd_registry.h",
+      "test/mock_logger.cc",
+      "test/mock_logger.h",
       "test/mock_mojo_media_router.cc",
       "test/mock_mojo_media_router.h",
       "test/noop_dual_media_sink_service.cc",

chrome/browser/media/router/mojo/media_router_mojo_impl.cc

@@ -942,6 +942,15 @@ void MediaRouterMojoImpl::OnMediaRemoterCreated(
   connector->ConnectToService(std::move(source_receiver), std::move(remoter));
 }
 
+void MediaRouterMojoImpl::GetLogger(
+    mojo::PendingReceiver<mojom::Logger> receiver) {
+  logger_.Bind(std::move(receiver));
+}
+
+void MediaRouterMojoImpl::GetLogsAsString(GetLogsAsStringCallback callback) {
+  std::move(callback).Run(logger_.GetLogsAsJson());
+}
+
 void MediaRouterMojoImpl::GetMediaSinkServiceStatus(
     mojom::MediaRouter::GetMediaSinkServiceStatusCallback callback) {
   MediaSinkServiceStatus status;

chrome/browser/media/router/mojo/media_router_mojo_impl.h

@@ -22,10 +22,12 @@
 #include "base/optional.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "chrome/browser/media/router/issue_manager.h"
+#include "chrome/browser/media/router/logger_impl.h"
 #include "chrome/browser/media/router/media_router_base.h"
 #include "chrome/browser/media/router/media_routes_observer.h"
 #include "chrome/browser/media/webrtc/desktop_media_picker_controller.h"
 #include "chrome/common/media_router/issue.h"
+#include "chrome/common/media_router/mojom/logger.mojom.h"
 #include "chrome/common/media_router/mojom/media_router.mojom.h"
 #include "chrome/common/media_router/route_request_result.h"
 #include "content/public/browser/browser_thread.h"
@@ -336,6 +338,8 @@ class MediaRouterMojoImpl : public MediaRouterBase, public mojom::MediaRouter {
       mojo::PendingRemote<media::mojom::MirrorServiceRemoter> remoter,
       mojo::PendingReceiver<media::mojom::MirrorServiceRemotingSource>
           source_receiver) override;
+  void GetLogger(mojo::PendingReceiver<mojom::Logger> receiver) override;
+  void GetLogsAsString(GetLogsAsStringCallback callback) override;
   void GetMediaSinkServiceStatus(
       mojom::MediaRouter::GetMediaSinkServiceStatusCallback callback) override;
   void GetMirroringServiceHostForTab(
@@ -420,6 +424,10 @@ class MediaRouterMojoImpl : public MediaRouterBase, public mojom::MediaRouter {
 
   base::Optional<PendingStreamRequest> pending_stream_request_;
 
+  // Collects logs from the Media Router and the native Media Route Providers.
+  // TODO(crbug.com/1077138): Limit logging before Media Router usage.
+  LoggerImpl logger_;
+
   base::WeakPtrFactory<MediaRouterMojoImpl> weak_factory_{this};
 
   DISALLOW_COPY_AND_ASSIGN(MediaRouterMojoImpl);

chrome/browser/media/router/providers/cast/cast_activity_manager.cc

@@ -14,6 +14,7 @@
 #include "base/metrics/histogram_functions.h"
 #include "base/optional.h"
 #include "chrome/browser/media/router/data_decoder_util.h"
+#include "chrome/browser/media/router/logger_impl.h"
 #include "chrome/browser/media/router/providers/cast/cast_activity_record.h"
 #include "chrome/browser/media/router/providers/cast/cast_media_route_provider_metrics.h"
 #include "chrome/browser/media/router/providers/cast/cast_session_client.h"
@@ -28,21 +29,30 @@ using blink::mojom::PresentationConnectionState;
 
 namespace media_router {
 
+namespace {
+
+constexpr char kLoggerComponent[] = "CastActivityManager";
+
+}  // namespace
+
 CastActivityManager::CastActivityManager(
     MediaSinkServiceBase* media_sink_service,
     CastSessionTracker* session_tracker,
     cast_channel::CastMessageHandler* message_handler,
     mojom::MediaRouter* media_router,
+    mojom::Logger* logger,
     const std::string& hash_token)
     : media_sink_service_(media_sink_service),
       session_tracker_(session_tracker),
       message_handler_(message_handler),
       media_router_(media_router),
+      logger_(logger),
       hash_token_(hash_token) {
   DCHECK(media_sink_service_);
+  DCHECK(session_tracker_);
   DCHECK(message_handler_);
   DCHECK(media_router_);
-  DCHECK(session_tracker_);
+  DCHECK(logger_);
   message_handler_->AddObserver(this);
   for (const auto& sink_id_session : session_tracker_->GetSessions()) {
     const MediaSinkInternal* sink =
@@ -106,7 +116,9 @@ void CastActivityManager::LaunchSessionParsed(
     mojom::MediaRouteProvider::CreateRouteCallback callback,
     data_decoder::DataDecoder::ValueOrError result) {
   if (!cast_source.app_params().empty() && result.error) {
-    DVLOG(1) << "Error parsing JSON data in appParams" << *result.error;
+    logger_->LogError(mojom::LogCategory::kRoute, kLoggerComponent,
+                      "Error parsing JSON data in appParams" + *result.error,
+                      sink.id(), cast_source.source_id(), "");
     std::move(callback).Run(
         base::nullopt, nullptr, std::string("Invalid JSON Format of appParams"),
         RouteRequestResult::ResultCode::NO_SUPPORTED_PROVIDER);
@@ -170,11 +182,6 @@ void CastActivityManager::DoLaunchSession(DoLaunchSessionParams params) {
       cast_source.supported_app_types());
   std::string app_id = ChooseAppId(cast_source, params.sink);
 
-  DVLOG(2) << "Launching session with route ID = " << route_id
-           << ", source ID = " << cast_source.source_id()
-           << ", sink ID = " << sink.sink().id() << ", app ID = " << app_id
-           << ", origin = " << params.origin << ", tab ID = " << params.tab_id;
-
   mojom::RoutePresentationConnectionPtr presentation_connection;
 
   ActivityRecord* activity_ptr =
@@ -203,6 +210,9 @@ void CastActivityManager::DoLaunchSession(DoLaunchSessionParams params) {
       base::BindOnce(&CastActivityManager::HandleLaunchSessionResponse,
                      weak_ptr_factory_.GetWeakPtr(), route_id, sink,
                      cast_source));
+  logger_->LogInfo(mojom::LogCategory::kRoute, kLoggerComponent,
+                   "Launched a session", sink.id(), cast_source.source_id(),
+                   route_id);
 
   std::move(params.callback)
       .Run(route, std::move(presentation_connection),

chrome/browser/media/router/providers/cast/cast_activity_manager.h

@@ -20,6 +20,7 @@
 #include "chrome/browser/media/router/providers/cast/cast_session_tracker.h"
 #include "chrome/common/media_router/discovery/media_sink_internal.h"
 #include "chrome/common/media_router/media_sink.h"
+#include "chrome/common/media_router/mojom/logger.mojom.h"
 #include "chrome/common/media_router/mojom/media_router.mojom.h"
 #include "chrome/common/media_router/providers/cast/cast_media_source.h"
 #include "mojo/public/cpp/bindings/pending_receiver.h"
@@ -69,6 +70,7 @@ class CastActivityManager : public CastActivityManagerBase,
                       CastSessionTracker* session_tracker,
                       cast_channel::CastMessageHandler* message_handler,
                       mojom::MediaRouter* media_router,
+                      mojom::Logger* logger,
                       const std::string& hash_token);
   ~CastActivityManager() override;
 
@@ -296,6 +298,7 @@ class CastActivityManager : public CastActivityManagerBase,
   CastSessionTracker* const session_tracker_;
   cast_channel::CastMessageHandler* const message_handler_;
   mojom::MediaRouter* const media_router_;
+  mojom::Logger* const logger_;
 
   const std::string hash_token_;
 

chrome/browser/media/router/providers/cast/cast_activity_manager_unittest.cc

@@ -25,6 +25,7 @@
 #include "chrome/browser/media/router/providers/cast/mock_cast_activity_record.h"
 #include "chrome/browser/media/router/providers/cast/test_util.h"
 #include "chrome/browser/media/router/providers/common/buffered_message_sender.h"
+#include "chrome/browser/media/router/test/mock_logger.h"
 #include "chrome/browser/media/router/test/mock_mojo_media_router.h"
 #include "chrome/browser/media/router/test/test_helper.h"
 #include "chrome/common/media_router/test/test_helper.h"
@@ -151,7 +152,7 @@ class CastActivityManagerTest : public testing::Test,
                                socket_service_.task_runner()));
     manager_ = std::make_unique<CastActivityManager>(
         &media_sink_service_, session_tracker_.get(), &message_handler_,
-        router_remote_.get(), "theHashToken");
+        router_remote_.get(), &logger_, "theHashToken");
 
     ON_CALL(message_handler_, StopSession)
         .WillByDefault(WithArg<3>([this](auto callback) {
@@ -404,6 +405,7 @@ class CastActivityManagerTest : public testing::Test,
   const MediaSource::Id route_query_ = "theRouteQuery";
   base::Optional<MediaRoute> updated_route_;
   cast_channel::ResultCallback stop_session_callback_;
+  MockLogger logger_;
 };
 
 TEST_F(CastActivityManagerTest, LaunchCastAppSession) {

chrome/browser/media/router/providers/cast/cast_media_route_provider.cc

@@ -11,6 +11,7 @@
 #include "base/bind.h"
 #include "base/stl_util.h"
 #include "base/task/post_task.h"
+#include "chrome/browser/media/router/logger_impl.h"
 #include "chrome/browser/media/router/providers/cast/cast_activity_manager.h"
 #include "chrome/browser/media/router/providers/cast/cast_internal_message_util.h"
 #include "chrome/browser/media/router/providers/cast/cast_session_tracker.h"
@@ -25,6 +26,8 @@ namespace media_router {
 
 namespace {
 
+constexpr char kLoggerComponent[] = "CastMediaRouteProvider";
+
 // Whitelist of origins allowed to use a PresentationRequest to initiate
 // mirroring.
 constexpr std::array<base::StringPiece, 2> kPresentationApiWhitelist = {
@@ -81,10 +84,11 @@ void CastMediaRouteProvider::Init(
 
   receiver_.Bind(std::move(receiver));
   media_router_.Bind(std::move(media_router));
+  media_router_->GetLogger(logger_.BindNewPipeAndPassReceiver());
 
   activity_manager_ = std::make_unique<CastActivityManager>(
       media_sink_service_, session_tracker, message_handler_,
-      media_router_.get(), hash_token);
+      media_router_.get(), logger_.get(), hash_token);
 
   // TODO(crbug.com/816702): This needs to be set properly according to sinks
   // discovered.
@@ -109,14 +113,15 @@ void CastMediaRouteProvider::CreateRoute(const std::string& source_id,
                                          base::TimeDelta timeout,
                                          bool incognito,
                                          CreateRouteCallback callback) {
-  DVLOG(2) << "CreateRoute with origin: " << origin << " and tab ID " << tab_id;
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
 
   // TODO(https://crbug.com/809249): Handle mirroring routes, including
   // mirror-to-Cast transitions.
   const MediaSinkInternal* sink = media_sink_service_->GetSinkById(sink_id);
   if (!sink) {
-    DVLOG(2) << "CreateRoute: sink not found";
+    logger_->LogError(mojom::LogCategory::kRoute, kLoggerComponent,
+                      "Attempted to create a route with an invalid sink ID",
+                      sink_id, source_id, "");
     std::move(callback).Run(base::nullopt, nullptr,
                             std::string("Sink not found"),
                             RouteRequestResult::ResultCode::SINK_NOT_FOUND);
@@ -126,7 +131,9 @@ void CastMediaRouteProvider::CreateRoute(const std::string& source_id,
   std::unique_ptr<CastMediaSource> cast_source =
       CastMediaSource::FromMediaSourceId(source_id);
   if (!cast_source) {
-    DVLOG(2) << "CreateRoute: invalid source";
+    logger_->LogError(mojom::LogCategory::kRoute, kLoggerComponent,
+                      "Attempted to create a route with an invalid source",
+                      sink_id, source_id, "");
     std::move(callback).Run(
         base::nullopt, nullptr, std::string("Invalid source"),
         RouteRequestResult::ResultCode::NO_SUPPORTED_PROVIDER);
@@ -193,7 +200,6 @@ void CastMediaRouteProvider::SendRouteBinaryMessage(
 
 void CastMediaRouteProvider::StartObservingMediaSinks(
     const std::string& media_source) {
-  DVLOG(1) << __func__ << ", media_source: " << media_source;
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   if (base::Contains(sink_queries_, media_source))
     return;
@@ -300,8 +306,6 @@ void CastMediaRouteProvider::GetState(GetStateCallback callback) {
 void CastMediaRouteProvider::OnSinkQueryUpdated(
     const MediaSource::Id& source_id,
     const std::vector<MediaSinkInternal>& sinks) {
-  DVLOG(1) << __func__ << ", source_id: " << source_id
-           << ", #sinks: " << sinks.size();
   media_router_->OnSinksReceived(MediaRouteProviderId::CAST, source_id, sinks,
                                  GetOrigins(source_id));
 }

chrome/browser/media/router/providers/cast/cast_media_route_provider.h

@@ -13,6 +13,7 @@
 #include "base/macros.h"
 #include "chrome/browser/media/router/providers/cast/cast_app_discovery_service.h"
 #include "chrome/browser/media/router/providers/cast/dual_media_sink_service.h"
+#include "chrome/common/media_router/mojom/logger.mojom.h"
 #include "chrome/common/media_router/mojom/media_router.mojom.h"
 #include "mojo/public/cpp/bindings/pending_receiver.h"
 #include "mojo/public/cpp/bindings/pending_remote.h"
@@ -116,6 +117,9 @@ class CastMediaRouteProvider : public mojom::MediaRouteProvider {
   // Mojo remote to the Media Router.
   mojo::Remote<mojom::MediaRouter> media_router_;
 
+  // Mojo remote to the logger owned by the Media Router.
+  mojo::Remote<mojom::Logger> logger_;
+
   // Non-owned pointer to the Cast MediaSinkServiceBase instance.
   MediaSinkServiceBase* const media_sink_service_;
 

chrome/browser/media/router/test/mock_logger.cc

+// Copyright 2020 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 "chrome/browser/media/router/test/mock_logger.h"
+
+namespace media_router {
+
+MockLogger::MockLogger() = default;
+
+MockLogger::~MockLogger() = default;
+
+}  // namespace media_router

chrome/browser/media/router/test/mock_logger.h

+// Copyright 2020 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 CHROME_BROWSER_MEDIA_ROUTER_TEST_MOCK_LOGGER_H_
+#define CHROME_BROWSER_MEDIA_ROUTER_TEST_MOCK_LOGGER_H_
+
+#include "chrome/common/media_router/mojom/logger.mojom.h"
+#include "testing/gmock/include/gmock/gmock.h"
+
+namespace media_router {
+
+class MockLogger : public mojom::Logger {
+ public:
+  MockLogger();
+  ~MockLogger() override;
+
+  MOCK_METHOD6(LogInfo,
+               void(mojom::LogCategory category,
+                    const std::string& component,
+                    const std::string& message,
+                    const std::string& sink_id,
+                    const std::string& media_source,
+                    const std::string& session_id));
+  MOCK_METHOD6(LogWarning,
+               void(mojom::LogCategory category,
+                    const std::string& component,
+                    const std::string& message,
+                    const std::string& sink_id,
+                    const std::string& media_source,
+                    const std::string& session_id));
+  MOCK_METHOD6(LogError,
+               void(mojom::LogCategory category,
+                    const std::string& component,
+                    const std::string& message,
+                    const std::string& sink_id,
+                    const std::string& media_source,
+                    const std::string& session_id));
+};
+
+}  // namespace media_router
+
+#endif  // CHROME_BROWSER_MEDIA_ROUTER_TEST_MOCK_LOGGER_H_

chrome/browser/media/router/test/mock_mojo_media_router.h

@@ -73,6 +73,8 @@ class MockMojoMediaRouter : public MockMediaRouter, public mojom::MediaRouter {
            mojo::PendingRemote<media::mojom::MirrorServiceRemoter> remoter,
            mojo::PendingReceiver<media::mojom::MirrorServiceRemotingSource>
                source_receiver));
+  MOCK_METHOD1(GetLogger, void(mojo::PendingReceiver<mojom::Logger> receiver));
+  MOCK_METHOD1(GetLogsAsString, void(GetLogsAsStringCallback callback));
   void GetMediaSinkServiceStatus(
       mojom::MediaRouter::GetMediaSinkServiceStatusCallback callback) override {
     GetMediaSinkServiceStatusInternal(callback);

chrome/common/media_router/mojom/BUILD.gn

@@ -26,6 +26,7 @@ mojom("media_router") {
   sources = [ "media_router.mojom" ]
 
   public_deps = [
+    ":logger",
     ":media_controller",
     "//components/mirroring/mojom:host",
     "//media/mojo/mojom:mirror_service_remoting",

chrome/common/media_router/mojom/media_router.mojom

@@ -4,6 +4,7 @@
 
 module media_router.mojom;
 
+import "chrome/common/media_router/mojom/logger.mojom";
 import "chrome/common/media_router/mojom/media_controller.mojom";
 import "chrome/common/media_router/mojom/media_status.mojom";
 import "components/mirroring/mojom/mirroring_service_host.mojom";
@@ -598,6 +599,15 @@ interface MediaRouter {
   // Returns current status of media sink service in JSON format.
   GetMediaSinkServiceStatus() => (string status);
 
+  // The logger can be used to add entries to logs returned by GetLogs().
+  GetLogger(pending_receiver<Logger> receiver);
+
+  // Returns a JSON array of logs collected by Media Router components.
+  // Serializing the logs requires allocating extra memory, so it should only be
+  // called under limited circumstances, such as when the user is submitting a
+  // feedback report.
+  GetLogsAsString() => (string logs);
+
   // Called to get a mirroring.mojom.MirroringServiceHost. These APIs are used
   // by Media Router extension to start mirroring through the mirroring service.
   // TODO(http://crbug.com/809249): Remove these APIs when native Cast MRP with

chrome/renderer/resources/extensions/media_router_bindings.js

@@ -972,6 +972,13 @@ MediaRouter.prototype.getMediaSinkServiceStatus = function() {
   return this.service_.getMediaSinkServiceStatus();
 }
 
+/**
+ * @return {!Promise<!{status: string}>}
+ */
+MediaRouter.prototype.getLogsAsString = function() {
+  return this.service_.getLogsAsString();
+}
+
 /**
  * @param {int32} target_tab_id
  * @param {!mojo.InterfaceRequest} request