| Message ID | 84fw9f5qxw.fsf@sauna.l.org |
|---|---|
| State | Not Applicable |
| Headers | show |
Hi, Timo Juhani Lindfors <timo.lindfors@iki.fi> writes: > * read results after a timeout. */ > - timeout = 5; > + timeout = 10; > if (drv->scan_complete_events) { I recompiled the debian package and reverted this change, now the package works for me so I am confident that this change indeed has something to do with the regression.
On Fri, Jun 29, 2012 at 12:15:23AM +0300, Timo Juhani Lindfors wrote: > > * read results after a timeout. */ > > - timeout = 5; > > + timeout = 10; > > if (drv->scan_complete_events) { > > I recompiled the debian package and reverted this change, now the > package works for me so I am confident that this change indeed has > something to do with the regression. This looks like some kind of issue with the driver taking way too long to scan or maybe more likely, inconvenient timing with operations and missing indicate of scan completions.. I would assume that this driver should really be used with ap_scan=2 mode (i.e., driver-based BSS selection) rather than ap_scan=1 to avoid this type of issues.
Jouni Malinen <j@w1.fi> writes: > This looks like some kind of issue with the driver taking way too long > to scan or maybe more likely, inconvenient timing with operations and > missing indicate of scan completions.. Do the log files that I linked from the bug report help here at all? It does show "Scan timeout" in both cases: http://w1.fi/bugz/show_bug.cgi?id=456 > I would assume that this driver should really be used with ap_scan=2 > mode (i.e., driver-based BSS selection) rather than ap_scan=1 to avoid > this type of issues. I tried sudo wpa_cli -p /var/run/wpa_supplicant -i wlan ap_scan 2 but dhclient still can't get an IP: 1340920078.721452: wpa_supplicant v1.0 1340920078.722241: random: Trying to read entropy from /dev/random 1340920078.722524: Initializing interface 'wlan' conf 'N/A' driver 'wext' ctrl_interface '/var/run/wpa_supplicant' bridge 'N/A' 1340920078.723968: rfkill: Cannot open RFKILL control device 1340920078.724131: WEXT: RFKILL status not available 1340920078.735391: SIOCGIWRANGE: WE(compiled)=22 WE(source)=13 enc_capa=0x0 1340920078.735572: capabilities: key_mgmt 0x0 enc 0x3 flags 0x0 1340920078.736655: WEXT: Failed to set bogus SSID to disconnect 1340920078.765387: netlink: Operstate: linkmode=1, operstate=5 1340920078.766675: wlan: Own MAC address: 00:12:cf:8f:19:1e 1340920078.766825: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0 1340920078.767480: Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE 1340920078.767735: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0 1340920078.768431: Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE 1340920078.768651: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0 1340920078.769339: Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE 1340920078.769560: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0 1340920078.770238: Driver did not support SIOCSIWENCODEEXT, trying SIOCSIWENCODE 1340920078.770485: wpa_driver_wext_set_countermeasures 1340920078.771038: wlan: RSN: flushing PMKID list in the driver 1340920078.771268: wlan: State: DISCONNECTED -> INACTIVE 1340920078.820351: EAPOL: SUPP_PAE entering state DISCONNECTED 1340920078.820592: EAPOL: Supplicant port status: Unauthorized 1340920078.820713: EAPOL: KEY_RX entering state NO_KEY_RECEIVE 1340920078.820737: EAPOL: SUPP_BE entering state INITIALIZE 1340920078.820818: EAP: EAP entering state DISABLED 1340920078.820950: EAPOL: Supplicant port status: Unauthorized 1340920078.820983: EAPOL: Supplicant port status: Unauthorized 1340920078.821808: wlan: Added interface wlan 1340920078.821958: Daemonize.. 1340920078.827995: random: Got 20/20 bytes from /dev/random 1340920078.828811: RTM_NEWLINK: operstate=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) 1340920078.829132: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.829550: WEXT: if_removed already cleared - ignore event 1340920078.829729: RTM_NEWLINK: operstate=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) 1340920078.829874: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.830036: WEXT: if_removed already cleared - ignore event 1340920078.830218: Wireless event: cmd=0x8b06 len=8 1340920078.830404: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920078.830539: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.830705: WEXT: if_removed already cleared - ignore event 1340920078.830869: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920078.831005: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.831165: WEXT: if_removed already cleared - ignore event 1340920078.831284: Wireless event: cmd=0x8b2a len=8 1340920078.831353: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920078.831485: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.831645: WEXT: if_removed already cleared - ignore event 1340920078.831765: Wireless event: cmd=0x8b2a len=8 1340920078.831838: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920078.831972: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.832137: WEXT: if_removed already cleared - ignore event 1340920078.832259: Wireless event: cmd=0x8b2a len=8 1340920078.832331: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920078.832466: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920078.832636: WEXT: if_removed already cleared - ignore event 1340920078.832757: Wireless event: cmd=0x8b2a len=8 1340920079.834957: EAPOL: disable timer tick 1340920079.835195: EAPOL: Supplicant port status: Unauthorized 1340920082.987014: RX ctrl_iface - hexdump_ascii(len=9): 41 50 5f 53 43 41 4e 20 32 AP_SCAN 2 1340920083.120842: RX ctrl_iface - hexdump_ascii(len=11): 41 44 44 5f 4e 45 54 57 4f 52 4b ADD_NETWORK 1340920083.121178: CTRL_IFACE: ADD_NETWORK 1340920087.276792: RX ctrl_iface - hexdump_ascii(len=51): [REMOVED] 1340920087.277012: CTRL_IFACE: SET_NETWORK id=0 name='ssid' 1340920087.277138: CTRL_IFACE: value - hexdump_ascii(len=32): [REMOVED] 1340920087.277390: ssid - hexdump_ascii(len=30): 53 6f 6e 65 72 61 47 61 74 65 77 61 79 30 30 2d SoneraGateway00- 32 36 2d 34 34 2d 41 31 2d 34 35 2d 41 39 26-44-A1-45-A9 1340920091.436249: RX ctrl_iface - hexdump_ascii(len=30): [REMOVED] 1340920091.436472: CTRL_IFACE: SET_NETWORK id=0 name='psk' 1340920091.436596: CTRL_IFACE: value - hexdump_ascii(len=12): [REMOVED] 1340920091.436635: PSK (ASCII passphrase) - hexdump_ascii(len=10): [REMOVED] 1340920091.777050: PSK (from passphrase) - hexdump(len=32): [REMOVED] 1340920095.935542: RX ctrl_iface - hexdump_ascii(len=16): 45 4e 41 42 4c 45 5f 4e 45 54 57 4f 52 4b 20 30 ENABLE_NETWORK 0 1340920095.935834: CTRL_IFACE: ENABLE_NETWORK id=0 1340920095.936098: wlan: Setting scan request: 0 sec 0 usec 1340920095.936569: wlan: State: INACTIVE -> SCANNING 1340920095.936821: wlan: Trying to associate with SSID 'SoneraGateway00-26-44-A1-45-A9' 1340920095.937002: wlan: Cancelling scan request 1340920095.937217: wlan: WPA: clearing own WPA/RSN IE 1340920095.937390: wlan: Automatic auth_alg selection: 0x1 1340920095.937554: wlan: WPA: No WPA/RSN IE available from association info 1340920095.937723: wlan: WPA: Set cipher suites based on configuration 1340920095.937899: wlan: WPA: Selected cipher suites: group 30 pairwise 24 key_mgmt 3 proto 2 1340920095.938061: wlan: WPA: clearing AP WPA IE 1340920095.938224: wlan: WPA: clearing AP RSN IE 1340920095.938381: wlan: WPA: using GTK CCMP 1340920095.938525: wlan: WPA: using PTK CCMP 1340920095.938669: wlan: WPA: using KEY_MGMT 802.1X 1340920095.938843: 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 01 00 00 1340920095.939203: wlan: No keys have been configured - skip key clearing 1340920095.939366: wlan: State: SCANNING -> ASSOCIATING 1340920095.939476: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) 1340920095.939516: netlink: Operstate: linkmode=-1, operstate=5 1340920095.939826: wpa_driver_wext_associate 1340920095.939966: wpa_driver_wext_set_drop_unencrypted 1340920095.940173: wpa_driver_wext_set_psk 1340920095.940844: wlan: Setting authentication timeout: 60 sec 0 usec 1340920095.941021: EAPOL: External notification - EAP success=0 1340920095.941211: EAPOL: Supplicant port status: Unauthorized 1340920095.941285: EAPOL: External notification - EAP fail=0 1340920095.941339: EAPOL: Supplicant port status: Unauthorized 1340920095.941384: EAPOL: External notification - portControl=Auto 1340920095.941436: EAPOL: Supplicant port status: Unauthorized 1340920095.941863: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920095.942042: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920095.942280: WEXT: if_removed already cleared - ignore event 1340920095.942417: Wireless event: cmd=0x8b06 len=8 1340920095.942497: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920095.942627: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920095.942796: WEXT: if_removed already cleared - ignore event 1340920095.942916: Wireless event: cmd=0x8b1a len=38 1340920155.981364: wlan: Authentication with 00:00:00:00:00:00 timed out. 1340920155.981532: Added BSSID 00:00:00:00:00:00 into blacklist 1340920155.981675: wlan: No keys have been configured - skip key clearing 1340920155.981820: wlan: State: ASSOCIATING -> DISCONNECTED 1340920155.981909: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) 1340920155.981954: netlink: Operstate: linkmode=-1, operstate=5 1340920155.982180: EAPOL: External notification - portEnabled=0 1340920155.982303: EAPOL: Supplicant port status: Unauthorized 1340920155.982342: EAPOL: External notification - portValid=0 1340920155.982395: EAPOL: Supplicant port status: Unauthorized 1340920155.982576: wlan: Setting scan request: 1 sec 0 usec 1340920156.991578: wlan: State: DISCONNECTED -> SCANNING 1340920156.991808: wlan: Trying to associate with SSID 'SoneraGateway00-26-44-A1-45-A9' 1340920156.991975: wlan: Cancelling scan request 1340920156.992150: wlan: WPA: clearing own WPA/RSN IE 1340920156.992319: wlan: Automatic auth_alg selection: 0x1 1340920156.992482: wlan: WPA: No WPA/RSN IE available from association info 1340920156.992647: wlan: WPA: Set cipher suites based on configuration 1340920156.992821: wlan: WPA: Selected cipher suites: group 30 pairwise 24 key_mgmt 3 proto 2 1340920156.992981: wlan: WPA: clearing AP WPA IE 1340920156.993142: wlan: WPA: clearing AP RSN IE 1340920156.993300: wlan: WPA: using GTK CCMP 1340920156.993442: wlan: WPA: using PTK CCMP 1340920156.993589: wlan: WPA: using KEY_MGMT 802.1X 1340920156.993708: 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 01 00 00 1340920156.993869: wlan: No keys have been configured - skip key clearing 1340920156.994025: wlan: State: SCANNING -> ASSOCIATING 1340920156.994135: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) 1340920156.994173: netlink: Operstate: linkmode=-1, operstate=5 1340920156.994338: wpa_driver_wext_associate 1340920156.994456: wpa_driver_wext_set_drop_unencrypted 1340920156.994658: wpa_driver_wext_set_psk 1340920156.995333: wlan: Setting authentication timeout: 60 sec 0 usec 1340920156.995513: EAPOL: External notification - EAP success=0 1340920156.995610: EAPOL: Supplicant port status: Unauthorized 1340920156.995681: EAPOL: External notification - EAP fail=0 1340920156.995746: EAPOL: Supplicant port status: Unauthorized 1340920156.995773: EAPOL: External notification - portControl=Auto 1340920156.995842: EAPOL: Supplicant port status: Unauthorized 1340920156.996228: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920156.996387: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920156.996645: WEXT: if_removed already cleared - ignore event 1340920156.996790: Wireless event: cmd=0x8b06 len=8 1340920156.996871: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920156.997001: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920156.997162: WEXT: if_removed already cleared - ignore event 1340920156.997282: Wireless event: cmd=0x8b1a len=38 1340920217.038438: wlan: Authentication with 00:00:00:00:00:00 timed out. 1340920217.038644: BSSID 00:00:00:00:00:00 blacklist count incremented to 2 1340920217.038812: wlan: No keys have been configured - skip key clearing 1340920217.038977: wlan: State: ASSOCIATING -> DISCONNECTED 1340920217.039084: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) 1340920217.039120: netlink: Operstate: linkmode=-1, operstate=5 1340920217.039290: EAPOL: External notification - portEnabled=0 1340920217.039414: EAPOL: Supplicant port status: Unauthorized 1340920217.039461: EAPOL: External notification - portValid=0 1340920217.039535: EAPOL: Supplicant port status: Unauthorized 1340920217.039637: wlan: Setting scan request: 1 sec 0 usec 1340920218.048368: wlan: State: DISCONNECTED -> SCANNING 1340920218.048594: wlan: Trying to associate with SSID 'SoneraGateway00-26-44-A1-45-A9' 1340920218.048763: wlan: Cancelling scan request 1340920218.048940: wlan: WPA: clearing own WPA/RSN IE 1340920218.049111: wlan: Automatic auth_alg selection: 0x1 1340920218.049277: wlan: WPA: No WPA/RSN IE available from association info 1340920218.049442: wlan: WPA: Set cipher suites based on configuration 1340920218.049616: wlan: WPA: Selected cipher suites: group 30 pairwise 24 key_mgmt 3 proto 2 1340920218.049778: wlan: WPA: clearing AP WPA IE 1340920218.049942: wlan: WPA: clearing AP RSN IE 1340920218.050103: wlan: WPA: using GTK CCMP 1340920218.050255: wlan: WPA: using PTK CCMP 1340920218.050405: wlan: WPA: using KEY_MGMT 802.1X 1340920218.050530: 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 01 00 00 1340920218.050703: wlan: No keys have been configured - skip key clearing 1340920218.050934: wlan: State: SCANNING -> ASSOCIATING 1340920218.051055: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) 1340920218.051094: netlink: Operstate: linkmode=-1, operstate=5 1340920218.051270: wpa_driver_wext_associate 1340920218.051395: wpa_driver_wext_set_drop_unencrypted 1340920218.051627: wpa_driver_wext_set_psk 1340920218.052316: wlan: Setting authentication timeout: 60 sec 0 usec 1340920218.052484: EAPOL: External notification - EAP success=0 1340920218.052590: EAPOL: Supplicant port status: Unauthorized 1340920218.052674: EAPOL: External notification - EAP fail=0 1340920218.052744: EAPOL: Supplicant port status: Unauthorized 1340920218.052791: EAPOL: External notification - portControl=Auto 1340920218.052848: EAPOL: Supplicant port status: Unauthorized 1340920218.053224: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920218.053389: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920218.053645: WEXT: if_removed already cleared - ignore event 1340920218.053798: Wireless event: cmd=0x8b06 len=8 1340920218.053877: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) 1340920218.054010: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan' added 1340920218.054187: WEXT: if_removed already cleared - ignore event 1340920218.054309: Wireless event: cmd=0x8b1a len=38
On Fri, Jun 29, 2012 at 12:51:34AM +0300, Timo Juhani Lindfors wrote: > Do the log files that I linked from the bug report help here at all? It > does show "Scan timeout" in both cases: Well, they just confirmed that the driver does not seem to indicate when scan results are available. As such, the timeout within wpa_supplicant is in full control of the interval between the scan request and connection request going to the driver. > 1340920082.987014: RX ctrl_iface - hexdump_ascii(len=9): > 41 50 5f 53 43 41 4e 20 32 AP_SCAN 2 > 1340920083.120842: RX ctrl_iface - hexdump_ascii(len=11): > 41 44 44 5f 4e 45 54 57 4f 52 4b ADD_NETWORK > 1340920083.121178: CTRL_IFACE: ADD_NETWORK > 1340920087.276792: RX ctrl_iface - hexdump_ascii(len=51): [REMOVED] > 1340920087.277012: CTRL_IFACE: SET_NETWORK id=0 name='ssid' > 1340920087.277138: CTRL_IFACE: value - hexdump_ascii(len=32): [REMOVED] > 1340920087.277390: ssid - hexdump_ascii(len=30): > 53 6f 6e 65 72 61 47 61 74 65 77 61 79 30 30 2d SoneraGateway00- > 32 36 2d 34 34 2d 41 31 2d 34 35 2d 41 39 26-44-A1-45-A9 > 1340920091.436249: RX ctrl_iface - hexdump_ascii(len=30): [REMOVED] > 1340920091.436472: CTRL_IFACE: SET_NETWORK id=0 name='psk' > 1340920091.436596: CTRL_IFACE: value - hexdump_ascii(len=12): [REMOVED] > 1340920091.436635: PSK (ASCII passphrase) - hexdump_ascii(len=10): [REMOVED] > 1340920091.777050: PSK (from passphrase) - hexdump(len=32): [REMOVED] > 1340920095.935542: RX ctrl_iface - hexdump_ascii(len=16): > 45 4e 41 42 4c 45 5f 4e 45 54 57 4f 52 4b 20 30 ENABLE_NETWORK 0 That's not enough for ap_scan 2 mode. You will need to specify the security policy in full, i.e., set key_mgmt, pairwise, group, and proto parameters to match with the network you are using. These seemed to be key_mgmt=WPA-PSK, pairwise=CCMP, group=TKIP, proto=RSN based on the debug logs with ap_scan 1. This does not match with the wpa_supplicant defaults: > 1340920095.937899: wlan: WPA: Selected cipher suites: group 30 pairwise 24 key_mgmt 3 proto 2 > 1340920095.938061: wlan: WPA: clearing AP WPA IE > 1340920095.938224: wlan: WPA: clearing AP RSN IE > 1340920095.938381: wlan: WPA: using GTK CCMP > 1340920095.938525: wlan: WPA: using PTK CCMP > 1340920095.938669: wlan: WPA: using KEY_MGMT 802.1X At least the GTK (group) parameter is different, so the driver may refuse to connect because of this. Setting the group parameter to TKIP should address that.
Jouni Malinen <j@w1.fi> writes: > Well, they just confirmed that the driver does not seem to indicate when > scan results are available. Ok. How should it indicate this? The source code at http://gitorious.org/pkg-fso/linux-2-6-gta02/blobs/gta02/debian/patches/features/gta02/0032-Add-ar6000-wireless-driver.patch shows ar6000_ioctl_siwscan() with ar->scan_complete = 0; wait_event_interruptible_timeout(ar6000_scan_queue, ar->scan_complete, 5 * HZ); and ar6000_scanComplete_event() with ar->scan_complete = 1; wake_up_interruptible(&ar6000_scan_queue); Using sudo killall dhclient sudo killall wpa_supplicant om wifi power 0 om wifi power 1 while ! ip link show wlan; do sleep 1; done om wifi maxperf wlan 1 sudo rm -f /tmp/wpasupplicant.log sudo wpa_supplicant -B -f /tmp/wpasupplicant.log -P /var/run/wpa_supplicant.wlan.pid -i wlan -D wext -t -ddd -C /var/run/wpa_supplicant while [ ! -e /var/run/wpa_supplicant ]; do sleep 0.5; done sudo wpa_cli -p /var/run/wpa_supplicant -i wlan add_network sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 ssid "\"SoneraGateway00-26-44-A1-45-A9\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 psk "\"Thaeret0\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan enable_network 0 sudo dhclient -d wlan and sudo stap -e 'probe module("ar6000").function("ar6000_ioctl_siwscan"), module("ar6000").function("ar6000_scanComplete_event") { printf("%d %s\n", gettimeofday_us(), probefunc()); } probe module("ar6000").function("ar6000_ioctl_siwscan").return { printf("%d %s returned\n", gettimeofday_us(), probefunc()); }' I see 1341061682435032 ar6000_ioctl_siwscan 1341061685389787 ar6000_scanComplete_event 1341061685389787 ar6000_ioctl_siwscan returned The matching wpa_supplicant.log.gz is attached. > That's not enough for ap_scan 2 mode. You will need to specify the > security policy in full, i.e., set key_mgmt, pairwise, group, and proto > parameters to match with the network you are using. These seemed to be > key_mgmt=WPA-PSK, pairwise=CCMP, group=TKIP, proto=RSN based on the > debug logs with ap_scan 1. This does not match with the wpa_supplicant > defaults: I can confirm that the following works: sudo killall dhclient sudo killall wpa_supplicant om wifi power 0 om wifi power 1 while ! ip link show wlan; do sleep 1; done om wifi maxperf wlan 1 sudo rm -f /tmp/wpasupplicant.log sudo wpa_supplicant -B -f /tmp/wpasupplicant.log -P /var/run/wpa_supplicant.wlan.pid -i wlan -D wext -t -ddd -C /var/run/wpa_supplicant while [ ! -e /var/run/wpa_supplicant ]; do sleep 0.5; done sudo wpa_cli -p /var/run/wpa_supplicant -i wlan ap_scan 2 sudo wpa_cli -p /var/run/wpa_supplicant -i wlan add_network sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 key_mgmt WPA-PSK sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 pairwise CCMP sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 group TKIP sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 proto RSN sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 ssid "\"SoneraGateway00-26-44-A1-45-A9\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 psk "\"Thaeret0\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan enable_network 0 sudo dhclient -d wlan (However this is not very practical since I don't want to manually specify such parameters for the networks that I visit...)
[ Resending a copy without the attachment since http://lists.shmoo.com/pipermail/hostap/2012-June/026251.html does not seem to show the original message since it contains an attachment and I really want to make sure that the discussion is indexed by search engines so that others can benefit from our results. ] Jouni Malinen <j@w1.fi> writes: > Well, they just confirmed that the driver does not seem to indicate when > scan results are available. Ok. How should it indicate this? The source code at http://gitorious.org/pkg-fso/linux-2-6-gta02/blobs/gta02/debian/patches/features/gta02/0032-Add-ar6000-wireless-driver.patch shows ar6000_ioctl_siwscan() with ar->scan_complete = 0; wait_event_interruptible_timeout(ar6000_scan_queue, ar->scan_complete, 5 * HZ); and ar6000_scanComplete_event() with ar->scan_complete = 1; wake_up_interruptible(&ar6000_scan_queue); Using sudo killall dhclient sudo killall wpa_supplicant om wifi power 0 om wifi power 1 while ! ip link show wlan; do sleep 1; done om wifi maxperf wlan 1 sudo rm -f /tmp/wpasupplicant.log sudo wpa_supplicant -B -f /tmp/wpasupplicant.log -P /var/run/wpa_supplicant.wlan.pid -i wlan -D wext -t -ddd -C /var/run/wpa_supplicant while [ ! -e /var/run/wpa_supplicant ]; do sleep 0.5; done sudo wpa_cli -p /var/run/wpa_supplicant -i wlan add_network sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 ssid "\"SoneraGateway00-26-44-A1-45-A9\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 psk "\"Thaeret0\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan enable_network 0 sudo dhclient -d wlan and sudo stap -e 'probe module("ar6000").function("ar6000_ioctl_siwscan"), module("ar6000").function("ar6000_scanComplete_event") { printf("%d %s\n", gettimeofday_us(), probefunc()); } probe module("ar6000").function("ar6000_ioctl_siwscan").return { printf("%d %s returned\n", gettimeofday_us(), probefunc()); }' I see 1341061682435032 ar6000_ioctl_siwscan 1341061685389787 ar6000_scanComplete_event 1341061685389787 ar6000_ioctl_siwscan returned The matching wpa_supplicant.log.gz is attached but here are the most relevant lines: ... 1341061682.437789: CTRL_IFACE: ENABLE_NETWORK id=0 1341061682.438047: wlan: Setting scan request: 0 sec 0 usec 1341061682.438510: wlan: State: INACTIVE -> SCANNING 1341061682.438715: wlan: Starting AP scan for wildcard SSID 1341061685.391121: Scan requested (ret=0) - scan timeout 10 seconds 1341061695.399522: Scan timeout - try to get results 1341061695.399843: wlan: Event SCAN_RESULTS (3) received 1341061695.401823: Received 3223 bytes of scan results (13 BSSes) 1341061695.402211: Sorted scan results 1341061695.402347: 00:1e:69:36:5f:11 freq=2462 qual=19 noise=-95 level=-76 flags=0x0 1341061695.402506: 68:7f:74:1b:ce:f8 freq=2412 qual=17 noise=-95 level=-78 flags=0x0 1341061695.402599: 00:26:44:a1:45:a9 freq=2437 qual=15 noise=-95 level=-80 flags=0x0 ... > That's not enough for ap_scan 2 mode. You will need to specify the > security policy in full, i.e., set key_mgmt, pairwise, group, and proto > parameters to match with the network you are using. These seemed to be > key_mgmt=WPA-PSK, pairwise=CCMP, group=TKIP, proto=RSN based on the > debug logs with ap_scan 1. This does not match with the wpa_supplicant > defaults: I can confirm that the following works: sudo killall dhclient sudo killall wpa_supplicant om wifi power 0 om wifi power 1 while ! ip link show wlan; do sleep 1; done om wifi maxperf wlan 1 sudo rm -f /tmp/wpasupplicant.log sudo wpa_supplicant -B -f /tmp/wpasupplicant.log -P /var/run/wpa_supplicant.wlan.pid -i wlan -D wext -t -ddd -C /var/run/wpa_supplicant while [ ! -e /var/run/wpa_supplicant ]; do sleep 0.5; done sudo wpa_cli -p /var/run/wpa_supplicant -i wlan ap_scan 2 sudo wpa_cli -p /var/run/wpa_supplicant -i wlan add_network sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 key_mgmt WPA-PSK sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 pairwise CCMP sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 group TKIP sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 proto RSN sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 ssid "\"SoneraGateway00-26-44-A1-45-A9\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan set_network 0 psk "\"Thaeret0\"" sudo wpa_cli -p /var/run/wpa_supplicant -i wlan enable_network 0 sudo dhclient -d wlan (However this is not very practical since I don't want to manually specify such parameters for the networks that I visit...)
diff --git a/src/drivers/driver_wext.c b/src/drivers/driver_wext.c index 9fa356b..e44aeac 100644 --- a/src/drivers/driver_wext.c +++ b/src/drivers/driver_wext.c @@ -1007,7 +1007,7 @@ int wpa_driver_wext_scan(void *priv, struct wpa_driver_scan_params *params) /* Not all drivers generate "scan completed" wireless event, so try to * read results after a timeout. */ - timeout = 5; + timeout = 10; if (drv->scan_complete_events) { /* * The driver seems to deliver SIOCGIWSCAN events to notify
Hi, I bisected this down to commit 180cdf45a415969b851aab530e9b23606032941a Author: Jouni Malinen <jouni@qca.qualcomm.com> Date: Tue Oct 18 23:04:36 2011 +0300 wext: Increase scan timeout from 5 to 10 seconds Some dualband cards can use more than five seconds to run through a full scan, so increase the timeout to avoid hitting the missing scan completed event workaround. Here's the log for completeness: git bisect start # good: [0b86f67a2970403d1b1b6d34ce49f5485ef5dbb3] Add wpa_gui-qt4 translation files into build git bisect good 0b86f67a2970403d1b1b6d34ce49f5485ef5dbb3 # bad: [106233504ab2f55dd5f5b6454e2443aed7914383] Update version number for 1.0 release. git bisect bad 106233504ab2f55dd5f5b6454e2443aed7914383 # good: [2a0cd0670b08ae84796352e17279b792e26fa8ba] OpenSSL: Add access to Android certificates git bisect good 2a0cd0670b08ae84796352e17279b792e26fa8ba # good: [a4cba8f1e208c95218f89daec01cbcb59d97dc6c] Use sched_scan in driver init git bisect good a4cba8f1e208c95218f89daec01cbcb59d97dc6c # bad: [1dc77cda118410904886776194f56f3623f830b4] Make crypto_hash_init() easier for static analyzers git bisect bad 1dc77cda118410904886776194f56f3623f830b4 # bad: [3803bd331de647bb99a80db00cf19361b0b04be2] TLS: Validate RSA ClientKeyExchange length field git bisect bad 3803bd331de647bb99a80db00cf19361b0b04be2 # good: [ea08bfe3847c7075c7fab802441a519dd02c7654] netlink: Do not use void pointer for pointer arithmetic git bisect good ea08bfe3847c7075c7fab802441a519dd02c7654 # bad: [9fb0407055112d9f24cd451ce880326197988a61] nl80211: Use a wrapper for genlmsg_put git bisect bad 9fb0407055112d9f24cd451ce880326197988a61 # bad: [9b90955ec706905d1c5b864885d252ebf7ddba4e] AP: Pass only bssid/addr/wds to EVENT_RX_FROM_UNKNOWN git bisect bad 9b90955ec706905d1c5b864885d252ebf7ddba4e # bad: [7a25f29d890f56c4df81143f8b5eb42fb5eeeb07] Interworking: Use unsigned integer for bitfield git bisect bad 7a25f29d890f56c4df81143f8b5eb42fb5eeeb07 # good: [54e9c5fc6976c4cd1fd4cccf2b7dadaad2c4e437] EAP: Clear ClientTimeout back to default value in INITIALIZE git bisect good 54e9c5fc6976c4cd1fd4cccf2b7dadaad2c4e437 # bad: [180cdf45a415969b851aab530e9b23606032941a] wext: Increase scan timeout from 5 to 10 seconds git bisect bad 180cdf45a415969b851aab530e9b23606032941a # good: [0597a5b59d731142d53bd854b18f802fb2e01046] Add log_level command git bisect good 0597a5b59d731142d53bd854b18f802fb2e01046 Any idea what the _real_ issue here could be? Surely increasing timeout should not cause regressions?