blob: 6851fcbefe41016383aadc7d7ed451591c3ab770 [file] [log] [blame]
Jay Srinivasan6f6ea002012-12-14 11:26:28 -08001// Copyright (c) 2012 The Chromium OS 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#include "update_engine/payload_state.h"
6
Jay Srinivasan08262882012-12-28 19:29:43 -08007#include <algorithm>
8
Jay Srinivasan6f6ea002012-12-14 11:26:28 -08009#include <base/logging.h>
Jay Srinivasan19409b72013-04-12 19:23:36 -070010#include "base/string_util.h"
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080011#include <base/stringprintf.h>
12
David Zeuthenf413fe52013-04-22 14:04:39 -070013#include "update_engine/clock.h"
Jay Srinivasand29695d2013-04-08 15:08:05 -070014#include "update_engine/constants.h"
Jay Srinivasan19409b72013-04-12 19:23:36 -070015#include "update_engine/prefs.h"
16#include "update_engine/system_state.h"
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -080017#include "update_engine/utils.h"
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080018
Jay Srinivasan08262882012-12-28 19:29:43 -080019using base::Time;
20using base::TimeDelta;
21using std::min;
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080022using std::string;
23
24namespace chromeos_update_engine {
25
David Zeuthen9a017f22013-04-11 16:10:26 -070026const TimeDelta PayloadState::kDurationSlack = TimeDelta::FromSeconds(600);
27
Jay Srinivasan08262882012-12-28 19:29:43 -080028// We want to upperbound backoffs to 16 days
Alex Deymo820cc702013-06-28 15:43:46 -070029static const int kMaxBackoffDays = 16;
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080030
Jay Srinivasan08262882012-12-28 19:29:43 -080031// We want to randomize retry attempts after the backoff by +/- 6 hours.
32static const uint32_t kMaxBackoffFuzzMinutes = 12 * 60;
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080033
Jay Srinivasan19409b72013-04-12 19:23:36 -070034PayloadState::PayloadState()
35 : prefs_(NULL),
36 payload_attempt_number_(0),
Alex Deymo820cc702013-06-28 15:43:46 -070037 full_payload_attempt_number_(0),
Jay Srinivasan19409b72013-04-12 19:23:36 -070038 url_index_(0),
David Zeuthencc6f9962013-04-18 11:57:24 -070039 url_failure_count_(0),
40 url_switch_count_(0) {
Jay Srinivasan19409b72013-04-12 19:23:36 -070041 for (int i = 0; i <= kNumDownloadSources; i++)
42 total_bytes_downloaded_[i] = current_bytes_downloaded_[i] = 0;
43}
44
45bool PayloadState::Initialize(SystemState* system_state) {
46 system_state_ = system_state;
47 prefs_ = system_state_->prefs();
Chris Sosaaa18e162013-06-20 13:20:30 -070048 powerwash_safe_prefs_ = system_state_->powerwash_safe_prefs();
Jay Srinivasan08262882012-12-28 19:29:43 -080049 LoadResponseSignature();
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -080050 LoadPayloadAttemptNumber();
Alex Deymo820cc702013-06-28 15:43:46 -070051 LoadFullPayloadAttemptNumber();
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080052 LoadUrlIndex();
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -080053 LoadUrlFailureCount();
David Zeuthencc6f9962013-04-18 11:57:24 -070054 LoadUrlSwitchCount();
Jay Srinivasan08262882012-12-28 19:29:43 -080055 LoadBackoffExpiryTime();
David Zeuthen9a017f22013-04-11 16:10:26 -070056 LoadUpdateTimestampStart();
57 // The LoadUpdateDurationUptime() method relies on LoadUpdateTimestampStart()
58 // being called before it. Don't reorder.
59 LoadUpdateDurationUptime();
Jay Srinivasan19409b72013-04-12 19:23:36 -070060 for (int i = 0; i < kNumDownloadSources; i++) {
61 DownloadSource source = static_cast<DownloadSource>(i);
62 LoadCurrentBytesDownloaded(source);
63 LoadTotalBytesDownloaded(source);
64 }
Chris Sosabe45bef2013-04-09 18:25:12 -070065 LoadNumReboots();
David Zeuthena573d6f2013-06-14 16:13:36 -070066 LoadNumResponsesSeen();
Chris Sosaaa18e162013-06-20 13:20:30 -070067 LoadRollbackVersion();
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080068 return true;
69}
70
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080071void PayloadState::SetResponse(const OmahaResponse& omaha_response) {
Jay Srinivasan08262882012-12-28 19:29:43 -080072 // Always store the latest response.
73 response_ = omaha_response;
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080074
Jay Srinivasan53173b92013-05-17 17:13:01 -070075 // Compute the candidate URLs first as they are used to calculate the
76 // response signature so that a change in enterprise policy for
77 // HTTP downloads being enabled or not could be honored as soon as the
78 // next update check happens.
79 ComputeCandidateUrls();
80
Jay Srinivasan08262882012-12-28 19:29:43 -080081 // Check if the "signature" of this response (i.e. the fields we care about)
82 // has changed.
83 string new_response_signature = CalculateResponseSignature();
84 bool has_response_changed = (response_signature_ != new_response_signature);
85
86 // If the response has changed, we should persist the new signature and
87 // clear away all the existing state.
Jay Srinivasan6f6ea002012-12-14 11:26:28 -080088 if (has_response_changed) {
Jay Srinivasan08262882012-12-28 19:29:43 -080089 LOG(INFO) << "Resetting all persisted state as this is a new response";
David Zeuthena573d6f2013-06-14 16:13:36 -070090 SetNumResponsesSeen(num_responses_seen_ + 1);
Jay Srinivasan08262882012-12-28 19:29:43 -080091 SetResponseSignature(new_response_signature);
92 ResetPersistedState();
93 return;
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -080094 }
95
Jay Srinivasan08262882012-12-28 19:29:43 -080096 // This is the earliest point at which we can validate whether the URL index
97 // we loaded from the persisted state is a valid value. If the response
98 // hasn't changed but the URL index is invalid, it's indicative of some
99 // tampering of the persisted state.
Jay Srinivasan53173b92013-05-17 17:13:01 -0700100 if (static_cast<uint32_t>(url_index_) >= candidate_urls_.size()) {
Jay Srinivasan08262882012-12-28 19:29:43 -0800101 LOG(INFO) << "Resetting all payload state as the url index seems to have "
102 "been tampered with";
103 ResetPersistedState();
104 return;
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800105 }
Jay Srinivasan19409b72013-04-12 19:23:36 -0700106
107 // Update the current download source which depends on the latest value of
108 // the response.
109 UpdateCurrentDownloadSource();
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800110}
111
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800112void PayloadState::DownloadComplete() {
113 LOG(INFO) << "Payload downloaded successfully";
114 IncrementPayloadAttemptNumber();
Alex Deymo820cc702013-06-28 15:43:46 -0700115 IncrementFullPayloadAttemptNumber();
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800116}
117
118void PayloadState::DownloadProgress(size_t count) {
119 if (count == 0)
120 return;
121
David Zeuthen9a017f22013-04-11 16:10:26 -0700122 CalculateUpdateDurationUptime();
Jay Srinivasan19409b72013-04-12 19:23:36 -0700123 UpdateBytesDownloaded(count);
David Zeuthen9a017f22013-04-11 16:10:26 -0700124
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800125 // We've received non-zero bytes from a recent download operation. Since our
126 // URL failure count is meant to penalize a URL only for consecutive
127 // failures, downloading bytes successfully means we should reset the failure
128 // count (as we know at least that the URL is working). In future, we can
129 // design this to be more sophisticated to check for more intelligent failure
130 // patterns, but right now, even 1 byte downloaded will mark the URL to be
131 // good unless it hits 10 (or configured number of) consecutive failures
132 // again.
133
134 if (GetUrlFailureCount() == 0)
135 return;
136
137 LOG(INFO) << "Resetting failure count of Url" << GetUrlIndex()
138 << " to 0 as we received " << count << " bytes successfully";
139 SetUrlFailureCount(0);
140}
141
Chris Sosabe45bef2013-04-09 18:25:12 -0700142void PayloadState::UpdateResumed() {
143 LOG(INFO) << "Resuming an update that was previously started.";
144 UpdateNumReboots();
145}
146
Jay Srinivasan19409b72013-04-12 19:23:36 -0700147void PayloadState::UpdateRestarted() {
148 LOG(INFO) << "Starting a new update";
149 ResetDownloadSourcesOnNewUpdate();
Chris Sosabe45bef2013-04-09 18:25:12 -0700150 SetNumReboots(0);
Jay Srinivasan19409b72013-04-12 19:23:36 -0700151}
152
David Zeuthen9a017f22013-04-11 16:10:26 -0700153void PayloadState::UpdateSucceeded() {
Jay Srinivasan19409b72013-04-12 19:23:36 -0700154 // Send the relevant metrics that are tracked in this class to UMA.
David Zeuthen9a017f22013-04-11 16:10:26 -0700155 CalculateUpdateDurationUptime();
David Zeuthenf413fe52013-04-22 14:04:39 -0700156 SetUpdateTimestampEnd(system_state_->clock()->GetWallclockTime());
Jay Srinivasan19409b72013-04-12 19:23:36 -0700157 ReportBytesDownloadedMetrics();
David Zeuthencc6f9962013-04-18 11:57:24 -0700158 ReportUpdateUrlSwitchesMetric();
Chris Sosabe45bef2013-04-09 18:25:12 -0700159 ReportRebootMetrics();
David Zeuthen674c3182013-04-18 14:05:20 -0700160 ReportDurationMetrics();
David Zeuthena573d6f2013-06-14 16:13:36 -0700161 ReportUpdatesAbandonedCountMetric();
Alex Deymo1c656c42013-06-28 11:02:14 -0700162 ReportPayloadTypeMetric();
Alex Deymo820cc702013-06-28 15:43:46 -0700163 ReportAttemptsCountMetrics();
David Zeuthena573d6f2013-06-14 16:13:36 -0700164
165 // Reset the number of responses seen since it counts from the last
166 // successful update, e.g. now.
167 SetNumResponsesSeen(0);
David Zeuthene4c58bf2013-06-18 17:26:50 -0700168
169 CreateSystemUpdatedMarkerFile();
David Zeuthen9a017f22013-04-11 16:10:26 -0700170}
171
David Zeuthena99981f2013-04-29 13:42:47 -0700172void PayloadState::UpdateFailed(ErrorCode error) {
173 ErrorCode base_error = utils::GetBaseErrorCode(error);
Jay Srinivasan55f50c22013-01-10 19:24:35 -0800174 LOG(INFO) << "Updating payload state for error code: " << base_error
175 << " (" << utils::CodeToString(base_error) << ")";
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800176
Jay Srinivasan53173b92013-05-17 17:13:01 -0700177 if (candidate_urls_.size() == 0) {
178 // This means we got this error even before we got a valid Omaha response
179 // or don't have any valid candidates in the Omaha response.
Jay Srinivasan08262882012-12-28 19:29:43 -0800180 // So we should not advance the url_index_ in such cases.
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800181 LOG(INFO) << "Ignoring failures until we get a valid Omaha response.";
182 return;
183 }
184
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800185 switch (base_error) {
186 // Errors which are good indicators of a problem with a particular URL or
187 // the protocol used in the URL or entities in the communication channel
188 // (e.g. proxies). We should try the next available URL in the next update
189 // check to quickly recover from these errors.
David Zeuthena99981f2013-04-29 13:42:47 -0700190 case kErrorCodePayloadHashMismatchError:
191 case kErrorCodePayloadSizeMismatchError:
192 case kErrorCodeDownloadPayloadVerificationError:
193 case kErrorCodeDownloadPayloadPubKeyVerificationError:
194 case kErrorCodeSignedDeltaPayloadExpectedError:
195 case kErrorCodeDownloadInvalidMetadataMagicString:
196 case kErrorCodeDownloadSignatureMissingInManifest:
197 case kErrorCodeDownloadManifestParseError:
198 case kErrorCodeDownloadMetadataSignatureError:
199 case kErrorCodeDownloadMetadataSignatureVerificationError:
200 case kErrorCodeDownloadMetadataSignatureMismatch:
201 case kErrorCodeDownloadOperationHashVerificationError:
202 case kErrorCodeDownloadOperationExecutionError:
203 case kErrorCodeDownloadOperationHashMismatch:
204 case kErrorCodeDownloadInvalidMetadataSize:
205 case kErrorCodeDownloadInvalidMetadataSignature:
206 case kErrorCodeDownloadOperationHashMissingError:
207 case kErrorCodeDownloadMetadataSignatureMissingError:
Gilad Arnold21504f02013-05-24 08:51:22 -0700208 case kErrorCodePayloadMismatchedType:
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800209 IncrementUrlIndex();
210 break;
211
212 // Errors which seem to be just transient network/communication related
213 // failures and do not indicate any inherent problem with the URL itself.
214 // So, we should keep the current URL but just increment the
215 // failure count to give it more chances. This way, while we maximize our
216 // chances of downloading from the URLs that appear earlier in the response
217 // (because download from a local server URL that appears earlier in a
218 // response is preferable than downloading from the next URL which could be
219 // a internet URL and thus could be more expensive).
David Zeuthena99981f2013-04-29 13:42:47 -0700220 case kErrorCodeError:
221 case kErrorCodeDownloadTransferError:
222 case kErrorCodeDownloadWriteError:
223 case kErrorCodeDownloadStateInitializationError:
224 case kErrorCodeOmahaErrorInHTTPResponse: // Aggregate code for HTTP errors.
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800225 IncrementFailureCount();
226 break;
227
228 // Errors which are not specific to a URL and hence shouldn't result in
229 // the URL being penalized. This can happen in two cases:
230 // 1. We haven't started downloading anything: These errors don't cost us
231 // anything in terms of actual payload bytes, so we should just do the
232 // regular retries at the next update check.
233 // 2. We have successfully downloaded the payload: In this case, the
234 // payload attempt number would have been incremented and would take care
Jay Srinivasan08262882012-12-28 19:29:43 -0800235 // of the backoff at the next update check.
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800236 // In either case, there's no need to update URL index or failure count.
David Zeuthena99981f2013-04-29 13:42:47 -0700237 case kErrorCodeOmahaRequestError:
238 case kErrorCodeOmahaResponseHandlerError:
239 case kErrorCodePostinstallRunnerError:
240 case kErrorCodeFilesystemCopierError:
241 case kErrorCodeInstallDeviceOpenError:
242 case kErrorCodeKernelDeviceOpenError:
243 case kErrorCodeDownloadNewPartitionInfoError:
244 case kErrorCodeNewRootfsVerificationError:
245 case kErrorCodeNewKernelVerificationError:
246 case kErrorCodePostinstallBootedFromFirmwareB:
247 case kErrorCodeOmahaRequestEmptyResponseError:
248 case kErrorCodeOmahaRequestXMLParseError:
249 case kErrorCodeOmahaResponseInvalid:
250 case kErrorCodeOmahaUpdateIgnoredPerPolicy:
251 case kErrorCodeOmahaUpdateDeferredPerPolicy:
252 case kErrorCodeOmahaUpdateDeferredForBackoff:
253 case kErrorCodePostinstallPowerwashError:
254 case kErrorCodeUpdateCanceledByChannelChange:
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800255 LOG(INFO) << "Not incrementing URL index or failure count for this error";
256 break;
257
David Zeuthena99981f2013-04-29 13:42:47 -0700258 case kErrorCodeSuccess: // success code
David Zeuthena99981f2013-04-29 13:42:47 -0700259 case kErrorCodeUmaReportedMax: // not an error code
260 case kErrorCodeOmahaRequestHTTPResponseBase: // aggregated already
261 case kErrorCodeDevModeFlag: // not an error code
262 case kErrorCodeResumedFlag: // not an error code
263 case kErrorCodeTestImageFlag: // not an error code
264 case kErrorCodeTestOmahaUrlFlag: // not an error code
265 case kErrorCodeSpecialFlags: // not an error code
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800266 // These shouldn't happen. Enumerating these explicitly here so that we
267 // can let the compiler warn about new error codes that are added to
268 // action_processor.h but not added here.
269 LOG(WARNING) << "Unexpected error code for UpdateFailed";
270 break;
271
272 // Note: Not adding a default here so as to let the compiler warn us of
273 // any new enums that were added in the .h but not listed in this switch.
274 }
275}
276
Jay Srinivasan08262882012-12-28 19:29:43 -0800277bool PayloadState::ShouldBackoffDownload() {
278 if (response_.disable_payload_backoff) {
279 LOG(INFO) << "Payload backoff logic is disabled. "
280 "Can proceed with the download";
281 return false;
282 }
283
284 if (response_.is_delta_payload) {
285 // If delta payloads fail, we want to fallback quickly to full payloads as
286 // they are more likely to succeed. Exponential backoffs would greatly
287 // slow down the fallback to full payloads. So we don't backoff for delta
288 // payloads.
289 LOG(INFO) << "No backoffs for delta payloads. "
290 << "Can proceed with the download";
291 return false;
292 }
293
294 if (!utils::IsOfficialBuild()) {
295 // Backoffs are needed only for official builds. We do not want any delays
296 // or update failures due to backoffs during testing or development.
297 LOG(INFO) << "No backoffs for test/dev images. "
298 << "Can proceed with the download";
299 return false;
300 }
301
302 if (backoff_expiry_time_.is_null()) {
303 LOG(INFO) << "No backoff expiry time has been set. "
304 << "Can proceed with the download";
305 return false;
306 }
307
308 if (backoff_expiry_time_ < Time::Now()) {
309 LOG(INFO) << "The backoff expiry time ("
310 << utils::ToString(backoff_expiry_time_)
311 << ") has elapsed. Can proceed with the download";
312 return false;
313 }
314
315 LOG(INFO) << "Cannot proceed with downloads as we need to backoff until "
316 << utils::ToString(backoff_expiry_time_);
317 return true;
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800318}
319
Chris Sosaaa18e162013-06-20 13:20:30 -0700320void PayloadState::Rollback() {
321 SetRollbackVersion(system_state_->request_params()->app_version());
322}
323
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800324void PayloadState::IncrementPayloadAttemptNumber() {
Alex Deymo820cc702013-06-28 15:43:46 -0700325 // Update the payload attempt number for both payload types: full and delta.
326 SetPayloadAttemptNumber(GetPayloadAttemptNumber() + 1);
327}
328
329void PayloadState::IncrementFullPayloadAttemptNumber() {
330 // Update the payload attempt number for full payloads and the backoff time.
Jay Srinivasan08262882012-12-28 19:29:43 -0800331 if (response_.is_delta_payload) {
332 LOG(INFO) << "Not incrementing payload attempt number for delta payloads";
333 return;
334 }
335
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800336 LOG(INFO) << "Incrementing the payload attempt number";
Alex Deymo820cc702013-06-28 15:43:46 -0700337 SetFullPayloadAttemptNumber(GetFullPayloadAttemptNumber() + 1);
Jay Srinivasan08262882012-12-28 19:29:43 -0800338 UpdateBackoffExpiryTime();
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800339}
340
341void PayloadState::IncrementUrlIndex() {
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800342 uint32_t next_url_index = GetUrlIndex() + 1;
Jay Srinivasan53173b92013-05-17 17:13:01 -0700343 if (next_url_index < candidate_urls_.size()) {
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800344 LOG(INFO) << "Incrementing the URL index for next attempt";
345 SetUrlIndex(next_url_index);
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800346 } else {
347 LOG(INFO) << "Resetting the current URL index (" << GetUrlIndex() << ") to "
Jay Srinivasan53173b92013-05-17 17:13:01 -0700348 << "0 as we only have " << candidate_urls_.size()
349 << " candidate URL(s)";
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800350 SetUrlIndex(0);
Alex Deymo820cc702013-06-28 15:43:46 -0700351 IncrementPayloadAttemptNumber();
352 IncrementFullPayloadAttemptNumber();
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800353 }
Jay Srinivasan08262882012-12-28 19:29:43 -0800354
David Zeuthencc6f9962013-04-18 11:57:24 -0700355 // If we have multiple URLs, record that we just switched to another one
Jay Srinivasan53173b92013-05-17 17:13:01 -0700356 if (candidate_urls_.size() > 1)
David Zeuthencc6f9962013-04-18 11:57:24 -0700357 SetUrlSwitchCount(url_switch_count_ + 1);
358
Jay Srinivasan08262882012-12-28 19:29:43 -0800359 // Whenever we update the URL index, we should also clear the URL failure
360 // count so we can start over fresh for the new URL.
361 SetUrlFailureCount(0);
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800362}
363
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800364void PayloadState::IncrementFailureCount() {
365 uint32_t next_url_failure_count = GetUrlFailureCount() + 1;
Jay Srinivasan08262882012-12-28 19:29:43 -0800366 if (next_url_failure_count < response_.max_failure_count_per_url) {
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800367 LOG(INFO) << "Incrementing the URL failure count";
368 SetUrlFailureCount(next_url_failure_count);
369 } else {
370 LOG(INFO) << "Reached max number of failures for Url" << GetUrlIndex()
371 << ". Trying next available URL";
372 IncrementUrlIndex();
373 }
374}
375
Jay Srinivasan08262882012-12-28 19:29:43 -0800376void PayloadState::UpdateBackoffExpiryTime() {
377 if (response_.disable_payload_backoff) {
378 LOG(INFO) << "Resetting backoff expiry time as payload backoff is disabled";
379 SetBackoffExpiryTime(Time());
380 return;
381 }
382
Alex Deymo820cc702013-06-28 15:43:46 -0700383 if (GetFullPayloadAttemptNumber() == 0) {
Jay Srinivasan08262882012-12-28 19:29:43 -0800384 SetBackoffExpiryTime(Time());
385 return;
386 }
387
388 // Since we're doing left-shift below, make sure we don't shift more
Alex Deymo820cc702013-06-28 15:43:46 -0700389 // than this. E.g. if int is 4-bytes, don't left-shift more than 30 bits,
Jay Srinivasan08262882012-12-28 19:29:43 -0800390 // since we don't expect value of kMaxBackoffDays to be more than 100 anyway.
Alex Deymo820cc702013-06-28 15:43:46 -0700391 int num_days = 1; // the value to be shifted.
392 const int kMaxShifts = (sizeof(num_days) * 8) - 2;
Jay Srinivasan08262882012-12-28 19:29:43 -0800393
394 // Normal backoff days is 2 raised to (payload_attempt_number - 1).
395 // E.g. if payload_attempt_number is over 30, limit power to 30.
Alex Deymo820cc702013-06-28 15:43:46 -0700396 int power = min(GetFullPayloadAttemptNumber() - 1, kMaxShifts);
Jay Srinivasan08262882012-12-28 19:29:43 -0800397
398 // The number of days is the minimum of 2 raised to (payload_attempt_number
399 // - 1) or kMaxBackoffDays.
400 num_days = min(num_days << power, kMaxBackoffDays);
401
402 // We don't want all retries to happen exactly at the same time when
403 // retrying after backoff. So add some random minutes to fuzz.
404 int fuzz_minutes = utils::FuzzInt(0, kMaxBackoffFuzzMinutes);
405 TimeDelta next_backoff_interval = TimeDelta::FromDays(num_days) +
406 TimeDelta::FromMinutes(fuzz_minutes);
407 LOG(INFO) << "Incrementing the backoff expiry time by "
408 << utils::FormatTimeDelta(next_backoff_interval);
409 SetBackoffExpiryTime(Time::Now() + next_backoff_interval);
410}
411
Jay Srinivasan19409b72013-04-12 19:23:36 -0700412void PayloadState::UpdateCurrentDownloadSource() {
413 current_download_source_ = kNumDownloadSources;
414
Jay Srinivasan53173b92013-05-17 17:13:01 -0700415 if (GetUrlIndex() < candidate_urls_.size()) {
416 string current_url = candidate_urls_[GetUrlIndex()];
Jay Srinivasan19409b72013-04-12 19:23:36 -0700417 if (StartsWithASCII(current_url, "https://", false))
418 current_download_source_ = kDownloadSourceHttpsServer;
419 else if (StartsWithASCII(current_url, "http://", false))
420 current_download_source_ = kDownloadSourceHttpServer;
421 }
422
423 LOG(INFO) << "Current download source: "
424 << utils::ToString(current_download_source_);
425}
426
427void PayloadState::UpdateBytesDownloaded(size_t count) {
428 SetCurrentBytesDownloaded(
429 current_download_source_,
430 GetCurrentBytesDownloaded(current_download_source_) + count,
431 false);
432 SetTotalBytesDownloaded(
433 current_download_source_,
434 GetTotalBytesDownloaded(current_download_source_) + count,
435 false);
436}
437
438void PayloadState::ReportBytesDownloadedMetrics() {
439 // Report metrics collected from all known download sources to UMA.
440 // The reported data is in Megabytes in order to represent a larger
441 // sample range.
Jay Srinivasandbd9ea22013-04-22 17:45:19 -0700442 int download_sources_used = 0;
443 string metric;
444 uint64_t successful_mbs = 0;
445 uint64_t total_mbs = 0;
Jay Srinivasan19409b72013-04-12 19:23:36 -0700446 for (int i = 0; i < kNumDownloadSources; i++) {
447 DownloadSource source = static_cast<DownloadSource>(i);
448 const int kMaxMiBs = 10240; // Anything above 10GB goes in the last bucket.
David Zeuthen44848602013-06-24 13:32:14 -0700449 uint64_t mbs;
Jay Srinivasan19409b72013-04-12 19:23:36 -0700450
David Zeuthen44848602013-06-24 13:32:14 -0700451 // Only consider this download source (and send byte counts) as
452 // having been used if we downloaded a non-trivial amount of bytes
453 // (e.g. at least 1 MiB) that contributed to the final success of
454 // the update. Otherwise we're going to end up with a lot of
455 // zero-byte events in the histogram.
Jay Srinivasandbd9ea22013-04-22 17:45:19 -0700456
David Zeuthen44848602013-06-24 13:32:14 -0700457 mbs = GetCurrentBytesDownloaded(source) / kNumBytesInOneMiB;
458 if (mbs > 0) {
Jay Srinivasandbd9ea22013-04-22 17:45:19 -0700459 download_sources_used |= (1 << source);
460
David Zeuthen44848602013-06-24 13:32:14 -0700461 metric = "Installer.SuccessfulMBsDownloadedFrom" +
462 utils::ToString(source);
463 successful_mbs += mbs;
464 LOG(INFO) << "Uploading " << mbs << " (MBs) for metric " << metric;
465 system_state_->metrics_lib()->SendToUMA(metric,
466 mbs,
467 0, // min
468 kMaxMiBs,
469 kNumDefaultUmaBuckets);
470 }
Jay Srinivasan19409b72013-04-12 19:23:36 -0700471 SetCurrentBytesDownloaded(source, 0, true);
472
Jay Srinivasan19409b72013-04-12 19:23:36 -0700473 mbs = GetTotalBytesDownloaded(source) / kNumBytesInOneMiB;
David Zeuthen44848602013-06-24 13:32:14 -0700474 if (mbs > 0) {
475 metric = "Installer.TotalMBsDownloadedFrom" + utils::ToString(source);
476 total_mbs += mbs;
477 LOG(INFO) << "Uploading " << mbs << " (MBs) for metric " << metric;
478 system_state_->metrics_lib()->SendToUMA(metric,
479 mbs,
480 0, // min
481 kMaxMiBs,
482 kNumDefaultUmaBuckets);
483 }
Jay Srinivasan19409b72013-04-12 19:23:36 -0700484 SetTotalBytesDownloaded(source, 0, true);
485 }
Jay Srinivasandbd9ea22013-04-22 17:45:19 -0700486
487 metric = "Installer.DownloadSourcesUsed";
488 LOG(INFO) << "Uploading 0x" << std::hex << download_sources_used
489 << " (bit flags) for metric " << metric;
490 int num_buckets = std::min(1 << kNumDownloadSources, kNumDefaultUmaBuckets);
491 system_state_->metrics_lib()->SendToUMA(metric,
492 download_sources_used,
493 0, // min
494 1 << kNumDownloadSources,
495 num_buckets);
496
497 if (successful_mbs) {
498 metric = "Installer.DownloadOverheadPercentage";
499 int percent_overhead = (total_mbs - successful_mbs) * 100 / successful_mbs;
500 LOG(INFO) << "Uploading " << percent_overhead << "% for metric " << metric;
501 system_state_->metrics_lib()->SendToUMA(metric,
502 percent_overhead,
503 0, // min: 0% overhead
504 1000, // max: 1000% overhead
505 kNumDefaultUmaBuckets);
506 }
Jay Srinivasan19409b72013-04-12 19:23:36 -0700507}
508
David Zeuthencc6f9962013-04-18 11:57:24 -0700509void PayloadState::ReportUpdateUrlSwitchesMetric() {
510 string metric = "Installer.UpdateURLSwitches";
511 int value = static_cast<int>(url_switch_count_);
512
513 LOG(INFO) << "Uploading " << value << " (count) for metric " << metric;
514 system_state_->metrics_lib()->SendToUMA(
515 metric,
516 value,
517 0, // min value
518 100, // max value
519 kNumDefaultUmaBuckets);
520}
521
Chris Sosabe45bef2013-04-09 18:25:12 -0700522void PayloadState::ReportRebootMetrics() {
523 // Report the number of num_reboots.
524 string metric = "Installer.UpdateNumReboots";
525 uint32_t num_reboots = GetNumReboots();
526 LOG(INFO) << "Uploading reboot count of " << num_reboots << " for metric "
527 << metric;
528 system_state_->metrics_lib()->SendToUMA(
529 metric,
530 static_cast<int>(num_reboots), // sample
531 0, // min = 0.
532 50, // max
533 25); // buckets
534 SetNumReboots(0);
535}
536
537void PayloadState::UpdateNumReboots() {
538 // We only update the reboot count when the system has been detected to have
539 // been rebooted.
540 if (!system_state_->system_rebooted()) {
541 return;
542 }
543
544 SetNumReboots(GetNumReboots() + 1);
545}
546
547void PayloadState::SetNumReboots(uint32_t num_reboots) {
548 CHECK(prefs_);
549 num_reboots_ = num_reboots;
550 prefs_->SetInt64(kPrefsNumReboots, num_reboots);
551 LOG(INFO) << "Number of Reboots during current update attempt = "
552 << num_reboots_;
553}
554
Jay Srinivasan08262882012-12-28 19:29:43 -0800555void PayloadState::ResetPersistedState() {
556 SetPayloadAttemptNumber(0);
Alex Deymo820cc702013-06-28 15:43:46 -0700557 SetFullPayloadAttemptNumber(0);
Jay Srinivasan08262882012-12-28 19:29:43 -0800558 SetUrlIndex(0);
559 SetUrlFailureCount(0);
David Zeuthencc6f9962013-04-18 11:57:24 -0700560 SetUrlSwitchCount(0);
Jay Srinivasan08262882012-12-28 19:29:43 -0800561 UpdateBackoffExpiryTime(); // This will reset the backoff expiry time.
David Zeuthenf413fe52013-04-22 14:04:39 -0700562 SetUpdateTimestampStart(system_state_->clock()->GetWallclockTime());
David Zeuthen9a017f22013-04-11 16:10:26 -0700563 SetUpdateTimestampEnd(Time()); // Set to null time
564 SetUpdateDurationUptime(TimeDelta::FromSeconds(0));
Jay Srinivasan19409b72013-04-12 19:23:36 -0700565 ResetDownloadSourcesOnNewUpdate();
Chris Sosaaa18e162013-06-20 13:20:30 -0700566 ResetRollbackVersion();
567}
568
569void PayloadState::ResetRollbackVersion() {
570 CHECK(powerwash_safe_prefs_);
571 rollback_version_ = "";
572 powerwash_safe_prefs_->Delete(kPrefsRollbackVersion);
Jay Srinivasan19409b72013-04-12 19:23:36 -0700573}
574
575void PayloadState::ResetDownloadSourcesOnNewUpdate() {
576 for (int i = 0; i < kNumDownloadSources; i++) {
577 DownloadSource source = static_cast<DownloadSource>(i);
578 SetCurrentBytesDownloaded(source, 0, true);
579 // Note: Not resetting the TotalBytesDownloaded as we want that metric
580 // to count the bytes downloaded across various update attempts until
581 // we have successfully applied the update.
582 }
583}
584
Chris Sosaaa18e162013-06-20 13:20:30 -0700585int64_t PayloadState::GetPersistedValue(const string& key,
586 bool across_powerwash) {
587 PrefsInterface* prefs = prefs_;
588 if (across_powerwash)
589 prefs = powerwash_safe_prefs_;
590
Jay Srinivasan19409b72013-04-12 19:23:36 -0700591 CHECK(prefs_);
Chris Sosaaa18e162013-06-20 13:20:30 -0700592 if (!prefs->Exists(key))
Jay Srinivasan19409b72013-04-12 19:23:36 -0700593 return 0;
594
595 int64_t stored_value;
Chris Sosaaa18e162013-06-20 13:20:30 -0700596 if (!prefs->GetInt64(key, &stored_value))
Jay Srinivasan19409b72013-04-12 19:23:36 -0700597 return 0;
598
599 if (stored_value < 0) {
600 LOG(ERROR) << key << ": Invalid value (" << stored_value
601 << ") in persisted state. Defaulting to 0";
602 return 0;
603 }
604
605 return stored_value;
Jay Srinivasan08262882012-12-28 19:29:43 -0800606}
607
608string PayloadState::CalculateResponseSignature() {
609 string response_sign = StringPrintf("NumURLs = %d\n",
Jay Srinivasan53173b92013-05-17 17:13:01 -0700610 candidate_urls_.size());
Jay Srinivasan08262882012-12-28 19:29:43 -0800611
Jay Srinivasan53173b92013-05-17 17:13:01 -0700612 for (size_t i = 0; i < candidate_urls_.size(); i++)
613 response_sign += StringPrintf("Candidate Url%d = %s\n",
614 i, candidate_urls_[i].c_str());
Jay Srinivasan08262882012-12-28 19:29:43 -0800615
616 response_sign += StringPrintf("Payload Size = %llu\n"
617 "Payload Sha256 Hash = %s\n"
618 "Metadata Size = %llu\n"
619 "Metadata Signature = %s\n"
620 "Is Delta Payload = %d\n"
621 "Max Failure Count Per Url = %d\n"
622 "Disable Payload Backoff = %d\n",
623 response_.size,
624 response_.hash.c_str(),
625 response_.metadata_size,
626 response_.metadata_signature.c_str(),
627 response_.is_delta_payload,
628 response_.max_failure_count_per_url,
629 response_.disable_payload_backoff);
630 return response_sign;
631}
632
633void PayloadState::LoadResponseSignature() {
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800634 CHECK(prefs_);
635 string stored_value;
Jay Srinivasan08262882012-12-28 19:29:43 -0800636 if (prefs_->Exists(kPrefsCurrentResponseSignature) &&
637 prefs_->GetString(kPrefsCurrentResponseSignature, &stored_value)) {
638 SetResponseSignature(stored_value);
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800639 }
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800640}
641
Jay Srinivasan19409b72013-04-12 19:23:36 -0700642void PayloadState::SetResponseSignature(const string& response_signature) {
Jay Srinivasan08262882012-12-28 19:29:43 -0800643 CHECK(prefs_);
644 response_signature_ = response_signature;
645 LOG(INFO) << "Current Response Signature = \n" << response_signature_;
646 prefs_->SetString(kPrefsCurrentResponseSignature, response_signature_);
647}
648
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800649void PayloadState::LoadPayloadAttemptNumber() {
Chris Sosaaa18e162013-06-20 13:20:30 -0700650 SetPayloadAttemptNumber(GetPersistedValue(kPrefsPayloadAttemptNumber,
651 false));
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800652}
653
Alex Deymo820cc702013-06-28 15:43:46 -0700654void PayloadState::LoadFullPayloadAttemptNumber() {
655 SetFullPayloadAttemptNumber(GetPersistedValue(kPrefsFullPayloadAttemptNumber,
656 false));
657}
658
659void PayloadState::SetPayloadAttemptNumber(int payload_attempt_number) {
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800660 CHECK(prefs_);
661 payload_attempt_number_ = payload_attempt_number;
662 LOG(INFO) << "Payload Attempt Number = " << payload_attempt_number_;
663 prefs_->SetInt64(kPrefsPayloadAttemptNumber, payload_attempt_number_);
664}
665
Alex Deymo820cc702013-06-28 15:43:46 -0700666void PayloadState::SetFullPayloadAttemptNumber(
667 int full_payload_attempt_number) {
668 CHECK(prefs_);
669 full_payload_attempt_number_ = full_payload_attempt_number;
670 LOG(INFO) << "Full Payload Attempt Number = " << full_payload_attempt_number_;
671 prefs_->SetInt64(kPrefsFullPayloadAttemptNumber,
672 full_payload_attempt_number_);
673}
674
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800675void PayloadState::LoadUrlIndex() {
Chris Sosaaa18e162013-06-20 13:20:30 -0700676 SetUrlIndex(GetPersistedValue(kPrefsCurrentUrlIndex, false));
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800677}
678
679void PayloadState::SetUrlIndex(uint32_t url_index) {
680 CHECK(prefs_);
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800681 url_index_ = url_index;
682 LOG(INFO) << "Current URL Index = " << url_index_;
683 prefs_->SetInt64(kPrefsCurrentUrlIndex, url_index_);
Jay Srinivasan19409b72013-04-12 19:23:36 -0700684
685 // Also update the download source, which is purely dependent on the
686 // current URL index alone.
687 UpdateCurrentDownloadSource();
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800688}
689
David Zeuthencc6f9962013-04-18 11:57:24 -0700690void PayloadState::LoadUrlSwitchCount() {
Chris Sosaaa18e162013-06-20 13:20:30 -0700691 SetUrlSwitchCount(GetPersistedValue(kPrefsUrlSwitchCount, false));
David Zeuthencc6f9962013-04-18 11:57:24 -0700692}
693
694void PayloadState::SetUrlSwitchCount(uint32_t url_switch_count) {
695 CHECK(prefs_);
696 url_switch_count_ = url_switch_count;
697 LOG(INFO) << "URL Switch Count = " << url_switch_count_;
698 prefs_->SetInt64(kPrefsUrlSwitchCount, url_switch_count_);
699}
700
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800701void PayloadState::LoadUrlFailureCount() {
Chris Sosaaa18e162013-06-20 13:20:30 -0700702 SetUrlFailureCount(GetPersistedValue(kPrefsCurrentUrlFailureCount,
703 false));
Jay Srinivasan2b5a0f02012-12-19 17:25:56 -0800704}
705
706void PayloadState::SetUrlFailureCount(uint32_t url_failure_count) {
707 CHECK(prefs_);
708 url_failure_count_ = url_failure_count;
709 LOG(INFO) << "Current URL (Url" << GetUrlIndex()
710 << ")'s Failure Count = " << url_failure_count_;
711 prefs_->SetInt64(kPrefsCurrentUrlFailureCount, url_failure_count_);
Jay Srinivasan6f6ea002012-12-14 11:26:28 -0800712}
713
Jay Srinivasan08262882012-12-28 19:29:43 -0800714void PayloadState::LoadBackoffExpiryTime() {
715 CHECK(prefs_);
716 int64_t stored_value;
717 if (!prefs_->Exists(kPrefsBackoffExpiryTime))
718 return;
719
720 if (!prefs_->GetInt64(kPrefsBackoffExpiryTime, &stored_value))
721 return;
722
723 Time stored_time = Time::FromInternalValue(stored_value);
724 if (stored_time > Time::Now() + TimeDelta::FromDays(kMaxBackoffDays)) {
725 LOG(ERROR) << "Invalid backoff expiry time ("
726 << utils::ToString(stored_time)
727 << ") in persisted state. Resetting.";
728 stored_time = Time();
729 }
730 SetBackoffExpiryTime(stored_time);
731}
732
733void PayloadState::SetBackoffExpiryTime(const Time& new_time) {
734 CHECK(prefs_);
735 backoff_expiry_time_ = new_time;
736 LOG(INFO) << "Backoff Expiry Time = "
737 << utils::ToString(backoff_expiry_time_);
738 prefs_->SetInt64(kPrefsBackoffExpiryTime,
739 backoff_expiry_time_.ToInternalValue());
740}
741
David Zeuthen9a017f22013-04-11 16:10:26 -0700742TimeDelta PayloadState::GetUpdateDuration() {
David Zeuthenf413fe52013-04-22 14:04:39 -0700743 Time end_time = update_timestamp_end_.is_null()
744 ? system_state_->clock()->GetWallclockTime() :
745 update_timestamp_end_;
David Zeuthen9a017f22013-04-11 16:10:26 -0700746 return end_time - update_timestamp_start_;
747}
748
749void PayloadState::LoadUpdateTimestampStart() {
750 int64_t stored_value;
751 Time stored_time;
752
753 CHECK(prefs_);
754
David Zeuthenf413fe52013-04-22 14:04:39 -0700755 Time now = system_state_->clock()->GetWallclockTime();
David Zeuthen9a017f22013-04-11 16:10:26 -0700756
757 if (!prefs_->Exists(kPrefsUpdateTimestampStart)) {
758 // The preference missing is not unexpected - in that case, just
759 // use the current time as start time
760 stored_time = now;
761 } else if (!prefs_->GetInt64(kPrefsUpdateTimestampStart, &stored_value)) {
762 LOG(ERROR) << "Invalid UpdateTimestampStart value. Resetting.";
763 stored_time = now;
764 } else {
765 stored_time = Time::FromInternalValue(stored_value);
766 }
767
768 // Sanity check: If the time read from disk is in the future
769 // (modulo some slack to account for possible NTP drift
770 // adjustments), something is fishy and we should report and
771 // reset.
772 TimeDelta duration_according_to_stored_time = now - stored_time;
773 if (duration_according_to_stored_time < -kDurationSlack) {
774 LOG(ERROR) << "The UpdateTimestampStart value ("
775 << utils::ToString(stored_time)
776 << ") in persisted state is "
David Zeuthen674c3182013-04-18 14:05:20 -0700777 << utils::FormatTimeDelta(duration_according_to_stored_time)
778 << " in the future. Resetting.";
David Zeuthen9a017f22013-04-11 16:10:26 -0700779 stored_time = now;
780 }
781
782 SetUpdateTimestampStart(stored_time);
783}
784
785void PayloadState::SetUpdateTimestampStart(const Time& value) {
786 CHECK(prefs_);
787 update_timestamp_start_ = value;
788 prefs_->SetInt64(kPrefsUpdateTimestampStart,
789 update_timestamp_start_.ToInternalValue());
790 LOG(INFO) << "Update Timestamp Start = "
791 << utils::ToString(update_timestamp_start_);
792}
793
794void PayloadState::SetUpdateTimestampEnd(const Time& value) {
795 update_timestamp_end_ = value;
796 LOG(INFO) << "Update Timestamp End = "
797 << utils::ToString(update_timestamp_end_);
798}
799
800TimeDelta PayloadState::GetUpdateDurationUptime() {
801 return update_duration_uptime_;
802}
803
804void PayloadState::LoadUpdateDurationUptime() {
805 int64_t stored_value;
806 TimeDelta stored_delta;
807
808 CHECK(prefs_);
809
810 if (!prefs_->Exists(kPrefsUpdateDurationUptime)) {
811 // The preference missing is not unexpected - in that case, just
812 // we'll use zero as the delta
813 } else if (!prefs_->GetInt64(kPrefsUpdateDurationUptime, &stored_value)) {
814 LOG(ERROR) << "Invalid UpdateDurationUptime value. Resetting.";
815 stored_delta = TimeDelta::FromSeconds(0);
816 } else {
817 stored_delta = TimeDelta::FromInternalValue(stored_value);
818 }
819
820 // Sanity-check: Uptime can never be greater than the wall-clock
821 // difference (modulo some slack). If it is, report and reset
822 // to the wall-clock difference.
823 TimeDelta diff = GetUpdateDuration() - stored_delta;
824 if (diff < -kDurationSlack) {
825 LOG(ERROR) << "The UpdateDurationUptime value ("
David Zeuthen674c3182013-04-18 14:05:20 -0700826 << utils::FormatTimeDelta(stored_delta)
David Zeuthen9a017f22013-04-11 16:10:26 -0700827 << ") in persisted state is "
David Zeuthen674c3182013-04-18 14:05:20 -0700828 << utils::FormatTimeDelta(diff)
829 << " larger than the wall-clock delta. Resetting.";
David Zeuthen9a017f22013-04-11 16:10:26 -0700830 stored_delta = update_duration_current_;
831 }
832
833 SetUpdateDurationUptime(stored_delta);
834}
835
Chris Sosabe45bef2013-04-09 18:25:12 -0700836void PayloadState::LoadNumReboots() {
Chris Sosaaa18e162013-06-20 13:20:30 -0700837 SetNumReboots(GetPersistedValue(kPrefsNumReboots, false));
838}
839
840void PayloadState::LoadRollbackVersion() {
841 SetNumReboots(GetPersistedValue(kPrefsRollbackVersion, true));
842}
843
844void PayloadState::SetRollbackVersion(const string& rollback_version) {
845 CHECK(powerwash_safe_prefs_);
846 LOG(INFO) << "Blacklisting version "<< rollback_version;
847 rollback_version_ = rollback_version;
848 powerwash_safe_prefs_->SetString(kPrefsRollbackVersion, rollback_version);
Chris Sosabe45bef2013-04-09 18:25:12 -0700849}
850
David Zeuthen9a017f22013-04-11 16:10:26 -0700851void PayloadState::SetUpdateDurationUptimeExtended(const TimeDelta& value,
852 const Time& timestamp,
853 bool use_logging) {
854 CHECK(prefs_);
855 update_duration_uptime_ = value;
856 update_duration_uptime_timestamp_ = timestamp;
857 prefs_->SetInt64(kPrefsUpdateDurationUptime,
858 update_duration_uptime_.ToInternalValue());
859 if (use_logging) {
860 LOG(INFO) << "Update Duration Uptime = "
David Zeuthen674c3182013-04-18 14:05:20 -0700861 << utils::FormatTimeDelta(update_duration_uptime_);
David Zeuthen9a017f22013-04-11 16:10:26 -0700862 }
863}
864
865void PayloadState::SetUpdateDurationUptime(const TimeDelta& value) {
David Zeuthenf413fe52013-04-22 14:04:39 -0700866 Time now = system_state_->clock()->GetMonotonicTime();
867 SetUpdateDurationUptimeExtended(value, now, true);
David Zeuthen9a017f22013-04-11 16:10:26 -0700868}
869
870void PayloadState::CalculateUpdateDurationUptime() {
David Zeuthenf413fe52013-04-22 14:04:39 -0700871 Time now = system_state_->clock()->GetMonotonicTime();
David Zeuthen9a017f22013-04-11 16:10:26 -0700872 TimeDelta uptime_since_last_update = now - update_duration_uptime_timestamp_;
873 TimeDelta new_uptime = update_duration_uptime_ + uptime_since_last_update;
874 // We're frequently called so avoid logging this write
875 SetUpdateDurationUptimeExtended(new_uptime, now, false);
876}
877
David Zeuthen674c3182013-04-18 14:05:20 -0700878void PayloadState::ReportDurationMetrics() {
879 TimeDelta duration = GetUpdateDuration();
880 TimeDelta duration_uptime = GetUpdateDurationUptime();
881 string metric;
882
883 metric = "Installer.UpdateDurationMinutes";
884 system_state_->metrics_lib()->SendToUMA(
885 metric,
886 static_cast<int>(duration.InMinutes()),
887 1, // min: 1 minute
888 365*24*60, // max: 1 year (approx)
889 kNumDefaultUmaBuckets);
890 LOG(INFO) << "Uploading " << utils::FormatTimeDelta(duration)
891 << " for metric " << metric;
892
893 metric = "Installer.UpdateDurationUptimeMinutes";
894 system_state_->metrics_lib()->SendToUMA(
895 metric,
896 static_cast<int>(duration_uptime.InMinutes()),
897 1, // min: 1 minute
898 30*24*60, // max: 1 month (approx)
899 kNumDefaultUmaBuckets);
900 LOG(INFO) << "Uploading " << utils::FormatTimeDelta(duration_uptime)
901 << " for metric " << metric;
902
903 prefs_->Delete(kPrefsUpdateTimestampStart);
904 prefs_->Delete(kPrefsUpdateDurationUptime);
905}
906
Alex Deymo1c656c42013-06-28 11:02:14 -0700907void PayloadState::ReportPayloadTypeMetric() {
908 string metric;
909 PayloadType uma_payload_type;
910 OmahaRequestParams* params = system_state_->request_params();
911
912 if (response_.is_delta_payload) {
913 uma_payload_type = kPayloadTypeDelta;
914 } else if (params->delta_okay()) {
915 uma_payload_type = kPayloadTypeFull;
916 } else { // Full payload, delta was not allowed by request.
917 uma_payload_type = kPayloadTypeForcedFull;
918 }
919
920 metric = "Installer.PayloadFormat";
921 system_state_->metrics_lib()->SendEnumToUMA(
922 metric,
923 uma_payload_type,
924 kNumPayloadTypes);
925 LOG(INFO) << "Uploading " << utils::ToString(uma_payload_type)
926 << " for metric " << metric;
927}
928
Alex Deymo820cc702013-06-28 15:43:46 -0700929void PayloadState::ReportAttemptsCountMetrics() {
930 string metric;
931 int total_attempts = GetPayloadAttemptNumber();
932
933 metric = "Installer.AttemptsCount.Total";
934 system_state_->metrics_lib()->SendToUMA(
935 metric,
936 total_attempts,
937 1, // min
938 50, // max
939 kNumDefaultUmaBuckets);
940 LOG(INFO) << "Uploading " << total_attempts
941 << " for metric " << metric;
942}
943
Jay Srinivasan19409b72013-04-12 19:23:36 -0700944string PayloadState::GetPrefsKey(const string& prefix, DownloadSource source) {
945 return prefix + "-from-" + utils::ToString(source);
946}
947
948void PayloadState::LoadCurrentBytesDownloaded(DownloadSource source) {
949 string key = GetPrefsKey(kPrefsCurrentBytesDownloaded, source);
Chris Sosaaa18e162013-06-20 13:20:30 -0700950 SetCurrentBytesDownloaded(source, GetPersistedValue(key, false), true);
Jay Srinivasan19409b72013-04-12 19:23:36 -0700951}
952
953void PayloadState::SetCurrentBytesDownloaded(
954 DownloadSource source,
955 uint64_t current_bytes_downloaded,
956 bool log) {
957 CHECK(prefs_);
958
959 if (source >= kNumDownloadSources)
960 return;
961
962 // Update the in-memory value.
963 current_bytes_downloaded_[source] = current_bytes_downloaded;
964
965 string prefs_key = GetPrefsKey(kPrefsCurrentBytesDownloaded, source);
966 prefs_->SetInt64(prefs_key, current_bytes_downloaded);
967 LOG_IF(INFO, log) << "Current bytes downloaded for "
968 << utils::ToString(source) << " = "
969 << GetCurrentBytesDownloaded(source);
970}
971
972void PayloadState::LoadTotalBytesDownloaded(DownloadSource source) {
973 string key = GetPrefsKey(kPrefsTotalBytesDownloaded, source);
Chris Sosaaa18e162013-06-20 13:20:30 -0700974 SetTotalBytesDownloaded(source, GetPersistedValue(key, false), true);
Jay Srinivasan19409b72013-04-12 19:23:36 -0700975}
976
977void PayloadState::SetTotalBytesDownloaded(
978 DownloadSource source,
979 uint64_t total_bytes_downloaded,
980 bool log) {
981 CHECK(prefs_);
982
983 if (source >= kNumDownloadSources)
984 return;
985
986 // Update the in-memory value.
987 total_bytes_downloaded_[source] = total_bytes_downloaded;
988
989 // Persist.
990 string prefs_key = GetPrefsKey(kPrefsTotalBytesDownloaded, source);
991 prefs_->SetInt64(prefs_key, total_bytes_downloaded);
992 LOG_IF(INFO, log) << "Total bytes downloaded for "
993 << utils::ToString(source) << " = "
994 << GetTotalBytesDownloaded(source);
995}
996
David Zeuthena573d6f2013-06-14 16:13:36 -0700997void PayloadState::LoadNumResponsesSeen() {
Chris Sosaaa18e162013-06-20 13:20:30 -0700998 SetNumResponsesSeen(GetPersistedValue(kPrefsNumResponsesSeen, false));
David Zeuthena573d6f2013-06-14 16:13:36 -0700999}
1000
1001void PayloadState::SetNumResponsesSeen(int num_responses_seen) {
1002 CHECK(prefs_);
1003 num_responses_seen_ = num_responses_seen;
1004 LOG(INFO) << "Num Responses Seen = " << num_responses_seen_;
1005 prefs_->SetInt64(kPrefsNumResponsesSeen, num_responses_seen_);
1006}
1007
1008void PayloadState::ReportUpdatesAbandonedCountMetric() {
1009 string metric = "Installer.UpdatesAbandonedCount";
1010 int value = num_responses_seen_ - 1;
1011
1012 LOG(INFO) << "Uploading " << value << " (count) for metric " << metric;
1013 system_state_->metrics_lib()->SendToUMA(
1014 metric,
1015 value,
1016 0, // min value
1017 100, // max value
1018 kNumDefaultUmaBuckets);
1019}
1020
Jay Srinivasan53173b92013-05-17 17:13:01 -07001021void PayloadState::ComputeCandidateUrls() {
1022 bool http_url_ok = false;
1023
1024 if (system_state_->IsOfficialBuild()) {
1025 const policy::DevicePolicy* policy = system_state_->device_policy();
1026 if (!(policy && policy->GetHttpDownloadsEnabled(&http_url_ok) &&
1027 http_url_ok))
1028 LOG(INFO) << "Downloads via HTTP Url are not enabled by device policy";
1029 } else {
1030 LOG(INFO) << "Allowing HTTP downloads for unofficial builds";
1031 http_url_ok = true;
1032 }
1033
1034 candidate_urls_.clear();
1035 for (size_t i = 0; i < response_.payload_urls.size(); i++) {
1036 string candidate_url = response_.payload_urls[i];
1037 if (StartsWithASCII(candidate_url, "http://", false) && !http_url_ok)
1038 continue;
1039 candidate_urls_.push_back(candidate_url);
1040 LOG(INFO) << "Candidate Url" << (candidate_urls_.size() - 1)
1041 << ": " << candidate_url;
1042 }
1043
1044 LOG(INFO) << "Found " << candidate_urls_.size() << " candidate URLs "
1045 << "out of " << response_.payload_urls.size() << " URLs supplied";
1046}
1047
David Zeuthene4c58bf2013-06-18 17:26:50 -07001048void PayloadState::CreateSystemUpdatedMarkerFile() {
1049 CHECK(prefs_);
1050 int64_t value = system_state_->clock()->GetWallclockTime().ToInternalValue();
1051 prefs_->SetInt64(kPrefsSystemUpdatedMarker, value);
1052}
1053
1054void PayloadState::BootedIntoUpdate(TimeDelta time_to_reboot) {
1055 // Send |time_to_reboot| as a UMA stat.
1056 string metric = "Installer.TimeToRebootMinutes";
1057 system_state_->metrics_lib()->SendToUMA(metric,
1058 time_to_reboot.InMinutes(),
1059 0, // min: 0 minute
1060 30*24*60, // max: 1 month (approx)
1061 kNumDefaultUmaBuckets);
1062 LOG(INFO) << "Uploading " << utils::FormatTimeDelta(time_to_reboot)
1063 << " for metric " << metric;
1064}
1065
1066void PayloadState::UpdateEngineStarted() {
1067 // Figure out if we just booted into a new update
1068 if (prefs_->Exists(kPrefsSystemUpdatedMarker)) {
1069 int64_t stored_value;
1070 if (prefs_->GetInt64(kPrefsSystemUpdatedMarker, &stored_value)) {
1071 Time system_updated_at = Time::FromInternalValue(stored_value);
1072 if (!system_updated_at.is_null()) {
1073 TimeDelta time_to_reboot =
1074 system_state_->clock()->GetWallclockTime() - system_updated_at;
1075 if (time_to_reboot.ToInternalValue() < 0) {
1076 LOG(ERROR) << "time_to_reboot is negative - system_updated_at: "
1077 << utils::ToString(system_updated_at);
1078 } else {
1079 BootedIntoUpdate(time_to_reboot);
1080 }
1081 }
1082 }
1083 prefs_->Delete(kPrefsSystemUpdatedMarker);
1084 }
1085}
1086
Jay Srinivasan6f6ea002012-12-14 11:26:28 -08001087} // namespace chromeos_update_engine