iwn(4) association issues in 11-Stable (and maybe RC)

Sun Aug 21 02:02:28 UTC 2016

On Aug 20, 2016 6:29 PM, "Adrian Chadd" <adrian.chadd at gmail.com> wrote:
>
> Hi,
>
> There have been some changes to the scan code and iwn scan timeout code.
Andriy may have some ideas.
>
> Thanks!
>
> A

One more note. There are multiple "link up" messages in the log. The LED
never stopped the flashing which indicates that it is not associated. If I
did "ifconfig wlan0 list aps", my hot spot was listed, but a simple
"ifconfig wlan0" never showed an association. Usually a few "netif
restart"s will get it to work, but sometimes it seems hopeless. It seems
worse when my phone is the hot spot than with my home router.
>
>
> On Aug 19, 2016 3:48 PM, "Kevin Oberman" <rkoberman at gmail.com> wrote:
>>
>> Lately I have had serious issues with my system successfully associating.
>> These were not present with 10.3.
>>
>> > uname -a
>> FreeBSD rogue 11.0-BETA4 FreeBSD 11.0-BETA4 #1 r303806: Sat Aug  6
18:50:50
>> PDT 2016     root at rogue:/usr/obj/usr/src/sys/GENERIC.4BSD  amd64
>>
>> iwn0 at pci0:3:0:0:    class=0x028000 card=0x13118086 chip=0x00858086
rev=0x34
>> hdr=0x00
>>     cap 01[c8] = powerspec 3  supports D0 D3  current D0
>>     cap 05[d0] = MSI supports 1 message, 64 bit enabled with 1 message
>>     cap 10[e0] = PCI-Express 1 endpoint max data 128(128) FLR RO NS
>>                  link x1(x1) speed 2.5(2.5) ASPM L1(L0s/L1)
>>     ecap 0001[100] = AER 1 0 fatal 0 non-fatal 0 corrected
>>     ecap 0003[140] = Serial 1 a088b4ffffc6ad28
>>
>> Once associated, it works fine, but a dropped association is often not
>> re-established and the network fails to come up at boot time. Kernel is
>> GENERIC except the 4BSD scheduler.
>>
>> I've been using a mobile hotspot this week during travels and it has
become
>> a real pain. With  lot of patience and many "netif restart wlan0"
>> operations, it will come up, but it can be painful. Here is what I see in
>> messages:
>> Aug 19 00:13:52 rogue kernel: wlan0: Ethernet address: a0:88:b4:c6:ad:28
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to UP
>> Aug 19 00:13:52 rogue kernel: ipfw2 (+ipv6) initialized, divert loadable,
>> nat loadable, default to deny, logging disabled
>> Aug 19 00:13:52 rogue kernel: wlan0: link state changed to DOWN
>> Aug 19 00:13:52 rogue kernel: iwn0: scan timeout
>> Aug 19 00:13:52 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:14:17 rogue dhclient[362]: send_packet: Network is down
>> Aug 19 00:14:37 rogue dhclient[362]: send_packet: Network is down
>> Aug 19 00:14:39 rogue wpa_supplicant[350]: wlan0: CTRL-EVENT-TERMINATING
>> Aug 19 00:14:39 rogue dhclient[362]: connection closed
>> Aug 19 00:14:39 rogue dhclient[362]: exiting.
>> Aug 19 00:14:39 rogue rtsold[873]: <rtsock_input_ifannounce> interface
>> wlan0 removed
>> Aug 19 00:14:39 rogue kernel: wlan0: Ethernet address: a0:88:b4:c6:ad:28
>> Aug 19 00:14:39 rogue wpa_supplicant[1621]: Successfully initialized
>> wpa_supplicant
>> Aug 19 00:14:39 rogue wpa_supplicant[1633]: Successfully initialized
>> wpa_supplicant
>> Aug 19 00:14:39 rogue root: /etc/rc.d/wpa_supplicant: WARNING: failed to
>> start wpa_supplicant
>> Aug 19 00:14:39 rogue kernel: iwn0: iwn_read_firmware: ucode
rev=0x12a80601
>> Aug 19 00:14:39 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:39 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:40 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:40 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:41 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:41 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:42 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:42 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:43 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:43 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:44 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:44 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:45 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:45 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:46 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:46 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:47 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:47 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:48 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:48 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:49 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:49 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:50 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:50 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:50 rogue root: /etc/rc.d/dhclient: WARNING: failed to start
>> dhclient
>> Aug 19 00:14:51 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:51 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:52 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:52 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>> Aug 19 00:14:53 rogue wpa_supplicant[1634]: ioctl[SIOCS80211, op=103,
>> val=0, arg_len=128]: Operation now in progress
>> Aug 19 00:14:53 rogue wpa_supplicant[1634]: wlan0: CTRL-EVENT-SCAN-FAILED
>> ret=-1 retry=1
>>
>> Is anyone else seeing this?
>>
>> Kevin Oberman, Part time kid herder and retired Network Engineer
>> E-mail: rkoberman at gmail.com
>> PGP Fingerprint: D03FB98AFA78E3B78C1694B318AB39EF1B055683
>> _______________________________________________
>> freebsd-net at freebsd.org mailing list
>> https://lists.freebsd.org/mailman/listinfo/freebsd-net
>> To unsubscribe, send any mail to "freebsd-net-unsubscribe at freebsd.org"