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: [EMAIL PROTECTED] ~]$ 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) [EMAIL PROTECTED] 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) [EMAIL PROTECTED] 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 _______________________________________________ mythtv-users mailing list mythtv-users@mythtv.org http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-users