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