chrome_frame/metrics_service.cc

   1 // Copyright (c) 2011 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 //------------------------------------------------------------------------------
   6 // Description of the life cycle of a instance of MetricsService.
   7 //
   8 //  OVERVIEW
   9 //
  10 // A MetricsService instance is created at ChromeFrame startup in
  11 // the IE process. It is the central controller for the UMA log data.
  12 // Its major job is to manage logs, prepare them for transmission.
  13 // Currently only histogram data is tracked in log.  When MetricsService
  14 // prepares log for submission it snapshots the current stats of histograms,
  15 // translates log to XML.  Transmission includes submitting a compressed log
  16 // as data in a URL-get, and is performed using functionality provided by
  17 // Urlmon
  18 // The actual transmission is performed using a windows timer procedure which
  19 // basically means that the thread on which the MetricsService object is
  20 // instantiated needs a message pump. Also on IE7 where every tab is created
  21 // on its own thread we would have a case where the timer procedures can
  22 // compete for sending histograms.
  23 //
  24 // When preparing log for submission we acquire a list of all local histograms
  25 // that have been flagged for upload to the UMA server.
  26 //
  27 // When ChromeFrame shuts down, there will typically be a fragment of an ongoing
  28 // log that has not yet been transmitted.  Currently this data is ignored.
  29 //
  30 // With the above overview, we can now describe the state machine's various
  31 // stats, based on the State enum specified in the state_ member.  Those states
  32 // are:
  33 //
  34 //    INITIALIZED,      // Constructor was called.
  35 //    ACTIVE,           // Accumalating log data.
  36 //    STOPPED,          // Service has stopped.
  37 //
  38 //-----------------------------------------------------------------------------
  39
  40 #include "chrome_frame/metrics_service.h"
  41
  42 #include <atlbase.h>
  43 #include <atlwin.h>
  44 #include <objbase.h>
  45 #include <windows.h>
  46
  47 #if defined(USE_SYSTEM_LIBBZ2)
  48 #include <bzlib.h>
  49 #else
  50 #include "third_party/bzip2/bzlib.h"
  51 #endif
  52
  53 #include "base/string_util.h"
  54 #include "base/stringprintf.h"
  55 #include "base/synchronization/lock.h"
  56 #include "base/string_number_conversions.h"
  57 #include "base/utf_string_conversions.h"
  58 #include "base/win/scoped_comptr.h"
  59 #include "chrome/common/chrome_version_info.h"
  60 #include "chrome/installer/util/browser_distribution.h"
  61 #include "chrome/installer/util/google_update_settings.h"
  62 #include "chrome_frame/bind_status_callback_impl.h"
  63 #include "chrome_frame/crash_reporting/crash_metrics.h"
  64 #include "chrome_frame/html_utils.h"
  65 #include "chrome_frame/utils.h"
  66
  67 using base::Time;
  68 using base::TimeDelta;
  69 using base::win::ScopedComPtr;
  70
  71 static const char kMetricsType[] = "application/vnd.mozilla.metrics.bz2";
  72
  73 // The first UMA upload occurs after this interval.
  74 static const int kInitialUMAUploadTimeoutMilliSeconds = 30000;
  75
  76 // Default to one UMA upload per 10 mins.
  77 static const int kMinMilliSecondsPerUMAUpload = 600000;
  78
  79 base::LazyInstance<base::ThreadLocalPointer<MetricsService> >
  80     MetricsService::g_metrics_instance_(base::LINKER_INITIALIZED);
  81
  82 base::Lock MetricsService::metrics_service_lock_;
  83
  84 // This class provides functionality to upload the ChromeFrame UMA data to the
  85 // server. An instance of this class is created whenever we have data to be
  86 // uploaded to the server.
  87 class ChromeFrameMetricsDataUploader : public BSCBImpl {
  88  public:
  89   ChromeFrameMetricsDataUploader()
  90       : cache_stream_(NULL),
  91         upload_data_size_(0) {
  92     DVLOG(1) << __FUNCTION__;
  93   }
  94
  95   ~ChromeFrameMetricsDataUploader() {
  96     DVLOG(1) << __FUNCTION__;
  97   }
  98
  99   static HRESULT ChromeFrameMetricsDataUploader::UploadDataHelper(
 100       const std::string& upload_data) {
 101     CComObject<ChromeFrameMetricsDataUploader>* data_uploader = NULL;
 102     CComObject<ChromeFrameMetricsDataUploader>::CreateInstance(&data_uploader);
 103     DCHECK(data_uploader != NULL);
 104
 105     data_uploader->AddRef();
 106     HRESULT hr = data_uploader->UploadData(upload_data);
 107     if (FAILED(hr)) {
 108       DLOG(ERROR) << "Failed to initialize ChromeFrame UMA data uploader: Err"
 109                   << hr;
 110     }
 111     data_uploader->Release();
 112     return hr;
 113   }
 114
 115   HRESULT UploadData(const std::string& upload_data) {
 116     if (upload_data.empty()) {
 117       NOTREACHED() << "Invalid upload data";
 118       return E_INVALIDARG;
 119     }
 120
 121     DCHECK(cache_stream_.get() == NULL);
 122
 123     upload_data_size_ = upload_data.size() + 1;
 124
 125     HRESULT hr = CreateStreamOnHGlobal(NULL, TRUE, cache_stream_.Receive());
 126     if (FAILED(hr)) {
 127       NOTREACHED() << "Failed to create stream. Error:"
 128                    << hr;
 129       return hr;
 130     }
 131
 132     DCHECK(cache_stream_.get());
 133
 134     unsigned long written = 0;
 135     cache_stream_->Write(upload_data.c_str(), upload_data_size_, &written);
 136     DCHECK(written == upload_data_size_);
 137
 138     RewindStream(cache_stream_);
 139
 140     BrowserDistribution* dist = BrowserDistribution::GetSpecificDistribution(
 141         BrowserDistribution::CHROME_FRAME);
 142     server_url_ = dist->GetStatsServerURL();
 143     DCHECK(!server_url_.empty());
 144
 145     hr = CreateURLMoniker(NULL, server_url_.c_str(),
 146                           upload_moniker_.Receive());
 147     if (FAILED(hr)) {
 148       DLOG(ERROR) << "Failed to create url moniker for url:"
 149                   << server_url_.c_str()
 150                   << " Error:"
 151                   << hr;
 152     } else {
 153       ScopedComPtr<IBindCtx> context;
 154       hr = CreateAsyncBindCtx(0, this, NULL, context.Receive());
 155       DCHECK(SUCCEEDED(hr));
 156       DCHECK(context);
 157
 158       ScopedComPtr<IStream> stream;
 159       hr = upload_moniker_->BindToStorage(
 160           context, NULL, IID_IStream,
 161           reinterpret_cast<void**>(stream.Receive()));
 162       if (FAILED(hr)) {
 163         NOTREACHED();
 164         DLOG(ERROR) << "Failed to bind to upload data moniker. Error:"
 165                     << hr;
 166       }
 167     }
 168     return hr;
 169   }
 170
 171   STDMETHOD(BeginningTransaction)(LPCWSTR url, LPCWSTR headers, DWORD reserved,
 172                                   LPWSTR* additional_headers) {
 173     std::string new_headers;
 174     new_headers =
 175         StringPrintf("Content-Length: %s\r\n"
 176                      "Content-Type: %s\r\n"
 177                      "%s\r\n",
 178                      base::Int64ToString(upload_data_size_).c_str(),
 179                      kMetricsType,
 180                      http_utils::GetDefaultUserAgentHeaderWithCFTag().c_str());
 181
 182     *additional_headers = reinterpret_cast<wchar_t*>(
 183         CoTaskMemAlloc((new_headers.size() + 1) * sizeof(wchar_t)));
 184
 185     lstrcpynW(*additional_headers, ASCIIToWide(new_headers).c_str(),
 186               new_headers.size());
 187
 188     return BSCBImpl::BeginningTransaction(url, headers, reserved,
 189                                           additional_headers);
 190   }
 191
 192   STDMETHOD(GetBindInfo)(DWORD* bind_flags, BINDINFO* bind_info) {
 193     if ((bind_info == NULL) || (bind_info->cbSize == 0) ||
 194         (bind_flags == NULL))
 195       return E_INVALIDARG;
 196
 197     *bind_flags = BINDF_ASYNCHRONOUS | BINDF_ASYNCSTORAGE | BINDF_PULLDATA;
 198     // Bypass caching proxies on POSTs and PUTs and avoid writing responses to
 199     // these requests to the browser's cache
 200     *bind_flags |= BINDF_GETNEWESTVERSION | BINDF_PRAGMA_NO_CACHE;
 201
 202     DCHECK(cache_stream_.get());
 203
 204     // Initialize the STGMEDIUM.
 205     memset(&bind_info->stgmedData, 0, sizeof(STGMEDIUM));
 206     bind_info->grfBindInfoF = 0;
 207     bind_info->szCustomVerb = NULL;
 208     bind_info->dwBindVerb = BINDVERB_POST;
 209     bind_info->stgmedData.tymed = TYMED_ISTREAM;
 210     bind_info->stgmedData.pstm = cache_stream_.get();
 211     bind_info->stgmedData.pstm->AddRef();
 212     return BSCBImpl::GetBindInfo(bind_flags, bind_info);
 213   }
 214
 215   STDMETHOD(OnResponse)(DWORD response_code, LPCWSTR response_headers,
 216                         LPCWSTR request_headers, LPWSTR* additional_headers) {
 217     DVLOG(1) << __FUNCTION__ << " headers: \n" << response_headers;
 218     return BSCBImpl::OnResponse(response_code, response_headers,
 219                                 request_headers, additional_headers);
 220   }
 221
 222  private:
 223   std::wstring server_url_;
 224   size_t upload_data_size_;
 225   ScopedComPtr<IStream> cache_stream_;
 226   ScopedComPtr<IMoniker> upload_moniker_;
 227 };
 228
 229 MetricsService* MetricsService::GetInstance() {
 230   if (g_metrics_instance_.Pointer()->Get())
 231     return g_metrics_instance_.Pointer()->Get();
 232
 233   g_metrics_instance_.Pointer()->Set(new MetricsService);
 234   return g_metrics_instance_.Pointer()->Get();
 235 }
 236
 237 MetricsService::MetricsService()
 238     : recording_active_(false),
 239       reporting_active_(false),
 240       user_permits_upload_(false),
 241       state_(INITIALIZED),
 242       thread_(NULL),
 243       initial_uma_upload_(true),
 244       transmission_timer_id_(0) {
 245 }
 246
 247 MetricsService::~MetricsService() {
 248   SetRecording(false);
 249   if (pending_log_) {
 250     delete pending_log_;
 251     pending_log_ = NULL;
 252   }
 253   if (current_log_) {
 254     delete current_log_;
 255     current_log_ = NULL;
 256   }
 257 }
 258
 259 void MetricsService::InitializeMetricsState() {
 260   DCHECK(state_ == INITIALIZED);
 261
 262   thread_ = base::PlatformThread::CurrentId();
 263
 264   user_permits_upload_ = GoogleUpdateSettings::GetCollectStatsConsent();
 265   // Update session ID
 266   session_id_ = CrashMetricsReporter::GetInstance()->IncrementMetric(
 267       CrashMetricsReporter::SESSION_ID);
 268
 269   // Ensure that an instance of the StatisticsRecorder object is created.
 270   CrashMetricsReporter::GetInstance()->set_active(true);
 271 }
 272
 273 // static
 274 void MetricsService::Start() {
 275   base::AutoLock lock(metrics_service_lock_);
 276
 277   if (GetInstance()->state_ == ACTIVE)
 278     return;
 279
 280   GetInstance()->InitializeMetricsState();
 281   GetInstance()->SetRecording(true);
 282   GetInstance()->SetReporting(true);
 283 }
 284
 285 // static
 286 void MetricsService::Stop() {
 287   base::AutoLock lock(metrics_service_lock_);
 288
 289   GetInstance()->SetReporting(false);
 290   GetInstance()->SetRecording(false);
 291 }
 292
 293 void MetricsService::SetRecording(bool enabled) {
 294   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 295   if (enabled == recording_active_)
 296     return;
 297
 298   if (enabled) {
 299     if (client_id_.empty()) {
 300       client_id_ = GenerateClientID();
 301       // Save client id somewhere.
 302     }
 303     StartRecording();
 304
 305   } else {
 306     state_ = STOPPED;
 307   }
 308   recording_active_ = enabled;
 309 }
 310
 311 // static
 312 std::string MetricsService::GenerateClientID() {
 313   const int kGUIDSize = 39;
 314
 315   GUID guid;
 316   HRESULT guid_result = CoCreateGuid(&guid);
 317   DCHECK(SUCCEEDED(guid_result));
 318
 319   std::wstring guid_string;
 320   int result = StringFromGUID2(guid,
 321                                WriteInto(&guid_string, kGUIDSize), kGUIDSize);
 322   DCHECK(result == kGUIDSize);
 323   return WideToUTF8(guid_string.substr(1, guid_string.length() - 2));
 324 }
 325
 326 // static
 327 void CALLBACK MetricsService::TransmissionTimerProc(HWND window,
 328                                                     unsigned int message,
 329                                                     unsigned int event_id,
 330                                                     unsigned int time) {
 331   DVLOG(1) << "Transmission timer notified";
 332   DCHECK(GetInstance() != NULL);
 333   GetInstance()->UploadData();
 334   if (GetInstance()->initial_uma_upload_) {
 335     // If this is the first uma upload by this process then subsequent uma
 336     // uploads should occur once every 10 minutes(default).
 337     GetInstance()->initial_uma_upload_ = false;
 338     DCHECK(GetInstance()->transmission_timer_id_ != 0);
 339     SetTimer(NULL, GetInstance()->transmission_timer_id_,
 340              kMinMilliSecondsPerUMAUpload,
 341              reinterpret_cast<TIMERPROC>(TransmissionTimerProc));
 342   }
 343 }
 344
 345 void MetricsService::SetReporting(bool enable) {
 346   static const int kChromeFrameMetricsTimerId = 0xFFFFFFFF;
 347
 348   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 349   if (reporting_active_ != enable) {
 350     reporting_active_ = enable;
 351     if (reporting_active_) {
 352       transmission_timer_id_ =
 353           SetTimer(NULL, kChromeFrameMetricsTimerId,
 354                    kInitialUMAUploadTimeoutMilliSeconds,
 355                    reinterpret_cast<TIMERPROC>(TransmissionTimerProc));
 356     } else {
 357       UploadData();
 358     }
 359   }
 360 }
 361
 362 //------------------------------------------------------------------------------
 363 // Recording control methods
 364
 365 void MetricsService::StartRecording() {
 366   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 367   if (current_log_)
 368     return;
 369
 370   current_log_ = new MetricsLogBase(client_id_, session_id_,
 371                                     GetVersionString());
 372   if (state_ == INITIALIZED)
 373     state_ = ACTIVE;
 374 }
 375
 376 void MetricsService::StopRecording(bool save_log) {
 377   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 378   if (!current_log_)
 379     return;
 380
 381   // Put incremental histogram deltas at the end of all log transmissions.
 382   // Don't bother if we're going to discard current_log_.
 383   if (save_log) {
 384     CrashMetricsReporter::GetInstance()->RecordCrashMetrics();
 385     RecordCurrentHistograms();
 386   }
 387
 388   if (save_log) {
 389     pending_log_ = current_log_;
 390   }
 391   current_log_ = NULL;
 392 }
 393
 394 void MetricsService::MakePendingLog() {
 395   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 396   if (pending_log())
 397     return;
 398
 399   switch (state_) {
 400     case INITIALIZED:  // We should be further along by now.
 401       DCHECK(false);
 402       return;
 403
 404     case ACTIVE:
 405       StopRecording(true);
 406       StartRecording();
 407       break;
 408
 409     default:
 410       DCHECK(false);
 411       return;
 412   }
 413
 414   DCHECK(pending_log());
 415 }
 416
 417 bool MetricsService::TransmissionPermitted() const {
 418   // If the user forbids uploading that's their business, and we don't upload
 419   // anything.
 420   return user_permits_upload_;
 421 }
 422
 423 std::string MetricsService::PrepareLogSubmissionString() {
 424   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 425
 426   MakePendingLog();
 427   DCHECK(pending_log());
 428   if (pending_log_== NULL) {
 429     return std::string();
 430   }
 431
 432   pending_log_->CloseLog();
 433   std::string pending_log_text = pending_log_->GetEncodedLogString();
 434   DCHECK(!pending_log_text.empty());
 435   DiscardPendingLog();
 436   return pending_log_text;
 437 }
 438
 439 bool MetricsService::UploadData() {
 440   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 441
 442   if (!GetInstance()->TransmissionPermitted())
 443     return false;
 444
 445   static long currently_uploading = 0;
 446   if (InterlockedCompareExchange(&currently_uploading, 1, 0)) {
 447     DVLOG(1) << "Contention for uploading metrics data. Backing off";
 448     return false;
 449   }
 450
 451   std::string pending_log_text = PrepareLogSubmissionString();
 452   DCHECK(!pending_log_text.empty());
 453
 454   // Allow security conscious users to see all metrics logs that we send.
 455   VLOG(1) << "METRICS LOG: " << pending_log_text;
 456
 457   bool ret = true;
 458
 459   if (!Bzip2Compress(pending_log_text, &compressed_log_)) {
 460     NOTREACHED() << "Failed to compress log for transmission.";
 461     ret = false;
 462   } else {
 463     HRESULT hr = ChromeFrameMetricsDataUploader::UploadDataHelper(
 464         compressed_log_);
 465     DCHECK(SUCCEEDED(hr));
 466   }
 467   DiscardPendingLog();
 468
 469   currently_uploading = 0;
 470   return ret;
 471 }
 472
 473 // static
 474 std::string MetricsService::GetVersionString() {
 475   chrome::VersionInfo version_info;
 476   if (version_info.is_valid()) {
 477     std::string version = version_info.Version();
 478     // Add the -F extensions to ensure that UMA data uploaded by ChromeFrame
 479     // lands in the ChromeFrame bucket.
 480     version += "-F";
 481     if (!version_info.IsOfficialBuild())
 482       version.append("-devel");
 483     return version;
 484   } else {
 485     NOTREACHED() << "Unable to retrieve version string.";
 486   }
 487
 488   return std::string();
 489 }