[mythtv-users] [CVS: Jul 23/24] Jump Ahead causes video freeze -- new vsync code?

Wed Aug 18 19:15:42 EDT 2004

When using the 23Jul04 CVS version of myth, I can Jump around in a show 
and it works just fine.

As of the 24Jul04 CVS version of myth, Jumping around in a show will 
frequently cause the video to freeze.  When this happens the output of 
mythfrontend -v playback shows:

2004-08-18 16:56:21 mythfrontend version: 0.15.20040528-1 www.mythtv.org
2004-08-18 16:56:21 Enabled verbose msgs : important general playback
2004-08-18 16:56:21 switchToGUI: Switched to 888 x 500
2004-08-18 16:56:21 Registering Internal as a media playback plugin.
Failed to run 'cdrecord --scanbus'
2004-08-18 16:56:22 Registering MythMusic Media Handler as a media handler
Error loading image file: /usr/local/share/mythtv/themes/default/camera.png
Error loading image file: 
/usr/local/share/mythtv/themes/default/search_l.png
2004-08-18 16:56:26 Default
2004-08-18 16:56:27 Connecting to backend server: 192.168.2.50:6543 (try 
1 of 5)
2004-08-18 16:56:27 Using protocol version 12
2004-08-18 16:56:27 Using protocol version 12
Program added to channel 1004 - 104 KOBDT (KOB-DT) at 2004/08/18 17:00 
to 19:00
2004-08-18 16:57:49 Default
2004-08-18 16:58:41 detectInterlace(Detect Scan, Detect Scan, 29.97, 
1088) ->Interlaced Scan
2004-08-18 16:58:41 Interlaced: Interlaced Scan  video_height: 1088  
fps: 29.97
2004-08-18 16:58:41 Estimated bitrate = 384000
2004-08-18 16:58:42 detectInterlace(Ignore Scan, Interlaced Scan, 29.97, 
1088) ->Interlaced Scan
2004-08-18 16:58:42 Interlaced: Interlaced Scan  video_height: 1088  fps: -1
2004-08-18 16:58:42 Position map found
2004-08-18 16:58:42 Opening ALSA audio device 'iec958'.
2004-08-18 16:58:42 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 16:58:42 Over/underscan. V: -0.03, H: 0, XOff: 0, YOff: 0
2004-08-18 16:58:43 switchToVid: Video size 1920 x 1088: Switched to 
resolution
1920 x 1080 403mm x 227mm
2004-08-18 16:58:43 Using XV port 145
2004-08-18 16:58:43 Image size. dispxoff 0, dispyoff: 33, dispwoff: 
1920, disphoff: 1013
2004-08-18 16:58:43 Image size. imgx 0, imgy: 0, imgw: 1920, imgh: 1080
2004-08-18 16:58:44 Not in the running state, state=2
2004-08-18 16:58:44 Not in the running state, state=2
2004-08-18 16:58:44 Not in the running state, state=2
2004-08-18 16:58:44 Not in the running state, state=2
2004-08-18 16:58:44 Not in the running state, state=2
2004-08-18 16:58:44 Changing from None to WatchingPreRecorded
2004-08-18 16:58:44 nVidiaVideoSync: VBlank ioctl did not work, 
unimplemented in this driver?
2004-08-18 16:58:44 DRMVideoSync: Could not open device /dev/dri/card0, 
No such device or address
2004-08-18 16:58:44 Using audio as timebase
2004-08-18 16:58:44 Video timing method: SGI OpenGL
2004-08-18 16:58:44 Refresh rate: 33366, frame interval: 33366
2004-08-18 16:58:44 waiting for prebuffer...
2004-08-18 16:58:44 prebuffer wait timed out..
2004-08-18 16:58:44 waiting for prebuffer...
2004-08-18 16:58:45 prebuffer wait timed out..
2004-08-18 16:58:45 waiting for prebuffer...
2004-08-18 16:58:48 waiting for prebuffer...
2004-08-18 16:58:48 prebuffer wait timed out..
2004-08-18 16:58:48 waiting for prebuffer...
'video_output' mean = '46115.48', std. dev. = '50414.89', fps = '21.68'
avsync_delay: 527, avsync_avg: 530, warpfactor: 0.9, warpfactor_avg: 
0.00504102
2004-08-18 16:58:50 waiting for prebuffer...
2004-08-18 16:58:50 prebuffer wait timed out..
2004-08-18 16:58:50 waiting for prebuffer...
2004-08-18 16:58:50 A/V diverged by 15178.6 frames, extending frame to 
keep audio in sync
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
2004-08-18 16:59:16 A/V diverged by 11389.5 frames, extending frame to 
keep audio in sync
2004-08-18 16:59:16 snd_pcm_mmap_writei(iec958,frames=1024) error Broken 
pipe
2004-08-18 16:59:16 Opening ALSA audio device 'iec958'.
2004-08-18 16:59:16 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 16:59:17 Waited too long for video out to pause
2004-08-18 16:59:18 Waited too long for video out to pause
2004-08-18 16:59:19 Waited too long for video out to pause
2004-08-18 16:59:20 Waited too long for video out to pause
2004-08-18 16:59:21 Waited too long for video out to pause
2004-08-18 16:59:22 Waited too long for video out to pause
2004-08-18 16:59:23 Waited too long for video out to pause
2004-08-18 16:59:24 Waited too long for video out to pause
2004-08-18 16:59:25 Waited too long for video out to pause
2004-08-18 16:59:26 Waited too long for video out to pause
2004-08-18 16:59:27 Waited too long for video out to pause
2004-08-18 16:59:28 Waited too long for video out to pause
2004-08-18 16:59:29 Waited too long for video out to pause
2004-08-18 16:59:30 Waited too long for video out to pause
2004-08-18 16:59:31 Waited too long for video out to pause
2004-08-18 16:59:32 Waited too long for video out to pause
2004-08-18 16:59:33 Waited too long for video out to pause
2004-08-18 16:59:34 Waited too long for video out to pause
2004-08-18 16:59:35 A/V diverged by 8536.36 frames, extending frame to 
keep audio in sync
2004-08-18 16:59:35 Not in the running state, state=2
2004-08-18 16:59:35 Not in the running state, state=2
2004-08-18 16:59:35 Not in the running state, state=2
2004-08-18 16:59:35 Not in the running state, state=2
2004-08-18 16:59:35 Not in the running state, state=2
2004-08-18 16:59:35 waiting for prebuffer...
2004-08-18 16:59:35 prebuffer wait timed out..
2004-08-18 16:59:35 waiting for prebuffer...
2004-08-18 16:59:35 prebuffer wait timed out..
2004-08-18 16:59:35 waiting for prebuffer...
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
waiting for free video buffers timed out
2004-08-18 16:59:49 snd_pcm_mmap_writei(iec958,frames=1024) error Broken 
pipe
2004-08-18 16:59:49 Opening ALSA audio device 'iec958'.
2004-08-18 16:59:49 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 16:59:49 Opening ALSA audio device 'iec958'.
ALSA lib pcm_hw.c:1155:(snd_pcm_hw_open) open /dev/snd/pcmC0D3p failed: 
No such device
2004-08-18 16:59:49 snd_pcm_open(iec958) error No such device
2004-08-18 16:59:49 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
.
.
.
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 snd_pcm_mmap_writei(iec958,frames=1024) error Broken 
pipe
2004-08-18 16:59:50 Opening ALSA audio device 'iec958'.
2004-08-18 16:59:50 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:50 Not in the running state, state=2
.
.
.
2004-08-18 16:59:50 Not in the running state, state=2
2004-08-18 16:59:51 prebuffering pause
2004-08-18 16:59:51 waiting for prebuffer...
2004-08-18 16:59:51 prebuffer wait timed out..
2004-08-18 16:59:51 waiting for prebuffer...
'video_output' mean = '625806.40', std. dev. = '3453409.21', fps = '1.60'
avsync_delay: 3, avsync_avg: 10, warpfactor: 0.9, warpfactor_avg: 0.0100043
'video_output' mean = '33231.63', std. dev. = '211.76', fps = '30.09'
avsync_delay: 31, avsync_avg: 25, warpfactor: 0.9, warpfactor_avg: 0.0149401
'video_output' mean = '33247.98', std. dev. = '698.24', fps = '30.08'
avsync_delay: 41, avsync_avg: 37, warpfactor: 0.9, warpfactor_avg: 0.0198485
'video_output' mean = '33548.63', std. dev. = '3984.39', fps = '29.81'
avsync_delay: 8, avsync_avg: 15, warpfactor: 0.9, warpfactor_avg: 0.0247297
'video_output' mean = '33576.89', std. dev. = '6895.70', fps = '29.78'
avsync_delay: 59, avsync_avg: 29, warpfactor: 0.9, warpfactor_avg: 0.0295838
'video_output' mean = '33221.22', std. dev. = '3721.05', fps = '30.10'
avsync_delay: 3, avsync_avg: 8, warpfactor: 0.9, warpfactor_avg: 0.0344109
'video_output' mean = '33230.21', std. dev. = '780.73', fps = '30.09'
avsync_delay: 34, avsync_avg: 26, warpfactor: 0.9, warpfactor_avg: 0.0392113
'video_output' mean = '33232.37', std. dev. = '334.14', fps = '30.09'
avsync_delay: 43, avsync_avg: 36, warpfactor: 0.9, warpfactor_avg: 0.0439851
'video_output' mean = '33563.76', std. dev. = '3355.23', fps = '29.79'
avsync_delay: 7, avsync_avg: 40, warpfactor: 0.9, warpfactor_avg: 0.0487324
2004-08-18 17:00:20 snd_pcm_mmap_writei(iec958,frames=1024) error Broken 
pipe
2004-08-18 17:00:20 Opening ALSA audio device 'iec958'.
2004-08-18 17:00:20 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 17:00:20 Not in the running state, state=2
2004-08-18 17:00:20 Not in the running state, state=2
.
.
.
2004-08-18 17:00:20 Not in the running state, state=2
2004-08-18 17:00:21 Not in the running state, state=2
2004-08-18 17:00:21 snd_pcm_mmap_writei(iec958,frames=1024) error Broken 
pipe
2004-08-18 17:00:21 Opening ALSA audio device 'iec958'.
2004-08-18 17:00:21 Audio: fragment_size=4096, bytes_per_sample=4
2004-08-18 17:00:21 Not in the running state, state=2
2004-08-18 17:00:21 Not in the running state, state=2
.
.
.
2004-08-18 17:00:21 Not in the running state, state=2
2004-08-18 17:00:21 Not in the running state, state=2
ate, state=2
2004-08-18 17:00:21 Not in the running state, state=2
'video_output' mean = '27000.82', std. dev. = '11093.23', fps = '37.04'
avsync_delay: 6, avsync_avg: -42, warpfactor: 0.9, warpfactor_avg: 0.0534534
'video_output' mean = '32489.71', std. dev. = '17669.71', fps = '30.78'
avsync_delay: 35, avsync_avg: 32, warpfactor: 0.9, warpfactor_avg: 0.0581482
'video_output' mean = '33232.42', std. dev. = '15251.25', fps = '30.09'
avsync_delay: -20, avsync_avg: 0, warpfactor: 0.9, warpfactor_avg: 0.062817
'video_output' mean = '33893.31', std. dev. = '15635.54', fps = '29.50'
avsync_delay: 32, avsync_avg: 34, warpfactor: 0.9, warpfactor_avg: 0.0674599
2004-08-18 17:00:32 snd_pcm_mmap_writei(iec958,frames=1024) error Broken 
pipe
mythfrontend: pcm.c:870: snd_pcm_state: Assertion `pcm' failed.

What is interesting, is that if I just leave it alone (not press any 
keys), after about 50 seconds the video will start playing again.  Then 
after a few seconds of the video playing fine, mythfrontend will 
terminate with an "Aborted" message.

This is with David George's patch to fix ALSA audio drops.  Without his 
fix, I get no audio when the video starts back up.

Trying to capture the BT in gdb, I get:

[New Thread 1364724656 (LWP 17272)]
[New Thread 1373117360 (LWP 17273)]
[New Thread 1381510064 (LWP 17274)]
Couldn't get registers: No such process.

I assume the problem is in NuppleVideoPlayer.  The only 
NuppleVideoPlayer changes to the CVS the night of 23Jul04 have to do 
with the new vsync code.

Doug Larrick, can you successfully Jump around in a show (NBC HD 
Olympics for example) without the video freezing up occasionally?

Thanks,

John