Bug 103326

Summary:	[CI] igt@* - dmesg-warn - ERROR timeout waiting for pcode write of 0x[0\|8]000000[0,1,6] to mbox 17 to finish for bxt_set_cdclk [i915]
Product:	DRI	Reporter:	Marta Löfstedt <marta.lofstedt>
Component:	DRM/Intel	Assignee:	Marta Löfstedt <marta.lofstedt>
Status:	CLOSED FIXED	QA Contact:	Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity:	normal
Priority:	medium	CC:	intel-gfx-bugs
Version:	DRI git
Hardware:	Other
OS:	All
Whiteboard:	ReadyForDev
i915 platform:	BXT, GLK	i915 features:	power/runtime PM

Description Marta Löfstedt 2017-10-18 07:36:43 UTC

CI_DRM_3252 APL-shards igt@pm_rpm@universal-planes-dpms dmesg-warn.

<7>[   43.094632] [drm:__bxt_hpd_detection_setup [i915]] Invert bit setting: hp_ctl:10001818 hp_port:38
<7>[   43.095839] [drm:__bxt_hpd_detection_setup [i915]] Invert bit setting: hp_ctl:10001818 hp_port:30
<7>[   43.095935] [drm:intel_runtime_resume [i915]] Device resumed
<7>[   43.096147] [drm:intel_runtime_suspend [i915]] Suspending device
<7>[   43.097049] [drm:gen9_set_dc_state [i915]] Setting DC state from 01 to 00
<3>[   43.098443] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x00000001 to mbox 17 to finish for bxt_set_cdclk [i915]
<3>[   43.098535] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq set failed, (err -110, freq 19200)
<7>[   43.098579] [drm:intel_power_well_disable [i915]] disabling power well 1
<7>[   43.098633] [drm:hsw_power_well_disable [i915]] power well 1 forced on (bios:1 driver:0 kvmr:0 debug:1)
<7>[   43.098729] [drm:bxt_enable_dc9 [i915]] Enabling DC9
<7>[   43.098773] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 08
<7>[   43.098831] [drm:intel_runtime_suspend [i915]] Device suspended
<7>[   43.122718] [drm:intel_runtime_resume [i915]] Resuming device

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3252/shard-apl6/igt@pm_rpm@universal-planes-dpms.html

Comment 1 Marta Löfstedt 2017-10-20 06:58:52 UTC

Also, CI_DRM_3266 GLK-shards igt@pm_rpm@universal-planes 

<7>[ 2362.849591] [drm:intel_runtime_suspend [i915]] Suspending device
<7>[ 2362.851517] [drm:gen9_set_dc_state [i915]] Setting DC state from 01 to 00
<3>[ 2362.853086] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
<3>[ 2362.853159] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)
<7>[ 2362.853193] [drm:intel_power_well_disable [i915]] disabling power well 1
<7>[ 2362.853233] [drm:hsw_power_well_disable [i915]] power well 1 forced on (bios:1 driver:0 kvmr:0 debug:0)

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3266/shard-glkb2/igt@pm_rpm@universal-planes.html

Comment 2 Marta Löfstedt 2017-10-23 07:39:03 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3272/shard-glkb1/igt@kms_flip@wf_vblank-vs-modeset.html

Comment 3 Marta Löfstedt 2017-10-23 10:09:24 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3274/shard-apl1/igt@kms_flip@vblank-vs-modeset-rpm-interruptible.html

Note this also hit a backtrace:
	

[  356.197331] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x00000006 to mbox 17 to finish for bxt_set_cdclk [i915]
[  356.197381] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq set failed, (err -110, freq 144000)
[  356.199523] WARN_ON(!intel_cdclk_state_compare(&dev_priv->cdclk.hw, &cdclk_state))
[  356.199556] ------------[ cut here ]------------
[  356.199598] WARNING: CPU: 3 PID: 2329 at drivers/gpu/drm/i915/intel_runtime_pm.c:708 gen9_dc_off_power_well_enable+0x1c5/0x210 [i915]
[  356.199602] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep lpc_ich snd_hda_core r8169 mii mei_me snd_pcm mei prime_numbers pinctrl_broxton pinctrl_intel
[  356.199647] CPU: 3 PID: 2329 Comm: kms_flip Tainted: G     U          4.14.0-rc5-CI-CI_DRM_3274+ #1
[  356.199650] Hardware name:                  /NUC6CAYB, BIOS AYAPLCEL.86A.0040.2017.0619.1722 06/19/2017
[  356.199654] task: ffff88026a830040 task.stack: ffffc90000a60000
[  356.199692] RIP: 0010:gen9_dc_off_power_well_enable+0x1c5/0x210 [i915]
[  356.199695] RSP: 0018:ffffc90000a63a40 EFLAGS: 00010286
[  356.199700] RAX: 0000000000000046 RBX: ffff880264ec0000 RCX: 0000000000000000
[  356.199703] RDX: 0000000080000001 RSI: 0000000000000001 RDI: ffffffff810efd60
[  356.199705] RBP: ffffc90000a63a58 R08: 0000000000000001 R09: 0000000000000000
[  356.199708] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880264ec0000
[  356.199712] R13: ffff880264ec0000 R14: 0000000200000000 R15: aaaaaaaaaaaaaaab
[  356.199715] FS:  00007f79116aba40(0000) GS:ffff88027fd80000(0000) knlGS:0000000000000000
[  356.199718] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  356.199722] CR2: 00007f243d66a000 CR3: 0000000273234000 CR4: 00000000003406e0
[  356.199725] Call Trace:
[  356.199767]  intel_power_well_enable+0x3a/0x50 [i915]
[  356.199806]  __intel_display_power_get_domain+0x81/0xa0 [i915]
[  356.199845]  intel_display_power_get+0x35/0x50 [i915]
[  356.199890]  intel_atomic_commit_tail+0xa5f/0xbf0 [i915]
[  356.199939]  intel_atomic_commit+0x21f/0x2b0 [i915]
[  356.199947]  drm_atomic_commit+0x4b/0x50
[  356.199953]  drm_atomic_helper_set_config+0x81/0x90
[  356.199958]  __drm_mode_set_config_internal+0x65/0x110
[  356.199962]  drm_mode_setcrtc+0x4c8/0x650
[  356.199968]  ? preempt_count_add+0x77/0xb0
[  356.199976]  ? drm_mode_getcrtc+0x190/0x190
[  356.199981]  drm_ioctl_kernel+0x69/0xb0
[  356.199986]  drm_ioctl+0x2f9/0x3d0
[  356.199989]  ? drm_mode_getcrtc+0x190/0x190
[  356.199997]  ? __vfs_read+0x28/0x120
[  356.200002]  do_vfs_ioctl+0x94/0x670
[  356.200036]  ? vfs_read+0x12d/0x150
[  356.200041]  SyS_ioctl+0x41/0x70
[  356.200047]  entry_SYSCALL_64_fastpath+0x1c/0xb1
[  356.200051] RIP: 0033:0x7f790f8ac587
[  356.200057] RSP: 002b:00007ffea0320be8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  356.200061] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f790f8ac587
[  356.200064] RDX: 00007ffea0320c20 RSI: 00000000c06864a2 RDI: 0000000000000003
[  356.200067] RBP: 00007ffea0320cb0 R08: 0000000000000000 R09: 00007ffea03210c8
[  356.200070] R10: 00007ffea0320f74 R11: 0000000000000246 R12: 20c49ba5e353f7cf
[  356.200073] R13: 00007ffea0320da0 R14: 0000000000000002 R15: 00007ffea0320f70
[  356.200080] Code: fe ff ff 8b 72 24 48 89 df e8 f8 c7 08 00 e9 d8 fe ff ff 8b 41 0c eb 82 48 c7 c6 c8 1e 25 a0 48 c7 c7 89 17 24 a0 e8 fc 2e fc e0 <0f> ff e9 80 fe ff ff 89 c6 48 c7 c7 10 1f 25 a0 e8 e7 2e fc e0 
[  356.200177] ---[ end trace c5edb6a763aade6f ]---

Comment 4 Marta Löfstedt 2017-10-27 07:24:21 UTC

new subtest 
CI_DRM_3287 shard-glkb1 igt@kms_draw_crc@draw-method-rgb565-mmap-gtt-ytiled

dmesg-warn:

[ 2098.905029] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 2098.905089] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3287/shard-glkb1/igt@kms_draw_crc@draw-method-rgb565-mmap-gtt-ytiled.html

Comment 5 Marta Löfstedt 2017-10-30 07:40:24 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3291/shard-glkb1/igt@kms_atomic_interruptible@legacy-dpms.html

