[fuchsia] Add a simple console log WebEngine integration test

More tests will be added in future CLs.

Also extracts TestLogListenerSafe for reuse and adds support for
starting WebEngine for tests without redirecting logging as required for
the new test to work.

Bug: 1051533,1133984
Change-Id: I709dcecc82c5c4b5648c2c25a3bbf64dc7090cf4
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2440980
Commit-Queue: David Dorwin <ddorwin@chromium.org>
Reviewed-by: Sergey Ulanov <sergeyu@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Cr-Commit-Position: refs/heads/master@{#814421}

base/BUILD.gn

@@ -2645,6 +2645,19 @@ if (is_fuchsia) {
       ":testfidl",
     ]
   }
+
+  source_set("test_log_listener_safe") {
+    testonly = true
+    sources = [
+      "fuchsia/test_log_listener_safe.cc",
+      "fuchsia/test_log_listener_safe.h",
+    ]
+    deps = [
+      ":base",
+      "//testing/gtest",
+    ]
+    public_deps = [ "//third_party/fuchsia-sdk/sdk/fidl/fuchsia.logger" ]
+  }
 }
 
 source_set("base_unittests_tasktraits") {
@@ -3311,6 +3324,7 @@ test("base_unittests") {
 
     deps += [
       ":test_interface_impl",
+      ":test_log_listener_safe",
       ":testfidl",
       "//third_party/fuchsia-sdk/sdk/fidl/fuchsia.intl",
       "//third_party/fuchsia-sdk/sdk/fidl/fuchsia.logger",

base/fuchsia/test_log_listener_safe.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 "base/fuchsia/test_log_listener_safe.h"
+
+#include "base/logging.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace base {
+
+TestLogListenerSafe::TestLogListenerSafe() = default;
+
+TestLogListenerSafe::~TestLogListenerSafe() = default;
+
+void TestLogListenerSafe::set_on_dump_logs_done(
+    base::OnceClosure on_dump_logs_done) {
+  on_dump_logs_done_ = std::move(on_dump_logs_done);
+}
+
+bool TestLogListenerSafe::DidReceiveString(
+    base::StringPiece message,
+    fuchsia::logger::LogMessage* logged_message) {
+  for (const auto& log_message : log_messages_) {
+    if (log_message.msg.find(message.as_string()) != std::string::npos) {
+      *logged_message = log_message;
+      return true;
+    }
+  }
+  return false;
+}
+
+void TestLogListenerSafe::LogMany(
+    std::vector<fuchsia::logger::LogMessage> messages,
+    LogManyCallback callback) {
+  log_messages_.insert(log_messages_.end(),
+                       std::make_move_iterator(messages.begin()),
+                       std::make_move_iterator(messages.end()));
+  callback();
+}
+
+void TestLogListenerSafe::Done() {
+  std::move(on_dump_logs_done_).Run();
+}
+
+void TestLogListenerSafe::NotImplemented_(const std::string& name) {
+  ADD_FAILURE() << "NotImplemented_: " << name;
+}
+
+}  // namespace base

base/fuchsia/test_log_listener_safe.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 BASE_FUCHSIA_TEST_LOG_LISTENER_SAFE_H_
+#define BASE_FUCHSIA_TEST_LOG_LISTENER_SAFE_H_
+
+#include <fuchsia/logger/cpp/fidl_test_base.h>
+
+#include "base/callback.h"
+#include "base/fuchsia/process_context.h"
+#include "base/strings/string_piece.h"
+
+namespace base {
+
+// A LogListenerSafe implementation for use in Fuchsia logging tests.
+// For use with fuchsia.logger.Log.DumpLogsSafe().
+// Stores messages received via LogMany() for inspection by tests.
+class TestLogListenerSafe
+    : public ::fuchsia::logger::testing::LogListenerSafe_TestBase {
+ public:
+  TestLogListenerSafe();
+  TestLogListenerSafe(const TestLogListenerSafe&) = delete;
+  TestLogListenerSafe& operator=(const TestLogListenerSafe&) = delete;
+  ~TestLogListenerSafe() override;
+
+  void set_on_dump_logs_done(base::OnceClosure on_dump_logs_done);
+
+  bool DidReceiveString(base::StringPiece message,
+                        ::fuchsia::logger::LogMessage* logged_message);
+
+  // LogListenerSafe implementation.
+  void LogMany(std::vector<::fuchsia::logger::LogMessage> messages,
+               LogManyCallback callback) override;
+  void Done() override;
+  void NotImplemented_(const std::string& name) override;
+
+ private:
+  std::vector<::fuchsia::logger::LogMessage> log_messages_;
+  base::OnceClosure on_dump_logs_done_;
+};
+
+}  // namespace base
+
+#endif  // BASE_FUCHSIA_TEST_LOG_LISTENER_SAFE_H_

base/logging_unittest.cc

@@ -40,7 +40,6 @@
 
 #if defined(OS_FUCHSIA)
 #include <fuchsia/logger/cpp/fidl.h>
-#include <fuchsia/logger/cpp/fidl_test_base.h>
 #include <lib/fidl/cpp/binding.h>
 #include <lib/sys/cpp/component_context.h>
 #include <lib/zx/channel.h>
@@ -56,6 +55,7 @@
 
 #include "base/fuchsia/fuchsia_logging.h"
 #include "base/fuchsia/process_context.h"
+#include "base/fuchsia/test_log_listener_safe.h"
 #endif  // OS_FUCHSIA
 
 namespace logging {
@@ -714,56 +714,12 @@ namespace nested_test {
 
 #if defined(OS_FUCHSIA)
 
-class TestLogListenerSafe
-    : public fuchsia::logger::testing::LogListenerSafe_TestBase {
- public:
-  TestLogListenerSafe() = default;
-  TestLogListenerSafe(const TestLogListenerSafe&) = delete;
-  TestLogListenerSafe& operator=(const TestLogListenerSafe&) = delete;
-  ~TestLogListenerSafe() override = default;
-
-  void set_on_dump_logs_done(base::OnceClosure on_dump_logs_done) {
-    on_dump_logs_done_ = std::move(on_dump_logs_done);
-  }
-
-  bool DidReceiveString(base::StringPiece message,
-                        fuchsia::logger::LogMessage* logged_message) {
-    for (const auto& log_message : log_messages_) {
-      if (log_message.msg.find(message.as_string()) != std::string::npos) {
-        *logged_message = log_message;
-        return true;
-      }
-    }
-    return false;
-  }
-
-  // LogListener implementation.
-  void LogMany(std::vector<fuchsia::logger::LogMessage> messages,
-               LogManyCallback callback) override {
-    log_messages_.insert(log_messages_.end(),
-                         std::make_move_iterator(messages.begin()),
-                         std::make_move_iterator(messages.end()));
-    callback();
-  }
-
-  void Done() override { std::move(on_dump_logs_done_).Run(); }
-
-  void NotImplemented_(const std::string& name) override {
-    ADD_FAILURE() << "NotImplemented_: " << name;
-  }
-
- private:
-  fuchsia::logger::LogListenerSafePtr log_listener_;
-  std::vector<fuchsia::logger::LogMessage> log_messages_;
-  base::OnceClosure on_dump_logs_done_;
-};
-
 // Verifies that calling the log macro goes to the Fuchsia system logs.
 TEST_F(LoggingTest, FuchsiaSystemLogging) {
   const char kLogMessage[] = "system log!";
   LOG(ERROR) << kLogMessage;
 
-  TestLogListenerSafe listener;
+  base::TestLogListenerSafe listener;
   fidl::Binding<fuchsia::logger::LogListenerSafe> binding(&listener);
 
   fuchsia::logger::LogMessage logged_message;
@@ -780,9 +736,10 @@ TEST_F(LoggingTest, FuchsiaSystemLogging) {
   });
 
   // |dump_logs| checks whether the expected log line has been received yet,
-  // and invokes DumpLogs() if not. It passes itself as the completion callback,
-  // so that when the call completes it can check again for the expected message
-  // and re-invoke DumpLogs(), or quit the loop, as appropriate.
+  // and invokes DumpLogsSafe() if not. It passes itself as the completion
+  // callback, so that when the call completes it can check again for the
+  // expected message and re-invoke DumpLogsSafe(), or quit the loop, as
+  // appropriate.
   base::RepeatingClosure dump_logs = base::BindLambdaForTesting([&]() {
     if (listener.DidReceiveString(kLogMessage, &logged_message)) {
       wait_for_message_loop.Quit();

fuchsia/base/context_provider_test_connector.cc

@@ -17,23 +17,32 @@
 
 namespace cr_fuchsia {
 
-fidl::InterfaceHandle<fuchsia::io::Directory> StartWebEngineForTests(
+namespace {
+
+// |is_for_logging_test| should only be true when testing WebEngine's logging
+// behavior as it prevents WebEngine logs from being included in the test
+// output. When false, WebEngine logs are not included in the Fuchsia system
+// log.
+fidl::InterfaceHandle<fuchsia::io::Directory> StartWebEngineForTestsInternal(
     fidl::InterfaceRequest<fuchsia::sys::ComponentController>
         component_controller_request,
-    const base::CommandLine& command_line) {
+    const base::CommandLine& command_line,
+    bool is_for_logging_test) {
   fuchsia::sys::LaunchInfo launch_info;
   launch_info.url =
       "fuchsia-pkg://fuchsia.com/web_engine#meta/context_provider.cmx";
   launch_info.arguments = command_line.argv();
 
-  // Clone stderr from the current process to WebEngine and ask it to
-  // redirects all logs to stderr.
-  launch_info.err = fuchsia::sys::FileDescriptor::New();
-  launch_info.err->type0 = PA_FD;
-  zx_status_t status = fdio_fd_clone(
-      STDERR_FILENO, launch_info.err->handle0.reset_and_get_address());
-  ZX_CHECK(status == ZX_OK, status);
-  launch_info.arguments->push_back("--enable-logging=stderr");
+  if (!is_for_logging_test) {
+    // Clone stderr from the current process to WebEngine and ask it to
+    // redirects all logs to stderr.
+    launch_info.err = fuchsia::sys::FileDescriptor::New();
+    launch_info.err->type0 = PA_FD;
+    zx_status_t status = fdio_fd_clone(
+        STDERR_FILENO, launch_info.err->handle0.reset_and_get_address());
+    ZX_CHECK(status == ZX_OK, status);
+    launch_info.arguments->push_back("--enable-logging=stderr");
+  }
 
   fidl::InterfaceHandle<fuchsia::io::Directory> web_engine_services_dir;
   launch_info.directory_request =
@@ -47,13 +56,31 @@ fidl::InterfaceHandle<fuchsia::io::Directory> StartWebEngineForTests(
   return web_engine_services_dir;
 }
 
+}  // namespace
+
+fidl::InterfaceHandle<fuchsia::io::Directory> StartWebEngineForTests(
+    fidl::InterfaceRequest<fuchsia::sys::ComponentController>
+        component_controller_request,
+    const base::CommandLine& command_line) {
+  return StartWebEngineForTestsInternal(std::move(component_controller_request),
+                                        command_line, false);
+}
+
 fuchsia::web::ContextProviderPtr ConnectContextProvider(
     fidl::InterfaceRequest<fuchsia::sys::ComponentController>
         component_controller_request,
     const base::CommandLine& command_line) {
-  sys::ServiceDirectory web_engine_service_dir(StartWebEngineForTests(
-      std::move(component_controller_request), command_line));
+  sys::ServiceDirectory web_engine_service_dir(StartWebEngineForTestsInternal(
+      std::move(component_controller_request), command_line, false));
   return web_engine_service_dir.Connect<fuchsia::web::ContextProvider>();
 }
 
+fuchsia::web::ContextProviderPtr ConnectContextProviderForLoggingTest(
+    fidl::InterfaceRequest<fuchsia::sys::ComponentController>
+        component_controller_request,
+    const base::CommandLine& command_line) {
+  sys::ServiceDirectory web_engine_service_dir(StartWebEngineForTestsInternal(
+      std::move(component_controller_request), command_line, true));
+  return web_engine_service_dir.Connect<fuchsia::web::ContextProvider>();
+}
 }  // namespace cr_fuchsia

fuchsia/base/context_provider_test_connector.h

@@ -14,18 +14,33 @@
 
 namespace cr_fuchsia {
 
+// Starts a WebEngine instance for tests.
+// WebEngine logs will be included in the test output but not in the Fuchsia
+// system log.
 fidl::InterfaceHandle<fuchsia::io::Directory> StartWebEngineForTests(
     fidl::InterfaceRequest<fuchsia::sys::ComponentController>
         component_controller_request,
     const base::CommandLine& command_line =
         base::CommandLine(base::CommandLine::NO_PROGRAM));
 
+// Starts a WebEngine and connects a ContextProvider instance for tests.
+// WebEngine logs will be included in the test output but not in the Fuchsia
+// system log.
 fuchsia::web::ContextProviderPtr ConnectContextProvider(
     fidl::InterfaceRequest<fuchsia::sys::ComponentController>
         component_controller_request,
     const base::CommandLine& command_line =
         base::CommandLine(base::CommandLine::NO_PROGRAM));
 
+// Does the same thing as ConnectContextProvider() except WebEngine logs are not
+// redirected and thus are included in the Fuchsia system log. WebEngine logs
+// are not included in the test output. Only use with tests that are verifying
+// WebEngine's logging behavior.
+fuchsia::web::ContextProviderPtr ConnectContextProviderForLoggingTest(
+    fidl::InterfaceRequest<fuchsia::sys::ComponentController>
+        component_controller_request,
+    const base::CommandLine& command_line =
+        base::CommandLine(base::CommandLine::NO_PROGRAM));
 }  // namespace cr_fuchsia
 
 #endif  // FUCHSIA_BASE_CONTEXT_PROVIDER_TEST_CONNECTOR_H_

fuchsia/engine/BUILD.gn

@@ -354,6 +354,7 @@ test("web_engine_integration_tests") {
   data = [ "test/data" ]
   deps = [
     "//base",
+    "//base:test_log_listener_safe",
     "//base/test:run_all_unittests",
     "//fuchsia/base",
     "//fuchsia/base:test_support",

fuchsia/engine/test/data/console_logging.html

+<html>
+  <body>
+    <video></video>
+    <script>
+      console.clear();
+
+      // The following are ConsoleLogLevel::DEBUG.
+      console.debug("This is a debug() message.");
+
+      document.title = 'ended';
+    </script>
+  </body>
+</html>

fuchsia/engine/web_engine_integration_test.cc

@@ -2,6 +2,8 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+#include <cstring>
+
 #include <fuchsia/mediacodec/cpp/fidl.h>
 #include <fuchsia/sys/cpp/fidl.h>
 #include <fuchsia/web/cpp/fidl.h>
@@ -18,8 +20,10 @@
 #include "base/fuchsia/fuchsia_logging.h"
 #include "base/fuchsia/process_context.h"
 #include "base/fuchsia/scoped_service_binding.h"
+#include "base/fuchsia/test_log_listener_safe.h"
 #include "base/macros.h"
 #include "base/path_service.h"
+#include "base/test/bind_test_util.h"
 #include "base/test/task_environment.h"
 #include "fuchsia/base/context_provider_test_connector.h"
 #include "fuchsia/base/fit_adapter.h"
@@ -336,6 +340,101 @@ class WebEngineIntegrationUserAgentTest : public WebEngineIntegrationTest {
   }
 };
 
+class WebEngineIntegrationLogTest : public WebEngineIntegrationTestBase {
+ protected:
+  WebEngineIntegrationLogTest()
+      : WebEngineIntegrationTestBase(), binding_(&test_log_listener_) {}
+  void SetUp() override {
+    WebEngineIntegrationTestBase::SetUp();
+    StartWebEngineForLoggingTest(
+        base::CommandLine(base::CommandLine::NO_PROGRAM));
+
+    logger_ = base::ComponentContextForProcess()
+                  ->svc()
+                  ->Connect<fuchsia::logger::Log>();
+    logger_.set_error_handler([&](zx_status_t status) {
+      ZX_LOG(ERROR, status) << "fuchsia.logger.Log disconnected";
+      ADD_FAILURE();
+      wait_for_message_loop_.Quit();
+    });
+  }
+
+  // Starts WebEngine without redirecting its logs.
+  void StartWebEngineForLoggingTest(base::CommandLine command_line) {
+    web_context_provider_ = cr_fuchsia::ConnectContextProviderForLoggingTest(
+        web_engine_controller_.NewRequest(), std::move(command_line));
+    web_context_provider_.set_error_handler(
+        [](zx_status_t status) { ADD_FAILURE(); });
+  }
+
+  // Checks whether the expected log line has been received yet,
+  // and invokes DumpLogsSafe() if not. It passes itself as the completion
+  // callback, so that when the call completes it can check again for the
+  // expected message and re-invoke DumpLogsSafe(), or quit the loop, as
+  // appropriate.
+  void DumpLogs() {
+    // Look for kLogTestPageFileName because that string is unique to the
+    // console logs generated by these tests.
+    if (test_log_listener_.DidReceiveString(kLogTestPageFileName,
+                                            &logged_message_)) {
+      wait_for_message_loop_.Quit();
+      return;
+    }
+
+    std::unique_ptr<fuchsia::logger::LogFilterOptions> options =
+        std::make_unique<fuchsia::logger::LogFilterOptions>();
+    options->tags = {kWebEngineLogTag};
+
+    test_log_listener_.set_on_dump_logs_done(base::BindOnce(
+        &WebEngineIntegrationLogTest::DumpLogs, base::Unretained(this)));
+    logger_->DumpLogsSafe(binding_.NewBinding(), std::move(options));
+  }
+
+  void LoadLogTestPage() {
+    EXPECT_TRUE(cr_fuchsia::LoadUrlAndExpectResponse(
+        navigation_controller_.get(), fuchsia::web::LoadUrlParams(),
+        embedded_test_server_.GetURL(std::string("/") + kLogTestPageFileName)
+            .spec()));
+  }
+
+  // Replaces the line number in frame_impl.cc with kNormalizedLineNumber and
+  // the port with kNormalizedPortNumber to enable reliable comparison of
+  // console log messages.
+  std::string NormalizeConsoleLogMessage(base::StringPiece original) {
+    size_t line_number_begin = original.find("(") + 1;
+    size_t close_parenthesis = original.find(")", line_number_begin);
+
+    const char kSchemePortColon[] = "http://127.0.0.1:";
+    size_t port_begin =
+        original.find(kSchemePortColon) + strlen(kSchemePortColon);
+    size_t path_begin = original.find("/", port_begin);
+
+    return original.as_string()
+        .replace(line_number_begin, close_parenthesis - line_number_begin,
+                 kNormalizedLineNumber)
+        .replace(port_begin, path_begin - port_begin, kNormalizedPortNumber);
+  }
+
+  static const char kLogTestPageFileName[];
+  static const char kWebEngineLogTag[];
+  static const char kNormalizedLineNumber[];
+  static const char kNormalizedPortNumber[];
+
+  fuchsia::logger::LogPtr logger_;
+  base::TestLogListenerSafe test_log_listener_;
+  fidl::Binding<fuchsia::logger::LogListenerSafe> binding_;
+
+  fuchsia::logger::LogMessage logged_message_;
+
+  base::RunLoop wait_for_message_loop_;
+};
+
+const char WebEngineIntegrationLogTest::kLogTestPageFileName[] =
+    "console_logging.html";
+const char WebEngineIntegrationLogTest::kWebEngineLogTag[] = "web_engine_exe";
+const char WebEngineIntegrationLogTest::kNormalizedLineNumber[] = "123";
+const char WebEngineIntegrationLogTest::kNormalizedPortNumber[] = "456";
+
 TEST_F(WebEngineIntegrationUserAgentTest, ValidProductOnly) {
   // Create a Context with just an embedder product specified.
   fuchsia::web::CreateContextParams create_params = DefaultContextParams();
@@ -795,3 +894,31 @@ TEST_F(WebEngineIntegrationTest, HardwareVideoDecoderFlag_NotProvided) {
 
   EXPECT_FALSE(is_requested);
 }
+
+// Verifies that calling messages from console.debug() calls go to the Fuchsia
+// system log when the script log level is set to DEBUG.
+TEST_F(WebEngineIntegrationLogTest, SetJavaScriptLogLevel_DEBUG) {
+  CreateContextAndFrame(DefaultContextParams());
+
+  // Enable all logging.
+  frame_->SetJavaScriptLogLevel(fuchsia::web::ConsoleLogLevel::DEBUG);
+
+  LoadLogTestPage();
+  navigation_listener_->RunUntilTitleEquals("ended");
+
+  // Start the first DumpLogs() call.
+  DumpLogs();
+
+  // Run until kLogMessage is received.
+  wait_for_message_loop_.Run();
+
+  EXPECT_EQ(logged_message_.severity,
+            static_cast<int32_t>(fuchsia::logger::LogLevelFilter::INFO));
+  ASSERT_EQ(logged_message_.tags.size(), 1u);
+  EXPECT_EQ(logged_message_.tags[0], kWebEngineLogTag);
+  EXPECT_EQ(NormalizeConsoleLogMessage(logged_message_.msg),
+            "frame_impl.cc(" + std::string(kNormalizedLineNumber) +
+                ") debug:http://127.0.0.1:" + kNormalizedPortNumber +
+                "/console_logging.html:8 "
+                ": This is a debug() message.");
+}

fuchsia/engine/web_engine_integration_tests.cmx

@@ -10,6 +10,7 @@
       "fuchsia.device.NameProvider",
       "fuchsia.fonts.Provider",
       "fuchsia.intl.PropertyProvider",
+      "fuchsia.logger.Log",
       "fuchsia.logger.LogSink",
       "fuchsia.media.Audio",
       "fuchsia.media.SessionAudioConsumerFactory",