From owner-freebsd-current@FreeBSD.ORG Tue Jan 6 14:50:37 2015 Return-Path: Delivered-To: current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id C67CCB65 for ; Tue, 6 Jan 2015 14:50:37 +0000 (UTC) Received: from albert.catwhisker.org (mx.catwhisker.org [198.144.209.73]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 65F3A1996 for ; Tue, 6 Jan 2015 14:50:36 +0000 (UTC) Received: from albert.catwhisker.org (localhost [127.0.0.1]) by albert.catwhisker.org (8.14.9/8.14.9) with ESMTP id t06EoZMu020355 for ; Tue, 6 Jan 2015 06:50:35 -0800 (PST) (envelope-from david@albert.catwhisker.org) Received: (from david@localhost) by albert.catwhisker.org (8.14.9/8.14.9/Submit) id t06EoZ6E020354 for current@freebsd.org; Tue, 6 Jan 2015 06:50:35 -0800 (PST) (envelope-from david) Date: Tue, 6 Jan 2015 06:50:35 -0800 From: David Wolfskill To: current@freebsd.org Subject: iwn0: iwn_panicked: controller panicked, iv_state = 5; resetting... Message-ID: <20150106145035.GY14822@albert.catwhisker.org> Reply-To: current@freebsd.org Mail-Followup-To: current@freebsd.org MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha512; protocol="application/pgp-signature"; boundary="DejVYFcqCV4p9T4J" Content-Disposition: inline User-Agent: Mutt/1.5.23 (2014-03-12) X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 06 Jan 2015 14:50:37 -0000 --DejVYFcqCV4p9T4J Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable 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: =2E.. Jan 6 06:24:12 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=3D0x08530= 501 Jan 6 06:24:14 g1-253 kernel: iwn0: iwn_tx_data: m=3D0xd2a33c00: seqno (25= 151) (63) !=3D 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 =3D "SYSASSERT" (0x00000005) Jan 6 06:24:14 g1-253 kernel: program counter =3D 0x0000C210 Jan 6 06:24:14 g1-253 kernel: source line =3D 0x00000E4E Jan 6 06:24:14 g1-253 kernel: error data =3D 0x0000000000000E4E Jan 6 06:24:14 g1-253 kernel: branch link =3D 0x0000C1280000C128 Jan 6 06:24:14 g1-253 kernel: interrupt link =3D 0x0000091600000000 Jan 6 06:24:14 g1-253 kernel: time =3D 1199025467 Jan 6 06:24:14 g1-253 kernel: driver status: Jan 6 06:24:14 g1-253 kernel: tx ring 0: qid=3D0 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 1: qid=3D1 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 2: qid=3D2 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 3: qid=3D3 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 4: qid=3D4 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 5: qid=3D5 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 6: qid=3D6 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 7: qid=3D7 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 8: qid=3D8 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 9: qid=3D9 cur=3D28 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 10: qid=3D10 cur=3D1 queued=3D1 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 11: qid=3D11 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 12: qid=3D12 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 13: qid=3D13 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 14: qid=3D14 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 15: qid=3D15 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 16: qid=3D16 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 17: qid=3D17 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 18: qid=3D18 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: tx ring 19: qid=3D19 cur=3D0 queued=3D0 = =20 Jan 6 06:24:14 g1-253 kernel: rx ring: cur=3D32 Jan 6 06:24:14 g1-253 kernel: iwn0: iwn_panicked: controller panicked, iv_= state =3D 5; resetting... Jan 6 06:24:14 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=3D0x08530= 501 Jan 6 06:24:16 g1-253 kernel: iwn0: iwn_tx_data: m=3D0xd2a41500: seqno (25= 152) (64) !=3D 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 =3D "SYSASSERT" (0x00000005) Jan 6 06:24:16 g1-253 kernel: program counter =3D 0x0000C210 Jan 6 06:24:16 g1-253 kernel: source line =3D 0x00000E4E Jan 6 06:24:16 g1-253 kernel: error data =3D 0x0000000000000E4E Jan 6 06:24:16 g1-253 kernel: branch link =3D 0x0000C1280000C128 Jan 6 06:24:16 g1-253 kernel: interrupt link =3D 0x0000091600000000 Jan 6 06:24:16 g1-253 kernel: time =3D 1201317618 Jan 6 06:24:16 g1-253 kernel: driver status: Jan 6 06:24:16 g1-253 kernel: tx ring 0: qid=3D0 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 1: qid=3D1 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 2: qid=3D2 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 3: qid=3D3 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 4: qid=3D4 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 5: qid=3D5 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 6: qid=3D6 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 7: qid=3D7 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 8: qid=3D8 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 9: qid=3D9 cur=3D27 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 10: qid=3D10 cur=3D1 queued=3D1 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 11: qid=3D11 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 12: qid=3D12 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 13: qid=3D13 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 14: qid=3D14 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 15: qid=3D15 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 16: qid=3D16 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 17: qid=3D17 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 18: qid=3D18 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: tx ring 19: qid=3D19 cur=3D0 queued=3D0 = =20 Jan 6 06:24:16 g1-253 kernel: rx ring: cur=3D30 Jan 6 06:24:16 g1-253 kernel: iwn0: iwn_panicked: controller panicked, iv_= state =3D 5; resetting... Jan 6 06:24:16 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=3D0x08530= 501 Jan 6 06:24:17 g1-253 kernel: iwn0: iwn_tx_data: m=3D0xd2a36900: seqno (25= 153) (65) !=3D 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 =3D "SYSASSERT" (0x00000005) Jan 6 06:24:17 g1-253 kernel: program counter =3D 0x0000C210 Jan 6 06:24:17 g1-253 kernel: source line =3D 0x00000E4E Jan 6 06:24:17 g1-253 kernel: error data =3D 0x0000000000000E4E Jan 6 06:24:17 g1-253 kernel: branch link =3D 0x0000C1280000C128 Jan 6 06:24:17 g1-253 kernel: interrupt link =3D 0x0000091600000000 Jan 6 06:24:17 g1-253 kernel: time =3D 1202473968 Jan 6 06:24:17 g1-253 kernel: driver status: Jan 6 06:24:17 g1-253 kernel: tx ring 0: qid=3D0 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 1: qid=3D1 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 2: qid=3D2 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 3: qid=3D3 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 4: qid=3D4 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 5: qid=3D5 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 6: qid=3D6 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 7: qid=3D7 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 8: qid=3D8 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 9: qid=3D9 cur=3D26 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 10: qid=3D10 cur=3D1 queued=3D1 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 11: qid=3D11 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 12: qid=3D12 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 13: qid=3D13 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 14: qid=3D14 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 15: qid=3D15 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 16: qid=3D16 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 17: qid=3D17 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 18: qid=3D18 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: tx ring 19: qid=3D19 cur=3D0 queued=3D0 = =20 Jan 6 06:24:17 g1-253 kernel: rx ring: cur=3D59 Jan 6 06:24:17 g1-253 kernel: iwn0: iwn_panicked: controller panicked, iv_= state =3D 5; resetting... Jan 6 06:24:17 g1-253 kernel: iwn0: iwn_read_firmware: ucode rev=3D0x08530= 501 =2E.... For the above, this is while running: FreeBSD g1-253.catwhisker.org 11.0-CURRENT FreeBSD 11.0-CURRENT #1475 r276= 694M/276694:1100052: Mon Jan 5 20:04:17 PST 2015 root@g1-253.catwhiske= r.org:/common/S4/obj/usr/src/sys/CANARY i386 while building the kernel as part of an update to head @r276749. Stable/10: FreeBSD g1-253.catwhisker.org 10.1-STABLE FreeBSD 10.1-STABLE #1434 r27674= 4M/276749:1001505: Tue Jan 6 04:52:54 PST 2015 root@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@pci0:12:0:0: class=3D0x028000 card=3D0x11218086 chip=3D0x4235808= 6 rev=3D0x00 hdr=3D0x00 vendor =3D 'Intel Corporation' device =3D 'Ultimate N WiFi Link 5300' class =3D network and in dmesg.boot, I see: =2E.. iwn0: mem 0xf1ffe000-0xf1ffffff irq 17 at= device 0.0 on pci12 =2E.. wlan0: Ethernet address: 00:21:6a:26:34:c0 iwn0: iwn_read_firmware: ucode rev=3D0x08530501 ifconfig says: iwn0: flags=3D8843 metric 0 mtu 2290 ether 00:21:6a:26:34:c0 nd6 options=3D21 media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng status: associated and: g1-253(11.0-C)[5] ifconfig -v wlan0 wlan0: flags=3D8843 metric 0 mtu 15= 00 ether 00:21:6a:26:34:c0 inet 172.17.1.253 netmask 0xffff0000 broadcast 172.17.255.255=20 nd6 options=3D29 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 =20 roam:11ng rssi 7dBm MCS 1 =20 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=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 g1-253(11.0-C)[6]=20 [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 --=20 David H. Wolfskill david@catwhisker.org Actions have consequences ... as do inactions. See http://www.catwhisker.org/~david/publickey.gpg for my public key. --DejVYFcqCV4p9T4J Content-Type: application/pgp-signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v2 iQJ8BAEBCgBmBQJUq/Y7XxSAAAAAAC4AKGlzc3Vlci1mcHJAbm90YXRpb25zLm9w ZW5wZ3AuZmlmdGhob3JzZW1hbi5uZXQ4RThEMDY4QTIxMjc1MDZFRDIzODYzRTc4 QTY3RjlDOERFRjQxOTNCAAoJEIpn+cje9Bk70eAP/2U9J9eyb0MEhIuxio1iUUVo cDB2A04QTzyshAKjMtGgdoJ+2WG3x0HafqpaFgRqCL/VSqal+z/fhlYC3LoLXeFo K5vfgIARuAzats1zwHueCOok1dFoyebZFZ7oJ1L/XxdDFEDYrvARh4hUDFkUiZle dtgCnqcfXN8p3hMhZAP62T14v/+8JTrBR07WzJg9MF2cH1QntVlb+sQY0NCY5rKT CdqiiulGuqXAJWE6tyR2XmF2lTbVBpCHGVGJHR/OofUhcJScUAKvsuWqfP5aE9PG iWLV2R72nFYDtnd9VkMVydY33wqxCAE2dF1dirwVyvVnT42U85rgm+6Nlf6j8HTl toMHUqf2Omco0/aFkEYLFgahmkjXO17bXoIEMu5VOgjIxJJYO+IKCUKt2cSQ0fQN ReM6YAd9j6Nl2JNF/CqHSrJ8MGMIX7RvZtQYtpt00M+iUGFyZppSi9IrCJZesWCK wGfBS5jS3+QAv4/1Mlwbs3FV7he8WoFf6Qs0QLCjROldhEkwDb4e/tapJb0qBzEc K4Ky63slsZaXZjUXoWeTT0FndjB95f0l+AHYAp0Y/hsXR6iQoX4sNfHkWrEhifBA aqrlO6tqm2TdGIjhmriu9zZD6noNMTHrdx0MONXE1p/HNTChadLcrgjT1eSvFGKd e8fThyxn1/FRYy9sXhFL =emIL -----END PGP SIGNATURE----- --DejVYFcqCV4p9T4J--