Subject: wpasupplicant: fails to bring up wlan interface on Rasberry PI 3B Package: wpasupplicant Version: 2:2.7+git20190128+0c1e29f-5 Severity: normal
Dear Maintainer, At some point my testing install failed to bring up the wlan interface on my Raspberry PI 3B. After a lot of trial and error, I narrowed it down to either a bug in wpasupplicant 2.7 (or newer) or a bug in the raspberry kernel, which is triggered by something new in the newer versions of wpasupplicant. I did a lot of investigation, and came to the following conclusions: 1. This only happens with the built-in wireless card of the PI 3B (even the PI 3B+ works fine) 2. This bug happens independant of the used kernel version 3. Every version up to 2:2.6-21 (the last 2.6 version I could find in Debian) works and every version from 2:2.7~git20180504+60a5737-1 (the first 2.7 release I could find) exhibits the bug. When connecting with a WPA-EAP network I get this in the syslog: May 24 09:24:57 localhost wpa_supplicant[13331]: Successfully initialized wpa_supplicant May 24 09:24:58 localhost dhclient[13339]: Internet Systems Consortium DHCP Client 4.4.1 May 24 09:24:58 localhost dhclient[13339]: Copyright 2004-2018 Internet Systems Consortium. May 24 09:24:58 localhost dhclient[13339]: All rights reserved. May 24 09:24:58 localhost dhclient[13339]: For info, please visit https://www.isc.org/software/dhcp/ May 24 09:24:58 localhost dhclient[13339]: May 24 09:24:58 localhost dhclient[13339]: Listening on LPF/wlan0/b8:27:eb:23:12:6c May 24 09:24:58 localhost dhclient[13339]: Sending on LPF/wlan0/b8:27:eb:23:12:6c May 24 09:24:58 localhost dhclient[13339]: Sending on Socket/fallback May 24 09:24:58 localhost dhclient[13339]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 4 May 24 09:24:58 localhost wpa_supplicant[13334]: wlan0: Trying to associate with SSID 'COMPANY' May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: Associated with e0:cb:bc:8b:54:e4 May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25 May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=VMCOMPANYAD02.company.local' hash=475dfb6460faafe5c41c2ab06386a7563ac8b3365df535005d462879fa784b9a May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:VMCOMPANYAD02.company.local May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=VMCOMPANYAD02.company.local' hash=475dfb6460faafe5c41c2ab06386a7563ac8b3365df535005d462879fa784b9a May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:VMCOMPANYAD02.company.local May 24 09:24:59 localhost wpa_supplicant[13334]: EAP-MSCHAPV2: Authentication succeeded May 24 09:24:59 localhost wpa_supplicant[13334]: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully May 24 09:24:59 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-CONNECTED - Connection to e0:cb:bc:8b:54:e4 completed [id=0 id_str=] May 24 09:24:59 localhost kernel: [ 1714.764692] ------------[ cut here ]------------ May 24 09:24:59 localhost kernel: [ 1714.764909] WARNING: CPU: 3 PID: 13334 at drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c:5124 brcmf_cfg80211_set_pmk+0x6c/0x80 [brcmfmac] May 24 09:24:59 localhost kernel: [ 1714.764916] Modules linked in: ipv6 brcmfmac brcmutil sha256_generic cfg80211 joydev evdev rfkill bcm2835_v4l2(C) v4l2_common bcm2835_codec(C) v4l2_mem2mem videobuf2_vmalloc bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev raspberrypi_hwmon hwmon media vc_sm_cma(C) uio_pdrv_genirq uio squashfs overlay fixed May 24 09:24:59 localhost kernel: [ 1714.765082] CPU: 3 PID: 13334 Comm: wpa_supplicant Tainted: G WC 4.19.42-v7+ #1219 May 24 09:24:59 localhost kernel: [ 1714.765088] Hardware name: BCM2835 May 24 09:24:59 localhost kernel: [ 1714.765122] [<80111eac>] (unwind_backtrace) from [<8010d430>] (show_stack+0x20/0x24) May 24 09:24:59 localhost kernel: [ 1714.765144] [<8010d430>] (show_stack) from [<8080ec80>] (dump_stack+0xd4/0x118) May 24 09:24:59 localhost kernel: [ 1714.765165] [<8080ec80>] (dump_stack) from [<80120904>] (__warn+0x104/0x11c) May 24 09:24:59 localhost kernel: [ 1714.765182] [<80120904>] (__warn) from [<80120a54>] (warn_slowpath_null+0x50/0x58) May 24 09:24:59 localhost kernel: [ 1714.765353] [<80120a54>] (warn_slowpath_null) from [<7f3e7ae0>] (brcmf_cfg80211_set_pmk+0x6c/0x80 [brcmfmac]) May 24 09:24:59 localhost kernel: [ 1714.765766] [<7f3e7ae0>] (brcmf_cfg80211_set_pmk [brcmfmac]) from [<7f24aaa0>] (nl80211_set_pmk+0x160/0x26c [cfg80211]) May 24 09:24:59 localhost kernel: [ 1714.765984] [<7f24aaa0>] (nl80211_set_pmk [cfg80211]) from [<80748d88>] (genl_rcv_msg+0x244/0x464) May 24 09:24:59 localhost kernel: [ 1714.766001] [<80748d88>] (genl_rcv_msg) from [<80747d80>] (netlink_rcv_skb+0x104/0x138) May 24 09:24:59 localhost kernel: [ 1714.766016] [<80747d80>] (netlink_rcv_skb) from [<80748b34>] (genl_rcv+0x34/0x44) May 24 09:24:59 localhost kernel: [ 1714.766029] [<80748b34>] (genl_rcv) from [<80747498>] (netlink_unicast+0x1b8/0x244) May 24 09:24:59 localhost kernel: [ 1714.766042] [<80747498>] (netlink_unicast) from [<807478c4>] (netlink_sendmsg+0x2dc/0x364) May 24 09:24:59 localhost kernel: [ 1714.766059] [<807478c4>] (netlink_sendmsg) from [<806d7c20>] (sock_sendmsg+0x24/0x34) May 24 09:24:59 localhost kernel: [ 1714.766074] [<806d7c20>] (sock_sendmsg) from [<806d846c>] (___sys_sendmsg+0x214/0x228) May 24 09:24:59 localhost kernel: [ 1714.766091] [<806d846c>] (___sys_sendmsg) from [<806d9540>] (__sys_sendmsg+0x60/0xa0) May 24 09:24:59 localhost kernel: [ 1714.766106] [<806d9540>] (__sys_sendmsg) from [<806d959c>] (sys_sendmsg+0x1c/0x20) May 24 09:24:59 localhost kernel: [ 1714.766122] [<806d959c>] (sys_sendmsg) from [<80101000>] (ret_fast_syscall+0x0/0x28) May 24 09:24:59 localhost kernel: [ 1714.766130] Exception stack(0x9fd99fa8 to 0x9fd99ff0) May 24 09:24:59 localhost kernel: [ 1714.766142] 9fa0: 00000074 017aa428 00000005 7eb15f70 00000000 00000000 May 24 09:24:59 localhost kernel: [ 1714.766155] 9fc0: 00000074 017aa428 017694a8 00000128 76f93000 ffffffff 00000001 00000004 May 24 09:24:59 localhost kernel: [ 1714.766164] 9fe0: 00000128 7eb15f20 76ba051f 76b1c746 May 24 09:24:59 localhost kernel: [ 1714.766172] ---[ end trace 7b2893f77456084b ]--- May 24 09:24:59 localhost kernel: [ 1714.766710] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready May 24 09:25:02 localhost dhclient[13339]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 7 May 24 09:25:03 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:cb:bc:8b:54:e4 reason=2 locally_generated=1 May 24 09:25:03 localhost wpa_supplicant[13334]: wlan0: Trying to associate with SSID 'COMPANY' May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: Associated with e0:cb:bc:8b:56:86 May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25 May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected May 24 09:25:04 localhost wpa_supplicant[13334]: EAP-MSCHAPV2: Authentication succeeded May 24 09:25:04 localhost wpa_supplicant[13334]: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully May 24 09:25:04 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-CONNECTED - Connection to e0:cb:bc:8b:56:86 completed [id=0 id_str=] May 24 09:25:04 localhost kernel: [ 1719.683122] ------------[ cut here ]------------ May 24 09:25:04 localhost kernel: [ 1719.683344] WARNING: CPU: 3 PID: 13334 at drivers/net/wireless/broadcom/brcm80211/brcmfmac/cfg80211.c:5124 brcmf_cfg80211_set_pmk+0x6c/0x80 [brcmfmac] May 24 09:25:04 localhost kernel: [ 1719.683353] Modules linked in: ipv6 brcmfmac brcmutil sha256_generic cfg80211 joydev evdev rfkill bcm2835_v4l2(C) v4l2_common bcm2835_codec(C) v4l2_mem2mem videobuf2_vmalloc bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev raspberrypi_hwmon hwmon media vc_sm_cma(C) uio_pdrv_genirq uio squashfs overlay fixed May 24 09:25:04 localhost kernel: [ 1719.683523] CPU: 3 PID: 13334 Comm: wpa_supplicant Tainted: G WC 4.19.42-v7+ #1219 May 24 09:25:04 localhost kernel: [ 1719.683528] Hardware name: BCM2835 May 24 09:25:04 localhost kernel: [ 1719.683563] [<80111eac>] (unwind_backtrace) from [<8010d430>] (show_stack+0x20/0x24) May 24 09:25:04 localhost kernel: [ 1719.683585] [<8010d430>] (show_stack) from [<8080ec80>] (dump_stack+0xd4/0x118) May 24 09:25:04 localhost kernel: [ 1719.683606] [<8080ec80>] (dump_stack) from [<80120904>] (__warn+0x104/0x11c) May 24 09:25:04 localhost kernel: [ 1719.683623] [<80120904>] (__warn) from [<80120a54>] (warn_slowpath_null+0x50/0x58) May 24 09:25:04 localhost kernel: [ 1719.683800] [<80120a54>] (warn_slowpath_null) from [<7f3e7ae0>] (brcmf_cfg80211_set_pmk+0x6c/0x80 [brcmfmac]) May 24 09:25:04 localhost kernel: [ 1719.684215] [<7f3e7ae0>] (brcmf_cfg80211_set_pmk [brcmfmac]) from [<7f24aaa0>] (nl80211_set_pmk+0x160/0x26c [cfg80211]) May 24 09:25:04 localhost kernel: [ 1719.684430] [<7f24aaa0>] (nl80211_set_pmk [cfg80211]) from [<80748d88>] (genl_rcv_msg+0x244/0x464) May 24 09:25:04 localhost kernel: [ 1719.684446] [<80748d88>] (genl_rcv_msg) from [<80747d80>] (netlink_rcv_skb+0x104/0x138) May 24 09:25:04 localhost kernel: [ 1719.684460] [<80747d80>] (netlink_rcv_skb) from [<80748b34>] (genl_rcv+0x34/0x44) May 24 09:25:04 localhost kernel: [ 1719.684473] [<80748b34>] (genl_rcv) from [<80747498>] (netlink_unicast+0x1b8/0x244) May 24 09:25:04 localhost kernel: [ 1719.684486] [<80747498>] (netlink_unicast) from [<807478c4>] (netlink_sendmsg+0x2dc/0x364) May 24 09:25:04 localhost kernel: [ 1719.684504] [<807478c4>] (netlink_sendmsg) from [<806d7c20>] (sock_sendmsg+0x24/0x34) May 24 09:25:04 localhost kernel: [ 1719.684519] [<806d7c20>] (sock_sendmsg) from [<806d846c>] (___sys_sendmsg+0x214/0x228) May 24 09:25:04 localhost kernel: [ 1719.684534] [<806d846c>] (___sys_sendmsg) from [<806d9540>] (__sys_sendmsg+0x60/0xa0) May 24 09:25:04 localhost kernel: [ 1719.684552] [<806d9540>] (__sys_sendmsg) from [<806d959c>] (sys_sendmsg+0x1c/0x20) May 24 09:25:04 localhost kernel: [ 1719.684570] [<806d959c>] (sys_sendmsg) from [<80101000>] (ret_fast_syscall+0x0/0x28) May 24 09:25:04 localhost kernel: [ 1719.684578] Exception stack(0x9fd99fa8 to 0x9fd99ff0) May 24 09:25:04 localhost kernel: [ 1719.684591] 9fa0: 00000074 017ac270 00000005 7eb15f70 00000000 00000000 May 24 09:25:04 localhost kernel: [ 1719.684605] 9fc0: 00000074 017ac270 017694a8 00000128 76f93000 ffffffff 00000001 00000004 May 24 09:25:04 localhost kernel: [ 1719.684614] 9fe0: 00000128 7eb15f20 76ba051f 76b1c746 May 24 09:25:04 localhost kernel: [ 1719.684624] ---[ end trace 7b2893f77456084c ]--- May 24 09:25:08 localhost wpa_supplicant[13334]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:cb:bc:8b:56:86 reason=2 locally_generated=1 The kernel dump seems to happen ervery time the dhclient sends a DHCP-REQUEST. The exact same software works fine with a Raspberry PI 3B+ (I even used the same SD-card). The bug also happens if I use a different PI 3B. If I downgrade wpasupplicant to version 2:2.6-21 I get this: May 24 11:55:04 localhost kernel: [ 589.354202] brcmfmac: power management disabled May 24 11:55:04 localhost kernel: [ 589.355784] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready May 24 11:55:04 localhost wpa_supplicant[3364]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING May 24 11:55:05 localhost wpa_supplicant[3364]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 May 24 11:55:05 localhost wpa_supplicant[3364]: wlan0: CTRL-EVENT-TERMINATING May 24 11:55:05 localhost wpa_supplicant[5892]: Successfully initialized wpa_supplicant May 24 11:55:06 localhost dhclient[5919]: Internet Systems Consortium DHCP Client 4.4.1 May 24 11:55:06 localhost dhclient[5919]: Copyright 2004-2018 Internet Systems Consortium. May 24 11:55:06 localhost dhclient[5919]: All rights reserved. May 24 11:55:06 localhost dhclient[5919]: For info, please visit https://www.isc.org/software/dhcp/ May 24 11:55:06 localhost dhclient[5919]: May 24 11:55:06 localhost dhclient[5919]: Listening on LPF/wlan0/b8:27:eb:23:12:6c May 24 11:55:06 localhost dhclient[5919]: Sending on LPF/wlan0/b8:27:eb:23:12:6c May 24 11:55:06 localhost dhclient[5919]: Sending on Socket/fallback May 24 11:55:06 localhost dhclient[5919]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 4 May 24 11:55:06 localhost wpa_supplicant[5912]: wlan0: Trying to associate with SSID 'COMPANY' May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: Associated with e0:cb:bc:8b:57:57 May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25 May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=VMCOMPANYAD02.company.local' hash=475dfb6460faafe5c41c2ab06386a7563ac8b3365df535005d462879fa784b9a May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:VMCOMPANYAD02.company.local May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=VMCOMPANYAD02.company.local' hash=475dfb6460faafe5c41c2ab06386a7563ac8b3365df535005d462879fa784b9a May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:VMCOMPANYAD02.company.local May 24 11:55:07 localhost wpa_supplicant[5912]: EAP-MSCHAPV2: Authentication succeeded May 24 11:55:07 localhost wpa_supplicant[5912]: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: WPA: Key negotiation completed with e0:cb:bc:8b:57:57 [PTK=CCMP GTK=CCMP] May 24 11:55:07 localhost wpa_supplicant[5912]: wlan0: CTRL-EVENT-CONNECTED - Connection to e0:cb:bc:8b:57:57 completed [id=0 id_str=] May 24 11:55:07 localhost kernel: [ 591.915662] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready May 24 11:55:10 localhost dhclient[5919]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 5 May 24 11:55:10 localhost dhclient[5919]: DHCPOFFER of 192.168.1.114 from 192.168.0.12 May 24 11:55:10 localhost dhclient[5919]: DHCPREQUEST for 192.168.1.114 on wlan0 to 255.255.255.255 port 67 May 24 11:55:10 localhost dhclient[5919]: DHCPACK of 192.168.1.114 from 192.168.0.12 May 24 11:55:11 localhost dhclient[5919]: bound to 192.168.1.114 -- renewal in 12894 seconds. -- System Information: Debian Release: 10.0 APT prefers testing APT policy: (500, 'testing') Architecture: armhf (armv7l) Kernel: Linux 4.19.42-v7+ (SMP w/4 CPU cores) Kernel taint flags: TAINT_CRAP Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE=C (charmap=UTF-8) Shell: /bin/sh linked to /bin/dash Init: sysvinit (via /sbin/init) Versions of packages wpasupplicant depends on: ii adduser 3.118 ii libc6 2.28-10 ii libdbus-1-3 1.12.12-1 ii libnl-3-200 3.4.0-1 ii libnl-genl-3-200 3.4.0-1 ii libpcsclite1 1.8.24-1 ii libreadline7 7.0-5 ii libssl1.1 1.1.1b-2 ii lsb-base 10.2019051400 wpasupplicant recommends no packages. Versions of packages wpasupplicant suggests: pn libengine-pkcs11-openssl <none> pn wpagui <none> -- no debconf information
