payload_state.cc 51 KB

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