Modify Chromoting logging to hook into base logging.

remoting/host/plugin/host_script_object.cc

Index: remoting/host/plugin/host_script_object.cc
diff --git a/remoting/host/plugin/host_script_object.cc b/remoting/host/plugin/host_script_object.cc
index 226df03ffb232b77ac49fbb3026917fa29448ce7..7b17a797eb45abee6a6cfc711e7a1d3290398734 100644
--- a/remoting/host/plugin/host_script_object.cc
+++ b/remoting/host/plugin/host_script_object.cc
@@ -9,6 +9,7 @@
 #include "base/task.h"
 #include "base/threading/platform_thread.h"
 #include "remoting/base/auth_token_util.h"
+#include "remoting/base/util.h"
 #include "remoting/host/chromoting_host.h"
 #include "remoting/host/chromoting_host_context.h"
 #include "remoting/host/host_config.h"
@@ -62,6 +63,13 @@ const int kMaxLoginAttempts = 5;
 
 }  // namespace
 
+// This flag blocks LOGs to the UI if we're already in the middle of logging
+// to the UI. This prevents a potential infinite loop if we encounter an error
+// while sending the log message to the UI.
+static bool logging_to_plugin_ = false;

[dmac, 2011/07/21 23:37:07]

again, should these be prefixed with a g? and they shouldn't have a _

[garykac, 2011/08/02 00:15:37]

Done.

+static HostNPScriptObject* logging_scriptable_object_ = NULL;
+static logging::LogMessageHandlerFunction logging_old_handler_ = NULL;
+
 HostNPScriptObject::HostNPScriptObject(NPP plugin, NPObject* parent)
     : plugin_(plugin),
       parent_(parent),
@@ -71,8 +79,11 @@ HostNPScriptObject::HostNPScriptObject(NPP plugin, NPObject* parent)
       np_thread_id_(base::PlatformThread::CurrentId()),
       failed_login_attempts_(0),
       disconnected_event_(true, false) {
-  logger_.reset(new HostPluginLogger(this));
-  logger_->VLog(2, "HostNPScriptObject");
+  logging_old_handler_ = logging::GetLogMessageHandler();

[dmac, 2011/07/21 23:37:07]

Is this not assuming that HostNPScriptObject is only going to be created once?

[garykac, 2011/08/02 00:15:37]

No, er.. yes. It's not not assuming...  I mean it *is* assuming.

Anyway, I fixed it up a bit and added a comment.  It doesn't seem worth the dev
effort to make the debug logging work perfectly for multiple Chromoting tabs.

+  logging::SetLogMessageHandler(&LogToUI);
+  logging_scriptable_object_ = this;
+
+  VLOG(2) << "HostNPScriptObject";
   host_context_.SetUITaskPostFunction(base::Bind(
       &HostNPScriptObject::PostTaskToNPThread, base::Unretained(this)));
 }
