Bug 93782 - [i9xx TV][BISECT] vblank wait timeout on crtc
Summary: [i9xx TV][BISECT] vblank wait timeout on crtc
Status: RESOLVED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: XOrg git
Hardware: x86-64 (AMD64) Linux (All)
: low normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords: bisected
: 96441 100907 103812 105878 106422 108728 108747 109776 (view as bug list)
Depends on:
Blocks:
 
Reported: 2016-01-19 21:47 UTC by guido
Modified: 2019-05-31 17:53 UTC (History)
35 users (show)

See Also:
i915 platform: I965GM
i915 features: display/atomic


Attachments
dmesg with drm.debug output (192.64 KB, text/plain)
2016-02-02 21:56 UTC, willma
no flags Details
debug output with drm.debug=0x3e (184.81 KB, text/plain)
2016-05-17 23:40 UTC, andram
no flags Details
dmesg as before, but with edde361 reverted (113.67 KB, text/plain)
2016-05-17 23:41 UTC, andram
no flags Details
Disable cxsr hack. (522 bytes, patch)
2016-05-18 05:24 UTC, Maarten Lankhorst
no flags Details | Splinter Review
dmesg with patch enable = false (185.49 KB, text/plain)
2016-05-19 21:46 UTC, andram
no flags Details
dmesg as before with timeout set to 500 (238.89 KB, text/plain)
2016-05-19 21:47 UTC, andram
no flags Details
dmesg Linux 4.9 with disabled cxsr hack (11.40 KB, text/plain)
2016-12-22 09:19 UTC, Felix Schwarz
no flags Details
dmesg Linux 4.9 with disabled cxsr hack (and DRM debug infos) (369.19 KB, text/plain)
2016-12-22 22:12 UTC, Felix Schwarz
no flags Details
Patch to get rid of vblank warnings (2.85 KB, patch)
2016-12-23 01:42 UTC, andram
no flags Details | Splinter Review
dmesg from old MacBook running lubuntu 18.04 (100.66 KB, text/plain)
2018-10-18 19:28 UTC, Stefan Brozinski
no flags Details

Description guido 2016-01-19 21:47:17 UTC
I am getting the following kernel warning with an Intel GM965/GL960 Integrated Graphics Controller:

Jan 19 22:38:43 lo45p kernel: [ 2791.152065] ------------[ cut here ]------------
Jan 19 22:38:43 lo45p kernel: [ 2791.152084] WARNING: CPU: 0 PID: 1768 at drivers/gpu/drm/drm_irq.c:1268 drm_wait_one_vblank+0x200/0x210 [drm]()
Jan 19 22:38:43 lo45p kernel: [ 2791.152087] vblank wait timed out on crtc 1
Jan 19 22:38:43 lo45p kernel: [ 2791.152089] Modules linked in: fuse arc4 i915 iwl4965 iwlegacy mac80211 btusb btrtl btbcm btintel bluetooth i2c_algo_bit cfg80211 drm_kms_helper snd_hda_codec_hdmi snd_hda_codec_realtek uvcvideo snd_hda_codec_generic drm coretemp acer_wmi snd_hda_intel sparse_keymap videobuf2_vmalloc snd_hda_codec irda videobuf2_v4l2 iTCO_wdt iTCO_vendor_support sdhci_pci sdhci videobuf2_core joydev tg3 pcspkr snd_hda_core videobuf2_memops mmc_core serio_raw v4l2_common tifm_7xx1 i2c_i801 videodev tifm_core snd_hwdep
ptp rfkill firewire_ohci ata_generic firewire_core pata_acpi syscopyarea media yenta_socket crc_itu_t sysfillrect sysimgblt wmi lpc_ich pps_core snd_pcm fb_sys_fops nfsd acpi_cpufreq video fjes shpchp crc_ccitt snd_timer snd soundcore tpm_tis tpm auth_rpcgss nfs_acl lockd grace sunrpc dm_crypt
Jan 19 22:38:43 lo45p kernel: [ 2791.152180] CPU: 0 PID: 1768 Comm: X Tainted: G        W       4.4.0 #1
Jan 19 22:38:43 lo45p kernel: [ 2791.152184] Hardware name: Acer            TravelMate 7720                /Tangiz                         , BIOS V1.35           07/03/2008
Jan 19 22:38:43 lo45p kernel: [ 2791.152187]  0000000000000000 000000001ba283c8 ffff8800b58b7890 ffffffff8145918f
Jan 19 22:38:43 lo45p kernel: [ 2791.152193]  ffffffffa03de632 ffff8800b58b7910 ffffffff81098858 ffffffffa03e1270
Jan 19 22:38:43 lo45p kernel: [ 2791.152198]  ffffffff00000020 ffff8800b58b7920 ffff8800b58b78c8 000000001ba283c8
Jan 19 22:38:43 lo45p kernel: [ 2791.152204] Call Trace:
Jan 19 22:38:43 lo45p kernel: [ 2791.152210]  [<ffffffff8145918f>] dump_stack+0x44/0x55
Jan 19 22:38:43 lo45p kernel: [ 2791.152215]  [<ffffffff81098858>] warn_slowpath_fmt+0xb8/0x140
Jan 19 22:38:43 lo45p kernel: [ 2791.152231]  [<ffffffffa03a5410>] drm_wait_one_vblank+0x200/0x210 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152236]  [<ffffffff810e6570>] ? wake_atomic_t_function+0x70/0x70
Jan 19 22:38:43 lo45p kernel: [ 2791.152273]  [<ffffffffa077ef0b>] i9xx_crtc_disable+0x3b/0x5e0 [i915]
Jan 19 22:38:43 lo45p kernel: [ 2791.152309]  [<ffffffffa0783c8e>] intel_atomic_commit+0x5ae/0x16c0 [i915]
Jan 19 22:38:43 lo45p kernel: [ 2791.152332]  [<ffffffffa03c9435>] ? drm_atomic_check_only+0x185/0x580 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152355]  [<ffffffffa03c8ca2>] ? drm_atomic_get_crtc_state+0x32/0xd0 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152366]  [<ffffffffa0483d98>] ? __drm_atomic_helper_plane_duplicate_state+0x68/0x70 [drm_kms_helper]
Jan 19 22:38:43 lo45p kernel: [ 2791.152388]  [<ffffffffa03c9867>] drm_atomic_commit+0x37/0x60 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152425]  [<ffffffffa078a5ba>] intel_release_load_detect_pipe+0x12a/0x1d0 [i915]
Jan 19 22:38:43 lo45p kernel: [ 2791.152468]  [<ffffffffa07d6490>] intel_tv_detect+0x320/0x6e0 [i915]
Jan 19 22:38:43 lo45p kernel: [ 2791.152476]  [<ffffffffa047ae08>] drm_helper_probe_single_connector_modes_merge_bits+0x328/0x8c0 [drm_kms_helper]
Jan 19 22:38:43 lo45p kernel: [ 2791.152482]  [<ffffffffa047b3b3>] drm_helper_probe_single_connector_modes+0x13/0x20 [drm_kms_helper]
Jan 19 22:38:43 lo45p kernel: [ 2791.152498]  [<ffffffffa03b5d1d>] drm_mode_getconnector+0x3ad/0x430 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152509]  [<ffffffffa03a3182>] drm_ioctl+0x152/0x540 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152524]  [<ffffffffa03b5970>] ? drm_mode_getcrtc+0x1a0/0x1a0 [drm]
Jan 19 22:38:43 lo45p kernel: [ 2791.152528]  [<ffffffff813ce38e>] ? selinux_file_ioctl+0x10e/0x3a0
Jan 19 22:38:43 lo45p kernel: [ 2791.152532]  [<ffffffff81297bc8>] do_vfs_ioctl+0x298/0x4c0
Jan 19 22:38:43 lo45p kernel: [ 2791.152536]  [<ffffffff813c1373>] ? security_file_ioctl+0x43/0x60
Jan 19 22:38:43 lo45p kernel: [ 2791.152539]  [<ffffffff81297e69>] SyS_ioctl+0x79/0x90
Jan 19 22:38:43 lo45p kernel: [ 2791.152542]  [<ffffffff81913617>] entry_SYSCALL_64_fastpath+0x12/0x6a
Jan 19 22:38:43 lo45p kernel: [ 2791.152545] ---[ end trace 15f5e94e3f9404d9 ]---
Comment 1 willma 2016-02-02 21:56:45 UTC
Created attachment 121476 [details]
dmesg with drm.debug output
Comment 2 willma 2016-02-02 22:00:59 UTC
I'm getting the same error also with a GM965/GL960 controller.

Hardware:
Dell Latitude D630

Architecture:
X86_64

Kernel:
4.4.1-300.vanilla.knurd.1.fc23.x86_64

Distribution:
Fedora 23

lspci:
00:00.0 Host bridge: Intel Corporation Mobile PM965/GM965/GL960 Memory Controller Hub (rev 0c)
00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (primary) (rev 0c)
00:02.1 Display controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (secondary) (rev 0c)
00:1a.0 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #4 (rev 02)
00:1a.1 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #5 (rev 02)
00:1a.7 USB controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI Controller #2 (rev 02)
00:1b.0 Audio device: Intel Corporation 82801H (ICH8 Family) HD Audio Controller (rev 02)
00:1c.0 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 1 (rev 02)
00:1c.1 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 2 (rev 02)
00:1c.5 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 6 (rev 02)
00:1d.0 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #1 (rev 02)
00:1d.1 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #2 (rev 02)
00:1d.2 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #3 (rev 02)
00:1d.7 USB controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI Controller #1 (rev 02)
00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev f2)
00:1f.0 ISA bridge: Intel Corporation 82801HM (ICH8M) LPC Interface Controller (rev 02)
00:1f.1 IDE interface: Intel Corporation 82801HM/HEM (ICH8M/ICH8M-E) IDE Controller (rev 02)
00:1f.2 SATA controller: Intel Corporation 82801HM/HEM (ICH8M/ICH8M-E) SATA Controller [AHCI mode] (rev 02)
00:1f.3 SMBus: Intel Corporation 82801H (ICH8 Family) SMBus Controller (rev 02)
03:01.0 CardBus bridge: O2 Micro, Inc. Cardbus bridge (rev 21)
03:01.4 FireWire (IEEE 1394): O2 Micro, Inc. Firewire (IEEE 1394) (rev 02)
09:00.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5755M Gigabit Ethernet PCI Express (rev 02)
0c:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)
Comment 3 Felix Schwarz 2016-02-05 13:17:20 UTC
Same here with kernel 4.5.0-0.rc2.git1.1.vanilla.knurd.1.fc23.x86_64
Comment 4 Christian Reis 2016-04-15 17:36:56 UTC
Could this be a dupe of bug 93509?
Comment 5 andram 2016-05-08 23:52:54 UTC
Get a similar warning. I have bisected my problem to the following kernel patch:

commit edde361711ef8f396e401b25d970e329f68bec0b
Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
Date:   Wed Feb 17 09:18:35 2016 +0100

    drm/i915: Use atomic state to obtain load detection crtc, v3.
    
    Instead of restoring dpms and a flag for whether a temp fb is allocated duplicate
    an atomic state before the new state is committed, and commit it the old state
    in intel_release_load_detect_pipe.
    
    Changes since v1:
    - Use a real atomic state. (Ville)
    Changes since v2:
    - Do not preserve shared_dpll any more, no need to do so. (Ville)
    
    Signed-off-by: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
    Reviewed-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
    Link: http://patchwork.freedesktop.org/patch/msgid/1455697119-31416-2-git-send-email-maarten.lankhorst@linux.intel.com

This leads to the following dmesg warnings for me:

[   10.613368] ------------[ cut here ]------------
[   10.613396] WARNING: CPU: 0 PID: 89 at drivers/gpu/drm/drm_irq.c:1268 drm_wait_one_vblank+0x170/0x180 [drm]()
[   10.613406] vblank wait timed out on crtc 0
[   10.613412] Modules linked in: coretemp evdev input_leds psmouse serio_raw pcspkr snd_hda_codec_hdmi snd_hda_codec_analog snd_hda_codec_generic lpc_ich mfd_core ssb mmc_core fan thermal wmi battery i915 snd_hda_intel i2c_algo_bit drm_kms_helper snd_hda_codec syscopyarea sysfillrect sysimgblt fb_sys_fops snd_hwdep hp_accel snd_hda_core lis3lv02d e1000e snd_pcm input_polldev led_class video snd_timer ptp drm intel_agp ac pps_core intel_gtt snd acpi_cpufreq soundcore agpgart button processor ip_tables x_tables ext4 crc16 mbcache jbd2 jitterentropy_rng sha256_generic hmac drbg ansi_cprng xts gf128mul algif_skcipher af_alg dm_crypt dm_mod sr_mod cdrom sd_mod ata_generic pata_acpi atkbd libps2 ata_piix ahci libahci libata scsi_mod ehci_pci uhci_hcd ehci_hcd usbcore usb_common i8042 serio
[   10.613531] CPU: 0 PID: 89 Comm: kworker/u4:4 Not tainted 4.5.0-rc3-AA-00365-gedde361 #32
[   10.613540] Hardware name: Hewlett-Packard HP 550/3618, BIOS 68MVU Ver. F.02 08/20/2008
[   10.613553] Workqueue: events_unbound async_run_entry_fn
[   10.613560]  00000286 00000286 f478dba8 c12681cf f478dbe8 f8382c65 f478dbd8 c105502d
[   10.613574]  f8385128 f478dc04 00000059 f8382c65 000004f4 f835a620 f835a620 f441b000
[   10.613587]  00000000 00000000 f478dbf0 c10550a3 00000009 f478dbe8 f8385128 f478dc04
[   10.613600] Call Trace:
[   10.613609]  [<c12681cf>] dump_stack+0x58/0x79
[   10.613616]  [<c105502d>] warn_slowpath_common+0x8d/0xd0
[   10.613628]  [<f835a620>] ? drm_wait_one_vblank+0x170/0x180 [drm]
[   10.613638]  [<f835a620>] ? drm_wait_one_vblank+0x170/0x180 [drm]
[   10.613645]  [<c10550a3>] warn_slowpath_fmt+0x33/0x40
[   10.613656]  [<f835a620>] drm_wait_one_vblank+0x170/0x180 [drm]
[   10.613665]  [<c1091cc0>] ? wake_atomic_t_function+0x70/0x70
[   10.613726]  [<f8657452>] intel_get_load_detect_pipe+0x762/0x7e0 [i915]
[   10.613774]  [<f869412a>] intel_tv_detect+0x1aa/0x6d0 [i915]
[   10.613786]  [<f836eb05>] ? drm_get_edid+0x25/0x3e0 [drm]
[   10.613798]  [<f8393b80>] drm_helper_probe_single_connector_modes+0x2f0/0x520 [drm_kms_helper]
[   10.613810]  [<f83a0c88>] drm_fb_helper_initial_config+0x88/0x400 [drm_kms_helper]
[   10.613854]  [<f8669789>] intel_fbdev_initial_config+0x19/0x30 [i915]
[   10.613862]  [<c1072539>] async_run_entry_fn+0x49/0x170
[   10.613870]  [<c106ad6e>] process_one_work+0x1ae/0x410
[   10.613877]  [<c106b007>] worker_thread+0x37/0x490
[   10.613883]  [<c106afd0>] ? process_one_work+0x410/0x410
[   10.613890]  [<c10700cb>] kthread+0x9b/0xb0
[   10.613899]  [<c1494689>] ret_from_kernel_thread+0x21/0x38
[   10.613905]  [<c1070030>] ? kthread_worker_fn+0x130/0x130
[   10.613912] ---[ end trace 1da52df1c4cdc7e7 ]---
Comment 6 andram 2016-05-09 19:58:09 UTC
Just to confirm that this bug is still present in Linux 4.6-rc7. A simple 

     git revert edde361

