wpa_supplicant, SAE secured MESH on RT5370 doesn't PING after peer connection is established

Greg Gigon greg.gigon at gmail.com
Tue Dec 6 05:05:47 PST 2016 

After returning to the MESH on Rasperry PI, I compiled the kernel from here: https://github.com/raspberrypi/linux/tree/rpi-4.8.y
I also got the latest code of wpa_supplicant (2.6) and recompiled it with CONFIG_MESH=y and CONFIG_IEEE80211W=y

My understanding is, that the 4.8.y branch in Raspberry PI repository merges the patches from Upstream vanilla Kernel.

The same problem still persists. I can see in the debug messages (at the bottom of this mail) that mesh node initiates the key exchange.
Ping and ARP still have problem with reaching host though.

How would I go about debugging the issue at this point? Please help :)
Greg

mesh: joining mesh foobar
nl80211: mesh join (ifindex=5)
  * freq=2442
  * vht_enabled=0
  * ht_enabled=1
  * sec_channel_offset=0
  * channel_type=1
  * Mesh ID (SSID) - hexdump_ascii(len=6):
     66 6f 6f 62 61 72                                 foobar
  * flags=0000000D
  * IEs - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 08 00 00
nl80211: mesh join request send successfully
nl80211: Set mesh operstate 1->1 (UP)
netlink: Operstate: ifindex=5 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
mesh: State: SCANNING -> COMPLETED
mesh: CTRL-EVENT-CONNECTED - Connection to 00:00:00:00:00:00 completed [id=0 id_str=]
nl80211: Set mesh operstate 1->1 (UP)
netlink: Operstate: ifindex=5 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
mesh: MESH-GROUP-STARTED ssid="foobar" id=0
RTM_NEWLINK: ifi_index=5 ifname=mesh wext ifi_family=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK: ifi_index=5 ifname=mesh operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1002 ()
nl80211: Ignore interface down event since interface mesh is up
RTM_NEWLINK: ifi_index=5 ifname=mesh operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK: ifi_index=5 ifname=mesh operstate=5 linkmode=1 ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
nl80211: Set IF_OPER_UP again based on ifi_flags and expected operstate
netlink: Operstate: ifindex=5 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
RTM_NEWLINK: ifi_index=5 ifname=mesh operstate=6 linkmode=1 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
l2_packet_receive - recvfrom: Network is down
RTM_NEWLINK: ifi_index=5 ifname=mesh operstate=6 linkmode=1 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
nl80211: Drv Event 72 (NL80211_CMD_NEW_PEER_CANDIDATE) received for mesh
nl80211: New peer candidate 00:19:86:11:98:93
mesh: Event NEW_PEER_CANDIDATE (49) received
mesh: new peer notification for 00:19:86:11:98:93
  New STA
ap_sta_add: register ap_handle_timer timeout for 00:19:86:11:98:93 (300 seconds - ap_max_inactivity)
  new AID 1
nl80211: Add STA 00:19:86:11:98:93
  * supported rates - hexdump(len=12): 82 84 8b 96 8c 12 98 24 b0 48 60 6c
  * capability=0x0
  * aid=1
  * listen_interval=100
  * flags set=0x18 mask=0x38
  * qosinfo=0x0