[  413.273115] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  413.273185] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 6 Marta Löfstedt 2017-11-01 06:46:40 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3304/shard-glkb1/igt@kms_flip@wf_vblank-vs-dpms-interruptible.html

<7>[ 2682.301320] [drm:intel_runtime_suspend [i915]] Suspending device
<7>[ 2682.302309] [drm:gen9_set_dc_state [i915]] Setting DC state from 01 to 00
<3>[ 2682.303849] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
<3>[ 2682.303892] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)
<7>[ 2682.303930] [drm:intel_power_well_disable [i915]] disabling power well 1
<7>[ 2682.303971] [drm:hsw_power_well_disable [i915]] power well 1 forced on (bios:1 driver:0 kvmr:0 debug:0)

Comment 7 Ville Syrjala 2017-11-01 09:42:59 UTC

(In reply to Marta Löfstedt from comment #6)
> <3>[ 2682.303849] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout
> waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk
> [i915]
> <3>[ 2682.303892] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change
> notify failed (err -110, freq 19200)

Sigh. I wonder if we need to start doing something similar to
skl_pcode_request() on bxt/glk as well.

Comment 8 Marta Löfstedt 2017-11-02 07:00:17 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3305/shard-glkb2/igt@kms_flip@wf_vblank-vs-modeset-interruptible.html

[  968.532100] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  968.532173] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 9 Marta Löfstedt 2017-11-06 07:04:16 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3313/shard-glkb2/igt@kms_plane@plane-panning-bottom-right-pipe-C-planes.html

[  360.992930] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  360.993052] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 10 Marta Löfstedt 2017-11-10 08:20:26 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3326/shard-glkb2/igt@pm_rpm@legacy-planes-dpms.html

[  942.774936] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  942.775007] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 11 Marta Löfstedt 2017-11-10 08:25:58 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3328/shard-glkb2/igt@kms_flip@blt-wf_vblank-vs-dpms-interruptible.html

	

[  124.295320] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x0000000d to mbox 17 to finish for bxt_set_cdclk [i915]
[  124.295385] [drm:bxt_set_cdclk [i915]] *ERROR* PCode CDCLK freq set failed, (err -110, freq 316800)
[  124.295390] cdclk state doesn't match!
[  124.295429] ------------[ cut here ]------------
[  124.295465] WARNING: CPU: 1 PID: 1456 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x5d/0x110 [i915]
[  124.295468] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me r8169 mii mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  124.295539] CPU: 1 PID: 1456 Comm: kms_flip Tainted: G     U          4.14.0-rc8-CI-CI_DRM_3328+ #1
[  124.295542] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  124.295546] task: ffff880174fe8040 task.stack: ffffc90000294000
[  124.295579] RIP: 0010:intel_set_cdclk+0x5d/0x110 [i915]
[  124.295582] RSP: 0018:ffffc90000297b00 EFLAGS: 00010286
[  124.295588] RAX: 000000000000001a RBX: ffff880166cf0000 RCX: 0000000000000001
[  124.295591] RDX: 0000000080000001 RSI: ffffffff81cb63e3 RDI: 00000000ffffffff
[  124.295594] RBP: ffffc90000297b10 R08: ffff880174fe8928 R09: 0000000000000000
[  124.295597] R10: 00000000d92cac81 R11: 0000000000000000 R12: ffff880166cf561c
[  124.295600] R13: ffff880170d78008 R14: ffff880170d7d3d8 R15: ffff88016491ae98
[  124.295603] FS:  00007f1a8e802a40(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
[  124.295606] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  124.295608] CR2: 00007f566469b000 CR3: 0000000168cc2000 CR4: 00000000003406e0
[  124.295611] Call Trace:
[  124.295648]  intel_atomic_commit_tail+0x8d1/0xbe0 [i915]
[  124.295687]  intel_atomic_commit+0x223/0x2d0 [i915]
[  124.295697]  drm_atomic_commit+0x4b/0x50
[  124.295701]  drm_atomic_connector_commit_dpms+0xee/0x100
[  124.295707]  set_property_atomic+0xec/0x110
[  124.295716]  drm_mode_obj_set_property_ioctl+0xcb/0x180
[  124.295721]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  124.295726]  drm_mode_connector_property_set_ioctl+0x30/0x40
[  124.295730]  drm_ioctl_kernel+0x69/0xb0
[  124.295736]  drm_ioctl+0x2f9/0x3d0
[  124.295739]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  124.295748]  ? lock_acquire+0xb0/0x200
[  124.295754]  ? __fget+0xe5/0x1f0
[  124.295761]  do_vfs_ioctl+0x94/0x670
[  124.295765]  ? __fget+0x102/0x1f0
[  124.295772]  SyS_ioctl+0x41/0x70
[  124.295779]  entry_SYSCALL_64_fastpath+0x1c/0xb1
[  124.295782] RIP: 0033:0x7f1a8ca01587
[  124.295785] RSP: 002b:00007fffc5122928 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  124.295790] RAX: ffffffffffffffda RBX: ffffffff81492003 RCX: 00007f1a8ca01587
[  124.295793] RDX: 00007fffc5122960 RSI: 00000000c01064ab RDI: 0000000000000003
[  124.295795] RBP: ffffc90000297f88 R08: 0000000000000001 R09: 0000000000000060
[  124.295798] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[  124.295800] R13: 0000000000000003 R14: 00000000c01064ab R15: 0000000000000003
[  124.295807]  ? __this_cpu_preempt_check+0x13/0x20
[  124.295813] Code: 89 e7 e8 87 ff ff ff 4c 89 e6 48 89 df ff 93 50 56 00 00 41 8b 04 24 39 83 2c 56 00 00 74 65 48 c7 c7 4a 36 25 a0 e8 b4 9a f4 e0 <0f> ff 48 8d bb 2c 56 00 00 48 c7 c6 66 36 25 a0 e8 4e ff ff ff 
[  124.295970] ---[ end trace 10f1c258bbd52cd9 ]---
[  124.803100] WARN_ON(intel_cdclk_needs_modeset(&dev_priv->cdclk.hw, &cdclk_state))
[  124.803143] ------------[ cut here ]------------
[  124.803191] WARNING: CPU: 3 PID: 1456 at drivers/gpu/drm/i915/intel_runtime_pm.c:709 gen9_dc_off_power_well_enable+0x1c6/0x210 [i915]
[  124.803196] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me r8169 mii mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  124.803298] CPU: 3 PID: 1456 Comm: kms_flip Tainted: G     U  W       4.14.0-rc8-CI-CI_DRM_3328+ #1
[  124.803303] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  124.803308] task: ffff880174fe8040 task.stack: ffffc90000294000
[  124.803355] RIP: 0010:gen9_dc_off_power_well_enable+0x1c6/0x210 [i915]
[  124.803360] RSP: 0018:ffffc90000297a78 EFLAGS: 00010296
[  124.803368] RAX: 0000000000000045 RBX: ffff880166cf0000 RCX: 0000000000000006
[  124.803373] RDX: 00000000000013b5 RSI: ffffffff81d11254 RDI: ffffffff81cc3d2e
[  124.803377] RBP: ffffc90000297a90 R08: ffff880174fe8950 R09: 0000000000000000
[  124.803381] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880166cf0000
[  124.803386] R13: ffff880166cf0000 R14: 0000000200000000 R15: aaaaaaaaaaaaaaab
[  124.803391] FS:  00007f1a8e802a40(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
[  124.803396] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  124.803400] CR2: 00007f1a8e77e000 CR3: 0000000168cc2000 CR4: 00000000003406e0
[  124.803405] Call Trace:
[  124.803456]  intel_power_well_enable+0x3a/0x50 [i915]
[  124.803504]  __intel_display_power_get_domain+0x81/0xa0 [i915]
[  124.803554]  intel_display_power_get+0x35/0x50 [i915]
[  124.803607]  intel_atomic_commit_tail+0xa4e/0xbe0 [i915]
[  124.803665]  intel_atomic_commit+0x223/0x2d0 [i915]
[  124.803675]  drm_atomic_commit+0x4b/0x50
[  124.803682]  drm_atomic_connector_commit_dpms+0xee/0x100
[  124.803691]  set_property_atomic+0xec/0x110
[  124.803707]  drm_mode_obj_set_property_ioctl+0xcb/0x180
[  124.803714]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  124.803721]  drm_mode_connector_property_set_ioctl+0x30/0x40
[  124.803728]  drm_ioctl_kernel+0x69/0xb0
[  124.803736]  drm_ioctl+0x2f9/0x3d0
[  124.803742]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  124.803756]  ? lock_acquire+0xb0/0x200
[  124.803761]  ? trace_hardirqs_on_caller+0xe3/0x1b0
[  124.803768]  ? __fget+0xe5/0x1f0
[  124.803779]  do_vfs_ioctl+0x94/0x670
[  124.803785]  ? __fget+0x102/0x1f0
[  124.803796]  SyS_ioctl+0x41/0x70
[  124.803806]  entry_SYSCALL_64_fastpath+0x1c/0xb1
[  124.803811] RIP: 0033:0x7f1a8ca01587
[  124.803815] RSP: 002b:00007fffc5122928 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  124.803824] RAX: ffffffffffffffda RBX: ffffffff81492003 RCX: 00007f1a8ca01587
[  124.803828] RDX: 00007fffc5122960 RSI: 00000000c01064ab RDI: 0000000000000003
[  124.803832] RBP: ffffc90000297f88 R08: 0000000000000001 R09: 0000000000000060
[  124.803837] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[  124.803841] R13: 0000000000000003 R14: 00000000c01064ab R15: 0000000000000003
[  124.803850]  ? __this_cpu_preempt_check+0x13/0x20
[  124.803861] Code: fe ff ff 8b 72 24 48 89 df e8 f7 e5 08 00 e9 d8 fe ff ff 8b 41 0c eb 82 48 c7 c6 d0 ef 25 a0 48 c7 c7 71 e7 24 a0 e8 3b 7b fb e0 <0f> ff e9 80 fe ff ff 89 c6 48 c7 c7 18 f0 25 a0 e8 26 7b fb e0 
[  124.804183] ---[ end trace 10f1c258bbd52cda ]---

