crash in vc4 drm_atomic_helper_wait_for_vblank

nullr0ute commented 7 years ago

Seeing this crash with Fedora 25 on GNOME workstation. The monitor is Haier HL22KN1.

Kernel is the Fedora 4.8.1-301 kernel which is vanilla with some upstream vc4/clock patches

The vc4/clocks patches on top of 4.8.4 are: http://pkgs.fedoraproject.org/cgit/rpms/kernel.git/tree/bcm283x-vc4-fixes.patch?h=f25&id=08645910f608325614c3a3da1e517c51ee4b2b19

 kernel: ------------[ cut here ]------------
 kernel: WARNING: CPU: 1 PID: 926 at drivers/gpu/drm/drm_atomic_helper.c:1121 drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e8 [drm_kms_helper]
 kernel: [CRTC:48] vblank wait timed out
 kernel: Modules linked in: nf_conntrack_netbios_ns nf_conntrack_broadcast ip6t_REJECT nf_reject_ipv6 xt_conntrack ip6t_rpfilter ip_set nfnetlink ebtable_broute bridge stp llc ebtable_nat ip6ta
 kernel: CPU: 1 PID: 926 Comm: gnome-shell Tainted: G        W       4.8.4-301.fc25.armv7hl #1
 kernel: Hardware name: Generic DT based system
 kernel: [] (unwind_backtrace) from [] (show_stack+0x18/0x1c)
 kernel: [] (show_stack) from [] (dump_stack+0x80/0x9c)
 kernel: [] (dump_stack) from [] (__warn+0xe4/0x104)
 kernel: [] (__warn) from [] (warn_slowpath_fmt+0x3c/0x4c)
 kernel: [] (warn_slowpath_fmt) from [] (drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e8 [drm_kms_helper])
 kernel: [] (drm_atomic_helper_wait_for_vblanks [drm_kms_helper]) from [] (vc4_atomic_complete_commit+0x5c/0x84 [vc4])
 kernel: [] (vc4_atomic_complete_commit [vc4]) from [] (vc4_atomic_commit+0x188/0x198 [vc4])
 kernel: [] (vc4_atomic_commit [vc4]) from [] (drm_atomic_helper_set_config+0x5c/0x98 [drm_kms_helper])
 kernel: [] (drm_atomic_helper_set_config [drm_kms_helper]) from [] (drm_mode_set_config_internal+0x44/0xd8 [drm])
 kernel: [] (drm_mode_set_config_internal [drm]) from [] (drm_mode_setcrtc+0x2ec/0x488 [drm])
 kernel: [] (drm_mode_setcrtc [drm]) from [] (drm_ioctl+0x264/0x41c [drm])
 kernel: [] (drm_ioctl [drm]) from [] (vfs_ioctl+0x28/0x3c)
 kernel: [] (vfs_ioctl) from [] (do_vfs_ioctl+0x8c/0x8b4)
 kernel: [] (do_vfs_ioctl) from [] (SyS_ioctl+0x54/0x78)
 kernel: [] (SyS_ioctl) from [] (ret_fast_syscall+0x0/0x3c)
 kernel: ---[ end trace a4c5e3c0e5032703 ]---

anholt commented 7 years ago

I've also seen this periodically and don't have any good ideas yet.

samtygier commented 7 years ago

Fedora bug https://bugzilla.redhat.com/show_bug.cgi?id=1389163

lategoodbye commented 7 years ago

This looks like a timing issue. So the first question would be: does the vc4 driver only exceed the timeout by a certain amount of time or is it possible that the driver would wait forever?

I suggest to add a second wait_event_timeout() with timeout = 1 sec to drm_atomic_helper_wait_for_vblank in case the first call fails. If the second wait_event_timeout also fails it's possible that the abort condition is never met in some situations.

But first of all we need a better scenario to reproduce the issue.

lategoodbye commented 7 years ago

I get the same output during boot with 4.10.0-next-20170303+ on a Raspberry Pi Zero.

Used config: bcm2835_defconfig + CONFIG_CMA + CONFIG_DMA_CMA

lategoodbye commented 7 years ago

Okay, Michael's patch seems to fix this issue.

nullr0ute commented 7 years ago

I've queued this for various Fedora kernels, and it's in -next already but it might be worthwhile getting it tagged for stable@

lategoodbye commented 7 years ago

Before sending to stable it would be necessary to identify the introducing commit, so we can add a fixes tag and name the relevant kernel versions.

anholt commented 7 years ago

@lategoodbye not sure how that cursor patch would help, since the backtrace here is from a general setcrtc.

pcdubs commented 7 years ago

Still seeing this in Fedora with 4.11 rc1. dmesg with drm.debug=0x1e attached. 4.11.rc1.raspberry-pi.drm.debug.txt

ryniker commented 7 years ago

