update_attempter.cc revision 819fef2e0fa08984cf31e848e704442c500ea4f9 
1// Copyright (c) 2010 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/rand_util.h>
18#include <glib.h>
19#include <metrics/metrics_library.h>
20
21#include "update_engine/dbus_service.h"
22#include "update_engine/download_action.h"
23#include "update_engine/filesystem_copier_action.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/postinstall_runner_action.h"
30#include "update_engine/prefs_interface.h"
31#include "update_engine/update_check_scheduler.h"
32
33using base::TimeDelta;
34using base::TimeTicks;
35using std::make_pair;
36using std::tr1::shared_ptr;
37using std::string;
38using std::vector;
39
40namespace chromeos_update_engine {
41
42const int UpdateAttempter::kMaxDeltaUpdateFailures = 3;
43
44const char* kUpdateCompletedMarker =
45    "/var/run/update_engine_autoupdate_completed";
46
47namespace {
48const int kMaxConsecutiveObeyProxyRequests = 20;
49}  // namespace {}
50
51const char* UpdateStatusToString(UpdateStatus status) {
52  switch (status) {
53    case UPDATE_STATUS_IDLE:
54      return "UPDATE_STATUS_IDLE";
55    case UPDATE_STATUS_CHECKING_FOR_UPDATE:
56      return "UPDATE_STATUS_CHECKING_FOR_UPDATE";
57    case UPDATE_STATUS_UPDATE_AVAILABLE:
58      return "UPDATE_STATUS_UPDATE_AVAILABLE";
59    case UPDATE_STATUS_DOWNLOADING:
60      return "UPDATE_STATUS_DOWNLOADING";
61    case UPDATE_STATUS_VERIFYING:
62      return "UPDATE_STATUS_VERIFYING";
63    case UPDATE_STATUS_FINALIZING:
64      return "UPDATE_STATUS_FINALIZING";
65    case UPDATE_STATUS_UPDATED_NEED_REBOOT:
66      return "UPDATE_STATUS_UPDATED_NEED_REBOOT";
67    case UPDATE_STATUS_REPORTING_ERROR_EVENT:
68      return "UPDATE_STATUS_REPORTING_ERROR_EVENT";
69    default:
70      return "unknown status";
71  }
72}
73
74// Turns a generic kActionCodeError to a generic error code specific
75// to |action| (e.g., kActionCodeFilesystemCopierError). If |code| is
76// not kActionCodeError, or the action is not matched, returns |code|
77// unchanged.
78ActionExitCode GetErrorCodeForAction(AbstractAction* action,
79                                     ActionExitCode code) {
80  if (code != kActionCodeError)
81    return code;
82
83  const string type = action->Type();
84  if (type == OmahaRequestAction::StaticType())
85    return kActionCodeOmahaRequestError;
86  if (type == OmahaResponseHandlerAction::StaticType())
87    return kActionCodeOmahaResponseHandlerError;
88  if (type == FilesystemCopierAction::StaticType())
89    return kActionCodeFilesystemCopierError;
90  if (type == PostinstallRunnerAction::StaticType())
91    return kActionCodePostinstallRunnerError;
92
93  return code;
94}
95
96UpdateAttempter::UpdateAttempter(PrefsInterface* prefs,
97                                 MetricsLibraryInterface* metrics_lib,
98                                 DbusGlibInterface* dbus_iface)
99    : processor_(new ActionProcessor()),
100      dbus_service_(NULL),
101      prefs_(prefs),
102      metrics_lib_(metrics_lib),
103      update_check_scheduler_(NULL),
104      http_response_code_(0),
105      priority_(utils::kProcessPriorityNormal),
106      manage_priority_source_(NULL),
107      download_active_(false),
108      status_(UPDATE_STATUS_IDLE),
109      download_progress_(0.0),
110      last_checked_time_(0),
111      new_version_("0.0.0.0"),
112      new_size_(0),
113      is_full_update_(false),
114      proxy_manual_checks_(0),
115      obeying_proxies_(true),
116      chrome_proxy_resolver_(dbus_iface) {
117  if (utils::FileExists(kUpdateCompletedMarker))
118    status_ = UPDATE_STATUS_UPDATED_NEED_REBOOT;
119}
120
121UpdateAttempter::~UpdateAttempter() {
122  CleanupPriorityManagement();
123}
124
125void UpdateAttempter::Update(const std::string& app_version,
126                             const std::string& omaha_url,
127                             bool obey_proxies) {
128  if (status_ == UPDATE_STATUS_UPDATED_NEED_REBOOT) {
129    LOG(INFO) << "Not updating b/c we already updated and we're waiting for "
130              << "reboot";
131    return;
132  }
133  if (status_ != UPDATE_STATUS_IDLE) {
134    // Update in progress. Do nothing
135    return;
136  }
137  http_response_code_ = 0;
138  if (!omaha_request_params_.Init(app_version, omaha_url)) {
139    LOG(ERROR) << "Unable to initialize Omaha request device params.";
140    return;
141  }
142
143  obeying_proxies_ = true;
144  if (obey_proxies || proxy_manual_checks_ == 0) {
145    LOG(INFO) << "forced to obey proxies";
146    // If forced to obey proxies, every 20th request will not use proxies
147    proxy_manual_checks_++;
148    LOG(INFO) << "proxy manual checks: " << proxy_manual_checks_;
149    if (proxy_manual_checks_ >= kMaxConsecutiveObeyProxyRequests) {
150      proxy_manual_checks_ = 0;
151      obeying_proxies_ = false;
152    }
153  } else if (base::RandInt(0, 4) == 0) {
154    obeying_proxies_ = false;
155  }
156  LOG_IF(INFO, !obeying_proxies_) << "To help ensure updates work, this update "
157      "check we are ignoring the proxy settings and using "
158      "direct connections.";
159
160  DisableDeltaUpdateIfNeeded();
161  CHECK(!processor_->IsRunning());
162  processor_->set_delegate(this);
163
164  // Actions:
165  LibcurlHttpFetcher* update_check_fetcher =
166      new LibcurlHttpFetcher(GetProxyResolver());
167  // Try harder to connect to the network. See comment in
168  // libcurl_http_fetcher.cc.
169  update_check_fetcher->set_no_network_max_retries(3);
170  shared_ptr<OmahaRequestAction> update_check_action(
171      new OmahaRequestAction(prefs_,
172                             omaha_request_params_,
173                             NULL,
174                             update_check_fetcher));  // passes ownership
175  shared_ptr<OmahaResponseHandlerAction> response_handler_action(
176      new OmahaResponseHandlerAction(prefs_));
177  shared_ptr<FilesystemCopierAction> filesystem_copier_action(
178      new FilesystemCopierAction(false, false));
179  shared_ptr<FilesystemCopierAction> kernel_filesystem_copier_action(
180      new FilesystemCopierAction(true, false));
181  shared_ptr<OmahaRequestAction> download_started_action(
182      new OmahaRequestAction(prefs_,
183                             omaha_request_params_,
184                             new OmahaEvent(
185                                 OmahaEvent::kTypeUpdateDownloadStarted),
186                             new LibcurlHttpFetcher(GetProxyResolver())));
187  shared_ptr<DownloadAction> download_action(
188      new DownloadAction(prefs_, new MultiRangeHTTPFetcher(
189          new LibcurlHttpFetcher(GetProxyResolver()))));
190  shared_ptr<OmahaRequestAction> download_finished_action(
191      new OmahaRequestAction(prefs_,
192                             omaha_request_params_,
193                             new OmahaEvent(
194                                 OmahaEvent::kTypeUpdateDownloadFinished),
195                             new LibcurlHttpFetcher(GetProxyResolver())));
196  shared_ptr<FilesystemCopierAction> filesystem_verifier_action(
197      new FilesystemCopierAction(false, true));
198  shared_ptr<FilesystemCopierAction> kernel_filesystem_verifier_action(
199      new FilesystemCopierAction(true, true));
200  shared_ptr<PostinstallRunnerAction> postinstall_runner_action(
201      new PostinstallRunnerAction);
202  shared_ptr<OmahaRequestAction> update_complete_action(
203      new OmahaRequestAction(prefs_,
204                             omaha_request_params_,
205                             new OmahaEvent(OmahaEvent::kTypeUpdateComplete),
206                             new LibcurlHttpFetcher(GetProxyResolver())));
207
208  download_action->set_delegate(this);
209  response_handler_action_ = response_handler_action;
210  download_action_ = download_action;
211
212  actions_.push_back(shared_ptr<AbstractAction>(update_check_action));
213  actions_.push_back(shared_ptr<AbstractAction>(response_handler_action));
214  actions_.push_back(shared_ptr<AbstractAction>(filesystem_copier_action));
215  actions_.push_back(shared_ptr<AbstractAction>(
216      kernel_filesystem_copier_action));
217  actions_.push_back(shared_ptr<AbstractAction>(download_started_action));
218  actions_.push_back(shared_ptr<AbstractAction>(download_action));
219  actions_.push_back(shared_ptr<AbstractAction>(download_finished_action));
220  actions_.push_back(shared_ptr<AbstractAction>(filesystem_verifier_action));
221  actions_.push_back(shared_ptr<AbstractAction>(
222      kernel_filesystem_verifier_action));
223  actions_.push_back(shared_ptr<AbstractAction>(postinstall_runner_action));
224  actions_.push_back(shared_ptr<AbstractAction>(update_complete_action));
225
226  // Enqueue the actions
227  for (vector<shared_ptr<AbstractAction> >::iterator it = actions_.begin();
228       it != actions_.end(); ++it) {
229    processor_->EnqueueAction(it->get());
230  }
231
232  // Bond them together. We have to use the leaf-types when calling
233  // BondActions().
234  BondActions(update_check_action.get(),
235              response_handler_action.get());
236  BondActions(response_handler_action.get(),
237              filesystem_copier_action.get());
238  BondActions(filesystem_copier_action.get(),
239              kernel_filesystem_copier_action.get());
240  BondActions(kernel_filesystem_copier_action.get(),
241              download_action.get());
242  BondActions(download_action.get(),
243              filesystem_verifier_action.get());
244  BondActions(filesystem_verifier_action.get(),
245              kernel_filesystem_verifier_action.get());
246  BondActions(kernel_filesystem_verifier_action.get(),
247              postinstall_runner_action.get());
248
249  SetStatusAndNotify(UPDATE_STATUS_CHECKING_FOR_UPDATE);
250  processor_->StartProcessing();
251}
252
253void UpdateAttempter::CheckForUpdate(const std::string& app_version,
254                                     const std::string& omaha_url) {
255  if (status_ != UPDATE_STATUS_IDLE) {
256    LOG(INFO) << "Check for update requested, but status is "
257              << UpdateStatusToString(status_) << ", so not checking.";
258    return;
259  }
260  Update(app_version, omaha_url, true);
261}
262
263bool UpdateAttempter::RebootIfNeeded() {
264  if (status_ != UPDATE_STATUS_UPDATED_NEED_REBOOT) {
265    LOG(INFO) << "Reboot requested, but status is "
266              << UpdateStatusToString(status_) << ", so not rebooting.";
267    return false;
268  }
269  TEST_AND_RETURN_FALSE(utils::Reboot());
270  return true;
271}
272
273// Delegate methods:
274void UpdateAttempter::ProcessingDone(const ActionProcessor* processor,
275                                     ActionExitCode code) {
276  CHECK(response_handler_action_);
277  LOG(INFO) << "Processing Done.";
278  actions_.clear();
279
280  // Reset process priority back to normal.
281  CleanupPriorityManagement();
282
283  if (status_ == UPDATE_STATUS_REPORTING_ERROR_EVENT) {
284    LOG(INFO) << "Error event sent.";
285    SetStatusAndNotify(UPDATE_STATUS_IDLE);
286    return;
287  }
288
289  if (code == kActionCodeSuccess) {
290    utils::WriteFile(kUpdateCompletedMarker, "", 0);
291    prefs_->SetInt64(kPrefsDeltaUpdateFailures, 0);
292    DeltaPerformer::ResetUpdateProgress(prefs_, false);
293    SetStatusAndNotify(UPDATE_STATUS_UPDATED_NEED_REBOOT);
294
295    // Report the time it took to update the system.
296    int64_t update_time = time(NULL) - last_checked_time_;
297    metrics_lib_->SendToUMA("Installer.UpdateTime",
298                            static_cast<int>(update_time),  // sample
299                            1,  // min = 1 second
300                            20 * 60,  // max = 20 minutes
301                            50);  // buckets
302    return;
303  }
304
305  if (ScheduleErrorEventAction()) {
306    return;
307  }
308  LOG(INFO) << "No update.";
309  SetStatusAndNotify(UPDATE_STATUS_IDLE);
310}
311
312void UpdateAttempter::ProcessingStopped(const ActionProcessor* processor) {
313  // Reset process priority back to normal.
314  CleanupPriorityManagement();
315  download_progress_ = 0.0;
316  SetStatusAndNotify(UPDATE_STATUS_IDLE);
317  actions_.clear();
318  error_event_.reset(NULL);
319}
320
321// Called whenever an action has finished processing, either successfully
322// or otherwise.
323void UpdateAttempter::ActionCompleted(ActionProcessor* processor,
324                                      AbstractAction* action,
325                                      ActionExitCode code) {
326  // Reset download progress regardless of whether or not the download
327  // action succeeded. Also, get the response code from HTTP request
328  // actions (update download as well as the initial update check
329  // actions).
330  const string type = action->Type();
331  if (type == DownloadAction::StaticType()) {
332    download_progress_ = 0.0;
333    DownloadAction* download_action = dynamic_cast<DownloadAction*>(action);
334    http_response_code_ = download_action->GetHTTPResponseCode();
335  } else if (type == OmahaRequestAction::StaticType()) {
336    OmahaRequestAction* omaha_request_action =
337        dynamic_cast<OmahaRequestAction*>(action);
338    // If the request is not an event, then it's the update-check.
339    if (!omaha_request_action->IsEvent()) {
340      http_response_code_ = omaha_request_action->GetHTTPResponseCode();
341      // Forward the server-dictated poll interval to the update check
342      // scheduler, if any.
343      if (update_check_scheduler_) {
344        update_check_scheduler_->set_poll_interval(
345            omaha_request_action->GetOutputObject().poll_interval);
346      }
347    }
348  }
349  if (code != kActionCodeSuccess) {
350    // If this was a delta update attempt and the current state is at or past
351    // the download phase, count the failure in case a switch to full update
352    // becomes necessary. Ignore network transfer timeouts and failures.
353    if (status_ >= UPDATE_STATUS_DOWNLOADING &&
354        !is_full_update_ &&
355        code != kActionCodeDownloadTransferError) {
356      MarkDeltaUpdateFailure();
357    }
358    // On failure, schedule an error event to be sent to Omaha.
359    CreatePendingErrorEvent(action, code);
360    return;
361  }
362  // Find out which action completed.
363  if (type == OmahaResponseHandlerAction::StaticType()) {
364    // Note that the status will be updated to DOWNLOADING when some bytes get
365    // actually downloaded from the server and the BytesReceived callback is
366    // invoked. This avoids notifying the user that a download has started in
367    // cases when the server and the client are unable to initiate the download.
368    CHECK(action == response_handler_action_.get());
369    const InstallPlan& plan = response_handler_action_->install_plan();
370    last_checked_time_ = time(NULL);
371    // TODO(adlr): put version in InstallPlan
372    new_version_ = "0.0.0.0";
373    new_size_ = plan.size;
374    is_full_update_ = plan.is_full_update;
375    SetupDownload();
376    SetupPriorityManagement();
377    SetStatusAndNotify(UPDATE_STATUS_UPDATE_AVAILABLE);
378  } else if (type == DownloadAction::StaticType()) {
379    SetStatusAndNotify(UPDATE_STATUS_FINALIZING);
380  }
381}
382
383// Stop updating. An attempt will be made to record status to the disk
384// so that updates can be resumed later.
385void UpdateAttempter::Terminate() {
386  // TODO(adlr): implement this method.
387  NOTIMPLEMENTED();
388}
389
390// Try to resume from a previously Terminate()d update.
391void UpdateAttempter::ResumeUpdating() {
392  // TODO(adlr): implement this method.
393  NOTIMPLEMENTED();
394}
395
396void UpdateAttempter::SetDownloadStatus(bool active) {
397  download_active_ = active;
398  LOG(INFO) << "Download status: " << (active ? "active" : "inactive");
399}
400
401void UpdateAttempter::BytesReceived(uint64_t bytes_received, uint64_t total) {
402  if (!download_active_) {
403    LOG(ERROR) << "BytesReceived called while not downloading.";
404    return;
405  }
406  double progress = static_cast<double>(bytes_received) /
407      static_cast<double>(total);
408  // Self throttle based on progress. Also send notifications if
409  // progress is too slow.
410  const double kDeltaPercent = 0.01;  // 1%
411  if (status_ != UPDATE_STATUS_DOWNLOADING ||
412      bytes_received == total ||
413      progress - download_progress_ >= kDeltaPercent ||
414      TimeTicks::Now() - last_notify_time_ >= TimeDelta::FromSeconds(10)) {
415    download_progress_ = progress;
416    SetStatusAndNotify(UPDATE_STATUS_DOWNLOADING);
417  }
418}
419
420bool UpdateAttempter::GetStatus(int64_t* last_checked_time,
421                                double* progress,
422                                std::string* current_operation,
423                                std::string* new_version,
424                                int64_t* new_size) {
425  *last_checked_time = last_checked_time_;
426  *progress = download_progress_;
427  *current_operation = UpdateStatusToString(status_);
428  *new_version = new_version_;
429  *new_size = new_size_;
430  return true;
431}
432
433void UpdateAttempter::SetStatusAndNotify(UpdateStatus status) {
434  status_ = status;
435  if (update_check_scheduler_) {
436    update_check_scheduler_->SetUpdateStatus(status_);
437  }
438  if (!dbus_service_)
439    return;
440  last_notify_time_ = TimeTicks::Now();
441  update_engine_service_emit_status_update(
442      dbus_service_,
443      last_checked_time_,
444      download_progress_,
445      UpdateStatusToString(status_),
446      new_version_.c_str(),
447      new_size_);
448}
449
450void UpdateAttempter::CreatePendingErrorEvent(AbstractAction* action,
451                                              ActionExitCode code) {
452  if (error_event_.get()) {
453    // This shouldn't really happen.
454    LOG(WARNING) << "There's already an existing pending error event.";
455    return;
456  }
457
458  // For now assume that Omaha response action failure means that
459  // there's no update so don't send an event. Also, double check that
460  // the failure has not occurred while sending an error event -- in
461  // which case don't schedule another. This shouldn't really happen
462  // but just in case...
463  if (action->Type() == OmahaResponseHandlerAction::StaticType() ||
464      status_ == UPDATE_STATUS_REPORTING_ERROR_EVENT) {
465    return;
466  }
467
468  code = GetErrorCodeForAction(action, code);
469  error_event_.reset(new OmahaEvent(OmahaEvent::kTypeUpdateComplete,
470                                    OmahaEvent::kResultError,
471                                    code));
472}
473
474bool UpdateAttempter::ScheduleErrorEventAction() {
475  if (error_event_.get() == NULL)
476    return false;
477
478  LOG(INFO) << "Update failed -- reporting the error event.";
479  shared_ptr<OmahaRequestAction> error_event_action(
480      new OmahaRequestAction(prefs_,
481                             omaha_request_params_,
482                             error_event_.release(),  // Pass ownership.
483                             new LibcurlHttpFetcher(GetProxyResolver())));
484  actions_.push_back(shared_ptr<AbstractAction>(error_event_action));
485  processor_->EnqueueAction(error_event_action.get());
486  SetStatusAndNotify(UPDATE_STATUS_REPORTING_ERROR_EVENT);
487  processor_->StartProcessing();
488  return true;
489}
490
491void UpdateAttempter::SetPriority(utils::ProcessPriority priority) {
492  if (priority_ == priority) {
493    return;
494  }
495  if (utils::SetProcessPriority(priority)) {
496    priority_ = priority;
497    LOG(INFO) << "Process priority = " << priority_;
498  }
499}
500
501void UpdateAttempter::SetupPriorityManagement() {
502  if (manage_priority_source_) {
503    LOG(ERROR) << "Process priority timeout source hasn't been destroyed.";
504    CleanupPriorityManagement();
505  }
506  const int kPriorityTimeout = 2 * 60 * 60;  // 2 hours
507  manage_priority_source_ = g_timeout_source_new_seconds(kPriorityTimeout);
508  g_source_set_callback(manage_priority_source_,
509                        StaticManagePriorityCallback,
510                        this,
511                        NULL);
512  g_source_attach(manage_priority_source_, NULL);
513  SetPriority(utils::kProcessPriorityLow);
514}
515
516void UpdateAttempter::CleanupPriorityManagement() {
517  if (manage_priority_source_) {
518    g_source_destroy(manage_priority_source_);
519    manage_priority_source_ = NULL;
520  }
521  SetPriority(utils::kProcessPriorityNormal);
522}
523
524gboolean UpdateAttempter::StaticManagePriorityCallback(gpointer data) {
525  return reinterpret_cast<UpdateAttempter*>(data)->ManagePriorityCallback();
526}
527
528bool UpdateAttempter::ManagePriorityCallback() {
529  SetPriority(utils::kProcessPriorityNormal);
530  manage_priority_source_ = NULL;
531  return false;  // Destroy the timeout source.
532}
533
534void UpdateAttempter::DisableDeltaUpdateIfNeeded() {
535  int64_t delta_failures;
536  if (omaha_request_params_.delta_okay &&
537      prefs_->GetInt64(kPrefsDeltaUpdateFailures, &delta_failures) &&
538      delta_failures >= kMaxDeltaUpdateFailures) {
539    LOG(WARNING) << "Too many delta update failures, forcing full update.";
540    omaha_request_params_.delta_okay = false;
541  }
542}
543
544void UpdateAttempter::MarkDeltaUpdateFailure() {
545  CHECK(!is_full_update_);
546  // Don't try to resume a failed delta update.
547  DeltaPerformer::ResetUpdateProgress(prefs_, false);
548  int64_t delta_failures;
549  if (!prefs_->GetInt64(kPrefsDeltaUpdateFailures, &delta_failures) ||
550      delta_failures < 0) {
551    delta_failures = 0;
552  }
553  prefs_->SetInt64(kPrefsDeltaUpdateFailures, ++delta_failures);
554}
555
556void UpdateAttempter::SetupDownload() {
557  MultiRangeHTTPFetcher* fetcher =
558      dynamic_cast<MultiRangeHTTPFetcher*>(download_action_->http_fetcher());
559  fetcher->ClearRanges();
560  if (response_handler_action_->install_plan().is_resume) {
561    // Resuming an update so fetch the update manifest metadata first.
562    int64_t manifest_metadata_size = 0;
563    prefs_->GetInt64(kPrefsManifestMetadataSize, &manifest_metadata_size);
564    fetcher->AddRange(0, manifest_metadata_size);
565    // If there're remaining unprocessed data blobs, fetch them. Be careful not
566    // to request data beyond the end of the payload to avoid 416 HTTP response
567    // error codes.
568    int64_t next_data_offset = 0;
569    prefs_->GetInt64(kPrefsUpdateStateNextDataOffset, &next_data_offset);
570    uint64_t resume_offset = manifest_metadata_size + next_data_offset;
571    if (resume_offset < response_handler_action_->install_plan().size) {
572      fetcher->AddRange(resume_offset, -1);
573    }
574  } else {
575    fetcher->AddRange(0, -1);
576  }
577}
578
579}  // namespace chromeos_update_engine
580