Fix device_event_log component build, make NonThreadSafe (Take 2)

This patch includes the correct GN changes.

This CL does the following:
* Fixes the component build
* Limits the length of LogEntry strings
* Cleans up the code a little to help with crash debugging

BUG=479095
For device_event_log gypi:
TBR=reillyg@chromium.org

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

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

chrome/browser/chrome_browser_main.cc

@@ -797,14 +797,19 @@ void ChromeBrowserMainParts::ToolkitInitialized() {
 void ChromeBrowserMainParts::PreMainMessageLoopStart() {
   TRACE_EVENT0("startup", "ChromeBrowserMainParts::PreMainMessageLoopStart");
 
-  device_event_log::Initialize(0 /* default max entries */);
-
   for (size_t i = 0; i < chrome_extra_parts_.size(); ++i)
     chrome_extra_parts_[i]->PreMainMessageLoopStart();
 }
 
 void ChromeBrowserMainParts::PostMainMessageLoopStart() {
   TRACE_EVENT0("startup", "ChromeBrowserMainParts::PostMainMessageLoopStart");
+
+  // device_event_log must be initialized after the message loop. Calls to
+  // {DEVICE}_LOG prior to here will only be logged with VLOG. Some
+  // platforms (e.g. chromeos) may have already initialized this.
+  if (!device_event_log::IsInitialized())
+    device_event_log::Initialize(0 /* default max entries */);
+
   for (size_t i = 0; i < chrome_extra_parts_.size(); ++i)
     chrome_extra_parts_[i]->PostMainMessageLoopStart();
 }

chrome/browser/chromeos/chrome_browser_main_chromeos.cc

@@ -109,6 +109,7 @@
 #include "chromeos/network/network_handler.h"
 #include "chromeos/system/statistics_provider.h"
 #include "chromeos/tpm/tpm_token_loader.h"
+#include "components/device_event_log/device_event_log.h"
 #include "components/metrics/metrics_service.h"
 #include "components/ownership/owner_key_util.h"
 #include "components/session_manager/core/session_manager.h"
@@ -310,6 +311,9 @@ void ChromeBrowserMainPartsChromeos::PreMainMessageLoopStart() {
 }
 
 void ChromeBrowserMainPartsChromeos::PostMainMessageLoopStart() {
+  // device_event_log must be initialized after the message loop.
+  device_event_log::Initialize(0 /* default max entries */);
+
   base::FilePath user_data_dir;
   if (!base::SysInfo::IsRunningOnChromeOS() &&
       PathService::Get(chrome::DIR_USER_DATA, &user_data_dir)) {

components/device_event_log.gypi

@@ -6,7 +6,7 @@
   'targets': [
     {
       'target_name': 'device_event_log_component',
-      'type': 'static_library',
+      'type': '<(component)',
       'dependencies': [
         '../base/base.gyp:base',
         '../net/net.gyp:net',
@@ -14,6 +14,9 @@
       'include_dirs': [
         '..',
       ],
+      'defines': [
+        'DEVICE_EVENT_LOG_IMPLEMENTATION',
+      ],
       'sources': [
         'device_event_log/device_event_log.cc',
         'device_event_log/device_event_log.h',

components/device_event_log/BUILD.gn

@@ -2,7 +2,7 @@
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
-source_set("device_event_log") {
+component("device_event_log") {
   sources = [
     "device_event_log.cc",
     "device_event_log.h",
@@ -10,6 +10,8 @@ source_set("device_event_log") {
     "device_event_log_impl.h",
   ]
 
+  defines = [ "DEVICE_EVENT_LOG_IMPLEMENTATION" ]
+
   deps = [
     "//base",
     "//net",

components/device_event_log/device_event_log.cc

@@ -7,6 +7,7 @@
 #include <string>
 
 #include "base/logging.h"
+#include "base/thread_task_runner_handle.h"
 #include "components/device_event_log/device_event_log_impl.h"
 
 namespace device_event_log {
@@ -28,7 +29,12 @@ void Initialize(size_t max_entries) {
   CHECK(!g_device_event_log);
   if (max_entries == 0)
     max_entries = kDefaultMaxEntries;
-  g_device_event_log = new DeviceEventLogImpl(max_entries);
+  g_device_event_log =
+      new DeviceEventLogImpl(base::ThreadTaskRunnerHandle::Get(), max_entries);
+}
+
+bool IsInitialized() {
+  return !!g_device_event_log;
 }
 
 void Shutdown() {

components/device_event_log/device_event_log.h

@@ -11,13 +11,20 @@
 #include "base/basictypes.h"
 #include "base/logging.h"
 #include "base/timer/elapsed_timer.h"
+#include "components/device_event_log/device_event_log_export.h"
 
 // These macros can be used to log device related events.
+//
+// NOTE: If these macros are called from a thread other than the thread that
+// device_event_log::Initialize() was called from (i.e. the UI thread), a task
+// will be posted to the UI thread to log the event.
+//
 // The following values should be used for |level| in these macros:
 //  ERROR Unexpected events, or device level failures. Use sparingly.
 //  USER  Events initiated directly by a user (or Chrome) action.
 //  EVENT Default event type.
 //  DEBUG Debugging details that are usually not interesting.
+//
 // Examples:
 //  NET_LOG(EVENT) << "NetworkState Changed " << name << ": " << state;
 //  POWER_LOG(USER) << "Suspend requested";
@@ -100,27 +107,28 @@ enum StringOrder { OLDEST_FIRST, NEWEST_FIRST };
 
 // Initializes / shuts down device event logging. If |max_entries| = 0 the
 // default value will be used.
-void Initialize(size_t max_entries);
-void Shutdown();
+void DEVICE_EVENT_LOG_EXPORT Initialize(size_t max_entries);
+bool DEVICE_EVENT_LOG_EXPORT IsInitialized();
+void DEVICE_EVENT_LOG_EXPORT Shutdown();
 
 // If the global instance is initialized, adds an entry to it. Regardless of
 // whether the global instance was intitialzed, this logs the event to
 // LOG(ERROR) if |type| = ERROR or VLOG(1) otherwise.
-void AddEntry(const char* file,
-              int line,
-              LogType type,
-              LogLevel level,
-              const std::string& event);
+void DEVICE_EVENT_LOG_EXPORT AddEntry(const char* file,
+                                      int line,
+                                      LogType type,
+                                      LogLevel level,
+                                      const std::string& event);
 
 // For backwards compatibility with network_event_log. Combines |event| and
 // |description| and calls AddEntry().
-void AddEntryWithDescription(
-    const char* file,
-    int line,
-    LogType type,
-    LogLevel level,
-    const std::string& event,
-    const std::string& description);
+void DEVICE_EVENT_LOG_EXPORT
+AddEntryWithDescription(const char* file,
+                        int line,
+                        LogType type,
+                        LogLevel level,
+                        const std::string& event,
+                        const std::string& description);
 
 // Outputs the log to a formatted string.
 // |order| determines which order to output the events.
@@ -138,20 +146,20 @@ void AddEntryWithDescription(
 // |max_level| determines the maximum log level to be included in the output.
 // |max_events| limits how many events are output if > 0, otherwise all events
 //  are included.
-std::string GetAsString(StringOrder order,
-                        const std::string& format,
-                        const std::string& types,
-                        LogLevel max_level,
-                        size_t max_events);
+std::string DEVICE_EVENT_LOG_EXPORT GetAsString(StringOrder order,
+                                                const std::string& format,
+                                                const std::string& types,
+                                                LogLevel max_level,
+                                                size_t max_events);
 
-extern const LogLevel kDefaultLogLevel;
+DEVICE_EVENT_LOG_EXPORT extern const LogLevel kDefaultLogLevel;
 
 namespace internal {
 
 // Implementation class for DEVICE_LOG macros. Provides a stream for creating
 // a log string and adds the event using device_event_log::AddEntry on
 // destruction.
-class DeviceEventLogInstance {
+class DEVICE_EVENT_LOG_EXPORT DeviceEventLogInstance {
  public:
   DeviceEventLogInstance(const char* file,
                          int line,
@@ -174,7 +182,7 @@ class DeviceEventLogInstance {
 // Implementation class for DEVICE_PLOG macros. Provides a stream for creating
 // a log string and adds the event, including system error code, using
 // device_event_log::AddEntry on destruction.
-class DeviceEventSystemErrorLogInstance {
+class DEVICE_EVENT_LOG_EXPORT DeviceEventSystemErrorLogInstance {
  public:
   DeviceEventSystemErrorLogInstance(const char* file,
                                     int line,
@@ -198,7 +206,7 @@ class DeviceEventSystemErrorLogInstance {
 // Implementation class for SCOPED_LOG_IF_SLOW macros. Tests the elapsed time on
 // destruction and adds a Debug or Error log entry if it exceeds the
 // corresponding expected maximum elapsed time.
-class ScopedDeviceLogIfSlow {
+class DEVICE_EVENT_LOG_EXPORT ScopedDeviceLogIfSlow {
  public:
   ScopedDeviceLogIfSlow(LogType type,
                         const char* file,

components/device_event_log/device_event_log_export.h

+// 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_DEVICE_EVENT_LOG_DEVICE_EVENT_LOG_EXPORT_H_
+#define COMPONENTS_DEVICE_EVENT_LOG_DEVICE_EVENT_LOG_EXPORT_H_
+
+#if defined(COMPONENT_BUILD)
+
+#if defined(WIN32)
+
+#if defined(DEVICE_EVENT_LOG_IMPLEMENTATION)
+#define DEVICE_EVENT_LOG_EXPORT __declspec(dllexport)
+#else
+#define DEVICE_EVENT_LOG_EXPORT __declspec(dllimport)
+#endif  // defined(DEVICE_EVENT_LOG_IMPLEMENTATION)
+
+#else  // defined(WIN32)
+
+#if defined(DEVICE_EVENT_LOG_IMPLEMENTATION)
+#define DEVICE_EVENT_LOG_EXPORT __attribute__((visibility("default")))
+#else
+#define DEVICE_EVENT_LOG_EXPORT
+#endif  // defined(DEVICE_EVENT_LOG_IMPLEMENTATION)
+
+#endif  // defined(WIN32)
+
+#else  // defined(COMPONENT_BUILD)
+
+#define DEVICE_EVENT_LOG_EXPORT
+
+#endif
+
+#endif  // COMPONENTS_DEVICE_EVENT_LOG_DEVICE_EVENT_LOG_EXPORT_H_

components/device_event_log/device_event_log_impl.cc

@@ -8,9 +8,11 @@
 #include <list>
 #include <set>
 
+#include "base/bind.h"
 #include "base/containers/adapters.h"
 #include "base/json/json_string_value_serializer.h"
 #include "base/json/json_writer.h"
+#include "base/location.h"
 #include "base/logging.h"
 #include "base/memory/scoped_ptr.h"
 #include "base/strings/string_tokenizer.h"
@@ -247,6 +249,14 @@ void GetLogTypes(const std::string& types,
   }
 }
 
+// Update count and time for identical events to avoid log spam.
+void IncreaseLogEntryCount(const DeviceEventLogImpl::LogEntry& new_entry,
+                           DeviceEventLogImpl::LogEntry* cur_entry) {
+  ++cur_entry->count;
+  cur_entry->log_level = std::min(cur_entry->log_level, new_entry.log_level);
+  cur_entry->time = base::Time::Now();
+}
+
 }  // namespace
 
 // static
@@ -259,8 +269,13 @@ void DeviceEventLogImpl::SendToVLogOrErrorLog(const char* file,
   SendLogEntryToVLogOrErrorLog(entry);
 }
 
-DeviceEventLogImpl::DeviceEventLogImpl(size_t max_entries)
-    : max_entries_(max_entries) {
+DeviceEventLogImpl::DeviceEventLogImpl(
+    scoped_refptr<base::SingleThreadTaskRunner> task_runner,
+    size_t max_entries)
+    : task_runner_(task_runner),
+      max_entries_(max_entries),
+      weak_ptr_factory_(this) {
+  DCHECK(task_runner_);
 }
 
 DeviceEventLogImpl::~DeviceEventLogImpl() {
@@ -272,47 +287,55 @@ void DeviceEventLogImpl::AddEntry(const char* file,
                                   LogLevel log_level,
                                   const std::string& event) {
   LogEntry entry(file, file_line, log_type, log_level, event);
+  if (!task_runner_->RunsTasksOnCurrentThread()) {
+    task_runner_->PostTask(FROM_HERE,
+                           base::Bind(&DeviceEventLogImpl::AddLogEntry,
+                                      weak_ptr_factory_.GetWeakPtr(), entry));
+    return;
+  }
   AddLogEntry(entry);
 }
 
 void DeviceEventLogImpl::AddLogEntry(const LogEntry& entry) {
+  DCHECK(task_runner_->RunsTasksOnCurrentThread());
   if (!entries_.empty()) {
     LogEntry& last = entries_.back();
     if (LogEntryMatches(last, entry)) {
-      // Update count and time for identical events to avoid log spam.
-      ++last.count;
-      last.log_level = std::min(last.log_level, entry.log_level);
-      last.time = base::Time::Now();
+      IncreaseLogEntryCount(entry, &last);
       return;
     }
   }
-  if (entries_.size() >= max_entries_) {
-    const size_t max_error_entries = max_entries_ / 2;
-    // Remove the first (oldest) non-error entry, or the oldest entry if more
-    // than half the entries are errors.
-    size_t error_count = 0;
-    for (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end();
-         ++iter) {
-      if (iter->log_level != LOG_LEVEL_ERROR) {
-        entries_.erase(iter);
-        break;
-      }
-      if (++error_count > max_error_entries) {
-        // Too many error entries, remove the oldest entry.
-        entries_.pop_front();
-        break;
-      }
-    }
-  }
+  if (entries_.size() >= max_entries_)
+    RemoveEntry();
   entries_.push_back(entry);
   SendLogEntryToVLogOrErrorLog(entry);
 }
 
+void DeviceEventLogImpl::RemoveEntry() {
+  const size_t max_error_entries = max_entries_ / 2;
+  DCHECK(max_error_entries < entries_.size());
+  // Remove the first (oldest) non-error entry, or the oldest entry if more
+  // than half the entries are errors.
+  size_t error_count = 0;
+  for (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end();
+       ++iter) {
+    if (iter->log_level != LOG_LEVEL_ERROR) {
+      entries_.erase(iter);
+      return;
+    }
+    if (++error_count > max_error_entries)
+      break;
+  }
+  // Too many error entries, remove the oldest entry.
+  entries_.pop_front();
+}
+
 std::string DeviceEventLogImpl::GetAsString(StringOrder order,
                                             const std::string& format,
                                             const std::string& types,
                                             LogLevel max_level,
                                             size_t max_events) {
+  DCHECK(task_runner_->RunsTasksOnCurrentThread());
   if (entries_.empty())
     return "No Log Entries.";
 

components/device_event_log/device_event_log_impl.h

@@ -8,12 +8,16 @@
 #include <list>
 #include <string>
 
+#include "base/memory/ref_counted.h"
+#include "base/memory/weak_ptr.h"
+#include "base/single_thread_task_runner.h"
 #include "base/time/time.h"
 #include "components/device_event_log/device_event_log.h"
 
 namespace device_event_log {
 
-class DeviceEventLogImpl {
+// Implementation class for DEVICE_LOG.
+class DEVICE_EVENT_LOG_EXPORT DeviceEventLogImpl {
  public:
   struct LogEntry {
     LogEntry(const char* filedesc,
@@ -31,7 +35,9 @@ class DeviceEventLogImpl {
     int count;
   };
 
-  explicit DeviceEventLogImpl(size_t max_entries);
+  explicit DeviceEventLogImpl(
+      scoped_refptr<base::SingleThreadTaskRunner> task_runner,
+      size_t max_entries);
   ~DeviceEventLogImpl();
 
   // Implements device_event_log::AddEntry.
@@ -62,13 +68,16 @@ class DeviceEventLogImpl {
   typedef std::list<LogEntry> LogEntryList;
 
   void AddLogEntry(const LogEntry& entry);
+  void RemoveEntry();
 
   // For testing
   size_t max_entries() const { return max_entries_; }
   void set_max_entries_for_test(size_t entries) { max_entries_ = entries; }
 
+  scoped_refptr<base::SingleThreadTaskRunner> task_runner_;
   size_t max_entries_;
   LogEntryList entries_;
+  base::WeakPtrFactory<DeviceEventLogImpl> weak_ptr_factory_;
 
   DISALLOW_COPY_AND_ASSIGN(DeviceEventLogImpl);
 };

components/device_event_log/device_event_log_impl_unittest.cc

@@ -5,6 +5,7 @@
 #include "components/device_event_log/device_event_log_impl.h"
 
 #include <algorithm>
+#include <string>
 
 #include "base/basictypes.h"
 #include "base/compiler_specific.h"
@@ -12,6 +13,7 @@
 #include "base/memory/scoped_ptr.h"
 #include "base/strings/string_split.h"
 #include "base/strings/stringprintf.h"
+#include "base/test/test_simple_task_runner.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 namespace device_event_log {
@@ -21,15 +23,29 @@ namespace {
 const size_t kDefaultMaxEvents = 100;
 LogLevel kDefaultLevel = LOG_LEVEL_EVENT;
 LogType kDefaultType = LOG_TYPE_NETWORK;
+const char kFileName[] = "file";
+
+// Calls GetAsString on the task thread and sets s_string_result. Make sure
+// that task_runner_->RunUntilIdle() is called before using s_string_result.
+std::string s_string_result;
+void CallGetAsString(DeviceEventLogImpl* impl,
+                     StringOrder order,
+                     const std::string& format,
+                     const std::string& types,
+                     LogLevel max_level,
+                     size_t max_events) {
+  s_string_result =
+      impl->GetAsString(order, format, types, max_level, max_events);
+}
 
 }  // namespace
 
 class DeviceEventLogTest : public testing::Test {
  public:
-  DeviceEventLogTest() {}
+  DeviceEventLogTest() : task_runner_(new base::TestSimpleTaskRunner()) {}
 
   void SetUp() override {
-    impl_.reset(new DeviceEventLogImpl(kDefaultMaxEvents));
+    impl_.reset(new DeviceEventLogImpl(task_runner_, kDefaultMaxEvents));
   }
 
   void TearDown() override { impl_.reset(); }
@@ -53,19 +69,32 @@ class DeviceEventLogTest : public testing::Test {
     return std::count(input.begin(), input.end(), '\n');
   }
 
+  std::string GetAsString(StringOrder order,
+                          const std::string& format,
+                          const std::string& types,
+                          LogLevel max_level,
+                          size_t max_events) {
+    task_runner_->PostTask(
+        FROM_HERE,
+        base::Bind(&CallGetAsString,
+                   impl_.get(), order, format, types, max_level, max_events));
+    task_runner_->RunUntilIdle();
+    return s_string_result;
+  }
+
   std::string GetLogString(StringOrder order,
                            const std::string& format,
                            LogLevel max_level,
                            size_t max_events) {
-    return impl_->GetAsString(order, format, "", max_level, max_events);
+    return GetAsString(order, format, "", max_level, max_events);
   }
 
   std::string GetOrderedString(StringOrder order, size_t max_events) {
-    return impl_->GetAsString(order, "file", "", kDefaultLevel, max_events);
+    return GetAsString(order, "file", "", kDefaultLevel, max_events);
   }
 
   std::string GetLogStringForType(const std::string& types) {
-    return impl_->GetAsString(OLDEST_FIRST, "type", types, kDefaultLevel, 0);
+    return GetAsString(OLDEST_FIRST, "type", types, kDefaultLevel, 0);
   }
 
   void AddNetworkEntry(const char* file,
@@ -73,18 +102,21 @@ class DeviceEventLogTest : public testing::Test {
                        LogLevel level,
                        const std::string& event) {
     impl_->AddEntry(file, line, kDefaultType, level, event);
+    task_runner_->RunUntilIdle();
   }
 
   void AddTestEvent(LogLevel level, const std::string& event) {
-    AddNetworkEntry("file", 0, level, event);
+    AddNetworkEntry(kFileName, 0, level, event);
   }
 
   void AddEventType(LogType type, const std::string& event) {
-    impl_->AddEntry("file", 0, type, kDefaultLevel, event);
+    impl_->AddEntry(kFileName, 0, type, kDefaultLevel, event);
+    task_runner_->RunUntilIdle();
   }
 
   size_t GetMaxEntries() const { return impl_->max_entries(); }
 
+  scoped_refptr<base::TestSimpleTaskRunner> task_runner_;
   scoped_ptr<DeviceEventLogImpl> impl_;
 
  private:
@@ -96,10 +128,13 @@ TEST_F(DeviceEventLogTest, TestNetworkEvents) {
   EXPECT_EQ("No Log Entries.", output_none);
 
   LogLevel level = kDefaultLevel;
-  AddNetworkEntry("file1", 1, level, "event1");
-  AddNetworkEntry("file2", 2, level, "event2");
-  AddNetworkEntry("file3", 3, level, "event3");
-  AddNetworkEntry("file3", 3, level, "event3");
+  static const char kFile1[] = "file1";
+  static const char kFile2[] = "file2";
+  static const char kFile3[] = "file3";
+  AddNetworkEntry(kFile1, 1, level, "event1");
+  AddNetworkEntry(kFile2, 2, level, "event2");
+  AddNetworkEntry(kFile3, 3, level, "event3");
+  AddNetworkEntry(kFile3, 3, level, "event3");
 
   const std::string expected_output_oldest_first(
       "file1:1 event1\n"
@@ -223,7 +258,7 @@ TEST_F(DeviceEventLogTest, TestMaxEvents) {
 
 TEST_F(DeviceEventLogTest, TestMaxErrors) {
   const int kMaxTestEntries = 4;
-  impl_.reset(new DeviceEventLogImpl(kMaxTestEntries));
+  impl_.reset(new DeviceEventLogImpl(task_runner_, kMaxTestEntries));
   AddTestEvent(LOG_LEVEL_EVENT, "event1");
   AddTestEvent(LOG_LEVEL_ERROR, "error2");
   AddTestEvent(LOG_LEVEL_EVENT, "event3");