Bug 98214 - drm/i915: WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)
Summary: drm/i915: WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)
Status: RESOLVED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: XOrg git
Hardware: x86-64 (AMD64) Linux (All)
: medium normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-10-12 14:46 UTC by Paul Bolle
Modified: 2016-12-02 13:54 UTC (History)
5 users (show)

See Also:
i915 platform: SKL
i915 features: display/Other


Attachments
dmesg excerpt #1 (4.33 KB, text/plain)
2016-10-22 16:16 UTC, bruno.pagani
no flags Details
dmesg excerpt #2 (4.27 KB, text/plain)
2016-10-22 16:17 UTC, bruno.pagani
no flags Details
dmesg excerpt #3 (4.27 KB, text/plain)
2016-10-22 16:17 UTC, bruno.pagani
no flags Details
dmesg excerpt #4 (4.26 KB, text/plain)
2016-10-22 16:18 UTC, bruno.pagani
no flags Details
dmesg with drm.debug=14 and running my small debugging patch (35.12 KB, text/plain)
2016-10-26 07:52 UTC, Paul Bolle
no flags Details
[PATCH] drm/i915: Fix cdclk vs. dev_cdclk mess when not recomputing things (1.49 KB, patch)
2016-10-26 17:34 UTC, Ville Syrjala
no flags Details | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Paul Bolle 2016-10-12 14:46:02 UTC
Reported at http://lkml.kernel.org/r/<1476266167.7439.8.camel@tiscali.nl> :

On a laptop that runs v4.8.y I see this WARNING:
    WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)

I never saw that WARNING in v4.7 and earlier. Since v4.8 I've had it in all boots.

Full trace:
WARNING: CPU: 3 PID: 1368 at drivers/gpu/drm/i915/intel_display.c:14178 skl_max_scale.part.120+0x75/0x80 [i915]
WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)
Modules linked in:
 rfcomm fuse nf_conntrack_netbios_ns nf_conntrack_broadcast ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 cmac nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables bnep vfat fat arc4 snd_hda_codec_hdmi snd_soc_skl dell_led snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp snd_hda_ext_core snd_soc_sst_match snd_soc_core intel_rapl snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal coretemp kvm_intel snd_compress snd_pcm_dmaengine ac97_bus kvm snd_hda_intel iwlmvm snd_hda_codec mac80211 iTCO_wdt
 iTCO_vendor_support uvcvideo snd_hda_core snd_hwdep snd_seq irqbypass dell_laptop i2c_designware_platform i2c_designware_core dell_wmi crct10dif_pclmul dell_smbios dcdbas crc32_pclmul snd_seq_device iwlwifi videobuf2_vmalloc videobuf2_memops ghash_clmulni_intel snd_pcm videobuf2_v4l2 videobuf2_core cfg80211 videodev media joydev pcspkr mei_me rtsx_pci_ms memstick snd_timer i2c_i801 i2c_smbus mei snd btusb soundcore shpchp hci_uart btrtl btbcm btqca idma64 btintel bluetooth intel_pch_thermal processor_thermal_device intel_lpss_pci intel_soc_dts_iosf wmi pinctrl_sunrisepoint intel_lpss_acpi rfkill pinctrl_intel intel_lpss int3400_thermal acpi_als int3403_thermal int340x_thermal_zone kfifo_buf acpi_thermal_rel intel_hid industrialio sparse_keymap acpi_pad tpm_tis tpm_tis_core tpm nfsd auth_rpcgss
 nfs_acl lockd grace sunrpc hid_multitouch i915 rtsx_pci_sdmmc mmc_core i2c_algo_bit drm_kms_helper crc32c_intel drm serio_raw nvme rtsx_pci nvme_core i2c_hid video fjes
CPU: 3 PID: 1368 Comm: Xorg Not tainted 4.8.1-1.local1.fc24.x86_64 #1
Hardware name: Dell Inc. XPS 13 9350/09JHRY, BIOS 1.4.4 06/14/2016
 0000000000000286 00000000df2f374c ffffa31528d53910 ffffffffb83e5cfd
 ffffa31528d53960 0000000000000000 ffffa31528d53950 ffffffffb80a7d5b
 00003762c72b3010 ffffa3151e4d8cc0 ffffa31526c23800 ffffa31526e60000
