[mythtv-users] Error message: "Audio buffer overflow, audio data lost!", but only on one PBS channel in S.F. Bay Area

Matthew Gast matthew.gast at gmail.com
Tue May 31 15:57:20 UTC 2005


Hi all,

I'm having a problem with the audio track on one of my local PBS
stations (KQED).  The high-level effect is that the programs I record
on it have choppy audio.  The audio content itself appears to be OK,
but it cuts out and makes the video pause a couple of times a second.
The end result is that it sounds as if the voices are going through a
fan.  Each cutout in the audio corresponds to a slight hestiation in
the picture.  Mythfrontend reports the error "Audio buffer overflow,
audio data lost!" repeatedly.

I've isolated the problem to KQED broadcasts.  I can record other HD
programming on other channels and play it back without any audio
problems, including broadcasts on a second PBS station in the area
(KCSM).  I am reasonably certain that the problem lies within Myth,
and not with my reception.  Most of the digital stations in my area
broadcast from the same tower, so the recordings I am comparing to are
transmitted from virtually the same location less than 3 miles from my
home.  According to FCC records, KQED-DT uses higher power than
several of the other stations on the same power.  (KQED-DT broadcasts
at 777 kW; the two stations I'll be comparing to, KCSM-DT and KBWB-DT,
use 536 kW and 383 kW, respectively.)  Furthermore, my home antenna
system uses a ChannelMaster distribution amplifier to split my
incoming antenna signal four ways.  Two go to my Myth box, and one
goes to a Hughes HTL-HD OTA receiver connected to my TV.  I can
confirm on the HTL-HD that the KQED-DT signal is received well.  I
realize the HTL-HD is a completely different tuner from my pcHDTV
HD-3000 card, but it indicates that my antenna system is functioning
as designed.

I tried searching on Google (and Google groups) for the error message
about the buffer overflow, but I didn't find any solutions.

I don't believe it's a generalized performance problem.  Most of the
time during playback, the CPU remains on its lowest speed (1 GHz),
even with deinterlacing enabled and without XvMC.  There does not
appear to be a disk bottleneck, since I can play back 1080i HD streams
without difficulty.  Real-time scheduling does not make a difference,
either.

During the course of some research, I found that the PCI latency of my
video card is set quite high (248), and could possibly be starving out
my sound card for bus access.  I fiddled quite a bit with PCI latency
settings, even going so far as to set the sound card to 128 (0x80) and
the video card to 32 (0x20).  I think the audio chopped up slightly
less, but I didn't make a detailed investigation.

I spent some time fiddling with the sound system.  I'm using Fedora
Core 3 (x86_64) because I have an Athlon64.  I updated ALSA by hand to
1.0.8 from the stock version (1.0.6), to no avail.  I could update to
1.0.9, which was released a few days ago, but the release notes don't
indicate any major changes to the driver I'm using.  I have an nForce
3 Ultra main board, and it uses the intel8x0 driver.  I tried changing
the settings for the period_size and buffer_size both up and down, but
neither made a difference.  Setting "aggressive soundcard buffering"
in Myth has no significant effect.

If I set the playback device to a nonexistent value (say,
"ALSA:foobar"), the video plays back smoothly.  Therefore, the problem
would appear to be in either the capture, storage, or playback of the
audio stream.

At the end of this message, I've enclosed verbose playback traces.

The first comes from a 1080i broadcast on KBWB, and the second comes
from a 480i broadcast on KQED.  The 480i broadcast has audio problems,
even though it is encoded at a much lower bit rate.  The traces are
standard, with one exception.  In the course of my troubleshooting, I
added a few additional debug messages prefaced with "msg_debug".  I
noticed that the function RingBuffer::CalcReadAheadThresh() in
libs/libmythtv/RingBuffer.cpp would set a fill threshold based on the
bit rate it received, and that the bit rate of some of the recordings
on KQED wasn't high enough to trigger it to increment.  I moved the
first threshold down from 6000 bps to 3000 bps to ensure that the
fill_threshold was getting incremented for the recordings that had
choppy sound, but that didn't work.  I didn't make any other changes
to the code, other than adding my own messages to the library.

When comparing the two verbose traces, I notice that the working case
and the non-working case are quite similar.  They use the same codecs,
and the audio stream is the same (a 48 kHz AC3 stream that requires
384 kbps).  In both cases, mythfrontend is trying to write out to the
card before it is ready, and there are messages that say "WriteAudio:
Preparing 4096 bytes (1024 frames)" followed by "audio waiting for
space on soundcard: have xxx need 4096".  Frequently, the latter
message appears repeatedly, with the xxx value increasing, indicating
the sound card is draining its buffer.

The difference I noticed is that in the working trace, the "free"
value in the lines that read "_AddSamples bytes=6144, used=xxx,
free=xxx, timecode=xxx" is always pretty high--above 400,000.  In the
non-working trace, it slowly goes down to the neighborhood of 8,000 to
30,000, and is accompanied by messages which read "A/V diverged by 30
frames, extending frame to keep audio in sync".  The A/v diverging
message appears repeatedly, and it's always by exactly 30 frames.

So, all that I can tell is that on this one channel, mythfrontend is
writing too much data into the sound buffer and causing it to
overflow.  I can't tell why, though, since the front end identifies
the audio streams as identical.

I thought that perhaps the problem was that KQED has five subchannels,
and the problem was sorting through all five audio streams.  I checked
on the setup of my capture cards, though, and they are set to record
the program stream (PS) rather than the transport stream (TS).  I'm
using the DVB drivers with my pcHDTV cards.

