Allow multiple logging::LogMessage{Handler,Listener}s

base/logging.cc

 // Copyright (c) 2012 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/logging.h"
 
 #include <limits.h>
 #include <stdint.h>
 
 #include "base/macros.h"
@@ skipping 31 matching lines @@
 #include <sys/stat.h>
 #include <unistd.h>
 #define MAX_PATH PATH_MAX
 typedef FILE* FileHandle;
 typedef pthread_mutex_t* MutexHandle;
 #endif
 
 #include <algorithm>
 #include <cstring>
 #include <ctime>
+#include <deque>
 #include <iomanip>
 #include <ostream>
 #include <string>
+#include <unordered_set>
 
 #include "base/base_switches.h"
 #include "base/command_line.h"
 #include "base/debug/alias.h"
 #include "base/debug/debugger.h"
 #include "base/debug/stack_trace.h"
+#include "base/lazy_instance.h"
 #include "base/posix/eintr_wrapper.h"
 #include "base/strings/string_piece.h"
 #include "base/strings/string_util.h"
 #include "base/strings/stringprintf.h"
 #include "base/strings/sys_string_conversions.h"
 #include "base/strings/utf_string_conversions.h"
 #include "base/synchronization/lock_impl.h"
 #include "base/threading/platform_thread.h"
 #include "base/vlog.h"
 #if defined(OS_POSIX)
@@ skipping 45 matching lines @@
 bool g_log_thread_id = false;
 bool g_log_timestamp = true;
 bool g_log_tickcount = false;
 
 // Should we pop up fatal debug messages in a dialog?
 bool show_error_dialogs = false;
 
 // An assert handler override specified by the client to be called instead of
 // the debug message dialog and process termination.
 LogAssertHandlerFunction log_assert_handler = nullptr;
-// A log message handler that gets notified of every log message we process.
-LogMessageHandlerFunction log_message_handler = nullptr;
+// Log message handlers that get notified of every log message we process.
+base::LazyInstance<std::deque<LogMessageHandler*>>::Leaky
+    log_message_handlers = LAZY_INSTANCE_INITIALIZER;
+// Log message listeners that get notified of every log message we process
+// before log message handlers.
+base::LazyInstance<std::unordered_set<LogMessageListener*>>::Leaky

[grt (UTC plus 2), 2016/07/27 20:38:20]

why an unordered set? are there really so many listeners that you need the extra
memory overhead for O(lgN) insert/remove? vector or deque seems adequate.

[wychen, 2016/08/01 16:12:25]

The number of listeners should be very low practically, so I'm not worried about
asymptotic complexity. BTW, I think insert/remove is O(1) here. The reason I
used unordered_set is to avoid subscribers to assume ordering.
LogMessageHandlers are run in stack order, because the handlers can sink the
message. The calling order of LogMessageListeners doesn't matter from the
perspective of LogMessage, but subscribers are free to add side effects inside
the listener functions, and we don't want these side effects to depend on
certain calling order. 

[grt (UTC plus 2), 2016/08/01 21:17:44]

Ouch. Apologies for the complexity goof. I haven't looked at the implementation
of unordered set, but my guess is that it uses a hash table. If so, you're
paying the memory cost of this for a small number of elements. I don't think
this is worthwhile. It's sufficient to document that subscribers must not make
any ordering assumptions; you don't need to impose a memory penalty to avoid the
appearance of ordering. If you think the properties of a set are important, use
a std::set; otherwise, use the most lightweight container possible. My guess is
that vector fits the bill.

[wychen, 2016/08/01 23:11:03]

Unordered set does use a hash table internally. Do you think it's a good idea to
use CallbackList underneath log_message_listeners while keeping the API the
same?

[grt (UTC plus 2), 2016/08/02 07:25:46]

I'm a bit divided. On the one hand, I prefer callbacks to single-method
interfaces. On the other hand, the subscription aspect of CallbackList can be a
little clunky to work with and you'd have to introduce Add/Remove methods. I'm
okay with keeping the interface as it is.

[wychen, 2016/08/04 03:53:55]

I meant keeping the single-method interface as is, but it uses CallbackList
internally. It is still scope-based from the users' perspective, and we don't
need to introduce add/remove methods. We add a callback in the constructor of
LogMessageListener, and the registration object would be in unique_ptr<> as a
member data. The unregistration would happen in destruction time automatically.

I think this is better than using locks like what I did.

+    log_message_listeners = LAZY_INSTANCE_INITIALIZER;
 
 // Helper functions to wrap platform differences.
 
 int32_t CurrentProcessId() {
 #if defined(OS_WIN)
   return GetCurrentProcessId();
 #elif defined(OS_POSIX)
   return getpid();
 #endif
 }
@@ skipping 197 matching lines @@
 void CloseLogFileUnlocked() {
   if (!g_log_file)
     return;
 
   CloseFile(g_log_file);
   g_log_file = nullptr;
 }
 
 }  // namespace
 
