chrome/browser/media/webrtc_logging_handler_host.cc

   1 // Copyright 2013 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "chrome/browser/media/webrtc_logging_handler_host.h"
   6
   7 #include <string>
   8
   9 #include "base/bind.h"
  10 #include "base/command_line.h"
  11 #include "base/cpu.h"
  12 #include "base/file_util.h"
  13 #include "base/logging.h"
  14 #include "base/prefs/pref_service.h"
  15 #include "base/strings/string_number_conversions.h"
  16 #include "base/sys_info.h"
  17 #include "base/time/time.h"
  18 #include "chrome/browser/browser_process.h"
  19 #include "chrome/browser/chromeos/settings/cros_settings.h"
  20 #include "chrome/browser/media/webrtc_log_list.h"
  21 #include "chrome/browser/media/webrtc_log_uploader.h"
  22 #include "chrome/browser/profiles/profile.h"
  23 #include "chrome/common/chrome_switches.h"
  24 #include "chrome/common/media/webrtc_logging_messages.h"
  25 #include "chrome/common/partial_circular_buffer.h"
  26 #include "chrome/common/pref_names.h"
  27 #include "chromeos/settings/cros_settings_names.h"
  28 #include "content/public/browser/browser_thread.h"
  29 #include "content/public/browser/content_browser_client.h"
  30 #include "content/public/browser/gpu_data_manager.h"
  31 #include "content/public/browser/render_process_host.h"
  32 #include "gpu/config/gpu_info.h"
  33 #include "net/base/address_family.h"
  34 #include "net/url_request/url_request_context_getter.h"
  35
  36 #if defined(OS_LINUX)
  37 #include "base/linux_util.h"
  38 #endif
  39
  40 #if defined(OS_MACOSX)
  41 #include "base/mac/mac_util.h"
  42 #endif
  43
  44 #if defined(OS_CHROMEOS)
  45 #include "chromeos/system/statistics_provider.h"
  46 #endif
  47
  48 using base::IntToString;
  49 using content::BrowserThread;
  50
  51
  52 #if defined(OS_ANDROID)
  53 const size_t kWebRtcLogSize = 1 * 1024 * 1024;  // 1 MB
  54 #else
  55 const size_t kWebRtcLogSize = 6 * 1024 * 1024;  // 6 MB
  56 #endif
  57
  58 namespace {
  59
  60 const char kLogNotStoppedOrNoLogOpen[] =
  61     "Logging not stopped or no log open.";
  62
  63 // For privacy reasons when logging IP addresses. The returned "sensitive
  64 // string" is for release builds a string with the end stripped away. Last
  65 // octet for IPv4 and last 80 bits (5 groups) for IPv6. String will be
  66 // "1.2.3.x" and "1.2.3::" respectively. For debug builds, the string is
  67 // not stripped.
  68 std::string IPAddressToSensitiveString(const net::IPAddressNumber& address) {
  69 #if defined(NDEBUG)
  70   std::string sensitive_address;
  71   switch (net::GetAddressFamily(address)) {
  72     case net::ADDRESS_FAMILY_IPV4: {
  73       sensitive_address = net::IPAddressToString(address);
  74       size_t find_pos = sensitive_address.rfind('.');
  75       if (find_pos == std::string::npos)
  76         return std::string();
  77       sensitive_address.resize(find_pos);
  78       sensitive_address += ".x";
  79       break;
  80     }
  81     case net::ADDRESS_FAMILY_IPV6: {
  82       // TODO(grunell): Create a string of format "1:2:3:x:x:x:x:x" to clarify
  83       // that the end has been stripped out.
  84       net::IPAddressNumber sensitive_address_number = address;
  85       sensitive_address_number.resize(net::kIPv6AddressSize - 10);
  86       sensitive_address_number.resize(net::kIPv6AddressSize, 0);
  87       sensitive_address = net::IPAddressToString(sensitive_address_number);
  88       break;
  89     }
  90     case net::ADDRESS_FAMILY_UNSPECIFIED: {
  91       break;
  92     }
  93   }
  94   return sensitive_address;
  95 #else
  96   return net::IPAddressToString(address);
  97 #endif
  98 }
  99
 100 void FormatMetaDataAsLogMessage(
 101     const MetaDataMap& meta_data,
 102     std::string* message) {
 103   for (MetaDataMap::const_iterator it = meta_data.begin();
 104        it != meta_data.end(); ++it) {
 105     *message += it->first + ": " + it->second + '\n';
 106   }
 107   // Remove last '\n'.
 108   message->resize(message->size() - 1);
 109 }
 110
 111 }  // namespace
 112
 113 WebRtcLoggingHandlerHost::WebRtcLoggingHandlerHost(Profile* profile)
 114     : BrowserMessageFilter(WebRtcLoggingMsgStart),
 115       profile_(profile),
 116       logging_state_(CLOSED),
 117       upload_log_on_render_close_(false) {
 118   DCHECK(profile_);
 119 }
 120
 121 WebRtcLoggingHandlerHost::~WebRtcLoggingHandlerHost() {}
 122
 123 void WebRtcLoggingHandlerHost::SetMetaData(
 124     const MetaDataMap& meta_data,
 125     const GenericDoneCallback& callback) {
 126   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 127   DCHECK(!callback.is_null());
 128
 129   std::string error_message;
 130   if (logging_state_ == CLOSED) {
 131     meta_data_ = meta_data;
 132   } else if (logging_state_ == STARTED) {
 133     meta_data_ = meta_data;
 134     std::string meta_data_message;
 135     FormatMetaDataAsLogMessage(meta_data_, &meta_data_message);
 136     LogToCircularBuffer(meta_data_message);
 137   } else {
 138     error_message = "Meta data must be set before stop or upload.";
 139   }
 140   bool success = error_message.empty();
 141   content::BrowserThread::PostTask(content::BrowserThread::UI, FROM_HERE,
 142                                    base::Bind(callback, success,
 143                                               error_message));
 144 }
 145
 146 void WebRtcLoggingHandlerHost::StartLogging(
 147     const GenericDoneCallback& callback) {
 148   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 149   DCHECK(!callback.is_null());
 150
 151   start_callback_ = callback;
 152   if (logging_state_ != CLOSED) {
 153     FireGenericDoneCallback(&start_callback_, false, "A log is already open");
 154     return;
 155   }
 156   logging_state_ = STARTING;
 157   BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(
 158       &WebRtcLoggingHandlerHost::StartLoggingIfAllowed, this));
 159 }
 160
 161 void WebRtcLoggingHandlerHost::StopLogging(
 162     const GenericDoneCallback& callback) {
 163   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 164   DCHECK(!callback.is_null());
 165
 166   stop_callback_ = callback;
 167   if (logging_state_ != STARTED) {
 168     FireGenericDoneCallback(&stop_callback_, false, "Logging not started");
 169     return;
 170   }
 171   logging_state_ = STOPPING;
 172   Send(new WebRtcLoggingMsg_StopLogging());
 173 }
 174
 175 void WebRtcLoggingHandlerHost::UploadLog(const UploadDoneCallback& callback) {
 176   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 177   DCHECK(!callback.is_null());
 178
 179   if (logging_state_ != STOPPED) {
 180     if (!callback.is_null()) {
 181       content::BrowserThread::PostTask(content::BrowserThread::UI, FROM_HERE,
 182           base::Bind(callback, false, "", kLogNotStoppedOrNoLogOpen));
 183     }
 184     return;
 185   }
 186   upload_callback_ = callback;
 187   content::BrowserThread::PostTaskAndReplyWithResult(
 188       content::BrowserThread::FILE,
 189       FROM_HERE,
 190       base::Bind(&WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists,
 191                  this),
 192       base::Bind(&WebRtcLoggingHandlerHost::TriggerUploadLog, this));
 193 }
 194
 195 void WebRtcLoggingHandlerHost::UploadLogDone() {
 196   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 197   logging_state_ = CLOSED;
 198 }
 199
 200 void WebRtcLoggingHandlerHost::DiscardLog(const GenericDoneCallback& callback) {
 201   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 202   DCHECK(!callback.is_null());
 203
 204   GenericDoneCallback discard_callback = callback;
 205   if (logging_state_ != STOPPED) {
 206     FireGenericDoneCallback(&discard_callback, false,
 207                             kLogNotStoppedOrNoLogOpen);
 208     return;
 209   }
 210   g_browser_process->webrtc_log_uploader()->LoggingStoppedDontUpload();
 211   circular_buffer_.reset();
 212   log_buffer_.reset();
 213   logging_state_ = CLOSED;
 214   FireGenericDoneCallback(&discard_callback, true, "");
 215 }
 216
 217 void WebRtcLoggingHandlerHost::LogMessage(const std::string& message) {
 218   BrowserThread::PostTask(
 219       BrowserThread::IO,
 220       FROM_HERE,
 221       base::Bind(
 222           &WebRtcLoggingHandlerHost::AddLogMessageFromBrowser,
 223           this,
 224           WebRtcLoggingMessageData(base::Time::Now(), message)));
 225 }
 226
 227 void WebRtcLoggingHandlerHost::OnChannelClosing() {
 228   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 229   if (logging_state_ == STARTED || logging_state_ == STOPPED) {
 230     if (upload_log_on_render_close_) {
 231       logging_state_ = STOPPED;
 232       logging_started_time_ = base::Time();
 233       content::BrowserThread::PostTaskAndReplyWithResult(
 234           content::BrowserThread::FILE,
 235           FROM_HERE,
 236           base::Bind(&WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists,
 237                      this),
 238           base::Bind(&WebRtcLoggingHandlerHost::TriggerUploadLog, this));
 239     } else {
 240       g_browser_process->webrtc_log_uploader()->LoggingStoppedDontUpload();
 241     }
 242   }
 243   content::BrowserMessageFilter::OnChannelClosing();
 244 }
 245
 246 void WebRtcLoggingHandlerHost::OnDestruct() const {
 247   BrowserThread::DeleteOnIOThread::Destruct(this);
 248 }
 249
 250 bool WebRtcLoggingHandlerHost::OnMessageReceived(const IPC::Message& message,
 251                                                  bool* message_was_ok) {
 252   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 253   bool handled = true;
 254   IPC_BEGIN_MESSAGE_MAP_EX(WebRtcLoggingHandlerHost, message, *message_was_ok)
 255     IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_AddLogMessages, OnAddLogMessages)
 256     IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_LoggingStopped,
 257                         OnLoggingStoppedInRenderer)
 258     IPC_MESSAGE_UNHANDLED(handled = false)
 259   IPC_END_MESSAGE_MAP_EX()
 260
 261   return handled;
 262 }
 263
 264 void WebRtcLoggingHandlerHost::AddLogMessageFromBrowser(
 265     const WebRtcLoggingMessageData& message) {
 266   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 267   if (logging_state_ == STARTED)
 268     LogToCircularBuffer(message.Format(logging_started_time_));
 269 }
 270
 271 void WebRtcLoggingHandlerHost::OnAddLogMessages(
 272     const std::vector<WebRtcLoggingMessageData>& messages) {
 273   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 274   if (logging_state_ == STARTED || logging_state_ == STOPPING) {
 275     for (size_t i = 0; i < messages.size(); ++i) {
 276       LogToCircularBuffer(messages[i].Format(logging_started_time_));
 277     }
 278   }
 279 }
 280
 281 void WebRtcLoggingHandlerHost::OnLoggingStoppedInRenderer() {
 282   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 283   if (logging_state_ != STOPPING) {
 284     // If an out-of-order response is received, stop_callback_ may be invalid,
 285     // and must not be invoked.
 286     DLOG(ERROR) << "OnLoggingStoppedInRenderer invoked in state "
 287                 << logging_state_;
 288     BadMessageReceived();
 289     return;
 290   }
 291   logging_started_time_ = base::Time();
 292   logging_state_ = STOPPED;
 293   FireGenericDoneCallback(&stop_callback_, true, "");
 294 }
 295
 296 void WebRtcLoggingHandlerHost::StartLoggingIfAllowed() {
 297   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
 298   if (!g_browser_process->webrtc_log_uploader()->ApplyForStartLogging()) {
 299     logging_state_ = CLOSED;
 300       FireGenericDoneCallback(
 301           &start_callback_, false, "Cannot start, maybe the maximum number of "
 302           "simultaneuos logs has been reached.");
 303     return;
 304   }
 305   BrowserThread::PostTask(BrowserThread::IO, FROM_HERE, base::Bind(
 306       &WebRtcLoggingHandlerHost::DoStartLogging, this));
 307 }
 308
 309 void WebRtcLoggingHandlerHost::DoStartLogging() {
 310   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 311
 312   log_buffer_.reset(new unsigned char[kWebRtcLogSize]);
 313   circular_buffer_.reset(
 314     new PartialCircularBuffer(log_buffer_.get(),
 315                               kWebRtcLogSize,
 316                               kWebRtcLogSize / 2,
 317                               false));
 318
 319   BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(
 320       &WebRtcLoggingHandlerHost::LogInitialInfoOnFileThread, this));
 321 }
 322
 323 void WebRtcLoggingHandlerHost::LogInitialInfoOnFileThread() {
 324   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
 325
 326   net::NetworkInterfaceList network_list;
 327   net::GetNetworkList(&network_list,
 328                       net::EXCLUDE_HOST_SCOPE_VIRTUAL_INTERFACES);
 329
 330   BrowserThread::PostTask(BrowserThread::IO, FROM_HERE, base::Bind(
 331       &WebRtcLoggingHandlerHost::LogInitialInfoOnIOThread, this, network_list));
 332 }
 333
 334 void WebRtcLoggingHandlerHost::LogInitialInfoOnIOThread(
 335     const net::NetworkInterfaceList& network_list) {
 336   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 337
 338   // Log start time (current time). We don't use base/i18n/time_formatting.h
 339   // here because we don't want the format of the current locale.
 340   base::Time::Exploded now = {0};
 341   base::Time::Now().LocalExplode(&now);
 342   LogToCircularBuffer(base::StringPrintf(
 343       "Start %d-%02d-%02d %02d:%02d:%02d", now.year, now.month,
 344       now.day_of_month, now.hour, now.minute, now.second));
 345
 346   // Write metadata if received before logging started.
 347   if (!meta_data_.empty()) {
 348     std::string info;
 349     FormatMetaDataAsLogMessage(meta_data_, &info);
 350     LogToCircularBuffer(info);
 351   }
 352
 353   // OS
 354   LogToCircularBuffer(base::SysInfo::OperatingSystemName() + " " +
 355                       base::SysInfo::OperatingSystemVersion() + " " +
 356                       base::SysInfo::OperatingSystemArchitecture());
 357 #if defined(OS_LINUX)
 358   LogToCircularBuffer("Linux distribution: " + base::GetLinuxDistro());
 359 #endif
 360
 361   // CPU
 362   base::CPU cpu;
 363   LogToCircularBuffer(
 364       "Cpu: " + IntToString(cpu.family()) + "." + IntToString(cpu.model()) +
 365       "." + IntToString(cpu.stepping()) + ", x" +
 366       IntToString(base::SysInfo::NumberOfProcessors()) + ", " +
 367       IntToString(base::SysInfo::AmountOfPhysicalMemoryMB()) + "MB");
 368   std::string cpu_brand = cpu.cpu_brand();
 369   // Workaround for crbug.com/249713.
 370   // TODO(grunell): Remove workaround when bug is fixed.
 371   size_t null_pos = cpu_brand.find('\0');
 372   if (null_pos != std::string::npos)
 373     cpu_brand.erase(null_pos);
 374   LogToCircularBuffer("Cpu brand: " + cpu_brand);
 375
 376   // Computer model
 377   std::string computer_model = "Not available";
 378 #if defined(OS_MACOSX)
 379   computer_model = base::mac::GetModelIdentifier();
 380 #elif defined(OS_CHROMEOS)
 381   chromeos::system::StatisticsProvider::GetInstance()->
 382       GetMachineStatistic(chromeos::system::kHardwareClassKey, &computer_model);
 383 #endif
 384   LogToCircularBuffer("Computer model: " + computer_model);
 385
 386   // GPU
 387   gpu::GPUInfo gpu_info = content::GpuDataManager::GetInstance()->GetGPUInfo();
 388   LogToCircularBuffer(
 389       "Gpu: machine-model-name='" + gpu_info.machine_model_name +
 390       "', machine-model-version=" + gpu_info.machine_model_version +
 391       "', vendor-id=" + IntToString(gpu_info.gpu.vendor_id) +
 392       ", device-id=" + IntToString(gpu_info.gpu.device_id) +
 393       ", driver-vendor='" + gpu_info.driver_vendor +
 394       "', driver-version=" + gpu_info.driver_version);
 395
 396   // Network interfaces
 397   LogToCircularBuffer("Discovered " + IntToString(network_list.size()) +
 398                       " network interfaces:");
 399   for (net::NetworkInterfaceList::const_iterator it = network_list.begin();
 400        it != network_list.end(); ++it) {
 401     LogToCircularBuffer("Name: " + it->friendly_name + ", Address: " +
 402                         IPAddressToSensitiveString(it->address));
 403   }
 404
 405   NotifyLoggingStarted();
 406 }
 407
 408 void WebRtcLoggingHandlerHost::NotifyLoggingStarted() {
 409   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 410   Send(new WebRtcLoggingMsg_StartLogging());
 411   logging_started_time_ = base::Time::Now();
 412   logging_state_ = STARTED;
 413   FireGenericDoneCallback(&start_callback_, true, "");
 414 }
 415
 416 void WebRtcLoggingHandlerHost::LogToCircularBuffer(const std::string& message) {
 417   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 418   DCHECK(circular_buffer_.get());
 419   circular_buffer_->Write(message.c_str(), message.length());
 420   const char eol = '\n';
 421   circular_buffer_->Write(&eol, 1);
 422 }
 423
 424 base::FilePath WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists() {
 425   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
 426   base::FilePath log_dir_path =
 427       WebRtcLogList::GetWebRtcLogDirectoryForProfile(profile_->GetPath());
 428   base::File::Error error;
 429   if (!base::CreateDirectoryAndGetError(log_dir_path, &error)) {
 430     DLOG(ERROR) << "Could not create WebRTC log directory, error: " << error;
 431     return base::FilePath();
 432   }
 433   return log_dir_path;
 434 }
 435
 436 void WebRtcLoggingHandlerHost::TriggerUploadLog(
 437     const base::FilePath& log_directory) {
 438   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 439   DCHECK(logging_state_ == STOPPED);
 440
 441   logging_state_ = UPLOADING;
 442   WebRtcLogUploadDoneData upload_done_data;
 443
 444   upload_done_data.log_path = log_directory;
 445   upload_done_data.callback = upload_callback_;
 446   upload_done_data.host = this;
 447   upload_callback_.Reset();
 448
 449   BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(
 450       &WebRtcLogUploader::LoggingStoppedDoUpload,
 451       base::Unretained(g_browser_process->webrtc_log_uploader()),
 452       Passed(&log_buffer_),
 453       kWebRtcLogSize,
 454       meta_data_,
 455       upload_done_data));
 456
 457   meta_data_.clear();
 458   circular_buffer_.reset();
 459 }
 460
 461 void WebRtcLoggingHandlerHost::FireGenericDoneCallback(
 462     GenericDoneCallback* callback, bool success,
 463     const std::string& error_message) {
 464   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 465   DCHECK(!(*callback).is_null());
 466   content::BrowserThread::PostTask(content::BrowserThread::UI, FROM_HERE,
 467                                    base::Bind(*callback, success,
 468                                               error_message));
 469   (*callback).Reset();
 470 }