Comment 12 Marta Löfstedt 2017-11-17 07:47:53 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3354/shard-glkb2/igt@kms_plane@plane-panning-top-left-pipe-c-planes.html

[ 2185.812946] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 2185.813020] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 13 Marta Löfstedt 2017-11-17 12:08:24 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3356/shard-glkb2/igt@kms_flip@flip-vs-dpms-off-vs-modeset-interruptible.html

[ 1884.113836] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 1884.113910] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 14 Marta Löfstedt 2017-11-23 07:56:55 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3371/shard-glkb6/igt@kms_flip@rcs-wf_vblank-vs-dpms-interruptible.html

[  290.999148] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  290.999343] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 316800)
[  290.999348] cdclk state doesn't match!
[  290.999381] ------------[ cut here ]------------
[  290.999440] WARNING: CPU: 1 PID: 4403 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x57/0x100 [i915]
[  290.999444] Modules linked in: snd_hda_intel i915 vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec snd_hwdep snd_hda_core r8169 snd_pcm mii mei_me mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel [last unloaded: i915]
[  290.999512] CPU: 1 PID: 4403 Comm: kms_flip Tainted: G     U          4.14.0-CI-CI_DRM_3371+ #1
[  290.999515] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0069.B31.1710111133 10/11/2017
[  290.999518] task: ffff880172b64ec0 task.stack: ffffc9000084c000
[  290.999552] RIP: 0010:intel_set_cdclk+0x57/0x100 [i915]
[  290.999554] RSP: 0018:ffffc9000084fb50 EFLAGS: 00010282
[  290.999559] RAX: 000000000000001a RBX: ffff88010c9e0000 RCX: 0000000000000001
[  290.999563] RDX: 0000000080000001 RSI: ffffffff81cb9723 RDI: 00000000ffffffff
[  290.999565] RBP: ffff88010c9e561c R08: ffff880172b657a8 R09: 0000000000000000
[  290.999569] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88016c21a548
[  290.999571] R13: 0000000000000000 R14: ffff88017819ca88 R15: 0000000000000003
[  290.999574] FS:  00007f13c6878a40(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
[  290.999577] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  290.999580] CR2: 00007f13c67f4000 CR3: 000000017058c000 CR4: 00000000003406e0
[  290.999582] Call Trace:
[  290.999620]  intel_atomic_commit_tail+0x9f1/0xd00 [i915]
[  290.999691]  ? intel_atomic_commit_ready+0x44/0x4c [i915]
[  290.999727]  ? __i915_sw_fence_complete+0x17a/0x230 [i915]
[  290.999790]  intel_atomic_commit+0x223/0x2d0 [i915]
[  290.999797]  drm_atomic_connector_commit_dpms+0xe7/0x100
[  290.999803]  set_property_atomic+0xdd/0x100
[  290.999812]  drm_mode_obj_set_property_ioctl+0xc2/0x170
[  290.999817]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  290.999821]  drm_mode_connector_property_set_ioctl+0x2e/0x40
[  290.999825]  drm_ioctl_kernel+0x65/0xb0
[  290.999830]  drm_ioctl+0x295/0x340
[  290.999835]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  290.999840]  ? retint_kernel+0x2d/0x2d
[  290.999847]  ? lock_acquire+0xaf/0x200
[  290.999853]  ? __fget+0xe4/0x1f0
[  290.999859]  do_vfs_ioctl+0x8f/0x670
[  290.999864]  ? __fget+0x101/0x1f0
[  290.999869]  SyS_ioctl+0x3b/0x70
[  290.999875]  do_syscall_64+0x5e/0x170
[  290.999880]  entry_SYSCALL64_slow_path+0x25/0x25
[  290.999883] RIP: 0033:0x7f13c4a77587
[  290.999886] RSP: 002b:00007ffe1d410398 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  290.999891] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f13c4a77587
[  290.999893] RDX: 00007ffe1d4103d0 RSI: 00000000c01064ab RDI: 0000000000000003
[  290.999896] RBP: 00007ffe1d4103d0 R08: 0000000000000001 R09: 0000000000000060
[  290.999898] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000c01064ab
[  290.999901] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000000000004
[  290.999909] Code: 48 89 ef e8 8c ff ff ff 48 89 ee 48 89 df ff 93 50 56 00 00 8b 45 00 39 83 2c 56 00 00 74 5e 48 c7 c7 e8 89 4d a0 e8 e4 d9 cb e0 <0f> ff 48 8d bb 2c 56 00 00 48 c7 c6 04 8a 4d a0 e8 54 ff ff ff 
[  291.000056] ---[ end trace f03e42956c9d1a68 ]---
[  291.812334] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe A FIFO underrun

Comment 15 Marta Löfstedt 2017-11-23 07:57:19 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3371/shard-glkb6/igt@kms_flip@flip-vs-dpms-interruptible.html

[  245.121061] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  245.121148] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 316800)
[  245.121152] cdclk state doesn't match!
[  245.121186] ------------[ cut here ]------------
[  245.121218] WARNING: CPU: 0 PID: 1753 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x57/0x100 [i915]
[  245.121222] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul i915 crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core r8169 mii snd_pcm mei_me mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  245.121287] CPU: 0 PID: 1753 Comm: kms_flip Tainted: G     U          4.14.0-CI-CI_DRM_3371+ #1
[  245.121290] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0069.B31.1710111133 10/11/2017
[  245.121292] task: ffff880122cf8040 task.stack: ffffc90000380000
[  245.121324] RIP: 0010:intel_set_cdclk+0x57/0x100 [i915]
[  245.121327] RSP: 0018:ffffc90000383b20 EFLAGS: 00010282
[  245.121332] RAX: 000000000000001a RBX: ffff880169f80000 RCX: 0000000000000001
[  245.121334] RDX: 0000000080000001 RSI: ffffffff81cb9723 RDI: 00000000ffffffff
[  245.121337] RBP: ffff880169f8561c R08: ffff880122cf8950 R09: 0000000000000000
[  245.121340] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880171e81bf8
[  245.121342] R13: 0000000000000000 R14: ffff88016c20c138 R15: 0000000000000003
[  245.121345] FS:  00007f2135900a40(0000) GS:ffff88017fc00000(0000) knlGS:0000000000000000
[  245.121348] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  245.121350] CR2: 00007f2133a36aa0 CR3: 000000016e5bc000 CR4: 00000000003406f0
[  245.121353] Call Trace:
[  245.121388]  intel_atomic_commit_tail+0x9f1/0xd00 [i915]
[  245.121422]  ? intel_atomic_commit_ready+0x44/0x4c [i915]
[  245.121452]  ? __i915_sw_fence_complete+0x17a/0x230 [i915]
[  245.121488]  intel_atomic_commit+0x223/0x2d0 [i915]
[  245.121495]  drm_atomic_helper_set_config+0x7a/0x90
[  245.121500]  __drm_mode_set_config_internal+0x61/0x110
[  245.121504]  drm_mode_setcrtc+0x45c/0x5d0
[  245.121517]  ? drm_mode_getcrtc+0x170/0x170
[  245.121520]  drm_ioctl_kernel+0x65/0xb0
[  245.121525]  drm_ioctl+0x295/0x340
[  245.121529]  ? drm_mode_getcrtc+0x170/0x170
[  245.121537]  ? __might_fault+0x3e/0x90
[  245.121545]  do_vfs_ioctl+0x8f/0x670
[  245.121550]  ? entry_SYSCALL_64_fastpath+0x5/0xb1
[  245.121556]  ? trace_hardirqs_on_caller+0xde/0x1c0
[  245.121561]  SyS_ioctl+0x3b/0x70
[  245.121566]  entry_SYSCALL_64_fastpath+0x1c/0xb1
[  245.121570] RIP: 0033:0x7f2133aff587
[  245.121573] RSP: 002b:00007ffd9910a928 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  245.121578] RAX: ffffffffffffffda RBX: ffffc90000383ff0 RCX: 00007f2133aff587
[  245.121580] RDX: 00007ffd9910a960 RSI: 00000000c06864a2 RDI: 0000000000000003
[  245.121582] RBP: 0000000000000003 R08: 0000000000000000 R09: 00007ffd9910ae08
[  245.121585] R10: 00007ffd9910acb4 R11: 0000000000000246 R12: 0000000000000046
[  245.121587] R13: 0000000000000003 R14: 00007ffd9910aea8 R15: 00007ffd9910acb0
[  245.121595] Code: 48 89 ef e8 8c ff ff ff 48 89 ee 48 89 df ff 93 50 56 00 00 8b 45 00 39 83 2c 56 00 00 74 5e 48 c7 c7 e8 f9 23 a0 e8 e4 69 f5 e0 <0f> ff 48 8d bb 2c 56 00 00 48 c7 c6 04 fa 23 a0 e8 54 ff ff ff 
[  245.121738] ---[ end trace 36b55890959acf34 ]---
[  245.967659] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe A FIFO underrun

