[mythtv-users] OpenGL vsync broken on Xorg 7.1 or latest nVidia driver?

[John P Poet]

On 11/14/06, Doug Larrick <doug at parkercat.org> wrote:
> John P Poet wrote:
> > Well... I reinstalled FC5 on my frontend, along side FC6.  On both FC5
> > and FC6 I am running a 2.6.18 kernel, and the latest nVidia binary
> > driver.
> >
> > With OpenGL vsync turned on, horizontal tickers are smooth on FC5, but
> > jumpy on FC6.
> >
> > I don't know what to make of this.  It could be an Xorg 7 issue, but I
> > guess other distributions with Xorg 7 do not have this problem.
>
> You might try enabling the commented-out debug prints in CalcDelay (in
> vsync.cpp) -- this would tell you if you're waiting an inappropriate
> amount of time in vsync (which would indicate an X/driver bug) or if
> you're arriving too late to do anything about it (which would indicate a
> scheduling/load-related issue).  Is it using realtime scheduling for
> video out -- are you sure you've got pam_limits set up properly on the
> FC6 system?
>
> -Doug

Hi Dough.  I know it has been a long time since I worked on this, but
I decided to give it a go, again.

I tried compiling with those debug statements active, but get:

vsync.cpp: In member function 'int VideoSync::CalcDelay()':
vsync.cpp:186: error: 'timeval_str' was not declared in this scope

I assume the timeval_str macro has been removed from the current
trunk?  Any idea how it was defined?

I am really confused about what the problem is.  Even playing back an
SD show, stutters.  For example the ticker on CNN has a very steady
stutter to it.  Under FC5 it did not.

Probably not much use with out the extra debugging you wanted, but
this is what I get with -v playback:

