All of lore.kernel.org
 help / color / mirror / Atom feed
* iwd 1.28 segfault while terminating
@ 2022-07-14 16:52 Alvin Šipraga
  2022-07-15 15:14 ` [PATCH] iwd: Add missing module dependencies Denis Kenzior
  2022-07-15 15:16 ` iwd 1.28 segfault while terminating Denis Kenzior
  0 siblings, 2 replies; 5+ messages in thread
From: Alvin Šipraga @ 2022-07-14 16:52 UTC (permalink / raw)
  To: iwd; +Cc: Emil Dahl Juhl

[-- Attachment #1: Type: text/plain, Size: 2858 bytes --]

Hi,

We noticed the following segfault in iwd 1.28:

  ... iwd is handling a SIGTERM ...
  Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/device.c:device_free()
  Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_free() Freeing wiphy phy0[0]
  Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_free() Freeing netdev wlan0[45]
  Jul 14 18:14:39 localhost systemd[1]: iwd.service: Main process exited, code=dumped, status=11/SEGV
  Jul 14 18:14:39 localhost systemd[1]: iwd.service: Failed with result 'core-dump'.

Here is the backtrace from the core dump I got:

  (gdb) bt
  #0  l_queue_peek_head (queue=<optimized out>) at ../iwd-1.28/ell/queue.c:241
  #1  0x0000aaaab752f2a0 in wiphy_radio_work_done (wiphy=0xaaaac3a129a0, id=6)
      at ../iwd-1.28/src/wiphy.c:2013
  #2  0x0000aaaab7523f50 in netdev_connect_free (netdev=netdev@entry=0xaaaac3a13db0)
      at ../iwd-1.28/src/netdev.c:765
  #3  0x0000aaaab7526208 in netdev_free (data=0xaaaac3a13db0) at ../iwd-1.28/src/netdev.c:909
  #4  0x0000aaaab75a3924 in l_queue_clear (queue=queue@entry=0xaaaac3a0c800, 
      destroy=destroy@entry=0xaaaab7526190 <netdev_free>) at ../iwd-1.28/ell/queue.c:107
  #5  0x0000aaaab75a3974 in l_queue_destroy (queue=0xaaaac3a0c800, 
      destroy=destroy@entry=0xaaaab7526190 <netdev_free>) at ../iwd-1.28/ell/queue.c:82
  #6  0x0000aaaab7522050 in netdev_exit () at ../iwd-1.28/src/netdev.c:6653
  #7  0x0000aaaab7579bb0 in iwd_modules_exit () at ../iwd-1.28/src/module.c:181
  #8  0x0000aaaab751e9bc in main (argc=<optimized out>, argv=<optimized out>)
      at ../iwd-1.28/src/main.c:602

