Bug 105185 - [CI] igt@kms_* - dmesg-warn - WARNING: CPU: 4 PID: 1734 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
Summary: [CI] igt@kms_* - dmesg-warn - WARNING: CPU: 4 PID: 1734 at drivers/gpu/drm/dr...
Status: CLOSED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: medium normal
Assignee: Maarten Lankhorst
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
Depends on:
Blocks:
 
Reported: 2018-02-21 07:09 UTC by Marta Löfstedt
Modified: 2018-04-19 05:43 UTC (History)
1 user (show)

See Also:
i915 platform: BXT, GLK, HSW, SNB
i915 features: display/Other


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Marta Löfstedt 2018-02-21 07:09:12 UTC
Same run different SNBs
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4274/shard-snb7/igt@kms_chv_cursor_fail@pipe-b-256x256-left-edge.html
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4274/shard-snb1/igt@kms_chv_cursor_fail@pipe-b-64x64-bottom-edge.html

we hit WARN_ONCE in:

"
	/* If mode timing undefined, just return as no-op:
	 * Happens during initial modesetting of a crtc.
	 */
	if (mode->crtc_clock == 0) {
		DRM_DEBUG("crtc %u: Noop due to uninitialized mode.\n", pipe);
		WARN_ON_ONCE(drm_drv_uses_atomic_modeset(dev));

		return false;
	}
"

Strange that the "Noop due to uninitialized mode" is not in dmesg.


<4>[   36.477658] WARNING: CPU: 4 PID: 1734 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   36.477692] 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 lpc_ich snd_hda_core broadcom bcm_phy_lib snd_pcm tg3 mei_me mei prime_numbers
<4>[   36.477750] CPU: 4 PID: 1734 Comm: kms_chv_cursor_ Tainted: G     U           4.16.0-rc1-CI-CI_DRM_3809+ #1
<4>[   36.477753] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
<4>[   36.477757] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   36.477760] RSP: 0018:ffff88022fb03d10 EFLAGS: 00010086
<4>[   36.477765] RAX: ffffffffa0294b40 RBX: ffff880211280000 RCX: 0000000000000001
<4>[   36.477768] RDX: ffffffff820e7b78 RSI: 0000000000000001 RDI: ffffffff82068c22
<4>[   36.477771] RBP: ffff88022fb03d70 R08: 0000000000000000 R09: ffffffff815d24d0
<4>[   36.477774] R10: 0000000000000000 R11: ffffffffa0164ca0 R12: 0000000000000001
<4>[   36.477776] R13: ffff880219a19bf8 R14: ffff880219a19f20 R15: 0000000000000000
<4>[   36.477780] FS:  00007ff22da26a40(0000) GS:ffff88022fb00000(0000) knlGS:0000000000000000
<4>[   36.477783] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[   36.477786] CR2: 00005564829458c8 CR3: 00000002205da004 CR4: 00000000000606e0
<4>[   36.477788] Call Trace:
<4>[   36.477791]  <IRQ>
<4>[   36.477809]  drm_get_last_vbltimestamp+0x36/0x50
<4>[   36.477815]  drm_update_vblank_count+0x64/0x240
<4>[   36.477827]  drm_crtc_accurate_vblank_count+0x41/0xb0
<4>[   36.477869]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[   36.477918]  i9xx_pipe_crc_irq_handler+0xfe/0x150 [i915]
<4>[   36.477962]  ironlake_irq_handler+0x618/0xa30 [i915]
<4>[   36.477978]  __handle_irq_event_percpu+0x3c/0x340
<4>[   36.477990]  handle_irq_event_percpu+0x1b/0x50
<4>[   36.477997]  handle_irq_event+0x2f/0x50
<4>[   36.478006]  handle_edge_irq+0xe4/0x1b0
<4>[   36.478017]  handle_irq+0x11/0x20
<4>[   36.478023]  do_IRQ+0x5e/0x120
<4>[   36.478036]  common_interrupt+0x9f/0x9f
<4>[   36.478040]  </IRQ>
<4>[   36.478044] RIP: 0010:vprintk_emit+0x23b/0x4f0
<4>[   36.478047] RSP: 0018:ffffc9000035f900 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
<4>[   36.478052] RAX: ffff88021073cf40 RBX: 0000000000000007 RCX: 0000000000000006
<4>[   36.478055] RDX: 000000000000131f RSI: ffffffff8210f919 RDI: ffffffff820c00a7
<4>[   36.478058] RBP: ffffc9000035f950 R08: ffff88021073d8e0 R09: 0000000029d3a949
<4>[   36.478061] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000246
<4>[   36.478063] R13: 0000000000000000 R14: 0000000000000030 R15: 0000000000000000
<4>[   36.478099]  printk+0x3e/0x46
<4>[   36.478151]  ? intel_disable_pipe+0x3c/0x170 [i915]
<4>[   36.478160]  drm_printk+0x89/0x90
<4>[   36.478170]  ? trace_hardirqs_on_caller+0xde/0x1c0
<4>[   36.478222]  intel_disable_pipe+0x3c/0x170 [i915]
<4>[   36.478272]  ironlake_crtc_disable+0x6a/0x6d0 [i915]
<4>[   36.478278]  ? __mutex_unlock_slowpath+0x38/0x270
<4>[   36.478332]  intel_atomic_commit_tail+0x1bb/0xce0 [i915]
<4>[   36.478393]  intel_atomic_commit+0x256/0x330 [i915]
<4>[   36.478404]  restore_fbdev_mode_atomic+0x199/0x1f0
<4>[   36.478432]  drm_fb_helper_restore_fbdev_mode_unlocked+0x42/0x90
<4>[   36.478439]  drm_fb_helper_set_par+0x24/0x50
<4>[   36.478486]  intel_fbdev_set_par+0x11/0x60 [i915]
<4>[   36.478494]  fbcon_init+0x594/0x620
<4>[   36.478509]  visual_init+0xca/0x120
<4>[   36.478517]  do_bind_con_driver+0x1bb/0x3a0
<4>[   36.478534]  do_unbind_con_driver+0x1a1/0x210
<4>[   36.478552]  store_bind+0xb8/0x1b0
<4>[   36.478563]  kernfs_fop_write+0xfe/0x180
<4>[   36.478574]  __vfs_write+0x1e/0x130
<4>[   36.478581]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[   36.478585]  ? rcu_sync_lockdep_assert+0x25/0x50
<4>[   36.478590]  ? __sb_start_write+0xd9/0x1f0
<4>[   36.478594]  ? __sb_start_write+0xf3/0x1f0
<4>[   36.478605]  vfs_write+0xbd/0x1b0
<4>[   36.478614]  SyS_write+0x40/0xa0
<4>[   36.478624]  do_syscall_64+0x68/0x1a0
<4>[   36.478632]  entry_SYSCALL_64_after_hwframe+0x26/0x9b
<4>[   36.478635] RIP: 0033:0x7ff22befe670
<4>[   36.478638] RSP: 002b:00007fff41fed078 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4>[   36.478644] RAX: ffffffffffffffda RBX: 000055648293d890 RCX: 00007ff22befe670
<4>[   36.478646] RDX: 0000000000000002 RSI: 0000556480986658 RDI: 0000000000000008
<4>[   36.478649] RBP: 00007fff41fed0a0 R08: 000055648293d903 R09: 0000000000000020
<4>[   36.478652] R10: 0000000000000073 R11: 0000000000000246 R12: 000055648098663c
<4>[   36.478655] R13: 0000556480986606 R14: 000055648293d903 R15: 0000556480986642
<4>[   36.478678] Code: e1 48 c7 c2 78 7b 0e 82 be 01 00 00 00 48 c7 c7 22 8c 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> ff 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41
Comment 1 Marta Löfstedt 2018-02-21 11:18:17 UTC
Also note related new occurrences on bug 104671
Comment 3 Marta Löfstedt 2018-02-23 06:47:56 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3822/shard-snb6/igt@kms_chv_cursor_fail@pipe-b-128x128-right-edge.html

