rtl8188eu icon indicating copy to clipboard operation
rtl8188eu copied to clipboard

After using v4.1.8_9499 as an AP, you cant connect to a station ever again.

Open jimmyw opened this issue 3 years ago • 2 comments

I noticed that after putting the device into AP/mode (Im using NetworkManager), the device will not be able to connect to a station ever again, until you reload the module.

This is some logs trying to connect (dmesg and NetworkManger):

Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3723] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3749] device (wlan0): Activation: (wifi) connection 'wbox-wifi' has security, and secrets exist.  No new secrets needed.
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3752] Config: added 'ssid' value 'JNET'
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3753] Config: added 'scan_ssid' value '1'
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3755] Config: added 'bgscan' value 'simple:30:-80:86400'
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3756] Config: added 'key_mgmt' value 'WPA-PSK'
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3757] Config: added 'auth_alg' value 'OPEN'
Dec 21 20:19:16 561a5f6 NetworkManager[29239]: <info>  [1640117956.3758] Config: added 'psk' value '<hidden>'
Dec 21 20:19:27 561a5f6 NetworkManager[29239]: <info>  [1640117967.2818] device (wlan0): supplicant interface state: disconnected -> scanning
Dec 21 20:19:28 561a5f6 NetworkManager[29239]: <info>  [1640117968.7648] device (wlan0): supplicant interface state: scanning -> disconnected
[103127.941208] ==> rtl8188e_iol_efuse_patch
[103128.244776] R8188EU: nolinked power save leave
Dec 21 20:19:39 561a5f6 NetworkManager[29239]: <info>  [1640117979.4300] device (wlan0): supplicant interface state: disconnected -> scanning
[103130.290633] R8188EU: nolinked power save enter
Dec 21 20:19:42 561a5f6 NetworkManager[29239]: <warn>  [1640117982.1212] device (wlan0): Activation: (wifi) association took too long, failing activation
Dec 21 20:19:42 561a5f6 NetworkManager[29239]: <info>  [1640117982.1215] device (wlan0): state change: config -> failed (reason 'ssid-not-found', sys-iface-state: 'managed')
Dec 21 20:19:42 561a5f6 NetworkManager[29239]: <info>  [1640117982.1274] manager: NetworkManager state is now CONNECTED_LOCAL
Dec 21 20:19:42 561a5f6 NetworkManager[29239]: <warn>  [1640117982.1511] device (wlan0): Activation: failed for connection 'wbox-wifi'
Dec 21 20:19:42 561a5f6 NetworkManager[29239]: <info>  [1640117982.1520] device (wlan0): supplicant interface state: scanning -> disconnected
Dec 21 20:19:42 561a5f6 NetworkManager[29239]: <info>  [1640117982.1569] device (wlan0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
[103131.371341] ==> rtl8188e_iol_efuse_patch
[103131.705249] R8188EU: nolinked power save leave
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3705] policy: auto-activating connection 'wbox-wifi' (9ce75bef-8b91-41b3-8f87-1abbdc8b54e3)
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3754] device (wlan0): Activation: starting connection 'wbox-wifi' (9ce75bef-8b91-41b3-8f87-1abbdc8b54e3)
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3768] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3810] manager: NetworkManager state is now CONNECTING
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3848] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3875] device (wlan0): Activation: (wifi) access point 'wbox-wifi' has security, but secrets are required.
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.3879] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4142] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4183] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4211] device (wlan0): Activation: (wifi) connection 'wbox-wifi' has security, and secrets exist.  No new secrets needed.
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4214] Config: added 'ssid' value 'JNET'
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4216] Config: added 'scan_ssid' value '1'
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4217] Config: added 'bgscan' value 'simple:30:-80:86400'
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4219] Config: added 'key_mgmt' value 'WPA-PSK'
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4220] Config: added 'auth_alg' value 'OPEN'
Dec 21 20:19:44 561a5f6 NetworkManager[29239]: <info>  [1640117984.4221] Config: added 'psk' value '<hidden>'
[103133.731022] R8188EU: nolinked power save enter
[103143.852956] ==> rtl8188e_iol_efuse_patch
[103144.156870] R8188EU: nolinked power save leave
Dec 21 20:19:55 561a5f6 NetworkManager[29239]: <info>  [1640117995.3400] device (wlan0): supplicant interface state: disconnected -> scanning
Dec 21 20:19:56 561a5f6 NetworkManager[29239]: <info>  [1640117996.8079] device (wlan0): supplicant interface state: scanning -> disconnected
[103146.212622] R8188EU: nolinked power save enter
[103155.974583] ==> rtl8188e_iol_efuse_patch
[103156.278371] R8188EU: nolinked power save leave
Dec 21 20:20:07 561a5f6 NetworkManager[29239]: <info>  [1640118007.4601] device (wlan0): supplicant interface state: disconnected -> scanning
[103158.294152] R8188EU: nolinked power save enter
Dec 21 20:20:10 561a5f6 NetworkManager[29239]: <warn>  [1640118010.1201] device (wlan0): Activation: (wifi) association took too long, failing activation
Dec 21 20:20:10 561a5f6 NetworkManager[29239]: <info>  [1640118010.1204] device (wlan0): state change: config -> failed (reason 'ssid-not-found', sys-iface-state: 'managed')
Dec 21 20:20:10 561a5f6 NetworkManager[29239]: <info>  [1640118010.1258] manager: NetworkManager state is now CONNECTED_LOCAL
Dec 21 20:20:10 561a5f6 NetworkManager[29239]: <warn>  [1640118010.1425] device (wlan0): Activation: failed for connection 'wbox-wifi'
Dec 21 20:20:10 561a5f6 NetworkManager[29239]: <info>  [1640118010.1437] device (wlan0): supplicant interface state: scanning -> disconnected
Dec 21 20:20:10 561a5f6 NetworkManager[29239]: <info>  [1640118010.1465] device (wlan0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
[103159.354954] ==> rtl8188e_iol_efuse_patch
[103159.688746] R8188EU: nolinked power save leave
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3501] policy: auto-activating connection 'wbox-wifi' (9ce75bef-8b91-41b3-8f87-1abbdc8b54e3)
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3559] device (wlan0): Activation: starting connection 'wbox-wifi' (9ce75bef-8b91-41b3-8f87-1abbdc8b54e3)
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3573] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3609] manager: NetworkManager state is now CONNECTING
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3646] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3672] device (wlan0): Activation: (wifi) access point 'wbox-wifi' has security, but secrets are required.
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3674] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3896] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3932] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3957] device (wlan0): Activation: (wifi) connection 'wbox-wifi' has security, and secrets exist.  No new secrets needed.
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3960] Config: added 'ssid' value 'JNET'
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3961] Config: added 'scan_ssid' value '1'
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3963] Config: added 'bgscan' value 'simple:30:-80:86400'
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3964] Config: added 'key_mgmt' value 'WPA-PSK'
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3965] Config: added 'auth_alg' value 'OPEN'
Dec 21 20:20:12 561a5f6 NetworkManager[29239]: <info>  [1640118012.3966] Config: added 'psk' value '<hidden>'
[103161.734575] R8188EU: nolinked power save enter

