chrome_frame/metrics_service.cc

   1 // Copyright (c) 2012 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/metrics/statistics_recorder.h"
  54 #include "base/string16.h"
  55 #include "base/string_util.h"
  56 #include "base/stringprintf.h"
  57 #include "base/synchronization/lock.h"
  58 #include "base/string_number_conversions.h"
  59 #include "base/utf_string_conversions.h"
  60 #include "base/win/scoped_comptr.h"
  61 #include "chrome/common/chrome_version_info.h"
  62 #include "chrome/common/metrics/metrics_log_base.h"
  63 #include "chrome/common/metrics/metrics_log_manager.h"
  64 #include "chrome/installer/util/browser_distribution.h"
  65 #include "chrome/installer/util/google_update_settings.h"
  66 #include "chrome_frame/bind_status_callback_impl.h"
  67 #include "chrome_frame/crash_reporting/crash_metrics.h"
  68 #include "chrome_frame/html_utils.h"
  69 #include "chrome_frame/utils.h"
  70
  71 using base::Time;
  72 using base::TimeDelta;
  73 using base::win::ScopedComPtr;
  74
  75 // The first UMA upload occurs after this interval.
  76 static const int kInitialUMAUploadTimeoutMilliSeconds = 30000;
  77
  78 // Default to one UMA upload per 10 mins.
  79 static const int kMinMilliSecondsPerUMAUpload = 600000;
  80
  81 base::LazyInstance<base::ThreadLocalPointer<MetricsService> >
  82     MetricsService::g_metrics_instance_ = LAZY_INSTANCE_INITIALIZER;
  83
  84 std::string MetricsService::client_id_;
  85
  86 base::Lock MetricsService::metrics_service_lock_;
  87
  88 // This class provides functionality to upload the ChromeFrame UMA data to the
  89 // server. An instance of this class is created whenever we have data to be
  90 // uploaded to the server.
  91 class ChromeFrameMetricsDataUploader : public BSCBImpl {
  92  public:
  93   ChromeFrameMetricsDataUploader()
  94       : cache_stream_(NULL),
  95         upload_data_size_(0) {
  96     DVLOG(1) << __FUNCTION__;
  97   }
  98
  99   ~ChromeFrameMetricsDataUploader() {
 100     DVLOG(1) << __FUNCTION__;
 101   }
 102
 103   static HRESULT ChromeFrameMetricsDataUploader::UploadDataHelper(
 104       const std::string& upload_data,
 105       const std::string& server_url,
 106       const std::string& mime_type) {
 107     CComObject<ChromeFrameMetricsDataUploader>* data_uploader = NULL;
 108     CComObject<ChromeFrameMetricsDataUploader>::CreateInstance(&data_uploader);
 109     DCHECK(data_uploader != NULL);
 110
 111     data_uploader->AddRef();
 112     HRESULT hr = data_uploader->UploadData(upload_data, server_url, mime_type);
 113     if (FAILED(hr)) {
 114       DLOG(ERROR) << "Failed to initialize ChromeFrame UMA data uploader: Err"
 115                   << hr;
 116     }
 117     data_uploader->Release();
 118     return hr;
 119   }
 120
 121   HRESULT UploadData(const std::string& upload_data,
 122                      const std::string& server_url,
 123                      const std::string& mime_type) {
 124     if (upload_data.empty()) {
 125       NOTREACHED() << "Invalid upload data";
 126       return E_INVALIDARG;
 127     }
 128
 129     DCHECK(cache_stream_.get() == NULL);
 130
 131     upload_data_size_ = upload_data.size() + 1;
 132
 133     HRESULT hr = CreateStreamOnHGlobal(NULL, TRUE, cache_stream_.Receive());
 134     if (FAILED(hr)) {
 135       NOTREACHED() << "Failed to create stream. Error:"
 136                    << hr;
 137       return hr;
 138     }
 139
 140     DCHECK(cache_stream_.get());
 141
 142     unsigned long written = 0;
 143     cache_stream_->Write(upload_data.c_str(), upload_data_size_, &written);
 144     DCHECK(written == upload_data_size_);
 145
 146     RewindStream(cache_stream_);
 147
 148     server_url_ = ASCIIToWide(server_url);
 149     mime_type_ = mime_type;
 150     DCHECK(!server_url_.empty());
 151     DCHECK(!mime_type_.empty());
 152
 153     hr = CreateURLMoniker(NULL, server_url_.c_str(),
 154                           upload_moniker_.Receive());
 155     if (FAILED(hr)) {
 156       DLOG(ERROR) << "Failed to create url moniker for url:"
 157                   << server_url_.c_str()
 158                   << " Error:"
 159                   << hr;
 160     } else {
 161       ScopedComPtr<IBindCtx> context;
 162       hr = CreateAsyncBindCtx(0, this, NULL, context.Receive());
 163       DCHECK(SUCCEEDED(hr));
 164       DCHECK(context);
 165
 166       ScopedComPtr<IStream> stream;
 167       hr = upload_moniker_->BindToStorage(
 168           context, NULL, IID_IStream,
 169           reinterpret_cast<void**>(stream.Receive()));
 170       if (FAILED(hr)) {
 171         NOTREACHED();
 172         DLOG(ERROR) << "Failed to bind to upload data moniker. Error:"
 173                     << hr;
 174       }
 175     }
 176     return hr;
 177   }
 178
 179   STDMETHOD(BeginningTransaction)(LPCWSTR url, LPCWSTR headers, DWORD reserved,
 180                                   LPWSTR* additional_headers) {
 181     std::string new_headers;
 182     new_headers =
 183         base::StringPrintf(
 184             "Content-Length: %s\r\n"
 185             "Content-Type: %s\r\n"
 186             "%s\r\n",
 187             base::Int64ToString(upload_data_size_).c_str(),
 188             mime_type_.c_str(),
 189             http_utils::GetDefaultUserAgentHeaderWithCFTag().c_str());
 190
 191     *additional_headers = reinterpret_cast<wchar_t*>(
 192         CoTaskMemAlloc((new_headers.size() + 1) * sizeof(wchar_t)));
 193
 194     lstrcpynW(*additional_headers, ASCIIToWide(new_headers).c_str(),
 195               new_headers.size());
 196
 197     return BSCBImpl::BeginningTransaction(url, headers, reserved,
 198                                           additional_headers);
 199   }
 200
 201   STDMETHOD(GetBindInfo)(DWORD* bind_flags, BINDINFO* bind_info) {
 202     if ((bind_info == NULL) || (bind_info->cbSize == 0) ||
 203         (bind_flags == NULL))
 204       return E_INVALIDARG;
 205
 206     *bind_flags = BINDF_ASYNCHRONOUS | BINDF_ASYNCSTORAGE | BINDF_PULLDATA;
 207     // Bypass caching proxies on POSTs and PUTs and avoid writing responses to
 208     // these requests to the browser's cache
 209     *bind_flags |= BINDF_GETNEWESTVERSION | BINDF_PRAGMA_NO_CACHE;
 210
 211     DCHECK(cache_stream_.get());
 212
 213     // Initialize the STGMEDIUM.
 214     memset(&bind_info->stgmedData, 0, sizeof(STGMEDIUM));
 215     bind_info->grfBindInfoF = 0;
 216     bind_info->szCustomVerb = NULL;
 217     bind_info->dwBindVerb = BINDVERB_POST;
 218     bind_info->stgmedData.tymed = TYMED_ISTREAM;
 219     bind_info->stgmedData.pstm = cache_stream_.get();
 220     bind_info->stgmedData.pstm->AddRef();
 221     return BSCBImpl::GetBindInfo(bind_flags, bind_info);
 222   }
 223
 224   STDMETHOD(OnResponse)(DWORD response_code, LPCWSTR response_headers,
 225                         LPCWSTR request_headers, LPWSTR* additional_headers) {
 226     DVLOG(1) << __FUNCTION__ << " headers: \n" << response_headers;
 227     return BSCBImpl::OnResponse(response_code, response_headers,
 228                                 request_headers, additional_headers);
 229   }
 230
 231  private:
 232   std::wstring server_url_;
 233   std::string mime_type_;
 234   size_t upload_data_size_;
 235   ScopedComPtr<IStream> cache_stream_;
 236   ScopedComPtr<IMoniker> upload_moniker_;
 237 };
 238
 239 MetricsService* MetricsService::GetInstance() {
 240   if (g_metrics_instance_.Pointer()->Get())
 241     return g_metrics_instance_.Pointer()->Get();
 242
 243   g_metrics_instance_.Pointer()->Set(new MetricsService);
 244   return g_metrics_instance_.Pointer()->Get();
 245 }
 246
 247 MetricsService::MetricsService()
 248     : recording_active_(false),
 249       reporting_active_(false),
 250       user_permits_upload_(false),
 251       state_(INITIALIZED),
 252       thread_(NULL),
 253       initial_uma_upload_(true),
 254       transmission_timer_id_(0) {
 255 }
 256
 257 MetricsService::~MetricsService() {
 258   SetRecording(false);
 259 }
 260
 261 void MetricsService::InitializeMetricsState() {
 262   DCHECK(state_ == INITIALIZED);
 263
 264   thread_ = base::PlatformThread::CurrentId();
 265
 266   user_permits_upload_ = GoogleUpdateSettings::GetCollectStatsConsent();
 267   // Update session ID
 268   session_id_ = CrashMetricsReporter::GetInstance()->IncrementMetric(
 269       CrashMetricsReporter::SESSION_ID);
 270
 271   base::StatisticsRecorder::Initialize();
 272   CrashMetricsReporter::GetInstance()->set_active(true);
 273 }
 274
 275 // static
 276 void MetricsService::Start() {
 277   base::AutoLock lock(metrics_service_lock_);
 278
 279   if (GetInstance()->state_ == ACTIVE)
 280     return;
 281
 282   GetInstance()->InitializeMetricsState();
 283   GetInstance()->SetRecording(true);
 284   GetInstance()->SetReporting(true);
 285 }
 286
 287 // static
 288 void MetricsService::Stop() {
 289   base::AutoLock lock(metrics_service_lock_);
 290
 291   GetInstance()->SetReporting(false);
 292   GetInstance()->SetRecording(false);
 293 }
 294
 295 void MetricsService::SetRecording(bool enabled) {
 296   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 297   if (enabled == recording_active_)
 298     return;
 299
 300   if (enabled) {
 301     StartRecording();
 302   } else {
 303     state_ = STOPPED;
 304   }
 305   recording_active_ = enabled;
 306 }
 307
 308 // static
 309 const std::string& MetricsService::GetClientID() {
 310   // TODO(robertshield): Chrome Frame shouldn't generate a new ID on every run
 311   // as this apparently breaks some assumptions during metric analysis.
 312   // See http://crbug.com/117188
 313   if (client_id_.empty()) {
 314     const int kGUIDSize = 39;
 315
 316     GUID guid;
 317     HRESULT guid_result = CoCreateGuid(&guid);
 318     DCHECK(SUCCEEDED(guid_result));
 319
 320     string16 guid_string;
 321     int result = StringFromGUID2(guid,
 322                                  WriteInto(&guid_string, kGUIDSize), kGUIDSize);
 323     DCHECK(result == kGUIDSize);
 324     client_id_ = WideToUTF8(guid_string.substr(1, guid_string.length() - 2));
 325   }
 326   return client_id_;
 327 }
 328
 329 // static
 330 void CALLBACK MetricsService::TransmissionTimerProc(HWND window,
 331                                                     unsigned int message,
 332                                                     unsigned int event_id,
 333                                                     unsigned int time) {
 334   DVLOG(1) << "Transmission timer notified";
 335   DCHECK(GetInstance() != NULL);
 336   GetInstance()->UploadData();
 337   if (GetInstance()->initial_uma_upload_) {
 338     // If this is the first uma upload by this process then subsequent uma
 339     // uploads should occur once every 10 minutes(default).
 340     GetInstance()->initial_uma_upload_ = false;
 341     DCHECK(GetInstance()->transmission_timer_id_ != 0);
 342     SetTimer(NULL, GetInstance()->transmission_timer_id_,
 343              kMinMilliSecondsPerUMAUpload,
 344              reinterpret_cast<TIMERPROC>(TransmissionTimerProc));
 345   }
 346 }
 347
 348 void MetricsService::SetReporting(bool enable) {
 349   static const int kChromeFrameMetricsTimerId = 0xFFFFFFFF;
 350
 351   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 352   if (reporting_active_ != enable) {
 353     reporting_active_ = enable;
 354     if (reporting_active_) {
 355       transmission_timer_id_ =
 356           SetTimer(NULL, kChromeFrameMetricsTimerId,
 357                    kInitialUMAUploadTimeoutMilliSeconds,
 358                    reinterpret_cast<TIMERPROC>(TransmissionTimerProc));
 359     } else {
 360       UploadData();
 361     }
 362   }
 363 }
 364
 365 //------------------------------------------------------------------------------
 366 // Recording control methods
 367
 368 void MetricsService::StartRecording() {
 369   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 370   if (log_manager_.current_log())
 371     return;
 372
 373   MetricsLogManager::LogType log_type = (state_ == INITIALIZED) ?
 374       MetricsLogManager::INITIAL_LOG : MetricsLogManager::ONGOING_LOG;
 375   log_manager_.BeginLoggingWithLog(new MetricsLogBase(GetClientID(),
 376                                                       session_id_,
 377                                                       GetVersionString()),
 378                                    log_type);
 379   if (state_ == INITIALIZED)
 380     state_ = ACTIVE;
 381 }
 382
 383 void MetricsService::StopRecording(bool save_log) {
 384   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 385   if (!log_manager_.current_log())
 386     return;
 387
 388   // Put incremental histogram deltas at the end of all log transmissions.
 389   // Don't bother if we're going to discard current_log.
 390   if (save_log) {
 391     CrashMetricsReporter::GetInstance()->RecordCrashMetrics();
 392     RecordCurrentHistograms();
 393   }
 394
 395   if (save_log) {
 396     log_manager_.FinishCurrentLog();
 397     log_manager_.StageNextLogForUpload();
 398   } else {
 399     log_manager_.DiscardCurrentLog();
 400   }
 401 }
 402
 403 void MetricsService::MakePendingLog() {
 404   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 405   if (log_manager_.has_staged_log())
 406     return;
 407
 408   if (state_ != ACTIVE) {
 409     NOTREACHED();
 410     return;
 411   }
 412
 413   StopRecording(true);
 414   StartRecording();
 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 bool MetricsService::UploadData() {
 424   DCHECK_EQ(thread_, base::PlatformThread::CurrentId());
 425
 426   if (!GetInstance()->TransmissionPermitted())
 427     return false;
 428
 429   static long currently_uploading = 0;
 430   if (InterlockedCompareExchange(&currently_uploading, 1, 0)) {
 431     DVLOG(1) << "Contention for uploading metrics data. Backing off";
 432     return false;
 433   }
 434
 435   MakePendingLog();
 436
 437   bool ret = true;
 438
 439   if (log_manager_.has_staged_log()) {
 440     HRESULT hr = ChromeFrameMetricsDataUploader::UploadDataHelper(
 441         log_manager_.staged_log_text().xml, kServerUrlXml, kMimeTypeXml);
 442     DCHECK(SUCCEEDED(hr));
 443     hr = ChromeFrameMetricsDataUploader::UploadDataHelper(
 444         log_manager_.staged_log_text().proto, kServerUrlProto, kMimeTypeProto);
 445     DCHECK(SUCCEEDED(hr));
 446     log_manager_.DiscardStagedLog();
 447   } else {
 448     NOTREACHED();
 449     ret = false;
 450   }
 451
 452   currently_uploading = 0;
 453   return ret;
 454 }
 455
 456 // static
 457 std::string MetricsService::GetVersionString() {
 458   chrome::VersionInfo version_info;
 459   if (version_info.is_valid()) {
 460     std::string version = version_info.Version();
 461     // Add the -F extensions to ensure that UMA data uploaded by ChromeFrame
 462     // lands in the ChromeFrame bucket.
 463     version += "-F";
 464     if (!version_info.IsOfficialBuild())
 465       version.append("-devel");
 466     return version;
 467   } else {
 468     NOTREACHED() << "Unable to retrieve version string.";
 469   }
 470
 471   return std::string();
 472 }