[   74.730271] WARNING: CPU: 4 PID: 0 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
[   74.730311] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_intel crct10dif_pclmul snd_hda_codec crc32_pclmul snd_hwdep broadcom ghash_clmulni_intel snd_hda_core bcm_phy_lib snd_pcm tg3 lpc_ich mei_me mei prime_numbers
[   74.730353] CPU: 4 PID: 0 Comm: swapper/4 Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3822+ #1
[   74.730355] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
[   74.730359] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
[   74.730361] RSP: 0018:ffff88022fb03d10 EFLAGS: 00010086
[   74.730365] RAX: ffffffffa0291d20 RBX: ffff88021a180000 RCX: 0000000000000001
[   74.730367] RDX: ffffffff820e7db8 RSI: 0000000000000001 RDI: ffffffff82068cea
[   74.730369] RBP: ffff88022fb03d70 R08: 0000000000000000 R09: ffffffff815d26d0
[   74.730371] R10: 0000000000000000 R11: ffffffffa0161ca0 R12: 0000000000000001
[   74.730373] R13: ffff880212448008 R14: ffff880212448330 R15: 0000000000000000
[   74.730376] FS:  0000000000000000(0000) GS:ffff88022fb00000(0000) knlGS:0000000000000000
[   74.730378] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   74.730380] CR2: 000055edcbec9000 CR3: 0000000002210001 CR4: 00000000000606e0
[   74.730382] Call Trace:
[   74.730385]  <IRQ>
[   74.730397]  drm_get_last_vbltimestamp+0x36/0x50
[   74.730401]  drm_update_vblank_count+0x64/0x240
[   74.730409]  drm_crtc_accurate_vblank_count+0x41/0x90
[   74.730453]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
[   74.730497]  i9xx_pipe_crc_irq_handler+0xfe/0x150 [i915]
[   74.730537]  ironlake_irq_handler+0x618/0xa30 [i915]
[   74.730548]  __handle_irq_event_percpu+0x3c/0x340
[   74.730556]  handle_irq_event_percpu+0x1b/0x50
[   74.730561]  handle_irq_event+0x2f/0x50
[   74.730566]  handle_edge_irq+0xe4/0x1b0
[   74.730572]  handle_irq+0x11/0x20
[   74.730576]  do_IRQ+0x5e/0x120
[   74.730584]  common_interrupt+0x84/0x84
[   74.730586]  </IRQ>
[   74.730591] RIP: 0010:cpuidle_enter_state+0xaa/0x350
[   74.730593] RSP: 0018:ffffc9000008beb8 EFLAGS: 00000212 ORIG_RAX: ffffffffffffffde
[   74.730597] RAX: ffff880226b80040 RBX: 000000000031fc3e RCX: 0000000000000001
[   74.730599] RDX: 0000000000000000 RSI: ffffffff8210fb59 RDI: ffffffff820c02e7
[   74.730601] RBP: 0000000000000004 R08: 00000000000040af R09: 0000000000000018
[   74.730603] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000004
[   74.730606] R13: ffffe8ffffd00430 R14: 0000001166120bf4 R15: ffffffff82294460
[   74.730621]  ? cpuidle_enter_state+0xa6/0x350
[   74.730629]  do_idle+0x188/0x1d0
[   74.730636]  cpu_startup_entry+0x14/0x20
[   74.730641]  start_secondary+0x129/0x160
[   74.730646]  secondary_startup_64+0xa5/0xb0
[   74.730660] Code: e1 48 c7 c2 b8 7d 0e 82 be 01 00 00 00 48 c7 c7 ea 8c 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
[   74.730754] ---[ end trace 14b1345705b68565 ]---
Comment 4 Marta Löfstedt 2018-02-26 06:38:04 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4292/shard-snb2/igt@kms_chv_cursor_fail@pipe-b-256x256-top-edge.html

	

[   83.043376] WARNING: CPU: 4 PID: 0 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
[   83.043521] 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 broadcom bcm_phy_lib mei_me tg3 lpc_ich prime_numbers mei
[   83.043562] CPU: 4 PID: 0 Comm: swapper/4 Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3830+ #1
[   83.043564] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
[   83.043568] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
[   83.043570] RSP: 0018:ffff88022fb03d10 EFLAGS: 00010082
[   83.043574] RAX: ffffffffa02d4d20 RBX: ffff8802114a0000 RCX: 0000000000000001
[   83.043576] RDX: ffffffff820e7e68 RSI: 0000000000000001 RDI: ffffffff82068da2
[   83.043578] RBP: ffff88022fb03d70 R08: 0000000000000000 R09: ffffffff815d2730
[   83.043580] R10: 0000000000000000 R11: ffffffffa01a4ca0 R12: 0000000000000001
[   83.043582] R13: ffff8802263437e8 R14: ffff880226343b10 R15: 0000000000000000
[   83.043584] FS:  0000000000000000(0000) GS:ffff88022fb00000(0000) knlGS:0000000000000000
[   83.043587] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   83.043589] CR2: 00007f1144932848 CR3: 0000000002210004 CR4: 00000000000606e0
[   83.043591] Call Trace:
[   83.043593]  <IRQ>
[   83.043605]  drm_get_last_vbltimestamp+0x36/0x50
[   83.043609]  drm_update_vblank_count+0x64/0x240
[   83.043617]  drm_crtc_accurate_vblank_count+0x41/0x90
[   83.043661]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
[   83.043705]  i9xx_pipe_crc_irq_handler+0xfe/0x150 [i915]
[   83.043746]  ironlake_irq_handler+0x618/0xa30 [i915]
[   83.043756]  __handle_irq_event_percpu+0x3c/0x340
[   83.043764]  handle_irq_event_percpu+0x1b/0x50
[   83.043769]  handle_irq_event+0x2f/0x50
[   83.043774]  handle_edge_irq+0xe4/0x1b0
[   83.043780]  handle_irq+0x11/0x20
[   83.043784]  do_IRQ+0x5e/0x120
[   83.043791]  common_interrupt+0x84/0x84
[   83.043794]  </IRQ>
[   83.043798] RIP: 0010:cpuidle_enter_state+0xaa/0x350
[   83.043800] RSP: 0018:ffffc9000008beb8 EFLAGS: 00000212 ORIG_RAX: ffffffffffffffdd
[   83.043804] RAX: ffff880226b80040 RBX: 0000000000fde97f RCX: 0000000000000001
[   83.043806] RDX: 0000000000000000 RSI: ffffffff8210fc09 RDI: ffffffff820c0397
[   83.043808] RBP: 0000000000000004 R08: 00000000000040ac R09: 0000000000000014
[   83.043810] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000004
[   83.043812] R13: ffffe8ffffd00430 R14: 0000001354c4195e R15: ffffffff82294460
[   83.043827]  ? cpuidle_enter_state+0xa6/0x350
[   83.043835]  do_idle+0x188/0x1d0
[   83.043842]  cpu_startup_entry+0x14/0x20
[   83.043847]  start_secondary+0x129/0x160
[   83.043852]  secondary_startup_64+0xa5/0xb0
[   83.043866] Code: e1 48 c7 c2 68 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
[   83.043960] ---[ end trace fe7d81c9e3c5e861 ]---
Comment 5 Marta Löfstedt 2018-02-27 06:40:56 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3833/shard-glkb2/igt@kms_plane_lowres@pipe-b-tiling-none.html

<7>[  188.382449] [drm:intel_disable_pipe [i915]] disabling pipe B
<4>[  188.382621] WARNING: CPU: 1 PID: 0 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  188.382681] 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 mii mei_me mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
<4>[  188.382835] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3833+ #1
<4>[  188.382881] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  188.382917] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  188.382929] RSP: 0018:ffff88017fc83d38 EFLAGS: 00010082
<4>[  188.382951] RAX: ffffffffa024fd20 RBX: ffff880166580000 RCX: 0000000000000001
<4>[  188.382963] RDX: ffffffff820e7e80 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[  188.382974] RBP: ffff88017fc83d98 R08: 0000000000000000 R09: ffffffff815d2780
<4>[  188.382993] R10: 0000000000000000 R11: ffffffffa011fca0 R12: 0000000000000001
<4>[  188.383005] R13: ffff8801667e4138 R14: ffff8801667e4460 R15: 0000000000000000
<4>[  188.383018] FS:  0000000000000000(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
<4>[  188.383030] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  188.383056] CR2: 00007f5307601000 CR3: 0000000005210000 CR4: 0000000000340ee0
<4>[  188.383062] Call Trace:
<4>[  188.383073]  <IRQ>
<4>[  188.383101]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  188.383115]  drm_update_vblank_count+0x64/0x240
<4>[  188.383137]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  188.383240]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  188.383356]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[  188.383454]  gen8_irq_handler+0x389/0x630 [i915]
<4>[  188.383485]  __handle_irq_event_percpu+0x3c/0x340
<4>[  188.383504]  handle_irq_event_percpu+0x1b/0x50
<4>[  188.383520]  handle_irq_event+0x2f/0x50
<4>[  188.383532]  handle_edge_irq+0xe4/0x1b0
<4>[  188.383546]  handle_irq+0x11/0x20
<4>[  188.383556]  do_IRQ+0x5e/0x120
<4>[  188.383575]  common_interrupt+0x84/0x84
<4>[  188.383585]  </IRQ>
<4>[  188.383595] RIP: 0010:cpuidle_enter_state+0xaa/0x350
<4>[  188.383601] RSP: 0018:ffffc900000c3eb8 EFLAGS: 00000202 ORIG_RAX: ffffffffffffffd9
<4>[  188.383614] RAX: ffff88017a948040 RBX: 0000000000fa04e6 RCX: 0000000000000001
<4>[  188.383620] RDX: 0000000000000000 RSI: ffffffff8210fc21 RDI: ffffffff820c0397
<4>[  188.383628] RBP: 0000000000000007 R08: 00000000ffffffff R09: 0000000000000008
<4>[  188.383637] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
<4>[  188.383646] R13: ffff88017fcab650 R14: 0000002bdb7e77e7 R15: ffffffff82294460
<4>[  188.383685]  ? cpuidle_enter_state+0xa6/0x350
<4>[  188.383702]  do_idle+0x188/0x1d0
<4>[  188.383720]  cpu_startup_entry+0x14/0x20
<4>[  188.383731]  start_secondary+0x129/0x160
<4>[  188.383743]  secondary_startup_64+0xa5/0xb0
<4>[  188.383777] Code: e1 48 c7 c2 80 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[  188.384145] ---[ end trace d8560d78250ac4de ]---
Comment 6 Marta Löfstedt 2018-02-27 06:41:51 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3833/shard-glkb4/igt@kms_plane_lowres@pipe-c-tiling-yf.html

