[Intel-gfx] ✗ Fi.CI.BAT: failure for drm/i915: Set PROBE_PREFER_ASYNCHRONOUS

[Matthew Auld]

On Tue, 1 Nov 2022 at 21:58, Brian Norris <briannorris at chromium.org> wrote:
>
> On Fri, Oct 28, 2022 at 5:24 PM Patchwork
> <patchwork at emeril.freedesktop.org> wrote:
> >
> > Patch Details
> > Series:drm/i915: Set PROBE_PREFER_ASYNCHRONOUS
> > URL:https://patchwork.freedesktop.org/series/110277/
> > State:failure
> > Details:https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_110277v1/index.html
> >
> > CI Bug Log - changes from CI_DRM_12317 -> Patchwork_110277v1
> >
> > Summary
> >
> > FAILURE
> >
> > Serious unknown changes coming with Patchwork_110277v1 absolutely need to be
> > verified manually.
> >
> > If you think the reported changes have nothing to do with the changes
> > introduced in Patchwork_110277v1, please notify your bug team to allow them
> > to document this new failure mode, which will reduce false positives in CI.
> >
> > External URL: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_110277v1/index.html
>
> For the record, I have almost zero idea what to do with this. From
> what I can tell, most (all?) of these failures are flaky(?) already
> and are probably not related to my change.

https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_110277v1/index.html

According to that link, this change appears to break every platform
when running the live selftests (looking at the purple squares).
Running the selftests normally involves loading and unloading the
module. Looking at the logs there is scary stuff like:

<3> [371.938060] INFO: task kworker/u12:1:46 blocked for more than 61 seconds.
<3> [371.944992] Tainted: G U W 6.1.0-rc2-Patchwork_110277v1-g0f9cbc285f7d+ #1
<3> [371.953546] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
<6> [371.961428] task:kworker/u12:1 state:D stack:11512 pid:46 ppid:2
flags:0x00004000
<6> [371.961433] Workqueue: events_unbound async_run_entry_fn
<6> [371.961452] Call Trace:
<6> [371.961454] <TASK>
<6> [371.961457] __schedule+0x30e/0xa70
<6> [371.961481] ? usleep_range_state+0xb0/0xb0
<6> [371.961484] ? __wait_for_common+0xd3/0x1d0
<6> [371.961487] schedule+0x4e/0xd0
<6> [371.961489] schedule_timeout+0x237/0x2e0
<6> [371.961493] ? usleep_range_state+0xb0/0xb0
<6> [371.961495] ? __wait_for_common+0xd3/0x1d0
<6> [371.961497] ? mark_held_locks+0x48/0x80
<6> [371.961500] ? _raw_spin_unlock_irq+0x1f/0x50
<6> [371.961504] ? usleep_range_state+0xb0/0xb0
<6> [371.961506] __wait_for_common+0xf5/0x1d0
<6> [371.961526] __flush_work+0x2c4/0x4e0
<6> [371.961530] ? flush_workqueue_prep_pwqs+0x120/0x120
<6> [371.961553] ? get_work_pool+0x90/0x90
<6> [371.961556] __cancel_work_timer+0x14e/0x1f0
<6> [371.961559] ? _raw_spin_unlock_irqrestore+0x54/0x70
<6> [371.961562] ? lockdep_hardirqs_on+0xbf/0x140
<6> [371.961567] intel_display_driver_unregister+0x27/0x40 [i915]
<6> [371.961722] i915_driver_remove+0x50/0x100 [i915]
<6> [371.961862] i915_pci_probe+0x123/0x240 [i915]
<6> [371.961996] ? _raw_spin_unlock_irqrestore+0x3d/0x70
<6> [371.962001] pci_device_probe+0x95/0x110
<6> [371.962005] really_probe+0xd6/0x350
<6> [371.962008] ? pm_runtime_barrier+0x4b/0xa0
<6> [371.962013] __driver_probe_device+0x73/0x170
<6> [371.962016] driver_probe_device+0x1a/0x90
<6> [371.962019] __driver_attach_async_helper+0x31/0x80
<6> [371.962023] async_run_entry_fn+0x28/0x130
<6> [371.962026] process_one_work+0x272/0x5b0
<6> [371.962032] worker_thread+0x37/0x370
<6> [371.962036] ? process_one_work+0x5b0/0x5b0
<6> [371.962038] kthread+0xed/0x120
<6> [371.962040] ? kthread_complete_and_exit+0x20/0x20
<6> [371.962044] ret_from_fork+0x1f/0x30
<6> [371.962053] </TASK>
<3> [371.962055] INFO: task kworker/3:1:57 blocked for more than 61 seconds.
<3> [371.968696] Tainted: G U W 6.1.0-rc2-Patchwork_110277v1-g0f9cbc285f7d+ #1
<3> [371.977219] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
<6> [371.985049] task:kworker/3:1 state:D stack:12488 pid:57 ppid:2
flags:0x00004000
<6> [371.985053] Workqueue: events output_poll_execute [drm_kms_helper]
<6> [371.985080] Call Trace:
<6> [371.985081] <TASK>
<6> [371.985102] __schedule+0x30e/0xa70
<6> [371.985108] schedule+0x4e/0xd0
<6> [371.985110] async_synchronize_cookie_domain+0xe7/0x120
<6> [371.985113] ? finish_swait+0x90/0x90
<6> [371.985117] intel_fbdev_output_poll_changed+0x82/0x90 [i915]
<6> [371.985281] drm_kms_helper_hotplug_event+0x1e/0x30 [drm_kms_helper]
<6> [371.985291] output_poll_execute+0x1f5/0x200 [drm_kms_helper]
<6> [371.985303] process_one_work+0x272/0x5b0
<6> [371.985310] worker_thread+0x37/0x370
<6> [371.985313] ? process_one_work+0x5b0/0x5b0
<6> [371.985316] kthread+0xed/0x120
<6> [371.985317] ? kthread_complete_and_exit+0x20/0x20
<6> [371.985321] ret_from_fork+0x1f/0x30
<6> [371.985329] </TASK>
<3> [371.985348] INFO: task i915_selftest:6017 blocked for more than 61 seconds.


>
> But if someone believes to actually be a blocking issue with my patch,
> let me know, and I can see if I can figure out a better answer than
> that.
>
> Thanks,
> Brian