[mythtv] Streaming Prebuffering Pause

Blammo blammo.doh at gmail.com
Tue Feb 15 04:49:15 UTC 2005


Bonzai!!


It's libmpeg2


disable it, and the problem goes away. Both with and without XvMC.

Here's the version I'm currently running:

mpeg2dec-0.4.0b

If anyone can tell me how to debug that specific lib I will, but that
is the culprit, at least in my case.




On Mon, 14 Feb 2005 21:32:52 -0700, Blammo <blammo.doh at gmail.com> wrote:
> Ok, I've been watching verbose output till my eyes are bleeding, and I
> have a couple things to add / clarifiy:
> 
> 1. With XvMC the lockups ONLY occur on my frontend when the OSD is
> fading out after a FFW / RW / etc.
> 
> 2. Without XvMC the lockups occur when FFW/RW.
> 
> I have a pile of -v debug, but here's the one thing that jumped out:
> 
> 2005-02-14 20:45:26.498 Timed out waiting for free video buffers.
> 
> Because the audio is showing "Paused" at this point, it doesn't appear
> to be an audio problem. I did try the patch suggested in another
> thread with no help.
> 
> I'm not able to get the data I wanted from GDB, call it inexperience,
> so unfortunately, the best I have is from -v playback from
> mythfrontend.
> 
> It doesn't appear to be a network or backend problem, that I can tell.
> I had mythbackend -v all and the logging simply stops. Once the
> frontend is killed, it shows the frontend disconnecting, so it doesn't
> appear the backend locked.
> 
> Anyway, here's the logs:
> 
> [mythtv at frontend1 ~]$ mythfrontend -v playback,osd,file,network
> 2005-02-14 21:25:20.849 mythfrontend version: 0.17.20050130-1 www.mythtv.org
> 2005-02-14 21:25:20.849 Enabled verbose msgs : important general
> playback osd file network
> 2005-02-14 21:25:21.092 Switching to square mode (Iulius)
> 2005-02-14 21:25:21.379 Registering Internal as a media playback plugin.
> 2005-02-14 21:25:21.415 Registering MythDVD DVD Media Handler as a media handler
> 2005-02-14 21:25:21.524 generating cache image for:
> /usr/local/share/mythtv/themes/default/blank.png
> 2005-02-14 21:25:26.545 All Programs
> 2005-02-14 21:25:27.118 Connecting to backend server:
> 192.168.2.222:6543 (try 1 of 50)
> 2005-02-14 21:25:27.119 write->10 21      MYTH_PROTO_VERSION 14:
> 2005-02-14 21:25:27.126 Using protocol version 14
> 2005-02-14 21:25:27.126 write->10 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:27.178 write->10 21      QUERY_RECORDINGS Play:
> 2005-02-14 21:25:27.468 write->13 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:27.481 write->14 74      ANN FileTransfer
> frontend1[]:[]/2081_...
> 2005-02-14 21:25:28.069 write->13 45      QUERY_FILETRANSFER
> 47[]:[]REQUEST_BLO...
> 2005-02-14 21:25:28.076 Read(): reqd=0, rcvd=0, rept=0, error=0
> 2005-02-14 21:25:28.076 write->13 30      QUERY_FILETRANSFER 47[]:[]DONE:
> 2005-02-14 21:25:28.083 write->10 632     QUERY_GENPIXMAP[]:[]CSI:
> Miami[]:[]Id...
> 2005-02-14 21:25:30.945 write->13 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:31.379 write->14 74      ANN FileTransfer
> frontend1[]:[]/2081_...
> 2005-02-14 21:25:31.388 write->13 49      QUERY_FILETRANSFER
> 47[]:[]REQUEST_BLO...
> 2005-02-14 21:25:31.413 Read(): reqd=28257, rcvd=28257, rept=28257, error=0
> 2005-02-14 21:25:31.413 write->13 30      QUERY_FILETRANSFER 47[]:[]DONE:
> 2005-02-14 21:25:31.843 write->13 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:31.907 write->14 74      ANN FileTransfer
> frontend1[]:[]/1015_...
> 2005-02-14 21:25:31.942 write->13 49      QUERY_FILETRANSFER
> 47[]:[]REQUEST_BLO...
> 2005-02-14 21:25:31.960 Read(): reqd=32601, rcvd=32601, rept=32601, error=0
> 2005-02-14 21:25:31.960 write->13 30      QUERY_FILETRANSFER 47[]:[]DONE:
> 2005-02-14 21:25:31.977 24      ANN Playback frontend1 1
> 2005-02-14 21:25:33.110 write->13 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:33.128 write->14 74      ANN FileTransfer
> frontend1[]:[]/2094_...
> 2005-02-14 21:25:33.137 write->13 49      QUERY_FILETRANSFER
> 47[]:[]REQUEST_BLO...
> 2005-02-14 21:25:33.145 Read(): reqd=25410, rcvd=25410, rept=25410, error=0
> 2005-02-14 21:25:33.145 write->13 30      QUERY_FILETRANSFER 47[]:[]DONE:
> 2005-02-14 21:25:34.174 write->13 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:34.206 write->14 74      ANN FileTransfer
> frontend1[]:[]/2081_...
> 2005-02-14 21:25:34.235 write->13 49      QUERY_FILETRANSFER
> 47[]:[]REQUEST_BLO...
> 2005-02-14 21:25:34.243 Read(): reqd=18855, rcvd=18855, rept=18855, error=0
> 2005-02-14 21:25:34.243 write->13 30      QUERY_FILETRANSFER 47[]:[]DONE:
> 2005-02-14 21:25:36.171 write->13 24      ANN Playback frontend1 0:
> 2005-02-14 21:25:36.470 write->14 74      ANN FileTransfer
> frontend1[]:[]/1005_...
> 2005-02-14 21:25:36.577 write->13 49      QUERY_FILETRANSFER
> 47[]:[]REQUEST_BLO...
> 2005-02-14 21:25:36.585 Read(): reqd=25498, rcvd=25498, rept=25498, error=0
> 2005-02-14 21:25:36.585 write->13 30      QUERY_FILETRANSFER 47[]:[]DONE:
> 2005-02-14 21:25:36.801 write->10 598     QUERY_CHECKFILE[]:[]CSI:
> Crime Scene ...
> 2005-02-14 21:25:36.942 AVFD
> 2005-02-14 21:25:36.942 AVFD: Opening Stream #0: codec id 2
> 2005-02-14 21:25:36.944 Using libmpeg2 for video decoding
> 2005-02-14 21:25:36.945 detectInterlace(Detect Scan, Detect Scan,
> 29.97, 480) ->Interlaced Scan
> 2005-02-14 21:25:36.945 Interlaced: Interlaced Scan  video_height: 480
>  fps: 29.97
> 2005-02-14 21:25:36.945 AVFD: Looking for decoder for 2
> 2005-02-14 21:25:36.945 AVFD
> 2005-02-14 21:25:36.945 AVFD: Opening Stream #1: codec id 86016
> 2005-02-14 21:25:36.945 AVFD: Looking for decoder for 86016
> 2005-02-14 21:25:36.947 Estimated bitrate = 16384
> 2005-02-14 21:25:37.218 Position map filled from DB to: 7184
> 2005-02-14 21:25:37.218 SyncPositionMap prerecorded, from DB: 7185 entries
> 2005-02-14 21:25:37.219 Position map found
> 2005-02-14 21:25:37.224 Opening audio device '/dev/adsp'.
> 2005-02-14 21:25:37.225 Opening OSS audio device '/dev/adsp'.
> 2005-02-14 21:25:37.236 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
> 2005-02-14 21:25:37.241 Using XV port 145
> 2005-02-14 21:25:37.245 Image size. dispxoff 111, dispyoff: 0,
> dispwoff: 666, disphoff: 508
> 2005-02-14 21:25:37.245 Image size. imgx 0, imgy: 0, imgw: 720, imgh: 480
> 2005-02-14 21:25:37.656 Realtime priority would require SUID as root.
> 2005-02-14 21:25:37.657 Changing from None to WatchingPreRecorded
> 2005-02-14 21:25:37.667 Using deinterlace method bobdeint
> 2005-02-14 21:25:37.768 nVidiaVideoSync: VBlank ioctl did not work,
> unimplemented in this driver?
> 2005-02-14 21:25:37.768 DRMVideoSync: Could not open device
> /dev/dri/card0, No such file or directory
> 2005-02-14 21:25:37.768 Using audio as timebase
> 2005-02-14 21:25:37.768 Video timing method: RTC
> 2005-02-14 21:25:37.768 Refresh rate: 16663, frame interval: 33366
> 2005-02-14 21:25:37.769 waiting for prebuffer...
> 'video_output' mean = '33528.13', std. dev. = '1778.35', fps = '29.83'
> 'video_output' mean = '33360.60', std. dev. = '384.26', fps = '29.98'
> 'video_output' mean = '33354.05', std. dev. = '359.64', fps = '29.98'
> 'video_output' mean = '33363.73', std. dev. = '368.82', fps = '29.97'
> 'video_output' mean = '33360.67', std. dev. = '369.68', fps = '29.98'
> 'video_output' mean = '33363.49', std. dev. = '365.59', fps = '29.97'
> 
> <at this point, the video freezes, and the "prebuffer" messages go by
> at 99 lines a second (figuratively)
> 
> 2005-02-14 21:25:59.056 waiting for prebuffer...
> 2005-02-14 21:26:01.695 prebuffering pause
> 2005-02-14 21:26:01.695 waiting for prebuffer...
> 2005-02-14 21:26:01.707 prebuffering pause
> 2005-02-14 21:26:01.707 waiting for prebuffer...
> 2005-02-14 21:26:01.718 prebuffering pause
> 2005-02-14 21:26:01.718 waiting for prebuffer...
> 2005-02-14 21:26:01.729 prebuffering pause
> 2005-02-14 21:26:01.729 waiting for prebuffer...
> 2005-02-14 21:26:01.740 prebuffering pause
> 
> <ad nausem>
> 
> If any of the devs can tell me either additional tests to run,
> features to flip off/on, etc, I will HAPPILY provide it.
> 
> Here's the snippet of code we seem to be running into, or at least
> that's reporting:
> 
> NuppelVideoPlayer.cpp
> 
> if (!videoOutput->EnoughFreeFrames() && !unsafe)
>         {
>             //cout << "waiting for video buffer to drain.\n";
>             setPrebuffering(false);
>             if (!videoOutput->availableVideoBuffersWait()->wait(10))
>             {
>                 if (++videobuf_retries >= 200)
>                 {
>                     VERBOSE(VB_IMPORTANT, "Timed out waiting for free
> video buffers.");
>                     if (videosync==NULL && tryingVideoSync)
>                     {
>                         VERBOSE(VB_IMPORTANT, "Attempting video sync
> thread restart");
>                         //pthread_create(&output_video, NULL,
> kickoffOutputVideoLoop, this);
>                     }
>                     videobuf_retries = 0;
>                 }
>                 return false;
>             }
> 
> On Mon, 14 Feb 2005 12:05:02 -0500, Bruce C. Dillahunty
> <bdillahu at peachbush.com> wrote:
> > Brian Foddy wrote:
> > > On Sunday 13 February 2005 09:11 pm, Blammo [doh] wrote:
> > >
> > >>Still happening here.. Had to shut off XvMC to get it to resolve.
> > >>Never happened under 0.16
> > >>
> >
> > Me to... nvidia setup... pause with XvMC enabled hangs the frontend...
> > really acts like things that update the OSD hang the frontend.
> >
> > Bruce
> >
> > _______________________________________________
> > mythtv-dev mailing list
> > mythtv-dev at mythtv.org
> > http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-dev
> >
>


More information about the mythtv-dev mailing list