I've attached logs as well. It looks like a use after free by netdev:

  static void netdev_connect_free(struct netdev *netdev)
  {
	  if (netdev->work.id)
		  wiphy_radio_work_done(netdev->wiphy, netdev->work.id);

where netdev->wiphy has already been freed.

I have been reproducing this on our brcmfmac-based platform by adding
the following to the .service file:

  [Unit]
  BindsTo=sys-subsystem-net-devices-wlan0.device
  After=sys-subsystem-net-devices-wlan0.device

  [Install]
  RequiredBy=sys-subsystem-net-devices-wlan0.device

  [Service]
  ExecStart=
  ExecStart=/usr/libexec/iwd --interface wlan0 -d

and then running the following vendor utility command a handful of times:

  wl -i wlan0 bus:disconnect 99

The command forces a firmware crash. brcmfmac will then destroy its
interfaces and wiphy before reloading the firmware and recreating
everything again. But in the mean time, systemd will send a SIGTERM to
iwd because of the BindsTo= above. From the logs, you can see that iwd
hangs around long enough to pick up the recreated station interface and
attempt an autoconnect before iwd_modules_exit() is called.

Hope that helps!

Kind regards,
Alvin

[-- Attachment #2: log.txt --]
[-- Type: text/plain, Size: 42130 bytes --]

Jul 14 18:14:33 localhost iwd[2867]: Wireless daemon version 1.28
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/main.c:main() Using configuration directory /etc/iwd
Jul 14 18:14:33 localhost iwd[2867]: Loaded configuration from /etc/iwd/main.conf
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/storage.c:storage_create_dirs() Using state directory /var/lib/iwd
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/main.c:nl80211_appeared() Found nl80211 interface
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/module.c:iwd_modules_init()
Jul 14 18:14:33 localhost iwd[2867]: station: Network configuration is disabled.
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/wsc.c:wsc_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap.c:__eap_method_enable()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-wsc.c:eap_wsc_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-md5.c:eap_md5_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-tls.c:eap_tls_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-ttls.c:eap_ttls_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-mschapv2.c:eap_mschapv2_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-sim.c:eap_sim_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-aka.c:eap_aka_prime_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-aka.c:eap_aka_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-peap.c:eap_peap_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-gtc.c:eap_gtc_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/eap-pwd.c:eap_pwd_init()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_wiphy_dump_callback() New wiphy phy0 added (0)
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_wiphy_dump_done()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_filtered_wiphy_dump_done()
Jul 14 18:14:33 localhost iwd[2867]: Wiphy: 0, Name: phy0
Jul 14 18:14:33 localhost iwd[2867]:         Permanent Address: 58:d5:0a:8b:6d:e0
Jul 14 18:14:33 localhost iwd[2867]:         2.4Ghz Band:
Jul 14 18:14:33 localhost iwd[2867]:                 Bitrates (non-HT):
Jul 14 18:14:33 localhost iwd[2867]:                          1.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                          2.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                          5.5 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         11.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                          6.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                          9.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         12.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         18.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         24.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         36.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         48.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         54.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                 HT Capabilities:
Jul 14 18:14:33 localhost iwd[2867]:                         HT20
Jul 14 18:14:33 localhost iwd[2867]:                         Short GI for 20Mhz
Jul 14 18:14:33 localhost iwd[2867]:                 HT RX MCS indexes:
Jul 14 18:14:33 localhost iwd[2867]:                         0-7
Jul 14 18:14:33 localhost iwd[2867]:         5Ghz Band:
Jul 14 18:14:33 localhost iwd[2867]:                 Bitrates (non-HT):
Jul 14 18:14:33 localhost iwd[2867]:                          6.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                          9.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         12.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         18.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         24.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         36.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         48.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                         54.0 Mbps
Jul 14 18:14:33 localhost iwd[2867]:                 HT Capabilities:
Jul 14 18:14:33 localhost iwd[2867]:                         HT40
Jul 14 18:14:33 localhost iwd[2867]:                         Short GI for 20Mhz
Jul 14 18:14:33 localhost iwd[2867]:                         Short GI for 40Mhz
Jul 14 18:14:33 localhost iwd[2867]:                 HT RX MCS indexes:
Jul 14 18:14:33 localhost iwd[2867]:                         0-7
Jul 14 18:14:33 localhost iwd[2867]:                 VHT Capabilities:
Jul 14 18:14:33 localhost iwd[2867]:                         Short GI for 80Mhz
Jul 14 18:14:33 localhost iwd[2867]:                         Max RX MCS: 0-9 for NSS: 1
Jul 14 18:14:33 localhost iwd[2867]:                         Max TX MCS: 0-9 for NSS: 1
Jul 14 18:14:33 localhost iwd[2867]:         Ciphers: CCMP TKIP BIP
Jul 14 18:14:33 localhost iwd[2867]:         Supported iftypes: ad-hoc station ap p2p-client p2p-go p2p-device
Jul 14 18:14:33 localhost iwd[2867]: Wiphy phy0 will only use the default interface
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_mlme_notify() MLME notification Disconnect(48)
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_interface_dump_callback()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_get_interface_cb()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_interface_dump_callback()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_get_interface_cb()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_interface_dump_callback()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_get_interface_cb()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_mlme_notify() MLME notification Disconnect(48)
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_interface_dump_done()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_use_default()
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_create_from_genl() Created interface wlan0[42 28]
Jul 14 18:14:33 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_update_reg_domain() New reg domain country code for phy0 is 99
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_set_4addr() netdev: 42 use_4addr: 0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_initial_up_cb() Interface 42 initialized
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: disconnected, new state: autoconnect_quick
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 1
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_next() Starting work item 1
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/rrm.c:rrm_add_frame_watches()
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command Set Interface(6)
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 28
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_quick_scan_triggered() Quick scan triggered for wlan0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_notify() Scan notification New Scan Results(34)
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 124/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 123/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 141/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 141/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 78/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 78/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 78/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 123/255
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_done() get_scan_done
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:42:1a:7e:7a:78' with SSID: akurasus_24G, freq: 2412, rank: 2022, strength: -2200, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "akurasus_24G" security psk
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '7a:ac:b9:bd:e8:27' with SSID: , freq: 2412, rank: 2022, strength: -3700, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '74:ac:b9:bd:e8:27' with SSID: hejlsberg_2G, freq: 2412, rank: 2022, strength: -3700, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "hejlsberg_2G" security psk
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '74:ac:b9:bd:f7:92' with SSID: hejlsberg_2G, freq: 2437, rank: 2022, strength: -4700, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '7a:ac:b9:bd:f7:92' with SSID: , freq: 2437, rank: 2022, strength: -4800, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '74:ac:b9:bd:f8:1a' with SSID: hejlsberg_2G, freq: 2412, rank: 2022, strength: -4900, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '7a:ac:b9:bd:f8:1a' with SSID: , freq: 2412, rank: 2022, strength: -4900, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:43:4f:cc' with SSID: , freq: 2412, rank: 2022, strength: -5000, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS 'f0:03:8c:99:d5:77' with SSID: BeoSound Moment 28154806, freq: 2412, rank: 2022, strength: -5100, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "BeoSound Moment 28154806" security open
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:3b:dc:a3' with SSID: , freq: 2437, rank: 2022, strength: -6100, data_rate: 72.2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:f0:21:88:54:78' with SSID: nxptest, freq: 2412, rank: 1820, strength: -4500, data_rate: 65.0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "nxptest" security psk
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:d4:c4:c4:24:f0' with SSID: esp32_network, freq: 2437, rank: 1820, strength: -6500, data_rate: 65.0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "esp32_network" security psk
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS 'fa:8f:ca:ae:54:78' with SSID: , freq: 2412, rank: 1820, strength: -6500, data_rate: 65.0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:f0:21:88:56:ef' with SSID: titan, freq: 2437, rank: 1512, strength: -2300, data_rate: 54.0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "titan" security psk
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:35:25:ef' with SSID: , freq: 2437, rank: 1213, strength: -6700, data_rate: 43.3
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:36:6e:58' with SSID: , freq: 2437, rank: 606, strength: -7500, data_rate: 21.7
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_autoconnect_start()
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_autoconnect_next() autoconnect: Trying SSID: titan
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_autoconnect_next() autoconnect: '04:f0:21:88:56:ef' freq: 2437, rank: 1512, strength: -2300
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_cqm_rssi_update()
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:__station_connect_network() connecting to BSS 04:f0:21:88:56:ef
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: autoconnect_quick, new state: connecting (auto)
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_cancel() Trying to cancel scan id 1 for wdev 28
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_done() Work item 1 done
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_next() Starting work item 2
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_netdev_event() Associating
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_connect_event()
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_handshake_event() Setting keys
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_connect_cb() 42, result: 0
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_connect_ok()
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: connecting (auto), new state: connected
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_done() Work item 2 done
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_newlink_notify() Retrying setting OperState to IF_OPER_UP
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:34 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:36 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command Del Interface(8)
Jul 14 18:14:36 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 17 on ifindex 44
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 43
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command Del Interface(8)
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 17 on ifindex 43
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_mlme_notify() MLME notification Disconnect(48)
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_disconnect_event()
Jul 14 18:14:37 localhost iwd[2867]: Received Deauthentication event, reason: 1, from_ap: false
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_disconnect_event() 42
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_disassociated() 42
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_reset_connection_state() 42
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_roam_state_clear() 42
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: connected, new state: disconnected
Jul 14 18:14:37 localhost iwd[2867]: Unable to write drop_unsolicited_na to /proc/sys/net/ipv6/conf/wlan0/drop_unsolicited_na
Jul 14 18:14:37 localhost iwd[2867]: Unable to write drop_unicast_in_l2_multicast to /proc/sys/net/ipv6/conf/wlan0/drop_unicast_in_l2_multicast
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: disconnected, new state: autoconnect_quick
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 3
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_next() Starting work item 3
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_quick_scan_triggered() Quick scan trigger failed: -5
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: autoconnect_quick, new state: autoconnect_full
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 28
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 4
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_done() Work item 3 done
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_next() Starting work item 4
Jul 14 18:14:37 localhost iwd[2867]: Received error during CMD_TRIGGER_SCAN: Input/output error (5)
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command Del Interface(8)
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_free() Freeing netdev wlan0[42]
Jul 14 18:14:37 localhost iwd[2867]: ../iwd-1.28/src/device.c:device_free()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_free()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 28
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_cancel() Trying to cancel scan id 4 for wdev 28
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_cancel() Scan is already started
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_done() Work item 4 done
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_roam_state_clear() 42
Jul 14 18:14:38 localhost iwd[2867]: Removing scan context for wdev 28
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_context_free() sc: 0xaaaac3a0ff80
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 42
Jul 14 18:14:38 localhost iwd[2867]: Terminate
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command Del Wiphy(4)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_destroy()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_free() Freeing wiphy phy0[0]
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 17 on ifindex 42
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command New Wiphy(3)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_reg_notify() Notification of command Reg Change(36)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_update_reg_domain() New reg domain country code for (global) is XX
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_filtered_wiphy_dump_done()
Jul 14 18:14:38 localhost iwd[2867]: Wiphy: 0, Name: phy0
Jul 14 18:14:38 localhost iwd[2867]:         Permanent Address: 58:d5:0a:8b:6d:e0
Jul 14 18:14:38 localhost iwd[2867]:         2.4Ghz Band:
Jul 14 18:14:38 localhost iwd[2867]:                 Bitrates (non-HT):
Jul 14 18:14:38 localhost iwd[2867]:                          1.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                          2.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                          5.5 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         11.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                          6.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                          9.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         12.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         18.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         24.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         36.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         48.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         54.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                 HT Capabilities:
Jul 14 18:14:38 localhost iwd[2867]:                         HT40
Jul 14 18:14:38 localhost iwd[2867]:                         Short GI for 20Mhz
Jul 14 18:14:38 localhost iwd[2867]:                 HT RX MCS indexes:
Jul 14 18:14:38 localhost iwd[2867]:                         0-7
Jul 14 18:14:38 localhost iwd[2867]:         5Ghz Band:
Jul 14 18:14:38 localhost iwd[2867]:                 Bitrates (non-HT):
Jul 14 18:14:38 localhost iwd[2867]:                          6.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                          9.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         12.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         18.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         24.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         36.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         48.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                         54.0 Mbps
Jul 14 18:14:38 localhost iwd[2867]:                 HT Capabilities:
Jul 14 18:14:38 localhost iwd[2867]:                         HT40
Jul 14 18:14:38 localhost iwd[2867]:                         Short GI for 20Mhz
Jul 14 18:14:38 localhost iwd[2867]:                         Short GI for 40Mhz
Jul 14 18:14:38 localhost iwd[2867]:                 HT RX MCS indexes:
Jul 14 18:14:38 localhost iwd[2867]:                         0-7
Jul 14 18:14:38 localhost iwd[2867]:                 VHT Capabilities:
Jul 14 18:14:38 localhost iwd[2867]:                         Short GI for 80Mhz
Jul 14 18:14:38 localhost iwd[2867]:                         Max RX MCS: 0-9 for NSS: 1
Jul 14 18:14:38 localhost iwd[2867]:                         Max TX MCS: 0-9 for NSS: 1
Jul 14 18:14:38 localhost iwd[2867]:         Ciphers: CCMP TKIP BIP
Jul 14 18:14:38 localhost iwd[2867]:         Supported iftypes: ad-hoc station ap p2p-client p2p-go p2p-device
Jul 14 18:14:38 localhost iwd[2867]: Wiphy phy0 will only use the default interface
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_filtered_interface_dump_done()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_use_default()
Jul 14 18:14:38 localhost iwd[2867]: No default interface for wiphy 0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_update_reg_domain() New reg domain country code for phy0 is 99
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command New Interface(7)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Retrying setup of wiphy 0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_get_interface_cb()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_use_default()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_create_from_genl() Created interface wlan0[45 2b]
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 45
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 45
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_set_4addr() netdev: 45 use_4addr: 0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_initial_up_cb() Interface 45 initialized
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: disconnected, new state: autoconnect_quick
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 5
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_next() Starting work item 5
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/rrm.c:rrm_add_frame_watches()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 45
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command Set Interface(6)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 2b
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_quick_scan_triggered() Quick scan triggered for wlan0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 46
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command New Interface(7)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 47
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/manager.c:manager_config_notify() Notification of command New Interface(7)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 45
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 45
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 47
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 46
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 46
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 46
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_notify() Scan notification New Scan Results(34)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_link_notify() event 16 on ifindex 45
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 124/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 133/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 111/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 111/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 89/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 69/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 69/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 133/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_callback() get_scan_callback
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_parse_bss_information_elements() Load: 64/255
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:get_scan_done() get_scan_done
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:42:1a:7e:7a:78' with SSID: akurasus_24G, freq: 2412, rank: 2022, strength: -2200, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "akurasus_24G" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '74:ac:b9:bd:e8:27' with SSID: hejlsberg_2G, freq: 2412, rank: 2022, strength: -3600, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "hejlsberg_2G" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '7a:ac:b9:bd:e8:27' with SSID: , freq: 2412, rank: 2022, strength: -3700, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS 'c4:93:00:19:d4:38' with SSID: EMAS_2g, freq: 2437, rank: 2022, strength: -4100, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "EMAS_2g" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '7a:ac:b9:bd:f7:92' with SSID: , freq: 2437, rank: 2022, strength: -4700, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '74:ac:b9:bd:f7:92' with SSID: hejlsberg_2G, freq: 2437, rank: 2022, strength: -4700, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '74:ac:b9:bd:f8:1a' with SSID: hejlsberg_2G, freq: 2412, rank: 2022, strength: -4900, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '7a:ac:b9:bd:f8:1a' with SSID: , freq: 2412, rank: 2022, strength: -4900, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:43:4f:cc' with SSID: , freq: 2412, rank: 2022, strength: -5000, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:38:64:98' with SSID: , freq: 2412, rank: 2022, strength: -5600, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:3b:dc:a3' with SSID: , freq: 2437, rank: 2022, strength: -6200, data_rate: 72.2
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:f0:21:88:54:78' with SSID: nxptest, freq: 2412, rank: 1820, strength: -1200, data_rate: 65.0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "nxptest" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:d4:c4:c4:24:f0' with SSID: esp32_network, freq: 2437, rank: 1820, strength: -6500, data_rate: 65.0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "esp32_network" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '04:f0:21:88:56:ef' with SSID: titan, freq: 2437, rank: 1512, strength: -2300, data_rate: 54.0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "titan" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:35:25:ef' with SSID: , freq: 2437, rank: 1213, strength: -6700, data_rate: 43.3
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS 'fa:8f:ca:ae:54:78' with SSID: , freq: 2412, rank: 1213, strength: -7000, data_rate: 43.3
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '00:09:a7:36:6e:58' with SSID: , freq: 2437, rank: 606, strength: -7500, data_rate: 21.7
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() BSS has hidden SSID
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Processing BSS '28:24:ff:9b:2b:63' with SSID: Modelokale 4, freq: 2412, rank: 364, strength: -7900, data_rate: 13.0
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_add_seen_bss() Added new Network "Modelokale 4" security psk
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_autoconnect_start()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_autoconnect_next() autoconnect: Trying SSID: titan
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_autoconnect_next() autoconnect: '04:f0:21:88:56:ef' freq: 2437, rank: 1512, strength: -2300
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_cqm_rssi_update()
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 6
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:__station_connect_network() connecting to BSS 04:f0:21:88:56:ef
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_enter_state() Old State: autoconnect_quick, new state: connecting (auto)
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_cancel() Trying to cancel scan id 5 for wdev 2b
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_done() Work item 5 done
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_radio_work_next() Starting work item 6
Jul 14 18:14:38 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_netdev_event() Associating
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/module.c:iwd_modules_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap.c:__eap_method_disable()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-wsc.c:eap_wsc_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-md5.c:eap_md5_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-tls.c:eap_tls_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-ttls.c:eap_ttls_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-mschapv2.c:eap_mschapv2_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-sim.c:eap_sim_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-aka.c:eap_aka_prime_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-aka.c:eap_aka_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-peap.c:eap_peap_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-gtc.c:eap_gtc_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/eap-pwd.c:eap_pwd_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/dpp.c:dpp_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/offchannel.c:offchannel_exit()
Jul 14 18:14:39 localhost iwd[2867]: RRM states still exist on exit!
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/wsc.c:wsc_exit()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/scan.c:scan_context_free() sc: 0xaaaac3a15560
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_free()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/station.c:station_roam_state_clear() 45
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/device.c:device_free()
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_free() Freeing wiphy phy0[0]
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_free() Freeing netdev wlan0[45]
Jul 14 18:14:39 localhost systemd[1]: iwd.service: Main process exited, code=dumped, status=11/SEGV
Jul 14 18:14:39 localhost systemd[1]: iwd.service: Failed with result 'core-dump'.

^ permalink raw reply	[flat|nested] 5+ messages in thread

* [PATCH] iwd: Add missing module dependencies
  2022-07-14 16:52 iwd 1.28 segfault while terminating Alvin Šipraga
@ 2022-07-15 15:14 ` Denis Kenzior
  2022-07-15 15:16 ` iwd 1.28 segfault while terminating Denis Kenzior
  1 sibling, 0 replies; 5+ messages in thread
From: Denis Kenzior @ 2022-07-15 15:14 UTC (permalink / raw)
  To: iwd; +Cc: Denis Kenzior

Certain module dependencies were missing, which could cause a crash on
exit under (very unlikely) circumstances.

  #0  l_queue_peek_head (queue=<optimized out>) at ../iwd-1.28/ell/queue.c:241
  #1  0x0000aaaab752f2a0 in wiphy_radio_work_done (wiphy=0xaaaac3a129a0, id=6)
      at ../iwd-1.28/src/wiphy.c:2013
  #2  0x0000aaaab7523f50 in netdev_connect_free (netdev=netdev@entry=0xaaaac3a13db0)
      at ../iwd-1.28/src/netdev.c:765
  #3  0x0000aaaab7526208 in netdev_free (data=0xaaaac3a13db0) at ../iwd-1.28/src/netdev.c:909
  #4  0x0000aaaab75a3924 in l_queue_clear (queue=queue@entry=0xaaaac3a0c800,
      destroy=destroy@entry=0xaaaab7526190 <netdev_free>) at ../iwd-1.28/ell/queue.c:107
  #5  0x0000aaaab75a3974 in l_queue_destroy (queue=0xaaaac3a0c800,
      destroy=destroy@entry=0xaaaab7526190 <netdev_free>) at ../iwd-1.28/ell/queue.c:82
  #6  0x0000aaaab7522050 in netdev_exit () at ../iwd-1.28/src/netdev.c:6653
  #7  0x0000aaaab7579bb0 in iwd_modules_exit () at ../iwd-1.28/src/module.c:181

