Bug 22166

Summary: DRI2 doesn't support SGI_video_sync extension
Product: Mesa Reporter: Daniel Gnoutcheff <daniel>
Component: Drivers/DRI/i965Assignee: Jesse Barnes <jbarnes>
Status: RESOLVED FIXED QA Contact:
Severity: enhancement    
Priority: high CC: bojan, haien.liu, sam, tmezzadra
Version: unspecified   
Hardware: x86-64 (AMD64)   
OS: Linux (All)   
Whiteboard:
i915 platform: i915 features:
Attachments: Xorg.0.log
xorg.conf
Xorg.1.log with latest 2D driver

Description Daniel Gnoutcheff 2009-06-08 17:21:16 UTC
Sync to vblank seems to be quite broken on this system, at least under the
"one true configuration" of DRI2/KMS/UXA. Running mesa's glsync demo prog with
'glsync -v -s s' (i.e. sync to vblank mode) produces a "waterfall" pattern
that is indistinguishable from what I get with 'glsync -s n' (i.e. without any
syncing), and the console output looks like this:

> gnoutchd@dan-lap:~/newkernel/mesa/progs/xdemos$ ./glsync -v -s s
> waiting on count 1
> waiting on count 4201526
> waiting on count 7067840
> error:  count didn't change: 7067840
> waiting on count 7067840
> error:  count didn't change: 7067840
> waiting on count 7067840
> error:  count didn't change: 7067840
> waiting on count 7067840
> error:  count didn't change: 7067840
<and so on, with the last two messages getting rapidly repeated until the app
is killed>

Also, the kernel message buffer is totally *flooded* with thousands of
repetitions of "failed to acquire vblank counter" messages. With debugging
messages on, we get something like this:

> [17732.592765] [drm:drm_ioctl] pid=13751, cmd=0x4020645d, nr=0x5d, dev
> 0xe200, auth=1
> [17732.592770] [drm:drm_ioctl] pid=13751, cmd=0x40286454, nr=0x54, dev
> 0xe200, auth=1
> [17732.592775] [drm:i915_add_request] 5328651
> [17732.592777] [drm:i915_add_request] 5328652
> [17732.592782] [drm:drm_ioctl] pid=13751, cmd=0xc0086457, nr=0x57, dev
> 0xe200, auth=1
> [17732.592796] [drm:drm_ioctl] pid=13751, cmd=0xc018643a, nr=0x3a, dev
> 0xe200, auth=1
> [17732.592799] [drm:drm_vblank_get] enabling vblank on crtc 0, ret: -22
> [17732.592802] [drm:drm_wait_vblank] *ERROR* failed to acquire vblank
> counter, -22
> [17732.592804] [drm:drm_ioctl] ret = ffffffea
> [17732.592815] [drm:drm_ioctl] pid=13751, cmd=0x4020645d, nr=0x5d, dev
> 0xe200, auth=1
> [17732.592821] [drm:drm_ioctl] pid=13751, cmd=0x40286454, nr=0x54, dev
> 0xe200, auth=1
> [17732.592825] [drm:i915_add_request] 5328653
> [17732.592828] [drm:i915_add_request] 5328654
> [17732.592833] [drm:drm_ioctl] pid=13751, cmd=0xc0086457, nr=0x57, dev
> 0xe200, auth=1
> [17732.592855] [drm:drm_ioctl] pid=13751, cmd=0xc018643a, nr=0x3a, dev
> 0xe200, auth=1
> [17732.592859] [drm:drm_vblank_get] enabling vblank on crtc 0, ret: -22
> [17732.592861] [drm:drm_wait_vblank] *ERROR* failed to acquire vblank
> counter, -22
> [17732.592864] [drm:drm_ioctl] ret = ffffffea
<over and over again>

These results are 100% reproducible.

The same problem seems to affect compiz as well - when I have vsync enabled
there, I also get lots of these "failed to acquire vblank counter" messages.
This spamming of my logs is sufficiently annoying to alone force me to turn
vsync off.

(Note that my glsync tests are done with compiz off.)

'export LIBGL_DEBUG=verbose' doesn't tell us anything meaningful.

System: Lenovo ThinkPad R61 7733A82
Graphics: "Intel Corporation Mobile GM965/GL960 Integrated Graphics
    Controller" [8086:2a03]
Display setup: single built-in LVDS
Distro: Ubuntu 9.04 amd64
Kernel: 2.6.30-rc8-00038-gccc0d38
    [using drm modules shipped with that kernel]
Userspace graphics stack from Ubuntu X-edgers PPA, versions:
    mesa: 7.5-rc3
    xf86-video-intel: 2.7.99+git-66ceedc0
    libdrm: 2.4.11+git-f355ad89
    xserver: 1.2.1.901+git-5cd5a012

Hope this helps! I'm ready and willing to compile from git, test patches, etc.

I'll post the standard logs and config files shortly.
Comment 1 Daniel Gnoutcheff 2009-06-08 18:03:36 UTC
Created attachment 26570 [details]
Xorg.0.log

