c630: vblank timeout
Periodically chomium and/or electron apps will get supper laggy, accompanied by a lot of:
Sep 02 10:18:42 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:42 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:44 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:45 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:46 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:53 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:54 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout
Sep 02 10:18:56 thunkpad kernel: [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeoutI think chromium/electron wayland backend is doing something with vblank events (frame pacing?) and when this starts happening it stops getting vblank events?
Activity
added bug label
Yes, we should trigger devcoredump, but should guard it with using phys_enc->pending_kickoff_cnt otherwise it will be too many devcoredumps.
The catch though is, we could have 0-2 pending.
@pending_kickoff_cnt: Atomic counter tracking the number of kickoffs vs. the number of done/vblank irqs. Should hover between 0-2 Incremented when a new kickoff is scheduled. Decremented in irq handler
So, technically > 2 qualifies for a devcoredump. We should also dump only once. Need to come up with a nice condition for that.
Thanks
Abhinav
Edited by Abhinav Kumar@pending_kickoff_cnt: Atomic counter tracking the number of kickoffs vs. the number of done/vblank irqs. Should hover between 0-2 Incremented when a new kickoff is scheduled. Decremented in irq handler
not sure I understand that.. core drm should reject an atomic update touching CRTCs that are still pending the previous update.
The comment seems to indicate that if two kickoffs in a wq are scheduled without the vblank irq firing, it can happen due to scheduling. Not sure if we will ever hit that condition though.
Edited by Abhinav Kumarattached is a dpu devcore:
also, drm logs:
this apparently also manifests as "sluggish-mouse-cursor":
<exeat> Another instance of the sluggish-mouse-cursor problem on the x13s, "fixed" by a suspend+resume cycle: https://paste.debian.net/hidden/5444847c/[55422.872084] ------------[ cut here ]------------ [55422.872091] WARNING: CPU: 4 PID: 34085 at drivers/gpu/drm/msm/disp/dpu1/dpu_hw_interrupts.c:530 dpu_core_irq_register_callback+0x19c/0x20c [msm] [55422.872111] Modules linked in: snd_soc_wsa883x q6prm_clocks q6apm_lpass_dais q6apm_dai snd_q6dsp_common q6prm rfcomm algif_hash algif_skcipher af_alg bnep snd_q6apm dm_crypt qrtr_mhi cdc_ncm cdc_ether usbnet mii apr fastrpc rpmsg_ctrl rpmsg_char qrtr_smd venus_dec venus_enc videobuf2_dma_contig videobuf2_memops qcom_spmi_temp_alarm qcom_spmi_adc5 qcom_spmi_adc_tm5 qcom_pon industrialio nvmem_qcom_spmi_sdam reboot_mode qcom_vadc_common hci_uart wireguard btqca snd_soc_hdmi_codec libchacha20poly1305 bluetooth snd_soc_wcd938x snd_soc_sc8280xp snd_soc_qcom_common chacha_neon ecdh_generic snd_soc_qcom_sdw venus_core snd_soc_wcd_classh libchacha ath11k_pci ecc v4l2_mem2mem qcom_stats poly1305_neon snd_soc_wcd938x_sdw videobuf2_v4l2 ip6_udp_tunnel ath11k regmap_sdw videodev udp_tunnel snd_soc_lpass_rx_macro snd_soc_lpass_tx_macro snd_soc_lpass_va_macro mac80211 snd_soc_lpass_wsa_macro snd_soc_wcd_mbhc soundwire_qcom snd_soc_lpass_macro_common libcurve25519_generic videobuf2_common libarc4 mc snd_soc_core icc_bwmon [55422.872147] snd_compress cfg80211 qcom_q6v5_pas mhi snd_pcm qcom_pil_info snd_timer qcom_common snd qcom_glink_smem qcom_q6v5 soundcore qcom_rng qcom_wdt qcom_sysmon soundwire_bus icc_osm_l3 qcom_battmgr socinfo rfkill hid_multitouch nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables nfnetlink fuse dm_mod ipv6 qcom_pm8008_regulator qcom_pm8008 panel_edp regmap_i2c i2c_hid_of i2c_hid nvme nvme_core pmic_glink_altmode msm mdt_loader gpu_sched leds_qcom_lpg rtc_pm8xxx led_class_multicolor drm_display_helper phy_qcom_qmp_combo drm_dp_aux_bus drm_kms_helper gpio_sbu_mux phy_qcom_edp drm i2c_qcom_geni pinctrl_sc8280xp_lpass_lpi qrtr i2c_core videocc_sm8350 pinctrl_lpass_lpi lpasscc_sc8280xp typec phy_qcom_qmp_usb pcie_qcom phy_qcom_snps_femto_v2 phy_qcom_qmp_pcie crc8 pmic_glink pdr_interface qmi_helpers pwm_bl [55422.872202] CPU: 4 PID: 34085 Comm: kworker/u16:8 Tainted: G W 6.6.0-rc4-ge263c1c76d24 #1 [55422.872204] Hardware name: LENOVO 21BXCTO1WW/21BXCTO1WW, BIOS N3HET85W (1.57 ) 07/26/2023 [55422.872206] Workqueue: events_unbound commit_work [drm_kms_helper] [55422.872215] pstate: 204000c5 (nzCv daIF +PAN -UAO -TCO -DIT -SSBS BTYPE=--) [55422.872217] pc : dpu_core_irq_register_callback+0x19c/0x20c [msm] [55422.872225] lr : dpu_core_irq_register_callback+0x48/0x20c [msm] [55422.872232] sp : ffff80008a49bb20 [55422.872232] x29: ffff80008a49bb20 x28: 0000000000000001 x27: ffff0ec305107ad0 [55422.872235] x26: 0000000000000001 x25: 0000000000000020 x24: 0000000000000001 [55422.872237] x23: 0000000000000000 x22: ffff0ec30481a000 x21: ffffbf7a61de47d4 [55422.872239] x20: ffff0ec302254080 x19: 0000000000000017 x18: 0000000000000000 [55422.872241] x17: 0000000000000000 x16: ffffbf7a9b3a9010 x15: 0000000000000780 [55422.872243] x14: 0000000000000000 x13: ffff80008a49b838 x12: ffffbf7a61e331e8 [55422.872246] x11: 0000000000000040 x10: ffffbf7a9b8ace70 x9 : ffffbf7a9b8ace68 [55422.872248] x8 : ffffbf7a61c82000 x7 : 0000000000000000 x6 : 0000000000000000 [55422.872250] x5 : 0000000000000000 x4 : 0000000000000228 x3 : ffff0ec30481a000 [55422.872252] x2 : ffff0ec30481c228 x1 : 0000000000000000 x0 : ffffbf7a61de47d4 [55422.872255] Call trace: [55422.872257] dpu_core_irq_register_callback+0x19c/0x20c [msm] [55422.872264] dpu_encoder_phys_vid_control_vblank_irq+0x184/0x18c [msm] [55422.872272] dpu_encoder_phys_vid_irq_control+0x24/0x7c [msm] [55422.872280] _dpu_encoder_irq_control+0x60/0xac [msm] [55422.872287] dpu_encoder_resource_control+0x1ec/0x4a8 [msm] [55422.872294] dpu_encoder_prepare_for_kickoff+0x84/0x330 [msm] [55422.872302] dpu_crtc_commit_kickoff+0xe8/0x234 [msm] [55422.872309] dpu_kms_flush_commit+0x60/0x8c [msm] [55422.872317] msm_atomic_commit_tail+0x2a0/0x514 [msm] [55422.872325] commit_tail+0xa4/0x18c [drm_kms_helper] [55422.872329] commit_work+0x14/0x20 [drm_kms_helper] [55422.872333] process_one_work+0x138/0x248 [55422.872344] worker_thread+0x320/0x438 [55422.872347] kthread+0x110/0x114 [55422.872350] ret_from_fork+0x10/0x20 [55422.872355] ---[ end trace 0000000000000000 ]--- [55422.872357] [drm:dpu_encoder_phys_vid_control_vblank_irq [msm]] *ERROR* failed: id:35 intf:5 ret:-16 enable:1 refcnt:0 [55422.872370] ------------[ cut here ]------------ [55422.872371] WARNING: CPU: 4 PID: 34085 at drivers/gpu/drm/msm/disp/dpu1/dpu_encoder_phys_vid.c:625 dpu_encoder_phys_vid_irq_control+0x74/0x7c [msm] [55422.872379] Modules linked in: snd_soc_wsa883x q6prm_clocks q6apm_lpass_dais q6apm_dai snd_q6dsp_common q6prm rfcomm algif_hash algif_skcipher af_alg bnep snd_q6apm dm_crypt qrtr_mhi cdc_ncm cdc_ether usbnet mii apr fastrpc rpmsg_ctrl rpmsg_char qrtr_smd venus_dec venus_enc videobuf2_dma_contig videobuf2_memops qcom_spmi_temp_alarm qcom_spmi_adc5 qcom_spmi_adc_tm5 qcom_pon industrialio nvmem_qcom_spmi_sdam reboot_mode qcom_vadc_common hci_uart wireguard btqca snd_soc_hdmi_codec libchacha20poly1305 bluetooth snd_soc_wcd938x snd_soc_sc8280xp snd_soc_qcom_common chacha_neon ecdh_generic snd_soc_qcom_sdw venus_core snd_soc_wcd_classh libchacha ath11k_pci ecc v4l2_mem2mem qcom_stats poly1305_neon snd_soc_wcd938x_sdw videobuf2_v4l2 ip6_udp_tunnel ath11k regmap_sdw videodev udp_tunnel snd_soc_lpass_rx_macro snd_soc_lpass_tx_macro snd_soc_lpass_va_macro mac80211 snd_soc_lpass_wsa_macro snd_soc_wcd_mbhc soundwire_qcom snd_soc_lpass_macro_common libcurve25519_generic videobuf2_common libarc4 mc snd_soc_core icc_bwmon [55422.872411] snd_compress cfg80211 qcom_q6v5_pas mhi snd_pcm qcom_pil_info snd_timer qcom_common snd qcom_glink_smem qcom_q6v5 soundcore qcom_rng qcom_wdt qcom_sysmon soundwire_bus icc_osm_l3 qcom_battmgr socinfo rfkill hid_multitouch nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables nfnetlink fuse dm_mod ipv6 qcom_pm8008_regulator qcom_pm8008 panel_edp regmap_i2c i2c_hid_of i2c_hid nvme nvme_core pmic_glink_altmode msm mdt_loader gpu_sched leds_qcom_lpg rtc_pm8xxx led_class_multicolor drm_display_helper phy_qcom_qmp_combo drm_dp_aux_bus drm_kms_helper gpio_sbu_mux phy_qcom_edp drm i2c_qcom_geni pinctrl_sc8280xp_lpass_lpi qrtr i2c_core videocc_sm8350 pinctrl_lpass_lpi lpasscc_sc8280xp typec phy_qcom_qmp_usb pcie_qcom phy_qcom_snps_femto_v2 phy_qcom_qmp_pcie crc8 pmic_glink pdr_interface qmi_helpers pwm_bl [55422.872441] CPU: 4 PID: 34085 Comm: kworker/u16:8 Tainted: G W 6.6.0-rc4-ge263c1c76d24 #1 [55422.872443] Hardware name: LENOVO 21BXCTO1WW/21BXCTO1WW, BIOS N3HET85W (1.57 ) 07/26/2023 [55422.872444] Workqueue: events_unbound commit_work [drm_kms_helper] [55422.872449] pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--) [55422.872451] pc : dpu_encoder_phys_vid_irq_control+0x74/0x7c [msm] [55422.872458] lr : dpu_encoder_phys_vid_irq_control+0x24/0x7c [msm] [55422.872466] sp : ffff80008a49bba0 [55422.872466] x29: ffff80008a49bba0 x28: 0000000000000001 x27: ffff0ec305107ad0 [55422.872468] x26: 0000000000000001 x25: 0000000000000020 x24: 0000000000000001 [55422.872471] x23: ffff0ec304858d08 x22: ffff0ec304858d08 x21: 0000000000000001 [55422.872473] x20: ffff0ec304858c80 x19: ffff0ec30481a000 x18: ffffffffffffffff [55422.872475] x17: 6c696166202a524f x16: 5252452a205d5d6d x15: 736d5b207172695f [55422.872477] x14: 6b6e616c62765f6c x13: ffffbf7a9b8afa98 x12: 0000000000000a80 [55422.872480] x11: 0000000000000380 x10: ffffbf7a9b907a98 x9 : ffffbf7a9b8afa98 [55422.872482] x8 : 00000000ffffefff x7 : ffffbf7a9b907a98 x6 : 80000000fffff000 [55422.872484] x5 : ffff0ece7c010b88 x4 : 0000000000000000 x3 : 0000000000000000 [55422.872486] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 00000000fffffff0 [55422.872488] Call trace: [55422.872488] dpu_encoder_phys_vid_irq_control+0x74/0x7c [msm] [55422.872496] _dpu_encoder_irq_control+0x60/0xac [msm] [55422.872502] dpu_encoder_resource_control+0x1ec/0x4a8 [msm] [55422.872509] dpu_encoder_prepare_for_kickoff+0x84/0x330 [msm] [55422.872517] dpu_crtc_commit_kickoff+0xe8/0x234 [msm] [55422.872524] dpu_kms_flush_commit+0x60/0x8c [msm] [55422.872531] msm_atomic_commit_tail+0x2a0/0x514 [msm] [55422.872538] commit_tail+0xa4/0x18c [drm_kms_helper] [55422.872542] commit_work+0x14/0x20 [drm_kms_helper] [55422.872547] process_one_work+0x138/0x248 [55422.872549] worker_thread+0x320/0x438 [55422.872551] kthread+0x110/0x114 [55422.872554] ret_from_fork+0x10/0x20 [55422.872556] ---[ end trace 0000000000000000 ]--- [55423.021797] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55424.354175] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55426.078841] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55426.590956] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55427.606556] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55428.134915] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55430.603051] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55431.423274] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55432.459327] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55433.579416] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55434.962583] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55435.382588] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55436.022643] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55436.239278] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55436.751622] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55436.918692] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55437.938772] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55438.031529] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55438.131100] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55438.375539] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55438.691129] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55438.966831] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55440.720287] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55440.851123] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55440.946953] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55441.255722] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55441.451771] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55441.619617] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55441.855826] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55442.003902] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55445.048035] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55445.148045] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55446.743805] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55466.685382] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55469.961249] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55471.117280] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55471.297297] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55472.617027] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55474.193682] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55476.110459] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55476.941310] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55477.073340] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55477.169750] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55477.361928] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55477.514243] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55477.654057] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55477.814258] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55478.450961] PM: suspend entry (s2idle) [55478.456166] Filesystems sync: 0.005 seconds [55478.497977] Freezing user space processes [55478.499977] Freezing user space processes completed (elapsed 0.001 seconds) [55478.499988] OOM killer disabled. [55478.499991] Freezing remaining freezable tasks [55478.501217] Freezing remaining freezable tasks completed (elapsed 0.001 seconds) [55478.501222] printk: Suspending console(s) (use no_console_suspend to debug) [55478.530233] [drm:dpu_encoder_frame_done_timeout:2330] [dpu error]enc35 frame done timeout [55478.787725] dwc3-qcom a4f8800.usb: HS-PHY not in L2 [55479.226462] nvme nvme0: 8/0/0 default/read/poll queues [55480.434464] OOM killer enabled. [55480.434471] Restarting tasks ... done. [55480.437209] random: crng reseeded on system resumption [55480.473795] PM: suspend exit [55480.662073] [drm:dpu_encoder_helper_report_irq_timeout [msm]] *ERROR* irq timeout id=35, intf_mode=INTF_MODE_VIDEO intf=5 wb=-1, pp=0, intr=0 [55480.662171] [drm:dpu_encoder_phys_vid_disable [msm]] *ERROR* wait disable failed: id:35 intf:5 ret:-110assigned to @quic_parellan
I think I've found a way to trigger this, but I'm not entirely sure. I noticed that as I was running builds of mutter to apply https://gitlab.gnome.org/GNOME/mutter/-/merge_requests/3428 to the debian 45.1 package, I was pretty frequently experiencing the issue.
At the time of running the builds, I was in an Xorg GNOME 45 session, and I had 1 Firefox, 1 Chromium, 2 alacritty and 2 sublime-text windows open. I had downloaded the above merge as 3428.patch. This did require some setup because I was building in an sbuild chroot, but I do believe that just running the mutter test suite should trigger it. I had to rebuild the package a number of times due to flaky tests, and at some point the system became extremely sluggish despite plenty of ram, when I ran
dmesgI noticed similar output.My dmesg output is at https://paste.debian.net/1299631/ (I believe it's far too large to post in a comment, but if preferred, I can download it and attach it as a text file)
Edited by Steev Klimaszewskihttps://patchwork.freedesktop.org/patch/571854/ has been pushed to address this (both the warning and the associated timeouts).
We didnt find a good way to reproduce this but the fix is reasonable.
This will be included with the changes for 6.8
Hence @robclark @steev1 please let us know if you hit this post 6.8
Thanks
Abhinav
On the sc8280xp, with this patch, everything seems good, however, on my sdm845 (Lenovo Yoga C630), I am seeing
[ 23.462045] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 23.462057] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 23.686070] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 23.686098] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 23.742412] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 23.742428] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 23.874056] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 23.874165] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 23.930082] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 23.930108] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 23.986085] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 23.986101] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.042207] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.042235] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.162049] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.162065] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.218073] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.218101] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.274055] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.274082] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.330460] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.330493] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.418054] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.418081] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.470187] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.470214] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.654078] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout [ 24.654105] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110when GDM first loads; restarting GDM, starting Sway, or logging in or out of GNOME does not reproduce the messages.
@lumag do you think you can try to recreate this on your device? Thanks. -Paloma
@lumag on the X13s this patch seems fine, but on the C630 is where I see those messages with it
@steev1 could you possibly be able to reproduce the issue with this debugging patch.
I have observed timeouts on SDM660 when the display is switching from split mode (for LM_0+LM_1) to single-LM mode.
diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_encoder_phys_vid.c b/drivers/gpu/drm/msm/disp/dpu1/dpu_encoder_phys_vid.c index d0f56c5c4cce..fb34067ab6af 100644 --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_encoder_phys_vid.c +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_encoder_phys_vid.c @@ -489,7 +489,7 @@ static int dpu_encoder_phys_vid_wait_for_commit_done( (hw_ctl->ops.get_flush_register(hw_ctl) == 0), msecs_to_jiffies(50)); if (ret <= 0) { - DPU_ERROR("vblank timeout\n"); + DPU_ERROR("vblank timeout: %x\n", hw_ctl->ops.get_flush_register(hw_ctl)); return -ETIMEDOUT; }[ 23.779699] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 23.779715] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.006727] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.006754] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.063096] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.063124] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.202856] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.202884] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.258733] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.258761] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.322730] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.322758] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.379502] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.379531] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.434737] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.434770] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.490749] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.490774] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.546730] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.546757] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.602713] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 24.602741] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 24.670735] usb 1-1.3: new high-speed USB device number 5 using xhci-hcd [ 24.856123] usb 1-1.3: Found UVC 1.00 device Integrated Camera (5986:2115) [ 37.587020] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 37.587064] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 37.643017] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 37.643101] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 41.123000] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 41.123045] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 41.177120] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 41.177215] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 97.589899] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 97.589932] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110 [ 97.649251] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 97.649293] [drm:dpu_kms_wait_for_commit_done:495] [dpu error]wait for commit done returned -110My sincerest apologies... I didn't realize I was still on the 6.6 kernel... with 6.7.0-rc8, i do not see these messages on the C630.
And now a few reboots later... it came back, same output -
[ 38.927251] ti_sn65dsi86 10-002c: [drm:ti_sn_bridge_atomic_enable [ti_sn65dsi86]] *ERROR* Can't read lane count (-5); assuming 4 [ 39.122284] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.122302] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.305956] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.305990] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.361907] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.361932] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.433983] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.434015] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.489920] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.489951] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.769938] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.769977] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.829886] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.829902] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.885912] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.885929] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.941969] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.941996] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 39.997913] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 39.997943] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.053894] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.053921] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.110009] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.110040] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.165804] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.165835] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.225953] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.225984] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.281905] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.281934] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.341908] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.341938] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.397931] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.397958] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.453910] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.453948] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.513927] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.513956] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.570114] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.570145] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.625942] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.625974] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.682225] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.682256] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.738208] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.738225] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 [ 40.801925] [drm:dpu_encoder_phys_vid_wait_for_commit_done:496] [dpu error]vblank timeout: 1000000 [ 40.801956] [drm:dpu_kms_wait_for_commit_done:494] [dpu error]wait for commit done returned -110 steev@limitless:~$ uname -a Linux limitless 6.7.0-rc8 #8 SMP PREEMPT Sat Jan 6 05:37:03 EET 2024 aarch64 GNU/LinuxEdited by Steev Klimaszewski
Please register or sign in to reply