In this particular case, wiphy module was de-initialized prior to the
netdev module:

Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/wiphy.c:wiphy_free() Freeing wiphy phy0[0]
Jul 14 18:14:39 localhost iwd[2867]: ../iwd-1.28/src/netdev.c:netdev_free() Freeing netdev wlan0[45]
---
 src/netdev.c     | 2 ++
 src/offchannel.c | 1 +
 src/rrm.c        | 1 +
 src/scan.c       | 1 +
 src/station.c    | 4 +++-
 5 files changed, 8 insertions(+), 1 deletion(-)

diff --git a/src/netdev.c b/src/netdev.c
index ece2aab39a10..5a6a7b703b51 100644
--- a/src/netdev.c
+++ b/src/netdev.c
@@ -6676,3 +6676,5 @@ void netdev_shutdown(void)
 
 IWD_MODULE(netdev, netdev_init, netdev_exit);
 IWD_MODULE_DEPENDS(netdev, eapol);
+IWD_MODULE_DEPENDS(netdev, frame_xchg);
+IWD_MODULE_DEPENDS(netdev, wiphy);
diff --git a/src/offchannel.c b/src/offchannel.c
index c6fed569b30e..80d4ad5618f0 100644
--- a/src/offchannel.c
+++ b/src/offchannel.c
@@ -322,3 +322,4 @@ static void offchannel_exit(void)
 }
 
 IWD_MODULE(offchannel, offchannel_init, offchannel_exit);