Comment 16 Marta Löfstedt 2017-11-23 07:57:43 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4003/shard-glkb2/igt@kms_plane_multiple@legacy-pipe-c-tiling-x.html

	

[ 8491.225825] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 8491.225900] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 316800)
[ 8491.225905] cdclk state doesn't match!
[ 8491.225939] ------------[ cut here ]------------
[ 8491.225974] WARNING: CPU: 2 PID: 13317 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x57/0x100 [i915]
[ 8491.225977] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal intel_powerclamp coretemp i915 crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core r8169 snd_pcm mei_me mii mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[ 8491.226047] CPU: 2 PID: 13317 Comm: kms_plane_multi Tainted: G     U  W       4.14.0-CI-CI_DRM_3371+ #1
[ 8491.226050] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[ 8491.226053] task: ffff8801633e8040 task.stack: ffffc9000026c000
[ 8491.226086] RIP: 0010:intel_set_cdclk+0x57/0x100 [i915]
[ 8491.226089] RSP: 0018:ffffc9000026fb20 EFLAGS: 00010282
[ 8491.226094] RAX: 000000000000001a RBX: ffff8801699d0000 RCX: 0000000000000001
[ 8491.226097] RDX: 0000000080000001 RSI: ffffffff81cb9723 RDI: 00000000ffffffff
[ 8491.226099] RBP: ffff8801699d561c R08: ffff8801633e8950 R09: 0000000000000000
[ 8491.226102] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88017455ae98
[ 8491.226104] R13: 0000000000000002 R14: ffff8801699c53d8 R15: 0000000000000003
[ 8491.226107] FS:  00007fb621e60a40(0000) GS:ffff88017fd00000(0000) knlGS:0000000000000000
[ 8491.226110] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 8491.226113] CR2: 00007fd949659000 CR3: 00000001719be000 CR4: 00000000003406e0
[ 8491.226116] Call Trace:
[ 8491.226155]  intel_atomic_commit_tail+0x9f1/0xd00 [i915]
[ 8491.226193]  ? intel_atomic_commit_ready+0x44/0x4c [i915]
[ 8491.226224]  ? __i915_sw_fence_complete+0x17a/0x230 [i915]
[ 8491.226261]  intel_atomic_commit+0x223/0x2d0 [i915]
[ 8491.226270]  drm_atomic_helper_set_config+0x7a/0x90
[ 8491.226277]  __drm_mode_set_config_internal+0x61/0x110
[ 8491.226281]  drm_mode_setcrtc+0x45c/0x5d0
[ 8491.226289]  ? drm_modeset_acquire_fini+0x1b/0x60
[ 8491.226293]  ? set_property_atomic+0xb4/0x100
[ 8491.226303]  ? drm_mode_getcrtc+0x170/0x170
[ 8491.226307]  drm_ioctl_kernel+0x65/0xb0
[ 8491.226313]  drm_ioctl+0x295/0x340
[ 8491.226318]  ? drm_mode_getcrtc+0x170/0x170
[ 8491.226326]  ? remove_vma+0x5b/0x70
[ 8491.226331]  ? rcu_read_lock_sched_held+0x74/0x80
[ 8491.226338]  do_vfs_ioctl+0x8f/0x670
[ 8491.226344]  ? entry_SYSCALL_64_fastpath+0x5/0xb1
[ 8491.226350]  ? trace_hardirqs_on_caller+0xde/0x1c0
[ 8491.226355]  SyS_ioctl+0x3b/0x70
[ 8491.226360]  entry_SYSCALL_64_fastpath+0x1c/0xb1
[ 8491.226363] RIP: 0033:0x7fb62005f587
[ 8491.226366] RSP: 002b:00007fffa3d00958 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 8491.226371] RAX: ffffffffffffffda RBX: ffffc9000026fff0 RCX: 00007fb62005f587
[ 8491.226373] RDX: 00007fffa3d00990 RSI: 00000000c06864a2 RDI: 0000000000000003
[ 8491.226376] RBP: 0000000000000003 R08: 0000000000000000 R09: 0000556c85d3d018
[ 8491.226378] R10: 0000556c85d3d038 R11: 0000000000000246 R12: 0000000000000046
[ 8491.226381] R13: 00000000ff0000ff R14: 0000000000000c80 R15: 00007fb61b9ca000
[ 8491.226390] Code: 48 89 ef e8 8c ff ff ff 48 89 ee 48 89 df ff 93 50 56 00 00 8b 45 00 39 83 2c 56 00 00 74 5e 48 c7 c7 e8 f9 23 a0 e8 e4 69 f5 e0 <0f> ff 48 8d bb 2c 56 00 00 48 c7 c6 04 fa 23 a0 e8 54 ff ff ff 
[ 8491.226538] ---[ end trace 364e5829b86671b3 ]---
[ 8491.975809] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe C FIFO underrun

Comment 17 Marta Löfstedt 2017-11-23 13:02:54 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3375/shard-glkb1/igt@kms_chv_cursor_fail@pipe-c-256x256-right-edge.html

No backtrace on WARN just:
[ 2557.361164] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 2557.361251] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 18 Marta Löfstedt 2017-11-29 09:32:54 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3399/shard-glkb2/igt@kms_cursor_crc@cursor-128x128-rapid-movement.html

	

