Bug 97607 - [ALL][BAT] dmesg WARN_ON(drm_crtc_vblank_get(crtc) == 0) while executing igt kms_flip --run-subtest basic-flip-vs-dpms
Summary: [ALL][BAT] dmesg WARN_ON(drm_crtc_vblank_get(crtc) == 0) while executing igt ...
Status: CLOSED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: highest critical
Assignee: Jari Tahvanainen
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-09-06 06:07 UTC by Jari Tahvanainen
Modified: 2016-09-09 10:45 UTC (History)
1 user (show)

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


Attachments
dmesg (test execution) (774.82 KB, application/x-zip-compressed)
2016-09-06 06:07 UTC, Jari Tahvanainen
no flags Details
dmesg (boot) (79.01 KB, text/plain)
2016-09-06 06:08 UTC, Jari Tahvanainen
no flags Details

Description Jari Tahvanainen 2016-09-06 06:07:40 UTC
Created attachment 126234 [details]
dmesg (test execution)

From CI build CI_DRM_1612 (first failure on commit e175837, last pass on commit 0c70339) onwards kms_flip --run-subtest basic-flip-vs-dpms starts to get dmesg-fail verdict with the following dmesg WARNINGS in log:
...
[  615.481611] WARNING: CPU: 1 PID: 10709 at drivers/gpu/drm/i915/intel_display.c:1355 assert_vblank_disabled+0x71/0x80 [i915]
[  615.481622] WARN_ON(drm_crtc_vblank_get(crtc) == 0)
...
[  615.498812] WARNING: CPU: 1 PID: 10709 at drivers/gpu/drm/drm_irq.c:1168 drm_vblank_put+0xb1/0xc0

This can be reproduced in all HW in CI with command:
<your path to igt>/tests/kms_flip --run-subtest basic-flip-vs-dpms

Dmesg is taken out from fi-skl-6260u with latest build CI_DRM_1612 
Detail	Value
Returncode	99
Time	0:01:01.885783
Stdout	
IGT-Version: 1.16-gf92e47f (x86_64) (Linux: 4.8.0-rc4-CI-CI_DRM_1612+ x86_64)
Using monotonic timestamps
Beginning basic-flip-vs-dpms on pipe A, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500
Stack trace:
  #0 [__igt_fail_assert+0x101]
  #1 [run_test_on_crtc_set.constprop.14+0x1998]
  #2 [run_test+0x26a]
  #3 [main+0x3c1]
  #4 [__libc_start_main+0xf0]
  #5 [_start+0x29]