<7>[   68.111539] [drm:intel_disable_pipe [i915]] disabling pipe C
<4>[   68.111665] WARNING: CPU: 1 PID: 1558 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   68.111717] 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 snd_pcm r8169 mii mei_me mei prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
<4>[   68.111872] CPU: 1 PID: 1558 Comm: kms_plane_lowre Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3833+ #1
<4>[   68.111878] Hardware name: Intel Corp. Geminilake/GLK RVP1 DDR4 (05), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[   68.111889] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   68.111896] RSP: 0018:ffff88017fc83d38 EFLAGS: 00010082
<4>[   68.111908] RAX: ffffffffa0238d20 RBX: ffff880166410000 RCX: 0000000000000002
<4>[   68.111914] RDX: ffffffff820e7e80 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[   68.111920] RBP: ffff88017fc83d98 R08: 0000000000000000 R09: ffffffff815d2780
<4>[   68.111927] R10: 0000000000000000 R11: ffffffffa0108ca0 R12: 0000000000000002
<4>[   68.111933] R13: ffff880165e0ae98 R14: ffff880165e0b3c8 R15: 0000000000000000
<4>[   68.111940] FS:  00007fd792298a40(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
<4>[   68.111947] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[   68.111956] CR2: 00007f9b8e949080 CR3: 0000000176e24000 CR4: 0000000000340ee0
<4>[   68.111962] Call Trace:
<4>[   68.111971]  <IRQ>
<4>[   68.111999]  drm_get_last_vbltimestamp+0x36/0x50
<4>[   68.112011]  drm_update_vblank_count+0x64/0x240
<4>[   68.112031]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[   68.112119]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[   68.112221]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[   68.112308]  gen8_irq_handler+0x389/0x630 [i915]
<4>[   68.112332]  __handle_irq_event_percpu+0x3c/0x340
<4>[   68.112352]  handle_irq_event_percpu+0x1b/0x50
<4>[   68.112363]  handle_irq_event+0x2f/0x50
<4>[   68.112375]  handle_edge_irq+0xe4/0x1b0
<4>[   68.112389]  handle_irq+0x11/0x20
<4>[   68.112398]  do_IRQ+0x5e/0x120
<4>[   68.112416]  common_interrupt+0x84/0x84
<4>[   68.112425]  </IRQ>
<4>[   68.112432] RIP: 0010:vprintk_emit+0x23b/0x4f0
<4>[   68.112439] RSP: 0018:ffffc900006679e0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffd9
<4>[   68.112451] RAX: ffff880163e62740 RBX: 0000000000000007 RCX: 0000000000000006
<4>[   68.112458] RDX: 00000000000013f1 RSI: ffffffff8210fc21 RDI: ffffffff820c0397
<4>[   68.112464] RBP: ffffc90000667a30 R08: ffff880163e63018 R09: 00000000c91c9ac7
<4>[   68.112470] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000246
<4>[   68.112476] R13: 0000000000000000 R14: 0000000000000030 R15: 0000000000000000
<4>[   68.112530]  printk+0x3e/0x46
<4>[   68.112634]  ? intel_disable_pipe+0x3c/0x170 [i915]
<4>[   68.112651]  drm_printk+0x89/0x90
<4>[   68.112668]  ? trace_hardirqs_on_caller+0xde/0x1c0
<4>[   68.112770]  intel_disable_pipe+0x3c/0x170 [i915]
<4>[   68.112873]  haswell_crtc_disable+0x69/0x130 [i915]
<4>[   68.112979]  intel_atomic_commit_tail+0x1ec/0xd20 [i915]
<4>[   68.113096]  intel_atomic_commit+0x256/0x330 [i915]
<4>[   68.113116]  drm_mode_atomic_ioctl+0x827/0x9d0
<4>[   68.113168]  ? drm_atomic_set_property+0x4c0/0x4c0
<4>[   68.113178]  drm_ioctl_kernel+0x60/0xa0
<4>[   68.113193]  drm_ioctl+0x2a0/0x340
<4>[   68.113208]  ? drm_atomic_set_property+0x4c0/0x4c0
<4>[   68.113248]  do_vfs_ioctl+0x8a/0x670
<4>[   68.113259]  ? __close_fd+0xbc/0xd0
<4>[   68.113272]  ? entry_SYSCALL_64_after_hwframe+0x52/0xb7
<4>[   68.113287]  SyS_ioctl+0x36/0x70
<4>[   68.113303]  do_syscall_64+0x65/0x1a0
<4>[   68.113316]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[   68.113324] RIP: 0033:0x7fd790497587
<4>[   68.113330] RSP: 002b:00007ffd0cef8798 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4>[   68.113343] RAX: ffffffffffffffda RBX: 000055c8080be920 RCX: 00007fd790497587
<4>[   68.113349] RDX: 00007ffd0cef87f0 RSI: 00000000c03864bc RDI: 0000000000000003
<4>[   68.113355] RBP: 00007ffd0cef87f0 R08: 000055c8080c6920 R09: 000055c8080c67d0
<4>[   68.113361] R10: 0000000000000001 R11: 0000000000000246 R12: 00000000c03864bc
<4>[   68.113368] R13: 0000000000000003 R14: 000055c8080c68e0 R15: 000055c8080c6900
<4>[   68.113400] Code: e1 48 c7 c2 80 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[   68.113762] ---[ end trace 76374fdf2f867fe7 ]---
Comment 7 Marta Löfstedt 2018-02-27 06:43:18 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4301/shard-snb2/igt@kms_chv_cursor_fail@pipe-b-256x256-right-edge.html

<7>[  160.756344] [drm:intel_disable_pipe [i915]] disabling pipe B
<4>[  160.756585] WARNING: CPU: 4 PID: 0 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  160.756700] 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 broadcom bcm_phy_lib snd_pcm tg3 mei_me mei prime_numbers lpc_ich
<4>[  160.756741] CPU: 4 PID: 0 Comm: swapper/4 Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3832+ #1
<4>[  160.756744] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
<4>[  160.756747] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  160.756750] RSP: 0018:ffff88022fb03d10 EFLAGS: 00010082
<4>[  160.756753] RAX: ffffffffa028cd20 RBX: ffff88021a350000 RCX: 0000000000000001
<4>[  160.756755] RDX: ffffffff820e7e68 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[  160.756757] RBP: ffff88022fb03d70 R08: 0000000000000000 R09: ffffffff815d2730
<4>[  160.756759] R10: 0000000000000000 R11: ffffffffa015cca0 R12: 0000000000000001
<4>[  160.756762] R13: ffff8802263437e8 R14: ffff880226343b10 R15: 0000000000000000
<4>[  160.756764] FS:  0000000000000000(0000) GS:ffff88022fb00000(0000) knlGS:0000000000000000
<4>[  160.756766] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  160.756769] CR2: 00007f5c4353d848 CR3: 0000000002210006 CR4: 00000000000606e0
<4>[  160.756771] Call Trace:
<4>[  160.756773]  <IRQ>
<4>[  160.756785]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  160.756789]  drm_update_vblank_count+0x64/0x240
<4>[  160.756797]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  160.756842]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  160.756886]  i9xx_pipe_crc_irq_handler+0xfe/0x150 [i915]
<4>[  160.756927]  ironlake_irq_handler+0x618/0xa30 [i915]
<4>[  160.756937]  __handle_irq_event_percpu+0x3c/0x340
<4>[  160.756945]  handle_irq_event_percpu+0x1b/0x50
<4>[  160.756950]  handle_irq_event+0x2f/0x50
<4>[  160.756955]  handle_edge_irq+0xe4/0x1b0
<4>[  160.756961]  handle_irq+0x11/0x20
<4>[  160.756965]  do_IRQ+0x5e/0x120
<4>[  160.756972]  common_interrupt+0x84/0x84
<4>[  160.756975]  </IRQ>
<4>[  160.756979] RIP: 0010:cpuidle_enter_state+0xaa/0x350
<4>[  160.756981] RSP: 0018:ffffc9000008beb8 EFLAGS: 00000212 ORIG_RAX: ffffffffffffffde
<4>[  160.756985] RAX: ffff880226b80040 RBX: 0000000000ebcabf RCX: 0000000000000001
<4>[  160.756987] RDX: 0000000000000000 RSI: ffffffff8210fc09 RDI: ffffffff820c0397
<4>[  160.756989] RBP: 0000000000000004 R08: 00000000000040ae R09: 0000000000000018
<4>[  160.756991] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000004
<4>[  160.756993] R13: ffffe8ffffd00430 R14: 000000256ce802c6 R15: ffffffff82294460
<4>[  160.757008]  ? cpuidle_enter_state+0xa6/0x350
<4>[  160.757016]  do_idle+0x188/0x1d0
<4>[  160.757023]  cpu_startup_entry+0x14/0x20
<4>[  160.757028]  start_secondary+0x129/0x160
<4>[  160.757033]  secondary_startup_64+0xa5/0xb0
<4>[  160.757047] Code: e1 48 c7 c2 68 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[  160.757141] ---[ end trace 0a492cca59b4deff ]---
Comment 8 Marta Löfstedt 2018-02-27 07:23:02 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4304/shard-glkb2/igt@kms_plane_lowres@pipe-b-tiling-yf.html

