Change Chromoting logger to be setup in plugin's NP_Initialize.

remoting/host/plugin/host_script_object.cc

 // Copyright (c) 2011 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 "remoting/host/plugin/host_script_object.h"
 
 #include "base/bind.h"
 #include "base/message_loop.h"
 #include "base/message_loop_proxy.h"
 #include "base/threading/platform_thread.h"
@@ skipping 54 matching lines @@
 const char* kAttrNameError = "ERROR";
 
 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 g_logging_to_plugin = false;
+static bool g_has_registered_log_handler = false;
 static HostNPScriptObject* g_logging_scriptable_object = NULL;
 static logging::LogMessageHandlerFunction g_logging_old_handler = NULL;
 
 HostNPScriptObject::HostNPScriptObject(NPP plugin, NPObject* parent)
     : plugin_(plugin),
       parent_(parent),
       state_(kDisconnected),
       log_debug_info_func_(NULL),
       on_state_changed_func_(NULL),
       np_thread_id_(base::PlatformThread::CurrentId()),
       failed_login_attempts_(0),
       disconnected_event_(true, false) {
-  // Set up log message handler.
-  // Note that this approach doesn't quite support having multiple instances
-  // of Chromoting running. In that case, the most recently opened tab will
-  // grab all the debug log messages, and when any Chromoting tab is closed
-  // the logging handler will go away.
-  // Since having multiple Chromoting tabs is not a primary use case, and this
-  // is just debug logging, we're punting improving debug log support for that
-  // case.
-  if (g_logging_old_handler == NULL)
-    g_logging_old_handler = logging::GetLogMessageHandler();
-  logging::SetLogMessageHandler(&LogToUI);
+  // Register this script object as the one that will handle all logging calls
+  // and display them to the user.
+  // If multiple plugins are run, then the last one registered will handle all
+  // logging for all instances.
   g_logging_scriptable_object = this;
 
   VLOG(2) << "HostNPScriptObject";
   host_context_.SetUITaskPostFunction(base::Bind(
       &HostNPScriptObject::PostTaskToNPThread, base::Unretained(this)));
 }
 
 HostNPScriptObject::~HostNPScriptObject() {
   CHECK_EQ(base::PlatformThread::CurrentId(), np_thread_id_);
 
   // Shutdown DesktopEnvironment first so that it doesn't try to post
   // tasks on the UI thread while we are stopping the host.
   desktop_environment_->Shutdown();
 
-  logging::SetLogMessageHandler(g_logging_old_handler);
-  g_logging_old_handler = NULL;
+  // Unregister this script object for logging.
+  // If there are multiple instances and this is the one that was registered
+  // last, then all logging to the UI will be stopped.
   g_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
   // is destroyed.
   destructing_.Set();
   disconnected_event_.Reset();
   DisconnectInternal();
   disconnected_event_.Wait();
@@ skipping 401 matching lines @@
   }
   state_ = state;
   if (on_state_changed_func_) {
     VLOG(2) << "Calling state changed " << state;
     bool is_good = InvokeAndIgnoreResult(on_state_changed_func_, NULL, 0);
     LOG_IF(ERROR, !is_good) << "OnStateChanged failed";
   }
 }
 
 // static
+void HostNPScriptObject::RegisterLogger() {
+  DCHECK(!g_has_registered_log_handler);
+
+  LOG(INFO) << "Registering global log handler";
+
+  // Record previous handler so we can call it in a chain.
+  g_logging_old_handler = logging::GetLogMessageHandler();
+
+  // Set up log message handler.
+  // Note that this will not log anything until a scriptable object instance
+  // has been created to handle the log message display.
+  logging::SetLogMessageHandler(&LogToUI);
+
+  g_has_registered_log_handler = true;
+}
+
+// static
+void HostNPScriptObject::UnregisterLogger() {
+  // Restore previous handler.
+  logging::SetLogMessageHandler(g_logging_old_handler);
+  g_logging_old_handler = NULL;
+  g_has_registered_log_handler = false;
+
+  LOG(INFO) << "Unregistering global log handler";

[Wez, 2011/08/16 00:05:45]

Why not have these in host_plugin.cc, since that's where they get called from?

[garykac, 2011/08/16 00:19:40]

Because having it here keeps all of the logic (and globals) in one file rather
than having some in the host_plugin and some in the scriptable object.

[Wez, 2011/08/16 00:30:52]

Could they live in their own code file?  The only bit specific to the script
object is the actual call to the logging function.

[garykac, 2011/08/29 23:27:15]

Done.

+}
+
+// static
 bool HostNPScriptObject::LogToUI(int severity, const char* file, int line,
                                  size_t message_start,
                                  const std::string& str) {
   // The |g_logging_to_plugin| check is to prevent logging to the scriptable
   // object if we're already in the middle of logging.
   // This can occur if we try to log an error while we're in the scriptable
   // object logging code.
   if (g_logging_scriptable_object && !g_logging_to_plugin) {
     g_logging_to_plugin = true;
     std::string message = remoting::GetTimestampString();
     message += (str.c_str() + message_start);
     g_logging_scriptable_object->LogDebugInfo(message);

[Wez, 2011/08/16 00:05:45]

Are we guaranteed that LogToUI will always be called on our plugin thread?

[garykac, 2011/08/16 00:19:40]

I don't think so, but LogDebugInfo below switches to the correct thread before
logging.

[Wez, 2011/08/16 00:30:52]

To do that, though, it touches members of the HostNPScriptObject, so if the
object that was set for logging happens to have gone away at that moment then
crashy crashy.

I think LogToUI needs to use the NPN postasynccall function directly (see
implementation of PostTaskToUIThread), without touching the logging script
object at all, and let the called function, i.e. a static equivalent of
LogDebugInfo(), touch the current logging scriptable to do the actual work.

[garykac, 2011/08/29 23:27:15]

Note that the code has changed.

For logging, it now posts to a proxy which is Detach'ed before the script object
is destroyed.

     g_logging_to_plugin = false;
   }
   if (g_logging_old_handler)
     return (g_logging_old_handler)(severity, file, line, message_start, str);
   return false;
 }
 
 void HostNPScriptObject::LogDebugInfo(const std::string& message) {
   if (destructing_.IsSet())
     return;
@@ skipping 46 matching lines @@
 }
 
 // static
 void HostNPScriptObject::NPTaskSpringboard(void* task) {
   base::Closure* real_task = reinterpret_cast<base::Closure*>(task);
   real_task->Run();
   delete real_task;
 }
 
 }  // namespace remoting