Crash in wpa_auth_sta_init() with wpa_auth=NULL
Joakim Lotsengård
joakim.lotsengard at verisure.com
Thu Aug 20 10:02:01 EDT 2020
Hi,
We (Verisure) are using hostapd (currently 2.9) in some over 100k instances of embedded machines in home alarm systems. Running Linux and using wifi (both STA + AP). Lately we gotten many crashes with coredumps from hostapd like below stack trace (full backtrace last in mail).
Core was generated by `/usr/sbin/hostapd -P /run/hostapd-uap0.pid /run/wlan/hostapd-uap0.conf'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 wpa_auth_sta_init (wpa_auth=0x0,
addr=addr at entry=0x22a0b38 "$\303", <incomplete sequence \371>,
p2p_dev_addr=0x0)
at ../src/ap/wpa_auth.c:608
Checking the events around this crash it seems like we get an STA association event from kernel during hostapd startup. hostapd has not yet said "AP ENABLED". It tries to handle the event, and crashes due to hapd->wpa_auth is NULL. The startup can be "delayed" by both ACS-scan and HT40-scan, giving time for this event to happen. Two log examples below.
I *think* we seen this issue even in hostapd 2.6 (we jumped to hostapd 2.9 some half a year ago, and never used 2.7 nor 2.8). It is still somewhat unclear in all crashes and logs I have.
This problem is hard to reproduce, as you need a station to assoc at the right moment. If I am even right in my guess here (assoc happens before AP has entered state AP-ENABLED). This is a guess of the cause.
I've tried my best google-fu to see if this is a known issue, but came up empty. I'm mailing the list as someone might have some insights to this.
Event log case1 - ACS still scanning:
Jun 18 15:58:49 lev-26GT666Y daemon.info systemd[1]: Starting Hostapd IEEE 802.11 AP, IEEE 802.1X/WPA/WPA2/EAP/RADIUS Authenticator...
Jun 18 15:58:49 lev-26GT666Y daemon.info systemd[1]: Started Hostapd IEEE 802.11 AP, IEEE 802.1X/WPA/WPA2/EAP/RADIUS Authenticator.
Jun 18 15:58:49 lev-26GT666Y daemon.info hostapd[6744]: Configuration file: /run/wlan/hostapd-uap0.conf
Jun 18 15:58:49 lev-26GT666Y daemon.info hostapd[6744]: rfkill: Cannot open RFKILL control device
Jun 18 15:58:49 lev-26GT666Y daemon.info hostapd[6744]: uap0: interface state UNINITIALIZED->COUNTRY_UPDATE
Jun 18 15:58:49 lev-26GT666Y daemon.info hostapd[6744]: ACS: Automatic channel selection started, this may take a bit
---> Jun 18 15:58:49 lev-26GT666Y user.info kernel: wlan_driver: wlan: EVENT: MICRO_AP_STA_ASSOC 24:XX:XX:XX:18:6b
Jun 18 15:58:51 lev-26GT666Y user.info kernel: wlan_driver: wlan: SCAN COMPLETED: scanned AP count=14
Jun 18 15:58:51 lev-26GT666Y daemon.info hostapd[6744]: uap0: interface state COUNTRY_UPDATE->ACS
Jun 18 15:58:51 lev-26GT666Y daemon.info hostapd[6744]: uap0: ACS-STARTED
Jun 18 15:58:51 lev-26GT666Y daemon.info hostapd[6744]: uap0: STA 24:c3:f9:00:18:6b IEEE 802.11: associated
Jun 18 15:58:51 lev-26GT666Y daemon.info systemd[1]: Started Process Core Dump (PID 6746/UID 0).
Jun 18 15:58:51 lev-26GT666Y daemon.warn systemd[1]: hostapd at uap0.service: Main process exited, code=dumped, status=11/SEGV
Jun 18 15:58:51 lev-26GT666Y daemon.warn systemd[1]: hostapd at uap0.service: Failed with result 'core-dump'.
Jun 18 15:58:52 lev-26GT666Y user.crit systemd-coredump[6747]: Process 6744 (hostapd) of user 0 dumped core.
Event log case2 - HT40 still scans:
Aug 19 18:11:34 lev-26HC4UQN daemon.info systemd[1]: Starting Hostapd IEEE 802.11 AP, IEEE 802.1X/WPA/WPA2/EAP/RADIUS Authenticator...
Aug 19 18:11:34 lev-26HC4UQN daemon.info systemd[1]: Started Hostapd IEEE 802.11 AP, IEEE 802.1X/WPA/WPA2/EAP/RADIUS Authenticator.
Aug 19 18:11:34 lev-26HC4UQN daemon.info hostapd[3955]: Configuration file: /run/wlan/hostapd-uap0.conf
Aug 19 18:11:34 lev-26HC4UQN daemon.info hostapd[3955]: rfkill: Cannot open RFKILL control device
Aug 19 18:11:34 lev-26HC4UQN daemon.info hostapd[3955]: uap0: interface state UNINITIALIZED->COUNTRY_UPDATE
Aug 19 18:11:34 lev-26HC4UQN daemon.info hostapd[3955]: uap0: interface state COUNTRY_UPDATE->HT_SCAN
---> Aug 19 18:11:34 lev-26HC4UQN user.info kernel: wlan_driver: wlan: EVENT: MICRO_AP_STA_ASSOC 24:XX:XX:XX:41:eb
Aug 19 18:11:36 lev-26HC4UQN user.info kernel: wlan_driver: wlan: SCAN COMPLETED: scanned AP count=2
Aug 19 18:11:36 lev-26HC4UQN daemon.info hostapd[3955]: uap0: STA 24:c3:f9:00:41:eb IEEE 802.11: associated
Aug 19 18:11:36 lev-26HC4UQN daemon.info systemd[1]: Started Process Core Dump (PID 3957/UID 0).
Aug 19 18:11:36 lev-26HC4UQN daemon.warn systemd[1]: hostapd at uap0.service: Main process exited, code=dumped, status=11/SEGV
Aug 19 18:11:36 lev-26HC4UQN daemon.warn systemd[1]: hostapd at uap0.service: Failed with result 'core-dump'.
We are running on Freescale IMX7s ARM A7 (single core) and using the Marvell 88W8997 WiFi-chip.
Full backtrace of the crash:
Core was generated by `/usr/sbin/hostapd -P /run/hostapd-uap0.pid /run/wlan/hostapd-uap0.conf'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 wpa_auth_sta_init (wpa_auth=0x0,
addr=addr at entry=0x22a0b38 "$\303", <incomplete sequence \371>,
p2p_dev_addr=0x0)
at ../src/ap/wpa_auth.c:608
Thread 1:
#0 wpa_auth_sta_init (wpa_auth=0x0,
addr=addr at entry=0x22a0b38 "$\303", <incomplete sequence \371>,
p2p_dev_addr=0x0)
at ../src/ap/wpa_auth.c:608
#1 0x004e5c74 in hostapd_notif_assoc
(hapd=hapd at entry=0x229ed88,
addr=0x22a0aa8 "$\303", <incomplete sequence \371>,
req_ies=0x22a0ac0 "",
req_ies_len=105, reassoc=0)
at ../src/ap/drv_callbacks.c:313
#2 0x004e6a40 in wpa_supplicant_event
(ctx=ctx at entry=0x229ed88,
event=event at entry=EVENT_ASSOC,
data=data at entry=0x7eec6558)
at ../src/ap/drv_callbacks.c:1772
#3 0x0051da50 in drv_event_assoc (
reassoc=0, ielen=105,
ie=0x22a0ac0 "",
addr=0x22a0aa8 "$\303", <incomplete sequence \371>, ctx=0x229ed88)
at ../src/drivers/driver.h:5687
#4 nl80211_new_station_event (
bss=<optimized out>,
tb=0x7eec6600,
drv=<optimized out>)
at ../src/drivers/driver_nl80211_event.c:1352
#5 do_process_drv_event (
tb=0x7eec6600,
cmd=<optimized out>,
bss=<optimized out>)
at ../src/drivers/driver_nl80211_event.c:2587
#6 process_global_event (
msg=<optimized out>,
arg=0x229f408)
at ../src/drivers/driver_nl80211_event.c:2674
#7 0x76f64ea4 in nl_cb_call (
msg=<optimized out>,
type=<optimized out>,
cb=<optimized out>)
at ../libnl-3.4.0/include/netlink-private/netlink.h:145
#8 recvmsgs (cb=0x229f490,
sk=0x229f868)
at ../libnl-3.4.0/lib/nl.c:1006
#9 nl_recvmsgs_report (
sk=sk at entry=0x229f868,
cb=cb at entry=0x229f490)
at ../libnl-3.4.0/lib/nl.c:1057
#10 0x76f651a6 in nl_recvmsgs (
sk=sk at entry=0x229f868,
cb=cb at entry=0x229f490)
at ../libnl-3.4.0/lib/nl.c:1081
#11 0x0050d114 in wpa_driver_nl80211_event_receive (sock=<optimized out>,
eloop_ctx=0x229f490,
handle=0x229f868)
at ../src/drivers/driver_nl80211.c:1623
#12 0x004f76f8 in eloop_sock_table_dispatch (table=0x594ad0 <eloop+8>,
fds=fds at entry=0x22a2c58)
at ../src/utils/eloop.c:600
#13 0x004f7e26 in eloop_sock_table_dispatch (fds=<optimized out>,
table=0x594ad0 <eloop+8>)
at ../src/utils/eloop.c:1223
#14 eloop_run ()
at ../src/utils/eloop.c:1223
#15 0x004dc456 in hostapd_global_run (
ifaces=0x7eec6bec,
pid_file=0x229b150 "/run/hostapd-uap0.pid", daemonize=0) at main.c:448
#16 main (argc=<optimized out>,
argv=<optimized out>)
at main.c:891
--
Best regards,
Joakim Lotsengård
More information about the Hostap
mailing list