<7>[  323.581728] [drm:intel_panel_actually_set_backlight [i915]] set backlight PWM = 0
<7>[  323.581891] [drm:intel_disable_pipe [i915]] disabling pipe B
<4>[  323.581967] WARNING: CPU: 1 PID: 0 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  323.582050] 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 r8169 mii mei_me prime_numbers mei i2c_hid pinctrl_geminilake pinctrl_intel
<4>[  323.582300] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3834+ #1
<4>[  323.582313] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  323.582331] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  323.582350] RSP: 0018:ffff88017fc83d38 EFLAGS: 00010082
<4>[  323.582374] RAX: ffffffffa0267d20 RBX: ffff880169590000 RCX: 0000000000000001
<4>[  323.582386] RDX: ffffffff820e7e80 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[  323.582412] RBP: ffff88017fc83d98 R08: 0000000000000000 R09: ffffffff815d2780
<4>[  323.582419] R10: 0000000000000000 R11: ffffffffa0137ca0 R12: 0000000000000001
<4>[  323.582426] R13: ffff8801676fc138 R14: ffff8801676fc460 R15: 0000000000000000
<4>[  323.582435] FS:  0000000000000000(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
<4>[  323.582447] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  323.582454] CR2: 000055ee8be532e8 CR3: 0000000005210000 CR4: 0000000000340ee0
<4>[  323.582461] Call Trace:
<4>[  323.582470]  <IRQ>
<4>[  323.582501]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  323.582514]  drm_update_vblank_count+0x64/0x240
<4>[  323.582536]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  323.582649]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  323.582775]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[  323.582884]  gen8_irq_handler+0x389/0x630 [i915]
<4>[  323.582914]  __handle_irq_event_percpu+0x3c/0x340
<4>[  323.582935]  handle_irq_event_percpu+0x1b/0x50
<4>[  323.582948]  handle_irq_event+0x2f/0x50
<4>[  323.582962]  handle_edge_irq+0xe4/0x1b0
<4>[  323.582977]  handle_irq+0x11/0x20
<4>[  323.582988]  do_IRQ+0x5e/0x120
<4>[  323.583008]  common_interrupt+0x84/0x84
<4>[  323.583017]  </IRQ>
<4>[  323.583029] RIP: 0010:cpuidle_enter_state+0xaa/0x350
<4>[  323.583040] RSP: 0018:ffffc900000c3eb8 EFLAGS: 00000202 ORIG_RAX: ffffffffffffffd9
<4>[  323.583054] RAX: ffff88017a948040 RBX: 0000000000e33da4 RCX: 0000000000000001
<4>[  323.583064] RDX: 0000000000000000 RSI: ffffffff8210fc21 RDI: ffffffff820c0397
<4>[  323.583071] RBP: 0000000000000007 R08: 0000000000000000 R09: 0000000000000001
<4>[  323.583078] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
<4>[  323.583085] R13: ffff88017fcab650 R14: 0000004b56170663 R15: ffffffff82294460
<4>[  323.583125]  ? cpuidle_enter_state+0xa6/0x350
<4>[  323.583145]  do_idle+0x188/0x1d0
<4>[  323.583165]  cpu_startup_entry+0x14/0x20
<4>[  323.583177]  start_secondary+0x129/0x160
<4>[  323.583190]  secondary_startup_64+0xa5/0xb0
<4>[  323.583227] Code: e1 48 c7 c2 80 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[  323.583645] ---[ end trace 979082a7e72b15a5 ]---
Comment 9 Marta Löfstedt 2018-02-28 06:51:31 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4306/shard-snb1/igt@kms_chv_cursor_fail@pipe-b-128x128-bottom-edge.html

<7>[   21.027126] [drm:intel_disable_pipe [i915]] disabling pipe B
<4>[   21.027208] WARNING: CPU: 1 PID: 1501 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   21.027247] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_intel crct10dif_pclmul crc32_pclmul snd_hda_codec broadcom snd_hwdep ghash_clmulni_intel bcm_phy_lib snd_hda_core snd_pcm mei_me tg3 mei lpc_ich prime_numbers
<4>[   21.027302] CPU: 1 PID: 1501 Comm: kms_chv_cursor_ Not tainted 4.16.0-rc2-CI-CI_DRM_3838+ #1
<4>[   21.027305] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
<4>[   21.027309] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   21.027312] RSP: 0018:ffff88022fa43d10 EFLAGS: 00010086
<4>[   21.027317] RAX: ffffffffa02ced20 RBX: ffff880218ec0000 RCX: 0000000000000001
<4>[   21.027320] RDX: ffffffff820e7e80 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[   21.027322] RBP: ffff88022fa43d70 R08: 0000000000000000 R09: ffffffff815d2780
<4>[   21.027325] R10: 0000000000000000 R11: ffffffffa019eca0 R12: 0000000000000001
<4>[   21.027328] R13: ffff88020f9392a8 R14: ffff88020f9395d0 R15: 0000000000000000
<4>[   21.027331] FS:  00007f34acc1da40(0000) GS:ffff88022fa40000(0000) knlGS:0000000000000000
<4>[   21.027334] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[   21.027337] CR2: 000055d05806d6a8 CR3: 00000002199ca001 CR4: 00000000000606e0
<4>[   21.027340] Call Trace:
<4>[   21.027342]  <IRQ>
<4>[   21.027360]  drm_get_last_vbltimestamp+0x36/0x50
<4>[   21.027366]  drm_update_vblank_count+0x64/0x240
<4>[   21.027379]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[   21.027420]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[   21.027470]  i9xx_pipe_crc_irq_handler+0xfe/0x150 [i915]
<4>[   21.027515]  ironlake_irq_handler+0x618/0xa30 [i915]
<4>[   21.027531]  __handle_irq_event_percpu+0x3c/0x340
<4>[   21.027543]  handle_irq_event_percpu+0x1b/0x50
<4>[   21.027550]  handle_irq_event+0x2f/0x50
<4>[   21.027557]  handle_edge_irq+0xe4/0x1b0
<4>[   21.027565]  handle_irq+0x11/0x20
<4>[   21.027569]  do_IRQ+0x5e/0x120
<4>[   21.027579]  common_interrupt+0x84/0x84
<4>[   21.027583]  </IRQ>
<4>[   21.027588] RIP: 0010:debug_lockdep_rcu_enabled.part.0+0x14/0x20
<4>[   21.027591] RSP: 0018:ffffc9000180b9a8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
<4>[   21.027596] RAX: 0000000000000001 RBX: 0000000000000000 RCX: 0000000000000000
<4>[   21.027599] RDX: 0000000000000002 RSI: 0000000000000712 RDI: ffffffffa02ff7e8
<4>[   21.027601] RBP: ffffffffa02ff7e8 R08: 0000000000000002 R09: 0000000000000064
<4>[   21.027604] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000712
<4>[   21.027607] R13: 0000000000000000 R14: 0000000000000000 R15: ffff880218ec0ca0
<4>[   21.027634]  ___might_sleep+0x15/0x240
<4>[   21.027688]  __intel_wait_for_register+0x49/0x160 [i915]
<4>[   21.027746]  intel_disable_pipe+0x113/0x170 [i915]
<4>[   21.027799]  ironlake_crtc_disable+0x6a/0x6d0 [i915]
<4>[   21.027806]  ? __mutex_unlock_slowpath+0x38/0x270
<4>[   21.027861]  intel_atomic_commit_tail+0x1ec/0xd20 [i915]
<4>[   21.027924]  intel_atomic_commit+0x256/0x330 [i915]
<4>[   21.027936]  restore_fbdev_mode_atomic+0x199/0x1f0
<4>[   21.027964]  drm_fb_helper_restore_fbdev_mode_unlocked+0x42/0x90
<4>[   21.027971]  drm_fb_helper_set_par+0x24/0x50
<4>[   21.028019]  intel_fbdev_set_par+0x11/0x60 [i915]
<4>[   21.028027]  fbcon_init+0x594/0x620
<4>[   21.028042]  visual_init+0xca/0x120
<4>[   21.028050]  do_bind_con_driver+0x1bb/0x3a0
<4>[   21.028067]  do_unbind_con_driver+0x1a1/0x210
<4>[   21.028085]  store_bind+0xb8/0x1b0
<4>[   21.028097]  kernfs_fop_write+0xfe/0x180
<4>[   21.028108]  __vfs_write+0x1e/0x130
<4>[   21.028114]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[   21.028118]  ? rcu_sync_lockdep_assert+0x25/0x50
<4>[   21.028123]  ? __sb_start_write+0xd9/0x1f0
<4>[   21.028127]  ? __sb_start_write+0xf3/0x1f0
<4>[   21.028138]  vfs_write+0xbd/0x1b0
<4>[   21.028147]  SyS_write+0x40/0xa0
<4>[   21.028157]  do_syscall_64+0x65/0x1a0
<4>[   21.028165]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[   21.028168] RIP: 0033:0x7f34ab0f5670
<4>[   21.028171] RSP: 002b:00007fff584913d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4>[   21.028176] RAX: ffffffffffffffda RBX: 000055d058065670 RCX: 00007f34ab0f5670
<4>[   21.028179] RDX: 0000000000000002 RSI: 000055d0579addf8 RDI: 0000000000000008
<4>[   21.028181] RBP: 00007fff58491400 R08: 000055d0580656e3 R09: 0000000000000020
<4>[   21.028184] R10: 0000000000000073 R11: 0000000000000246 R12: 000055d0579adddc
<4>[   21.028187] R13: 000055d0579adda6 R14: 000055d0580656e3 R15: 000055d0579adde2
<4>[   21.028211] Code: e1 48 c7 c2 80 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[   21.028348] ---[ end trace 7eaa47f887fd291b ]---
Comment 10 Marta Löfstedt 2018-02-28 06:52:06 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4306/shard-snb7/igt@kms_chv_cursor_fail@pipe-b-64x64-top-edge.html

