Encryption problems with nl80211

[simo]

Hi Dan, 

this is a detailed debugging output with wpa_supplicant using wext
drivers:


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