update_attempter.cc revision 19409b74019d787100b768306e75ab3e5882898d 
1// Copyright (c) 2012 The Chromium OS Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5#include "update_engine/update_attempter.h"
6
7#include <string>
8#include <tr1/memory>
9#include <vector>
10
11#include <base/file_util.h>
12#include <base/rand_util.h>
13#include <glib.h>
14#include <metrics/metrics_library.h>
15#include <policy/libpolicy.h>
16#include <policy/device_policy.h>
17
18#include "update_engine/certificate_checker.h"
19#include "update_engine/constants.h"
20#include "update_engine/dbus_service.h"
21#include "update_engine/download_action.h"
22#include "update_engine/filesystem_copier_action.h"
23#include "update_engine/gpio_handler.h"
24#include "update_engine/libcurl_http_fetcher.h"
25#include "update_engine/multi_range_http_fetcher.h"
26#include "update_engine/omaha_request_action.h"
27#include "update_engine/omaha_request_params.h"
28#include "update_engine/omaha_response_handler_action.h"
29#include "update_engine/payload_state_interface.h"
30#include "update_engine/postinstall_runner_action.h"
31#include "update_engine/prefs_interface.h"
32#include "update_engine/subprocess.h"
33#include "update_engine/system_state.h"
34#include "update_engine/update_check_scheduler.h"
35
36using base::TimeDelta;
37using base::TimeTicks;
38using google::protobuf::NewPermanentCallback;
39using std::make_pair;
40using std::tr1::shared_ptr;
41using std::set;
42using std::string;
43using std::vector;
44
45namespace chromeos_update_engine {
46
47const int UpdateAttempter::kMaxDeltaUpdateFailures = 3;
48
49// Private test server URL w/ custom port number.
50// TODO(garnold) This is a temporary hack to allow us to test the closed loop
51// automated update testing. To be replaced with an hard-coded local IP address.
52const char* const UpdateAttempter::kTestUpdateUrl(
53    "http://garnold.mtv.corp.google.com:8080/update");
54
55const char* kUpdateCompletedMarker =
56    "/var/run/update_engine_autoupdate_completed";
57
58namespace {
59const int kMaxConsecutiveObeyProxyRequests = 20;
60}  // namespace {}
61
62const char* UpdateStatusToString(UpdateStatus status) {
63  switch (status) {
64    case UPDATE_STATUS_IDLE:
65      return "UPDATE_STATUS_IDLE";
66    case UPDATE_STATUS_CHECKING_FOR_UPDATE:
67      return "UPDATE_STATUS_CHECKING_FOR_UPDATE";
68    case UPDATE_STATUS_UPDATE_AVAILABLE:
69      return "UPDATE_STATUS_UPDATE_AVAILABLE";
70    case UPDATE_STATUS_DOWNLOADING:
71      return "UPDATE_STATUS_DOWNLOADING";
72    case UPDATE_STATUS_VERIFYING:
73      return "UPDATE_STATUS_VERIFYING";
74    case UPDATE_STATUS_FINALIZING:
75      return "UPDATE_STATUS_FINALIZING";
76    case UPDATE_STATUS_UPDATED_NEED_REBOOT:
77      return "UPDATE_STATUS_UPDATED_NEED_REBOOT";
78    case UPDATE_STATUS_REPORTING_ERROR_EVENT:
79      return "UPDATE_STATUS_REPORTING_ERROR_EVENT";
80    default:
81      return "unknown status";
82  }
83}
84
85// Turns a generic kActionCodeError to a generic error code specific
86// to |action| (e.g., kActionCodeFilesystemCopierError). If |code| is
87// not kActionCodeError, or the action is not matched, returns |code|
88// unchanged.
89ActionExitCode GetErrorCodeForAction(AbstractAction* action,
90                                     ActionExitCode code) {
91  if (code != kActionCodeError)
92    return code;
93
94  const string type = action->Type();
95  if (type == OmahaRequestAction::StaticType())
96    return kActionCodeOmahaRequestError;
97  if (type == OmahaResponseHandlerAction::StaticType())
98    return kActionCodeOmahaResponseHandlerError;
99  if (type == FilesystemCopierAction::StaticType())
100    return kActionCodeFilesystemCopierError;
101  if (type == PostinstallRunnerAction::StaticType())
102    return kActionCodePostinstallRunnerError;
103
104  return code;
105}
106
107UpdateAttempter::UpdateAttempter(SystemState* system_state,
108                                 DbusGlibInterface* dbus_iface)
109    : processor_(new ActionProcessor()),
110      system_state_(system_state),
111      dbus_service_(NULL),
112      update_check_scheduler_(NULL),
113      fake_update_success_(false),
114      http_response_code_(0),
115      shares_(utils::kCpuSharesNormal),
116      manage_shares_source_(NULL),
117      download_active_(false),
118      status_(UPDATE_STATUS_IDLE),
119      download_progress_(0.0),
120      last_checked_time_(0),
121      new_version_("0.0.0.0"),
122      new_payload_size_(0),
123      proxy_manual_checks_(0),
124      obeying_proxies_(true),
125      chrome_proxy_resolver_(dbus_iface),
126      updated_boot_flags_(false),
127      update_boot_flags_running_(false),
128      start_action_processor_(false),
129      policy_provider_(NULL),
130      is_using_test_url_(false),
131      is_test_mode_(false),
132      is_test_update_attempted_(false) {
133  prefs_ = system_state->prefs();
134  omaha_request_params_ = system_state->request_params();
135  if (utils::FileExists(kUpdateCompletedMarker))
136    status_ = UPDATE_STATUS_UPDATED_NEED_REBOOT;
137}
138
139UpdateAttempter::~UpdateAttempter() {
140  CleanupCpuSharesManagement();
141}
142
143void UpdateAttempter::Update(const string& app_version,
144                             const string& omaha_url,
145                             bool obey_proxies,
146                             bool interactive,
147                             bool is_test_mode) {
148  chrome_proxy_resolver_.Init();
149  fake_update_success_ = false;
150  if (status_ == UPDATE_STATUS_UPDATED_NEED_REBOOT) {
151    // Although we have applied an update, we still want to ping Omaha
152    // to ensure the number of active statistics is accurate.
153    LOG(INFO) << "Not updating b/c we already updated and we're waiting for "
154              << "reboot, we'll ping Omaha instead";
155    PingOmaha();
156    return;
157  }
158  if (status_ != UPDATE_STATUS_IDLE) {
159    // Update in progress. Do nothing
160    return;
161  }
162
163  if (!CalculateUpdateParams(app_version,
164                             omaha_url,
165                             obey_proxies,
166                             interactive,
167                             is_test_mode)) {
168    return;
169  }
170
171  BuildUpdateActions(interactive);
172
173  SetStatusAndNotify(UPDATE_STATUS_CHECKING_FOR_UPDATE,
174                     kUpdateNoticeUnspecified);
175
176  // Just in case we didn't update boot flags yet, make sure they're updated
177  // before any update processing starts.
178  start_action_processor_ = true;
179  UpdateBootFlags();
180}
181
182void UpdateAttempter::RefreshDevicePolicy() {
183  // Lazy initialize the policy provider, or reload the latest policy data.
184  if (!policy_provider_.get())
185    policy_provider_.reset(new policy::PolicyProvider());
186  policy_provider_->Reload();
187
188  const policy::DevicePolicy* device_policy = NULL;
189  if (policy_provider_->device_policy_is_loaded())
190    device_policy = &policy_provider_->GetDevicePolicy();
191
192  if (device_policy)
193    LOG(INFO) << "Device policies/settings present";
194  else
195    LOG(INFO) << "No device policies/settings present.";
196
197  system_state_->set_device_policy(device_policy);
198}
199
200bool UpdateAttempter::CalculateUpdateParams(const string& app_version,
201                                            const string& omaha_url,
202                                            bool obey_proxies,
203                                            bool interactive,
204                                            bool is_test_mode) {
205  http_response_code_ = 0;
206
207  // Set the test mode flag for the current update attempt.
208  is_test_mode_ = is_test_mode;
209  RefreshDevicePolicy();
210  const policy::DevicePolicy* device_policy = system_state_->device_policy();
211  if (device_policy) {
212    bool update_disabled = false;
213    if (device_policy->GetUpdateDisabled(&update_disabled))
214      omaha_request_params_->set_update_disabled(update_disabled);
215
216    string target_version_prefix;
217    if (device_policy->GetTargetVersionPrefix(&target_version_prefix))
218      omaha_request_params_->set_target_version_prefix(target_version_prefix);
219
220    set<string> allowed_types;
221    string allowed_types_str;
222    if (device_policy->GetAllowedConnectionTypesForUpdate(&allowed_types)) {
223      set<string>::const_iterator iter;
224      for (iter = allowed_types.begin(); iter != allowed_types.end(); ++iter)
225        allowed_types_str += *iter + " ";
226    }
227
228    LOG(INFO) << "Networks over which updates are allowed per policy : "
229              << (allowed_types_str.empty() ? "all" : allowed_types_str);
230  }
231
232  CalculateScatteringParams(interactive);
233
234  // Determine whether an alternative test address should be used.
235  string omaha_url_to_use = omaha_url;
236  if ((is_using_test_url_ = (omaha_url_to_use.empty() && is_test_mode_))) {
237    omaha_url_to_use = kTestUpdateUrl;
238    LOG(INFO) << "using alternative server address: " << omaha_url_to_use;
239  }
240
241  if (!omaha_request_params_->Init(app_version,
242                                   omaha_url_to_use,
243                                   interactive)) {
244    LOG(ERROR) << "Unable to initialize Omaha request params.";
245    return false;
246  }
247
248  // Set the target channel iff ReleaseChannelDelegated policy is set to
249  // false and a non-empty ReleaseChannel policy is present. If delegated
250  // is true, we'll ignore ReleaseChannel policy value.
251  if (device_policy) {
252    bool delegated = false;
253    if (device_policy->GetReleaseChannelDelegated(&delegated) && delegated) {
254      LOG(INFO) << "Channel settings are delegated to user by policy. "
255                   "Ignoring ReleaseChannel policy value";
256    }
257    else {
258      LOG(INFO) << "Channel settings are not delegated to the user by policy";
259      string target_channel;
260      if (device_policy->GetReleaseChannel(&target_channel) &&
261          !target_channel.empty()) {
262        // Pass in false for powerwash_allowed until we add it to the policy
263        // protobuf.
264        LOG(INFO) << "Setting target channel from ReleaseChannel policy value";
265        omaha_request_params_->SetTargetChannel(target_channel, false);
266
267        // Since this is the beginning of a new attempt, update the download
268        // channel. The download channel won't be updated until the next
269        // attempt, even if target channel changes meanwhile, so that how we'll
270        // know if we should cancel the current download attempt if there's
271        // such a change in target channel.
272        omaha_request_params_->UpdateDownloadChannel();
273      } else {
274        LOG(INFO) << "No ReleaseChannel specified in policy";
275      }
276    }
277  }
278
279  LOG(INFO) << "update_disabled = "
280            << utils::ToString(omaha_request_params_->update_disabled())
281            << ", target_version_prefix = "
282            << omaha_request_params_->target_version_prefix()
283            << ", scatter_factor_in_seconds = "
284            << utils::FormatSecs(scatter_factor_.InSeconds());
285
286  LOG(INFO) << "Wall Clock Based Wait Enabled = "
287            << omaha_request_params_->wall_clock_based_wait_enabled()
288            << ", Update Check Count Wait Enabled = "
289            << omaha_request_params_->update_check_count_wait_enabled()
290            << ", Waiting Period = " << utils::FormatSecs(
291               omaha_request_params_->waiting_period().InSeconds());
292
293  obeying_proxies_ = true;
294  if (obey_proxies || proxy_manual_checks_ == 0) {
295    LOG(INFO) << "forced to obey proxies";
296    // If forced to obey proxies, every 20th request will not use proxies
297    proxy_manual_checks_++;
298    LOG(INFO) << "proxy manual checks: " << proxy_manual_checks_;
299    if (proxy_manual_checks_ >= kMaxConsecutiveObeyProxyRequests) {
300      proxy_manual_checks_ = 0;
301      obeying_proxies_ = false;
302    }
303  } else if (base::RandInt(0, 4) == 0) {
304    obeying_proxies_ = false;
305  }
306  LOG_IF(INFO, !obeying_proxies_) << "To help ensure updates work, this update "
307      "check we are ignoring the proxy settings and using "
308      "direct connections.";
309
310  DisableDeltaUpdateIfNeeded();
311  return true;
312}
313
314void UpdateAttempter::CalculateScatteringParams(bool interactive) {
315  // Take a copy of the old scatter value before we update it, as
316  // we need to update the waiting period if this value changes.
317  TimeDelta old_scatter_factor = scatter_factor_;
318  const policy::DevicePolicy* device_policy = system_state_->device_policy();
319  if (device_policy) {
320    int64 new_scatter_factor_in_secs = 0;
321    device_policy->GetScatterFactorInSeconds(&new_scatter_factor_in_secs);
322    if (new_scatter_factor_in_secs < 0) // sanitize input, just in case.
323      new_scatter_factor_in_secs  = 0;
324    scatter_factor_ = TimeDelta::FromSeconds(new_scatter_factor_in_secs);
325  }
326
327  bool is_scatter_enabled = false;
328  if (scatter_factor_.InSeconds() == 0) {
329    LOG(INFO) << "Scattering disabled since scatter factor is set to 0";
330  } else if (interactive) {
331    LOG(INFO) << "Scattering disabled as this is an interactive update check";
332  } else if (!system_state_->IsOOBEComplete()) {
333    LOG(INFO) << "Scattering disabled since OOBE is not complete yet";
334  } else {
335    is_scatter_enabled = true;
336    LOG(INFO) << "Scattering is enabled";
337  }
338
339  if (is_scatter_enabled) {
340    // This means the scattering policy is turned on.
341    // Now check if we need to update the waiting period. The two cases
342    // in which we'd need to update the waiting period are:
343    // 1. First time in process or a scheduled check after a user-initiated one.
344    //    (omaha_request_params_->waiting_period will be zero in this case).
345    // 2. Admin has changed the scattering policy value.
346    //    (new scattering value will be different from old one in this case).
347    int64 wait_period_in_secs = 0;
348    if (omaha_request_params_->waiting_period().InSeconds() == 0) {
349      // First case. Check if we have a suitable value to set for
350      // the waiting period.
351      if (prefs_->GetInt64(kPrefsWallClockWaitPeriod, &wait_period_in_secs) &&
352          wait_period_in_secs > 0 &&
353          wait_period_in_secs <= scatter_factor_.InSeconds()) {
354        // This means:
355        // 1. There's a persisted value for the waiting period available.
356        // 2. And that persisted value is still valid.
357        // So, in this case, we should reuse the persisted value instead of
358        // generating a new random value to improve the chances of a good
359        // distribution for scattering.
360        omaha_request_params_->set_waiting_period(
361          TimeDelta::FromSeconds(wait_period_in_secs));
362        LOG(INFO) << "Using persisted wall-clock waiting period: " <<
363            utils::FormatSecs(
364                omaha_request_params_->waiting_period().InSeconds());
365      }
366      else {
367        // This means there's no persisted value for the waiting period
368        // available or its value is invalid given the new scatter_factor value.
369        // So, we should go ahead and regenerate a new value for the
370        // waiting period.
371        LOG(INFO) << "Persisted value not present or not valid ("
372                  << utils::FormatSecs(wait_period_in_secs)
373                  << ") for wall-clock waiting period.";
374        GenerateNewWaitingPeriod();
375      }
376    } else if (scatter_factor_ != old_scatter_factor) {
377      // This means there's already a waiting period value, but we detected
378      // a change in the scattering policy value. So, we should regenerate the
379      // waiting period to make sure it's within the bounds of the new scatter
380      // factor value.
381      GenerateNewWaitingPeriod();
382    } else {
383      // Neither the first time scattering is enabled nor the scattering value
384      // changed. Nothing to do.
385      LOG(INFO) << "Keeping current wall-clock waiting period: " <<
386          utils::FormatSecs(
387              omaha_request_params_->waiting_period().InSeconds());
388    }
389
390    // The invariant at this point is that omaha_request_params_->waiting_period
391    // is non-zero no matter which path we took above.
392    LOG_IF(ERROR, omaha_request_params_->waiting_period().InSeconds() == 0)
393        << "Waiting Period should NOT be zero at this point!!!";
394
395    // Since scattering is enabled, wall clock based wait will always be
396    // enabled.
397    omaha_request_params_->set_wall_clock_based_wait_enabled(true);
398
399    // If we don't have any issues in accessing the file system to update
400    // the update check count value, we'll turn that on as well.
401    bool decrement_succeeded = DecrementUpdateCheckCount();
402    omaha_request_params_->set_update_check_count_wait_enabled(
403      decrement_succeeded);
404  } else {
405    // This means the scattering feature is turned off or disabled for
406    // this particular update check. Make sure to disable
407    // all the knobs and artifacts so that we don't invoke any scattering
408    // related code.
409    omaha_request_params_->set_wall_clock_based_wait_enabled(false);
410    omaha_request_params_->set_update_check_count_wait_enabled(false);
411    omaha_request_params_->set_waiting_period(TimeDelta::FromSeconds(0));
412    prefs_->Delete(kPrefsWallClockWaitPeriod);
413    prefs_->Delete(kPrefsUpdateCheckCount);
414    // Don't delete the UpdateFirstSeenAt file as we don't want manual checks
415    // that result in no-updates (e.g. due to server side throttling) to
416    // cause update starvation by having the client generate a new
417    // UpdateFirstSeenAt for each scheduled check that follows a manual check.
418  }
419}
420
421void UpdateAttempter::GenerateNewWaitingPeriod() {
422  omaha_request_params_->set_waiting_period(TimeDelta::FromSeconds(
423      base::RandInt(1, scatter_factor_.InSeconds())));
424
425  LOG(INFO) << "Generated new wall-clock waiting period: " << utils::FormatSecs(
426                omaha_request_params_->waiting_period().InSeconds());
427
428  // Do a best-effort to persist this in all cases. Even if the persistence
429  // fails, we'll still be able to scatter based on our in-memory value.
430  // The persistence only helps in ensuring a good overall distribution
431  // across multiple devices if they tend to reboot too often.
432  prefs_->SetInt64(kPrefsWallClockWaitPeriod,
433                   omaha_request_params_->waiting_period().InSeconds());
434}
435
436void UpdateAttempter::BuildUpdateActions(bool interactive) {
437  CHECK(!processor_->IsRunning());
438  processor_->set_delegate(this);
439
440  // Actions:
441  LibcurlHttpFetcher* update_check_fetcher =
442      new LibcurlHttpFetcher(GetProxyResolver(), system_state_, is_test_mode_);
443  // Try harder to connect to the network, esp when not interactive.
444  // See comment in libcurl_http_fetcher.cc.
445  update_check_fetcher->set_no_network_max_retries(interactive ? 1 : 3);
446  update_check_fetcher->set_check_certificate(CertificateChecker::kUpdate);
447  shared_ptr<OmahaRequestAction> update_check_action(
448      new OmahaRequestAction(system_state_,
449                             NULL,
450                             update_check_fetcher,  // passes ownership
451                             false));
452  shared_ptr<OmahaResponseHandlerAction> response_handler_action(
453      new OmahaResponseHandlerAction(system_state_));
454  shared_ptr<FilesystemCopierAction> filesystem_copier_action(
455      new FilesystemCopierAction(false, false));
456  shared_ptr<FilesystemCopierAction> kernel_filesystem_copier_action(
457      new FilesystemCopierAction(true, false));
458  shared_ptr<OmahaRequestAction> download_started_action(
459      new OmahaRequestAction(system_state_,
460                             new OmahaEvent(
461                                 OmahaEvent::kTypeUpdateDownloadStarted),
462                             new LibcurlHttpFetcher(GetProxyResolver(),
463                                                    system_state_,
464                                                    is_test_mode_),
465                             false));
466  LibcurlHttpFetcher* download_fetcher =
467      new LibcurlHttpFetcher(GetProxyResolver(), system_state_, is_test_mode_);
468  download_fetcher->set_check_certificate(CertificateChecker::kDownload);
469  shared_ptr<DownloadAction> download_action(
470      new DownloadAction(prefs_,
471                         system_state_,
472                         new MultiRangeHttpFetcher(
473                             download_fetcher)));  // passes ownership
474  shared_ptr<OmahaRequestAction> download_finished_action(
475      new OmahaRequestAction(system_state_,
476                             new OmahaEvent(
477                                 OmahaEvent::kTypeUpdateDownloadFinished),
478                             new LibcurlHttpFetcher(GetProxyResolver(),
479                                                    system_state_,
480                                                    is_test_mode_),
481                             false));
482  shared_ptr<FilesystemCopierAction> filesystem_verifier_action(
483      new FilesystemCopierAction(false, true));
484  shared_ptr<FilesystemCopierAction> kernel_filesystem_verifier_action(
485      new FilesystemCopierAction(true, true));
486  shared_ptr<PostinstallRunnerAction> postinstall_runner_action(
487      new PostinstallRunnerAction);
488  shared_ptr<OmahaRequestAction> update_complete_action(
489      new OmahaRequestAction(system_state_,
490                             new OmahaEvent(OmahaEvent::kTypeUpdateComplete),
491                             new LibcurlHttpFetcher(GetProxyResolver(),
492                                                    system_state_,
493                                                    is_test_mode_),
494                             false));
495
496  download_action->set_delegate(this);
497  response_handler_action_ = response_handler_action;
498  download_action_ = download_action;
499
500  actions_.push_back(shared_ptr<AbstractAction>(update_check_action));
501  actions_.push_back(shared_ptr<AbstractAction>(response_handler_action));
502  actions_.push_back(shared_ptr<AbstractAction>(filesystem_copier_action));
503  actions_.push_back(shared_ptr<AbstractAction>(
504      kernel_filesystem_copier_action));
505  actions_.push_back(shared_ptr<AbstractAction>(download_started_action));
506  actions_.push_back(shared_ptr<AbstractAction>(download_action));
507  actions_.push_back(shared_ptr<AbstractAction>(download_finished_action));
508  actions_.push_back(shared_ptr<AbstractAction>(filesystem_verifier_action));
509  actions_.push_back(shared_ptr<AbstractAction>(
510      kernel_filesystem_verifier_action));
511  actions_.push_back(shared_ptr<AbstractAction>(postinstall_runner_action));
512  actions_.push_back(shared_ptr<AbstractAction>(update_complete_action));
513
514  // Enqueue the actions
515  for (vector<shared_ptr<AbstractAction> >::iterator it = actions_.begin();
516       it != actions_.end(); ++it) {
517    processor_->EnqueueAction(it->get());
518  }
519
520  // Bond them together. We have to use the leaf-types when calling
521  // BondActions().
522  BondActions(update_check_action.get(),
523              response_handler_action.get());
524  BondActions(response_handler_action.get(),
525              filesystem_copier_action.get());
526  BondActions(filesystem_copier_action.get(),
527              kernel_filesystem_copier_action.get());
528  BondActions(kernel_filesystem_copier_action.get(),
529              download_action.get());
530  BondActions(download_action.get(),
531              filesystem_verifier_action.get());
532  BondActions(filesystem_verifier_action.get(),
533              kernel_filesystem_verifier_action.get());
534  BondActions(kernel_filesystem_verifier_action.get(),
535              postinstall_runner_action.get());
536}
537
538void UpdateAttempter::CheckForUpdate(const string& app_version,
539                                     const string& omaha_url,
540                                     bool interactive) {
541  LOG(INFO) << "New update check requested";
542
543  if (status_ != UPDATE_STATUS_IDLE) {
544    LOG(INFO) << "Skipping update check because current status is "
545              << UpdateStatusToString(status_);
546    return;
547  }
548
549  // Read GPIO signals and determine whether this is an automated test scenario.
550  // For safety, we only allow a test update to be performed once; subsequent
551  // update requests will be carried out normally.
552  bool is_test_mode = (!is_test_update_attempted_ &&
553                       system_state_->gpio_handler()->IsTestModeSignaled());
554  if (is_test_mode) {
555    LOG(WARNING) << "this is a test mode update attempt!";
556    is_test_update_attempted_ = true;
557  }
558
559  // Pass through the interactive flag, in case we want to simulate a scheduled
560  // test.
561  Update(app_version, omaha_url, true, interactive, is_test_mode);
562}
563
564bool UpdateAttempter::RebootIfNeeded() {
565  if (status_ != UPDATE_STATUS_UPDATED_NEED_REBOOT) {
566    LOG(INFO) << "Reboot requested, but status is "
567              << UpdateStatusToString(status_) << ", so not rebooting.";
568    return false;
569  }
570  TEST_AND_RETURN_FALSE(utils::Reboot());
571  return true;
572}
573
574// Delegate methods:
575void UpdateAttempter::ProcessingDone(const ActionProcessor* processor,
576                                     ActionExitCode code) {
577  CHECK(response_handler_action_);
578  LOG(INFO) << "Processing Done.";
579  actions_.clear();
580
581  // Reset cpu shares back to normal.
582  CleanupCpuSharesManagement();
583
584  if (status_ == UPDATE_STATUS_REPORTING_ERROR_EVENT) {
585    LOG(INFO) << "Error event sent.";
586
587    // Inform scheduler of new status; also specifically inform about a failed
588    // update attempt with a test address.
589    SetStatusAndNotify(UPDATE_STATUS_IDLE,
590                       (is_using_test_url_ ? kUpdateNoticeTestAddrFailed :
591                        kUpdateNoticeUnspecified));
592
593    if (!fake_update_success_) {
594      return;
595    }
596    LOG(INFO) << "Booted from FW B and tried to install new firmware, "
597        "so requesting reboot from user.";
598  }
599
600  if (code == kActionCodeSuccess) {
601    utils::WriteFile(kUpdateCompletedMarker, "", 0);
602    prefs_->SetInt64(kPrefsDeltaUpdateFailures, 0);
603    prefs_->SetString(kPrefsPreviousVersion,
604                      omaha_request_params_->app_version());
605    DeltaPerformer::ResetUpdateProgress(prefs_, false);
606
607    system_state_->payload_state()->UpdateSucceeded();
608
609    if (!fake_update_success_) {
610      // Get the time it took to update the system
611      TimeDelta duration = system_state_->payload_state()->GetUpdateDuration();
612      TimeDelta duration_uptime =
613        system_state_->payload_state()->GetUpdateDurationUptime();
614      system_state_->metrics_lib()->SendToUMA(
615           "Installer.UpdateDuration",
616           static_cast<int>(duration.InSeconds()),  // sample
617           1,  // min = 1 second
618           20 * 60,  // max = 20 minutes
619           50);  // buckets
620      system_state_->metrics_lib()->SendToUMA(
621           "Installer.UpdateDurationUptime",
622           static_cast<int>(duration_uptime.InSeconds()),  // sample
623           1,  // min = 1 second
624           20 * 60,  // max = 20 minutes
625           50);  // buckets
626    }
627
628    // Since we're done with scattering fully at this point, this is the
629    // safest point delete the state files, as we're sure that the status is
630    // set to reboot (which means no more updates will be applied until reboot)
631    // This deletion is required for correctness as we want the next update
632    // check to re-create a new random number for the update check count.
633    // Similarly, we also delete the wall-clock-wait period that was persisted
634    // so that we start with a new random value for the next update check
635    // after reboot so that the same device is not favored or punished in any
636    // way.
637    prefs_->Delete(kPrefsUpdateCheckCount);
638    prefs_->Delete(kPrefsWallClockWaitPeriod);
639    prefs_->Delete(kPrefsUpdateFirstSeenAt);
640    prefs_->Delete(kPrefsUpdateTimestampStart);
641    prefs_->Delete(kPrefsUpdateDurationUptime);
642
643    SetStatusAndNotify(UPDATE_STATUS_UPDATED_NEED_REBOOT,
644                       kUpdateNoticeUnspecified);
645    LOG(INFO) << "Update successfully applied, waiting to reboot.";
646
647    // Also report the success code so that the percentiles can be
648    // interpreted properly for the remaining error codes in UMA.
649    utils::SendErrorCodeToUma(system_state_, code);
650    return;
651  }
652
653  if (ScheduleErrorEventAction()) {
654    return;
655  }
656  LOG(INFO) << "No update.";
657  SetStatusAndNotify(UPDATE_STATUS_IDLE, kUpdateNoticeUnspecified);
658}
659
660void UpdateAttempter::ProcessingStopped(const ActionProcessor* processor) {
661  // Reset cpu shares back to normal.
662  CleanupCpuSharesManagement();
663  download_progress_ = 0.0;
664  SetStatusAndNotify(UPDATE_STATUS_IDLE, kUpdateNoticeUnspecified);
665  actions_.clear();
666  error_event_.reset(NULL);
667}
668
669// Called whenever an action has finished processing, either successfully
670// or otherwise.
671void UpdateAttempter::ActionCompleted(ActionProcessor* processor,
672                                      AbstractAction* action,
673                                      ActionExitCode code) {
674  // Reset download progress regardless of whether or not the download
675  // action succeeded. Also, get the response code from HTTP request
676  // actions (update download as well as the initial update check
677  // actions).
678  const string type = action->Type();
679  if (type == DownloadAction::StaticType()) {
680    download_progress_ = 0.0;
681    DownloadAction* download_action = dynamic_cast<DownloadAction*>(action);
682    http_response_code_ = download_action->GetHTTPResponseCode();
683  } else if (type == OmahaRequestAction::StaticType()) {
684    OmahaRequestAction* omaha_request_action =
685        dynamic_cast<OmahaRequestAction*>(action);
686    // If the request is not an event, then it's the update-check.
687    if (!omaha_request_action->IsEvent()) {
688      http_response_code_ = omaha_request_action->GetHTTPResponseCode();
689      // Forward the server-dictated poll interval to the update check
690      // scheduler, if any.
691      if (update_check_scheduler_) {
692        update_check_scheduler_->set_poll_interval(
693            omaha_request_action->GetOutputObject().poll_interval);
694      }
695    }
696  }
697  if (code != kActionCodeSuccess) {
698    // If the current state is at or past the download phase, count the failure
699    // in case a switch to full update becomes necessary. Ignore network
700    // transfer timeouts and failures.
701    if (status_ >= UPDATE_STATUS_DOWNLOADING &&
702        code != kActionCodeDownloadTransferError) {
703      MarkDeltaUpdateFailure();
704    }
705    // On failure, schedule an error event to be sent to Omaha.
706    CreatePendingErrorEvent(action, code);
707    return;
708  }
709  // Find out which action completed.
710  if (type == OmahaResponseHandlerAction::StaticType()) {
711    // Note that the status will be updated to DOWNLOADING when some bytes get
712    // actually downloaded from the server and the BytesReceived callback is
713    // invoked. This avoids notifying the user that a download has started in
714    // cases when the server and the client are unable to initiate the download.
715    CHECK(action == response_handler_action_.get());
716    const InstallPlan& plan = response_handler_action_->install_plan();
717    last_checked_time_ = time(NULL);
718    // TODO(adlr): put version in InstallPlan
719    new_version_ = "0.0.0.0";
720    new_payload_size_ = plan.payload_size;
721    SetupDownload();
722    SetupCpuSharesManagement();
723    SetStatusAndNotify(UPDATE_STATUS_UPDATE_AVAILABLE,
724                       kUpdateNoticeUnspecified);
725  } else if (type == DownloadAction::StaticType()) {
726    SetStatusAndNotify(UPDATE_STATUS_FINALIZING, kUpdateNoticeUnspecified);
727  }
728}
729
730// Stop updating. An attempt will be made to record status to the disk
731// so that updates can be resumed later.
732void UpdateAttempter::Terminate() {
733  // TODO(adlr): implement this method.
734  NOTIMPLEMENTED();
735}
736
737// Try to resume from a previously Terminate()d update.
738void UpdateAttempter::ResumeUpdating() {
739  // TODO(adlr): implement this method.
740  NOTIMPLEMENTED();
741}
742
743void UpdateAttempter::SetDownloadStatus(bool active) {
744  download_active_ = active;
745  LOG(INFO) << "Download status: " << (active ? "active" : "inactive");
746}
747
748void UpdateAttempter::BytesReceived(uint64_t bytes_received, uint64_t total) {
749  if (!download_active_) {
750    LOG(ERROR) << "BytesReceived called while not downloading.";
751    return;
752  }
753  double progress = static_cast<double>(bytes_received) /
754      static_cast<double>(total);
755  // Self throttle based on progress. Also send notifications if
756  // progress is too slow.
757  const double kDeltaPercent = 0.01;  // 1%
758  if (status_ != UPDATE_STATUS_DOWNLOADING ||
759      bytes_received == total ||
760      progress - download_progress_ >= kDeltaPercent ||
761      TimeTicks::Now() - last_notify_time_ >= TimeDelta::FromSeconds(10)) {
762    download_progress_ = progress;
763    SetStatusAndNotify(UPDATE_STATUS_DOWNLOADING, kUpdateNoticeUnspecified);
764  }
765}
766
767bool UpdateAttempter::ResetStatus() {
768  LOG(INFO) << "Attempting to reset state from "
769            << UpdateStatusToString(status_) << " to UPDATE_STATUS_IDLE";
770
771  switch (status_) {
772    case UPDATE_STATUS_IDLE:
773      // no-op.
774      return true;
775
776    case UPDATE_STATUS_UPDATED_NEED_REBOOT:  {
777      bool ret_value = true;
778      status_ = UPDATE_STATUS_IDLE;
779      LOG(INFO) << "Reset Successful";
780
781      // Remove the reboot marker so that if the machine is rebooted
782      // after resetting to idle state, it doesn't go back to
783      // UPDATE_STATUS_UPDATED_NEED_REBOOT state.
784      const FilePath kUpdateCompletedMarkerPath(kUpdateCompletedMarker);
785      if (!file_util::Delete(kUpdateCompletedMarkerPath, false))
786        ret_value = false;
787
788      return ret_value;
789    }
790
791    default:
792      LOG(ERROR) << "Reset not allowed in this state.";
793      return false;
794  }
795}
796
797bool UpdateAttempter::GetStatus(int64_t* last_checked_time,
798                                double* progress,
799                                string* current_operation,
800                                string* new_version,
801                                int64_t* new_payload_size) {
802  *last_checked_time = last_checked_time_;
803  *progress = download_progress_;
804  *current_operation = UpdateStatusToString(status_);
805  *new_version = new_version_;
806  *new_payload_size = new_payload_size_;
807  return true;
808}
809
810void UpdateAttempter::UpdateBootFlags() {
811  if (update_boot_flags_running_) {
812    LOG(INFO) << "Update boot flags running, nothing to do.";
813    return;
814  }
815  if (updated_boot_flags_) {
816    LOG(INFO) << "Already updated boot flags. Skipping.";
817    if (start_action_processor_) {
818      ScheduleProcessingStart();
819    }
820    return;
821  }
822  // This is purely best effort. Failures should be logged by Subprocess. Run
823  // the script asynchronously to avoid blocking the event loop regardless of
824  // the script runtime.
825  update_boot_flags_running_ = true;
826  LOG(INFO) << "Updating boot flags...";
827  vector<string> cmd(1, "/usr/sbin/chromeos-setgoodkernel");
828  if (!Subprocess::Get().Exec(cmd, StaticCompleteUpdateBootFlags, this)) {
829    CompleteUpdateBootFlags(1);
830  }
831}
832
833void UpdateAttempter::CompleteUpdateBootFlags(int return_code) {
834  update_boot_flags_running_ = false;
835  updated_boot_flags_ = true;
836  if (start_action_processor_) {
837    ScheduleProcessingStart();
838  }
839}
840
841void UpdateAttempter::StaticCompleteUpdateBootFlags(
842    int return_code,
843    const string& output,
844    void* p) {
845  reinterpret_cast<UpdateAttempter*>(p)->CompleteUpdateBootFlags(return_code);
846}
847
848void UpdateAttempter::BroadcastStatus() {
849  if (!dbus_service_) {
850    return;
851  }
852  last_notify_time_ = TimeTicks::Now();
853  update_engine_service_emit_status_update(
854      dbus_service_,
855      last_checked_time_,
856      download_progress_,
857      UpdateStatusToString(status_),
858      new_version_.c_str(),
859      new_payload_size_);
860}
861
862uint32_t UpdateAttempter::GetErrorCodeFlags()  {
863  uint32_t flags = 0;
864
865  if (!utils::IsNormalBootMode())
866    flags |= kActionCodeDevModeFlag;
867
868  if (response_handler_action_.get() &&
869      response_handler_action_->install_plan().is_resume)
870    flags |= kActionCodeResumedFlag;
871
872  if (!utils::IsOfficialBuild())
873    flags |= kActionCodeTestImageFlag;
874
875  if (omaha_request_params_->update_url() != kProductionOmahaUrl)
876    flags |= kActionCodeTestOmahaUrlFlag;
877
878  return flags;
879}
880
881bool UpdateAttempter::ShouldCancel(ActionExitCode* cancel_reason) {
882  // Check if the channel we're attempting to update to is the same as the
883  // target channel currently chosen by the user.
884  OmahaRequestParams* params = system_state_->request_params();
885  if (params->download_channel() != params->target_channel()) {
886    LOG(ERROR) << "Aborting download as target channel: "
887               << params->target_channel()
888               << " is different from the download channel: "
889               << params->download_channel();
890    *cancel_reason = kActionCodeUpdateCanceledByChannelChange;
891    return true;
892  }
893
894  return false;
895}
896
897void UpdateAttempter::SetStatusAndNotify(UpdateStatus status,
898                                         UpdateNotice notice) {
899  status_ = status;
900  if (update_check_scheduler_) {
901    update_check_scheduler_->SetUpdateStatus(status_, notice);
902  }
903  BroadcastStatus();
904}
905
906void UpdateAttempter::CreatePendingErrorEvent(AbstractAction* action,
907                                              ActionExitCode code) {
908  if (error_event_.get()) {
909    // This shouldn't really happen.
910    LOG(WARNING) << "There's already an existing pending error event.";
911    return;
912  }
913
914  // For now assume that a generic Omaha response action failure means that
915  // there's no update so don't send an event. Also, double check that the
916  // failure has not occurred while sending an error event -- in which case
917  // don't schedule another. This shouldn't really happen but just in case...
918  if ((action->Type() == OmahaResponseHandlerAction::StaticType() &&
919       code == kActionCodeError) ||
920      status_ == UPDATE_STATUS_REPORTING_ERROR_EVENT) {
921    return;
922  }
923
924  // Classify the code to generate the appropriate result so that
925  // the Borgmon charts show up the results correctly.
926  // Do this before calling GetErrorCodeForAction which could potentially
927  // augment the bit representation of code and thus cause no matches for
928  // the switch cases below.
929  OmahaEvent::Result event_result;
930  switch (code) {
931    case kActionCodeOmahaUpdateIgnoredPerPolicy:
932    case kActionCodeOmahaUpdateDeferredPerPolicy:
933    case kActionCodeOmahaUpdateDeferredForBackoff:
934      event_result = OmahaEvent::kResultUpdateDeferred;
935      break;
936    default:
937      event_result = OmahaEvent::kResultError;
938      break;
939  }
940
941  code = GetErrorCodeForAction(action, code);
942  fake_update_success_ = code == kActionCodePostinstallBootedFromFirmwareB;
943
944  // Compute the final error code with all the bit flags to be sent to Omaha.
945  code = static_cast<ActionExitCode>(code | GetErrorCodeFlags());
946  error_event_.reset(new OmahaEvent(OmahaEvent::kTypeUpdateComplete,
947                                    event_result,
948                                    code));
949}
950
951bool UpdateAttempter::ScheduleErrorEventAction() {
952  if (error_event_.get() == NULL)
953    return false;
954
955  LOG(ERROR) << "Update failed.";
956  system_state_->payload_state()->UpdateFailed(error_event_->error_code);
957
958  // Send it to Uma.
959  LOG(INFO) << "Reporting the error event";
960  utils::SendErrorCodeToUma(system_state_, error_event_->error_code);
961
962  // Send it to Omaha.
963  shared_ptr<OmahaRequestAction> error_event_action(
964      new OmahaRequestAction(system_state_,
965                             error_event_.release(),  // Pass ownership.
966                             new LibcurlHttpFetcher(GetProxyResolver(),
967                                                    system_state_,
968                                                    is_test_mode_),
969                             false));
970  actions_.push_back(shared_ptr<AbstractAction>(error_event_action));
971  processor_->EnqueueAction(error_event_action.get());
972  SetStatusAndNotify(UPDATE_STATUS_REPORTING_ERROR_EVENT,
973                     kUpdateNoticeUnspecified);
974  processor_->StartProcessing();
975  return true;
976}
977
978void UpdateAttempter::SetCpuShares(utils::CpuShares shares) {
979  if (shares_ == shares) {
980    return;
981  }
982  if (utils::SetCpuShares(shares)) {
983    shares_ = shares;
984    LOG(INFO) << "CPU shares = " << shares_;
985  }
986}
987
988void UpdateAttempter::SetupCpuSharesManagement() {
989  if (manage_shares_source_) {
990    LOG(ERROR) << "Cpu shares timeout source hasn't been destroyed.";
991    CleanupCpuSharesManagement();
992  }
993  const int kCpuSharesTimeout = 2 * 60 * 60;  // 2 hours
994  manage_shares_source_ = g_timeout_source_new_seconds(kCpuSharesTimeout);
995  g_source_set_callback(manage_shares_source_,
996                        StaticManageCpuSharesCallback,
997                        this,
998                        NULL);
999  g_source_attach(manage_shares_source_, NULL);
1000  SetCpuShares(utils::kCpuSharesLow);
1001}
1002
1003void UpdateAttempter::CleanupCpuSharesManagement() {
1004  if (manage_shares_source_) {
1005    g_source_destroy(manage_shares_source_);
1006    manage_shares_source_ = NULL;
1007  }
1008  SetCpuShares(utils::kCpuSharesNormal);
1009}
1010
1011gboolean UpdateAttempter::StaticManageCpuSharesCallback(gpointer data) {
1012  return reinterpret_cast<UpdateAttempter*>(data)->ManageCpuSharesCallback();
1013}
1014
1015gboolean UpdateAttempter::StaticStartProcessing(gpointer data) {
1016  reinterpret_cast<UpdateAttempter*>(data)->processor_->StartProcessing();
1017  return FALSE;  // Don't call this callback again.
1018}
1019
1020void UpdateAttempter::ScheduleProcessingStart() {
1021  LOG(INFO) << "Scheduling an action processor start.";
1022  start_action_processor_ = false;
1023  g_idle_add(&StaticStartProcessing, this);
1024}
1025
1026bool UpdateAttempter::ManageCpuSharesCallback() {
1027  SetCpuShares(utils::kCpuSharesNormal);
1028  manage_shares_source_ = NULL;
1029  return false;  // Destroy the timeout source.
1030}
1031
1032void UpdateAttempter::DisableDeltaUpdateIfNeeded() {
1033  int64_t delta_failures;
1034  if (omaha_request_params_->delta_okay() &&
1035      prefs_->GetInt64(kPrefsDeltaUpdateFailures, &delta_failures) &&
1036      delta_failures >= kMaxDeltaUpdateFailures) {
1037    LOG(WARNING) << "Too many delta update failures, forcing full update.";
1038    omaha_request_params_->set_delta_okay(false);
1039  }
1040}
1041
1042void UpdateAttempter::MarkDeltaUpdateFailure() {
1043  // Don't try to resume a failed delta update.
1044  DeltaPerformer::ResetUpdateProgress(prefs_, false);
1045  int64_t delta_failures;
1046  if (!prefs_->GetInt64(kPrefsDeltaUpdateFailures, &delta_failures) ||
1047      delta_failures < 0) {
1048    delta_failures = 0;
1049  }
1050  prefs_->SetInt64(kPrefsDeltaUpdateFailures, ++delta_failures);
1051}
1052
1053void UpdateAttempter::SetupDownload() {
1054  MultiRangeHttpFetcher* fetcher =
1055      dynamic_cast<MultiRangeHttpFetcher*>(download_action_->http_fetcher());
1056  fetcher->ClearRanges();
1057  if (response_handler_action_->install_plan().is_resume) {
1058    // Resuming an update so fetch the update manifest metadata first.
1059    int64_t manifest_metadata_size = 0;
1060    prefs_->GetInt64(kPrefsManifestMetadataSize, &manifest_metadata_size);
1061    fetcher->AddRange(0, manifest_metadata_size);
1062    // If there're remaining unprocessed data blobs, fetch them. Be careful not
1063    // to request data beyond the end of the payload to avoid 416 HTTP response
1064    // error codes.
1065    int64_t next_data_offset = 0;
1066    prefs_->GetInt64(kPrefsUpdateStateNextDataOffset, &next_data_offset);
1067    uint64_t resume_offset = manifest_metadata_size + next_data_offset;
1068    if (resume_offset < response_handler_action_->install_plan().payload_size) {
1069      fetcher->AddRange(resume_offset);
1070    }
1071  } else {
1072    fetcher->AddRange(0);
1073  }
1074}
1075
1076void UpdateAttempter::PingOmaha() {
1077  if (!processor_->IsRunning()) {
1078    shared_ptr<OmahaRequestAction> ping_action(
1079        new OmahaRequestAction(system_state_,
1080                               NULL,
1081                               new LibcurlHttpFetcher(GetProxyResolver(),
1082                                                      system_state_,
1083                                                      is_test_mode_),
1084                               true));
1085    actions_.push_back(shared_ptr<OmahaRequestAction>(ping_action));
1086    processor_->set_delegate(NULL);
1087    processor_->EnqueueAction(ping_action.get());
1088    // Call StartProcessing() synchronously here to avoid any race conditions
1089    // caused by multiple outstanding ping Omaha requests.  If we call
1090    // StartProcessing() asynchronously, the device can be suspended before we
1091    // get a chance to callback to StartProcessing().  When the device resumes
1092    // (assuming the device sleeps longer than the next update check period),
1093    // StartProcessing() is called back and at the same time, the next update
1094    // check is fired which eventually invokes StartProcessing().  A crash
1095    // can occur because StartProcessing() checks to make sure that the
1096    // processor is idle which it isn't due to the two concurrent ping Omaha
1097    // requests.
1098    processor_->StartProcessing();
1099  } else {
1100    LOG(WARNING) << "Action processor running, Omaha ping suppressed.";
1101  }
1102
1103  // Update the status which will schedule the next update check
1104  SetStatusAndNotify(UPDATE_STATUS_UPDATED_NEED_REBOOT,
1105                     kUpdateNoticeUnspecified);
1106}
1107
1108
1109bool UpdateAttempter::DecrementUpdateCheckCount() {
1110  int64 update_check_count_value;
1111
1112  if (!prefs_->Exists(kPrefsUpdateCheckCount)) {
1113    // This file does not exist. This means we haven't started our update
1114    // check count down yet, so nothing more to do. This file will be created
1115    // later when we first satisfy the wall-clock-based-wait period.
1116    LOG(INFO) << "No existing update check count. That's normal.";
1117    return true;
1118  }
1119
1120  if (prefs_->GetInt64(kPrefsUpdateCheckCount, &update_check_count_value)) {
1121    // Only if we're able to read a proper integer value, then go ahead
1122    // and decrement and write back the result in the same file, if needed.
1123    LOG(INFO) << "Update check count = " << update_check_count_value;
1124
1125    if (update_check_count_value == 0) {
1126      // It could be 0, if, for some reason, the file didn't get deleted
1127      // when we set our status to waiting for reboot. so we just leave it
1128      // as is so that we can prevent another update_check wait for this client.
1129      LOG(INFO) << "Not decrementing update check count as it's already 0.";
1130      return true;
1131    }
1132
1133    if (update_check_count_value > 0)
1134      update_check_count_value--;
1135    else
1136      update_check_count_value = 0;
1137
1138    // Write out the new value of update_check_count_value.
1139    if (prefs_->SetInt64(kPrefsUpdateCheckCount, update_check_count_value)) {
1140      // We successfully wrote out te new value, so enable the
1141      // update check based wait.
1142      LOG(INFO) << "New update check count = " << update_check_count_value;
1143      return true;
1144    }
1145  }
1146
1147  LOG(INFO) << "Deleting update check count state due to read/write errors.";
1148
1149  // We cannot read/write to the file, so disable the update check based wait
1150  // so that we don't get stuck in this OS version by any chance (which could
1151  // happen if there's some bug that causes to read/write incorrectly).
1152  // Also attempt to delete the file to do our best effort to cleanup.
1153  prefs_->Delete(kPrefsUpdateCheckCount);
1154  return false;
1155}
1156}  // namespace chromeos_update_engine
1157