| Message ID | 20161217092917.15778-1-tomoharu.hatano@sonymobile.com |
|---|---|
| State | Superseded |
| Headers | show |
On Sat, Dec 17, 2016 at 06:29:17PM +0900, Tomoharu Hatano wrote: > Increase EAPOL RX frame timeout from 100 to 900 ms. > This will fix occasional roaming and authentication > disconnects on EAP networks. Would you happen to have a debug log with timestamps showing such a case where this change helps? It is somewhat surprising if it can take 900 ms for the kernel to deliver association event after it has delivered an EAPOL frame from that association. This optimization handling for pending EAPOL frame is really there only to work around the possibility of those kernel event getting reordered. In addition, it would be interesting know how lack of this workaround would result in disconnection. I would expect the AP/Authenticator to try again if it does not receive a response. If this workaround is neede to avoid a disconnection (i.e., to do something else than just speed up the connection a bit by avoiding retry), it would seem to indicate that something else is broken in the network or frame processing..
Hi Jouni, I'm sorry for the late reply. Please give me more time to confirm it. Best Regards, Tomoharu Hatano -----Original Message----- From: Jouni Malinen [mailto:j@w1.fi] Sent: Sunday, December 18, 2016 5:51 AM To: Hatano, Tomoharu (Sony Mobile) <Tomoharu.Hatano@sonymobile.com> Cc: hostap@lists.infradead.org; Sogo, Shinji (Sony Mobile) <Shinji.Sogo@sonymobile.com>; Nanbu, Tomonori (Sony Mobile) <Tomonori.Nanbu@sonymobile.com>; Andrejs Cainikovs <andrejs.cainikovs@sonymobile.com> Subject: Re: [PATCH] Fix delayed EAPOL RX frames On Sat, Dec 17, 2016 at 06:29:17PM +0900, Tomoharu Hatano wrote: > Increase EAPOL RX frame timeout from 100 to 900 ms. > This will fix occasional roaming and authentication disconnects on EAP > networks. Would you happen to have a debug log with timestamps showing such a case where this change helps? It is somewhat surprising if it can take 900 ms for the kernel to deliver association event after it has delivered an EAPOL frame from that association. This optimization handling for pending EAPOL frame is really there only to work around the possibility of those kernel event getting reordered. In addition, it would be interesting know how lack of this workaround would result in disconnection. I would expect the AP/Authenticator to try again if it does not receive a response. If this workaround is neede to avoid a disconnection (i.e., to do something else than just speed up the connection a bit by avoiding retry), it would seem to indicate that something else is broken in the network or frame processing..
Hi Jouni, I'm sorry to have kept you waiting long time. After I confirmed from our log, it took around 110ms in worst case. So, it looks 200ms is enough for fix. And it may depend on the implementation of chip vendor. Can we continue to discuss it if we change the timeout of the patch from 900ms to 200ms? ---------- 11-19 16:16:20.704 D/wpa_supplicant( 1371): wlan0: RX EAPOL from c8:d7:19:da:8f:41 11-19 16:16:20.704 D/wpa_supplicant( 1371): RX EAPOL - hexdump(len=9): 02 00 00 05 01 00 00 05 01 11-19 16:16:20.704 D/wpa_supplicant( 1371): wlan0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=c8:d7:19:da:8d:ed) *** Received 1st EAPOL frame 11-19 16:16:20.804 D/wpa_supplicant( 1371): nl80211: Event message available 11-19 16:16:20.804 D/wpa_supplicant( 1371): nl80211: Drv Event 47 (NL80211_CMD_ROAM) received for wlan0 11-19 16:16:20.804 D/wpa_supplicant( 1371): nl80211: Roam event 11-19 16:16:20.814 D/wpa_supplicant( 1371): nl80211: Associated on 2412 MHz 11-19 16:16:20.814 D/wpa_supplicant( 1371): nl80211: Associated with c8:d7:19:da:8f:41 *** Associated. (It took 110ms) 11-19 16:16:20.814 D/wpa_supplicant( 1371): nl80211: Operating frequency for the associated BSS from scan results: 2412 MHz ---------- Best Regards, Tomoharu Hatano -----Original Message----- From: Hatano, Tomoharu (Sony Mobile) Sent: Friday, January 06, 2017 10:20 PM To: Jouni Malinen <j@w1.fi> Cc: hostap@lists.infradead.org; Sogo, Shinji (Sony Mobile) <Shinji.Sogo@sonymobile.com>; Nanbu, Tomonori (Sony Mobile) <Tomonori.Nanbu@sonymobile.com>; Hatano, Tomoharu (Sony Mobile) <Tomoharu.Hatano@sonymobile.com> Subject: RE: [PATCH] Fix delayed EAPOL RX frames Hi Jouni, I'm sorry for the late reply. Please give me more time to confirm it. Best Regards, Tomoharu Hatano -----Original Message----- From: Jouni Malinen [mailto:j@w1.fi] Sent: Sunday, December 18, 2016 5:51 AM To: Hatano, Tomoharu (Sony Mobile) <Tomoharu.Hatano@sonymobile.com> Cc: hostap@lists.infradead.org; Sogo, Shinji (Sony Mobile) <Shinji.Sogo@sonymobile.com>; Nanbu, Tomonori (Sony Mobile) <Tomonori.Nanbu@sonymobile.com>; Andrejs Cainikovs <andrejs.cainikovs@sonymobile.com> Subject: Re: [PATCH] Fix delayed EAPOL RX frames On Sat, Dec 17, 2016 at 06:29:17PM +0900, Tomoharu Hatano wrote: > Increase EAPOL RX frame timeout from 100 to 900 ms. > This will fix occasional roaming and authentication disconnects on EAP > networks. Would you happen to have a debug log with timestamps showing such a case where this change helps? It is somewhat surprising if it can take 900 ms for the kernel to deliver association event after it has delivered an EAPOL frame from that association. This optimization handling for pending EAPOL frame is really there only to work around the possibility of those kernel event getting reordered. In addition, it would be interesting know how lack of this workaround would result in disconnection. I would expect the AP/Authenticator to try again if it does not receive a response. If this workaround is neede to avoid a disconnection (i.e., to do something else than just speed up the connection a bit by avoiding retry), it would seem to indicate that something else is broken in the network or frame processing..
> On 20 Jan 2017, at 4:32 AM, Hatano, Tomoharu (Sony Mobile) <Tomoharu.Hatano@sonymobile.com> wrote: > > After I confirmed from our log, it took around 110ms in worst case. > So, it looks 200ms is enough for fix. > And it may depend on the implementation of chip vendor. Thanks! > Can we continue to discuss it if we change the timeout of the patch from 900ms to 200ms? Yes, it makes sense to me to increase the delay from 100 to 200 ms based on the clear example that was not covered by the current time limit. - Jouni
Hi Jouni, Thank you for your reply. I have uploaded new patch. Please confirm it. Best Regards, Tomoharu Hatano -----Original Message----- From: Jouni Malinen [mailto:j@w1.fi] Sent: Friday, January 20, 2017 10:53 PM To: Hatano, Tomoharu (Sony Mobile) <Tomoharu.Hatano@sonymobile.com> Cc: Sogo, Shinji (Sony Mobile) <Shinji.Sogo@sonymobile.com>; hostap@lists.infradead.org; Nanbu, Tomonori (Sony Mobile) <Tomonori.Nanbu@sonymobile.com> Subject: Re: [PATCH] Fix delayed EAPOL RX frames > On 20 Jan 2017, at 4:32 AM, Hatano, Tomoharu (Sony Mobile) <Tomoharu.Hatano@sonymobile.com> wrote: > > After I confirmed from our log, it took around 110ms in worst case. > So, it looks 200ms is enough for fix. > And it may depend on the implementation of chip vendor. Thanks! > Can we continue to discuss it if we change the timeout of the patch from 900ms to 200ms? Yes, it makes sense to me to increase the delay from 100 to 200 ms based on the clear example that was not covered by the current time limit. - Jouni
diff --git a/wpa_supplicant/events.c b/wpa_supplicant/events.c index 61390335d..763317999 100644 --- a/wpa_supplicant/events.c +++ b/wpa_supplicant/events.c @@ -2374,7 +2374,7 @@ static void wpa_supplicant_event_assoc(struct wpa_supplicant *wpa_s, struct os_reltime now, age; os_get_reltime(&now); os_reltime_sub(&now, &wpa_s->pending_eapol_rx_time, &age); - if (age.sec == 0 && age.usec < 100000 && + if (age.sec == 0 && age.usec < 900000 && os_memcmp(wpa_s->pending_eapol_rx_src, bssid, ETH_ALEN) == 0) { wpa_dbg(wpa_s, MSG_DEBUG, "Process pending EAPOL "