Ensure LogMessage is called on the correct thread.

ChromeWebRtcLogMessageDelegate was using CalledOnValidThread() to determine
whether to trampoline the request to the IO thread, but CalledOnValidThread()
compiles to "return true" in Release builds (see NonThreadSafe implementation),
so many log messages and IPC requests were happening on the wrong thread.
This CL fixes the bug so that logging always happens on the IO thread.

BUG=335027,335534
TBR=tommi,grunell
NOTRY=True

Review URL: https://codereview.chromium.org/130213010

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

5 files changed, 49 insertions, 27 deletions

diff --git a/chrome/renderer/media/chrome_webrtc_log_message_delegate.cc b/chrome/renderer/media/chrome_webrtc_log_message_delegate.cc
index 7b84006..cc09c93 100644
--- a/chrome/renderer/media/chrome_webrtc_log_message_delegate.cc
+++ b/chrome/renderer/media/chrome_webrtc_log_message_delegate.cc
@@ -23,15 +23,16 @@ ChromeWebRtcLogMessageDelegate::~ChromeWebRtcLogMessageDelegate() {
 }
 
 void ChromeWebRtcLogMessageDelegate::LogMessage(const std::string& message) {
-  if (!CalledOnValidThread()) {
-    io_message_loop_->PostTask(
-        FROM_HERE, base::Bind(
-            &ChromeWebRtcLogMessageDelegate::LogMessage,
-            base::Unretained(this),
-            message));
-    return;
-  }
+  io_message_loop_->PostTask(
+      FROM_HERE, base::Bind(
+          &ChromeWebRtcLogMessageDelegate::LogMessageOnIOThread,
+          base::Unretained(this),
+          message));
+}
 
