OLD | NEW |
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 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 | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 //------------------------------------------------------------------------------ | 5 //------------------------------------------------------------------------------ |
6 // Description of the life cycle of a instance of MetricsService. | 6 // Description of the life cycle of a instance of MetricsService. |
7 // | 7 // |
8 // OVERVIEW | 8 // OVERVIEW |
9 // | 9 // |
10 // A MetricsService instance is typically created at application startup. It is | 10 // A MetricsService instance is typically created at application startup. It is |
(...skipping 167 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
178 #include "base/strings/utf_string_conversions.h" | 178 #include "base/strings/utf_string_conversions.h" |
179 #include "base/threading/platform_thread.h" | 179 #include "base/threading/platform_thread.h" |
180 #include "base/threading/thread.h" | 180 #include "base/threading/thread.h" |
181 #include "base/threading/thread_restrictions.h" | 181 #include "base/threading/thread_restrictions.h" |
182 #include "base/tracked_objects.h" | 182 #include "base/tracked_objects.h" |
183 #include "base/values.h" | 183 #include "base/values.h" |
184 #include "chrome/browser/browser_process.h" | 184 #include "chrome/browser/browser_process.h" |
185 #include "chrome/browser/chrome_notification_types.h" | 185 #include "chrome/browser/chrome_notification_types.h" |
186 #include "chrome/browser/io_thread.h" | 186 #include "chrome/browser/io_thread.h" |
187 #include "chrome/browser/metrics/chrome_stability_metrics_provider.h" | 187 #include "chrome/browser/metrics/chrome_stability_metrics_provider.h" |
188 #include "chrome/browser/metrics/compression_utils.h" | |
189 #include "chrome/browser/metrics/gpu_metrics_provider.h" | 188 #include "chrome/browser/metrics/gpu_metrics_provider.h" |
190 #include "chrome/browser/metrics/metrics_log.h" | 189 #include "chrome/browser/metrics/metrics_log.h" |
191 #include "chrome/browser/metrics/metrics_state_manager.h" | 190 #include "chrome/browser/metrics/metrics_state_manager.h" |
192 #include "chrome/browser/metrics/network_metrics_provider.h" | 191 #include "chrome/browser/metrics/network_metrics_provider.h" |
193 #include "chrome/browser/metrics/omnibox_metrics_provider.h" | 192 #include "chrome/browser/metrics/omnibox_metrics_provider.h" |
194 #include "chrome/browser/metrics/tracking_synchronizer.h" | 193 #include "chrome/browser/metrics/tracking_synchronizer.h" |
195 #include "chrome/common/pref_names.h" | 194 #include "chrome/common/pref_names.h" |
196 #include "chrome/common/variations/variations_util.h" | 195 #include "chrome/common/variations/variations_util.h" |
197 #include "components/metrics/metrics_log_base.h" | 196 #include "components/metrics/metrics_log_base.h" |
198 #include "components/metrics/metrics_log_manager.h" | 197 #include "components/metrics/metrics_log_manager.h" |
| 198 #include "components/metrics/metrics_log_uploader.h" |
199 #include "components/metrics/metrics_pref_names.h" | 199 #include "components/metrics/metrics_pref_names.h" |
200 #include "components/metrics/metrics_reporting_scheduler.h" | 200 #include "components/metrics/metrics_reporting_scheduler.h" |
201 #include "components/metrics/metrics_service_client.h" | 201 #include "components/metrics/metrics_service_client.h" |
202 #include "components/variations/entropy_provider.h" | 202 #include "components/variations/entropy_provider.h" |
203 #include "net/base/load_flags.h" | |
204 #include "net/url_request/url_fetcher.h" | |
205 | 203 |
206 #if defined(ENABLE_PLUGINS) | 204 #if defined(ENABLE_PLUGINS) |
207 // TODO(asvitkine): Move this out of MetricsService. | 205 // TODO(asvitkine): Move this out of MetricsService. |
208 #include "chrome/browser/metrics/plugin_metrics_provider.h" | 206 #include "chrome/browser/metrics/plugin_metrics_provider.h" |
209 #endif | 207 #endif |
210 | 208 |
211 #if defined(OS_WIN) | 209 #if defined(OS_WIN) |
212 #include "chrome/browser/metrics/google_update_metrics_provider_win.h" | 210 #include "chrome/browser/metrics/google_update_metrics_provider_win.h" |
213 #endif | 211 #endif |
214 | 212 |
(...skipping 48 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
263 enum ResponseStatus { | 261 enum ResponseStatus { |
264 UNKNOWN_FAILURE, | 262 UNKNOWN_FAILURE, |
265 SUCCESS, | 263 SUCCESS, |
266 BAD_REQUEST, // Invalid syntax or log too large. | 264 BAD_REQUEST, // Invalid syntax or log too large. |
267 NO_RESPONSE, | 265 NO_RESPONSE, |
268 NUM_RESPONSE_STATUSES | 266 NUM_RESPONSE_STATUSES |
269 }; | 267 }; |
270 | 268 |
271 ResponseStatus ResponseCodeToStatus(int response_code) { | 269 ResponseStatus ResponseCodeToStatus(int response_code) { |
272 switch (response_code) { | 270 switch (response_code) { |
| 271 case -1: |
| 272 return NO_RESPONSE; |
273 case 200: | 273 case 200: |
274 return SUCCESS; | 274 return SUCCESS; |
275 case 400: | 275 case 400: |
276 return BAD_REQUEST; | 276 return BAD_REQUEST; |
277 case net::URLFetcher::RESPONSE_CODE_INVALID: | |
278 return NO_RESPONSE; | |
279 default: | 277 default: |
280 return UNKNOWN_FAILURE; | 278 return UNKNOWN_FAILURE; |
281 } | 279 } |
282 } | 280 } |
283 | 281 |
284 void MarkAppCleanShutdownAndCommit(PrefService* local_state) { | 282 void MarkAppCleanShutdownAndCommit(PrefService* local_state) { |
285 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true); | 283 local_state->SetBoolean(prefs::kStabilityExitedCleanly, true); |
286 local_state->SetInteger(prefs::kStabilityExecutionPhase, | 284 local_state->SetInteger(prefs::kStabilityExecutionPhase, |
287 MetricsService::SHUTDOWN_COMPLETE); | 285 MetricsService::SHUTDOWN_COMPLETE); |
288 // Start writing right away (write happens on a different thread). | 286 // Start writing right away (write happens on a different thread). |
(...skipping 75 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
364 : log_manager_(local_state, kUploadLogAvoidRetransmitSize), | 362 : log_manager_(local_state, kUploadLogAvoidRetransmitSize), |
365 histogram_snapshot_manager_(this), | 363 histogram_snapshot_manager_(this), |
366 state_manager_(state_manager), | 364 state_manager_(state_manager), |
367 client_(client), | 365 client_(client), |
368 local_state_(local_state), | 366 local_state_(local_state), |
369 recording_active_(false), | 367 recording_active_(false), |
370 reporting_active_(false), | 368 reporting_active_(false), |
371 test_mode_active_(false), | 369 test_mode_active_(false), |
372 state_(INITIALIZED), | 370 state_(INITIALIZED), |
373 has_initial_stability_log_(false), | 371 has_initial_stability_log_(false), |
| 372 log_upload_in_progress_(false), |
374 idle_since_last_transmission_(false), | 373 idle_since_last_transmission_(false), |
375 session_id_(-1), | 374 session_id_(-1), |
376 self_ptr_factory_(this), | 375 self_ptr_factory_(this), |
377 state_saver_factory_(this), | 376 state_saver_factory_(this) { |
378 waiting_for_asynchronous_reporting_step_(false) { | |
379 DCHECK(IsSingleThreaded()); | 377 DCHECK(IsSingleThreaded()); |
380 DCHECK(state_manager_); | 378 DCHECK(state_manager_); |
381 DCHECK(client_); | 379 DCHECK(client_); |
382 DCHECK(local_state_); | 380 DCHECK(local_state_); |
383 | 381 |
384 #if defined(OS_ANDROID) | 382 #if defined(OS_ANDROID) |
385 // TODO(asvitkine): Move this out of MetricsService. | 383 // TODO(asvitkine): Move this out of MetricsService. |
386 RegisterMetricsProvider( | 384 RegisterMetricsProvider( |
387 scoped_ptr<metrics::MetricsProvider>(new AndroidMetricsProvider( | 385 scoped_ptr<metrics::MetricsProvider>(new AndroidMetricsProvider( |
388 local_state_))); | 386 local_state_))); |
(...skipping 489 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
878 log_manager_.FinishCurrentLog(); | 876 log_manager_.FinishCurrentLog(); |
879 } | 877 } |
880 | 878 |
881 void MetricsService::PushPendingLogsToPersistentStorage() { | 879 void MetricsService::PushPendingLogsToPersistentStorage() { |
882 if (state_ < SENDING_INITIAL_STABILITY_LOG) | 880 if (state_ < SENDING_INITIAL_STABILITY_LOG) |
883 return; // We didn't and still don't have time to get plugin list etc. | 881 return; // We didn't and still don't have time to get plugin list etc. |
884 | 882 |
885 if (log_manager_.has_staged_log()) { | 883 if (log_manager_.has_staged_log()) { |
886 // We may race here, and send second copy of the log later. | 884 // We may race here, and send second copy of the log later. |
887 metrics::PersistedLogs::StoreType store_type; | 885 metrics::PersistedLogs::StoreType store_type; |
888 if (current_fetch_.get()) | 886 if (log_upload_in_progress_) |
889 store_type = metrics::PersistedLogs::PROVISIONAL_STORE; | 887 store_type = metrics::PersistedLogs::PROVISIONAL_STORE; |
890 else | 888 else |
891 store_type = metrics::PersistedLogs::NORMAL_STORE; | 889 store_type = metrics::PersistedLogs::NORMAL_STORE; |
892 log_manager_.StoreStagedLogAsUnsent(store_type); | 890 log_manager_.StoreStagedLogAsUnsent(store_type); |
893 } | 891 } |
894 DCHECK(!log_manager_.has_staged_log()); | 892 DCHECK(!log_manager_.has_staged_log()); |
895 CloseCurrentLog(); | 893 CloseCurrentLog(); |
896 log_manager_.PersistUnsentLogs(); | 894 log_manager_.PersistUnsentLogs(); |
897 | 895 |
898 // If there was a staged and/or current log, then there is now at least one | 896 // If there was a staged and/or current log, then there is now at least one |
(...skipping 54 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
953 log_manager_.StageNextLogForUpload(); | 951 log_manager_.StageNextLogForUpload(); |
954 SendStagedLog(); | 952 SendStagedLog(); |
955 } else { | 953 } else { |
956 client_->CollectFinalMetrics( | 954 client_->CollectFinalMetrics( |
957 base::Bind(&MetricsService::OnFinalLogInfoCollectionDone, | 955 base::Bind(&MetricsService::OnFinalLogInfoCollectionDone, |
958 self_ptr_factory_.GetWeakPtr())); | 956 self_ptr_factory_.GetWeakPtr())); |
959 } | 957 } |
960 } | 958 } |
961 | 959 |
962 void MetricsService::OnFinalLogInfoCollectionDone() { | 960 void MetricsService::OnFinalLogInfoCollectionDone() { |
963 // If somehow there is a fetch in progress, we return and hope things work | 961 // If somehow there is a log upload in progress, we return and hope things |
964 // out. The scheduler isn't informed since if this happens, the scheduler | 962 // work out. The scheduler isn't informed since if this happens, the scheduler |
965 // will get a response from the upload. | 963 // will get a response from the upload. |
966 DCHECK(!current_fetch_.get()); | 964 DCHECK(!log_upload_in_progress_); |
967 if (current_fetch_.get()) | 965 if (log_upload_in_progress_) |
968 return; | 966 return; |
969 | 967 |
970 // Abort if metrics were turned off during the final info gathering. | 968 // Abort if metrics were turned off during the final info gathering. |
971 if (!recording_active()) { | 969 if (!recording_active()) { |
972 scheduler_->Stop(); | 970 scheduler_->Stop(); |
973 scheduler_->UploadCancelled(); | 971 scheduler_->UploadCancelled(); |
974 return; | 972 return; |
975 } | 973 } |
976 | 974 |
977 StageNewLog(); | 975 StageNewLog(); |
(...skipping 126 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1104 | 1102 |
1105 log_manager_.FinishCurrentLog(); | 1103 log_manager_.FinishCurrentLog(); |
1106 log_manager_.ResumePausedLog(); | 1104 log_manager_.ResumePausedLog(); |
1107 | 1105 |
1108 DCHECK(!log_manager_.has_staged_log()); | 1106 DCHECK(!log_manager_.has_staged_log()); |
1109 log_manager_.StageNextLogForUpload(); | 1107 log_manager_.StageNextLogForUpload(); |
1110 } | 1108 } |
1111 | 1109 |
1112 void MetricsService::SendStagedLog() { | 1110 void MetricsService::SendStagedLog() { |
1113 DCHECK(log_manager_.has_staged_log()); | 1111 DCHECK(log_manager_.has_staged_log()); |
| 1112 if (!log_manager_.has_staged_log()) |
| 1113 return; |
1114 | 1114 |
1115 PrepareFetchWithStagedLog(); | 1115 DCHECK(!log_upload_in_progress_); |
| 1116 log_upload_in_progress_ = true; |
1116 | 1117 |
1117 bool upload_created = (current_fetch_.get() != NULL); | 1118 if (!log_uploader_) { |
1118 UMA_HISTOGRAM_BOOLEAN("UMA.UploadCreation", upload_created); | 1119 log_uploader_ = client_->CreateUploader( |
1119 if (!upload_created) { | 1120 kServerUrl, kMimeType, |
1120 // Compression failed, and log discarded :-/. | 1121 base::Bind(&MetricsService::OnLogUploadComplete, |
| 1122 self_ptr_factory_.GetWeakPtr())); |
| 1123 } |
| 1124 |
| 1125 const std::string hash = |
| 1126 base::HexEncode(log_manager_.staged_log_hash().data(), |
| 1127 log_manager_.staged_log_hash().size()); |
| 1128 bool success = log_uploader_->UploadLog(log_manager_.staged_log(), hash); |
| 1129 UMA_HISTOGRAM_BOOLEAN("UMA.UploadCreation", success); |
| 1130 if (!success) { |
1121 // Skip this upload and hope things work out next time. | 1131 // Skip this upload and hope things work out next time. |
1122 log_manager_.DiscardStagedLog(); | 1132 log_manager_.DiscardStagedLog(); |
1123 scheduler_->UploadCancelled(); | 1133 scheduler_->UploadCancelled(); |
| 1134 log_upload_in_progress_ = false; |
1124 return; | 1135 return; |
1125 } | 1136 } |
1126 | 1137 |
1127 DCHECK(!waiting_for_asynchronous_reporting_step_); | |
1128 waiting_for_asynchronous_reporting_step_ = true; | |
1129 | |
1130 current_fetch_->Start(); | |
1131 | |
1132 HandleIdleSinceLastTransmission(true); | 1138 HandleIdleSinceLastTransmission(true); |
1133 } | 1139 } |
1134 | 1140 |
1135 void MetricsService::PrepareFetchWithStagedLog() { | |
1136 DCHECK(log_manager_.has_staged_log()); | |
1137 | 1141 |
1138 // Prepare the protobuf version. | 1142 void MetricsService::OnLogUploadComplete(int response_code) { |
1139 DCHECK(!current_fetch_.get()); | 1143 DCHECK(log_upload_in_progress_); |
1140 if (log_manager_.has_staged_log()) { | 1144 log_upload_in_progress_ = false; |
1141 current_fetch_.reset(net::URLFetcher::Create( | |
1142 GURL(kServerUrl), net::URLFetcher::POST, this)); | |
1143 current_fetch_->SetRequestContext( | |
1144 g_browser_process->system_request_context()); | |
1145 | |
1146 std::string log_text = log_manager_.staged_log(); | |
1147 std::string compressed_log_text; | |
1148 bool compression_successful = chrome::GzipCompress(log_text, | |
1149 &compressed_log_text); | |
1150 DCHECK(compression_successful); | |
1151 if (compression_successful) { | |
1152 current_fetch_->SetUploadData(kMimeType, compressed_log_text); | |
1153 // Tell the server that we're uploading gzipped protobufs. | |
1154 current_fetch_->SetExtraRequestHeaders("content-encoding: gzip"); | |
1155 const std::string hash = | |
1156 base::HexEncode(log_manager_.staged_log_hash().data(), | |
1157 log_manager_.staged_log_hash().size()); | |
1158 DCHECK(!hash.empty()); | |
1159 current_fetch_->AddExtraRequestHeader("X-Chrome-UMA-Log-SHA1: " + hash); | |
1160 UMA_HISTOGRAM_PERCENTAGE( | |
1161 "UMA.ProtoCompressionRatio", | |
1162 100 * compressed_log_text.size() / log_text.size()); | |
1163 UMA_HISTOGRAM_CUSTOM_COUNTS( | |
1164 "UMA.ProtoGzippedKBSaved", | |
1165 (log_text.size() - compressed_log_text.size()) / 1024, | |
1166 1, 2000, 50); | |
1167 } | |
1168 | |
1169 // We already drop cookies server-side, but we might as well strip them out | |
1170 // client-side as well. | |
1171 current_fetch_->SetLoadFlags(net::LOAD_DO_NOT_SAVE_COOKIES | | |
1172 net::LOAD_DO_NOT_SEND_COOKIES); | |
1173 } | |
1174 } | |
1175 | |
1176 void MetricsService::OnURLFetchComplete(const net::URLFetcher* source) { | |
1177 DCHECK(waiting_for_asynchronous_reporting_step_); | |
1178 | |
1179 // We're not allowed to re-use the existing |URLFetcher|s, so free them here. | |
1180 // Note however that |source| is aliased to the fetcher, so we should be | |
1181 // careful not to delete it too early. | |
1182 DCHECK_EQ(current_fetch_.get(), source); | |
1183 scoped_ptr<net::URLFetcher> s(current_fetch_.Pass()); | |
1184 | |
1185 int response_code = source->GetResponseCode(); | |
1186 | 1145 |
1187 // Log a histogram to track response success vs. failure rates. | 1146 // Log a histogram to track response success vs. failure rates. |
1188 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.Protobuf", | 1147 UMA_HISTOGRAM_ENUMERATION("UMA.UploadResponseStatus.Protobuf", |
1189 ResponseCodeToStatus(response_code), | 1148 ResponseCodeToStatus(response_code), |
1190 NUM_RESPONSE_STATUSES); | 1149 NUM_RESPONSE_STATUSES); |
1191 | 1150 |
1192 // If the upload was provisionally stored, drop it now that the upload is | 1151 // If the upload was provisionally stored, drop it now that the upload is |
1193 // known to have gone through. | 1152 // known to have gone through. |
1194 log_manager_.DiscardLastProvisionalStore(); | 1153 log_manager_.DiscardLastProvisionalStore(); |
1195 | 1154 |
1196 bool upload_succeeded = response_code == 200; | 1155 bool upload_succeeded = response_code == 200; |
1197 | 1156 |
1198 // Provide boolean for error recovery (allow us to ignore response_code). | 1157 // Provide boolean for error recovery (allow us to ignore response_code). |
1199 bool discard_log = false; | 1158 bool discard_log = false; |
1200 const size_t log_size = log_manager_.staged_log().length(); | 1159 const size_t log_size = log_manager_.staged_log().length(); |
1201 if (!upload_succeeded && log_size > kUploadLogAvoidRetransmitSize) { | 1160 if (!upload_succeeded && log_size > kUploadLogAvoidRetransmitSize) { |
1202 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded", | 1161 UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded", |
1203 static_cast<int>(log_size)); | 1162 static_cast<int>(log_size)); |
1204 discard_log = true; | 1163 discard_log = true; |
1205 } else if (response_code == 400) { | 1164 } else if (response_code == 400) { |
1206 // Bad syntax. Retransmission won't work. | 1165 // Bad syntax. Retransmission won't work. |
1207 discard_log = true; | 1166 discard_log = true; |
1208 } | 1167 } |
1209 | 1168 |
1210 if (upload_succeeded || discard_log) | 1169 if (upload_succeeded || discard_log) |
1211 log_manager_.DiscardStagedLog(); | 1170 log_manager_.DiscardStagedLog(); |
1212 | 1171 |
1213 waiting_for_asynchronous_reporting_step_ = false; | |
1214 | |
1215 if (!log_manager_.has_staged_log()) { | 1172 if (!log_manager_.has_staged_log()) { |
1216 switch (state_) { | 1173 switch (state_) { |
1217 case SENDING_INITIAL_STABILITY_LOG: | 1174 case SENDING_INITIAL_STABILITY_LOG: |
1218 // Store the updated list to disk now that the removed log is uploaded. | 1175 // Store the updated list to disk now that the removed log is uploaded. |
1219 log_manager_.PersistUnsentLogs(); | 1176 log_manager_.PersistUnsentLogs(); |
1220 PrepareInitialMetricsLog(); | 1177 PrepareInitialMetricsLog(); |
1221 SendStagedLog(); | 1178 SendStagedLog(); |
1222 state_ = SENDING_INITIAL_METRICS_LOG; | 1179 state_ = SENDING_INITIAL_METRICS_LOG; |
1223 break; | 1180 break; |
1224 | 1181 |
(...skipping 149 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1374 RecordCurrentState(local_state_); | 1331 RecordCurrentState(local_state_); |
1375 } | 1332 } |
1376 | 1333 |
1377 void MetricsService::RecordCurrentState(PrefService* pref) { | 1334 void MetricsService::RecordCurrentState(PrefService* pref) { |
1378 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT()); | 1335 pref->SetInt64(prefs::kStabilityLastTimestampSec, Time::Now().ToTimeT()); |
1379 | 1336 |
1380 #if defined(ENABLE_PLUGINS) | 1337 #if defined(ENABLE_PLUGINS) |
1381 plugin_metrics_provider_->RecordPluginChanges(); | 1338 plugin_metrics_provider_->RecordPluginChanges(); |
1382 #endif | 1339 #endif |
1383 } | 1340 } |
OLD | NEW |