<7>[  106.473273] [drm:intel_disable_pipe [i915]] disabling pipe B
<4>[  106.473349] WARNING: CPU: 4 PID: 3250 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  106.473368] 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 snd_hda_intel crc32_pclmul ghash_clmulni_intel snd_hda_codec snd_hwdep snd_hda_core broadcom bcm_phy_lib snd_pcm tg3 mei_me lpc_ich mei prime_numbers
<4>[  106.473426] CPU: 4 PID: 3250 Comm: kms_chv_cursor_ Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3838+ #1
<4>[  106.473429] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
<4>[  106.473433] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  106.473436] RSP: 0018:ffff88022fb03d10 EFLAGS: 00010086
<4>[  106.473441] RAX: ffffffffa04c6d20 RBX: ffff88020ee90000 RCX: 0000000000000001
<4>[  106.473444] RDX: ffffffff820e7e80 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[  106.473446] RBP: ffff88022fb03d70 R08: 0000000000000000 R09: ffffffff815d2780
<4>[  106.473449] R10: 0000000000000000 R11: ffffffffa0396ca0 R12: 0000000000000001
<4>[  106.473452] R13: ffff88021832c138 R14: ffff88021832c460 R15: 0000000000000000
<4>[  106.473455] FS:  00007f4800810a40(0000) GS:ffff88022fb00000(0000) knlGS:0000000000000000
<4>[  106.473458] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  106.473461] CR2: 0000561e912a3858 CR3: 000000021281e005 CR4: 00000000000606e0
<4>[  106.473464] Call Trace:
<4>[  106.473467]  <IRQ>
<4>[  106.473484]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  106.473490]  drm_update_vblank_count+0x64/0x240
<4>[  106.473503]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  106.473545]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  106.473595]  i9xx_pipe_crc_irq_handler+0xfe/0x150 [i915]
<4>[  106.473639]  ironlake_irq_handler+0x618/0xa30 [i915]
<4>[  106.473655]  __handle_irq_event_percpu+0x3c/0x340
<4>[  106.473667]  handle_irq_event_percpu+0x1b/0x50
<4>[  106.473674]  handle_irq_event+0x2f/0x50
<4>[  106.473681]  handle_edge_irq+0xe4/0x1b0
<4>[  106.473689]  handle_irq+0x11/0x20
<4>[  106.473693]  do_IRQ+0x5e/0x120
<4>[  106.473704]  common_interrupt+0x84/0x84
<4>[  106.473708]  </IRQ>
<4>[  106.473713] RIP: 0010:debug_object_init_on_stack+0x0/0x20
<4>[  106.473716] RSP: 0018:ffffc900005ef940 EFLAGS: 00000202 ORIG_RAX: ffffffffffffffde
<4>[  106.473721] RAX: 00000018c774b4a4 RBX: ffffc900005ef9b8 RCX: 0000000000000001
<4>[  106.473724] RDX: 0000000000000000 RSI: ffffffff82249480 RDI: ffffc900005ef948
<4>[  106.473727] RBP: 0000000000000000 R08: ffff88021945d8e0 R09: 00000000f7096856
<4>[  106.473730] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000002710
<4>[  106.473732] R13: 0000000000000001 R14: 0000000000000014 R15: 000000000000000a
<4>[  106.473757]  schedule_hrtimeout_range_clock+0x5c/0x140
<4>[  106.473762]  ? ktime_get+0xde/0x100
<4>[  106.473769]  ? trace_hardirqs_on_caller+0xde/0x1c0
<4>[  106.473774]  ? ktime_get+0x84/0x100
<4>[  106.473780]  ? usleep_range+0x3b/0x70
<4>[  106.473785]  usleep_range+0x57/0x70
<4>[  106.473836]  __intel_wait_for_register+0xf5/0x160 [i915]
<4>[  106.473891]  intel_disable_pipe+0x113/0x170 [i915]
<4>[  106.473942]  ironlake_crtc_disable+0x6a/0x6d0 [i915]
<4>[  106.473948]  ? __mutex_unlock_slowpath+0x38/0x270
<4>[  106.474001]  intel_atomic_commit_tail+0x1ec/0xd20 [i915]
<4>[  106.474063]  intel_atomic_commit+0x256/0x330 [i915]
<4>[  106.474075]  restore_fbdev_mode_atomic+0x199/0x1f0
<4>[  106.474103]  drm_fb_helper_restore_fbdev_mode_unlocked+0x42/0x90
<4>[  106.474110]  drm_fb_helper_set_par+0x24/0x50
<4>[  106.474157]  intel_fbdev_set_par+0x11/0x60 [i915]
<4>[  106.474165]  fbcon_init+0x594/0x620
<4>[  106.474180]  visual_init+0xca/0x120
<4>[  106.474187]  do_bind_con_driver+0x1bb/0x3a0
<4>[  106.474204]  do_unbind_con_driver+0x1a1/0x210
<4>[  106.474222]  store_bind+0xb8/0x1b0
<4>[  106.474234]  kernfs_fop_write+0xfe/0x180
<4>[  106.474244]  __vfs_write+0x1e/0x130
<4>[  106.474251]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[  106.474255]  ? rcu_sync_lockdep_assert+0x25/0x50
<4>[  106.474260]  ? __sb_start_write+0xd9/0x1f0
<4>[  106.474264]  ? __sb_start_write+0xf3/0x1f0
<4>[  106.474274]  vfs_write+0xbd/0x1b0
<4>[  106.474283]  SyS_write+0x40/0xa0
<4>[  106.474293]  do_syscall_64+0x65/0x1a0
<4>[  106.474301]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[  106.474304] RIP: 0033:0x7f47fece8670
<4>[  106.474307] RSP: 002b:00007fff8cb10868 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4>[  106.474312] RAX: ffffffffffffffda RBX: 0000561e9129b820 RCX: 00007f47fece8670
<4>[  106.474315] RDX: 0000000000000002 RSI: 0000561e904a9df8 RDI: 0000000000000008
<4>[  106.474318] RBP: 00007fff8cb10890 R08: 0000561e9129b893 R09: 0000000000000020
<4>[  106.474320] R10: 0000000000000073 R11: 0000000000000246 R12: 0000561e904a9ddc
<4>[  106.474323] R13: 0000561e904a9da6 R14: 0000561e9129b893 R15: 0000561e904a9de2
<4>[  106.474346] Code: e1 48 c7 c2 80 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[  106.474483] ---[ end trace ead0eae4bce6b4b6 ]---
Comment 11 Marta Löfstedt 2018-02-28 06:53:57 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3839/shard-glkb2/igt@kms_plane_lowres@pipe-b-tiling-x.html
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4305/shard-glkb3/igt@kms_plane_lowres@pipe-b-tiling-y.html
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4306/shard-glkb2/igt@kms_plane_lowres@pipe-c-tiling-y.html