Call Trace:
 [<ffffffffb83e5cfd>] dump_stack+0x63/0x86
 [<ffffffffb80a7d5b>] __warn+0xcb/0xf0
 [<ffffffffb80a7ddf>] warn_slowpath_fmt+0x5f/0x80
 [<ffffffffb83f5247>] ? sort+0x147/0x220
 [<ffffffffc0132754>] ? drm_atomic_helper_normalize_zpos+0x264/0x300 [drm_kms_helper]
 [<ffffffffc01f20e5>] skl_max_scale.part.120+0x75/0x80 [i915]
 [<ffffffffc01f21b6>] intel_check_primary_plane+0xc6/0xe0 [i915]
 [<ffffffffc0132754>] ? drm_atomic_helper_normalize_zpos+0x264/0x300 [drm_kms_helper]
 [<ffffffffc01e33d2>] intel_plane_atomic_check+0x132/0x1f0 [i915]
 [<ffffffffc012f524>] drm_atomic_helper_check_planes+0x84/0x200 [drm_kms_helper]
 [<ffffffffc01fdd07>] intel_atomic_check+0x9a7/0x11a0 [i915]
 [<ffffffffb822c84a>] ? __kmalloc_track_caller+0x17a/0x210
 [<ffffffffc00bbf07>] drm_atomic_check_only+0x187/0x610 [drm]
 [<ffffffffc00bb6c8>] ? drm_atomic_get_crtc_state+0x88/0x100 [drm]
 [<ffffffffc00bc3a7>] drm_atomic_commit+0x17/0x60 [drm]
 [<ffffffffc012e90c>] drm_atomic_helper_update_plane+0xec/0x130 [drm_kms_helper]
 [<ffffffffc00ab16b>] __setplane_internal+0x22b/0x270 [drm]
 [<ffffffffc00ab2e9>] drm_mode_cursor_universal+0x139/0x240 [drm]
 [<ffffffffc00ab46e>] drm_mode_cursor_common+0x7e/0x180 [drm]
 [<ffffffffc00af9de>] drm_mode_cursor2_ioctl+0xe/0x10 [drm]
 [<ffffffffc00a1f0a>] drm_ioctl+0x1da/0x4b0 [drm]
 [<ffffffffc00af9d0>] ? drm_mode_cursor_ioctl+0x70/0x70 [drm]
 [<ffffffffb81161bd>] ? enqueue_hrtimer+0x3d/0x80
 [<ffffffffb8266693>] do_vfs_ioctl+0xa3/0x5e0
 [<ffffffffb86bc151>] ? __sys_recvmsg+0x51/0x90
 [<ffffffffb8266c49>] SyS_ioctl+0x79/0x90
 [<ffffffffb87fc4f2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
Comment 1 bruno.pagani 2016-10-22 16:15:59 UTC
Same here. Also happening to this person: https://bugs.freedesktop.org/show_bug.cgi?id=97293#c0. They are subtle variations, so posted all I’ve got.

I haven’t found any consequences of this warning, just noticed them in dmesg.
Comment 2 bruno.pagani 2016-10-22 16:16:55 UTC
Created attachment 127470 [details]
dmesg excerpt #1
Comment 3 bruno.pagani 2016-10-22 16:17:13 UTC
Created attachment 127471 [details]
dmesg excerpt #2
Comment 4 bruno.pagani 2016-10-22 16:17:29 UTC
Created attachment 127472 [details]
dmesg excerpt #3
Comment 5 bruno.pagani 2016-10-22 16:18:03 UTC
Created attachment 127473 [details]
dmesg excerpt #4
Comment 6 Joseph Yasi 2016-10-25 03:35:45 UTC
I am also seeing this same issue on an i7-6700K desktop after upgrading to v4.8. I never saw the issue in the 4.7.y series. It coincides with the screen going black for about a second and returning.

[Mon Oct 24 20:39:53 2016] ------------[ cut here ]------------
[Mon Oct 24 20:39:53 2016] WARNING: CPU: 7 PID: 1731 at drivers/gpu/drm/i915/intel_display.c:14178 skl_max_scale.part.123+0x64/0x70 [i915]
[Mon Oct 24 20:39:53 2016] WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)
[Mon Oct 24 20:39:53 2016] Modules linked in:
[Mon Oct 24 20:39:53 2016]  rfcomm pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) bnep binfmt_misc vfat fat snd_hda_codec_hdmi uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core videodev snd_usb_audio snd_hda_codec_realtek snd_usbmidi_lib media snd_hda_codec_generic intel_rapl x86_pkg_temp_thermal intel_powerclamp crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel input_leds aesni_intel aes_x86_64 lrw glue_helper ablk_helper cryptd intel_cstate intel_rapl_perf snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm_oss efi_pstore snd_mixer_oss btusb btrtl btbcm snd_pcm btintel bluetooth snd_seq_oss snd_seq_midi efivars snd_rawmidi snd_seq_midi_event snd_seq snd_seq_device snd_timer snd soundcore wl(PO) cfg80211 rfkill battery intel_lpss_acpi intel_lpss mfd_core
[Mon Oct 24 20:39:53 2016]  acpi_pad tpm_tis acpi_als tpm_tis_core kfifo_buf tpm industrialio sg coretemp loop nfsd auth_rpcgss oid_registry nfs_acl lockd grace sunrpc efivarfs ipv6 crc_ccitt hid_generic usbhid uas usb_storage mxm_wmi igb bcache dca i915 e1000e psmouse intel_gtt ptp xhci_pci drm_kms_helper pps_core syscopyarea hwmon sysfillrect sysimgblt xhci_hcd fb_sys_fops i2c_algo_bit drm sr_mod usbcore cdrom i2c_core usb_common fan thermal wmi pinctrl_sunrisepoint video pinctrl_intel button
[Mon Oct 24 20:39:53 2016] CPU: 7 PID: 1731 Comm: Xorg Tainted: P           O    4.8.4-customskl #1
[Mon Oct 24 20:39:53 2016] Hardware name: System manufacturer System Product Name/Z170-DELUXE, BIOS 2202 09/19/2016
[Mon Oct 24 20:39:53 2016]  0000000000000000 ffffffffb235b4ad ffff8f149fd8f9e0 0000000000000000
[Mon Oct 24 20:39:53 2016]  ffffffffb204b194 ffff8f13df140300 ffff8f149fd8fa30 ffff8f14b7426000
[Mon Oct 24 20:39:53 2016]  ffff8f13df140300 ffff8f14b343f400 ffffffffc06e2aa0 ffffffffb204b1fa
[Mon Oct 24 20:39:53 2016] Call Trace:
[Mon Oct 24 20:39:53 2016]  [<ffffffffb235b4ad>] ? dump_stack+0x46/0x59
[Mon Oct 24 20:39:53 2016]  [<ffffffffb204b194>] ? __warn+0xb4/0xd0
[Mon Oct 24 20:39:53 2016]  [<ffffffffb204b1fa>] ? warn_slowpath_fmt+0x4a/0x50
[Mon Oct 24 20:39:53 2016]  [<ffffffffb210a3fd>] ? kmemdup+0x2d/0x40
[Mon Oct 24 20:39:53 2016]  [<ffffffffc05b26b7>] ? drm_atomic_helper_normalize_zpos+0x237/0x2d0 [drm_kms_helper]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc068b584>] ? skl_max_scale.part.123+0x64/0x70 [i915]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc068b64b>] ? intel_check_primary_plane+0xbb/0xd0 [i915]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc05b26b7>] ? drm_atomic_helper_normalize_zpos+0x237/0x2d0 [drm_kms_helper]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc067d715>] ? intel_plane_atomic_check+0x125/0x1c0 [i915]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc05af8d7>] ? drm_atomic_helper_check_planes+0x77/0x1d0 [drm_kms_helper]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc0696988>] ? intel_atomic_check+0xa58/0x11a0 [i915]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04c7adc>] ? drm_atomic_check_only+0x17c/0x600 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04c7f6d>] ? drm_atomic_commit+0xd/0x50 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc05b1941>] ? drm_atomic_helper_disable_plane+0xa1/0xe0 [drm_kms_helper]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04b8361>] ? __setplane_internal+0x171/0x270 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04b8572>] ? drm_mode_cursor_universal+0x112/0x1f0 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04b86c6>] ? drm_mode_cursor_common+0x76/0x170 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04bc82f>] ? drm_mode_cursor_ioctl+0x3f/0x50 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04b03a7>] ? drm_ioctl+0x197/0x430 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffc04bc7f0>] ? drm_mode_setcrtc+0x510/0x510 [drm]
[Mon Oct 24 20:39:53 2016]  [<ffffffffb20161be>] ? do_signal+0x17e/0x670
[Mon Oct 24 20:39:53 2016]  [<ffffffffb211a854>] ? handle_mm_fault+0x774/0xf20
[Mon Oct 24 20:39:53 2016]  [<ffffffffb216b1ca>] ? do_vfs_ioctl+0x8a/0x5b0
[Mon Oct 24 20:39:53 2016]  [<ffffffffb217531b>] ? __fget+0x6b/0xb0
[Mon Oct 24 20:39:53 2016]  [<ffffffffb216b75f>] ? SyS_ioctl+0x6f/0x80
[Mon Oct 24 20:39:53 2016]  [<ffffffffb25ff41f>] ? entry_SYSCALL_64_fastpath+0x17/0x93
[Mon Oct 24 20:39:53 2016] ---[ end trace f134d3732f849a88 ]---
[Mon Oct 24 20:39:54 2016] [drm:gen8_irq_handler [i915]] *ERROR* CPU pipe A FIFO underrun
Comment 7 Daniel J Blueman 2016-10-25 05:45:23 UTC
I see this on an Dell XPS 15 9550 with internal eDP panel @ 3840x2160, 60Hz on kernel 4.8.4.

