initialization of wpa_supplicant is very long

Arthur LAMBERT lambertarthur22 at gmail.com
Mon Jun 3 01:19:17 PDT 2019


Hi,

I have an issue with wpa_supplicant. Just after booting my device, I run
wpa_supplicant, it took between 30 seconds and 90 seconds to
initialize. It is normal ? Is there an issue in my setup/configuration ?
I am using wpa_supplicant 2.7 version on embedded device handle with
buildroot.

I can call wpa_cli -i wlan0 terminate to kill wpa_supplicant. Then if
I tried to initialize wpa_supplicant again, its only 2 or 3 seconds
to initialize. In fact the initializatiion process is not long the first
time, its seems that the process is very long only just after boot.
If I boot my device, then I wait 60 seconds, then I can run wpa_supplicant
and the work is done very quickly !

My wpa configuration file :

# cat /data/conf/wpa_supplicant.conf
ctrl_interface=/var/run/wpa_supplicant
update_config=1

logs :

# time wpa_supplicant  -B -c /data/conf/wpa_supplicant.conf -dd -i wlan0 -t
1559548613.929934: wpa_supplicant v2.7
1559548613.933464: random: Trying to read entropy from /dev/random
1559548613.933819: Successfully initialized wpa_supplicant
1559548613.934203: Initializing interface 'wlan0' conf '/data/conf/wpa_supplicant.conf' driver 'default' ctrl_interface 'N/A' bridge 'N/A'
1559548613.934691: Configuration file '/data/conf/wpa_supplicant.conf' -> '/data/conf/wpa_supplicant.conf'
1559548613.934924: Reading configuration file '/data/conf/wpa_supplicant.conf'
1559548613.936368: ctrl_interface='/var/run/wpa_supplicant'
1559548613.936706: update_config=1
1559548613.937093: Line: 4 - start of a new network block
1559548613.937441: ssid - hexdump_ascii(len=13):
     44 52 45 45 4d 2d 42 41 43 4b 2d 55 50            XXXXXXX
1559548613.938472: PSK (ASCII passphrase) - hexdump_ascii(len=9): [REMOVED]
1559548614.040959: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1559548614.041154: Line: 9 - start of a new network block
1559548614.041254: ssid - hexdump_ascii(len=10):
     44 72 65 65 6d 5f 54 65 61 6d                     XXXXXXX