<7>[  184.654188] [drm:intel_disable_pipe [i915]] disabling pipe C
<4>[  184.654297] WARNING: CPU: 1 PID: 0 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  184.654377] 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 mei_me r8169 snd_pcm mei mii prime_numbers i2c_hid pinctrl_geminilake pinctrl_intel
<4>[  184.654535] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U           4.16.0-rc2-CI-CI_DRM_3838+ #1
<4>[  184.654542] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  184.654553] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  184.654560] RSP: 0018:ffff88017fc83d38 EFLAGS: 00010086
<4>[  184.654572] RAX: ffffffffa0241d20 RBX: ffff880169400000 RCX: 0000000000000002
<4>[  184.654579] RDX: ffffffff820e7e80 RSI: 0000000000000001 RDI: ffffffff82068da2
<4>[  184.654585] RBP: ffff88017fc83d98 R08: 0000000000000000 R09: ffffffff815d2780
<4>[  184.654592] R10: 0000000000000000 R11: ffffffffa0111ca0 R12: 0000000000000002
<4>[  184.654601] R13: ffff8801639e2548 R14: ffff8801639e2a78 R15: 0000000000000000
<4>[  184.654608] FS:  0000000000000000(0000) GS:ffff88017fc80000(0000) knlGS:0000000000000000
<4>[  184.654616] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  184.654622] CR2: 00007fd24f436000 CR3: 0000000005210000 CR4: 0000000000340ee0
<4>[  184.654633] Call Trace:
<4>[  184.654645]  <IRQ>
<4>[  184.654675]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  184.654690]  drm_update_vblank_count+0x64/0x240
<4>[  184.654713]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  184.654816]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  184.654927]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[  184.655030]  gen8_irq_handler+0x389/0x630 [i915]
<4>[  184.655057]  __handle_irq_event_percpu+0x3c/0x340
<4>[  184.655075]  handle_irq_event_percpu+0x1b/0x50
<4>[  184.655087]  handle_irq_event+0x2f/0x50
<4>[  184.655100]  handle_edge_irq+0xe4/0x1b0
<4>[  184.655114]  handle_irq+0x11/0x20
<4>[  184.655123]  do_IRQ+0x5e/0x120
<4>[  184.655143]  common_interrupt+0x84/0x84
<4>[  184.655152]  </IRQ>
<4>[  184.655161] RIP: 0010:cpuidle_enter_state+0xaa/0x350
<4>[  184.655168] RSP: 0018:ffffc900000c3eb8 EFLAGS: 00000212 ORIG_RAX: ffffffffffffffdc
<4>[  184.655181] RAX: ffff88017a948040 RBX: 0000000000f9fddc RCX: 0000000000000001
<4>[  184.655187] RDX: 0000000000000000 RSI: ffffffff8210fc21 RDI: ffffffff820c0397
<4>[  184.655193] RBP: 0000000000000007 R08: 0000000000002878 R09: 0000000000000018
<4>[  184.655199] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
<4>[  184.655206] R13: ffff88017fcab650 R14: 0000002afd4466dc R15: ffffffff82294460
<4>[  184.655241]  ? cpuidle_enter_state+0xa6/0x350
<4>[  184.655259]  do_idle+0x188/0x1d0
<4>[  184.655279]  cpu_startup_entry+0x14/0x20
<4>[  184.655289]  start_secondary+0x129/0x160
<4>[  184.655301]  secondary_startup_64+0xa5/0xb0
<4>[  184.655334] Code: e1 48 c7 c2 80 7e 0e 82 be 01 00 00 00 48 c7 c7 a2 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[  184.655700] ---[ end trace 3a2be6cee118eef3 ]---
Comment 17 Marta Löfstedt 2018-03-06 06:49:47 UTC
Now also on HSW:

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3874/shard-hsw8/igt@kms_chv_cursor_fail@pipe-c-128x128-left-edge.html

<7>[  785.410971] [drm:intel_disable_pipe [i915]] disabling pipe C
<4>[  785.411057] WARNING: CPU: 4 PID: 6891 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  785.411102] Modules linked in: vgem snd_hda_codec_hdmi i915 snd_hda_codec_realtek x86_pkg_temp_thermal snd_hda_codec_generic intel_powerclamp coretemp snd_hda_intel snd_hda_codec crct10dif_pclmul snd_hwdep crc32_pclmul snd_hda_core ghash_clmulni_intel snd_pcm r8169 mii mei_me mei lpc_ich prime_numbers
<4>[  785.411156] CPU: 4 PID: 6891 Comm: kms_chv_cursor_ Tainted: G     U  W        4.16.0-rc3-CI-CI_DRM_3874+ #1
<4>[  785.411159] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  785.411164] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  785.411167] RSP: 0018:ffff88041fb03d38 EFLAGS: 00010082
<4>[  785.411172] RAX: ffffffffa0302b00 RBX: ffff880400480000 RCX: 0000000000000002
<4>[  785.411174] RDX: ffffffff820e7f60 RSI: 0000000000000001 RDI: ffffffff82068daa
<4>[  785.411177] RBP: ffff88041fb03d98 R08: 0000000000000000 R09: ffffffff815d2b70
<4>[  785.411180] R10: 0000000000000000 R11: ffffffffa01bc470 R12: 0000000000000002
<4>[  785.411182] R13: ffff8803fffed3d8 R14: ffff8803fffed908 R15: 0000000000000000
<4>[  785.411186] FS:  00007f96b1825a40(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[  785.411188] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  785.411191] CR2: 0000560918a7d9f8 CR3: 00000004071c6002 CR4: 00000000001606e0
<4>[  785.411194] Call Trace:
<4>[  785.411197]  <IRQ>
<4>[  785.411214]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  785.411220]  drm_update_vblank_count+0x64/0x240
<4>[  785.411233]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  785.411288]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  785.411353]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[  785.411408]  ironlake_irq_handler+0x8ac/0xa30 [i915]
<4>[  785.411424]  __handle_irq_event_percpu+0x3c/0x340
<4>[  785.411436]  handle_irq_event_percpu+0x1b/0x50
<4>[  785.411443]  handle_irq_event+0x2f/0x50
<4>[  785.411450]  handle_edge_irq+0xe4/0x1b0
<4>[  785.411459]  handle_irq+0x11/0x20
<4>[  785.411464]  do_IRQ+0x5e/0x120
<4>[  785.411475]  common_interrupt+0x84/0x84
<4>[  785.411479]  </IRQ>
<4>[  785.411483] RIP: 0010:vprintk_emit+0x23b/0x4f0
<4>[  785.411486] RSP: 0018:ffffc90000a7b990 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
<4>[  785.411491] RAX: ffff8804068b0040 RBX: 0000000000000007 RCX: 0000000000000006
<4>[  785.411494] RDX: 0000000000001356 RSI: ffffffff8210fd11 RDI: ffffffff820c03af
<4>[  785.411496] RBP: ffffc90000a7b9e0 R08: ffff8804068b09e0 R09: 0000000088c83963
<4>[  785.411499] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000246
<4>[  785.411502] R13: 0000000000000000 R14: 0000000000000030 R15: 0000000000000000
<4>[  785.411535]  printk+0x3e/0x46
<4>[  785.411613]  ? intel_disable_pipe+0x3c/0x170 [i915]
<4>[  785.411621]  drm_printk+0x89/0x90
<4>[  785.411632]  ? trace_hardirqs_on_caller+0xde/0x1c0
<4>[  785.411711]  intel_disable_pipe+0x3c/0x170 [i915]
<4>[  785.411789]  haswell_crtc_disable+0x69/0x130 [i915]
<4>[  785.411869]  intel_atomic_commit_tail+0x1ec/0xd20 [i915]
<4>[  785.411957]  intel_atomic_commit+0x256/0x330 [i915]
<4>[  785.411970]  restore_fbdev_mode_atomic+0x199/0x1f0
<4>[  785.411996]  drm_fb_helper_restore_fbdev_mode_unlocked+0x42/0x90
<4>[  785.412003]  drm_fb_helper_set_par+0x24/0x50
<4>[  785.412076]  intel_fbdev_set_par+0x11/0x60 [i915]
<4>[  785.412085]  fbcon_init+0x594/0x620
<4>[  785.412100]  visual_init+0xca/0x120
<4>[  785.412107]  do_bind_con_driver+0x1bb/0x3a0
<4>[  785.412123]  store_bind+0x190/0x1b0
<4>[  785.412134]  kernfs_fop_write+0xfe/0x180
<4>[  785.412146]  __vfs_write+0x1e/0x130
<4>[  785.412153]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[  785.412157]  ? rcu_sync_lockdep_assert+0x25/0x50
<4>[  785.412163]  ? __sb_start_write+0xd9/0x1f0
<4>[  785.412167]  ? __sb_start_write+0xf3/0x1f0
<4>[  785.412177]  vfs_write+0xbd/0x1b0
<4>[  785.412186]  SyS_write+0x40/0xa0
<4>[  785.412195]  do_syscall_64+0x65/0x1a0
<4>[  785.412204]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[  785.412207] RIP: 0033:0x7f96afcfd670
<4>[  785.412210] RSP: 002b:00007ffc1b47b188 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4>[  785.412215] RAX: ffffffffffffffda RBX: 0000560918a759c0 RCX: 00007f96afcfd670
<4>[  785.412217] RDX: 0000000000000002 RSI: 0000560917294540 RDI: 0000000000000008
<4>[  785.412220] RBP: 0000000000000008 R08: 0000560918a75a33 R09: 0000000000000020
<4>[  785.412223] R10: 0000000000000073 R11: 0000000000000246 R12: 000056091729455b
<4>[  785.412225] R13: 0000560917294561 R14: 0000560917294546 R15: 0000560918a75a33
<4>[  785.412247] Code: e1 48 c7 c2 60 7f 0e 82 be 01 00 00 00 48 c7 c7 aa 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[  785.412381] WARNING: CPU: 4 PID: 6891 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[  785.412384] ---[ end trace 1b9ccb6cf102d2a1 ]---
Comment 19 Marta Löfstedt 2018-03-06 06:51:39 UTC
And introducing APL:
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3874/shard-apl1/igt@kms_chv_cursor_fail@pipe-c-64x64-bottom-edge.html

