Bug 105912

Summary:

[IGT] gem_exec_reloc@cpu-30 iwlwifi 0000:00:14.3: Scan failed! ret -110 dmesg-warn

Product:

DRI

Reporter:

Ricardo Perez <ricardo.o.perez>

Component:

IGT

Assignee:

Default DRI bug account <dri-devel>

Status:

CLOSED NOTOURBUG

QA Contact:

Severity:

normal

Priority:

medium

Version:

DRI git

Hardware:

x86-64 (AMD64)

OS:

Linux (All)

Whiteboard:

i915 platform:

i915 features:

Attachments:

Description	Flags
dmesg and kern-logs	none

Description Ricardo Perez 2018-04-05 19:00:18 UTC

Created attachment 138637 [details]
dmesg and kern-logs

On CNL, the following tests are failing:

igt@gem_exec_reloc@cpu-30
igt@gem_exec_reloc@cpu-31

Software configuration:

IGT-Version: 1.22-g0721161 (x86_64) (Linux: 4.16.0-rc6-drm-intel-qa-ww12-commit-4db112a+ x86_64)
Subtest cpu-30: SUCCESS (2.069s)


The following dmesg-warn message is happening:

[  523.908771] Setting dangerous option reset - tainting kernel
[  526.402693] Setting dangerous option reset - tainting kernel
[  531.731647] Setting dangerous option reset - tainting kernel
[  532.541941] Setting dangerous option reset - tainting kernel
[  541.020060] iwlwifi 0000:00:14.3: Error sending SCAN_REQ_UMAC: time out after 2000ms.
[  541.020066] iwlwifi 0000:00:14.3: Current CMD queue read_ptr 117 write_ptr 118
[  541.020897] iwlwifi 0000:00:14.3: Loaded firmware version: 33.610294.0
[  541.020900] iwlwifi 0000:00:14.3: 0x00000000 | ADVANCED_SYSASSERT          
[  541.020902] iwlwifi 0000:00:14.3: 0x00000000 | trm_hw_status0
[  541.020904] iwlwifi 0000:00:14.3: 0x00000000 | trm_hw_status1
[  541.020906] iwlwifi 0000:00:14.3: 0x00000000 | branchlink2
[  541.020908] iwlwifi 0000:00:14.3: 0x00000000 | interruptlink1
[  541.020909] iwlwifi 0000:00:14.3: 0x00000000 | interruptlink2
[  541.020911] iwlwifi 0000:00:14.3: 0x00000000 | data1
[  541.020913] iwlwifi 0000:00:14.3: 0x00000000 | data2
[  541.020915] iwlwifi 0000:00:14.3: 0x00000000 | data3
[  541.020916] iwlwifi 0000:00:14.3: 0x00000000 | beacon time
[  541.020918] iwlwifi 0000:00:14.3: 0x00000000 | tsf low
[  541.020920] iwlwifi 0000:00:14.3: 0x00000000 | tsf hi
[  541.020922] iwlwifi 0000:00:14.3: 0x00000000 | time gp1
[  541.020924] iwlwifi 0000:00:14.3: 0x00000000 | time gp2
[  541.020926] iwlwifi 0000:00:14.3: 0x00000000 | uCode revision type
[  541.020927] iwlwifi 0000:00:14.3: 0x00000000 | uCode version major
[  541.020929] iwlwifi 0000:00:14.3: 0x00094FF6 | uCode version minor
[  541.020931] iwlwifi 0000:00:14.3: 0x00000312 | hw version
[  541.020933] iwlwifi 0000:00:14.3: 0x00489008 | board version
[  541.020935] iwlwifi 0000:00:14.3: 0x80F1FE01 | hcmd
[  541.020937] iwlwifi 0000:00:14.3: 0x00022000 | isr0
[  541.020938] iwlwifi 0000:00:14.3: 0x00800000 | isr1
[  541.020940] iwlwifi 0000:00:14.3: 0x08001802 | isr2
[  541.020942] iwlwifi 0000:00:14.3: 0x40400180 | isr3
[  541.020944] iwlwifi 0000:00:14.3: 0x00000000 | isr4
[  541.020946] iwlwifi 0000:00:14.3: 0x80F00051 | last cmd Id
[  541.020947] iwlwifi 0000:00:14.3: 0x00000000 | wait_event
[  541.020949] iwlwifi 0000:00:14.3: 0x00000000 | l2p_control
[  541.020951] iwlwifi 0000:00:14.3: 0x00000000 | l2p_duration
[  541.020953] iwlwifi 0000:00:14.3: 0x00000000 | l2p_mhvalid
[  541.020954] iwlwifi 0000:00:14.3: 0x00000000 | l2p_addr_match
[  541.020956] iwlwifi 0000:00:14.3: 0x0000008F | lmpm_pmg_sel
[  541.020958] iwlwifi 0000:00:14.3: 0x25101602 | timestamp
[  541.020960] iwlwifi 0000:00:14.3: 0x00348874 | flow_handler
[  541.021007] iwlwifi 0000:00:14.3: Start IWL Error Log Dump:
[  541.021009] iwlwifi 0000:00:14.3: Status: 0x00000100, count: 7
[  541.021011] iwlwifi 0000:00:14.3: 0x00000066 | NMI_INTERRUPT_HOST
[  541.021013] iwlwifi 0000:00:14.3: 0x00000000 | umac branchlink1
[  541.021014] iwlwifi 0000:00:14.3: 0xC0087BC4 | umac branchlink2
[  541.021016] iwlwifi 0000:00:14.3: 0x00000000 | umac interruptlink1
[  541.021018] iwlwifi 0000:00:14.3: 0xC008E402 | umac interruptlink2
[  541.021020] iwlwifi 0000:00:14.3: 0x01000000 | umac data1
[  541.021022] iwlwifi 0000:00:14.3: 0xC008E402 | umac data2
[  541.021024] iwlwifi 0000:00:14.3: 0xDEADBEEF | umac data3
[  541.021025] iwlwifi 0000:00:14.3: 0x00000021 | umac major
[  541.021027] iwlwifi 0000:00:14.3: 0x00094FF6 | umac minor
[  541.021029] iwlwifi 0000:00:14.3: 0xC0886280 | frame pointer
[  541.021031] iwlwifi 0000:00:14.3: 0xC0886280 | stack pointer
[  541.021033] iwlwifi 0000:00:14.3: 0x0075010D | last host cmd
[  541.021034] iwlwifi 0000:00:14.3: 0x00000000 | isr status reg
[  541.021039] ------------[ cut here ]------------
[  541.021039] UMAC scan UID 0 status was not cleaned
[  541.021061] WARNING: CPU: 0 PID: 898 at drivers/net/wireless/intel/iwlwifi/mvm/scan.c:1784 iwl_mvm_report_scan_aborted+0x200/0x210 [iwlmvm]
[  541.021061] Modules linked in: snd_hda_codec_hdmi bnep 8250_dw nls_iso8859_1 arc4 snd_soc_skl x86_pkg_temp_thermal intel_powerclamp snd_soc_skl_ipc coretemp snd_soc_sst_ipc snd_soc_sst_dsp kvm_intel snd_hda_ext_core snd_hda_codec_realtek snd_soc_acpi snd_hda_codec_generic kvm snd_soc_core snd_compress snd_pcm_dmaengine irqbypass ac97_bus crct10dif_pclmul iwlmvm crc32_pclmul ghash_clmulni_intel pcbc mac80211 aesni_intel snd_hda_intel aes_x86_64 crypto_simd glue_helper cryptd snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi serio_raw snd_seq wmi_bmof btusb btrtl snd_seq_device btbcm iwlwifi asix snd_timer btintel usbnet mii bluetooth snd input_leds soundcore ecdh_generic idma64 shpchp virt_dma mei_me intel_lpss_pci cfg80211 mei intel_pch_thermal intel_lpss acpi_pad
[  541.021091]  mac_hid parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_generic usbhid hid i915 dwc3 udc_core ulpi e1000e dwc3_pci prime_numbers wmi video
[  541.021103] CPU: 0 PID: 898 Comm: wpa_supplicant Tainted: G     U           4.16.0-rc6-drm-intel-qa-ww12-commit-4db112a+ #1
[  541.021103] Hardware name: Intel Corporation CannonLake Client Platform/CannonLake Y LPDDR4 RVP, BIOS CNLSFWR1.R00.X124.B02.1802051422 02/05/2018
[  541.021109] RIP: 0010:iwl_mvm_report_scan_aborted+0x200/0x210 [iwlmvm]
[  541.021110] RSP: 0018:ffffbba981edf618 EFLAGS: 00010286
[  541.021111] RAX: 0000000000000000 RBX: ffff9eb22faf2ea4 RCX: 0000000000000006
[  541.021112] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff9eb23f8165d0
[  541.021113] RBP: 0000000000000000 R08: 0000000000000001 R09: 000000000000cf73
[  541.021114] R10: ffffbba981edf440 R11: 000000000000cf73 R12: ffff9eb22faf1528
[  541.021114] R13: ffff9eb22c988eb0 R14: 0000000000000015 R15: 0000000000000000
[  541.021115] FS:  00007f095260bd40(0000) GS:ffff9eb23f800000(0000) knlGS:0000000000000000
[  541.021116] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  541.021117] CR2: 00007f63de081290 CR3: 00000002aedfe002 CR4: 0000000000760ef0
[  541.021118] PKRU: 55555554
[  541.021118] Call Trace:
[  541.021125]  iwl_mvm_nic_restart+0x20/0x150 [iwlmvm]
[  541.021132]  iwl_trans_pcie_send_hcmd+0x501/0x540 [iwlwifi]
[  541.021135]  ? wait_woken+0x80/0x80
[  541.021141]  iwl_trans_send_cmd+0x54/0xd0 [iwlwifi]
[  541.021146]  iwl_mvm_send_cmd+0x2c/0x90 [iwlmvm]
[  541.021151]  iwl_mvm_reg_scan_start+0x2fc/0x410 [iwlmvm]
[  541.021158]  ? iwl_mvm_mac_hw_scan+0x50/0x70 [iwlmvm]
[  541.021161]  iwl_mvm_mac_hw_scan+0x50/0x70 [iwlmvm]
[  541.021175]  __ieee80211_start_scan+0x2a6/0x6f0 [mac80211]
[  541.021185]  ieee80211_request_scan+0x2b/0x50 [mac80211]
[  541.021199]  nl80211_trigger_scan+0x4bf/0x7a0 [cfg80211]
[  541.021202]  genl_family_rcv_msg+0x1e9/0x380
[  541.021204]  genl_rcv_msg+0x47/0x90
[  541.021206]  ? __alloc_skb+0x82/0x1c0
[  541.021207]  ? genl_family_rcv_msg+0x380/0x380
[  541.021209]  netlink_rcv_skb+0xde/0x110
[  541.021210]  genl_rcv+0x24/0x40
[  541.021212]  netlink_unicast+0x191/0x250
[  541.021214]  netlink_sendmsg+0x2da/0x3c0
[  541.021216]  sock_sendmsg+0x36/0x40
[  541.021217]  ___sys_sendmsg+0x2dd/0x2f0
[  541.021220]  ? __set_current_blocked+0x3d/0x60
[  541.021222]  ? signal_setup_done+0x67/0xb0
[  541.021224]  ? do_signal+0x199/0x6b0
[  541.021226]  ? __fpu__restore_sig+0x97/0x480
[  541.021227]  ? __sys_sendmsg+0x51/0x90
[  541.021228]  __sys_sendmsg+0x51/0x90
[  541.021231]  do_syscall_64+0x6e/0x120
[  541.021233]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[  541.021234] RIP: 0033:0x7f0950e05d57
[  541.021235] RSP: 002b:00007ffdeed14398 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
[  541.021236] RAX: ffffffffffffffda RBX: 000056414fe4c540 RCX: 00007f0950e05d57
[  541.021237] RDX: 0000000000000000 RSI: 00007ffdeed143d0 RDI: 0000000000000006
[  541.021238] RBP: 000056414feb2980 R08: 0000000000000000 R09: 000056414fead960
[  541.021238] R10: 0000000000000007 R11: 0000000000000246 R12: 000056414fe4c450
[  541.021239] R13: 00007ffdeed143d0 R14: 0000000000000000 R15: 000056414fe4d210
[  541.021240] Code: 00 41 8b 84 24 00 19 00 00 a8 02 0f 85 02 ff ff ff e9 ce fe ff ff 89 ee 48 c7 c7 b0 f2 ab c0 c6 05 d4 c9 03 00 01 e8 a0 82 7e fa <0f> 0b e9 11 ff ff ff e8 34 85 7e fa 0f 1f 40 00 0f 1f 44 00 00 
[  541.021268] WARNING: CPU: 0 PID: 898 at drivers/net/wireless/intel/iwlwifi/mvm/scan.c:1784 iwl_mvm_report_scan_aborted+0x200/0x210 [iwlmvm]
[  541.021269] ---[ end trace f0fa44b748c10db4 ]---
[  541.021276] iwlwifi 0000:00:14.3: Scan failed! ret -110
[  541.021314] iwlwifi 0000:00:14.3: Microcode SW error detected. Restarting 0x1.
[  544.496863] iwlwifi 0000:00:14.3: HCMD_ACTIVE already clear for command SCAN_REQ_UMAC
[  545.094397] WARNING: CPU: 1 PID: 47 at drivers/net/wireless/intel/iwlwifi/mvm/scan.c:1608 iwl_mvm_rx_umac_scan_complete_notif+0x1fe/0x210 [iwlmvm]
[  545.094398] Modules linked in: snd_hda_codec_hdmi bnep 8250_dw nls_iso8859_1 arc4 snd_soc_skl x86_pkg_temp_thermal intel_powerclamp snd_soc_skl_ipc coretemp snd_soc_sst_ipc snd_soc_sst_dsp kvm_intel snd_hda_ext_core snd_hda_codec_realtek snd_soc_acpi snd_hda_codec_generic kvm snd_soc_core snd_compress snd_pcm_dmaengine irqbypass ac97_bus crct10dif_pclmul iwlmvm crc32_pclmul ghash_clmulni_intel pcbc mac80211 aesni_intel snd_hda_intel aes_x86_64 crypto_simd glue_helper cryptd snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi serio_raw snd_seq wmi_bmof btusb btrtl snd_seq_device btbcm iwlwifi asix snd_timer btintel usbnet mii bluetooth snd input_leds soundcore ecdh_generic idma64 shpchp virt_dma mei_me intel_lpss_pci cfg80211 mei intel_pch_thermal intel_lpss acpi_pad
[  545.094430]  mac_hid parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_generic usbhid hid i915 dwc3 udc_core ulpi e1000e dwc3_pci prime_numbers wmi video
[  545.094441] CPU: 1 PID: 47 Comm: kworker/1:1 Tainted: G     U  W        4.16.0-rc6-drm-intel-qa-ww12-commit-4db112a+ #1
[  545.094442] Hardware name: Intel Corporation CannonLake Client Platform/CannonLake Y LPDDR4 RVP, BIOS CNLSFWR1.R00.X124.B02.1802051422 02/05/2018
[  545.094448] Workqueue: events iwl_mvm_async_handlers_wk [iwlmvm]
[  545.094454] RIP: 0010:iwl_mvm_rx_umac_scan_complete_notif+0x1fe/0x210 [iwlmvm]
[  545.094455] RSP: 0018:ffffbba980e7bdf8 EFLAGS: 00010246
[  545.094456] RAX: 0000000000000000 RBX: ffff9eb1fe981000 RCX: ffff9eb2357a8001
[  545.094457] RDX: 0000000000000000 RSI: ffff9eb22cf12a90 RDI: ffff9eb22faf1528
[  545.094458] RBP: ffffbba980e7be38 R08: 0000000000000000 R09: 0000000000000001
[  545.094459] R10: ffffbba980e7be38 R11: 0000000000000000 R12: ffff9eb22faf152c
[  545.094459] R13: ffff9eb22faf1528 R14: ffff9eb22faf1558 R15: ffff9eb233c29a80
[  545.094461] FS:  0000000000000000(0000) GS:ffff9eb23f880000(0000) knlGS:0000000000000000
[  545.094462] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  545.094462] CR2: 00007fe0c7e7bc50 CR3: 000000013320a003 CR4: 0000000000760ee0
[  545.094463] PKRU: 55555554
[  545.094464] Call Trace:
[  545.094470]  iwl_mvm_async_handlers_wk+0x9a/0x130 [iwlmvm]
[  545.094474]  process_one_work+0x147/0x3c0
[  545.094476]  worker_thread+0x4a/0x440
[  545.094478]  kthread+0xf8/0x130
[  545.094480]  ? rescuer_thread+0x360/0x360
[  545.094481]  ? kthread_associate_blkcg+0x90/0x90
[  545.094483]  ret_from_fork+0x35/0x40
[  545.094485] Code: 89 4c 24 04 e8 24 8f 09 00 c7 85 1c 19 00 00 00 00 00 00 8b 95 00 19 00 00 41 8b 84 24 7c 19 00 00 44 8b 4c 24 04 e9 77 fe ff ff <0f> 0b e9 26 ff ff ff e8 26 92 7e fa 66 0f 1f 44 00 00 0f 1f 44 
[  545.094515] WARNING: CPU: 1 PID: 47 at drivers/net/wireless/intel/iwlwifi/mvm/scan.c:1608 iwl_mvm_rx_umac_scan_complete_notif+0x1fe/0x210 [iwlmvm]
[  545.094515] ---[ end trace f0fa44b748c10db5 ]---
[  561.872267] Setting dangerous option reset - tainting kernel
[  562.977732] Setting dangerous option reset - tainting kernel
[  567.865254] Setting dangerous option reset - tainting kernel
[  577.855254] Setting dangerous option reset - tainting kernel
[  579.573912] Setting dangerous option reset - tainting kernel
[  604.039990] watchdog: BUG: soft lockup - CPU#3 stuck for 22s! [gem_exec_reloc:2144]
[  604.039997] Modules linked in: snd_hda_codec_hdmi bnep 8250_dw nls_iso8859_1 arc4 snd_soc_skl x86_pkg_temp_thermal intel_powerclamp snd_soc_skl_ipc coretemp snd_soc_sst_ipc snd_soc_sst_dsp kvm_intel snd_hda_ext_core snd_hda_codec_realtek snd_soc_acpi snd_hda_codec_generic kvm snd_soc_core snd_compress snd_pcm_dmaengine irqbypass ac97_bus crct10dif_pclmul iwlmvm crc32_pclmul ghash_clmulni_intel pcbc mac80211 aesni_intel snd_hda_intel aes_x86_64 crypto_simd glue_helper cryptd snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi serio_raw snd_seq wmi_bmof btusb btrtl snd_seq_device btbcm iwlwifi asix snd_timer btintel usbnet mii bluetooth snd input_leds soundcore ecdh_generic idma64 shpchp virt_dma mei_me intel_lpss_pci cfg80211 mei intel_pch_thermal intel_lpss acpi_pad
[  604.040035]  mac_hid parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_generic usbhid hid i915 dwc3 udc_core ulpi e1000e dwc3_pci prime_numbers wmi video
[  604.040049] CPU: 3 PID: 2144 Comm: gem_exec_reloc Tainted: G     U  W        4.16.0-rc6-drm-intel-qa-ww12-commit-4db112a+ #1
[  604.040049] Hardware name: Intel Corporation CannonLake Client Platform/CannonLake Y LPDDR4 RVP, BIOS CNLSFWR1.R00.X124.B02.1802051422 02/05/2018
[  604.040086] RIP: 0010:i915_exit+0x44/0x3b7 [i915]
[  604.040087] RSP: 0018:ffffbba98215f8d0 EFLAGS: 00050246 ORIG_RAX: ffffffffffffff12
[  604.040089] RAX: 0000000000000000 RBX: ffffbba98215fb58 RCX: ffff9eb231e55004
[  604.040090] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[  604.040091] RBP: ffff9eb22d796100 R08: 0000000000001000 R09: 0000000001e2ed51
[  604.040092] R10: ffff9eb22d796100 R11: 0000000000000001 R12: 00007f7ce694ac10
[  604.040092] R13: 00007f7ce694aa30 R14: ffffbba98215f900 R15: ffff9eb22d2295c0
[  604.040094] FS:  00007f7ced73a8c0(0000) GS:ffff9eb23f980000(0000) knlGS:0000000000000000
[  604.040095] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  604.040095] CR2: 00007f7ce694aa30 CR3: 00000002af862002 CR4: 0000000000760ee0
[  604.040096] PKRU: 55555554
[  604.040097] Call Trace:
[  604.040124]  i915_gem_do_execbuffer+0x591/0x1020 [i915]
[  604.040131]  ? shmem_getpage_gfp+0x7a1/0xcf0
[  604.040135]  ? is_bpf_text_address+0xa/0x20
[  604.040138]  ? __save_stack_trace+0x92/0x100
[  604.040140]  ? create_object+0x24e/0x300
[  604.040161]  i915_gem_execbuffer2_ioctl+0xe7/0x340 [i915]
[  604.040180]  ? i915_gem_execbuffer_ioctl+0x2b0/0x2b0 [i915]
[  604.040184]  drm_ioctl_kernel+0x67/0xb0
[  604.040186]  drm_ioctl+0x2d4/0x3c0
[  604.040205]  ? i915_gem_execbuffer_ioctl+0x2b0/0x2b0 [i915]
[  604.040208]  ? vma_merge+0xc8/0x330
[  604.040211]  do_vfs_ioctl+0xa2/0x610
[  604.040214]  SyS_ioctl+0x74/0x80
[  604.040217]  do_syscall_64+0x6e/0x120
[  604.040220]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[  604.040222] RIP: 0033:0x7f7ceb91aef7
[  604.040222] RSP: 002b:00007ffebad27fd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  604.040224] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f7ceb91aef7
[  604.040225] RDX: 00007ffebad28090 RSI: 0000000040406469 RDI: 0000000000000003
[  604.040225] RBP: 00007ffebad28090 R08: ffffffffffffffff R09: 0000000000000000
[  604.040226] R10: 000000000000049e R11: 0000000000000246 R12: 0000000040406469
[  604.040227] R13: 0000000000000003 R14: 00007ffebad28090 R15: 0000000002000000
[  604.040228] Code: ff ff ff e9 75 11 f1 ff b9 f2 ff ff ff e9 7d 11 f1 ff b8 f2 ff ff ff 40 30 f6 e9 d3 3a f2 ff b8 f2 ff ff ff 30 d2 e9 db 3a f2 ff <ba> f2 ff ff ff e9 6b 55 f2 ff b8 f2 ff ff ff e9 1c 5a f2 ff b8 
[  641.307239] Setting dangerous option reset - tainting kernel

Comment 1 Chris Wilson 2018-04-05 20:39:40 UTC

The softlockup is expected, but the novelty here is the iwlwifi error and not graphics related at all.

Comment 2 Lakshmi 2018-08-22 11:16:00 UTC

This is not a graphics bug. Tests related to gem_exec_reloc doesn't have any failures in CI. Closing this bug.
https://intel-gfx-ci.01.org/tree/drm-tip/igt-shards-all.html.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.