As per standard procedure.
Comment 2 Daniel Gnoutcheff 2009-06-08 18:06:08 UTC
Created attachment 26571 [details]
xorg.conf

Normally, I run with a really minimal xorg.conf that has an "Option DontZap off" and nothing else, but as per procedure I generated an xorg.conf with X -configure and edited it slightly.
Comment 3 Daniel Gnoutcheff 2009-06-08 18:12:55 UTC
Kernel messages showing system+Xorg bootup found at:
http://www.vu.union.edu/~gnoutchd/bugs/intel-vblank/kern-log
Warning: 4.4 megabytes! (i.e. too big to attach)

That log was made with drm.debug=1, so that's why it's so big. ;) Note that hat log was actually extracted from syslog, standard kernel message buffer wasn't big enough. :)

If desired, I can reboot without such verbose debugging and attach a more "normal" dmesg.

Any additional info/tests are just a request away ;)
Comment 4 Jesse Barnes 2009-06-09 17:20:32 UTC
This should be fixed in git master of the 2D driver, can you give it a try?
Comment 5 Daniel Gnoutcheff 2009-06-09 22:11:33 UTC
Created attachment 26611 [details]
Xorg.1.log with latest 2D driver

(In reply to comment #4)
> This should be fixed in git master of the 2D driver, can you give it a try?

Done. I'm afraid upgrading does not help, it makes no noticeable change in behavior. Xorg log attached.

I've tried upgrading only the 2D driver, and I've also tried going for broke and compiling *everything* from git. Neither fixes this bug.

I should note, though, that when I install everything from from git I start getting lots of segfaults - another issue I have to investigate and probably file bug(s) for. For example, the attached log shows a crash on xterm exit. Also, with with latest xserver, I get a segfault immediately on server start, making it impossible to test for this bug. Because of this, I'm currently testing with a self-compiled xserver that matches the version from X-edgers.
Comment 6 Jesse Barnes 2009-06-10 07:51:04 UTC
Ahh.. the -ss option doesn't work with DRI2... we haven't hooked it up yet.  -sb should work ok though since it uses buffer swaps (those do the vblank waiting in the server).

Since SGI_video_sync shouldn't be used to avoid tearing anyway, I don't think this is a huge issue (swapbuffers is the most reliable way to avoid tearing).
Comment 7 Daniel Gnoutcheff 2009-06-10 10:50:31 UTC
(In reply to comment #6)
> Ahh.. the -ss option doesn't work with DRI2... we haven't hooked it up yet. 
> -sb should work ok though since it uses buffer swaps (those do the vblank
> waiting in the server).
> 
> Since SGI_video_sync shouldn't be used to avoid tearing anyway, I don't think
> this is a huge issue (swapbuffers is the most reliable way to avoid tearing).

OK, yes, -sb does work correctly, no tearing there.

Any idea how soon SGI_video_sync will be implemented, if ever? Because if it's not "soon", I really do think that something should be done about the dmesg spamming, at least. When vsync is turned on in compiz (as it is by default), my system logs very quickly grow to hundreds of megabytes, even with drm.debug=0.
Comment 8 Jesse Barnes 2009-06-10 11:16:10 UTC
> 2009-06-10 10:50:31 PST --- (In reply to comment #6)
> > Ahh.. the -ss option doesn't work with DRI2... we haven't hooked it
> > up yet. -sb should work ok though since it uses buffer swaps (those
> > do the vblank waiting in the server).
> > 
> > Since SGI_video_sync shouldn't be used to avoid tearing anyway, I
> > don't think this is a huge issue (swapbuffers is the most reliable
> > way to avoid tearing).
> 
> OK, yes, -sb does work correctly, no tearing there.
> 
> Any idea how soon SGI_video_sync will be implemented, if ever?
> Because if it's not "soon", I really do think that something should
> be done about the dmesg spamming, at least. When vsync is turned on
> in compiz (as it is by default), my system logs very quickly grow to
> hundreds of megabytes, even with drm.debug=0.

It might be soon, it shouldn't actually be too hard.  But yeah I'll get
rid of the message for 2.6.31 as well.  It's really just debug output
to indicate that userspace tried to wait on a disabled pipe (which is
bad, but we shouldn't spam the log about it, since the return value
will be enough).

Jesse
Comment 9 Jesse Barnes 2009-06-26 09:38:58 UTC
*** Bug 22492 has been marked as a duplicate of this bug. ***
Comment 10 Jesse Barnes 2009-10-05 10:37:51 UTC
*** Bug 22056 has been marked as a duplicate of this bug. ***
Comment 11 Gordon Jin 2009-10-09 23:15:09 UTC
increasing priority as it impacts moblin: http://bugzilla.moblin.org/show_bug.cgi?id=6488
Comment 12 Jesse Barnes 2010-01-26 14:44:06 UTC
Support added by mesa c6ef705e414c8e93ee471f50d15ada3492a9b067, xserver 04a54f69a8085ab3fe11a8713bd8b6b16ed1db27, and xf86-video-intel 51c75906329a4727e37c8d1f64f257ea9602caa2.

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.