src/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   logging_state_ = UPLOADING;
 188   content::BrowserThread::PostTaskAndReplyWithResult(
 189       content::BrowserThread::FILE,
 190       FROM_HERE,
 191       base::Bind(&WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists,
 192                  this),
 193       base::Bind(&WebRtcLoggingHandlerHost::TriggerUploadLog, this));
 194 }
 195
 196 void WebRtcLoggingHandlerHost::UploadLogDone() {
 197   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 198   logging_state_ = CLOSED;
 199 }
 200
 201 void WebRtcLoggingHandlerHost::DiscardLog(const GenericDoneCallback& callback) {
 202   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 203   DCHECK(!callback.is_null());
 204
 205   GenericDoneCallback discard_callback = callback;
 206   if (logging_state_ != STOPPED) {
 207     FireGenericDoneCallback(&discard_callback, false,
 208                             kLogNotStoppedOrNoLogOpen);
 209     return;
 210   }
 211   g_browser_process->webrtc_log_uploader()->LoggingStoppedDontUpload();
 212   circular_buffer_.reset();
 213   log_buffer_.reset();
 214   logging_state_ = CLOSED;
 215   FireGenericDoneCallback(&discard_callback, true, "");
 216 }
 217
 218 void WebRtcLoggingHandlerHost::LogMessage(const std::string& message) {
 219   BrowserThread::PostTask(
 220       BrowserThread::IO,
 221       FROM_HERE,
 222       base::Bind(
 223           &WebRtcLoggingHandlerHost::AddLogMessageFromBrowser,
 224           this,
 225           WebRtcLoggingMessageData(base::Time::Now(), message)));
 226 }
 227
 228 void WebRtcLoggingHandlerHost::StartRtpDump(
 229     bool incoming,
 230     bool outgoing,
 231     const GenericDoneCallback& callback) {
 232   NOTIMPLEMENTED();
 233 }
 234
 235 void WebRtcLoggingHandlerHost::StopRtpDump(
 236     bool incoming,
 237     bool outgoing,
 238     const GenericDoneCallback& callback) {
 239   NOTIMPLEMENTED();
 240 }
 241
 242 void WebRtcLoggingHandlerHost::OnChannelClosing() {
 243   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 244   if (logging_state_ == STARTED || logging_state_ == STOPPED) {
 245     if (upload_log_on_render_close_) {
 246       logging_state_ = UPLOADING;
 247       logging_started_time_ = base::Time();
 248       content::BrowserThread::PostTaskAndReplyWithResult(
 249           content::BrowserThread::FILE,
 250           FROM_HERE,
 251           base::Bind(&WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists,
 252                      this),
 253           base::Bind(&WebRtcLoggingHandlerHost::TriggerUploadLog, this));
 254     } else {
 255       g_browser_process->webrtc_log_uploader()->LoggingStoppedDontUpload();
 256     }
 257   }
 258   content::BrowserMessageFilter::OnChannelClosing();
 259 }
 260
 261 void WebRtcLoggingHandlerHost::OnDestruct() const {
 262   BrowserThread::DeleteOnIOThread::Destruct(this);
 263 }
 264
 265 bool WebRtcLoggingHandlerHost::OnMessageReceived(const IPC::Message& message,
 266                                                  bool* message_was_ok) {
 267   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 268   bool handled = true;
 269   IPC_BEGIN_MESSAGE_MAP_EX(WebRtcLoggingHandlerHost, message, *message_was_ok)
 270     IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_AddLogMessages, OnAddLogMessages)
 271     IPC_MESSAGE_HANDLER(WebRtcLoggingMsg_LoggingStopped,
 272                         OnLoggingStoppedInRenderer)
 273     IPC_MESSAGE_UNHANDLED(handled = false)
 274   IPC_END_MESSAGE_MAP_EX()
 275
 276   return handled;
 277 }
 278
 279 void WebRtcLoggingHandlerHost::AddLogMessageFromBrowser(
 280     const WebRtcLoggingMessageData& message) {
 281   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 282   if (logging_state_ == STARTED)
 283     LogToCircularBuffer(message.Format(logging_started_time_));
 284 }
 285
 286 void WebRtcLoggingHandlerHost::OnAddLogMessages(
 287     const std::vector<WebRtcLoggingMessageData>& messages) {
 288   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 289   if (logging_state_ == STARTED || logging_state_ == STOPPING) {
 290     for (size_t i = 0; i < messages.size(); ++i) {
 291       LogToCircularBuffer(messages[i].Format(logging_started_time_));
 292     }
 293   }
 294 }
 295
 296 void WebRtcLoggingHandlerHost::OnLoggingStoppedInRenderer() {
 297   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 298   if (logging_state_ != STOPPING) {
 299     // If an out-of-order response is received, stop_callback_ may be invalid,
 300     // and must not be invoked.
 301     DLOG(ERROR) << "OnLoggingStoppedInRenderer invoked in state "
 302                 << logging_state_;
 303     BadMessageReceived();
 304     return;
 305   }
 306   logging_started_time_ = base::Time();
 307   logging_state_ = STOPPED;
 308   FireGenericDoneCallback(&stop_callback_, true, "");
 309 }
 310
 311 void WebRtcLoggingHandlerHost::StartLoggingIfAllowed() {
 312   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
 313   if (!g_browser_process->webrtc_log_uploader()->ApplyForStartLogging()) {
 314     logging_state_ = CLOSED;
 315       FireGenericDoneCallback(
 316           &start_callback_, false, "Cannot start, maybe the maximum number of "
 317           "simultaneuos logs has been reached.");
 318     return;
 319   }
 320   BrowserThread::PostTask(BrowserThread::IO, FROM_HERE, base::Bind(
 321       &WebRtcLoggingHandlerHost::DoStartLogging, this));
 322 }
 323
 324 void WebRtcLoggingHandlerHost::DoStartLogging() {
 325   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 326
 327   log_buffer_.reset(new unsigned char[kWebRtcLogSize]);
 328   circular_buffer_.reset(
 329     new PartialCircularBuffer(log_buffer_.get(),
 330                               kWebRtcLogSize,
 331                               kWebRtcLogSize / 2,
 332                               false));
 333
 334   BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(
 335       &WebRtcLoggingHandlerHost::LogInitialInfoOnFileThread, this));
 336 }
 337
 338 void WebRtcLoggingHandlerHost::LogInitialInfoOnFileThread() {
 339   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
 340
 341   net::NetworkInterfaceList network_list;
 342   net::GetNetworkList(&network_list,
 343                       net::EXCLUDE_HOST_SCOPE_VIRTUAL_INTERFACES);
 344
 345   BrowserThread::PostTask(BrowserThread::IO, FROM_HERE, base::Bind(
 346       &WebRtcLoggingHandlerHost::LogInitialInfoOnIOThread, this, network_list));
 347 }
 348
 349 void WebRtcLoggingHandlerHost::LogInitialInfoOnIOThread(
 350     const net::NetworkInterfaceList& network_list) {
 351   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 352
 353   // Log start time (current time). We don't use base/i18n/time_formatting.h
 354   // here because we don't want the format of the current locale.
 355   base::Time::Exploded now = {0};
 356   base::Time::Now().LocalExplode(&now);
 357   LogToCircularBuffer(base::StringPrintf(
 358       "Start %d-%02d-%02d %02d:%02d:%02d", now.year, now.month,
 359       now.day_of_month, now.hour, now.minute, now.second));
 360
 361   // Write metadata if received before logging started.
 362   if (!meta_data_.empty()) {
 363     std::string info;
 364     FormatMetaDataAsLogMessage(meta_data_, &info);
 365     LogToCircularBuffer(info);
 366   }
 367
 368   // OS
 369   LogToCircularBuffer(base::SysInfo::OperatingSystemName() + " " +
 370                       base::SysInfo::OperatingSystemVersion() + " " +
 371                       base::SysInfo::OperatingSystemArchitecture());
 372 #if defined(OS_LINUX)
 373   LogToCircularBuffer("Linux distribution: " + base::GetLinuxDistro());
 374 #endif
 375
 376   // CPU
 377   base::CPU cpu;
 378   LogToCircularBuffer(
 379       "Cpu: " + IntToString(cpu.family()) + "." + IntToString(cpu.model()) +
 380       "." + IntToString(cpu.stepping()) + ", x" +
 381       IntToString(base::SysInfo::NumberOfProcessors()) + ", " +
 382       IntToString(base::SysInfo::AmountOfPhysicalMemoryMB()) + "MB");
 383   std::string cpu_brand = cpu.cpu_brand();
 384   // Workaround for crbug.com/249713.
 385   // TODO(grunell): Remove workaround when bug is fixed.
 386   size_t null_pos = cpu_brand.find('\0');
 387   if (null_pos != std::string::npos)
 388     cpu_brand.erase(null_pos);
 389   LogToCircularBuffer("Cpu brand: " + cpu_brand);
 390
 391   // Computer model
 392   std::string computer_model = "Not available";
 393 #if defined(OS_MACOSX)
 394   computer_model = base::mac::GetModelIdentifier();
 395 #elif defined(OS_CHROMEOS)
 396   chromeos::system::StatisticsProvider::GetInstance()->
 397       GetMachineStatistic(chromeos::system::kHardwareClassKey, &computer_model);
 398 #endif
 399   LogToCircularBuffer("Computer model: " + computer_model);
 400
 401   // GPU
 402   gpu::GPUInfo gpu_info = content::GpuDataManager::GetInstance()->GetGPUInfo();
 403   LogToCircularBuffer(
 404       "Gpu: machine-model-name=" + gpu_info.machine_model_name +
 405       ", machine-model-version=" + gpu_info.machine_model_version +
 406       ", vendor-id=" + IntToString(gpu_info.gpu.vendor_id) +
 407       ", device-id=" + IntToString(gpu_info.gpu.device_id) +
 408       ", driver-vendor=" + gpu_info.driver_vendor +
 409       ", driver-version=" + gpu_info.driver_version);
 410   LogToCircularBuffer(
 411       "OpenGL: gl-vendor=" + gpu_info.gl_vendor +
 412       ", gl-renderer=" + gpu_info.gl_renderer +
 413       ", gl-version=" + gpu_info.gl_version);
 414
 415   // Network interfaces
 416   LogToCircularBuffer("Discovered " + IntToString(network_list.size()) +
 417                       " network interfaces:");
 418   for (net::NetworkInterfaceList::const_iterator it = network_list.begin();
 419        it != network_list.end(); ++it) {
 420     LogToCircularBuffer("Name: " + it->friendly_name + ", Address: " +
 421                         IPAddressToSensitiveString(it->address));
 422   }
 423
 424   NotifyLoggingStarted();
 425 }
 426
 427 void WebRtcLoggingHandlerHost::NotifyLoggingStarted() {
 428   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 429   Send(new WebRtcLoggingMsg_StartLogging());
 430   logging_started_time_ = base::Time::Now();
 431   logging_state_ = STARTED;
 432   FireGenericDoneCallback(&start_callback_, true, "");
 433 }
 434
 435 void WebRtcLoggingHandlerHost::LogToCircularBuffer(const std::string& message) {
 436   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 437   DCHECK(circular_buffer_.get());
 438   circular_buffer_->Write(message.c_str(), message.length());
 439   const char eol = '\n';
 440   circular_buffer_->Write(&eol, 1);
 441 }
 442
 443 base::FilePath WebRtcLoggingHandlerHost::GetLogDirectoryAndEnsureExists() {
 444   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
 445   base::FilePath log_dir_path =
 446       WebRtcLogList::GetWebRtcLogDirectoryForProfile(profile_->GetPath());
 447   base::File::Error error;
 448   if (!base::CreateDirectoryAndGetError(log_dir_path, &error)) {
 449     DLOG(ERROR) << "Could not create WebRTC log directory, error: " << error;
 450     return base::FilePath();
 451   }
 452   return log_dir_path;
 453 }
 454
 455 void WebRtcLoggingHandlerHost::TriggerUploadLog(
 456     const base::FilePath& log_directory) {
 457   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 458   DCHECK_EQ(logging_state_, UPLOADING);
 459
 460   WebRtcLogUploadDoneData upload_done_data;
 461   upload_done_data.log_path = log_directory;
 462   upload_done_data.callback = upload_callback_;
 463   upload_done_data.host = this;
 464   upload_callback_.Reset();
 465
 466   BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(
 467       &WebRtcLogUploader::LoggingStoppedDoUpload,
 468       base::Unretained(g_browser_process->webrtc_log_uploader()),
 469       Passed(&log_buffer_),
 470       kWebRtcLogSize,
 471       meta_data_,
 472       upload_done_data));
 473
 474   meta_data_.clear();
 475   circular_buffer_.reset();
 476 }
 477
 478 void WebRtcLoggingHandlerHost::FireGenericDoneCallback(
 479     GenericDoneCallback* callback, bool success,
 480     const std::string& error_message) {
 481   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 482   DCHECK(!(*callback).is_null());
 483   content::BrowserThread::PostTask(content::BrowserThread::UI, FROM_HERE,
 484                                    base::Bind(*callback, success,
 485                                               error_message));
 486   (*callback).Reset();
 487 }