iwn0: iwn_panicked: controller panicked, iv_state = 5; resetting...

From: David Wolfskill <david_at_catwhisker.org>
Date: Tue, 6 Jan 2015 06:50:35 -0800
One of the things I've noticed for a bit (but failed ot mention, as it's
been something I find difficult to describe adequately) is that when I
run head on my laptop -- generally, just to perform a source-based
upgrade-in-place (so it tends to be rather busy), the machine acts as if
it's failing to pay attention to some of the interrupts sometimes.

E.g., moving the mouse is extremely laggy & jerky (with a fair amount of
overshooting once the position settles).  And the wireless NIC (iwn)
will often lose ... well, everything it can.  And I'm seeing messages
such as this in /var/log/messages:

...
Jan  6 06:24:12 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=0x08530501
Jan  6 06:24:14 g1-253 kernel: iwn0: iwn_tx_data: m=0xd2a33c00: seqno (25151) (63) != ring index (0) !
Jan  6 06:24:14 g1-253 kernel: iwn0: iwn_intr: fatal firmware error
Jan  6 06:24:14 g1-253 kernel: firmware error log:
Jan  6 06:24:14 g1-253 kernel: error type      = "SYSASSERT" (0x00000005)
Jan  6 06:24:14 g1-253 kernel: program counter = 0x0000C210
Jan  6 06:24:14 g1-253 kernel: source line     = 0x00000E4E
Jan  6 06:24:14 g1-253 kernel: error data      = 0x0000000000000E4E
Jan  6 06:24:14 g1-253 kernel: branch link     = 0x0000C1280000C128
Jan  6 06:24:14 g1-253 kernel: interrupt link  = 0x0000091600000000
Jan  6 06:24:14 g1-253 kernel: time            = 1199025467
Jan  6 06:24:14 g1-253 kernel: driver status:
Jan  6 06:24:14 g1-253 kernel: tx ring  0: qid=0  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  1: qid=1  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  2: qid=2  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  3: qid=3  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  4: qid=4  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  5: qid=5  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  6: qid=6  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  7: qid=7  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  8: qid=8  cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring  9: qid=9  cur=28  queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 10: qid=10 cur=1   queued=1  
Jan  6 06:24:14 g1-253 kernel: tx ring 11: qid=11 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 12: qid=12 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 13: qid=13 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 14: qid=14 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 15: qid=15 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 16: qid=16 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 17: qid=17 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 18: qid=18 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: tx ring 19: qid=19 cur=0   queued=0  
Jan  6 06:24:14 g1-253 kernel: rx ring: cur=32
Jan  6 06:24:14 g1-253 kernel: iwn0: iwn_panicked: controller panicked, iv_state = 5; resetting...
Jan  6 06:24:14 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=0x08530501
Jan  6 06:24:16 g1-253 kernel: iwn0: iwn_tx_data: m=0xd2a41500: seqno (25152) (64) != ring index (0) !
Jan  6 06:24:16 g1-253 kernel: iwn0: iwn_intr: fatal firmware error
Jan  6 06:24:16 g1-253 kernel: firmware error log:
Jan  6 06:24:16 g1-253 kernel: error type      = "SYSASSERT" (0x00000005)
Jan  6 06:24:16 g1-253 kernel: program counter = 0x0000C210
Jan  6 06:24:16 g1-253 kernel: source line     = 0x00000E4E
Jan  6 06:24:16 g1-253 kernel: error data      = 0x0000000000000E4E
Jan  6 06:24:16 g1-253 kernel: branch link     = 0x0000C1280000C128
Jan  6 06:24:16 g1-253 kernel: interrupt link  = 0x0000091600000000
Jan  6 06:24:16 g1-253 kernel: time            = 1201317618
Jan  6 06:24:16 g1-253 kernel: driver status:
Jan  6 06:24:16 g1-253 kernel: tx ring  0: qid=0  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  1: qid=1  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  2: qid=2  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  3: qid=3  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  4: qid=4  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  5: qid=5  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  6: qid=6  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  7: qid=7  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  8: qid=8  cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring  9: qid=9  cur=27  queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 10: qid=10 cur=1   queued=1  
Jan  6 06:24:16 g1-253 kernel: tx ring 11: qid=11 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 12: qid=12 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 13: qid=13 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 14: qid=14 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 15: qid=15 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 16: qid=16 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 17: qid=17 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 18: qid=18 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: tx ring 19: qid=19 cur=0   queued=0  
Jan  6 06:24:16 g1-253 kernel: rx ring: cur=30
Jan  6 06:24:16 g1-253 kernel: iwn0: iwn_panicked: controller panicked, iv_state = 5; resetting...
Jan  6 06:24:16 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=0x08530501
Jan  6 06:24:17 g1-253 kernel: iwn0: iwn_tx_data: m=0xd2a36900: seqno (25153) (65) != ring index (0) !
Jan  6 06:24:17 g1-253 kernel: iwn0: iwn_intr: fatal firmware error
Jan  6 06:24:17 g1-253 kernel: firmware error log:
Jan  6 06:24:17 g1-253 kernel: error type      = "SYSASSERT" (0x00000005)
Jan  6 06:24:17 g1-253 kernel: program counter = 0x0000C210
Jan  6 06:24:17 g1-253 kernel: source line     = 0x00000E4E
Jan  6 06:24:17 g1-253 kernel: error data      = 0x0000000000000E4E
Jan  6 06:24:17 g1-253 kernel: branch link     = 0x0000C1280000C128
Jan  6 06:24:17 g1-253 kernel: interrupt link  = 0x0000091600000000
Jan  6 06:24:17 g1-253 kernel: time            = 1202473968
Jan  6 06:24:17 g1-253 kernel: driver status:
Jan  6 06:24:17 g1-253 kernel: tx ring  0: qid=0  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  1: qid=1  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  2: qid=2  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  3: qid=3  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  4: qid=4  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  5: qid=5  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  6: qid=6  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  7: qid=7  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  8: qid=8  cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring  9: qid=9  cur=26  queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 10: qid=10 cur=1   queued=1  
Jan  6 06:24:17 g1-253 kernel: tx ring 11: qid=11 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 12: qid=12 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 13: qid=13 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 14: qid=14 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 15: qid=15 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 16: qid=16 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 17: qid=17 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 18: qid=18 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: tx ring 19: qid=19 cur=0   queued=0  
Jan  6 06:24:17 g1-253 kernel: rx ring: cur=59
Jan  6 06:24:17 g1-253 kernel: iwn0: iwn_panicked: controller panicked, iv_state = 5; resetting...
Jan  6 06:24:17 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=0x08530501
.....