Tried to disable rtw_enusbss and rtw_power_mgnt without any change. Any other parameters that I might fiddle with?

Using NetworkManager to put it into ap mode, not sure that is using hostapd or interfaces the kernel directly?

Im happy to provide more logs, and debug if you send me in the right direction.

versions: rtl8188eu: v4.1.8_9499 Linux version: 5.4.166 wpa_supplicant: v2.9 NetworkManager: 1.20.2

/Jimmy

jimmyw avatar Dec 21 '21 20:12 jimmyw

logs from wpa_supplicant

wlan0: Starting AP scan for wildcard SSID
wlan0: Add radio work 'scan'@0x651968
wlan0: First radio work item in the queue - schedule start immediately
wlan0: Starting radio work 'scan'@0x651968 after 0.000053 second wait
wlan0: nl80211: scan request
nl80211: Scan SSID JNET
nl80211: Scan SSID
[160800.682481] ==> rtl8188e_iol_efuse_patch
[160800.986672] R8188EU: nolinked power save leave
Scan requested (ret=0) - scan timeout 30 seconds
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
nl80211: Event message available
nl80211: Drv Event 33 (NL80211_CMD_TRIGGER_SCAN) received for wlan0
wlan0: nl80211: Scan trigger
wlan0: Event SCAN_STARTED (47) received
wlan0: Own scan request started a scan in 0.002623 seconds
nl80211: Event message available
nl80211: Drv Event 34 (NL80211_CMD_NEW_SCAN_RESULTS) received for wlan0
wlan0: nl80211: New scan results available
nl80211: Scan probed for SSID 'JNET'
nl80211: Scan probed for SSID ''
nl80211: Scan included frequencies: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 2467 2472 2484 5180 5190 5200 5210 5220 5230 5240 5260 5280 5300 5320 5500 5520 5540 5560 5580 5600 5620 5640 5660 5680 5700 5745 5765 5785 5805 5825
wlan0: Event SCAN_RESULTS (3) received
wlan0: Scan completed in 1.432231 seconds
nl80211: Received scan results (14 BSSes)
nl80211: Scan results indicate BSS status with 68:d7:9a:45:c5:22 as associated
nl80211: Local state (not associated) does not match with BSS state
wlan0: BSS: Start scan result update 4
wlan0: BSS: Add new id 13 BSSID 08:36:c9:1d:cd:fe SSID 'NETGEAR_EXT' freq 2412
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/13'
BSS: last_scan_res_used=14/32
wlan0: New scan results available (own=1 ext=0)
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: AP 08:36:c9:1d:cd:fe type 0 added
WPS: AP[0] 28:41:c6:32:55:80 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[1] 00:5f:67:53:03:a5 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[2] fc:34:97:6e:da:40 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[3] a4:11:62:8e:99:28 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[4] a4:11:62:80:ff:38 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[5] fc:34:97:6e:d9:41 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[6] 84:1e:a3:4b:6c:a6 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[7] 08:36:c9:1d:cd:fe type=0 tries=0 last_attempt=-1 sec ago blacklist=0
wlan0: Radio work 'scan'@0x651968 done in 2.112508 seconds
wlan0: radio_work_free('scan'@0x651968): num_active_works --> 0
wlan0: Scan results matching the currently selected network
wlan0: 2: 68:d7:9a:45:ce:aa freq=2412 level=-53 snr=36 est_throughput=65000
wpa_parse_wpa_ie_rsn: ignore trailing bytes - hexdump(len=4): 00 0f ac 06
wlan0: Selecting BSS from priority group 0
wlan0: 0: 68:d7:9a:45:c5:22 ssid='JNET' wpa_ie_len=0 rsn_ie_len=20 caps=0x31 level=-45 freq=2462
wlan0:    skip - blacklisted (count=1 limit=0)
wlan0: 1: 6a:d7:9a:15:c5:22 ssid='' wpa_ie_len=0 rsn_ie_len=20 caps=0x431 level=-45 freq=2462
wlan0:    skip - SSID not known
wlan0: 2: 68:d7:9a:45:ce:aa ssid='JNET' wpa_ie_len=0 rsn_ie_len=20 caps=0x31 level=-53 freq=2412
wlan0:    selected based on RSN IE
wlan0:    selected BSS 68:d7:9a:45:ce:aa ssid='JNET'
wlan0: Considering connect request: reassociate: 0  selected: 68:d7:9a:45:ce:aa  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING  ssid=0x6509a8  current_ssid=0x6509a8
wlan0: Request association with 68:d7:9a:45:ce:aa
wlan0: Re-association to the same ESS
wlan0: No ongoing scan/p2p-scan found to abort
wlan0: Add radio work 'connect'@0x651d68
wlan0: First radio work item in the queue - schedule start immediately
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
wlan0: Starting radio work 'connect'@0x651d68 after 0.000143 second wait
wlan0: Trying to associate with 68:d7:9a:45:ce:aa (SSID='JNET' freq=2412 MHz)
wlan0: Cancelling scan request
wlan0: WPA: clearing own WPA/RSN IE
RSN: PMKSA cache search - network_ctx=0x6509a8 try_opportunistic=0 akmp=0x0
RSN: Search for BSSID 68:d7:9a:45:ce:aa
RSN: No PMKSA cache entry found
wlan0: RSN: using IEEE 802.11i/D9.0
wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
wlan0: WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlan0: WPA: AP group 0x10 network profile group 0x18; available group 0x10
wlan0: WPA: using GTK CCMP
wlan0: WPA: AP pairwise 0x10 network profile pairwise 0x18; available pairwise 0x10
wlan0: WPA: using PTK CCMP
wlan0: WPA: AP key_mgmt 0x2 network profile key_mgmt 0x2; available key_mgmt 0x2
wlan0: WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
PSK (set in config) - hexdump(len=32): [REMOVED]
WPA: Set PMK based on external data - hexdump(len=32): [REMOVED]
wlan0: Automatic auth_alg selection: 0x1
wlan0: Overriding auth_alg selection: 0x1
Added supported operating classes IE - hexdump(len=20): 3b 12 51 51 52 53 54 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f
wlan0: State: SCANNING -> ASSOCIATING
nl80211: Set wlan0 operstate 0->0 (DORMANT)
netlink: Operstate: ifindex=13 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
Limit connection to BSSID 68:d7:9a:45:ce:aa freq=2412 MHz based on scan results (bssid_set=0 wps=0)
nl80211: Set mode ifindex 13 iftype 2 (STATION)
nl80211: Unsubscribe mgmt frames handle 0x88ed9739 (mode change)
nl80211: Subscribe to mgmt frames with non-AP handle 0x651fb0
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=06
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0a07
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0a11
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=1101
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=1102
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0505
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0500
nl80211: Connect (ifindex=13)
  * bssid=68:d7:9a:45:ce:aa
  * bssid_hint=68:d7:9a:45:ce:aa
  * freq=2412
  * freq_hint=2412
  * SSID=JNET
  * IEs - hexdump(len=42): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 3b 12 51 51 52 53 54 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f
  * WPA Versions 0x2
  * pairwise=0xfac04
  * group=0xfac04
  * akm=0xfac02
  * Auth Type 0
