Crash in hostapd_eid_time_adv with DFS CAC

Mon Mar 1 22:35:01 GMT 2021

Hi,

this is the logs resulting in the crash.

It can be seen that we have DFS-RADAR-DETECTED on wlan1, wlan1: 
interface state ENABLED->DISABLED, and later wlan1 is reenabled.
Thus hostapd_disable_iface -> hostapd_free_hapd_data -> 
wpabuf_free(hapd->time_adv) when wlan1 becomes disabled.
Later when wlan1 is re-enabled, hapd->time_adv points to a freed 
pointer, as - different to e.g. hapd->radius - it is not cleared after 
freeing.

Please find attached a patch that addresses this.

Regards,
M. Braun

1614623852.209013: wl1_2: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 
4-Way Handshake
VLAN: Interface wl1_2.4096 configured to vlan 527 in br_vlan_add
VLAN (netlink): Interface wl1_2.4096 add to vlan 527 in _linux_br_vlan
VLAN: Interface wl1_2.4096 configured to vlan 527 in vlan_newlink_real
1614623852.219940: wl1_2: STA xx:xx:xx:xx:xx:xx WPA: received EAPOL-Key 
frame (2/4 Pairwise)
1614623852.220845: wl1_2: STA xx:xx:xx:xx:xx:xx WPA: sending 3/4 msg of 
4-Way Handshake
1614623852.236195: wl1_2: STA xx:xx:xx:xx:xx:xx WPA: received EAPOL-Key 
frame (4/4 Pairwise)
wl1_2: AP-STA-CONNECTED xx:xx:xx:xx:xx:xx
1614623852.238279: wl1_2: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: authorizing 
port
1614623852.239046: wl1_2: STA xx:xx:xx:xx:xx:xx RADIUS: starting 
accounting session E517AD69514481A6
1614623852.239385: wl1_2: RADIUS Sending RADIUS message to accounting 
server
1614623852.240467: wl1_2: RADIUS Next RADIUS client retransmit in 3 
seconds
1614623852.240820: wl1_2: STA xx:xx:xx:xx:xx:xx WPA: pairwise key 
handshake completed (RSN)
wlan1: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
wlan1: DFS-NEW-CHANNEL freq=5620 chan=124 sec_chan=1
DFS failed to schedule CSA (-22) - trying fallback
wlan1: AP-DISABLED
1614623852.294656: wlan1: RADIUS Sending RADIUS message to accounting 
server
1614623852.295534: wlan1: RADIUS Next RADIUS client retransmit in 3 
seconds
1614623852.296736: wl1_1: RADIUS Sending RADIUS message to accounting 
server
1614623852.297268: wl1_1: RADIUS Next RADIUS client retransmit in 3 
seconds
Failed to remove bssid to ft_bridge br-mgnt
1614623852.634842: wl1_2: STA xx:xx:xx:xx:xx:xx MLME: 
MLME-DEAUTHENTICATE.indication(xx:xx:xx:xx:xx:xx, 1)
1614623852.635865: wl1_2: STA xx:xx:xx:xx:xx:xx RADIUS: updated TX/RX 
stats: rx_bytes=1411 [0:0] tx_bytes=557 [0:0] bytes_64bit=1
1614623852.636632: wl1_2: RADIUS Sending RADIUS message to accounting 
server
1614623852.637981: wl1_2: RADIUS Next RADIUS client retransmit in 3 
seconds
1614623852.638568: wl1_2: STA xx:xx:xx:xx:xx:xx RADIUS: stopped 
accounting session E517AD69514481A6
wl1_2: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
1614623853.044158: wl1_2: RADIUS Sending RADIUS message to accounting 
server
1614623853.044909: wl1_2: RADIUS Next RADIUS client retransmit in 2 
seconds
1614623853.247363: wl1_6: RADIUS Sending RADIUS message to accounting 
server
1614623853.250053: wl1_6: RADIUS Next RADIUS client retransmit in 3 
seconds
nl80211: Failed to remove interface wl1_6 from bridge br-wlan: Invalid 
argument
nl80211: deinit ifname=wlan1 disabled_11b_rates=0
wlan1: interface state ENABLED->DISABLED
rfkill: Cannot open RFKILL control device
wlan1: interface state DISABLED->COUNTRY_UPDATE
wlan1: interface state COUNTRY_UPDATE->HT_SCAN
wlan0: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
current_mode != IEEE80211A
wlan1: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
wlan0: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
current_mode != IEEE80211A
wlan1: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
wlan0: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
current_mode != IEEE80211A
wlan1: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
wlan0: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
current_mode != IEEE80211A
wlan1: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
wlan0: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
current_mode != IEEE80211A
wlan1: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
wlan0: DFS-RADAR-DETECTED freq=5260 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5270 cf2=0
current_mode != IEEE80211A
wlan1: interface state HT_SCAN->DFS
wlan1: DFS-CAC-START freq=5620 chan=124 sec_chan=1, width=0, seg0=0, 
seg1=0, cac_time=60s
1614623880.597302: wl0_2: STA xx:xx:xx:xx:xx:xx RADIUS: updated TX/RX 
stats: rx_bytes=259709 [0:0] tx_bytes=4886318 [0:0] bytes_64bit=1
1614623880.597809: wl0_2: RADIUS Sending RADIUS message to accounting 
server
1614623880.598291: wl0_2: RADIUS Next RADIUS client retransmit in 3 
seconds
1614623880.653695: wl0_2: RADIUS Received 20 bytes from RADIUS server
1614623880.654185: wl0_2: RADIUS Received RADIUS message
1614623880.654969: wl0_2: STA xx:xx:xx:xx:xx:xx RADIUS: Received RADIUS 
packet matched with a pending request, round trip time 0.05 sec
wlan0: DFS-CAC-COMPLETED success=1 freq=5620 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5630 cf2=0
current_mode != IEEE80211A
wlan1: DFS-CAC-COMPLETED success=1 freq=5620 ht_enabled=1 chan_offset=1 
chan_width=2 cf1=5630 cf2=0
1614623915.642704: wlan1: RADIUS Accounting server 10.30.254.16:1813
1614623915.643888: wlan1: RADIUS Sending RADIUS message to accounting 
server
1614623915.644632: wlan1: RADIUS Next RADIUS client retransmit in 3 
seconds
10.30.1.94 2021-03-01T18:38:35+01:00 femap015e hostapd-capture:
10.30.1.94 2021-03-01T18:38:35+01:00 femap015e hostapd-capture: Program 
received signal SIGSEGV, Segmentation fault.