Still present with Fedora 4.11.0-0.rc6.git0.1.fc26.armv7h. Happens whenever vc4 is not blacklisted.

nullr0ute commented 7 years ago

@ryniker can you please provide details of how this is happening, it's hardware related so a "me too" is useless. Details of the monitor, the connecting interface etc are useful, and an updated crash output for the appropriate kernel too.

lategoodbye commented 7 years ago

@ryniker Could you please also provide the exact stacktrace and test the mentioned patch (which is only in linux-next)?

ryniker commented 7 years ago

There does seem to be a hardware issue here. My monitor is a Dell P2415Qb connected by an HDMI cable to the Raspberry Pi. The monitor wants to display 3840x2160, but of course it can accomodate lesser resolution.

I tried with an older Viewsonic VX2235wm monitor that cannot support such high resolution.. The kernel fault did not occur. To be more accurate, this (issue #66) kernel fault did not occur; a different fault (not related to the vc4 module) occurred at a later time.

The complete log for connection to the Dell monitor is available here:

http://ryniker.org/Fedora/arm/log_04

The first backtrace (it happens multiple times) is copied below. The log for connection to the Viewsonic monitor is here:

http://ryniker.org/Fedora/arm/log_03

Peter, do you know if there is already a Fedora 26 build with this patch:

https://patchwork.kernel.org/patch/9589651/

I suspect to answer this question requires koji-fu beyond my ken.

I did experience delays when I used the Viewsonic monitor that matched what mzoran@crowfest.net described as fixed by this patch.

Mar 01 16:43:27 rpi3-2 kernel: ------------[ cut here ]------------ Mar 01 16:43:27 rpi3-2 kernel: WARNING: CPU: 0 PID: 476 at drivers/gpu/drm/drm_atomic_helper.c:1122 drm_atomic_helper_wait_for_vblanks+0xdc/0x1e8 [drm_kms_helper] Mar 01 16:43:27 rpi3-2 kernel: [CRTC:65] vblank wait timed out Mar 01 16:43:27 rpi3-2 kernel: Modules linked in: vc4(+) snd_soc_core ac97_bus snd_pcm_dmaengine snd_seq snd_seq_device joydev snd_pcm snd_timer brcmfmac snd soundcore brcmutil drm_kms_helper cfg80211 drm rfkill fb_sys_fops syscopyarea sysfillrect sysimgblt bcm2835_rng bcm2835_dma bcm2835_wdt leds_gpio nfsd auth_rpcgss nfs_acl lockd grace sunrpc hid_logitech_hidpp hid_logitech_dj smsc95xx usbnet mii mmc_block dwc2 udc_core sdhci_iproc sdhci_pltfm sdhci pwm_bcm2835 bcm2835 mmc_core i2c_bcm2835 Mar 01 16:43:27 rpi3-2 kernel: CPU: 0 PID: 476 Comm: systemd-udevd Not tainted 4.11.0-0.rc7.git0.1.fc26.armv7hl #1 Mar 01 16:43:27 rpi3-2 kernel: Hardware name: Generic DT based system Mar 01 16:43:27 rpi3-2 kernel: [] (unwind_backtrace) from [] (show_stack+0x18/0x1c) Mar 01 16:43:27 rpi3-2 kernel: [] (show_stack) from [] (dump_stack+0x80/0xa0) Mar 01 16:43:27 rpi3-2 kernel: [] (dump_stack) from [] (warn+0xe4/0x104) Mar 01 16:43:27 rpi3-2 kernel: [] (warn) from [] (warn_slowpath_fmt+0x3c/0x4c) Mar 01 16:43:27 rpi3-2 kernel: [] (warn_slowpath_fmt) from [] (drm_atomic_helper_wait_for_vblanks+0xdc/0x1e8 [drm_kms_helper]) Mar 01 16:43:27 rpi3-2 kernel: [] (drm_atomic_helper_wait_for_vblanks [drm_kms_helper]) from [] (vc4_atomic_complete_commit+0x5c/0xb4 [vc4]) Mar 01 16:43:27 rpi3-2 kernel: [] (vc4_atomic_complete_commit [vc4]) from [] (vc4_atomic_commit+0x200/0x210 [vc4]) Mar 01 16:43:27 rpi3-2 kernel: [] (vc4_atomic_commit [vc4]) from [] (restore_fbdev_mode+0x98/0x268 [drm_kms_helper]) Mar 01 16:43:27 rpi3-2 kernel: [] (restore_fbdev_mode [drm_kms_helper]) from [] (drm_fb_helper_restore_fbdev_mode_unlocked+0x38/0x70 [drm_kms_helper]) Mar 01 16:43:27 rpi3-2 kernel: [] (drm_fb_helper_restore_fbdev_mode_unlocked [drm_kms_helper]) from [] (drm_fb_helper_set_par+0x54/0x64 [drm_kms_helper]) Mar 01 16:43:27 rpi3-2 kernel: [] (drm_fb_helper_set_par [drm_kms_helper]) from [] (fbcon_init+0x2c8/0x44c) Mar 01 16:43:27 rpi3-2 kernel: [] (fbcon_init) from [] (visual_init+0xc4/0x114) Mar 01 16:43:27 rpi3-2 kernel: [] (visual_init) from [] (do_bind_con_driver+0x26c/0x2d8) Mar 01 16:43:27 rpi3-2 kernel: [] (do_bind_con_driver) from [] (do_take_over_console+0x16c/0x1a0) Mar 01 16:43:27 rpi3-2 kernel: [] (do_take_over_console) from [] (do_fbcon_takeover+0x58/0xc0) Mar 01 16:43:27 rpi3-2 kernel: [] (do_fbcon_takeover) from [] (notifier_call_chain+0x48/0x6c) Mar 01 16:43:27 rpi3-2 kernel: [] (notifier_call_chain) from [] (blocking_notifier_call_chain+0x48/0x60) Mar 01 16:43:27 rpi3-2 kernel: [] (__blocking_notifier_call_chain) from [] (blocking_notifier_call_chain+0x1c/0x24) Mar 01 16:43:27 rpi3-2 kernel: [] (blocking_notifier_call_chain) from [] (register_framebuffer+0x230/0x274) Mar 01 16:43:27 rpi3-2 kernel: [] (register_framebuffer) from [] (drm_fb_helper_initial_config+0x16c/0x344 [drm_kms_helper]) Mar 01 16:43:27 rpi3-2 kernel: [] (drm_fb_helper_initial_config [drm_kms_helper]) from [] (drm_fbdev_cma_init_with_funcs+0xb8/0xf4 [drm_kms_helper]) Mar 01 16:43:27 rpi3-2 kernel: [] (drm_fbdev_cma_init_with_funcs [drm_kms_helper]) from [] (vc4_kms_load+0x90/0xb0 [vc4]) Mar 01 16:43:27 rpi3-2 kernel: [] (vc4_kms_load [vc4]) from [] (vc4_drm_bind+0xe4/0x128 [vc4]) Mar 01 16:43:27 rpi3-2 kernel: [] (vc4_drm_bind [vc4]) from [] (try_to_bring_up_master+0x1ec/0x254) Mar 01 16:43:27 rpi3-2 kernel: [] (try_to_bring_up_master) from [] (component_master_add_with_match+0xbc/0xe8) Mar 01 16:43:27 rpi3-2 kernel: [] (component_master_add_with_match) from [] (vc4_platform_drm_probe+0x74/0xb0 [vc4]) Mar 01 16:43:27 rpi3-2 kernel: [] (vc4_platform_drm_probe [vc4]) from [] (platform_drv_probe+0x58/0xa4) Mar 01 16:43:27 rpi3-2 kernel: [] (platform_drv_probe) from [] (driver_probe_device+0x274/0x40c) Mar 01 16:43:27 rpi3-2 kernel: [] (driver_probe_device) from [] (driver_attach+0x88/0xf8) Mar 01 16:43:27 rpi3-2 kernel: [] (__driver_attach) from [] (bus_for_each_dev+0x84/0x94) Mar 01 16:43:27 rpi3-2 kernel: [] (bus_for_each_dev) from [] (bus_add_driver+0x1bc/0x23c) Mar 01 16:43:27 rpi3-2 kernel: [] (bus_add_driver) from [] (driver_register+0xa8/0xe8) Mar 01 16:43:27 rpi3-2 kernel: [] (driver_register) from [] (do_one_initcall+0x12c/0x154) Mar 01 16:43:27 rpi3-2 kernel: [] (do_one_initcall) from [] (do_init_module+0x60/0x1d8) Mar 01 16:43:27 rpi3-2 kernel: [] (do_init_module) from [] (load_module+0x2120/0x21bc) Mar 01 16:43:27 rpi3-2 kernel: [] (load_module) from [] (SyS_finit_module+0xb0/0xc4) Mar 01 16:43:27 rpi3-2 kernel: [] (SyS_finit_module) from [] (__sys_trace_return+0x0/0x10) Mar 01 16:43:27 rpi3-2 kernel: ---[ end trace 8a938154436ca048 ]---

nullr0ute commented 7 years ago

We've had the "drm: vc4: Don't wait for vblank when updating the cursor" since March 1st, it's helped in a small subset of cases.

nullr0ute commented 7 years ago

I'm seeing the crash with a fairly generic Samsung UE50F6500 1080 TV.

Looking through the text file there's 3-4 different back traces that all end up in the drm_atomic_helper_wait_for_vblanks crash.

It also seems some what random, I wrong out a second identical card and booted it and it worked on this TV, same PRi3 etc. This image booted fine on a RPi3, then fine on a RPi2, and then crashed when put into the RPi3. Resetting it it then booted fine. It seems very timing based.

vc4-4.11rc6-crash-samsungUE50F6500.txt

nullr0ute commented 7 years ago

With a RPi3 on the Samsung UE50F6500 1080 TV it's pretty much 50/50 whether we crash or it works. The alignment though is terrible.

lategoodbye commented 7 years ago

Today i was able to reproduce this (or a similiar) issue on my Raspberry Pi Zero with a HP ZR2440w and a 3 port HDMI switch.

Scenario:

switch to PC as HDMI display source
power on Raspberry Pi Zero which is connected to the HDMI switch
HDMI switch select Raspberry Pi Zero as new source
issue appear after starting vc4

It never crashed the system, but the display stays black in this state. Unfortunately i wasn't able to reproduce it always (maybe 3 of 12 cases) and the kernel is a little bit older 4.11.0-rc5-next-20170404+.

Here are the traces:

[    1.873808] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-02-13 17:40
[    1.908785] vc4_hdmi 20902000.hdmi: vc4-hdmi-hifi <-> 20902000.hdmi mapping ok
[    1.940867] vc4-drm soc:gpu: bound 20902000.hdmi (ops vc4_hdmi_ops)
[    1.970472] vc4-drm soc:gpu: bound 20806000.vec (ops vc4_vec_ops)
[    1.999441] vc4-drm soc:gpu: bound 20400000.hvs (ops vc4_hvs_ops)
[    2.028710] vc4-drm soc:gpu: bound 20206000.pixelvalve (ops vc4_crtc_ops)
[    2.058809] vc4-drm soc:gpu: bound 20207000.pixelvalve (ops vc4_crtc_ops)
[    2.088597] vc4-drm soc:gpu: bound 20807000.pixelvalve (ops vc4_crtc_ops)
[    2.117975] vc4-drm soc:gpu: bound 20c00000.v3d (ops vc4_v3d_ops)
[    2.146281] fb: switching to vc4drmfb from simple
[    2.173006] Console: switching to colour dummy device 80x30
[    2.181667] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
[    2.188390] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    2.195155] [drm] Driver supports precise vblank timestamp query.
[    2.299306] ------------[ cut here ]------------
[    2.299360] WARNING: CPU: 0 PID: 49 at drivers/gpu/drm/drm_atomic_helper.c:1129 drm_atomic_helper_wait_for_vblanks+0x1cc/0x218
[    2.299369] [CRTC:66:crtc-2] vblank wait timed out
[    2.299386] CPU: 0 PID: 49 Comm: kworker/0:2 Not tainted 4.11.0-rc5-next-20170404+ #52
[    2.299391] Hardware name: BCM2835
[    2.299415] Workqueue: events deferred_probe_work_func
[    2.299483] [<c010e530>] (unwind_backtrace) from [<c010ba0c>] (show_stack+0x20/0x24)
[    2.299513] [<c010ba0c>] (show_stack) from [<c0377a3c>] (dump_stack+0x20/0x28)
[    2.299543] [<c0377a3c>] (dump_stack) from [<c011deb8>] (__warn+0xe0/0x10c)
[    2.299568] [<c011deb8>] (__warn) from [<c011df2c>] (warn_slowpath_fmt+0x48/0x50)
[    2.299594] [<c011df2c>] (warn_slowpath_fmt) from [<c03ffd30>] (drm_atomic_helper_wait_for_vblanks+0x1cc/0x218)
[    2.299623] [<c03ffd30>] (drm_atomic_helper_wait_for_vblanks) from [<c04311d4>] (vc4_atomic_complete_commit+0x64/0x9c)
[    2.299645] [<c04311d4>] (vc4_atomic_complete_commit) from [<c043140c>] (vc4_atomic_commit+0x200/0x220)
[    2.299680] [<c043140c>] (vc4_atomic_commit) from [<c041ef78>] (drm_atomic_commit+0x54/0x68)
[    2.299717] [<c041ef78>] (drm_atomic_commit) from [<c040439c>] (restore_fbdev_mode+0x120/0x264)
[    2.299749] [<c040439c>] (restore_fbdev_mode) from [<c0406c28>] (drm_fb_helper_restore_fbdev_mode_unlocked+0x3c/0x7c)
[    2.299778] [<c0406c28>] (drm_fb_helper_restore_fbdev_mode_unlocked) from [<c0406cb8>] (drm_fb_helper_set_par+0x50/0x6c)
[    2.299814] [<c0406cb8>] (drm_fb_helper_set_par) from [<c03b4f64>] (fbcon_init+0x32c/0x450)
[    2.299847] [<c03b4f64>] (fbcon_init) from [<c03e47b4>] (visual_init+0xa4/0xf0)
[    2.299874] [<c03e47b4>] (visual_init) from [<c03e57a0>] (do_bind_con_driver+0x15c/0x270)
[    2.299901] [<c03e57a0>] (do_bind_con_driver) from [<c03e715c>] (do_take_over_console+0x148/0x18c)
[    2.299928] [<c03e715c>] (do_take_over_console) from [<c03b50f8>] (do_fbcon_takeover+0x70/0xd8)
[    2.299953] [<c03b50f8>] (do_fbcon_takeover) from [<c03b5938>] (fbcon_event_notify+0x438/0x850)
[    2.299982] [<c03b5938>] (fbcon_event_notify) from [<c0139fd8>] (notifier_call_chain+0x48/0x78)
[    2.300007] [<c0139fd8>] (notifier_call_chain) from [<c013a24c>] (__blocking_notifier_call_chain+0x54/0x6c)
[    2.300030] [<c013a24c>] (__blocking_notifier_call_chain) from [<c013a28c>] (blocking_notifier_call_chain+0x28/0x30)
[    2.300055] [<c013a28c>] (blocking_notifier_call_chain) from [<c03b7f2c>] (fb_notifier_call_chain+0x28/0x30)
[    2.300083] [<c03b7f2c>] (fb_notifier_call_chain) from [<c03b9c70>] (register_framebuffer+0x1fc/0x278)
[    2.300115] [<c03b9c70>] (register_framebuffer) from [<c0406ab0>] (drm_fb_helper_initial_config+0x2e8/0x374)
[    2.300143] [<c0406ab0>] (drm_fb_helper_initial_config) from [<c0407564>] (drm_fbdev_cma_init_with_funcs+0xb4/0x100)
[    2.300169] [<c0407564>] (drm_fbdev_cma_init_with_funcs) from [<c04075cc>] (drm_fbdev_cma_init+0x1c/0x24)
[    2.300193] [<c04075cc>] (drm_fbdev_cma_init) from [<c043150c>] (vc4_kms_load+0x9c/0xc8)
[    2.300232] [<c043150c>] (vc4_kms_load) from [<c042c8b8>] (vc4_drm_bind+0xe4/0x130)
[    2.300271] [<c042c8b8>] (vc4_drm_bind) from [<c043ae44>] (try_to_bring_up_master+0x17c/0x280)
[    2.300297] [<c043ae44>] (try_to_bring_up_master) from [<c043b4ac>] (component_add+0x8c/0x128)
[    2.300321] [<c043b4ac>] (component_add) from [<c043833c>] (vc4_v3d_dev_probe+0x20/0x28)
[    2.300350] [<c043833c>] (vc4_v3d_dev_probe) from [<c04428dc>] (platform_drv_probe+0x68/0xb0)
[    2.300376] [<c04428dc>] (platform_drv_probe) from [<c0440fb8>] (driver_probe_device+0x198/0x450)
[    2.300399] [<c0440fb8>] (driver_probe_device) from [<c0441468>] (__device_attach_driver+0xc0/0x108)
[    2.300421] [<c0441468>] (__device_attach_driver) from [<c043f6bc>] (bus_for_each_drv+0x5c/0xa4)
[    2.300442] [<c043f6bc>] (bus_for_each_drv) from [<c0440c74>] (__device_attach+0x9c/0x138)
[    2.300463] [<c0440c74>] (__device_attach) from [<c04414ec>] (device_initial_probe+0x1c/0x20)
[    2.300484] [<c04414ec>] (device_initial_probe) from [<c043f8d0>] (bus_probe_device+0x38/0x90)
[    2.300505] [<c043f8d0>] (bus_probe_device) from [<c04406ec>] (deferred_probe_work_func+0x5c/0xa4)
[    2.300530] [<c04406ec>] (deferred_probe_work_func) from [<c0132f48>] (process_one_work+0x1d0/0x37c)
[    2.300553] [<c0132f48>] (process_one_work) from [<c0133124>] (process_scheduled_works+0x30/0x40)
[    2.300574] [<c0133124>] (process_scheduled_works) from [<c01333f0>] (worker_thread+0x2bc/0x414)
[    2.300603] [<c01333f0>] (worker_thread) from [<c0138744>] (kthread+0x13c/0x158)
[    2.300633] [<c0138744>] (kthread) from [<c01080f8>] (ret_from_fork+0x14/0x3c)
[    2.300644] ---[ end trace 9612b375f96a4385 ]---

