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