I don't know how to separate the audio stream from the video for
separate playback.  MPlayer's mencoder wants to combine both the audio
stream and the video stream, so I don't know how to create an MP3 to
see if the audio is getting captured correctly.

I'd greatly appreciate any help that you could offer, and I'm
obviously more than happy to run any diagnostics that would help you
guide me towards a solution.  Thanks in advance for your help!

  --Matthew


====================
Hardware:

MSI K8N Neo2 Platinum mainboard (model 7025)
  - sound card: nForce3 built-in sound using Realtek ALC850 7.1 chip
AMD Athlon64 3200+ (2 GHz Winchester core)
1 GB DDR-400 PC3200 Kingston memory, in two banks for dual-channel operation
Giga-byte GeForce FX5200 video card, AGP8x
Two pcHDTV HD-3000
Samsung SpinPoint SATA drive, 120 GB

====================
Software:

Fedora Core 3
nVidia x86_64 video drivers, version 7174
Updated kernel:  2.6.11-1.14_FC3
pcHDTV 2.0 drivers (DVB)
Updated ALSA to 1.0.8 from source from alsa-project.org
MythTV 0.18.1 (built from scratch, not ATrpms)

====================
aplay audio device listing output:

[mythtv at localhost ~]$ aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: CK8S [NVidia CK8S], device 0: Intel ICH [NVidia CK8S]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: CK8S [NVidia CK8S], device 2: Intel ICH - IEC958 [NVidia CK8S - IEC958]
  Subdevices: 1/1
  Subdevice #0: subdevice #0

====================
.asoundrc:

Sound is configured using the .asoundrc from 
http://www.mythtv.info/moin.cgi/DigitalSoundHowTo, with one small
change.  I've changed my mixer device to have a larger period_size and
buffer_size, though that really hasn't helped:

# Direct software mixing plugin for analog output on
# the nForce2/4 (hw:0,0)
# Do not use this directly--it requires specific rate,
# channels, and format
pcm.dmix-analog {
 type dmix
 ipc_key 1234
 slave {
   pcm "analog-hw"
   period_time 0
   period_size 2048
   buffer_size 32768
   rate 48000
 }
}

====================
lspci output for audio device:

(It's identified as an nForce3 controller, not a Realtek ALC850.  Is
that normal?)

00:06.0 Multimedia audio controller: nVidia Corporation nForce3 250Gb
AC'97 Audio Controller (rev a1)
        Subsystem: Micro-Star International Co., Ltd.: Unknown device 7585
        Flags: bus master, 66Mhz, fast devsel, latency 0, IRQ 209
        I/O ports at ac00 [size=256]
        I/O ports at b000 [size=128]
        Memory at f8001000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [44] Power Management version 2


====================
mythfrontend output from a working HD stream:

(From channel 20-1, audio works)