Am 01.03.2021 22:56, schrieb michael-dev:
> Hi,
> 
> I'm seeing the following and very similar backtrace in different
> hostapd versions (based on 59e9794c or c7a9a574). I'll still need to
> reproduce this with upstream (vanilla) hostapd, but was wondering, if
> there is any hint on it yet? (as the locally applied patches do not
> alter beacon setup or timeadv).
> 
> wpabuf.h:60 ist wpabuf_len, which is called from hostapd_eid_time_adv
> on hapd->time_adv
> 
> #0  0x0fb5c4a8 in _wordcopy_fwd_dest_aligned () from /lib/libc.so.6
> #1  0x0fb5c2e4 in memcpy () from /lib/libc.so.6
> #2  0x10028d7c in     (hapd=hapd at entry=0x106b07f0, eid=0x106cc6d9
> <error reading variable>) at ../src/utils/wpabuf.h:60
> #3  0x1002ab58 in ieee802_11_build_ap_params
> (hapd=hapd at entry=0x106b07f0, params=0xbffd0d30,
> params at entry=0xbffd0d40) at ../src/ap/beacon.c:1532
> #4  0x1002afe8 in ieee802_11_set_beacon (hapd=hapd at entry=0x106b07f0)
> at ../src/ap/beacon.c:1763
> #5  0x100093b4 in hostapd_setup_bss (hapd=hapd at entry=0x106b07f0,
> first=first at entry=0) at ../src/ap/hostapd.c:1377
> #6  0x1000b500 in hostapd_setup_interface_complete_sync
> (iface=0x106acf70, err=<optimized out>) at ../src/ap/hostapd.c:2089
> #7  0x1000b5fc in hostapd_setup_interface_complete
> (iface=iface at entry=0x106acf70, err=err at entry=0) at
> ../src/ap/hostapd.c:2260
> #8  0x10082c48 in hostapd_dfs_complete_cac (iface=0x106acf70,
> success=1, freq=5620, ht_enabled=<optimized out>,
> chan_offset=<optimized out>, chan_width=2, cf1=5630, cf2=0) at
> ../src/ap/dfs.c:908
> #9  0x10012388 in hostapd_event_dfs_cac_aborted (hapd=<optimized out>,
> radar=<optimized out>) at ../src/ap/drv_callbacks.c:1713
> #10 wpa_supplicant_event (ctx=0x106ad980,
> event=EVENT_DFS_CAC_FINISHED, data=0xbffd1550) at
> ../src/ap/drv_callbacks.c:2004
> #11 0x1006ce14 in mlme_event_dh_event (drv=<optimized out>,
> bss=<optimized out>, tb=<optimized out>) at
> ../src/drivers/driver.h:6049
> #12 do_process_drv_event (tb=0xbffd10c8, cmd=<optimized out>,
> bss=<optimized out>) at ../src/drivers/driver_nl80211_event.c:2971
> #13 process_global_event (msg=<optimized out>, arg=<optimized out>) at
> ../src/drivers/driver_nl80211_event.c:3030
> #14 0x0fe3f988 in nl_cb_call (msg=<optimized out>, type=<optimized
> out>, cb=<optimized out>) at ./include/netlink-private/netlink.h:144
> #15 recvmsgs (cb=0x106b3390, sk=0x106b34b0) at lib/nl.c:1007
> #16 nl_recvmsgs_report (sk=sk at entry=0x106b34b0,
> cb=cb at entry=0x106b3390) at lib/nl.c:1058
> #17 0x0fe3fc00 in nl_recvmsgs (sk=sk at entry=0x106b34b0,
> cb=cb at entry=0x106b3390) at lib/nl.c:1082
> #18 0x100545d8 in wpa_driver_nl80211_event_receive (sock=<optimized
> out>, eloop_ctx=0x106b3390, handle=0x106b34b0) at
> ../src/drivers/driver_nl80211.c:1758
> #19 0x1002d220 in eloop_sock_table_dispatch
> (table=table at entry=0x100e1410 <eloop+8>, fds=fds at entry=0x106b8c70) at
> ../src/utils/eloop.c:603
> #20 0x1002df9c in eloop_sock_table_dispatch (fds=<optimized out>,
> table=0x100e1410 <eloop+8>) at ../src/utils/eloop.c:597
> #21 eloop_run () at ../src/utils/eloop.c:1228
> 
> Regards,
> M. Braun
> 
> _______________________________________________
> Hostap mailing list
> Hostap at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/hostap
-------------- next part --------------
A non-text attachment was scrubbed...
Name: timeadv-fix.patch
Type: text/x-diff
Size: 844 bytes
Desc: not available
URL: <http://lists.infradead.org/pipermail/hostap/attachments/20210301/70820c14/attachment.bin>