[ 2236.760626] WARNING: CPU: 1 PID: 1150 at /home/kernel/COD/linux/drivers/gpu/drm/i915/intel_display.c:14178 skl_max_scale.part.120+0x75/0x80 [i915]
[ 2236.760627] WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)
[ 2236.760628] Modules linked in:
[ 2236.760629]  bnep ax88179_178a usbnet mii ebtable_filter ebtables iptable_mangle xt_DSCP hid_multitouch snd_hda_codec_hdmi dell_led snd_hda_codec_realtek snd_hda_codec_generic i2c_designware_platform i2c_designware_core dell_wmi snd_hda_intel snd_hda_codec snd_hda_core dell_laptop snd_hwdep dell_smbios intel_rapl dcdbas x86_pkg_temp_thermal intel_powerclamp nls_iso8859_1 coretemp crct10dif_pclmul crc32_pclmul snd_pcm ghash_clmulni_intel aesni_intel snd_seq_midi snd_seq_midi_event aes_x86_64 lrw brcmfmac glue_helper ablk_helper snd_rawmidi cryptd uvcvideo intel_cstate brcmutil videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 intel_rapl_perf snd_seq videobuf2_core cfg80211 videodev input_leds joydev snd_seq_device media snd_timer rtsx_pci_ms snd memstick serio_raw soundcore idma64 virt_dma mei_me
[ 2236.760673]  shpchp processor_thermal_device mei intel_soc_dts_iosf intel_lpss_pci hci_uart btbcm btqca btintel bluetooth int3403_thermal intel_lpss_acpi dell_smo8800 intel_lpss int3402_thermal int3400_thermal intel_hid int340x_thermal_zone acpi_als acpi_pad acpi_thermal_rel sparse_keymap kfifo_buf mac_hid industrialio kvm_intel kvm irqbypass xt_hl ip6t_rt nf_conntrack_ipv6 nf_defrag_ipv6 ipt_REJECT nf_reject_ipv4 xt_limit xt_tcpudp xt_addrtype nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack ip6table_filter ip6_tables nf_conntrack_netbios_ns nf_conntrack_broadcast nf_nat_ftp nf_nat nf_conntrack_ftp nf_conntrack iptable_filter ip_tables x_tables parport_pc ppdev lp parport autofs4 rtsx_pci_sdmmc nouveau i915 mxm_wmi ttm i2c_algo_bit drm_kms_helper psmouse syscopyarea sysfillrect sysimgblt fb_sys_fops
[ 2236.760716]  nvme nvme_core drm rtsx_pci i2c_hid hid wmi pinctrl_sunrisepoint video pinctrl_intel fjes
[ 2236.760726] CPU: 1 PID: 1150 Comm: Xorg Not tainted 4.8.4-040804-generic #201610220733
[ 2236.760727] Hardware name: Dell Inc. XPS 15 9550/0N7TVV, BIOS 01.02.00 04/07/2016
[ 2236.760729]  0000000000000286 0000000066463e07 ffff8ed2e4f2b930 ffffffffafe12f12
[ 2236.760733]  ffff8ed2e4f2b980 0000000000000000 ffff8ed2e4f2b970 ffffffffafa82d9b
[ 2236.760736]  00003762000000b0 ffff8ed2e78896c0 ffff8ed2e2fd5800 ffff8ed2e36e5000
[ 2236.760739] Call Trace:
[ 2236.760744]  [<ffffffffafe12f12>] dump_stack+0x63/0x81
[ 2236.760748]  [<ffffffffafa82d9b>] __warn+0xcb/0xf0
[ 2236.760751]  [<ffffffffafa82e1f>] warn_slowpath_fmt+0x5f/0x80
[ 2236.760763]  [<ffffffffc04a5924>] ? drm_atomic_helper_normalize_zpos+0x264/0x300 [drm_kms_helper]
[ 2236.760799]  [<ffffffffc0580085>] skl_max_scale.part.120+0x75/0x80 [i915]
[ 2236.760830]  [<ffffffffc0580156>] intel_check_primary_plane+0xc6/0xe0 [i915]
[ 2236.760841]  [<ffffffffc04a5924>] ? drm_atomic_helper_normalize_zpos+0x264/0x300 [drm_kms_helper]
[ 2236.760875]  [<ffffffffc05713f2>] intel_plane_atomic_check+0x132/0x1f0 [i915]
[ 2236.760885]  [<ffffffffc04a2794>] drm_atomic_helper_check_planes+0x84/0x200 [drm_kms_helper]
[ 2236.760926]  [<ffffffffc058bef5>] intel_atomic_check+0x155/0x760 [i915]
[ 2236.760952]  [<ffffffffc0416757>] drm_atomic_check_only+0x187/0x610 [drm]
[ 2236.760972]  [<ffffffffc0416bf7>] drm_atomic_commit+0x17/0x60 [drm]
[ 2236.760983]  [<ffffffffc04a49ac>] drm_atomic_helper_disable_plane+0xac/0xf0 [drm_kms_helper]
[ 2236.761003]  [<ffffffffc040543b>] __setplane_internal+0x17b/0x270 [drm]
[ 2236.761006]  [<ffffffffafac6f60>] ? __wake_up_sync_key+0x50/0x60
[ 2236.761024]  [<ffffffffc0405669>] drm_mode_cursor_universal+0x139/0x240 [drm]
[ 2236.761046]  [<ffffffffc04057ee>] drm_mode_cursor_common+0x7e/0x180 [drm]
[ 2236.761070]  [<ffffffffc0409f10>] drm_mode_cursor_ioctl+0x50/0x70 [drm]
[ 2236.761091]  [<ffffffffc03fbda0>] drm_ioctl+0x200/0x4f0 [drm]
[ 2236.761115]  [<ffffffffc0409ec0>] ? drm_mode_setcrtc+0x580/0x580 [drm]
[ 2236.761120]  [<ffffffffafc30d97>] ? __vfs_read+0x37/0x150
[ 2236.761124]  [<ffffffffafc46a53>] do_vfs_ioctl+0xa3/0x600
[ 2236.761129]  [<ffffffffafa9015b>] ? recalc_sigpending+0x1b/0x50
[ 2236.761134]  [<ffffffffafa90f21>] ? __set_task_blocked+0x41/0xa0
[ 2236.761138]  [<ffffffffafc47029>] SyS_ioctl+0x79/0x90
[ 2236.761140]  [<ffffffffafa93b9e>] ? SyS_rt_sigprocmask+0x8e/0xc0
[ 2236.761145]  [<ffffffffb0282ef6>] entry_SYSCALL_64_fastpath+0x1e/0xa8
[ 2236.761148] ---[ end trace 0a69ec658ca26029 ]---
[ 2290.023659] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=3183 end=3184) time 560 us, min 2146, max 2159, scanline start 2120, end 2189
[ 3356.918317] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=67193 end=67194) time 719 us, min 2146, max 2159, scanline start 2107, end 2197
[ 5485.971871] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=194929 end=194930) time 785 us, min 2146, max 2159, scanline start 2073, end 2166
[ 5962.865923] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=223541 end=223542) time 281 us, min 2146, max 2159, scanline start 2134, end 2160
[ 6072.139161] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=230097 end=230098) time 627 us, min 2146, max 2159, scanline start 2102, end 2185
[ 6072.155778] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=230098 end=230099) time 753 us, min 2146, max 2159, scanline start 2091, end 2197
[ 6133.875655] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=233801 end=233802) time 280 us, min 2146, max 2159, scanline start 2137, end 2180
Comment 8 Paul Bolle 2016-10-25 07:17:15 UTC
(In reply to Joseph Yasi from comment #6)
> It coincides with the screen going black for about a second and returning.

> [Mon Oct 24 20:39:54 2016] [drm:gen8_irq_handler [i915]] *ERROR* CPU pipe A
> FIFO underrun

The screen going black could be related to that *ERROR*.

I'm seeing something similar too (but it coincides with a very quick, well, flashing of the screen). In my case it looks independent of this annoying WARNING. Ie, most of these WARNINGs happen without a nearby FIFO underrun *ERROR* and vice versa.
Comment 9 Paul Bolle 2016-10-25 07:19:30 UTC
(In reply to Daniel J Blueman from comment #7)
> [ 2290.023659] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update
> failure on pipe A (start=3183 end=3184) time 560 us, min 2146, max 2159,
> scanline start 2120, end 2189
> [repeated quite a few times]

I'm not seeing that. My guess is that it is unrelated to this issue.
Comment 10 Paul Bolle 2016-10-26 07:43:26 UTC
0) Partial copy of my message at http://lkml.kernel.org/r/<1477342074.1872.24.camel@tiscali.nl> :

1) So I used the most reliable debugging tool that I actually
understand: printk():

