security/wpa_supplicant: Reassoc on NWID change

classic Classic list List threaded Threaded
16 messages Options
Reply | Threaded
Open this post in threaded view
|

security/wpa_supplicant: Reassoc on NWID change

Gregor Best-2

Hi David and ports@,

I've built a little patch to security/wpa_supplicant that lets it listen to
changes in the associated network SSID (thanks to Ken's RTM_80211INFO) and
reassociate itself.

This essentially means that now you can run `wpa_supplicant` in the background
and configure e.g. eduroam like `ifconfig iwm0 join eduroam wpaakms 802.1x`
without having to manually kick wpa_supplicant by restarting it or running
`wpa_cli reassoc`.

I'll be out of range of my usual eduroam access points until next week, so I
haven't tested this beyond "wpa_supplicant doesn't crash and it tries to reassoc
if the NWID changes".

I'd be really grateful if a few of you who do run wpa_supplicant for wireless
802.1x networks could give this a spin. All that's needed is applying the patch
below my signature to `/usr/ports/security/wpa_supplicant` and running `make
reinstall`.

--
        Gregor

Index: patches/patch-src_drivers_driver_openbsd_c
===================================================================
RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
retrieving revision 1.5
diff -u -p -u -r1.5 patch-src_drivers_driver_openbsd_c
--- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
+++ patches/patch-src_drivers_driver_openbsd_c 20 Nov 2018 17:59:00 -0000
@@ -2,23 +2,130 @@ $OpenBSD: patch-src_drivers_driver_openb

 Fix includes

---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
-+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
-@@ -9,13 +9,14 @@
+Index: src/drivers/driver_openbsd.c
+--- src/drivers/driver_openbsd.c.orig
++++ src/drivers/driver_openbsd.c
+@@ -9,19 +9,31 @@
  #include "includes.h"
  #include <sys/ioctl.h>

 +#include "common.h"
 +#include "driver.h"
++#include "eloop.h"
 +
++#include <sys/socket.h>
  #include <net/if.h>
 +#include <net/if_var.h>
++#include <net/route.h>
  #include <net80211/ieee80211.h>
  #include <net80211/ieee80211_crypto.h>
  #include <net80211/ieee80211_ioctl.h>
--
+
 -#include "common.h"
 -#include "driver.h"
++#define RTM_READSZ 2048

  struct openbsd_driver_data {
- char ifname[IFNAMSIZ + 1];
+- char ifname[IFNAMSIZ + 1];
+ void *ctx;
+
+- int sock; /* open socket for 802.11 ioctls */
++ char ifname[IFNAMSIZ + 1];
++ int ifindex;  /* Ifindex of the configured interface */
++
++ int sock;     /* open socket for 802.11 ioctls */
++ int rtsock;   /* routing socket for interface state messages */
++
++ int nwid_len; /* Length of last seen SSID (as per routing message) */
++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
+ };
+
+
+@@ -90,6 +102,54 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
+ return 0;
+ }
+
++static void
++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
++{
++ struct openbsd_driver_data *drv = sock_ctx;
++ struct rt_msghdr *rtm;
++ struct if_ieee80211_data *ifie;
++ char *rtmmsg;
++ ssize_t n;
++
++ rtmmsg = os_zalloc(RTM_READSZ);
++ if (rtmmsg == NULL) {
++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
++ return;
++ }
++
++ do {
++ n = read(sock, rtmmsg, RTM_READSZ);
++ } while (n == -1 && errno == EINTR);
++
++ if (n == -1)
++ goto done;
++
++ rtm = (struct rt_msghdr *)rtmmsg;
++
++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
++    n < rtm->rtm_msglen ||
++    rtm->rtm_version != RTM_VERSION)
++ goto done;
++
++ if ((rtm->rtm_type != RTM_80211INFO) ||
++    (rtm->rtm_index != drv->ifindex))
++ goto done;
++
++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
++
++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0)) {
++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
++ drv->nwid_len = ifie->ifie_nwid_len;
++
++ /* Emit ASSOC event */
++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
++ }
++
++done:
++ os_free(rtmmsg);
++}
++
+ static void *
+ wpa_driver_openbsd_init(void *ctx, const char *ifname)
+ {
+@@ -103,9 +163,20 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
+ if (drv->sock < 0)
+ goto fail;
+
++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
++ if (drv->rtsock < 0)
++ goto fail;
++
+ drv->ctx = ctx;
+ os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
+
++ drv->ifindex = if_nametoindex(drv->ifname);
++ if (drv->ifindex == 0) /* No interface with that name */
++ goto fail;
++
++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
++
++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
+ return drv;
+
+ fail:
+@@ -119,7 +190,11 @@ wpa_driver_openbsd_deinit(void *priv)
+ {
+ struct openbsd_driver_data *drv = priv;
+
++ eloop_unregister_read_sock(drv->rtsock);
++
+ close(drv->sock);
++ close(drv->rtsock);
++
+ os_free(drv);
+ }
+

signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Gregor Best-2
Peter Hessler <[hidden email]> writes:

> This looks really cool, thank you for looking at it!
>
> One thing that you may also need, is to may also need to reassoc when
> the bssid changes (roaming between different APs).  Can you also test
> that when you do your join testing?
> [...]

Good call. That does turn out to be necessary, so I've amended my
original patch. An updated patch is attached below my signature.

I've tested this with a two-AP 802.1x network now, but since the APs are
more or less sitting on top of each other, I can't really move out of
range of only one of them to test organic handover. I've emulated that
by adding the SSID to my `iwm0`'s joinlist and manually exchanging the
BSSID.

I'll try to see if I can squeeze in some time at my local eduroam
network tomorrow to check out how this works in the "I got out of range
of one AP and the kernel switched me over to another"-scenario.

--
        Gregor

Index: patches/patch-src_drivers_driver_openbsd_c
===================================================================
RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
retrieving revision 1.5
diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
--- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
+++ patches/patch-src_drivers_driver_openbsd_c 28 Nov 2018 17:51:30 -0000
@@ -2,23 +2,137 @@ $OpenBSD: patch-src_drivers_driver_openb
 
 Fix includes
 
---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
-+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
-@@ -9,13 +9,14 @@
+Index: src/drivers/driver_openbsd.c
+--- src/drivers/driver_openbsd.c.orig
++++ src/drivers/driver_openbsd.c
+@@ -9,19 +9,34 @@
  #include "includes.h"
  #include <sys/ioctl.h>
 
 +#include "common.h"
 +#include "driver.h"
++#include "eloop.h"
 +
++#include <sys/socket.h>
  #include <net/if.h>
 +#include <net/if_var.h>
++#include <net/route.h>
  #include <net80211/ieee80211.h>
  #include <net80211/ieee80211_crypto.h>
  #include <net80211/ieee80211_ioctl.h>
--
+
 -#include "common.h"
 -#include "driver.h"
++#define RTM_READSZ 2048
 
  struct openbsd_driver_data {
- char ifname[IFNAMSIZ + 1];
+- char ifname[IFNAMSIZ + 1];
+ void *ctx;
+
+- int sock; /* open socket for 802.11 ioctls */
++ char ifname[IFNAMSIZ + 1];
++ int ifindex;  /* Ifindex of the configured interface */
++
++ int sock;     /* open socket for 802.11 ioctls */
++ int rtsock;   /* routing socket for interface state messages */
++
++ /* These fields are used to track the last seen (and associated) access point
++   to determine whether we should kick off an association event */
++ int nwid_len; /* Length of last seen SSID (as per routing message) */
++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
+ };
+
+
+@@ -90,6 +105,57 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
+ return 0;
+ }
+
++static void
++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
++{
++ struct openbsd_driver_data *drv = sock_ctx;
++ struct rt_msghdr *rtm;
++ struct if_ieee80211_data *ifie;
++ char *rtmmsg;
++ ssize_t n;
++
++ rtmmsg = os_zalloc(RTM_READSZ);
++ if (rtmmsg == NULL) {
++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
++ return;
++ }
++
++ do {
++ n = read(sock, rtmmsg, RTM_READSZ);
++ } while (n == -1 && errno == EINTR);
++
++ if (n == -1)
++ goto done;
++
++ rtm = (struct rt_msghdr *)rtmmsg;
++
++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
++    n < rtm->rtm_msglen ||
++    rtm->rtm_version != RTM_VERSION)
++ goto done;
++
++ if ((rtm->rtm_type != RTM_80211INFO) ||
++    (rtm->rtm_index != drv->ifindex))
++ goto done;
++
++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
++
++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
++    (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
++ os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
++
++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
++ drv->nwid_len = ifie->ifie_nwid_len;
++
++ /* Emit ASSOC event */
++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
++ }
++
++done:
++ os_free(rtmmsg);
++}
++
+ static void *
+ wpa_driver_openbsd_init(void *ctx, const char *ifname)
+ {
+@@ -103,9 +169,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
+ if (drv->sock < 0)
+ goto fail;
+
++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
++ if (drv->rtsock < 0)
++ goto fail;
++
+ drv->ctx = ctx;
+ os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
+
++ drv->ifindex = if_nametoindex(drv->ifname);
++ if (drv->ifindex == 0) /* No interface with that name */
++ goto fail;
++
++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
++
++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
+ return drv;
+
+ fail:
+@@ -119,7 +197,11 @@ wpa_driver_openbsd_deinit(void *priv)
+ {
+ struct openbsd_driver_data *drv = priv;
+
++ eloop_unregister_read_sock(drv->rtsock);
++
+ close(drv->sock);
++ close(drv->rtsock);
++
+ os_free(drv);
+ }
+

signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Peter Hessler
On 2018 Nov 28 (Wed) at 18:56:46 +0100 (+0100), Gregor Best wrote:
:Peter Hessler <[hidden email]> writes:
:
:> This looks really cool, thank you for looking at it!
:>
:> One thing that you may also need, is to may also need to reassoc when
:> the bssid changes (roaming between different APs).  Can you also test
:> that when you do your join testing?
:> [...]
:
:Good call. That does turn out to be necessary, so I've amended my
:original patch. An updated patch is attached below my signature.
:
:I've tested this with a two-AP 802.1x network now, but since the APs are
:more or less sitting on top of each other, I can't really move out of
:range of only one of them to test organic handover. I've emulated that
:by adding the SSID to my `iwm0`'s joinlist and manually exchanging the
:BSSID.
:
:I'll try to see if I can squeeze in some time at my local eduroam
:network tomorrow to check out how this works in the "I got out of range
:of one AP and the kernel switched me over to another"-scenario.
:
:--
: Gregor
:

I'm not able to test this yet, but this looks OK to me (with a REVISION
bump, of course)


