Pass error messages from native messaging to web-app.

remoting/host/native_messaging/log_message_handler.cc

+// Copyright (c) 2015 The Chromium Authors. All rights reserved.

[Sergey Ulanov, 2015/08/16 23:22:02]

nit: remove (c)

[Jamie, 2015/08/17 17:32:23]

Done.

+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "remoting/host/native_messaging/log_message_handler.h"
+
+#include "base/bind.h"
+#include "base/lazy_instance.h"
+#include "base/strings/string_util.h"
+#include "base/synchronization/lock.h"
+#include "base/thread_task_runner_handle.h"
+#include "base/tracked_objects.h"
+
+namespace remoting {
+
+namespace {
+// Log message handler registration and deregistration is not thread-safe.
+// This lock must be held in order to set or restore a log message handler,
+// and when accessing the weak pointer to the LogMessageHandler instance.
+base::LazyInstance<base::Lock>::Leaky g_lock = LAZY_INSTANCE_INITIALIZER;
+
+// The singleton LogMessageHandler instance, or null if log messages are
+// not being intercepted. It must be dereferenced and updated under a lock.
+base::LazyInstance<base::WeakPtr<LogMessageHandler> >::Leaky
+    g_log_message_handler = LAZY_INSTANCE_INITIALIZER;
+}  // namespace
+
+LogMessageHandler::LogMessageHandler(
+    const Delegate& delegate)
+    : delegate_(delegate),
+      suppress_logging_(false),
+      caller_task_runner_(base::ThreadTaskRunnerHandle::Get()),
+      weak_ptr_factory_(this) {
+  base::AutoLock lock(g_lock.Get());
+  if (g_log_message_handler.Get()) {
+    LOG(FATAL) << "LogMessageHandler is already registered. Only one instance "
+               << "per process is allowed.";
+  }
+  previous_log_message_handler_ = logging::GetLogMessageHandler();
+  logging::SetLogMessageHandler(&LogMessageHandler::OnLogMessage);
+  g_log_message_handler.Get() = weak_ptr_factory_.GetWeakPtr();
+}
+
+LogMessageHandler::~LogMessageHandler() {
+  base::AutoLock lock(g_lock.Get());
+  if (logging::GetLogMessageHandler() != &LogMessageHandler::OnLogMessage) {
+    LOG(FATAL) << "LogMessageHandler is not the top-most message handler. "
+               << "Cannot unregister.";
+  }
+  logging::SetLogMessageHandler(previous_log_message_handler_);
+  g_log_message_handler.Get().reset();
+}
+
+bool LogMessageHandler::OnLogMessage(

[Sergey Ulanov, 2015/08/16 23:22:02]

add //static comment to make clear that this is a static method.

[Jamie, 2015/08/17 17:32:23]

Done.

+    logging::LogSeverity severity, const char* file, int line,
+    size_t message_start, const std::string& str) {
+  base::AutoLock lock(g_lock.Get());
+  if (g_log_message_handler.Get()) {

[Sergey Ulanov, 2015/08/16 23:22:02]

WeakPtr can be deferenced only on one thread, so you can't check it here. I
realize that there is a lock, but there is a DCHECK in WeakPtr implementations
for threads. I don't think you really need WeakPtr. You can store a raw pointer
- it's reset in the destructor anyway.

[Jamie, 2015/08/17 17:32:23]

Doesn't that introduce a race if the LogMessageHandler is being destroyed on one
thread while another thread is logging? If OnLogMessage wins the race and grabs
the lock before the dtor, then by the time the message is processed on the other
thread, it will be invoking it on a dead object. This doesn't seem like a
particularly uncommon pattern; is there a standard solution?

[Sergey Ulanov, 2015/08/17 21:01:16]

You can still post the task using weak pointer. PostLogMessageToCorrectThread()
already calls GetWeakPtr() to post the task. That's safe because it doesn't
require dereferencing the pointer. You just can't call WeakPtr::Get() on other
threads.
g_log_message_handler is only used with g_lock held, so it doesn't need to be a
weak pointer.

[Jamie, 2015/08/17 21:23:35]

Done.

+    g_log_message_handler.Get()->PostLogMessageToCorrectThread(
+        severity, file, line, message_start, str);
+  }
+  return false;
+}
+
+void LogMessageHandler::PostLogMessageToCorrectThread(
+    logging::LogSeverity severity, const char* file, int line,
+    size_t message_start, const std::string& str) {

[Sergey Ulanov, 2015/08/16 23:22:02]

nit: one parameter per line please

[Jamie, 2015/08/17 17:32:23]

Done.

+  // Don't process this message if we're already logging. This guards against
+  // an infinite loop if any code called by this class logs something. Note
+  // that this will also suppress messages logged on other threads while any
+  // message is being processed; this is an acceptable trade-off.
+  if (suppress_logging_) {

[Sergey Ulanov, 2015/08/16 23:22:02]

I think this is necessary only on the caller thread, where suppress_logging_ is
set. I.e. you need caller_task_runner_->BelongsToCurrentThread() condition here.

[Jamie, 2015/08/17 17:32:24]

Done.

+    return;
+  }
+
+  // This method is always called under the global lock, so post a task to
+  // handle the log message, even if we're already on the correct thread.
+  // This alows the lock to be released quickly.

[Sergey Ulanov, 2015/08/16 23:22:02]

One downside of this approach is that LOG_FATAL errors will always be lost.
That's not a big issue here because the messages will still show up in stderr
(unlike the client plugin). Still worth calling it out here in the comment.

Potentially this can be fixed. E.g. even just writing all messages synchronously
(with a lock) would be acceptable - that wouldn't hurt performance much because
there is a buffer for the pipe in the OS, but that would require changing how we
send all messages, not just for logging.

[Jamie, 2015/08/17 17:32:23]

Done.

+  caller_task_runner_->PostTask(
+      FROM_HERE,
+      base::Bind(&LogMessageHandler::SendLogMessageToClient,
+                 weak_ptr_factory_.GetWeakPtr(),
+                 severity, file, line, message_start, str));
+}
+
+void LogMessageHandler::SendLogMessageToClient(
+    logging::LogSeverity severity, const char* file, int line,
+    size_t message_start, const std::string& str) {
+  suppress_logging_ = true;
+
+  std::string severity_string = "log";
+  switch (severity) {
+    case logging::LOG_WARNING:
+      severity_string = "warn";
+      break;
+    case logging::LOG_FATAL:
+    case logging::LOG_ERROR:
+      severity_string = "error";
+      break;
+  }
+
+  std::string message = str.c_str() + message_start;

[Sergey Ulanov, 2015/08/16 23:22:02]

message = std.substr(message_start);

[Jamie, 2015/08/17 17:32:23]

Done.

+  base::TrimWhitespaceASCII(message, base::TRIM_ALL, &message);
+
+  scoped_ptr<base::DictionaryValue> dictionary(new base::DictionaryValue);
+  dictionary->SetString("type", "_debug_log");
+  dictionary->SetString("severity", severity_string);
+  dictionary->SetString("message", message);
+  dictionary->SetString("file", file);
+  dictionary->SetInteger("line", line);
+
+  delegate_.Run(dictionary.Pass());
+
+  suppress_logging_ = false;
+}
+
+}  // namespace remoting