From owner-freebsd-wireless@freebsd.org Sat Mar 5 01:44:05 2016 Return-Path: Delivered-To: freebsd-wireless@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 519AFA09AC7; Sat, 5 Mar 2016 01:44:05 +0000 (UTC) (envelope-from ler@lerctr.org) Received: from thebighonker.lerctr.org (thebighonker.lerctr.org [IPv6:2001:470:1f0f:3ad:223:7dff:fe9e:6e8a]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "thebighonker.lerctr.org", Issuer "COMODO RSA Domain Validation Secure Server CA" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 2CAC7FDC; Sat, 5 Mar 2016 01:44:05 +0000 (UTC) (envelope-from ler@lerctr.org) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=lerctr.org; s=lerami; h=In-Reply-To:Content-Type:MIME-Version:References:Message-ID: Subject:Cc:To:From:Date; bh=h0ohvCFrHhjKzoNbOwzPkJnntZ7DPuCCG+eQir4IL+Q=; b=l La04RFK7+qzwcIMqauWi3/RG8+Ld0d6SCYs8PAKE7tiiXMV+3fB893BcG1jlcgw7W6Mt6q1CpO2SR jB+N9TyvdHurdFMZadY89wjCc3kxy7OtdZn9Rxi7p3DzaGF60qW3tOWpAPYyuSrSWVikp6SrLshHO 70KorlIL8ikgAGc4=; Received: from [2605:6000:ec17:203:5a91:cfff:fe1a:4569] (port=33492 helo=lrosenman-dell.lerctr.org) by thebighonker.lerctr.org with esmtpsa (TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256) (Exim 4.86_2 (FreeBSD)) (envelope-from ) id 1ac1GG-00026Y-2Y; Fri, 04 Mar 2016 19:44:04 -0600 Date: Fri, 4 Mar 2016 19:44:02 -0600 From: Larry Rosenman To: Andriy Voskoboinyk Cc: owner-freebsd-wireless@freebsd.org, freebsd-wireless@freebsd.org, Adrian Chadd Subject: Re: iwm7265fw: fatal firmware error Message-ID: <20160305014401.GA1780@lrosenman-dell.lerctr.org> Mail-Followup-To: Andriy Voskoboinyk , owner-freebsd-wireless@freebsd.org, freebsd-wireless@freebsd.org, Adrian Chadd References: <6E0E9EC8-3035-4443-A495-5981E8C9D4FA@FreeBSD.org> <9d04d7dcee3d3f12583a7c54d56c847c@thebighonker.lerctr.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.5.24 (2015-08-30) X-Spam-Score: -1.0 (-) X-LERCTR-Spam-Score: -1.0 (-) X-Spam-Report: SpamScore (-1.0/5.0) ALL_TRUSTED=-1,SHORTCIRCUIT=-0.0001 X-LERCTR-Spam-Report: SpamScore (-1.0/5.0) ALL_TRUSTED=-1, SHORTCIRCUIT=-0.0001 X-BeenThere: freebsd-wireless@freebsd.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: "Discussions of 802.11 stack, tools device driver development." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 05 Mar 2016 01:44:05 -0000 On Fri, Mar 04, 2016 at 06:50:10PM -0600, Larry Rosenman wrote: > On 2016-03-04 18:21, Larry Rosenman wrote: > > On 2016-03-04 14:46, Larry Rosenman wrote: > >> On 2016-03-04 14:24, Andriy Voskoboinyk wrote: > >>> Fri, 04 Mar 2016 18:18:22 +0200 ???????? ???????????????? Jonathan Anderson > >>> : > >>> > >>>> On 4 Mar 2016, at 0:47, Adrian Chadd wrote: > >>>> > >>>>> It's a known problem. Someone has to fix the firmware api use. It's > >>>>> just > >>>>> wrong. > >>>> > >>>> Ok, thanks. > >>>> > >>> > >>> May be workaroundable with https://reviews.freebsd.org/D4236 > >>> (restarts > >>> the device > >>> automatically after each failure; but the problem is still here) > >>> > >>>> > >> Any chance of that being committed as a workaround while y'all look > >> for the real problem? > >> > >> (I'll apply it to my 7260 tonight :) ) > > doesn't seem to help. > > > > I'm seeing the following in the log, and it NEVER associates now. > I uploaded a messages file with IWM_DEBUG, and sysctl > dev.iwm.0.debug=255 to: > > http://www.lerctr.org/~ler/FreeBSD/messages-iwm.debug > > After making sure the antenna's were really connected, it seems(!) to be working now, but we still get the fatal's. What debugging do we need here? I'm typing this from that box. re0: flags=8802 metric 0 mtu 1500 options=8209b ether 20:47:47:73:07:5f nd6 options=29 media: Ethernet autoselect (none) status: no carrier lo0: flags=8049 metric 0 mtu 16384 options=600003 inet6 ::1 prefixlen 128 inet6 fe80::1%lo0 prefixlen 64 scopeid 0x2 inet 127.0.0.1 netmask 0xff000000 nd6 options=21 groups: lo wlan0: flags=8843 metric 0 mtu 1500 ether 58:91:cf:1a:45:69 inet6 fe80::5a91:cfff:fe1a:4569%wlan0 prefixlen 64 scopeid 0x3 inet6 2605:6000:ec17:203:5a91:cfff:fe1a:4569 prefixlen 64 autoconf inet 192.168.203.228 netmask 0xffffff00 broadcast 192.168.203.255 nd6 options=23 media: IEEE 802.11 Wireless Ethernet OFDM/18Mbps mode 11g status: associated ssid "LERCTR NETWORK 2.5" channel 6 (2437 MHz 11g) bssid bc:ee:7b:6f:41:b8 country US authmode WPA2/802.11i privacy ON deftxkey UNDEF AES-CCM 2:128-bit txpower 0 bmiss 10 scanvalid 60 protmode CTS wme roaming MANUAL groups: wlan Mar 4 19:37:18 lrosenman-dell kernel: iwm0: fatal firmware error Mar 4 19:37:18 lrosenman-dell kernel: wlan0: ieee80211_new_state_locked: pending SCAN -> AUTH transition lost Mar 4 19:37:18 lrosenman-dell kernel: iwm0: iwm_auth: binding cmd Mar 4 19:37:18 lrosenman-dell kernel: iwm0: iwm_newstate: could not move to auth state: 35 Mar 4 19:37:18 lrosenman-dell kernel: ubt0: ubt_ctrl_write_callback:780: control transfer failed: USB_ERR_TIMEOUT Mar 4 19:37:18 lrosenman-dell kernel: ng_hci_process_command_timeout: ubt0hci - unable to complete HCI command OGF=0x3, OCF=0x3. Timeout Mar 4 19:37:18 lrosenman-dell ntpd[897]: ntpd 4.2.8p6-a (1): Starting Mar 4 19:37:18 lrosenman-dell ntpd[898]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): good hash signature Mar 4 19:37:18 lrosenman-dell ntpd[898]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): loaded, expire=2016-06-01T00:00:00Z last=2015-07-01T00:00:00Z ofs=36 Mar 4 19:37:19 lrosenman-dell wpa_supplicant[327]: wlan0: Authentication with bc:ee:7b:6f:41:b8 timed out. Mar 4 19:37:19 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-DISCONNECTED bssid=bc:ee:7b:6f:41:b8 reason=3 locally_generated=1 Mar 4 19:37:19 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=1 ssid="LERCTR NETWORK 2.5" auth_failures=2 duration=23 reason=CONN_FAILED Mar 4 19:37:19 lrosenman-dell root: /etc/rc: WARNING: $hald_enable is not set properly - see rc.conf(5). Mar 4 19:37:20 lrosenman-dell kernel: info: [drm] Initialized drm 1.1.0 20060810 Mar 4 19:37:23 lrosenman-dell wpa_supplicant[327]: wlan0: Trying to associate with bc:ee:7b:6f:41:bc (SSID='LERCTR NETWORK 5' freq=5745 MHz) Mar 4 19:37:23 lrosenman-dell kernel: iwm0: iwm_update_edca: called Mar 4 19:37:27 lrosenman-dell dbus[863]: [system] Activating service name='org.freedesktop.ConsoleKit' (using servicehelper) Mar 4 19:37:27 lrosenman-dell dbus[863]: [system] Activating service name='org.freedesktop.PolicyKit1' (using servicehelper) Mar 4 19:37:27 lrosenman-dell dbus[863]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Mar 4 19:37:27 lrosenman-dell dbus[863]: [system] Successfully activated service 'org.freedesktop.ConsoleKit' Mar 4 19:37:33 lrosenman-dell wpa_supplicant[327]: wlan0: Authentication with bc:ee:7b:6f:41:bc timed out. Mar 4 19:37:33 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-DISCONNECTED bssid=bc:ee:7b:6f:41:bc reason=3 locally_generated=1 Mar 4 19:37:33 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="LERCTR NETWORK 5" auth_failures=1 duration=10 reason=CONN_FAILED Mar 4 19:37:40 lrosenman-dell dbus[863]: [system] Activating service name='org.freedesktop.UPower' (using servicehelper) Mar 4 19:37:40 lrosenman-dell dbus[863]: [system] Successfully activated service 'org.freedesktop.UPower' Mar 4 19:37:42 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-SSID-REENABLED id=1 ssid="LERCTR NETWORK 2.5" Mar 4 19:37:42 lrosenman-dell wpa_supplicant[327]: wlan0: Trying to associate with bc:ee:7b:6f:41:b8 (SSID='LERCTR NETWORK 2.5' freq=2437 MHz) Mar 4 19:37:42 lrosenman-dell kernel: iwm0: iwm_update_edca: called Mar 4 19:37:42 lrosenman-dell kernel: iwm0: dumping device error log Mar 4 19:37:42 lrosenman-dell kernel: iwm0: Start IWL Error Log Dump: Mar 4 19:37:42 lrosenman-dell kernel: iwm0: Status: 0x3, count: 6 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 0x00003001 | ADVANCED_SYSASSERT Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 002002B0 | uPc Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | branchlink1 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000BA4 | branchlink2 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 0001626C | interruptlink1 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 006C6A4F | interruptlink2 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000001 | data1 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | data2 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: DEADBEEF | data3 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | beacon time Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 01E96D7C | tsf low Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | tsf hi Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | time gp1 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 01E96D7C | time gp2 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | time gp3 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 000419E4 | uCode version Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000144 | hw version Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00009004 | board version Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 0923002B | hcmd Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00022080 | isr0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | isr1 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000002 | isr2 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 0041C0C0 | isr3 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000001 | isr4 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 01000112 | isr_pref Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | wait_event Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 000000C4 | l2p_control Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00010000 | l2p_duration Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000007 | l2p_mhvalid Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000000 | l2p_addr_match Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 00000005 | lmpm_pmg_sel Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 20111734 | timestamp Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 0000C8D0 | flow_handler Mar 4 19:37:42 lrosenman-dell kernel: iwm0: driver status: Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 0: qid=0 cur=1 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 1: qid=1 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 2: qid=2 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 3: qid=3 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 4: qid=4 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 5: qid=5 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 6: qid=6 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 7: qid=7 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 8: qid=8 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 9: qid=9 cur=36 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 10: qid=10 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 11: qid=11 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 12: qid=12 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 13: qid=13 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 14: qid=14 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 15: qid=15 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 16: qid=16 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 17: qid=17 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 18: qid=18 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: tx ring 19: qid=19 cur=0 queued=0 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: rx ring: cur=203 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: 802.11 state 1 Mar 4 19:37:42 lrosenman-dell kernel: iwm0: fatal firmware error Mar 4 19:37:42 lrosenman-dell kernel: wlan0: ieee80211_new_state_locked: pending SCAN -> AUTH transition lost Mar 4 19:37:43 lrosenman-dell kernel: iwm0: iwm_auth: binding cmd Mar 4 19:37:43 lrosenman-dell kernel: iwm0: iwm_newstate: could not move to auth state: 35 Mar 4 19:37:52 lrosenman-dell kernel: ifa_maintain_loopback_route: deletion failed for interface lo0: 48 Mar 4 19:37:52 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-DISCONNECTED bssid=bc:ee:7b:6f:41:b8 reason=3 locally_generated=1 Mar 4 19:37:52 lrosenman-dell wpa_supplicant[327]: wlan0: CTRL-EVENT-TERMINATING Mar 4 19:37:52 lrosenman-dell kernel: wlan0: Ethernet address: 58:91:cf:1a:45:69 Mar 4 19:37:52 lrosenman-dell wpa_supplicant[1469]: Successfully initialized wpa_supplicant Mar 4 19:37:52 lrosenman-dell kernel: wlan0: ieee80211_new_state_locked: pending INIT -> SCAN transition lost Mar 4 19:37:57 lrosenman-dell wpa_supplicant[1504]: wlan0: Trying to associate with bc:ee:7b:6f:41:b8 (SSID='LERCTR NETWORK 2.5' freq=2437 MHz) Mar 4 19:37:57 lrosenman-dell kernel: iwm0: iwm_update_edca: called Mar 4 19:37:57 lrosenman-dell kernel: iwm0: iwm_update_edca: called Mar 4 19:37:57 lrosenman-dell kernel: wlan0: link state changed to UP Mar 4 19:37:57 lrosenman-dell wpa_supplicant[1504]: wlan0: Associated with bc:ee:7b:6f:41:b8 Mar 4 19:37:57 lrosenman-dell wpa_supplicant[1504]: wlan0: WPA: Key negotiation completed with bc:ee:7b:6f:41:b8 [PTK=CCMP GTK=CCMP] Mar 4 19:37:57 lrosenman-dell wpa_supplicant[1504]: wlan0: CTRL-EVENT-CONNECTED - Connection to bc:ee:7b:6f:41:b8 completed [id=1 id_str=] Mar 4 19:37:57 lrosenman-dell dbus[863]: [system] Failed to activate service 'org.freedesktop.Avahi': timed out Mar 4 19:38:09 lrosenman-dell dhclient: New IP Address (wlan0): 192.168.203.228 Mar 4 19:38:09 lrosenman-dell dhclient: New Subnet Mask (wlan0): 255.255.255.0 Mar 4 19:38:09 lrosenman-dell dhclient: New Broadcast Address (wlan0): 192.168.203.255 Mar 4 19:38:09 lrosenman-dell dhclient: New Routers (wlan0): 192.168.203.1 -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 214-642-9640 E-Mail: ler@lerctr.org US Mail: 7011 W Parmer Ln, Apt 1115, Austin, TX 78729-6961