Bug 204959 - iwlwifi: AX200: TOF_RANGE_REQ command is called, crash on firmware.
Summary: iwlwifi: AX200: TOF_RANGE_REQ command is called, crash on firmware.
Status: ASSIGNED
Alias: None
Product: Drivers
Classification: Unclassified
Component: network-wireless (show other bugs)
Hardware: Intel Linux
: P1 high
Assignee: Intel Linux Wireless
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-09-23 02:07 UTC by chany kim
Modified: 2019-12-20 12:54 UTC (History)
3 users (show)

See Also:
Kernel Version: 5.1.0-050100-generic
Tree: Mainline
Regression: No


Attachments

Description chany kim 2019-09-23 02:07:25 UTC
I tried to measurement ftm_request through iw 5.3 version.
ex) iw wlan0 measurement ftm_request config_file which include <mac address> bw=80 cf=5240 cf1=5210 asap.

At that time, iwlwifi always go to crash status.
- iwlwifi : backport-iwlwifi 4.3
- firmware : iwlwifi-cc-a0-48.ucode (firmware-version: 48.4fa0041f.0)
- kernel: 5.1.0-050100-generic

I think that there is a problem
 -> iwlwifi 0000:01:00.0: FW error in SYNC CMD TOF_RANGE_REQ_CMD
I attached dmesg, syslog, iwl.dump files.

There is a dmesg:

