[fuchsia] Use Listen() rather than Dump() when testing Fuchsia logging.

Bug: 1088094, 1139396
Change-Id: I6a1f6d2a71abc117cf66304b91e0b331a0e4c324
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2527384
Commit-Queue: Wez <wez@chromium.org>
Reviewed-by: David Dorwin <ddorwin@chromium.org>
Auto-Submit: Wez <wez@chromium.org>
Cr-Commit-Position: refs/heads/master@{#834774}

base/BUILD.gn

@@ -2701,6 +2701,7 @@ if (build_base_unittests) {
       ]
       deps = [
         ":base",
+        "//base/test:test_support",
         "//testing/gtest",
       ]
       public_deps = [ "//third_party/fuchsia-sdk/sdk/fidl/fuchsia.logger" ]

base/fuchsia/test_log_listener_safe.cc

@@ -4,7 +4,9 @@
 
 #include "base/fuchsia/test_log_listener_safe.h"
 
-#include "base/logging.h"
+#include "base/fuchsia/fuchsia_logging.h"
+#include "base/run_loop.h"
+#include "base/test/bind.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 namespace base {
@@ -13,38 +15,90 @@ 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);
+void TestLogListenerSafe::set_on_log_message(
+    base::RepeatingCallback<void(const fuchsia::logger::LogMessage&)>
+        callback) {
+  on_log_message_ = std::move(callback);
 }
 
-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::Log(fuchsia::logger::LogMessage message,
+                              LogCallback callback) {
+  if (on_log_message_)
+    on_log_message_.Run(message);
+  callback();
 }
 
 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()));
+  for (const auto& message : messages)
+    on_log_message_.Run(message);
   callback();
 }
 
-void TestLogListenerSafe::Done() {
-  std::move(on_dump_logs_done_).Run();
-}
+void TestLogListenerSafe::Done() {}
 
 void TestLogListenerSafe::NotImplemented_(const std::string& name) {
   ADD_FAILURE() << "NotImplemented_: " << name;
 }
 
+SimpleTestLogListener::SimpleTestLogListener() : binding_(&listener_) {}
+
+SimpleTestLogListener::~SimpleTestLogListener() = default;
+
+void SimpleTestLogListener::ListenToLog(
+    fuchsia::logger::Log* log,
+    std::unique_ptr<fuchsia::logger::LogFilterOptions> options) {
+  listener_.set_on_log_message(base::BindRepeating(
+      &SimpleTestLogListener::PushLoggedMessage, base::Unretained(this)));
+  log->ListenSafe(binding_.NewBinding(), std::move(options));
+}
+
+base::Optional<fuchsia::logger::LogMessage>
+SimpleTestLogListener::RunUntilMessageReceived(
+    base::StringPiece expected_string) {
+  while (!logged_messages_.empty()) {
+    fuchsia::logger::LogMessage message = logged_messages_.front();
+    logged_messages_.pop_front();
+    if (base::StringPiece(message.msg).find(expected_string) !=
+        std::string::npos) {
+      return message;
+    }
+  }
+
+  base::Optional<fuchsia::logger::LogMessage> logged_message;
+  base::RunLoop loop;
+  binding_.set_error_handler(
+      [quit_loop = loop.QuitClosure()](zx_status_t status) {
+        ZX_LOG(ERROR, status) << "LogListenerSafe disconnected";
+        quit_loop.Run();
+      });
+  on_log_message_ = base::BindLambdaForTesting(
+      [&logged_message, expected_string = expected_string.as_string(),
+       quit_loop =
+           loop.QuitClosure()](const fuchsia::logger::LogMessage& message) {
+        if (message.msg.find(expected_string) == std::string::npos)
+          return;
+        logged_message.emplace(message);
+        quit_loop.Run();
+      });
+
+  loop.Run();
+
+  binding_.set_error_handler({});
+  on_log_message_ = {};
+
+  return logged_message;
+}
+
+void SimpleTestLogListener::PushLoggedMessage(
+    const fuchsia::logger::LogMessage& message) {
+  if (on_log_message_) {
+    DCHECK(logged_messages_.empty());
+    on_log_message_.Run(message);
+  } else {
+    logged_messages_.push_back(std::move(message));
+  }
+}
+
 }  // namespace base

base/fuchsia/test_log_listener_safe.h

@@ -7,37 +7,73 @@
 
 #include <fuchsia/logger/cpp/fidl_test_base.h>
 
+#include <lib/fidl/cpp/binding.h>
+#include <memory>
+
 #include "base/callback.h"
-#include "base/fuchsia/process_context.h"
+#include "base/containers/circular_deque.h"
+#include "base/optional.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.
+// LogListenerSafe implementation that invokes a caller-supplied callback for
+// each received message.
 class TestLogListenerSafe