mesh: SME: Selected SAE group 19
SAE: password - hexdump_ascii(len=18): [REMOVED]
SAE: PWE derivation - addr1=00:19:86:81:42:62 addr2=00:19:86:11:98:93
SAE: counter = 1
SAE: pwd-seed - hexdump(len=32): [REMOVED]
SAE: pwd-value - hexdump(len=32): [REMOVED]
SAE: Selected pwd-seed with counter 1
...
SAE: pwd-seed - hexdump(len=32): [REMOVED]
SAE: pwd-value - hexdump(len=32): [REMOVED]
mesh: AUTH: started authentication with SAE peer: 00:19:86:11:98:93
SAE: own commit-scalar - hexdump(len=32): f6 b1 27 db 49 40 02 31 ce b3 24 76 67 e5 a0 dd f1 13 6b e3 ac 21 95 a8 de f1 1c 6d 84 5b 39 89
SAE: own commit-element(x) - hexdump(len=32): 71 e3 da a5 54 d3 dd 75 e4 4f 4a 39 a6 49 f0 a3 ac 67 e6 d7 fd be d6 61 99 f5 6b cc 10 68 0f 82
SAE: own commit-element(y) - hexdump(len=32): 61 f2 55 53 0f 77 82 26 97 a8 d4 37 2a ea 7a 9f c6 aa af dc 82 ae 61 8f 5f 08 9f 78 4f 93 cf 0f
authentication reply: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=1 resp=0 (IE len=98)
nl80211: send_mlme - da= 00:19:86:11:98:93 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2442
nl80211: send_frame -> send_frame_cmd
nl80211: Drv Event 19 (NL80211_CMD_NEW_STATION) received for mesh
nl80211: New station 00:19:86:11:98:93
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=04 (unknown) (ack=1)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for mesh
nl80211: RX frame da=00:19:86:81:42:62 sa=00:19:86:11:98:93 bssid=00:19:86:11:98:93 freq=2442 ssi_signal=-29 fc=0xb0 seq_ctrl=0xbe0 stype=11 (WLAN_FC_STYPE_AUTH) len=128
mesh: Event RX_MGMT (19) received
mgmt::auth
authentication: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=1 status_code=0 wep=0 seq_ctrl=0xbe0
hostapd_logger: STA 00:19:86:11:98:93 - start SAE authentication (RX commit, status=0)
SAE: Peer commit-scalar - hexdump(len=32): 0d ee 71 bc cd 98 51 d8 92 cb 60 1d 57 39 fe 70 96 89 c3 de 69 d2 26 03 d6 52 0f 82 fe 60 52 a2
SAE: Peer commit-element(x) - hexdump(len=32): 92 65 01 59 13 95 85 55 c4 41 90 99 08 ba bb 4f 82 7a 49 b9 03 e3 65 f2 fe 03 27 11 57 e9 b9 6c
SAE: Peer commit-element(y) - hexdump(len=32): f5 7d 1f 7d 3b 9b 24 4c 1d 64 4e 41 e9 a1 32 66 5e 52 d2 63 61 4e f3 3e 4b 22 0a 1b e9 01 e7 f8
SAE: k - hexdump(len=32): [REMOVED]
SAE: keyseed - hexdump(len=32): [REMOVED]
SAE: PMKID - hexdump(len=16): 04 9f 99 99 16 d8 54 09 61 7e 84 93 bf 1f 9f 4e
SAE: KCK - hexdump(len=32): [REMOVED]
SAE: PMK - hexdump(len=32): [REMOVED]
authentication reply: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=2 resp=0 (IE len=34)
nl80211: send_mlme - da= 00:19:86:11:98:93 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2442
nl80211: send_frame -> send_frame_cmd
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=05 (unknown) (ack=1)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for mesh
nl80211: RX frame da=00:19:86:81:42:62 sa=00:19:86:11:98:93 bssid=00:19:86:11:98:93 freq=2442 ssi_signal=-31 fc=0xb0 seq_ctrl=0xbf0 stype=11 (WLAN_FC_STYPE_AUTH) len=128
mesh: Event RX_MGMT (19) received
mgmt::auth
authentication: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=1 status_code=0 wep=0 seq_ctrl=0xbf0
hostapd_logger: STA 00:19:86:11:98:93 - start SAE authentication (RX commit, status=0)
SAE: Peer commit-scalar - hexdump(len=32): 0d ee 71 bc cd 98 51 d8 92 cb 60 1d 57 39 fe 70 96 89 c3 de 69 d2 26 03 d6 52 0f 82 fe 60 52 a2
SAE: Peer commit-element(x) - hexdump(len=32): 92 65 01 59 13 95 85 55 c4 41 90 99 08 ba bb 4f 82 7a 49 b9 03 e3 65 f2 fe 03 27 11 57 e9 b9 6c
SAE: Peer commit-element(y) - hexdump(len=32): f5 7d 1f 7d 3b 9b 24 4c 1d 64 4e 41 e9 a1 32 66 5e 52 d2 63 61 4e f3 3e 4b 22 0a 1b e9 01 e7 f8
SAE: password - hexdump_ascii(len=18): [REMOVED]
SAE: PWE derivation - addr1=00:19:86:81:42:62 addr2=00:19:86:11:98:93
SAE: counter = 1
SAE: pwd-seed - hexdump(len=32): [REMOVED]
SAE: pwd-value - hexdump(len=32): [REMOVED]
...
SAE: pwd-seed - hexdump(len=32): [REMOVED]
SAE: pwd-value - hexdump(len=32): [REMOVED]
SAE: own commit-scalar - hexdump(len=32): 67 7f 87 ed b5 4a 99 c5 60 78 6c 0a 59 90 4e d9 9c 9a 4c 30 1b 8d 8c 51 db fe 97 79 d8 68 32 72
SAE: own commit-element(x) - hexdump(len=32): 48 b8 46 89 f9 34 cc 88 11 59 33 1b ef 2f 1f 20 8e 89 d4 9e b2 81 e7 74 86 1d bb 89 0b eb 88 3d
SAE: own commit-element(y) - hexdump(len=32): 7e 7a 52 b0 0f 1f f3 b5 06 4b d8 4a 96 b2 f5 ab f3 c1 c0 e8 b4 fe 39 14 3f 19 07 a0 3c 30 a5 6f
authentication reply: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=1 resp=0 (IE len=98)
nl80211: send_mlme - da= 00:19:86:11:98:93 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2442
nl80211: send_frame -> send_frame_cmd
SAE: k - hexdump(len=32): [REMOVED]
SAE: keyseed - hexdump(len=32): [REMOVED]
SAE: PMKID - hexdump(len=16): 75 6d f9 aa 82 e2 eb 9d f3 43 cc 27 b0 ca 4d 4a
SAE: KCK - hexdump(len=32): [REMOVED]
SAE: PMK - hexdump(len=32): [REMOVED]
authentication reply: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=2 resp=0 (IE len=34)
nl80211: send_mlme - da= 00:19:86:11:98:93 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2442
nl80211: send_frame -> send_frame_cmd
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=06 (unknown) (ack=1)
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=07 (unknown) (ack=1)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for mesh
nl80211: RX frame da=00:19:86:81:42:62 sa=00:19:86:11:98:93 bssid=00:19:86:11:98:93 freq=2442 ssi_signal=-29 fc=0xb0 seq_ctrl=0xc10 stype=11 (WLAN_FC_STYPE_AUTH) len=64
mesh: Event RX_MGMT (19) received
mgmt::auth
authentication: STA=00:19:86:11:98:93 auth_alg=3 auth_transaction=2 status_code=0 wep=0 seq_ctrl=0xc10
hostapd_logger: STA 00:19:86:11:98:93 - SAE authentication (RX confirm, status=0)
SAE: peer-send-confirm 0
hostapd_logger: STA 00:19:86:11:98:93 - MLME-AUTHENTICATE.indication(00:19:86:11:98:93, unknown)
AUTH: 00:19:86:11:98:93 - event 0 notification
mesh: MPM authenticating 00:19:86:11:98:93
nl80211: Set STA 00:19:86:11:98:93
  * flags set=0x22 mask=0x22