[  971.195463] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  971.195500] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 316800)
[  971.195503] ------------[ cut here ]------------
[  971.195505] cdclk state doesn't match!
[  971.195568] WARNING: CPU: 2 PID: 3531 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x52/0x100 [i915]
[  971.195571] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me r8169 mii mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  971.195610] CPU: 2 PID: 3531 Comm: kms_cursor_crc Tainted: G     U           4.15.0-rc1-CI-CI_DRM_3399+ #1
[  971.195612] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  971.195614] task: ffff88017aa82900 task.stack: ffffc90001e18000
[  971.195647] RIP: 0010:intel_set_cdclk+0x52/0x100 [i915]
[  971.195649] RSP: 0018:ffffc90001e1bb18 EFLAGS: 00010296
[  971.195652] RAX: 000000000000001a RBX: ffff8801691f0000 RCX: 0000000000000001
[  971.195654] RDX: 0000000080000001 RSI: ffffffff81ca998d RDI: 00000000ffffffff
[  971.195656] RBP: ffff8801691f60d4 R08: 0000000000000001 R09: 0000000000000001
[  971.195658] R10: 0000000000000000 R11: ffffffff82f73f0d R12: ffff880178922548
[  971.195660] R13: 0000000000000001 R14: ffff88016e6d92a8 R15: 0000000000000003
[  971.195663] FS:  00007fd6765cfa40(0000) GS:ffff88017fd00000(0000) knlGS:0000000000000000
[  971.195665] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  971.195668] CR2: 00007f6f926d1010 CR3: 0000000175e6d000 CR4: 0000000000340ee0
[  971.195671] Call Trace:
[  971.195706]  intel_atomic_commit_tail+0xa08/0xd10 [i915]
[  971.195740]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  971.195771]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  971.195808]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  971.195814]  drm_atomic_helper_set_config+0x7b/0x90
[  971.195818]  __drm_mode_set_config_internal+0x5c/0x110
[  971.195822]  drm_mode_setcrtc+0x457/0x5d0
[  971.195833]  ? drm_mode_getcrtc+0x160/0x160
[  971.195835]  drm_ioctl_kernel+0x60/0xa0
[  971.195839]  drm_ioctl+0x290/0x330
[  971.195843]  ? drm_mode_getcrtc+0x160/0x160
[  971.195850]  ? remove_vma+0x56/0x60
[  971.195856]  do_vfs_ioctl+0x8a/0x680
[  971.195862]  SyS_ioctl+0x36/0x70
[  971.195868]  entry_SYSCALL_64_fastpath+0x1c/0x89
[  971.195870] RIP: 0033:0x7fd6747ce587
[  971.195872] RSP: 002b:00007ffcca384c88 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  971.195876] RAX: ffffffffffffffda RBX: 0000000000000063 RCX: 00007fd6747ce587
[  971.195878] RDX: 00007ffcca384cc0 RSI: 00000000c06864a2 RDI: 0000000000000003
[  971.195880] RBP: 0000000000000708 R08: 0000000000000000 R09: 0000555d70af3fc8
[  971.195882] R10: 0000555d70af3fe8 R11: 0000000000000246 R12: 0000000000000c80
[  971.195884] R13: 00000000ff000000 R14: 0000000000000c80 R15: 00007fd670139000
[  971.195890] Code: 48 89 ef e8 a1 ff ff ff 48 89 ee 48 89 df ff 93 08 61 00 00 8b 45 00 39 83 e4 60 00 00 74 5e 48 c7 c7 d1 bd 26 a0 e8 9e 9f eb e0 <0f> ff 48 8d bb e4 60 00 00 48 c7 c6 ed bd 26 a0 e8 69 ff ff ff 
[  971.195958] ---[ end trace f9d9722b632242de ]---
[  971.406544] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun

Comment 19 Marta Löfstedt 2017-11-30 07:36:08 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3409/shard-glkb1/igt@kms_flip@flip-vs-panning-interruptible.html

[ 2436.064559] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 2436.064620] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 20 Marta Löfstedt 2017-12-04 06:55:17 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3441/fi-glk-1/igt@gem_exec_suspend@basic-s3.html

[  250.351640] ACPI: button: The lid device is not compliant to SW_LID.
[  250.520492] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  250.520673] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 79200)
[  250.520676] ------------[ cut here ]------------
[  250.520678] cdclk state doesn't match!
[  250.520745] WARNING: CPU: 3 PID: 3134 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x52/0x100 [i915]
[  250.520747] Modules linked in: snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm r8169 mei_me mii prime_numbers mei i2c_hid pinctrl_geminilake pinctrl_intel
[  250.520849] CPU: 3 PID: 3134 Comm: kworker/u8:20 Tainted: G     U           4.15.0-rc1-CI-CI_DRM_3441+ #1
[  250.520851] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  250.520856] Workqueue: events_unbound async_run_entry_fn
[  250.520860] task: ffff880170a2a900 task.stack: ffffc9000098c000
[  250.520893] RIP: 0010:intel_set_cdclk+0x52/0x100 [i915]
[  250.520896] RSP: 0000:ffffc9000098fb60 EFLAGS: 00010282
[  250.520899] RAX: 000000000000001a RBX: ffff880166610000 RCX: 0000000000000006
[  250.520902] RDX: 0000000000001455 RSI: ffffffff81d05401 RDI: ffffffff81cb67e6
[  250.520904] RBP: ffff8801666160dc R08: 0000000000000000 R09: 0000000000000001
[  250.520906] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801668dd3d8
[  250.520908] R13: 0000000000000002 R14: ffff8801650312a8 R15: 0000000000000003
[  250.520910] FS:  0000000000000000(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
[  250.520912] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  250.520914] CR2: 0000000000000000 CR3: 0000000003e10000 CR4: 0000000000340ee0
[  250.520916] Call Trace:
[  250.520954]  intel_atomic_commit_tail+0xa18/0xd20 [i915]
[  250.520990]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  250.521020]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  250.521059]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  250.521066]  ? pci_pm_suspend_late+0x30/0x30
[  250.521072]  drm_atomic_helper_commit_duplicated_state+0xd4/0x100
[  250.521075]  ? pci_pm_suspend_late+0x30/0x30
[  250.521110]  __intel_display_resume+0x76/0xc0 [i915]
[  250.521145]  intel_display_resume+0xbc/0xf0 [i915]
[  250.521149]  ? __mutex_unlock_slowpath+0x38/0x270
[  250.521189]  i915_pm_restore+0xc4/0x140 [i915]
[  250.521194]  dpm_run_callback+0x5f/0x310
[  250.521200]  device_resume+0xa3/0x1b0
[  250.521206]  ? dpm_watchdog_set+0x60/0x60
[  250.521214]  async_resume+0x14/0x40
[  250.521218]  async_run_entry_fn+0x2e/0x160
[  250.521224]  process_one_work+0x227/0x650
[  250.521234]  worker_thread+0x48/0x3a0
[  250.521242]  kthread+0x173/0x1b0
[  250.521246]  ? process_one_work+0x650/0x650
[  250.521248]  ? _kthread_create_on_node+0x30/0x30
[  250.521254]  ret_from_fork+0x24/0x30
[  250.521268] Code: 48 89 ef e8 a1 ff ff ff 48 89 ee 48 89 df ff 93 10 61 00 00 8b 45 00 39 83 ec 60 00 00 74 5e 48 c7 c7 97 6d 25 a0 e8 ee d2 ec e0 <0f> ff 48 8d bb ec 60 00 00 48 c7 c6 b3 6d 25 a0 e8 69 ff ff ff 
[  250.521384] ---[ end trace 6eb7f480503d42bc ]---

Comment 21 Marta Löfstedt 2017-12-04 07:55:03 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3435/shard-glkb2/igt@kms_frontbuffer_tracking@fbc-1p-offscren-pri-indfb-draw-mmap-wc.html

[ 1143.820529] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 1143.820628] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 22 Marta Löfstedt 2017-12-04 07:55:30 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4031/shard-glkb2/igt@kms_flip@blocking-absolute-wf_vblank-interruptible.html
	

[ 1296.788208] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x00000001 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 1296.788303] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq set failed, (err -110, freq 19200)

Comment 23 Marta Löfstedt 2017-12-05 07:36:46 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3451/shard-glkb2/igt@kms_flip@dpms-off-confusion-interruptible.html

	

