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