[mythtv] LiveTV Shuttering & Squeaky Audio

[Paul McEnery]

I ran this message for the last couple of days on the mythtv-users
list, but think it goes a
little beyond the scope of normal usage and troubleshooting.

I am running mythtv-trunk r12637 (not particularly relevant) with a
DVB-C card (TT C2300). I
am able to successfully lock onto all channels found during a scan, and 95% of
the channels work correctly. About a dozen channels (out of about 150)
are shuttering and the audio is squeaky.

I installed mplayer to see if this behaviour is consistent. mplayer
is able to play the stream, but eventually freezes (after a couple of
minutes and recommends
running it with the -cache 8192 flag. I have just read about and
enabled the "aggressive
audio buffering" option in mythtv-setup, but this makes no difference.

I have tried recording the channels, and then playing them back, but
MythTV plays the channel with the same shuttering and squeaky audio. I
am not sure where to look next.
I find it odd that other channels on the same multiplex work
perfectly. Any advice would be much appreciated, as I don't know where
to turn.

P.S. I have tried with and without --enable-proc-opt

Compile flags:

--enable-dvb --enable-lirc --enable-xvmc --enable-proc-opt


Hardware:
--------------
P4 2.6HT
1G Memory
Abit IC7 ( http://www.abit-usa.com/products/mb/techspec.php?categories=1&model=5
)
Nvidia Fx5600 (256M)
TT DVB-C C-2300


$ mythfrontend -v most -o mythfrontend.log
==============================
2007-01-26 00:28: 32.033 SG(Default): FindRecordingFile: Found
'/mnt/store/2502_20070126002831
.mpg'
2007-01-26 00:28:32.033 ProgramInfo: GetPlaybackURL: File is local:
'/mnt/store/2502_20070126002831.mpg'
2007-01-26 00:28: 32.033 RingBuf(/mnt/store/2502_20070126002828.mpg):
OpenFile(/mnt/store/2502_20070126002831.mpg, 12)
2007-01-26 00:28:32.035 MythSocket(b481b280:18): socket is readable
2007-01-26 00:28:32.035 MythSocket(b481b280:18): cb->readyRead()
2007-01-26 00:28:32.035 read <- 18 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-01-26 00:28:32.035 MythEvent: RECORDING_LIST_CHANGE
2007-01-26 00:28:32.254 RingBuf(/mnt/store/2502_20070126002831.mpg):
CalcReadAheadThresh(3086681172 KB)
-> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-01-26 00:28:32.287 NVP: Waiting for prebuffer.. 0
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
mpegts_add_stream: at pid 0x15a2 with type 4
mpegts_add_stream: stream #0, has id 0x15a2 and codec MP3, type Audio
at 0xb4860a20
mpegts_add_stream: at pid 0x1502 with type 2
mpegts_add_stream: stream #1, has id 0x1502 and codec MPEG2VIDEO, type
Video at 0xb483c5e0
mpegts_add_stream: at pid 0x15d2 with type 257
mpegts_add_stream: stream #2, has id 0x15d2 and codec DVB_VBI, type
Data at 0xb48460b0
mpegts_add_stream: at pid 0x1522 with type 3
mpegts_add_stream: stream #3, has id 0x1522 and codec MP3, type Audio
at 0xb483e850
2007-01-26 00:28:32.420 AFD: Stream #0, has id 0x5538 codec id MP3,
type Audio, bitrate 128000 at 0x0xb4860a20
2007-01-26 00:28:32.420 AFD: Looking for decoder for MP3
2007-01-26 00:28:32.445 AFD: Opened codec 0xb4860d10, id(MP3) type(Audio)
2007-01-26 00:28:32.445 AFD: Audio Track #1 is A/V stream #0 and has 1
channels in the English language(6647399).
2007-01-26 00:28:32.446 AFD: Stream #1, has id 0x5378 codec id
MPEG2VIDEO, type Video, bitrate 15000000 at 0x0xb483c5e0
2007-01-26 00:28:32.448 VideoOutputXv: InputChanged(528,576,1.33333)
2007-01-26 00:28:32.448 VideoOutputXv: DiscardFrames(1)
2007-01-26 00:28:32.449 VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:32.449 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28:32.449 VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-01-26 00:28:32.449 VideoOutputXv: DiscardFrames() 3:
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28: 32.449 VideoOutputXv: DiscardFrames(1)
2007-01-26 00:28:32.449 VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:32.449 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28:32.449 VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-01-26 00:28:32.450 VideoOutputXv: DiscardFrames() 3:
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28: 32.450 VideoOutputXv: DiscardFrames(1)
2007-01-26 00:28:32.450 VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:32.450 VideoBuffers::DiscardFrames():
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28:32.450 VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-01-26 00:28:32.450 VideoOutputXv: DiscardFrames() 3:
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28: 32.454 VideoOutputXv: Closing XVideo port 244
2007-01-26 00:28:32.461 VideoOutputXv: XvMCTex: Init failed
2007-01-26 00:28:32.461 VideoOutputXv: @ j=3 Looking for flag[s]:
XvInputMask XvImageMask
2007-01-26 00:28: 32.461 VideoOutputXv: Adaptor#0: NV17 Video Overlay
has flag[s]: XvInputMask XvImageMask
2007-01-26 00:28:32.467 VideoOutputXv: Grabbed xv port 244
2007-01-26 00:28:32.467 VideoOutputXv: XVideo surface found on port 244
2007-01-26 00:28:32.467 VideoOutputXv: XVideo Adaptor Name: 'NV17 Video Overlay'
2007-01-26 00:28:32.467 VideoOutputXv: XVideo Format #0 is 'YUY2'
2007-01-26 00:28:32.467 VideoOutputXv: XVideo Format #1 is 'YV12'
2007-01-26 00:28:32.467 VideoOutputXv: XVideo Format #2 is 'UYVY'
2007-01-26 00:28:32.467 VideoOutputXv: XVideo Format #3 is 'I420'
2007-01-26 00:28:32.467 VideoOutputXv: Using XVideo Format 'I420'
2007-01-26 00:28:32.467 VideoOutputXv: CreateShmImages(32): video_dim: 528x576
2007-01-26 00:28:32.497 Display Rect left: 0, top: 0, width: 1280,
height: 1024, aspect: 1.2649
2007-01-26 00:28:32.497 Video Rect left: 0, top: 0, width: 528,
height: 576, aspect: 1.33333
2007-01-26 00:28:32.674 Avg read interval was 194 msec. 64K block size
2007-01-26 00:28:32.737 NVP: ClearAfterSeek(1)
2007-01-26 00:28:32.738 VideoOutputXv: ClearAfterSeek()
2007-01-26 00:28:32.738 VideoOutputXv: DiscardFrames(0)
2007-01-26 00:28:32.738 VideoBuffers::DiscardFrames(0):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:32.738 VideoBuffers::DiscardFrames(0):
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
2007-01-26 00:28:32.738 VideoOutputXv: DiscardFrames() 3:
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
2007-01-26 00:28:32.738 detectInterlace(Detect Scan, Interlaced Scan,
25, 576) ->Interlaced Scan
2007-01-26 00:28:32.739 AFD: Looking for decoder for MPEG2VIDEO
2007-01-26 00:28:32.739 AFD: Opened codec 0xb482f970, id(MPEG2VIDEO)
type(Video)
2007-01-26 00:28:32.739 AFD: Stream #2, has id 0x5586 codec id
DVB_VBI, type Data, bitrate 0 at 0x0xb48460b0
2007-01-26 00:28:32.739 AFD: data codec (Data)
2007-01-26 00:28:32.739 NVP: Waiting for prebuffer.. 1
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:32.758 AFD: Stream #3, has id 0x5410 codec id MP3,
type Audio, bitrate 128000 at 0x0xb483e850
2007-01-26 00:28:32.759 AFD: Looking for decoder for MP3
2007-01-26 00:28:32.759 AFD: Opened codec 0xb4833f20, id(MP3) type(Audio)
2007-01-26 00:28:32.759 AFD: Audio Track #2 is A/V stream #3 and has 1
channels in the English language(6647399).
2007-01-26 00:28:32.759 RingBuf(/mnt/store/2502_20070126002831.mpg):
CalcReadAheadThresh(3053961204 KB)
-> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-01-26 00:28:32.759 AFD: Trying to select audio track (w/lang)
2007-01-26 00:28:32.759 AFD: Selected track 1: English MP2 1ch (A/V Stream #0)
2007-01-26 00:28:32.759 AFD: Initializing audio parms from audio track #1
2007-01-26 00:28:32.759 AFD: Audio format changed
from id(NONE) -1Hz -1ch 0bps ; id(NONE) -1Hz
-1ch 0bps
to id( MP3) 48000Hz 1ch 16bps ; id( MP3) 48000Hz
1ch 16bps
2007-01-26 00:28:32.762 AO: Killing AudioOutputDSP
2007-01-26 00:28:32.762 Opening OSS audio device '/dev/dsp'.
2007-01-26 00:28: 32.767 AO: Audio fragment size: 2048
2007-01-26 00:28:32.767 AO: Audio Stretch Factor: 1
2007-01-26 00:28:32.768 AO: Ending reconfigure
2007-01-26 00:28:32.768 NVP: Enabling Audio
2007-01-26 00:28:32.768 Dec: Trying to select track (w/lang)
2007-01-26 00:28:32.768 Dec: Selecting first track
2007-01-26 00:28:32.768 Dec: Selected track #1 in the Unknown language(0)
2007-01-26 00:28:32.768 Resyncing position map. posmapStarted = 0
livetv(1) watchingRec(0)
2007-01-26 00:28:32.768 AO: kickoffOutputAudioLoop: pid = 11047
2007-01-26 00:28:32.769 Position map filled from DB to: 0
2007-01-26 00:28:32.769 SyncPositionMap watchingrecording, from DB: 1 entries
2007-01-26 00:28: 32.769 write -> 22 39 QUERY_RECORDER
1[]:[]GET_FRAMES_WRITTEN
2007-01-26 00:28:32.769 read <- 22 8 0[]:[]13
2007-01-26 00:28:32.769 AO: OutputAudioLoop: Play Event
2007-01-26 00:28:32.770 Filling position map from 1 to 13
2007-01-26 00:28:32.770 AO: Broadcasting free space avail
2007-01-26 00:28:32.770 write -> 22 51 QUERY_RECORDER
1[]:[]FILL_POSITION_MAP[]:[]1[]:[]13
2007-01-26 00:28:32.770 read <- 22 25 0[]:[]12[]:[]0[]:[]192512
2007-01-26 00:28:32.770 Position map filled from Encoder to: 12
2007-01-26 00:28:32.770 SyncPositionMap watchingrecording total: 2 entries
2007-01-26 00:28:32.770 SyncPositionMap, new totframes: 12, new
length: 0, posMap size: 2
Input #0, mpegts, from '/mnt/store/2502_20070126002831.mpg':
Duration: N/A, bitrate: N/A
Stream #0.0[0x15a2](eng), 1/90000: Audio: mp2, 48000 Hz, mono, 128 kb/s
Stream #0.1[0x1502](eng), 1/90000: Video: mpeg2video, yuv420p,
528x576, 1/25, 15000 kb/s, 25.00 fps(r)
Stream #0.2[0x15d2](eng), 1/90000: Data: 0x0000
Stream #0.3[0x1522](eng), 1/90000: Audio: mp2, 48000 Hz, mono, 128 kb/s
2007-01-26 00:28:32.771 AFD: Partial position map found
2007-01-26 00:28: 32.771 AFD: Successfully opened decoder for file:
"/mnt/store/2502_20070126002831.mpg". novideo(0)
2007-01-26 00:28:32.773 NVP: DoPlay: rate: 25 speed: 1 skip: 1 => new
interval 40000
2007-01-26 00:28: 32.773 Set video sync frame interval to 40000
2007-01-26 00:28:32.773 NVP: Stretch Factor 1, allow passthru
2007-01-26 00:28:32.773 RingBuf(/mnt/store/2502_20070126002831.mpg):
CalcReadAheadThresh(138203504 KB)
-> threshhold(64 KB) min read(0 KB) blk size(32 KB)
2007-01-26 00:28:32.773 Resyncing position map. posmapStarted = 0
livetv(1) watchingRec(1)
2007-01-26 00:28:32.774 Position map filled from DB to: 0
2007-01-26 00:28:32.775 SyncPositionMap watchingrecording, from DB: 1 entries
2007-01-26 00:28:32.775 write -> 22 39 QUERY_RECORDER
1[]:[]GET_FRAMES_WRITTEN
2007-01-26 00:28:32.775 read <- 22 8 0[]:[]13
2007-01-26 00:28:32.775 Filling position map from 1 to 13
2007-01-26 00:28: 32.775 write -> 22 51 QUERY_RECORDER
1[]:[]FILL_POSITION_MAP[]:[]1[]:[]13
2007-01-26 00:28:32.776 read <- 22 25 0[]:[]12[]:[]0[]:[]192512
2007-01-26 00:28:32.776 Position map filled from Encoder to: 12
2007-01-26 00:28:32.776 SyncPositionMap watchingrecording total: 2 entries
2007-01-26 00:28:32.784 AO: Broadcasting free space avail
2007-01-26 00:28:32.804 AO: Broadcasting free space avail
2007-01-26 00:28: 32.824 AO: Broadcasting free space avail
2007-01-26 00:28:32.844 AO: Broadcasting free space avail
2007-01-26 00:28:32.864 AO: Broadcasting free space avail
2007-01-26 00:28:32.884 AO: Broadcasting free space avail
2007-01-26 00:28:32.904 AO: OutputAudioLoop: audio paused
2007-01-26 00:28:32.904 NVP: Waiting for prebuffer.. 2
uLAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:32.904 AO: 32768 bytes free on soundcard
2007-01-26 00:28: 32.964 Avg read interval was 198 msec. 64K block size
2007-01-26 00:28:33.074 NVP: Waiting for prebuffer.. 3
uLAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:33.244 NVP: Waiting for prebuffer.. 4
uLAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:33.414 NVP: Waiting for prebuffer.. 5
uLAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:33.584 NVP: Waiting for prebuffer.. 6
uLAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:33.754 NVP: Waiting for prebuffer.. 7
UUUUUuULAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:33.924 NVP: Waiting for prebuffer.. 8
UUUUUuULAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:34.094 NVP: Waiting for prebuffer.. 9
UUUUUuULAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:34.264 NVP: Prebuffer wait timed out 10 times.
2007-01-26 00:28:34.264 NVP: Waiting for prebuffer.. 0
UUUUUuULAAAAAAAAAAAAAAAAAAAAAAA
2007-01-26 00:28:34.304 AO: OutputAudioLoop: Play Event
2007-01-26 00:28:34.304 AO: Broadcasting free space avail

...

2007-01-26 00:28:34.306 AO: Broadcasting free space avail
2007-01-26 00:28:34.306 AO: audio waiting for buffer to fill: have 512 want 2048
2007-01-26 00:28:34.306 AO: Broadcasting free space avail
2007-01-26 00:28:34.324 Avg read interval was 181 msec. 96K block size
2007-01-26 00:28:34.324 AO: Broadcasting free space avail
2007-01-26 00:28:34.324 AO: Broadcasting free space avail
2007-01-26 00:28:34.325 AO: Broadcasting free space avail
2007-01-26 00:28:34.325 AO: audio waiting for space on soundcard: have
1968 need 2048
2007-01-26 00:28:34.344 AO: Broadcasting free space avail
2007-01-26 00:28:34.344 AO: Broadcasting free space avail
2007-01-26 00:28:34.344 AO: audio waiting for space on soundcard: have
1822 need 2048
2007-01-26 00:28: 34.364 AO: Broadcasting free space avail
2007-01-26 00:28:34.364 AO: Broadcasting free space avail
2007-01-26 00:28:34.364 AO: audio waiting for space on soundcard: have
1670 need 2048
2007-01-26 00:28:34.376 NVP: Video is 4.15938 frames behind audio
(too slow), dropping frame to catch up.
==============================