On Tue, 2 Aug 2022, Bakul Shah wrote:
Ok, I narrowed it down to a specific case. If I use
ifconfig_wlan0="WPA DHCP"
everything works. If I replace DHCP with a fixed address it panics as before.
That is interesting. I'll try to repro that next week.
Apparently this happens as soon as the device associates with an AP.
According to the log it didn't associate yet when the firmware crashed.
Given this is a 9260 this looks like a bug we fixed about 6-ish weeks ago.
Is this a 14-CURRENT or an up-to-date stable/13?
What's the branch and git hash? (possible uname -v)
The stuff you asked for is below.
Thanks.
On Aug 2, 2022, at 1:00 PM, Bjoern A. Zeeb <b...@freebsd.org> wrote:
On Sun, 31 Jul 2022, Bakul Shah wrote:
On Jul 30, 2022, at 5:51 PM, Bjoern A. Zeeb <b...@freebsd.org> wrote:
Hi,
I've updated the firmware for iwlwifi in main (HEAD/CURRENT) with
https://cgit.FreeBSD.org/src/commit/?id=13a7663c521ac3541756aa1157dcfce9f0ce78e8
It has a ~3 week MFC timer so it can be tested.
If you are running main with an AX2xx or 9xxx card please give it a
try. In case they don't work for you please let me know and (as
always) please have a way to revert in case WiFi is the only
connectivity on your device.
I still get the same panic I was getting a few months back,
when I run -current in a bhyve VM. Not a priority so this
can wait. To see if this a bhyve problem I should try using
wifi from a linux guest and see if it works....
What's the leadup to this? What's the wpa_supplicant log saying?
The below is wlandebug but that's fine too.
Clearing /tmp (X related).
Autoloading module: if_iwlwifi
Intel(R) Wireless WiFi based driver for FreeBSD
iwlwifi0: <iwlwifi> mem 0xc1034000-0xc1037fff irq 20 at device 7.0 on pci0
iwlwifi0: successfully loaded firmware image 'iwlwifi-9260-th-b0-jf-b0-46.ucode'
iwlwifi0: WRT: Overriding region id 0
iwlwifi0: WRT: Overriding region id 1
iwlwifi0: WRT: Overriding region id 2
iwlwifi0: WRT: Overriding region id 3
iwlwifi0: WRT: Overriding region id 4
iwlwifi0: WRT: Overriding region id 6
iwlwifi0: WRT: Overriding region id 8
iwlwifi0: WRT: Overriding region id 9
iwlwifi0: WRT: Overriding region id 10
iwlwifi0: WRT: Overriding region id 11
iwlwifi0: WRT: Overriding region id 15
iwlwifi0: WRT: Overriding region id 16
iwlwifi0: WRT: Overriding region id 18
iwlwifi0: WRT: Overriding region id 19
iwlwifi0: WRT: Overriding region id 20
iwlwifi0: WRT: Overriding region id 21
iwlwifi0: WRT: Overriding region id 28
iwlwifi0: loaded firmware version 46.9d0122c0.0 9260-th-b0-jf-b0-46.ucode
op_mode iwlmvm
iwlwifi0: Detected Intel(R) Wireless-AC 9260 160MHz, REV=0x321
Starting sendmail_outbound.
Performing sanity check on sshd configuration.
iwlwifi0: base HW address: 8c:a9:82:fc:e8:9c, OTP minor version: 0x4
Starting sshd.
Setting hostname: xxxxxxxxxxx
Setting up harvesting:
PURE_RDRAND,[CALLOUT],[UMA],[FS_ATIME],SWI,INTERRUPT,NET_NG,[NET_ETHER],NET_TUN,MOUSE,KEYBOARD,ATTACH,CACHED
Feeding entropy: .
Creating and/or trimming log files.
ELF ldconfig path: /lib /usr/lib /usr/lib/compat /usr/local/lib
/usr/local/lib/compat/pkg /usr/local/lib/compat/pkg
/usr/local/lib/perl5/5.32/mach/CORE /usr/local/llvm12/lib /usr/local/llvm13/lib
32-bit compatibility ldconfig path: /usr/lib32
Updating /var/run/os-release done.
Recovering vi editor sessions:.
wlan0: Ethernet address: 8c:a9:82:fc:e8:9c
net.wlan.0.debug: 0x0 => 0x11c91000<crypto,node,assoc,auth,state,dot1xsm,wpa>
Created wlan(4) interfaces: wlan0.
lo0: link state changed to UP
uhub0: 8 ports with 8 removable, self powered
ugen0.2: <BHYVE HID Tablet> at usbus0
wlan0: ieee80211_init
wlan0: start running, 0 vaps running
wlan0: ieee80211_start_locked: up parent iwlwifi0
Starting wpa_supplicant.
wlan0: _ieee80211_crypto_delkey: NONE keyix 65535 flags 0x3 rsc 0 tsc 0 len 0
wlan0: _ieee80211_crypto_delkey: NONE keyix 65535 flags 0x3 rsc 0 tsc 0 len 0
wlan0: _ieee80211_crypto_delkey: NONE keyix 65535 flags 0x3 rsc 0 tsc 0 len 0
wlan0: _ieee80211_crypto_delkey: NONE keyix 65535 flags 0x3 rsc 0 tsc 0 len 0
wlan0: stop running, 1 vaps running
wlan0: ieee80211_new_state_locked: INIT -> INIT (arg -1) (nrunning 0 nscanning
0)
wlan0: down parent iwlwifi0
wlan0: ieee80211_newstate_cb: INIT -> INIT arg -1
wlan0: sta_newstate: INIT -> INIT (-1)
wlan0: start running, 0 vaps running
wlan0: ieee80211_start_locked: up parent iwlwifi0
wlan0: ieee80211_new_state_locked: INIT -> SCAN (arg 0) (nrunning 0 nscanning 0)
wlan0: start running, 1 vaps running
wlan0: ieee80211_newstate_cb: INIT -> SCAN arg 0
wlan0: sta_newstate: INIT -> SCAN (0)
wlan0: [ac:22:0b:d4:8c:30] station assoc via MLME
wlan0: ieee80211_alloc_node 0xfffffe009ebcc000<ac:22:0b:d4:8c:30> in station
table
wlan0: node_reclaim: remove 0xfffffe009eba2000<8c:a9:82:fc:e8:9c> from station
table, refcnt 1
wlan0: ieee80211_sta_join1 0xfffffe009ebcc000<ac:22:0b:d4:8c:30> SCAN -> AUTH,
FC0_SUBTYPE_DEAUTH
wlan0: ieee80211_new_state_locked: SCAN -> AUTH (arg 192) (nrunning 0 nscanning
0)
wlan0: ieee80211_newstate_cb: SCAN -> AUTH arg 192
This is followed by the line with "Microcode SW error"
Console output with yesterday's -current:
iwlwifi0: Microcode SW error detected. Restarting 0x0.
iwlwifi0: Start IWL Error Log Dump:
iwlwifi0: Transport status: 0x0000004B, valid: 6
iwlwifi0: Loaded firmware version: 46.9d0122c0.0 9260-th-b0-jf-b0-46.ucode
iwlwifi0: 0x0000340A | ADVANCED_SYSASSERT
iwlwifi0: 0x000022F0 | trm_hw_status0
iwlwifi0: 0x00000000 | trm_hw_status1
iwlwifi0: 0x00481CEE | branchlink2
iwlwifi0: 0x0047161E | interruptlink1
iwlwifi0: 0x00000000 | interruptlink2
iwlwifi0: 0x00000000 | data1
iwlwifi0: 0xDEADBEEF | data2
iwlwifi0: 0xDEADBEEF | data3
iwlwifi0: 0x00000000 | beacon time
iwlwifi0: 0x0017BB87 | tsf low
iwlwifi0: 0x00000000 | tsf hi
iwlwifi0: 0x00000000 | time gp1
iwlwifi0: 0x0017BB87 | time gp2
iwlwifi0: 0x00000001 | uCode revision type
iwlwifi0: 0x0000002E | uCode version major
iwlwifi0: 0x9D0122C0 | uCode version minor
iwlwifi0: 0x00000321 | hw version
iwlwifi0: 0x00C89001 | board version
iwlwifi0: 0x801CF402 | hcmd
iwlwifi0: 0x00022000 | isr0
iwlwifi0: 0x00000000 | isr1
iwlwifi0: 0x08201802 | isr2
iwlwifi0: 0x00417CC0 | isr3
iwlwifi0: 0x00000000 | isr4
iwlwifi0: 0x8019FB03 | last cmd Id
iwlwifi0: 0x0001B726 | wait_event
iwlwifi0: 0x00009809 | l2p_control
iwlwifi0: 0x00000020 | l2p_duration
iwlwifi0: 0x00000003 | l2p_mhvalid
iwlwifi0: 0x00000080 | l2p_addr_match
iwlwifi0: 0x0000000D | lmpm_pmg_sel
iwlwifi0: 0x03061219 | timestamp
iwlwifi0: 0x00001840 | flow_handler
iwlwifi0: Start IWL Error Log Dump:
iwlwifi0: Transport status: 0x0000004B, valid: 7
iwlwifi0: 0x20000070 | NMI_INTERRUPT_LMAC_FATAL
iwlwifi0: 0x00000000 | umac branchlink1
iwlwifi0: 0xC0088A4A | umac branchlink2
iwlwifi0: 0xC0084484 | umac interruptlink1
iwlwifi0: 0xC0084484 | umac interruptlink2
iwlwifi0: 0x00000800 | umac data1
iwlwifi0: 0xC0084484 | umac data2
iwlwifi0: 0xDEADBEEF | umac data3
iwlwifi0: 0x0000002E | umac major
iwlwifi0: 0x9D0122C0 | umac minor
iwlwifi0: 0x0017BB9E | frame pointer
iwlwifi0: 0xC088627C | stack pointer
iwlwifi0: 0x001E012B | last host cmd
iwlwifi0: 0x00000000 | isr status reg
iwlwifi0: IML/ROM dump:
iwlwifi0: 0x00000000 | IML/ROM error/state
iwlwifi0: 0x00000003 | IML/ROM data1
iwlwifi0: Fseq Registers:
iwlwifi0: 0xE767707A | FSEQ_ERROR_CODE
iwlwifi0: 0x00000000 | FSEQ_TOP_INIT_VERSION
iwlwifi0: 0xDC9858EE | FSEQ_CNVIO_INIT_VERSION
iwlwifi0: 0x0000A371 | FSEQ_OTP_VERSION
iwlwifi0: 0x39D43B3D | FSEQ_TOP_CONTENT_VERSION
iwlwifi0: 0xF6D44C76 | FSEQ_ALIVE_TOKEN
iwlwifi0: 0xAD4B6D4F | FSEQ_CNVI_ID
iwlwifi0: 0x71DAB327 | FSEQ_CNVR_ID
iwlwifi0: 0x01000200 | CNVI_AUX_MISC_CHIP
iwlwifi0: 0x01300202 | CNVR_AUX_MISC_CHIP
iwlwifi0: 0x0000485B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
iwlwifi0: 0x0BADCAFE | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
iwlwifi0: WRT: Collecting data: ini trigger 4 fired (delay=0ms).
iwlwifi0: FW error in SYNC CMD BINDING_CONTEXT_CMD
#0 0xffffffff80e5b45b at linux_dump_stack+0x1b
#1 0xffffffff82a7b024 at iwl_trans_txq_send_hcmd+0x414
#2 0xffffffff82a2317e at iwl_trans_send_cmd+0xce
#3 0xffffffff82a62b43 at iwl_mvm_send_cmd_status+0x53
#4 0xffffffff82a62c4f at iwl_mvm_send_cmd_pdu_status+0x4f
#5 0xffffffff82a2bcf6 at iwl_mvm_binding_update+0x216
#6 0xffffffff82a3d5be at __iwl_mvm_assign_vif_chanctx+0x9e
#7 0xffffffff82a39ea8 at iwl_mvm_assign_vif_chanctx+0x68
#8 0xffffffff80e55cf2 at lkpi_80211_mo_assign_vif_chanctx+0x22
#9 0xffffffff80e50814 at lkpi_sta_scan_to_auth+0x4b4
#10 0xffffffff80e55683 at lkpi_iv_newstate+0x1b3
#11 0xffffffff80d90b75 at ieee80211_newstate_cb+0x1f5
#12 0xffffffff80c4d87a at taskqueue_run_locked+0xaa
#13 0xffffffff80c4e922 at taskqueue_thread_loop+0xc2
#14 0xffffffff80ba0b30 at fork_exit+0x80
#15 0xffffffff8109910e at fork_trampoline+0xe
iwlwifi0: Failed to send binding (action:1): -5
iwlwifi0: PHY ctxt cmd error. ret=-5
iwlwifi0: lkpi_iv_newstate: error -5 during state transition 1 (SCAN) -> 2
(AUTH)
iwlwifi0: No queue was found. Dropping TX
iwlwifi0: iwl_trans_wait_tx_queues_empty bad state = 0
iwlwifi0: Failed to trigger RX queues sync (-5)
panic: lkpi_sta_auth_to_scan: lsta 0xfffff80005d44800 state not NONE: 0, nstate
1 arg 1
cpuid = 1
time = 1659327285
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe009e760c60
vpanic() at vpanic+0x151/frame 0xfffffe009e760cb0
panic() at panic+0x43/frame 0xfffffe009e760d10
lkpi_sta_auth_to_scan() at lkpi_sta_auth_to_scan+0x253/frame 0xfffffe009e760d80
lkpi_iv_newstate() at lkpi_iv_newstate+0x1b3/frame 0xfffffe009e760df0
ieee80211_newstate_cb() at ieee80211_newstate_cb+0x1f5/frame 0xfffffe009e760e40
taskqueue_run_locked() at taskqueue_run_locked+0xaa/frame 0xfffffe009e760ec0
taskqueue_thread_loop() at taskqueue_thread_loop+0xc2/frame 0xfffffe009e760ef0
fork_exit() at fork_exit+0x80/frame 0xfffffe009e760f30
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe009e760f30
--- trap 0x6b616873, rip = 0x645f336c73730065, rsp = 0x6f745f68645f6c73, rbp =
0x5f7874635f336c73 ---
KDB: enter: panic
[ thread pid 0 tid 100108 ]
Stopped at kdb_enter+0x32: movq $0,0x12a3293(%rip)
db> bt
Tracing pid 0 tid 100108 td 0xfffffe006b59d3a0
kdb_enter() at kdb_enter+0x32/frame 0xfffffe009e760c60
vpanic() at vpanic+0x182/frame 0xfffffe009e760cb0
panic() at panic+0x43/frame 0xfffffe009e760d10
lkpi_sta_auth_to_scan() at lkpi_sta_auth_to_scan+0x253/frame 0xfffffe009e760d80
lkpi_iv_newstate() at lkpi_iv_newstate+0x1b3/frame 0xfffffe009e760df0
ieee80211_newstate_cb() at ieee80211_newstate_cb+0x1f5/frame 0xfffffe009e760e40
taskqueue_run_locked() at taskqueue_run_locked+0xaa/frame 0xfffffe009e760ec0
taskqueue_thread_loop() at taskqueue_thread_loop+0xc2/frame 0xfffffe009e760ef0
fork_exit() at fork_exit+0x80/frame 0xfffffe009e760f30
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe009e760f30
--- trap 0x6b616873, rip = 0x645f336c73730065, rsp = 0x6f745f68645f6c73, rbp =
0x5f7874635f336c73 ---
db>
--
Bjoern A. Zeeb r15:7
--
Bjoern A. Zeeb r15:7