mesh: Plaintext AMPE element - hexdump(len=98): [REMOVED]
mesh: Mesh MPM: Sending peering frame type 1 to 00:19:86:11:98:93 (my_lid=0x9634 peer_lid=0x0)
nl80211: Send Action frame (ifindex=5, freq=2442 MHz wait=0 ms no_cck=0)
mesh: MPM set 00:19:86:11:98:93 from IDLE into OPN_SNT
nl80211: Set STA 00:19:86:11:98:93
  * flags set=0x0 mask=0x0
RSN: added PMKSA cache entry for 00:19:86:11:98:93
RSN: added PMKID - hexdump(len=16): 75 6d f9 aa 82 e2 eb 9d f3 43 cc 27 b0 ca 4d 4a
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for mesh
nl80211: RX frame da=00:19:86:81:42:62 sa=00:19:86:11:98:93 bssid=00:19:86:11:98:93 freq=2442 ssi_signal=-31 fc=0xd0 seq_ctrl=0xc20 stype=13 (WLAN_FC_STYPE_ACTION) len=221
mesh: Event RX_MGMT (19) received
mesh: Received Action frame: SA=00:19:86:11:98:93 Category=15 DataLen=196 freq=2442 MHz
MPM: Received PLINK action 1
MPM: Capability 0x10
MPM: plid=0x950f llid=0x0
mesh: Decrypted AMPE element - hexdump(len=98): [REMOVED]
mesh: GTKdata - MGTK - hexdump(len=16): [REMOVED]
mesh: GTKdata - MGTK - Key RSC - hexdump(len=8): 00 00 00 00 00 00 00 00
mesh: GTKdata - MGTK - GTKExpirationTime: 4294967295 seconds
mesh: MPM 00:19:86:11:98:93 state OPN_SNT event OPN_ACPT
mesh: MPM set 00:19:86:11:98:93 from OPN_SNT into OPN_RCVD
nl80211: Set STA 00:19:86:11:98:93
  * flags set=0x0 mask=0x0
