conman: Don't interrupt provisioning.
The WLAN retry period was much too low (15s), and this was
interrupting provisioning (which might be needed to get an updated
config). The default period has been increased to 120s, and
provisioning won't be interrupted to retry it.
Also added unit tests for this case and for reprovisioning in general,
and slightly tightened up tests in general.
Change-Id: I8049679964974c068fb04cf384918a8bcbe35e71
diff --git a/conman/connection_manager.py b/conman/connection_manager.py
index c27ef8d..076f1a6 100755
--- a/conman/connection_manager.py
+++ b/conman/connection_manager.py
@@ -179,6 +179,7 @@
return True
def _post_start_client(self):
+ self.wifi.handle_wpa_events()
self.wifi.status.connected_to_wlan = True
logging.info('Started wifi client on %s GHz', self.band)
self.wifi.attach_wpa_control(self._wpa_control_interface)
@@ -196,6 +197,7 @@
# TODO(rofrankel): Make this work for dual-radio devices.
self.wifi.status.connected_to_wlan = False
logging.info('Stopped wifi client on %s GHz', self.band)
+ self.wifi.handle_wpa_events()
except subprocess.CalledProcessError as e:
logging.error('Failed to stop wifi client: %s', e.output)
@@ -233,7 +235,7 @@
moca_tmp_dir='/tmp/cwmp/monitoring/moca2',
wpa_control_interface='/var/run/wpa_supplicant',
run_duration_s=1, interface_update_period=5,
- wifi_scan_period_s=120, wlan_retry_s=15, associate_wait_s=15,
+ wifi_scan_period_s=120, wlan_retry_s=120, associate_wait_s=15,
dhcp_wait_s=10, acs_start_wait_s=20, acs_finish_wait_s=120,
bssid_cycle_length_s=30):
@@ -452,6 +454,11 @@
for wifi in self.wifi:
continue_wifi = False
+ provisioning_failed = self.provisioning_failed(wifi)
+ if self.currently_provisioning(wifi):
+ continue
+
+ provisioning_failed = self.provisioning_failed(wifi)
# Only one wlan_configuration per interface will have access_point ==
# True. Try 5 GHz first, then 2.4 GHz. If both bands are supported by
@@ -489,11 +496,11 @@
if self._connected_to_wlan(wifi):
wifi.status.connected_to_wlan = True
logging.debug('Connected to WLAN on %s, nothing else to do.', wifi.name)
- break
+ continue
# This interface is not connected to the WLAN, so scan for potential
# routes to the ACS for provisioning.
- if ((not self.acs() or self.provisioning_failed(wifi)) and
+ if ((not self.acs() or provisioning_failed) and
not getattr(wifi, 'last_successful_bss_info', None) and
time.time() > wifi.last_wifi_scan_time + self._wifi_scan_period_s):
logging.debug('Performing scan on %s.', wifi.name)
@@ -506,7 +513,7 @@
# case 5 is unavailable for some reason.
for band in wifi.bands:
wlan_configuration = self._wlan_configuration.get(band, None)
- if wlan_configuration and time.time() > self._try_wlan_after[band]:
+ if wlan_configuration and time.time() >= self._try_wlan_after[band]:
logging.info('Trying to join WLAN on %s.', wifi.name)
wlan_configuration.start_client()
if self._connected_to_wlan(wifi):
@@ -527,7 +534,6 @@
# isn't registered to any accounts.
logging.debug('Unable to join WLAN on %s', wifi.name)
wifi.status.connected_to_wlan = False
- provisioning_failed = self.provisioning_failed(wifi)
if self.acs():
logging.debug('Connected to ACS')
if self._try_to_upload_logs:
@@ -811,6 +817,8 @@
self.start_provisioning(wifi)
connected = self._try_bssid(wifi, bss_info)
if connected:
+ wifi.attach_wpa_control(self._wpa_control_interface)
+ wifi.handle_wpa_events()
wifi.status.connected_to_open = True
now = time.time()
wifi.complain_about_acs_at = now + 5
@@ -946,6 +954,14 @@
wifi.provisioning_ratchet.current_step().name)
return True
+ def provisioning_completed(self, wifi):
+ return bool(wifi.provisioning_ratchet.done_after)
+
+ def currently_provisioning(self, wifi):
+ return (self._connected_to_open(wifi) and
+ (not (self.provisioning_failed(wifi) or
+ self.provisioning_completed(wifi))))
+
def provisioning_since(self, wifi):
return wifi.provisioning_ratchet.t0
diff --git a/conman/connection_manager_test.py b/conman/connection_manager_test.py
index a64ab79..9b806f9 100755
--- a/conman/connection_manager_test.py
+++ b/conman/connection_manager_test.py
@@ -181,17 +181,24 @@
WIFI_SETCLIENT = ['echo', 'setclient']
WIFI_STOPCLIENT = ['echo', 'stopclient']
+ def __init__(self, *args, **kwargs):
+ super(WLANConfiguration, self).__init__(*args, **kwargs)
+ self.stale = False
+
def _actually_start_client(self):
self.client_was_up = self.client_up
self.was_attached = self.wifi.attached()
self.wifi._secure_testonly = True
- # Do this before calling the super method so that the attach call at the end
- # succeeds.
+
+ super(WLANConfiguration, self)._actually_start_client()
+
if not self.client_was_up and not self.was_attached:
self.wifi._initial_ssid_testonly = self.ssid
self.wifi.start_wpa_supplicant_testonly(self._wpa_control_interface)
- return True
+ if self.wifi._wpa_control:
+ self.wifi._wpa_control.connected = not self.stale
+ return not self.stale
def _post_start_client(self):
if not self.client_was_up:
@@ -327,6 +334,8 @@
self.dhcp_failure_on_s3 = False
self.log_upload_count = 0
self.acs_session_fails = False
+ for wifi in self.wifi:
+ wifi.bssids_tried_testonly = 0
def create_wifi_interfaces(self):
super(ConnectionManager, self).create_wifi_interfaces()
@@ -349,11 +358,14 @@
wifi.add_terminating_event()
def _try_bssid(self, wifi, bss_info):
- wifi.add_disconnected_event()
+ if wifi.wpa_status().get('wpa_state', None) == 'COMPLETED':
+ wifi.add_disconnected_event()
self.last_provisioning_attempt = bss_info
super(ConnectionManager, self)._try_bssid(wifi, bss_info)
+ wifi.bssids_tried_testonly += 1
+
def connect(connection_check_result, dhcp_failure=False):
# pylint: disable=protected-access
if wifi.attached():
@@ -446,6 +458,11 @@
# Test methods
+ def tried_to_upload_logs(self):
+ result = getattr(self, 'last_log_upload_count', 0) < self.log_upload_count
+ self.last_log_upload_count = self.log_upload_count
+ return result
+
def delete_wlan_config(self, band):
delete_wlan_config(self._config_dir, band)
@@ -614,6 +631,7 @@
wpa_control_interface=wpa_control_interface,
run_duration_s=run_duration_s,
interface_update_period=interface_update_period,
+ wlan_retry_s=0,
wifi_scan_period_s=wifi_scan_period_s,
associate_wait_s=associate_wait_s,
dhcp_wait_s=dhcp_wait_s,
@@ -752,7 +770,7 @@
wvtest.WVPASS(c.internet())
wvtest.WVFAIL(c.client_up(band))
wvtest.WVPASS(c.wifi_for_band(band).current_routes())
- wvtest.WVPASSEQ(c.log_upload_count, 1)
+ wvtest.WVPASS(c.tried_to_upload_logs())
# Disable scan results again.
c.interface_with_scan_results = None
c.run_until_interface_update()
@@ -774,11 +792,35 @@
c.wifi_for_band(band).kill_wpa_supplicant_testonly(c._wpa_control_interface)
wvtest.WVFAIL(c.client_up(band))
wvtest.WVFAIL(c._connected_to_wlan(c.wifi_for_band(band)))
+ # Make sure we stay connected to s2, rather than disconnecting and
+ # reconnecting.
c.run_once()
wvtest.WVPASS(c.has_status_files([status.P.CONNECTED_TO_WLAN]))
wvtest.WVPASS(c.client_up(band))
wvtest.WVPASS(c._connected_to_wlan(c.wifi_for_band(band)))
+ # Now, update the WLAN configuration and make sure we reprovision.
+
+ # The AP restarts with a new configuration, kicking us off. We should
+ # reprovision.
+ c._wlan_configuration[band].stale = True
+ c.wifi_for_band(band).add_disconnected_event()
+ c.run_once()
+ wvtest.WVFAIL(c.client_up(band))
+ wvtest.WVPASS(c._connected_to_open(c.wifi_for_band(band)))
+ wvtest.WVPASSEQ(c.last_provisioning_attempt.ssid, 's2')
+
+ # Now that we're on the provisioning network, create the new WLAN
+ # configuration, which should be connected to.
+ ssid = 'wlan2'
+ psk = 'password2'
+ c.write_wlan_config(band, ssid, psk)
+ c.run_once()
+ wvtest.WVPASS(c.client_up(band))
+ wvtest.WVPASS(c.wifi_for_band(band).wpa_status()['ssid'] == ssid)
+ wvtest.WVPASS(c.has_status_files([status.P.CONNECTED_TO_WLAN]))
+ wvtest.WVPASS(c.wifi_for_band(band).current_routes())
+
# Now, remove the WLAN configuration and make sure we are disconnected. Then
# disable the previously used ACS connection via s2, re-enable scan results,
# add the user's WLAN to the scan results, and scan again. This time, the
@@ -796,14 +838,11 @@
wvtest.WVPASSEQ(c.last_provisioning_attempt.bssid, 'ff:ee:dd:cc:bb:aa')
# The log upload happens on the next main loop after joining s3.
c.run_once()
- wvtest.WVPASSEQ(c.log_upload_count, 2)
+ wvtest.WVPASS(c.tried_to_upload_logs())
# Now, recreate the same WLAN configuration, which should be connected to.
# Also, test that atomic writes/renames work.
- ssid = 'wlan'
- psk = 'password'
c.write_wlan_config(band, ssid, psk, atomic=True)
- c.disable_access_point(band)
c.run_once()
wvtest.WVPASS(c.client_up(band))
wvtest.WVPASS(c.wifi_for_band(band).current_routes())
@@ -872,7 +911,7 @@
# Make sure we didn't scan on `band`.
wvtest.WVPASSEQ(scan_count_for_band, c.wifi_for_band(band).wifi_scan_counter)
c.run_once()
- wvtest.WVPASSEQ(c.log_upload_count, 3)
+ wvtest.WVPASS(c.tried_to_upload_logs())
# Now re-create the WLAN config, connect to the WLAN, and make sure that s3 is
# unset as last_successful_bss_info, since it is no longer available.
@@ -898,6 +937,9 @@
# 4) Connect to s2 but get no ACS access; see that last_successful_bss_info is
# unset.
c.write_wlan_config(band, ssid, psk)
+ # Connect
+ c.run_once()
+ # Process DHCP results
c.run_once()
wvtest.WVPASS(c.acs())
wvtest.WVPASS(c.internet())
@@ -916,7 +958,7 @@
s2_bss = iw.BssInfo('01:23:45:67:89:ab', 's2')
wvtest.WVPASSEQ(c.wifi_for_band(band).last_successful_bss_info, s2_bss)
c.run_once()
- wvtest.WVPASSEQ(c.log_upload_count, 4)
+ wvtest.WVPASS(c.tried_to_upload_logs())
c.s2_fail = True
c.write_wlan_config(band, ssid, psk)
@@ -925,9 +967,12 @@
wvtest.WVPASS(c.internet())
wvtest.WVPASSEQ(c.wifi_for_band(band).last_successful_bss_info, s2_bss)
- c.delete_wlan_config(band)
+ c._wlan_configuration[band].stale = True
+ c.wifi_for_band(band).add_disconnected_event()
# Run once so that c will reconnect to s2.
c.run_once()
+ wvtest.WVPASS(c.wifi_for_band(band).connected_to_open())
+ wvtest.WVPASSEQ(c.wifi_for_band(band).wpa_status().get('ssid'), 's2')
# Now run until it sees the lack of ACS access.
c.run_until_interface_update()
wvtest.WVPASSEQ(c.wifi_for_band(band).last_successful_bss_info, None)
@@ -935,7 +980,8 @@
# Test that we wait dhcp_wait_s seconds for a DHCP lease before trying the
# next BSSID. The scan results contain an s3 AP with vendor IEs that fails to
# send a DHCP lease. This ensures that s3 will be tried before any other AP,
- # which lets us force a timeout and proceed to the next AP.
+ # which lets us force a timeout and proceed to the next AP. Having a stale
+ # WLAN configuration shouldn't interrupt provisioning.
del c.wifi_for_band(band).cycler
c.interface_with_scan_results = c.wifi_for_band(band).name
c.scan_results_include_hidden = True
@@ -946,6 +992,7 @@
last_bss_info = c.wifi_for_band(band).last_attempted_bss_info
wvtest.WVPASSEQ(last_bss_info.ssid, 's3')
wvtest.WVPASSEQ(last_bss_info.bssid, 'ff:ee:dd:cc:bb:aa')
+ c.write_wlan_config(band, ssid, psk)
# Second iteration: check that we try s3 again since there's no gateway yet.
c.run_once()
last_bss_info = c.wifi_for_band(band).last_attempted_bss_info
@@ -960,6 +1007,9 @@
wvtest.WVPASSNE(last_bss_info.ssid, 's3')
wvtest.WVPASSNE(last_bss_info.bssid, 'ff:ee:dd:cc:bb:aa')
+ # We can delete the stale WLAN config now, to simplify subsequent tests.
+ c.delete_wlan_config(band)
+
# Now repeat the above, but for an ACS session that takes a while. We don't
# necessarily want to leave if it fails (so we don't want the third check),
# but we do want to make sure we don't leave while we're still waiting for it.
@@ -1151,7 +1201,7 @@
wvtest.WVPASS(c.wifi_for_band('2.4').current_routes())
wvtest.WVFAIL(c.wifi_for_band('5').current_routes_normal_testonly())
c.run_once()
- wvtest.WVPASSEQ(c.log_upload_count, 1)
+ wvtest.WVPASS(c.tried_to_upload_logs())
@wvtest.wvtest
@@ -1285,6 +1335,9 @@
# Make sure 2.4 still works.
c.write_wlan_config('2.4', 'my ssid', 'my psk')
+ # Connect
+ c.run_once()
+ # Process DHCP results
c.run_once()
wvtest.WVPASS(c.wifi_for_band('2.4').acs())
wvtest.WVPASS(c.wifi_for_band('2.4').internet())
diff --git a/conman/interface.py b/conman/interface.py
index b20709a..51647ee 100755
--- a/conman/interface.py
+++ b/conman/interface.py
@@ -507,7 +507,6 @@
k, v = line.strip().split('=', 1)
status[k] = v
- logging.debug('%s wpa status is %s', self.name, status)
return status
def get_wpa_control(self, socket):
@@ -533,6 +532,7 @@
match = self.WPA_EVENT_RE.match(self._wpa_control.recv())
if match:
event = match.group('event')
+ logging.debug('%s got wpa_supplicant event %s', self.name, event)
if event == 'CONNECTED':
self.wpa_supplicant = True
elif event in ('DISCONNECTED', 'TERMINATING', 'ASSOC-REJECT',
diff --git a/conman/interface_test.py b/conman/interface_test.py
index e8f0876..74363b8 100755
--- a/conman/interface_test.py
+++ b/conman/interface_test.py
@@ -43,6 +43,8 @@
def _connection_check(self, *args, **kwargs):
result = super(FakeInterfaceMixin, self)._connection_check(*args, **kwargs)
+ if not self.links:
+ return False
if (self.current_routes().get('default', {}).get('via', None) !=
self._gateway_ip):
return False
