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