@@ -80,6 +91,10 @@ HostNPScriptObject::HostNPScriptObject(NPP plugin, NPObject* parent)
 HostNPScriptObject::~HostNPScriptObject() {
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
 
+  logging::SetLogMessageHandler(logging_old_handler_);
+  logging_old_handler_ = NULL;
+  logging_scriptable_object_ = NULL;
+
   // Disconnect synchronously. We cannot disconnect asynchronously
   // here because |host_context_| needs to be stopped on the plugin
   // thread, but the plugin thread may not exist after the instance
@@ -99,14 +114,14 @@ HostNPScriptObject::~HostNPScriptObject() {
 }
 
 bool HostNPScriptObject::Init() {
-  logger_->VLog(2, "Init");
+  VLOG(2) << "Init";
   // TODO(wez): This starts a bunch of threads, which might fail.
   host_context_.Start();
   return true;
 }
 
 bool HostNPScriptObject::HasMethod(const std::string& method_name) {
-  logger_->VLog(2, "HasMethod %s", method_name.c_str());
+  VLOG(2) << "HasMethod " << method_name;
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   return (method_name == kFuncNameConnect ||
           method_name == kFuncNameDisconnect);
@@ -115,7 +130,7 @@ bool HostNPScriptObject::HasMethod(const std::string& method_name) {
 bool HostNPScriptObject::InvokeDefault(const NPVariant* args,
                                        uint32_t argCount,
                                        NPVariant* result) {
-  logger_->VLog(2, "InvokeDefault");
+  VLOG(2) << "InvokeDefault";
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   SetException("exception during default invocation");
   return false;
@@ -125,7 +140,7 @@ bool HostNPScriptObject::Invoke(const std::string& method_name,
                                 const NPVariant* args,
                                 uint32_t argCount,
                                 NPVariant* result) {
-  logger_->VLog(2, "Invoke %s", method_name.c_str());
+  VLOG(2) << "Invoke " << method_name;
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   if (method_name == kFuncNameConnect) {
     return Connect(args, argCount, result);
@@ -138,7 +153,7 @@ bool HostNPScriptObject::Invoke(const std::string& method_name,
 }
 
 bool HostNPScriptObject::HasProperty(const std::string& property_name) {
-  logger_->VLog(2, "HasProperty %s", property_name.c_str());
+  VLOG(2) << "HasProperty " << property_name;
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   return (property_name == kAttrNameAccessCode ||
           property_name == kAttrNameState ||
@@ -154,7 +169,7 @@ bool HostNPScriptObject::HasProperty(const std::string& property_name) {
 
 bool HostNPScriptObject::GetProperty(const std::string& property_name,
                                      NPVariant* result) {
-  logger_->VLog(2, "GetProperty %s", property_name.c_str());
+  VLOG(2) << "GetProperty " << property_name;
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   if (!result) {
     SetException("GetProperty: NULL result");
@@ -199,7 +214,7 @@ bool HostNPScriptObject::GetProperty(const std::string& property_name,
 
 bool HostNPScriptObject::SetProperty(const std::string& property_name,
                                      const NPVariant* value) {
-  logger_->VLog(2, "SetProperty %s", property_name.c_str());
+  VLOG(2) <<  "SetProperty " << property_name;
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
 
   if (property_name == kAttrNameOnStateChanged) {
@@ -240,13 +255,13 @@ bool HostNPScriptObject::SetProperty(const std::string& property_name,
 }
 
 bool HostNPScriptObject::RemoveProperty(const std::string& property_name) {
-  logger_->VLog(2, "RemoveProperty %s", property_name.c_str());
+  VLOG(2) << "RemoveProperty " << property_name;
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   return false;
 }
 
 bool HostNPScriptObject::Enumerate(std::vector<std::string>* values) {
-  logger_->VLog(2, "Enumerate");
+  VLOG(2) << "Enumerate";
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   const char* entries[] = {
     kAttrNameAccessCode,
@@ -300,7 +315,7 @@ bool HostNPScriptObject::Connect(const NPVariant* args,
                                  NPVariant* result) {
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
 
-  LogDebugInfo("Connecting...");
+  LOG(INFO) << "Connecting...";
 
   if (arg_count != 2) {
     SetException("connect: bad number of arguments");
@@ -370,7 +385,7 @@ void HostNPScriptObject::ConnectInternal(
   // Create the Host.
   scoped_refptr<ChromotingHost> host =
       ChromotingHost::Create(&host_context_, host_config,
-                             access_verifier.release(), logger_.get());
+                             access_verifier.release());
   host->AddStatusObserver(this);
   host->AddStatusObserver(register_request.get());
   host->set_it2me(true);
@@ -463,12 +478,28 @@ void HostNPScriptObject::OnStateChanged(State state) {
   }
   state_ = state;
   if (on_state_changed_func_) {
-    logger_->VLog(2, "Calling state changed %s", state);
+    VLOG(2) << "Calling state changed " << state;
     bool is_good = InvokeAndIgnoreResult(on_state_changed_func_, NULL, 0);
     LOG_IF(ERROR, !is_good) << "OnStateChanged failed";
   }
 }
 
+// static
+bool HostNPScriptObject::LogToUI(int severity, const char* file, int line,
+                                 size_t message_start,
+                                 const std::string& str) {
+  if (logging_scriptable_object_ && !logging_to_plugin_) {

[dmac, 2011/07/21 23:37:07]

accessing logging_to_plugin_ from multiple thread problems?

[garykac, 2011/08/02 00:15:37]

Pushed this check down into the UIThread code below (in LogDebugInfo).

+    logging_to_plugin_ = true;
+    std::string message = remoting::GetTimestampString();
+    message += (str.c_str() + message_start);
+    logging_scriptable_object_->LogDebugInfo(message);
+    logging_to_plugin_ = false;
+  }
+  if (logging_old_handler_)
+    return (logging_old_handler_)(severity, file, line, message_start, str);
+  return false;
+}
+
 void HostNPScriptObject::LogDebugInfo(const std::string& message) {
   if (!host_context_.IsUIThread()) {
     host_context_.PostToUIThread(
@@ -487,7 +518,7 @@ void HostNPScriptObject::LogDebugInfo(const std::string& message) {
 void HostNPScriptObject::SetException(const std::string& exception_string) {
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
   g_npnetscape_funcs->setexception(parent_, exception_string.c_str());
-  LogDebugInfo(exception_string);
+  LOG(INFO) << exception_string;
 }
 
 bool HostNPScriptObject::InvokeAndIgnoreResult(NPObject* func,