nl80211: MLME connect failed: ret=-114 (Operation already in progress)
nl80211: Explicitly disconnecting before reassociation attempt
wpa_driver_nl80211_disconnect(reason_code=2)
nl80211: Connect (ifindex=13)
  * bssid=68:d7:9a:45:ce:aa
  * bssid_hint=68:d7:9a:45:ce:aa
  * freq=2412
  * freq_hint=2412
  * SSID=JNET
  * IEs - hexdump(len=42): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 3b 12 51 51 52 53 54 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f
  * WPA Versions 0x2
  * pairwise=0xfac04
  * group=0xfac04
  * akm=0xfac02
  * Auth Type 0
nl80211: ML[160803.012154] R8188EU: nolinked power save enter
ME connect failed: ret=-114 (Operation already in progress)
wlan0: Association request to the driver failed
wlan0: Radio work 'connect'@0x651d68 done in 0.334760 seconds
wlan0: radio_work_free('connect'@0x651d68): num_active_works --> 0
Added BSSID 68:d7:9a:45:ce:aa into blacklist
wlan0: Blacklist count 2 --> request scan in 500 ms
wlan0: Setting scan request: 0.500000 sec
wlan0: State: ASSOCIATING -> DISCONNECTED
nl80211: Set wlan0 operstate 0->0 (DORMANT)
netlink: Operstate: ifindex=13 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/13) [s]
RTM_NEWLINK: ifi_index=13 ifname=wlan0 wext ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
wlan0: State: DISCONNECTED -> SCANNING
Scan SSID - hexdump_ascii(len=4):
     4a 4e 45 54                                       JNET