:Index: patches/patch-src_drivers_driver_openbsd_c
:===================================================================
:RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
:retrieving revision 1.5
:diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
:--- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
:+++ patches/patch-src_drivers_driver_openbsd_c 28 Nov 2018 17:51:30 -0000
:@@ -2,23 +2,137 @@ $OpenBSD: patch-src_drivers_driver_openb
:
: Fix includes
:
:---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
:-+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
:-@@ -9,13 +9,14 @@
:+Index: src/drivers/driver_openbsd.c
:+--- src/drivers/driver_openbsd.c.orig
:++++ src/drivers/driver_openbsd.c
:+@@ -9,19 +9,34 @@
:  #include "includes.h"
:  #include <sys/ioctl.h>
:  
: +#include "common.h"
: +#include "driver.h"
:++#include "eloop.h"
: +
:++#include <sys/socket.h>
:  #include <net/if.h>
: +#include <net/if_var.h>
:++#include <net/route.h>
:  #include <net80211/ieee80211.h>
:  #include <net80211/ieee80211_crypto.h>
:  #include <net80211/ieee80211_ioctl.h>
:--
:+
: -#include "common.h"
: -#include "driver.h"
:++#define RTM_READSZ 2048
:  
:  struct openbsd_driver_data {
:- char ifname[IFNAMSIZ + 1];
:+- char ifname[IFNAMSIZ + 1];
:+ void *ctx;
:+
:+- int sock; /* open socket for 802.11 ioctls */
:++ char ifname[IFNAMSIZ + 1];
:++ int ifindex;  /* Ifindex of the configured interface */
:++
:++ int sock;     /* open socket for 802.11 ioctls */
:++ int rtsock;   /* routing socket for interface state messages */
:++
:++ /* These fields are used to track the last seen (and associated) access point
:++   to determine whether we should kick off an association event */
:++ int nwid_len; /* Length of last seen SSID (as per routing message) */
:++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
:++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
:+ };
:+
:+
:+@@ -90,6 +105,57 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
:+ return 0;
:+ }
:+
:++static void
:++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
:++{
:++ struct openbsd_driver_data *drv = sock_ctx;
:++ struct rt_msghdr *rtm;
:++ struct if_ieee80211_data *ifie;
:++ char *rtmmsg;
:++ ssize_t n;
:++
:++ rtmmsg = os_zalloc(RTM_READSZ);
:++ if (rtmmsg == NULL) {
:++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
:++ return;
:++ }
:++
:++ do {
:++ n = read(sock, rtmmsg, RTM_READSZ);
:++ } while (n == -1 && errno == EINTR);
:++
:++ if (n == -1)
:++ goto done;
:++
:++ rtm = (struct rt_msghdr *)rtmmsg;
:++
:++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
:++    n < rtm->rtm_msglen ||
:++    rtm->rtm_version != RTM_VERSION)
:++ goto done;
:++
:++ if ((rtm->rtm_type != RTM_80211INFO) ||
:++    (rtm->rtm_index != drv->ifindex))
:++ goto done;
:++
:++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
:++
:++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
:++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
:++    (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
:++ os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
:++
:++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
:++ drv->nwid_len = ifie->ifie_nwid_len;
:++
:++ /* Emit ASSOC event */
:++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
:++ }
:++
:++done:
:++ os_free(rtmmsg);
:++}
:++
:+ static void *
:+ wpa_driver_openbsd_init(void *ctx, const char *ifname)
:+ {
:+@@ -103,9 +169,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
:+ if (drv->sock < 0)
:+ goto fail;
:+
:++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
:++ if (drv->rtsock < 0)
:++ goto fail;
:++
:+ drv->ctx = ctx;
:+ os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
:+
:++ drv->ifindex = if_nametoindex(drv->ifname);
:++ if (drv->ifindex == 0) /* No interface with that name */
:++ goto fail;
:++
:++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
:++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
:++
:++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
:+ return drv;
:+
:+ fail:
:+@@ -119,7 +197,11 @@ wpa_driver_openbsd_deinit(void *priv)
:+ {
:+ struct openbsd_driver_data *drv = priv;
:+
:++ eloop_unregister_read_sock(drv->rtsock);
:++
:+ close(drv->sock);
:++ close(drv->rtsock);
:++
:+ os_free(drv);
:+ }
:+



--
A sine curve goes off to infinity or at least the end of the blackboard.
                -- Prof. Steiner

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Edd Barrett-3
In reply to this post by Gregor Best-2
Hi,

On Tue, Nov 20, 2018 at 07:18:37PM +0100, Gregor Best wrote:

> I've built a little patch to security/wpa_supplicant that lets it listen to
> changes in the associated network SSID (thanks to Ken's RTM_80211INFO) and
> reassociate itself.
>
> This essentially means that now you can run `wpa_supplicant` in the background
> and configure e.g. eduroam like `ifconfig iwm0 join eduroam wpaakms 802.1x`
> without having to manually kick wpa_supplicant by restarting it or running
> `wpa_cli reassoc`.
>
> I'll be out of range of my usual eduroam access points until next week, so I
> haven't tested this beyond "wpa_supplicant doesn't crash and it tries to reassoc
> if the NWID changes".

Should wpa-supplicant transition between access points on the same SSID?
At first I thought this was what this patch proposed, but I think I
misinterpreted.

--
Best Regards
Edd Barrett

http://www.theunixzoo.co.uk

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Peter Hessler
On 2018 Dec 07 (Fri) at 16:32:53 +0000 (+0000), Edd Barrett wrote:
:Hi,
:
:On Tue, Nov 20, 2018 at 07:18:37PM +0100, Gregor Best wrote:
:> I've built a little patch to security/wpa_supplicant that lets it listen to
:> changes in the associated network SSID (thanks to Ken's RTM_80211INFO) and
:> reassociate itself.
:>
:> This essentially means that now you can run `wpa_supplicant` in the background
:> and configure e.g. eduroam like `ifconfig iwm0 join eduroam wpaakms 802.1x`
:> without having to manually kick wpa_supplicant by restarting it or running
:> `wpa_cli reassoc`.
:>
:> I'll be out of range of my usual eduroam access points until next week, so I
:> haven't tested this beyond "wpa_supplicant doesn't crash and it tries to reassoc
:> if the NWID changes".
:
:Should wpa-supplicant transition between access points on the same SSID?
:At first I thought this was what this patch proposed, but I think I
:misinterpreted.
:

Yes, it needs to negotiate with every AP (BSSID) that it connects to,
even if it is the same ESSID.


--
This sentence contradicts itself -- no actually it doesn't.
                -- Hofstadter

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Mikolaj Kucharski-3
In reply to this post by Gregor Best-2
Hi Gregor,

I've tested your diff in recent days and in my case most often
when I change the physical location (and hence AP) I put my
laptop into suspend. I've noticed that with your diff wpa
supplicant is not abble to reassoc to the AP on resume. However
it looks to me more like wpa supplicant problem than your diff.

It ends up in infinite loop of:

1544442781.550029: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442781.550061: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1544442781.550103: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
1544442786.575010: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442786.575042: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1544442786.575085: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
1544442791.593955: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442791.593986: RX EAPOL - hexdump(len=46): 01 00 00 05 01 02 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1544442791.594030: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
1544442796.618836: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442796.618867: RX EAPOL - hexdump(len=46): 01 00 00 05 01 02 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1544442796.618910: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
1544442801.641262: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442801.641293: RX EAPOL - hexdump(len=46): 01 00 00 05 01 02 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1544442801.641335: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
1544442806.684327: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442806.684358: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1544442806.684402: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
1544442811.738381: iwn0: RX EAPOL from 04:bd:88:4a:11:50
1544442811.738412: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

in the same time iwn0 interface shows:

        status: no network
        ieee80211: join lighthouse chan 132 bssid 04:bd:88:4a:31:50 -52dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp

bssid is visible, however status is no network. I also should mention, that
the problem of reassociating to AP after resume works sometimes.

However, I can say I don't see any negative effects from your diff, as problem
of reassociation after resume was always there with wpa supplicant.

Regards,
 Mikolaj

On Wed, Nov 28, 2018 at 06:56:46PM +0100, Gregor Best wrote:

> Peter Hessler <[hidden email]> writes:
>
> > This looks really cool, thank you for looking at it!
> >
> > One thing that you may also need, is to may also need to reassoc when
> > the bssid changes (roaming between different APs).  Can you also test
> > that when you do your join testing?
> > [...]
>
> Good call. That does turn out to be necessary, so I've amended my
> original patch. An updated patch is attached below my signature.
>
> I've tested this with a two-AP 802.1x network now, but since the APs are
> more or less sitting on top of each other, I can't really move out of
> range of only one of them to test organic handover. I've emulated that
> by adding the SSID to my `iwm0`'s joinlist and manually exchanging the
> BSSID.
>
> I'll try to see if I can squeeze in some time at my local eduroam
> network tomorrow to check out how this works in the "I got out of range
> of one AP and the kernel switched me over to another"-scenario.
>
> --
> Gregor
>
> Index: patches/patch-src_drivers_driver_openbsd_c
> ===================================================================
> RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
> retrieving revision 1.5
> diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
> --- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
> +++ patches/patch-src_drivers_driver_openbsd_c 28 Nov 2018 17:51:30 -0000
> @@ -2,23 +2,137 @@ $OpenBSD: patch-src_drivers_driver_openb
>  
>  Fix includes
>  
> ---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
> -+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
> -@@ -9,13 +9,14 @@
> +Index: src/drivers/driver_openbsd.c
> +--- src/drivers/driver_openbsd.c.orig
> ++++ src/drivers/driver_openbsd.c
> +@@ -9,19 +9,34 @@
>   #include "includes.h"
>   #include <sys/ioctl.h>
>  
>  +#include "common.h"
>  +#include "driver.h"
> ++#include "eloop.h"
>  +
> ++#include <sys/socket.h>
>   #include <net/if.h>
>  +#include <net/if_var.h>
> ++#include <net/route.h>
>   #include <net80211/ieee80211.h>
>   #include <net80211/ieee80211_crypto.h>
>   #include <net80211/ieee80211_ioctl.h>
> --
> +
>  -#include "common.h"
>  -#include "driver.h"
> ++#define RTM_READSZ 2048
>  
>   struct openbsd_driver_data {
> - char ifname[IFNAMSIZ + 1];
> +- char ifname[IFNAMSIZ + 1];
> + void *ctx;
> +
> +- int sock; /* open socket for 802.11 ioctls */
> ++ char ifname[IFNAMSIZ + 1];
> ++ int ifindex;  /* Ifindex of the configured interface */
> ++
> ++ int sock;     /* open socket for 802.11 ioctls */
> ++ int rtsock;   /* routing socket for interface state messages */
> ++
> ++ /* These fields are used to track the last seen (and associated) access point
> ++   to determine whether we should kick off an association event */
> ++ int nwid_len; /* Length of last seen SSID (as per routing message) */
> ++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
> ++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
> + };
> +
> +
> +@@ -90,6 +105,57 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
> + return 0;
> + }
> +
> ++static void
> ++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
> ++{
> ++ struct openbsd_driver_data *drv = sock_ctx;
> ++ struct rt_msghdr *rtm;
> ++ struct if_ieee80211_data *ifie;
> ++ char *rtmmsg;
> ++ ssize_t n;
> ++
> ++ rtmmsg = os_zalloc(RTM_READSZ);
> ++ if (rtmmsg == NULL) {
> ++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
> ++ return;
> ++ }
> ++
> ++ do {
> ++ n = read(sock, rtmmsg, RTM_READSZ);
> ++ } while (n == -1 && errno == EINTR);
> ++
> ++ if (n == -1)
> ++ goto done;
> ++
> ++ rtm = (struct rt_msghdr *)rtmmsg;
> ++
> ++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
> ++    n < rtm->rtm_msglen ||
> ++    rtm->rtm_version != RTM_VERSION)
> ++ goto done;
> ++
> ++ if ((rtm->rtm_type != RTM_80211INFO) ||
> ++    (rtm->rtm_index != drv->ifindex))
> ++ goto done;
> ++
> ++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
> ++
> ++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
> ++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
> ++    (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
> ++ os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
> ++
> ++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
> ++ drv->nwid_len = ifie->ifie_nwid_len;
> ++
> ++ /* Emit ASSOC event */
> ++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
> ++ }
> ++
> ++done:
> ++ os_free(rtmmsg);
> ++}
> ++
> + static void *
> + wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + {
> +@@ -103,9 +169,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + if (drv->sock < 0)
> + goto fail;
> +
> ++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
> ++ if (drv->rtsock < 0)
> ++ goto fail;
> ++
> + drv->ctx = ctx;
> + os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
> +
> ++ drv->ifindex = if_nametoindex(drv->ifname);
> ++ if (drv->ifindex == 0) /* No interface with that name */
> ++ goto fail;
> ++
> ++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
> ++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
> ++
> ++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
> + return drv;
> +
> + fail:
> +@@ -119,7 +197,11 @@ wpa_driver_openbsd_deinit(void *priv)
> + {
> + struct openbsd_driver_data *drv = priv;
> +
> ++ eloop_unregister_read_sock(drv->rtsock);
> ++
> + close(drv->sock);
> ++ close(drv->rtsock);
> ++
> + os_free(drv);
> + }
> +


Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Raf Czlonka-2
Hi Gregor,

When I boot my laptop up, it connects to eduroam just fine.

However, when I move around the building, it does not associate
with any other AP.

I can't even make it associate if I manually run:

        sh /etc/netstart

While running wpa_cli(8) in another tmux(1) window, I see a constant
stream of:

        <3>CTRL-EVENT-DISCONNECTED bssid=12:34:56:ab:cd:ef reason=3 locally_generated=1
        <3>CTRL-EVENT-SUBNET-STATUS-UPDATE status=0

I don't think this is related to wpa_supplicant(8) but mentioning
it here just in case.

In order to be able to associate with any other IP, I have to run:

        ifconfig urtwn0 -nwid

Only then does the laptop reconnect.

I thought that I'll be able to simply use:

        ifconfig urtwn0 -joinlist

followed by:

        sh /etc/netstart

but, after I run the '-joinlist' option, I see this in ifconfig(8)
output:

        ieee80211: nwid eduroam chan 1 bssid 12:34:56:ab:cd:ef -76dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp

This seemed a bit strange since I don't use 'nwid' anywhere in my
hostname.if file - only 'join' - but I guess this is how 'join'
works "under the hood"(?).

To sum it up, unfortunately, the diff doesn't work for me.

Regards,

Raf

On Mon, Dec 10, 2018 at 02:07:32PM GMT, Mikolaj Kucharski wrote:

> Hi Gregor,
>
> I've tested your diff in recent days and in my case most often
> when I change the physical location (and hence AP) I put my
> laptop into suspend. I've noticed that with your diff wpa
> supplicant is not abble to reassoc to the AP on resume. However
> it looks to me more like wpa supplicant problem than your diff.
>
> It ends up in infinite loop of:
>
> 1544442781.550029: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442781.550061: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> 1544442781.550103: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
> 1544442786.575010: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442786.575042: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> 1544442786.575085: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
> 1544442791.593955: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442791.593986: RX EAPOL - hexdump(len=46): 01 00 00 05 01 02 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> 1544442791.594030: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
> 1544442796.618836: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442796.618867: RX EAPOL - hexdump(len=46): 01 00 00 05 01 02 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> 1544442796.618910: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
> 1544442801.641262: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442801.641293: RX EAPOL - hexdump(len=46): 01 00 00 05 01 02 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> 1544442801.641335: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
> 1544442806.684327: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442806.684358: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> 1544442806.684402: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=6c:f3:7f:d6:5e:f0)
> 1544442811.738381: iwn0: RX EAPOL from 04:bd:88:4a:11:50
> 1544442811.738412: RX EAPOL - hexdump(len=46): 01 00 00 05 01 01 00 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>
> in the same time iwn0 interface shows:
>
> status: no network
> ieee80211: join lighthouse chan 132 bssid 04:bd:88:4a:31:50 -52dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp
>
> bssid is visible, however status is no network. I also should mention, that
> the problem of reassociating to AP after resume works sometimes.
>
> However, I can say I don't see any negative effects from your diff, as problem
> of reassociation after resume was always there with wpa supplicant.
>
> Regards,
>  Mikolaj
>
> On Wed, Nov 28, 2018 at 06:56:46PM +0100, Gregor Best wrote:
> > Peter Hessler <[hidden email]> writes:
> >
> > > This looks really cool, thank you for looking at it!
> > >
> > > One thing that you may also need, is to may also need to reassoc when
> > > the bssid changes (roaming between different APs).  Can you also test
> > > that when you do your join testing?
> > > [...]
> >
> > Good call. That does turn out to be necessary, so I've amended my
> > original patch. An updated patch is attached below my signature.
> >
> > I've tested this with a two-AP 802.1x network now, but since the APs are
> > more or less sitting on top of each other, I can't really move out of
> > range of only one of them to test organic handover. I've emulated that
> > by adding the SSID to my `iwm0`'s joinlist and manually exchanging the
> > BSSID.
> >
> > I'll try to see if I can squeeze in some time at my local eduroam
> > network tomorrow to check out how this works in the "I got out of range
> > of one AP and the kernel switched me over to another"-scenario.
> >
> > --
> > Gregor
> >
> > Index: patches/patch-src_drivers_driver_openbsd_c
> > ===================================================================
> > RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
> > retrieving revision 1.5
> > diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
> > --- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
> > +++ patches/patch-src_drivers_driver_openbsd_c 28 Nov 2018 17:51:30 -0000
> > @@ -2,23 +2,137 @@ $OpenBSD: patch-src_drivers_driver_openb
> >  
> >  Fix includes
> >  
> > ---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
> > -+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
> > -@@ -9,13 +9,14 @@
> > +Index: src/drivers/driver_openbsd.c
> > +--- src/drivers/driver_openbsd.c.orig
> > ++++ src/drivers/driver_openbsd.c
> > +@@ -9,19 +9,34 @@
> >   #include "includes.h"
> >   #include <sys/ioctl.h>
> >  
> >  +#include "common.h"
> >  +#include "driver.h"
> > ++#include "eloop.h"
> >  +
> > ++#include <sys/socket.h>
> >   #include <net/if.h>
> >  +#include <net/if_var.h>
> > ++#include <net/route.h>
> >   #include <net80211/ieee80211.h>
> >   #include <net80211/ieee80211_crypto.h>
> >   #include <net80211/ieee80211_ioctl.h>
> > --
> > +
> >  -#include "common.h"
> >  -#include "driver.h"
> > ++#define RTM_READSZ 2048
> >  
> >   struct openbsd_driver_data {
> > - char ifname[IFNAMSIZ + 1];
> > +- char ifname[IFNAMSIZ + 1];
> > + void *ctx;
> > +
> > +- int sock; /* open socket for 802.11 ioctls */
> > ++ char ifname[IFNAMSIZ + 1];
> > ++ int ifindex;  /* Ifindex of the configured interface */
> > ++
> > ++ int sock;     /* open socket for 802.11 ioctls */
> > ++ int rtsock;   /* routing socket for interface state messages */
> > ++
> > ++ /* These fields are used to track the last seen (and associated) access point
> > ++   to determine whether we should kick off an association event */
> > ++ int nwid_len; /* Length of last seen SSID (as per routing message) */
> > ++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
> > ++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
> > + };
> > +
> > +
> > +@@ -90,6 +105,57 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
> > + return 0;
> > + }
> > +
> > ++static void
> > ++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
> > ++{
> > ++ struct openbsd_driver_data *drv = sock_ctx;
> > ++ struct rt_msghdr *rtm;
> > ++ struct if_ieee80211_data *ifie;
> > ++ char *rtmmsg;
> > ++ ssize_t n;
> > ++
> > ++ rtmmsg = os_zalloc(RTM_READSZ);
> > ++ if (rtmmsg == NULL) {
> > ++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
> > ++ return;
> > ++ }
> > ++
> > ++ do {
> > ++ n = read(sock, rtmmsg, RTM_READSZ);
> > ++ } while (n == -1 && errno == EINTR);
> > ++
> > ++ if (n == -1)
> > ++ goto done;
> > ++
> > ++ rtm = (struct rt_msghdr *)rtmmsg;
> > ++
> > ++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
> > ++    n < rtm->rtm_msglen ||
> > ++    rtm->rtm_version != RTM_VERSION)
> > ++ goto done;
> > ++
> > ++ if ((rtm->rtm_type != RTM_80211INFO) ||
> > ++    (rtm->rtm_index != drv->ifindex))
> > ++ goto done;
> > ++
> > ++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
> > ++
> > ++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
> > ++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
> > ++    (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
> > ++ os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
> > ++
> > ++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
> > ++ drv->nwid_len = ifie->ifie_nwid_len;
> > ++
> > ++ /* Emit ASSOC event */
> > ++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
> > ++ }
> > ++
> > ++done:
> > ++ os_free(rtmmsg);
> > ++}
> > ++
> > + static void *
> > + wpa_driver_openbsd_init(void *ctx, const char *ifname)
> > + {
> > +@@ -103,9 +169,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
> > + if (drv->sock < 0)
> > + goto fail;
> > +
> > ++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
> > ++ if (drv->rtsock < 0)
> > ++ goto fail;
> > ++
> > + drv->ctx = ctx;
> > + os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
> > +
> > ++ drv->ifindex = if_nametoindex(drv->ifname);
> > ++ if (drv->ifindex == 0) /* No interface with that name */
> > ++ goto fail;
> > ++
> > ++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
> > ++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
> > ++
> > ++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
> > + return drv;
> > +
> > + fail:
> > +@@ -119,7 +197,11 @@ wpa_driver_openbsd_deinit(void *priv)
> > + {
> > + struct openbsd_driver_data *drv = priv;
> > +
> > ++ eloop_unregister_read_sock(drv->rtsock);
> > ++
> > + close(drv->sock);
> > ++ close(drv->rtsock);
> > ++
> > + os_free(drv);
> > + }
> > +
>
>

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Mikolaj Kucharski-3
In reply to this post by Gregor Best-2
Hi Gregor,

I've looked into this more and from debugging perspective.
I've added wpa_printf(MSG_DEBUG, "XXX ...") statements
to the top of each function in src/drivers/driver_openbsd.c
and also one additional just before wpa_supplicant_event()
inside an if() statement. That was mostly for me so I know
I'm definately running your code and to understand better
flow of the code.

As I said in my previous email, after suspend/resume wpa
supplicant doesn't reassociate with AP and wireless interface
ends up in state:

        status: no network
        ieee80211: join lighthouse chan 100 bssid 6c:f3:7f:d6:5e:f0 -47dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp


However by running `wpa_cli reassoc` wpa supplicant triggers
reassociation and successfully authenticates to the network:

        status: active
        ieee80211: join lighthouse chan 100 bssid 6c:f3:7f:d6:5e:f0 -47dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp


Here is full log, just before the suspend, resume and then waiting a bit
without successful auth to the network and then manual `wpa_cli reassoc`:


# /usr/local/sbin/wpa_supplicant -c /etc/wpa_supplicant.conf -D openbsd -i iwn0 -dd -t | \
        sed -e 's/^\(.*\) hexdump(len=[0-9][0-9]*): .*/\1 hexdump XXX REMOVED XXX/'
...
1544451783.290841: XXX wpa_driver_openbsd_event_receive() start
1544451783.356712: XXX wpa_driver_openbsd_event_receive() start
1544451783.356800: XXX wpa_driver_openbsd_event_receive() start
1544451783.356888: XXX wpa_driver_openbsd_event_receive() start
1544451783.356920: XXX wpa_driver_openbsd_event_receive() start
1544451783.356951: XXX wpa_driver_openbsd_event_receive() start
1544451783.357106: XXX wpa_driver_openbsd_event_receive() start
1544451783.357133: XXX wpa_driver_openbsd_event_receive() start
1544451783.357591: XXX wpa_driver_openbsd_event_receive() start
1544451784.223351: XXX wpa_driver_openbsd_event_receive() start
1544451784.245911: XXX wpa_driver_openbsd_event_receive() start
1544451784.397337: XXX wpa_driver_openbsd_event_receive() start
1544451785.410632: XXX wpa_driver_openbsd_event_receive() start
1544451786.417586: XXX wpa_driver_openbsd_event_receive() start
1544451791.519192: XXX wpa_driver_openbsd_event_receive() start
1544451812.501002: EAPOL: authWhile --> 0
1544451812.501016: EAPOL: startWhen --> 0
1544451843.640493: EAPOL: idleWhile --> 0
1544451843.640512: EAPOL: disable timer tick
1544452119.960234: XXX wpa_driver_openbsd_event_receive() start
1544452161.423999: XXX wpa_driver_openbsd_event_receive() start
1544452698.636069: XXX wpa_driver_openbsd_event_receive() start
1544452756.315182: XXX wpa_driver_openbsd_event_receive() start
1544452987.451435: XXX wpa_driver_openbsd_event_receive() start
1544454186.334245: XXX wpa_driver_openbsd_event_receive() start
1544454193.706468: XXX wpa_driver_openbsd_event_receive() start
1544455323.097838: XXX wpa_driver_openbsd_event_receive() start
1544455383.622915: XXX wpa_driver_openbsd_event_receive() start
1544455402.771107: XXX wpa_driver_openbsd_event_receive() start
1544456602.822885: XXX wpa_driver_openbsd_event_receive() start
1544458081.366761: XXX wpa_driver_openbsd_event_receive() start
1544458983.952662: XXX wpa_driver_openbsd_event_receive() start
1544458986.638529: XXX wpa_driver_openbsd_event_receive() start
1544459085.039967: XXX wpa_driver_openbsd_event_receive() start
1544459387.326189: XXX wpa_driver_openbsd_event_receive() start
1544460486.671975: XXX wpa_driver_openbsd_event_receive() start
1544460590.428104: XXX wpa_driver_openbsd_event_receive() start
1544461790.147951: XXX wpa_driver_openbsd_event_receive() start
1544462584.084171: XXX wpa_driver_openbsd_event_receive() start
1544463018.143647: XXX wpa_driver_openbsd_event_receive() start
1544464023.572019: XXX wpa_driver_openbsd_event_receive() start
1544464221.649357: XXX wpa_driver_openbsd_event_receive() start
1544465286.802092: XXX wpa_driver_openbsd_event_receive() start
1544465439.921320: XXX wpa_driver_openbsd_event_receive() start
// laptop suspended and then resumed between those lines
1544514315.067941: XXX wpa_driver_openbsd_event_receive() start
1544514315.067960: XXX wpa_driver_openbsd_event_receive() start
1544514315.067973: XXX wpa_driver_openbsd_event_receive() start
1544514315.067984: XXX wpa_driver_openbsd_event_receive() start
1544514315.068605: XXX wpa_driver_openbsd_event_receive() start
1544514315.068619: XXX wpa_driver_openbsd_event_receive() start
1544514315.085484: XXX wpa_driver_openbsd_event_receive() start
1544514315.085502: XXX wpa_driver_openbsd_event_receive() start
1544514318.914662: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514318.914684: RX EAPOL - hexdump XXX REMOVED XXX
1544514318.914699: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514323.896880: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514323.896911: RX EAPOL - hexdump XXX REMOVED XXX
1544514323.896926: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514328.910056: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514328.910084: RX EAPOL - hexdump XXX REMOVED XXX
1544514328.910125: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514333.924341: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514333.924366: RX EAPOL - hexdump XXX REMOVED XXX
1544514333.924408: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514338.942072: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514338.942099: RX EAPOL - hexdump XXX REMOVED XXX
1544514338.942140: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514343.957116: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514343.957156: RX EAPOL - hexdump XXX REMOVED XXX
1544514343.957201: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514349.056369: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514349.056395: RX EAPOL - hexdump XXX REMOVED XXX
1544514349.056436: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514353.989536: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514353.989571: RX EAPOL - hexdump XXX REMOVED XXX
1544514353.989613: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514359.003678: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514359.003711: RX EAPOL - hexdump XXX REMOVED XXX
1544514359.003753: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514364.017571: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514364.017603: RX EAPOL - hexdump XXX REMOVED XXX
1544514364.017645: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514369.031546: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514369.031578: RX EAPOL - hexdump XXX REMOVED XXX
1544514369.031622: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514374.047301: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514374.047332: RX EAPOL - hexdump XXX REMOVED XXX
1544514374.047374: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514379.148281: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514379.148312: RX EAPOL - hexdump XXX REMOVED XXX
1544514379.148355: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514384.079507: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514384.079541: RX EAPOL - hexdump XXX REMOVED XXX
1544514384.079584: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514389.095138: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514389.095168: RX EAPOL - hexdump XXX REMOVED XXX
1544514389.095210: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514394.109269: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514394.109362: RX EAPOL - hexdump XXX REMOVED XXX
1544514394.109414: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514399.123788: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514399.123818: RX EAPOL - hexdump XXX REMOVED XXX
1544514399.123868: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514404.138785: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514404.138817: RX EAPOL - hexdump XXX REMOVED XXX
1544514404.138859: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514409.239975: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514409.240002: RX EAPOL - hexdump XXX REMOVED XXX
1544514409.240044: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514414.188634: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514414.188664: RX EAPOL - hexdump XXX REMOVED XXX
1544514414.188706: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514419.188759: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514419.188790: RX EAPOL - hexdump XXX REMOVED XXX
1544514419.188833: iwn0: Not associated - Delay processing of received EAPOL frame (state=COMPLETED bssid=04:bd:88:4a:11:50)
1544514423.823352: iwn0: Control interface command 'REASSOCIATE'
1544514423.823431: iwn0: Setting scan request: 0.000000 sec
1544514423.823507: XXX wpa_driver_openbsd_get_ssid() start
1544514423.823537: XXX wpa_driver_openbsd_get_bssid() start
1544514423.823568: EAPOL: External notification - EAP success=0
1544514423.823592: EAPOL: External notification - EAP fail=0
1544514423.823617: EAPOL: External notification - portControl=Auto
1544514423.823675: iwn0: Already associated with a configured network - generating associated event
1544514423.823727: iwn0: Event ASSOC (0) received
1544514423.823754: iwn0: Association info event
1544514423.823779: XXX wpa_driver_openbsd_get_bssid() start
1544514423.823816: iwn0: State: COMPLETED -> ASSOCIATED
1544514423.823834: iwn0: Associated to a new BSS: BSSID=6c:f3:7f:d6:5e:f0
1544514423.823850: XXX wpa_driver_openbsd_set_key() start
1544514423.823860: XXX wpa_driver_openbsd_set_key() start
1544514423.823885: iwn0: Select network based on association information
1544514423.825026: XXX wpa_driver_openbsd_get_ssid() start
1544514423.825047: XXX wpa_driver_openbsd_get_bssid() start
1544514423.825069: iwn0: Network configuration found for the current AP
1544514423.825089: iwn0: WPA: Using WPA IE from AssocReq to set cipher suites
1544514423.825172: iwn0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 1 proto 2
1544514423.825188: iwn0: WPA: clearing AP WPA IE
1544514423.825240: iwn0: WPA: clearing AP RSN IE
1544514423.825342: iwn0: WPA: using GTK CCMP
1544514423.825358: iwn0: WPA: using PTK CCMP
1544514423.825372: iwn0: WPA: using KEY_MGMT 802.1X
1544514423.825385: WPA: Set own WPA IE default - hexdump XXX REMOVED XXX
1544514423.825472: iwn0: Failed to get scan results
1544514423.825495: EAPOL: External notification - EAP success=0
1544514423.825510: EAPOL: External notification - EAP fail=0
1544514423.825520: EAPOL: External notification - portControl=Auto
1544514423.825537: iwn0: Associated with 6c:f3:7f:d6:5e:f0
1544514423.825551: iwn0: WPA: Association event - clear replay counter
1544514423.825564: iwn0: WPA: Clear old PTK
1544514423.825576: EAPOL: External notification - portEnabled=0
1544514423.825586: EAPOL: SUPP_PAE entering state DISCONNECTED
1544514423.825606: EAPOL: Supplicant port status: Unauthorized
1544514423.825617: EAPOL: SUPP_BE entering state INITIALIZE
1544514423.825635: EAP: EAP entering state DISABLED
1544514423.825650: EAPOL: External notification - portValid=0
1544514423.825662: EAPOL: External notification - portEnabled=1
1544514423.825672: EAPOL: SUPP_PAE entering state CONNECTING
1544514423.825682: EAPOL: enable timer tick
1544514423.825695: EAPOL: SUPP_BE entering state IDLE
1544514423.825710: EAP: EAP entering state INITIALIZE
1544514423.825722: EAP: maintaining EAP method data for fast reauthentication
1544514423.825732: EAP: EAP entering state IDLE
1544514423.825753: iwn0: Setting authentication timeout: 10 sec 0 usec
1544514423.825773: iwn0: Cancelling scan request
1544514423.825784: EAPOL: External notification - portValid=1
1544514423.825798: WMM AC: Missing IEs
1544514423.825815: iwn0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
1544514424.202712: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.202740: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.202780: iwn0: Setting authentication timeout: 70 sec 0 usec
1544514424.202799: EAPOL: Received EAP-Packet frame
1544514424.202812: EAPOL: SUPP_PAE entering state RESTART
1544514424.202823: EAP: EAP entering state INITIALIZE
1544514424.202834: EAP: maintaining EAP method data for fast reauthentication
1544514424.202845: EAP: EAP entering state IDLE
1544514424.202856: EAPOL: SUPP_PAE entering state AUTHENTICATING
1544514424.202868: EAPOL: SUPP_BE entering state REQUEST
1544514424.202877: EAPOL: getSuppRsp
1544514424.202886: EAP: EAP entering state RECEIVED
1544514424.202911: EAP: Received EAP-Request id=2 method=1 vendor=0 vendorMethod=0
1544514424.202923: EAP: EAP entering state IDENTITY
1544514424.202940: iwn0: CTRL-EVENT-EAP-STARTED EAP authentication started
1544514424.202953: EAP: Status notification: started (param=)
1544514424.202969: EAP: EAP-Request Identity data - hexdump_ascii(len=0):
1544514424.202993: EAP: using real identity - hexdump_ascii(len=10):
     6d 6b 75 63 68 61 72 73 6b 69                     mkucharski      
1544514424.203038: EAP: EAP entering state SEND_RESPONSE
1544514424.203049: EAP: EAP entering state IDLE
1544514424.203064: EAPOL: SUPP_BE entering state RESPONSE
1544514424.203074: EAPOL: txSuppRsp
1544514424.203086: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.203097: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.203143: EAPOL: SUPP_BE entering state RECEIVE
1544514424.237461: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.237484: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.237522: EAPOL: Received EAP-Packet frame
1544514424.237533: EAPOL: SUPP_BE entering state REQUEST
1544514424.237587: EAPOL: getSuppRsp
1544514424.237639: EAP: EAP entering state RECEIVED
1544514424.237688: EAP: Received EAP-Request id=3 method=13 vendor=0 vendorMethod=0
1544514424.237737: EAP: EAP entering state GET_METHOD
1544514424.237783: iwn0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13
1544514424.237823: EAP: Status notification: accept proposed method (param=TLS)
1544514424.237869: EAP: Using previous method data for fast re-authentication
1544514424.237911: EAP: Initialize selected EAP method: vendor 0 method 13 (TLS)
1544514424.238246: iwn0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
1544514424.238263: EAP: EAP entering state METHOD
1544514424.238281: SSL: Received packet(len=6) - Flags 0x20
1544514424.238292: EAP-TLS: Start
1544514424.238311: SSL: (where=0x10 ret=0x1)
1544514424.238347: SSL: (where=0x1001 ret=0x1)
1544514424.238359: SSL: SSL_connect:before/connect initialization
1544514424.238666: OpenSSL: TX ver=0x303 content_type=22 (handshake/client hello)
1544514424.238682: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.238703: SSL: (where=0x1001 ret=0x1)
1544514424.238714: SSL: SSL_connect:SSLv3 write client hello A
1544514424.238879: SSL: (where=0x1002 ret=0xffffffff)
1544514424.238897: SSL: SSL_connect:error in SSLv3 read server hello A
1544514424.238913: SSL: SSL_connect - want more data
1544514424.238924: SSL: 184 bytes pending from ssl_out
1544514424.238938: SSL: 184 bytes left to be sent out (of total 184 bytes)
1544514424.238952: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718b07a6500
1544514424.238970: EAP: EAP entering state SEND_RESPONSE
1544514424.238983: EAP: EAP entering state IDLE
1544514424.238994: EAPOL: SUPP_BE entering state RESPONSE
1544514424.239004: EAPOL: txSuppRsp
1544514424.239014: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.239029: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.240217: EAPOL: SUPP_BE entering state RECEIVE
1544514424.286418: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.286442: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.286906: EAPOL: Received EAP-Packet frame
1544514424.286919: EAPOL: SUPP_BE entering state REQUEST
1544514424.286929: EAPOL: getSuppRsp
1544514424.286940: EAP: EAP entering state RECEIVED
1544514424.286964: EAP: Received EAP-Request id=4 method=13 vendor=0 vendorMethod=0
1544514424.286977: EAP: EAP entering state METHOD
1544514424.287005: SSL: Received packet(len=1034) - Flags 0xc0
1544514424.287018: SSL: TLS Message Length: 11351
1544514424.287039: SSL: Need 10327 bytes more input data
1544514424.287060: SSL: Building ACK (type=13 id=4 ver=0)
1544514424.287078: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8ce00
1544514424.287091: EAP: EAP entering state SEND_RESPONSE
1544514424.287103: EAP: EAP entering state IDLE
1544514424.287113: EAPOL: SUPP_BE entering state RESPONSE
1544514424.287122: EAPOL: txSuppRsp
1544514424.287133: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.287143: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.287186: EAPOL: SUPP_BE entering state RECEIVE
1544514424.314503: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.314526: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.314974: EAPOL: Received EAP-Packet frame
1544514424.314987: EAPOL: SUPP_BE entering state REQUEST
1544514424.314997: EAPOL: getSuppRsp
1544514424.315011: EAP: EAP entering state RECEIVED
1544514424.315033: EAP: Received EAP-Request id=5 method=13 vendor=0 vendorMethod=0
1544514424.315067: EAP: EAP entering state METHOD
1544514424.315082: SSL: Received packet(len=1030) - Flags 0x40
1544514424.315104: SSL: Need 9303 bytes more input data
1544514424.315117: SSL: Building ACK (type=13 id=5 ver=0)
1544514424.315129: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71957b7ff80
1544514424.315141: EAP: EAP entering state SEND_RESPONSE
1544514424.315153: EAP: EAP entering state IDLE
1544514424.315164: EAPOL: SUPP_BE entering state RESPONSE
1544514424.315173: EAPOL: txSuppRsp
1544514424.315184: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.315195: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.315237: EAPOL: SUPP_BE entering state RECEIVE
1544514424.344473: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.344496: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.344916: EAPOL: Received EAP-Packet frame
1544514424.344928: EAPOL: SUPP_BE entering state REQUEST
1544514424.344937: EAPOL: getSuppRsp
1544514424.344949: EAP: EAP entering state RECEIVED
1544514424.344972: EAP: Received EAP-Request id=6 method=13 vendor=0 vendorMethod=0
1544514424.344985: EAP: EAP entering state METHOD
1544514424.345013: SSL: Received packet(len=1030) - Flags 0x40
1544514424.345027: SSL: Need 8279 bytes more input data
1544514424.345048: SSL: Building ACK (type=13 id=6 ver=0)
1544514424.345059: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x719953ab9c0
1544514424.345072: EAP: EAP entering state SEND_RESPONSE
1544514424.345083: EAP: EAP entering state IDLE
1544514424.345094: EAPOL: SUPP_BE entering state RESPONSE
1544514424.345103: EAPOL: txSuppRsp
1544514424.345114: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.345125: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.345161: EAPOL: SUPP_BE entering state RECEIVE
1544514424.370471: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.370617: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.372819: EAPOL: Received EAP-Packet frame
1544514424.372837: EAPOL: SUPP_BE entering state REQUEST
1544514424.372850: EAPOL: getSuppRsp
1544514424.372865: EAP: EAP entering state RECEIVED
1544514424.372887: EAP: Received EAP-Request id=7 method=13 vendor=0 vendorMethod=0
1544514424.372913: EAP: EAP entering state METHOD
1544514424.372928: SSL: Received packet(len=1030) - Flags 0x40
1544514424.372959: SSL: Need 7255 bytes more input data
1544514424.372972: SSL: Building ACK (type=13 id=7 ver=0)
1544514424.372984: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71957b75fc0
1544514424.372997: EAP: EAP entering state SEND_RESPONSE
1544514424.373010: EAP: EAP entering state IDLE
1544514424.373021: EAPOL: SUPP_BE entering state RESPONSE
1544514424.373031: EAPOL: txSuppRsp
1544514424.373042: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.373054: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.373107: EAPOL: SUPP_BE entering state RECEIVE
1544514424.398431: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.398455: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.398901: EAPOL: Received EAP-Packet frame
1544514424.398915: EAPOL: SUPP_BE entering state REQUEST
1544514424.398926: EAPOL: getSuppRsp
1544514424.398937: EAP: EAP entering state RECEIVED
1544514424.398960: EAP: Received EAP-Request id=8 method=13 vendor=0 vendorMethod=0
1544514424.398974: EAP: EAP entering state METHOD
1544514424.399003: SSL: Received packet(len=1030) - Flags 0x40
1544514424.399019: SSL: Need 6231 bytes more input data
1544514424.399036: SSL: Building ACK (type=13 id=8 ver=0)
1544514424.399048: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8cd40
1544514424.399061: EAP: EAP entering state SEND_RESPONSE
1544514424.399074: EAP: EAP entering state IDLE
1544514424.399085: EAPOL: SUPP_BE entering state RESPONSE
1544514424.399095: EAPOL: txSuppRsp
1544514424.399106: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.399118: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.399178: EAPOL: SUPP_BE entering state RECEIVE
1544514424.424508: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.424532: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.424948: EAPOL: Received EAP-Packet frame
1544514424.424960: EAPOL: SUPP_BE entering state REQUEST
1544514424.424970: EAPOL: getSuppRsp
1544514424.424983: EAP: EAP entering state RECEIVED
1544514424.425010: EAP: Received EAP-Request id=9 method=13 vendor=0 vendorMethod=0
1544514424.425043: EAP: EAP entering state METHOD
1544514424.425058: SSL: Received packet(len=1030) - Flags 0x40
1544514424.425079: SSL: Need 5207 bytes more input data
1544514424.425091: SSL: Building ACK (type=13 id=9 ver=0)
1544514424.425103: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71957b752c0
1544514424.425116: EAP: EAP entering state SEND_RESPONSE
1544514424.425129: EAP: EAP entering state IDLE
1544514424.425140: EAPOL: SUPP_BE entering state RESPONSE
1544514424.425150: EAPOL: txSuppRsp
1544514424.425161: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.425173: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.425229: EAPOL: SUPP_BE entering state RECEIVE
1544514424.450710: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.450734: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.451150: EAPOL: Received EAP-Packet frame
1544514424.451162: EAPOL: SUPP_BE entering state REQUEST
1544514424.451172: EAPOL: getSuppRsp
1544514424.451183: EAP: EAP entering state RECEIVED
1544514424.451206: EAP: Received EAP-Request id=10 method=13 vendor=0 vendorMethod=0
1544514424.451220: EAP: EAP entering state METHOD
1544514424.451249: SSL: Received packet(len=1030) - Flags 0x40
1544514424.451265: SSL: Need 4183 bytes more input data
1544514424.451282: SSL: Building ACK (type=13 id=10 ver=0)
1544514424.451294: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c140
1544514424.451307: EAP: EAP entering state SEND_RESPONSE
1544514424.451320: EAP: EAP entering state IDLE
1544514424.451331: EAPOL: SUPP_BE entering state RESPONSE
1544514424.451341: EAPOL: txSuppRsp
1544514424.451352: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.451364: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.451418: EAPOL: SUPP_BE entering state RECEIVE
1544514424.483513: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.483538: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.484151: EAPOL: Received EAP-Packet frame
1544514424.484165: EAPOL: SUPP_BE entering state REQUEST
1544514424.484176: EAPOL: getSuppRsp
1544514424.484187: EAP: EAP entering state RECEIVED
1544514424.485543: EAP: Received EAP-Request id=11 method=13 vendor=0 vendorMethod=0
1544514424.485619: EAP: EAP entering state METHOD
1544514424.485662: SSL: Received packet(len=1030) - Flags 0x40
1544514424.485733: SSL: Need 3159 bytes more input data
1544514424.485775: SSL: Building ACK (type=13 id=11 ver=0)
1544514424.485828: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x719897cb780
1544514424.485868: EAP: EAP entering state SEND_RESPONSE
1544514424.485909: EAP: EAP entering state IDLE
1544514424.485966: EAPOL: SUPP_BE entering state RESPONSE
1544514424.486020: EAPOL: txSuppRsp
1544514424.486058: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.486096: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.486170: EAPOL: SUPP_BE entering state RECEIVE
1544514424.516786: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.516811: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.517267: EAPOL: Received EAP-Packet frame
1544514424.517281: EAPOL: SUPP_BE entering state REQUEST
1544514424.517291: EAPOL: getSuppRsp
1544514424.517302: EAP: EAP entering state RECEIVED
1544514424.517327: EAP: Received EAP-Request id=12 method=13 vendor=0 vendorMethod=0
1544514424.517340: EAP: EAP entering state METHOD
1544514424.517369: SSL: Received packet(len=1030) - Flags 0x40
1544514424.517386: SSL: Need 2135 bytes more input data
1544514424.517403: SSL: Building ACK (type=13 id=12 ver=0)
1544514424.517415: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c280
1544514424.517428: EAP: EAP entering state SEND_RESPONSE
1544514424.517441: EAP: EAP entering state IDLE
1544514424.517452: EAPOL: SUPP_BE entering state RESPONSE
1544514424.517462: EAPOL: txSuppRsp
1544514424.517473: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.517485: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.517525: EAPOL: SUPP_BE entering state RECEIVE
1544514424.544527: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.544551: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.544976: EAPOL: Received EAP-Packet frame
1544514424.544988: EAPOL: SUPP_BE entering state REQUEST
1544514424.544998: EAPOL: getSuppRsp
1544514424.545012: EAP: EAP entering state RECEIVED
1544514424.545036: EAP: Received EAP-Request id=13 method=13 vendor=0 vendorMethod=0
1544514424.545049: EAP: EAP entering state METHOD
1544514424.545078: SSL: Received packet(len=1030) - Flags 0x40
1544514424.545094: SSL: Need 1111 bytes more input data
1544514424.545111: SSL: Building ACK (type=13 id=13 ver=0)
1544514424.545123: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718a7f0e880
1544514424.545136: EAP: EAP entering state SEND_RESPONSE
1544514424.545148: EAP: EAP entering state IDLE
1544514424.545159: EAPOL: SUPP_BE entering state RESPONSE
1544514424.545169: EAPOL: txSuppRsp
1544514424.545181: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.545192: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.545235: EAPOL: SUPP_BE entering state RECEIVE
1544514424.570194: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.570218: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.570644: EAPOL: Received EAP-Packet frame
1544514424.570656: EAPOL: SUPP_BE entering state REQUEST
1544514424.570666: EAPOL: getSuppRsp
1544514424.570678: EAP: EAP entering state RECEIVED
1544514424.570702: EAP: Received EAP-Request id=14 method=13 vendor=0 vendorMethod=0
1544514424.570715: EAP: EAP entering state METHOD
1544514424.570744: SSL: Received packet(len=1030) - Flags 0x40
1544514424.570761: SSL: Need 87 bytes more input data
1544514424.570778: SSL: Building ACK (type=13 id=14 ver=0)
1544514424.570789: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718a7f0ebc0
1544514424.570802: EAP: EAP entering state SEND_RESPONSE
1544514424.570815: EAP: EAP entering state IDLE
1544514424.570827: EAPOL: SUPP_BE entering state RESPONSE
1544514424.570837: EAPOL: txSuppRsp
1544514424.570848: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.570859: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.570902: EAPOL: SUPP_BE entering state RECEIVE
1544514424.595567: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.595592: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.595687: EAPOL: Received EAP-Packet frame
1544514424.595740: EAPOL: SUPP_BE entering state REQUEST
1544514424.595778: EAPOL: getSuppRsp
1544514424.595819: EAP: EAP entering state RECEIVED
1544514424.595865: EAP: Received EAP-Request id=15 method=13 vendor=0 vendorMethod=0
1544514424.595910: EAP: EAP entering state METHOD
1544514424.595955: SSL: Received packet(len=93) - Flags 0x00
1544514424.596017: OpenSSL: RX ver=0x303 content_type=22 (handshake/server hello)
1544514424.596069: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.596155: SSL: (where=0x1001 ret=0x1)
1544514424.596198: SSL: SSL_connect:SSLv3 read server hello A
1544514424.596352: OpenSSL: RX ver=0x303 content_type=22 (handshake/certificate)
1544514424.596370: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.597296: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=3 buf='/DC=com/DC=thefacebook/CN=FBROOTCA'
1544514424.597537: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/DC=com/DC=thefacebook/CN=FBROOTCA' hash=f8e8e33b4cb262448b6fc519cdbda9cdac970d204c7bfe0efe0faa48cadb8d2f
1544514424.600391: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=2 buf='/DC=com/DC=thefacebook/CN=FBINTCA'
1544514424.600474: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/DC=com/DC=thefacebook/CN=FBINTCA' hash=be26443aa70a19ffe8e3b1dcde7062fcbc98d557f252a86e867a53f6988195e9
1544514424.602116: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=1 buf='/DC=com/DC=TheFacebook/CN=PRN-CASUB02'
1544514424.602192: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/DC=com/DC=TheFacebook/CN=PRN-CASUB02' hash=bca78633422bf849c7b0fdbb0d5f5fb296a0815ff38665be48cca35c867e0c0f
1544514424.603875: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=0 buf='/C=GB/ST=GB/L=London/O=facebook/OU=corpnet/CN=lhr-clearpass01.thefacebook.com/emailAddress=[hidden email]'
1544514424.603965: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=GB/ST=GB/L=London/O=facebook/OU=corpnet/CN=lhr-clearpass01.thefacebook.com/emailAddress=[hidden email]' hash=3b50120c9f98e41efacb9cf43a07959a01bace0b47df5a7cdb60fedb0706a27d
1544514424.604819: iwn0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:lhr-clearpass01.thefacebook.com
1544514424.604836: iwn0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:lhr-clearpass01.corp.tfbnw.net
1544514424.604851: EAP: Status notification: remote certificate verification (param=success)
1544514424.604893: SSL: (where=0x1001 ret=0x1)
1544514424.604907: SSL: SSL_connect:SSLv3 read server certificate A
1544514424.604936: OpenSSL: RX ver=0x303 content_type=22 (handshake/server key exchange)
1544514424.604950: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.605896: SSL: (where=0x1001 ret=0x1)
1544514424.605913: SSL: SSL_connect:SSLv3 read server key exchange A
1544514424.606003: OpenSSL: RX ver=0x303 content_type=22 (handshake/certificate request)
1544514424.606018: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.607278: SSL: (where=0x1001 ret=0x1)
1544514424.607295: SSL: SSL_connect:SSLv3 read server certificate request A
1544514424.607310: OpenSSL: RX ver=0x303 content_type=22 (handshake/server hello done)
1544514424.607322: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.607335: SSL: (where=0x1001 ret=0x1)
1544514424.607346: SSL: SSL_connect:SSLv3 read server done A
1544514424.607439: OpenSSL: TX ver=0x303 content_type=22 (handshake/certificate)
1544514424.607454: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.607466: SSL: (where=0x1001 ret=0x1)
1544514424.607477: SSL: SSL_connect:SSLv3 write client certificate A
1544514424.611591: OpenSSL: TX ver=0x303 content_type=22 (handshake/client key exchange)
1544514424.611611: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.611623: SSL: (where=0x1001 ret=0x1)
1544514424.611635: SSL: SSL_connect:SSLv3 write client key exchange A
1544514424.639829: OpenSSL: TX ver=0x303 content_type=22 (handshake/certificate verify)
1544514424.639850: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.639864: SSL: (where=0x1001 ret=0x1)
1544514424.639876: SSL: SSL_connect:SSLv3 write certificate verify A
1544514424.639895: OpenSSL: TX ver=0x303 content_type=20 (change cipher spec/)
1544514424.639908: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.639989: SSL: (where=0x1001 ret=0x1)
1544514424.640002: SSL: SSL_connect:SSLv3 write change cipher spec A
1544514424.640063: OpenSSL: TX ver=0x303 content_type=22 (handshake/finished)
1544514424.640077: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.640088: SSL: (where=0x1001 ret=0x1)
1544514424.640099: SSL: SSL_connect:SSLv3 write finished A
1544514424.640114: SSL: (where=0x1001 ret=0x1)
1544514424.640125: SSL: SSL_connect:SSLv3 flush data
1544514424.640138: SSL: (where=0x1002 ret=0xffffffff)
1544514424.640150: SSL: SSL_connect:error in SSLv3 read finished A
1544514424.640165: SSL: SSL_connect - want more data
1544514424.640176: SSL: 3021 bytes pending from ssl_out
1544514424.640191: SSL: 3021 bytes left to be sent out (of total 3021 bytes)
1544514424.640203: SSL: sending 1398 bytes, more fragments will follow
1544514424.640216: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71959b3e000
1544514424.640230: EAP: EAP entering state SEND_RESPONSE
1544514424.640252: EAP: EAP entering state IDLE
1544514424.640264: EAPOL: SUPP_BE entering state RESPONSE
1544514424.640274: EAPOL: txSuppRsp
1544514424.640286: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.640298: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.640888: EAPOL: SUPP_BE entering state RECEIVE
1544514424.670162: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.670304: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.670514: EAPOL: Received EAP-Packet frame
1544514424.670563: EAPOL: SUPP_BE entering state REQUEST
1544514424.670603: EAPOL: getSuppRsp
1544514424.670646: EAP: EAP entering state RECEIVED
1544514424.670696: EAP: Received EAP-Request id=16 method=13 vendor=0 vendorMethod=0
1544514424.670741: EAP: EAP entering state METHOD
1544514424.670784: SSL: Received packet(len=6) - Flags 0x00
1544514424.670825: SSL: 1623 bytes left to be sent out (of total 3021 bytes)
1544514424.670869: SSL: sending 1398 bytes, more fragments will follow
1544514424.670940: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7198bd97000
1544514424.670985: EAP: EAP entering state SEND_RESPONSE
1544514424.671028: EAP: EAP entering state IDLE
1544514424.671070: EAPOL: SUPP_BE entering state RESPONSE
1544514424.671107: EAPOL: txSuppRsp
1544514424.671151: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.671194: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.671853: EAPOL: SUPP_BE entering state RECEIVE
1544514424.697717: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.697741: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.697780: EAPOL: Received EAP-Packet frame
1544514424.697792: EAPOL: SUPP_BE entering state REQUEST
1544514424.697846: EAPOL: getSuppRsp
1544514424.697926: EAP: EAP entering state RECEIVED
1544514424.697974: EAP: Received EAP-Request id=17 method=13 vendor=0 vendorMethod=0
1544514424.698023: EAP: EAP entering state METHOD
1544514424.698065: SSL: Received packet(len=6) - Flags 0x00
1544514424.698107: SSL: 225 bytes left to be sent out (of total 3021 bytes)
1544514424.698154: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7194b02e400
1544514424.698202: EAP: EAP entering state SEND_RESPONSE
1544514424.698257: EAP: EAP entering state IDLE
1544514424.698301: EAPOL: SUPP_BE entering state RESPONSE
1544514424.698338: EAPOL: txSuppRsp
1544514424.698378: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.698424: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.698586: EAPOL: SUPP_BE entering state RECEIVE
1544514424.747507: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.747532: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.747736: EAPOL: Received EAP-Packet frame
1544514424.749108: EAPOL: SUPP_BE entering state REQUEST
1544514424.749125: EAPOL: getSuppRsp
1544514424.749136: EAP: EAP entering state RECEIVED
1544514424.749165: EAP: Received EAP-Request id=18 method=13 vendor=0 vendorMethod=0
1544514424.749179: EAP: EAP entering state METHOD
1544514424.749195: SSL: Received packet(len=61) - Flags 0x80
1544514424.749207: SSL: TLS Message Length: 51
1544514424.749240: OpenSSL: RX ver=0x303 content_type=20 (change cipher spec/)
1544514424.749255: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.749371: OpenSSL: RX ver=0x303 content_type=22 (handshake/finished)
1544514424.749390: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514424.749403: SSL: (where=0x1001 ret=0x1)
1544514424.749416: SSL: SSL_connect:SSLv3 read finished A
1544514424.749442: SSL: (where=0x20 ret=0x1)
1544514424.749454: SSL: (where=0x1002 ret=0x1)
1544514424.749465: SSL: 0 bytes pending from ssl_out
1544514424.749478: OpenSSL: Handshake finished - resumed=0
1544514424.749495: SSL: No Application Data included
1544514424.749508: SSL: No data to be sent out
1544514424.749520: EAP-TLS: Done
1544514424.749614: EAP-TLS: Derived key - hexdump XXX REMOVED XXX
1544514424.749630: EAP-TLS: Derived EMSK - hexdump XXX REMOVED XXX
1544514424.749643: EAP-TLS: Derived Session-Id - hexdump XXX REMOVED XXX
1544514424.749683: SSL: Building ACK (type=13 id=18 ver=0)
1544514424.749695: EAP: method process -> ignore=FALSE methodState=DONE decision=UNCOND_SUCC eapRespData=0x7196492f900
1544514424.749710: EAP: Session-Id - hexdump XXX REMOVED XXX
1544514424.749746: EAP: EAP entering state SEND_RESPONSE
1544514424.749759: EAP: EAP entering state IDLE
1544514424.749779: EAPOL: SUPP_BE entering state RESPONSE
1544514424.749795: EAPOL: txSuppRsp
1544514424.749815: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514424.749843: TX EAPOL - hexdump XXX REMOVED XXX
1544514424.749890: EAPOL: SUPP_BE entering state RECEIVE
1544514424.812703: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.812728: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.812766: EAPOL: Received EAP-Packet frame
1544514424.812779: EAPOL: SUPP_BE entering state REQUEST
1544514424.812794: EAPOL: getSuppRsp
1544514424.812805: EAP: EAP entering state RECEIVED
1544514424.812828: EAP: Received EAP-Success
1544514424.812839: EAP: Status notification: completion (param=success)
1544514424.812856: EAP: EAP entering state SUCCESS
1544514424.812870: iwn0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
1544514424.812887: EAPOL: SUPP_PAE entering state AUTHENTICATED
1544514424.812901: EAPOL: Supplicant port status: Authorized
1544514424.812912: EAPOL: SUPP_BE entering state RECEIVE
1544514424.812923: EAPOL: SUPP_BE entering state SUCCESS
1544514424.812934: EAPOL: SUPP_BE entering state IDLE
1544514424.812944: EAPOL authentication completed - result=SUCCESS
1544514424.812955: Configure PMK for driver-based RSN 4-way handshake
1544514424.812965: EAPOL: Successfully fetched key (len=32)
1544514424.812981: RSN: Configure PMK for driver-based 4-way handshake - hexdump XXX REMOVED XXX
1544514424.812994: XXX wpa_driver_openbsd_set_key() start
1544514424.813004: XXX wpa_driver_openbsd_get_bssid() start
1544514424.813050: iwn0: Cancelling scan request
1544514424.813066: iwn0: Cancelling authentication timeout
1544514424.813083: iwn0: State: ASSOCIATED -> COMPLETED
1544514424.813103: iwn0: CTRL-EVENT-CONNECTED - Connection to 6c:f3:7f:d6:5e:f0 completed [id=0 id_str=]
1544514424.907103: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.907129: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.907198: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
1544514424.907213: EAPOL: External notification - portValid=1
1544514424.929085: XXX wpa_driver_openbsd_event_receive() start
1544514424.930104: XXX emitting assoc event via wpa_supplicant_event()
1544514424.930634: iwn0: Event ASSOC (0) received
1544514424.930844: XXX wpa_driver_openbsd_get_bssid() start
1544514424.931092: iwn0: State: COMPLETED -> ASSOCIATED
1544514424.931341: iwn0: Associated with 6c:f3:7f:d6:5e:f0
1544514424.931557: iwn0: WPA: Association event - clear replay counter
1544514424.931718: iwn0: WPA: Clear old PTK
1544514424.931869: EAPOL: External notification - portEnabled=0
1544514424.932083: EAPOL: SUPP_PAE entering state DISCONNECTED
1544514424.932259: EAPOL: Supplicant port status: Unauthorized
1544514424.932477: EAPOL: SUPP_BE entering state INITIALIZE
1544514424.932619: EAP: EAP entering state DISABLED
1544514424.932826: EAPOL: External notification - portValid=0
1544514424.933103: EAPOL: External notification - portEnabled=1
1544514424.933250: EAPOL: SUPP_PAE entering state CONNECTING
1544514424.933411: EAPOL: SUPP_BE entering state IDLE
1544514424.933565: EAP: EAP entering state INITIALIZE
1544514424.933783: EAP: maintaining EAP method data for fast reauthentication
1544514424.933916: EAP: EAP entering state IDLE
1544514424.934107: iwn0: Setting authentication timeout: 10 sec 0 usec
1544514424.934237: iwn0: Cancelling scan request
1544514424.934413: EAPOL: External notification - portValid=1
1544514424.934665: XXX wpa_driver_openbsd_event_receive() start
1544514424.934816: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514424.935027: RX EAPOL - hexdump XXX REMOVED XXX
1544514424.935331: iwn0: Setting authentication timeout: 70 sec 0 usec
1544514424.935459: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
1544514424.935576: EAPOL: External notification - portValid=1
1544514424.935806: XXX wpa_driver_openbsd_event_receive() start
1544514425.035725: XXX wpa_driver_openbsd_event_receive() start
1544514425.037877: XXX wpa_driver_openbsd_event_receive() start
1544514425.037919: XXX wpa_driver_openbsd_event_receive() start
1544514425.037957: XXX wpa_driver_openbsd_event_receive() start
1544514425.037986: XXX wpa_driver_openbsd_event_receive() start
1544514425.038610: XXX wpa_driver_openbsd_event_receive() start
1544514425.038652: XXX wpa_driver_openbsd_event_receive() start
1544514425.038684: XXX wpa_driver_openbsd_event_receive() start
1544514426.029858: XXX wpa_driver_openbsd_event_receive() start
1544514426.030049: XXX wpa_driver_openbsd_event_receive() start
1544514426.158502: XXX wpa_driver_openbsd_event_receive() start
1544514426.439572: XXX wpa_driver_openbsd_event_receive() start
1544514426.869794: EAPOL: startWhen --> 0
1544514426.869870: EAPOL: SUPP_PAE entering state CONNECTING
1544514426.869914: EAPOL: txStart
1544514426.869954: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514426.870003: TX EAPOL - hexdump XXX REMOVED XXX
1544514426.892138: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514426.892170: RX EAPOL - hexdump XXX REMOVED XXX
1544514426.892208: EAPOL: Received EAP-Packet frame
1544514426.892220: EAPOL: SUPP_PAE entering state RESTART
1544514426.892283: EAP: EAP entering state INITIALIZE
1544514426.892335: EAP: maintaining EAP method data for fast reauthentication
1544514426.892375: EAP: EAP entering state IDLE
1544514426.892424: EAPOL: SUPP_PAE entering state AUTHENTICATING
1544514426.892461: EAPOL: SUPP_BE entering state REQUEST
1544514426.893234: EAPOL: getSuppRsp
1544514426.893494: EAP: EAP entering state RECEIVED
1544514426.893525: EAP: Received EAP-Request id=20 method=1 vendor=0 vendorMethod=0
1544514426.893539: EAP: EAP entering state IDENTITY
1544514426.893555: iwn0: CTRL-EVENT-EAP-STARTED EAP authentication started
1544514426.893568: EAP: Status notification: started (param=)
1544514426.893587: EAP: EAP-Request Identity data - hexdump_ascii(len=0):
1544514426.893699: EAP: using real identity - hexdump_ascii(len=10):
     6d 6b 75 63 68 61 72 73 6b 69                     mkucharski      
1544514426.893997: EAP: EAP entering state SEND_RESPONSE
1544514426.894309: EAP: EAP entering state IDLE
1544514426.894324: EAPOL: SUPP_BE entering state RESPONSE
1544514426.894335: EAPOL: txSuppRsp
1544514426.894349: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514426.894362: TX EAPOL - hexdump XXX REMOVED XXX
1544514426.894481: EAPOL: SUPP_BE entering state RECEIVE
1544514426.934222: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514426.934253: RX EAPOL - hexdump XXX REMOVED XXX
1544514426.934293: EAPOL: Received EAP-Packet frame
1544514426.934305: EAPOL: SUPP_BE entering state REQUEST
1544514426.934359: EAPOL: getSuppRsp
1544514426.934414: EAP: EAP entering state RECEIVED
1544514426.934467: EAP: Received EAP-Request id=21 method=13 vendor=0 vendorMethod=0
1544514426.934520: EAP: EAP entering state GET_METHOD
1544514426.934564: iwn0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13
1544514426.934614: EAP: Status notification: accept proposed method (param=TLS)
1544514426.934660: EAP: Using previous method data for fast re-authentication
1544514426.935118: EAP: Initialize selected EAP method: vendor 0 method 13 (TLS)
1544514426.937482: iwn0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
1544514426.937502: EAP: EAP entering state METHOD
1544514426.937522: SSL: Received packet(len=6) - Flags 0x20
1544514426.937535: EAP-TLS: Start
1544514426.937603: SSL: (where=0x10 ret=0x1)
1544514426.937670: SSL: (where=0x1001 ret=0x1)
1544514426.937737: SSL: SSL_connect:before/connect initialization
1544514426.939253: OpenSSL: TX ver=0x303 content_type=22 (handshake/client hello)
1544514426.939276: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514426.939291: SSL: (where=0x1001 ret=0x1)
1544514426.939303: SSL: SSL_connect:SSLv3 write client hello A
1544514426.939320: SSL: (where=0x1002 ret=0xffffffff)
1544514426.939332: SSL: SSL_connect:error in SSLv3 read server hello A
1544514426.939408: SSL: SSL_connect - want more data
1544514426.939458: SSL: 184 bytes pending from ssl_out
1544514426.939506: SSL: 184 bytes left to be sent out (of total 184 bytes)
1544514426.939556: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7195498c100
1544514426.939599: EAP: EAP entering state SEND_RESPONSE
1544514426.939783: EAP: EAP entering state IDLE
1544514426.939799: EAPOL: SUPP_BE entering state RESPONSE
1544514426.939810: EAPOL: txSuppRsp
1544514426.939822: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514426.939835: TX EAPOL - hexdump XXX REMOVED XXX
1544514426.939963: EAPOL: SUPP_BE entering state RECEIVE
1544514426.976375: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514426.976408: RX EAPOL - hexdump XXX REMOVED XXX
1544514426.976990: EAPOL: Received EAP-Packet frame
1544514426.977102: EAPOL: SUPP_BE entering state REQUEST
1544514426.977155: EAPOL: getSuppRsp
1544514426.977206: EAP: EAP entering state RECEIVED
1544514426.977262: EAP: Received EAP-Request id=22 method=13 vendor=0 vendorMethod=0
1544514426.977333: EAP: EAP entering state METHOD
1544514426.977380: SSL: Received packet(len=1034) - Flags 0xc0
1544514426.977436: SSL: TLS Message Length: 11351
1544514426.977637: SSL: Need 10327 bytes more input data
1544514426.980351: SSL: Building ACK (type=13 id=22 ver=0)
1544514426.980371: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c780
1544514426.980387: EAP: EAP entering state SEND_RESPONSE
1544514426.980402: EAP: EAP entering state IDLE
1544514426.980432: EAPOL: SUPP_BE entering state RESPONSE
1544514426.980444: EAPOL: txSuppRsp
1544514426.980457: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514426.980469: TX EAPOL - hexdump XXX REMOVED XXX
1544514426.980524: EAPOL: SUPP_BE entering state RECEIVE
1544514427.008533: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.008561: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.009841: EAPOL: Received EAP-Packet frame
1544514427.009858: EAPOL: SUPP_BE entering state REQUEST
1544514427.009868: EAPOL: getSuppRsp
1544514427.009880: EAP: EAP entering state RECEIVED
1544514427.009909: EAP: Received EAP-Request id=23 method=13 vendor=0 vendorMethod=0
1544514427.009923: EAP: EAP entering state METHOD
1544514427.009942: SSL: Received packet(len=1030) - Flags 0x40
1544514427.009959: SSL: Need 9303 bytes more input data
1544514427.009973: SSL: Building ACK (type=13 id=23 ver=0)
1544514427.009985: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718a7f0e640
1544514427.009999: EAP: EAP entering state SEND_RESPONSE
1544514427.010012: EAP: EAP entering state IDLE
1544514427.010024: EAPOL: SUPP_BE entering state RESPONSE
1544514427.010034: EAPOL: txSuppRsp
1544514427.010046: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.010058: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.010105: EAPOL: SUPP_BE entering state RECEIVE
1544514427.038512: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.038540: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.040639: EAPOL: Received EAP-Packet frame
1544514427.040665: EAPOL: SUPP_BE entering state REQUEST
1544514427.040680: EAPOL: getSuppRsp
1544514427.040692: EAP: EAP entering state RECEIVED
1544514427.040721: EAP: Received EAP-Request id=24 method=13 vendor=0 vendorMethod=0
1544514427.040735: EAP: EAP entering state METHOD
1544514427.040755: SSL: Received packet(len=1030) - Flags 0x40
1544514427.040771: SSL: Need 8279 bytes more input data
1544514427.040785: SSL: Building ACK (type=13 id=24 ver=0)
1544514427.040798: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c900
1544514427.040812: EAP: EAP entering state SEND_RESPONSE
1544514427.040826: EAP: EAP entering state IDLE
1544514427.040837: EAPOL: SUPP_BE entering state RESPONSE
1544514427.040920: EAPOL: txSuppRsp
1544514427.040947: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.040960: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.041012: EAPOL: SUPP_BE entering state RECEIVE
1544514427.067290: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.067316: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.067781: EAPOL: Received EAP-Packet frame
1544514427.067793: EAPOL: SUPP_BE entering state REQUEST
1544514427.067803: EAPOL: getSuppRsp
1544514427.067814: EAP: EAP entering state RECEIVED
1544514427.067887: EAP: Received EAP-Request id=25 method=13 vendor=0 vendorMethod=0
1544514427.067901: EAP: EAP entering state METHOD
1544514427.067917: SSL: Received packet(len=1030) - Flags 0x40
1544514427.068036: SSL: Need 7255 bytes more input data
1544514427.068051: SSL: Building ACK (type=13 id=25 ver=0)
1544514427.068071: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c1c0
1544514427.068085: EAP: EAP entering state SEND_RESPONSE
1544514427.068099: EAP: EAP entering state IDLE
1544514427.068110: EAPOL: SUPP_BE entering state RESPONSE
1544514427.068130: EAPOL: txSuppRsp
1544514427.068142: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.068154: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.068197: EAPOL: SUPP_BE entering state RECEIVE
1544514427.098166: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.098197: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.099107: EAPOL: Received EAP-Packet frame
1544514427.099356: EAPOL: SUPP_BE entering state REQUEST
1544514427.099374: EAPOL: getSuppRsp
1544514427.099388: EAP: EAP entering state RECEIVED
1544514427.099490: EAP: Received EAP-Request id=26 method=13 vendor=0 vendorMethod=0
1544514427.099504: EAP: EAP entering state METHOD
1544514427.099523: SSL: Received packet(len=1030) - Flags 0x40
1544514427.099625: SSL: Need 6231 bytes more input data
1544514427.099676: SSL: Building ACK (type=13 id=26 ver=0)
1544514427.099752: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7190d2d5dc0
1544514427.100180: EAP: EAP entering state SEND_RESPONSE
1544514427.100276: EAP: EAP entering state IDLE
1544514427.100376: EAPOL: SUPP_BE entering state RESPONSE
1544514427.100454: EAPOL: txSuppRsp
1544514427.100559: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.100844: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.100905: EAPOL: SUPP_BE entering state RECEIVE
1544514427.129005: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.129031: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.130374: EAPOL: Received EAP-Packet frame
1544514427.130392: EAPOL: SUPP_BE entering state REQUEST
1544514427.130404: EAPOL: getSuppRsp
1544514427.130415: EAP: EAP entering state RECEIVED
1544514427.130441: EAP: Received EAP-Request id=27 method=13 vendor=0 vendorMethod=0
1544514427.130455: EAP: EAP entering state METHOD
1544514427.130484: SSL: Received packet(len=1030) - Flags 0x40
1544514427.130498: SSL: Need 5207 bytes more input data
1544514427.130520: SSL: Building ACK (type=13 id=27 ver=0)
1544514427.130532: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718a7f0e000
1544514427.130545: EAP: EAP entering state SEND_RESPONSE
1544514427.130558: EAP: EAP entering state IDLE
1544514427.130569: EAPOL: SUPP_BE entering state RESPONSE
1544514427.130579: EAPOL: txSuppRsp
1544514427.130591: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.130603: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.130661: EAPOL: SUPP_BE entering state RECEIVE
1544514427.158860: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.158888: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.159672: EAPOL: Received EAP-Packet frame
1544514427.160301: EAPOL: SUPP_BE entering state REQUEST
1544514427.160312: EAPOL: getSuppRsp
1544514427.160324: EAP: EAP entering state RECEIVED
1544514427.160352: EAP: Received EAP-Request id=28 method=13 vendor=0 vendorMethod=0
1544514427.160367: EAP: EAP entering state METHOD
1544514427.160386: SSL: Received packet(len=1030) - Flags 0x40
1544514427.160466: SSL: Need 4183 bytes more input data
1544514427.160490: SSL: Building ACK (type=13 id=28 ver=0)
1544514427.160508: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c9c0
1544514427.160522: EAP: EAP entering state SEND_RESPONSE
1544514427.160539: EAP: EAP entering state IDLE
1544514427.160551: EAPOL: SUPP_BE entering state RESPONSE
1544514427.160564: EAPOL: txSuppRsp
1544514427.160576: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.160588: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.160635: EAPOL: SUPP_BE entering state RECEIVE
1544514427.188979: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.189020: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.190387: EAPOL: Received EAP-Packet frame
1544514427.190407: EAPOL: SUPP_BE entering state REQUEST
1544514427.190418: EAPOL: getSuppRsp
1544514427.190429: EAP: EAP entering state RECEIVED
1544514427.190582: EAP: Received EAP-Request id=29 method=13 vendor=0 vendorMethod=0
1544514427.190602: EAP: EAP entering state METHOD
1544514427.190620: SSL: Received packet(len=1030) - Flags 0x40
1544514427.190670: SSL: Need 3159 bytes more input data
1544514427.190686: SSL: Building ACK (type=13 id=29 ver=0)
1544514427.190701: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c100
1544514427.190715: EAP: EAP entering state SEND_RESPONSE
1544514427.190734: EAP: EAP entering state IDLE
1544514427.190745: EAPOL: SUPP_BE entering state RESPONSE
1544514427.190755: EAPOL: txSuppRsp
1544514427.190767: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.190779: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.190822: EAPOL: SUPP_BE entering state RECEIVE
1544514427.217055: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.217081: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.217733: EAPOL: Received EAP-Packet frame
1544514427.217784: EAPOL: SUPP_BE entering state REQUEST
1544514427.219381: EAPOL: getSuppRsp
1544514427.219411: EAP: EAP entering state RECEIVED
1544514427.219441: EAP: Received EAP-Request id=30 method=13 vendor=0 vendorMethod=0
1544514427.219456: EAP: EAP entering state METHOD
1544514427.219473: SSL: Received packet(len=1030) - Flags 0x40
1544514427.219488: SSL: Need 2135 bytes more input data
1544514427.219502: SSL: Building ACK (type=13 id=30 ver=0)
1544514427.219514: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718a7f0e000
1544514427.219528: EAP: EAP entering state SEND_RESPONSE
1544514427.219541: EAP: EAP entering state IDLE
1544514427.219553: EAPOL: SUPP_BE entering state RESPONSE
1544514427.219564: EAPOL: txSuppRsp
1544514427.219576: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.219588: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.219636: EAPOL: SUPP_BE entering state RECEIVE
1544514427.246774: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.246801: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.247516: EAPOL: Received EAP-Packet frame
1544514427.247534: EAPOL: SUPP_BE entering state REQUEST
1544514427.247544: EAPOL: getSuppRsp
1544514427.247555: EAP: EAP entering state RECEIVED
1544514427.247580: EAP: Received EAP-Request id=31 method=13 vendor=0 vendorMethod=0
1544514427.247598: EAP: EAP entering state METHOD
1544514427.247616: SSL: Received packet(len=1030) - Flags 0x40
1544514427.247633: SSL: Need 1111 bytes more input data
1544514427.247647: SSL: Building ACK (type=13 id=31 ver=0)
1544514427.247659: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7190d2d5d80
1544514427.247672: EAP: EAP entering state SEND_RESPONSE
1544514427.247685: EAP: EAP entering state IDLE
1544514427.247697: EAPOL: SUPP_BE entering state RESPONSE
1544514427.247707: EAPOL: txSuppRsp
1544514427.247719: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.247731: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.247783: EAPOL: SUPP_BE entering state RECEIVE
1544514427.275344: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.275380: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.275807: EAPOL: Received EAP-Packet frame
1544514427.275889: EAPOL: SUPP_BE entering state REQUEST
1544514427.275900: EAPOL: getSuppRsp
1544514427.275912: EAP: EAP entering state RECEIVED
1544514427.275942: EAP: Received EAP-Request id=32 method=13 vendor=0 vendorMethod=0
1544514427.275992: EAP: EAP entering state METHOD
1544514427.276012: SSL: Received packet(len=1030) - Flags 0x40
1544514427.276029: SSL: Need 87 bytes more input data
1544514427.276046: SSL: Building ACK (type=13 id=32 ver=0)
1544514427.276122: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x71925e8c240
1544514427.276145: EAP: EAP entering state SEND_RESPONSE
1544514427.276161: EAP: EAP entering state IDLE
1544514427.276172: EAPOL: SUPP_BE entering state RESPONSE
1544514427.276182: EAPOL: txSuppRsp
1544514427.276205: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.276218: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.276267: EAPOL: SUPP_BE entering state RECEIVE
1544514427.300673: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.300703: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.300770: EAPOL: Received EAP-Packet frame
1544514427.300782: EAPOL: SUPP_BE entering state REQUEST
1544514427.300794: EAPOL: getSuppRsp
1544514427.300805: EAP: EAP entering state RECEIVED
1544514427.300828: EAP: Received EAP-Request id=33 method=13 vendor=0 vendorMethod=0
1544514427.300841: EAP: EAP entering state METHOD
1544514427.300859: SSL: Received packet(len=93) - Flags 0x00
1544514427.300905: OpenSSL: RX ver=0x303 content_type=22 (handshake/server hello)
1544514427.300921: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.300952: SSL: (where=0x1001 ret=0x1)
1544514427.300965: SSL: SSL_connect:SSLv3 read server hello A
1544514427.301052: OpenSSL: RX ver=0x303 content_type=22 (handshake/certificate)
1544514427.301067: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.302039: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=3 buf='/DC=com/DC=thefacebook/CN=FBROOTCA'
1544514427.302115: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/DC=com/DC=thefacebook/CN=FBROOTCA' hash=f8e8e33b4cb262448b6fc519cdbda9cdac970d204c7bfe0efe0faa48cadb8d2f
1544514427.303466: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=2 buf='/DC=com/DC=thefacebook/CN=FBINTCA'
1544514427.303542: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/DC=com/DC=thefacebook/CN=FBINTCA' hash=be26443aa70a19ffe8e3b1dcde7062fcbc98d557f252a86e867a53f6988195e9
1544514427.305268: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=1 buf='/DC=com/DC=TheFacebook/CN=PRN-CASUB02'
1544514427.305359: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/DC=com/DC=TheFacebook/CN=PRN-CASUB02' hash=bca78633422bf849c7b0fdbb0d5f5fb296a0815ff38665be48cca35c867e0c0f
1544514427.307049: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) ca_cert_verify=1 depth=0 buf='/C=GB/ST=GB/L=London/O=facebook/OU=corpnet/CN=lhr-clearpass01.thefacebook.com/emailAddress=[hidden email]'
1544514427.307140: iwn0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=GB/ST=GB/L=London/O=facebook/OU=corpnet/CN=lhr-clearpass01.thefacebook.com/emailAddress=[hidden email]' hash=3b50120c9f98e41efacb9cf43a07959a01bace0b47df5a7cdb60fedb0706a27d
1544514427.308015: iwn0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:lhr-clearpass01.thefacebook.com
1544514427.308035: iwn0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:lhr-clearpass01.corp.tfbnw.net
1544514427.308051: EAP: Status notification: remote certificate verification (param=success)
1544514427.308101: SSL: (where=0x1001 ret=0x1)
1544514427.308115: SSL: SSL_connect:SSLv3 read server certificate A
1544514427.308145: OpenSSL: RX ver=0x303 content_type=22 (handshake/server key exchange)
1544514427.308160: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.309188: SSL: (where=0x1001 ret=0x1)
1544514427.309207: SSL: SSL_connect:SSLv3 read server key exchange A
1544514427.309255: OpenSSL: RX ver=0x303 content_type=22 (handshake/certificate request)
1544514427.309270: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.311433: SSL: (where=0x1001 ret=0x1)
1544514427.311467: SSL: SSL_connect:SSLv3 read server certificate request A
1544514427.311495: OpenSSL: RX ver=0x303 content_type=22 (handshake/server hello done)
1544514427.311509: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.311522: SSL: (where=0x1001 ret=0x1)
1544514427.311534: SSL: SSL_connect:SSLv3 read server done A
1544514427.311616: OpenSSL: TX ver=0x303 content_type=22 (handshake/certificate)
1544514427.311636: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.311648: SSL: (where=0x1001 ret=0x1)
1544514427.311659: SSL: SSL_connect:SSLv3 write client certificate A
1544514427.315793: OpenSSL: TX ver=0x303 content_type=22 (handshake/client key exchange)
1544514427.315815: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.315829: SSL: (where=0x1001 ret=0x1)
1544514427.315841: SSL: SSL_connect:SSLv3 write client key exchange A
1544514427.345380: OpenSSL: TX ver=0x303 content_type=22 (handshake/certificate verify)
1544514427.345420: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.345436: SSL: (where=0x1001 ret=0x1)
1544514427.345448: SSL: SSL_connect:SSLv3 write certificate verify A
1544514427.345467: OpenSSL: TX ver=0x303 content_type=20 (change cipher spec/)
1544514427.345480: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.345592: SSL: (where=0x1001 ret=0x1)
1544514427.345606: SSL: SSL_connect:SSLv3 write change cipher spec A
1544514427.346669: OpenSSL: TX ver=0x303 content_type=22 (handshake/finished)
1544514427.346879: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.346896: SSL: (where=0x1001 ret=0x1)
1544514427.346919: SSL: SSL_connect:SSLv3 write finished A
1544514427.346937: SSL: (where=0x1001 ret=0x1)
1544514427.346948: SSL: SSL_connect:SSLv3 flush data
1544514427.346964: SSL: (where=0x1002 ret=0xffffffff)
1544514427.346975: SSL: SSL_connect:error in SSLv3 read finished A
1544514427.346997: SSL: SSL_connect - want more data
1544514427.347008: SSL: 3021 bytes pending from ssl_out
1544514427.347027: SSL: 3021 bytes left to be sent out (of total 3021 bytes)
1544514427.347041: SSL: sending 1398 bytes, more fragments will follow
1544514427.347058: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7198bd99000
1544514427.347073: EAP: EAP entering state SEND_RESPONSE
1544514427.347088: EAP: EAP entering state IDLE
1544514427.347102: EAPOL: SUPP_BE entering state RESPONSE
1544514427.347115: EAPOL: txSuppRsp
1544514427.347130: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.347144: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.348209: EAPOL: SUPP_BE entering state RECEIVE
1544514427.376965: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.376985: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.377004: EAPOL: Received EAP-Packet frame
1544514427.377011: EAPOL: SUPP_BE entering state REQUEST
1544514427.377017: EAPOL: getSuppRsp
1544514427.377026: EAP: EAP entering state RECEIVED
1544514427.377040: EAP: Received EAP-Request id=34 method=13 vendor=0 vendorMethod=0
1544514427.377045: EAP: EAP entering state METHOD
1544514427.377055: SSL: Received packet(len=6) - Flags 0x00
1544514427.377061: SSL: 1623 bytes left to be sent out (of total 3021 bytes)
1544514427.377066: SSL: sending 1398 bytes, more fragments will follow
1544514427.377073: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x7198bd98800
1544514427.377078: EAP: EAP entering state SEND_RESPONSE
1544514427.377084: EAP: EAP entering state IDLE
1544514427.377090: EAPOL: SUPP_BE entering state RESPONSE
1544514427.377403: EAPOL: txSuppRsp
1544514427.377413: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.377418: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.377645: EAPOL: SUPP_BE entering state RECEIVE
1544514427.403822: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.403840: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.403857: EAPOL: Received EAP-Packet frame
1544514427.403862: EAPOL: SUPP_BE entering state REQUEST
1544514427.404103: EAPOL: getSuppRsp
1544514427.404109: EAP: EAP entering state RECEIVED
1544514427.404123: EAP: Received EAP-Request id=35 method=13 vendor=0 vendorMethod=0
1544514427.404129: EAP: EAP entering state METHOD
1544514427.404138: SSL: Received packet(len=6) - Flags 0x00
1544514427.404144: SSL: 225 bytes left to be sent out (of total 3021 bytes)
1544514427.404152: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x718e5863000
1544514427.404157: EAP: EAP entering state SEND_RESPONSE
1544514427.404163: EAP: EAP entering state IDLE
1544514427.404168: EAPOL: SUPP_BE entering state RESPONSE
1544514427.404171: EAPOL: txSuppRsp
1544514427.404177: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.404181: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.404235: EAPOL: SUPP_BE entering state RECEIVE
1544514427.440016: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.440036: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.440055: EAPOL: Received EAP-Packet frame
1544514427.440061: EAPOL: SUPP_BE entering state REQUEST
1544514427.440065: EAPOL: getSuppRsp
1544514427.440073: EAP: EAP entering state RECEIVED
1544514427.440115: EAP: Received EAP-Request id=36 method=13 vendor=0 vendorMethod=0
1544514427.440137: EAP: EAP entering state METHOD
1544514427.440158: SSL: Received packet(len=61) - Flags 0x80
1544514427.440174: SSL: TLS Message Length: 51
1544514427.440262: OpenSSL: RX ver=0x303 content_type=20 (change cipher spec/)
1544514427.440356: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.440426: OpenSSL: RX ver=0x303 content_type=22 (handshake/finished)
1544514427.440465: OpenSSL: Message - hexdump XXX REMOVED XXX
1544514427.440474: SSL: (where=0x1001 ret=0x1)
1544514427.440479: SSL: SSL_connect:SSLv3 read finished A
1544514427.440495: SSL: (where=0x20 ret=0x1)
1544514427.440500: SSL: (where=0x1002 ret=0x1)
1544514427.440505: SSL: 0 bytes pending from ssl_out
1544514427.440510: OpenSSL: Handshake finished - resumed=0
1544514427.440517: SSL: No Application Data included
1544514427.440522: SSL: No data to be sent out
1544514427.440527: EAP-TLS: Done
1544514427.440563: EAP-TLS: Derived key - hexdump XXX REMOVED XXX
1544514427.440568: EAP-TLS: Derived EMSK - hexdump XXX REMOVED XXX
1544514427.440574: EAP-TLS: Derived Session-Id - hexdump XXX REMOVED XXX
1544514427.440588: SSL: Building ACK (type=13 id=36 ver=0)
1544514427.440593: EAP: method process -> ignore=FALSE methodState=DONE decision=UNCOND_SUCC eapRespData=0x718e5864240
1544514427.440599: EAP: Session-Id - hexdump XXX REMOVED XXX
1544514427.440616: EAP: EAP entering state SEND_RESPONSE
1544514427.440621: EAP: EAP entering state IDLE
1544514427.440626: EAPOL: SUPP_BE entering state RESPONSE
1544514427.440629: EAPOL: txSuppRsp
1544514427.440635: TX EAPOL: dst=6c:f3:7f:d6:5e:f0
1544514427.440640: TX EAPOL - hexdump XXX REMOVED XXX
1544514427.440662: EAPOL: SUPP_BE entering state RECEIVE
1544514427.491045: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.491083: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.491125: EAPOL: Received EAP-Packet frame
1544514427.491195: EAPOL: SUPP_BE entering state REQUEST
1544514427.491282: EAPOL: getSuppRsp
1544514427.491321: EAP: EAP entering state RECEIVED
1544514427.491377: EAP: Received EAP-Success
1544514427.491424: EAP: Status notification: completion (param=success)
1544514427.491499: EAP: EAP entering state SUCCESS
1544514427.493010: iwn0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
1544514427.493054: EAPOL: SUPP_PAE entering state AUTHENTICATED
1544514427.493100: EAPOL: Supplicant port status: Authorized
1544514427.493138: EAPOL: SUPP_BE entering state RECEIVE
1544514427.493180: EAPOL: SUPP_BE entering state SUCCESS
1544514427.493220: EAPOL: SUPP_BE entering state IDLE
1544514427.493261: EAPOL authentication completed - result=SUCCESS
1544514427.493302: Configure PMK for driver-based RSN 4-way handshake
1544514427.493343: EAPOL: Successfully fetched key (len=32)
1544514427.493386: RSN: Configure PMK for driver-based 4-way handshake - hexdump XXX REMOVED XXX
1544514427.493440: XXX wpa_driver_openbsd_set_key() start
1544514427.493483: XXX wpa_driver_openbsd_get_bssid() start
1544514427.493571: iwn0: Cancelling scan request
1544514427.493618: iwn0: Cancelling authentication timeout
1544514427.493667: iwn0: State: ASSOCIATED -> COMPLETED
1544514427.493715: iwn0: CTRL-EVENT-CONNECTED - Connection to 6c:f3:7f:d6:5e:f0 completed [id=0 id_str=]
1544514427.512836: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.512871: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.512996: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
1544514427.513064: EAPOL: External notification - portValid=1
1544514427.534674: iwn0: RX EAPOL from 6c:f3:7f:d6:5e:f0
1544514427.534703: RX EAPOL - hexdump XXX REMOVED XXX
1544514427.535001: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
1544514427.536558: EAPOL: External notification - portValid=1
1544514430.024459: XXX wpa_driver_openbsd_event_receive() start
1544514430.024591: XXX wpa_driver_openbsd_event_receive() start
1544514430.024630: XXX wpa_driver_openbsd_event_receive() start
1544514430.024658: XXX wpa_driver_openbsd_event_receive() start
1544514430.024688: XXX wpa_driver_openbsd_event_receive() start
1544514430.024715: XXX wpa_driver_openbsd_event_receive() start
1544514430.024743: XXX wpa_driver_openbsd_event_receive() start
1544514430.024782: XXX wpa_driver_openbsd_event_receive() start
1544514430.024810: XXX wpa_driver_openbsd_event_receive() start
1544514430.024839: XXX wpa_driver_openbsd_event_receive() start
1544514430.025180: XXX wpa_driver_openbsd_event_receive() start
1544514430.025262: XXX wpa_driver_openbsd_event_receive() start
1544514430.025332: XXX wpa_driver_openbsd_event_receive() start
1544514430.026329: XXX wpa_driver_openbsd_event_receive() start
1544514430.028031: XXX wpa_driver_openbsd_event_receive() start
1544514435.279905: XXX wpa_driver_openbsd_event_receive() start
1544514435.809660: XXX wpa_driver_openbsd_event_receive() start
1544514435.894438: XXX wpa_driver_openbsd_event_receive() start
1544514436.070381: XXX wpa_driver_openbsd_event_receive() start
1544514436.070487: XXX wpa_driver_openbsd_event_receive() start
1544514436.070546: XXX wpa_driver_openbsd_event_receive() start
1544514457.189759: EAPOL: authWhile --> 0
1544514457.189793: EAPOL: startWhen --> 0
1544514487.499689: EAPOL: idleWhile --> 0
1544514487.499717: EAPOL: disable timer tick