[  382.281120] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  382.281255] [drm:bxt_init_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 79200)
[  382.281331] [drm:bxt_display_core_init [i915]] *ERROR* DBuf power enable timeout
[  382.287113] ------------[ cut here ]------------
[  382.287120] WARN_ON(intel_cdclk_needs_modeset(&dev_priv->cdclk.hw, &cdclk_state))
[  382.287242] WARNING: CPU: 3 PID: 1719 at drivers/gpu/drm/i915/intel_runtime_pm.c:709 gen9_dc_off_power_well_enable+0x1bb/0x200 [i915]
[  382.287250] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core r8169 snd_pcm mei_me mii prime_numbers mei i2c_hid pinctrl_geminilake pinctrl_intel
[  382.287410] CPU: 3 PID: 1719 Comm: kms_flip Tainted: G     U           4.15.0-rc2-CI-CI_DRM_3451+ #1
[  382.287417] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  382.287425] task: 00000000cc1d03e3 task.stack: 000000001541c206
[  382.287500] RIP: 0010:gen9_dc_off_power_well_enable+0x1bb/0x200 [i915]
[  382.287507] RSP: 0018:ffffc900007f3aa8 EFLAGS: 00010292
[  382.287519] RAX: 0000000000000045 RBX: ffff880167e40000 RCX: 0000000000000006
[  382.287526] RDX: 00000000000013ec RSI: ffffffff81d05619 RDI: ffffffff81cb69d6
[  382.287533] RBP: ffff880167e40000 R08: ffff88017aa83258 R09: 00000000bd59b8f6
[  382.287540] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000021
[  382.287546] R13: 0000000200000000 R14: aaaaaaaaaaaaaaab R15: ffff8801756fd508
[  382.287554] FS:  00007f9029b7ca40(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
[  382.287561] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  382.287567] CR2: 00007faf2492d030 CR3: 00000001783d6000 CR4: 0000000000340ee0
[  382.287574] Call Trace:
[  382.287658]  intel_power_well_enable+0x30/0x40 [i915]
[  382.287738]  __intel_display_power_get_domain+0x77/0x90 [i915]
[  382.287821]  intel_display_power_get+0x2b/0x40 [i915]
[  382.287913]  intel_atomic_commit_tail+0xb94/0xd20 [i915]
[  382.288005]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  382.288080]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  382.288176]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  382.288200]  drm_atomic_helper_set_config+0x7b/0x90
[  382.288218]  __drm_mode_set_config_internal+0x5c/0x110
[  382.288231]  drm_mode_setcrtc+0x457/0x5d0
[  382.288255]  ? __lock_acquire+0x42c/0x15a0
[  382.288297]  ? drm_mode_getcrtc+0x160/0x160
[  382.288307]  drm_ioctl_kernel+0x60/0xa0
[  382.288323]  drm_ioctl+0x290/0x330
[  382.288339]  ? drm_mode_getcrtc+0x160/0x160
[  382.288378]  do_vfs_ioctl+0x8a/0x680
[  382.288391]  ? entry_SYSCALL_64_fastpath+0x5/0x89
[  382.288404]  ? trace_hardirqs_on_caller+0xde/0x1c0
[  382.288420]  SyS_ioctl+0x36/0x70
[  382.288436]  entry_SYSCALL_64_fastpath+0x1c/0x89
[  382.288444] RIP: 0033:0x7f9027d7b587
[  382.288450] RSP: 002b:00007ffde89a75b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  382.288463] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f9027d7b587
[  382.288470] RDX: 00007ffde89a75f0 RSI: 00000000c06864a2 RDI: 0000000000000003
[  382.288476] RBP: 00007ffde89a75f0 R08: 0000000000000000 R09: 00007ffde89a7a98
[  382.288482] R10: 00007ffde89a7944 R11: 0000000000000246 R12: 00000000c06864a2
[  382.288489] R13: 0000000000000003 R14: 00007ffde89a7b38 R15: 00007ffde89a7940
[  382.288522] Code: fe ff ff 8b 72 24 48 89 df e8 82 08 09 00 e9 d9 fe ff ff 8b 41 0c eb 82 48 c7 c6 80 cb 27 a0 48 c7 c7 44 a3 26 a0 e8 75 41 f2 e0 <0f> ff e9 81 fe ff ff 89 c6 48 c7 c7 c8 cb 27 a0 e8 60 41 f2 e0 
[  382.288902] ---[ end trace 8c294127f05bc045 ]---

Comment 24 Marta Löfstedt 2017-12-05 07:37:02 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3449/shard-glkb1/igt@kms_flip@rcs-wf_vblank-vs-dpms.html

	

[  641.712581] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  641.712683] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 316800)
[  641.712688] ------------[ cut here ]------------
[  641.712691] cdclk state doesn't match!
[  641.712758] WARNING: CPU: 3 PID: 5698 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x52/0x100 [i915]
[  641.712762] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal intel_powerclamp i915 coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core mei_me mei snd_pcm r8169 mii prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  641.712863] CPU: 3 PID: 5698 Comm: kms_flip Tainted: G     U           4.15.0-rc2-CI-CI_DRM_3449+ #1
[  641.712866] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  641.712870] task: 000000003c48215c task.stack: 0000000084df96fe
[  641.712908] RIP: 0010:intel_set_cdclk+0x52/0x100 [i915]
[  641.712939] RSP: 0018:ffffc900007cfb68 EFLAGS: 00010292
[  641.712944] RAX: 000000000000001a RBX: ffff880167ec0000 RCX: 0000000000000001
[  641.712947] RDX: 0000000080000001 RSI: ffffffff81ca8e7d RDI: 00000000ffffffff
[  641.712950] RBP: ffff880167ec60dc R08: ffff88016a81dab8 R09: 00000000370c1748
[  641.712952] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88016f866678
[  641.712955] R13: 0000000000000002 R14: ffff88016e72e678 R15: 0000000000000003
[  641.712958] FS:  00007f82d1c76a40(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
[  641.712961] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  641.712964] CR2: 00007f82d1bf2000 CR3: 0000000178613000 CR4: 0000000000340ee0
[  641.712967] Call Trace:
[  641.713007]  intel_atomic_commit_tail+0xa18/0xd20 [i915]
[  641.713047]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  641.713081]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  641.713124]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  641.713134]  drm_atomic_connector_commit_dpms+0xe2/0xf0
[  641.713140]  set_property_atomic+0xde/0x100
[  641.713154]  drm_mode_obj_set_property_ioctl+0xbd/0x170
[  641.713161]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  641.713165]  drm_mode_connector_property_set_ioctl+0x29/0x30
[  641.713171]  drm_ioctl_kernel+0x60/0xa0
[  641.713177]  drm_ioctl+0x290/0x330
[  641.713184]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  641.713200]  do_vfs_ioctl+0x8a/0x680
[  641.713206]  ? __fget+0xff/0x1f0
[  641.713214]  SyS_ioctl+0x36/0x70
[  641.713222]  entry_SYSCALL_64_fastpath+0x1c/0x89
[  641.713225] RIP: 0033:0x7f82cfe75587
[  641.713228] RSP: 002b:00007fff053fb848 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  641.713233] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f82cfe75587
[  641.713236] RDX: 00007fff053fb880 RSI: 00000000c01064ab RDI: 0000000000000003
[  641.713239] RBP: 00007fff053fb7a0 R08: 0000000000000001 R09: 0000000000000060
[  641.713241] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[  641.713244] R13: 00007fff053fb7e0 R14: 000055bbb824e600 R15: 0000000000000002
[  641.713258] Code: 48 89 ef e8 a1 ff ff ff 48 89 ee 48 89 df ff 93 10 61 00 00 8b 45 00 39 83 ec 60 00 00 74 5e 48 c7 c7 97 4d 24 a0 e8 ee f2 ed e0 <0f> ff 48 8d bb ec 60 00 00 48 c7 c6 b3 4d 24 a0 e8 69 ff ff ff 
[  641.713413] ---[ end trace 5819e4453604ce20 ]---
[  642.547172] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe C FIFO underrun

Comment 25 Marta Löfstedt 2017-12-07 09:05:13 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3458/shard-glkb1/igt@kms_vblank@wait-busy.html

[ 1263.720018] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[ 1263.720116] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 26 Marta Löfstedt 2017-12-07 09:06:48 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3461/shard-glkb5/igt@kms_universal_plane@universal-plane-pipe-a-functional.html

[   70.472642] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x00000001 to mbox 17 to finish for bxt_set_cdclk [i915]
[   70.472726] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq set failed, (err -110, freq 19200)

Comment 27 Marta Löfstedt 2017-12-08 07:17:49 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3471/shard-glkb1/igt@kms_flip@basic-flip-vs-modeset.html

	

[  372.951300] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  372.951417] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 28 Marta Löfstedt 2017-12-11 08:06:49 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3487/shard-glkb5/igt@kms_cursor_legacy@flip-vs-cursor-crc-legacy.html

[  368.851933] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  368.852095] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 29 Marta Löfstedt 2017-12-11 12:11:39 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3496/shard-glkb1/igt@kms_flip@vblank-vs-dpms-rpm-interruptible.html

[  273.905767] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  273.905855] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 30 Marta Löfstedt 2017-12-14 06:50:00 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3506/shard-glkb1/igt@kms_flip@wf_vblank-vs-dpms.html

