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