Bug 193826 - iwn does not scan channels
Summary: iwn does not scan channels
Status: New
Alias: None
Product: Base System
Classification: Unclassified
Component: wireless (show other bugs)
Version: CURRENT
Hardware: amd64 Any
: --- Affects Some People
Assignee: freebsd-wireless (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-09-22 04:13 UTC by Henry Hu
Modified: 2014-12-23 01:23 UTC (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Henry Hu 2014-09-22 04:13:28 UTC
I'm trying to use DTrace to trace a problem I'm seeing from time to time.
After some time, iwn can't get any scan result. ifconfig says:

wlan0: flags=8c43<UP,BROADCAST,RUNNING,OACTIVE,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether c4:85:08:82:da:5c
        inet 0.0.0.0 netmask 0xff000000 broadcast 255.255.255.255
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
        media: IEEE 802.11 Wireless Ethernet MCS mode 11ng (autoselect)
        status: no carrier
        ssid "" channel 1 (2412 MHz 11g ht/20)
        country US authmode WPA1+WPA2/802.11i privacy MIXED deftxkey UNDEF
        txpower 11 bmiss 10 scanvalid 60 protmode CTS ht20 ampdulimit 8k
        -amsdutx amsdurx shortgi wme roaming MANUAL

and ifconfig wlan0 scan returns no results, neither do wpa_cli scan_results

With wlandebug +scan, I see these messages:

Sep 21 00:40:52 pepsi kernel: wlan0: ieee80211_scanreq: flags 0x20052 duration 0x7fffffff mindwell 0 maxdwell 0 nssid 1
Sep 21 00:40:52 pepsi kernel: wlan0: ieee80211_check_scan: active scan, append, nojoin, once
Sep 21 00:40:52 pepsi kernel: wlan0: start_scan_locked: active scan, duration 2147483647 mindwell 0 maxdwell 0, desired mode 11ng, append, nojoin, once
Sep 21 00:40:52 pepsi kernel: wlan0: scan set  dwell min 20ms max 200ms
Sep 21 00:40:52 pepsi kernel: wlan0: scan_task: no channels to scan
Sep 21 00:40:52 pepsi kernel: wlan0: notify scan done

it seems like that the channel list to scan is empty.

By using dtrace to print some information in makescanlist() in ieee80211_scan_sta.c, I find that:
vap->iv_des_mode = 9 (IEEE80211_MODE_11NG)
everything in table[] has mode = 1 or 2 (IEEE80211_MODE_11A / 11B)
According to logic in makescanlist,
        if (vap->iv_des_mode != IEEE80211_MODE_AUTO) {
            /*
             * If a desired mode was specified, scan only
             * channels that satisfy that constraint.
             */
            if (vap->iv_des_mode != mode) {
                /*
                 * The scan table marks 2.4Ghz channels as b
                 * so if the desired mode is 11g, then use
                 * the 11b channel list but upgrade the mode.
                 */
                if (vap->iv_des_mode != IEEE80211_MODE_11G ||
                    mode != IEEE80211_MODE_11B)
                    continue;
This would skip all the channels.

Later it calls sweepchannels(). In this function, we have these channels in ieee80211com.ic_channels:
freq / flags / ieee number / state / ht ext channel
chan: 2412 a0 1 0 0
chan: 2412 480 1 0 0
chan: 2412 10480 1 0 0
chan: 2412 20480 1 0 5
chan: 2417 a0 2 0 0
chan: 2417 480 2 0 0
chan: 2417 10480 2 0 0
chan: 2417 20480 2 0 6
....

so for each freq, we have
CCK | 2G = a0
DYN | 2G = 480
HT20 | DYN | 2G = 10480
HT40 | DYN | 2G = 20480

In sweepchannels(), it says
    for (i = 0; i < ic->ic_nchans; i++) {
        if (ss->ss_last >= IEEE80211_SCAN_MAX)
            break;

        c = &ic->ic_channels[i];
        /*
         * Ignore dynamic turbo channels; we scan them
         * in normal mode (i.e. not boosted).  Likewise
         * for HT channels, they get scanned using
         * legacy rates.
         */
        if (IEEE80211_IS_CHAN_DTURBO(c) || IEEE80211_IS_CHAN_HT(c))
            continue;
// here, HT20 and HT40 channels are filtered out
        /*
         * If a desired mode was specified, scan only
         * channels that satisfy that constraint.
         */
        if (vap->iv_des_mode != IEEE80211_MODE_AUTO &&
            vap->iv_des_mode != ieee80211_chan2mode(c))
            continue;
// iv_des_mode = 11NG, chan2mode(DYN | 2G) = 11G, chan2mode(CCK | 2G) = 11B, so other channels are filtered out

as a result, no channels are prepared for scan.
Comment 1 Henry Hu 2014-12-21 21:04:13 UTC
I just discovered that when wlan0 is connected and working normally, the empty scan is also going on:

Dec 21 15:59:54 pepsi kernel: wlan0: ieee80211_scanreq: flags 0x20052 duration 0x7fffffff mindwell 0 maxdwell 0 nssid 1
Dec 21 15:59:54 pepsi kernel: wlan0: ieee80211_check_scan: active scan, append, nojoin, once
Dec 21 15:59:54 pepsi kernel: wlan0: start_scan_locked: active scan, duration 2147483647 mindwell 0 maxdwell 0, desired mode 11ng, append, nojoin, once
Dec 21 15:59:54 pepsi kernel: wlan0: scan set  dwell min 20ms max 200ms
Dec 21 15:59:54 pepsi kernel: wlan0: scan_task: no channels to scan
Dec 21 15:59:54 pepsi kernel: wlan0: notify scan done

Even if I disabled bgscan, it's still running.

wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether c4:85:08:82:da:5c
        inet 192.168.1.110 netmask 0xffffff00 broadcast 192.168.1.255 
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
        media: IEEE 802.11 Wireless Ethernet MCS mode 11ng
        status: associated
        ssid henryhu channel 11 (2462 MHz 11g ht/20) bssid 10:fe:ed:50:0b:b8
        country US authmode WPA1+WPA2/802.11i privacy ON deftxkey UNDEF
        TKIP 2:128-bit TKIP 3:128-bit powersavemode CAM powersavesleep 100
        txpower 11 bmiss 10 scanvalid 60 protmode CTS ht20 ampdulimit 64k
        ampdudensity 8 -amsdutx amsdurx shortgi wme roaming MANUAL
        groups: wlan 

uname -a:
FreeBSD pepsi 11.0-CURRENT FreeBSD 11.0-CURRENT #1 r275568M: Sat Dec  6 15:54:52 EST 2014     root@pepsi:/usr/obj/usr/src/sys/MYKERNEL  amd64
Comment 2 Adrian Chadd freebsd_committer 2014-12-21 22:58:31 UTC
Hi!

I just fixed it in -HEAD. Please update and give it a whirl!

Thanks!



-adrian
Comment 3 Henry Hu 2014-12-23 00:53:37 UTC
(In reply to Adrian Chadd from comment #2)
> Hi!
> 
> I just fixed it in -HEAD. Please update and give it a whirl!
> 
> Thanks!
> 
> 
> 
> -adrian

I updated iwn and net80211 directory, and rebuilt the kernel. I keep wlandebug scan on.

After one day, when I came back, the system is disconnected.
ifconfig says

wlan0: flags=8c43<UP,BROADCAST,RUNNING,OACTIVE,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether c4:85:08:82:da:5c
        inet 192.168.1.110 netmask 0xffffff00 broadcast 192.168.1.255 
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
        media: IEEE 802.11 Wireless Ethernet MCS mode 11ng (autoselect)
        status: no carrier
        ssid "" channel 60 (5300 MHz 11a)
        country US authmode WPA1+WPA2/802.11i privacy ON deftxkey UNDEF
        powersavemode CAM powersavesleep 100 txpower 14 bmiss 10 mcastrate 6
        mgmtrate 6 scanvalid 60 bgscan bgscanintvl 300 bgscanidle 250
        roam:rssi 7 roam:rate 12 wme roaming MANUAL
        groups: wlan 

and in messages, I see

Dec 22 19:28:40 pepsi kernel: [88:1f:a1:3e:9f:a9] new beacon on chan 60 (bss chan 60) "Overbreaker5G" rssi 9
Dec 22 19:28:40 pepsi kernel: [88:1f:a1:3e:9f:a9] caps 0x1511 bintval 100 erp 0x0 country [US  36-43,30 100-104,30 132-134,30 149-153,30]

repeating over and over.

> wpa_cli status
Selected interface 'wlan0'
wpa_state=SCANNING
ip_address=192.168.1.110
address=c4:85:08:82:da:5c

I tried the old workaround: ifconfig wlan0 mode auto

wlan0: flags=8c43<UP,BROADCAST,RUNNING,OACTIVE,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether c4:85:08:82:da:5c
        inet 192.168.1.110 netmask 0xffffff00 broadcast 192.168.1.255 
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
        media: IEEE 802.11 Wireless Ethernet MCS (autoselect)
        status: no carrier
        ssid "" channel 60 (5300 MHz 11a)
        country US authmode WPA1+WPA2/802.11i privacy ON deftxkey UNDEF
        powersavemode CAM powersavesleep 100 txpower 14 bmiss 10 mcastrate 6
        mgmtrate 6 scanvalid 60 bgscan bgscanintvl 300 bgscanidle 250
        roam:rssi 7 roam:rate 12 wme roaming MANUAL
        groups: wlan 

But nothing changed.

Then I tried "ifconfig wlan0 scan". I see this:

Dec 22 19:30:27 pepsi kernel: wlan0: ieee80211_scanreq: flags 0x1b duration 0x7fffffff mindwell 0 maxdwell 0 nssid 0
Dec 22 19:30:27 pepsi kernel: wlan0: start_scan_locked: active scan already in progress

Finally, I tried ifconfig wlan0 down; ifconfig wlan0 up, and it returns to normal:

Dec 22 19:32:43 pepsi kernel: wlan0: ieee80211_cancel_scan: cancel active scan
Dec 22 19:32:43 pepsi kernel: wlan0: scan_task: loop start; scandone=1
Dec 22 19:32:43 pepsi kernel: wlan0: scan_task: out
Dec 22 19:32:43 pepsi kernel: wlan0: scan_task: done, [ticks 86384585, dwell min 20 scanend 2214685618]
Dec 22 19:32:43 pepsi kernel: wlan0: ieee80211_cancel_scan: called; F_SCAN=0, vap=match, CANCEL=0
Dec 22 19:32:43 pepsi kernel: wlan0: ieee80211_scan_flush
Dec 22 19:32:43 pepsi wpa_supplicant[412]: ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Operation not supported
Dec 22 19:32:43 pepsi wpa_supplicant[412]: ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Operation not supported
Dec 22 19:32:43 pepsi wpa_supplicant[412]: wlan0: CTRL-EVENT-TERMINATING 
Dec 22 19:32:43 pepsi dhclient[628]: connection closed
Dec 22 19:32:43 pepsi dhclient[628]: exiting.
.....

So it seems to stuck in the scan.

I checked the older logs, and found that there was a firmware error. You can find the relevant log at:

http://pastebin.com/c1TA26sh
Comment 4 Adrian Chadd freebsd_committer 2014-12-23 01:23:57 UTC
ok, this is a different bug. It seems like you hit an interesting corner case:

* the vap was scanning;
* you hit a firmware crash;
* the min dwell time was met - so the interface should've moved onto the next scan;
* .. but since the firmware crashed, ieee80211_scan_next() would never be called as it didn't know it was supposed to be scanning.

So you would've just kept receiving that beacon over and over again; but if_iwn would've never called ieee80211_scan_next().

It's odd that the net80211 stack with all of the work I did over the weekend still got stuck without finishing a scan. It should've moved onto the next channel. Odd.

So, there's two issues:

* iee80211_scan_next() shouldn't be a requirement to move to the next channel - the whole scan framework should just sleep for a while, fire off a timer and then move channels;
* then the iwn driver restarted OK but it didn't restart the firmware scan or tell net80211 that it was over so it could move to the next channel.