Use a local UpdateFirstSeenAt timestamp instead of UpdatePublishedOn
The existing implementation that used the UpdatePublishedOn doesn't work
well with other AU enterprise policies such as stop AU, target version,
etc. This change will help all those scenarios to work and will make
the co-existence of policies more intuitive for the enterprise admin.
Basically, these scenarios bring out a flaw in the assumption I had
made earlier. i.e. we had assumed that if an update was pushed 5 months
ago, we never have to scatter that because most machines would have
been picked up the update by then. With the other AU policies like
stop AU or version pinning, this assumption is not true and scattering
is still relevant in these cases.
This new UpdateFirstSeenAt timestamp is the first time a Chrome device
hears of an update from Omaha that's eligble to be applied to the device
based on all policies except scattering. It'll use this timestamp instead
of the UpdatePublishedOn from the rule (which is no longer needed) and
everything else remains the same. This UpdateFirstSeenAt value will
also be persisted so that the waiting period can be satisfied over reboots
when an update is not ready to be applied yet.
This timestamp will be cleared (only) after an update has been successfully
applied and the device is waiting to be rebooted.
Also contains a minor fix for avoiding the crash mentioned in 32797.
BUG=chromium-os:32280
TEST=Added new unit tests, tested on ZGB.
Change-Id: I1d7845a11f7eb7fc0a019018c8c4b9a3c68ee2cd
Reviewed-on: https://gerrit.chromium.org/gerrit/28100
Commit-Ready: Jay Srinivasan <jaysri@chromium.org>
Reviewed-by: Jay Srinivasan <jaysri@chromium.org>
Tested-by: Jay Srinivasan <jaysri@chromium.org>
diff --git a/omaha_request_action.cc b/omaha_request_action.cc
index ae8e5e7..24641cb 100644
--- a/omaha_request_action.cc
+++ b/omaha_request_action.cc
@@ -467,6 +467,13 @@
if (params_->update_disabled) {
LOG(INFO) << "Ignoring Omaha updates as updates are disabled by policy.";
completer.set_code(kActionCodeOmahaUpdateIgnoredPerPolicy);
+ // Note: We could technically delete the UpdateFirstSeenAt state here.
+ // If we do, it'll mean a device has to restart the UpdateFirstSeenAt
+ // and thus help scattering take effect when the AU is turned on again.
+ // On the other hand, it also increases the chance of update starvation if
+ // an admin turns AU on/off more frequently. We choose to err on the side
+ // of preventing starvation at the cost of not applying scattering in
+ // those cases.
return;
}
@@ -536,23 +543,53 @@
OmahaRequestAction::WallClockWaitResult
OmahaRequestAction::IsWallClockBasedWaitingSatisfied(
xmlNode* updatecheck_node) {
- Time update_published_time;
+ Time update_first_seen_at;
+ int64 update_first_seen_at_int;
- // UpdatePublishedOn must be in GMT.
- if (!Time::FromString(
- XmlGetProperty(updatecheck_node, "UpdatePublishedOn").c_str(),
- &update_published_time)) {
- LOG(INFO) << "UpdatePublishedOn not present in rule. Treating as 0.";
- return kWallClockWaitDoneAndUpdateCheckWaitNotRequired;
+ if (prefs_->Exists(kPrefsUpdateFirstSeenAt)) {
+ if (prefs_->GetInt64(kPrefsUpdateFirstSeenAt, &update_first_seen_at_int)) {
+ // Note: This timestamp could be that of ANY update we saw in the past
+ // (not necessarily this particular update we're considering to apply)
+ // but never got to apply because of some reason (e.g. stop AU policy,
+ // updates being pulled out from Omaha, changes in target version prefix,
+ // new update being rolled out, etc.). But for the purposes of scattering
+ // it doesn't matter which update the timestamp corresponds to. i.e.
+ // the clock starts ticking the first time we see an update and we're
+ // ready to apply when the random wait period is satisfied relative to
+ // that first seen timestamp.
+ update_first_seen_at = Time::FromInternalValue(update_first_seen_at_int);
+ LOG(INFO) << "Using persisted value of UpdateFirstSeenAt: "
+ << utils::ToString(update_first_seen_at);
+ } else {
+ // This seems like an unexpected error where the persisted value exists
+ // but it's not readable for some reason. Just skip scattering in this
+ // case to be safe.
+ LOG(INFO) << "Not scattering as UpdateFirstSeenAt value cannot be read";
+ return kWallClockWaitDoneAndUpdateCheckWaitNotRequired;
+ }
+ } else {
+ update_first_seen_at = Time::Now();
+ update_first_seen_at_int = update_first_seen_at.ToInternalValue();
+ if (prefs_->SetInt64(kPrefsUpdateFirstSeenAt, update_first_seen_at_int)) {
+ LOG(INFO) << "Persisted the new value for UpdateFirstSeenAt: "
+ << utils::ToString(update_first_seen_at);
+ }
+ else {
+ // This seems like an unexpected error where the value cannot be
+ // persisted for some reason. Just skip scattering in this
+ // case to be safe.
+ LOG(INFO) << "Not scattering as UpdateFirstSeenAt value "
+ << utils::ToString(update_first_seen_at)
+ << " cannot be persisted";
+ return kWallClockWaitDoneAndUpdateCheckWaitNotRequired;
+ }
}
- TimeDelta elapsed_time = Time::Now() - update_published_time;
+ TimeDelta elapsed_time = Time::Now() - update_first_seen_at;
TimeDelta max_scatter_period = TimeDelta::FromDays(
ParseInt(XmlGetProperty(updatecheck_node, "MaxDaysToScatter")));
- LOG(INFO) << "Update Published On = "
- << utils::ToString(update_published_time)
- << ", Waiting Period = "
+ LOG(INFO) << "Waiting Period = "
<< utils::FormatSecs(params_->waiting_period.InSeconds())
<< ", Time Elapsed = "
<< utils::FormatSecs(elapsed_time.InSeconds())
@@ -576,10 +613,9 @@
}
if (elapsed_time > max_scatter_period) {
- // This means it's been a while since the update was published and
- // we are less likely to cause bandwidth spikes by downloading now.
- // This also establishes an upperbound wait in terms of wall-clock time
- // so as to prevent machines from not getting updated for too long.
+ // This means we've waited more than the upperbound wait in the rule
+ // from the time we first saw a valid update available to us.
+ // This will prevent update starvation.
LOG(INFO) << "Not scattering as we're past the MaxDaysToScatter limit.";
return kWallClockWaitDoneAndUpdateCheckWaitNotRequired;
}
diff --git a/omaha_request_action_unittest.cc b/omaha_request_action_unittest.cc
index d8bef5e..a336bdd 100644
--- a/omaha_request_action_unittest.cc
+++ b/omaha_request_action_unittest.cc
@@ -27,6 +27,7 @@
using std::vector;
using testing::_;
using testing::AllOf;
+using testing::DoAll;
using testing::Ge;
using testing::Le;
using testing::NiceMock;
@@ -71,7 +72,6 @@
const string& needsadmin,
const string& size,
const string& deadline,
- Time published_on,
const string& max_days_to_scatter) {
return string(
"<?xml version=\"1.0\" encoding=\"UTF-8\"?><gupdate "
@@ -82,7 +82,6 @@
"ChromeOSVersion=\"" + display_version + "\" "
"MoreInfo=\"" + more_info_url + "\" Prompt=\"" + prompt + "\" "
"IsDelta=\"true\" "
- "UpdatePublishedOn=\"" + utils::ToString(published_on) + "\" "
"MaxDaysToScatter=\"" + max_days_to_scatter + "\" "
"codebase=\"" + codebase + "\" "
"hash=\"not-applicable\" "
@@ -111,7 +110,6 @@
needsadmin,
size,
deadline,
- Time::Now(),
"7");
}
@@ -291,6 +289,7 @@
&response,
NULL));
EXPECT_TRUE(response.update_exists);
+ EXPECT_TRUE(response.update_exists);
EXPECT_EQ("1.2.3.4", response.display_version);
EXPECT_EQ("http://code/base", response.codebase);
EXPECT_EQ("http://more/info", response.more_info_url);
@@ -369,7 +368,6 @@
"false", // needs admin
"123", // size
"", // deadline
- Time::Now(), // published on
"7"), // max days to scatter
-1,
false, // ping_only
@@ -410,7 +408,6 @@
"false", // needs admin
"123", // size
"", // deadline
- Time::Now(), // published on
"7"), // max days to scatter
-1,
false, // ping_only
@@ -451,7 +448,6 @@
"false", // needs admin
"123", // size
"", // deadline
- Time::Now(), // published on
"0"), // max days to scatter
-1,
false, // ping_only
@@ -493,7 +489,6 @@
"false", // needs admin
"123", // size
"", // deadline
- Time::Now(), // published on
"7"), // max days to scatter
-1,
false, // ping_only
@@ -538,7 +533,6 @@
"false", // needs admin
"123", // size
"", // deadline
- Time::Now(), // published on
"7"), // max days to scatter
-1,
false, // ping_only
@@ -585,7 +579,6 @@
"false", // needs admin
"123", // size
"", // deadline
- Time::Now(), // published on
"7"), // max days to scatter
-1,
false, // ping_only
@@ -1323,4 +1316,93 @@
EXPECT_FALSE(response.update_exists);
}
+TEST(OmahaRequestActionTest, TestUpdateFirstSeenAtGetsPersistedFirstTime) {
+ OmahaResponse response;
+ OmahaRequestParams params = kDefaultTestParams;
+ params.wall_clock_based_wait_enabled = true;
+ params.waiting_period = TimeDelta().FromDays(1);
+ params.update_check_count_wait_enabled = false;
+
+ string prefs_dir;
+ EXPECT_TRUE(utils::MakeTempDirectory("/tmp/ue_ut_prefs.XXXXXX",
+ &prefs_dir));
+ ScopedDirRemover temp_dir_remover(prefs_dir);
+
+ Prefs prefs;
+ LOG_IF(ERROR, !prefs.Init(FilePath(prefs_dir)))
+ << "Failed to initialize preferences.";
+
+ ASSERT_FALSE(TestUpdateCheck(
+ &prefs, // prefs
+ params,
+ GetUpdateResponse2(OmahaRequestParams::kAppId,
+ "1.2.3.4", // version
+ "http://more/info",
+ "true", // prompt
+ "http://code/base", // dl url
+ "HASH1234=", // checksum
+ "false", // needs admin
+ "123", // size
+ "", // deadline
+ "7"), // max days to scatter
+ -1,
+ false, // ping_only
+ kActionCodeOmahaUpdateDeferredPerPolicy,
+ &response,
+ NULL));
+
+ int64 timestamp = 0;
+ ASSERT_TRUE(prefs.GetInt64(kPrefsUpdateFirstSeenAt, ×tamp));
+ ASSERT_TRUE(timestamp > 0);
+ EXPECT_FALSE(response.update_exists);
+}
+
+TEST(OmahaRequestActionTest, TestUpdateFirstSeenAtGetsUsedIfAlreadyPresent) {
+ OmahaResponse response;
+ OmahaRequestParams params = kDefaultTestParams;
+ params.wall_clock_based_wait_enabled = true;
+ params.waiting_period = TimeDelta().FromDays(1);
+ params.update_check_count_wait_enabled = false;
+
+ string prefs_dir;
+ EXPECT_TRUE(utils::MakeTempDirectory("/tmp/ue_ut_prefs.XXXXXX",
+ &prefs_dir));
+ ScopedDirRemover temp_dir_remover(prefs_dir);
+
+ Prefs prefs;
+ LOG_IF(ERROR, !prefs.Init(FilePath(prefs_dir)))
+ << "Failed to initialize preferences.";
+
+ // Set the timestamp to a very old value such that it exceeds the
+ // waiting period set above.
+ Time t1;
+ Time::FromString("1/1/2012", &t1);
+ ASSERT_TRUE(prefs.SetInt64(kPrefsUpdateFirstSeenAt, t1.ToInternalValue()));
+ ASSERT_TRUE(TestUpdateCheck(
+ &prefs, // prefs
+ params,
+ GetUpdateResponse2(OmahaRequestParams::kAppId,
+ "1.2.3.4", // version
+ "http://more/info",
+ "true", // prompt
+ "http://code/base", // dl url
+ "HASH1234=", // checksum
+ "false", // needs admin
+ "123", // size
+ "", // deadline
+ "7"), // max days to scatter
+ -1,
+ false, // ping_only
+ kActionCodeSuccess,
+ &response,
+ NULL));
+
+ EXPECT_TRUE(response.update_exists);
+
+ // Make sure the timestamp t1 is unchanged showing that it was reused.
+ int64 timestamp = 0;
+ ASSERT_TRUE(prefs.GetInt64(kPrefsUpdateFirstSeenAt, ×tamp));
+ ASSERT_TRUE(timestamp == t1.ToInternalValue());
+}
+
} // namespace chromeos_update_engine
diff --git a/prefs.cc b/prefs.cc
index 1388817..abce538 100644
--- a/prefs.cc
+++ b/prefs.cc
@@ -35,6 +35,7 @@
"update-state-signed-sha-256-context";
const char kPrefsUpdateCheckCount[] = "update-check-count";
const char kPrefsWallClockWaitPeriod[] = "wall-clock-wait-period";
+const char kPrefsUpdateFirstSeenAt[] = "update-first-seen-at";
bool Prefs::Init(const FilePath& prefs_dir) {
prefs_dir_ = prefs_dir;
diff --git a/prefs_interface.h b/prefs_interface.h
index 3cb4059..d0ff0d0 100644
--- a/prefs_interface.h
+++ b/prefs_interface.h
@@ -26,6 +26,7 @@
extern const char kPrefsUpdateStateSignedSHA256Context[];
extern const char kPrefsUpdateCheckCount[];
extern const char kPrefsWallClockWaitPeriod[];
+extern const char kPrefsUpdateFirstSeenAt[];
// The prefs interface allows access to a persistent preferences
// store. The two reasons for providing this as an interface are
diff --git a/system_state.cc b/system_state.cc
index d2bd6f1..57483ea 100644
--- a/system_state.cc
+++ b/system_state.cc
@@ -10,7 +10,9 @@
static const char kOOBECompletedMarker[] = "/home/chronos/.oobe_completed";
-RealSystemState::RealSystemState() : connection_manager_(this) {}
+RealSystemState::RealSystemState()
+ : device_policy_(NULL),
+ connection_manager_(this) {}
bool RealSystemState::IsOOBEComplete() {
return file_util::PathExists(FilePath(kOOBECompletedMarker));
diff --git a/update_attempter.cc b/update_attempter.cc
index 8dd4622..0b7e836 100644
--- a/update_attempter.cc
+++ b/update_attempter.cc
@@ -238,6 +238,7 @@
<< (allowed_types_str.empty() ? "all" : allowed_types_str);
} else {
LOG(INFO) << "No device policies present.";
+ system_state_->SetDevicePolicy(NULL);
}
bool is_scatter_enabled = false;
@@ -541,6 +542,7 @@
// way.
prefs_->Delete(kPrefsUpdateCheckCount);
prefs_->Delete(kPrefsWallClockWaitPeriod);
+ prefs_->Delete(kPrefsUpdateFirstSeenAt);
SetStatusAndNotify(UPDATE_STATUS_UPDATED_NEED_REBOOT,
kUpdateNoticeUnspecified);