+void ChromeWebRtcLogMessageDelegate::LogMessageOnIOThread(
+    const std::string& message) {
+  DCHECK(CalledOnValidThread());
   if (logging_started_ && message_filter_) {
     if (!log_buffer_.empty()) {
       // A delayed task has already been posted for sending the buffer contents.
diff --git a/chrome/renderer/media/chrome_webrtc_log_message_delegate.h b/chrome/renderer/media/chrome_webrtc_log_message_delegate.h
index d0749ee..c3ecf52 100644
--- a/chrome/renderer/media/chrome_webrtc_log_message_delegate.h
+++ b/chrome/renderer/media/chrome_webrtc_log_message_delegate.h
@@ -41,6 +41,7 @@ class ChromeWebRtcLogMessageDelegate
   void OnStopLogging();
 
  private:
+  void LogMessageOnIOThread(const std::string& message);
   void SendLogBuffer();
 
   scoped_refptr<base::MessageLoopProxy> io_message_loop_;
diff --git a/chrome/renderer/media/chrome_webrtc_log_message_delegate_unittest.cc b/chrome/renderer/media/chrome_webrtc_log_message_delegate_unittest.cc
index 3df3362..3760347 100644
--- a/chrome/renderer/media/chrome_webrtc_log_message_delegate_unittest.cc
+++ b/chrome/renderer/media/chrome_webrtc_log_message_delegate_unittest.cc
@@ -4,35 +4,47 @@
 
 #include <string>
 
-#include "base/process/process_handle.h"
-#include "chrome/common/partial_circular_buffer.h"
+#include "base/bind.h"
+#include "base/message_loop/message_loop.h"
 #include "chrome/renderer/media/chrome_webrtc_log_message_delegate.h"
 #include "chrome/renderer/media/mock_webrtc_logging_message_filter.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 TEST(ChromeWebRtcLogMessageDelegateTest, Basic) {
   const char kTestString[] = "abcdefghijklmnopqrstuvwxyz";
-
   base::MessageLoopForIO message_loop;
-
   scoped_refptr<MockWebRtcLoggingMessageFilter> log_message_filter(
       new MockWebRtcLoggingMessageFilter(message_loop.message_loop_proxy()));
-
-  scoped_ptr<ChromeWebRtcLogMessageDelegate> log_message_delegate(
-      new ChromeWebRtcLogMessageDelegate(message_loop.message_loop_proxy(),
-                                         log_message_filter));
-
-  log_message_delegate->OnStartLogging();
-
-  // These log messages should be added to the log buffer.
+  // Run message loop to initialize delegate.
+  // TODO(vrk): Fix this so that we can construct a delegate without needing to
+  // construct a message filter.
+  message_loop.RunUntilIdle();
+
+  ChromeWebRtcLogMessageDelegate* log_message_delegate =
+      log_message_filter->log_message_delegate();
+
+  // Start logging on the IO loop.
+  message_loop.message_loop_proxy()->PostTask(
+      FROM_HERE, base::Bind(
+          &ChromeWebRtcLogMessageDelegate::OnStartLogging,
+          base::Unretained(log_message_delegate)));
+
+  // These log messages should be added to the log buffer outside of the IO
+  // loop.
   log_message_delegate->LogMessage(kTestString);
   log_message_delegate->LogMessage(kTestString);
 
-  log_message_delegate->OnStopLogging();
+  // Stop logging on IO loop.
+  message_loop.message_loop_proxy()->PostTask(
+      FROM_HERE, base::Bind(
+          &ChromeWebRtcLogMessageDelegate::OnStopLogging,
+          base::Unretained(log_message_delegate)));
 
   // This log message should not be added to the log buffer.
   log_message_delegate->LogMessage(kTestString);
 
+  message_loop.RunUntilIdle();
+
   // Size is calculated as (sizeof(kTestString) - 1 for terminating null
   // + 1 for eol added for each log message in LogMessage) * 2.
   const uint32 kExpectedSize = sizeof(kTestString) * 2;
diff --git a/chrome/renderer/media/mock_webrtc_logging_message_filter.h b/chrome/renderer/media/mock_webrtc_logging_message_filter.h
index 19221f5..f7b358f 100644
--- a/chrome/renderer/media/mock_webrtc_logging_message_filter.h
+++ b/chrome/renderer/media/mock_webrtc_logging_message_filter.h
@@ -16,6 +16,10 @@ class MockWebRtcLoggingMessageFilter
   virtual void AddLogMessage(const std::string& message) OVERRIDE;
   virtual void LoggingStopped() OVERRIDE;
 
+  ChromeWebRtcLogMessageDelegate* log_message_delegate() {
+    return log_message_delegate_;
+  }
+
   std::string log_buffer_;
   bool logging_stopped_;
 
diff --git a/chrome/renderer/media/webrtc_logging_message_filter.h b/chrome/renderer/media/webrtc_logging_message_filter.h
index 9ff3092..181accc 100644
--- a/chrome/renderer/media/webrtc_logging_message_filter.h
+++ b/chrome/renderer/media/webrtc_logging_message_filter.h
@@ -34,6 +34,16 @@ class WebRtcLoggingMessageFilter
 
   scoped_refptr<base::MessageLoopProxy> io_message_loop_;
 
+  // Owned by this class. The only other pointer to it is in libjingle's logging
+  // file. That's a global pointer used on different threads, so we will leak
+  // this object when we go away to ensure that it outlives any log messages
+  // coming from libjingle.
+  // This is protected for unit test purposes.
+  // TODO(vrk): Remove ChromeWebRtcLogMessageDelegate's pointer to
+  // WebRtcLoggingMessageFilter so that we can write a unit test that doesn't
+  // need this accessor.
+  ChromeWebRtcLogMessageDelegate* log_message_delegate_;
+
  private:
   // IPC::ChannelProxy::MessageFilter implementation.
   virtual bool OnMessageReceived(const IPC::Message& message) OVERRIDE;
@@ -47,12 +57,6 @@ class WebRtcLoggingMessageFilter
   void OnStopLogging();
   void Send(IPC::Message* message);
 
-  // Owned by this class. The only other pointer to it is in libjingle's logging
-  // file. That's a global pointer used on different threads, so we will leak
-  // this object when we go away to ensure that it outlives any log messages
-  // coming from libjingle.
-  ChromeWebRtcLogMessageDelegate* log_message_delegate_;
-
   IPC::Channel* channel_;
 
   DISALLOW_COPY_AND_ASSIGN(WebRtcLoggingMessageFilter);