+IWD_MODULE_DEPENDS(offchannel, wiphy);
diff --git a/src/rrm.c b/src/rrm.c
index d32ffbff4237..311e62fbe5d3 100644
--- a/src/rrm.c
+++ b/src/rrm.c
@@ -890,3 +890,4 @@ static void rrm_exit(void)
 
 IWD_MODULE(rrm, rrm_init, rrm_exit);
 IWD_MODULE_DEPENDS(rrm, netdev);
+IWD_MODULE_DEPENDS(rrm, frame_xchg);
diff --git a/src/scan.c b/src/scan.c
index cc6e682c93ee..241fecbb05e6 100644
--- a/src/scan.c
+++ b/src/scan.c
@@ -2198,3 +2198,4 @@ static void scan_exit(void)
 }
 
 IWD_MODULE(scan, scan_init, scan_exit)
+IWD_MODULE_DEPENDS(scan, wiphy)
diff --git a/src/station.c b/src/station.c
index e5972269a92f..02f21c764fe4 100644
--- a/src/station.c
+++ b/src/station.c
@@ -4614,4 +4614,6 @@ static void station_exit(void)
 
 IWD_MODULE(station, station_init, station_exit)
 IWD_MODULE_DEPENDS(station, netdev);
-IWD_MODULE_DEPENDS(station, netconfig)
+IWD_MODULE_DEPENDS(station, netconfig);
+IWD_MODULE_DEPENDS(station, frame_xchg);
+IWD_MODULE_DEPENDS(station, wiphy);
-- 
2.35.1