-    : public ::fuchsia::logger::testing::LogListenerSafe_TestBase {
+    : public fuchsia::logger::testing::LogListenerSafe_TestBase {
  public:
+  using OnLogMessageCallback =
+      base::RepeatingCallback<void(const fuchsia::logger::LogMessage&)>;
+
   TestLogListenerSafe();
+  ~TestLogListenerSafe() final;
+
   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);
+  // Sets a callback to be invoked with every message received via Log().
+  void set_on_log_message(OnLogMessageCallback callback);
 
+ private:
   // LogListenerSafe implementation.
-  void LogMany(std::vector<::fuchsia::logger::LogMessage> messages,
-               LogManyCallback callback) override;
-  void Done() override;
-  void NotImplemented_(const std::string& name) override;
+  void Log(fuchsia::logger::LogMessage message, LogCallback callback) final;
+  void LogMany(std::vector<fuchsia::logger::LogMessage> messages,
+               LogManyCallback callback) final;
+  void Done() final;
+  void NotImplemented_(const std::string& name) final;
+
+  OnLogMessageCallback on_log_message_;
+};
+
+// Helper that manages a TestLogListenerSafe to simplify running the message
+// loop until specific messages are received.
+class SimpleTestLogListener {
+ public:
+  SimpleTestLogListener();
+  ~SimpleTestLogListener();
+
+  SimpleTestLogListener(const SimpleTestLogListener&) = delete;
+  SimpleTestLogListener& operator=(const SimpleTestLogListener&) = delete;
+
+  // Attaches this instance to receive data matching |options|, from |log|.
+  void ListenToLog(fuchsia::logger::Log* log,
+                   std::unique_ptr<fuchsia::logger::LogFilterOptions> options);
+
+  // Runs the message loop until a log message containing |expected_string| is
+  // received, and returns it. Returns |base::nullopt| if |binding_| disconnects
+  // without the |expected_string| having been logged.
+  base::Optional<fuchsia::logger::LogMessage> RunUntilMessageReceived(
+      base::StringPiece expected_string);
 
  private:
-  std::vector<::fuchsia::logger::LogMessage> log_messages_;
-  base::OnceClosure on_dump_logs_done_;
+  // Pushes |message| to the |logged_messages_| queue, or to |on_log_message_|.
+  void PushLoggedMessage(const fuchsia::logger::LogMessage& message);
+
+  TestLogListenerSafe listener_;
+  fidl::Binding<fuchsia::logger::LogListenerSafe> binding_;
+
+  base::circular_deque<fuchsia::logger::LogMessage> logged_messages_;
+  TestLogListenerSafe::OnLogMessageCallback on_log_message_;
 };
 
 }  // namespace base

base/logging_unittest.cc

@@ -717,56 +717,34 @@ namespace nested_test {
 
 // Verifies that calling the log macro goes to the Fuchsia system logs.
 TEST_F(LoggingTest, FuchsiaSystemLogging) {
-  const char kLogMessage[] = "system log!";
-  LOG(ERROR) << kLogMessage;
-
-  base::TestLogListenerSafe listener;
-  fidl::Binding<fuchsia::logger::LogListenerSafe> binding(&listener);
-
-  fuchsia::logger::LogMessage logged_message;
-
-  base::RunLoop wait_for_message_loop;
+  constexpr char kLogMessage[] = "system log!";
 
-  fuchsia::logger::LogPtr logger = base::ComponentContextForProcess()
-                                       ->svc()
-                                       ->Connect<fuchsia::logger::Log>();
-  logger.set_error_handler([&wait_for_message_loop](zx_status_t status) {
-    ZX_LOG(ERROR, status) << "fuchsia.logger.Log disconnected";
-    ADD_FAILURE();
-    wait_for_message_loop.Quit();
-  });
+  base::SimpleTestLogListener listener;
 
-  // |dump_logs| 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.
-  base::RepeatingClosure dump_logs = base::BindLambdaForTesting([&]() {
-    if (listener.DidReceiveString(kLogMessage, &logged_message)) {
-      wait_for_message_loop.Quit();
-      return;
-    }
-
-    std::unique_ptr<fuchsia::logger::LogFilterOptions> options =
-        std::make_unique<fuchsia::logger::LogFilterOptions>();
-    options->tags = {"base_unittests__exec"};
-    listener.set_on_dump_logs_done(dump_logs);
-    logger->DumpLogsSafe(binding.NewBinding(), std::move(options));
-  });
+  // Connect the test LogListenerSafe to the Log.
+  std::unique_ptr<fuchsia::logger::LogFilterOptions> options =
+      std::make_unique<fuchsia::logger::LogFilterOptions>();
+  options->tags = {"base_unittests__exec"};
+  fuchsia::logger::LogPtr log = base::ComponentContextForProcess()
+                                    ->svc()
+                                    ->Connect<fuchsia::logger::Log>();
+  listener.ListenToLog(log.get(), std::move(options));
 
-  // Start the first DumpLogs() call.
-  dump_logs.Run();
+  // Emit the test log message, and spin the loop until it is reported to the
+  // test listener.
+  LOG(ERROR) << kLogMessage;
 
-  // Run until kLogMessage is received.
-  wait_for_message_loop.Run();
+  base::Optional<fuchsia::logger::LogMessage> logged_message =
+      listener.RunUntilMessageReceived(kLogMessage);
 
-  EXPECT_EQ(logged_message.severity,
+  ASSERT_TRUE(logged_message.has_value());
+  EXPECT_EQ(logged_message->severity,
             static_cast<int32_t>(fuchsia::logger::LogLevelFilter::ERROR));
-  ASSERT_EQ(logged_message.tags.size(), 1u);
-  EXPECT_EQ(logged_message.tags[0], base::CommandLine::ForCurrentProcess()
-                                        ->GetProgram()
-                                        .BaseName()
-                                        .AsUTF8Unsafe());
+  ASSERT_EQ(logged_message->tags.size(), 1u);
+  EXPECT_EQ(logged_message->tags[0], base::CommandLine::ForCurrentProcess()
+                                         ->GetProgram()
+                                         .BaseName()
+                                         .AsUTF8Unsafe());
 }
 
 TEST_F(LoggingTest, FuchsiaLogging) {
@@ -786,6 +764,7 @@ TEST_F(LoggingTest, FuchsiaLogging) {
   ZX_CHECK(true, ZX_ERR_INTERNAL);
   ZX_DCHECK(true, ZX_ERR_INTERNAL);
 }
+
 #endif  // defined(OS_FUCHSIA)
 
 TEST_F(LoggingTest, LogPrefix) {