[  194.006148] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x0000000d to mbox 17 to finish for bxt_set_cdclk [i915]
[  194.006324] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq set failed, (err -110, freq 316800)
[  194.006329] ------------[ cut here ]------------
[  194.006332] cdclk state doesn't match!
[  194.006417] WARNING: CPU: 3 PID: 1880 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x52/0x100 [i915]
[  194.006420] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm r8169 mei_me mii mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  194.006483] CPU: 3 PID: 1880 Comm: kms_flip Tainted: G     U           4.15.0-rc3-CI-CI_DRM_3506+ #1
[  194.006486] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  194.006520] RIP: 0010:intel_set_cdclk+0x52/0x100 [i915]
[  194.006524] RSP: 0018:ffffc9000093bb68 EFLAGS: 00010292
[  194.006529] RAX: 000000000000001a RBX: ffff880168b80000 RCX: 0000000000000001
[  194.006531] RDX: 0000000080000001 RSI: ffffffff81ca922d RDI: 00000000ffffffff
[  194.006534] RBP: ffff880168b8616c R08: ffff88017110dab8 R09: 000000002e165738
[  194.006536] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801770b6fc8
[  194.006539] R13: 0000000000000002 R14: ffff88016e9f5d28 R15: 0000000000000003
[  194.006542] FS:  00007f751fbd9a40(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
[  194.006544] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  194.006547] CR2: 00007f56baeab000 CR3: 000000017111d000 CR4: 0000000000340ee0
[  194.006550] Call Trace:
[  194.006588]  intel_atomic_commit_tail+0x9d6/0xce0 [i915]
[  194.006625]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  194.006658]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  194.006698]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  194.006707]  drm_atomic_connector_commit_dpms+0xe2/0xf0
[  194.006714]  set_property_atomic+0xde/0x100
[  194.006728]  drm_mode_obj_set_property_ioctl+0xbd/0x170
[  194.006734]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  194.006737]  drm_mode_connector_property_set_ioctl+0x29/0x30
[  194.006742]  drm_ioctl_kernel+0x60/0xa0
[  194.006748]  drm_ioctl+0x290/0x330
[  194.006754]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  194.006768]  ? __vfs_read+0x1e/0x120
[  194.006775]  do_vfs_ioctl+0x8a/0x680
[  194.006781]  ? entry_SYSCALL_64_fastpath+0x5/0x89
[  194.006787]  ? trace_hardirqs_on_caller+0xde/0x1c0
[  194.006794]  SyS_ioctl+0x36/0x70
[  194.006800]  entry_SYSCALL_64_fastpath+0x1c/0x89
[  194.006803] RIP: 0033:0x7f751ddd8587
[  194.006806] RSP: 002b:00007fff1c0799f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  194.006811] RAX: ffffffffffffffda RBX: 00007fff1c079aa0 RCX: 00007f751ddd8587
[  194.006814] RDX: 00007fff1c079a30 RSI: 00000000c01064ab RDI: 0000000000000003
[  194.006816] RBP: 00007fff1c079bc0 R08: 00343c1b26364e67 R09: 00007fff1c150080
[  194.006819] R10: 000000000002a518 R11: 0000000000000246 R12: 000000000000000a
[  194.006821] R13: 0000000000000003 R14: 00007fff1c079a50 R15: 00007fff1c079d80
[  194.006834] Code: 48 89 ef e8 a1 ff ff ff 48 89 ee 48 89 df ff 93 a0 61 00 00 8b 45 00 39 83 7c 61 00 00 74 5e 48 c7 c7 3a 42 27 a0 e8 6e 27 eb e0 <0f> ff 48 8d bb 7c 61 00 00 48 c7 c6 56 42 27 a0 e8 69 ff ff ff 
[  194.006981] ---[ end trace 4476dcba5b158d1b ]---
[  195.160051] ------------[ cut here ]------------
[  195.160056] WARN_ON(intel_cdclk_needs_modeset(&dev_priv->cdclk.hw, &cdclk_state))
[  195.160149] WARNING: CPU: 1 PID: 1880 at drivers/gpu/drm/i915/intel_runtime_pm.c:711 gen9_dc_off_power_well_enable+0x1bb/0x200 [i915]
[  195.160155] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm r8169 mei_me mii mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  195.160265] CPU: 1 PID: 1880 Comm: kms_flip Tainted: G     U  W        4.15.0-rc3-CI-CI_DRM_3506+ #1
[  195.160270] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
[  195.160326] RIP: 0010:gen9_dc_off_power_well_enable+0x1bb/0x200 [i915]
[  195.160331] RSP: 0018:ffffc9000093baf8 EFLAGS: 00010292
[  195.160340] RAX: 0000000000000045 RBX: ffff880168b80000 RCX: 0000000000000006
[  195.160345] RDX: 00000000000013c4 RSI: ffffffff81d05aa9 RDI: ffffffff81cb6d86
[  195.160350] RBP: ffff880168b80000 R08: ffff88017110dae8 R09: 00000000a53ce283
[  195.160354] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000021
[  195.160359] R13: 0000000200000000 R14: aaaaaaaaaaaaaaab R15: ffff8801738cf4e8
[  195.160364] FS:  00007f751fbd9a40(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
[  195.160369] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  195.160373] CR2: 00007f7c9490d000 CR3: 000000017111d000 CR4: 0000000000340ee0
[  195.160378] Call Trace:
[  195.160440]  intel_power_well_enable+0x30/0x40 [i915]
[  195.160500]  __intel_display_power_get_domain+0x77/0x90 [i915]
[  195.160562]  intel_display_power_get+0x2b/0x40 [i915]
[  195.160626]  intel_atomic_commit_tail+0xb52/0xce0 [i915]
[  195.160690]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  195.160745]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  195.160815]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  195.160831]  drm_atomic_connector_commit_dpms+0xe2/0xf0
[  195.160842]  set_property_atomic+0xde/0x100
[  195.160866]  drm_mode_obj_set_property_ioctl+0xbd/0x170
[  195.160878]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  195.160884]  drm_mode_connector_property_set_ioctl+0x29/0x30
[  195.160893]  drm_ioctl_kernel+0x60/0xa0
[  195.160904]  drm_ioctl+0x290/0x330
[  195.160916]  ? drm_mode_connector_set_obj_prop+0x70/0x70
[  195.160938]  ? __vfs_read+0x1e/0x120
[  195.160950]  do_vfs_ioctl+0x8a/0x680
[  195.160959]  ? entry_SYSCALL_64_fastpath+0x5/0x89
[  195.160969]  ? trace_hardirqs_on_caller+0xde/0x1c0
[  195.160980]  SyS_ioctl+0x36/0x70
[  195.160991]  entry_SYSCALL_64_fastpath+0x1c/0x89
[  195.160997] RIP: 0033:0x7f751ddd8587
[  195.161001] RSP: 002b:00007fff1c0799f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  195.161011] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f751ddd8587
[  195.161015] RDX: 00007fff1c079a30 RSI: 00000000c01064ab RDI: 0000000000000003
[  195.161020] RBP: 00007fff1c079a30 R08: 0001f41e7d82798c R09: 00007fff1c150080
[  195.161024] R10: 000000000002a782 R11: 0000000000000246 R12: 00000000c01064ab
[  195.161029] R13: 0000000000000003 R14: 0000000000000001 R15: 0000000000000004
[  195.161054] Code: fe ff ff 8b 72 24 48 89 df e8 02 0d 09 00 e9 d9 fe ff ff 8b 41 0c eb 82 48 c7 c6 d0 02 28 a0 48 c7 c7 6e d6 26 a0 e8 25 3a f2 e0 <0f> ff e9 81 fe ff ff 89 c6 48 c7 c7 18 03 28 a0 e8 10 3a f2 e0 
[  195.161321] ---[ end trace 4476dcba5b158d1c ]---

Comment 31 Marta Löfstedt 2017-12-15 07:34:16 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3521/shard-glkb1/igt@pm_rpm@cursor-dpms.html

[  400.801888] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  400.801971] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 32 Marta Löfstedt 2017-12-18 08:23:21 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3526/shard-glkb6/igt@kms_flip@blt-flip-vs-panning-interruptible.html

	