Subtest basic-flip-vs-dpms: FAIL (0.173s)
Stderr	
(kms_flip:11618) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:903:
(kms_flip:11618) CRITICAL: Failed assertion: do_page_flip(o, new_fb_id, true) == expected_einval
(kms_flip:11618) CRITICAL: Last errno: 22, Invalid argument
Subtest basic-flip-vs-dpms failed.
**** DEBUG ****
(kms_flip:11618) DEBUG: Test requirement passed: (flags & TEST_HANG) == 0 || !is_wedged(drm_fd)
(kms_flip:11618) DEBUG: Test requirement passed: modes
(kms_flip:11618) INFO: Beginning basic-flip-vs-dpms on pipe A, connector HDMI-A-1
(kms_flip:11618) igt-fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=0x34325258, tiling=0x0, size=0)
(kms_flip:11618) igt-fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680)
(kms_flip:11618) igt-fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=0x34325258, tiling=0x0, size=0)
(kms_flip:11618) igt-fb-DEBUG: igt_create_fb_with_bo_size(handle=3, pitch=7680)
(kms_flip:11618) igt-kms-INFO:   1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500
(kms_flip:11618) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 406.348768
current_received_ts = 406.366974
current_seq = 12916
count = 0
seq_step = 1
(kms_flip:11618) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:903:
(kms_flip:11618) CRITICAL: Failed assertion: do_page_flip(o, new_fb_id, true) == expected_einval
(kms_flip:11618) CRITICAL: Last errno: 22, Invalid argument
****  END  ****
Environment	
PIGLIT_SOURCE_DIR="/opt/igt/piglit" PIGLIT_PLATFORM="mixed_glx_egl"
Command	/opt/igt/tests/kms_flip --run-subtest basic-flip-vs-dpms
dmesg	
[  467.969822] ------------[ cut here ]------------
[  467.969903] WARNING: CPU: 2 PID: 11618 at drivers/gpu/drm/i915/intel_display.c:1355 assert_vblank_disabled+0x71/0x80 [i915]
[  467.969906] WARN_ON(drm_crtc_vblank_get(crtc) == 0)
[  467.969910] Modules linked in:
[  467.969913]  snd_hda_intel i915 ax88179_178a usbnet mii snd_hda_codec_hdmi snd_hda_codec_realtek x86_pkg_temp_thermal snd_hda_codec_generic intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me mei sdhci_pci e1000e sdhci ptp pps_core mmc_core i2c_hid [last unloaded: vgem]
[  467.969972] CPU: 2 PID: 11618 Comm: kms_flip Tainted: G     U          4.8.0-rc4-CI-CI_DRM_1612+ #1
[  467.969975] Hardware name:                  /NUC6i5SYB, BIOS SYSKLi35.86A.0042.2016.0409.1246 04/09/2016
[  467.969979]  0000000000000000 ffff8802629b7928 ffffffff81426de5 ffff8802629b7978
[  467.969989]  0000000000000000 ffff8802629b7968 ffffffff8107d2a6 0000054b810d3e62
[  467.969997]  ffff8802635f1158 ffff88023af90000 ffff880230f24138 00000000fffffffc
[  467.970006] Call Trace:
[  467.970017]  [<ffffffff81426de5>] dump_stack+0x67/0x92
[  467.970025]  [<ffffffff8107d2a6>] __warn+0xc6/0xe0
[  467.970031]  [<ffffffff8107d30a>] warn_slowpath_fmt+0x4a/0x50
[  467.970100]  [<ffffffffa047e331>] assert_vblank_disabled+0x71/0x80 [i915]
[  467.970169]  [<ffffffffa04925f4>] haswell_crtc_enable+0x314/0x7e0 [i915]
[  467.970220]  [<ffffffffa04259c3>] ? intel_runtime_pm_put+0x53/0xc0 [i915]
[  467.970268]  [<ffffffffa0425b8c>] ? intel_display_power_put+0xbc/0x100 [i915]
[  467.970332]  [<ffffffffa048dc09>] intel_update_crtc+0x49/0xe0 [i915]
[  467.970393]  [<ffffffffa048de98>] skl_update_crtcs+0x178/0x190 [i915]
[  467.970450]  [<ffffffffa048e420>] intel_atomic_commit_tail+0x350/0x1190 [i915]
[  467.970458]  [<ffffffff8153c50e>] ? drm_atomic_helper_swap_state+0x10e/0x2f0
[  467.970463]  [<ffffffff8153c539>] ? drm_atomic_helper_swap_state+0x139/0x2f0
[  467.970519]  [<ffffffffa048f675>] intel_atomic_commit+0x415/0x580 [i915]
[  467.970528]  [<ffffffff810c8530>] ? wake_atomic_t_function+0x60/0x60
[  467.970536]  [<ffffffff8155ff62>] drm_atomic_commit+0x52/0x60
[  467.970541]  [<ffffffff8153ca08>] drm_atomic_helper_connector_dpms+0xe8/0x1a0
[  467.970549]  [<ffffffff815637ed>] drm_mode_connector_set_obj_prop+0x5d/0x70
[  467.970554]  [<ffffffff81564b26>] drm_mode_obj_set_property_ioctl+0x126/0x160
[  467.970561]  [<ffffffff8156382b>] drm_mode_connector_property_set_ioctl+0x2b/0x30
[  467.970566]  [<ffffffff815490e7>] drm_ioctl+0x207/0x4c0
[  467.970573]  [<ffffffff81563800>] ? drm_mode_connector_set_obj_prop+0x70/0x70
[  467.970580]  [<ffffffff810ea55d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[  467.970585]  [<ffffffff810ea55d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[  467.970593]  [<ffffffff811fe12e>] do_vfs_ioctl+0x8e/0x680
[  467.970599]  [<ffffffff810d3e62>] ? trace_hardirqs_on_caller+0x122/0x1b0
[  467.970605]  [<ffffffff811fe75c>] SyS_ioctl+0x3c/0x70
[  467.970613]  [<ffffffff818109e9>] entry_SYSCALL_64_fastpath+0x1c/0xac
[  467.970618] ---[ end trace 7371ed5213b0e4d5 ]---
[  467.971118] ------------[ cut here ]------------
[  467.971123] WARNING: CPU: 0 PID: 8389 at drivers/gpu/drm/drm_irq.c:1168 drm_vblank_put+0xb1/0xc0
[  467.971125] Modules linked in: snd_hda_intel i915 ax88179_178a usbnet mii snd_hda_codec_hdmi snd_hda_codec_realtek x86_pkg_temp_thermal snd_hda_codec_generic intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me mei sdhci_pci e1000e sdhci ptp pps_core mmc_core i2c_hid [last unloaded: vgem]
[  467.971175] CPU: 0 PID: 8389 Comm: dmesg Tainted: G     U  W       4.8.0-rc4-CI-CI_DRM_1612+ #1
[  467.971179] Hardware name:                  /NUC6i5SYB, BIOS SYSKLi35.86A.0042.2016.0409.1246 04/09/2016
[  467.971182]  0000000000000000 ffff88026ec03d48 ffffffff81426de5 0000000000000000
[  467.971190]  0000000000000000 ffff88026ec03d88 ffffffff8107d2a6 0000049059510578
[  467.971195]  ffff8802635f1158 ffff8802651cd728 ffff88023af90000 0000000000000001
[  467.971199] Call Trace:
[  467.971200]  <IRQ>  [<ffffffff81426de5>] dump_stack+0x67/0x92
[  467.971205]  [<ffffffff8107d2a6>] __warn+0xc6/0xe0
[  467.971207]  [<ffffffff8107d378>] warn_slowpath_null+0x18/0x20
[  467.971209]  [<ffffffff8154af51>] drm_vblank_put+0xb1/0xc0
[  467.971211]  [<ffffffff8154af72>] drm_crtc_vblank_put+0x12/0x20
[  467.971235]  [<ffffffffa047cbcb>] page_flip_completed+0x3b/0x1b0 [i915]
[  467.971260]  [<ffffffffa0495fd5>] intel_finish_page_flip_mmio+0x65/0x70 [i915]
[  467.971280]  [<ffffffffa040aad8>] intel_pipe_handle_vblank+0x28/0x40 [i915]
[  467.971298]  [<ffffffffa040ea73>] gen8_irq_handler+0x373/0x6f0 [i915]
[  467.971304]  [<ffffffff810e23e8>] __handle_irq_event_percpu+0x58/0x370
[  467.971308]  [<ffffffff810e271e>] handle_irq_event_percpu+0x1e/0x50
[  467.971311]  [<ffffffff810e2784>] handle_irq_event+0x34/0x60
[  467.971316]  [<ffffffff810e592e>] handle_edge_irq+0xbe/0x150
[  467.971320]  [<ffffffff8101e635>] handle_irq+0x15/0x20
[  467.971324]  [<ffffffff8101dc88>] do_IRQ+0x68/0x130
[  467.971326]  [<ffffffff81811389>] common_interrupt+0x89/0x89
[  467.971327]  <EOI>  [<ffffffff818101f4>] ? _raw_spin_unlock_irqrestore+0x54/0x60
[  467.971333]  [<ffffffff811cbf9d>] free_debug_processing+0x16d/0x3c0
[  467.971336]  [<ffffffff812c7d3a>] ? jbd2_journal_stop+0x1ba/0x4d0
[  467.971338]  [<ffffffff811cc53d>] __slab_free+0x34d/0x490
[  467.971341]  [<ffffffff818101f2>] ? _raw_spin_unlock_irqrestore+0x52/0x60
[  467.971343]  [<ffffffff810d3efd>] ? trace_hardirqs_on+0xd/0x10
[  467.971345]  [<ffffffff818101dd>] ? _raw_spin_unlock_irqrestore+0x3d/0x60
[  467.971348]  [<ffffffff814468da>] ? debug_check_no_obj_freed+0x20a/0x220
[  467.971351]  [<ffffffff810d3d0f>] ? mark_held_locks+0x6f/0xa0
[  467.971355]  [<ffffffff811cc884>] ? kmem_cache_free+0x204/0x340
[  467.971359]  [<ffffffff812c7d3a>] ? jbd2_journal_stop+0x1ba/0x4d0
[  467.971362]  [<ffffffff811cc94a>] kmem_cache_free+0x2ca/0x340
[  467.971366]  [<ffffffff812c7d3a>] jbd2_journal_stop+0x1ba/0x4d0
[  467.971369]  [<ffffffff8127c4fe>] ? ext4_mark_iloc_dirty+0x4de/0x7d0
[  467.971374]  [<ffffffff812acb94>] ? __ext4_journal_get_write_access+0x44/0x80
[  467.971379]  [<ffffffff812ac8f7>] __ext4_journal_stop+0x37/0xa0
[  467.971383]  [<ffffffff81281967>] ext4_dirty_inode+0x57/0x60
[  467.971387]  [<ffffffff8121cb58>] __mark_inode_dirty+0x78/0x700
[  467.971390]  [<ffffffff812082e1>] generic_update_time+0x71/0xc0
[  467.971394]  [<ffffffff8120e1a9>] ? mnt_clone_write+0x39/0x60
[  467.971396]  [<ffffffff81208430>] file_update_time+0x90/0xe0
[  467.971398]  [<ffffffff8116d8d7>] __generic_file_write_iter+0x97/0x1f0
[  467.971400]  [<ffffffff81272a32>] ext4_file_write_iter+0xc2/0x3b0
[  467.971403]  [<ffffffff811ea28f>] __vfs_write+0xbf/0x120
[  467.971405]  [<ffffffff811eaf03>] vfs_write+0xb3/0x1b0
[  467.971407]  [<ffffffff810d3e62>] ? trace_hardirqs_on_caller+0x122/0x1b0
[  467.971409]  [<ffffffff811ec234>] SyS_write+0x44/0xb0
[  467.971412]  [<ffffffff818109e9>] entry_SYSCALL_64_fastpath+0x1c/0xac
[  467.971414] ---[ end trace 7371ed5213b0e4d6 ]---
Comment 1 Jari Tahvanainen 2016-09-06 06:08:32 UTC
Created attachment 126235 [details]
dmesg (boot)
Comment 2 Jari Tahvanainen 2016-09-06 06:47:02 UTC
Same dmesg WARNING is visible multiple times in log also when executing test command:
<your path to igt>/tests/kms_flip --run-subtest basic-flip-vs-modeset
Comment 3 Jari Tahvanainen 2016-09-06 07:08:21 UTC
the commit log data taken 30 minutes ago:
commit eac8e03923dba8cf300fb87eabf8769e5a059fd3
Merge: 7dd5da7 2b2fd56
Author:     Chris Wilson <chris@chris-wilson.co.uk>
AuthorDate: Sat Sep 3 13:12:33 2016 +0100
Commit:     Chris Wilson <chris@chris-wilson.co.uk>
CommitDate: Sat Sep 3 13:12:33 2016 +0100

    Merge remote-tracking branch 'drm-upstream/drm-next' into drm-intel-nightly

    # Conflicts:
    #   drivers/gpu/drm/amd/amdgpu/amdgpu.h
    #   drivers/gpu/drm/drm_crtc.c
Comment 4 Imre Deak 2016-09-07 17:53:02 UTC
The following should fix this:
https://patchwork.freedesktop.org/patch/109270/
Comment 5 Jari Tahvanainen 2016-09-08 07:52:56 UTC
I would say that patch series (https://patchwork.freedesktop.org/series/12129/) removes the failure based on the latest CI results (see below).
Lets change the status to resolved when the change is in drm-intel-nightly. Any idea when this could be there?

Series 12129v1 drm: Fix error path in drm_mode_page_flip_ioctl()
http://patchwork.freedesktop.org/api/1.0/series/12129/revisions/1/mbox/

Test kms_flip:
        Subgroup basic-flip-vs-dpms:
                dmesg-fail -> PASS       (fi-snb-2600)
                dmesg-fail -> PASS       (fi-ivb-3520m)
                dmesg-fail -> PASS       (fi-bdw-5557u)
                dmesg-fail -> PASS       (fi-hsw-4770r)
                dmesg-fail -> PASS       (fi-snb-2520m)
                dmesg-fail -> PASS       (fi-ivb-3770)
                dmesg-fail -> PASS       (fi-skl-6700k)
                dmesg-fail -> PASS       (fi-ilk-650)
                dmesg-fail -> PASS       (fi-hsw-4770k)
                dmesg-fail -> PASS       (fi-bsw-n3050)
                dmesg-fail -> PASS       (fi-skl-6260u)
        Subgroup basic-flip-vs-modeset:
                dmesg-warn -> PASS       (fi-snb-2600)
                dmesg-warn -> PASS       (fi-ivb-3520m)
                dmesg-warn -> PASS       (fi-bdw-5557u)
                dmesg-warn -> PASS       (fi-hsw-4770r)
                dmesg-warn -> PASS       (fi-snb-2520m)
                dmesg-warn -> PASS       (fi-ivb-3770)
                dmesg-warn -> PASS       (fi-skl-6700k)
                dmesg-warn -> PASS       (fi-ilk-650)
                dmesg-warn -> PASS       (fi-hsw-4770k)
                dmesg-warn -> PASS       (fi-bsw-n3050)
                dmesg-warn -> PASS       (fi-skl-6260u)
        Subgroup basic-flip-vs-wf_vblank:
                dmesg-warn -> PASS       (fi-snb-2600)
                dmesg-warn -> PASS       (fi-ivb-3520m)
                dmesg-warn -> PASS       (fi-bdw-5557u)
                dmesg-warn -> PASS       (fi-hsw-4770r)
                dmesg-warn -> PASS       (fi-ivb-3770)
                dmesg-warn -> PASS       (fi-skl-6700k)
                dmesg-warn -> PASS       (fi-ilk-650)
                dmesg-warn -> PASS       (fi-hsw-4770k)
                dmesg-warn -> PASS       (fi-skl-6260u)

E.g. for fi-skl-6260u
IGT-Version: 1.16-g6bd4208 (x86_64) (Linux: 4.8.0-rc5-CI-Patchwork_2483+ x86_64)
Using monotonic timestamps
Beginning basic-flip-vs-dpms on pipe A, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500

basic-flip-vs-dpms on pipe A, connector HDMI-A-1: PASSED

Beginning basic-flip-vs-dpms on pipe B, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500

basic-flip-vs-dpms on pipe B, connector HDMI-A-1: PASSED

Beginning basic-flip-vs-dpms on pipe C, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500

basic-flip-vs-dpms on pipe C, connector HDMI-A-1: PASSED

Subtest basic-flip-vs-dpms: SUCCESS (20.433s)
Comment 6 Imre Deak 2016-09-08 14:11:57 UTC
(In reply to Jari Tahvanainen from comment #5)
> I would say that patch series
> (https://patchwork.freedesktop.org/series/12129/) removes the failure based
> on the latest CI results (see below).
> Lets change the status to resolved when the change is in drm-intel-nightly.
> Any idea when this could be there?

The fix is now merged, so closing.
Comment 7 Jari Tahvanainen 2016-09-09 10:45:16 UTC
Verified. In latest execution on drm-intel-nightly CI_DRM_1622/fi-skl-6260u

Result: pass

Back to summary

Details

Detail	Value
Returncode	0
Time	0:00:20.511960
Stdout	
IGT-Version: 1.16-ge4d74f2 (x86_64) (Linux: 4.8.0-rc5-CI-CI_DRM_1622+ x86_64)
Using monotonic timestamps
Beginning basic-flip-vs-dpms on pipe A, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500

basic-flip-vs-dpms on pipe A, connector HDMI-A-1: PASSED

Beginning basic-flip-vs-dpms on pipe B, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500

basic-flip-vs-dpms on pipe B, connector HDMI-A-1: PASSED

Beginning basic-flip-vs-dpms on pipe C, connector HDMI-A-1
  1920x1080 60 1920 2008 2052 2200 1080 1084 1089 1125 0x5 0x48 148500

basic-flip-vs-dpms on pipe C, connector HDMI-A-1: PASSED

Subtest basic-flip-vs-dpms: SUCCESS (20.398s)
Stderr	
Environment	
PIGLIT_SOURCE_DIR="/opt/igt/piglit" PIGLIT_PLATFORM="mixed_glx_egl"
Command	/opt/igt/tests/kms_flip --run-subtest basic-flip-vs-dpms
dmesg


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.