fixes it for me.
Comment 7 Jani Nikula 2016-05-10 08:01:02 UTC
(In reply to andram from comment #6)
> Just to confirm that this bug is still present in Linux 4.6-rc7. A simple 
> 
>      git revert edde361
> 
> fixes it for me.

commit edde361711ef8f396e401b25d970e329f68bec0b
Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
Date:   Wed Feb 17 09:18:35 2016 +0100

    drm/i915: Use atomic state to obtain load detection crtc, v3.
Comment 8 Maarten Lankhorst 2016-05-11 10:15:25 UTC
Could you post a drm.debug=0x3e log with and without revert?
Comment 9 andram 2016-05-17 23:40:06 UTC
Created attachment 123855 [details]
debug output with drm.debug=0x3e
Comment 10 andram 2016-05-17 23:41:29 UTC
Created attachment 123856 [details]
dmesg as before, but with edde361 reverted
Comment 11 andram 2016-05-17 23:43:43 UTC
Requested attachments are created. Let me know if you need further info.
Comment 12 Maarten Lankhorst 2016-05-18 05:24:12 UTC
Created attachment 123865 [details] [review]
Disable cxsr hack.

Well, this looks weird..


The original log shows that load detection doesn't work at all:

[    0.645655] [drm:update_connector_routing] [CONNECTOR:38:SVIDEO-1] using [ENCODER:39:TV-39] on [CRTC:26:crtc-0]
[    0.645657] [drm:drm_atomic_helper_check_modeset] [CRTC:26:crtc-0] active changed
[    0.645660] [drm:drm_atomic_helper_check_modeset] [CRTC:26:crtc-0] needs all connectors, enable: y, active: y
[    0.645662] [drm:drm_atomic_add_affected_connectors] Adding all current connectors for [CRTC:26:crtc-0] to f47fb800
[    0.645664] [drm:drm_atomic_helper_check_modeset] [CRTC:26:crtc-0] enabled/connectors mismatch
[    0.645666] [drm:intel_get_load_detect_pipe] failed to set mode on load-detect pipe

While the modified log shows no vblank for ~200 ms. It also enables cxsr,
and the counter was running before so lets see if there was an issue with that.. can you try attached patch?

If this doesn't work, can you try change the timeout in drivers/gpu/drm/drm_irq.c drm_wait_one_vblank from 100 msecs to 500?
Comment 13 Davide 2016-05-19 10:32:20 UTC
Hi, I have the same issue and I tried with both patches* (for intel_pm.c and drm_irq.c).
Neither of them has worked for me.

*Applied to 4.4.3
Comment 14 Felix Schwarz 2016-05-19 11:00:29 UTC
(In reply to Davide from comment #13)
> Hi, I have the same issue and I tried with both patches* (for intel_pm.c and
> drm_irq.c).
> Neither of them has worked for me.

I think there might be multiple issues here. The commit identified by andram only applies to the 4.6 kernel but the initial report was about version 4.4. Reverting commit edde361 did not fix the problem for me either.

However as Maarten started to investigate the bug based on edde361 I think it's best to let him proceed here without distractions about "same symptom - maybe other cause". I started to bisect the problem myself but I'll file a separate issue when I'm done in order not to spam this report here.
Comment 15 andram 2016-05-19 21:46:24 UTC
Created attachment 123928 [details]
dmesg with patch enable = false

dmesg with patch 123865: Disable cxsr hack.
Comment 16 andram 2016-05-19 21:47:49 UTC
Created attachment 123929 [details]
dmesg as before with timeout set to 500
Comment 17 andram 2016-05-19 21:53:09 UTC
(In reply to Maarten Lankhorst from comment #12)
> While the modified log shows no vblank for ~200 ms. It also enables cxsr,
> and the counter was running before so lets see if there was an issue with
> that.. can you try attached patch?

I applied it, but still get the "vblank wait timed out on crtc 0". Dmesg is attached as "enable_false_dmesg"

> If this doesn't work, can you try change the timeout in
> drivers/gpu/drm/drm_irq.c drm_wait_one_vblank from 100 msecs to 500?

Unfortunately this did not help either, see attached dmesg (timeout_500_dmesg). 

Any other ideas, what I can try?
Comment 18 andram 2016-05-22 19:37:23 UTC
One more data point on this:

I notice that the "vblank wait timed out on crtc 0" warning is apparently triggered by switching from the linux console to the X server.  This is either at booting, when the X-server starts for the first time, or when I switch to the console and back to X manually using Ctrl-Alt-F1 followed by Alt-F7. 

For one switch I get typically three such warnings with call traces, and there is a clear delay of about a second before X is responsive again after the switch.  Any keys presseed during this time are swallowed. Then there is a short flicker of the whole screen just before X is again responsive to kbd and mouse input.
Comment 19 elupus 2016-05-28 19:42:29 UTC
Indeed i can second the VT switch comment. I can trigger the hang with a:
sudo chvt 1
sudo chvt 7

Linux htpc 4.4.0-22-generic #40-Ubuntu SMP Thu May 12 22:03:15 UTC 2016 i686 i686 i686 GNU/Linux
On Ubuntu 16.04
Comment 20 Till Schäfer 2016-09-25 19:17:18 UTC
I am also seeing this dmesg warning when switching tty. However, it does not only be related to the kernel. I have used the 4.4.6 kernel with xorg server 1.17.4, mesa 11.0.6 and intel driver 2.99.917 without any issues (I am not 100% sure that this does not happened before, but i look quite regular at the dmesg and do not remember to see a stack trace popping up. 

Now after updating to xorg server 1.18.4 with mesa 12.0.1 and intel driver 2.99.917_p20160621-r1 (snapshot for gentoo) the vblank timeout occurs. 

Furthermore, i have notices some display freezes (programs seem to react, but the display is not updated). I do not know if this is related. 

I have then also tested kernels 4.4.21 and 4.7.5, both show the vblank warning. 

Hardware: I am also using the Dell D630 Laptop with Intel 965GM graphics.



[   55.375183] ------------[ cut here ]------------
[   55.375205] WARNING: CPU: 1 PID: 3609 at drivers/gpu/drm/drm_irq.c:1318 drm_wait_one_vblank+0x131/0x180
[   55.375209] vblank wait timed out on crtc 0
[   55.375212] Modules linked in: iwl4965 iwlegacy
[   55.375227] CPU: 1 PID: 3609 Comm: X Tainted: G        W       4.7.5-gentoo #1
[   55.375231] Hardware name: Dell Inc. Latitude D630                   /0KU184, BIOS A17 01/04/2010
[   55.375236]  0000000000000000 ffffffff8144a38d ffff8800d6013910 0000000000000000
[   55.375244]  ffffffff810daeaf 0000000000000000 ffff8800d6013960 0000000000000000
[   55.375252]  0000000000000014 ffff8800da17b608 0000000000000001 ffffffff810daf1a
[   55.375260] Call Trace:
[   55.375272]  [<ffffffff8144a38d>] ? dump_stack+0x46/0x59
[   55.375280]  [<ffffffff810daeaf>] ? __warn+0xbf/0xe0
[   55.375286]  [<ffffffff810daf1a>] ? warn_slowpath_fmt+0x4a/0x50
[   55.375293]  [<ffffffff81985c72>] ? _raw_spin_lock_irqsave+0x12/0x40
[   55.375299]  [<ffffffff81523af1>] ? drm_wait_one_vblank+0x131/0x180
[   55.375307]  [<ffffffff81115770>] ? wait_woken+0x80/0x80
[   55.375316]  [<ffffffff815b8ce5>] ? intel_pre_plane_update+0x145/0x170
[   55.375322]  [<ffffffff815b94f6>] ? intel_atomic_commit+0x336/0x12d0
[   55.375330]  [<ffffffff8153a715>] ? drm_atomic_check_only+0x145/0x640
[   55.375335]  [<ffffffff81985a8f>] ? _raw_spin_unlock_irqrestore+0xf/0x30
[   55.375342]  [<ffffffff815bf8c1>] ? intel_release_load_detect_pipe+0x21/0x80
[   55.375350]  [<ffffffff815fa236>] ? intel_tv_detect+0x326/0x570
[   55.375360]  [<ffffffff81510234>] ? drm_helper_probe_single_connector_modes+0x2c4/0x4d0
[   55.375368]  [<ffffffff8152e629>] ? drm_mode_getconnector+0x319/0x360
[   55.375374]  [<ffffffff810fd2c9>] ? preempt_count_add+0x99/0xa0
[   55.375381]  [<ffffffff81521de1>] ? drm_ioctl+0x121/0x490
[   55.375387]  [<ffffffff8152e310>] ? drm_mode_getcrtc+0x120/0x120
[   55.375395]  [<ffffffff812208c6>] ? do_vfs_ioctl+0x86/0x5b0
[   55.375402]  [<ffffffff812146bf>] ? SyS_newfstat+0x1f/0x30
[   55.375409]  [<ffffffff8122aa4b>] ? __fget+0x6b/0xb0
[   55.375414]  [<ffffffff81220e26>] ? SyS_ioctl+0x36/0x70
[   55.375420]  [<ffffffff81001a5c>] ? syscall_trace_enter_phase2+0x12c/0x210
[   55.375425]  [<ffffffff81001cdd>] ? do_syscall_64+0x4d/0x100
[   55.375431]  [<ffffffff819860fc>] ? entry_SYSCALL64_slow_path+0x25/0x25
[   55.375436] ---[ end trace da2e91405d3d4515 ]---
Comment 21 Erik Koennecke 2016-10-24 21:17:29 UTC
The bug is still in 4.9.0-rc2, on a Dell Latitude D830 with i915 graphics. It gets triggered during the boot process 14 times and is delaying considerably, sometimes freezing the machine.

[   12.100251] ------------[ cut here ]------------
[   12.100292] WARNING: CPU: 0 PID: 6 at /home/kernel/COD/linux/drivers/gpu/drm/drm_irq.c:1252 drm_wait_one_vblank+0x1aa/0x1b0 [drm]
[   12.100294] vblank wait timed out on crtc 0
[   12.100295] Modules linked in: uas usb_storage psmouse ahci libahci firewire_ohci pata_acpi firewire_core crc_itu_t tg3 ptp pps_core i915 wmi i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt video fb_sys_fops drm
[   12.100329] CPU: 0 PID: 6 Comm: kworker/u4:0 Not tainted 4.9.0-040900rc2-generic #201610232131
[   12.100331] Hardware name: Dell Inc. Latitude D830                   /0HN341, BIOS A17 06/19/2013
[   12.100339] Workqueue: events_unbound async_run_entry_fn
[   12.100342]  ffffaf220065f9d0 ffffffff86416f32 ffffaf220065fa20 0000000000000000
[   12.100348]  ffffaf220065fa10 ffffffff860835ab 000004e49276e000 ffff8a7992730000
[   12.100354]  0000000000000000 0000000000000000 0000000001000001 ffff8a799271fc08
[   12.100359] Call Trace:
[   12.100367]  [<ffffffff86416f32>] dump_stack+0x63/0x81
[   12.100372]  [<ffffffff860835ab>] __warn+0xcb/0xf0
[   12.100376]  [<ffffffff8608362f>] warn_slowpath_fmt+0x5f/0x80
[   12.100383]  [<ffffffff860c82d6>] ? finish_wait+0x56/0x70
[   12.100405]  [<ffffffffc02a1a2a>] drm_wait_one_vblank+0x1aa/0x1b0 [drm]
[   12.100408]  [<ffffffff860c86f0>] ? wake_atomic_t_function+0x60/0x60
[   12.100487]  [<ffffffffc040fb4b>] intel_get_load_detect_pipe+0x5fb/0x610 [i915]
[   12.100518]  [<ffffffffc044b0b5>] intel_tv_detect+0x155/0x550 [i915]
[   12.100525]  [<ffffffffc034315f>] drm_helper_probe_single_connector_modes+0x3ff/0x4f0 [drm_kms_helper]
[   12.100537]  [<ffffffffc0351a8e>] drm_fb_helper_initial_config+0xae/0x430 [drm_kms_helper]
[   12.100565]  [<ffffffffc0424d88>] intel_fbdev_initial_config+0x18/0x30 [i915]
[   12.100566]  [<ffffffff860a7d37>] async_run_entry_fn+0x37/0x150
[   12.100568]  [<ffffffff8609e40c>] process_one_work+0x1fc/0x4b0
[   12.100569]  [<ffffffff8609e70b>] worker_thread+0x4b/0x500
[   12.100571]  [<ffffffff8609e6c0>] ? process_one_work+0x4b0/0x4b0
[   12.100573]  [<ffffffff860a4a69>] kthread+0xd9/0xf0
[   12.100575]  [<ffffffff860a4990>] ? kthread_park+0x60/0x60
[   12.100577]  [<ffffffff86890f35>] ret_from_fork+0x25/0x30
[   12.100579] ---[ end trace 6070e1592611415d ]---
[   12.245461] ------------[ cut here ]------------
Comment 22 Mariusz Mazur 2016-11-01 11:41:47 UTC
Original bug report was against 4.4.0 on GM965/GL960, so the commit indicated in the comments is likely a separate issue. I've checked a few kernels (using http://kernel.ubuntu.com/~kernel-ppa/mainline/ builds) and the one that's definitively stable and which I'm using right now (on my old GM965 laptop) is 4.1.35.

My initial tests indicated that this problem was immediately noticeable on 4.4 and up (it was enough to boot without X and check dmesg|grep vblank), but not on 4.3.6, though the latter showed some issues when waking up from sleep, so I'm not 100% it's not present.

Bottom line: my initial test indicate that this issue was definitively introduced somewhere between 4.2 and 4.4, likely in 4.4. Once I have some more time and learn how to efficiently use bisect on ubuntu, I'll pinpoint the precise commit.
Comment 23 Mariusz Mazur 2016-11-01 22:02:53 UTC
I don't see myself having much success (or time for) bisecting this, so maybe somebody else will find this info useful:

- 4.1 and 4.2 are perfectly fine (which is why I suggest 4.1.x for anybody using gm965 and seeing this problem)
- 4.3-rc1 has a ton of i915/drm changes, which result in a (not obviously harmful) call traces in kernel logs that end in drm_atomic_check_only()
- traces ending in drm_atomic_check_only persist into official 4.3.0, though the full trace differs somewhat from 4.3rc1
- around 4.4-rc1 or 4.4-rc2 (I only have rc3 to test, but that has zero i915 changes in the commit log, so it must've been one one the former two) drm_atomic_check_only disappears and the thread initiator, drm_wait_one_vblank (along with "vblank wait timed out on crtc 0"), appears.
- this persists up until at least ubuntu's 4.8.0
Comment 24 Mariusz Mazur 2016-11-01 22:23:34 UTC
Oh, and call traces for comparison (I'm attaching first traces after boot, there are always multiple ones in the log, the latter differing slightly, like having a call to i9xx_crtc_disable):

4.3.0-040300-generic #201511020949
 Call Trace:
  [<ffffffff813a4c94>] dump_stack+0x44/0x60
  [<ffffffff81078052>] warn_slowpath_common+0x82/0xc0
  [<ffffffff8107814a>] warn_slowpath_null+0x1a/0x20
  [<ffffffffc004d2fe>] drm_atomic_check_only+0x46e/0x540 [drm]
  [<ffffffffc004d4bd>] ? drm_atomic_set_fb_for_plane+0x2d/0x90 [drm]
  [<ffffffffc004d3e7>] drm_atomic_commit+0x17/0x60 [drm]
  [<ffffffffc0193355>] intel_get_load_detect_pipe+0x3d5/0x530 [i915]
  [<ffffffffc01c96fd>] intel_tv_detect+0x13d/0x5f0 [i915]
  [<ffffffffc0047d5f>] ? drm_get_edid+0x2f/0x3d0 [drm]
  [<ffffffffc00cfc35>] drm_helper_probe_single_connector_modes_merge_bits+0x235/0x4d0 [drm_kms_helper]
  [<ffffffffc00cfee3>] drm_helper_probe_single_connector_modes+0x13/0x20 [drm_kms_helper]
  [<ffffffffc00db704>] drm_fb_helper_initial_config+0x74/0x3e0 [drm_kms_helper]
  [<ffffffffc01a2deb>] intel_fbdev_initial_config+0x1b/0x20 [i915]
  [<ffffffff81098928>] async_run_entry_fn+0x48/0x150
  [<ffffffff8108ff1a>] process_one_work+0x1aa/0x440
  [<ffffffff810901fb>] worker_thread+0x4b/0x4c0
  [<ffffffff817aedac>] ? __schedule+0x36c/0x980
  [<ffffffff810901b0>] ? process_one_work+0x440/0x440
  [<ffffffff810901b0>] ? process_one_work+0x440/0x440
  [<ffffffff810960f9>] kthread+0xc9/0xe0
  [<ffffffff81096030>] ? kthread_create_on_node+0x180/0x180
  [<ffffffff817b33cf>] ret_from_fork+0x3f/0x70
  [<ffffffff81096030>] ? kthread_create_on_node+0x180/0x180
 ---[ end trace cb8c0d778aaecb5a ]---


4.4.1-040401-generic #201601311534:
 Call Trace:
  [<ffffffff813c8e14>] dump_stack+0x44/0x60
  [<ffffffff8107dba2>] warn_slowpath_common+0x82/0xc0
  [<ffffffff8107dc3c>] warn_slowpath_fmt+0x5c/0x80
  [<ffffffff810bfa25>] ? finish_wait+0x55/0x70
  [<ffffffffc002d2a5>] drm_wait_one_vblank+0x1b5/0x1c0 [drm]
  [<ffffffff810bfec0>] ? wake_atomic_t_function+0x60/0x60
  [<ffffffffc01d66a9>] intel_get_load_detect_pipe+0x529/0x530 [i915]
  [<ffffffffc020fbfd>] intel_tv_detect+0x13d/0x5f0 [i915]
  [<ffffffffc004103e>] ? drm_get_edid+0x3e/0x3f0 [drm]
  [<ffffffff817fcdd6>] ? schedule_hrtimeout_range_clock.part.23+0xa6/0x150
  [<ffffffffc0100da5>] drm_helper_probe_single_connector_modes_merge_bits+0x235/0x4d0 [drm_kms_helper]
  [<ffffffffc0101053>] drm_helper_probe_single_connector_modes+0x13/0x20 [drm_kms_helper]
  [<ffffffffc010d05e>] drm_fb_helper_initial_config+0xae/0x420 [drm_kms_helper]
  [<ffffffffc01e681b>] intel_fbdev_initial_config+0x1b/0x20 [i915]
  [<ffffffff8109f628>] async_run_entry_fn+0x48/0x150
  [<ffffffff8109688a>] process_one_work+0x1aa/0x440
  [<ffffffff81096b6b>] worker_thread+0x4b/0x4c0
  [<ffffffff81096b20>] ? process_one_work+0x440/0x440
  [<ffffffff8109cce8>] kthread+0xd8/0xf0
  [<ffffffff8109cc10>] ? kthread_create_on_node+0x1a0/0x1a0
  [<ffffffff817fdf4f>] ret_from_fork+0x3f/0x70
  [<ffffffff8109cc10>] ? kthread_create_on_node+0x1a0/0x1a0
 ---[ end trace fd397c034408c00f ]---


4.8.0-22-generic #24-Ubuntu
 Call Trace:
  [<ffffffffa222f5d2>] dump_stack+0x63/0x81
  [<ffffffffa1e82e5b>] __warn+0xcb/0xf0
  [<ffffffffa1e82edf>] warn_slowpath_fmt+0x5f/0x80
  [<ffffffffa1ec6ef5>] ? finish_wait+0x55/0x70
  [<ffffffffc0289c06>] drm_wait_one_vblank+0x1b6/0x1c0 [drm]
  [<ffffffffa1ec73a0>] ? wake_atomic_t_function+0x60/0x60
  [<ffffffffc04a95a2>] intel_get_load_detect_pipe+0x662/0x680 [i915]
  [<ffffffffc04e591f>] intel_tv_detect+0x13f/0x5d0 [i915]
  [<ffffffffc034b03b>] drm_helper_probe_single_connector_modes+0x27b/0x520 [drm_kms_helper]
  [<ffffffffc0359bbe>] drm_fb_helper_initial_config+0xae/0x430 [drm_kms_helper]
  [<ffffffffc04bed08>] intel_fbdev_initial_config+0x18/0x30 [i915]
  [<ffffffffa1ea6627>] async_run_entry_fn+0x37/0x150
  [<ffffffffa1e9d61c>] process_one_work+0x1fc/0x4b0
  [<ffffffffa1e9d91b>] worker_thread+0x4b/0x500
  [<ffffffffa1e9d8d0>] ? process_one_work+0x4b0/0x4b0
  [<ffffffffa1e9d8d0>] ? process_one_work+0x4b0/0x4b0
  [<ffffffffa1ea3c18>] kthread+0xd8/0xf0
  [<ffffffffa269f29f>] ret_from_fork+0x1f/0x40
  [<ffffffffa1ea3b40>] ? kthread_create_on_node+0x1e0/0x1e0
 ---[ end trace 4d6ade8c54672b71 ]---
Comment 25 Jani Nikula 2016-11-02 08:11:15 UTC
There was a somewhat related fix eons ago

commit 7a98948f3b536ca9a077e84966ddc0e9f53726df
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Mon Sep 8 17:43:01 2014 +0300

    drm/i915: Wait for vblank before enabling the TV encoder

but apparently the problem is now in intel_get_load_detect_pipe() rather than intel_tv_detect_type().
Comment 26 Mariusz Mazur 2016-11-02 09:01:17 UTC
Ah, progress, thanks for that. Based on your comment I've snooped around the code, and found this in drivers/gpu/drm/i915/intel_tv.c:

    /* For unknown reasons the hw barfs if we don't do this vblank wait. */
    intel_wait_for_vblank(dev, intel_crtc->pipe);

along with the commit log for it (bf2125e2f7e931b50a6c76ba0435ba001409ccbf):

    drm/i915: wait for a vblank to pass after tv detect
    
    Otherwise the hw will get confused and result in a black screen.

    (…)

    v2: As suggested by Chris Wilson, add a small comment to ensure that
    no one accidentally removes this vblank wait again - there really
    seems to be no sane explanation for why we need it, but it is
    required.

Which leads me to believe that if I figure out a few places in the code to sprinkle intel_wait_for_vblank() calls, it might fix the issue. I'll get my lucky dice and get right to it.
Comment 27 Mariusz Mazur 2016-11-02 11:01:58 UTC
No, that's not how that works.
Comment 28 Anwar 2016-11-20 08:51:44 UTC
Same happened with Ubuntu kernel provided by the proposed branch `4.4.0-49-generic`. I used kernel `4.8.0-27.29~16.04.1` from Canonical Kernel PPA and got same error. The difference is the kernel from the PPA freezes the screen for 3-5 seconds. Same error was present with the default kernel shipped with Ubuntu 16.04.


I too am using Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller.
Comment 29 Till Schäfer 2016-12-01 00:18:03 UTC
Same here on a dell d630 (GM965/GL960) with Gentoo using the 4.8.10 kernel
Comment 30 José Jorge 2016-12-04 09:31:04 UTC
Same here with Mageia Cauldron, the bug was not there with kernels 4.7.x, it came with 4.8.x.

Still here with 4.8.12 :

[   12.768066] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:26:pipe A] flip_done timed out
[   12.869022] ------------[ cut here ]------------
[   12.869057] WARNING: CPU: 0 PID: 91 at drivers/gpu/drm/drm_irq.c:1224 drm_wait_one_vblank+0x199/0x1a0 [drm]
[   12.869058] vblank wait timed out on crtc 0
[   12.869059] Modules linked in: i915 video button i2c_algo_bit drm_kms_helper drm ide_pci_generic piix ide_core ata_generic pata_acpi ata_piix
[   12.869072] CPU: 0 PID: 91 Comm: kworker/u4:5 Not tainted 4.8.12-desktop-1.mga6 #1
[   12.869074] Hardware name: Acer       Aspire 5315     /Acadia   , BIOS V1.45 11/10/2008
[   12.869081] Workqueue: events_unbound async_run_entry_fn
[   12.869083]  0000000000000000 ffff9dc5b78bba20 ffffffff88417b1e ffff9dc5b78bba70
[   12.869087]  0000000000000000 ffff9dc5b78bba60 ffffffff8807018b 000004c8ff20fc40
[   12.869090]  ffff9dc5b7c20000 0000000000000000 0000000000000000 0000000001000001
[   12.869093] Call Trace:
[   12.869099]  [<ffffffff88417b1e>] dump_stack+0x63/0x85
[   12.869102]  [<ffffffff8807018b>] __warn+0xcb/0xf0
[   12.869104]  [<ffffffff880701ff>] warn_slowpath_fmt+0x4f/0x60
[   12.869108]  [<ffffffff8873cbfe>] ? _raw_spin_unlock_irqrestore+0xe/0x10
[   12.869112]  [<ffffffff880aecd5>] ? finish_wait+0x55/0x70
[   12.869127]  [<ffffffffc03c4b19>] drm_wait_one_vblank+0x199/0x1a0 [drm]
[   12.869130]  [<ffffffff880af160>] ? wake_atomic_t_function+0x60/0x60
[   12.869201]  [<ffffffffc04e3e78>] intel_get_load_detect_pipe+0x618/0x630 [i915]
[   12.869250]  [<ffffffffc051fe13>] intel_tv_detect+0x113/0x5b0 [i915]
[   12.869260]  [<ffffffffc043aeee>] drm_helper_probe_single_connector_modes+0x27e/0x540 [drm_kms_helper]
[   12.869270]  [<ffffffffc04490f1>] drm_fb_helper_initial_config+0x81/0x3f0 [drm_kms_helper]
[   12.869317]  [<ffffffffc04fa2e8>] intel_fbdev_initial_config+0x18/0x30 [i915]
[   12.869319]  [<ffffffff880917e7>] async_run_entry_fn+0x37/0x150
[   12.869322]  [<ffffffff880893f6>] process_one_work+0x166/0x4a0
[   12.869325]  [<ffffffff8808977b>] worker_thread+0x4b/0x4f0
[   12.869327]  [<ffffffff88089730>] ? process_one_work+0x4a0/0x4a0
[   12.869329]  [<ffffffff88089730>] ? process_one_work+0x4a0/0x4a0
[   12.869331]  [<ffffffff8808ef99>] kthread+0xc9/0xe0
[   12.869334]  [<ffffffff8873d25f>] ret_from_fork+0x1f/0x40
[   12.869336]  [<ffffffff8808eed0>] ? kthread_worker_fn+0x180/0x180
[   12.869338] ---[ end trace 0a4c4b6782c36413 ]---
Comment 31 Maarten Lankhorst 2016-12-21 11:01:06 UTC
Did anyone here test the patch I provided, for those with >100 us delays in their pipe updates?
Comment 32 Felix Schwarz 2016-12-22 09:19:40 UTC
Created attachment 128625 [details]
dmesg Linux 4.9 with disabled cxsr hack

(In reply to Maarten Lankhorst from comment #31)
> Did anyone here test the patch I provided, for those with >100 us delays in
> their pipe updates?

Well I think andram did (comment #15, comment #16).

I did not comment earlier as andram bisected the problem back to 4.6 change when my problems (and the initial reporter's problem) started much earlier (see comment 14). However just to be sure I applied your patch on top of git commit 69973b83(4.9) but that does not solve the problem for me (traceback attached).

I started to bisect the problem on my machine but this a quite time consuming process. First of all the machine itself is quite slow and this hardware is ancient - but I somehow I despise to retire a machine due to a regression in the Linux kernel.

However the main problem is that there is no clear "beginning" but there are multiple interleaved issues. At risk of dilluting the focus here is what I found so far:
- Linux 4.2 graphics works fine
- 4.3.0: first traceback (warning in drm_atomic_check_only)
- 4.4-rc1: vblank-wait-timed-out-on-crt1
- 4.4-rc2: vblank-wait-timed-out-on-crt0

With newer kernel versions the symptoms become more severe for me: For example right now (4.8.x) I see multi-second screen freezes during the boot process and whenever the screen is activated (e.g. resuming).

However not all computers with this chipset are affected so it seems some of them need some kind of workaround due to connectors, bios, ...

One thing I noticed in my dmesg is:
> [Firmware Bug]: Duplicate ACPI video bus devices for the same VGA controller, please try module parameter "video.allow_duplicates=1"if the current driver doesn't work.

("video.allow_duplicates=1" does not make any difference for me)

My current speculation is that something in the initial atomic conversion broke this specific chip set and this bug is exposed more often as more and more parts of the driver rely on atomic helpers/correct atomic behavior.

I'll continue to bisect the bug on my machine but it will take time as I have more pressing issues on my plate.
Comment 33 andram 2016-12-22 12:02:17 UTC
I try to compare your dmesg with the one I sent in earlier.  I was told to put drm.debug=0x3e on the kernel command line, which gave more debugging info.  Could you also put it, and provide the resulting dmesg?
Comment 34 Felix Schwarz 2016-12-22 22:12:33 UTC
Created attachment 128639 [details]
dmesg Linux 4.9 with disabled cxsr hack (and DRM debug infos)

(In reply to andram from comment #33)
> I try to compare your dmesg with the one I sent in earlier.  I was told to
> put drm.debug=0x3e on the kernel command line, which gave more debugging
> info.  Could you also put it, and provide the resulting dmesg?

Sure, see attached.
Comment 35 andram 2016-12-23 01:42:53 UTC
Created attachment 128644 [details] [review]
Patch to get rid of vblank warnings

Thanks. Would you mind to try the attached patch. It solves the problem for me.
Comment 36 guido 2016-12-23 16:26:17 UTC
(In reply to andram from comment #35)
> Created attachment 128644 [details] [review] [review]
> Patch to get rid of vblank warnings
> 
> Thanks. Would you mind to try the attached patch. It solves the problem for
> me.

Hello.

I have just tried the attached patch and it works, in the sense that it avoids crashing the system, although the backtrace is still getting printed in the logs/dmesg.
Comment 37 andram 2016-12-23 18:00:16 UTC
(In reply to g.trentalancia from comment #36)
> I have just tried the attached patch and it works, in the sense that it
> avoids crashing the system, although the backtrace is still getting printed
> in the logs/dmesg.

Does the backtrace still contain intel_tv_detect() as it did when you opened the bug?  

Could you add "drm.debug=0x3e" to the kernel command line and attach the dmesg to this bug?
Comment 38 guido 2016-12-23 21:35:15 UTC
(In reply to andram from comment #37)
> (In reply to g.trentalancia from comment #36)
> > I have just tried the attached patch and it works, in the sense that it
> > avoids crashing the system, although the backtrace is still getting printed
> > in the logs/dmesg.
> 
> Does the backtrace still contain intel_tv_detect() as it did when you opened
> the bug?  

Yes, unfortunately, it still contains intel_tv_detect(). I suspect the patch is not fully effective...

> Could you add "drm.debug=0x3e" to the kernel command line and attach the
> dmesg to this bug?
Comment 39 Felix Schwarz 2017-01-05 15:22:05 UTC
just wanted to mention that Lyude Paul from Red Hat started investigating the bug some time ago (with low priority) so you might also want check https://bugzilla.redhat.com/show_bug.cgi?id=1342755 and/or provide a proper bisect.
Comment 40 andram 2017-01-07 01:03:02 UTC
FWIW,  for me I can get around this problem by disabling the SVIDEO-1 connector. The laptop in question does not even have a physical svideo connector, so no functionality is lost for me.  

I do this either by my patch above, or alternatively by adding 

video=SVIDEO-1:d

to the kernel command line.
Comment 41 Felix Schwarz 2017-01-07 10:13:43 UTC
(In reply to andram from comment #40)
> FWIW,  for me I can get around this problem by disabling the SVIDEO-1
> connector. The laptop in question does not even have a physical svideo
> connector, so no functionality is lost for me.  
> 
> I do this either by my patch above, or alternatively by adding 
> 
> video=SVIDEO-1:d
> 
> to the kernel command line.

That works for me too. :-)


In the mean time I finally automated my kernel bisection (and trimmed down the number of modules to build) so it did not require so much personal time.

As I suspected before the problem is in the atomic conversion:

commit 74c090b1bdc57b1c9f1361908cca5a3d8a80fb08
Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
Date:   Mon Jul 13 16:30:30 2015 +0200

    drm/i915: Use full atomic modeset.
    
    Huzzah! \o/
    
    Signed-off-by: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
    Reviewed-by: Daniel Stone <daniels@collabora.com>
    Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>


Please note that there are few caveats if you try to reproduce this with a GM965 chipset:
- I was unable to compile these kernel versions with GCC 6 (had to resort to GCC 5 instead)
- There was an unrelated bug introduced in git rev eddfcbcd (and fixed about 1 ½ months later in git rev 80aa9312) which prevents the kernel to boot with a GM965 chipset. In order to bisect I had to apply the fix to all commits in betwen.
- For some time before (and exactly up to) the bisection commit 74c090b1 I always see this error in dmesg:
>> [drm:drm_calc_timestamping_constants] *ERROR* crtc 24: Can't calculate constants, dotclock = 0!

I chose to treat the dotclock error as "good" but that might be a hint where to look.


Anyway I'll provide some hardware to Lyude Paul from Red Hat and he was optimistic to find the problem pretty quickly. However if anyone has an idea based on the bisected commit I'd be glad to try :-)
Comment 42 Till Schäfer 2017-01-07 18:52:03 UTC
(In reply to andram from comment #40)
> video=SVIDEO-1:d
> 
> to the kernel command line.

Fixed it here on gentoo sources 4.9.0 as well. Interestingly, it also causes the KDE login (after sddm login) and logout to be a lot faster.
Comment 43 Stuart Gathman 2017-01-07 19:31:50 UTC
(In reply to Till Schäfer from comment #42)
> (In reply to andram from comment #40)
> > video=SVIDEO-1:d
> > 
> > to the kernel command line.
> 
> Fixed it here on gentoo sources 4.9.0 as well. Interestingly, it also causes
> the KDE login (after sddm login) and logout to be a lot faster.

That's because the Desktop Environments set brightness at least once at login - invoking the timeout each time.
Comment 44 guido 2017-01-08 00:06:46 UTC
(In reply to andram from comment #40)
> FWIW,  for me I can get around this problem by disabling the SVIDEO-1
> connector. The laptop in question does not even have a physical svideo
> connector, so no functionality is lost for me.  
> 
> I do this either by my patch above, or alternatively by adding 
> 
> video=SVIDEO-1:d
> 
> to the kernel command line.

I have just tried the above kernel boot option and it solves the problem ! 

Unfortunately, the patch does not work...
Comment 45 andram 2017-01-08 12:10:24 UTC
> As I suspected before the problem is in the atomic conversion:
> 
> commit 74c090b1bdc57b1c9f1361908cca5a3d8a80fb08
> Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
> Date:   Mon Jul 13 16:30:30 2015 +0200
> 

Okay, it seems the "vblank wait timed out on crtc 0" problem has 
it's potential cause in a number of patches.

For your bisected patch I get

$git describe --contains  74c090b1bdc57
v4.3-rc1~20^2~40^2~11

which would mean that mainline Kernel 4.3.0 is the first affected one. 

For my bisected patch I get

$git describe --contains  edde361711ef8
v4.6-rc1~12^2~22^2~30

and indeed for me the problem first occurs in Linux 4.6.0.

Then we also have the report from https://bugs.freedesktop.org/show_bug.cgi?id=93782#c30 which says "the bug was not there with kernels 4.7.x, it came with 4.8.x."

It therefore seems that GM965 broke independently a number of times during the last year.  As far as I understand, in all cases a failing load detection of intel_tv_detect() for svideo was responsible, although the details of that failure might be different for different people. 

Given this situation, it seems that currently nobody really understands, how to do load detection for svideo on this old hardware anymore. 

What is annoying is that the failing load detection also breaks hardware which does not even have a physical svideo port. Is there any evidence that svideo works at all with recent kernels? If not, it might be best to disable it by default.  Alternatively, there could be a "i915_legacy" driver, which is kept frozen at the status of v4.2.x for those who depend on svideo.
Comment 46 Rob 2017-01-14 10:08:04 UTC
I'm getting the same error with a GM965/GL960 controller, too.

On kernel 4.8.0-2-amd64 and 4.9.0-1-amd64 this results in a kernel freeze during the boot process. Found a "vblank wait timed out on crtc 0" with a following "Call Trace" in an old kern.log with a 4.7.0-1-amd64, too but during that time that doesn't result in a kernel freeze.

Hardware:
Acer Extensa 5220

Architecture:
X86_64

Kernel:
4.7.0-1-amd64
4.8.0-2-amd64
4.9.0-1-amd64

Distribution:
Debian testing/sid

Workaround to skip the freeze during the boot process:
Boot kernel in recovery mode and skip root login with Ctrl+D
Comment 47 Felix Schwarz 2017-01-14 10:34:22 UTC
just fyi: Lyude Paul from Red Hat is "very close to having a fix". He said the problem is "some that of the TV encoding registers not being set
properly before trying to call intel_wait_for_vblank()".
Comment 48 Dorian Fevrier 2017-01-23 23:15:15 UTC
I just want to say I also have this problem:

[   22.997392] ------------[ cut here ]------------
[   22.997423] WARNING: CPU: 0 PID: 274 at /build/linux-6SeTy4/linux-4.8.15/drivers/gpu/drm/drm_irq.c:1224 drm_wait_one_vblank+0x130/0x180 [drm]
[   22.997438] vblank wait timed out on crtc 0
[   22.997446] Modules linked in: nfsd auth_rpcgss nfs_acl nfs lockd grace fscache sunrpc uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core videodev media dell_laptop dell_wmi dell_smbios iTCO_wdt dcdbas sparse_keymap iTCO_vendor_support coretemp dell_smm_hwmon pcspkr arc4 joydev evdev iwl3945 serio_raw iwlegacy mac80211 i2c_i801 cfg80211 i915 i2c_smbus drm_kms_helper snd_hda_codec_realtek snd_hda_codec_generic drm rfkill sg lpc_ich mfd_core snd_hda_intel snd_hda_codec snd_hda_core i2c_algo_bit shpchp snd_hwdep wmi snd_pcm ac battery tpm_infineon video button snd_timer snd soundcore acpi_cpufreq tpm_tis tpm_tis_core tpm fuse autofs4 ext4 crc16 jbd2 fscrypto mbcache sr_mod sd_mod cdrom ata_generic ahci libahci ata_piix psmouse libata firewire_ohci sdhci_pci sdhci scsi_mod mmc_core
[   22.997620]  firewire_core crc_itu_t r8169 mii uhci_hcd ehci_pci ehci_hcd usbcore usb_common
[   22.997647] CPU: 0 PID: 274 Comm: kworker/u4:2 Tainted: G        W       4.8.0-0.bpo.2-686-pae #1 Debian 4.8.15-2~bpo8+2
[   22.997661] Hardware name: Dell Inc. Vostro1310/0H528C, BIOS A15 03/18/2009
[   22.997676] Workqueue: events_unbound async_run_entry_fn
[   22.997686]  00000286 b889104a f6a6bb2c df2e72fc f6a6bb40 00000000 df0674ea f87fb544
[   22.997707]  f6a6bb60 00000112 f87fb0f4 000004c8 f87d4640 000004c8 00000009 f87d4640
[   22.997728]  00000000 f6f00000 00000000 f6a6bb4c df067556 00000009 00000000 f6a6bb40
[   22.997748] Call Trace:
[   22.997762]  [<df2e72fc>] ? dump_stack+0x55/0x79
[   22.997774]  [<df0674ea>] ? __warn+0xea/0x110
[   22.997792]  [<f87d4640>] ? drm_wait_one_vblank+0x130/0x180 [drm]
[   22.997811]  [<f87d4640>] ? drm_wait_one_vblank+0x130/0x180 [drm]
[   22.997823]  [<df067556>] ? warn_slowpath_fmt+0x46/0x60
[   22.997841]  [<f87d4640>] ? drm_wait_one_vblank+0x130/0x180 [drm]
[   22.997854]  [<df0a84f0>] ? wait_woken+0x80/0x80
[   22.997942]  [<f8a5cdb0>] ? intel_pre_plane_update+0x180/0x1b0 [i915]
[   22.998022]  [<f8a6310e>] ? intel_atomic_commit_tail+0xee/0xf00 [i915]
[   22.998035]  [<df1b5ff7>] ? kmem_cache_alloc_trace+0xa7/0x1a0
[   22.998050]  [<f8815b44>] ? drm_atomic_helper_setup_commit+0x2a4/0x2f0 [drm_kms_helper]
[   22.998069]  [<f8815d6c>] ? drm_atomic_helper_swap_state+0x1dc/0x2c0 [drm_kms_helper]
[   22.998151]  [<f8a65d80>] ? intel_crtc_restore_mode+0xc0/0xc0 [i915]
[   22.998166]  [<f88134ad>] ? drm_atomic_helper_prepare_planes+0x3d/0xc0 [drm_kms_helper]
[   22.998248]  [<f8a642e2>] ? intel_atomic_commit+0x3c2/0x530 [i915]
[   22.998268]  [<f87ec1b9>] ? drm_atomic_check_only+0x2a9/0x6b0 [drm]
[   22.998345]  [<f8a3b480>] ? gen5_write8+0x140/0x140 [i915]
[   22.998363]  [<f87ec5f2>] ? drm_atomic_commit+0x32/0x60 [drm]
[   22.998441]  [<f8a62198>] ? intel_release_load_detect_pipe+0x28/0xb0 [i915]
[   22.998453]  [<df0a84f0>] ? wait_woken+0x80/0x80
[   22.998536]  [<f8aa16a9>] ? intel_tv_detect+0x329/0x600 [i915]
[   22.998553]  [<f880cd30>] ? drm_helper_probe_single_connector_modes+0x270/0x510 [drm_kms_helper]
[   22.998573]  [<f88191a1>] ? drm_fb_helper_probe_connector_modes.isra.5+0x41/0x60 [drm_kms_helper]
[   22.998591]  [<f881b0d2>] ? drm_fb_helper_initial_config+0x72/0x3c6 [drm_kms_helper]
[   22.998607]  [<df08e058>] ? check_preempt_curr+0x78/0x80
[   22.998617]  [<df08e077>] ? ttwu_do_wakeup+0x17/0x110
[   22.998696]  [<f8a7a516>] ? intel_fbdev_initial_config+0x16/0x30 [i915]
[   22.998709]  [<df086cb8>] ? async_run_entry_fn+0x38/0x180
[   22.998719]  [<df08eb94>] ? try_to_wake_up+0x44/0x360
[   22.998731]  [<df58a750>] ? mutex_lock+0x10/0x30
[   22.998742]  [<df409c6a>] ? deferred_probe_work_func+0x1a/0xc0
[   22.998754]  [<df07f20d>] ? process_one_work+0x10d/0x380
[   22.998765]  [<df0d257c>] ? try_to_del_timer_sync+0x4c/0x80
[   22.998776]  [<df07fb89>] ? worker_thread+0x49/0x470
[   22.998786]  [<df07fb40>] ? rescuer_thread+0x2e0/0x2e0
[   22.998797]  [<df0843d3>] ? kthread+0xb3/0xd0
[   22.998808]  [<df58d262>] ? ret_from_kernel_thread+0xe/0x24
[   22.998818]  [<df084320>] ? kthread_park+0x50/0x50
[   22.998827] ---[ end trace 2aa034e61f30fc33 ]---

- Dell Vostro 1310
- Linux balmoss 4.8.0-0.bpo.2-686-pae #1 SMP Debian 4.8.15-2~bpo8+2 (2017-01-17) i686 GNU/Linux
- mesa 12.0.4-2~bpo8+1 (jessie-backports)
- libdrm-intel1 2.4.74.1~bpo8+1 (jessie-backports)
- xserver-xorg-video-intel 2:2.99.917+git20161206-1~pbo8+1 (jessie-backports)

Putting video=SVIDEO-1:d in the kernel boot command fixed the problem.

I just want to say thank you guys for your hard work. :)
Comment 49 Karsten Hohmeier 2017-03-12 14:38:43 UTC
I am affected by the same bug on on the latest Debian 8 Backport Kernel 4.9.x. The workaround "Putting video=SVIDEO-1:d in the kernel boot command" works for me as well.

 ------------[ cut here ]------------
 WARNING: CPU: 1 PID: 907 at /home/zumbi/linux-4.7.2/drivers/gpu/drm/drm_irq.c:1318 drm_wait_one_vblank+0x15b/0x1a0 [drm]
 vblank wait timed out on crtc 0
 Modules linked in: hmac(E) drbg(E) ansi_cprng(E) ctr(E) ccm(E) pci_stub(E) vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) cpufreq_stats(E) cpufreq_userspace(E) cpufreq_conservative(E) cpufreq_powersave(E) vboxdrv(OE) nfsd(E) auth_rpcgss(E) nfs_acl(E) nfs(E) lockd(E) grace(E) fscache(E) sunrpc(E) iTCO_wdt(E) iTCO_vendor_support(E) hp_wmi(E) sparse_keymap(E) coretemp(E) arc4(E) joydev(E) evdev(E) serio_raw(E) pcspkr(E) snd_hda_codec_hdmi(E) iwl3945(E) snd_hda_codec_analog(E) iwlegacy(E) snd_hda_codec_generic(E) mac80211(E) i915(E) snd_hda_intel(E) lpc_ich(E) mfd_core(E) cfg80211(E) snd_hda_codec(E) snd_hda_core(E) snd_hwdep(E) rfkill(E) snd_pcm(E) drm_kms_helper(E) snd_timer(E) snd(E) soundcore(E) drm(E) shpchp(E) i2c_algo_bit(E) wmi(E) battery(E) tpm_infineon(E) hp_accel(E) lis3lv02d(E) input_polldev(E) video(E) acpi_cpufreq(E) ac(E) button(E) tpm_tis(E) tpm(E) loop(E) fuse(E) parport_pc(E) ppdev(E) lp(E) parport(E) autofs4(E) ext4(E) crc16(E) jbd2(E) mbcache(E) crc32c_generic(E) btrfs(E) xor(E) raid6_pq(E) dm_mod(E) sg(E) sr_mod(E) cdrom(E) sd_mod(E) ata_generic(E) psmouse(E) ata_piix(E) ahci(E) libahci(E) libata(E) scsi_mod(E) fan(E) thermal(E) fjes(E) ehci_pci(E) e1000e(E) uhci_hcd(E) ehci_hcd(E) usbcore(E) ptp(E) usb_common(E) pps_core(E)
 CPU: 1 PID: 907 Comm: Xorg Tainted: G        W  OE   4.7.0-0.bpo.1-amd64 #1 Debian 4.7.2-1~bpo8+1
 Hardware name: Hewlett-Packard HP Compaq 6720s/30D8, BIOS 68MDU Ver. F.0D 11/04/2008
  0000000000000286 00000000df391234 ffffffffbe717ca5 ffff880079cbf998
  0000000000000000 ffffffffbe47a3e4 0000000000000000 ffff880079cbf9f0
  0000000000000000 000000000000000d ffff88007c3e0e08 0000000000000001
 Call Trace:
  [<ffffffffbe717ca5>] ? dump_stack+0x5c/0x77
  [<ffffffffbe47a3e4>] ? __warn+0xc4/0xe0
  [<ffffffffbe47a45f>] ? warn_slowpath_fmt+0x5f/0x80
  [<ffffffffbe4bb1bb>] ? finish_wait+0x3b/0x70
  [<ffffffffc04cf43b>] ? drm_wait_one_vblank+0x15b/0x1a0 [drm]
  [<ffffffffbe4bb320>] ? wait_woken+0x90/0x90
  [<ffffffffc076e9cd>] ? intel_get_load_detect_pipe+0x61d/0x640 [i915]
  [<ffffffffc07ab24d>] ? intel_tv_detect+0x13d/0x590 [i915]
  [<ffffffffc04de4a0>] ? drm_gtf2_hbreak+0x30/0x60 [drm]
  [<ffffffffc055bd0c>] ? drm_helper_probe_single_connector_modes+0x2cc/0x4f0 [drm_kms_helper]
  [<ffffffffbe9d86ce>] ? mutex_lock+0xe/0x30
  [<ffffffffc04dabd6>] ? drm_mode_getconnector+0x336/0x380 [drm]
  [<ffffffffbe9d850c>] ? __mutex_unlock_slowpath+0x6c/0x90
  [<ffffffffc04cd686>] ? drm_ioctl+0x126/0x490 [drm]
  [<ffffffffc04da8a0>] ? drm_mode_getcrtc+0x120/0x120 [drm]
  [<ffffffffbe60977b>] ? do_vfs_ioctl+0x9b/0x5e0
  [<ffffffffbe5fb02f>] ? SYSC_newfstat+0x2f/0x50
  [<ffffffffbe609d36>] ? SyS_ioctl+0x76/0x90
  [<ffffffffbe4e7e9d>] ? posix_ktime_get_ts+0xd/0x10
  [<ffffffffbe9da736>] ? system_call_fast_compare_end+0xc/0x96
 ---[ end trace 07b886525ef927b8 ]---
Comment 50 Jari Tahvanainen 2017-03-21 13:23:14 UTC
*** Bug 96441 has been marked as a duplicate of this bug. ***
Comment 51 Ævar Arnfjörð Bjarmason 2017-04-03 08:58:49 UTC
I also have a Dell Inspiron 1525. Running on 4.9.0-2-amd64 (the Debian stretch rc2) without the video=SVIDEO-1:d parameter:

$ sudo dmesg|grep -B1 'Modules linked in'|grep -v Modules|grep -v -- --|perl -pe 's/.*?\]//'|sort|uniq -c|sort -nr
     13  encoder detached but still enabled on pipe A.
     13  connector enabled without attached crtc
     10  vblank wait timed out on crtc 1
      2  vblank wait timed out on crtc 0

And with:

$ sudo dmesg|grep -B1 'Modules linked in'|grep -v Modules|grep -v -- --|perl -pe 's/.*?\]//'|sort|uniq -c|sort -nr
      1  encoder detached but still enabled on pipe A.
      1  connector enabled without attached crtc

I can provide the more detailed backtraces if needed, but thought noting the frequency would be interesting. This kernel option stops the freezes for me & makes the computer responsive.

I'd be happy to test any kernel patches to see if they solve these issues, this laptop also has an actualy svideo port (although I don't have a cable, but could get one...)>
Comment 52 Jani Saarinen 2017-04-26 07:02:31 UTC
Hi reporters, 
can we test latest drm-tip and see if there are still issues seen?
Comment 53 OmegaPhil 2017-04-26 11:44:35 UTC
Just looking into this to see if I can help - I'm guessing you want the master branch of https://cgit.freedesktop.org/drm-intel tested, is a Devuan Testing machine with 4.9.13-1 kernel and xserver-xorg 7.7+18 useful for this?
Comment 54 Ricardo 2017-05-09 17:39:59 UTC
Adding tag into "Whiteboard" field - ReadyForDev
The bug still active
*Status is correct
*Platform is included
*Feature is included
*Priority and Severity correctly set
*Logs included
Comment 55 Thomas Nilefalk 2017-05-10 06:23:56 UTC
(In reply to andram from comment #40)
> FWIW,  for me I can get around this problem by disabling the SVIDEO-1
> connector. The laptop in question does not even have a physical svideo
> connector, so no functionality is lost for me.  
> 
> I do this either by my patch above, or alternatively by adding 
> 
> video=SVIDEO-1:d
> 
> to the kernel command line.

I am assuming "SVIDEO-1" stems from the line:

> [    0.645655] [drm:update_connector_routing] [CONNECTOR:38:SVIDEO-1] using [ENCODER:39:TV-39] on [CRTC:26:crtc-0]

I seem to have the same problem (stack trace is very similar) as I have reported in https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1689651.

But the workaround with disabling SVIDEO-1 doesn't work for me. So I was wondering if there are anything else I should be looking for? Or can help out with?

I am suspecting that the problem in effect renders Linux unusable on a whole lot of laptops, particularly for mine, so if there is anything that I can do, I'm happy to.
Comment 56 freedesktop 2017-05-10 09:08:49 UTC
Even if the device doesn't seem to have a physical S-VIDEO connector, it possibly can be made available by using a docking station. This is the case for the Dell D630.

Nevertheless: I'd thankfully remove the S-VIDEO support in favor to a booting system :)
Comment 57 Jari Tahvanainen 2017-07-06 13:36:12 UTC
Maarten - were April updates related to this intended to fix this problem?Folks, do you still see the problem on your systems with the latest kernels (preferable from drm-tip)? If problem still persist please change the status as REOPENED, otherwise one can mark this as resolved.
Comment 58 Khurshid Alam 2017-08-01 04:56:03 UTC
I still see the problem with 4.10, 4.11 and 4.12 and I also tried kernels from drm-tip. Can anyone else confirm?
Comment 59 Axel Kittenberger 2017-08-24 13:37:31 UTC
If below is the same error, then yes. I just tested with linux-4.13-rc6.

Kernel 3.16 is the last of the ones I tried that ran on this machine (Macbook Air 2011 edition), at least since 4.6 this is broken, and my usual way just to skip one or two releases until these stuff is fixed doesn't work.

Turning of SVIDEO doesn't help, installing microcodes doesn't help, there is no newer BIOS for this machine. And 3.16 starts being an issue with newer mice.

I gladly keep testing what you throw at me to get this finally fixed.

PS: If this is a different kind of error, I'm sorry and I'll open a new bug.

""""""""""""""""
[   96.023467] fuse init (API version 7.26)
[   98.449856] [drm:ironlake_crtc_enable [i915]] *ERROR* mode set failed: pipe A stuck
[   98.504650] pipe A vblank wait timed out
[   98.504692] ------------[ cut here ]------------
[   98.504746] WARNING: CPU: 1 PID: 1522 at drivers/gpu/drm/i915/intel_display.c:12844 intel_atomic_commit_tail+0xe46/0xe70 [i915]
[   98.504748] Modules linked in: fuse rfcomm cmac bnep cpufreq_conservative cpufreq_userspace cpufreq_powersave snd_hda_codec_hdmi snd_hda_codec_cirrus snd_hda_codec_generic binfmt_misc btusb btrtl nls_utf8 btbcm nls_cp437 btintel bluetooth vfat fat arc4 brcmsmac cordic brcmutil b43 sha256_ssse3 sha256_generic hmac drbg ansi_cprng ecdh_generic mac80211 hid_generic cfg80211 usb_storage ssb i915 mmc_core rfkill rng_core intel_rapl pcmcia pcmcia_core x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm iTCO_wdt joydev hid_apple iTCO_vendor_support evdev irqbypass crct10dif_pclmul uvcvideo applesmc crc32_pclmul ghash_clmulni_intel input_polldev pcbc videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 snd_hda_intel drm_kms_helper videobuf2_core snd_hda_codec videodev efi_pstore aesni_intel drm snd_hda_core
[   98.504836]  aes_x86_64 media snd_hwdep crypto_simd glue_helper snd_pcm cryptd bcma asix snd_timer efivars pcspkr snd usbnet usbhid bcm5974 mii libphy i2c_algo_bit soundcore mei_me hid sg mei lpc_ich shpchp mfd_core sbs battery apple_bl sbshc video ac button acpi_cpufreq sunrpc parport_pc ppdev lp parport efivarfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 sd_mod ahci libahci libata crc32c_intel scsi_mod i2c_i801 i2c_core uhci_hcd ehci_pci ehci_hcd usbcore usb_common
[   98.504913] CPU: 1 PID: 1522 Comm: Xorg Tainted: G     U          4.13.0-rc6 #1
[   98.504915] Hardware name: Apple Inc. MacBookAir4,2/Mac-742912EFDBEE19B3, BIOS MBA41.88Z.0077.B14.1510261805 10/26/2015
[   98.504918] task: ffff88016753f040 task.stack: ffffc90000e78000
[   98.504962] RIP: 0010:intel_atomic_commit_tail+0xe46/0xe70 [i915]
[   98.504964] RSP: 0018:ffffc90000e7bb08 EFLAGS: 00010296
[   98.504968] RAX: 000000000000001c RBX: ffff880168000000 RCX: 0000000000000000
[   98.504971] RDX: ffff88016fa95ab8 RSI: ffff88016fa8ddb8 RDI: ffff88016fa8ddb8
[   98.504973] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000365
[   98.504975] R10: ffffc90000e7bb08 R11: 0000000000000000 R12: 0000000000000000
[   98.504977] R13: 0000000000000000 R14: ffff8801696dd000 R15: 0000000000000001
[   98.504981] FS:  00007f9fe2e2aa40(0000) GS:ffff88016fa80000(0000) knlGS:0000000000000000
[   98.504984] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   98.504987] CR2: 00007f73b15b1090 CR3: 0000000163fca000 CR4: 00000000000406e0
[   98.504990] Call Trace:
[   98.505004]  ? wait_woken+0x80/0x80
[   98.505044]  ? intel_atomic_commit+0x38c/0x480 [i915]
[   98.505057]  ? drm_atomic_helper_set_config+0x61/0x90 [drm_kms_helper]
[   98.505077]  ? drm_crtc_check_viewport+0x2a/0x90 [drm]
[   98.505093]  ? __drm_mode_set_config_internal+0x61/0x110 [drm]
[   98.505107]  ? drm_mode_setcrtc+0x46e/0x5e0 [drm]
[   98.505122]  ? drm_mode_getcrtc+0x160/0x160 [drm]
[   98.505136]  ? drm_ioctl_kernel+0x65/0xb0 [drm]
[   98.505151]  ? drm_ioctl+0x2d2/0x380 [drm]
[   98.505164]  ? drm_mode_getcrtc+0x160/0x160 [drm]
[   98.505172]  ? do_vfs_ioctl+0x8f/0x5c0
[   98.505178]  ? vfs_write+0x154/0x190
[   98.505184]  ? SyS_ioctl+0x74/0x80
[   98.505189]  ? entry_SYSCALL_64_fastpath+0x1e/0xa9
[   98.505192] Code: 24 50 4c 89 04 24 48 83 c7 08 e8 b6 dc 85 e0 4c 8b 04 24 4d 85 c0 0f 85 08 fe ff ff 8d 75 41 48 c7 c7 a0 48 8f a0 e8 a5 41 87 e0 <0f> ff e9 f2 fd ff ff 8d 70 41 48 c7 c7 70 48 8f a0 e8 8f 41 87 
[   98.505259] ---[ end trace 90b06c05a66b68eb ]---
""""""""""
Comment 60 Elizabeth 2017-09-12 15:21:04 UTC
(In reply to Axel Kittenberger from comment #59)
> 
> """"""""""""""""
> [   96.023467] fuse init (API version 7.26)
> [   98.449856] [drm:ironlake_crtc_enable [i915]] *ERROR* mode set failed:
> pipe A stuck
> [   98.504650] pipe A vblank wait timed out
> [   98.504692] ------------[ cut here ]------------
> [   98.504746] WARNING: CPU: 1 PID: 1522 at
> drivers/gpu/drm/i915/intel_display.c:12844
> intel_atomic_commit_tail+0xe46/0xe70 [i915]
> ...
Hello Axel, this seems to be a different problem that the one reported in this bug. Could you please file a new case for this problem, including HW and SW information, and dmesg log with debug parameter. Thank you.
Comment 61 Axel Kittenberger 2017-09-15 10:52:03 UTC
My problem seems to be fixed with 4.13.1 i just tried.
4.13.0-rc6 was the last I tried before still having had my issue. 
Sorry for noise on this bug.
Comment 62 Ferenc Wágner 2017-10-03 07:32:25 UTC
Hi, unfortunately this problem is still present on current drm-tip (894ff8f6f64647989f77705813b6c69fdb2e21a5, 4.14.0-rc2+).
The video=SVIDEO-1:d workaround works, though.
I spare you the dmesg output, intel_tv_detect and intel_get_load_detect_pipe are still in the trace.
Comment 63 peter m 2017-10-05 08:01:39 UTC
OS Fedora 26

lspci | grep -i vga

00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (primary) (rev 0c)

uname -r
4.13.4-200.fc26.i686

dmesg | grep -i 'warning: cpu'
[   14.405111] WARNING: CPU: 0 PID: 95 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[   14.542111] WARNING: CPU: 0 PID: 95 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[   34.885117] WARNING: CPU: 0 PID: 27 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[   71.237130] WARNING: CPU: 0 PID: 706 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[   81.989128] WARNING: CPU: 0 PID: 706 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[  110.149133] WARNING: CPU: 0 PID: 706 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[  120.901078] WARNING: CPU: 0 PID: 706 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[  131.653135] WARNING: CPU: 0 PID: 706 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[  149.061172] WARNING: CPU: 0 PID: 706 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]

dmesg | grep -i '*error*'
[   14.304061] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:30:pipe A] flip_done timed out
[   34.784061] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[   71.136064] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[   81.888061] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[  110.048067] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[  120.800067] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[  131.552061] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[  148.960067] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out

dmesg not tained report
[   14.405076] ------------[ cut here ]------------
[   14.405111] WARNING: CPU: 0 PID: 95 at drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[   14.405112] Modules linked in: i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops e1000e drm serio_raw ata_generic pata_acpi ptp pps_core video
[   14.405125] CPU: 0 PID: 95 Comm: kworker/u4:5 Not tainted 4.13.4-200.fc26.i686 #1
[   14.405130] Hardware name: Hewlett-Packard         /30D8, BIOS 68MDU Ver. F.01 07/05/2007
[   14.405140] Workqueue: events_unbound async_run_entry_fn
[   14.405144] task: f34733c0 task.stack: f35ce000
[   14.405161] EIP: drm_wait_one_vblank+0x1a1/0x1b0 [drm]
[   14.405162] EFLAGS: 00010246 CPU: 0
[   14.405164] EAX: 0000001f EBX: f6d94000 ECX: f73d8a80 EDX: f73d3fac
[   14.405165] ESI: 00000000 EDI: 00000000 EBP: f35cfc40 ESP: f35cfc08
[   14.405167]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[   14.405168] CR0: 80050033 CR2: b7f5fc20 CR3: 17034000 CR4: 000006d0
[   14.405170] Call Trace:
[   14.405177]  ? finish_wait+0x70/0x70
[   14.405264]  intel_get_load_detect_pipe+0x5d5/0x640 [i915]
[   14.405323]  intel_tv_detect+0x113/0x450 [i915]
[   14.405385]  ? intel_tv_get_modes+0x1f0/0x1f0 [i915]
[   14.405400]  drm_helper_probe_detect+0x42/0x80 [drm_kms_helper]
[   14.405412]  drm_helper_probe_single_connector_modes+0xbc/0x670 [drm_kms_helper]
[   14.405428]  drm_setup_crtcs+0x62/0x950 [drm_kms_helper]
[   14.405437]  ? schedule_preempt_disabled+0xd/0x10
[   14.405443]  ? __mutex_lock.isra.1+0x1d8/0x470
[   14.405456]  drm_fb_helper_initial_config+0x69/0x400 [drm_kms_helper]
[   14.405464]  ? __switch_to+0xb0/0x300
[   14.405523]  intel_fbdev_initial_config+0x16/0x30 [i915]
[   14.405530]  async_run_entry_fn+0x35/0x160
[   14.405537]  process_one_work+0x14b/0x340
[   14.405544]  worker_thread+0x39/0x3c0
[   14.405550]  kthread+0xf3/0x110
[   14.405556]  ? process_one_work+0x340/0x340
[   14.405562]  ? kthread_park+0x70/0x70
[   14.405568]  ret_from_fork+0x19/0x24
[   14.405573] Code: 00 00 00 e9 e4 fe ff ff e8 4d c9 51 de 8b 45 d0 8d 55 dc e8 b2 d1 55 de 85 ff 0f 85 ee fe ff ff 56 68 8c 5e f5 f7 e8 4c 8a 57 de <0f> ff 58 5a e9 da fe ff ff 8d b6 00 00 00 00 66 66 66 66 90 55
[   14.405619] ---[ end trace fa94df2d2728a060 ]---
[   14.542062] vblank wait timed out on crtc 0
[   14.542088] ------------[ cut here ]------------

lsmod | grep video
video                  40960  1 i915
Comment 64 Elizabeth 2017-11-03 22:01:37 UTC
Decreasing priority since there are workarounds, patches and is an old HW for this issue.
Comment 65 Kenn Sully 2018-01-07 15:46:54 UTC
I have the same problem on Ubuntu 16.04 in kernel 4.13.0-21.

|[drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out

I used `video=SVIDEO-1:d` kernel parameter as a workaround.
Comment 66 Jani Saarinen 2018-03-29 07:11:10 UTC
First of all. Sorry about spam.
This is mass update for our bugs. 

Sorry if you feel this annoying but with this trying to understand if bug still valid or not.
If bug investigation still in progress, please ignore this and I apologize!

If you think this is not anymore valid, please comment to the bug that can be closed.
If you haven't tested with our latest pre-upstream tree(drm-tip), can you do that also to see if issue is valid there still and if you cannot see issue there, please comment to the bug.
Comment 67 Maarten Lankhorst 2018-04-04 08:35:55 UTC
*** Bug 105878 has been marked as a duplicate of this bug. ***
Comment 68 Maarten Lankhorst 2018-04-05 08:52:28 UTC
*** Bug 103812 has been marked as a duplicate of this bug. ***
Comment 69 Peter Wood 2018-04-06 14:49:00 UTC
Same issue with GM965/GL960 on kernel 4.13.0-38:

# Video Card
lspci | grep -i vga
00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (primary) (rev 03)

# Kernel trace
[ 6053.340080] [drm:drm_atomic_helper_commit_cleanup_done [drm_kms_helper]] *ERROR* [CRTC:35:pipe B] flip_done timed out
[ 6053.444067] vblank wait timed out on crtc 1
[ 6053.444131] ------------[ cut here ]------------
[ 6053.444170] WARNING: CPU: 1 PID: 3993 at /build/linux-cg_do7/linux-4.13.0/drivers/gpu/drm/drm_vblank.c:1090 drm_wait_one_vblank+0x19b/0x1b0 [drm]
[ 6053.444171] Modules linked in: rfcomm pci_stub vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) vboxdrv(OE) ccm bnep btusb btrtl btbcm btintel bluetooth ecdh_generic joydev nls_iso8859_1 coretemp kvm_intel applesmc input_polldev kvm irqbypass appletouch snd_hda_codec_realtek snd_hda_codec_generic isight_firmware input_leds snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep snd_pcm arc4 b43 snd_seq_midi bcma snd_seq_midi_event mac80211 lpc_ich snd_rawmidi cfg80211 snd_seq shpchp snd_seq_device snd_timer snd soundcore sbs sbshc mac_hid apple_bl cuse parport_pc ppdev lp parport ip_tables x_tables autofs4 hid_logitech_hidpp hid_apple hid_logitech_dj hid_appleir hid_generic usbhid hid ssb_hcd i915 ahci libahci firewire_ohci i2c_algo_bit drm_kms_helper pata_acpi syscopyarea firewire_core sysfillrect sysimgblt
[ 6053.444262]  fb_sys_fops crc_itu_t sky2 ssb drm video
[ 6053.444274] CPU: 1 PID: 3993 Comm: Xorg Tainted: G        W  OE   4.13.0-38-generic #43-Ubuntu
[ 6053.444276] Hardware name: Apple Inc. MacBook4,1/Mac-F22788A9, BIOS     MB41.88Z.00C1.B00.0802091535 02/09/08
[ 6053.444278] task: ffff93871c5bd800 task.stack: ffffbadf81a6c000
[ 6053.444302] RIP: 0010:drm_wait_one_vblank+0x19b/0x1b0 [drm]
[ 6053.444304] RSP: 0018:ffffbadf81a6f978 EFLAGS: 00010286
[ 6053.444308] RAX: 000000000000001f RBX: ffff9387b06a0000 RCX: 0000000000000000
[ 6053.444310] RDX: 0000000000000000 RSI: ffff9387bfd16578 RDI: ffff9387bfd16578
[ 6053.444313] RBP: ffffbadf81a6f9d8 R08: 0000000000000001 R09: 000000000000072f
[ 6053.444315] R10: ffffbadf81a6f978 R11: 0000000000000000 R12: 0000000000000001
[ 6053.444317] R13: 0000000000000170 R14: 000000000b00076a R15: 0000000000000000
[ 6053.444321] FS:  00007f8705758440(0000) GS:ffff9387bfd00000(0000) knlGS:0000000000000000
[ 6053.444324] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6053.444326] CR2: 00007f5d7a5e4ea0 CR3: 000000009c556000 CR4: 00000000000006e0
[ 6053.444328] Call Trace:
[ 6053.444340]  ? wait_woken+0x80/0x80
[ 6053.444431]  intel_get_load_detect_pipe+0x5c6/0x640 [i915]
[ 6053.444498]  intel_tv_detect+0x147/0x510 [i915]
[ 6053.444506]  ? __ww_mutex_lock_slowpath+0x16/0x20
[ 6053.444524]  drm_helper_probe_detect+0x50/0x90 [drm_kms_helper]
[ 6053.444536]  ? drm_helper_probe_detect+0x50/0x90 [drm_kms_helper]
[ 6053.444548]  drm_helper_probe_single_connector_modes+0xe1/0x790 [drm_kms_helper]
[ 6053.444553]  ? __mark_inode_dirty+0x11a/0x3b0
[ 6053.444579]  drm_mode_getconnector+0x159/0x340 [drm]
[ 6053.444605]  ? drm_mode_connector_property_set_ioctl+0x60/0x60 [drm]
[ 6053.444626]  drm_ioctl_kernel+0x5f/0xb0 [drm]
[ 6053.444647]  drm_ioctl+0x31b/0x3d0 [drm]
[ 6053.444672]  ? drm_mode_connector_property_set_ioctl+0x60/0x60 [drm]
[ 6053.444677]  ? dput.part.23+0x2d/0x1e0
[ 6053.444682]  do_vfs_ioctl+0xa8/0x630
[ 6053.444687]  ? entry_SYSCALL_64_after_hwframe+0xe9/0x139
[ 6053.444690]  ? entry_SYSCALL_64_after_hwframe+0xe2/0x139
[ 6053.444694]  ? entry_SYSCALL_64_after_hwframe+0xdb/0x139
[ 6053.444697]  ? entry_SYSCALL_64_after_hwframe+0xd4/0x139
[ 6053.444701]  ? entry_SYSCALL_64_after_hwframe+0xcd/0x139
[ 6053.444704]  ? entry_SYSCALL_64_after_hwframe+0xc6/0x139
[ 6053.444707]  ? entry_SYSCALL_64_after_hwframe+0xbf/0x139
[ 6053.444711]  ? entry_SYSCALL_64_after_hwframe+0xb8/0x139
[ 6053.444714]  ? entry_SYSCALL_64_after_hwframe+0xb1/0x139
[ 6053.444718]  SyS_ioctl+0x79/0x90
[ 6053.444722]  ? entry_SYSCALL_64_after_hwframe+0x72/0x139
[ 6053.444726]  entry_SYSCALL_64_fastpath+0x24/0xab
[ 6053.444729] RIP: 0033:0x7f8702bc4ef7
[ 6053.444731] RSP: 002b:00007ffde1a06958 EFLAGS: 00003246 ORIG_RAX: 0000000000000010
[ 6053.444735] RAX: ffffffffffffffda RBX: 0000561993fb9f20 RCX: 00007f8702bc4ef7
[ 6053.444738] RDX: 00007ffde1a06990 RSI: 00000000c05064a7 RDI: 000000000000000e
[ 6053.444740] RBP: 00000000000000c0 R08: 00000000ffffffff R09: 0000000000000000
[ 6053.444742] R10: 0000000000000000 R11: 0000000000003246 R12: 00007f8702e95c20
[ 6053.444745] R13: 00000000000000b0 R14: 00007f8702e95c78 R15: 0000000000000000
[ 6053.444747] Code: ff e8 1a 56 00 f4 48 8b 7d a0 48 8d 75 a8 e8 0d b1 04 f4 45 85 ff 0f 85 0c ff ff ff 44 89 e6 48 c7 c7 d8 eb 09 c0 e8 c6 64 06 f4 <0f> ff e9 f6 fe ff ff 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00
[ 6053.444818] ---[ end trace 1b96d135a2a10dae ]---
Comment 70 Ville Syrjala 2018-04-06 15:06:50 UTC
The immediate bug is that the frame counter goes AWOL as soon as the TV encoder gets enabled on 965gm. It also has other issues such as the scanline counter speeding up during the the vertical blanking period and stopping entirely for the duration of the bottom border, which means the timestamp based frame counter emulation of gen2 wouldn't work reliably either.

I have an affected machine and I started to hack together some things to fix these problems. But it's looking like I won't have time to finish that stuff in the immediate future.
Comment 71 tom 2018-04-28 12:55:47 UTC
Just adding output from my machine:

$ uname -a
Linux faxnet 4.16.4-1-ARCH #1 SMP PREEMPT Tue Apr 24 13:21:29 UTC 2018 x86_64 GNU/Linux

$ lspci | grep -i vga
00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (primary) (rev 03)

$ dmesg | awk '/\[ cut here \]/{flag=1}/\[ end trace .* \]/{print;flag=0}flag'
[   18.930181] ------------[ cut here ]------------
[   18.930188] vblank wait timed out on crtc 0
[   18.930302] WARNING: CPU: 0 PID: 148 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x169/0x170 [drm]
[   18.930305] Modules linked in: 8021q mrp snd_hda_codec_realtek snd_hda_codec_generic nls_iso8859_1 snd_hda_intel nls_cp437 coretemp vfat snd_hda_codec fat joydev kvm_intel iTCO_wdt kvm iTCO_vendor_support snd_hda_core b43 applesmc irqbypass bcma input_polldev isight_firmware mac80211 appletouch input_leds snd_hwdep hid_apple mousedev i915 snd_pcm pcspkr cfg80211 i2c_i801 i2c_algo_bit rfkill snd_timer led_class rng_core drm_kms_helper sky2 drm sbs lpc_ich snd sbshc ac intel_agp intel_gtt evdev syscopyarea rtc_cmos soundcore agpgart mac_hid apple_bl sysfillrect shpchp sysimgblt fb_sys_fops acpi_cpufreq ip_tables x_tables crc32c_generic ext4 crc16 mbcache jbd2 fscrypto hid_appleir hid_generic usbhid hid sr_mod cdrom sd_mod ata_generic pata_acpi ssb_hcd ahci ata_piix libahci uhci_hcd libata firewire_ohci
[   18.930457]  scsi_mod firewire_core crc_itu_t ssb pcmcia ehci_pci pcmcia_core ehci_hcd mmc_core usbcore usb_common
[   18.930484] CPU: 0 PID: 148 Comm: kworker/u4:2 Not tainted 4.16.4-1-ARCH #1
[   18.930488] Hardware name: Apple Inc. MacBook4,1/Mac-F22788A9, BIOS     MB41.88Z.00C1.B00.0802091535 02/09/08
[   18.930500] Workqueue: events_unbound async_run_entry_fn
[   18.930540] RIP: 0010:drm_wait_one_vblank+0x169/0x170 [drm]
[   18.930544] RSP: 0018:ffff9ee98060bab0 EFLAGS: 00010286
[   18.930549] RAX: 0000000000000000 RBX: ffff9bf5b8c88000 RCX: 0000000000000001
[   18.930553] RDX: 0000000080000001 RSI: ffffffff8ee6807c RDI: 00000000ffffffff
[   18.930557] RBP: 0000000000000000 R08: 0000000000000030 R09: 00000000000003e0
[   18.930560] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
[   18.930564] R13: 0000000001000001 R14: ffff9bf57791b808 R15: ffff9bf5b862b400
[   18.930569] FS:  0000000000000000(0000) GS:ffff9bf5bce00000(0000) knlGS:0000000000000000
[   18.930574] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   18.930577] CR2: 00005572f7a48518 CR3: 000000004800a000 CR4: 00000000000006f0
[   18.930580] Call Trace:
[   18.930597]  ? wait_woken+0x80/0x80
[   18.930754]  intel_get_load_detect_pipe+0x363/0x3d0 [i915]
[   18.930889]  intel_tv_detect+0x147/0x500 [i915]
[   18.930927]  ? drm_helper_probe_single_connector_modes+0xd8/0x6e0 [drm_kms_helper]
[   18.930946]  drm_helper_probe_single_connector_modes+0xd8/0x6e0 [drm_kms_helper]
[   18.930973]  drm_setup_crtcs+0x13d/0xaf0 [drm_kms_helper]
[   18.930983]  ? dequeue_entity+0x38d/0x970
[   18.931005]  __drm_fb_helper_initial_config_and_unlock+0x39/0x430 [drm_kms_helper]
[   18.931012]  ? finish_task_switch+0x85/0x2c0
[   18.931144]  intel_fbdev_initial_config+0x14/0x30 [i915]
[   18.931154]  async_run_entry_fn+0x37/0x140
[   18.931163]  process_one_work+0x1ce/0x3f0
[   18.931170]  worker_thread+0x2b/0x3d0
[   18.931177]  ? process_one_work+0x3f0/0x3f0
[   18.931182]  kthread+0x113/0x130
[   18.931188]  ? kthread_create_on_node+0x70/0x70
[   18.931197]  ret_from_fork+0x35/0x40
[   18.931204] Code: 2d ff ff ff e8 49 7d ac cd 48 89 e6 4c 89 f7 e8 ce e6 b0 cd 45 85 e4 0f 85 0a ff ff ff 89 ee 48 c7 c7 68 48 5d c0 e8 97 7a ac cd <0f> 0b e9 f5 fe ff ff 66 66 66 66 90 8b b7 90 00 00 00 48 8b 3f 
[   18.931316] ---[ end trace 8a889bc87cc30d7f ]---
[   50.076888] ------------[ cut here ]------------
[   50.076895] vblank wait timed out on crtc 1
[   50.077014] WARNING: CPU: 1 PID: 270 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x169/0x170 [drm]
[   50.077017] Modules linked in: 8021q mrp snd_hda_codec_realtek snd_hda_codec_generic nls_iso8859_1 snd_hda_intel nls_cp437 coretemp vfat snd_hda_codec fat joydev kvm_intel iTCO_wdt kvm iTCO_vendor_support snd_hda_core b43 applesmc irqbypass bcma input_polldev isight_firmware mac80211 appletouch input_leds snd_hwdep hid_apple mousedev i915 snd_pcm pcspkr cfg80211 i2c_i801 i2c_algo_bit rfkill snd_timer led_class rng_core drm_kms_helper sky2 drm sbs lpc_ich snd sbshc ac intel_agp intel_gtt evdev syscopyarea rtc_cmos soundcore agpgart mac_hid apple_bl sysfillrect shpchp sysimgblt fb_sys_fops acpi_cpufreq ip_tables x_tables crc32c_generic ext4 crc16 mbcache jbd2 fscrypto hid_appleir hid_generic usbhid hid sr_mod cdrom sd_mod ata_generic pata_acpi ssb_hcd ahci ata_piix libahci uhci_hcd libata firewire_ohci
[   50.077179]  scsi_mod firewire_core crc_itu_t ssb pcmcia ehci_pci pcmcia_core ehci_hcd mmc_core usbcore usb_common
[   50.077206] CPU: 1 PID: 270 Comm: kworker/1:3 Tainted: G        W        4.16.4-1-ARCH #1
[   50.077210] Hardware name: Apple Inc. MacBook4,1/Mac-F22788A9, BIOS     MB41.88Z.00C1.B00.0802091535 02/09/08
[   50.077237] Workqueue: events output_poll_execute [drm_kms_helper]
[   50.077283] RIP: 0010:drm_wait_one_vblank+0x169/0x170 [drm]
[   50.077287] RSP: 0018:ffff9ee9807cfac0 EFLAGS: 00010282
[   50.077292] RAX: 0000000000000000 RBX: ffff9bf5b8c88000 RCX: 0000000000000001
[   50.077296] RDX: 0000000080000001 RSI: ffffffff8ee6807c RDI: 00000000ffffffff
[   50.077300] RBP: 0000000000000001 R08: 0000000000000030 R09: 000000000000040c
[   50.077303] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
[   50.077307] R13: 0000000001000012 R14: ffff9bf57791b968 R15: ffff9bf5b3e76400
[   50.077312] FS:  0000000000000000(0000) GS:ffff9bf5bcf00000(0000) knlGS:0000000000000000
[   50.077316] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   50.077320] CR2: 00007efd6942bef0 CR3: 000000004800a000 CR4: 00000000000006e0
[   50.077323] Call Trace:
[   50.077343]  ? wait_woken+0x80/0x80
[   50.077459]  intel_get_load_detect_pipe+0x363/0x3d0 [i915]
[   50.077554]  intel_tv_detect+0x147/0x500 [i915]
[   50.077585]  ? drm_helper_probe_single_connector_modes+0xd8/0x6e0 [drm_kms_helper]
[   50.077605]  drm_helper_probe_single_connector_modes+0xd8/0x6e0 [drm_kms_helper]
[   50.077632]  drm_setup_crtcs+0x13d/0xaf0 [drm_kms_helper]
[   50.077656]  ? drm_fb_helper_is_bound.isra.16+0x76/0xa0 [drm_kms_helper]
[   50.077678]  drm_fb_helper_hotplug_event.part.28+0x8b/0xb0 [drm_kms_helper]
[   50.077697]  output_poll_execute+0xa2/0x1b0 [drm_kms_helper]
[   50.077712]  process_one_work+0x1ce/0x3f0
[   50.077720]  worker_thread+0x2b/0x3d0
[   50.077727]  ? process_one_work+0x3f0/0x3f0
[   50.077733]  kthread+0x113/0x130
[   50.077739]  ? kthread_create_on_node+0x70/0x70
[   50.077746]  ? do_syscall_64+0x74/0x190
[   50.077753]  ? SyS_exit_group+0x10/0x10
[   50.077761]  ret_from_fork+0x35/0x40
[   50.077768] Code: 2d ff ff ff e8 49 7d ac cd 48 89 e6 4c 89 f7 e8 ce e6 b0 cd 45 85 e4 0f 85 0a ff ff ff 89 ee 48 c7 c7 68 48 5d c0 e8 97 7a ac cd <0f> 0b e9 f5 fe ff ff 66 66 66 66 90 8b b7 90 00 00 00 48 8b 3f 
[   50.077880] ---[ end trace 8a889bc87cc30d80 ]---
[   80.583270] ------------[ cut here ]------------
[   80.583273] vblank wait timed out on crtc 1
[   80.583351] WARNING: CPU: 1 PID: 270 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x169/0x170 [drm]
[   80.583353] Modules linked in: 8021q mrp snd_hda_codec_realtek snd_hda_codec_generic nls_iso8859_1 snd_hda_intel nls_cp437 coretemp vfat snd_hda_codec fat joydev kvm_intel iTCO_wdt kvm iTCO_vendor_support snd_hda_core b43 applesmc irqbypass bcma input_polldev isight_firmware mac80211 appletouch input_leds snd_hwdep hid_apple mousedev i915 snd_pcm pcspkr cfg80211 i2c_i801 i2c_algo_bit rfkill snd_timer led_class rng_core drm_kms_helper sky2 drm sbs lpc_ich snd sbshc ac intel_agp intel_gtt evdev syscopyarea rtc_cmos soundcore agpgart mac_hid apple_bl sysfillrect shpchp sysimgblt fb_sys_fops acpi_cpufreq ip_tables x_tables crc32c_generic ext4 crc16 mbcache jbd2 fscrypto hid_appleir hid_generic usbhid hid sr_mod cdrom sd_mod ata_generic pata_acpi ssb_hcd ahci ata_piix libahci uhci_hcd libata firewire_ohci
[   80.583460]  scsi_mod firewire_core crc_itu_t ssb pcmcia ehci_pci pcmcia_core ehci_hcd mmc_core usbcore usb_common
[   80.583478] CPU: 1 PID: 270 Comm: kworker/1:3 Tainted: G        W        4.16.4-1-ARCH #1
[   80.583480] Hardware name: Apple Inc. MacBook4,1/Mac-F22788A9, BIOS     MB41.88Z.00C1.B00.0802091535 02/09/08
[   80.583494] Workqueue: events output_poll_execute [drm_kms_helper]
[   80.583521] RIP: 0010:drm_wait_one_vblank+0x169/0x170 [drm]
[   80.583523] RSP: 0018:ffff9ee9807cfac0 EFLAGS: 00010282
[   80.583527] RAX: 0000000000000000 RBX: ffff9bf5b8c88000 RCX: 0000000000000001
[   80.583530] RDX: 0000000080000001 RSI: ffffffff8ee6807c RDI: 00000000ffffffff
[   80.583532] RBP: 0000000000000001 R08: 0000000000000030 R09: 0000000000000435
[   80.583534] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
[   80.583537] R13: 0000000003000013 R14: ffff9bf57791b968 R15: ffff9bf5b3e76400
[   80.583540] FS:  0000000000000000(0000) GS:ffff9bf5bcf00000(0000) knlGS:0000000000000000
[   80.583543] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   80.583546] CR2: 000055817b4b9e78 CR3: 000000004800a000 CR4: 00000000000006e0
[   80.583548] Call Trace:
[   80.583560]  ? wait_woken+0x80/0x80
[   80.583634]  intel_get_load_detect_pipe+0x363/0x3d0 [i915]
[   80.583697]  intel_tv_detect+0x147/0x500 [i915]
[   80.583717]  ? drm_helper_probe_single_connector_modes+0xd8/0x6e0 [drm_kms_helper]
[   80.583729]  drm_helper_probe_single_connector_modes+0xd8/0x6e0 [drm_kms_helper]
[   80.583747]  drm_setup_crtcs+0x13d/0xaf0 [drm_kms_helper]
[   80.583764]  ? drm_fb_helper_is_bound.isra.16+0x76/0xa0 [drm_kms_helper]
[   80.583778]  drm_fb_helper_hotplug_event.part.28+0x8b/0xb0 [drm_kms_helper]
[   80.583791]  output_poll_execute+0x185/0x1b0 [drm_kms_helper]
[   80.583798]  process_one_work+0x1ce/0x3f0
[   80.583803]  worker_thread+0x241/0x3d0
[   80.583808]  ? process_one_work+0x3f0/0x3f0
[   80.583812]  kthread+0x113/0x130
[   80.583816]  ? kthread_create_on_node+0x70/0x70
[   80.583821]  ? do_syscall_64+0x74/0x190
[   80.583825]  ? SyS_exit_group+0x10/0x10
[   80.583831]  ret_from_fork+0x35/0x40
[   80.583835] Code: 2d ff ff ff e8 49 7d ac cd 48 89 e6 4c 89 f7 e8 ce e6 b0 cd 45 85 e4 0f 85 0a ff ff ff 89 ee 48 c7 c7 68 48 5d c0 e8 97 7a ac cd <0f> 0b e9 f5 fe ff ff 66 66 66 66 90 8b b7 90 00 00 00 48 8b 3f 
[   80.583910] ---[ end trace 8a889bc87cc30d81 ]---
Comment 72 Ville Syrjala 2018-05-23 14:54:08 UTC
*** Bug 106422 has been marked as a duplicate of this bug. ***
Comment 73 Zakhar 2018-06-03 07:13:35 UTC
For bug 106422 (marked as duplicate as this one) I provided the i915.vbt as requested. I hope doing a sudo cp to /tmp worked ok.

The hardware (Dell Inspiron 1525) has:
- built in screen (1280x800)
- VGA-Out
- HDMI

With the workaround, I could test built-in screen and VGA-Out work fine. As for HDMI, I don't have a cable (no big deal!)

Graphic acceleration is present.

There are no more messages in the log about slow graphics or timeouts, that is even true for 14.04 (3.13 kernel) where we had messages but no timeout.

As for that hardware the workaround is perfect.

I have read the bissect procedure, considering how slow this old hardware is (it takes quite a long time to compile a kernel!) and the fact that the workaround is about one parameter to add in /etc/default/grub and works fine on this PC with no adverse effect, I won't start bissecting. Sorry for those that have a different hardware and might loose features with the workaround.


As far as I am concerned, I am Ok with the "low" urgency on this bug. I'll remove the workaround if you ever find why there is now some timeouts in recent kernels on this "TV detection".
Comment 74 Zakhar 2018-06-04 14:25:53 UTC
Dear all, as recommended by Ubuntu kernel team, after I posted automated apport messages here https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1774845, I tested:

- last ubuntu drm-tip (as of June 3rd): http://kernel.ubuntu.com/~kernel-ppa/mainline/drm-tip/current/
- suggested patch on comment #12 on this thread (on 4.17 rc3+ kernel I already had the source)

Both tests were unsuccessful to fix the bug (unlike the workaround that makes the time-out disappear).
Comment 75 Waynem Ccollough 2018-08-16 07:10:20 UTC
(In reply to Zakhar from comment #74)
> Dear all, as recommended by Ubuntu kernel team, after I posted automated
> apport messages here
> https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1774845, I tested:
> 
> - last ubuntu drm-tip (as of June 3rd):
> http://kernel.ubuntu.com/~kernel-ppa/mainline/drm-tip/current/
> - suggested patch on comment #12 on this thread (on 4.17 rc3+ kernel I
> already had the source)
> 
> Both tests were unsuccessful to fix the bug (unlike the workaround that
> makes the time-out disappear).

Thanks for the update Zakhar, but do we still have other sources that can help us to fix this one? I wonder. Thank you again.

Castro B.
https://webtrafficgeeks.org/
Comment 76 Stefan Brozinski 2018-10-18 19:28:51 UTC
Created attachment 142084 [details]
dmesg from old MacBook running lubuntu 18.04

Same problem here on an old MacBook running lubuntu 18.04.

A good workaround is adding "video=SVIDEO-1:d" to the grub kernel parameters.
Comment 77 Ville Syrjala 2018-11-13 14:29:38 UTC
*** Bug 108728 has been marked as a duplicate of this bug. ***
Comment 78 Ville Syrjala 2018-11-13 14:30:16 UTC
Fixes posted:
https://patchwork.freedesktop.org/series/52378/
Comment 79 René Rebe 2018-11-13 14:33:25 UTC
My vintage MacBook4,1 is obviously also affected by this:

[    0.000000] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:41:pipe B] flip_done timed out
[    0.000000] ------------[ cut here ]------------
[    0.000000] vblank wait timed out on crtc 1
[    0.000000] WARNING: CPU: 0 PID: 1158 at drivers/gpu/drm/drm_vblank.c:1084 drm_wait_one_vblank+0x15c/0x170 [drm]
[    0.000000] Modules linked in: ipv6 kvm_intel kvm irqbypass btusb btintel btbcm btrtl bluetooth ecdh_generic b43 mac80211 deflate efi_pstore mcryptd sha256_ssse3 joydev i915 snd_hda_codec_realtek sha256_generic snd_hda_codec_generic gpio_ich snd_hda_intel snd_hda_codec snd_hda_core applesmc input_leds drm_kms_helper hwmon appletouch isight_firmware snd_hwdep input_polldev cfg80211 drm fb_sys_fops sysimgblt sysfillrect rfkill syscopyarea snd_pcm i2c_algo_bit bcma snd_timer i2c_i801 rng_core snd pcspkr i2c_core intel_agp led_class ssb_hcd lpc_ich intel_gtt soundcore efivars apple_bl acpi_cpufreq dm_crypt ecb glue_helper crypto_simd cryptd aes_x86_64 xts algif_skcipher af_alg hid_apple dm_mod xfs udf reiserfs ntfs jfs isofs vfat msdos fat ext4 jbd2 crc16 ext2 mbcache dlm fscrypto configfs btrfs raid6_pq
[    0.000000]  zstd_compress xor libcrc32c raid1 md_mod sr_mod ide_gd_mod hid_appleir hid_generic usbhid hid uas usb_storage ide_generic firewire_sbp2 sg sd_mod ide_cd_mod cdrom pata_acpi ide_pci_generic ata_generic ata_piix ahci libahci ehci_pci ehci_hcd uhci_hcd firewire_ohci firewire_core crc_itu_t piix ssb sky2 libata usbcore usb_common
[    0.000000] CPU: 0 PID: 1158 Comm: X Tainted: G        W         4.17.6-dist #1
[    0.000000] Hardware name: Apple Inc. MacBook4,1/Mac-F22788A9, BIOS     MB41.88Z.00C1.B00.0802091535 02/09/08
[    0.000000] RIP: 0010:drm_wait_one_vblank+0x15c/0x170 [drm]
[    0.000000] RSP: 0018:ffffa36d402f7a08 EFLAGS: 00010286
[    0.000000] RAX: 0000000000000000 RBX: ffff95732e4b0000 RCX: 0000000000000006
[    0.000000] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff95733fc15390
[    0.000000] RBP: 0000000000000001 R08: 0000000000000030 R09: 0000000000000512
[    0.000000] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
[    0.000000] R13: 000000000b000009 R14: ffff95732e661968 R15: ffff9573297fa800
[    0.000000] FS:  00007f84795bbcc0(0000) GS:ffff95733fc00000(0000) knlGS:0000000000000000
[    0.000000] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    0.000000] CR2: 0000000001684038 CR3: 000000012b90a000 CR4: 00000000000006f0
[    0.000000] Call Trace:
[    0.000000]  ? wait_woken+0x80/0x80
[    0.000000]  intel_get_load_detect_pipe+0x365/0x3b0 [i915]
[    0.000000]  intel_tv_detect+0x126/0x490 [i915]
[    0.000000]  ? merge+0x59/0xb0
[    0.000000]  ? drm_modeset_lock+0x2b/0xa0 [drm]
[    0.000000]  drm_helper_probe_single_connector_modes+0xce/0x6b0 [drm_kms_helper]
[    0.000000]  drm_mode_getconnector+0x2c3/0x2f0 [drm]
[    0.000000]  ? _cond_resched+0x10/0x20
[    0.000000]  ? mutex_lock+0x9/0x30
[    0.000000]  ? drm_mode_connector_property_set_ioctl+0x50/0x50 [drm]
[    0.000000]  drm_ioctl_kernel+0x56/0xb0 [drm]
[    0.000000]  drm_ioctl+0x18d/0x350 [drm]
[    0.000000]  ? drm_mode_connector_property_set_ioctl+0x50/0x50 [drm]
[    0.000000]  ? __fpu__restore_sig+0x70/0x410
[    0.000000]  do_vfs_ioctl+0x9f/0x5f0
[    0.000000]  ? _copy_from_user+0x37/0x60
[    0.000000]  ksys_ioctl+0x35/0x70
[    0.000000]  __x64_sys_ioctl+0x11/0x20
[    0.000000]  do_syscall_64+0x5a/0x170
[    0.000000]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] RIP: 0033:0x7f847713ebb7
[    0.000000] RSP: 002b:00007ffc5f9fb338 EFLAGS: 00003246 ORIG_RAX: 0000000000000010
[    0.000000] RAX: ffffffffffffffda RBX: 0000000001684f80 RCX: 00007f847713ebb7
[    0.000000] RDX: 00007ffc5f9fb370 RSI: 00000000c05064a7 RDI: 000000000000000c
[    0.000000] RBP: 000000000000000c R08: 001e14ebd77f85a3 R09: 00007ffc5facb080
[    0.000000] R10: 000000000000ed2c R11: 0000000000003246 R12: 00000000c05064a7
[    0.000000] R13: 00007ffc5f9fb370 R14: 00007ffc5f9fb370 R15: 0000000001684e30
[    0.000000] Code: 5f f6 0f 0b e9 32 ff ff ff 48 89 e6 4c 89 f7 e8 cb ad 62 f6 45 85 e4 0f 85 14 ff ff ff 89 ee 48 c7 c7 38 cf a7 c0 e8 eb 26 5f f6 <0f> 0b e9 ff fe ff ff e8 28 25 5f f6 0f 1f 84 00 00 00 00 00 8b 
[    0.000000] ---[ end trace 10a5ec3e58e1a8d1 ]---
Comment 80 René Rebe 2018-11-13 20:31:36 UTC
(In reply to Ville Syrjala from comment #78)
> Fixes posted:
> https://patchwork.freedesktop.org/series/52378/

Awesome, big thanks! Works for me, tested on MacBook4,1 https://www.youtube.com/watch?v=GqH21-KcFzU
Comment 81 hobbitalastair 2018-11-20 07:00:43 UTC
(In reply to Ville Syrjala from comment #78)
> Fixes posted:
> https://patchwork.freedesktop.org/series/52378/

I can confirm that building from your git branch fixes the hangs/dmesg traces that I was seeing at boot or when switching virtual terminals. Thanks for looking into this!
Comment 82 Ville Syrjala 2018-11-22 12:59:02 UTC
*** Bug 108747 has been marked as a duplicate of this bug. ***
Comment 83 tom 2018-11-23 01:09:11 UTC
(In reply to Ville Syrjala from comment #78)
> Fixes posted:
> https://patchwork.freedesktop.org/series/52378/

Likewise, building the `tvout_fixes` branch results in a kernel that fixes the issue on my MacBook, which is a great result! As a complete outsider to the DRI/DRM process, how does this then get moved into the mainline kernel?
Comment 84 david.vantyghem 2018-12-13 22:11:39 UTC
Same bug with Linux Mint MATE, kernel 4.15.0-42, GPU Intel Mobile GM965/960, module i915.
Adding "video=SVIDEO-1:d" works.
Comment 85 Ville Syrjala 2019-01-25 17:31:21 UTC
Fix merged.

commit ed20151a7699bb2c77eba3610199789a126940c4
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Tue Nov 27 20:20:04 2018 +0200

    drm/vblank: Allow dynamic per-crtc max_vblank_count

commit 32db0b6501d97b09e92e70caefc74fa35aa9a8d6
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Tue Nov 27 22:05:50 2018 +0200

    drm/i915: Don't try to use the hardware frame counter with i965gm TV output

Should land in 5.0 hopefully.
Comment 86 Ville Syrjala 2019-02-25 21:12:18 UTC
*** Bug 109776 has been marked as a duplicate of this bug. ***
Comment 87 Ville Syrjala 2019-05-31 17:53:44 UTC
*** Bug 100907 has been marked as a duplicate of this 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.