https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_347/fi-blb-e6850/igt@gem_pwrite@small-cpu-random.html <6> [34.633962] Console: switching to colour dummy device 80x25 <6> [34.634076] [IGT] gem_pwrite: executing <6> [34.645570] [IGT] gem_pwrite: starting subtest small-cpu-random <6> [34.660994] gem_pwrite (1005): drop_caches: 4 <6> [38.869235] [IGT] gem_pwrite: exiting, ret=0 <5> [38.871552] Setting dangerous option reset - tainting kernel <3> [124.235542] INFO: task kworker/u16:4:154 blocked for more than 61 seconds. <3> [124.235628] Tainted: G U W 5.3.0-rc4-ge64af2bda23c-drmtip_347+ #1 <3> [124.235681] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6> [124.235719] kworker/u16:4 D13272 154 2 0x80004000 <6> [124.235734] Workqueue: events_unbound async_run_entry_fn <4> [124.235738] Call Trace: <4> [124.235748] ? __schedule+0x30e/0x860 <4> [124.235756] ? wait_for_common+0x116/0x1f0 <4> [124.235761] schedule+0x2e/0xb0 <4> [124.235765] schedule_timeout+0x21b/0x3d0 <4> [124.235773] ? wait_for_common+0x116/0x1f0 <4> [124.235777] ? mark_held_locks+0x49/0x70 <4> [124.235781] ? _raw_spin_unlock_irq+0x24/0x50 <4> [124.235787] ? wait_for_common+0x116/0x1f0 <4> [124.235791] wait_for_common+0x13a/0x1f0 <4> [124.235797] ? wake_up_q+0x80/0x80 <4> [124.235806] __flush_work+0x28f/0x4d0 <4> [124.235812] ? flush_workqueue_prep_pwqs+0x1b0/0x1b0 <4> [124.235825] ? work_busy+0x150/0x150 <4> [124.235829] __cancel_work_timer+0x13b/0x1e0 <4> [124.235847] mei_cancel_work+0x1c/0x30 [mei] <4> [124.235855] mei_me_probe+0x316/0x380 [mei_me] <4> [124.235863] pci_device_probe+0x9e/0x120 <4> [124.235871] really_probe+0xea/0x3d0 <4> [124.235877] driver_probe_device+0x10b/0x120 <4> [124.235882] __driver_attach_async_helper+0x7f/0x90 <4> [124.235887] async_run_entry_fn+0x34/0x160 <4> [124.235893] process_one_work+0x245/0x610 <4> [124.235903] worker_thread+0x37/0x380 <4> [124.235910] ? process_one_work+0x610/0x610 <4> [124.235913] kthread+0x119/0x130 <4> [124.235917] ? kthread_park+0xa0/0xa0 <4> [124.235924] ret_from_fork+0x3a/0x50 <3> [124.235941] INFO: task systemd-udevd:264 blocked for more than 61 seconds. <3> [124.235975] Tainted: G U W 5.3.0-rc4-ge64af2bda23c-drmtip_347+ #1 <3> [124.236013] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6> [124.236051] systemd-udevd D12504 264 214 0x80004100 <4> [124.236058] Call Trace: <4> [124.236066] ? __schedule+0x30e/0x860 <4> [124.236075] schedule+0x2e/0xb0 <4> [124.236080] async_synchronize_cookie_domain+0x9f/0x150 <4> [124.236084] ? wait_woken+0xa0/0xa0 <4> [124.236094] do_init_module+0xb7/0x1f6 <4> [124.236099] load_module+0x25bd/0x2a40 <4> [124.236123] ? __se_sys_finit_module+0xd3/0xf0 <4> [124.236127] __se_sys_finit_module+0xd3/0xf0 <4> [124.236143] do_syscall_64+0x55/0x1c0 <4> [124.236148] entry_SYSCALL_64_after_hwframe+0x49/0xbe <4> [124.236151] RIP: 0033:0x7fe3834c8839 <4> [124.236159] Code: Bad RIP value. <4> [124.236162] RSP: 002b:00007ffe64261328 EFLAGS: 00000246 ORIG_RAX: 0000000000000139 <4> [124.236166] RAX: ffffffffffffffda RBX: 0000558d1f9eebb0 RCX: 00007fe3834c8839 <4> [124.236169] RDX: 0000000000000000 RSI: 00007fe3831a7145 RDI: 000000000000000f <4> [124.236172] RBP: 00007fe3831a7145 R08: 0000000000000000 R09: 00007ffe64261440 <4> [124.236175] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000 <4> [124.236178] R13: 0000558d1fa10e90 R14: 0000000000020000 R15: 0000558d1f9eebb0 <3> [124.236192] INFO: task systemd-udevd:266 blocked for more than 61 seconds. <3> [124.236227] Tainted: G U W 5.3.0-rc4-ge64af2bda23c-drmtip_347+ #1 <3> [124.236264] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6> [124.236302] systemd-udevd D13176 266 214 0x80004100 <4> [124.236310] Call Trace: <4> [124.236317] ? __schedule+0x30e/0x860 <4> [124.236327] schedule+0x2e/0xb0 <4> [124.236331] async_synchronize_cookie_domain+0x9f/0x150 <4> [124.236336] ? wait_woken+0xa0/0xa0 <4> [124.236343] do_init_module+0xb7/0x1f6 <4> [124.236348] load_module+0x25bd/0x2a40 <4> [124.236372] ? __se_sys_finit_module+0xd3/0xf0 <4> [124.236375] __se_sys_finit_module+0xd3/0xf0 <4> [124.236391] do_syscall_64+0x55/0x1c0 <4> [124.236395] entry_SYSCALL_64_after_hwframe+0x49/0xbe <4> [124.236398] RIP: 0033:0x7fe3834c8839 <4> [124.236403] Code: Bad RIP value. <4> [124.236406] RSP: 002b:00007ffe64261328 EFLAGS: 00000246 ORIG_RAX: 0000000000000139 <4> [124.236410] RAX: ffffffffffffffda RBX: 0000558d1f9eebb0 RCX: 00007fe3834c8839 <4> [124.236413] RDX: 0000000000000000 RSI: 00007fe3831a7145 RDI: 000000000000000f <4> [124.236416] RBP: 00007fe3831a7145 R08: 0000000000000000 R09: 00007ffe64261440 <4> [124.236419] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000 <4> [124.236422] R13: 0000558d1fa10e90 R14: 0000000000020000 R15: 0000558d1f9eebb0 <3> [124.236440] INFO: task kworker/1:4:455 blocked for more than 61 seconds. <3> [124.236473] Tainted: G U W 5.3.0-rc4-ge64af2bda23c-drmtip_347+ #1 <3> [124.236551] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6> [124.236590] kworker/1:4 D14480 455 2 0x80004000 <6> [124.236602] Workqueue: events output_poll_execute <4> [124.236606] Call Trace: <4> [124.236613] ? __schedule+0x30e/0x860 <4> [124.236623] schedule+0x2e/0xb0 <4> [124.236627] async_synchronize_cookie_domain+0x9f/0x150 <4> [124.236632] ? wait_woken+0xa0/0xa0 <4> [124.236801] intel_fbdev_output_poll_changed+0x7e/0x90 [i915] <4> [124.236809] drm_kms_helper_hotplug_event+0x21/0x30 <4> [124.236813] output_poll_execute+0x1a0/0x1b0 <4> [124.236822] process_one_work+0x245/0x610 <4> [124.236832] worker_thread+0x37/0x380 <4> [124.236839] ? process_one_work+0x610/0x610 <4> [124.236842] kthread+0x119/0x130 <4> [124.236846] ? kthread_park+0xa0/0xa0 <4> [124.236852] ret_from_fork+0x3a/0x50 <3> [124.236876] INFO: task gem_pwrite:1005 blocked for more than 61 seconds. <3> [124.236910] Tainted: G U W 5.3.0-rc4-ge64af2bda23c-drmtip_347+ #1 <3> [124.236949] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. <6> [124.236988] gem_pwrite D12808 1005 1004 0x00000000 <4> [124.236995] Call Trace: <4> [124.237002] ? __schedule+0x30e/0x860 <4> [124.237012] schedule+0x2e/0xb0 <4> [124.237016] async_synchronize_cookie_domain+0x9f/0x150 <4> [124.237021] ? wait_woken+0xa0/0xa0 <4> [124.237105] intel_fbdev_restore_mode+0x3a/0x60 [i915] <4> [124.237110] drm_lastclose+0x2a/0x50 <4> [124.237114] drm_release+0xb9/0xe0 <4> [124.237120] __fput+0xc2/0x250 <4> [124.237128] task_work_run+0x82/0xb0 <4> [124.237135] exit_to_usermode_loop+0x93/0xa0 <4> [124.237139] do_syscall_64+0x16d/0x1c0 <4> [124.237143] entry_SYSCALL_64_after_hwframe+0x49/0xbe <4> [124.237147] RIP: 0033:0x7f27e2779421 <4> [124.237152] Code: Bad RIP value. <4> [124.237155] RSP: 002b:00007ffe421b4678 EFLAGS: 00000246 ORIG_RAX: 0000000000000003 <4> [124.237159] RAX: 0000000000000000 RBX: 0000000000000001 RCX: 00007f27e2779421 <4> [124.237162] RDX: 0000000000000000 RSI: 00007ffe421b44b0 RDI: 0000000000000006 <4> [124.237165] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000 <4> [124.237168] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f27e2c0d860 <4> [124.237171] R13: 0000000000000003 R14: 00007f27e2767628 R15: 00007f27e2763d80 <4> [124.237184] Showing all locks held in the system: <4> [124.237190] 1 lock held by khungtaskd/23: <4> [124.237192] #0: 00000000d5e7ba30 (rcu_read_lock){....}, at: debug_show_all_locks+0xe/0x1a0 <4> [124.237204] 3 locks held by kworker/u16:4/154: <4> [124.237207] #0: 00000000d401d32d ((wq_completion)events_unbound){+.+.}, at: process_one_work+0x1bf/0x610 <4> [124.237214] #1: 000000008c682750 ((work_completion)(&entry->work)){+.+.}, at: process_one_work+0x1bf/0x610 <4> [124.237221] #2: 00000000439a769d (&dev->mutex){....}, at: __driver_attach_async_helper+0x13/0x90 <4> [124.237229] 3 locks held by kworker/1:2/159: <4> [124.237232] #0: 00000000a264814d ((wq_completion)events){+.+.}, at: process_one_work+0x1bf/0x610 <4> [124.237238] #1: 00000000f59b9d9b ((work_completion)(&dev->bus_rescan_work)){+.+.}, at: process_one_work+0x1bf/0x610 <4> [124.237245] #2: 0000000062295e78 (&dev->cl_bus_lock){+.+.}, at: mei_cl_bus_rescan_work+0x2f/0x350 [mei] <4> [124.237258] 1 lock held by in:imklog/281: <4> [124.237262] 2 locks held by kworker/1:4/455: <4> [124.237265] #0: 00000000a264814d ((wq_completion)events){+.+.}, at: process_one_work+0x1bf/0x610 <4> [124.237271] #1: 00000000c7d25de6 ((work_completion)(&(&dev->mode_config.output_poll_work)->work)){+.+.}, at: process_one_work+0x1bf/0x610 <4> [124.237283] 3 locks held by dmesg/987: <4> [124.237286] 1 lock held by gem_pwrite/1005: <4> [124.237288] #0: 00000000b0cf4ab7 (drm_global_mutex){+.+.}, at: drm_release+0x26/0xe0
The CI Bug Log issue associated to this bug has been updated. ### New filters associated * BLB: igt@gem_pwrite@small-cpu-randomigt@gem_pwrite@small-cpu-random - dmesg-warn - INFO: task kworker/u16:4:154 blocked for more than 61 seconds. - https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_347/fi-blb-e6850/igt@gem_pwrite@small-cpu-random.html
mei strikes again. We must already have a bug open for this because it regularly takes out module-reload on blb.
Pure mei bug.
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.