[    1.863561] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-02-13 17:40
[    1.898601] vc4_hdmi 20902000.hdmi: vc4-hdmi-hifi <-> 20902000.hdmi mapping ok
[    1.930743] vc4-drm soc:gpu: bound 20902000.hdmi (ops vc4_hdmi_ops)
[    1.960338] vc4-drm soc:gpu: bound 20806000.vec (ops vc4_vec_ops)
[    1.989269] vc4-drm soc:gpu: bound 20400000.hvs (ops vc4_hvs_ops)
[    2.018419] vc4-drm soc:gpu: bound 20206000.pixelvalve (ops vc4_crtc_ops)
[    2.048566] vc4-drm soc:gpu: bound 20207000.pixelvalve (ops vc4_crtc_ops)
[    2.078423] vc4-drm soc:gpu: bound 20807000.pixelvalve (ops vc4_crtc_ops)
[    2.107773] vc4-drm soc:gpu: bound 20c00000.v3d (ops vc4_v3d_ops)
[    2.135952] fb: switching to vc4drmfb from simple
[    2.162711] Console: switching to colour dummy device 80x30
[    2.171370] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
[    2.178096] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    2.184858] [drm] Driver supports precise vblank timestamp query.
[    2.345886] Console: switching to colour frame buffer device 240x75
[    2.399303] ------------[ cut here ]------------
[    2.399355] WARNING: CPU: 0 PID: 49 at drivers/gpu/drm/drm_atomic_helper.c:1129 drm_atomic_helper_wait_for_vblanks+0x1cc/0x218
[    2.399364] [CRTC:66:crtc-2] vblank wait timed out
[    2.399380] CPU: 0 PID: 49 Comm: kworker/0:2 Not tainted 4.11.0-rc5-next-20170404+ #52
[    2.399385] Hardware name: BCn2835
[    2.399408] Workqueue: events deferred_probe_work_func
[    2.399476] [<c010e530>] (unwind_backtrace) from [<c010ba0c>] (show_stack+0x20/0x24)
[    2.399506] [<c010ba0c>] (show_stack) from [<c0377a3c>] (dump_stack+0x20/0x28)
[    2.399534] [<c0377a3c>] (dump_stack) from [<c011deb8>] (__warn+0xe0/0x10c)
[    2.399558] [<c011deb8>] (__warn) from [<c011df2c>] (warn_slowpath_fmt+0x48/0x50)
[    2.399587] [<c011df2c>] (warn_slowpath_fmt) from [<c03ffd30>] (drm_atomic_helper_wait_for_vblanks+0x1cc/0x218)
[    2.399615] [<c03ffd30>] (drm_atomic_helper_wait_for_vblanks) from [<c04311d4>] (vc4_atomic_complete_commit+0x64/0x9c)
[    2.399637] [<c04311d4>] (vc4_atomic_complete_commit) from [<c043140c>] (vc4_atomic_commit+0x200/0x220)
[    2.399674] [<c043140c>] (vc4_atomic_commit) from [<c041ef78>] (drm_atomic_commit+0x54/0x68)
[    2.399715] [<c041ef78>] (drm_atomic_commit) from [<c04058c4>] (drm_fb_helper_pan_display+0x114/0x1f8)
[    2.399759] [<c04058c4>] (drm_fb_helper_pan_display) from [<c03b8b0c>] (fb_pan_display+0xfc/0x138)
[    2.399786] [<c03b8b0c>] (fb_pan_display) from [<c03b7318>] (bit_update_start+0x24/0x40)
[    2.399811] [<c03b7318>] (bit_update_start) from [<c03b400c>] (fbcon_switch+0x444/0x478)
[    2.399844] [<c03b400c>] (fbcon_switch) from [<c03e5554>] (redraw_screen+0xf8/0x1e8)
[    2.399869] [<c03e5554>] (redraw_screen) from [<c03e5854>] (do_bind_con_driver+0x210/0x270)
[    2.399895] [<c03e5854>] (do_bind_con_driver) from [<c03e715c>] (do_take_over_console+0x148/0x18c)
[    2.399922] [<c03e715c>] (do_take_over_console) from [<c03b50f8>] (do_fbcon_takeover+0x70/0xd8)
[    2.399947] [<c03b50f8>] (do_fbcon_takeover) from [<c03b5938>] (fbcon_event_notify+0x438/0x850)
[    2.399976] [<c03b5938>] (fbcon_event_notify) from [<c0139fd8>] (notifier_call_chain+0x48/0x78)
[    2.400001] [<c0139fd8>] (notifier_call_chain) from [<c013a24c>] (__blocking_notifier_call_chain+0x54/0x6c)
[    2.400025] [<c013a24c>] (__blocking_notifier_call_chain) from [<c013a28c>] (blocking_notifier_call_chain+0x28/0x30)
[    2.400048] [<c013a28c>] (blocking_notifier_call_chain) from [<c03b7f2c>] (fb_notifier_call_chain+0x28/0x30)
[    2.400075] [<c03b7f2c>] (fb_notifier_call_chain) from [<c03b9c70>] (register_framebuffer+0x1fc/0x278)
[    2.400109] [<c03b9c70>] (register_framebuffer) from [<c0406ab0>] (drm_fb_helper_initial_config+0x2e8/0x374)
[    2.400138] [<c0406ab0>] (drm_fb_helper_initial_config) from [<c0407564>] (drm_fbdev_cma_init_with_funcs+0xb4/0x100)
[    2.400164] [<c0407564>] (drm_fbdev_cma_init_with_funcs) from [<c04075cc>] (drm_fbdev_cma_init+0x1c/0x24)
[    2.400188] [<c04075cc>] (drm_fbdev_cma_init) from [<c043150c>] (vc4_kms_load+0x9c/0xc8)
[    2.400227] [<c043150c>] (vc4_kms_load) from [<c042c8b8>] (vc4_drm_bind+0xe4/0x130)
[    2.400265] [<c042c8b8>] (vc4_drm_bind) from [<c043ae44>] (try_to_bring_up_master+0x17c/0x280)
[    2.400292] [<c043ae44>] (try_to_bring_up_master) from [<c043b4ac>] (component_add+0x8c/0x128)
[    2.400316] [<c043b4ac>] (component_add) from [<c043833c>] (vc4_v3d_dev_probe+0x20/0x28)
[    2.400346] [<c043833c>] (vc4_v3d_dev_probe) from [<c04428dc>] (platform_drv_probe+0x68/0xb0)
[    2.400370] [<c04428dc>] (platform_drv_probe) from [<c0440fb8>] (driver_probe_device+0x198/0x450)
[    2.400392] [<c0440fb8>] (driver_probe_device) from [<c0441468>] (__device_attach_driver+0xc0/0x108)
[    2.400413] [<c0441468>] (__device_attach_driver) from [<c043f6bc>] (bus_for_each_drv+0x5c/0xa4)
[    2.400434] [<c043f6bc>] (bus_for_each_drv) from [<c0440c74>] (__device_attach+0x9c/0x138)
[    2.400455] [<c0440c74>] (__device_attach) from [<c04414ec>] (device_initial_probe+0x1c/0x20)
[    2.400476] [<c04414ec>] (device_initial_probe) from [<c043f8d0>] (bus_probe_device+0x38/0x90)
[    2.400498] [<c043f8d0>] (bus_probe_device) from [<c04406ec>] (deferred_probe_work_func+0x5c/0xa4)
[    2.400522] [<c04406ec>] (deferred_probe_work_func) from [<c0132f48>] (process_one_work+0x1d0/0x37c)
[    2.400545] [<c0132f48>] (process_one_work) from [<c0133124>] (process_scheduled_works+0x30/0x40)
[    2.400566] [<c0133124>] (process_scheduled_works) from [<c01333f0>] (worker_thread+0x2bc/0x414)
[    2.400596] [<c01333f0>] (worker_thread) from [<c0138744>] (kthread+0x13c/0x158)
[    2.400627] [<c0138744>] (kthread) from [<c01080f8>] (ret_from_fork+0x14/0x3c)
[    2.400638] ---[ end trace b5439f64d59ee7eb ]---

