[mythtv] Re: prebuffer audio related?

[jeff at harmonyintegration.com]

Hello everyone.  I've been playing around with Myth since August. The goal
was to build my own Video On Demand system.  Building an ondemand library
of content has grown into using myth modules and HD.  I'm addicted!

Anyway this thread relates to my system and I though I might be able to
provide a bit more insite.

First my system info:

HW:
ECS 484-p motherboard (Onboard audio Intel ICH5 - Many headaches here)
Pentium 4 2.4
512 MB
PVR-250 (Tuner type 8)
HD3000
2 - SATA drives, LVM video partition of 433GB (Onboard Intel ICH5 SATA
Controler)
Ensoniq 5880 AudioPCI (Sound Blaster 16bit replacement for onboard ICH5)
FX5200 (DVI connected to Sony HDTV)

SW:
Debian 2.6.9 custom kernel
Myth .16 from CVS of about 12/6/04
ivtv-0.1.10-pre2-ck115i
HD-3000 vers.04 (Increased buffer in cx88-atsc.c to #define BUF_DEFAULT
188*1536)
alsa-driver-1.0.5a (with card snd_ens1371)
lirc-0.7.0pre6
NVIDIA-Linux-x86-1.0-6629

Other:
ALSA:front (No OSS emulation)


Generally things are great.  I do see these messages in the frontend log
when watching live TV and occasionally during playback of SD or HD
recorded files.

ABC here in Denver is 720p.  Here is an bit from the log.


2004-12-26 21:19:29.200 mythfrontend version: 0.16.20041207-1 www.mythtv.org
2004-12-26 21:19:29.213 Enabled verbose msgs : important general playback
2004-12-26 21:19:29.221 Could not connect to LCDd: connection refused.
2004-12-26 21:19:30.086 Joystick disabled.
2004-12-26 21:19:30.122 Registering Internal as a media playback plugin.
Failed to run 'cdrecord --scanbus'
2004-12-26 21:19:30.419 Registering MythMusic Media Handler as a media
handler
2004-12-26 21:19:35.972 Connecting to backend server: 127.0.0.1:6543 (try
1 of 5)
2004-12-26 21:19:35.978 Using protocol version 14
2004-12-26 21:19:36.009 Using protocol version 14
2004-12-26 21:19:36.014 Using protocol version 14
adding pes stream at pid 0x21 with type 2
adding pes stream at pid 0x24 with type 129
2004-12-26 21:19:41.059 AVFD
2004-12-26 21:19:41.059 AVFD: Opening Stream #0: codec id 2
2004-12-26 21:19:41.059 detectInterlace(Detect Scan, Detect Scan, 59.9401,
720) ->Progressive Scan
2004-12-26 21:19:41.059 Interlaced: Progressive Scan  video_height: 720 
fps: 59.9401
2004-12-26 21:19:41.060 AVFD: Looking for decoder for 2
2004-12-26 21:19:41.067 AVFD
2004-12-26 21:19:41.067 AVFD: Opening Stream #1: codec id 86020
2004-12-26 21:19:41.067 AVFD: Looking for decoder for 86020
2004-12-26 21:19:41.071 Initializing audio parms from stream #0.
2004-12-26 21:19:41.072 Estimated bitrate = 384000
2004-12-26 21:19:41.077 Filling position map from 0 to 229
2004-12-26 21:19:41.087 Position map filled from Encoder to: 215
2004-12-26 21:19:41.087 SyncPositionMap liveTV, from Encoder: 8 entries
2004-12-26 21:19:41.088 detectInterlace(Ignore Scan, Progressive Scan,
59.9401, 720) ->Progressive Scan
2004-12-26 21:19:41.088 Interlaced: Progressive Scan  video_height: 720 
fps: -1
2004-12-26 21:19:41.089 Partial position map found
2004-12-26 21:19:41.092 Opening audio device 'front'.
2004-12-26 21:19:41.149 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
2004-12-26 21:19:41.153 Using XV port 107
2004-12-26 21:19:41.156 Image size. dispxoff 0, dispyoff: 0, dispwoff:
960, disphoff: 539
2004-12-26 21:19:41.156 Image size. imgx 0, imgy: 0, imgw: 1280, imgh: 720
2004-12-26 21:19:41.518 Using realtime priority.
2004-12-26 21:19:41.532 Changing from None to WatchingLiveTV
2004-12-26 21:19:41.619 nVidiaVideoSync: VBlank ioctl did not work,
unimplemented in this driver?
2004-12-26 21:19:41.619 DRMVideoSync: Could not open device
/dev/dri/card0, No such file or directory
2004-12-26 21:19:41.619 RTCVideoSync: Could not set RTC frequency,
Permission denied.
2004-12-26 21:19:41.619 Using audio as timebase
2004-12-26 21:19:41.619 Video timing method: USleep with busy wait
2004-12-26 21:19:41.619 Refresh rate: 16681, frame interval: 16683
2004-12-26 21:19:41.619 waiting for prebuffer...
2004-12-26 21:19:41.738 A/V diverged by 8.24192 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.771 A/V diverged by 14.2435 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.804 A/V diverged by 18.475 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.838 A/V diverged by 21.4238 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.871 A/V diverged by 23.3656 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.904 A/V diverged by 24.5673 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.938 A/V diverged by 25.2288 frames, extending frame to
keep audio in sync
2004-12-26 21:19:41.971 A/V diverged by 25.4852 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.005 A/V diverged by 25.4077 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.038 A/V diverged by 25.0948 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.071 A/V diverged by 24.6354 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.105 A/V diverged by 24.0361 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.138 A/V diverged by 23.3318 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.171 A/V diverged by 22.5639 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.205 A/V diverged by 21.7182 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.238 A/V diverged by 20.8442 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.271 A/V diverged by 19.9489 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.305 A/V diverged by 19.0077 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.338 A/V diverged by 18.062 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.372 A/V diverged by 17.113 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.405 A/V diverged by 16.1315 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.438 A/V diverged by 15.1556 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.472 A/V diverged by 14.1689 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.505 A/V diverged by 13.1892 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.549 A/V diverged by 12.1996 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.572 A/V diverged by 11.0378 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.605 A/V diverged by 10.0916 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.638 A/V diverged by 9.12714 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.672 A/V diverged by 8.14907 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.705 A/V diverged by 7.17575 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.738 A/V diverged by 6.19097 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.771 A/V diverged by 5.21267 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.805 A/V diverged by 4.22418 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.838 A/V diverged by 3.22808 frames, extending frame to
keep audio in sync
2004-12-26 21:19:42.875 WriteAudio: buffer underrun