diff --git a/drivers/gpu/drm/i915/intel_display.c b/drivers/gpu/drm/i915/intel_display.c
index fbcfed63a76e..791de414cf1e 100644
--- a/drivers/gpu/drm/i915/intel_display.c
+++ b/drivers/gpu/drm/i915/intel_display.c
@@ -14771,10 +14771,16 @@ skl_max_scale(struct intel_crtc *intel_crtc, struct intel_crtc_state *crtc_state
                return DRM_PLANE_HELPER_NO_SCALING;
 
        crtc_clock = crtc_state->base.adjusted_mode.crtc_clock;
-       cdclk = to_intel_atomic_state(crtc_state->base.state)->cdclk;
+       if (WARN_ON_ONCE(!crtc_clock))
+               return DRM_PLANE_HELPER_NO_SCALING;
 
-       if (WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock))
+       cdclk = to_intel_atomic_state(crtc_state->base.state)->cdclk;
+       if (WARN_ON_ONCE(cdclk < crtc_clock)) {
+               printk(KERN_DEBUG "i915: cdclk < crtc_clock: %d < %d\n", cdclk, crtc_clock);
                return DRM_PLANE_HELPER_NO_SCALING;
+       }
+
+       printk_ratelimited(KERN_DEBUG "i915: cdclk >= crtc_clock: %d >= %d\n", cdclk, crtc_clock);
 
        /*
         * skl max scale is lower of:

2) This taught me that crtc_clock always is 373250 on my machine. cdclk
mostly is 450000, but every now and then it briefly is 337500.

3) Now the interesting pattern is that cdclk drops to 337500 only after
two quick calls of skl_max_scale() with cdclk set to 450000, and a
roughly 300ms pause before the third call of that function. Example:

<7>[23758.501933] i915: cdclk >= crtc_clock: 450000 >= 373250
<7>[23758.515211] i915: cdclk >= crtc_clock: 450000 >= 373250
<7>[23758.869057] i915: cdclk < crtc_clock: 337500 < 373250

This pattern of cdclk being 337500 after roughly 300ms is surprisingly
stable.

4) So _perhaps_ there's some roughly 300ms timeout, somehow, somewhere,
that sets cdclk to 337500 and triggers this issue. Ideas?
Comment 11 Paul Bolle 2016-10-26 07:52:09 UTC
Created attachment 127551 [details]
dmesg with drm.debug=14 and running my small debugging patch

Jani Nikula requested I "attach dmesg [..] with drm.debug=14 and running your patch".

It is the part of dmesg that includes a typical WARN_ON_ONCE(). The interesting stuff is between timestamp 6382 and 6387.

I have no idea what explains the large jump between timestamp 6387 and timestamp 7513. AFK?
Comment 12 Ville Syrjala 2016-10-26 17:34:17 UTC
Created attachment 127554 [details] [review]
[PATCH] drm/i915: Fix cdclk vs. dev_cdclk mess when not recomputing  things

This could fix it, I think. Please test.
Comment 13 Paul Bolle 2016-10-26 19:06:53 UTC
@Ville,

0) Your patch builds and boots fine. On top of v4.8.4, that is.

1) So far so good. I'll only report success if the WARN_ON_ONCE() isn't hit before v4.8.5 is released (which means I'll test this patch for about a day and a half).
Comment 14 Paul Bolle 2016-10-28 09:04:35 UTC
(In reply to Paul Bolle from comment #13)
> 1) So far so good. I'll only report success if the WARN_ON_ONCE() isn't hit
> before v4.8.5 is released (which means I'll test this patch for about a day
> and a half).

I'm about to reboot in v4.8.5 and can report success! No WARN_ON_ONCE was triggered in over a day and a half of uptime. (The FIFO underrun error is still there, so I'm positive it's a separate issue.)

This qualifies as a "Tested-by: Paul Bolle <pebolle@tiscali.nl>", I guess.

Have fun writing a real commit explanation!
Comment 15 Joseph Yasi 2016-10-28 13:52:44 UTC
I can also confirm the patch got rid of the warning for me as well, but not the underruns.
Comment 16 bruno.pagani 2016-10-28 13:55:58 UTC
The FIFO underrun must be something separate, since I don’t have any.
Comment 17 yann 2016-11-02 13:56:27 UTC
Reference to Ville's patch : https://patchwork.freedesktop.org/series/14540/
Comment 18 Daniel Rowe 2016-11-03 12:00:57 UTC
Also seeing this issue on a intel NUC 6th gen on Fedora 24 which has just updated to 4.8.*.

Also see screen flicker and see this in dmesg:

intel_display.c:14178 skl_max_scale.part.120+0x75/0x80 [i915]
[drm:intel_dp_link_training_clock_recovery [i915]] *ERROR* too many full retries, give up

------------[ cut here ]------------
[ 1317.038438] WARNING: CPU: 0 PID: 1410 at drivers/gpu/drm/i915/intel_display.c:14178 skl_max_scale.part.120+0x75/0x80 [i915]
[ 1317.038439] WARN_ON_ONCE(!crtc_clock || cdclk < crtc_clock)
[ 1317.038440] Modules linked in:
[ 1317.038442]  rfcomm fuse xt_CHECKSUM ipt_MASQUERADE nf_nat_masquerade_ipv4 tun rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache nf_conntrack_netbios_ns nf_conntrack_broadcast ip6t_REJECT nf_reject_ipv6 ip6t_rpfilter xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_raw ip6table_mangle ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_raw iptable_mangle iptable_security ebtable_filter ebtables ip6table_filter ip6_tables cmac bnep vfat fat arc4 intel_rapl x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_hdmi coretemp kvm_intel snd_soc_skl kvm snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp snd_hda_ext_core snd_hda_codec_realtek snd_soc_sst_match snd_hda_codec_generic
[ 1317.038491]  snd_soc_core snd_compress snd_pcm_dmaengine iwlmvm ac97_bus snd_hda_intel snd_hda_codec mac80211 iTCO_wdt snd_hda_core iTCO_vendor_support snd_hwdep irqbypass snd_seq crct10dif_pclmul crc32_pclmul snd_seq_device ghash_clmulni_intel intel_cstate snd_pcm intel_uncore hci_uart iwlwifi btusb btqca btrtl intel_rapl_perf joydev btbcm cfg80211 btintel bluetooth snd_timer mei_me mei snd idma64 soundcore i2c_i801 ir_lirc_codec lirc_dev intel_lpss_pci shpchp i2c_smbus intel_pch_thermal rfkill rc_rc6_mce ite_cir pinctrl_sunrisepoint rc_core intel_lpss_acpi pinctrl_intel intel_lpss acpi_pad acpi_als kfifo_buf industrialio tpm_tis tpm_tis_core tpm nfsd auth_rpcgss nfs_acl lockd grace sunrpc 8021q garp stp llc mrp btrfs xor raid6_pq i915 i2c_algo_bit e1000e drm_kms_helper crc32c_intel drm sdhci_pci
[ 1317.038575]  ptp sdhci pps_core mmc_core nvme nvme_core video i2c_hid fjes
[ 1317.038588] CPU: 0 PID: 1410 Comm: Xorg Not tainted 4.8.4-200.fc24.x86_64 #1
[ 1317.038590] Hardware name:                  /NUC6i5SYB, BIOS SYSKLi35.86A.0052.2016.0910.1456 09/10/2016
[ 1317.038593]  0000000000000286 0000000039322c5c ffff8fd4a9c0b910 ffffffffb33e5d0d
[ 1317.038598]  ffff8fd4a9c0b960 0000000000000000 ffff8fd4a9c0b950 ffffffffb30a0e4b
[ 1317.038601]  00003762000000b0 ffff8fd49caed240 ffff8fd4a7fcc000 ffff8fd4a8836000
[ 1317.038604] Call Trace:
[ 1317.038618]  [<ffffffffb33e5d0d>] dump_stack+0x63/0x86
[ 1317.038624]  [<ffffffffb30a0e4b>] __warn+0xcb/0xf0
[ 1317.038627]  [<ffffffffb30a0ecf>] warn_slowpath_fmt+0x5f/0x80
[ 1317.038632]  [<ffffffffb33f52a7>] ? sort+0x147/0x220
[ 1317.038651]  [<ffffffffc01b4754>] ? drm_atomic_helper_normalize_zpos+0x264/0x300 [drm_kms_helper]
[ 1317.038701]  [<ffffffffc0290375>] skl_max_scale.part.120+0x75/0x80 [i915]
[ 1317.038749]  [<ffffffffc0290446>] intel_check_primary_plane+0xc6/0xe0 [i915]
[ 1317.038766]  [<ffffffffc01b4754>] ? drm_atomic_helper_normalize_zpos+0x264/0x300 [drm_kms_helper]
[ 1317.038821]  [<ffffffffc0281662>] intel_plane_atomic_check+0x132/0x1f0 [i915]
[ 1317.038837]  [<ffffffffc01b1524>] drm_atomic_helper_check_planes+0x84/0x200 [drm_kms_helper]
[ 1317.038887]  [<ffffffffc029bf87>] intel_atomic_check+0x9a7/0x11a0 [i915]
[ 1317.038894]  [<ffffffffb3229d0b>] ? __kmalloc_track_caller+0x16b/0x210
[ 1317.038919]  [<ffffffffc014c0d7>] drm_atomic_check_only+0x187/0x610 [drm]
[ 1317.038939]  [<ffffffffc014b898>] ? drm_atomic_get_crtc_state+0x88/0x100 [drm]
[ 1317.038962]  [<ffffffffc014c577>] drm_atomic_commit+0x17/0x60 [drm]
[ 1317.038977]  [<ffffffffc01b090c>] drm_atomic_helper_update_plane+0xec/0x130 [drm_kms_helper]
[ 1317.039001]  [<ffffffffc013b21b>] __setplane_internal+0x22b/0x270 [drm]
[ 1317.039023]  [<ffffffffc013b399>] drm_mode_cursor_universal+0x139/0x240 [drm]
[ 1317.039048]  [<ffffffffc013b51e>] drm_mode_cursor_common+0x7e/0x180 [drm]
[ 1317.039073]  [<ffffffffc013fabe>] drm_mode_cursor2_ioctl+0xe/0x10 [drm]
[ 1317.039095]  [<ffffffffc0131fa0>] drm_ioctl+0x200/0x4f0 [drm]
[ 1317.039126]  [<ffffffffc013fab0>] ? drm_mode_cursor_ioctl+0x70/0x70 [drm]
[ 1317.039137]  [<ffffffffb311178d>] ? enqueue_hrtimer+0x3d/0x80
[ 1317.039141]  [<ffffffffb3264cf3>] do_vfs_ioctl+0xa3/0x5f0
[ 1317.039145]  [<ffffffffb36bd191>] ? __sys_recvmsg+0x51/0x90
[ 1317.039148]  [<ffffffffb32652b9>] SyS_ioctl+0x79/0x90
[ 1317.039154]  [<ffffffffb3802572>] entry_SYSCALL_64_fastpath+0x1a/0xa4
[ 1317.039226] ---[ end trace d9c8cd460822922a ]---
Comment 19 belette 2016-11-25 21:31:15 UTC
any idea if this would be go upstream soon?
I confirm I got the same problem on Archlinux / Parabola and the only option is to go back to 4.7.X :(
Comment 20 Ville Syrjala 2016-12-02 13:54:36 UTC
Looks like I forgot to close the bug when I pushed the patch:

commit e0ca7a6be38ce603d26df5707c22e53870a623e0
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Mon Nov 14 18:35:09 2016 +0200

    drm/i915: Fix cdclk vs. dev_cdclk mess when not recomputing things

A second small fix was also needed:

commit 6a259b1f8a9e99b1ed114f8bf8b0cfccee130e54
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Tue Nov 29 16:13:57 2016 +0200

    drm/i915: Initialize dev_priv->atomic_cdclk_freq at init time


bug/show.html.tmpl processed on Feb 22, 2017 at 10:43:22.
(provided by the Example extension).