2007-02-13 18:51:35.756 TV: Attempting to change from None to WatchingRecording
2007-02-13 18:51:35.757
RingBuf(myth://192.168.2.50:6543/2033_20070213185100.mpg):
OpenFile(myth://192.168.2.50:6543/2033_20070213185100.mpg, 12)
2007-02-13 18:51:35.768
RingBuf(myth://192.168.2.50:6543/2033_20070213185100.mpg):
CalcReadAheadThresh(1307183840 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-02-13 18:51:35.771 Using protocol version 32
2007-02-13 18:51:35.895 Avg read interval was 197 msec. 64K block size
2007-02-13 18:51:35.922 Avg read interval was 197 msec. 96K block size
[mpeg @ 0xb76096b0]Parser not found for Codec Id: 94210 !
2007-02-13 18:51:35.959 Avg read interval was 198 msec. 128K block size
2007-02-13 18:51:35.999 Avg read interval was 198 msec. 160K block size
2007-02-13 18:51:36.029 Avg read interval was 198 msec. 64K block size
0: start_time: 0.036 duration: 0.132
1: start_time: 2309.993 duration: 0.087
2: start_time: 0.026 duration: 0.119
stream: start_time: 0.289 duration: 25667.264 bitrate=0 kb/s
2007-02-13 18:51:36.045 AFD: Stream #0, has id 0x480 codec id
MPEG2VIDEO, type Video, bitrate 16000000 at 0x0xa7897e30
2007-02-13 18:51:36.045 Avg read interval was 196 msec. 64K block size
2007-02-13 18:51:36.047 detectInterlace(Detect Scan, Interlaced Scan,
29.97, 480) ->Interlaced Scan
2007-02-13 18:51:36.047 AFD: Looking for decoder for MPEG2VIDEO
2007-02-13 18:51:36.047 AFD: Opened codec 0xa75d4210, id(MPEG2VIDEO) type(Video)
2007-02-13 18:51:36.047 AFD: Stream #1, has id 0x105 codec id
MPEG2VBI, type Data, bitrate 0 at 0x0xa75f7f50
2007-02-13 18:51:36.048 AFD: data codec (Data)
2007-02-13 18:51:36.048 AFD: Stream #2, has id 0x448 codec id MP2,
type Audio, bitrate 384000 at 0x0xa7a12130
2007-02-13 18:51:36.048 AFD: Looking for decoder for MP2
2007-02-13 18:51:36.048 AFD: Opened codec 0xa7c99d00, id(MP2) type(Audio)
2007-02-13 18:51:36.048
RingBuf(myth://192.168.2.50:6543/2033_20070213185100.mpg):
CalcReadAheadThresh(3076780456 KB)
			 -> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-02-13 18:51:36.051 Opening ALSA audio device 'ice_spdif'.
2007-02-13 18:51:36.068 Avg read interval was 197 msec. 64K block size
2007-02-13 18:51:36.077 Dec: Trying to select track (w/lang)
2007-02-13 18:51:36.077 Dec: Selecting first track
2007-02-13 18:51:36.077 Dec: Selected track #1 in the Unknown language(0)
2007-02-13 18:51:36.077 Resyncing position map. posmapStarted = 0
livetv(0) watchingRec(1)
2007-02-13 18:51:36.079 Position map filled from DB to: 16
2007-02-13 18:51:36.079 SyncPositionMap watchingrecording, from DB: 16 entries
2007-02-13 18:51:36.080 Filling position map from 17 to 19
2007-02-13 18:51:36.080 Position map filled from Encoder to: 19
2007-02-13 18:51:36.080 SyncPositionMap watchingrecording total: 19 entries
2007-02-13 18:51:36.080 SyncPositionMap, new totframes: 285, new
length: 9, posMap size: 19
2007-02-13 18:51:36.080 AFD: Partial position map found
2007-02-13 18:51:36.080 AFD: Successfully opened decoder for file:
"myth://192.168.2.50:6543/2033_20070213185100.mpg". novideo(0)
2007-02-13 18:51:36.095 Avg read interval was 197 msec. 96K block size
2007-02-13 18:51:36.096 VideoOutputXv: ctor
2007-02-13 18:51:36.097 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
2007-02-13 18:51:36.097 Display Rect  left: 0, top: 0, width: 1920,
height: 1080, aspect: 1.33333
2007-02-13 18:51:36.097 Video Rect    left: 0, top: 0, width: 720,
height: 480, aspect: 1.33333
2007-02-13 18:51:36.097 VideoOutputXv: Pixel dimensions: Screen
1920x1080, window 1920x1080
2007-02-13 18:51:36.097 VideoOutputXv: Estimated display dimensions:
488x274 mm  Aspect: 1.78102
2007-02-13 18:51:36.097 VideoOutputXv: Estimated window dimensions:
488x274 mm  Aspect: 1.78102
2007-02-13 18:51:36.098 VideoOutputXv: XvMCTex: Init failed
2007-02-13 18:51:36.106 VideoOutputXv: @ j=3 Looking for flag[s]:
XvInputMask XvImageMask
2007-02-13 18:51:36.106 VideoOutputXv: Adaptor#0: NV17 Video Texture
has flag[s]: XvInputMask XvImageMask
2007-02-13 18:51:36.106 VideoOutputXv: Grabbed xv port 245
2007-02-13 18:51:36.106 VideoOutputXv: XVideo surface found on port 245
2007-02-13 18:51:36.106 VideoOutputXv: XVideo Adaptor Name: 'NV17 Video Texture'
2007-02-13 18:51:36.106 VideoOutputXv: XVideo Format #0 is 'YUY2'
2007-02-13 18:51:36.106 VideoOutputXv: XVideo Format #1 is 'YV12'
2007-02-13 18:51:36.106 VideoOutputXv: XVideo Format #2 is 'UYVY'
2007-02-13 18:51:36.106 VideoOutputXv: XVideo Format #3 is 'I420'
2007-02-13 18:51:36.107 VideoOutputXv: Using XVideo Format 'I420'
2007-02-13 18:51:36.107 VideoOutputXv: CreateShmImages(32): video_dim: 720x480
2007-02-13 18:51:36.122 Avg read interval was 197 msec. 128K block size
X Error: BadMatch (invalid parameter attributes) 8
  Major opcode:  141
  Minor opcode:  14
  Resource id:  0x135
2007-02-13 18:51:36.145 VideoOutputXv: Chromakeying not possible with
this XVideo port.
2007-02-13 18:51:36.145 Display Rect  left: 240, top: 0, width: 1440,
height: 1080, aspect: 1.77778
2007-02-13 18:51:36.145 Video Rect    left: 0, top: 0, width: 720,
height: 480, aspect: 1.33333
2007-02-13 18:51:36.158 Avg read interval was 197 msec. 160K block size
2007-02-13 18:51:36.195 Avg read interval was 198 msec. 192K block size
2007-02-13 18:51:36.235 Avg read interval was 198 msec. 224K block size
2007-02-13 18:51:37.309 NVP: ClearAfterSeek(1)
2007-02-13 18:51:37.309 VideoOutputXv: ClearAfterSeek()
2007-02-13 18:51:37.309 VideoOutputXv: DiscardFrames(0)
2007-02-13 18:51:37.309 VideoBuffers::DiscardFrames(0):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-02-13 18:51:37.309 VideoBuffers::DiscardFrames(0):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-02-13 18:51:37.310 VideoOutputXv: DiscardFrames() 3:
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-02-13 18:51:37.311 Using realtime priority.
2007-02-13 18:51:37.312 TV: StartPlayer(): took 1430 ms to start player.
2007-02-13 18:51:37.313 Using deinterlace method kerneldeint
2007-02-13 18:51:37.314 TV: Changing from None to WatchingRecording
2007-02-13 18:51:37.373 AFD: HandleGopStart: gopset not set, syncing positionMap
2007-02-13 18:51:37.373 Resyncing position map. posmapStarted = 1
livetv(0) watchingRec(1)
2007-02-13 18:51:37.374 Filling position map from 20 to 21
2007-02-13 18:51:37.374 Position map filled from Encoder to: 21
2007-02-13 18:51:37.374 SyncPositionMap watchingrecording total: 21 entries
2007-02-13 18:51:37.374 SyncPositionMap, new totframes: 315, new
length: 10, posMap size: 21
2007-02-13 18:51:37.374 AFD: HandleGopStart: Initial key frame distance: 15.
2007-02-13 18:51:37.415 nVidiaVideoSync: VBlank ioctl did not work,
unimplemented in this driver?
2007-02-13 18:51:37.415 DRMVideoSync: Could not open device
/dev/dri/card0, No such file or directory
2007-02-13 18:51:37.416 OpenGLVideoSync: GLX extensions:
GLX_EXT_visual_info GLX_EXT_visual_rating GLX_SGIX_fbconfig
GLX_SGIX_pbuffer GLX_SGI_video_sync GLX_SGI_swap_control
GLX_EXT_texture_from_pixmap GLX_ARB_multisample GLX_NV_float_buffer
GLX_ARB_get_proc_address
2007-02-13 18:51:37.417 OpenGLVideoSync: x,y -> 959, 539
2007-02-13 18:51:37.437 Using OpenGLVideoSync
2007-02-13 18:51:37.440 Using audio as timebase
2007-02-13 18:51:37.440 Video timing method: SGI OpenGL
2007-02-13 18:51:37.441 Refresh rate: 16683, frame interval: 33366
'video_output' mean = '34177.22', std. dev. = '13995.83', fps = '29.26'
'video_output' mean = '33092.79', std. dev. = '13802.16', fps = '30.22'
'video_output' mean = '33357.45', std. dev. = '13720.86', fps = '29.98'
2007-02-13 18:51:50.748 NVP: 400 interlaced frames seen.
'video_output' mean = '33392.33', std. dev. = '13754.99', fps = '29.95'
'video_output' mean = '33093.33', std. dev. = '13723.55', fps = '30.22'
'video_output' mean = '33357.47', std. dev. = '13912.35', fps = '29.98'
'video_output' mean = '33392.09', std. dev. = '13755.41', fps = '29.95'
2007-02-13 18:52:04.042 NVP: 800 interlaced frames seen.
'video_output' mean = '33093.48', std. dev. = '13711.76', fps = '30.22'
'video_output' mean = '33356.80', std. dev. = '13789.57', fps = '29.98'
'video_output' mean = '33392.41', std. dev. = '13848.45', fps = '29.95'
'video_output' mean = '33093.02', std. dev. = '13861.88', fps = '30.22'
2007-02-13 18:52:17.363 NVP: 1200 interlaced frames seen.
'video_output' mean = '33357.67', std. dev. = '13721.89', fps = '29.98'
'video_output' mean = '33392.45', std. dev. = '13763.69', fps = '29.95'
'video_output' mean = '33092.69', std. dev. = '13784.91', fps = '30.22'
'video_output' mean = '33357.45', std. dev. = '13717.77', fps = '29.98'
2007-02-13 18:52:30.687 NVP: 1600 interlaced frames seen.
'video_output' mean = '33392.20', std. dev. = '13831.52', fps = '29.95'
'video_output' mean = '33093.02', std. dev. = '13786.65', fps = '30.22'
'video_output' mean = '33395.08', std. dev. = '13810.62', fps = '29.94'
'video_output' mean = '33020.84', std. dev. = '13624.20', fps = '30.28'
2007-02-13 18:52:44.011 NVP: 2000 interlaced frames seen.
'video_output' mean = '33392.44', std. dev. = '13594.99', fps = '29.95'
'video_output' mean = '33429.83', std. dev. = '13550.02', fps = '29.91'
'video_output' mean = '33058.25', std. dev. = '13671.92', fps = '30.25'
'video_output' mean = '33392.27', std. dev. = '13672.06', fps = '29.95'
2007-02-13 18:52:57.302 NVP: 2400 interlaced frames seen.
'video_output' mean = '33354.43', std. dev. = '13550.18', fps = '29.98'
'video_output' mean = '33095.99', std. dev. = '13713.06', fps = '30.22'
'video_output' mean = '33392.32', std. dev. = '13589.42', fps = '29.95'
'video_output' mean = '33354.77', std. dev. = '13629.05', fps = '29.98'
2007-02-13 18:53:10.626 NVP: 2800 interlaced frames seen.
'video_output' mean = '33392.00', std. dev. = '13595.54', fps = '29.95'
'video_output' mean = '33095.74', std. dev. = '13555.16', fps = '30.22'
'video_output' mean = '33354.64', std. dev. = '13546.06', fps = '29.98'
'video_output' mean = '33096.11', std. dev. = '13550.64', fps = '30.22'
2007-02-13 18:53:23.920 NVP: 3200 interlaced frames seen.
'video_output' mean = '33391.94', std. dev. = '13521.14', fps = '29.95'
'video_output' mean = '33355.24', std. dev. = '13541.73', fps = '29.98'


John