[    1.863246] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-02-13 17:40
[    1.898198] vc4_hdmi 20902000.hdmi: vc4-hdmi-hifi <-> 20902000.hdmi mapping ok
[    1.930275] vc4-drm soc:gpu: bound 20902000.hdmi (ops vc4_hdmi_ops)
[    1.959785] vc4-drm soc:gpu: bound 20806000.vec (ops vc4_vec_ops)
[    1.988719] vc4-drm soc:gpu: bound 20400000.hvs (ops vc4_hvs_ops)
[    2.017922] vc4-drm soc:gpu: bound 20206000.pixelvalve (ops vc4_crtc_ops)
[    2.048069] vc4-drm soc:gpu: bound 20207000.pixelvalve (ops vc4_crtc_ops)
[    2.077845] vc4-drm soc:gpu: bound 20807000.pixelvalve (ops vc4_crtc_ops)
[    2.107105] vc4-drm soc:gpu: bound 20c00000.v3d (ops vc4_v3d_ops)
[    2.135333] fb: switching to vc4drmfb from simple
[    2.162038] Console: switching to colour dummy device 80x30
[    2.170711] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
[    2.177436] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    2.184197] [drm] Driver supports precise vblank timestamp query.
[    2.343474] Console: switching to colour frame buffer device 240x75
[    2.379315] random: fast init done
[    2.454143] vc4-drm soc:gpu: fb0:  frame buffer device
[    2.919450] dwc2 20980000.usb: dwc2_check_param_tx_fifo_sizes: fifo_count = 7, sum = 3584, total = 3776
[    2.929689] dwc2 20980000.usb: EPs: 8, dedicated fifos, 4080 entries in SPRAM
[    2.938577] g_serial gadget: Gadget Serial v2.4
[    2.943655] g_serial gadget: g_serial ready
[    2.948188] dwc2 20980000.usb: bound driver g_serial
[    2.954101] dwc2 20980000.usb: DWC OTG Controller
[    2.960007] dwc2 20980000.usb: new USB bus registered, assigned bus number 1
[    2.967676] dwc2 20980000.usb: irq 33, io mem 0x20980000
[    2.975632] hub 1-0:1.0: USB hub found
[    2.979988] hub 1-0:1.0: 1 port detected
[    2.986339] ALSA device list:
[    2.989722]   #0: vc4-hdmi
[    2.993466] uart-pl011 20201000.serial: no DMA platform data
[    3.002058] EXT4-fs (mmcblk0p2): couldn't mount as ext3 due to feature incompatibilities
[    3.017100] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
[    3.025066] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
[    3.559322] ------------[ cut here ]------------
[    3.564277] WARNING: CPU: 0 PID: 11 at drivers/gpu/drm/drm_atomic_helper.c:1129 drm_atomic_helper_wait_for_vblanks+0x1cc/0x218
[    3.576312] [CRTC:66:crtc-2] vblank wait timed out
[    3.581466] CPU: 0 PID: 11 Comm: kworker/0:1 Not tainted 4.11.0-rc5-next-20170404+ #52
[    3.589846] Hardware name: BCM2835
[    3.593464] Workqueue: events output_poll_execute
[    3.598485] [<c010e530>] (unwind_backtrace) from [<c010ba0c>] (show_stack+0x20/0x24)
[    3.606710] [<c010ba0c>] (show_stack) from [<c0377a3c>] (dump_stack+0x20/0x28)
[    3.614384] [<c0377a3c>] (dump_stack) from [<c011deb8>] (__warn+0xe0/0x10c)
[    3.621788] [<c011deb8>] (__warn) from [<c011df2c>] (warn_slowpath_fmt+0x48/0x50)
[    3.629736] [<c011df2c>] (warn_slowpath_fmt) from [<c03ffd30>] (drm_atomic_helper_wait_for_vblanks+0x1cc/0x218)
[    3.640415] [<c03ffd30>] (drm_atomic_helper_wait_for_vblanks) from [<c04311d4>] (vc4_atomic_complete_commit+0x64/0x9c)
[    3.651719] [<c04311d4>] (vc4_atomic_complete_commit) from [<c043140c>] (vc4_atomic_commit+0x200/0x220)
[    3.661671] [<c043140c>] (vc4_atomic_commit) from [<c041ef78>] (drm_atomic_commit+0x54/0x68)
[    3.670633] [<c041ef78>] (drm_atomic_commit) from [<c040439c>] (restore_fbdev_mode+0x120/0x264)
[    3.679864] [<c040439c>] (restore_fbdev_mode) from [<c0406c28>] (drm_fb_helper_restore_fbdev_mode_unlocked+0x3c/0x7c)
[    3.691089] [<c0406c28>] (drm_fb_helper_restore_fbdev_mode_unlocked) from [<c0406cb8>] (drm_fb_helper_set_par+0x50/0x6c)
[    3.702588] [<c0406cb8>] (drm_fb_helper_set_par) from [<c0406bd8>] (drm_fb_helper_hotplug_event+0x9c/0xb0)
[    3.712812] [<c0406bd8>] (drm_fb_helper_hotplug_event) from [<c0407688>] (drm_fbdev_cma_hotplug_event+0x20/0x24)
[    3.723582] [<c0407688>] (drm_fbdev_cma_hotplug_event) from [<c043146c>] (vc4_output_poll_changed+0x20/0x24)
[    3.733979] [<c043146c>] (vc4_output_poll_changed) from [<c03f9ad0>] (drm_kms_helper_hotplug_event+0x34/0x38)
[    3.744463] [<c03f9ad0>] (drm_kms_helper_hotplug_event) from [<c03f9c08>] (output_poll_execute+0x134/0x16c)
[    3.754768] [<c03f9c08>] (output_poll_execute) from [<c0132f48>] (process_one_work+0x1d0/0x37c)
[    3.763980] [<c0132f48>] (process_one_work) from [<c01333c8>] (worker_thread+0x294/0x414)
[    3.772652] [<c01333c8>] (worker_thread) from [<c0138744>] (kthread+0x13c/0x158)
[    3.780507] [<c0138744>] (kthread) from [<c01080f8>] (ret_from_fork+0x14/0x3c)
[    3.788115] ---[ end trace 9c912f086c1ffca2 ]---

lategoodbye commented 5 years ago

@nullr0ute Is this issue still reproducible with Fedora 29?

nullr0ute commented 5 years ago

This one seems to randomly pop up every now and again, we can probably close it but I've not idea if it's definitely fixed.

anholt / linux

crash in vc4 drm_atomic_helper_wait_for_vblank #66