Encryption problems with nl80211

[Dan Williams]

On Wed, 2015-10-28 at 17:25 +0100, simo wrote:
> Hi Dan, 
> 
> this is a detailed debugging output with wpa_supplicant using wext
> drivers:

Hmm, I'll bet your kernel has CFG80211_WEXT_EXPORT disabled...  so with
that in mind, the best option is to just get cfg80211 fixed to allow WEP
keys during create/join for IBSS.

Dan

> wpa_supplicant -D wext -i wlan0
> -c /etc/wpa_supplicant/wpa_supplicant.conf -dd
> wpa_supplicant v2.3
> random: Trying to read entropy from /dev/random
> Successfully initialized wpa_supplicant
> Initializing interface 'wlan0' conf
> '/etc/wpa_supplicant/wpa_supplicant.conf' driver 'wext' ctrl_interface
> 'N/A' bridge 'N/A'
> Configuration file '/etc/wpa_supplicant/wpa_supplicant.conf' ->
> '/etc/wpa_supplicant/wpa_supplicant.conf'
> Reading configuration file '/etc/wpa_supplicant/wpa_supplicant.conf'
> ap_scan=1
> ctrl_interface='/var/run/wpa_supplicant'
> Line: 3 - start of a new network block
> ssid - hexdump_ascii(len=10):
>      6d 79 2d 6e 65 74 2d 33 30 32                     my-net-302      
> mode=1 (0x1)
> frequency=2412 (0x96c)
> key_mgmt: 0x4
> priority=10 (0xa)
> Priority group 10
>    id=0 ssid='my-net-302'
> WEXT: cfg80211-based driver detected
> wext: interface wlan0 phy: phy0
> rfkill: initial event: idx=0 type=1 op=0 soft=0 hard=0
> rfkill: initial event: idx=1 type=2 op=0 soft=0 hard=0
> ioctl[SIOCSIWMODE]: Operation not supported
> Could not configure driver to use managed mode
> ioctl[SIOCGIWRANGE]: Operation not supported
> ioctl[SIOCGIWMODE]: Operation not supported
> ioctl[SIOCSIWAP]: Operation not supported
> WEXT: Failed to clear BSSID selection on disconnect
> ioctl[SIOCSIWESSID]: Operation not supported
> WEXT: Failed to clear SSID on disconnect
> netlink: Operstate: ifindex=2 linkmode=1 (userspace-control),
> operstate=5 (IF_OPER_DORMANT)
> Add interface wlan0 to a new radio phy0
> wlan0: Own MAC address: 00:19:88:4d:53:ae
> wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
> ioctl[SIOCSIWENCODEEXT]: Operation not supported
> Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE
> ioctl[SIOCSIWENCODE]: Operation not supported
> wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
> ioctl[SIOCSIWENCODEEXT]: Operation not supported
> Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE
> ioctl[SIOCSIWENCODE]: Operation not supported
> wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
> ioctl[SIOCSIWENCODEEXT]: Operation not supported
> Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE
> ioctl[SIOCSIWENCODE]: Operation not supported
> wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
> ioctl[SIOCSIWENCODEEXT]: Operation not supported
> Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE
> ioctl[SIOCSIWENCODE]: Operation not supported
> wpa_driver_wext_set_countermeasures
> wlan0: RSN: flushing PMKID list in the driver
> wlan0: Setting scan request: 0.100000 sec
> wlan0: WPS: UUID based on MAC address:
> 39cee858-d55e-5e3d-b589-30e2c9d32960
> EAPOL: SUPP_PAE entering state DISCONNECTED
> EAPOL: Supplicant port status: Unauthorized
> EAPOL: KEY_RX entering state NO_KEY_RECEIVE
> EAPOL: SUPP_BE entering state INITIALIZE
> EAP: EAP entering state DISABLED
> wlan0: Added interface wlan0
> wlan0: State: DISCONNECTED -> DISCONNECTED
> wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
> netlink: Operstate: ifindex=2 linkmode=-1 (no change), operstate=5
> (IF_OPER_DORMANT)
> random: Got 20/20 bytes from /dev/random
> RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
> RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
> WEXT: if_removed already cleared - ignore event
> RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
> RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
> WEXT: if_removed already cleared - ignore event
> wlan0: State: DISCONNECTED -> SCANNING
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa450
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa450 after 0.000091 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa450 done in 0.000458 seconds
> EAPOL: disable timer tick
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000091 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000428 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000061 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000488 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000122 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000641 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000092 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000427 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000091 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000488 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000091 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000427 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000092 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000427 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000091 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000458 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000091 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000458 seconds
> Scan timeout - try to get results
> wlan0: Event SCAN_RESULTS (3) received
> ioctl[SIOCGIWSCAN]: Operation not supported
> wlan0: Failed to get scan results
> wlan0: Failed to get scan results - try scanning again
> wlan0: Setting scan request: 1.000000 sec
> wlan0: Starting AP scan for wildcard SSID
> wlan0: Add radio work 'scan'@0xfa168
> wlan0: First radio work item in the queue - schedule start immediately
> wlan0: Starting radio work 'scan'@0xfa168 after 0.000092 second wait
> ioctl[SIOCSIWSCAN]: Operation not supported
> Scan requested (ret=-1) - scan timeout 10 seconds
> wlan0: Radio work 'scan'@0xfa168 done in 0.000427 seconds
> ^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 state=SCANNING
> wlan0: State: SCANNING -> DISCONNECTED
> wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
> netlink: Operstate: ifindex=2 linkmode=-1 (no change), operstate=5
> (IF_OPER_DORMANT)
> EAPOL: External notification - portEnabled=0
> EAPOL: External notification - portValid=0
> wpa_driver_wext_set_countermeasures
> wlan0: Cancelling scan request
> wlan0: Cancelling authentication timeout
> Remove interface wlan0 from radio phy0
> Remove radio phy0
> ioctl[SIOCGIWMODE]: Operation not supported
> ioctl[SIOCSIWAP]: Operation not supported
> WEXT: Failed to clear BSSID selection on disconnect
> ioctl[SIOCSIWESSID]: Operation not supported
> WEXT: Failed to clear SSID on disconnect
> netlink: Operstate: ifindex=2 linkmode=0 (kernel-control), operstate=6
> (IF_OPER_UP)
> wlan0: CTRL-EVENT-TERMINATING
> 
> 
> As you can see I stopped it because the error continues on and on, the
> network does not appears..
> 
> >I suppose we should be clearer about what "driver" we're
> >talking about.
> 
> >Here I'm talking about the supplicant driver, since the kernel driver
> >exposes both nl80211 and WEXT APIs.
> 
> When I wrote bout the driver I should modify, I was referring to the
> wpa_supplicant driver. I mentioned it because I see that the error
> strings are printed from the code of that driver, but I am not sure if
> this issues comes from the wpa_supplicant driver or kernel driver. 
> 
> I should have to analyse the code carefully.
> 
> The drivers that appear from the output of lsmod I suppose are the
> kernel drivers. wpa_supplicant drivers are built-in into the
> application, if I am not wrong.
> 
> Regarding to libertas driver, the wifi module uses it.
> 
> Dan, from which driver do you think the issue comes from ?
> Regards,
> 
> Simon
> 
> 
> _______________________________________________
> Hostap mailing list
> Hostap at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/hostap