[mythtv-users] VDPAU HD-PVR Prebuffering Pause 0.23

[Bobby Schwartz]

I'm having a problem with audio stuttering in 0.23 (Minimyth 73b10.)
This problem is new since I upgraded to 0.23 (from 0.22.)  The stutter
is only audio, video playback seems normal and smooth.  This only
affects my HD-PVR recordings.  I've spent a few nights searching list
posts and my logs for clues and I've come to the end of my rope.  I
really could use some help.  The recordings play well in Windows VLC.

I recently upgraded my whole MythTV setup (backend and two frontends) to
0.23.  The backend is running Mythbuntu 10.04.

Logs are below.  This was recorded with verbose logging.  This block
repeats about every second.  Without verbose logging the frontend logs
only prebuffering pauses.

I've read a lot about prebuffering pauses (including the troubleshooting
wiki page.)  The backend, both frontends, and MySQL server are all on
the same gigabit switch.  The backend is a Core 2 Duo E8200 running
64-bit with 4 SATA drives (formatted with JFS) available for recording.
The SQL server is a Core 2 Duo E6850.  The frontends are clones.  Both
are Zotac Atom/ION boards connected to an HDMI flat-panel.  I'm not
using surround sound.  Audio goes to the TV via HDMI.    I normally use
the temporal 1x deinterlacer, but the problem remains when I switch to
others.  Aside from the HD-PVR I also have 2 PVR-150s and an HD Homerun.
All of those devices work well and playback is flawless.  Overall,
during playback, all the machines' CPUs are idle.  I've done some
testing with extra cooling and the issue doesn't seem to be thermal.

23:45:23.430 VidOutVDPAU: Frame B is in use by avlib and so is being
held for later discarding.
23:45:23.430 AO: Pause 1
23:45:23.430 NVP(1): Waiting for prebuffer..  0 AdAAALAAADAAAALDD
23:45:23.431 AO: OutputAudioLoop: audio paused
23:45:23.431 AO: 54796 bytes free on soundcard
23:45:23.434 AO: 55368 bytes free on soundcard
23:45:23.438 AO: 56008 bytes free on soundcard
23:45:23.441 AO: 56648 bytes free on soundcard
23:45:23.444 AO: 57288 bytes free on soundcard
23:45:23.448 AO: 57932 bytes free on soundcard
23:45:23.448 MythSocket(2839bc0:52): write -> 52 50
QUERY_FILETRANSFER 48[]:[]REQUEST_BLOCK[]:[]327680
23:45:23.448 MythSocket(2839bc0:52): writeBlock(0x140500818876872, 58)
23:45:23.449 MythSocket(25de820:53): readBlock(0x46381568, 327680)
called
23:45:23.449 MythSocket(25de820:53): readBlock(0x46423560, 285688)
called
23:45:23.450 MythSocket(25de820:53): readBlock(0x46488720, 220528)
called
23:45:23.450 MythSocket(25de820:53): readBlock(0x46549536, 159712)
called
23:45:23.451 MythSocket(25de820:53): readBlock(0x46659584, 49664) called
23:45:23.452 AO: 58740 bytes free on soundcard
23:45:23.452 MythSocket(2839bc0:52): readBlock(0x140500872566520, 8)
called
23:45:23.453 MythSocket(2839bc0:52): readBlock(0x140501132829192, 6)
called
23:45:23.453 MythSocket(2839bc0:52): read  <- 52 6       327680
23:45:23.453 Got data on select
23:45:23.453 Processing ready reads
23:45:23.453 MythSocketThread: Total read time: 0ms, on sockets
23:45:23.454 Reacquired ready read lock
23:45:23.454 ProcessAddRemoveQueues
23:45:23.454 Construct FD_SET
23:45:23.454 Waiting on select..
23:45:23.454 Read(): reqd=327680, rcvd=327680, rept=327680, error=0
23:45:23.458 AO: 59860 bytes free on soundcard
23:45:23.458 WriteAudio: Preparing 6144 bytes (1536 frames)
23:45:23.461 AO: 54340 bytes free on soundcard
23:45:23.464 AO: 54984 bytes free on soundcard
23:45:23.468 AO: 55636 bytes free on soundcard
23:45:23.468 AFD: video timecode 19787066 19775054 219722 219689
23:45:23.469 AFD: audio timecode 19782994 19782994 219811 219843
23:45:23.469 AO: _AddSamples samples=1536 bytes=6144, used=1,
free=1535999, timecode=219811 needsupmix 0
23:45:23.469 AO: Pause 0
23:45:23.469 NVP(1): A/V Divergence: -1.25496, Rate: -0.221033,
Warpfactor: 0.988954, warpfactor_avg: 0.997282
23:45:23.471 AO: OutputAudioLoop: Play Event
23:45:23.471 SetAudiotime set=1276832723.471831, audt=219764 atc=219843
tb=15324 sb=9180 eds=4800000 abps=4 sf=1
23:45:23.472 GetAudiotime now=1276832723.472092, set=1276832723.471831,
ret=0, audt=219764 sf=1
23:45:23.472 AO: Broadcasting free space avail
23:45:23.472 WriteAudio: Preparing 6144 bytes (1536 frames)
23:45:23.472 SetAudiotime set=1276832723.472680, audt=219765 atc=219843
tb=15160 sb=15160 eds=4800000 abps=4 sf=1
23:45:23.474 AVSync waitforframe 0 0
23:45:23.475 AVSync show
23:45:23.475 GetAudiotime now=1276832723.475655, set=1276832723.472680,
ret=2, audt=219765 sf=1
23:45:23.476 NVP(1): prebuffering pause