Bug 36392

Summary: drm errors on Intel Corporation Mobile GM965/GL960
Product: Sisyphus Reporter: Ivan Zakharyaschev <imz>
Component: kernel-modules-drm-std-defAssignee: Vitaly Chikunov <vt>
Status: NEW --- QA Contact: qa-sisyphus
Severity: normal    
Priority: P3 CC: kernelbot, placeholder, vt
Version: unstable   
Hardware: all   
OS: Linux   
Bug Depends on:    
Bug Blocks: 36393, 36414, 36418    

Description Ivan Zakharyaschev 2019-03-25 23:14:14 MSK 
kernel-modules-drm-std-def-4.19.30-alt1.x86_64

[root@acer ~]# lspci -k | egrep -ie 'vga|display' -A5
00:02.0 VGA compatible controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (primary) (rev 03)
	Subsystem: Acer Incorporated [ALI] Device 011e
	Kernel driver in use: i915
00:02.1 Display controller: Intel Corporation Mobile GM965/GL960 Integrated Graphics Controller (secondary) (rev 03)
	Subsystem: Acer Incorporated [ALI] Device 011e
00:1a.0 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #4 (rev 03)
	Subsystem: Acer Incorporated [ALI] Device 011e
	Kernel driver in use: uhci_hcd
00:1a.1 USB controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #5 (rev 03)
[root@acer ~]# fgrep -i modesetting /var/log/Xorg.0.log
[   127.562] (==) Matched modesetting as autoconfigured driver 1
[   127.870] (II) LoadModule: "modesetting"
[   127.870] (II) Loading /usr/lib64/X11/modules/drivers/modesetting_drv.so
[   128.010] (II) Module modesetting: vendor="X.Org Foundation"
[   128.242] (II) modesetting: Driver for Modesetting Kernel Drivers: kms
[   128.295] (WW) Falling back to old probe method for modesetting
[   128.356] (II) UnloadModule: "modesetting"
[   128.356] (II) Unloading modesetting
[root@acer ~]# locate i915 | xargs rpm -qf | sort -u
firmware-linux-20190314-alt1.noarch
i586-xorg-dri-intel-19.0.0-alt1.i586
kernel-modules-drm-std-def-4.19.30-alt1.x86_64
kernel-modules-drm-un-def-4.20.17-alt1.x86_64
xorg-dri-intel-19.0.0-alt1.x86_64

[root@acer ~]# 

In dmesg, there are many errors like this. And sometimes it writes "reboot in 30 sec" and reboots.

[   27.940301] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:34:pipe A] flip_done timed out
[   28.042348] ------------[ cut here ]------------
[   28.042354] vblank wait timed out on crtc 0
[   28.042520] WARNING: CPU: 1 PID: 7 at drivers/gpu/drm/drm_vblank.c:1084 drm_wait_one_vblank+0x15c/0x170 [drm]
[   28.042522] Modules linked in: pktcdvd uvcvideo hid_generic videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev btusb btrtl usbhid
 btbcm btintel hid media bluetooth cpufreq_ondemand ecdh_generic joydev wl(PO) sr_mod iTCO_wdt iTCO_vendor_support acer_wmi cdrom sparse_keymap coretemp kvm 
arc4 irqbypass psmouse iwl3945 iwlegacy mac80211 ir_rc6_decoder rc_rc6_mce r852 sm_common cfg80211 nand nand_ecc nand_bch firewire_ohci bch i915 sdhci_pci r5
92 pcc_cpufreq firewire_core cqhci mtd memstick ata_generic pata_acpi ac battery acpi_cpufreq sdhci ene_ir mmc_core rfkill crc_itu_t rc_core wmi snd_hda_code
c_hdmi lpc_ich thermal video ata_piix drm_kms_helper snd_hda_codec_realtek snd_hda_codec_generic ehci_pci uhci_hcd snd_hda_intel ehci_hcd drm snd_hda_codec u
sbcore usb_common tg3 snd_hda_core
[   28.042655]  i2c_algo_bit hwmon snd_hwdep snd_pcm i2c_core intel_agp intel_gtt vboxnetadp(O) vboxnetflt(O) pci_stub vboxpci(O) vboxdrv(O) dm_multipath scs
i_dh_rdac scsi_dh_emc scsi_dh_alua snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi snd_seq_device snd_timer snd soundcore button ip_tables x_tables ipv6 
crc_ccitt autofs4 ext4 crc32c_generic crc16 mbcache jbd2 fscrypto sd_mod ahci libahci libata scsi_mod evdev input_leds serio_raw xts af_packet dm_crypt dm_mo
d
[   28.042747] CPU: 1 PID: 7 Comm: kworker/u4:0 Tainted: P           O      4.19.30-std-def-alt1 #1
[   28.042749] Hardware name: Acer       Aspire 5720     /Nettiling, BIOS V1.14 08/09/2007
[   28.042761] Workqueue: events_unbound async_run_entry_fn
[   28.042804] RIP: 0010:drm_wait_one_vblank+0x15c/0x170 [drm]
[   28.042809] Code: e0 0f 0b e9 32 ff ff ff 48 89 e6 4c 89 f7 e8 fb ea 98 e0 45 85 e4 0f 85 14 ff ff ff 89 ee 48 c7 c7 08 99 76 a0 e8 8e 5b 94 e0 <0f> 0b e9
 ff fe ff ff e8 78 58 94 e0 0f 1f 84 00 00 00 00 00 66 66