mesh: Plaintext AMPE element - hexdump(len=70): [REMOVED]
mesh: Mesh MPM: Sending peering frame type 2 to 00:19:86:11:98:93 (my_lid=0x9634 peer_lid=0x950f)
nl80211: Send Action frame (ifindex=5, freq=2442 MHz wait=0 ms no_cck=0)
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=08 (unknown) (ack=1)
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=09 (match) (ack=1)
mesh: Event TX_STATUS (17) received
mesh: EVENT_TX_STATUS dst=00:19:86:11:98:93 type=0 stype=13
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for mesh
nl80211: RX frame da=00:19:86:81:42:62 sa=00:19:86:11:98:93 bssid=00:19:86:11:98:93 freq=2442 ssi_signal=-31 fc=0xd0 seq_ctrl=0xc30 stype=13 (WLAN_FC_STYPE_ACTION) len=197
mesh: Event RX_MGMT (19) received
mesh: Received Action frame: SA=00:19:86:11:98:93 Category=15 DataLen=172 freq=2442 MHz
MPM: Received PLINK action 2
MPM: Capability 0x10
MPM: AID 0x1
MPM: plid=0x950f llid=0x9634
mesh: Decrypted AMPE element - hexdump(len=70): [REMOVED]
mesh: MPM 00:19:86:11:98:93 state OPN_RCVD event CNF_ACPT
mesh: mesh plink with 00:19:86:11:98:93 established
mesh: MTK - hexdump(len=16): [REMOVED]
wpa_driver_nl80211_set_key: ifindex=5 (mesh) alg=3 addr=0x87e0f0 key_idx=0 set_tx=0 seq_len=6 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
nl80211: KEY_SEQ - hexdump(len=6): 00 00 00 00 00 00
   addr=00:19:86:11:98:93
mesh: RX MGTK Key RSC - hexdump(len=6): [REMOVED]
mesh: RX MGTK - hexdump(len=16): [REMOVED]
wpa_driver_nl80211_set_key: ifindex=5 (mesh) alg=3 addr=0x87e0f0 key_idx=1 set_tx=0 seq_len=6 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
nl80211: KEY_SEQ - hexdump(len=6): 00 00 00 00 00 00
   addr=00:19:86:11:98:93
   RSN IBSS RX GTK
mesh: MPM set 00:19:86:11:98:93 from OPN_RCVD into ESTAB
nl80211: Set STA 00:19:86:11:98:93
  * flags set=0x0 mask=0x0
mesh: MESH-PEER-CONNECTED 00:19:86:11:98:93
mesh: ap_handle_timer: 00:19:86:11:98:93 flags=0x603 timeout_next=0
Station 00:19:86:11:98:93 has been active 0s ago
ap_handle_timer: register ap_handle_timer timeout for 00:19:86:11:98:93 (306 seconds)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for mesh
nl80211: RX frame da=00:19:86:81:42:62 sa=00:19:86:11:98:93 bssid=00:19:86:11:98:93 freq=2442 ssi_signal=-31 fc=0x8d0 seq_ctrl=0x1030 stype=13 (WLAN_FC_STYPE_ACTION) len=148
mesh: Event RX_MGMT (19) received
mesh: Received Action frame: SA=00:19:86:11:98:93 Category=15 DataLen=123 freq=2442 MHz
MPM: Received PLINK action 3
MPM: plid=0x950f llid=0x9634
MPM: close reason=52
mesh: Decrypted AMPE element - hexdump(len=70): [REMOVED]
mesh: MPM 00:19:86:11:98:93 state ESTAB event CLS_ACPT
mesh: MPM set 00:19:86:11:98:93 from ESTAB into HOLDING
nl80211: Set STA 00:19:86:11:98:93
  * flags set=0x0 mask=0x0
mesh: mesh plink with 00:19:86:11:98:93 closed with reason 55
mesh: MESH-PEER-DISCONNECTED 00:19:86:11:98:93
mesh: Plaintext AMPE element - hexdump(len=70): [REMOVED]
mesh: Mesh MPM: Sending peering frame type 3 to 00:19:86:11:98:93 (my_lid=0x9634 peer_lid=0x950f)
nl80211: Send Action frame (ifindex=5, freq=2442 MHz wait=0 ms no_cck=0)
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for mesh
nl80211: Frame TX status event
nl80211: Action TX status: cookie=0a (match) (ack=0)
mesh: Event TX_STATUS (17) received
mesh: EVENT_TX_STATUS dst=00:19:86:11:98:93 type=0 stype=13
nl80211: sta_remove -> DEL_STATION mesh 00:19:86:11:98:93 --> 0 (Success)
ap_free_sta: cancel ap_handle_timer for 00:19:86:11:98:93
nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for mesh
nl80211: Delete station 00:19:86:11:98:93

> On 20 Nov 2016, at 23:53, Bob Copeland <me at bobcopeland.com> wrote:
> 
> On Sun, Nov 20, 2016 at 03:46:54PM +0000, Greg Gigon wrote:
>> Would you be able to point to the kernel release that includes the mac80211 fixes for mesh? There is a 4.8.y build on Raspibian GitHub, https://github.com/raspberrypi/linux/tree/rpi-4.8.y.
>> However, I don’t know wether it includes the changes.
>> 
>> Or do you have a link to patch somewhere? Linux Kernel dev is a jungle for me and I don’t how to find the right patches to apply.
>> Any help would be greatly appreciated !
> 
> 4.8 should have the necessary changes.
> 
> -- 
> Bob Copeland %% http://bobcopeland.com/

More information about the Hostap mailing list