+LogMessageHandler::LogMessageHandler() {
+  log_message_handlers.Get().push_front(this);
+}
+
+LogMessageHandler::~LogMessageHandler() {
+  auto& handlers = log_message_handlers.Get();
+  unsigned count = handlers.size();

[grt (UTC plus 2), 2016/07/27 20:38:20]

size_t

[wychen, 2016/08/01 16:12:25]

Done.

+  handlers.erase(std::remove(handlers.begin(), handlers.end(), this),
+      handlers.end());
+  DCHECK_EQ(count - 1, handlers.size());
+}
+
+unsigned LogMessageHandlerCountForTesting() {
+  return log_message_handlers.Get().size();
+}
+
+LogMessageListener::LogMessageListener() {
+  log_message_listeners.Get().insert(this);
+}
+
+LogMessageListener::~LogMessageListener() {
+  DCHECK_EQ(1u, log_message_listeners.Get().erase(this));
+}
+
+unsigned LogMessageListenerCountForTesting() {
+  return log_message_listeners.Get().size();
+}
+
 LoggingSettings::LoggingSettings()
     : logging_dest(LOG_DEFAULT),
       log_file(nullptr),
       lock_log(LOCK_LOG_FILE),
       delete_old(APPEND_TO_OLD_LOG_FILE) {}
 
 bool BaseInitLoggingImpl(const LoggingSettings& settings) {
 #if defined(OS_NACL)
   // Can log only to the system debug log.
   CHECK_EQ(settings.logging_dest & ~LOG_TO_SYSTEM_DEBUG_LOG, 0);
@@ skipping 47 matching lines @@
   return g_min_log_level;
 }
 
 bool ShouldCreateLogMessage(int severity) {
   if (severity < g_min_log_level)
     return false;
 
   // Return true here unless we know ~LogMessage won't do anything. Note that
   // ~LogMessage writes to stderr if severity_ >= kAlwaysPrintErrorLevel, even
   // when g_logging_destination is LOG_NONE.
-  return g_logging_destination != LOG_NONE || log_message_handler ||
+  return g_logging_destination != LOG_NONE ||
+         !log_message_handlers.Get().empty() ||
+         !log_message_listeners.Get().empty() ||
          severity >= kAlwaysPrintErrorLevel;
 }
 
 int GetVlogVerbosity() {
   return std::max(-1, LOG_INFO - GetMinLogLevel());
 }
 
 int GetVlogLevelHelper(const char* file, size_t N) {
   DCHECK_GT(N, 0U);
   // Note: |g_vlog_info| may change on a different thread during startup
@@ skipping 13 matching lines @@
 }
 
 void SetShowErrorDialogs(bool enable_dialogs) {
   show_error_dialogs = enable_dialogs;
 }
 
 void SetLogAssertHandler(LogAssertHandlerFunction handler) {
   log_assert_handler = handler;
 }
 
-void SetLogMessageHandler(LogMessageHandlerFunction handler) {
-  log_message_handler = handler;
-}
-
-LogMessageHandlerFunction GetLogMessageHandler() {
-  return log_message_handler;
-}
-
 // Explicit instantiations for commonly used comparisons.
 template std::string* MakeCheckOpString<int, int>(
     const int&, const int&, const char* names);
 template std::string* MakeCheckOpString<unsigned long, unsigned long>(
     const unsigned long&, const unsigned long&, const char* names);
 template std::string* MakeCheckOpString<unsigned long, unsigned int>(
     const unsigned long&, const unsigned int&, const char* names);
 template std::string* MakeCheckOpString<unsigned int, unsigned long>(
     const unsigned int&, const unsigned long&, const char* names);
 template std::string* MakeCheckOpString<std::string, std::string>(
@@ skipping 66 matching lines @@
   if (severity_ == LOG_FATAL && !base::debug::BeingDebugged()) {
     // Include a stack trace on a fatal, unless a debugger is attached.
     base::debug::StackTrace trace;
     stream_ << std::endl;  // Newline to separate from log message.
     trace.OutputToStream(&stream_);
   }
 #endif
   stream_ << std::endl;
   std::string str_newline(stream_.str());
 
-  // Give any log message handler first dibs on the message.
-  if (log_message_handler &&
-      log_message_handler(severity_, file_, line_,
-                          message_start_, str_newline)) {
-    // The handler took care of it, no further processing.
-    return;
+  // Broadcast to log message listeners first.
+  for (auto* listeners : log_message_listeners.Get()) {

[grt (UTC plus 2), 2016/07/27 20:38:20]

listeners -> listener

[grt (UTC plus 2), 2016/07/28 06:28:47]

since logging may happen on any thread at any time, how are you going to
guarantee that one thread isn't adding or removing a listener/handler while
another is doing these iterations?

[wychen, 2016/08/01 16:12:25]

I've added Locks.

[wychen, 2016/08/01 16:12:25]

Done.

+    listeners->OnMessage(severity_, file_, line_, message_start_, str_newline);
+  }
+
+  // Give log message handlers first dibs on the message.
+  for (auto* handler : log_message_handlers.Get()) {
+    if (handler->OnMessage(severity_, file_, line_, message_start_,
+        str_newline)) {
+      // The handler took care of it, no further processing.
+      return;
+    }
   }
 
   if ((g_logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) != 0) {
 #if defined(OS_WIN)
     OutputDebugStringA(str_newline.c_str());
 #elif defined(OS_MACOSX)
     // In LOG_TO_SYSTEM_DEBUG_LOG mode, log messages are always written to
     // stderr. If stderr is /dev/null, also log via ASL (Apple System Log). If
     // there's something weird about stderr, assume that log messages are going
     // nowhere and log via ASL too. Messages logged via ASL show up in
@@ skipping 365 matching lines @@
 BASE_EXPORT void LogErrorNotReached(const char* file, int line) {
   LogMessage(file, line, LOG_ERROR).stream()
       << "NOTREACHED() hit.";
 }
 
 }  // namespace logging
 
 std::ostream& std::operator<<(std::ostream& out, const wchar_t* wstr) {
   return out << (wstr ? base::WideToUTF8(wstr) : std::string());
 }