Hello,
FYI this happens in mainline kernel and at least dates back to v4.13 .
It has been reported before, well sorry, if cannot be fixed or
work-around, it'll keep popping up in our tests and consume our time.
The last resort would be to blacklist this error from future 0day
reports.
[ 13.867832] [00] BAD ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 13.874320] [00] BAD ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 14.037671] fbcon: inteldrmfb (fb0) is primary device
[ 14.176079] ------------[ cut here ]------------
[ 14.176081] vblank wait timed out on crtc 0
[ 14.176118] WARNING: CPU: 0 PID: 269 at drivers/gpu/drm/drm_vblank.c:1084 drm_wait_one_vblank+0x160/0x170 [drm]
[ 14.176119] Modules linked in: intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_realtek snd_hda_codec_generic kvm_intel i915 kvm snd_hda_intel irqbypass crct10dif_pclmul crc32_pclmul snd_hda_codec crc32c_intel ghash_clmulni_intel drm_kms_helper pcbc ahci syscopyarea snd_hda_core aesni_intel libahci snd_hwdep crypto_simd sysfillrect sysimgblt fb_sys_fops dcdbas snd_pcm cryptd glue_helper libata pcspkr snd_timer shpchp drm snd soundcore video ip_tables
[ 14.176139] CPU: 0 PID: 269 Comm: kworker/u16:7 Not tainted 4.17.0-rc1 #1
[ 14.176140] Hardware name: Dell Inc. OptiPlex 9020/0DNKMN, BIOS A05 12/05/2013
[ 14.176144] Workqueue: events_unbound async_run_entry_fn
[ 14.176154] RIP: 0010:drm_wait_one_vblank+0x160/0x170 [drm]
[ 14.176155] RSP: 0018:ffffc900013cf918 EFLAGS: 00010296
[ 14.176157] RAX: 000000000000001f RBX: ffff88021bfe8000 RCX: 0000000000000000
[ 14.176157] RDX: 0000000000000000 RSI: 0000000000000002 RDI: 0000000000000202
[ 14.176158] RBP: 0000000000000000 R08: 0000000000000000 R09: 000000000000001f
[ 14.176159] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 14.176160] R13: 0000000000000002 R14: ffff88021b98a008 R15: ffff88021b64fc00
[ 14.176161] FS: 0000000000000000(0000) GS:ffff88021ea00000(0000) knlGS:0000000000000000
[ 14.176162] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 14.176163] CR2: 0000557ac4b38e50 CR3: 000000021d40a002 CR4: 00000000001606f0
[ 14.176164] Call Trace:
[ 14.176171] ? finish_wait+0x80/0x80:
autoremove_wake_function at kernel/sched/wait.c:372
[ 14.176216] hsw_enable_crt+0x3d/0x90 [i915]
[ 14.176253] intel_encoders_enable+0x55/0x80 [i915]
[ 14.176285] haswell_crtc_enable+0x2a2/0x7f0 [i915]
[ 14.176315] intel_update_crtc+0x39/0x90 [i915]
[ 14.176343] intel_update_crtcs+0x47/0x60 [i915]
[ 14.176369] intel_atomic_commit_tail+0x1d2/0xc50 [i915]
[ 14.176394] intel_atomic_commit+0x215/0x2f0 [i915]
[ 14.176402] restore_fbdev_mode_atomic+0x19c/0x1f0 [drm_kms_helper]
[ 14.176409] drm_fb_helper_restore_fbdev_mode_unlocked+0x45/0x90 [drm_kms_helper]
[ 14.176414] drm_fb_helper_set_par+0x29/0x50 [drm_kms_helper]
[ 14.176446] intel_fbdev_set_par+0x16/0x60 [i915]
[ 14.176450] fbcon_init+0x4d7/0x680:
fbcon_init at drivers/video/fbdev/core/fbcon.c:1138
[ 14.176453] visual_init+0xd5/0x130:
visual_init at drivers/tty/vt/vt.c:748
[ 14.176456] do_bind_con_driver+0x1f4/0x400:
do_bind_con_driver at drivers/tty/vt/vt.c:3184
[ 14.176458] do_take_over_console+0x7b/0x190:
do_take_over_console at drivers/tty/vt/vt.c:3744
[ 14.176460] do_fbcon_takeover+0x58/0xb0:
do_fbcon_takeover at drivers/video/fbdev/core/fbcon.c:547
[ 14.176462] notifier_call_chain+0x47/0x70:
notifier_call_chain at kernel/notifier.c:95 (discriminator 1)
[ 14.176464] blocking_notifier_call_chain+0x3e/0x60:
__blocking_notifier_call_chain at kernel/notifier.c:319
(inlined by) blocking_notifier_call_chain at kernel/notifier.c:328
[ 14.176467] ? _cond_resched+0x19/0x30:
_cond_resched at kernel/sched/core.c:4982
[ 14.176469] register_framebuffer+0x224/0x330:
unlock_fb_info at include/linux/fb.h:657
(inlined by) do_register_framebuffer at drivers/video/fbdev/core/fbmem.c:1713
(inlined by) register_framebuffer at drivers/video/fbdev/core/fbmem.c:1806
[ 14.176475] __drm_fb_helper_initial_config_and_unlock+0x209/0x430 [drm_kms_helper]
[ 14.176505] intel_fbdev_initial_config+0x14/0x30 [i915]
[ 14.176508] async_run_entry_fn+0x39/0x160:
async_run_entry_fn at kernel/async.c:128
[ 14.176510] process_one_work+0x182/0x3a0:
arch_static_branch at kernel/workqueue.c:2145
(inlined by) static_key_false at include/linux/jump_label.h:142
(inlined by) trace_workqueue_execute_end at include/trace/events/workqueue.h:112
(inlined by) process_one_work at kernel/workqueue.c:2150
[ 14.176511] worker_thread+0x3a/0x3b0:
__read_once_size at include/linux/compiler.h:188
(inlined by) list_empty at include/linux/list.h:203
(inlined by) worker_thread at kernel/workqueue.c:2280
[ 14.176513] ? process_one_work+0x3a0/0x3a0:
worker_thread at kernel/workqueue.c:2222
[ 14.176515] kthread+0x11e/0x140:
kthread at kernel/kthread.c:238
[ 14.176517] ? kthread_associate_blkcg+0xb0/0xb0:
kthread at kernel/kthread.c:198
[ 14.176520] ret_from_fork+0x35/0x40:
ret_from_fork at arch/x86/entry/entry_64.S:418
[ 14.176522] Code: fc e0 0f 0b e9 39 ff ff ff 48 89 e6 4c 89 f7 e8 f7 79 01 e1 45 85 e4 0f 85 1b ff ff ff 89 ee 48 c7 c7 c8 23 0d a0 e8 40 ea fc e0 <0f> 0b e9 06 ff ff ff 66 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00
[ 14.176545] ---[ end trace 25747e44b68a53bc ]---
[ 14.280077] ------------[ cut here ]------------
[ 14.280077] ------------[ cut here ]------------
[ 14.280079] vblank wait timed out on crtc 0
[ 14.280119] WARNING: CPU: 0 PID: 269 at drivers/gpu/drm/drm_vblank.c:1084 drm_wait_one_vblank+0x160/0x170 [drm]
[ 14.280119] Modules linked in: intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_realtek snd_hda_codec_generic kvm_intel i915 kvm snd_hda_intel irqbypass crct10dif_pclmul crc32_pclmul snd_hda_codec crc32c_intel ghash_clmulni_intel drm_kms_helper pcbc ahci syscopyarea snd_hda_core aesni_intel libahci snd_hwdep crypto_simd sysfillrect sysimgblt fb_sys_fops dcdbas snd_pcm cryptd glue_helper libata pcspkr snd_timer shpchp drm snd soundcore video ip_tables
[ 14.280140] CPU: 0 PID: 269 Comm: kworker/u16:7 Tainted: G W 4.17.0-rc1 #1
[ 14.280141] Hardware name: Dell Inc. OptiPlex 9020/0DNKMN, BIOS A05 12/05/2013
[ 14.280145] Workqueue: events_unbound async_run_entry_fn
[ 14.280156] RIP: 0010:drm_wait_one_vblank+0x160/0x170 [drm]
[ 14.280157] RSP: 0018:ffffc900013cf918 EFLAGS: 00010296
[ 14.280159] RAX: 000000000000001f RBX: ffff88021bfe8000 RCX: 0000000000000000
[ 14.280159] RDX: 0000000000000000 RSI: 0000000000000002 RDI: 0000000000000202
[ 14.280160] RBP: 0000000000000000 R08: 0000000000000000 R09: 000000000000001f
[ 14.280161] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 14.280162] R13: 0000000000000002 R14: ffff88021b98a008 R15: ffff88021b64fc00
[ 14.280163] FS: 0000000000000000(0000) GS:ffff88021ea00000(0000) knlGS:0000000000000000
[ 14.280164] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 14.280165] CR2: 0000557ac4b38e50 CR3: 000000021d40a002 CR4: 00000000001606f0
[ 14.280166] Call Trace:
[ 14.280174] ? finish_wait+0x80/0x80:
autoremove_wake_function at kernel/sched/wait.c:372
[ 14.280226] hsw_enable_crt+0x47/0x90 [i915]
[ 14.280265] intel_encoders_enable+0x55/0x80 [i915]
[ 14.280300] haswell_crtc_enable+0x2a2/0x7f0 [i915]
[ 14.280331] intel_update_crtc+0x39/0x90 [i915]
[ 14.280360] intel_update_crtcs+0x47/0x60 [i915]
[ 14.280386] intel_atomic_commit_tail+0x1d2/0xc50 [i915]
[ 14.280413] intel_atomic_commit+0x215/0x2f0 [i915]
[ 14.280421] restore_fbdev_mode_atomic+0x19c/0x1f0 [drm_kms_helper]
[ 14.280428] drm_fb_helper_restore_fbdev_mode_unlocked+0x45/0x90 [drm_kms_helper]
[ 14.280434] drm_fb_helper_set_par+0x29/0x50 [drm_kms_helper]
[ 14.280468] intel_fbdev_set_par+0x16/0x60 [i915]
[ 14.280471] fbcon_init+0x4d7/0x680:
fbcon_init at drivers/video/fbdev/core/fbcon.c:1138
[ 14.280475] visual_init+0xd5/0x130:
visual_init at drivers/tty/vt/vt.c:748
[ 14.280478] do_bind_con_driver+0x1f4/0x400:
do_bind_con_driver at drivers/tty/vt/vt.c:3184
[ 14.280480] do_take_over_console+0x7b/0x190:
do_take_over_console at drivers/tty/vt/vt.c:3744
[ 14.280482] do_fbcon_takeover+0x58/0xb0:
do_fbcon_takeover at drivers/video/fbdev/core/fbcon.c:547
[ 14.280484] notifier_call_chain+0x47/0x70:
notifier_call_chain at kernel/notifier.c:95 (discriminator 1)
[ 14.280486] blocking_notifier_call_chain+0x3e/0x60:
__blocking_notifier_call_chain at kernel/notifier.c:319
(inlined by) blocking_notifier_call_chain at kernel/notifier.c:328
[ 14.280490] ? _cond_resched+0x19/0x30:
_cond_resched at kernel/sched/core.c:4982
[ 14.280492] register_framebuffer+0x224/0x330:
unlock_fb_info at include/linux/fb.h:657
(inlined by) do_register_framebuffer at drivers/video/fbdev/core/fbmem.c:1713
(inlined by) register_framebuffer at drivers/video/fbdev/core/fbmem.c:1806
[ 14.280499] __drm_fb_helper_initial_config_and_unlock+0x209/0x430 [drm_kms_helper]
[ 14.280530] intel_fbdev_initial_config+0x14/0x30 [i915]
[ 14.280533] async_run_entry_fn+0x39/0x160:
async_run_entry_fn at kernel/async.c:128
[ 14.280535] process_one_work+0x182/0x3a0:
arch_static_branch at kernel/workqueue.c:2145
(inlined by) static_key_false at include/linux/jump_label.h:142
(inlined by) trace_workqueue_execute_end at include/trace/events/workqueue.h:112
(inlined by) process_one_work at kernel/workqueue.c:2150
[ 14.280537] worker_thread+0x3a/0x3b0:
__read_once_size at include/linux/compiler.h:188
(inlined by) list_empty at include/linux/list.h:203
(inlined by) worker_thread at kernel/workqueue.c:2280
[ 14.280539] ? process_one_work+0x3a0/0x3a0:
worker_thread at kernel/workqueue.c:2222
[ 14.280541] kthread+0x11e/0x140:
kthread at kernel/kthread.c:238
[ 14.280543] ? kthread_associate_blkcg+0xb0/0xb0:
kthread at kernel/kthread.c:198
[ 14.280546] ret_from_fork+0x35/0x40:
ret_from_fork at arch/x86/entry/entry_64.S:418
[ 14.280548] Code: fc e0 0f 0b e9 39 ff ff ff 48 89 e6 4c 89 f7 e8 f7 79 01 e1 45 85 e4 0f 85 1b ff ff ff 89 ee 48 c7 c7 c8 23 0d a0 e8 40 ea fc e0 <0f> 0b e9 06 ff ff ff 66 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00
[ 14.280571] ---[ end trace 25747e44b68a53bd ]---
[ 16.741085] ata1: link is slow to respond, please be patient (ready=0)
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang