Bug 85431 - [gm45] intel_display.c:902 g4x_wait_for_vblank+0xd5/0xf0 [i915]() vblank wait timed out
Summary: [gm45] intel_display.c:902 g4x_wait_for_vblank+0xd5/0xf0 [i915]() vblank wait...
Status: RESOLVED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: Video(DRI - Intel) (show other bugs)
Hardware: x86-64 Linux
: P3 normal
Assignee: intel-gfx-bugs@lists.freedesktop.org
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-10-02 00:30 UTC by Alan Bartlett
Modified: 2015-10-07 11:01 UTC (History)
3 users (show)

See Also:
Kernel Version: 3.17-rc7
Subsystem:
Regression: No
Bisected commit-id:


Attachments
Relevant output of lspci -nnvv command (1.56 KB, text/plain)
2014-10-02 00:30 UTC, Alan Bartlett
Details
Full dmesg output (61.85 KB, text/plain)
2014-10-02 00:32 UTC, Alan Bartlett
Details
The bad commit (579 bytes, text/plain)
2014-10-02 15:33 UTC, Alan Bartlett
Details

Description Alan Bartlett 2014-10-02 00:30:34 UTC
Created attachment 152201 [details]
Relevant output of lspci -nnvv command

------------[ cut here ]------------
WARNING: CPU: 1 PID: 116 at drivers/gpu/drm/i915/intel_display.c:902 g4x_wait_for_vblank+0xd5/0xf0 [i915]()
vblank wait timed out
Modules linked in: i915 drm_kms_helper video
CPU: 1 PID: 116 Comm: plymouthd Not tainted 3.17.0-0.rc7.el6.elrepo.x86_64 #1
Hardware name: Dell Inc. Latitude E5500                  /0DW633, BIOS A19 06/13/2013
 0000000000000386 ffff8801196179d8 ffffffff8165a527 0000000000000386
 ffff880119617a28 ffff880119617a18 ffffffff8107183c 00000000fffb7398
 ffff8800d8a50000 0000000000071040 0000000000000009 00000000fffb7397
Call Trace:
 [<ffffffff8165a527>] dump_stack+0x49/0x62
 [<ffffffff8107183c>] warn_slowpath_common+0x8c/0xc0
 [<ffffffff81071926>] warn_slowpath_fmt+0x46/0x50
 [<ffffffffa008bcd5>] g4x_wait_for_vblank+0xd5/0xf0 [i915]
 [<ffffffffa008bd25>] intel_wait_for_vblank+0x35/0x130 [i915]
 [<ffffffffa00c447b>] intel_tv_detect_type+0x10b/0x330 [i915]
 [<ffffffffa00c4793>] intel_tv_detect+0xf3/0x200 [i915]
 [<ffffffffa0010d23>] drm_helper_probe_single_connector_modes_merge_bits+0x2b3/0x3d0 [drm_kms_helper]
 [<ffffffff8141117b>] ? _object_find+0x8b/0xc0
 [<ffffffffa0010e73>] drm_helper_probe_single_connector_modes+0x13/0x20 [drm_kms_helper]
 [<ffffffff81413b8c>] drm_mode_getconnector+0x40c/0x450
 [<ffffffff811c3697>] ? do_huge_pmd_anonymous_page+0x107/0x290
 [<ffffffff814079ce>] drm_ioctl+0x2de/0x650
 [<ffffffff8105d864>] ? __do_page_fault+0xe4/0x4c0
 [<ffffffff81413780>] ? drm_plane_force_disable+0x70/0x70
 [<ffffffff811e88b3>] do_vfs_ioctl+0x73/0x380
 [<ffffffff8127548f>] ? selinux_file_ioctl+0x4f/0xf0
 [<ffffffff811e8c61>] SyS_ioctl+0xa1/0xb0
 [<ffffffff8165ede9>] system_call_fastpath+0x16/0x1b
---[ end trace 50529787d26448be ]---

Bisecting the kernel results in the following log --

git bisect start
# bad: [fe82dcec644244676d55a1384c958d5f67979adb] Linux 3.17-rc7
git bisect bad fe82dcec644244676d55a1384c958d5f67979adb
# good: [1860e379875dfe7271c649058aeddffe5afd9d0d] Linux 3.15
git bisect good 1860e379875dfe7271c649058aeddffe5afd9d0d
# bad: [fa24615f4ce27fc41f11348459b2e26655c7255a] Merge tag 'char-misc-3.16-rc6' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/char-misc
git bisect bad fa24615f4ce27fc41f11348459b2e26655c7255a
# good: [dcbff5d1effbbd52be1ed9f2efb6c8d0445ad188] idr: reorder the fields
git bisect good dcbff5d1effbbd52be1ed9f2efb6c8d0445ad188
# bad: [0430e49b6e7c6b5e076be8fefdee089958c9adad] ima: introduce ima_kernel_read()
git bisect bad 0430e49b6e7c6b5e076be8fefdee089958c9adad
# good: [9ee4d7a6538308a7681b638d2f35f2a301420355] Merge branch 'akpm' (patches from Andrew Morton)
git bisect good 9ee4d7a6538308a7681b638d2f35f2a301420355
# bad: [bc1dfff04a5d4064ba0db1fab13f84ab4f333d2b] Merge branch 'drm-nouveau-next' of git://anongit.freedesktop.org/git/nouveau/linux-2.6 into drm-next
git bisect bad bc1dfff04a5d4064ba0db1fab13f84ab4f333d2b
# bad: [4fa62c890cea83f28c30e1d5dc8fc86f61210280] drm/i915: Move buffer pinning and ring selection to intel_crtc_page_flip()
git bisect bad 4fa62c890cea83f28c30e1d5dc8fc86f61210280
# bad: [aeab0b5af7df88284d101abf8d121f0e913b81ff] drm/i915: disable runtime PM if RC6 is disabled
git bisect bad aeab0b5af7df88284d101abf8d121f0e913b81ff
# bad: [13732ba7493fd4b28568f768ee12497e26a0c8af] drm/i915: move infoframe setting to after pll enable v3
git bisect bad 13732ba7493fd4b28568f768ee12497e26a0c8af
# good: [7c4d664e03c9b12572356a6ce8e69c7d59e6f4f7] drm/i915: fix open coded gen5_gt_irq_preinstall
git bisect good 7c4d664e03c9b12572356a6ce8e69c7d59e6f4f7
# good: [9926ada1280767a039c4bc0f84549eb8f273c5de] drm/i915: only check for irqs_disabled when disabling LCPLL
git bisect good 9926ada1280767a039c4bc0f84549eb8f273c5de
# good: [4e04632e882719e46edcbbc0b76fad778a0ed845] drm/i915/vlv:Implement the WA 'WaDisable_RenderCache_OperationalFlush'
git bisect good 4e04632e882719e46edcbbc0b76fad778a0ed845
# bad: [2a44b76bb5a1f520371432825c91fa46c63bde84] drm/i915: Add some more tracked state to intel_pipe_wm
git bisect bad 2a44b76bb5a1f520371432825c91fa46c63bde84
# good: [935f38d6948eb0bf10ac691d010fec9e9163a9c6] drm/i915: Unref context on failed eb_create
git bisect good 935f38d6948eb0bf10ac691d010fec9e9163a9c6
# bad: [17d36749a559905f7d9a640239a9fc74fc3bb445] drm/i915: Dump the whole context object.
git bisect bad 17d36749a559905f7d9a640239a9fc74fc3bb445

The file .git/refs/bisect/bad contains --

17d36749a559905f7d9a640239a9fc74fc3bb445
Comment 1 Alan Bartlett 2014-10-02 00:32:10 UTC
Created attachment 152211 [details]
Full dmesg output
Comment 2 Jani Nikula 2014-10-02 08:10:24 UTC
Please finish the bisect.
Comment 3 Alan Bartlett 2014-10-02 13:35:57 UTC
(In reply to Jani Nikula from comment #2)
> Please finish the bisect.

Obviously I thought I had. :(

Please help me out and clarify exactly what is missing. More importantly, please explain how one knows that a bisection is complete.
Comment 4 Alan Bartlett 2014-10-02 15:31:13 UTC
Retracing my steps I can now see that I miscounted (due to lack of sleep).

The log --

[Build64R6 linux]$ git bisect log
git bisect start
# bad: [fe82dcec644244676d55a1384c958d5f67979adb] Linux 3.17-rc7
git bisect bad fe82dcec644244676d55a1384c958d5f67979adb
# good: [1860e379875dfe7271c649058aeddffe5afd9d0d] Linux 3.15
git bisect good 1860e379875dfe7271c649058aeddffe5afd9d0d
# bad: [fa24615f4ce27fc41f11348459b2e26655c7255a] Merge tag 'char-misc-3.16-rc6' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/char-misc
git bisect bad fa24615f4ce27fc41f11348459b2e26655c7255a
# good: [dcbff5d1effbbd52be1ed9f2efb6c8d0445ad188] idr: reorder the fields
git bisect good dcbff5d1effbbd52be1ed9f2efb6c8d0445ad188
# bad: [0430e49b6e7c6b5e076be8fefdee089958c9adad] ima: introduce ima_kernel_read()
git bisect bad 0430e49b6e7c6b5e076be8fefdee089958c9adad
# good: [9ee4d7a6538308a7681b638d2f35f2a301420355] Merge branch 'akpm' (patches from Andrew Morton)
git bisect good 9ee4d7a6538308a7681b638d2f35f2a301420355
# bad: [bc1dfff04a5d4064ba0db1fab13f84ab4f333d2b] Merge branch 'drm-nouveau-next' of git://anongit.freedesktop.org/git/nouveau/linux-2.6 into drm-next
git bisect bad bc1dfff04a5d4064ba0db1fab13f84ab4f333d2b
# bad: [4fa62c890cea83f28c30e1d5dc8fc86f61210280] drm/i915: Move buffer pinning and ring selection to intel_crtc_page_flip()
git bisect bad 4fa62c890cea83f28c30e1d5dc8fc86f61210280
# bad: [aeab0b5af7df88284d101abf8d121f0e913b81ff] drm/i915: disable runtime PM if RC6 is disabled
git bisect bad aeab0b5af7df88284d101abf8d121f0e913b81ff
# bad: [13732ba7493fd4b28568f768ee12497e26a0c8af] drm/i915: move infoframe setting to after pll enable v3
git bisect bad 13732ba7493fd4b28568f768ee12497e26a0c8af
# good: [7c4d664e03c9b12572356a6ce8e69c7d59e6f4f7] drm/i915: fix open coded gen5_gt_irq_preinstall
git bisect good 7c4d664e03c9b12572356a6ce8e69c7d59e6f4f7
# good: [9926ada1280767a039c4bc0f84549eb8f273c5de] drm/i915: only check for irqs_disabled when disabling LCPLL
git bisect good 9926ada1280767a039c4bc0f84549eb8f273c5de
# good: [4e04632e882719e46edcbbc0b76fad778a0ed845] drm/i915/vlv:Implement the WA 'WaDisable_RenderCache_OperationalFlush'
git bisect good 4e04632e882719e46edcbbc0b76fad778a0ed845
# bad: [2a44b76bb5a1f520371432825c91fa46c63bde84] drm/i915: Add some more tracked state to intel_pipe_wm
git bisect bad 2a44b76bb5a1f520371432825c91fa46c63bde84
# good: [935f38d6948eb0bf10ac691d010fec9e9163a9c6] drm/i915: Unref context on failed eb_create
git bisect good 935f38d6948eb0bf10ac691d010fec9e9163a9c6
# bad: [17d36749a559905f7d9a640239a9fc74fc3bb445] drm/i915: Dump the whole context object.
git bisect bad 17d36749a559905f7d9a640239a9fc74fc3bb445
# bad: [9393707190194eb8b42e412b444a03331db6862f] drm/i915: warn when a vblank wait times out
git bisect bad 9393707190194eb8b42e412b444a03331db6862f
[Build64R6 linux]$

The bad commit --

[Build64R6 linux]$ git bisect bad
9393707190194eb8b42e412b444a03331db6862f is the first bad commit
commit 9393707190194eb8b42e412b444a03331db6862f
Author: Jesse Barnes <jbarnes@virtuousgeek.org>
Date:   Fri Apr 4 16:12:09 2014 -0700

    drm/i915: warn when a vblank wait times out
    
    This always indicates a bug somewhere.
    
    Signed-off-by: Jesse Barnes <jbarnes@virtuousgeek.org>
    Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>

:040000 040000 ea35b90af96d508197e845a7793f782067e7736b ac515983fd901a9b3d83c279618ab4365724dd95 M	drivers
[Build64R6 linux]$
Comment 5 Alan Bartlett 2014-10-02 15:33:43 UTC
Created attachment 152221 [details]
The bad commit
Comment 6 Jani Nikula 2014-10-02 18:28:20 UTC
Thanks for the bisect; as you see "xxx is the first bad commit" was what I was looking for!

Sadly, that commit is where we started issuing the warning for what's already going wrong. :(
Comment 7 Alan Bartlett 2014-10-02 18:37:00 UTC
(In reply to Jani Nikula from comment #6)
> Thanks for the bisect; as you see "xxx is the first bad commit" was what I
> was looking for!
> 
> Sadly, that commit is where we started issuing the warning for what's
> already going wrong. :(

Yes, I see it now (that I am fully awake).

Hmm, I had a feeling that result was going to be a NOP. Is there anything else I can try to help to pin-point the location?
Comment 8 Jani Nikula 2015-01-28 14:29:22 UTC
See also

commit 7a98948f3b536ca9a077e84966ddc0e9f53726df
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Mon Sep 8 17:43:01 2014 +0300

    drm/i915: Wait for vblank before enabling the TV encoder
Comment 9 Jani Nikula 2015-02-11 14:36:11 UTC
Please try drm-intel-nightly branch of http://cgit.freedesktop.org/drm-intel
Comment 10 Alan Bartlett 2015-02-15 13:37:47 UTC
Here follows my report after using the above drm-intel-nightly branch . . .

Defining the video hardware --

00:02.0 VGA compatible controller [0300]: Intel Corporation Mobile 4 Series Chipset Integrated Graphics Controller [8086:2a42] (rev 07)
00:02.1 Display controller [0380]: Intel Corporation Mobile 4 Series Chipset Integrated Graphics Controller [8086:2a43] (rev 07)

Verbose report --

A 64-bit kernel version was built, installed and booted. At the usual point where kernel modesetting adjusts the display the output was blanked and the system locked up solidly. No further disk activity occurred and it was impossible to access via ssh. Repeat testing confirms that the lock-up was not a one-off event.
Comment 11 Alan Bartlett 2015-02-16 18:31:40 UTC
For completeness, I will mention that my test documented in comment 10, above, was performed using a RHEL 6.6 system.
Comment 12 Alan Bartlett 2015-06-19 12:49:07 UTC
In my opinion, this report can now be closed as "resolved/code fix" as the bug has not been experienced with newer kernels, up to and including 4.1-rc8
Comment 13 Jani Nikula 2015-10-07 11:01:22 UTC
(In reply to Alan Bartlett from comment #12)
> In my opinion, this report can now be closed as "resolved/code fix" as the
> bug has not been experienced with newer kernels, up to and including 4.1-rc8

Thanks for the follow-up.

Note You need to log in before you can comment on or make changes to this bug.