[mythtv at localhost]$ sudo mythfrontend --verbose all
2005-05-29 15:13:06.246 New DB connection, total: 1
Total desktop width=1024, height=768, numscreens=2
2005-05-29 15:13:06.252 Using screen 0, 1024x768 at 0,0
2005-05-29 15:13:06.255 mythfrontend version: 0.18.1.20050510-1 www.mythtv.=
org
2005-05-29 15:13:06.255 Enabled verbose msgs :all
2005-05-29 15:13:06.507 max_width: 1024 max_height: 768
2005-05-29 15:13:06.530 Switching to square mode (blue)
2005-05-29 15:13:06.986 Registering Internal as a media playback plugin.
2005-05-29 15:13:28.609 All Programs
2005-05-29 15:13:28.980 Connecting to backend server: 127.0.0.1:6543
(try 1 of 5)
2005-05-29 15:13:28.981 write->11 21      MYTH_PROTO_VERSION 15:
2005-05-29 15:13:28.987 Using protocol version 15
2005-05-29 15:13:28.987 write->11 36      ANN Playback localhost.localdomai=
n 0:
2005-05-29 15:13:28.995 write->11 21      QUERY_RECORDINGS Play:
2005-05-29 15:13:29.075 36      ANN Playback localhost.localdomain 1
2005-05-29 15:13:30.120 New DB connection, total: 2
2005-05-29 15:13:30.145 Output filters for this channel are: ''
2005-05-29 15:13:30.196 AVFD
2005-05-29 15:13:30.196 AVFD: Opening Stream #0: codec id 2
2005-05-29 15:13:30.198 detectInterlace(Detect Scan, Detect Scan,
29.97, 1088) ->Interlaced Scan
2005-05-29 15:13:30.198 Interlaced: Interlaced Scan  video_height:
1088  fps: 29.97
2005-05-29 15:13:30.198 AVFD: Looking for decoder for 2
2005-05-29 15:13:30.198 AVFD
2005-05-29 15:13:30.198 AVFD: Opening Stream #1: codec id 86020
2005-05-29 15:13:30.198 AVFD: Looking for decoder for 86020
2005-05-29 15:13:30.199 Stream #1 (audio track #0) is an audio stream
with 2 channels.
2005-05-29 15:13:30.200 Auto-selecting AC3 audio track (stream #1).
2005-05-29 15:13:30.200 Initializing audio parms from audio track #0.
2005-05-29 15:13:30.201 Estimated bitrate = 16184
2005-05-29 15:13:30.201 msg_debug: upping fill threshold above 3000 bps
2005-05-29 15:13:30.201 msg_debug: Fill threshold is = 768000
2005-05-29 15:13:30.202 msg_debug: Readblock size = 128000
2005-05-29 15:13:30.266 Position map filled from DB to: 119076
2005-05-29 15:13:30.266 SyncPositionMap prerecorded, from DB: 3586 entries
2005-05-29 15:13:30.266 SyncPositionMap, new totframes: 119076, new
length: 3973, posMap size: 3586
Input #0, mpeg, from '/video/1000_20050522220000_20050522230000.nuv':
  Stream #0.0: Video: mpeg2video, 1920x1080, 29.97 fps, 15800 kb/s
  Stream #0.1: Audio: ac3, 48000 Hz, stereo, 384 kb/s
2005-05-29 15:13:30.267 Position map found
2005-05-29 15:13:30.268 Commercial Detection initialized: width =
1920, height = 1088, fps = 29.97, method = 255
2005-05-29 15:13:30.269 Using Sample Spacing of 10 horizontal & 10
vertical pixels.
2005-05-29 15:13:30.270 CommDetect::ClearAllMaps()
2005-05-29 15:13:30.271 Killing AudioOutputDSP
2005-05-29 15:13:30.272 Opening audio device 'analog'.
2005-05-29 15:13:30.275 in SetParameters(format=2, channels=2,
rate=48000, buffer_time=500000, period_time=125000)
2005-05-29 15:13:30.277 get_buffer_size returned 16384
2005-05-29 15:13:30.277 set_period_time_near returned 85333
2005-05-29 15:13:30.277 get_period_size returned 4096
2005-05-29 15:13:30.278 Opening mixer default
2005-05-29 15:13:30.280 Setting Master volume to 85
2005-05-29 15:13:30.280 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:13:30.281 channel 0 vol set to 26
2005-05-29 15:13:30.281 Setting Master volume to 85
2005-05-29 15:13:30.281 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:13:30.281 channel 1 vol set to 26
2005-05-29 15:13:30.281 Setting PCM volume to 72
2005-05-29 15:13:30.282 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:13:30.282 channel 0 vol set to 22
2005-05-29 15:13:30.282 Setting PCM volume to 72
2005-05-29 15:13:30.282 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:13:30.282 channel 1 vol set to 22
2005-05-29 15:13:30.282 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:13:30.282 Audio fragment size: 4096
2005-05-29 15:13:30.283 Audio Stretch Factor: 1
2005-05-29 15:13:30.283 Ending reconfigure
2005-05-29 15:13:30.288 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
2005-05-29 15:13:30.291 Using XV port 177
2005-05-29 15:13:30.299 Couldn't get the color key color, and we need it.
You likely won't get any video.
2005-05-29 15:13:30.299 Image size. dispxoff 0, dispyoff: 0, dispwoff:
1024, disphoff: 768
2005-05-29 15:13:30.299 Image size. imgx 0, imgy: 0, imgw: 1920, imgh: 1080
2005-05-29 15:13:30.317 kickoffOutputAudioLoop: pid = 5728
2005-05-29 15:13:30.317 OutputAudioLoop: Play Event
2005-05-29 15:13:30.317 Broadcasting free space avail

(The same message appears 212 times, snipped for brevity)

2005-05-29 15:13:31.313 Broadcasting free space avail
2005-05-29 15:13:31.316 Using realtime priority.
2005-05-29 15:13:31.317 Using deinterlace method bobdeint
2005-05-29 15:13:31.317 OutputAudioLoop: audio paused
2005-05-29 15:13:31.317 16384 bytes free on soundcard
2005-05-29 15:13:31.317 Changing from None to WatchingPreRecorded
2005-05-29 15:13:31.391 _AddSamples bytes=6144, used=1, free=511999,
timecode=11590329
2005-05-29 15:13:31.392 _AddSamples bytes=6144, used=6145,
free=505855, timecode=11590361
2005-05-29 15:13:31.392 _AddSamples bytes=6144, used=12289,
free=499711, timecode=11590393
2005-05-29 15:13:31.418 nVidiaVideoSync: VBlank ioctl did not work,
unimplemented in this driver?
2005-05-29 15:13:31.418 DRMVideoSync: Could not open device
/dev/dri/card0, No such file or directory
2005-05-29 15:13:31.418 Set video sync frame interval to 33366
2005-05-29 15:13:31.418 Using audio as timebase
2005-05-29 15:13:31.418 Video timing method: RTC
2005-05-29 15:13:31.418 Refresh rate: 11765, frame interval: 33366
2005-05-29 15:13:31.418 waiting for prebuffer...
2005-05-29 15:13:31.455 _AddSamples bytes=6144, used=18433,
free=493567, timecode=11590425
2005-05-29 15:13:31.455 _AddSamples bytes=6144, used=24577,
free=487423, timecode=11590457
2005-05-29 15:13:31.455 _AddSamples bytes=6144, used=30721,
free=481279, timecode=11590489
2005-05-29 15:13:31.455 _AddSamples bytes=6144, used=36865,
free=475135, timecode=11590521
2005-05-29 15:13:31.515 _AddSamples bytes=6144, used=43009,
free=468991, timecode=11590553
2005-05-29 15:13:31.516 _AddSamples bytes=6144, used=49153,
free=462847, timecode=11590585
2005-05-29 15:13:31.516 _AddSamples bytes=6144, used=55297,
free=456703, timecode=11590617
2005-05-29 15:13:31.516 _AddSamples bytes=6144, used=61441,
free=450559, timecode=11590649
2005-05-29 15:13:31.546 OutputAudioLoop: Play Event
2005-05-29 15:13:31.546 Broadcasting free space avail
2005-05-29 15:13:31.546 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.546 Broadcasting free space avail
2005-05-29 15:13:31.546 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.546 Broadcasting free space avail
2005-05-29 15:13:31.546 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.546 Broadcasting free space avail
2005-05-29 15:13:31.546 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.546 audio waiting for space on soundcard: have 256 need 4096
2005-05-29 15:13:31.553 audio waiting for space on soundcard: have
1536 need 4096
2005-05-29 15:13:31.560 audio waiting for space on soundcard: have
2848 need 4096
2005-05-29 15:13:31.567 Broadcasting free space avail
2005-05-29 15:13:31.567 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.567 audio waiting for space on soundcard: have 160 need 4096
2005-05-29 15:13:31.574 audio waiting for space on soundcard: have
1472 need 4096
2005-05-29 15:13:31.581 audio waiting for space on soundcard: have
2784 need 4096
2005-05-29 15:13:31.588 Broadcasting free space avail
2005-05-29 15:13:31.588 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.588 audio waiting for space on soundcard: have 64 need 4096
2005-05-29 15:13:31.595 audio waiting for space on soundcard: have
1408 need 4096
2005-05-29 15:13:31.602 audio waiting for space on soundcard: have
2752 need 4096
2005-05-29 15:13:31.610 Broadcasting free space avail
2005-05-29 15:13:31.610 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.610 audio waiting for space on soundcard: have 192 need 4096
2005-05-29 15:13:31.617 audio waiting for space on soundcard: have
1504 need 4096
2005-05-29 15:13:31.624 audio waiting for space on soundcard: have
2912 need 4096
2005-05-29 15:13:31.631 Broadcasting free space avail
2005-05-29 15:13:31.631 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:13:31.631 audio waiting for space on soundcard: have 128 need 4096
2005-05-29 15:13:31.635 _AddSamples bytes=6144, used=34817,
free=477183, timecode=11590681
2005-05-29 15:13:31.635 _AddSamples bytes=6144, used=40961,
free=471039, timecode=11590713
2005-05-29 15:13:31.636 _AddSamples bytes=6144, used=47105,
free=464895, timecode=11590745
2005-05-29 15:13:31.637 _AddSamples bytes=6144, used=53249,
free=458751, timecode=11590777
2005-05-29 15:13:31.638 audio waiting for space on soundcard: have
1440 need 4096
2005-05-29 15:13:31.641 A/V diverged by 3.01765 frames, extending
frame to keep audio in sync

====================
mythfrontend output:

(From channel 9-5, audio stutters badly)

[mythtv at localhost]$ sudo mythfrontend --verbose all
2005-05-29 15:16:10.308 New DB connection, total: 1
Total desktop width=1024, height=768, numscreens=2
2005-05-29 15:16:10.314 Using screen 0, 1024x768 at 0,0
2005-05-29 15:16:10.317 mythfrontend version: 0.18.1.20050510-1 www.mythtv.=
org
2005-05-29 15:16:10.317 Enabled verbose msgs :all
2005-05-29 15:16:10.553 max_width: 1024 max_height: 768
2005-05-29 15:16:10.575 Switching to square mode (blue)
2005-05-29 15:16:11.045 Registering Internal as a media playback plugin.
2005-05-29 15:16:15.277 All Programs
2005-05-29 15:16:15.654 Connecting to backend server: 127.0.0.1:6543
(try 1 of 5)
2005-05-29 15:16:15.654 write->10 21      MYTH_PROTO_VERSION 15:
2005-05-29 15:16:15.661 Using protocol version 15
2005-05-29 15:16:15.661 write->10 36      ANN Playback localhost.localdomai=
n 0:
2005-05-29 15:16:15.668 write->10 21      QUERY_RECORDINGS Play:
2005-05-29 15:16:15.732 36      ANN Playback localhost.localdomain 1
2005-05-29 15:16:17.717 All Programs
2005-05-29 15:16:18.097 write->10 21      QUERY_RECORDINGS Play:
2005-05-29 15:16:20.432 New DB connection, total: 2
2005-05-29 15:16:20.498 Output filters for this channel are: ''
2005-05-29 15:16:20.531 AVFD
2005-05-29 15:16:20.531 AVFD: Opening Stream #0: codec id 2
2005-05-29 15:16:20.531 detectInterlace(Detect Scan, Detect Scan,
29.97, 480) ->Interlaced Scan
2005-05-29 15:16:20.531 Interlaced: Interlaced Scan  video_height: 480
 fps: 29.97
2005-05-29 15:16:20.531 AVFD: Looking for decoder for 2
2005-05-29 15:16:20.532 AVFD
2005-05-29 15:16:20.532 AVFD: Opening Stream #1: codec id 86020
2005-05-29 15:16:20.532 AVFD: Looking for decoder for 86020
2005-05-29 15:16:20.533 Stream #1 (audio track #0) is an audio stream
with 2 channels.
2005-05-29 15:16:20.533 Auto-selecting AC3 audio track (stream #1).
2005-05-29 15:16:20.533 Initializing audio parms from audio track #0.
2005-05-29 15:16:20.535 Estimated bitrate = 4684
2005-05-29 15:16:20.535 msg_debug: upping fill threshold above 3000 bps
2005-05-29 15:16:20.535 msg_debug: Fill threshold is = 256000
2005-05-29 15:16:20.535 msg_debug: Readblock size = 128000
Input #0, mpeg, from '/video/1011_20050529084000_20050529093000.nuv':
  Stream #0.0: Video: mpeg2video, 704x480, 29.97 fps, 4300 kb/s
  Stream #0.1: Audio: ac3, 48000 Hz, stereo, 384 kb/s
2005-05-29 15:16:20.535 Commercial Detection initialized: width = 704,
height = 480, fps = 29.97, method = 255
2005-05-29 15:16:20.536 Using Sample Spacing of 6 horizontal & 4
vertical pixels.
2005-05-29 15:16:20.537 CommDetect::ClearAllMaps()
2005-05-29 15:16:20.576 Image size. dispxoff 0, dispyoff: 0, dispwoff:
0, disphoff: 0
2005-05-29 15:16:20.576 Image size. imgx 0, imgy: 0, imgw: 704, imgh: 480
2005-05-29 15:16:20.578 positionMap[ 0 ] == 142316.
2005-05-29 15:16:20.597 AVFD
2005-05-29 15:16:20.597 AVFD: Opening Stream #0: codec id 2
2005-05-29 15:16:20.598 detectInterlace(Detect Scan, Detect Scan,
29.97, 480) ->Interlaced Scan
2005-05-29 15:16:20.598 Interlaced: Interlaced Scan  video_height: 480
 fps: 29.97
2005-05-29 15:16:20.599 AVFD: Looking for decoder for 2
2005-05-29 15:16:20.599 AVFD
2005-05-29 15:16:20.599 AVFD: Opening Stream #1: codec id 86020
2005-05-29 15:16:20.599 AVFD: Looking for decoder for 86020
2005-05-29 15:16:20.600 Stream #1 (audio track #0) is an audio stream
with 2 channels.
2005-05-29 15:16:20.600 Auto-selecting AC3 audio track (stream #1).
2005-05-29 15:16:20.600 Initializing audio parms from audio track #0.
2005-05-29 15:16:20.601 Estimated bitrate = 4684
2005-05-29 15:16:20.601 msg_debug: upping fill threshold above 3000 bps
2005-05-29 15:16:20.601 msg_debug: Fill threshold is = 256000
2005-05-29 15:16:20.602 msg_debug: Readblock size = 128000
2005-05-29 15:16:21.307 Position map filled from DB to: 90125
2005-05-29 15:16:21.308 SyncPositionMap prerecorded, from DB: 5931 entries
2005-05-29 15:16:21.309 SyncPositionMap, new totframes: 90125, new
length: 3007, posMap size: 5931
Input #0, mpeg, from '/video/1011_20050529084000_20050529093000.nuv':
  Stream #0.0: Video: mpeg2video, 704x480, 29.97 fps, 4300 kb/s
  Stream #0.1: Audio: ac3, 48000 Hz, stereo, 384 kb/s
2005-05-29 15:16:21.309 Position map found
2005-05-29 15:16:21.311 Commercial Detection initialized: width = 704,
height = 480, fps = 29.97, method = 255
2005-05-29 15:16:21.311 Using Sample Spacing of 6 horizontal & 4
vertical pixels.
2005-05-29 15:16:21.312 CommDetect::ClearAllMaps()
2005-05-29 15:16:21.313 Killing AudioOutputDSP
2005-05-29 15:16:21.314 Opening audio device 'analog'.
2005-05-29 15:16:21.317 in SetParameters(format=2, channels=2,
rate=48000, buffer_time=500000, period_time=125000)
2005-05-29 15:16:21.319 get_buffer_size returned 16384
2005-05-29 15:16:21.319 set_period_time_near returned 85333
2005-05-29 15:16:21.319 get_period_size returned 4096
2005-05-29 15:16:21.321 Opening mixer default
2005-05-29 15:16:21.323 Setting Master volume to 85
2005-05-29 15:16:21.323 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:16:21.323 channel 0 vol set to 26
2005-05-29 15:16:21.323 Setting Master volume to 85
2005-05-29 15:16:21.323 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:16:21.323 channel 1 vol set to 26
2005-05-29 15:16:21.324 Setting PCM volume to 72
2005-05-29 15:16:21.324 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:16:21.324 channel 0 vol set to 22
2005-05-29 15:16:21.324 Setting PCM volume to 72
2005-05-29 15:16:21.324 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:16:21.324 channel 1 vol set to 22
2005-05-29 15:16:21.324 Volume range is 0 to 31, mult=3.22581
2005-05-29 15:16:21.324 Audio fragment size: 4096
2005-05-29 15:16:21.325 Audio Stretch Factor: 1
2005-05-29 15:16:21.325 Ending reconfigure
2005-05-29 15:16:21.325 kickoffOutputAudioLoop: pid = 5742
2005-05-29 15:16:21.325 OutputAudioLoop: Play Event
2005-05-29 15:16:21.326 Broadcasting free space avail
2005-05-29 15:16:21.330 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
2005-05-29 15:16:21.334 Using XV port 177
2005-05-29 15:16:21.341 Couldn't get the color key color, and we need it.
You likely won't get any video.
2005-05-29 15:16:21.342 Image size. dispxoff 0, dispyoff: 0, dispwoff:
1024, disphoff: 768
2005-05-29 15:16:21.342 Image size. imgx 0, imgy: 0, imgw: 704, imgh: 480
2005-05-29 15:16:21.455 Broadcasting free space avail

(The same message appears 43 times, snipped for brevity)

2005-05-29 15:16:21.631 Broadcasting free space avail
2005-05-29 15:16:21.634 Using realtime priority.
2005-05-29 15:16:21.635 Using deinterlace method bobdeint
2005-05-29 15:16:21.635 OutputAudioLoop: audio paused
2005-05-29 15:16:21.635 16384 bytes free on soundcard
2005-05-29 15:16:21.636 Changing from None to WatchingPreRecorded
2005-05-29 15:16:21.661 _AddSamples bytes=6144, used=1, free=511999,
timecode=72391557
2005-05-29 15:16:21.661 _AddSamples bytes=6144, used=6145,
free=505855, timecode=72391589
2005-05-29 15:16:21.661 _AddSamples bytes=6144, used=12289,
free=499711, timecode=72391621
2005-05-29 15:16:21.664 _AddSamples bytes=6144, used=18433,
free=493567, timecode=72391653
2005-05-29 15:16:21.667 _AddSamples bytes=6144, used=24577,
free=487423, timecode=72391625
2005-05-29 15:16:21.670 _AddSamples bytes=6144, used=30721,
free=481279, timecode=72391657
2005-05-29 15:16:21.670 _AddSamples bytes=6144, used=36865,
free=475135, timecode=72391689
2005-05-29 15:16:21.670 _AddSamples bytes=6144, used=43009,
free=468991, timecode=72391650
2005-05-29 15:16:21.670 _AddSamples bytes=6144, used=49153,
free=462847, timecode=72391682
2005-05-29 15:16:21.671 _AddSamples bytes=6144, used=55297,
free=456703, timecode=72391714
2005-05-29 15:16:21.673 _AddSamples bytes=6144, used=61441,
free=450559, timecode=72391746
2005-05-29 15:16:21.676 _AddSamples bytes=6144, used=67585,
free=444415, timecode=72391721
2005-05-29 15:16:21.676 _AddSamples bytes=6144, used=73729,
free=438271, timecode=72391685
2005-05-29 15:16:21.677 _AddSamples bytes=6144, used=79873,
free=432127, timecode=72391717
2005-05-29 15:16:21.677 _AddSamples bytes=6144, used=86017,
free=425983, timecode=72391749
2005-05-29 15:16:21.677 _AddSamples bytes=6144, used=92161,
free=419839, timecode=72391781
2005-05-29 15:16:21.680 _AddSamples bytes=6144, used=98305,
free=413695, timecode=72391753
2005-05-29 15:16:21.685 _AddSamples bytes=6144, used=104449,
free=407551, timecode=72391785
2005-05-29 15:16:21.685 _AddSamples bytes=6144, used=110593,
free=401407, timecode=72391817
2005-05-29 15:16:21.686 _AddSamples bytes=6144, used=116737,
free=395263, timecode=72391778
2005-05-29 15:16:21.686 _AddSamples bytes=6144, used=122881,
free=389119, timecode=72391810
2005-05-29 15:16:21.686 _AddSamples bytes=6144, used=129025,
free=382975, timecode=72391842
2005-05-29 15:16:21.689 _AddSamples bytes=6144, used=135169,
free=376831, timecode=72391874
2005-05-29 15:16:21.691 _AddSamples bytes=6144, used=141313,
free=370687, timecode=72391849
2005-05-29 15:16:21.692 _AddSamples bytes=6144, used=147457,
free=364543, timecode=72391813
2005-05-29 15:16:21.692 _AddSamples bytes=6144, used=153601,
free=358399, timecode=72391845
2005-05-29 15:16:21.692 _AddSamples bytes=6144, used=159745,
free=352255, timecode=72391877
2005-05-29 15:16:21.695 _AddSamples bytes=6144, used=165889,
free=346111, timecode=72391909
2005-05-29 15:16:21.695 _AddSamples bytes=6144, used=172033,
free=339967, timecode=72391881
2005-05-29 15:16:21.696 _AddSamples bytes=6144, used=178177,
free=333823, timecode=72391913
2005-05-29 15:16:21.696 _AddSamples bytes=6144, used=184321,
free=327679, timecode=72391945
2005-05-29 15:16:21.696 _AddSamples bytes=6144, used=190465,
free=321535, timecode=72391906
2005-05-29 15:16:21.696 _AddSamples bytes=6144, used=196609,
free=315391, timecode=72391938
2005-05-29 15:16:21.696 _AddSamples bytes=6144, used=202753,
free=309247, timecode=72391970
2005-05-29 15:16:21.697 _AddSamples bytes=6144, used=208897,
free=303103, timecode=72392002
2005-05-29 15:16:21.697 _AddSamples bytes=6144, used=215041,
free=296959, timecode=72391977
2005-05-29 15:16:21.697 _AddSamples bytes=6144, used=221185,
free=290815, timecode=72391941
2005-05-29 15:16:21.697 _AddSamples bytes=6144, used=227329,
free=284671, timecode=72391973
2005-05-29 15:16:21.697 _AddSamples bytes=6144, used=233473,
free=278527, timecode=72392005
2005-05-29 15:16:21.698 OutputAudioLoop: Play Event
2005-05-29 15:16:21.698 Broadcasting free space avail
2005-05-29 15:16:21.698 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.698 Broadcasting free space avail
2005-05-29 15:16:21.698 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.698 Broadcasting free space avail
2005-05-29 15:16:21.698 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.698 Broadcasting free space avail
2005-05-29 15:16:21.698 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.698 audio waiting for space on soundcard: have 256 need 4096
2005-05-29 15:16:21.698 _AddSamples bytes=6144, used=223233,
free=288767, timecode=72392037
2005-05-29 15:16:21.704 _AddSamples bytes=6144, used=229377,
free=282623, timecode=72392009
2005-05-29 15:16:21.705 audio waiting for space on soundcard: have
1536 need 4096
2005-05-29 15:16:21.707 _AddSamples bytes=6144, used=235521,
free=276479, timecode=72392041
2005-05-29 15:16:21.707 _AddSamples bytes=6144, used=241665,
free=270335, timecode=72392073
2005-05-29 15:16:21.708 _AddSamples bytes=6144, used=247809,
free=264191, timecode=72392034
2005-05-29 15:16:21.708 _AddSamples bytes=6144, used=253953,
free=258047, timecode=72392066
2005-05-29 15:16:21.708 _AddSamples bytes=6144, used=260097,
free=251903, timecode=72392098
2005-05-29 15:16:21.711 _AddSamples bytes=6144, used=266241,
free=245759, timecode=72392130
2005-05-29 15:16:21.712 audio waiting for space on soundcard: have
2880 need 4096
2005-05-29 15:16:21.712 _AddSamples bytes=6144, used=272385,
free=239615, timecode=72392105
2005-05-29 15:16:21.712 _AddSamples bytes=6144, used=278529,
free=233471, timecode=72392069
2005-05-29 15:16:21.712 _AddSamples bytes=6144, used=284673,
free=227327, timecode=72392101
2005-05-29 15:16:21.712 _AddSamples bytes=6144, used=290817,
free=221183, timecode=72392133
2005-05-29 15:16:21.715 _AddSamples bytes=6144, used=296961,
free=215039, timecode=72392165
2005-05-29 15:16:21.718 _AddSamples bytes=6144, used=303105,
free=208895, timecode=72392137
2005-05-29 15:16:21.719 Broadcasting free space avail
2005-05-29 15:16:21.719 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.719 audio waiting for space on soundcard: have 128 need 
 4096
2005-05-29 15:16:21.721 _AddSamples bytes=6144, used=305153,
free=206847, timecode=72392169
2005-05-29 15:16:21.722 _AddSamples bytes=6144, used=311297,
free=200703, timecode=72392201
2005-05-29 15:16:21.722 _AddSamples bytes=6144, used=317441,
free=194559, timecode=72392162
2005-05-29 15:16:21.722 _AddSamples bytes=6144, used=323585,
free=188415, timecode=72392194
2005-05-29 15:16:21.722 _AddSamples bytes=6144, used=329729,
free=182271, timecode=72392226
2005-05-29 15:16:21.726 audio waiting for space on soundcard: have
1472 need 4096
2005-05-29 15:16:21.728 _AddSamples bytes=6144, used=335873,
free=176127, timecode=72392258
2005-05-29 15:16:21.728 _AddSamples bytes=6144, used=342017,
free=169983, timecode=72392233
2005-05-29 15:16:21.728 _AddSamples bytes=6144, used=348161,
free=163839, timecode=72392197
2005-05-29 15:16:21.728 _AddSamples bytes=6144, used=354305,
free=157695, timecode=72392229
2005-05-29 15:16:21.729 _AddSamples bytes=6144, used=360449,
free=151551, timecode=72392261
2005-05-29 15:16:21.729 _AddSamples bytes=6144, used=366593,
free=145407, timecode=72392293
2005-05-29 15:16:21.733 audio waiting for space on soundcard: have
2816 need 4096
2005-05-29 15:16:21.734 _AddSamples bytes=6144, used=372737,
free=139263, timecode=72392265
2005-05-29 15:16:21.737 nVidiaVideoSync: VBlank ioctl did not work,
unimplemented in this driver?
2005-05-29 15:16:21.737 DRMVideoSync: Could not open device
/dev/dri/card0, No such file or directory
2005-05-29 15:16:21.737 Set video sync frame interval to 33366
2005-05-29 15:16:21.737 Using audio as timebase
2005-05-29 15:16:21.737 Video timing method: RTC
2005-05-29 15:16:21.737 Refresh rate: 11765, frame interval: 33366
2005-05-29 15:16:21.740 Broadcasting free space avail
2005-05-29 15:16:21.740 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.740 audio waiting for space on soundcard: have 64 need =
4096
2005-05-29 15:16:21.740 _AddSamples bytes=6144, used=374785,
free=137215, timecode=72392297
2005-05-29 15:16:21.740 _AddSamples bytes=6144, used=380929,
free=131071, timecode=72392329
2005-05-29 15:16:21.740 _AddSamples bytes=6144, used=387073,
free=124927, timecode=72392290
2005-05-29 15:16:21.740 _AddSamples bytes=6144, used=393217,
free=118783, timecode=72392322
2005-05-29 15:16:21.741 _AddSamples bytes=6144, used=399361,
free=112639, timecode=72392354
2005-05-29 15:16:21.744 _AddSamples bytes=6144, used=405505,
free=106495, timecode=72392386
2005-05-29 15:16:21.746 _AddSamples bytes=6144, used=411649,
free=100351, timecode=72392361
2005-05-29 15:16:21.747 audio waiting for space on soundcard: have
1408 need 4096
2005-05-29 15:16:21.747 _AddSamples bytes=6144, used=417793,
free=94207, timecode=72392325
2005-05-29 15:16:21.747 _AddSamples bytes=6144, used=423937,
free=88063, timecode=72392357
2005-05-29 15:16:21.747 _AddSamples bytes=6144, used=430081,
free=81919, timecode=72392389
2005-05-29 15:16:21.747 _AddSamples bytes=6144, used=436225,
free=75775, timecode=72392421
2005-05-29 15:16:21.750 _AddSamples bytes=6144, used=442369,
free=69631, timecode=72392393
2005-05-29 15:16:21.751 _AddSamples bytes=6144, used=448513,
free=63487, timecode=72392425
2005-05-29 15:16:21.751 _AddSamples bytes=6144, used=454657,
free=57343, timecode=72392457
2005-05-29 15:16:21.751 _AddSamples bytes=6144, used=460801,
free=51199, timecode=72392418
2005-05-29 15:16:21.751 _AddSamples bytes=6144, used=466945,
free=45055, timecode=72392450
2005-05-29 15:16:21.752 _AddSamples bytes=6144, used=473089,
free=38911, timecode=72392482
2005-05-29 15:16:21.754 audio waiting for space on soundcard: have
2752 need 4096
2005-05-29 15:16:21.756 _AddSamples bytes=6144, used=479233,
free=32767, timecode=72392514
2005-05-29 15:16:21.757 _AddSamples bytes=6144, used=485377,
free=26623, timecode=72392489
2005-05-29 15:16:21.757 _AddSamples bytes=6144, used=491521,
free=20479, timecode=72392453
2005-05-29 15:16:21.757 _AddSamples bytes=6144, used=497665,
free=14335, timecode=72392485
2005-05-29 15:16:21.757 _AddSamples bytes=6144, used=503809,
free=8191, timecode=72392517
2005-05-29 15:16:21.760 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.761 Broadcasting free space avail
2005-05-29 15:16:21.761 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.761 audio waiting for space on soundcard: have 64 need =
4096
2005-05-29 15:16:21.763 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.768 audio waiting for space on soundcard: have
1344 need 4096
2005-05-29 15:16:21.775 audio waiting for space on soundcard: have
2688 need 4096
2005-05-29 15:16:21.782 audio waiting for space on soundcard: have
4032 need 4096
2005-05-29 15:16:21.789 Broadcasting free space avail
2005-05-29 15:16:21.789 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.789 audio waiting for space on soundcard: have
1280 need 4096
2005-05-29 15:16:21.796 audio waiting for space on soundcard: have
2624 need 4096
2005-05-29 15:16:21.800 A/V diverged by 14.753 frames, extending frame
to keep audio in sync
2005-05-29 15:16:21.801 _AddSamples bytes=6144, used=501761,
free=10239, timecode=72392553
2005-05-29 15:16:21.801 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.801 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.801 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.802 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.803 audio waiting for space on soundcard: have
3968 need 4096
2005-05-29 15:16:21.810 Broadcasting free space avail
2005-05-29 15:16:21.810 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.810 audio waiting for space on soundcard: have
1216 need 4096
2005-05-29 15:16:21.816 audio waiting for space on soundcard: have
2528 need 4096
2005-05-29 15:16:21.824 audio waiting for space on soundcard: have
3904 need 4096
2005-05-29 15:16:21.831 Broadcasting free space avail
2005-05-29 15:16:21.831 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.831 audio waiting for space on soundcard: have
1152 need 4096
2005-05-29 15:16:21.837 audio waiting for space on soundcard: have
2464 need 4096
2005-05-29 15:16:21.845 audio waiting for space on soundcard: have
3840 need 4096
2005-05-29 15:16:21.852 Broadcasting free space avail
2005-05-29 15:16:21.852 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.852 audio waiting for space on soundcard: have
1088 need 4096
2005-05-29 15:16:21.858 audio waiting for space on soundcard: have
2400 need 4096
2005-05-29 15:16:21.865 audio waiting for space on soundcard: have
3744 need 4096
2005-05-29 15:16:21.866 A/V diverged by 26.657 frames, extending frame
to keep audio in sync
2005-05-29 15:16:21.867 _AddSamples bytes=6144, used=495617,
free=16383, timecode=72392642
2005-05-29 15:16:21.873 Broadcasting free space avail
2005-05-29 15:16:21.873 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.873 audio waiting for space on soundcard: have
1024 need 4096
2005-05-29 15:16:21.879 audio waiting for space on soundcard: have
2336 need 4096
2005-05-29 15:16:21.886 audio waiting for space on soundcard: have
3680 need 4096
2005-05-29 15:16:21.893 Broadcasting free space avail
2005-05-29 15:16:21.894 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.894 audio waiting for space on soundcard: have 960 need 
 4096
2005-05-29 15:16:21.900 audio waiting for space on soundcard: have
2272 need 4096
2005-05-29 15:16:21.907 audio waiting for space on soundcard: have
3616 need 4096
2005-05-29 15:16:21.914 Broadcasting free space avail
2005-05-29 15:16:21.915 WriteAudio: Preparing 4096 bytes (1024 frames)
2005-05-29 15:16:21.915 audio waiting for space on soundcard: have 896 need 
 4096
2005-05-29 15:16:21.921 audio waiting for space on soundcard: have
2208 need 4096
2005-05-29 15:16:21.928 audio waiting for space on soundcard: have
3552 need 4096
2005-05-29 15:16:21.933 A/V diverged by 30 frames, extending frame to
keep audio in sync
2005-05-29 15:16:21.934 _AddSamples bytes=6144, used=489473,
free=22527, timecode=72392617
2005-05-29 15:16:21.934 _AddSamples bytes=6144, used=495617,
free=16383, timecode=72392581
2005-05-29 15:16:21.934 _AddSamples bytes=6144, used=501761,
free=10239, timecode=72392613
2005-05-29 15:16:21.934 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.934 Audio buffer overflow, audio data lost!
2005-05-29 15:16:21.937 Broadcasting free space avail


More information about the mythtv-users mailing list