wlan0: Starting AP scan for wildcard SSID
wlan0: Add radio work 'scan'@0x651d68
wlan0: First radio work item in the queue - schedule start immediately
wlan0: Starting radio work 'scan'@0x651d68 after 0.000052 second wait
wlan0: nl80211: scan request
nl80211: Scan SSID JNET
nl80211: Scan SSID
[160803.632865] ==> rtl8188e_iol_efuse_patch
[160803.936783] R8188EU: nolinked power save leave
Scan requested (ret=0) - scan timeout 30 seconds
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
nl80211: Event message available
nl80211: Drv Event 33 (NL80211_CMD_TRIGGER_SCAN) received for wlan0
wlan0: nl80211: Scan trigger
wlan0: Event SCAN_STARTED (47) received
wlan0: Own scan request started a scan in 0.002367 seconds
nl80211: Event message available
nl80211: Drv Event 34 (NL80211_CMD_NEW_SCAN_RESULTS) received for wlan0
wlan0: nl80211: New scan results available
nl80211: Scan probed for SSID 'JNET'
nl80211: Scan probed for SSID ''
nl80211: Scan included frequencies: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 2467 2472 2484 5180 5190 5200 5210 5220 5230 5240 5260 5280 5300 5320 5500 5520 5540 5560 5580 5600 5620 5640 5660 5680 5700 5745 5765 5785 5805 5825
wlan0: Event SCAN_RESULTS (3) received
wlan0: Scan completed in 1.433390 seconds
nl80211: Received scan results (14 BSSes)
nl80211: Scan results indicate BSS status with 68:d7:9a:45:c5:22 as associated
nl80211: Local state (not associated) does not match with BSS state
wlan0: BSS: Start scan result update 5
BSS: last_scan_res_used=14/32
wlan0: New scan results available (own=1 ext=0)
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: AP[0] 28:41:c6:32:55:80 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[1] 00:5f:67:53:03:a5 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[2] fc:34:97:6e:da:40 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[3] a4:11:62:8e:99:28 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[4] a4:11:62:80:ff:38 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[5] fc:34:97:6e:d9:41 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[6] 84:1e:a3:4b:6c:a6 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[7] 08:36:c9:1d:cd:fe type=0 tries=0 last_attempt=-1 sec ago blacklist=0
wlan0: Radio work 'scan'@0x651d68 done in 2.112698 seconds
wlan0: radio_work_free('scan'@0x651d68): num_active_works --> 0
wlan0: Scan results matching the currently selected network
wpa_parse_wpa_ie_rsn: ignore trailing bytes - hexdump(len=4): 00 0f ac 06
wlan0: Selecting BSS from priority group 0
wlan0: 0: 68:d7:9a:45:c5:22 ssid='JNET' wpa_ie_len=0 rsn_ie_len=20 caps=0x31 level=-45 freq=2462
wlan0:    skip - blacklisted (count=1 limit=0)
wlan0: 1: 6a:d7:9a:15:c5:22 ssid='' wpa_ie_len=0 rsn_ie_len=20 caps=0x431 level=-45 freq=2462
wlan0:    skip - SSID not known
wlan0: 2: 68:d7:9a:45:ce:aa ssid='JNET' wpa_ie_len=0 rsn_ie_len=20 caps=0x31 level=-53 freq=2412
wlan0:    skip - blacklisted (count=1 limit=0)
wlan0: 3: 28:41:c6:32:55:80 ssid='JNET2' wpa_ie_len=0 rsn_ie_len=24 caps=0x1431 level=-68 freq=2452  wps
wlan0:    skip - SSID mismatch
wlan0: 4: 00:5f:67:53:03:a5 ssid='Panji Airlines' wpa_ie_len=0 rsn_ie_len=20 caps=0x1c11 level=-68 freq=2462  wps
wlan0:    skip - SSID mismatch
wlan0: 5: 02:5f:67:63:03:a5 ssid='' wpa_ie_len=0 rsn_ie_len=20 caps=0xc11 level=-69 freq=2462
wlan0:    skip - SSID not known
wlan0: 6: a4:11:62:8e:99:28 ssid='ARLO_VMB_2661226231' wpa_ie_len=0 rsn_ie_len=20 caps=0x431 level=-73 freq=2457  wps
wlan0:    skip - SSID mismatch
wlan0: 7: a4:11:62:80:ff:38 ssid='ARLO_VMB_5381126489' wpa_ie_len=0 rsn_ie_len=20 caps=0x431 level=-73 freq=2462  wps
wlan0:    skip - SSID mismatch
wlan0: 8: fc:34:97:6e:da:40 ssid='Molle2' wpa_ie_len=22 rsn_ie_len=20 caps=0x1411 level=-73 freq=2457  wps
wlan0:    skip - SSID mismatch
wlan0: 9: fc:34:97:6e:d9:41 ssid='Molle2' wpa_ie_len=22 rsn_ie_len=20 caps=0x1411 level=-74 freq=2457  wps
wlan0:    skip - SSID mismatch
wlan0: 10: 0c:96:bf:85:6b:1d ssid='Tele2Internet-13F90' wpa_ie_len=26 rsn_ie_len=24 caps=0x411 level=-82 freq=2412
wlan0:    skip - SSID mismatch
wpa_parse_wpa_ie_rsn: ignore trailing bytes - hexdump(len=4): 00 0f ac 06
wlan0: 11: 84:1e:a3:4b:6c:a6 ssid='Panji Airlines Optic' wpa_ie_len=0 rsn_ie_len=26 caps=0x1411 level=-83 freq=2437  wps
wlan0:    skip - SSID mismatch
wlan0: 12: fa:8f:ca:66:b8:97 ssid='' wpa_ie_len=0 rsn_ie_len=0 caps=0x421 level=-82 freq=2457
wlan0:    skip - SSID not known
wlan0: 13: 08:36:c9:1d:cd:fe ssid='NETGEAR_EXT' wpa_ie_len=0 rsn_ie_len=0 caps=0x1421 level=-83 freq=2412  wps
wlan0:    skip - SSID mismatch
wlan0: No APs found - clear blacklist and try again
Removed BSSID 68:d7:9a:45:ce:aa from blacklist (clear)
Removed BSSID 68:d7:9a:45:c5:22 from blacklist (clear)
wlan0: Scan results matching the currently selected network
wlan0: 0: 68:d7:9a:45:c5:22 freq=2462 level=-45 snr=44 est_throughput=65000
wlan0: 2: 68:d7:9a:45:ce:aa freq=2412 level=-53 snr=36 est_throughput=65000
wpa_parse_wpa_ie_rsn: ignore trailing bytes - hexdump(len=4): 00 0f ac 06
wlan0: Selecting BSS from priority group 0
wlan0: 0: 68:d7:9a:45:c5:22 ssid='JNET' wpa_ie_len=0 rsn_ie_len=20 caps=0x31 level=-45 freq=2462
wlan0:    selected based on RSN IE
wlan0:    selected BSS 68:d7:9a:45:c5:22 ssid='JNET'
wlan0: Considering connect request: reassociate: 0  selected: 68:d7:9a:45:c5:22  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING  ssid=0x6509a8  current_ssid=0x6509a8
wlan0: Request association with 68:d7:9a:45:c5:22
wlan0: Re-association to the same ESS
wlan0: No ongoing scan/p2p-scan found to abort
wlan0: Add radio work 'connect'@0x651d68
wlan0: First radio work item in the queue - schedule start immediately
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
RTM_NEWLINK: ifi_index=13 ifname=wlan0 wext ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/0
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/10
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/1
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/4
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/2
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/3
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/5
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/7
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/6
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/[160805.972510] R8188EU: nolinked power save enter
8
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/12
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/11
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
WPS: Unsupported attribute type 0x1058 len=24
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/9
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/13
wlan0: Starting radio work 'connect'@0x651d68 after 0.007398 second wait
wlan0: Trying to associate with 68:d7:9a:45:c5:22 (SSID='JNET' freq=2462 MHz)
wlan0: Cancelling scan request
wlan0: WPA: clearing own WPA/RSN IE
RSN: PMKSA cache search - network_ctx=0x6509a8 try_opportunistic=0 akmp=0x0
RSN: Search for BSSID 68:d7:9a:45:c5:22
RSN: No PMKSA cache entry found
wlan0: RSN: using IEEE 802.11i/D9.0
wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
wlan0: WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlan0: WPA: AP group 0x10 network profile group 0x18; available group 0x10
wlan0: WPA: using GTK CCMP
wlan0: WPA: AP pairwise 0x10 network profile pairwise 0x18; available pairwise 0x10
wlan0: WPA: using PTK CCMP
wlan0: WPA: AP key_mgmt 0x2 network profile key_mgmt 0x2; available key_mgmt 0x2
wlan0: WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
PSK (set in config) - hexdump(len=32): [REMOVED]
WPA: Set PMK based on external data - hexdump(len=32): [REMOVED]
wlan0: Automatic auth_alg selection: 0x1
wlan0: Overriding auth_alg selection: 0x1
Added supported operating classes IE - hexdump(len=20): 3b 12 51 51 52 53 54 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f
wlan0: State: SCANNING -> ASSOCIATING
nl80211: Set wlan0 operstate 0->0 (DORMANT)
netlink: Operstate: ifindex=13 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
Limit connection to BSSID 68:d7:9a:45:c5:22 freq=2462 MHz based on scan results (bssid_set=0 wps=0)
nl80211: Set mode ifindex 13 iftype 2 (STATION)
nl80211: Unsubscribe mgmt frames handle 0x88ed9739 (mode change)
nl80211: Subscribe to mgmt frames with non-AP handle 0x651fb0
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=06
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0a07
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0a11
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=1101
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=1102
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0505
nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x651fb0 match=0500
nl80211: Connect (ifindex=13)
  * bssid=68:d7:9a:45:c5:22
  * bssid_hint=68:d7:9a:45:c5:22
  * freq=2462
  * freq_hint=2462
  * SSID=JNET
  * IEs - hexdump(len=42): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 3b 12 51 51 52 53 54 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f
  * WPA Versions 0x2
  * pairwise=0xfac04
  * group=0xfac04
  * akm=0xfac02
  * Auth Type 0
