Fix the timestamp generation for webrtc native log.

chrome/browser/media/webrtc_logging_handler_host.cc

Index: chrome/browser/media/webrtc_logging_handler_host.cc
diff --git a/chrome/browser/media/webrtc_logging_handler_host.cc b/chrome/browser/media/webrtc_logging_handler_host.cc
index e1919d2670c2bb17bd436916f522fb9ab448de55..5ec136e001b856b2b0e700460f5274bf928260ab 100644
--- a/chrome/browser/media/webrtc_logging_handler_host.cc
+++ b/chrome/browser/media/webrtc_logging_handler_host.cc
@@ -21,7 +21,6 @@
 #include "chrome/browser/media/webrtc_log_uploader.h"
 #include "chrome/browser/profiles/profile.h"
 #include "chrome/common/chrome_switches.h"
-#include "chrome/common/media/webrtc_logging_messages.h"
 #include "chrome/common/partial_circular_buffer.h"
 #include "chrome/common/pref_names.h"
 #include "chromeos/settings/cros_settings_names.h"
@@ -219,7 +218,10 @@ void WebRtcLoggingHandlerHost::LogMessage(const std::string& message) {
       BrowserThread::IO,
       FROM_HERE,
       base::Bind(
-          &WebRtcLoggingHandlerHost::AddLogMessageFromBrowser, this, message));
+          &WebRtcLoggingHandlerHost::AddLogMessageFromBrowser,
+          this,
+          base::Time::Now(),
+          message));
 }
 
 void WebRtcLoggingHandlerHost::OnChannelClosing() {
@@ -227,6 +229,7 @@ void WebRtcLoggingHandlerHost::OnChannelClosing() {
   if (logging_state_ == STARTED || logging_state_ == STOPPED) {
     if (upload_log_on_render_close_) {
       logging_state_ = STOPPED;
+      logging_started_time_ = base::Time();
       content::BrowserThread::PostTaskAndReplyWithResult(
           content::BrowserThread::FILE,
           FROM_HERE,
@@ -249,7 +252,7 @@ bool WebRtcLoggingHandlerHost::OnMessageReceived(const IPC::Message& message,
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   bool handled = true;
   IPC_BEGIN_MESSAGE_MAP_EX(WebRtcLoggingHandlerHost, message, *message_was_ok)
-    IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_AddLogMessage, OnAddLogMessage)
+    IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_AddLogMessages, OnAddLogMessages)
     IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_LoggingStopped,
                         OnLoggingStoppedInRenderer)
     IPC_MESSAGE_UNHANDLED(handled = false)
@@ -259,16 +262,22 @@ bool WebRtcLoggingHandlerHost::OnMessageReceived(const IPC::Message& message,
 }
 
 void WebRtcLoggingHandlerHost::AddLogMessageFromBrowser(
-    const std::string& message) {
+    const base::Time& timestamp, const std::string& message) {

[tommi (sloooow) - chröme, 2014/04/02 15:17:59]

can we use WebRtcLoggingMessage here?

[jiayl, 2014/04/02 16:23:59]

Done.

   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   if (logging_state_ == STARTED)
-    LogToCircularBuffer(message);
+    LogToCircularBuffer(FormatMessageWithTimestamp(timestamp, message));

[tommi (sloooow) - chröme, 2014/04/02 15:17:59]

maybe FormatMessage should just accept WebRtcLoggingMessage?
would it even be possible to have Format() be a member function of
WebRtcLoggingMessage?

[jiayl, 2014/04/02 16:23:59]

Done.

 }
 
-void WebRtcLoggingHandlerHost::OnAddLogMessage(const std::string& message) {
+void WebRtcLoggingHandlerHost::OnAddLogMessages(
+    const std::vector<WebRtcLoggingMessage>& messages) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
-  if (logging_state_ == STARTED || logging_state_ == STOPPING)
-    LogToCircularBuffer(message);
+  if (logging_state_ == STARTED || logging_state_ == STOPPING) {
+    for (size_t i = 0; i < messages.size(); ++i) {
+      LogToCircularBuffer(
+          FormatMessageWithTimestamp(messages[i].timestamp,
+                                     messages[i].message));
+    }
+  }
 }
 
 void WebRtcLoggingHandlerHost::OnLoggingStoppedInRenderer() {
@@ -281,6 +290,7 @@ void WebRtcLoggingHandlerHost::OnLoggingStoppedInRenderer() {
     BadMessageReceived();
     return;
   }
+  logging_started_time_ = base::Time();
   logging_state_ = STOPPED;
   FireGenericDoneCallback(&stop_callback_, true, "");
 }
@@ -398,6 +408,7 @@ void WebRtcLoggingHandlerHost::LogInitialInfoOnIOThread(
 void WebRtcLoggingHandlerHost::NotifyLoggingStarted() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   Send(new WebRtcLoggingMsg_StartLogging());
+  logging_started_time_ = base::Time::Now();
   logging_state_ = STARTED;
   FireGenericDoneCallback(&start_callback_, true, "");
 }
@@ -457,3 +468,14 @@ void WebRtcLoggingHandlerHost::FireGenericDoneCallback(
                                               error_message));
   (*callback).Reset();
 }
+
+std::string WebRtcLoggingHandlerHost::FormatMessageWithTimestamp(
+    const base::Time& timestamp, const std::string& message) {
+  uint64 interval_ms = (timestamp - logging_started_time_).InMilliseconds();
+
+  std::string result = base::StringPrintf("[%03ld:%03ld] %s",
+                                          interval_ms / 1000,
+                                          interval_ms % 1000,
+                                          message.c_str());
+  return result;
+}