On Wed, Nov 28, 2018 at 06:56:46PM +0100, Gregor Best wrote:

>
> Index: patches/patch-src_drivers_driver_openbsd_c
> ===================================================================
> RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
> retrieving revision 1.5
> diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
> --- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
> +++ patches/patch-src_drivers_driver_openbsd_c 28 Nov 2018 17:51:30 -0000
> @@ -2,23 +2,137 @@ $OpenBSD: patch-src_drivers_driver_openb
>  
>  Fix includes
>  
> ---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
> -+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
> -@@ -9,13 +9,14 @@
> +Index: src/drivers/driver_openbsd.c
> +--- src/drivers/driver_openbsd.c.orig
> ++++ src/drivers/driver_openbsd.c
> +@@ -9,19 +9,34 @@
>   #include "includes.h"
>   #include <sys/ioctl.h>
>  
>  +#include "common.h"
>  +#include "driver.h"
> ++#include "eloop.h"
>  +
> ++#include <sys/socket.h>
>   #include <net/if.h>
>  +#include <net/if_var.h>
> ++#include <net/route.h>
>   #include <net80211/ieee80211.h>
>   #include <net80211/ieee80211_crypto.h>
>   #include <net80211/ieee80211_ioctl.h>
> --
> +
>  -#include "common.h"
>  -#include "driver.h"
> ++#define RTM_READSZ 2048
>  
>   struct openbsd_driver_data {
> - char ifname[IFNAMSIZ + 1];
> +- char ifname[IFNAMSIZ + 1];
> + void *ctx;
> +
> +- int sock; /* open socket for 802.11 ioctls */
> ++ char ifname[IFNAMSIZ + 1];
> ++ int ifindex;  /* Ifindex of the configured interface */
> ++
> ++ int sock;     /* open socket for 802.11 ioctls */
> ++ int rtsock;   /* routing socket for interface state messages */
> ++
> ++ /* These fields are used to track the last seen (and associated) access point
> ++   to determine whether we should kick off an association event */
> ++ int nwid_len; /* Length of last seen SSID (as per routing message) */
> ++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
> ++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
> + };
> +
> +
> +@@ -90,6 +105,57 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
> + return 0;
> + }
> +
> ++static void
> ++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
> ++{
> ++ struct openbsd_driver_data *drv = sock_ctx;
> ++ struct rt_msghdr *rtm;
> ++ struct if_ieee80211_data *ifie;
> ++ char *rtmmsg;
> ++ ssize_t n;
> ++
> ++ rtmmsg = os_zalloc(RTM_READSZ);
> ++ if (rtmmsg == NULL) {
> ++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
> ++ return;
> ++ }
> ++
> ++ do {
> ++ n = read(sock, rtmmsg, RTM_READSZ);
> ++ } while (n == -1 && errno == EINTR);
> ++
> ++ if (n == -1)
> ++ goto done;
> ++
> ++ rtm = (struct rt_msghdr *)rtmmsg;
> ++
> ++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
> ++    n < rtm->rtm_msglen ||
> ++    rtm->rtm_version != RTM_VERSION)
> ++ goto done;
> ++
> ++ if ((rtm->rtm_type != RTM_80211INFO) ||
> ++    (rtm->rtm_index != drv->ifindex))
> ++ goto done;
> ++
> ++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
> ++
> ++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
> ++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
> ++    (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
> ++ os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
> ++
> ++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
> ++ drv->nwid_len = ifie->ifie_nwid_len;
> ++
> ++ /* Emit ASSOC event */
> ++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
> ++ }
> ++
> ++done:
> ++ os_free(rtmmsg);
> ++}
> ++
> + static void *
> + wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + {
> +@@ -103,9 +169,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + if (drv->sock < 0)
> + goto fail;
> +
> ++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
> ++ if (drv->rtsock < 0)
> ++ goto fail;
> ++
> + drv->ctx = ctx;
> + os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
> +
> ++ drv->ifindex = if_nametoindex(drv->ifname);
> ++ if (drv->ifindex == 0) /* No interface with that name */
> ++ goto fail;
> ++
> ++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
> ++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
> ++
> ++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
> + return drv;
> +
> + fail:
> +@@ -119,7 +197,11 @@ wpa_driver_openbsd_deinit(void *priv)
> + {
> + struct openbsd_driver_data *drv = priv;
> +
> ++ eloop_unregister_read_sock(drv->rtsock);
> ++
> + close(drv->sock);
> ++ close(drv->rtsock);
> ++
> + os_free(drv);
> + }
> +


Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Edd Barrett-3
In reply to this post by Raf Czlonka-2
On Mon, Dec 10, 2018 at 04:31:02PM +0000, Raf Czlonka wrote:
> Hi Gregor,
>
> When I boot my laptop up, it connects to eduroam just fine.
>
> However, when I move around the building, it does not associate
> with any other AP.

This was my experience too.

It seems that you can sometimes jump back on the network by running:
$ wpa_cli reassoc

--
Best Regards
Edd Barrett

http://www.theunixzoo.co.uk

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Mikolaj Kucharski-3
In reply to this post by Gregor Best-2
Comment inlined about RTM_IFINFO

On Wed, Nov 28, 2018 at 06:56:46PM +0100, Gregor Best wrote:

> Index: patches/patch-src_drivers_driver_openbsd_c
> ===================================================================
> RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
> retrieving revision 1.5
> diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
> --- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
> +++ patches/patch-src_drivers_driver_openbsd_c 28 Nov 2018 17:51:30 -0000
> @@ -2,23 +2,137 @@ $OpenBSD: patch-src_drivers_driver_openb
>  
>  Fix includes
>  
> ---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
> -+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
> -@@ -9,13 +9,14 @@
> +Index: src/drivers/driver_openbsd.c
> +--- src/drivers/driver_openbsd.c.orig
> ++++ src/drivers/driver_openbsd.c
> +@@ -9,19 +9,34 @@
>   #include "includes.h"
>   #include <sys/ioctl.h>
>  
>  +#include "common.h"
>  +#include "driver.h"
> ++#include "eloop.h"
>  +
> ++#include <sys/socket.h>
>   #include <net/if.h>
>  +#include <net/if_var.h>
> ++#include <net/route.h>
>   #include <net80211/ieee80211.h>
>   #include <net80211/ieee80211_crypto.h>
>   #include <net80211/ieee80211_ioctl.h>
> --
> +
>  -#include "common.h"
>  -#include "driver.h"
> ++#define RTM_READSZ 2048
>  
>   struct openbsd_driver_data {
> - char ifname[IFNAMSIZ + 1];
> +- char ifname[IFNAMSIZ + 1];
> + void *ctx;
> +
> +- int sock; /* open socket for 802.11 ioctls */
> ++ char ifname[IFNAMSIZ + 1];
> ++ int ifindex;  /* Ifindex of the configured interface */
> ++
> ++ int sock;     /* open socket for 802.11 ioctls */
> ++ int rtsock;   /* routing socket for interface state messages */
> ++
> ++ /* These fields are used to track the last seen (and associated) access point
> ++   to determine whether we should kick off an association event */
> ++ int nwid_len; /* Length of last seen SSID (as per routing message) */
> ++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
> ++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
> + };
> +
> +
> +@@ -90,6 +105,57 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
> + return 0;
> + }
> +
> ++static void
> ++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
> ++{
> ++ struct openbsd_driver_data *drv = sock_ctx;
> ++ struct rt_msghdr *rtm;
> ++ struct if_ieee80211_data *ifie;
> ++ char *rtmmsg;
> ++ ssize_t n;
> ++
> ++ rtmmsg = os_zalloc(RTM_READSZ);
> ++ if (rtmmsg == NULL) {
> ++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
> ++ return;
> ++ }
> ++
> ++ do {
> ++ n = read(sock, rtmmsg, RTM_READSZ);
> ++ } while (n == -1 && errno == EINTR);
> ++
> ++ if (n == -1)
> ++ goto done;
> ++
> ++ rtm = (struct rt_msghdr *)rtmmsg;
> ++
> ++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
> ++    n < rtm->rtm_msglen ||
> ++    rtm->rtm_version != RTM_VERSION)
> ++ goto done;
> ++
> ++ if ((rtm->rtm_type != RTM_80211INFO) ||

I'm currently testing your diff with additional condition to also
handle RTM_IFINFO, as I see it happening just after resume:

1544537117.597172: XXX wpa_driver_openbsd_event_receive() start
1544537117.597197: XXX evnt_rcv: name=iwn0, type=0xe

> ++    (rtm->rtm_index != drv->ifindex))
> ++ goto done;
> ++
> ++ ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
> ++
> ++ if ((ifie->ifie_nwid_len != drv->nwid_len) ||
> ++    (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
> ++    (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
> ++ os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
> ++
> ++ os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
> ++ drv->nwid_len = ifie->ifie_nwid_len;
> ++
> ++ /* Emit ASSOC event */
> ++ wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
> ++ }
> ++
> ++done:
> ++ os_free(rtmmsg);
> ++}
> ++
> + static void *
> + wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + {
> +@@ -103,9 +169,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + if (drv->sock < 0)
> + goto fail;
> +
> ++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
> ++ if (drv->rtsock < 0)
> ++ goto fail;
> ++
> + drv->ctx = ctx;
> + os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
> +
> ++ drv->ifindex = if_nametoindex(drv->ifname);
> ++ if (drv->ifindex == 0) /* No interface with that name */
> ++ goto fail;
> ++
> ++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
> ++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
> ++
> ++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
> + return drv;
> +
> + fail:
> +@@ -119,7 +197,11 @@ wpa_driver_openbsd_deinit(void *priv)
> + {
> + struct openbsd_driver_data *drv = priv;
> +
> ++ eloop_unregister_read_sock(drv->rtsock);
> ++
> + close(drv->sock);
> ++ close(drv->rtsock);
> ++
> + os_free(drv);
> + }
> +


Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Raf Czlonka-2
In reply to this post by Edd Barrett-3
On Tue, Dec 11, 2018 at 11:35:42AM GMT, Edd Barrett wrote:

> On Mon, Dec 10, 2018 at 04:31:02PM +0000, Raf Czlonka wrote:
> > Hi Gregor,
> >
> > When I boot my laptop up, it connects to eduroam just fine.
> >
> > However, when I move around the building, it does not associate
> > with any other AP.
>
> This was my experience too.
>
> It seems that you can sometimes jump back on the network by running:
> $ wpa_cli reassoc
>

Hi Edd,

For me this happened *only* after going back near the AP the laptop
originally associated with.

Regards,

Raf

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Edd Barrett-3
On Tue, Dec 11, 2018 at 05:19:26PM +0000, Raf Czlonka wrote:
> For me this happened *only* after going back near the AP the laptop
> originally associated with.

Ah yes. As it happens, that was when I did it too!

Sorry, I wasn't clear.

--
Best Regards
Edd Barrett

http://www.theunixzoo.co.uk

Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Gregor Best-2
In reply to this post by Mikolaj Kucharski-3

Hi Mikolaj,

> [...]
> I'm currently testing your diff with additional condition to also
> handle RTM_IFINFO, as I see it happening just after resume:
>
> 1544537117.597172: XXX wpa_driver_openbsd_event_receive() start
> 1544537117.597197: XXX evnt_rcv: name=iwn0, type=0xe
> [...]

Good idea. How does it work for you? I'll add this to my patch as well
and try it a bit tonight.

--
        Gregor

signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Gregor Best-2
In reply to this post by Edd Barrett-3

Hi Edd, Raf, Mikolaj, ports@

I just updated my proposed patch with Mikolaj's suggestion of also
listening to RTM_IFINFO instead of just RTM_80211INFO. The patch is
attached below the signature.

It makes reassociation over suspend/resume work (if I resume in the
same spot I suspended in, haven't checked going out of range). What's
noteworthy is that it takes a while (in the area of 10 - 15 seconds)
for wpa_supplicant to re-establish a connection.

As for Edd's report that moving out of range with the device on doesn't
cause re-association (did I understand that correctly?), I think the
output of `route monitor` and `ifconfig $dev scan` before and after
loss of signal (and going into range of the other AP) might be
interesting to see if there's another routing message that we have to
consider.

Maybe the attached patch also helps Edd's situation. As always, I'm
grateful for testing and feedback.

--
        Gregor

Index: patches/patch-src_drivers_driver_openbsd_c
===================================================================
RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
retrieving revision 1.5
diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
--- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
+++ patches/patch-src_drivers_driver_openbsd_c 12 Dec 2018 20:18:19 -0000
@@ -1,24 +1,151 @@
 $OpenBSD: patch-src_drivers_driver_openbsd_c,v 1.5 2016/05/17 08:29:27 dcoppa Exp $
 
-Fix includes
+Fix includes and react to NWID changes and suspend/resume.
 
---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
-+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
-@@ -9,13 +9,14 @@
+Index: src/drivers/driver_openbsd.c
+--- src/drivers/driver_openbsd.c.orig
++++ src/drivers/driver_openbsd.c
+@@ -9,19 +9,34 @@
  #include "includes.h"
  #include <sys/ioctl.h>
-
+
 +#include "common.h"
 +#include "driver.h"
++#include "eloop.h"
 +
++#include <sys/socket.h>
  #include <net/if.h>
 +#include <net/if_var.h>
++#include <net/route.h>
  #include <net80211/ieee80211.h>
  #include <net80211/ieee80211_crypto.h>
  #include <net80211/ieee80211_ioctl.h>
--
+
 -#include "common.h"
 -#include "driver.h"
-
++#define RTM_READSZ 2048
+
  struct openbsd_driver_data {
- char ifname[IFNAMSIZ + 1];
+- char ifname[IFNAMSIZ + 1];
+ void *ctx;
+
+- int sock; /* open socket for 802.11 ioctls */
++ char ifname[IFNAMSIZ + 1];
++ int ifindex;  /* Ifindex of the configured interface */
++
++ int sock;     /* open socket for 802.11 ioctls */
++ int rtsock;   /* routing socket for interface state messages */
++
++ /* These fields are used to track the last seen (and associated) access point
++   to determine whether we should kick off an association event */
++ int nwid_len; /* Length of last seen SSID (as per routing message) */
++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
+ };
+
+
+@@ -90,6 +105,71 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
+ return 0;
+ }
+
++static void
++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
++{
++ struct openbsd_driver_data *drv = sock_ctx;
++ struct rt_msghdr *rtm;
++ struct if_ieee80211_data *ifie;
++ char *rtmmsg;
++ ssize_t n;
++
++ rtmmsg = os_zalloc(RTM_READSZ);
++ if (rtmmsg == NULL) {
++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
++ return;
++ }
++
++ do {
++ n = read(sock, rtmmsg, RTM_READSZ);
++ } while (n == -1 && errno == EINTR);
++
++ if (n == -1)
++ goto done;
++
++ rtm = (struct rt_msghdr *)rtmmsg;
++
++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
++    n < rtm->rtm_msglen ||
++    rtm->rtm_version != RTM_VERSION)
++ goto done;
++
++  if (rtm->rtm_index != drv->ifindex)
++    goto done;
++
++  if (rtm->rtm_type == RTM_80211INFO) {
++    printf("RTM_80211INFO received\n");
++    ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
++
++    if ((ifie->ifie_nwid_len != drv->nwid_len) ||
++        (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
++        (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
++      os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
++
++      os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
++      drv->nwid_len = ifie->ifie_nwid_len;
++
++      /* Emit ASSOC event */
++      wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
++    }
++ } else if (rtm->rtm_type == RTM_IFINFO) {
++    /* This is here so we can react to suspend/resume.
++
++       This is a bit rough, sometimes there are two or more IFINFOs notifying
++       us that the device just got "up" again. It doesn't seem to hurt to
++       issue multiple EVENT_ASSOC in those cases though.
++    */
++
++    if (rtm->rtm_flags & RTF_UP) {
++      /* Emit ASSOC event */
++      wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
++    }
++  }
++
++done:
++ os_free(rtmmsg);
++}
++
+ static void *
+ wpa_driver_openbsd_init(void *ctx, const char *ifname)
+ {
+@@ -103,9 +183,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
+ if (drv->sock < 0)
+ goto fail;
+
++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
++ if (drv->rtsock < 0)
++ goto fail;
++
+ drv->ctx = ctx;
+ os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
+
++ drv->ifindex = if_nametoindex(drv->ifname);
++ if (drv->ifindex == 0) /* No interface with that name */
++ goto fail;
++
++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
++
++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
+ return drv;
+
+ fail:
+@@ -119,7 +211,11 @@ wpa_driver_openbsd_deinit(void *priv)
+ {
+ struct openbsd_driver_data *drv = priv;
+
++ eloop_unregister_read_sock(drv->rtsock);
++
+ close(drv->sock);
++ close(drv->rtsock);
++
+ os_free(drv);
+ }

signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Mikolaj Kucharski-3
Gregor,

Thank you for working on this. I have one comment about your code,
comments inlined in your below diff.

Here is debug output of one day session, with suspend in the middle
when going home, back to work and home again.

# grep -E 'type=0x(15|e)' wpa_supplicant.log
1544550580.320374: XXX evnt_rcv: name=iwn0, type=0x15
1544550580.321089: XXX evnt_rcv: name=iwn0, type=0xe
1544558742.024184: XXX evnt_rcv: name=iwn0, type=0xe
1544558753.880521: XXX evnt_rcv: name=iwn0, type=0x15
1544558753.883372: XXX evnt_rcv: name=iwn0, type=0xe
1544612208.200216: XXX evnt_rcv: name=iwn0, type=0xe
1544612217.053147: XXX evnt_rcv: name=iwn0, type=0x15
1544612217.053676: XXX evnt_rcv: name=iwn0, type=0xe
1544648478.023587: XXX evnt_rcv: name=iwn0, type=0xe

Above is while being sationary and not going around in the office.
This means that I switched only between AP closest to my desk and
to home AP with resume in between. Interestingly it seems that
each RTM_80211INFO is also accompanied with RTM_IFINFO, in random
order.

Tomorrow I may give you example of above log when walking around the
office, to compare events while switching APs. The other day I did
testing by walking around and it works most of the time, however there
is a race somewhere, as while I was walking around I sometimes ended up
without connection and ifconfig(8) at the same time was showing:

        status: active
        ieee80211: join lighthouse chan 100 bssid <random-ap-close> <level>dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp

like network should work, but it didn't and connection was totally
offline. This is very empirical, but it looked to me, when I walked
slower to give wpa_supplicant time to reassoc with each access point on
the way it all worked. When I got bored and walked faster, passing by
multiple APs on the way and with reassocs happening one after another,
before previous assoc was able to finish and me finally stopping, I
ended up with iwn0 card with status active, but no connectivity.
Restarting slaacd(8) or dhclient(8) was not helping as problem was layer
below them.

All in all, I would need to test all of this more and collect more debug
information. Unfortunately this is my last week with my current employer,
so in practice tomorrow is my last day I can test all of this :)

I think your diff makes sense and with handling of RTM_IFINFO it's good
progress in correct direction. I even took your diff and tested with
latest wpa_supplicant 2.7 and it works there too. However I cannot
dive into this more, as I have too many changes in my personal and
professional life in coming days.

If you would like to see any specific info tomorrow, please let me know
I will try to arrange something. After that I'll go offline for family
time.

See comments inline your diff below.

Regards,
 Mikolaj

On Wed, Dec 12, 2018 at 09:44:24PM +0100, Gregor Best wrote:

>
> Hi Edd, Raf, Mikolaj, ports@
>
> I just updated my proposed patch with Mikolaj's suggestion of also
> listening to RTM_IFINFO instead of just RTM_80211INFO. The patch is
> attached below the signature.
>
> It makes reassociation over suspend/resume work (if I resume in the
> same spot I suspended in, haven't checked going out of range). What's
> noteworthy is that it takes a while (in the area of 10 - 15 seconds)
> for wpa_supplicant to re-establish a connection.
>
> As for Edd's report that moving out of range with the device on doesn't
> cause re-association (did I understand that correctly?), I think the
> output of `route monitor` and `ifconfig $dev scan` before and after
> loss of signal (and going into range of the other AP) might be
> interesting to see if there's another routing message that we have to
> consider.
>
> Maybe the attached patch also helps Edd's situation. As always, I'm
> grateful for testing and feedback.
>
> --
> Gregor
>
> Index: patches/patch-src_drivers_driver_openbsd_c
> ===================================================================
> RCS file: /home/cvs/ports/security/wpa_supplicant/patches/patch-src_drivers_driver_openbsd_c,v
> retrieving revision 1.5
> diff -u -p -r1.5 patch-src_drivers_driver_openbsd_c
> --- patches/patch-src_drivers_driver_openbsd_c 17 May 2016 08:29:27 -0000 1.5
> +++ patches/patch-src_drivers_driver_openbsd_c 12 Dec 2018 20:18:19 -0000
> @@ -1,24 +1,151 @@
>  $OpenBSD: patch-src_drivers_driver_openbsd_c,v 1.5 2016/05/17 08:29:27 dcoppa Exp $
>  
> -Fix includes
> +Fix includes and react to NWID changes and suspend/resume.
>  
> ---- src/drivers/driver_openbsd.c.orig Sun Sep 27 21:02:05 2015
> -+++ src/drivers/driver_openbsd.c Mon Sep 28 09:51:53 2015
> -@@ -9,13 +9,14 @@
> +Index: src/drivers/driver_openbsd.c
> +--- src/drivers/driver_openbsd.c.orig
> ++++ src/drivers/driver_openbsd.c
> +@@ -9,19 +9,34 @@
>   #include "includes.h"
>   #include <sys/ioctl.h>
> -
> +
>  +#include "common.h"
>  +#include "driver.h"
> ++#include "eloop.h"
>  +
> ++#include <sys/socket.h>
>   #include <net/if.h>
>  +#include <net/if_var.h>
> ++#include <net/route.h>
>   #include <net80211/ieee80211.h>
>   #include <net80211/ieee80211_crypto.h>
>   #include <net80211/ieee80211_ioctl.h>
> --
> +
>  -#include "common.h"
>  -#include "driver.h"
> -
> ++#define RTM_READSZ 2048
> +
>   struct openbsd_driver_data {
> - char ifname[IFNAMSIZ + 1];
> +- char ifname[IFNAMSIZ + 1];
> + void *ctx;
> +
> +- int sock; /* open socket for 802.11 ioctls */
> ++ char ifname[IFNAMSIZ + 1];
> ++ int ifindex;  /* Ifindex of the configured interface */
> ++
> ++ int sock;     /* open socket for 802.11 ioctls */
> ++ int rtsock;   /* routing socket for interface state messages */
> ++
> ++ /* These fields are used to track the last seen (and associated) access point
> ++   to determine whether we should kick off an association event */
> ++ int nwid_len; /* Length of last seen SSID (as per routing message) */
> ++ char nwid[IEEE80211_NWID_LEN]; /* Last seen SSID (as per routing message) */
> ++ char addr[IEEE80211_ADDR_LEN]; /* Last seen BSSID (as per routing message) */
> + };
> +
> +
> +@@ -90,6 +105,71 @@ wpa_driver_openbsd_set_key(const char *ifname, void *p
> + return 0;
> + }
> +
> ++static void
> ++wpa_driver_openbsd_event_receive(int sock, void *global, void *sock_ctx)
> ++{
> ++ struct openbsd_driver_data *drv = sock_ctx;
> ++ struct rt_msghdr *rtm;
> ++ struct if_ieee80211_data *ifie;
> ++ char *rtmmsg;
> ++ ssize_t n;
> ++
> ++ rtmmsg = os_zalloc(RTM_READSZ);
> ++ if (rtmmsg == NULL) {
> ++ wpa_printf(MSG_ERROR, "Can't allocate space for routing message");
> ++ return;
> ++ }
> ++
> ++ do {
> ++ n = read(sock, rtmmsg, RTM_READSZ);
> ++ } while (n == -1 && errno == EINTR);
> ++
> ++ if (n == -1)
> ++ goto done;
> ++
> ++ rtm = (struct rt_msghdr *)rtmmsg;
> ++
> ++ if ((size_t)n < sizeof(rtm->rtm_msglen) ||
> ++    n < rtm->rtm_msglen ||
> ++    rtm->rtm_version != RTM_VERSION)
> ++ goto done;
> ++
> ++  if (rtm->rtm_index != drv->ifindex)
> ++    goto done;
> ++
> ++  if (rtm->rtm_type == RTM_80211INFO) {
> ++    printf("RTM_80211INFO received\n");

This printf(3) should be removed or changed into wpa_printf(). For my tests
I've used wpa_printf(MSG_DEBUG, ...), which I think is good enough balance
of being not noisy in logs by default, but still providing info when there
is a need via debug flag to the cli. However this is your call and giving
the current sparsity of debug log lines in this c-file, I would just remove
it.

> ++    ifie = &((struct if_ieee80211_msghdr *)rtm)->ifim_ifie;
> ++
> ++    if ((ifie->ifie_nwid_len != drv->nwid_len) ||
> ++        (os_memcmp(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len) != 0) ||
> ++        (os_memcmp(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN) != 0)) {
> ++      os_memcpy(drv->addr, ifie->ifie_addr, IEEE80211_ADDR_LEN);
> ++
> ++      os_memcpy(drv->nwid, ifie->ifie_nwid, ifie->ifie_nwid_len);
> ++      drv->nwid_len = ifie->ifie_nwid_len;
> ++
> ++      /* Emit ASSOC event */
> ++      wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
> ++    }
> ++ } else if (rtm->rtm_type == RTM_IFINFO) {
> ++    /* This is here so we can react to suspend/resume.
> ++
> ++       This is a bit rough, sometimes there are two or more IFINFOs notifying
> ++       us that the device just got "up" again. It doesn't seem to hurt to
> ++       issue multiple EVENT_ASSOC in those cases though.
> ++    */
> ++
> ++    if (rtm->rtm_flags & RTF_UP) {
> ++      /* Emit ASSOC event */
> ++      wpa_supplicant_event(drv->ctx, EVENT_ASSOC, NULL);
> ++    }
> ++  }
> ++
> ++done:
> ++ os_free(rtmmsg);
> ++}
> ++
> + static void *
> + wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + {
> +@@ -103,9 +183,21 @@ wpa_driver_openbsd_init(void *ctx, const char *ifname)
> + if (drv->sock < 0)
> + goto fail;
> +
> ++ drv->rtsock = socket(PF_ROUTE, SOCK_RAW, AF_UNSPEC);
> ++ if (drv->rtsock < 0)
> ++ goto fail;
> ++
> + drv->ctx = ctx;
> + os_strlcpy(drv->ifname, ifname, sizeof(drv->ifname));
> +
> ++ drv->ifindex = if_nametoindex(drv->ifname);
> ++ if (drv->ifindex == 0) /* No interface with that name */
> ++ goto fail;
> ++
> ++ drv->nwid_len = wpa_driver_openbsd_get_ssid(drv, drv->nwid);
> ++ wpa_driver_openbsd_get_bssid(drv, drv->addr);
> ++
> ++ eloop_register_read_sock(drv->rtsock, wpa_driver_openbsd_event_receive, NULL, drv);
> + return drv;
> +
> + fail:
> +@@ -119,7 +211,11 @@ wpa_driver_openbsd_deinit(void *priv)
> + {
> + struct openbsd_driver_data *drv = priv;
> +
> ++ eloop_unregister_read_sock(drv->rtsock);
> ++
> + close(drv->sock);
> ++ close(drv->rtsock);
> ++
> + os_free(drv);
> + }


Reply | Threaded
Open this post in threaded view
|

Re: security/wpa_supplicant: Reassoc on NWID change

Gregor Best-2

Hi Mikolaj et al,

Mikolaj Kucharski <[hidden email]> writes:

>
> Here is debug output of one day session, with suspend in the middle
> when going home, back to work and home again.
> [...]
> Tomorrow I may give you example of above log when walking around the
> office, to compare events while switching APs.
> [...]

That'd be good, thank you.

> The other day I did testing by walking around and it works most of the
> time, however there is a race somewhere, as while I was walking around
> I sometimes ended up without connection and ifconfig(8) at the same
> time was showing:
>
> status: active
> ieee80211: join lighthouse chan 100 bssid <random-ap-close> <level>dBm wpaprotos wpa2 wpaakms 802.1x wpaciphers ccmp wpagroupcipher ccmp
>
> like network should work, but it didn't and connection was totally
> offline.

> This is very empirical, but it looked to me, when I walked
> slower to give wpa_supplicant time to reassoc with each access point on
> the way it all worked. When I got bored and walked faster, passing by
> multiple APs on the way and with reassocs happening one after another,
> before previous assoc was able to finish and me finally stopping, I
> ended up with iwn0 card with status active, but no connectivity.
> Restarting slaacd(8) or dhclient(8) was not helping as problem was layer
> below them.
> [...]

Yeah, I've got the feeling that wpa_supplicant really doesn't like
getting poked while it's doing its thing. Maybe I've got to work on the
timing here a bit or sort of deduplicate ASSOC events after multiple
IFINFO/802INFO are received.

> [...]
> I think your diff makes sense and with handling of RTM_IFINFO it's good
> progress in correct direction. I even took your diff and tested with
> latest wpa_supplicant 2.7 and it works there too.
> [...]

That is good to hear. I'm planning on sending this upstream as soon as
we've agreed it's more or less working.

> [...]
> If you would like to see any specific info tomorrow, please let me know
> I will try to arrange something. After that I'll go offline for family
> time.
> [...]

I'm afraid I don't have anything more specific I could ask you to test.
Thanks a bunch for your help this far. I'll just have to walk around my
university some time next week, I'm not at work then anyway :)

> [...]
>> ++  if (rtm->rtm_type == RTM_80211INFO) {
>> ++    printf("RTM_80211INFO received\n");
>
> This printf(3) should be removed or changed into wpa_printf(). For my tests
> I've used wpa_printf(MSG_DEBUG, ...), which I think is good enough balance
> of being not noisy in logs by default, but still providing info when there
> is a need via debug flag to the cli. However this is your call and giving
> the current sparsity of debug log lines in this c-file, I would just remove
> it.
> [...]
Absolutely. This was an oversight that I wanted to remove before sending
out the patch. Same for the weird indentation :)

--
        Gregor

signature.asc (849 bytes) Download Attachment