[  408.957910] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  408.958004] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 316800)
[  408.958009] ------------[ cut here ]------------
[  408.958011] cdclk state doesn't match!
[  408.958077] WARNING: CPU: 2 PID: 4119 at drivers/gpu/drm/i915/intel_cdclk.c:1859 intel_set_cdclk+0x52/0x100 [i915]
[  408.958080] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal intel_powerclamp coretemp i915 crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm r8169 mii mei_me mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
[  408.958150] CPU: 2 PID: 4119 Comm: kms_flip Tainted: G     U           4.15.0-rc3-CI-CI_DRM_3526+ #1
[  408.958154] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0069.B31.1710111133 10/11/2017
[  408.958187] RIP: 0010:intel_set_cdclk+0x52/0x100 [i915]
[  408.958190] RSP: 0018:ffffc900004dfb18 EFLAGS: 00010296
[  408.958195] RAX: 000000000000001a RBX: ffff880169fc0000 RCX: 0000000000000001
[  408.958198] RDX: 0000000080000001 RSI: ffffffff81cab34d RDI: 00000000ffffffff
[  408.958201] RBP: ffff880169fc61bc R08: ffff88016e1cdae8 R09: 000000007b3f7328
[  408.958203] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880173a60008
[  408.958206] R13: 0000000000000002 R14: ffff880167f61bf8 R15: 0000000000000003
[  408.958209] FS:  00007fb2b013ea40(0000) GS:ffff88017fd00000(0000) knlGS:0000000000000000
[  408.958212] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  408.958214] CR2: 00007fb2a8b14c90 CR3: 00000001752cc000 CR4: 0000000000340ee0
[  408.958217] Call Trace:
[  408.958254]  intel_atomic_commit_tail+0x9d6/0xce0 [i915]
[  408.958289]  ? intel_atomic_commit_ready+0x3f/0x44 [i915]
[  408.958323]  ? __i915_sw_fence_complete+0x175/0x230 [i915]
[  408.958361]  intel_atomic_commit+0x22a/0x2e0 [i915]
[  408.958370]  drm_atomic_helper_set_config+0x7b/0x90
[  408.958377]  __drm_mode_set_config_internal+0x5c/0x110
[  408.958382]  drm_mode_setcrtc+0x457/0x5d0
[  408.958392]  ? __lock_acquire+0x42c/0x15a0
[  408.958409]  ? drm_mode_getcrtc+0x160/0x160
[  408.958412]  drm_ioctl_kernel+0x60/0xa0
[  408.958419]  drm_ioctl+0x290/0x330
[  408.958425]  ? drm_mode_getcrtc+0x160/0x160
[  408.958441]  do_vfs_ioctl+0x8a/0x680
[  408.958448]  ? __fget+0xff/0x1f0
[  408.958455]  SyS_ioctl+0x36/0x70
[  408.958463]  entry_SYSCALL_64_fastpath+0x1c/0x89
[  408.958466] RIP: 0033:0x7fb2ae33d587
[  408.958469] RSP: 002b:00007fff81207aa8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  408.958474] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007fb2ae33d587
[  408.958477] RDX: 00007fff81207ae0 RSI: 00000000c06864a2 RDI: 0000000000000003
[  408.958480] RBP: 00007fff81207ae0 R08: 0000000000000000 R09: 00007fff81207f88
[  408.958482] R10: 00007fff81207e34 R11: 0000000000000246 R12: 00000000c06864a2
[  408.958485] R13: 0000000000000003 R14: 00007fff81208028 R15: 00007fff81207e30
[  408.958498] Code: 48 89 ef e8 a1 ff ff ff 48 89 ee 48 89 df ff 93 f0 61 00 00 8b 45 00 39 83 cc 61 00 00 74 5e 48 c7 c7 a4 42 24 a0 e8 ee 51 ee e0 <0f> ff 48 8d bb cc 61 00 00 48 c7 c6 c0 42 24 a0 e8 69 ff ff ff 
[  408.958652] ---[ end trace 8082ac2a062a13cd ]---
[  409.812974] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe C FIFO underrun

Comment 33 Marta Löfstedt 2018-01-02 08:03:08 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3543/shard-glkb2/igt@kms_chv_cursor_fail@pipe-c-64x64-top-edge.html

[  297.163310] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  297.163428] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 34 Marta Löfstedt 2018-01-02 08:16:44 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3558/shard-glkb1/igt@kms_flip@basic-flip-vs-dpms.html

[  391.376442] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  391.376524] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 35 Marta Löfstedt 2018-01-17 07:34:55 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4141/shard-glkb2/igt@pm_rpm@gem-execbuf.html

[  575.032928] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  575.033009] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 36 Marta Löfstedt 2018-01-23 07:20:18 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3671/shard-glkb6/igt@kms_vblank@query-forked-busy.html

Note this one is on 0x80000000, most of the other are on 0x0000000N

[  217.933650] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  217.933790] [drm:intel_set_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 79200)
[  217.933795] ------------[ cut here ]------------
[  217.933797] cdclk state doesn't match!
[  217.933864] WARNING: CPU: 3 PID: 2756 at drivers/gpu/drm/i915/intel_cdclk.c:1877 intel_set_cdclk+0x52/0x100 [i915]
[  217.933867] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal intel_powerclamp i915 coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm r8169 mei_me mii prime_numbers mei i2c_hid pinctrl_geminilake pinctrl_intel
[  217.933935] CPU: 3 PID: 2756 Comm: kms_vblank Tainted: G     U           4.15.0-rc9-CI-CI_DRM_3671+ #1
[  217.933938] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0069.B31.1710111133 10/11/2017
[  217.933972] RIP: 0010:intel_set_cdclk+0x52/0x100 [i915]
[  217.933977] RSP: 0018:ffffc900002afb30 EFLAGS: 00010282
[  217.933981] RAX: 000000000000001a RBX: ffff88016ab40000 RCX: 0000000000000001
[  217.933984] RDX: 0000000080000001 RSI: ffffffff820abe27 RDI: 00000000ffffffff
[  217.933986] RBP: ffff88016ab48210 R08: ffff88016cfd5740 R09: 0000000036650ffd
[  217.933989] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88016ebb8958
[  217.933991] R13: ffff88016ab40000 R14: ffff880169a64138 R15: 0000000000000003
[  217.933994] FS:  00007fcfefa19a40(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
[  217.933997] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  217.933999] CR2: 00007fcfead8f028 CR3: 0000000176d72000 CR4: 0000000000340ee0
[  217.934002] Call Trace:
[  217.934042]  intel_atomic_commit_tail+0x9d6/0xce0 [i915]
[  217.934088]  intel_atomic_commit+0x256/0x330 [i915]
[  217.934100]  drm_atomic_helper_set_config+0x7b/0x90
[  217.934107]  __drm_mode_set_config_internal+0x5c/0x110
[  217.934112]  drm_mode_setcrtc+0x457/0x5d0
[  217.934121]  ? lock_acquire+0xaf/0x200
[  217.934127]  ? __might_fault+0x39/0x90
[  217.934143]  ? drm_mode_getcrtc+0x160/0x160
[  217.934148]  drm_ioctl_kernel+0x60/0xa0
[  217.934154]  drm_ioctl+0x290/0x330
[  217.934160]  ? drm_mode_getcrtc+0x160/0x160
[  217.934175]  do_vfs_ioctl+0x8a/0x670
[  217.934182]  ? entry_SYSCALL_64_fastpath+0x5/0x8f
[  217.934187]  ? trace_hardirqs_on_caller+0xde/0x1c0
[  217.934193]  SyS_ioctl+0x36/0x70
[  217.934200]  entry_SYSCALL_64_fastpath+0x22/0x8f
[  217.934203] RIP: 0033:0x7fcfedc18587
[  217.934205] RSP: 002b:00007ffcd323b018 EFLAGS: 00000246
[  217.934218] Code: 48 89 ef e8 91 ff ff ff 48 89 ee 48 89 df ff 93 50 82 00 00 8b 45 00 39 83 24 82 00 00 74 5e 48 c7 c7 e5 b8 24 a0 e8 2e 1a ee e0 <0f> ff 48 8d bb 24 82 00 00 48 c7 c6 01 b9 24 a0 e8 59 ff ff ff 
[  217.934365] ---[ end trace 82df3ed7b13758f7 ]---

Comment 37 Marta Löfstedt 2018-01-23 07:32:23 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3670/shard-glkb2/igt@pm_rpm@gem-pread.html

[  202.762915] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  202.763055] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 38 Marta Löfstedt 2018-01-25 06:34:56 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3683/shard-glkb2/igt@kms_cursor_crc@cursor-256x256-rapid-movement.html

[  645.532858] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  645.532932] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 39 Jani Saarinen 2018-01-30 11:53:12 UTC

Reference: https://patchwork.freedesktop.org/series/37338/

Comment 40 Marta Löfstedt 2018-01-31 08:00:40 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3701/shard-glkb1/igt@kms_busy@extended-modeset-hang-newfb-render-a.html

[  657.082669] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  657.082800] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

Comment 41 Imre Deak 2018-02-01 19:22:21 UTC

Fix merged to -dinq.

Comment 42 Marta Löfstedt 2018-02-02 06:49:29 UTC

I will monitor and close

Comment 43 Marta Löfstedt 2018-02-02 07:42:09 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4210/shard-glkb2/igt@prime_mmap_kms@buffer-sharing.html

[  193.016444] [drm:sandybridge_pcode_write [i915]] *ERROR* timeout waiting for pcode write of 0x80000000 to mbox 17 to finish for bxt_set_cdclk [i915]
[  193.016566] [drm:bxt_uninit_cdclk [i915]] *ERROR* PCode CDCLK freq change notify failed (err -110, freq 19200)

IGT-Version: 1.21-g902b7548 (x86_64) (Linux: 4.15.0-CI-CI_DRM_3711+ x86_64)

The fix was integrated to CI_DRM_3714, so above was before the fix.

Comment 44 Marta Löfstedt 2018-02-05 07:42:20 UTC

OK, no new occurrences. I will close and archive.

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.