Add PA_LOG() macro to for logging messages specific to Proximity Auth.

This macro is built on top of the standard logging system defined in
base/logging.h, but also allows us to show Proximity Auth specific logs in the
debug WebUI at chrome://proximity-auth.

BUG=409158
TEST=unit test

Committed: https://crrev.com/dda9f80847aa2966b03a9625419fbe01c8e47192
Cr-Commit-Position: refs/heads/master@{#328026}

Review URL: https://codereview.chromium.org/1113023006

Cr-Commit-Position: refs/heads/master@{#328156}

10 files changed, 365 insertions, 1 deletions

diff --git a/components/components_tests.gyp b/components/components_tests.gyp
index 2585f0a..78092da 100644
--- a/components/components_tests.gyp
+++ b/components/components_tests.gyp
@@ -421,6 +421,7 @@
       'proximity_auth/cryptauth/cryptauth_client_impl_unittest.cc',
       'proximity_auth/cryptauth/cryptauth_enroller_impl_unittest.cc',
       'proximity_auth/cryptauth/fake_secure_message_delegate_unittest.cc',
+      'proximity_auth/logging/logging_unittest.cc',
       'proximity_auth/proximity_auth_system_unittest.cc',
       'proximity_auth/remote_status_update_unittest.cc',
       'proximity_auth/throttled_bluetooth_connection_finder_unittest.cc',
diff --git a/components/proximity_auth.gypi b/components/proximity_auth.gypi
index 38880d4..9ac28c5 100644
--- a/components/proximity_auth.gypi
+++ b/components/proximity_auth.gypi
@@ -13,6 +13,7 @@
         '..',
       ],
       'dependencies': [
+        ':proximity_auth_logging',
         '../base/base.gyp:base',
         '../device/bluetooth/bluetooth.gyp:device_bluetooth',
         '../net/net.gyp:net',
@@ -57,7 +58,24 @@
       ],
     },
     {
-      # GN version: //components/cryptauth/proto
+      # GN version: //components/proximity_auth/logging
+      'target_name': 'proximity_auth_logging',
+      'type': 'static_library',
+      'include_dirs': [
+        '..',
+      ],
+      'dependencies': [
+        '../base/base.gyp:base',
+      ],
+      'sources': [
+        "proximity_auth/logging/log_buffer.cc",
+        "proximity_auth/logging/log_buffer.h",
+        "proximity_auth/logging/logging.h",
+        "proximity_auth/logging/logging.cc",
+      ]
+    },
+    {
+      # GN version: //components/proximity_auth/cryptauth/proto
       'target_name': 'cryptauth_proto',
       'type': 'static_library',
       'sources': [
diff --git a/components/proximity_auth/BUILD.gn b/components/proximity_auth/BUILD.gn
index e2faf96..6f3ae96 100644
--- a/components/proximity_auth/BUILD.gn
+++ b/components/proximity_auth/BUILD.gn
@@ -41,6 +41,7 @@ source_set("proximity_auth") {
   ]
 
   deps = [
+    "logging",
     "//base",
     "//device/bluetooth",
     "//net",
@@ -66,6 +67,7 @@ source_set("unit_tests") {
   deps = [
     ":proximity_auth",
     "cryptauth:unit_tests",
+    "logging:unit_tests",
     "//base/test:test_support",
     "//device/bluetooth:mocks",
     "//testing/gmock",
diff --git a/components/proximity_auth/cryptauth/BUILD.gn b/components/proximity_auth/cryptauth/BUILD.gn
index fcbf846..92f35843 100644
--- a/components/proximity_auth/cryptauth/BUILD.gn
+++ b/components/proximity_auth/cryptauth/BUILD.gn
@@ -25,6 +25,7 @@ source_set("cryptauth") {
 
   deps = [
     "//base",
+    "//components/proximity_auth/logging",
     "//google_apis",
     "//net",
   ]
diff --git a/components/proximity_auth/logging/BUILD.gn b/components/proximity_auth/logging/BUILD.gn
new file mode 100644
index 0000000..dbc8045
--- /dev/null
+++ b/components/proximity_auth/logging/BUILD.gn
@@ -0,0 +1,28 @@
+# Copyright 2015 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.
+
+source_set("logging") {
+  sources = [
+    "log_buffer.cc",
+    "log_buffer.h",
+    "logging.cc",
+    "logging.h",
+  ]
+
+  deps = [
+    "//base",
+  ]
+}
+
+source_set("unit_tests") {
+  testonly = true
+  sources = [
+    "logging_unittest.cc",
+  ]
+
+  deps = [
+    "//base/test:test_support",
+    "//testing/gtest",
+  ]
+}
diff --git a/components/proximity_auth/logging/log_buffer.cc b/components/proximity_auth/logging/log_buffer.cc
new file mode 100644
index 0000000..60e763a
--- /dev/null
+++ b/components/proximity_auth/logging/log_buffer.cc
@@ -0,0 +1,56 @@
+// Copyright 2015 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 "components/proximity_auth/logging/log_buffer.h"
+
+#include "base/lazy_instance.h"
+
+namespace proximity_auth {
+
+namespace {
+
+// The maximum number of logs that can be stored in the buffer.
+const size_t kMaxBufferSize = 1000;
+
+// The global instance returned by LogBuffer::GetInstance().
+base::LazyInstance<LogBuffer>::Leaky g_log_buffer = LAZY_INSTANCE_INITIALIZER;
+
+}  // namespace
+
+LogBuffer::LogMessage::LogMessage(const std::string& text,
+                                  const base::Time& time,
+                                  const std::string& file,
+                                  const int line,
+                                  logging::LogSeverity severity)
+    : text(text), time(time), file(file), line(line), severity(severity) {
+}
+
+LogBuffer::LogBuffer() {
+}
+
+LogBuffer::~LogBuffer() {
+}
+
+// static
+LogBuffer* LogBuffer::GetInstance() {
+  return &g_log_buffer.Get();
+}
+
+void LogBuffer::AddLogMessage(const LogMessage& log_message) {
+  // Note: We may want to sort the messages by timestamp if there are cases
+  // where logs are not added chronologically.
+  log_messages_.push_back(log_message);
+  if (log_messages_.size() > MaxBufferSize())
+    log_messages_.pop_front();
+}
+
+void LogBuffer::Clear() {
+  log_messages_.clear();
+}
+
+size_t LogBuffer::MaxBufferSize() const {
+  return kMaxBufferSize;
+}
+
+}  // proximity_auth
diff --git a/components/proximity_auth/logging/log_buffer.h b/components/proximity_auth/logging/log_buffer.h
new file mode 100644
index 0000000..3fefd68
--- /dev/null
+++ b/components/proximity_auth/logging/log_buffer.h
@@ -0,0 +1,64 @@
+// Copyright 2015 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 COMPONENTS_PROXIMITY_AUTH_LOGGING_LOG_BUFFER_H
+#define COMPONENTS_PROXIMITY_AUTH_LOGGING_LOG_BUFFER_H
+
+#include <list>
+
+#include "base/logging.h"
+#include "base/macros.h"
+#include "base/time/time.h"
+
+namespace proximity_auth {
+
+// Contains logs specific to the Proximity Auth. This buffer has a maximum size
+// and will discard entries in FIFO order.
+// Call LogBuffer::GetInstance() to get the global LogBuffer instance.
+class LogBuffer {
+ public:
+  // Represents a single log entry in the log buffer.
+  struct LogMessage {
+    const std::string text;
+    const base::Time time;
+    const std::string file;
+    const int line;
+    const logging::LogSeverity severity;
+
+    LogMessage(const std::string& text,
+               const base::Time& time,
+               const std::string& file,
+               int line,
+               logging::LogSeverity severity);
+  };
+
+  LogBuffer();
+  ~LogBuffer();
+
+  // Returns the global instance.
+  static LogBuffer* GetInstance();
+
+  // Adds a new log message to the buffer. If the number of log messages exceeds
+  // the maximum, then the earliest added log will be removed.
+  void AddLogMessage(const LogMessage& log_message);
+
+  // Clears all logs in the buffer.
+  void Clear();
+
+  // Returns the maximum number of logs that can be stored.
+  size_t MaxBufferSize() const;
+
+  // Returns the list logs in the buffer, sorted chronologically.
+  const std::list<LogMessage>* logs() { return &log_messages_; }
+
+ private:
+  // The messages currently in the buffer.
+  std::list<LogMessage> log_messages_;
+
+  DISALLOW_COPY_AND_ASSIGN(LogBuffer);
+};
+
+}  // namespace proximity_auth
+
+#endif  // COMPONENTS_PROXIMITY_AUTH_LOGGING_LOG_BUFFER_H
diff --git a/components/proximity_auth/logging/logging.cc b/components/proximity_auth/logging/logging.cc
new file mode 100644
index 0000000..544904a
--- /dev/null
+++ b/components/proximity_auth/logging/logging.cc
@@ -0,0 +1,27 @@
+// Copyright 2015 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 "components/proximity_auth/logging/logging.h"
+
+#include "components/proximity_auth/logging/log_buffer.h"
+
+namespace proximity_auth {
+
+ScopedLogMessage::ScopedLogMessage(const char* file,
+                                   int line,
+                                   logging::LogSeverity severity)
+    : file_(file), line_(line), severity_(severity) {
+}
+
+ScopedLogMessage::~ScopedLogMessage() {
+  LogBuffer::GetInstance()->AddLogMessage(LogBuffer::LogMessage(
+      stream_.str(), base::Time::Now(), file_, line_, severity_));
+
+  // The destructor of |log_message| also creates a log for the standard logging
+  // system.
+  logging::LogMessage log_message(file_, line_, severity_);
+  log_message.stream() << stream_.str();
+}
+
+}  // proximity_auth
diff --git a/components/proximity_auth/logging/logging.h b/components/proximity_auth/logging/logging.h
new file mode 100644
index 0000000..0d3abfa
--- /dev/null
+++ b/components/proximity_auth/logging/logging.h
@@ -0,0 +1,50 @@
+// Copyright 2015 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 COMPONENTS_PROXIMITY_AUTH_LOGGING_LOGGING_H
+#define COMPONENTS_PROXIMITY_AUTH_LOGGING_LOGGING_H
+
+#include <sstream>
+
+#include "base/logging.h"
+
+namespace proximity_auth {
+
+// Use the PA_LOG() macro for all logging related to Proximity Auth, so the
+// system is aware of all logs related to this feature. We display these logs in
+// the debug WebUI (chrome://proximity-auth).
+//
+// PA_LOG() has the same interface as the standard LOG() macro and also creates
+// a normal log message of the same severity.
+// Examples:
+//   PA_LOG(INFO) << "Waiting for " << x << " pending requests.";
+//   PA_LOG(ERROR) << "Request failed: " << error_string;
+#define PA_LOG(severity)                               \
+  proximity_auth::ScopedLogMessage(__FILE__, __LINE__, \
+                                   logging::LOG_##severity).stream()
+
+// An intermediate object used by the PA_LOG macro, wrapping a
+// logging::LogMessage instance. When this object is destroyed, the message will
+// be logged with the standard logging system and also added to Proximity Auth
+// specific log buffer.  You should use the PA_LOG() macro instead of this class
+// directly.
+class ScopedLogMessage {
+ public:
+  ScopedLogMessage(const char* file, int line, logging::LogSeverity severity);
+  ~ScopedLogMessage();
+
+  std::ostream& stream() { return stream_; }
+
+ private:
+  const char* file_;
+  int line_;
+  logging::LogSeverity severity_;
+  std::ostringstream stream_;
+
+  DISALLOW_COPY_AND_ASSIGN(ScopedLogMessage);
+};
+
+}  // namespace proximity_auth
+
+#endif  // COMPONENTS_PROXIMITY_AUTH_LOGGING_LOGGING_H
diff --git a/components/proximity_auth/logging/logging_unittest.cc b/components/proximity_auth/logging/logging_unittest.cc
new file mode 100644
index 0000000..513436e
--- /dev/null
+++ b/components/proximity_auth/logging/logging_unittest.cc
@@ -0,0 +1,117 @@
+// Copyright 2015 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 "components/proximity_auth/logging/logging.h"
+
+#include "base/lazy_instance.h"
+#include "base/numerics/safe_conversions.h"
+#include "base/strings/string_number_conversions.h"
+#include "components/proximity_auth/logging/log_buffer.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace proximity_auth {
+
+namespace {
+
+const char kLog1[] = "Mahogony destined to make a sturdy table";
+const char kLog2[] = "Construction grade cedar";
+const char kLog3[] = "Pine infested by hungry beetles";
+
+// Called for every log message added to the standard logging system. The new
+// log is saved in |g_standard_logs| and consumed so it does not flood stdout.
+base::LazyInstance<std::vector<std::string>> g_standard_logs =
+    LAZY_INSTANCE_INITIALIZER;
+bool HandleStandardLogMessage(int severity,
+                              const char* file,
+                              int line,
+                              size_t message_start,
+                              const std::string& str) {
+  g_standard_logs.Get().push_back(str);
+  return true;
+}
+
+}  // namespace
+
+class ProximityAuthLoggingTest : public testing::Test {
+ public:
+  ProximityAuthLoggingTest() : previous_handler_(NULL) {}
+
+  void SetUp() override {
+    LogBuffer::GetInstance()->Clear();
+    g_standard_logs.Get().clear();
+
+    previous_handler_ = logging::GetLogMessageHandler();
+    logging::SetLogMessageHandler(&HandleStandardLogMessage);
+  }
+
+  void TearDown() override { logging::SetLogMessageHandler(previous_handler_); }
+
+ private:
+  logging::LogMessageHandlerFunction previous_handler_;
+};
+
+TEST_F(ProximityAuthLoggingTest, LogsSavedToBuffer) {
+  int base_line_number = __LINE__;
+  PA_LOG(INFO) << kLog1;
+  PA_LOG(WARNING) << kLog2;
+  PA_LOG(ERROR) << kLog3;
+
+  auto logs = LogBuffer::GetInstance()->logs();
+  ASSERT_EQ(3u, logs->size());
+
+  auto iterator = logs->begin();
+  const LogBuffer::LogMessage& log_message1 = *iterator;
+  EXPECT_EQ(kLog1, log_message1.text);
+  EXPECT_EQ(__FILE__, log_message1.file);
+  EXPECT_EQ(base_line_number + 1, log_message1.line);
+  EXPECT_EQ(logging::LOG_INFO, log_message1.severity);
+
+  ++iterator;
+  const LogBuffer::LogMessage& log_message2 = *iterator;
+  EXPECT_EQ(kLog2, log_message2.text);
+  EXPECT_EQ(__FILE__, log_message2.file);
+  EXPECT_EQ(base_line_number + 2, log_message2.line);
+  EXPECT_EQ(logging::LOG_WARNING, log_message2.severity);
+
+  ++iterator;
+  const LogBuffer::LogMessage& log_message3 = *iterator;
+  EXPECT_EQ(kLog3, log_message3.text);
+  EXPECT_EQ(__FILE__, log_message3.file);
+  EXPECT_EQ(base_line_number + 3, log_message3.line);
+  EXPECT_EQ(logging::LOG_ERROR, log_message3.severity);
+}
+
+TEST_F(ProximityAuthLoggingTest, LogWhenBufferIsFull) {
+  LogBuffer* log_buffer = LogBuffer::GetInstance();
+  EXPECT_EQ(0u, log_buffer->logs()->size());
+
+  for (size_t i = 0; i < log_buffer->MaxBufferSize(); ++i) {
+    PA_LOG(INFO) << "log " << i;
+  }
+
+  EXPECT_EQ(log_buffer->MaxBufferSize(), log_buffer->logs()->size());
+  PA_LOG(INFO) << kLog1;
+  EXPECT_EQ(log_buffer->MaxBufferSize(), log_buffer->logs()->size());
+
+  auto iterator = log_buffer->logs()->begin();
+  for (size_t i = 0; i < log_buffer->MaxBufferSize() - 1; ++iterator, ++i) {
+    std::string expected_text =
+        "log " + base::IntToString(base::saturated_cast<int>(i + 1));
+    EXPECT_EQ(expected_text, (*iterator).text);
+  }
+  EXPECT_EQ(kLog1, (*iterator).text);
+}
+
+TEST_F(ProximityAuthLoggingTest, StandardLogsCreated) {
+  PA_LOG(INFO) << kLog1;
+  PA_LOG(WARNING) << kLog2;
+  PA_LOG(ERROR) << kLog3;
+
+  ASSERT_EQ(3u, g_standard_logs.Get().size());
+  EXPECT_NE(std::string::npos, g_standard_logs.Get()[0].find(kLog1));
+  EXPECT_NE(std::string::npos, g_standard_logs.Get()[1].find(kLog2));
+  EXPECT_NE(std::string::npos, g_standard_logs.Get()[2].find(kLog3));
+}
+
+}  // namespace proximity_auth