^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: iwd 1.28 segfault while terminating
  2022-07-14 16:52 iwd 1.28 segfault while terminating Alvin Šipraga
  2022-07-15 15:14 ` [PATCH] iwd: Add missing module dependencies Denis Kenzior
@ 2022-07-15 15:16 ` Denis Kenzior
  2022-07-18  9:10   ` Alvin Šipraga
  1 sibling, 1 reply; 5+ messages in thread
From: Denis Kenzior @ 2022-07-15 15:16 UTC (permalink / raw)
  To: Alvin Šipraga, iwd; +Cc: Emil Dahl Juhl

Hi Alvin,

<snip>

> iwd because of the BindsTo= above. From the logs, you can see that iwd
> hangs around long enough to pick up the recreated station interface and

So we manage to detect and setup the device, scan and start the connect in the 1 
second grace period during shutdown? Impressive.

Can you try the patch I just sent out to the list and see if it fixes the crash? 
  I guess we could also add some logic to disable wiphy detection when we're 
shutting down, but this is a pretty weird set of circumstances :)

Regards,
-Denis

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: iwd 1.28 segfault while terminating
  2022-07-15 15:16 ` iwd 1.28 segfault while terminating Denis Kenzior
@ 2022-07-18  9:10   ` Alvin Šipraga
  2022-07-18 15:58     ` Denis Kenzior
  0 siblings, 1 reply; 5+ messages in thread