For the above, this is while running:

FreeBSD g1-253.catwhisker.org 11.0-CURRENT FreeBSD 11.0-CURRENT #1475  r276694M/276694:1100052: Mon Jan  5 20:04:17 PST 2015     root_at_g1-253.catwhisker.org:/common/S4/obj/usr/src/sys/CANARY  i386

while building the kernel as part of an update to head _at_r276749.


Stable/10:

FreeBSD g1-253.catwhisker.org 10.1-STABLE FreeBSD 10.1-STABLE #1434  r276744M/276749:1001505: Tue Jan  6 04:52:54 PST 2015     root_at_g1-253.catwhisker.org:/common/S1/obj/usr/src/sys/CANARY  i386

has few (if any) problems of that nature in this environment
(presently at home).

The iwn(4) device shows up as:

iwn0_at_pci0:12:0:0:       class=0x028000 card=0x11218086 chip=0x42358086 rev=0x00 hdr=0x00
    vendor     = 'Intel Corporation'
    device     = 'Ultimate N WiFi Link 5300'
    class      = network

and in dmesg.boot, I see:
...
iwn0: <Intel Ultimate N WiFi Link 5300> mem 0xf1ffe000-0xf1ffffff irq 17 at device 0.0 on pci12
...
wlan0: Ethernet address: 00:21:6a:26:34:c0
iwn0: iwn_read_firmware: ucode rev=0x08530501

ifconfig says:
iwn0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 2290
        ether 00:21:6a:26:34:c0
        nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
        media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng
        status: associated

and:

g1-253(11.0-C)[5] ifconfig -v wlan0






wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        ether 00:21:6a:26:34:c0
        inet 172.17.1.253 netmask 0xffff0000 broadcast 172.17.255.255 
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
        media: IEEE 802.11 Wireless Ethernet MCS mode 11ng
        status: associated
        ssid lmdhw-net channel 11 (2462 MHz 11g ht/20) bssid 04:18:d6:22:22:1f
        regdomain 0 country US anywhere -ecm authmode WPA2/802.11i -wps -tsn
        privacy ON deftxkey UNDEF
        AES-CCM 2:128-bit powersavemode OFF powersavesleep 100 txpower 15
        txpowmax 50.0 -dotd rtsthreshold 2346 fragthreshold 2346 bmiss 10
        11a     ucast NONE    mgmt  6 Mb/s mcast  6 Mb/s maxretry 6
        11b     ucast NONE    mgmt  1 Mb/s mcast  1 Mb/s maxretry 6
        11g     ucast NONE    mgmt  1 Mb/s mcast  1 Mb/s maxretry 6
        turboA  ucast NONE    mgmt  6 Mb/s mcast  6 Mb/s maxretry 6
        turboG  ucast NONE    mgmt  1 Mb/s mcast  1 Mb/s maxretry 6
        sturbo  ucast NONE    mgmt  6 Mb/s mcast  6 Mb/s maxretry 6
        11na    ucast NONE    mgmt 12 MCS  mcast 12 MCS  maxretry 6
        11ng    ucast NONE    mgmt  2 MCS  mcast  2 MCS  maxretry 6
        half    ucast NONE    mgmt  3 Mb/s mcast  3 Mb/s maxretry 6
        quarter ucast NONE    mgmt  1 Mb/s mcast  1 Mb/s maxretry 6
        scanvalid 60 bgscan bgscanintvl 300 bgscanidle 250
        roam:11a     rssi    7dBm rate 12 Mb/s
        roam:11b     rssi    7dBm rate  1 Mb/s
        roam:11g     rssi    7dBm rate  5 Mb/s
        roam:turboA  rssi    7dBm rate 12 Mb/s
        roam:turboG  rssi    7dBm rate 12 Mb/s
        roam:sturbo  rssi    7dBm rate 12 Mb/s
        roam:11na    rssi    7dBm  MCS  1    
        roam:11ng    rssi    7dBm  MCS  1    
        roam:half    rssi    7dBm rate  6 Mb/s
        roam:quarter rssi    7dBm rate  3 Mb/s
        -pureg protmode CTS ht htcompat ampdu ampdulimit 64k ampdudensity 8
        -amsdutx amsdurx shortgi htprotmode RTSCTS -puren -smps -rifs wme
        -burst -dwds roaming MANUAL bintval 100
        AC_BE cwmin  4 cwmax 10 aifs  3 txopLimit   0 -acm ack
              cwmin  4 cwmax 10 aifs  3 txopLimit   0 -acm
        AC_BK cwmin  4 cwmax 10 aifs  7 txopLimit   0 -acm ack
              cwmin  4 cwmax 10 aifs  7 txopLimit   0 -acm
        AC_VI cwmin  3 cwmax  4 aifs  2 txopLimit  94 -acm ack
              cwmin  3 cwmax  4 aifs  2 txopLimit  94 -acm
        AC_VO cwmin  2 cwmax  3 aifs  2 txopLimit  47 -acm ack
              cwmin  2 cwmax  3 aifs  2 txopLimit  47 -acm
        groups: wlan 
g1-253(11.0-C)[6] 
g1-253(11.0-C)[6] 
g1-253(11.0-C)[6] 
g1-253(11.0-C)[6] 
g1-253(11.0-C)[6] 
g1-253(11.0-C)[6] 

g1-253(11.0-C)[6] 
g1-253(11.0-C)[6] 

[Remember that I mentioned something about "interrupts" up there?
The above silliness with the extraneous linefeeds is another symptom
of that, I think: I had only hit "Enter" the minimum number of times..]

So: what can be done about this?  I'm happy to test....

Peace,
david
-- 
David H. Wolfskill				david_at_catwhisker.org
Actions have consequences ... as do inactions.

See http://www.catwhisker.org/~david/publickey.gpg for my public key.

Received on Tue Jan 06 2015 - 13:50:37 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:54 UTC