[72796.188587] iwlwifi 0000:01:00.0: HCMD_ACTIVE already clear for command TOF_RANGE_REQ_CMD
[72796.188621] iwlwifi 0000:01:00.0: FW error in SYNC CMD TOF_RANGE_REQ_CMD
[72796.188640] CPU: 3 PID: 25443 Comm: iw Tainted: G        W  OE     5.1.0-050100-generic #201905052130
[72796.188644] Hardware name: GIGABYTE GB-BSi5-6200/MKLP5AP-00, BIOS F6 05/16/2016
[72796.188646] Call Trace:
[72796.188666]  dump_stack+0x63/0x8a
[72796.188715]  iwl_trans_pcie_gen2_send_hcmd+0x43a/0x4f0 [iwlwifi]
[72796.188724]  ? wait_woken+0x80/0x80
[72796.188754]  iwl_trans_send_cmd+0x5c/0xd0 [iwlwifi]
[72796.188794]  iwl_mvm_send_cmd_status+0x38/0xc0 [iwlmvm]
[72796.188834]  iwl_mvm_ftm_start+0x3aa/0x5d0 [iwlmvm]
[72796.188852]  ? nla_validate.part.7+0x50/0x90
[72796.188862]  ? validate_nla+0xda/0x580
[72796.188872]  ? nla_validate.part.7+0x50/0x90
[72796.188881]  ? __nla_parse+0x38/0x120
[72796.188907]  iwl_mvm_start_pmsr+0x38/0x50 [iwlmvm]
[72796.188931]  ? iwl_mvm_start_pmsr+0x38/0x50 [iwlmvm]
[72796.189007]  ieee80211_start_pmsr+0x75/0x170 [mac80211]
[72796.189086]  nl80211_pmsr_start+0x49e/0x6d0 [cfg80211]
[72796.189113]  genl_family_rcv_msg+0x1d8/0x410
[72796.189123]  ? __wake_up_common_lock+0x8e/0xc0
[72796.189136]  genl_rcv_msg+0x4c/0x93
[72796.189147]  ? _cond_resched+0x19/0x30
[72796.189155]  ? genl_family_rcv_msg+0x410/0x410
[72796.189164]  netlink_rcv_skb+0x4f/0x120
[72796.189175]  genl_rcv+0x28/0x40
[72796.189184]  netlink_unicast+0x19f/0x260
[72796.189194]  netlink_sendmsg+0x20d/0x3c0
[72796.189207]  sock_sendmsg+0x3e/0x50
[72796.189216]  ___sys_sendmsg+0x295/0x2f0
[72796.189229]  ? generic_file_read_iter+0xdf/0x150
[72796.189239]  ? mem_cgroup_throttle_swaprate+0x1b/0x118
[72796.189261]  ? ext4_file_read_iter+0x54/0xf0
[72796.189278]  ? new_sync_read+0x111/0x170
[72796.189308]  __sys_sendmsg+0x5c/0xa0
[72796.189328]  __x64_sys_sendmsg+0x1f/0x30
[72796.189348]  do_syscall_64+0x5a/0x110
[72796.189367]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[72796.189385] RIP: 0033:0x7f8f11f3a490
[72796.189399] Code: 8b 15 0c ba 2b 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb cd 66 0f 1f 44 00 00 83 3d b9 12 2c 00 00 75 10 b8 2e 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 2e cc 00 00 48 89 04 24
[72796.189411] RSP: 002b:00007ffebdfdec28 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
[72796.189429] RAX: ffffffffffffffda RBX: 0000000000d55320 RCX: 00007f8f11f3a490
[72796.189443] RDX: 0000000000000000 RSI: 00007ffebdfdecb0 RDI: 0000000000000003
[72796.189456] RBP: 0000000000d54100 R08: 0000000000000001 R09: 0000000000000001
[72796.189470] R10: 00000000000000eb R11: 0000000000000246 R12: 0000000000d541d0
[72796.189482] R13: 00007ffebdfdecb0 R14: 0000000000d55230 R15: 0000000000d55320
[72796.836373] iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM
[72796.985918] iwlwifi 0000:01:00.0: FW already configured (0) - re-configuring
[73001.079029] iwlwifi 0000:01:00.0: Microcode SW error detected. Restarting 0x0.
[73001.079120] iwlwifi 0000:01:00.0: Start IWL Error Log Dump:
[73001.079124] iwlwifi 0000:01:00.0: Status: 0x00000080, count: 6
[73001.079126] iwlwifi 0000:01:00.0: Loaded firmware version: 48.4fa0041f.0
[73001.079129] iwlwifi 0000:01:00.0: 0x00000071 | NMI_INTERRUPT_UMAC_FATAL    
[73001.079131] iwlwifi 0000:01:00.0: 0x000022F0 | trm_hw_status0
[73001.079133] iwlwifi 0000:01:00.0: 0x00000000 | trm_hw_status1
[73001.079136] iwlwifi 0000:01:00.0: 0x004F8E3C | branchlink2
[73001.079138] iwlwifi 0000:01:00.0: 0x004E4FF4 | interruptlink1
[73001.079140] iwlwifi 0000:01:00.0: 0x004E4FF4 | interruptlink2
[73001.079142] iwlwifi 0000:01:00.0: 0x004F4AD2 | data1
[73001.079144] iwlwifi 0000:01:00.0: 0x00001000 | data2
[73001.079146] iwlwifi 0000:01:00.0: 0xF0000008 | data3
[73001.079148] iwlwifi 0000:01:00.0: 0x003E07A3 | beacon time
[73001.079150] iwlwifi 0000:01:00.0: 0x0C2C1461 | tsf low
[73001.079152] iwlwifi 0000:01:00.0: 0x00000000 | tsf hi
[73001.079153] iwlwifi 0000:01:00.0: 0x00000000 | time gp1
[73001.079156] iwlwifi 0000:01:00.0: 0x0C2C7576 | time gp2
[73001.079157] iwlwifi 0000:01:00.0: 0x00000001 | uCode revision type
[73001.079160] iwlwifi 0000:01:00.0: 0x00000030 | uCode version major
[73001.079162] iwlwifi 0000:01:00.0: 0x4FA0041F | uCode version minor
[73001.079164] iwlwifi 0000:01:00.0: 0x00000340 | hw version
[73001.079166] iwlwifi 0000:01:00.0: 0x18C89000 | board version
[73001.079168] iwlwifi 0000:01:00.0: 0x802FFF02 | hcmd
[73001.079170] iwlwifi 0000:01:00.0: 0x00020000 | isr0
[73001.079172] iwlwifi 0000:01:00.0: 0x00000000 | isr1
[73001.079174] iwlwifi 0000:01:00.0: 0x18F84802 | isr2
[73001.079176] iwlwifi 0000:01:00.0: 0x04C1FFCC | isr3
[73001.079178] iwlwifi 0000:01:00.0: 0x00000000 | isr4
[73001.079179] iwlwifi 0000:01:00.0: 0x001D01D2 | last cmd Id
[73001.079181] iwlwifi 0000:01:00.0: 0x004F4AD2 | wait_event
[73001.079183] iwlwifi 0000:01:00.0: 0x00000000 | l2p_control
[73001.079185] iwlwifi 0000:01:00.0: 0x00000000 | l2p_duration
[73001.079187] iwlwifi 0000:01:00.0: 0x00000000 | l2p_mhvalid
[73001.079189] iwlwifi 0000:01:00.0: 0x00000000 | l2p_addr_match
[73001.079191] iwlwifi 0000:01:00.0: 0x00000008 | lmpm_pmg_sel
[73001.079193] iwlwifi 0000:01:00.0: 0x00000000 | timestamp
[73001.079195] iwlwifi 0000:01:00.0: 0x00001868 | flow_handler
[73001.079230] iwlwifi 0000:01:00.0: Start IWL Error Log Dump:
[73001.079232] iwlwifi 0000:01:00.0: Status: 0x00000080, count: 7
[73001.079233] iwlwifi 0000:01:00.0: 0x2010104C | ADVANCED_SYSASSERT
[73001.079235] iwlwifi 0000:01:00.0: 0x00000000 | umac branchlink1
[73001.079236] iwlwifi 0000:01:00.0: 0xC008CC3C | umac branchlink2
[73001.079237] iwlwifi 0000:01:00.0: 0xC0087698 | umac interruptlink1
[73001.079238] iwlwifi 0000:01:00.0: 0x00000000 | umac interruptlink2
[73001.079239] iwlwifi 0000:01:00.0: 0xFFFF0106 | umac data1
[73001.079241] iwlwifi 0000:01:00.0: 0x00100080 | umac data2
[73001.079242] iwlwifi 0000:01:00.0: 0xDEADBEEF | umac data3
[73001.079243] iwlwifi 0000:01:00.0: 0x00000030 | umac major
[73001.079244] iwlwifi 0000:01:00.0: 0x4FA0041F | umac minor
[73001.079245] iwlwifi 0000:01:00.0: 0x0C2C756A | frame pointer
[73001.079247] iwlwifi 0000:01:00.0: 0xC0887F3C | stack pointer
[73001.079248] iwlwifi 0000:01:00.0: 0xFFFF0106 | last host cmd
[73001.079249] iwlwifi 0000:01:00.0: 0x00020040 | isr status reg
[73001.079256] iwlwifi 0000:01:00.0: Fseq Registers:
[73001.079260] iwlwifi 0000:01:00.0: 0xE0000000 | FSEQ_ERROR_CODE
[73001.079263] iwlwifi 0000:01:00.0: 0x80290001 | FSEQ_TOP_INIT_VERSION
[73001.079267] iwlwifi 0000:01:00.0: 0x80050008 | FSEQ_CNVIO_INIT_VERSION
[73001.079271] iwlwifi 0000:01:00.0: 0x0000A503 | FSEQ_OTP_VERSION
[73001.079274] iwlwifi 0000:01:00.0: 0x80000003 | FSEQ_TOP_CONTENT_VERSION
[73001.079278] iwlwifi 0000:01:00.0: 0x4552414E | FSEQ_ALIVE_TOKEN
[73001.079282] iwlwifi 0000:01:00.0: 0x00100530 | FSEQ_CNVI_ID
[73001.079285] iwlwifi 0000:01:00.0: 0x00000532 | FSEQ_CNVR_ID
[73001.079289] iwlwifi 0000:01:00.0: 0x00100530 | CNVI_AUX_MISC_CHIP
[73001.079295] iwlwifi 0000:01:00.0: 0x00000532 | CNVR_AUX_MISC_CHIP
[73001.079301] iwlwifi 0000:01:00.0: 0x05B0905B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
[73001.079306] iwlwifi 0000:01:00.0: 0x0000025B | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
[73001.079441] iwlwifi 0000:01:00.0: Collecting data: trigger 2 fired.
[73001.079446] ieee80211 phy0: Hardware restart was requested
[73001.717676] iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM
[73001.867195] iwlwifi 0000:01:00.0: FW already configured (0) - re-configuring