nl80211: MLME connect failed: ret=-114 (Operation already in progress)
nl80211: Explicitly disconnecting before reassociation attempt
wpa_driver_nl80211_disconnect(reason_code=2)
nl80211: Connect (ifindex=13)
  * bssid=68:d7:9a:45:c5:22
  * bssid_hint=68:d7:9a:45:c5:22
  * freq=2462
  * freq_hint=2462
  * SSID=JNET
  * IEs - hexdump(len=42): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 3b 12 51 51 52 53 54 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f
  * WPA Versions 0x2
  * pairwise=0xfac04
  * group=0xfac04
  * akm=0xfac02
  * Auth Type 0
nl80211: MLME connect failed: ret=-114 (Operation already in progress)
wlan0: Association request to the driver failed
wlan0: Radio work 'connect'@0x651d68 done in 0.337598 seconds
wlan0: radio_work_free('connect'@0x651d68): num_active_works --> 0
Added BSSID 68:d7:9a:45:c5:22 into blacklist
wlan0: Blacklist count 3 --> request scan in 1000 ms
wlan0: Setting scan request: 1.000000 sec
wlan0: State: ASSOCIATING -> DISCONNECTED
nl80211: Set wlan0 operstate 0->0 (DORMANT)
netlink: Operstate: ifindex=13 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
^Cwlan0: Removing interface wlan0
wlan0: Request to deauthenticate - bssid=00:00:00:00:00:00 pending_bssid=00:00:00:00:00:00 reason=3 (DEAUTH_LEAVING) state=DISCONNECTED
wlan0: State: DISCONNECTED -> DISCONNECTED
nl80211: Set wlan0 operstate 0->0 (DORMANT)
netlink: Operstate: ifindex=13 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - EAP success=0
dbus: Unregister network object '/fi/w1/wpa_supplicant1/Interfaces/0/Networks/0'
wlan0: WPA: Clear old PMK and PTK
Removed BSSID 68:d7:9a:45:c5:22 from blacklist (clear)
wlan0: BSS: Remove id 0 BSSID 68:d7:9a:45:c5:22 SSID 'JNET' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/0'
wlan0: BSS: Remove id 10 BSSID 6a:d7:9a:15:c5:22 SSID '' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/10'
wlan0: BSS: Remove id 1 BSSID 68:d7:9a:45:ce:aa SSID 'JNET' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/1'
wlan0: BSS: Remove id 4 BSSID 28:41:c6:32:55:80 SSID 'JNET2' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/4'
wlan0: BSS: Remove id 2 BSSID 00:5f:67:53:03:a5 SSID 'Panji Airlines' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/2'
wlan0: BSS: Remove id 3 BSSID 02:5f:67:63:03:a5 SSID '' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/3'
wlan0: BSS: Remove id 5 BSSID a4:11:62[160807.049786] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
:8e:99:28 SSID 'ARLO_VMB_2661226231' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/5'
wlan0: BSS: Remove id 7 BSSID a4:11:62:80:ff:38 SSID 'ARLO_VMB_5381126489' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/7'
wlan0: BSS: Remove id 6 BSSID fc:34:97:6e:da:40 SSID 'Molle2' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/6'
wlan0: BSS: Remove id 8 BSSID fc:34:97:6e:d9:41 SSID 'Molle2' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/8'
wlan0: BSS: Remove id 12 BSSID 0c:96:bf:85:6b:1d SSID 'Tele2Internet-13F90' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/12'
wlan0: BSS: Remove id 11 BSSID 84:1e:a3:4b:6c:a6 SSID 'Panji Airlines Optic' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/11'
wlan0: BSS: Remove id 9 BSSID fa:8f:ca:66:b8:97 SSID '' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/9'
wlan0: BSS: Remove id 13 BSSID 08:36:c9:1d:cd:fe SSID 'NETGEAR_EXT' due to wpa_bss_flush
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/13'
wlan0: Cancelling scan request
wlan0: Cancelling authentication timeout
Remove interface wlan0 from radio phy4
Remove radio phy4
nl80211: deinit ifname=wlan0 disabled_11b_rates=0
nl80211: Remove monitor interface: refcount=0
netlink: Operstate: ifindex=13 linkmode=0 (kernel-control), operstate=6 (IF_OPER_UP)
nl80211: Set mode ifindex 13 iftype 2 (STATION)
nl80211: Unsubscribe mgmt frames handle 0x88ed9739 (mode change)
dbus: Unregister interface object '/fi/w1/wpa_supplicant1/Interfaces/0'
wlan0: CTRL-EVENT-TERMINATING
dbus: Unregister D-Bus object '/fi/w1/wpa_supplicant1'

