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