shill: Service: Track DHCP failures and inform ShouldUseMinimalDHCPConfig()
The default DHCP configuration used by ChromeOS requests a
large number of options in order to support features like
Web Proxy Auto-Discovery. Unfortunately this practice
sometimes runs afoul of issues in some network topologies.
In some networks, a large number of option values in the
DHCP response can cause MTU problems with proxies or other
network elements. This may prevent the reply from being
forwarded back to the client.
Although the problem may not lie with the outgoing request,
it may be possible to mitigate this issue by modifying these
requests. This CL provides a means for the Service to track
such failures and infer from a series of experiments whether
it is likely to be due to an MTU issue. To do this, the
Device informs the selected Service of each DHCP success and
failure, and queries the Service before starting each DHCP
session to inquire whether it should request an extensive or
minimal DHCP options from the server.
In order to detect and respond to such issues, this CL
maintains state in the Service about how DHCP has been
performing. If there have been a spate of recent DHCP
failures, we should suspect that this may be due to the
number of options we are requesting from the DHCP server.
We should confirm that this is in fact the issue by testing
whether a request for a smaller response succeeds. If this
request succeeds we can consider the hunch confirmed and the
client should switch to using small requests for some period
of time. If our test request fails, we can assume for now
that the problem isn't realated to a DHCP response size and
return to the default behavior.
If we have confirmed our hunch earlier and the time period
expires, we should try again to use a more comprehensive
DHCP request. If this succeeds, we can assume either the
network infrastructure has repaired itself or that the
previous hunch was in error, and return to the "not
detected" state. If it fails, we should confirm whether
this is the identical problem to before by re-testing a
small DHCP request size. Since the "confirmed" state did
not pay attention to DHCP failures, it's possible that they
have been failing across the board as of late. If indeed
both large and small DHCP responses fail to reach us, we
should put off our re-test until we start receiving DHCP
replies again.
The state machine implemented for DHCP failures is
illustrated in state machine diagram below (all events not
shown do not cause a state change):
[ Not Detected (send full request) ] <------------
| ^ |
| | |
n * failure failure |
| | |
V | |
[ Suspected (send minimal request) ] |
| |
success |
| |
V |
[ Confirmed (send minimal request) ] |
^ | |
| hold timer elapsed |
| | |
success V |
| [ Retest Full Request ] ----success--/
| | ^
| failure |
| | |
| V |
[ Retest Minimal Request ] |
| success
failure |
| |
V |
[ Retest With No Reply (send minimal requests) ]
The Service only persists two states: "Not Detected" and
"Confirmed". This is done via the presence or absence of
the stored "LastDHCPOptionFailure" property, which is the
time the system last entered the "Confirmed" state. A
third state, "Reset Full Request" is implicitly persisted
if this timestamp is old enough that the hold timer has
expired.
BUG=chromium:297607
TEST=Unit tests
Change-Id: I1ee83debf4d11f25678fe3586574ec04f254a83f
Reviewed-on: https://chromium-review.googlesource.com/174634
Reviewed-by: Paul Stewart <pstew@chromium.org>
Commit-Queue: Paul Stewart <pstew@chromium.org>
Tested-by: Paul Stewart <pstew@chromium.org>
diff --git a/device.cc b/device.cc
index d6145dd..ff3ccc7 100644
--- a/device.cc
+++ b/device.cc
@@ -382,7 +382,7 @@
}
bool Device::ShouldUseMinimalDHCPConfig() const {
- return false;
+ return selected_service_ && selected_service_->ShouldUseMinimalDHCPConfig();
}
bool Device::AcquireIPConfig() {
@@ -478,6 +478,7 @@
// SetConnection must occur after the UpdateFromIPConfig so the
// service can use the values derived from the connection.
if (selected_service_) {
+ selected_service_->OnDHCPSuccess();
selected_service_->SetConnection(connection_);
}
// The service state change needs to happen last, so that at the
@@ -498,32 +499,35 @@
} else {
// TODO(pstew): This logic gets yet more complex when multiple
// IPConfig types are run in parallel (e.g. DHCP and DHCP6)
- if (selected_service_ &&
- selected_service_->static_ip_parameters().ContainsAddress()) {
- // Consider three cases:
- //
- // 1. We're here because DHCP failed while starting up. There
- // are two subcases:
- // a. DHCP has failed, and Static IP config has _not yet_
- // completed. It's fine to do nothing, because we'll
- // apply the static config shortly.
- // b. DHCP has failed, and Static IP config has _already_
- // completed. It's fine to do nothing, because we can
- // continue to use the static config that's already
- // been applied.
- //
- // 2. We're here because a previously valid DHCP configuration
- // is no longer valid. There's still a static IP config,
- // because the condition in the if clause evaluated to true.
- // Furthermore, the static config includes an IP address for
- // us to use.
- //
- // The current configuration may include some DHCP
- // parameters, overriden by any static parameters
- // provided. We continue to use this configuration, because
- // the only configuration element that is leased to us (IP
- // address) will be overriden by a static parameter.
- return;
+ if (selected_service_) {
+ selected_service_->OnDHCPFailure();
+
+ if (selected_service_->static_ip_parameters().ContainsAddress()) {
+ // Consider three cases:
+ //
+ // 1. We're here because DHCP failed while starting up. There
+ // are two subcases:
+ // a. DHCP has failed, and Static IP config has _not yet_
+ // completed. It's fine to do nothing, because we'll
+ // apply the static config shortly.
+ // b. DHCP has failed, and Static IP config has _already_
+ // completed. It's fine to do nothing, because we can
+ // continue to use the static config that's already
+ // been applied.
+ //
+ // 2. We're here because a previously valid DHCP configuration
+ // is no longer valid. There's still a static IP config,
+ // because the condition in the if clause evaluated to true.
+ // Furthermore, the static config includes an IP address for
+ // us to use.
+ //
+ // The current configuration may include some DHCP
+ // parameters, overriden by any static parameters
+ // provided. We continue to use this configuration, because
+ // the only configuration element that is leased to us (IP
+ // address) will be overriden by a static parameter.
+ return;
+ }
}
OnIPConfigFailure();
diff --git a/device_unittest.cc b/device_unittest.cc
index ebb4b75..f7f68e4 100644
--- a/device_unittest.cc
+++ b/device_unittest.cc
@@ -311,23 +311,23 @@
SelectService(service);
EXPECT_TRUE(device_->selected_service_.get() == service.get());
- EXPECT_CALL(*service.get(), SetState(Service::kStateConfiguring));
+ EXPECT_CALL(*service, SetState(Service::kStateConfiguring));
device_->SetServiceState(Service::kStateConfiguring);
- EXPECT_CALL(*service.get(), SetFailure(Service::kFailureOutOfRange));
+ EXPECT_CALL(*service, SetFailure(Service::kFailureOutOfRange));
device_->SetServiceFailure(Service::kFailureOutOfRange);
// Service should be returned to "Idle" state
- EXPECT_CALL(*service.get(), state())
+ EXPECT_CALL(*service, state())
.WillOnce(Return(Service::kStateUnknown));
- EXPECT_CALL(*service.get(), SetState(Service::kStateIdle));
- EXPECT_CALL(*service.get(), SetConnection(IsNullRefPtr()));
+ EXPECT_CALL(*service, SetState(Service::kStateIdle));
+ EXPECT_CALL(*service, SetConnection(IsNullRefPtr()));
SelectService(NULL);
// A service in the "Failure" state should not be reset to "Idle"
SelectService(service);
- EXPECT_CALL(*service.get(), state())
+ EXPECT_CALL(*service, state())
.WillOnce(Return(Service::kStateFailure));
- EXPECT_CALL(*service.get(), SetConnection(IsNullRefPtr()));
+ EXPECT_CALL(*service, SetConnection(IsNullRefPtr()));
SelectService(NULL);
}
@@ -338,8 +338,9 @@
metrics(),
manager()));
SelectService(service);
- EXPECT_CALL(*service.get(), DisconnectWithFailure(Service::kFailureDHCP, _));
- EXPECT_CALL(*service.get(), SetConnection(IsNullRefPtr()));
+ EXPECT_CALL(*service, OnDHCPFailure());
+ EXPECT_CALL(*service, DisconnectWithFailure(Service::kFailureDHCP, _));
+ EXPECT_CALL(*service, SetConnection(IsNullRefPtr()));
OnIPConfigUpdated(NULL, false);
}
@@ -352,8 +353,11 @@
SelectService(service);
service->static_ip_parameters_.args_.SetString(kAddressProperty, "1.1.1.1");
service->static_ip_parameters_.args_.SetInt(kPrefixlenProperty, 16);
- EXPECT_CALL(*service.get(), SetState(_)).Times(0);
- EXPECT_CALL(*service.get(), SetConnection(_)).Times(0);
+ // Even though we won't call DisconnectWithFailure, we should still have
+ // the service learn from the failed DHCP attempt.
+ EXPECT_CALL(*service, OnDHCPFailure());
+ EXPECT_CALL(*service, DisconnectWithFailure(_, _)).Times(0);
+ EXPECT_CALL(*service, SetConnection(_)).Times(0);
OnIPConfigUpdated(NULL, false);
}
@@ -366,13 +370,14 @@
SelectService(service);
scoped_refptr<MockIPConfig> ipconfig = new MockIPConfig(control_interface(),
kDeviceName);
- EXPECT_CALL(*service.get(), SetState(Service::kStateConnected));
- EXPECT_CALL(*service.get(), IsConnected())
+ EXPECT_CALL(*service, SetState(Service::kStateConnected));
+ EXPECT_CALL(*service, IsConnected())
.WillRepeatedly(Return(true));
- EXPECT_CALL(*service.get(), IsPortalDetectionDisabled())
+ EXPECT_CALL(*service, IsPortalDetectionDisabled())
.WillRepeatedly(Return(true));
- EXPECT_CALL(*service.get(), SetState(Service::kStateOnline));
- EXPECT_CALL(*service.get(), SetConnection(NotNullRefPtr()));
+ EXPECT_CALL(*service, SetState(Service::kStateOnline));
+ EXPECT_CALL(*service, OnDHCPSuccess());
+ EXPECT_CALL(*service, SetConnection(NotNullRefPtr()));
OnIPConfigUpdated(ipconfig.get(), true);
}
@@ -515,7 +520,7 @@
manager()));
SelectService(service);
- EXPECT_CALL(*service.get(), state()).
+ EXPECT_CALL(*service, state()).
WillRepeatedly(Return(Service::kStateConnected));
EXPECT_CALL(*dynamic_cast<DeviceMockAdaptor *>(device_->adaptor_.get()),
EmitBoolChanged(kPoweredProperty, false));
@@ -623,10 +628,10 @@
MockLinkMonitor *link_monitor = new StrictMock<MockLinkMonitor>();
SetLinkMonitor(link_monitor); // Passes ownership.
SetManager(&manager);
- EXPECT_CALL(*service.get(), state())
+ EXPECT_CALL(*service, state())
.WillOnce(Return(Service::kStateIdle));
- EXPECT_CALL(*service.get(), SetState(_));
- EXPECT_CALL(*service.get(), SetConnection(_));
+ EXPECT_CALL(*service, SetState(_));
+ EXPECT_CALL(*service, SetConnection(_));
EXPECT_TRUE(HasLinkMonitor());
SelectService(NULL);
EXPECT_FALSE(HasLinkMonitor());
@@ -686,6 +691,23 @@
}
TEST_F(DeviceTest, ShouldUseMinimalDHCPConfig) {
+ // With no selected service, we should not choose a minimal config.
+ EXPECT_FALSE(device_->ShouldUseMinimalDHCPConfig());
+
+ MockManager manager(control_interface(),
+ dispatcher(),
+ metrics(),
+ glib());
+ scoped_refptr<MockService> service(
+ new StrictMock<MockService>(control_interface(),
+ dispatcher(),
+ metrics(),
+ &manager));
+ SelectService(service);
+ EXPECT_CALL(*service, ShouldUseMinimalDHCPConfig())
+ .WillOnce(Return(true))
+ .WillOnce(Return(false));
+ EXPECT_TRUE(device_->ShouldUseMinimalDHCPConfig());
EXPECT_FALSE(device_->ShouldUseMinimalDHCPConfig());
}
diff --git a/ethernet.cc b/ethernet.cc
index 3fa2ded..85fbf11 100644
--- a/ethernet.cc
+++ b/ethernet.cc
@@ -129,8 +129,8 @@
void Ethernet::ConnectTo(EthernetService *service) {
CHECK(service == service_.get()) << "Ethernet was asked to connect the "
<< "wrong service?";
+ SelectService(service);
if (AcquireIPConfigWithLeaseName(service->GetStorageIdentifier())) {
- SelectService(service);
SetServiceState(Service::kStateConfiguring);
} else {
LOG(ERROR) << "Unable to acquire DHCP config.";
diff --git a/ethernet_unittest.cc b/ethernet_unittest.cc
index 8a31f59..533382c 100644
--- a/ethernet_unittest.cc
+++ b/ethernet_unittest.cc
@@ -289,10 +289,9 @@
WillOnce(Return(dhcp_config_));
EXPECT_CALL(*dhcp_config_.get(), RequestIP()).WillOnce(Return(false));
EXPECT_CALL(dispatcher_, PostTask(_)); // Posts ConfigureStaticIPTask.
- // Since we never called SelectService()...
- EXPECT_CALL(*mock_service_, SetState(_)).Times(0);
+ EXPECT_CALL(*mock_service_, SetState(Service::kStateFailure));
ethernet_->ConnectTo(mock_service_);
- EXPECT_EQ(NULL, GetSelectedService().get());
+ EXPECT_EQ(mock_service_, GetSelectedService().get());
}
TEST_F(EthernetTest, ConnectToSuccess) {
diff --git a/metrics.cc b/metrics.cc
index efec578..f74e667 100644
--- a/metrics.cc
+++ b/metrics.cc
@@ -265,6 +265,10 @@
const int Metrics::kMetricVpnUserAuthenticationTypeMax =
Metrics::kVpnUserAuthenticationTypeMax;
+// static
+const char Metrics::kMetricDHCPOptionFailureDetected[] =
+ "Network.Shill.%s.DHCPOptionFailureDetected";
+
Metrics::Metrics(EventDispatcher *dispatcher)
: dispatcher_(dispatcher),
library_(&metrics_library_),
@@ -1017,6 +1021,15 @@
kCorruptedProfileMax);
}
+void Metrics::NotifyDHCPOptionFailure(const Service &service) {
+ Technology::Identifier technology = service.technology();
+ string histogram = GetFullMetricName(kMetricDHCPOptionFailureDetected,
+ technology);
+ SendEnumToUMA(histogram,
+ kDHCPOptionFailure,
+ kDHCPOptionFailureMax);
+}
+
bool Metrics::SendEnumToUMA(const string &name, int sample, int max) {
SLOG(Metrics, 5)
<< "Sending enum " << name << " with value " << sample << ".";
diff --git a/metrics.h b/metrics.h
index fc214de..1c9f776 100644
--- a/metrics.h
+++ b/metrics.h
@@ -261,6 +261,11 @@
kVpnUserAuthenticationTypeMax
};
+ enum DHCPOptionFailure {
+ kDHCPOptionFailure = 1,
+ kDHCPOptionFailureMax
+ };
+
static const char kMetricDisconnect[];
static const int kMetricDisconnectMax;
static const int kMetricDisconnectMin;
@@ -418,6 +423,11 @@
static const char kMetricVpnUserAuthenticationType[];
static const int kMetricVpnUserAuthenticationTypeMax;
+ // We have detected that a DHCP server can only deliver leases if
+ // we reduce the number of options that we request of it. This
+ // implies an infrastructure issue.
+ static const char kMetricDHCPOptionFailureDetected[];
+
explicit Metrics(EventDispatcher *dispatcher);
virtual ~Metrics();
@@ -578,6 +588,9 @@
// Notifies this object about a corrupted profile.
virtual void NotifyCorruptedProfile();
+ // Notifies this object about a service with DHCP infrastructure problems.
+ virtual void NotifyDHCPOptionFailure(const Service &service);
+
// Sends linear histogram data to UMA.
virtual bool SendEnumToUMA(const std::string &name, int sample, int max);
diff --git a/mock_metrics.h b/mock_metrics.h
index 567ffec..5103f03 100644
--- a/mock_metrics.h
+++ b/mock_metrics.h
@@ -37,6 +37,7 @@
MOCK_METHOD0(Notify3GPPRegistrationDelayedDropPosted, void());
MOCK_METHOD0(Notify3GPPRegistrationDelayedDropCanceled, void());
MOCK_METHOD0(NotifyCorruptedProfile, void());
+ MOCK_METHOD1(NotifyDHCPOptionFailure, void(const Service &service));
MOCK_METHOD3(SendEnumToUMA, bool(const std::string &name, int sample,
int max));
MOCK_METHOD5(SendToUMA, bool(const std::string &name, int sample, int min,
diff --git a/mock_service.h b/mock_service.h
index 304ed05..330d278 100644
--- a/mock_service.h
+++ b/mock_service.h
@@ -64,6 +64,9 @@
MOCK_CONST_METHOD0(eap, const EapCredentials *());
MOCK_CONST_METHOD0(technology, Technology::Identifier());
MOCK_METHOD1(OnPropertyChanged, void(const std::string &property));
+ MOCK_METHOD0(OnDHCPFailure, void());
+ MOCK_METHOD0(OnDHCPSuccess, void());
+ MOCK_METHOD0(ShouldUseMinimalDHCPConfig, bool());
// Set a string for this Service via |store|. Can be wired to Save() for
// test purposes.
bool FauxSave(StoreInterface *store);
diff --git a/service.cc b/service.cc
index 67ce9ad..37797af 100644
--- a/service.cc
+++ b/service.cc
@@ -77,6 +77,7 @@
const char Service::kStorageFavorite[] = "Favorite";
const char Service::kStorageGUID[] = "GUID";
const char Service::kStorageHasEverConnected[] = "HasEverConnected";
+const char Service::kStorageLastDHCPOptionFailure[] = "LastDHCPOptionFailure";
const char Service::kStorageName[] = "Name";
const char Service::kStoragePriority[] = "Priority";
const char Service::kStorageProxyConfig[] = "ProxyConfig";
@@ -96,6 +97,10 @@
const int Service::kReportDisconnectsThreshold = 2;
const int Service::kReportMisconnectsThreshold = 3;
const int Service::kMaxDisconnectEventHistory = 20;
+const int Service::kMaxDHCPOptionFailures = 2;
+
+// If we encounter MTU issues, hold off sending a full DHCP request for 30 days.
+const int Service::kDHCPOptionHoldOffPeriodSeconds = 30 * 24 * 60 * 60;
// static
unsigned int Service::next_serial_number_ = 0;
@@ -138,7 +143,9 @@
manager_(manager),
sockets_(new Sockets()),
time_(Time::GetInstance()),
- diagnostics_reporter_(DiagnosticsReporter::GetInstance()) {
+ diagnostics_reporter_(DiagnosticsReporter::GetInstance()),
+ consecutive_dhcp_failures_(0),
+ dhcp_option_failure_state_(kDHCPOptionFailureNotDetected) {
HelpRegisterDerivedBool(kAutoConnectProperty,
&Service::GetAutoConnect,
&Service::SetAutoConnectFull,
@@ -417,6 +424,18 @@
storage->GetBool(id, kStorageSaveCredentials, &save_credentials_);
LoadString(storage, id, kStorageUIData, "", &ui_data_);
+ uint64 last_dhcp_option_failure;
+ if (storage->GetUint64(id, kStorageLastDHCPOptionFailure,
+ &last_dhcp_option_failure)) {
+ struct timeval tv = { 0, 0 };
+ tv.tv_sec = last_dhcp_option_failure;
+ last_dhcp_option_failure_ = Timestamp(tv, "");
+ dhcp_option_failure_state_ = kDHCPOptionFailureConfirmed;
+ } else {
+ last_dhcp_option_failure_ = Timestamp();
+ dhcp_option_failure_state_ = kDHCPOptionFailureNotDetected;
+ }
+
static_ip_parameters_.Load(storage, id);
if (mutable_eap()) {
@@ -440,6 +459,9 @@
proxy_config_ = "";
save_credentials_ = true;
ui_data_ = "";
+ consecutive_dhcp_failures_ = 0;
+ last_dhcp_option_failure_ = Timestamp();
+ dhcp_option_failure_state_ = kDHCPOptionFailureNotDetected;
if (mutable_eap()) {
mutable_eap()->Reset();
}
@@ -487,10 +509,24 @@
storage->SetBool(id, kStorageSaveCredentials, save_credentials_);
SaveString(storage, id, kStorageUIData, ui_data_, false, true);
+ if (dhcp_option_failure_state_ == kDHCPOptionFailureConfirmed ||
+ dhcp_option_failure_state_ == kDHCPOptionFailureRetestMinimalRequest ||
+ dhcp_option_failure_state_ == kDHCPOptionFailureRetestFullRequest ||
+ dhcp_option_failure_state_ == kDHCPOptionFailureRetestGotNoReply) {
+ // In any of the states where we maintain a history of DHCP option
+ // failures and we haven't confirmed that this is no longer an issue,
+ // we should save the last option failure time even if it is very long ago.
+ storage->SetUint64(id, kStorageLastDHCPOptionFailure,
+ last_dhcp_option_failure_.monotonic.tv_sec);
+ } else {
+ storage->DeleteKey(id, kStorageLastDHCPOptionFailure);
+ }
+
static_ip_parameters_.Save(storage, id);
if (eap()) {
eap()->Save(storage, id, save_credentials_);
}
+
return true;
}
@@ -789,7 +825,7 @@
struct timeval period = (const struct timeval){ seconds_ago };
while (!events->empty()) {
if (events->size() < static_cast<size_t>(kMaxDisconnectEventHistory)) {
- struct timeval elapsed = (const struct timeval){ 0 };
+ struct timeval elapsed { 0 };
timersub(&now.monotonic, &events->front().monotonic, &elapsed);
if (timercmp(&elapsed, &period, <)) {
break;
@@ -1401,4 +1437,131 @@
adaptor_->EmitStringChanged(kErrorProperty, error);
}
+void Service::OnDHCPFailure() {
+ consecutive_dhcp_failures_++;
+ switch (dhcp_option_failure_state_) {
+ case kDHCPOptionFailureNotDetected:
+ // If we run into too many consecutive DHCP failures, we must suspect
+ // that this may be due in part to the number of options we are requesting
+ // from the server. Next time, we should try asking for less options.
+ if (consecutive_dhcp_failures_ >= kMaxDHCPOptionFailures) {
+ SLOG(Service, 2) << "Service " << unique_name_ << " is failing to "
+ << "receive DHCP responses. The next attempt will "
+ << "be with minimal DHCP options.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureSuspected;
+ }
+ break;
+
+ case kDHCPOptionFailureSuspected:
+ // Requesting a shorter DHCP reply does not seem to have helped. As
+ // such, we should exonerate DHCP options as the source of the failures.
+ SLOG(Service, 2) << "Service " << unique_name_ << " did not get a DHCP "
+ << "response even with minimal options set.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureNotDetected;
+
+ // Unless we set our failure count back to 0, we'll end up toggling back
+ // and forth endlessly between the Suspected and NotDetected states.
+ consecutive_dhcp_failures_ = 0;
+ break;
+
+ case kDHCPOptionFailureConfirmed:
+ // Nothing to do here. We've previously confirmed that this network
+ // has problems with requests for a large number of DHCP options, so
+ // we'll continue to send small requests until our timeout expires.
+ break;
+
+ case kDHCPOptionFailureRetestFullRequest:
+ // This means that we are still running into issues with DHCP responses
+ // when we send a full request. It's likely that the problem with this
+ // network still exists. Let's confirm this by switching back to minimal
+ // requests.
+ SLOG(Service, 2) << "Service " << unique_name_ << " tried a full DHCP "
+ << "request and it still appears to be failing.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureRetestMinimalRequest;
+ break;
+
+ case kDHCPOptionFailureRetestMinimalRequest:
+ // Requesting a shorter DHCP reply does not seem to have helped.
+ // However we still have a memory of this once being a problem, so
+ // it is probably best to continue sending short requests and postpone
+ // a re-test until we get a reply.
+ SLOG(Service, 2) << "Service " << unique_name_ << " seems not to be "
+ << "getting any DHCP responses at all.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureRetestGotNoReply;
+ break;
+
+ case kDHCPOptionFailureRetestGotNoReply:
+ // Nothing to do here. We are still failing to receive a reply.
+ break;
+ }
+}
+
+void Service::OnDHCPSuccess() {
+ consecutive_dhcp_failures_ = 0;
+ switch (dhcp_option_failure_state_) {
+ case kDHCPOptionFailureNotDetected:
+ // Nothing to do. All is well with the world.
+ break;
+
+ case kDHCPOptionFailureSuspected: // FALLTHROUGH
+ case kDHCPOptionFailureRetestMinimalRequest:
+ LOG(WARNING) << "Service " << unique_name_ << " can get a DHCP "
+ << "response only with minimal options requested.";
+ // We just performed an experiment to prove that the DHCP failures we
+ // have been having might be related to the number of options we have
+ // been requesting. It appears that as soon as we reduced the option
+ // count, our request succeeded.
+ dhcp_option_failure_state_ = kDHCPOptionFailureConfirmed;
+ last_dhcp_option_failure_ = time_->GetNow();
+ metrics_->NotifyDHCPOptionFailure(*this);
+ break;
+
+ case kDHCPOptionFailureConfirmed:
+ // Nothing to do here. We've previously confirmed that this network
+ // has problems with requests for a large number of DHCP options, so
+ // we'll continue to send small requests until our timeout expires.
+ break;
+
+ case kDHCPOptionFailureRetestFullRequest:
+ // We expected this request to fail, since we attempted a full request
+ // on a network we previously believed dropped DHCP replies for such
+ // requests. Let's exonerate this network.
+ SLOG(Service, 2) << "Service " << unique_name_ << " was able to receive "
+ << "a response to a full DHCP request. Switching back "
+ << "to full requests by default.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureNotDetected;
+ break;
+
+ case kDHCPOptionFailureRetestGotNoReply:
+ // We are finally receiving DHCP replies again. Resume the test
+ // starting with the next time we perform a DHCP request.
+ SLOG(Service, 2) << "Service " << unique_name_ << " was finally able to "
+ << "receive a DHCP response.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureRetestFullRequest;
+ break;
+ }
+}
+
+bool Service::ShouldUseMinimalDHCPConfig() {
+ // If it's been a while since we have tested for options failures, we should
+ // re-confirm if this issue still exists.
+ if (dhcp_option_failure_state_ == kDHCPOptionFailureConfirmed) {
+ Timestamp now = time_->GetNow();
+ struct timeval elapsed { 0 };
+ timersub(&now.monotonic, &last_dhcp_option_failure_.monotonic, &elapsed);
+ struct timeval period { kDHCPOptionHoldOffPeriodSeconds };
+ if (timercmp(&elapsed, &period, >=)) {
+ SLOG(Service, 2) << "Service " << unique_name_ << " will be re-tested to "
+ << "see if the server responds to a full DHCP request.";
+ dhcp_option_failure_state_ = kDHCPOptionFailureRetestFullRequest;
+ }
+ }
+
+ return
+ dhcp_option_failure_state_ == kDHCPOptionFailureSuspected ||
+ dhcp_option_failure_state_ == kDHCPOptionFailureConfirmed ||
+ dhcp_option_failure_state_ == kDHCPOptionFailureRetestMinimalRequest ||
+ dhcp_option_failure_state_ == kDHCPOptionFailureRetestGotNoReply;
+}
+
} // namespace shill
diff --git a/service.h b/service.h
index cb3c3d8..007cd18 100644
--- a/service.h
+++ b/service.h
@@ -72,6 +72,7 @@
static const char kStorageFavorite[];
static const char kStorageGUID[];
static const char kStorageHasEverConnected[];
+ static const char kStorageLastDHCPOptionFailure[];
static const char kStorageName[];
static const char kStoragePriority[];
static const char kStorageProxyConfig[];
@@ -121,7 +122,14 @@
kCryptoRc4,
kCryptoAes
};
-
+ enum DHCPOptionFailureState {
+ kDHCPOptionFailureNotDetected,
+ kDHCPOptionFailureSuspected,
+ kDHCPOptionFailureConfirmed,
+ kDHCPOptionFailureRetestFullRequest,
+ kDHCPOptionFailureRetestMinimalRequest,
+ kDHCPOptionFailureRetestGotNoReply
+ };
static const int kPriorityNone;
// A constructor for the Service object
@@ -406,6 +414,15 @@
// Called by the manager once after a resume.
virtual void OnAfterResume();
+ // Called by the device if a DHCP attempt fails.
+ virtual void OnDHCPFailure();
+
+ // Called by the device if a DHCP attempt succeeds.
+ virtual void OnDHCPSuccess();
+
+ // Called by the device to test for historical DHCP issues.
+ virtual bool ShouldUseMinimalDHCPConfig();
+
EapCredentials *mutable_eap() { return eap_.get(); }
PropertyStore *mutable_store() { return &store_; }
@@ -620,6 +637,15 @@
static const int kReportMisconnectsThreshold;
static const int kMaxDisconnectEventHistory;
+ // The number of DHCP failures to allow before we start suspecting that
+ // this may be indirectly due to the number of options we are requesting.
+ static const int kMaxDHCPOptionFailures;
+
+ // The number of DHCP failures to allow before we start suspecting that
+ // this may be indirectly due to the number of options we are requesting.
+ static const int kDHCPOptionHoldOffPeriodSeconds;
+
+
bool GetAutoConnect(Error *error);
std::string GetCheckPortal(Error *error);
@@ -751,6 +777,17 @@
Time *time_;
DiagnosticsReporter *diagnostics_reporter_;
+ // Tracks the number of consecutive failed DHCP attempts.
+ int consecutive_dhcp_failures_;
+
+ // Tracks the last time we had a failure that appered correlated
+ // to the DHCP client asking for too many options.
+ Timestamp last_dhcp_option_failure_;
+
+ // Tracks the current progress in deciding if DHCP failures appear
+ // correlated to requests for a large number of DHCP options.
+ DHCPOptionFailureState dhcp_option_failure_state_;
+
// The |serial_number_| for the next Service.
static unsigned int next_serial_number_;
diff --git a/service_unittest.cc b/service_unittest.cc
index 913761d..628aec6 100644
--- a/service_unittest.cc
+++ b/service_unittest.cc
@@ -53,6 +53,7 @@
using testing::Return;
using testing::ReturnRef;
using testing::StrictMock;
+using testing::StrNe;
using testing::SetArgumentPointee;
using testing::Test;
using testing::Values;
@@ -182,6 +183,39 @@
return service_->SetAutoConnectFull(connect, error);
}
+ int GetConsecutiveDHCPFailures() {
+ return service_->consecutive_dhcp_failures_;
+ }
+
+ void SetConsecutiveDHCPFailures(int failures) {
+ service_->consecutive_dhcp_failures_ = failures;
+ }
+
+ int GetLastDHCPOptionFailure() {
+ return service_->last_dhcp_option_failure_.monotonic.tv_sec;
+ }
+
+ void SetLastDHCPOptionFailure(int monotonic_seconds) {
+ service_->last_dhcp_option_failure_ = GetTimestamp(monotonic_seconds, "");
+ }
+
+ Service::DHCPOptionFailureState GetDHCPOptionFailureState() {
+ return service_->dhcp_option_failure_state_;
+ }
+
+ void SetDHCPOptionFailureState(
+ Service::DHCPOptionFailureState failure_state) {
+ service_->dhcp_option_failure_state_ = failure_state;
+ }
+
+ int GetMaxDHCPOptionFailures() {
+ return Service::kMaxDHCPOptionFailures;
+ }
+
+ int GetDHCPOptionHoldOffPeriodSeconds() {
+ return Service::kDHCPOptionHoldOffPeriodSeconds;
+ }
+
MockManager mock_manager_;
MockDiagnosticsReporter diagnostics_reporter_;
MockTime time_;
@@ -637,12 +671,19 @@
EXPECT_FALSE(service_->explicitly_disconnected_);
EXPECT_TRUE(service_->has_ever_connected_);
service_->explicitly_disconnected_ = true;
+ SetConsecutiveDHCPFailures(100);
+ SetLastDHCPOptionFailure(200);
+ SetDHCPOptionFailureState(Service::kDHCPOptionFailureConfirmed);
EXPECT_CALL(*eap_, Reset());
service_->Unload();
EXPECT_EQ(string(""), service_->ui_data_);
EXPECT_EQ(string(""), service_->guid_);
EXPECT_FALSE(service_->explicitly_disconnected_);
EXPECT_FALSE(service_->has_ever_connected_);
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
}
TEST_F(ServiceTest, State) {
@@ -1795,4 +1836,308 @@
TestCustomSetterNoopChange(service_, &mock_manager_);
}
+TEST_F(ServiceTest, DHCPOptionFailureState) {
+ // We are testing the transitions out of each node in this
+ // state diagram:
+ //
+ // [ Not Detected (send full request) ] <------------
+ // | ^ |
+ // | | |
+ // n * failure failure |
+ // | | |
+ // V | |
+ // [ Suspected (send minimal request) ] |
+ // | |
+ // success |
+ // | |
+ // V |
+ // [ Confirmed (send minimal request) ] |
+ // ^ | |
+ // | hold timer elapsed |
+ // | | |
+ // success V |
+ // | [ Retest Full Request ] ----success--/
+ // | | ^
+ // | failure |
+ // | | |
+ // | V |
+ // [ Retest Minimal Request ] |
+ // | success
+ // failure |
+ // | |
+ // V |
+ // [ Retest With No Reply (send minimal requests) ]
+
+ // Check initial state.
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+
+ // Let's make up a constant to represent enough iterations that we
+ // safely expect that the state machine won't transition as a result
+ // of more iterations.
+ const int kManyTimes = GetMaxDHCPOptionFailures() * 10;
+
+ // NotDetected -> NotDetected.
+ for (int i = 0; i < kManyTimes; ++i) {
+ service_->OnDHCPSuccess();
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+ }
+
+ for (int i = 0; i < GetMaxDHCPOptionFailures() - 1; ++i) {
+ service_->OnDHCPFailure();
+ EXPECT_EQ(i + 1, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+ }
+
+ NiceMock<MockStore> storage;
+ EXPECT_CALL(storage,
+ DeleteKey(_, StrNe(Service::kStorageLastDHCPOptionFailure)))
+ .WillRepeatedly(Return(true));
+ EXPECT_CALL(storage,
+ DeleteKey(storage_id_, Service::kStorageLastDHCPOptionFailure));
+ EXPECT_CALL(*eap_, Save(_, _, _)).Times(AnyNumber());
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // NotDetected -> Suspected.
+ service_->OnDHCPFailure();
+ EXPECT_EQ(GetMaxDHCPOptionFailures(), GetConsecutiveDHCPFailures());
+ // This value only updates at the time the failure is confirmed.
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureSuspected, GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ DeleteKey(storage_id_, Service::kStorageLastDHCPOptionFailure));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // Suspected -> NotDetected.
+ EXPECT_EQ(GetMaxDHCPOptionFailures(), GetConsecutiveDHCPFailures());
+ service_->OnDHCPFailure();
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ DeleteKey(storage_id_, Service::kStorageLastDHCPOptionFailure));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // Suspected -> Confirmed.
+ SetConsecutiveDHCPFailures(GetMaxDHCPOptionFailures());
+ SetLastDHCPOptionFailure(0);
+ SetDHCPOptionFailureState(Service::kDHCPOptionFailureSuspected);
+
+ int kFirstFailureTime = 1234;
+ EXPECT_CALL(time_, GetNow())
+ .WillRepeatedly(Return(GetTimestamp(kFirstFailureTime, "")));
+ EXPECT_CALL(*metrics(), NotifyDHCPOptionFailure(_));
+ service_->OnDHCPSuccess();
+ Mock::VerifyAndClearExpectations(metrics());
+
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed, GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // Confirmed -> Confirmed.
+ Mock::VerifyAndClearExpectations(&time_);
+ int kAlmostAtFirstFailureExpiry =
+ kFirstFailureTime + GetDHCPOptionHoldOffPeriodSeconds() - 1;
+ EXPECT_CALL(time_, GetNow())
+ .WillRepeatedly(Return(GetTimestamp(kAlmostAtFirstFailureExpiry, "")));
+
+ for (int i = 0; i < kManyTimes; ++i) {
+ service_->OnDHCPSuccess();
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed,
+ GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+ }
+
+ for (int i = 0; i < kManyTimes; ++i) {
+ service_->OnDHCPFailure();
+ EXPECT_EQ(i + 1, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed,
+ GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+ }
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // Confirmed -> RetestFullRequest.
+ Mock::VerifyAndClearExpectations(&time_);
+ int kFirstFailureExpiry =
+ kFirstFailureTime + GetDHCPOptionHoldOffPeriodSeconds();
+ EXPECT_CALL(time_, GetNow())
+ .WillRepeatedly(Return(GetTimestamp(kFirstFailureExpiry, "")));
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureRetestFullRequest,
+ GetDHCPOptionFailureState());
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // RetestFullRequest -> NotDetected.
+ service_->OnDHCPSuccess();
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ DeleteKey(storage_id_, Service::kStorageLastDHCPOptionFailure));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // RetestFullRequest -> RetestMinimalRequest.
+ SetDHCPOptionFailureState(Service::kDHCPOptionFailureRetestFullRequest);
+
+ service_->OnDHCPFailure();
+ EXPECT_EQ(1, GetConsecutiveDHCPFailures());
+ // This value only updates at the time the failure is confirmed.
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureRetestMinimalRequest,
+ GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // RetestMinimalRequest -> Confirmed.
+ Mock::VerifyAndClearExpectations(&time_);
+ int kSecondFailureTime = kFirstFailureExpiry + 1;
+ EXPECT_CALL(time_, GetNow())
+ .WillRepeatedly(Return(GetTimestamp(kSecondFailureTime, "")));
+ EXPECT_CALL(*metrics(), NotifyDHCPOptionFailure(_));
+ service_->OnDHCPSuccess();
+ Mock::VerifyAndClearExpectations(metrics());
+
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kSecondFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed, GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kSecondFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // RetestMinimalRequest -> RetestGotNoReply.
+ SetDHCPOptionFailureState(Service::kDHCPOptionFailureRetestMinimalRequest);
+ SetConsecutiveDHCPFailures(1);
+ SetLastDHCPOptionFailure(kFirstFailureTime);
+
+ service_->OnDHCPFailure();
+ EXPECT_EQ(2, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureRetestGotNoReply,
+ GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // RetestGotNoReply -> RetestGotNoReply.
+ for (int i = 0; i < kManyTimes; ++i) {
+ service_->OnDHCPFailure();
+ EXPECT_EQ(i + 3, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureRetestGotNoReply,
+ GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+ }
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // RetestGotNoReply -> RetestFullRequest.
+ service_->OnDHCPSuccess();
+ EXPECT_EQ(0, GetConsecutiveDHCPFailures());
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureRetestFullRequest,
+ GetDHCPOptionFailureState());
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+
+ EXPECT_CALL(storage,
+ SetUint64(storage_id_,
+ Service::kStorageLastDHCPOptionFailure,
+ kFirstFailureTime));
+ EXPECT_TRUE(service_->Save(&storage));
+
+ // Load into NotDetected.
+ EXPECT_CALL(storage, ContainsGroup(storage_id_)).WillRepeatedly(Return(true));
+ EXPECT_CALL(*eap_, Load(&storage, storage_id_)).Times(AnyNumber());
+ EXPECT_CALL(storage,
+ GetUint64(storage_id_, Service::kStorageLastDHCPOptionFailure, _))
+ .WillOnce(Return(false));
+ EXPECT_TRUE(service_->Load(&storage));
+ EXPECT_EQ(0, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+ // Note that ShouldUseMinimalDHCPConfig() doesn't change this state.
+ EXPECT_EQ(Service::kDHCPOptionFailureNotDetected,
+ GetDHCPOptionFailureState());
+
+ // Load into Confirmed.
+ EXPECT_CALL(storage,
+ GetUint64(storage_id_, Service::kStorageLastDHCPOptionFailure, _))
+ .WillOnce(DoAll(SetArgumentPointee<2>(kSecondFailureTime), Return(true)));
+ EXPECT_TRUE(service_->Load(&storage));
+ EXPECT_EQ(kSecondFailureTime, GetLastDHCPOptionFailure());
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed, GetDHCPOptionFailureState());
+ EXPECT_TRUE(service_->ShouldUseMinimalDHCPConfig());
+ // Note that ShouldUseMinimalDHCPConfig() doesn't change this state.
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed, GetDHCPOptionFailureState());
+
+ // Load into RetestFullRequest.
+ EXPECT_CALL(storage,
+ GetUint64(storage_id_, Service::kStorageLastDHCPOptionFailure, _))
+ .WillOnce(DoAll(SetArgumentPointee<2>(kFirstFailureTime), Return(true)));
+ EXPECT_TRUE(service_->Load(&storage));
+ EXPECT_EQ(kFirstFailureTime, GetLastDHCPOptionFailure());
+ // At load time we believe we're confirmed...
+ EXPECT_EQ(Service::kDHCPOptionFailureConfirmed, GetDHCPOptionFailureState());
+ // But as soon as we query ShouldUseMinimalConfig, we'll switch, since
+ // kFirstFailureTime is too far in the past.
+ EXPECT_FALSE(service_->ShouldUseMinimalDHCPConfig());
+ EXPECT_EQ(Service::kDHCPOptionFailureRetestFullRequest,
+ GetDHCPOptionFailureState());
+}
+
} // namespace shill