Fix the timestamp generation for webrtc native log.

chrome/browser/media/webrtc_logging_handler_host.cc

 // Copyright 2013 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 "chrome/browser/media/webrtc_logging_handler_host.h"
 
 #include <string>
 
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/cpu.h"
 #include "base/file_util.h"
 #include "base/logging.h"
 #include "base/prefs/pref_service.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/sys_info.h"
 #include "base/time/time.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chromeos/settings/cros_settings.h"
 #include "chrome/browser/media/webrtc_log_list.h"
 #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"
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/content_browser_client.h"
 #include "content/public/browser/gpu_data_manager.h"
 #include "content/public/browser/render_process_host.h"
 #include "gpu/config/gpu_info.h"
 #include "net/base/address_family.h"
 #include "net/url_request/url_request_context_getter.h"
@@ skipping 177 matching lines @@
   log_buffer_.reset();
   logging_state_ = CLOSED;
   FireGenericDoneCallback(&discard_callback, true, "");
 }
 
 void WebRtcLoggingHandlerHost::LogMessage(const std::string& message) {
   BrowserThread::PostTask(
       BrowserThread::IO,
       FROM_HERE,
       base::Bind(
-          &WebRtcLoggingHandlerHost::AddLogMessageFromBrowser, this, message));
+          &WebRtcLoggingHandlerHost::AddLogMessageFromBrowser,
+          this,
+          base::Time::Now(),
+          message));
 }
 
 void WebRtcLoggingHandlerHost::OnChannelClosing() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   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,
           base::Bind(&WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists,
                      this),
           base::Bind(&WebRtcLoggingHandlerHost::TriggerUploadLog, this));
     } else {
       g_browser_process->webrtc_log_uploader()->LoggingStoppedDontUpload();
     }
   }
   content::BrowserMessageFilter::OnChannelClosing();
 }
 
 void WebRtcLoggingHandlerHost::OnDestruct() const {
   BrowserThread::DeleteOnIOThread::Destruct(this);
 }
 
 bool WebRtcLoggingHandlerHost::OnMessageReceived(const IPC::Message& message,
                                                  bool* message_was_ok) {
   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)
   IPC_END_MESSAGE_MAP_EX()
 
   return handled;
 }
 
 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() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   if (logging_state_ != STOPPING) {
     // If an out-of-order response is received, stop_callback_ may be invalid,
     // and must not be invoked.
     DLOG(ERROR) << "OnLoggingStoppedInRenderer invoked in state "
                 << logging_state_;
     BadMessageReceived();
     return;
   }
+  logging_started_time_ = base::Time();
   logging_state_ = STOPPED;
   FireGenericDoneCallback(&stop_callback_, true, "");
 }
 
 void WebRtcLoggingHandlerHost::StartLoggingIfAllowed() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
   if (!g_browser_process->webrtc_log_uploader()->ApplyForStartLogging()) {
     logging_state_ = CLOSED;
       FireGenericDoneCallback(
           &start_callback_, false, "Cannot start, maybe the maximum number of "
@@ skipping 97 matching lines @@
     LogToCircularBuffer("Name: " + it->friendly_name + ", Address: " +
                         IPAddressToSensitiveString(it->address));
   }
 
   NotifyLoggingStarted();
 }
 
 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, "");
 }
 
 void WebRtcLoggingHandlerHost::LogToCircularBuffer(const std::string& message) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   DCHECK(circular_buffer_.get());
   circular_buffer_->Write(message.c_str(), message.length());
   const char eol = '\n';
   circular_buffer_->Write(&eol, 1);
@@ skipping 39 matching lines @@
 void WebRtcLoggingHandlerHost::FireGenericDoneCallback(
     GenericDoneCallback* callback, bool success,
     const std::string& error_message) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   DCHECK(!(*callback).is_null());
   content::BrowserThread::PostTask(content::BrowserThread::UI, FROM_HERE,
                                    base::Bind(*callback, success,
                                               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;
+}