<4>[   37.170635] WARNING: CPU: 1 PID: 1443 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   37.170653] Modules linked in: 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 snd_pcm r8169 mii mei_me mei prime_numbers pinctrl_broxton pinctrl_intel
<4>[   37.170748] CPU: 1 PID: 1443 Comm: kms_chv_cursor_ Not tainted 4.16.0-rc3-CI-CI_DRM_3874+ #1
<4>[   37.170752] Hardware name:  /NUC6CAYB, BIOS AYAPLCEL.86A.0047.2018.0108.1419 01/08/2018
<4>[   37.170759] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   37.170764] RSP: 0018:ffff88027fc83d20 EFLAGS: 00010082
<4>[   37.170772] RAX: ffffffffa026db00 RBX: ffff880262940000 RCX: 0000000000000002
<4>[   37.170776] RDX: ffffffff820e7f60 RSI: 0000000000000001 RDI: ffffffff82068daa
<4>[   37.170780] RBP: ffff88027fc83d80 R08: 0000000000000000 R09: ffffffff815d2b70
<4>[   37.170785] R10: 0000000000000000 R11: ffffffffa0127470 R12: 0000000000000002
<4>[   37.170789] R13: ffff880262af2e98 R14: ffff880262af33c8 R15: 0000000000000000
<4>[   37.170794] FS:  00007f8221523a40(0000) GS:ffff88027fc80000(0000) knlGS:0000000000000000
<4>[   37.170798] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[   37.170803] CR2: 0000558d96d3aff8 CR3: 000000025f2da000 CR4: 00000000003406e0
<4>[   37.170807] Call Trace:
<4>[   37.170813]  <IRQ>
<4>[   37.170841]  drm_get_last_vbltimestamp+0x36/0x50
<4>[   37.170850]  drm_update_vblank_count+0x64/0x240
<4>[   37.170869]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[   37.170967]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[   37.171075]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[   37.171171]  gen8_de_irq_handler+0x1fa/0x5a0 [i915]
<4>[   37.171271]  gen8_irq_handler+0x95/0xa0 [i915]
<4>[   37.171288]  __handle_irq_event_percpu+0x3c/0x340
<4>[   37.171306]  handle_irq_event_percpu+0x1b/0x50
<4>[   37.171315]  handle_irq_event+0x2f/0x50
<4>[   37.171326]  handle_edge_irq+0xe4/0x1b0
<4>[   37.171336]  handle_irq+0x11/0x20
<4>[   37.171343]  do_IRQ+0x5e/0x120
<4>[   37.171358]  common_interrupt+0x84/0x84
<4>[   37.171365]  </IRQ>
<4>[   37.171371] RIP: 0010:_raw_spin_unlock_irq+0x2a/0x50
<4>[   37.171376] RSP: 0018:ffffc9000041fa58 EFLAGS: 00000202 ORIG_RAX: ffffffffffffffdb
<4>[   37.171384] RAX: ffff88026ab58040 RBX: ffff880262940ca0 RCX: 0000000000000006
<4>[   37.171388] RDX: 0000000000001388 RSI: ffffffff8210fd11 RDI: 0000000000000001
<4>[   37.171392] RBP: 0000000040000000 R08: ffff88026ab589e0 R09: 00000000531bbf4a
<4>[   37.171397] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000072008
<4>[   37.171401] R13: 0000000000000000 R14: 0000000000000000 R15: ffff880262940ca0
<4>[   37.171440]  ? _raw_spin_unlock_irq+0x24/0x50
<4>[   37.171547]  __intel_wait_for_register+0x91/0x160 [i915]
<4>[   37.171671]  intel_disable_pipe+0x113/0x170 [i915]
<4>[   37.171791]  haswell_crtc_disable+0x69/0x130 [i915]
<4>[   37.171911]  intel_atomic_commit_tail+0x1ec/0xd20 [i915]
<4>[   37.172046]  intel_atomic_commit+0x256/0x330 [i915]
<4>[   37.172063]  restore_fbdev_mode_atomic+0x199/0x1f0
<4>[   37.172106]  drm_fb_helper_restore_fbdev_mode_unlocked+0x42/0x90
<4>[   37.172118]  drm_fb_helper_set_par+0x24/0x50
<4>[   37.172229]  intel_fbdev_set_par+0x11/0x60 [i915]
<4>[   37.172241]  fbcon_init+0x594/0x620
<4>[   37.172263]  visual_init+0xca/0x120
<4>[   37.172275]  do_bind_con_driver+0x1bb/0x3a0
<4>[   37.172299]  store_bind+0x190/0x1b0
<4>[   37.172316]  kernfs_fop_write+0xfe/0x180
<4>[   37.172331]  __vfs_write+0x1e/0x130
<4>[   37.172341]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[   37.172347]  ? rcu_sync_lockdep_assert+0x25/0x50
<4>[   37.172354]  ? __sb_start_write+0xd9/0x1f0
<4>[   37.172360]  ? __sb_start_write+0xf3/0x1f0
<4>[   37.172375]  vfs_write+0xbd/0x1b0
<4>[   37.172390]  SyS_write+0x40/0xa0
<4>[   37.172405]  do_syscall_64+0x65/0x1a0
<4>[   37.172416]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[   37.172422] RIP: 0033:0x7f821f9fb670
<4>[   37.172426] RSP: 002b:00007ffc3e8ab228 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4>[   37.172434] RAX: ffffffffffffffda RBX: 0000558d96d32fc0 RCX: 00007f821f9fb670
<4>[   37.172438] RDX: 0000000000000002 RSI: 0000558d9661d540 RDI: 0000000000000008
<4>[   37.172442] RBP: 0000000000000008 R08: 0000558d96d33033 R09: 0000000000000020
<4>[   37.172446] R10: 0000000000000073 R11: 0000000000000246 R12: 0000558d9661d55b
<4>[   37.172451] R13: 0000558d9661d561 R14: 0000558d9661d546 R15: 0000558d96d33033
<4>[   37.172486] Code: e1 48 c7 c2 60 7f 0e 82 be 01 00 00 00 48 c7 c7 aa 8d 06 82 e8 64 ec ff ff 48 8b 83 c8 07 00 00 48 83 78 28 00 0f 84 e2 fe ff ff <0f> 0b 45 31 ed e9 db fe ff ff 41 b8 d3 4d 62 10 89 c8 6a 03 41 
<4>[   37.172722] WARNING: CPU: 1 PID: 1443 at drivers/gpu/drm/drm_vblank.c:614 drm_calc_vbltimestamp_from_scanoutpos+0x13e/0x2f0
<4>[   37.172726] ---[ end trace 83bd06219681b1cf ]---
Comment 27 Maarten Lankhorst 2018-03-06 17:35:38 UTC
https://patchwork.freedesktop.org/series/39454/
Comment 29 Marta Löfstedt 2018-03-07 06:37:48 UTC
Since HSW hits this incomplete on related test I file these on this bug as well:

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4315/shard-snb2/igt@kms_chv_cursor_fail@pipe-b-256x256-left-edge.html

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3883/shard-hsw2/igt@kms_chv_cursor_fail@pipe-c-64x64-right-edge.html

