https://bugs.freedesktop.org/show_bug.cgi?id=105912

Bug ID: 105912 Summary: [IGT] gem_exec_reloc@cpu-30 iwlwifi 0000:00:14.3: Scan failed! ret -110 dmesg-warn Product: DRI Version: DRI git Hardware: x86-64 (AMD64) OS: Linux (All) Status: NEW Severity: normal Priority: medium Component: IGT Assignee: dri-devel@lists.freedesktop.org Reporter: ricardo.o.perez@intel.com

Created attachment 138637 --> https://bugs.freedesktop.org/attachment.cgi?id=138637&action=edit 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