From: Kirtika Ruchandani <kirtika@xxxxxxxxxxxx>
Chrome OS relies on its connection manager, shill, to bump up the
logging level in wpa_supplicant during 'interesting' times via its
WiFi::SetConnectionDebugging method. The method sets wpa_supplicant
debug level to 'info' (quieter) or 'debug' (when verbose).
Currently, it is not guaranteed that SetConnectionDebugging will be
called on all roaming paths, therefore we end up with two scenarios in
the logs: one where roaming happens out of the blue, like so (timestamp
removed):
shill: [INFO:manager.cc(497)] Service updated; state: Connected failure Unknown
shill: [INFO:wifi.cc(9)] Enabling high bitrates.
// Connected here
shill: [INFO:service.cc(404)] Service : state Connected -> Online
shill: [INFO:manager.cc(497)] Service updated; state: Online failure Unknown
shill: [INFO:wifi_service.cc(78)] Representative endpoint updated for service...
shill: [INFO:manager.cc(74)] Default physical service: (connected)
shill: [INFO:wifi.cc(9)] Scan on wlan0 from RequestScan
// We have roamed to a new AP that we are trying to authenticate with,
// and we don't know why...
wpa_supplicant: wlan0: SME: Trying to authenticate with <> (SSID='' freq= MHz)
wpa_supplicant: wlan0: Trying to associate with <> (SSID='' freq= MHz)
The second scenario, and the preferable one, is where we get details of
how roaming decisions were made. This happens when
WiFi::SetConnectionDebugging(true) is on the execution path, which seems
to be only when connecting to a new service:
wpa_supplicant: BSS: last_scan_res_used=14/32
wpa_supplicant: wlan0: New scan results available (own=1 ext=0)
wpa_supplicant: bgscan simple: scan result notification
wpa_supplicant: bgscan simple: freq_idx 0
wpa_supplicant: bgscan_poll_signal_monitor: bgscan poll noisefloor: 9999
wpa_supplicant: wlan0: Radio work 'scan'<> done in <> seconds
wpa_supplicant: wlan0: Selecting BSS from priority group <>
wpa_supplicant: wlan0: 0: <MAC> ssid='' wpa_ie_len=<> rsn_ie_len=<> caps=<> level=<> freq=<> wps
wpa_supplicant: wlan0: selected based on RSN IE
wpa_supplicant: wlan0: selected BSS <> ssid=''
wpa_supplicant: wlan0: Allow reassociation - selected BSS has better estimated throughput
wpa_supplicant: wlan0: Considering connect request: reassociate: 0 selected: <> bssid: <> ...
wpa_supplicant: wlan0: Request association with <>
wpa_supplicant: wlan0: Re-association to the same ESS
...
wpa_supplicant: wlan0: SME: Trying to authenticate with <> (SSID='' freq=<> MHz)
Until we have confidence that all roaming scenarios do go through shill
and can be intercepted with WiFi::SetConnectionDebugging(true), the
safer route is to bump up the logging level of the following directly
in wpa_supplicant itself:
- roaming decisions.
- estimated throughput and channel quality calculations.
Signed-off-by: Kirtika Ruchandani <kirtika@xxxxxxxxxxxx>
---
wpa_supplicant/events.c | 18 ++++++++++--------
1 file changed, 10 insertions(+), 8 deletions(-)
diff --git a/wpa_supplicant/events.c b/wpa_supplicant/events.c
index 21ce943d6..46c8b9bae 100644
--- a/wpa_supplicant/events.c
+++ b/wpa_supplicant/events.c
@@ -1705,13 +1705,13 @@ static int wpa_supplicant_need_to_roam(struct wpa_supplicant *wpa_s,
return 1; /* current BSS not seen in the last scan */
#ifndef CONFIG_NO_ROAMING
- wpa_dbg(wpa_s, MSG_DEBUG, "Considering within-ESS reassociation");
- wpa_dbg(wpa_s, MSG_DEBUG, "Current BSS: " MACSTR
+ wpa_dbg(wpa_s, MSG_INFO, "Considering within-ESS reassociation");
+ wpa_dbg(wpa_s, MSG_INFO, "Current BSS: " MACSTR
" freq=%d level=%d snr=%d est_throughput=%u",
MAC2STR(current_bss->bssid),
current_bss->freq, current_bss->level,
current_bss->snr, current_bss->est_throughput);
- wpa_dbg(wpa_s, MSG_DEBUG, "Selected BSS: " MACSTR
+ wpa_dbg(wpa_s, MSG_INFO, "Selected BSS: " MACSTR
" freq=%d level=%d snr=%d est_throughput=%u",
MAC2STR(selected->bssid), selected->freq, selected->level,
selected->snr, selected->est_throughput);
@@ -1719,14 +1719,16 @@ static int wpa_supplicant_need_to_roam(struct wpa_supplicant *wpa_s,
if (wpa_s->current_ssid->bssid_set &&
os_memcmp(selected->bssid, wpa_s->current_ssid->bssid, ETH_ALEN) ==
0) {
- wpa_dbg(wpa_s, MSG_DEBUG, "Allow reassociation - selected BSS "
+ wpa_dbg(wpa_s, MSG_INFO, "Allow reassociation - selected BSS "
"has preferred BSSID");
return 1;
}
if (selected->est_throughput > current_bss->est_throughput + 5000) {
- wpa_dbg(wpa_s, MSG_DEBUG,
- "Allow reassociation - selected BSS has better estimated throughput");
+ wpa_dbg(wpa_s, MSG_INFO,
+ "Allow reassociation - selected BSS has better "
+ "estimated throughput (current: %u, selected: %u)",
+ current_bss->est_throughput, selected->est_throughput);
return 1;
}
@@ -1734,7 +1736,7 @@ static int wpa_supplicant_need_to_roam(struct wpa_supplicant *wpa_s,
if (current_bss->level < 0 &&
current_bss->level > selected->level + to_5ghz * 2) {
- wpa_dbg(wpa_s, MSG_DEBUG, "Skip roam - Current BSS has better "
+ wpa_dbg(wpa_s, MSG_INFO, "Skip roam - Current BSS has better "
"signal level");
return 0;
}
@@ -1786,7 +1788,7 @@ static int wpa_supplicant_need_to_roam(struct wpa_supplicant *wpa_s,
}
diff = abs(current_bss->level - selected->level);
if (diff < min_diff) {
- wpa_dbg(wpa_s, MSG_DEBUG,
+ wpa_dbg(wpa_s, MSG_INFO,
"Skip roam - too small difference in signal level (%d < %d)",
diff, min_diff);
return 0;
--
2.24.0.393.g34dc348eaf-goog
_______________________________________________
Hostap mailing list
Hostap@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/hostap