[   28.042813] RSP: 0018:ffffc9000037bac0 EFLAGS: 00010282
[   28.042818] RAX: 0000000000000000 RBX: ffff88807b6d8000 RCX: 0000000000000006
[   28.042821] RDX: 0000000000000007 RSI: 0000000000000086 RDI: ffff88807d116560
[   28.042825] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000319
[   28.042828] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
[   28.042831] R13: 0000000001000001 R14: ffff88807b0efc08 R15: ffff8880761e6000
[   28.042836] FS:  0000000000000000(0000) GS:ffff88807d100000(0000) knlGS:0000000000000000
[   28.042840] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   28.042844] CR2: 000056284f3b4788 CR3: 000000000200a000 CR4: 00000000000006e0
[   28.042847] Call Trace:
[   28.042863]  ? wait_woken+0x80/0x80
[   28.043003]  intel_get_load_detect_pipe+0x381/0x3a0 [i915]
[   28.043122]  intel_tv_detect+0x12d/0x4e0 [i915]
[   28.043172]  ? drm_modeset_lock+0x30/0xa0 [drm]
[   28.043199]  drm_helper_probe_single_connector_modes+0xd3/0x6b0 [drm_kms_helper]
[   28.043223]  drm_setup_crtcs+0x18c/0xa30 [drm_kms_helper]
[   28.043232]  ? __switch_to_asm+0x40/0x70
[   28.043237]  ? __switch_to_asm+0x34/0x70
[   28.043241]  ? __switch_to_asm+0x40/0x70
[   28.043244]  ? __switch_to_asm+0x34/0x70
[   28.043248]  ? __switch_to_asm+0x40/0x70
[   28.043251]  ? __switch_to_asm+0x34/0x70
[   28.043272]  __drm_fb_helper_initial_config_and_unlock+0x3d/0x420 [drm_kms_helper]
[   28.043277]  ? __switch_to_asm+0x34/0x70
[   28.043281]  ? __switch_to_asm+0x40/0x70
[   28.043285]  ? finish_task_switch+0x71/0x280
[   28.043289]  intel_fbdev_initial_config+0x14/0x30 [i915]
[   28.043289]  async_run_entry_fn+0x37/0xe0
[   28.043289]  process_one_work+0x207/0x430
[   28.043289]  worker_thread+0x109/0x460
[   28.043289]  ? process_one_work+0x430/0x430
[   28.043289]  kthread+0x112/0x130
[   28.043289]  ? kthread_bind+0x30/0x30
[   28.043289]  ret_from_fork+0x35/0x40
[   28.043289] ---[ end trace 600c08a7d900feda ]---
[   38.180394] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:34:pipe A] flip_done timed out
[   48.420387] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:50:SVIDEO-1] flip_done timed out
[   48.442346] fbcon: inteldrmfb (fb0) is primary device
[   49.142535] Console: switching to colour frame buffer device 160x50
[   49.165919] i915 0000:00:02.0: fb0: inteldrmfb frame buffer device
[   59.683346] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:34:pipe A] flip_done timed out
[   59.784302] ------------[ cut here ]------------
[   59.784307] vblank wait timed out on crtc 0
[   59.784477] WARNING: CPU: 0 PID: 70 at drivers/gpu/drm/drm_vblank.c:1084 drm_wait_one_vblank+0x15c/0x170 [drm]
[   59.784479] Modules linked in: pktcdvd uvcvideo hid_generic videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev btusb btrtl usbhid btbcm btintel hid media bluetooth cpufreq_ondemand ecdh_generic joydev wl(PO) sr_mod iTCO_wdt iTCO_vendor_support acer_wmi cdrom sparse_keymap coretemp kvm arc4 irqbypass psmouse iwl3945 iwlegacy mac80211 ir_rc6_decoder rc_rc6_mce r852 sm_common cfg80211 nand nand_ecc nand_bch firewire_ohci bch i915 sdhci_pci r592 pcc_cpufreq firewire_core cqhci mtd memstick ata_generic pata_acpi ac battery acpi_cpufreq sdhci ene_ir mmc_core rfkill crc_itu_t rc_core wmi snd_hda_codec_hdmi lpc_ich thermal video ata_piix drm_kms_helper snd_hda_codec_realtek snd_hda_codec_generic ehci_pci uhci_hcd snd_hda_intel ehci_hcd drm snd_hda_codec usbcore usb_common tg3 snd_hda_core
[   59.784590]  i2c_algo_bit hwmon snd_hwdep snd_pcm i2c_core intel_agp intel_gtt vboxnetadp(O) vboxnetflt(O) pci_stub vboxpci(O) vboxdrv(O) dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi snd_seq_device snd_timer snd soundcore button ip_tables x_tables ipv6 crc_ccitt autofs4 ext4 crc32c_generic crc16 mbcache jbd2 fscrypto sd_mod ahci libahci libata scsi_mod evdev input_leds serio_raw xts af_packet dm_crypt dm_mod
[   59.784672] CPU: 0 PID: 70 Comm: kworker/0:2 Tainted: P        W  O      4.19.30-std-def-alt1 #1
[   59.784674] Hardware name: Acer       Aspire 5720     /Nettiling, BIOS V1.14 08/09/2007
[   59.784702] Workqueue: events output_poll_execute [drm_kms_helper]
[   59.784747] RIP: 0010:drm_wait_one_vblank+0x15c/0x170 [drm]
[   59.784753] Code: e0 0f 0b e9 32 ff ff ff 48 89 e6 4c 89 f7 e8 fb ea 98 e0 45 85 e4 0f 85 14 ff ff ff 89 ee 48 c7 c7 08 99 76 a0 e8 8e 5b 94 e0 <0f> 0b e9 ff fe ff ff e8 78 58 94 e0 0f 1f 84 00 00 00 00 00 66 66
[   59.784756] RSP: 0018:ffffc90000673ab0 EFLAGS: 00010282
[   59.784761] RAX: 0000000000000000 RBX: ffff88807b6d8000 RCX: 0000000000000006
[   59.784764] RDX: 0000000000000007 RSI: 0000000000000086 RDI: ffff88807d016560
[   59.784767] RBP: 0000000000000000 R08: fffffffffff1925c R09: 0000000000021240
[   59.784770] R10: 0000000f34bd1967 R11: 000000000000ebf0 R12: 0000000000000000
[   59.784773] R13: 0000000003000002 R14: ffff88807b0efc08 R15: ffff88807ba77000
[   59.784778] FS:  0000000000000000(0000) GS:ffff88807d000000(0000) knlGS:0000000000000000
[   59.784781] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   59.784784] CR2: 000056284f44ef38 CR3: 000000000200a000 CR4: 00000000000006f0
[   59.784788] Call Trace:
[   59.784805]  ? wait_woken+0x80/0x80
[   59.784905]  intel_get_load_detect_pipe+0x381/0x3a0 [i915]
[   59.784987]  intel_tv_detect+0x12d/0x4e0 [i915]
[   59.785017]  drm_helper_probe_single_connector_modes+0xd3/0x6b0 [drm_kms_helper]
[   59.785040]  drm_setup_crtcs+0x18c/0xa30 [drm_kms_helper]
[   59.785050]  ? async_synchronize_cookie_domain+0xbc/0xd0
[   59.785097]  ? drm_modeset_lock+0x63/0xa0 [drm]
[   59.785118]  ? drm_fb_helper_is_bound.isra.24+0x70/0xa0 [drm_kms_helper]
[   59.785138]  drm_fb_helper_hotplug_event.part.38+0x77/0xb0 [drm_kms_helper]
[   59.785157]  drm_kms_helper_hotplug_event+0x26/0x30 [drm_kms_helper]
[   59.785176]  output_poll_execute+0x198/0x1c0 [drm_kms_helper]
[   59.785184]  process_one_work+0x207/0x430
[   59.785189]  worker_thread+0x109/0x460
[   59.785193]  ? process_one_work+0x430/0x430
[   59.785198]  kthread+0x112/0x130
[   59.785204]  ? kthread_bind+0x30/0x30
[   59.785210]  ret_from_fork+0x35/0x40
[   59.785216] ---[ end trace 600c08a7d900fedb ]---
[   69.923348] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:34:pipe A] flip_done timed out
[   80.163346] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:50:SVIDEO-1] flip_done timed out
[   90.403348] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:34:pipe A] flip_done timed out
[   90.504312] ------------[ cut here ]------------
[   90.504316] vblank wait timed out on crtc 0
[   90.504487] WARNING: CPU: 0 PID: 70 at drivers/gpu/drm/drm_vblank.c:1084 drm_wait_one_vblank+0x15c/0x170 [drm]
[   90.504490] Modules linked in: pktcdvd uvcvideo hid_generic videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev btusb btrtl usbhid btbcm btintel hid media bluetooth cpufreq_ondemand ecdh_generic joydev wl(PO) sr_mod iTCO_wdt iTCO_vendor_support acer_wmi cdrom sparse_keymap coretemp kvm arc4 irqbypass psmouse iwl3945 iwlegacy mac80211 ir_rc6_decoder rc_rc6_mce r852 sm_common cfg80211 nand nand_ecc nand_bch firewire_ohci bch i915 sdhci_pci r592 pcc_cpufreq firewire_core cqhci mtd memstick ata_generic pata_acpi ac battery acpi_cpufreq sdhci ene_ir mmc_core rfkill crc_itu_t rc_core wmi snd_hda_codec_hdmi lpc_ich thermal video ata_piix drm_kms_helper snd_hda_codec_realtek snd_hda_codec_generic ehci_pci uhci_hcd snd_hda_intel ehci_hcd drm snd_hda_codec usbcore usb_common tg3 snd_hda_core
[   90.504597]  i2c_algo_bit hwmon snd_hwdep snd_pcm i2c_core intel_agp intel_gtt vboxnetadp(O) vboxnetflt(O) pci_stub vboxpci(O) vboxdrv(O) dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi snd_seq_device snd_timer snd soundcore button ip_tables x_tables ipv6 crc_ccitt autofs4 ext4 crc32c_generic crc16 mbcache jbd2 fscrypto sd_mod ahci libahci libata scsi_mod evdev input_leds serio_raw xts af_packet dm_crypt dm_mod
[   90.504675] CPU: 0 PID: 70 Comm: kworker/0:2 Tainted: P        W  O      4.19.30-std-def-alt1 #1
[   90.504678] Hardware name: Acer       Aspire 5720     /Nettiling, BIOS V1.14 08/09/2007
[   90.504706] Workqueue: events output_poll_execute [drm_kms_helper]
[   90.504750] RIP: 0010:drm_wait_one_vblank+0x15c/0x170 [drm]
[   90.504755] Code: e0 0f 0b e9 32 ff ff ff 48 89 e6 4c 89 f7 e8 fb ea 98 e0 45 85 e4 0f 85 14 ff ff ff 89 ee 48 c7 c7 08 99 76 a0 e8 8e 5b 94 e0 <0f> 0b e9 ff fe ff ff e8 78 58 94 e0 0f 1f 84 00 00 00 00 00 66 66
[   90.504758] RSP: 0018:ffffc90000673ab0 EFLAGS: 00010282
[   90.504763] RAX: 0000000000000000 RBX: ffff88807b6d8000 RCX: 0000000000000006
[   90.504766] RDX: 0000000000000007 RSI: 0000000000000086 RDI: ffff88807d016560
[   90.504769] RBP: 0000000000000000 R08: fffffffffff1a2cf R09: 0000000000021240
[   90.504772] R10: 0000000f6e70a6d1 R11: 000000000000db80 R12: 0000000000000000
[   90.504775] R13: 0000000005000003 R14: ffff88807b0efc08 R15: ffff88807ba77000
[   90.504780] FS:  0000000000000000(0000) GS:ffff88807d000000(0000) knlGS:0000000000000000
[   90.504783] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   90.504786] CR2: 00007f36e1b633dc CR3: 000000000200a000 CR4: 00000000000006f0
[   90.504789] Call Trace:
[   90.504807]  ? wait_woken+0x80/0x80
[   90.504907]  intel_get_load_detect_pipe+0x381/0x3a0 [i915]
[   90.504988]  intel_tv_detect+0x12d/0x4e0 [i915]
[   90.505018]  drm_helper_probe_single_connector_modes+0xd3/0x6b0 [drm_kms_helper]
[   90.505042]  drm_setup_crtcs+0x18c/0xa30 [drm_kms_helper]
[   90.505090]  ? drm_modeset_lock+0x63/0xa0 [drm]
[   90.505111]  ? drm_fb_helper_is_bound.isra.24+0x70/0xa0 [drm_kms_helper]
Comment 1 Ivan Zakharyaschev 2019-03-26 05:46:58 MSK 
Workaround valid for all the listed 4.20.*, 4.19.*, 4.9.* kernels in sisyphus and p8: https://bugs.freedesktop.org/show_bug.cgi?id=93782#c84 :

Adding "video=SVIDEO-1:d" to the kernel cmdline works.


The fix is https://bugs.freedesktop.org/show_bug.cgi?id=93782#c85 :

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.