<7>[  855.521563] [drm:intel_disable_pipe [i915]] disabling pipe C
<4>[  855.521566] divide error: 0000 [#1] PREEMPT SMP PTI
<0>[  855.521570] Dumping ftrace buffer:
<0>[  855.521575]    (ftrace buffer empty)
<4>[  855.521577] Modules linked in: snd_hda_intel i915 vgem snd_hda_codec_hdmi x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul snd_hda_codec_realtek crc32_pclmul snd_hda_codec_generic ghash_clmulni_intel snd_hda_codec r8169 snd_hwdep mei_me mii snd_hda_core mei snd_pcm lpc_ich prime_numbers [last unloaded: i915]
<4>[  855.521602] CPU: 4 PID: 0 Comm: swapper/4 Tainted: G     U  W        4.16.0-rc4-CI-CI_DRM_3883+ #1
<4>[  855.521603] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  855.521609] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x1c9/0x2f0
<4>[  855.521611] RSP: 0018:ffff88041fb03d38 EFLAGS: 00010086
<4>[  855.521614] RAX: ffffffec890d3c00 RBX: 000000c7218c002b RCX: 0000000000000000
<4>[  855.521615] RDX: ffffffffffffffff RSI: ffffffff8210ff39 RDI: 000000c7218c002b
<4>[  855.521616] RBP: ffff88041fb03d98 R08: 0000000000000000 R09: 0000000000000001
<4>[  855.521618] R10: 0000000000000000 R11: 00000000000002cd R12: 0000000000000002
<4>[  855.521619] R13: 0000000000000001 R14: ffff8803fa1daa78 R15: 0000000000000000
<4>[  855.521621] FS:  0000000000000000(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[  855.521623] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  855.521624] CR2: 000055ab64d5be98 CR3: 0000000005210002 CR4: 00000000001606e0
<4>[  855.521625] Call Trace:
<4>[  855.521628]  <IRQ>
<4>[  855.521634]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  855.521637]  drm_update_vblank_count+0x64/0x240
<4>[  855.521642]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  855.521708]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  855.521762]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[  855.521812]  ironlake_irq_handler+0x8ac/0xa30 [i915]
<4>[  855.521820]  __handle_irq_event_percpu+0x3c/0x340
<4>[  855.521825]  handle_irq_event_percpu+0x1b/0x50
<4>[  855.521828]  handle_irq_event+0x2f/0x50
<4>[  855.521832]  handle_edge_irq+0xe4/0x1b0
<4>[  855.521838]  handle_irq+0x11/0x20
<4>[  855.521842]  do_IRQ+0x5e/0x120
<4>[  855.521849]  common_interrupt+0xf/0xf
<4>[  855.521850]  </IRQ>
<4>[  855.521855] RIP: 0010:cpuidle_enter_state+0xaa/0x350
<4>[  855.521856] RSP: 0018:ffffc900000afeb8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffffdd
<4>[  855.521859] RAX: ffff88040d5a0040 RBX: 0000000000020487 RCX: 0000000000000001
<4>[  855.521861] RDX: 0000000000000000 RSI: ffffffff8210ff39 RDI: ffffffff820c05bf
<4>[  855.521862] RBP: 0000000000000005 R08: 0000000000004034 R09: 0000000000000008
<4>[  855.521863] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000005
<4>[  855.521865] R13: ffffe8ffffd09090 R14: 000000c7310a8fa7 R15: ffffffff822944a0
<4>[  855.521873]  ? cpuidle_enter_state+0xa6/0x350
<4>[  855.521878]  do_idle+0x188/0x1d0
<4>[  855.521882]  cpu_startup_entry+0x14/0x20
<4>[  855.521887]  start_secondary+0x129/0x160
<4>[  855.521892]  secondary_startup_64+0xa5/0xb0
<4>[  855.521898] Code: ac 48 8b 45 b0 48 89 fb 44 89 18 41 8b 86 a8 00 00 00 0f af 45 b8 49 63 8e 90 00 00 00 03 45 bc 48 98 48 69 c0 40 42 0f 00 48 99 <48> f7 f9 48 98 48 29 c3 48 89 d8 48 8b 5d a0 48 89 03 f6 05 ce 
<1>[  855.521951] RIP: drm_calc_vbltimestamp_from_scanoutpos+0x1c9/0x2f0 RSP: ffff88041fb03d38
<4>[  855.521954] ---[ end trace 361123ac88e02638 ]---
Comment 30 Marta Löfstedt 2018-03-08 06:35:09 UTC
Since HSW hits this incomplete on related test I file these on this bug as well:

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4315/shard-snb2/igt@kms_chv_cursor_fail@pipe-b-256x256-left-edge.html

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3883/shard-hsw2/igt@kms_chv_cursor_fail@pipe-c-64x64-right-edge.html

<7>[  855.521563] [drm:intel_disable_pipe [i915]] disabling pipe C
<4>[  855.521566] divide error: 0000 [#1] PREEMPT SMP PTI
<0>[  855.521570] Dumping ftrace buffer:
<0>[  855.521575]    (ftrace buffer empty)
<4>[  855.521577] Modules linked in: snd_hda_intel i915 vgem snd_hda_codec_hdmi x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul snd_hda_codec_realtek crc32_pclmul snd_hda_codec_generic ghash_clmulni_intel snd_hda_codec r8169 snd_hwdep mei_me mii snd_hda_core mei snd_pcm lpc_ich prime_numbers [last unloaded: i915]
<4>[  855.521602] CPU: 4 PID: 0 Comm: swapper/4 Tainted: G     U  W        4.16.0-rc4-CI-CI_DRM_3883+ #1
<4>[  855.521603] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  855.521609] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x1c9/0x2f0
<4>[  855.521611] RSP: 0018:ffff88041fb03d38 EFLAGS: 00010086
<4>[  855.521614] RAX: ffffffec890d3c00 RBX: 000000c7218c002b RCX: 0000000000000000
<4>[  855.521615] RDX: ffffffffffffffff RSI: ffffffff8210ff39 RDI: 000000c7218c002b
<4>[  855.521616] RBP: ffff88041fb03d98 R08: 0000000000000000 R09: 0000000000000001
<4>[  855.521618] R10: 0000000000000000 R11: 00000000000002cd R12: 0000000000000002
<4>[  855.521619] R13: 0000000000000001 R14: ffff8803fa1daa78 R15: 0000000000000000
<4>[  855.521621] FS:  0000000000000000(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[  855.521623] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  855.521624] CR2: 000055ab64d5be98 CR3: 0000000005210002 CR4: 00000000001606e0
<4>[  855.521625] Call Trace:
<4>[  855.521628]  <IRQ>
<4>[  855.521634]  drm_get_last_vbltimestamp+0x36/0x50
<4>[  855.521637]  drm_update_vblank_count+0x64/0x240
<4>[  855.521642]  drm_crtc_accurate_vblank_count+0x41/0x90
<4>[  855.521708]  display_pipe_crc_irq_handler+0x176/0x220 [i915]
<4>[  855.521762]  hsw_pipe_crc_irq_handler+0x46/0x50 [i915]
<4>[  855.521812]  ironlake_irq_handler+0x8ac/0xa30 [i915]
<4>[  855.521820]  __handle_irq_event_percpu+0x3c/0x340
<4>[  855.521825]  handle_irq_event_percpu+0x1b/0x50
<4>[  855.521828]  handle_irq_event+0x2f/0x50
<4>[  855.521832]  handle_edge_irq+0xe4/0x1b0
<4>[  855.521838]  handle_irq+0x11/0x20
<4>[  855.521842]  do_IRQ+0x5e/0x120
<4>[  855.521849]  common_interrupt+0xf/0xf
<4>[  855.521850]  </IRQ>
<4>[  855.521855] RIP: 0010:cpuidle_enter_state+0xaa/0x350
<4>[  855.521856] RSP: 0018:ffffc900000afeb8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffffdd
<4>[  855.521859] RAX: ffff88040d5a0040 RBX: 0000000000020487 RCX: 0000000000000001
<4>[  855.521861] RDX: 0000000000000000 RSI: ffffffff8210ff39 RDI: ffffffff820c05bf
<4>[  855.521862] RBP: 0000000000000005 R08: 0000000000004034 R09: 0000000000000008
<4>[  855.521863] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000005
<4>[  855.521865] R13: ffffe8ffffd09090 R14: 000000c7310a8fa7 R15: ffffffff822944a0
<4>[  855.521873]  ? cpuidle_enter_state+0xa6/0x350
<4>[  855.521878]  do_idle+0x188/0x1d0
<4>[  855.521882]  cpu_startup_entry+0x14/0x20
<4>[  855.521887]  start_secondary+0x129/0x160
<4>[  855.521892]  secondary_startup_64+0xa5/0xb0
<4>[  855.521898] Code: ac 48 8b 45 b0 48 89 fb 44 89 18 41 8b 86 a8 00 00 00 0f af 45 b8 49 63 8e 90 00 00 00 03 45 bc 48 98 48 69 c0 40 42 0f 00 48 99 <48> f7 f9 48 98 48 29 c3 48 89 d8 48 8b 5d a0 48 89 03 f6 05 ce 
<1>[  855.521951] RIP: drm_calc_vbltimestamp_from_scanoutpos+0x1c9/0x2f0 RSP: ffff88041fb03d38
<4>[  855.521954] ---[ end trace 361123ac88e02638 ]---
Comment 35 Marta Löfstedt 2018-03-15 07:47:29 UTC
I believe this is the last occurrence:
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3899/shard-snb5/igt@kms_chv_cursor_fail@pipe-b-128x128-top-edge.html

CI_DRM_3899: 6 days / 52 runs ago

However, no one seem to have any idea what that may have fixed it...

So, I will have to keep this open.
Comment 36 Marta Löfstedt 2018-03-19 14:39:01 UTC
I still haven't seen this again. Since it is such big impact for a so many machines I will archive the bug from cibuglog, but keep the bug open if someone want to go back and bisect why it was "fixed".
Comment 37 Jani Saarinen 2018-04-18 11:00:21 UTC
Can this be resolved?
Comment 38 Marta Löfstedt 2018-04-18 11:08:35 UTC
(In reply to Jani Saarinen from comment #37)
> Can this be resolved?

OK, I will close it.
Comment 39 Maarten Lankhorst 2018-04-18 13:07:44 UTC
commit 033b7a230cfa759d1b582fa46bf2cd54db406cf3
Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
Date:   Thu Mar 8 13:02:02 2018 +0100

    drm/i915: Handle pipe CRC around enabling/disabling pipe.


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.