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