Could you check this issue.
Comment 1 Luca Coelho 2019-09-24 05:44:13 UTC
This doesn't seem to be a backports bug per se.  Can you try it with a mainline kernel without backports?

In any case, reassigning.
Comment 2 chany kim 2019-10-07 03:19:30 UTC
Yes, This issue doesn't seem to be a backports bug.
I confirmed same issue on kernel 5.3.4
I think that it is a problem on iwlwifi firmware.

Could yo check whether ToF support on ax200 or not?

There is a log file on kernel 5.3.4
------------------------------------
[    5.152126] iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM
[    5.301110] iwlwifi 0000:01:00.0: FW already configured (0) - re-configuring
[   13.561197] e1000e: enp0s31f6 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[   13.561244] IPv6: ADDRCONF(NETDEV_CHANGE): enp0s31f6: link becomes ready
[   14.646537] logitech-hidpp-device 0003:046D:406B.0005: HID++ 4.5 device connected.
[  146.895750] iwlwifi 0000:01:00.0: Microcode SW error detected. Restarting 0x0.
[  146.895768] iwlwifi 0000:01:00.0: FW error in SYNC CMD TOF_RANGE_REQ_CMD
[  146.895773] CPU: 1 PID: 2160 Comm: iw Not tainted 5.3.4-050304-generic #201910051526
[  146.895774] Hardware name: GIGABYTE GB-BSi5-6200/MKLP5AP-00, BIOS F6 05/16/2016
[  146.895774] Call Trace:
[  146.895780]  dump_stack+0x63/0x8a
[  146.895791]  iwl_pcie_gen2_send_hcmd_sync+0x435/0x450 [iwlwifi]
[  146.895794]  ? wait_woken+0x80/0x80
[  146.895801]  iwl_trans_pcie_gen2_send_hcmd+0x5c/0xd0 [iwlwifi]
[  146.895807]  iwl_trans_send_cmd+0x5d/0xc0 [iwlwifi]
[  146.895815]  iwl_mvm_send_cmd_status+0x3c/0xc0 [iwlmvm]
[  146.895822]  iwl_mvm_ftm_start+0x3d5/0x4a0 [iwlmvm]
[  146.895825]  ? __nla_validate+0xb/0x10
[  146.895827]  ? validate_nla+0x366/0x640
[  146.895829]  ? __nla_validate_parse+0x116/0x140
[  146.895831]  ? __nla_validate_parse+0x42/0x140
[  146.895837]  iwl_mvm_start_pmsr+0x3a/0x60 [iwlmvm]
[  146.895837] iwlwifi 0000:01:00.0: Start IWL Error Log Dump:
[  146.895839] iwlwifi 0000:01:00.0: Status: 0x00000080, count: 6
[  146.895840] iwlwifi 0000:01:00.0: Loaded firmware version: 48.4fa0041f.0
[  146.895842] iwlwifi 0000:01:00.0: 0x00000071 | NMI_INTERRUPT_UMAC_FATAL    
[  146.895861]  ieee80211_start_pmsr+0x74/0x150 [mac80211]
[  146.895881]  nl80211_pmsr_start+0x23b/0x710 [cfg80211]
[  146.895881] iwlwifi 0000:01:00.0: 0x000022F0 | trm_hw_status0
[  146.895882] iwlwifi 0000:01:00.0: 0x00000000 | trm_hw_status1
[  146.895883] iwlwifi 0000:01:00.0: 0x004F8E3C | branchlink2
[  146.895884] iwlwifi 0000:01:00.0: 0x004E4FF4 | interruptlink1
[  146.895885] iwlwifi 0000:01:00.0: 0x004E4FF4 | interruptlink2
[  146.895886] iwlwifi 0000:01:00.0: 0x000067F4 | data1
[  146.895887] iwlwifi 0000:01:00.0: 0x00001000 | data2
[  146.895888] iwlwifi 0000:01:00.0: 0xF0000008 | data3
[  146.895889] iwlwifi 0000:01:00.0: 0x00000000 | beacon time
[  146.895891] iwlwifi 0000:01:00.0: 0x08727281 | tsf low
[  146.895893]  genl_family_rcv_msg+0x1b9/0x470
[  146.895895] iwlwifi 0000:01:00.0: 0x00000000 | tsf hi
[  146.895896]  genl_rcv_msg+0x4c/0xa0
[  146.895898]  ? _cond_resched+0x19/0x30
[  146.895900]  ? genl_family_rcv_msg+0x470/0x470
[  146.895901] iwlwifi 0000:01:00.0: 0x00000000 | time gp1
[  146.895902]  netlink_rcv_skb+0x50/0x120
[  146.895904]  genl_rcv+0x29/0x40
[  146.895905] iwlwifi 0000:01:00.0: 0x0872D3D2 | time gp2
[  146.895906]  netlink_unicast+0x187/0x220
[  146.895908]  netlink_sendmsg+0x20a/0x3c0
[  146.895909] iwlwifi 0000:01:00.0: 0x00000001 | uCode revision type
[  146.895911]  sock_sendmsg+0x65/0x70
[  146.895913]  ___sys_sendmsg+0x2ae/0x330
[  146.895914] iwlwifi 0000:01:00.0: 0x00000030 | uCode version major
[  146.895917]  ? generic_file_read_iter+0xdc/0x140
[  146.895919]  ? ext4_file_read_iter+0x4f/0x100
[  146.895920] iwlwifi 0000:01:00.0: 0x4FA0041F | uCode version minor
[  146.895922]  ? new_sync_read+0x122/0x1b0
[  146.895924]  __sys_sendmsg+0x5c/0xa0
[  146.895925] iwlwifi 0000:01:00.0: 0x00000340 | hw version
[  146.895926] iwlwifi 0000:01:00.0: 0x18C89000 | board version
[  146.895927] iwlwifi 0000:01:00.0: 0x805EFC04 | hcmd
[  146.895928] iwlwifi 0000:01:00.0: 0x00020000 | isr0
[  146.895929] iwlwifi 0000:01:00.0: 0x00000000 | isr1
[  146.895930] iwlwifi 0000:01:00.0: 0x18F00002 | isr2
[  146.895931] iwlwifi 0000:01:00.0: 0x00C1FFCC | isr3
[  146.895932] iwlwifi 0000:01:00.0: 0x00000000 | isr4
[  146.895933] iwlwifi 0000:01:00.0: 0x0040019C | last cmd Id
[  146.895934] iwlwifi 0000:01:00.0: 0x000067F4 | wait_event
[  146.895935] iwlwifi 0000:01:00.0: 0x00000094 | l2p_control
[  146.895936] iwlwifi 0000:01:00.0: 0x00000020 | l2p_duration
[  146.895937] iwlwifi 0000:01:00.0: 0x0000000F | l2p_mhvalid
[  146.895938] iwlwifi 0000:01:00.0: 0x00000000 | l2p_addr_match
[  146.895939] iwlwifi 0000:01:00.0: 0x00000009 | lmpm_pmg_sel
[  146.895940] iwlwifi 0000:01:00.0: 0x00000000 | timestamp
[  146.895941] iwlwifi 0000:01:00.0: 0x0000A8F4 | flow_handler
[  146.895947]  __x64_sys_sendmsg+0x1f/0x30
[  146.895959]  do_syscall_64+0x5a/0x130
[  146.895962]  entry_SYSCALL_64_after_hwframe+0x44/0xa9

Note You need to log in before you can comment on or make changes to this bug.