1559548614.041630: PSK (ASCII passphrase) - hexdump_ascii(len=17): [REMOVED]
1559548614.114452: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1559548614.114641: Priority group 0
1559548614.114716:    id=0 ssid='XXXXX'
1559548614.114796:    id=1 ssid='XXXXX'
1559548614.128129: nl80211: Using driver-based roaming
1559548614.128267: nl80211: Supported cipher 00-0f-ac:1
1559548614.128430: nl80211: Supported cipher 00-0f-ac:5
1559548614.128542: nl80211: Supported cipher 00-0f-ac:2
1559548614.128651: nl80211: Supported cipher 00-0f-ac:4
1559548614.129181: nl80211: Using driver-based off-channel TX
1559548614.129327: nl80211: Supported vendor command: vendor_id=0x1018 subcmd=1
1559548614.129488: nl80211: Use separate P2P group interface (driver advertised support)
1559548614.129557: nl80211: use P2P_DEVICE support
1559548614.129613: nl80211: interface wlan0 in phy phy0
1559548614.131540: nl80211: Set mode ifindex 4 iftype 2 (STATION)
1559548614.132108: nl80211: Subscribe to mgmt frames with non-AP handle 0x832020
1559548614.132253: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0104
1559548614.132538: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=040a
1559548614.132789: nl80211: RegistIPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
er frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=040b
1559548614.133026: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=040c
1559548614.133248: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=040d
1559548614.133464: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=090a
1559548614.133684: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=090b
1559548614.133904: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=090c
1559548614.134180: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=090d
1559548614.134416: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0409506f9a09
1559548614.134647: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=7f506f9a09
1559548614.134861: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=06
1559548614.135077: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0a07
1559548614.135291: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0a11
1559548614.135509: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0a1a
1559548614.135727: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=1101
1559548614.135942: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=1102
1559548614.136159: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0505
1559548614.136378: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x832020 match=0500
1559548614.137522: rfkill: Cannot open RFKILL control device
1559548614.137626: nl80211: RFKILL status not available
1559548614.230560: netlink: Operstate: ifindex=4 linkmode=1 (userspace-control), operstate=5 (IF_OPER_DORMANT)
1559548614.232515: Add interface wlan0 to a new radio phy0
1559548614.234236: nl80211: Regulatory information - country=00
1559548614.234357: nl80211: 2402-2472 @ 40 MHz 20 mBm
1559548614.234503: nl80211: 2457-2482 @ 20 MHz 20 mBm (no IR)
1559548614.234640: nl80211: 2474-2494 @ 20 MHz 20 mBm (no OFDM) (no IR)
1559548614.234783: nl80211: 5170-5250 @ 80 MHz 20 mBm (no IR)
1559548614.234920: nl80211: 5250-5330 @ 80 MHz 20 mBm (DFS) (no IR)
1559548614.235064: nl80211: 5490-5730 @ 160 MHz 20 mBm (DFS) (no IR)
1559548614.235207: nl80211: 5735-5835 @ 80 MHz 20 mBm (no IR)
1559548614.235343: nl80211: 57240-63720 @ 2160 MHz 0 mBm
1559548614.235588: nl80211: Added 802.11b mode based on 802.11g information
1559548614.257134: wlan0: Own MAC address: 8c:45:00:5c:09:d3
1559548614.257434: wpa_driver_nl80211_set_key: ifindex=4 (wlan0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
1559548614.257961: wpa_driver_nl80211_set_key: ifindex=4 (wlan0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
1559548614.258406: wpa_driver_nl80211_set_key: ifindex=4 (wlan0) alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
1559548614.258762: wpa_driver_nl80211_set_key: ifindex=4 (wlan0) alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
1559548614.259067: wlan0: RSN: flushing PMKID list in the driver
1559548614.259149: nl80211: Flush PMKIDs
1559548614.263694: wlan0: WPS: UUID based on MAC address: 0e36585e-44e7-545d-866f-4a351076558f

(...)
Very long delay here
(...)

random: nonblocking pool is initialized
1559548683.469670: EAPOL: SUPP_PAE entering state DISCONNECTED
1559548683.469949: EAPOL: Supplicant port status: Unauthorized
1559548683.470122: nl80211: Skip set_supp_port(unauthorized) while not associated
1559548683.470260: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1559548683.470396: EAPOL: SUPP_BE entering state INITIALIZE
1559548683.470535: EAP: EAP entering state DISABLED
1559548683.471473: wlan0: Added interface wlan0
1559548683.471813: wlan0: State: DISCONNECTED -> DISCONNECTED
1559548683.472005: nl80211: Set wlan0 operstate 0->0 (DORMANT)
1559548683.472295: netlink: Operstate: ifindex=4 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
1559548683.472887: nl80211: Create interface iftype 10 (P2P_DEVICE)
1559548683.487103: nl80211: New P2P Device interface p2p-dev-wlan0 (0x2) created
1559548683.487496: Initializing interface 'p2p-dev-wlan0' conf '/data/conf/wpa_supplicant.conf' driver 'nl80211' ctrl_interface '/var/run/wpa_supplicant' bridge 'N/A'
1559548683.487857: Configuration file '/data/conf/wpa_supplicant.conf' -> '/data/conf/wpa_supplicant.conf'
1559548683.488089: Reading configuration file '/data/conf/wpa_supplicant.conf'
1559548683.488520: ctrl_interface='/var/run/wpa_supplicant'
1559548683.488786: update_config=1
1559548683.488977: Line: 4 - start of a new network block
1559548683.489178: ssid - hexdump_ascii(len=13):
     44 52 45 45 4d 2d 42 41 43 4b 2d 55 50            DREEM-BACK-UP   
1559548683.490242: PSK (ASCII passphrase) - hexdump_ascii(len=9): [REMOVED]
1559548683.573446: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1559548683.573601: Line: 9 - start of a new network block
1559548683.573698: ssid - hexdump_ascii(len=10):
     44 72 65 65 6d 5f 54 65 61 6d                     Dreem_Team      
1559548683.574068: PSK (ASCII passphrase) - hexdump_ascii(len=17): [REMOVED]
1559548683.647239: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1559548683.647414: Priority group 0
1559548683.647485:    id=0 ssid='DREEM-BACK-UP'
1559548683.647568:    id=1 ssid='Dreem_Team'
1559548683.720112: nl80211: Using driver-based roaming
1559548683.720283: nl80211: Supported cipher 00-0f-ac:1
1559548683.720405: nl80211: Supported cipher 00-0f-ac:5
1559548683.720518: nl80211: Supported cipher 00-0f-ac:2
1559548683.720625: nl80211: Supported cipher 00-0f-ac:4
1559548683.721162: nl80211: Using driver-based off-channel TX
1559548683.721300: nl80211: Supported vendor command: vendor_id=0x1018 subcmd=1
1559548683.721460: nl80211: Use separate P2P group interface (driver advertised support)
1559548683.721532: nl80211: use P2P_DEVICE support
1559548683.721586: nl80211: interface p2p-dev-wlan0 in phy phy0
1559548683.723166: nl80211: Set mode ifindex 0 iftype 10 (P2P_DEVICE)
1559548683.723467: nl80211: Failed to set interface 0 to mode 10: -22 (Invalid argument)
1559548683.724396: nl80211: Subscribe to mgmt frames with non-AP handle 0x84d258
1559548683.724525: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0104
1559548683.724796: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=040a
1559548683.725041: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=040b
1559548683.725270: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=040c
1559548683.725491: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=040d
1559548683.725713: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=090a
1559548683.725928: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=090b
1559548683.726144: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=090c
1559548683.726357: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=090d
1559548683.726627: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0409506f9a09
1559548683.727060: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=7f506f9a09
1559548683.727315: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=06
1559548683.727546: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0a07
1559548683.727769: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0a11
1559548683.727993: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0a1a
1559548683.728210: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=1101
1559548683.728425: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=1102
1559548683.728645: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0505
1559548683.728870: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x84d258 match=0500
1559548683.729978: rfkill: Cannot get wiphy information
1559548683.730072: nl80211: RFKILL status not available
1559548683.732725: nl80211: Start P2P Device p2p-dev-wlan0 (0x2): Success
1559548683.734386: Add interface p2p-dev-wlan0 to existing radio phy0
1559548683.736012: nl80211: Regulatory information - country=00
1559548683.736126: nl80211: 2402-2472 @ 40 MHz 20 mBm
1559548683.736272: nl80211: 2457-2482 @ 20 MHz 20 mBm (no IR)
1559548683.736413: nl80211: 2474-2494 @ 20 MHz 20 mBm (no OFDM) (no IR)
1559548683.736554: nl80211: 5170-5250 @ 80 MHz 20 mBm (no IR)
1559548683.736691: nl80211: 5250-5330 @ 80 MHz 20 mBm (DFS) (no IR)
1559548683.737129: nl80211: 5490-5730 @ 160 MHz 20 mBm (DFS) (no IR)
1559548683.737292: nl80211: 5735-5835 @ 80 MHz 20 mBm (no IR)
1559548683.737432: nl80211: 57240-63720 @ 2160 MHz 0 mBm
1559548683.737740: nl80211: Added 802.11b mode based on 802.11g information
1559548683.737874: p2p-dev-wlan0: Own MAC address: xx:xx:xx:xx:xx:xx
1559548683.737963: p2p-dev-wlan0: RSN: flushing PMKID list in the driver
1559548683.738033: nl80211: Flush PMKIDs
1559548683.738245: p2p-dev-wlan0: State: DISCONNECTED -> INACTIVE
1559548683.738421: p2p-dev-wlan0: WPS: UUID from the first interface: 0e36585e-44e7-545d-866f-4a351076558f
1559548683.741240: EAPOL: SUPP_PAE entering state DISCONNECTED
1559548683.741346: EAPOL: Supplicant port status: Unauthorized
1559548683.741417: nl80211: Skip set_supp_port(unauthorized) while not associated
1559548684.073928: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1559548684.074115: EAPOL: SUPP_BE entering state INITIALIZE
1559548684.074272: EAP: EAP entering state DISABLED
1559548684.074653: Using existing control interface directory.
1559548684.075236: P2P: Add operating class 81
1559548684.075460: P2P: Channels - hexdump(len=13): 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d
1559548684.076333: P2P: Add operating class 115
1559548684.076501: P2P: Channels - hexdump(len=4): 24 28 2c 30
1559548684.077099: P2P: Add operating class 116
1559548684.077273: P2P: Channels - hexdump(len=2): 24 2c
1559548684.077554: P2P: Add operating class 117
1559548684.077719: P2P: Channels - hexdump(len=2): 28 30
1559548684.077998: P2P: Add operating class 124
1559548684.078170: P2P: Channels - hexdump(len=4): 95 99 9d a1
1559548684.078525: P2P: Add operating class 125
1559548684.078699: P2P: Channels - hexdump(len=5): 95 99 9d a1 a5
1559548684.079095: P2P: Add operating class 126
1559548684.079262: P2P: Channels - hexdump(len=2): 95 9d
1559548684.079593: P2P: Add operating class 127
1559548684.079761: P2P: Channels - hexdump(len=2): 99 a1
1559548684.080120: P2P: Add operating class 130
1559548684.080332: P2P: Channels - hexdump(len=20): 24 28 2c 30 34 38 3c 40 64 68 6c 70 74 78 7c 80 84 88 8c 90
1559548684.086137: P2P: Own listen channel: 81:6
1559548684.086574: P2P: Random operating channel: 81:1
1559548684.087581: P2P: initialized
1559548684.088802: P2P: channels: 81:1,2,3,4,5,6,7,8,9,10,11,12,13 115:36,40,44,48 116:36,44 117:40,48 124:149,153,157,161 125:149,153,157,161,165 126:149,157 127:153,161 130:36,40,44,48,52,56,60,64,100,10
4,108,112,116,120,124,128,132,136,140,144
1559548684.089060: P2P: cli_channels:
1559548684.089308: p2p-dev-wlan0: Added interface p2p-dev-wlan0
1559548684.089624: p2p-dev-wlan0: State: INACTIVE -> DISCONNECTED
1559548684.089832: nl80211: Set p2p-dev-wlan0 operstate 0->0 (DORMANT)
1559548684.090128: netlink: Operstate: ifindex=0 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
1559548684.090645: p2p-dev-wlan0: Determining shared radio frequencies (max len 1)
1559548684.090929: p2p-dev-wlan0: Shared frequencies (len=0): completed iteration
1559548684.091131: P2P: Add operating class 81
1559548684.091315: P2P: Channels - hexdump(len=13): 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d
1559548684.092172: P2P: Add operating class 115
1559548684.092384: P2P: Channels - hexdump(len=4): 24 28 2c 30
1559548684.092747: P2P: Add operating class 116
1559548684.092912: P2P: Channels - hexdump(len=2): 24 2c
1559548684.093189: P2P: Add operating class 117
1559548684.093354: P2P: Channels - hexdump(len=2): 28 30
1559548684.093634: P2P: Add operating class 124
1559548684.093803: P2P: Channels - hexdump(len=4): 95 99 9d a1
1559548684.094157: P2P: Add operating class 125
1559548684.094327: P2P: Channels - hexdump(len=5): 95 99 9d a1 a5
1559548684.094725: P2P: Add operating class 126
1559548684.094890: P2P: Channels - hexdump(len=2): 95 9d
1559548684.095217: P2P: Add operating class 127
1559548684.095384: P2P: Channels - hexdump(len=2): 99 a1
1559548684.095744: P2P: Add operating class 130
1559548684.095956: P2P: Channels - hexdump(len=20): 24 28 2c 30 34 38 3c 40 64 68 6c 70 74 78 7c 80 84 88 8c 90
1559548684.097451: P2P: Update channel list
1559548684.098088: P2P: channels: 81:1,2,3,4,5,6,7,8,9,10,11,12,13 115:36,40,44,48 116:36,44 117:40,48 124:149,153,157,161 125:149,153,157,161,165 126:149,157 127:153,161 130:36,40,44,48,52,56,60,64,100,10
4,108,112,116,120,124,128,132,136,140,144
1559548684.098230: P2P: cli_channels:
1559548684.098330: Daemonize..
real    1m 10.29s
user    0m 0.38s
sys     0m 0.10s

Thanks,
Arthur.



More information about the Hostap mailing list