###########################################################
#   Here is another bit from the log.
###########################################################

2004-12-26 22:49:16.016 Changing from None to None
2004-12-26 22:49:19.651 Using protocol version 14
adding pes stream at pid 0x21 with type 2
adding pes stream at pid 0x24 with type 129
2004-12-26 22:49:24.729 AVFD
2004-12-26 22:49:24.729 AVFD: Opening Stream #0: codec id 2
2004-12-26 22:49:24.729 detectInterlace(Detect Scan, Detect Scan, 59.9401,
720) ->Progressive Scan
2004-12-26 22:49:24.729 Interlaced: Progressive Scan  video_height: 720 
fps: 59.9401
2004-12-26 22:49:24.730 AVFD: Looking for decoder for 2
2004-12-26 22:49:24.730 AVFD
2004-12-26 22:49:24.730 AVFD: Opening Stream #1: codec id 86020
2004-12-26 22:49:24.730 AVFD: Looking for decoder for 86020
2004-12-26 22:49:24.731 Initializing audio parms from stream #0.
2004-12-26 22:49:24.732 Estimated bitrate = 384000
2004-12-26 22:49:24.737 Filling position map from 0 to 235
2004-12-26 22:49:24.747 Position map filled from Encoder to: 215
2004-12-26 22:49:24.747 SyncPositionMap liveTV, from Encoder: 8 entries
2004-12-26 22:49:24.747 detectInterlace(Ignore Scan, Progressive Scan,
59.9401, 720) ->Progressive Scan
2004-12-26 22:49:24.747 Interlaced: Progressive Scan  video_height: 720 
fps: -1
2004-12-26 22:49:24.748 Partial position map found
2004-12-26 22:49:24.750 Opening audio device 'front'.
2004-12-26 22:49:24.757 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
2004-12-26 22:49:24.761 Using XV port 107
2004-12-26 22:49:24.764 Image size. dispxoff 0, dispyoff: 0, dispwoff:
960, disphoff: 539
2004-12-26 22:49:24.764 Image size. imgx 0, imgy: 0, imgw: 1280, imgh: 720
2004-12-26 22:49:25.102 Using realtime priority.
2004-12-26 22:49:25.117 Changing from None to WatchingLiveTV
2004-12-26 22:49:25.202 nVidiaVideoSync: VBlank ioctl did not work,
unimplemented in this driver?
2004-12-26 22:49:25.203 DRMVideoSync: Could not open device
/dev/dri/card0, No such file or directory
2004-12-26 22:49:25.203 RTCVideoSync: Could not set RTC frequency,
Permission denied.
2004-12-26 22:49:25.204 Using video as timebase
2004-12-26 22:49:25.204 Video timing method: USleep with busy wait
2004-12-26 22:49:25.204 Refresh rate: 16681, frame interval: 16683
2004-12-26 22:49:25.204 waiting for prebuffer...
2004-12-26 22:49:25.279 A/V diverged by 8.13703 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.313 A/V diverged by 14.2398 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.357 A/V diverged by 18.5621 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.380 A/V diverged by 21.3842 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.413 A/V diverged by 23.4109 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.446 A/V diverged by 24.6912 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.479 A/V diverged by 25.3816 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.513 A/V diverged by 25.6747 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.546 A/V diverged by 25.6547 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.580 A/V diverged by 25.385 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.613 A/V diverged by 24.9279 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.646 A/V diverged by 24.3454 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.680 A/V diverged by 23.6387 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.713 A/V diverged by 22.854 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.746 A/V diverged by 22.0257 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.780 A/V diverged by 21.1497 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.813 A/V diverged by 20.238 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.847 A/V diverged by 19.3144 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.880 A/V diverged by 18.367 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.913 A/V diverged by 17.4017 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.947 A/V diverged by 16.4229 frames, extending frame to
keep audio in sync
2004-12-26 22:49:25.980 A/V diverged by 15.4491 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.013 A/V diverged by 14.449 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.047 A/V diverged by 13.4442 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.080 A/V diverged by 12.4508 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.114 A/V diverged by 11.451 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.147 A/V diverged by 10.4464 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.180 A/V diverged by 9.45316 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.225 A/V diverged by 8.42354 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.247 A/V diverged by 7.23173 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.280 A/V diverged by 6.27795 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.313 A/V diverged by 5.32284 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.347 A/V diverged by 4.33675 frames, extending frame to
keep audio in sync
2004-12-26 22:49:26.380 A/V diverged by 3.35743 frames, extending frame to
keep audio in sync
'video_output' mean = '22332.31', std. dev. = '8306.30', fps = '44.78'
2004-12-26 22:49:28.868 positionMap[ 216 ] == 6001336.
'video_output' mean = '16688.14', std. dev. = '965.00', fps = '59.92'
2004-12-26 22:49:29.318 positionMap[ 243 ] == 6750704.
2004-12-26 22:49:29.768 positionMap[ 270 ] == 7507216.
2004-12-26 22:49:30.217 positionMap[ 297 ] == 8231956.
2004-12-26 22:49:30.668 positionMap[ 324 ] == 9001064
'video_output' mean = '16675.66', std. dev. = '444.29', fps = '59.97'
2004-12-26 22:49:31.119 positionMap[ 351 ] == 9734076.
2004-12-26 22:49:31.569 positionMap[ 378 ] == 10487580.
2004-12-26 22:49:32.020 positionMap[ 405 ] == 11273984.
2004-12-26 22:49:32.470 positionMap[ 432 ] == 12090844.
'video_output' mean = '16692.98', std. dev. = '1373.49', fps = '59.91'
2004-12-26 22:49:32.920 positionMap[ 459 ] == 12751664.
2004-12-26 22:49:33.371 positionMap[ 486 ] == 13483548.
2004-12-26 22:49:33.821 positionMap[ 513 ] == 14246076.
'video_output' mean = '16672.16', std. dev. = '806.29', fps = '59.98'
2004-12-26 22:49:34.272 positionMap[ 540 ] == 14984540.
2004-12-26 22:49:34.722 positionMap[ 567 ] == 15727516.
2004-12-26 22:49:35.172 positionMap[ 594 ] == 16494180.
2004-12-26 22:49:35.624 positionMap[ 621 ] == 17189780.
'video_output' mean = '16676.89', std. dev. = '692.94', fps = '59.96'
2004-12-26 22:49:36.074 positionMap[ 648 ] == 17985960.
2004-12-26 22:49:36.525 positionMap[ 675 ] == 18735516.
2004-12-26 22:49:36.974 positionMap[ 702 ] == 19506880.
2004-12-26 22:49:37.425 positionMap[ 729 ] == 20241020.
'video_output' mean = '16679.34', std. dev. = '508.27', fps = '59.95'
2004-12-26 22:49:37.875 positionMap[ 756 ] == 21002044.
2004-12-26 22:49:38.337 positionMap[ 783 ] == 21754232.
2004-12-26 22:49:38.777 positionMap[ 810 ] == 22500592.



>From here everything seems to click along fine until I change the channel.
 Then the "A/V diverged" messages come back and don't seem to go away
UNTIL I EXIT TO THE GUI AND HIT LIVE TV AGAIN.  Then everything is fine
until the next channel change.  This goes for all 4 HD channels I get. 
Once I exit and go back they seem to play fine with only occasional (once
every 10 minutes or so) "A/V diverged" messages.

CPU usage is as follows:

1080i - 7-10% free
720p - 30-33% free

My Intel audio controler didn't like 2.6.9 and ALSA.  I only got one
channel (left) and plenty of the "WriteAudio: buffer underrun" messages. 
I still see these messages occasionally with the SB audio card.

So again the processes is:

1. Watch live TV of HD channel
2. Change channel to another HD channel (Audio/Video diverge)
3. Exit to UI
4. Watch TV again (All is good)
5. Repeat for next channel change

I know this is a bit long but hope it helps.  Please let me know if you
need more info.

BTW - To Isaac and all, Great job.  I've worked in VOD for the past 7
years and have seen many UI's.  None have this level of feature set or nav
structure.