jimmyw avatar Dec 22 '21 10:12 jimmyw

Im not sure if this is realated to my erlier bug, but getting the same "Operation already in progress (-114)" error. Not sure if my commands are correct, or if this are supposed to work.

Load module

root@561a5f6:/etc# modprobe 8188eu
[621190.093262] bFWReady == false call reset 8051...
[621190.132628] SupportPlatform 0x4
[621190.144757] usbcore: registered new interface driver rtl8188eu

Bring up interface

root@561a5f6:/etc# ifconfig wlan0 up
[621199.768194] R8188EU: +load_firmware: !bUsedWoWLANFw, FmrmwareLen:13904+
[621199.775008] R8188EU: Loaded firmware file rtlwifi/rtl8188eufw.bin
[621199.781271] R8188EU: Firmware Version 11, SubVersion 1, Signature 0x88e1
[621200.150740] ==> rtl8188e_iol_efuse_patch
root@561a5f6:/etc# iw dev wlan0 link
Not connected.

Connect to a AP

root@561a5f6:/etc# iw wlan0 connect JNETM
[621247.997125] ==> rtl8188e_iol_efuse_patch
[621248.301415] R8188EU: nolinked power save leave
[621248.306216] R8188EU: rtw_set_802_11_connect(wlan0)  fw_state =0x00000000
root@561a5f6:/etc# [621249.787645] R8188EU: start auth
[621249.797742] R8188EU: auth success, start assoc
[621249.812089] R8188EU: rtw_cfg80211_indicate_connect(wlan0) BSS not found !!
[621249.819114] R8188EU: assoc success
[621249.822769] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
root@561a5f6:/etc# iw dev wlan0 link
Connected to da:0f:15:0c:48:5a (on wlan0)
        SSID: JNETM
        freq: 2462
        tx bitrate: 72.2 MBit/s

Disconnect

root@561a5f6:/etc# iw dev wlan0 disconnect
root@561a5f6:/etc# iw dev wlan0 link
Connected to da:0f:15:0c:48:5a (on wlan0)
        SSID: JNETM
        freq: 2462
command failed: No such file or directory (-2)
root@561a5f6:/etc# iw wlan0 connect JNETM
command failed: Operation already in progress (-114)

jimmyw avatar Dec 27 '21 20:12 jimmyw