| Summary: | OpenGL vsync no longer working properly | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | xorg | Reporter: | Pierre Ossman <pierre-bugzilla> | ||||||
| Component: | Driver/Radeon | Assignee: | xf86-video-ati maintainers <xorg-driver-ati> | ||||||
| Status: | RESOLVED INVALID | QA Contact: | Xorg Project Team <xorg-team> | ||||||
| Severity: | normal | ||||||||
| Priority: | medium | CC: | jbarnes | ||||||
| Version: | unspecified | ||||||||
| Hardware: | x86-64 (AMD64) | ||||||||
| OS: | Linux (All) | ||||||||
| Whiteboard: | |||||||||
| i915 platform: | i915 features: | ||||||||
| Attachments: |
|
||||||||
|
Description
Pierre Ossman
2010-06-06 09:59:56 UTC
Bug 26240 might have some relevance as it was a similar problem with the same system. These two issues may be relevant: http://lists.x.org/archives/xorg-devel/2010-June/009693.html http://lists.freedesktop.org/archives/dri-devel/2010-June/001110.html This may be a dupe of bug 28341. Oddly enough, I can no longer reproduce the flickering. No components have changed in the system, so whatever caused it yesterday must have been some weird state caused by flipping mesa/libdrm versions back and forth. vsync problem is still present and need investigation though. Hmm... bad ground work on my part. It seems xbmc did some kind of reset at some point and turned off the vsync setting. Turning it on though results in one frame every five seconds or so. Not really usable... This was with libdrm and mesa updated to head: Mesa: 149e709701e0b6ac2c0c820d89db6a3cd32c5f09 DRM: 66375fd6e8d3e95df5d124883a1426460c1b8ed8 Shifting back to the fc13 packages and the flickering is back in place. No frame rate limiting though... I forgot to mention the kernel versions used. Before upgrade: 2.6.32.12-115.fc12.x86_64 After upgrade: 2.6.33.5-112.fc13.x86_64 Unfortunately these are Fedora kernels so I'm not sure what DRM stuff is in there. Been testing different mesa versions to see some kind of pattern: 7.7 branch (mesa_7_6_1_rc1-2602-g0e08054): Low fps mesa_7_6_1_rc1-3851-g833acea: "just" no sync 7.8 branch (mesa_7_6_1_rc1-5911-gd2f2d0a): Flickering More pinpointing will follow... The commit that causes the flickering is: 1ca968363dd55e919bd91c8fc31c34d207af3958 is the first bad commit commit 1ca968363dd55e919bd91c8fc31c34d207af3958 Author: Jesse Barnes <jbarnes@virtuousgeek.org> Date: Fri Mar 5 11:17:19 2010 -0800 DRI2: expose OML_sync_control if possible If the server supports the OML related protocol, enable support for the extension. Not too surprising as xbmc uses the OML stuff. Have you tried the latest 1.8.x X server? Several fixes landed recently that might affect this... No, haven't tried replacing the X server as that is the messiest component to swap out. I'll try a compile and just get a custom Xorg binary... I've now tested with xorg-server-1.8.1.901 and the results are slightly different. Instead of 0.2 fps, I get 2 fps. An increase by a magnitude, but still not useful. possibly also related to bug 28383. I wasn't completely correct in my previous comment. Mesa 7.8.1 branch went from flickering to 2 fps. I've now tested master as well and that did however go from 0.2 fps to 2 fps. Should also note that xbmc is eating 100% CPU now, so I guess it is busy waiting for something. Has anyone had a look at this? Upgraded to latest mesa today and the problem is still there. Even omlsync in mesa/demos is broken. :/ I did some extra output from omlsync.c: glXGetSyncValuesOML(disp, winGL, &ust, &msc, &sbc); fprintf(stderr, "ust: %lld, msc: %lld, sbc: %lld\n", (long long)ust, (long long)msc, (long long)sbc); Result is this: ust: 0, msc: 0, sbc: 8912 ust: 0, msc: 0, sbc: 8913 ust: 0, msc: 0, sbc: 8914 ust: 0, msc: 0, sbc: 8915 ust: 0, msc: 0, sbc: 8916 ust: 0, msc: 0, sbc: 8917 ust: 0, msc: 0, sbc: 8918 Doesn't seem correct to me that neither ust nor msc are incrementing. In regard to comment 2, which resulted in bug 28341, I tried the following in omlsync.c: glXSwapBuffersMscOML(disp, winGL, msc, 0, 0); glXWaitForSbcOML(disp, winGL, 0, &ust, &msc, &sbc); Still no syncing. Regarding comment 15, it's hitting this code in Xorg: if (!ds->GetMSC) { *ust = 0; *msc = 0; *sbc = pPriv->swap_count; return Success; } (from DRI2GetMSC()) Turns out the DDX I was using (6.13.0) didn't have the GetMSC callback. Using master, I got some more proper values. Unfortunately the result now is that omlsync locks up after a bit. Investigating... Output from omlsync: ust: 1278446384416354, msc: 37158, sbc: 0 ust: 1278446384416680, msc: 37158, sbc: 0 (hang) More digging. The client hangs because the X server ignores the request in this code:
/*
* Ensures an out of control client can't exhaust our swap queue, and
* also orders swaps.
*/
if (DRI2ThrottleClient(client, pDrawable))
return client->noClientException;
(from ProcDRI2SwapBuffers())
From the looks of it, I guess that code means no reply is sent to the client and it will wait forever.
The server does accept the first SwapBuffer request, but the second triggers that throttle thing.
Looks like some kernel issue. Xorg is calling drmWaitVBlank() with proper arguments as far as I can tell:
fprintf(stderr, "Current counter: %lld\n", (long long)current_msc);
fprintf(stderr, "Waiting for %lld (0x%08x)\n", (long long)*target_msc, vbl.request.type);
in radeon_dri2_schedule_swap() results in:
Current counter: 132192
Waiting for 132192 (0x14000000)
A vblank event never occurs though so the Xorg stack just sits there forever.
And turning on debug in the kernel shows that vblank interrupts aren't enabled when this is going on. They are running for a while just as the X server is starting, but then they are disabled again.
Some stuff from dmesg: [drm:r600_irq_process], IH: D2 vblank [drm:r600_irq_process], r600_irq_process start: rptr 24736, wptr 24752 [drm:r600_irq_process], IH: D2 vblank [drm:r600_irq_process], r600_irq_process start: rptr 24752, wptr 24768 [drm:r600_irq_process], IH: D2 vblank [drm:vblank_disable_fn], disabling vblank on crtc 1 [drm:r600_irq_set], r600_irq_set: vblank 0 [drm:r600_irq_set], r600_irq_set: hpd 1 [drm:r600_irq_set], r600_irq_set: hpd 2 Above is once X is running and idle. Then when starting omlsync: [drm:drm_stub_open], [drm:drm_open_helper], pid = 9962, minor = 0 [drm:drm_ioctl], pid=9962, cmd=0x80046402, nr=0x02, dev 0xe200, auth=1 [drm:drm_add_magic], 37 [drm:drm_getmagic], 37 [drm:drm_ioctl], pid=9952, cmd=0x40046411, nr=0x11, dev 0xe200, auth=1 [drm:drm_authmagic], 37 [drm:drm_remove_magic], 37 [drm:drm_ioctl], pid=9962, cmd=0xc0406400, nr=0x00, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0406400, nr=0x00, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0106467, nr=0x67, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0106467, nr=0x67, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc018645c, nr=0x5c, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_wait_vblank], waiting on vblank count 132192, crtc 0 [drm:drm_wait_vblank], returning 132192 to client [drm:drm_ioctl], pid=9952, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc008640a, nr=0x0a, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc008640a, nr=0x0a, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc008640a, nr=0x0a, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc010640b, nr=0x0b, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc00c6469, nr=0x69, dev 0xe200, auth=1 [drm:radeon_gem_get_tiling_ioctl], [drm:drm_ioctl], pid=9962, cmd=0xc010640b, nr=0x0b, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc00c6469, nr=0x69, dev 0xe200, auth=1 [drm:radeon_gem_get_tiling_ioctl], [drm:drm_ioctl], pid=9962, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_wait_vblank], waiting on vblank count 132192, crtc 0 [drm:drm_wait_vblank], returning 132192 to client [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_wait_vblank], waiting on vblank count 132192, crtc 0 [drm:drm_wait_vblank], returning 132192 to client [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_wait_vblank], waiting on vblank count 132192, crtc 0 [drm:drm_wait_vblank], returning 132192 to client [drm:drm_ioctl], pid=9952, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_wait_vblank], waiting on vblank count 132192, crtc 0 [drm:drm_wait_vblank], returning 132192 to client [drm:drm_ioctl], pid=9952, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_queue_vblank_event], event on vblank count 132193, current 132192, crtc 0 [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645d, nr=0x5d, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc020645e, nr=0x5e, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9962, cmd=0xc0086464, nr=0x64, dev 0xe200, auth=1 [drm:drm_ioctl], pid=9952, cmd=0xc018643a, nr=0x3a, dev 0xe200, auth=1 [drm:drm_wait_vblank], waiting on vblank count 132192, crtc 0 [drm:drm_wait_vblank], returning 132192 to client Sounds like a potential problem with the radeon drm driver... the vbltest program from libdrm tests just the events by themselves, that can help verify if events are working at all. It could be that X is waiting on a disabled pipe or something, you wouldn't generally see events from that. vbltest does indeed indicate some problem: [root@hugin vbltest]# ./vbltest trying to load module i915...failed. trying to load module radeon...success. starting count: 13013 select timed out or error (ret 0) select timed out or error (ret 0) select timed out or error (ret 0) select timed out or error (ret 0) But if I turn off X (still KMS though): [root@hugin vbltest]# ./vbltest trying to load module i915...failed. trying to load module radeon...success. starting count: 13289 freq: 60.27Hz freq: 60.02Hz freq: 60.02Hz freq: 60.02Hz freq: 60.02Hz However! This works with X running: [root@hugin vbltest]# ./vbltest -s trying to load module i915...failed. trying to load module radeon...success. starting count: 9081 freq: 60.85Hz freq: 60.02Hz freq: 60.02Hz freq: 60.02Hz Could there be some confusion about pipes here? On Wed, 7 Jul 2010 12:04:55 -0700 (PDT) bugzilla-daemon@freedesktop.org wrote: > https://bugs.freedesktop.org/show_bug.cgi?id=28410 > > --- Comment #25 from Pierre Ossman <pierre-bugzilla@ossman.eu> 2010-07-07 12:04:55 PDT --- > However! This works with X running: > > [root@hugin vbltest]# ./vbltest -s > trying to load module i915...failed. > trying to load module radeon...success. > starting count: 9081 > freq: 60.85Hz > freq: 60.02Hz > freq: 60.02Hz > freq: 60.02Hz > > > > Could there be some confusion about pipes here? Yeah, looks like X uses a different pipe config than fbcon. That would explain the above at least. Now you just need to check the X code to be sure it's getting things right... Noteworthy is also that drm-next is need to get any working condition. Backward compatibility with older kernels seem to be a little lacking here guys. ;) On Wed, 7 Jul 2010 12:17:52 -0700 (PDT) bugzilla-daemon@freedesktop.org wrote: > https://bugs.freedesktop.org/show_bug.cgi?id=28410 > > --- Comment #27 from Pierre Ossman <pierre-bugzilla@ossman.eu> 2010-07-07 12:17:52 PDT --- > Noteworthy is also that drm-next is need to get any working condition. Backward > compatibility with older kernels seem to be a little lacking here guys. ;) DRI2 didn't support any of the vsync related extensions until both the kernel vblank event support landed and support for the new DRI2 protocol bits landed in the X server and DDX drivers. So compat with older kernels (i.e. kernels w/o vblank event support) isn't really possible. Bingo! Xorg thinks it is using the primary pipe, but is actually using the secondary pipe. Doing some ugly hacks makes omlsync work. Haven't tested xbmc yet. So where should the problem be? Where does Xorg associate pipes with CRTCs? (In reply to comment #28) > > DRI2 didn't support any of the vsync related extensions until both the > kernel vblank event support landed and support for the new DRI2 > protocol bits landed in the X server and DDX drivers. So compat with > older kernels (i.e. kernels w/o vblank event support) isn't really > possible. But couldn't there be a fallback to whatever mechanism was in place with the initial interrupt support? OpenGL vsync was fine with Xorg 1.7.x and Fedora's 2.6.32 kernel. Although I appreciate the lack of manpower, this whole business of having very narrow compatibility windows between the different graphics components makes testing very difficult. :/ On Wed, 7 Jul 2010 12:38:09 -0700 (PDT) bugzilla-daemon@freedesktop.org wrote: > https://bugs.freedesktop.org/show_bug.cgi?id=28410 > > --- Comment #30 from Pierre Ossman <pierre-bugzilla@ossman.eu> 2010-07-07 12:38:09 PDT --- > (In reply to comment #28) > > > > DRI2 didn't support any of the vsync related extensions until both the > > kernel vblank event support landed and support for the new DRI2 > > protocol bits landed in the X server and DDX drivers. So compat with > > older kernels (i.e. kernels w/o vblank event support) isn't really > > possible. > > But couldn't there be a fallback to whatever mechanism was in place with the > initial interrupt support? OpenGL vsync was fine with Xorg 1.7.x and Fedora's > 2.6.32 kernel. Ah yeah there were some bits that worked sometimes, but they didn't have any knowledge of pipe configuration, so they'd only work in certain configs. There's no easy way to fall back to that... > Although I appreciate the lack of manpower, this whole business of having very > narrow compatibility windows between the different graphics components makes > testing very difficult. :/ Yes, it is a pain. Things have slowed down a lot recently though; it's much better than when we were first developing TTM, GEM and KMS at least. :) As for the pipe config error you found, I think that's probably a DDX driver bug. If the DDX doesn't pass the right flags to drm_wait_vblank you'll see timeouts, so maybe the DDX isn't detecting which pipe to wait on properly? Seems like I had an old xorg.conf still around. Removing it seems to clear things up.
This is the conf:
# Xorg configuration created by pyxf86config
Section "ServerLayout"
Identifier "Default Layout"
Screen 0 "Screen0" 0 0
EndSection
Section "ServerFlags"
Option "AutoAddDevices" "false"
EndSection
Section "Extensions"
# Option "Composite" "Disable"
EndSection
Section "Device"
Identifier "ATI"
Driver "radeon"
# BusID "PCI:1:5:0"
Option "AccelMethod" "EXA"
Option "DRI" "on"
# Option "EXAVSync" "off"
# Option "DMAForXv" "on"
# Option "noint10" "true"
EndSection
Section "Monitor"
Identifier "DVI-0"
Option "Enable" "yes"
ModeLine "HDTV" 71.2 1360 1424 1536 1792 768 771 777 795
Option "PreferredMode" "HDTV"
EndSection
Section "Screen"
Identifier "Screen0"
Device "ATI"
DefaultDepth 24
SubSection "Display"
Viewport 0 0
Depth 24
# Virtual 2720 768
EndSubSection
EndSection
DVI-0 was unused, and therefore probably forced on here. Not really something I wanted or needed, but it still shouldn't cause problems like this.
Created attachment 36844 [details] [review] return the proper crtc_id Return the crtc_id, not the counter value. They are not necessarily the same. Patch did not fix the issue, I'm afraid. Removed xorg.conf and tested xbmc. It is now frame rate limited to 60 Hz, but there is some bad buffer handling that causes quite a bit of flickering. Might be bug 28341. > --- Comment #28 from Jesse Barnes <jbarnes@virtuousgeek.org> 2010-07-07 12:22:31 PDT ---
> DRI2 didn't support any of the vsync related extensions until both the
> kernel vblank event support landed and support for the new DRI2
> protocol bits landed in the X server and DDX drivers. So compat with
> older kernels (i.e. kernels w/o vblank event support) isn't really
> possible.
>
it's not possible to only advertise support for those vsync related
extensions if the support is actually there?
On Wed, 7 Jul 2010 13:34:59 -0700 (PDT) bugzilla-daemon@freedesktop.org wrote: > https://bugs.freedesktop.org/show_bug.cgi?id=28410 > > --- Comment #36 from Julien Cristau <jcristau@debian.org> 2010-07-07 13:34:59 PDT --- > > --- Comment #28 from Jesse Barnes <jbarnes@virtuousgeek.org> 2010-07-07 12:22:31 PDT --- > > DRI2 didn't support any of the vsync related extensions until both the > > kernel vblank event support landed and support for the new DRI2 > > protocol bits landed in the X server and DDX drivers. So compat with > > older kernels (i.e. kernels w/o vblank event support) isn't really > > possible. > > > it's not possible to only advertise support for those vsync related > extensions if the support is actually there? Yeah, we try to. If the DDX doesn't support the interfaces, the X server won't list them in the GLX server extensions string. Tried the ugly hack from Dänzer, but it didn't fix the flickering with xbmc unfortunately. Also tried adding a call to glXWaitForSbcOML() as suggested in bug 28341, but no luck with that either. :/ Hacking xbmc to use plain ol' glXSwapBuffers() makes everything work properly though, so it would seem like it's only the OML_sync_control extension that's broken. Does reverting xf86-video-ati Git commit 30591320ec46e491ba20904cc64f3405b51c6505 ('kms: add support for the MSC swap & sync API') fix this problem?
Created attachment 37036 [details] [review] Revert xf86-video-ati commit 30591320ec46e491ba20904cc64f3405b51c6505 Here's a patch against current xf86-video-ati Git master with the conflicts resolved. No noticeable effect. Flickering is still there. Didn't brake the frame rate limiting though, so it's not worse either... Installed the final patch from bug 28341 and it solved the flickering issue. So now OpenGL vsync seems to be back to a fully working state. What do you want to do with this bug? There is still a remaining issue of vsync breaking if you have a disconnected output that's forced on. It doesn't affect me anymore, but it's still a bug. Can you elaborate on the bug when one output is forced on ? What exactly is the bug ? Hmm... I guess we had that discussion on irc. Anyway, the problem seemed to boil down to: CRTC 0 is forced on (via xorg.conf) and disconnected CRTC 1 is on and connected Somehow this caused confusion between userspace and the kernel as to which CRTC is which. This caused vblank events to not be delivered as userspace asked for CRTC 1 but the kernel only considered CRTC 0 to be running. Alex Deucher guessed that some parts of the kernel might be looking at connect state instead of on/off. Didn't really investigate further as I had no need to force an output on so my immediate problem was solved. Mass closure: This bug has been untouched for more than six years, and is not obviously still valid. Please reopen this bug or file a new report if you continue to experience issues with current releases. |
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.