1 //
2 // Copyright (C) 2012 The Android Open Source Project
3 //
4 // Licensed under the Apache License, Version 2.0 (the "License");
5 // you may not use this file except in compliance with the License.
6 // You may obtain a copy of the License at
7 //
8 //      http://www.apache.org/licenses/LICENSE-2.0
9 //
10 // Unless required by applicable law or agreed to in writing, software
11 // distributed under the License is distributed on an "AS IS" BASIS,
12 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 // See the License for the specific language governing permissions and
14 // limitations under the License.
15 //
16 
17 #include "update_engine/payload_state.h"
18 
19 #include <algorithm>
20 #include <string>
21 
22 #include <base/logging.h>
23 #include <base/strings/string_util.h>
24 #include <base/strings/stringprintf.h>
25 #include <metrics/metrics_library.h>
26 #include <policy/device_policy.h>
27 
28 #include "update_engine/common/clock.h"
29 #include "update_engine/common/constants.h"
30 #include "update_engine/common/error_code_utils.h"
31 #include "update_engine/common/hardware_interface.h"
32 #include "update_engine/common/prefs.h"
33 #include "update_engine/common/utils.h"
34 #include "update_engine/connection_manager_interface.h"
35 #include "update_engine/metrics_reporter_interface.h"
36 #include "update_engine/metrics_utils.h"
37 #include "update_engine/omaha_request_params.h"
38 #include "update_engine/payload_consumer/install_plan.h"
39 #include "update_engine/system_state.h"
40 
41 using base::Time;
42 using base::TimeDelta;
43 using std::min;
44 using std::string;
45 
46 namespace chromeos_update_engine {
47 
48 using metrics_utils::GetPersistedValue;
49 
50 const TimeDelta PayloadState::kDurationSlack = TimeDelta::FromSeconds(600);
51 
52 // We want to upperbound backoffs to 16 days
53 static const int kMaxBackoffDays = 16;
54 
55 // We want to randomize retry attempts after the backoff by +/- 6 hours.
56 static const uint32_t kMaxBackoffFuzzMinutes = 12 * 60;
57 
PayloadState()58 PayloadState::PayloadState()
59     : prefs_(nullptr),
60       using_p2p_for_downloading_(false),
61       p2p_num_attempts_(0),
62       payload_attempt_number_(0),
63       full_payload_attempt_number_(0),
64       url_index_(0),
65       url_failure_count_(0),
66       url_switch_count_(0),
67       attempt_num_bytes_downloaded_(0),
68       attempt_connection_type_(metrics::ConnectionType::kUnknown),
69       attempt_error_code_(ErrorCode::kSuccess),
70       attempt_type_(AttemptType::kUpdate) {
71   for (int i = 0; i <= kNumDownloadSources; i++)
72     total_bytes_downloaded_[i] = current_bytes_downloaded_[i] = 0;
73 }
74 
Initialize(SystemState * system_state)75 bool PayloadState::Initialize(SystemState* system_state) {
76   system_state_ = system_state;
77   prefs_ = system_state_->prefs();
78   powerwash_safe_prefs_ = system_state_->powerwash_safe_prefs();
79   LoadResponseSignature();
80   LoadPayloadAttemptNumber();
81   LoadFullPayloadAttemptNumber();
82   LoadUrlIndex();
83   LoadUrlFailureCount();
84   LoadUrlSwitchCount();
85   LoadBackoffExpiryTime();
86   LoadUpdateTimestampStart();
87   // The LoadUpdateDurationUptime() method relies on LoadUpdateTimestampStart()
88   // being called before it. Don't reorder.
89   LoadUpdateDurationUptime();
90   for (int i = 0; i < kNumDownloadSources; i++) {
91     DownloadSource source = static_cast<DownloadSource>(i);
92     LoadCurrentBytesDownloaded(source);
93     LoadTotalBytesDownloaded(source);
94   }
95   LoadNumReboots();
96   LoadNumResponsesSeen();
97   LoadRollbackVersion();
98   LoadP2PFirstAttemptTimestamp();
99   LoadP2PNumAttempts();
100   return true;
101 }
102 
SetResponse(const OmahaResponse & omaha_response)103 void PayloadState::SetResponse(const OmahaResponse& omaha_response) {
104   // Always store the latest response.
105   response_ = omaha_response;
106 
107   // Compute the candidate URLs first as they are used to calculate the
108   // response signature so that a change in enterprise policy for
109   // HTTP downloads being enabled or not could be honored as soon as the
110   // next update check happens.
111   ComputeCandidateUrls();
112 
113   // Check if the "signature" of this response (i.e. the fields we care about)
114   // has changed.
115   string new_response_signature = CalculateResponseSignature();
116   bool has_response_changed = (response_signature_ != new_response_signature);
117 
118   // If the response has changed, we should persist the new signature and
119   // clear away all the existing state.
120   if (has_response_changed) {
121     LOG(INFO) << "Resetting all persisted state as this is a new response";
122     SetNumResponsesSeen(num_responses_seen_ + 1);
123     SetResponseSignature(new_response_signature);
124     ResetPersistedState();
125     return;
126   }
127 
128   // Always start from payload index 0, even for resume, to download partition
129   // info from previous payloads.
130   payload_index_ = 0;
131 
132   // This is the earliest point at which we can validate whether the URL index
133   // we loaded from the persisted state is a valid value. If the response
134   // hasn't changed but the URL index is invalid, it's indicative of some
135   // tampering of the persisted state.
136   if (payload_index_ >= candidate_urls_.size() ||
137       url_index_ >= candidate_urls_[payload_index_].size()) {
138     LOG(INFO) << "Resetting all payload state as the url index seems to have "
139                  "been tampered with";
140     ResetPersistedState();
141     return;
142   }
143 
144   // Update the current download source which depends on the latest value of
145   // the response.
146   UpdateCurrentDownloadSource();
147 }
148 
SetUsingP2PForDownloading(bool value)149 void PayloadState::SetUsingP2PForDownloading(bool value) {
150   using_p2p_for_downloading_ = value;
151   // Update the current download source which depends on whether we are
152   // using p2p or not.
153   UpdateCurrentDownloadSource();
154 }
155 
DownloadComplete()156 void PayloadState::DownloadComplete() {
157   LOG(INFO) << "Payload downloaded successfully";
158   IncrementPayloadAttemptNumber();
159   IncrementFullPayloadAttemptNumber();
160 }
161 
DownloadProgress(size_t count)162 void PayloadState::DownloadProgress(size_t count) {
163   if (count == 0)
164     return;
165 
166   CalculateUpdateDurationUptime();
167   UpdateBytesDownloaded(count);
168 
169   // We've received non-zero bytes from a recent download operation.  Since our
170   // URL failure count is meant to penalize a URL only for consecutive
171   // failures, downloading bytes successfully means we should reset the failure
172   // count (as we know at least that the URL is working). In future, we can
173   // design this to be more sophisticated to check for more intelligent failure
174   // patterns, but right now, even 1 byte downloaded will mark the URL to be
175   // good unless it hits 10 (or configured number of) consecutive failures
176   // again.
177 
178   if (GetUrlFailureCount() == 0)
179     return;
180 
181   LOG(INFO) << "Resetting failure count of Url" << GetUrlIndex()
182             << " to 0 as we received " << count << " bytes successfully";
183   SetUrlFailureCount(0);
184 }
185 
AttemptStarted(AttemptType attempt_type)186 void PayloadState::AttemptStarted(AttemptType attempt_type) {
187   // Flush previous state from abnormal attempt failure, if any.
188   ReportAndClearPersistedAttemptMetrics();
189 
190   attempt_type_ = attempt_type;
191 
192   ClockInterface *clock = system_state_->clock();
193   attempt_start_time_boot_ = clock->GetBootTime();
194   attempt_start_time_monotonic_ = clock->GetMonotonicTime();
195   attempt_num_bytes_downloaded_ = 0;
196 
197   metrics::ConnectionType type;
198   ConnectionType network_connection_type;
199   ConnectionTethering tethering;
200   ConnectionManagerInterface* connection_manager =
201       system_state_->connection_manager();
202   if (!connection_manager->GetConnectionProperties(&network_connection_type,
203                                                    &tethering)) {
204     LOG(ERROR) << "Failed to determine connection type.";
205     type = metrics::ConnectionType::kUnknown;
206   } else {
207     type = metrics_utils::GetConnectionType(network_connection_type, tethering);
208   }
209   attempt_connection_type_ = type;
210 
211   if (attempt_type == AttemptType::kUpdate)
212     PersistAttemptMetrics();
213 }
214 
UpdateResumed()215 void PayloadState::UpdateResumed() {
216   LOG(INFO) << "Resuming an update that was previously started.";
217   UpdateNumReboots();
218   AttemptStarted(AttemptType::kUpdate);
219 }
220 
UpdateRestarted()221 void PayloadState::UpdateRestarted() {
222   LOG(INFO) << "Starting a new update";
223   ResetDownloadSourcesOnNewUpdate();
224   SetNumReboots(0);
225   AttemptStarted(AttemptType::kUpdate);
226 }
227 
UpdateSucceeded()228 void PayloadState::UpdateSucceeded() {
229   // Send the relevant metrics that are tracked in this class to UMA.
230   CalculateUpdateDurationUptime();
231   SetUpdateTimestampEnd(system_state_->clock()->GetWallclockTime());
232 
233   switch (attempt_type_) {
234     case AttemptType::kUpdate:
235       CollectAndReportAttemptMetrics(ErrorCode::kSuccess);
236       CollectAndReportSuccessfulUpdateMetrics();
237       ClearPersistedAttemptMetrics();
238       break;
239 
240     case AttemptType::kRollback:
241       system_state_->metrics_reporter()->ReportRollbackMetrics(
242           metrics::RollbackResult::kSuccess);
243       break;
244   }
245   attempt_error_code_ = ErrorCode::kSuccess;
246 
247   // Reset the number of responses seen since it counts from the last
248   // successful update, e.g. now.
249   SetNumResponsesSeen(0);
250   SetPayloadIndex(0);
251 
252   metrics_utils::SetSystemUpdatedMarker(system_state_->clock(), prefs_);
253 }
254 
UpdateFailed(ErrorCode error)255 void PayloadState::UpdateFailed(ErrorCode error) {
256   ErrorCode base_error = utils::GetBaseErrorCode(error);
257   LOG(INFO) << "Updating payload state for error code: " << base_error
258             << " (" << utils::ErrorCodeToString(base_error) << ")";
259   attempt_error_code_ = base_error;
260 
261   if (candidate_urls_.size() == 0) {
262     // This means we got this error even before we got a valid Omaha response
263     // or don't have any valid candidates in the Omaha response.
264     // So we should not advance the url_index_ in such cases.
265     LOG(INFO) << "Ignoring failures until we get a valid Omaha response.";
266     return;
267   }
268 
269   switch (attempt_type_) {
270     case AttemptType::kUpdate:
271       CollectAndReportAttemptMetrics(base_error);
272       ClearPersistedAttemptMetrics();
273       break;
274 
275     case AttemptType::kRollback:
276       system_state_->metrics_reporter()->ReportRollbackMetrics(
277           metrics::RollbackResult::kFailed);
278       break;
279   }
280 
281 
282   switch (base_error) {
283     // Errors which are good indicators of a problem with a particular URL or
284     // the protocol used in the URL or entities in the communication channel
285     // (e.g. proxies). We should try the next available URL in the next update
286     // check to quickly recover from these errors.
287     case ErrorCode::kPayloadHashMismatchError:
288     case ErrorCode::kPayloadSizeMismatchError:
289     case ErrorCode::kDownloadPayloadVerificationError:
290     case ErrorCode::kDownloadPayloadPubKeyVerificationError:
291     case ErrorCode::kSignedDeltaPayloadExpectedError:
292     case ErrorCode::kDownloadInvalidMetadataMagicString:
293     case ErrorCode::kDownloadSignatureMissingInManifest:
294     case ErrorCode::kDownloadManifestParseError:
295     case ErrorCode::kDownloadMetadataSignatureError:
296     case ErrorCode::kDownloadMetadataSignatureVerificationError:
297     case ErrorCode::kDownloadMetadataSignatureMismatch:
298     case ErrorCode::kDownloadOperationHashVerificationError:
299     case ErrorCode::kDownloadOperationExecutionError:
300     case ErrorCode::kDownloadOperationHashMismatch:
301     case ErrorCode::kDownloadInvalidMetadataSize:
302     case ErrorCode::kDownloadInvalidMetadataSignature:
303     case ErrorCode::kDownloadOperationHashMissingError:
304     case ErrorCode::kDownloadMetadataSignatureMissingError:
305     case ErrorCode::kPayloadMismatchedType:
306     case ErrorCode::kUnsupportedMajorPayloadVersion:
307     case ErrorCode::kUnsupportedMinorPayloadVersion:
308     case ErrorCode::kPayloadTimestampError:
309       IncrementUrlIndex();
310       break;
311 
312     // Errors which seem to be just transient network/communication related
313     // failures and do not indicate any inherent problem with the URL itself.
314     // So, we should keep the current URL but just increment the
315     // failure count to give it more chances. This way, while we maximize our
316     // chances of downloading from the URLs that appear earlier in the response
317     // (because download from a local server URL that appears earlier in a
318     // response is preferable than downloading from the next URL which could be
319     // a internet URL and thus could be more expensive).
320 
321     case ErrorCode::kError:
322     case ErrorCode::kDownloadTransferError:
323     case ErrorCode::kDownloadWriteError:
324     case ErrorCode::kDownloadStateInitializationError:
325     case ErrorCode::kOmahaErrorInHTTPResponse:  // Aggregate for HTTP errors.
326       IncrementFailureCount();
327       break;
328 
329     // Errors which are not specific to a URL and hence shouldn't result in
330     // the URL being penalized. This can happen in two cases:
331     // 1. We haven't started downloading anything: These errors don't cost us
332     // anything in terms of actual payload bytes, so we should just do the
333     // regular retries at the next update check.
334     // 2. We have successfully downloaded the payload: In this case, the
335     // payload attempt number would have been incremented and would take care
336     // of the backoff at the next update check.
337     // In either case, there's no need to update URL index or failure count.
338     case ErrorCode::kOmahaRequestError:
339     case ErrorCode::kOmahaResponseHandlerError:
340     case ErrorCode::kPostinstallRunnerError:
341     case ErrorCode::kFilesystemCopierError:
342     case ErrorCode::kInstallDeviceOpenError:
343     case ErrorCode::kKernelDeviceOpenError:
344     case ErrorCode::kDownloadNewPartitionInfoError:
345     case ErrorCode::kNewRootfsVerificationError:
346     case ErrorCode::kNewKernelVerificationError:
347     case ErrorCode::kPostinstallBootedFromFirmwareB:
348     case ErrorCode::kPostinstallFirmwareRONotUpdatable:
349     case ErrorCode::kOmahaRequestEmptyResponseError:
350     case ErrorCode::kOmahaRequestXMLParseError:
351     case ErrorCode::kOmahaResponseInvalid:
352     case ErrorCode::kOmahaUpdateIgnoredPerPolicy:
353     case ErrorCode::kOmahaUpdateDeferredPerPolicy:
354     case ErrorCode::kNonCriticalUpdateInOOBE:
355     case ErrorCode::kOmahaUpdateDeferredForBackoff:
356     case ErrorCode::kPostinstallPowerwashError:
357     case ErrorCode::kUpdateCanceledByChannelChange:
358     case ErrorCode::kOmahaRequestXMLHasEntityDecl:
359     case ErrorCode::kFilesystemVerifierError:
360     case ErrorCode::kUserCanceled:
361     case ErrorCode::kUpdatedButNotActive:
362       LOG(INFO) << "Not incrementing URL index or failure count for this error";
363       break;
364 
365     case ErrorCode::kSuccess:                            // success code
366     case ErrorCode::kUmaReportedMax:                     // not an error code
367     case ErrorCode::kOmahaRequestHTTPResponseBase:       // aggregated already
368     case ErrorCode::kDevModeFlag:                       // not an error code
369     case ErrorCode::kResumedFlag:                        // not an error code
370     case ErrorCode::kTestImageFlag:                      // not an error code
371     case ErrorCode::kTestOmahaUrlFlag:                   // not an error code
372     case ErrorCode::kSpecialFlags:                       // not an error code
373       // These shouldn't happen. Enumerating these  explicitly here so that we
374       // can let the compiler warn about new error codes that are added to
375       // action_processor.h but not added here.
376       LOG(WARNING) << "Unexpected error code for UpdateFailed";
377       break;
378 
379     // Note: Not adding a default here so as to let the compiler warn us of
380     // any new enums that were added in the .h but not listed in this switch.
381   }
382 }
383 
ShouldBackoffDownload()384 bool PayloadState::ShouldBackoffDownload() {
385   if (response_.disable_payload_backoff) {
386     LOG(INFO) << "Payload backoff logic is disabled. "
387                  "Can proceed with the download";
388     return false;
389   }
390   if (GetUsingP2PForDownloading() && !GetP2PUrl().empty()) {
391     LOG(INFO) << "Payload backoff logic is disabled because download "
392               << "will happen from local peer (via p2p).";
393     return false;
394   }
395   if (system_state_->request_params()->interactive()) {
396     LOG(INFO) << "Payload backoff disabled for interactive update checks.";
397     return false;
398   }
399   for (const auto& package : response_.packages) {
400     if (package.is_delta) {
401       // If delta payloads fail, we want to fallback quickly to full payloads as
402       // they are more likely to succeed. Exponential backoffs would greatly
403       // slow down the fallback to full payloads.  So we don't backoff for delta
404       // payloads.
405       LOG(INFO) << "No backoffs for delta payloads. "
406                 << "Can proceed with the download";
407       return false;
408     }
409   }
410 
411   if (!system_state_->hardware()->IsOfficialBuild()) {
412     // Backoffs are needed only for official builds. We do not want any delays
413     // or update failures due to backoffs during testing or development.
414     LOG(INFO) << "No backoffs for test/dev images. "
415               << "Can proceed with the download";
416     return false;
417   }
418 
419   if (backoff_expiry_time_.is_null()) {
420     LOG(INFO) << "No backoff expiry time has been set. "
421               << "Can proceed with the download";
422     return false;
423   }
424 
425   if (backoff_expiry_time_ < Time::Now()) {
426     LOG(INFO) << "The backoff expiry time ("
427               << utils::ToString(backoff_expiry_time_)
428               << ") has elapsed. Can proceed with the download";
429     return false;
430   }
431 
432   LOG(INFO) << "Cannot proceed with downloads as we need to backoff until "
433             << utils::ToString(backoff_expiry_time_);
434   return true;
435 }
436 
Rollback()437 void PayloadState::Rollback() {
438   SetRollbackVersion(system_state_->request_params()->app_version());
439   AttemptStarted(AttemptType::kRollback);
440 }
441 
IncrementPayloadAttemptNumber()442 void PayloadState::IncrementPayloadAttemptNumber() {
443   // Update the payload attempt number for both payload types: full and delta.
444   SetPayloadAttemptNumber(GetPayloadAttemptNumber() + 1);
445 }
446 
IncrementFullPayloadAttemptNumber()447 void PayloadState::IncrementFullPayloadAttemptNumber() {
448   // Update the payload attempt number for full payloads and the backoff time.
449   if (response_.packages[payload_index_].is_delta) {
450     LOG(INFO) << "Not incrementing payload attempt number for delta payloads";
451     return;
452   }
453 
454   LOG(INFO) << "Incrementing the full payload attempt number";
455   SetFullPayloadAttemptNumber(GetFullPayloadAttemptNumber() + 1);
456   UpdateBackoffExpiryTime();
457 }
458 
IncrementUrlIndex()459 void PayloadState::IncrementUrlIndex() {
460   size_t next_url_index = url_index_ + 1;
461   size_t max_url_size = 0;
462   for (const auto& urls : candidate_urls_)
463     max_url_size = std::max(max_url_size, urls.size());
464   if (next_url_index < max_url_size) {
465     LOG(INFO) << "Incrementing the URL index for next attempt";
466     SetUrlIndex(next_url_index);
467   } else {
468     LOG(INFO) << "Resetting the current URL index (" << url_index_ << ") to "
469               << "0 as we only have " << max_url_size << " candidate URL(s)";
470     SetUrlIndex(0);
471     IncrementPayloadAttemptNumber();
472     IncrementFullPayloadAttemptNumber();
473   }
474 
475   // If we have multiple URLs, record that we just switched to another one
476   if (max_url_size > 1)
477     SetUrlSwitchCount(url_switch_count_ + 1);
478 
479   // Whenever we update the URL index, we should also clear the URL failure
480   // count so we can start over fresh for the new URL.
481   SetUrlFailureCount(0);
482 }
483 
IncrementFailureCount()484 void PayloadState::IncrementFailureCount() {
485   uint32_t next_url_failure_count = GetUrlFailureCount() + 1;
486   if (next_url_failure_count < response_.max_failure_count_per_url) {
487     LOG(INFO) << "Incrementing the URL failure count";
488     SetUrlFailureCount(next_url_failure_count);
489   } else {
490     LOG(INFO) << "Reached max number of failures for Url" << GetUrlIndex()
491               << ". Trying next available URL";
492     IncrementUrlIndex();
493   }
494 }
495 
UpdateBackoffExpiryTime()496 void PayloadState::UpdateBackoffExpiryTime() {
497   if (response_.disable_payload_backoff) {
498     LOG(INFO) << "Resetting backoff expiry time as payload backoff is disabled";
499     SetBackoffExpiryTime(Time());
500     return;
501   }
502 
503   if (GetFullPayloadAttemptNumber() == 0) {
504     SetBackoffExpiryTime(Time());
505     return;
506   }
507 
508   // Since we're doing left-shift below, make sure we don't shift more
509   // than this. E.g. if int is 4-bytes, don't left-shift more than 30 bits,
510   // since we don't expect value of kMaxBackoffDays to be more than 100 anyway.
511   int num_days = 1;  // the value to be shifted.
512   const int kMaxShifts = (sizeof(num_days) * 8) - 2;
513 
514   // Normal backoff days is 2 raised to (payload_attempt_number - 1).
515   // E.g. if payload_attempt_number is over 30, limit power to 30.
516   int power = min(GetFullPayloadAttemptNumber() - 1, kMaxShifts);
517 
518   // The number of days is the minimum of 2 raised to (payload_attempt_number
519   // - 1) or kMaxBackoffDays.
520   num_days = min(num_days << power, kMaxBackoffDays);
521 
522   // We don't want all retries to happen exactly at the same time when
523   // retrying after backoff. So add some random minutes to fuzz.
524   int fuzz_minutes = utils::FuzzInt(0, kMaxBackoffFuzzMinutes);
525   TimeDelta next_backoff_interval = TimeDelta::FromDays(num_days) +
526                                     TimeDelta::FromMinutes(fuzz_minutes);
527   LOG(INFO) << "Incrementing the backoff expiry time by "
528             << utils::FormatTimeDelta(next_backoff_interval);
529   SetBackoffExpiryTime(Time::Now() + next_backoff_interval);
530 }
531 
UpdateCurrentDownloadSource()532 void PayloadState::UpdateCurrentDownloadSource() {
533   current_download_source_ = kNumDownloadSources;
534 
535   if (using_p2p_for_downloading_) {
536     current_download_source_ = kDownloadSourceHttpPeer;
537   } else if (payload_index_ < candidate_urls_.size() &&
538              candidate_urls_[payload_index_].size() != 0) {
539     const string& current_url = candidate_urls_[payload_index_][GetUrlIndex()];
540     if (base::StartsWith(
541             current_url, "https://", base::CompareCase::INSENSITIVE_ASCII)) {
542       current_download_source_ = kDownloadSourceHttpsServer;
543     } else if (base::StartsWith(current_url,
544                                 "http://",
545                                 base::CompareCase::INSENSITIVE_ASCII)) {
546       current_download_source_ = kDownloadSourceHttpServer;
547     }
548   }
549 
550   LOG(INFO) << "Current download source: "
551             << utils::ToString(current_download_source_);
552 }
553 
UpdateBytesDownloaded(size_t count)554 void PayloadState::UpdateBytesDownloaded(size_t count) {
555   SetCurrentBytesDownloaded(
556       current_download_source_,
557       GetCurrentBytesDownloaded(current_download_source_) + count,
558       false);
559   SetTotalBytesDownloaded(
560       current_download_source_,
561       GetTotalBytesDownloaded(current_download_source_) + count,
562       false);
563 
564   attempt_num_bytes_downloaded_ += count;
565 }
566 
CalculatePayloadType()567 PayloadType PayloadState::CalculatePayloadType() {
568   for (const auto& package : response_.packages) {
569     if (package.is_delta) {
570       return kPayloadTypeDelta;
571     }
572   }
573   OmahaRequestParams* params = system_state_->request_params();
574   if (params->delta_okay()) {
575     return kPayloadTypeFull;
576   }
577   // Full payload, delta was not allowed by request.
578   return kPayloadTypeForcedFull;
579 }
580 
581 // TODO(zeuthen): Currently we don't report the UpdateEngine.Attempt.*
582 // metrics if the attempt ends abnormally, e.g. if the update_engine
583 // process crashes or the device is rebooted. See
584 // http://crbug.com/357676
CollectAndReportAttemptMetrics(ErrorCode code)585 void PayloadState::CollectAndReportAttemptMetrics(ErrorCode code) {
586   int attempt_number = GetPayloadAttemptNumber();
587 
588   PayloadType payload_type = CalculatePayloadType();
589 
590   int64_t payload_size = GetPayloadSize();
591 
592   int64_t payload_bytes_downloaded = attempt_num_bytes_downloaded_;
593 
594   ClockInterface *clock = system_state_->clock();
595   TimeDelta duration = clock->GetBootTime() - attempt_start_time_boot_;
596   TimeDelta duration_uptime = clock->GetMonotonicTime() -
597       attempt_start_time_monotonic_;
598 
599   int64_t payload_download_speed_bps = 0;
600   int64_t usec = duration_uptime.InMicroseconds();
601   if (usec > 0) {
602     double sec = static_cast<double>(usec) / Time::kMicrosecondsPerSecond;
603     double bps = static_cast<double>(payload_bytes_downloaded) / sec;
604     payload_download_speed_bps = static_cast<int64_t>(bps);
605   }
606 
607   DownloadSource download_source = current_download_source_;
608 
609   metrics::DownloadErrorCode payload_download_error_code =
610     metrics::DownloadErrorCode::kUnset;
611   ErrorCode internal_error_code = ErrorCode::kSuccess;
612   metrics::AttemptResult attempt_result = metrics_utils::GetAttemptResult(code);
613 
614   // Add additional detail to AttemptResult
615   switch (attempt_result) {
616     case metrics::AttemptResult::kPayloadDownloadError:
617       payload_download_error_code = metrics_utils::GetDownloadErrorCode(code);
618       break;
619 
620     case metrics::AttemptResult::kInternalError:
621       internal_error_code = code;
622       break;
623 
624     // Explicit fall-through for cases where we do not have additional
625     // detail. We avoid the default keyword to force people adding new
626     // AttemptResult values to visit this code and examine whether
627     // additional detail is needed.
628     case metrics::AttemptResult::kUpdateSucceeded:
629     case metrics::AttemptResult::kMetadataMalformed:
630     case metrics::AttemptResult::kOperationMalformed:
631     case metrics::AttemptResult::kOperationExecutionError:
632     case metrics::AttemptResult::kMetadataVerificationFailed:
633     case metrics::AttemptResult::kPayloadVerificationFailed:
634     case metrics::AttemptResult::kVerificationFailed:
635     case metrics::AttemptResult::kPostInstallFailed:
636     case metrics::AttemptResult::kAbnormalTermination:
637     case metrics::AttemptResult::kUpdateCanceled:
638     case metrics::AttemptResult::kUpdateSucceededNotActive:
639     case metrics::AttemptResult::kNumConstants:
640     case metrics::AttemptResult::kUnset:
641       break;
642   }
643 
644   system_state_->metrics_reporter()->ReportUpdateAttemptMetrics(
645       system_state_,
646       attempt_number,
647       payload_type,
648       duration,
649       duration_uptime,
650       payload_size,
651       attempt_result,
652       internal_error_code);
653 
654   system_state_->metrics_reporter()->ReportUpdateAttemptDownloadMetrics(
655       payload_bytes_downloaded,
656       payload_download_speed_bps,
657       download_source,
658       payload_download_error_code,
659       attempt_connection_type_);
660 }
661 
PersistAttemptMetrics()662 void PayloadState::PersistAttemptMetrics() {
663   // TODO(zeuthen): For now we only persist whether an attempt was in
664   // progress and not values/metrics related to the attempt. This
665   // means that when this happens, of all the UpdateEngine.Attempt.*
666   // metrics, only UpdateEngine.Attempt.Result is reported (with the
667   // value |kAbnormalTermination|). In the future we might want to
668   // persist more data so we can report other metrics in the
669   // UpdateEngine.Attempt.* namespace when this happens.
670   prefs_->SetBoolean(kPrefsAttemptInProgress, true);
671 }
672 
ClearPersistedAttemptMetrics()673 void PayloadState::ClearPersistedAttemptMetrics() {
674   prefs_->Delete(kPrefsAttemptInProgress);
675 }
676 
ReportAndClearPersistedAttemptMetrics()677 void PayloadState::ReportAndClearPersistedAttemptMetrics() {
678   bool attempt_in_progress = false;
679   if (!prefs_->GetBoolean(kPrefsAttemptInProgress, &attempt_in_progress))
680     return;
681   if (!attempt_in_progress)
682     return;
683 
684   system_state_->metrics_reporter()
685       ->ReportAbnormallyTerminatedUpdateAttemptMetrics();
686 
687   ClearPersistedAttemptMetrics();
688 }
689 
CollectAndReportSuccessfulUpdateMetrics()690 void PayloadState::CollectAndReportSuccessfulUpdateMetrics() {
691   string metric;
692 
693   // Report metrics collected from all known download sources to UMA.
694   int64_t total_bytes_by_source[kNumDownloadSources];
695   int64_t successful_bytes = 0;
696   int64_t total_bytes = 0;
697   int64_t successful_mbs = 0;
698   int64_t total_mbs = 0;
699 
700   for (int i = 0; i < kNumDownloadSources; i++) {
701     DownloadSource source = static_cast<DownloadSource>(i);
702     int64_t bytes;
703 
704     // Only consider this download source (and send byte counts) as
705     // having been used if we downloaded a non-trivial amount of bytes
706     // (e.g. at least 1 MiB) that contributed to the final success of
707     // the update. Otherwise we're going to end up with a lot of
708     // zero-byte events in the histogram.
709 
710     bytes = GetCurrentBytesDownloaded(source);
711     successful_bytes += bytes;
712     successful_mbs += bytes / kNumBytesInOneMiB;
713     SetCurrentBytesDownloaded(source, 0, true);
714 
715     bytes = GetTotalBytesDownloaded(source);
716     total_bytes_by_source[i] = bytes;
717     total_bytes += bytes;
718     total_mbs += bytes / kNumBytesInOneMiB;
719     SetTotalBytesDownloaded(source, 0, true);
720   }
721 
722   int download_overhead_percentage = 0;
723   if (successful_bytes > 0) {
724     download_overhead_percentage = (total_bytes - successful_bytes) * 100ULL /
725                                    successful_bytes;
726   }
727 
728   int url_switch_count = static_cast<int>(url_switch_count_);
729 
730   int reboot_count = GetNumReboots();
731 
732   SetNumReboots(0);
733 
734   TimeDelta duration = GetUpdateDuration();
735 
736   prefs_->Delete(kPrefsUpdateTimestampStart);
737   prefs_->Delete(kPrefsUpdateDurationUptime);
738 
739   PayloadType payload_type = CalculatePayloadType();
740 
741   int64_t payload_size = GetPayloadSize();
742 
743   int attempt_count = GetPayloadAttemptNumber();
744 
745   int updates_abandoned_count = num_responses_seen_ - 1;
746 
747   system_state_->metrics_reporter()->ReportSuccessfulUpdateMetrics(
748       attempt_count,
749       updates_abandoned_count,
750       payload_type,
751       payload_size,
752       total_bytes_by_source,
753       download_overhead_percentage,
754       duration,
755       reboot_count,
756       url_switch_count);
757 }
758 
UpdateNumReboots()759 void PayloadState::UpdateNumReboots() {
760   // We only update the reboot count when the system has been detected to have
761   // been rebooted.
762   if (!system_state_->system_rebooted()) {
763     return;
764   }
765 
766   SetNumReboots(GetNumReboots() + 1);
767 }
768 
SetNumReboots(uint32_t num_reboots)769 void PayloadState::SetNumReboots(uint32_t num_reboots) {
770   num_reboots_ = num_reboots;
771   metrics_utils::SetNumReboots(num_reboots, prefs_);
772 }
773 
ResetPersistedState()774 void PayloadState::ResetPersistedState() {
775   SetPayloadAttemptNumber(0);
776   SetFullPayloadAttemptNumber(0);
777   SetPayloadIndex(0);
778   SetUrlIndex(0);
779   SetUrlFailureCount(0);
780   SetUrlSwitchCount(0);
781   UpdateBackoffExpiryTime();  // This will reset the backoff expiry time.
782   SetUpdateTimestampStart(system_state_->clock()->GetWallclockTime());
783   SetUpdateTimestampEnd(Time());  // Set to null time
784   SetUpdateDurationUptime(TimeDelta::FromSeconds(0));
785   ResetDownloadSourcesOnNewUpdate();
786   ResetRollbackVersion();
787   SetP2PNumAttempts(0);
788   SetP2PFirstAttemptTimestamp(Time());  // Set to null time
789   SetScatteringWaitPeriod(TimeDelta());
790 }
791 
ResetRollbackVersion()792 void PayloadState::ResetRollbackVersion() {
793   CHECK(powerwash_safe_prefs_);
794   rollback_version_ = "";
795   powerwash_safe_prefs_->Delete(kPrefsRollbackVersion);
796 }
797 
ResetDownloadSourcesOnNewUpdate()798 void PayloadState::ResetDownloadSourcesOnNewUpdate() {
799   for (int i = 0; i < kNumDownloadSources; i++) {
800     DownloadSource source = static_cast<DownloadSource>(i);
801     SetCurrentBytesDownloaded(source, 0, true);
802     // Note: Not resetting the TotalBytesDownloaded as we want that metric
803     // to count the bytes downloaded across various update attempts until
804     // we have successfully applied the update.
805   }
806 }
807 
CalculateResponseSignature()808 string PayloadState::CalculateResponseSignature() {
809   string response_sign;
810   for (size_t i = 0; i < response_.packages.size(); i++) {
811     const auto& package = response_.packages[i];
812     response_sign += base::StringPrintf(
813         "Payload %zu:\n"
814         "  Size = %ju\n"
815         "  Sha256 Hash = %s\n"
816         "  Metadata Size = %ju\n"
817         "  Metadata Signature = %s\n"
818         "  Is Delta = %d\n"
819         "  NumURLs = %zu\n",
820         i,
821         static_cast<uintmax_t>(package.size),
822         package.hash.c_str(),
823         static_cast<uintmax_t>(package.metadata_size),
824         package.metadata_signature.c_str(),
825         package.is_delta,
826         candidate_urls_[i].size());
827 
828     for (size_t j = 0; j < candidate_urls_[i].size(); j++)
829       response_sign += base::StringPrintf(
830           "  Candidate Url%zu = %s\n", j, candidate_urls_[i][j].c_str());
831   }
832 
833   response_sign += base::StringPrintf(
834       "Max Failure Count Per Url = %d\n"
835       "Disable Payload Backoff = %d\n",
836       response_.max_failure_count_per_url,
837       response_.disable_payload_backoff);
838   return response_sign;
839 }
840 
LoadResponseSignature()841 void PayloadState::LoadResponseSignature() {
842   CHECK(prefs_);
843   string stored_value;
844   if (prefs_->Exists(kPrefsCurrentResponseSignature) &&
845       prefs_->GetString(kPrefsCurrentResponseSignature, &stored_value)) {
846     SetResponseSignature(stored_value);
847   }
848 }
849 
SetResponseSignature(const string & response_signature)850 void PayloadState::SetResponseSignature(const string& response_signature) {
851   CHECK(prefs_);
852   response_signature_ = response_signature;
853   LOG(INFO) << "Current Response Signature = \n" << response_signature_;
854   prefs_->SetString(kPrefsCurrentResponseSignature, response_signature_);
855 }
856 
LoadPayloadAttemptNumber()857 void PayloadState::LoadPayloadAttemptNumber() {
858   SetPayloadAttemptNumber(
859       GetPersistedValue(kPrefsPayloadAttemptNumber, prefs_));
860 }
861 
LoadFullPayloadAttemptNumber()862 void PayloadState::LoadFullPayloadAttemptNumber() {
863   SetFullPayloadAttemptNumber(
864       GetPersistedValue(kPrefsFullPayloadAttemptNumber, prefs_));
865 }
866 
SetPayloadAttemptNumber(int payload_attempt_number)867 void PayloadState::SetPayloadAttemptNumber(int payload_attempt_number) {
868   payload_attempt_number_ = payload_attempt_number;
869   metrics_utils::SetPayloadAttemptNumber(payload_attempt_number, prefs_);
870 }
871 
SetFullPayloadAttemptNumber(int full_payload_attempt_number)872 void PayloadState::SetFullPayloadAttemptNumber(
873     int full_payload_attempt_number) {
874   CHECK(prefs_);
875   full_payload_attempt_number_ = full_payload_attempt_number;
876   LOG(INFO) << "Full Payload Attempt Number = " << full_payload_attempt_number_;
877   prefs_->SetInt64(kPrefsFullPayloadAttemptNumber,
878       full_payload_attempt_number_);
879 }
880 
SetPayloadIndex(size_t payload_index)881 void PayloadState::SetPayloadIndex(size_t payload_index) {
882   CHECK(prefs_);
883   payload_index_ = payload_index;
884   LOG(INFO) << "Payload Index = " << payload_index_;
885   prefs_->SetInt64(kPrefsUpdateStatePayloadIndex, payload_index_);
886 }
887 
NextPayload()888 bool PayloadState::NextPayload() {
889   if (payload_index_ + 1 >= candidate_urls_.size())
890     return false;
891   SetPayloadIndex(payload_index_ + 1);
892   return true;
893 }
894 
LoadUrlIndex()895 void PayloadState::LoadUrlIndex() {
896   SetUrlIndex(GetPersistedValue(kPrefsCurrentUrlIndex, prefs_));
897 }
898 
SetUrlIndex(uint32_t url_index)899 void PayloadState::SetUrlIndex(uint32_t url_index) {
900   CHECK(prefs_);
901   url_index_ = url_index;
902   LOG(INFO) << "Current URL Index = " << url_index_;
903   prefs_->SetInt64(kPrefsCurrentUrlIndex, url_index_);
904 
905   // Also update the download source, which is purely dependent on the
906   // current URL index alone.
907   UpdateCurrentDownloadSource();
908 }
909 
LoadScatteringWaitPeriod()910 void PayloadState::LoadScatteringWaitPeriod() {
911   SetScatteringWaitPeriod(TimeDelta::FromSeconds(
912       GetPersistedValue(kPrefsWallClockWaitPeriod, prefs_)));
913 }
914 
SetScatteringWaitPeriod(TimeDelta wait_period)915 void PayloadState::SetScatteringWaitPeriod(TimeDelta wait_period) {
916   CHECK(prefs_);
917   scattering_wait_period_ = wait_period;
918   LOG(INFO) << "Scattering Wait Period (seconds) = "
919             << scattering_wait_period_.InSeconds();
920   if (scattering_wait_period_.InSeconds() > 0) {
921     prefs_->SetInt64(kPrefsWallClockWaitPeriod,
922                      scattering_wait_period_.InSeconds());
923   } else {
924     prefs_->Delete(kPrefsWallClockWaitPeriod);
925   }
926 }
927 
LoadUrlSwitchCount()928 void PayloadState::LoadUrlSwitchCount() {
929   SetUrlSwitchCount(GetPersistedValue(kPrefsUrlSwitchCount, prefs_));
930 }
931 
SetUrlSwitchCount(uint32_t url_switch_count)932 void PayloadState::SetUrlSwitchCount(uint32_t url_switch_count) {
933   CHECK(prefs_);
934   url_switch_count_ = url_switch_count;
935   LOG(INFO) << "URL Switch Count = " << url_switch_count_;
936   prefs_->SetInt64(kPrefsUrlSwitchCount, url_switch_count_);
937 }
938 
LoadUrlFailureCount()939 void PayloadState::LoadUrlFailureCount() {
940   SetUrlFailureCount(GetPersistedValue(kPrefsCurrentUrlFailureCount, prefs_));
941 }
942 
SetUrlFailureCount(uint32_t url_failure_count)943 void PayloadState::SetUrlFailureCount(uint32_t url_failure_count) {
944   CHECK(prefs_);
945   url_failure_count_ = url_failure_count;
946   LOG(INFO) << "Current URL (Url" << GetUrlIndex()
947             << ")'s Failure Count = " << url_failure_count_;
948   prefs_->SetInt64(kPrefsCurrentUrlFailureCount, url_failure_count_);
949 }
950 
LoadBackoffExpiryTime()951 void PayloadState::LoadBackoffExpiryTime() {
952   CHECK(prefs_);
953   int64_t stored_value;
954   if (!prefs_->Exists(kPrefsBackoffExpiryTime))
955     return;
956 
957   if (!prefs_->GetInt64(kPrefsBackoffExpiryTime, &stored_value))
958     return;
959 
960   Time stored_time = Time::FromInternalValue(stored_value);
961   if (stored_time > Time::Now() + TimeDelta::FromDays(kMaxBackoffDays)) {
962     LOG(ERROR) << "Invalid backoff expiry time ("
963                << utils::ToString(stored_time)
964                << ") in persisted state. Resetting.";
965     stored_time = Time();
966   }
967   SetBackoffExpiryTime(stored_time);
968 }
969 
SetBackoffExpiryTime(const Time & new_time)970 void PayloadState::SetBackoffExpiryTime(const Time& new_time) {
971   CHECK(prefs_);
972   backoff_expiry_time_ = new_time;
973   LOG(INFO) << "Backoff Expiry Time = "
974             << utils::ToString(backoff_expiry_time_);
975   prefs_->SetInt64(kPrefsBackoffExpiryTime,
976                    backoff_expiry_time_.ToInternalValue());
977 }
978 
GetUpdateDuration()979 TimeDelta PayloadState::GetUpdateDuration() {
980   Time end_time = update_timestamp_end_.is_null()
981     ? system_state_->clock()->GetWallclockTime() :
982       update_timestamp_end_;
983   return end_time - update_timestamp_start_;
984 }
985 
LoadUpdateTimestampStart()986 void PayloadState::LoadUpdateTimestampStart() {
987   int64_t stored_value;
988   Time stored_time;
989 
990   CHECK(prefs_);
991 
992   Time now = system_state_->clock()->GetWallclockTime();
993 
994   if (!prefs_->Exists(kPrefsUpdateTimestampStart)) {
995     // The preference missing is not unexpected - in that case, just
996     // use the current time as start time
997     stored_time = now;
998   } else if (!prefs_->GetInt64(kPrefsUpdateTimestampStart, &stored_value)) {
999     LOG(ERROR) << "Invalid UpdateTimestampStart value. Resetting.";
1000     stored_time = now;
1001   } else {
1002     stored_time = Time::FromInternalValue(stored_value);
1003   }
1004 
1005   // Sanity check: If the time read from disk is in the future
1006   // (modulo some slack to account for possible NTP drift
1007   // adjustments), something is fishy and we should report and
1008   // reset.
1009   TimeDelta duration_according_to_stored_time = now - stored_time;
1010   if (duration_according_to_stored_time < -kDurationSlack) {
1011     LOG(ERROR) << "The UpdateTimestampStart value ("
1012                << utils::ToString(stored_time)
1013                << ") in persisted state is "
1014                << utils::FormatTimeDelta(duration_according_to_stored_time)
1015                << " in the future. Resetting.";
1016     stored_time = now;
1017   }
1018 
1019   SetUpdateTimestampStart(stored_time);
1020 }
1021 
SetUpdateTimestampStart(const Time & value)1022 void PayloadState::SetUpdateTimestampStart(const Time& value) {
1023   update_timestamp_start_ = value;
1024   metrics_utils::SetUpdateTimestampStart(value, prefs_);
1025 }
1026 
SetUpdateTimestampEnd(const Time & value)1027 void PayloadState::SetUpdateTimestampEnd(const Time& value) {
1028   update_timestamp_end_ = value;
1029   LOG(INFO) << "Update Timestamp End = "
1030             << utils::ToString(update_timestamp_end_);
1031 }
1032 
GetUpdateDurationUptime()1033 TimeDelta PayloadState::GetUpdateDurationUptime() {
1034   return update_duration_uptime_;
1035 }
1036 
LoadUpdateDurationUptime()1037 void PayloadState::LoadUpdateDurationUptime() {
1038   int64_t stored_value;
1039   TimeDelta stored_delta;
1040 
1041   CHECK(prefs_);
1042 
1043   if (!prefs_->Exists(kPrefsUpdateDurationUptime)) {
1044     // The preference missing is not unexpected - in that case, just
1045     // we'll use zero as the delta
1046   } else if (!prefs_->GetInt64(kPrefsUpdateDurationUptime, &stored_value)) {
1047     LOG(ERROR) << "Invalid UpdateDurationUptime value. Resetting.";
1048     stored_delta = TimeDelta::FromSeconds(0);
1049   } else {
1050     stored_delta = TimeDelta::FromInternalValue(stored_value);
1051   }
1052 
1053   // Sanity-check: Uptime can never be greater than the wall-clock
1054   // difference (modulo some slack). If it is, report and reset
1055   // to the wall-clock difference.
1056   TimeDelta diff = GetUpdateDuration() - stored_delta;
1057   if (diff < -kDurationSlack) {
1058     LOG(ERROR) << "The UpdateDurationUptime value ("
1059                << utils::FormatTimeDelta(stored_delta)
1060                << ") in persisted state is "
1061                << utils::FormatTimeDelta(diff)
1062                << " larger than the wall-clock delta. Resetting.";
1063     stored_delta = update_duration_current_;
1064   }
1065 
1066   SetUpdateDurationUptime(stored_delta);
1067 }
1068 
LoadNumReboots()1069 void PayloadState::LoadNumReboots() {
1070   SetNumReboots(GetPersistedValue(kPrefsNumReboots, prefs_));
1071 }
1072 
LoadRollbackVersion()1073 void PayloadState::LoadRollbackVersion() {
1074   CHECK(powerwash_safe_prefs_);
1075   string rollback_version;
1076   if (powerwash_safe_prefs_->GetString(kPrefsRollbackVersion,
1077                                        &rollback_version)) {
1078     SetRollbackVersion(rollback_version);
1079   }
1080 }
1081 
SetRollbackVersion(const string & rollback_version)1082 void PayloadState::SetRollbackVersion(const string& rollback_version) {
1083   CHECK(powerwash_safe_prefs_);
1084   LOG(INFO) << "Blacklisting version "<< rollback_version;
1085   rollback_version_ = rollback_version;
1086   powerwash_safe_prefs_->SetString(kPrefsRollbackVersion, rollback_version);
1087 }
1088 
SetUpdateDurationUptimeExtended(const TimeDelta & value,const Time & timestamp,bool use_logging)1089 void PayloadState::SetUpdateDurationUptimeExtended(const TimeDelta& value,
1090                                                    const Time& timestamp,
1091                                                    bool use_logging) {
1092   CHECK(prefs_);
1093   update_duration_uptime_ = value;
1094   update_duration_uptime_timestamp_ = timestamp;
1095   prefs_->SetInt64(kPrefsUpdateDurationUptime,
1096                    update_duration_uptime_.ToInternalValue());
1097   if (use_logging) {
1098     LOG(INFO) << "Update Duration Uptime = "
1099               << utils::FormatTimeDelta(update_duration_uptime_);
1100   }
1101 }
1102 
SetUpdateDurationUptime(const TimeDelta & value)1103 void PayloadState::SetUpdateDurationUptime(const TimeDelta& value) {
1104   Time now = system_state_->clock()->GetMonotonicTime();
1105   SetUpdateDurationUptimeExtended(value, now, true);
1106 }
1107 
CalculateUpdateDurationUptime()1108 void PayloadState::CalculateUpdateDurationUptime() {
1109   Time now = system_state_->clock()->GetMonotonicTime();
1110   TimeDelta uptime_since_last_update = now - update_duration_uptime_timestamp_;
1111   TimeDelta new_uptime = update_duration_uptime_ + uptime_since_last_update;
1112   // We're frequently called so avoid logging this write
1113   SetUpdateDurationUptimeExtended(new_uptime, now, false);
1114 }
1115 
GetPrefsKey(const string & prefix,DownloadSource source)1116 string PayloadState::GetPrefsKey(const string& prefix, DownloadSource source) {
1117   return prefix + "-from-" + utils::ToString(source);
1118 }
1119 
LoadCurrentBytesDownloaded(DownloadSource source)1120 void PayloadState::LoadCurrentBytesDownloaded(DownloadSource source) {
1121   string key = GetPrefsKey(kPrefsCurrentBytesDownloaded, source);
1122   SetCurrentBytesDownloaded(source, GetPersistedValue(key, prefs_), true);
1123 }
1124 
SetCurrentBytesDownloaded(DownloadSource source,uint64_t current_bytes_downloaded,bool log)1125 void PayloadState::SetCurrentBytesDownloaded(
1126     DownloadSource source,
1127     uint64_t current_bytes_downloaded,
1128     bool log) {
1129   CHECK(prefs_);
1130 
1131   if (source >= kNumDownloadSources)
1132     return;
1133 
1134   // Update the in-memory value.
1135   current_bytes_downloaded_[source] = current_bytes_downloaded;
1136 
1137   string prefs_key = GetPrefsKey(kPrefsCurrentBytesDownloaded, source);
1138   prefs_->SetInt64(prefs_key, current_bytes_downloaded);
1139   LOG_IF(INFO, log) << "Current bytes downloaded for "
1140                     << utils::ToString(source) << " = "
1141                     << GetCurrentBytesDownloaded(source);
1142 }
1143 
LoadTotalBytesDownloaded(DownloadSource source)1144 void PayloadState::LoadTotalBytesDownloaded(DownloadSource source) {
1145   string key = GetPrefsKey(kPrefsTotalBytesDownloaded, source);
1146   SetTotalBytesDownloaded(source, GetPersistedValue(key, prefs_), true);
1147 }
1148 
SetTotalBytesDownloaded(DownloadSource source,uint64_t total_bytes_downloaded,bool log)1149 void PayloadState::SetTotalBytesDownloaded(
1150     DownloadSource source,
1151     uint64_t total_bytes_downloaded,
1152     bool log) {
1153   CHECK(prefs_);
1154 
1155   if (source >= kNumDownloadSources)
1156     return;
1157 
1158   // Update the in-memory value.
1159   total_bytes_downloaded_[source] = total_bytes_downloaded;
1160 
1161   // Persist.
1162   string prefs_key = GetPrefsKey(kPrefsTotalBytesDownloaded, source);
1163   prefs_->SetInt64(prefs_key, total_bytes_downloaded);
1164   LOG_IF(INFO, log) << "Total bytes downloaded for "
1165                     << utils::ToString(source) << " = "
1166                     << GetTotalBytesDownloaded(source);
1167 }
1168 
LoadNumResponsesSeen()1169 void PayloadState::LoadNumResponsesSeen() {
1170   SetNumResponsesSeen(GetPersistedValue(kPrefsNumResponsesSeen, prefs_));
1171 }
1172 
SetNumResponsesSeen(int num_responses_seen)1173 void PayloadState::SetNumResponsesSeen(int num_responses_seen) {
1174   CHECK(prefs_);
1175   num_responses_seen_ = num_responses_seen;
1176   LOG(INFO) << "Num Responses Seen = " << num_responses_seen_;
1177   prefs_->SetInt64(kPrefsNumResponsesSeen, num_responses_seen_);
1178 }
1179 
ComputeCandidateUrls()1180 void PayloadState::ComputeCandidateUrls() {
1181   bool http_url_ok = true;
1182 
1183   if (system_state_->hardware()->IsOfficialBuild()) {
1184     const policy::DevicePolicy* policy = system_state_->device_policy();
1185     if (policy && policy->GetHttpDownloadsEnabled(&http_url_ok) && !http_url_ok)
1186       LOG(INFO) << "Downloads via HTTP Url are not enabled by device policy";
1187   } else {
1188     LOG(INFO) << "Allowing HTTP downloads for unofficial builds";
1189     http_url_ok = true;
1190   }
1191 
1192   candidate_urls_.clear();
1193   for (const auto& package : response_.packages) {
1194     candidate_urls_.emplace_back();
1195     for (const string& candidate_url : package.payload_urls) {
1196       if (base::StartsWith(
1197               candidate_url, "http://", base::CompareCase::INSENSITIVE_ASCII) &&
1198           !http_url_ok) {
1199         continue;
1200       }
1201       candidate_urls_.back().push_back(candidate_url);
1202       LOG(INFO) << "Candidate Url" << (candidate_urls_.back().size() - 1)
1203                 << ": " << candidate_url;
1204     }
1205     LOG(INFO) << "Found " << candidate_urls_.back().size() << " candidate URLs "
1206               << "out of " << package.payload_urls.size()
1207               << " URLs supplied in package " << candidate_urls_.size() - 1;
1208   }
1209 }
1210 
UpdateEngineStarted()1211 void PayloadState::UpdateEngineStarted() {
1212   // Flush previous state from abnormal attempt failure, if any.
1213   ReportAndClearPersistedAttemptMetrics();
1214 
1215   // Avoid the UpdateEngineStarted actions if this is not the first time we
1216   // run the update engine since reboot.
1217   if (!system_state_->system_rebooted())
1218     return;
1219 
1220   // Report time_to_reboot if we booted into a new update.
1221   metrics_utils::LoadAndReportTimeToReboot(
1222       system_state_->metrics_reporter(), prefs_, system_state_->clock());
1223   prefs_->Delete(kPrefsSystemUpdatedMarker);
1224 
1225   // Check if it is needed to send metrics about a failed reboot into a new
1226   // version.
1227   ReportFailedBootIfNeeded();
1228 }
1229 
ReportFailedBootIfNeeded()1230 void PayloadState::ReportFailedBootIfNeeded() {
1231   // If the kPrefsTargetVersionInstalledFrom is present, a successfully applied
1232   // payload was marked as ready immediately before the last reboot, and we
1233   // need to check if such payload successfully rebooted or not.
1234   if (prefs_->Exists(kPrefsTargetVersionInstalledFrom)) {
1235     int64_t installed_from = 0;
1236     if (!prefs_->GetInt64(kPrefsTargetVersionInstalledFrom, &installed_from)) {
1237       LOG(ERROR) << "Error reading TargetVersionInstalledFrom on reboot.";
1238       return;
1239     }
1240     // Old Chrome OS devices will write 2 or 4 in this setting, with the
1241     // partition number. We are now using slot numbers (0 or 1) instead, so
1242     // the following comparison will not match if we are comparing an old
1243     // partition number against a new slot number, which is the correct outcome
1244     // since we successfully booted the new update in that case. If the boot
1245     // failed, we will read this value from the same version, so it will always
1246     // be compatible.
1247     if (installed_from == system_state_->boot_control()->GetCurrentSlot()) {
1248       // A reboot was pending, but the chromebook is again in the same
1249       // BootDevice where the update was installed from.
1250       int64_t target_attempt;
1251       if (!prefs_->GetInt64(kPrefsTargetVersionAttempt, &target_attempt)) {
1252         LOG(ERROR) << "Error reading TargetVersionAttempt when "
1253                       "TargetVersionInstalledFrom was present.";
1254         target_attempt = 1;
1255       }
1256 
1257       // Report the UMA metric of the current boot failure.
1258       system_state_->metrics_reporter()->ReportFailedUpdateCount(
1259           target_attempt);
1260     } else {
1261       prefs_->Delete(kPrefsTargetVersionAttempt);
1262       prefs_->Delete(kPrefsTargetVersionUniqueId);
1263     }
1264     prefs_->Delete(kPrefsTargetVersionInstalledFrom);
1265   }
1266 }
1267 
ExpectRebootInNewVersion(const string & target_version_uid)1268 void PayloadState::ExpectRebootInNewVersion(const string& target_version_uid) {
1269   // Expect to boot into the new partition in the next reboot setting the
1270   // TargetVersion* flags in the Prefs.
1271   string stored_target_version_uid;
1272   string target_version_id;
1273   string target_partition;
1274   int64_t target_attempt;
1275 
1276   if (prefs_->Exists(kPrefsTargetVersionUniqueId) &&
1277       prefs_->GetString(kPrefsTargetVersionUniqueId,
1278                         &stored_target_version_uid) &&
1279       stored_target_version_uid == target_version_uid) {
1280     if (!prefs_->GetInt64(kPrefsTargetVersionAttempt, &target_attempt))
1281       target_attempt = 0;
1282   } else {
1283     prefs_->SetString(kPrefsTargetVersionUniqueId, target_version_uid);
1284     target_attempt = 0;
1285   }
1286   prefs_->SetInt64(kPrefsTargetVersionAttempt, target_attempt + 1);
1287 
1288   prefs_->SetInt64(kPrefsTargetVersionInstalledFrom,
1289                    system_state_->boot_control()->GetCurrentSlot());
1290 }
1291 
ResetUpdateStatus()1292 void PayloadState::ResetUpdateStatus() {
1293   // Remove the TargetVersionInstalledFrom pref so that if the machine is
1294   // rebooted the next boot is not flagged as failed to rebooted into the
1295   // new applied payload.
1296   prefs_->Delete(kPrefsTargetVersionInstalledFrom);
1297 
1298   // Also decrement the attempt number if it exists.
1299   int64_t target_attempt;
1300   if (prefs_->GetInt64(kPrefsTargetVersionAttempt, &target_attempt))
1301     prefs_->SetInt64(kPrefsTargetVersionAttempt, target_attempt - 1);
1302 }
1303 
GetP2PNumAttempts()1304 int PayloadState::GetP2PNumAttempts() {
1305   return p2p_num_attempts_;
1306 }
1307 
SetP2PNumAttempts(int value)1308 void PayloadState::SetP2PNumAttempts(int value) {
1309   p2p_num_attempts_ = value;
1310   LOG(INFO) << "p2p Num Attempts = " << p2p_num_attempts_;
1311   CHECK(prefs_);
1312   prefs_->SetInt64(kPrefsP2PNumAttempts, value);
1313 }
1314 
LoadP2PNumAttempts()1315 void PayloadState::LoadP2PNumAttempts() {
1316   SetP2PNumAttempts(GetPersistedValue(kPrefsP2PNumAttempts, prefs_));
1317 }
1318 
GetP2PFirstAttemptTimestamp()1319 Time PayloadState::GetP2PFirstAttemptTimestamp() {
1320   return p2p_first_attempt_timestamp_;
1321 }
1322 
SetP2PFirstAttemptTimestamp(const Time & time)1323 void PayloadState::SetP2PFirstAttemptTimestamp(const Time& time) {
1324   p2p_first_attempt_timestamp_ = time;
1325   LOG(INFO) << "p2p First Attempt Timestamp = "
1326             << utils::ToString(p2p_first_attempt_timestamp_);
1327   CHECK(prefs_);
1328   int64_t stored_value = time.ToInternalValue();
1329   prefs_->SetInt64(kPrefsP2PFirstAttemptTimestamp, stored_value);
1330 }
1331 
LoadP2PFirstAttemptTimestamp()1332 void PayloadState::LoadP2PFirstAttemptTimestamp() {
1333   int64_t stored_value =
1334       GetPersistedValue(kPrefsP2PFirstAttemptTimestamp, prefs_);
1335   Time stored_time = Time::FromInternalValue(stored_value);
1336   SetP2PFirstAttemptTimestamp(stored_time);
1337 }
1338 
P2PNewAttempt()1339 void PayloadState::P2PNewAttempt() {
1340   CHECK(prefs_);
1341   // Set timestamp, if it hasn't been set already
1342   if (p2p_first_attempt_timestamp_.is_null()) {
1343     SetP2PFirstAttemptTimestamp(system_state_->clock()->GetWallclockTime());
1344   }
1345   // Increase number of attempts
1346   SetP2PNumAttempts(GetP2PNumAttempts() + 1);
1347 }
1348 
P2PAttemptAllowed()1349 bool PayloadState::P2PAttemptAllowed() {
1350   if (p2p_num_attempts_ > kMaxP2PAttempts) {
1351     LOG(INFO) << "Number of p2p attempts is " << p2p_num_attempts_
1352               << " which is greater than "
1353               << kMaxP2PAttempts
1354               << " - disallowing p2p.";
1355     return false;
1356   }
1357 
1358   if (!p2p_first_attempt_timestamp_.is_null()) {
1359     Time now = system_state_->clock()->GetWallclockTime();
1360     TimeDelta time_spent_attempting_p2p = now - p2p_first_attempt_timestamp_;
1361     if (time_spent_attempting_p2p.InSeconds() < 0) {
1362       LOG(ERROR) << "Time spent attempting p2p is negative"
1363                  << " - disallowing p2p.";
1364       return false;
1365     }
1366     if (time_spent_attempting_p2p.InSeconds() > kMaxP2PAttemptTimeSeconds) {
1367       LOG(INFO) << "Time spent attempting p2p is "
1368                 << utils::FormatTimeDelta(time_spent_attempting_p2p)
1369                 << " which is greater than "
1370                 << utils::FormatTimeDelta(TimeDelta::FromSeconds(
1371                        kMaxP2PAttemptTimeSeconds))
1372                 << " - disallowing p2p.";
1373       return false;
1374     }
1375   }
1376 
1377   return true;
1378 }
1379 
GetPayloadSize()1380 int64_t PayloadState::GetPayloadSize() {
1381   int64_t payload_size = 0;
1382   for (const auto& package : response_.packages)
1383     payload_size += package.size;
1384   return payload_size;
1385 }
1386 
1387 }  // namespace chromeos_update_engine
1388