From: Alvin Šipraga @ 2022-07-18  9:10 UTC (permalink / raw)
  To: Denis Kenzior; +Cc: iwd, Emil Dahl Juhl

Hi Denis,

On Fri, Jul 15, 2022 at 10:16:43AM -0500, Denis Kenzior wrote:
> Hi Alvin,
> 
> <snip>
> 
> > iwd because of the BindsTo= above. From the logs, you can see that iwd
> > hangs around long enough to pick up the recreated station interface and
> 
> So we manage to detect and setup the device, scan and start the connect in
> the 1 second grace period during shutdown? Impressive.

That's right ;-D

> 
> Can you try the patch I just sent out to the list and see if it fixes the
> crash?  I guess we could also add some logic to disable wiphy detection when
> we're shutting down, but this is a pretty weird set of circumstances :)

Thanks a lot for the patch. Sorry for the slow reply. But I tried it now
and it seems to do the job: after hundreds of cycles it didn't segfault
at all. Previously it was reproducible after 2-3 cycles. And I had a
look over the patch and it seems correct.

Do you intend to commit it to the upstream git tree?

Kind regards,
Alvin

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: iwd 1.28 segfault while terminating
  2022-07-18  9:10   ` Alvin Šipraga
@ 2022-07-18 15:58     ` Denis Kenzior
  0 siblings, 0 replies; 5+ messages in thread
From: Denis Kenzior @ 2022-07-18 15:58 UTC (permalink / raw)
  To: Alvin Šipraga; +Cc: iwd, Emil Dahl Juhl

Hi Alvin,

> Thanks a lot for the patch. Sorry for the slow reply. But I tried it now > and it seems to do the job: after hundreds of cycles it didn't segfault> at 
all. Previously it was reproducible after 2-3 cycles. And I had a> look over the 
patch and it seems correct.
Excellent, thanks for testing!

> 
> Do you intend to commit it to the upstream git tree?

Yes, pushed out upstream now.

Regards,
-Denis

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2022-07-18 16:03 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-07-14 16:52 iwd 1.28 segfault while terminating Alvin Šipraga
2022-07-15 15:14 ` [PATCH] iwd: Add missing module dependencies Denis Kenzior
2022-07-15 15:16 ` iwd 1.28 segfault while terminating Denis Kenzior
2022-07-18  9:10   ` Alvin Šipraga
2022-07-18 15:58     ` Denis Kenzior

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.