Enable verbose logging during PluginMsg_CreateInstance.

This should get rid of the spurious ERROR messages when closing tabs, and log backtraces when we need them.

BUG=141055


Review URL: https://chromiumcodereview.appspot.com/10834355

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@151975 0039d316-1c4b-4281-b951-d872f2087c98

content/common/np_channel_base.cc

@@ -141,7 +141,7 @@ bool NPChannelBase::Init(base::MessageLoopProxy* ipc_message_loop,
 
 bool NPChannelBase::Send(IPC::Message* message) {
   if (!channel_.get()) {
-    LOG(ERROR) << "Channel is NULL; dropping message";
+    VLOG(1) << "Channel is NULL; dropping message";
     delete message;
     return false;
   }

content/renderer/webplugin_delegate_proxy.cc

@@ -73,6 +73,28 @@ using WebKit::WebInputEvent;
 using WebKit::WebString;
 using WebKit::WebView;
 
+namespace {
+
+class ScopedLogLevel {
+ public:
+  ScopedLogLevel(int level);
+  ~ScopedLogLevel();
+
+ private:
+  int old_level_;
+
+  DISALLOW_COPY_AND_ASSIGN(ScopedLogLevel);
+};
+
+ScopedLogLevel::ScopedLogLevel(int level)
+    : old_level_(logging::GetMinLogLevel()) {
+  logging::SetMinLogLevel(level);
+}
+
+ScopedLogLevel::~ScopedLogLevel() {
+  logging::SetMinLogLevel(old_level_);
+}
+
 // Proxy for WebPluginResourceClient.  The object owns itself after creation,
 // deleting itself after its callback has been called.
 class ResourceClientProxy : public webkit::npapi::WebPluginResourceClient {
@@ -169,6 +191,8 @@ class ResourceClientProxy : public webkit::npapi::WebPluginResourceClient {
   bool multibyte_response_expected_;
 };
 
+}  // namespace
+
 WebPluginDelegateProxy::WebPluginDelegateProxy(
     const std::string& mime_type,
     const base::WeakPtr<RenderViewImpl>& render_view)
@@ -319,11 +343,15 @@ bool WebPluginDelegateProxy::Initialize(
 #endif
 
   int instance_id;
-  bool result = channel_host->Send(new PluginMsg_CreateInstance(
-      mime_type_, &instance_id));
-  if (!result) {
-    LOG(ERROR) << "Couldn't send PluginMsg_CreateInstance";
-    return false;
+  {
+    // TODO(bauerb): Debugging for http://crbug.com/141055.
+    ScopedLogLevel log_level(-2);  // Equivalent to --v=2
+    bool result = channel_host->Send(new PluginMsg_CreateInstance(
+        mime_type_, &instance_id));
+    if (!result) {
+      LOG(ERROR) << "Couldn't send PluginMsg_CreateInstance";
+      return false;
+    }
   }
 
   channel_host_ = channel_host;
@@ -356,7 +384,7 @@ bool WebPluginDelegateProxy::Initialize(
 
   plugin_ = plugin;
 
-  result = false;
+  bool result = false;
   IPC::Message* msg = new PluginMsg_Init(instance_id_, params, &result);
   Send(msg);
 

ipc/ipc_sync_channel.cc

@@ -5,6 +5,7 @@
 #include "ipc/ipc_sync_channel.h"
 
 #include "base/bind.h"
+#include "base/debug/stack_trace.h"
 #include "base/lazy_instance.h"
 #include "base/location.h"
 #include "base/logging.h"
@@ -307,9 +308,9 @@ bool SyncChannel::SyncContext::TryToUnblockListener(const Message* msg) {
     bool send_result = deserializers_.back().deserializer->
         SerializeOutputParameters(*msg);
     deserializers_.back().send_result = send_result;
-    LOG_IF(ERROR, !send_result) << "Couldn't deserialize reply message";
+    VLOG_IF(1, !send_result) << "Couldn't deserialize reply message";
   } else {
-    LOG(ERROR) << "Received error reply";
+    VLOG(1) << "Received error reply";
   }
   deserializers_.back().done_event->Signal();
 
@@ -363,7 +364,7 @@ void SyncChannel::SyncContext::OnChannelClosed() {
 void SyncChannel::SyncContext::OnSendTimeout(int message_id) {
   base::AutoLock auto_lock(deserializers_lock_);
   PendingSyncMessageQueue::iterator iter;
-  LOG(ERROR) << "Send timeout";
+  VLOG(1) << "Send timeout";
   for (iter = deserializers_.begin(); iter != deserializers_.end(); iter++) {
     if (iter->id == message_id) {
       iter->done_event->Signal();
@@ -375,7 +376,14 @@ void SyncChannel::SyncContext::OnSendTimeout(int message_id) {
 void SyncChannel::SyncContext::CancelPendingSends() {
   base::AutoLock auto_lock(deserializers_lock_);
   PendingSyncMessageQueue::iterator iter;
-  LOG(ERROR) << "Canceling pending sends";
+#if !defined(OS_ANDROID) && !defined(OS_NACL)
+  // TODO(bauerb): Remove once http://crbug/141055 is fixed.
+  if (VLOG_IS_ON(1)) {
+    VLOG(1) << "Canceling pending sends";
+    base::debug::StackTrace trace;
+    trace.PrintBacktrace();
+  }
+#endif
   for (iter = deserializers_.begin(); iter != deserializers_.end(); iter++)
     iter->done_event->Signal();
 }
@@ -435,7 +443,7 @@ bool SyncChannel::SendWithTimeout(Message* message, int timeout_ms) {
   // *this* might get deleted in WaitForReply.
   scoped_refptr<SyncContext> context(sync_context());
   if (context->shutdown_event()->IsSignaled()) {
-    LOG(ERROR) << "shutdown event is signaled";
+    VLOG(1) << "shutdown event is signaled";
     delete message;
     return false;
   }