[mythtv-users] 0.25 Live TV Video frame buffering failed too many times

[Mark Hutchinson]

On Thu, Mar 1, 2012 at 6:29 AM, Mark Hutchinson <markhsa at gmail.com> wrote:

>
>
> On Wed, Feb 29, 2012 at 12:06 PM, Neil Salstrom <salstrom at gmail.com>wrote:
>
>> I recently moved to master (0.25) to give it a try.  Overall it's been
>> a great move (did it after the feature freeze) and has been very
>> positive with the exception of Live TV.  It randomly (but often) will
>> drop back to to the menu giving a error of the video frame buffering
>> failed too many times.  This is using VDPAU and a GT430 card.  Here is
>> the details of the compile:
>>
>> mythfrontend --version
>> Please attach all output as a file in bug reports.
>> MythTV Version : v0.25pre-4702-g14ec737
>> MythTV Branch : master
>> Network Protocol : 72
>> Library API : 0.25.20120225-2
>> QT Version : 4.7.4
>> Options compiled in:
>>  linux profile use_hidesyms using_alsa using_pulse using_backend
>> using_bindings_perl using_bindings_python using_bindings_php using_dvb
>> using_frontend using_hdhomerun using_iptv using_libcrypto
>> using_libdns_sd using_libxml2 using_lirc using_mheg using_opengl_video
>> using_qtwebkit using_qtscript using_qtdbus using_v4l2 using_x11
>> using_xrandr using_xv using_bindings_perl using_bindings_python
>> using_bindings_php using_mythtranscode using_opengl using_vdpau
>> using_ffmpeg_threads using_live using_mheg using_libass using_libxml2
>>
>> First the logs are flooded with this:
>>
>> 2012-02-29 10:31:29.695116 N  Player(0): Waited 18849ms for video
>> buffers AALAAAAAAAAAfA
>> 2012-02-29 10:31:29.798261 N  Player(0): Waited 18952ms for video
>> buffers AALAAAAAAAAAfA
>> 2012-02-29 10:31:29.815125 I
>> RingBuf(/livetv/1021_20120229102849.mpg): Waited 4.0 seconds for data
>> to become available... 15564 < 32768
>> 2012-02-29 10:31:29.870632 I
>> RingBuf(/livetv/1021_20120229102849.mpg): Waited 4.0 seconds for data
>> to become available... 15564 < 32768
>> 2012-02-29 10:31:29.899937 N  Player(0): Waited 19053ms for video
>> buffers AALAAAAAAAAAfA
>> 2012-02-29 10:31:30.000804 N  Player(0): Waited 19154ms for video
>> buffers AALAAAAAAAAAfA
>> 2012-02-29 10:31:30.103200 N  Player(0): Waited 19257ms for video
>> buffers AALAAAAAAAAAfA
>> 2012-02-29 10:31:30.205927 N  Player(0): Waited 19359ms for video
>> buffers AALAAAAAAAAAfA
>>
>>
>> Followed by this right before dumping back to the frontend menu:
>>
>> 2012-02-29 10:31:34.623358 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:34.647622 I
>> RingBuf(/livetv/1021_20120229102849.mpg): Waited 1.0 seconds for data
>> to become available... 21148 < 32768
>> 2012-02-29 10:31:34.723691 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:34.823827 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:34.924009 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.024137 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.124288 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.224436 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.324580 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.424724 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.524877 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.625033 W  Player(0): Waited 100ms for decoder to pause
>> 2012-02-29 10:31:35.634445 I
>> RingBuf(/livetv/1021_20120229102849.mpg): Waited 2.0 seconds for data
>> to become available... 30736 < 32768
>> 2012-02-29 10:31:35.690255 I  Closing DB connection named 'DBManager7'
>> 2012-02-29 10:31:35.697355 I  VDPAU Painter: Clearing VDPAU painter cache.
>> 2012-02-29 10:31:35.701148 W  MythPainter: 1 images not yet de-allocated.
>> 2012-02-29 10:31:35.775329 I  Trying 1920x1080 0.000 Hz
>> 2012-02-29 10:31:35.775370 I  SwitchToGUI: Switched to 1920x1080 0.000 Hz
>> 2012-02-29 10:31:35.981661 I  Pulse: PulseAudio resume OK
>> 2012-02-29 10:31:36.142201 I  TV: Changing from WatchingLiveTV to None
>> 2012-02-29 10:31:36.143608 I  TV: Exiting main playback loop.
>> 2012-02-29 10:31:36.185395 I  TV: Attempting to change from None to
>> WatchingLiveTV
>>
>> Anything else someone would like me to do to track down the issue?
>>
>> Thanks,
>>
>> Neil
>> _______________________________________________
>> mythtv-users mailing list
>> mythtv-users at mythtv.org
>> http://www.mythtv.org/mailman/listinfo/mythtv-users
>>
>
> I am getting this behaviour as well in myth video.
>
> Details on this:
I am running .25-master (version below) and getting lockups on mythvideo
player.  Sometimes 10 min in, sometimes longer, but happens frequently.  I
have not seen any commits or tickets mentioning behaviour or fixes like
this, so I thought I should check here first and get thoughts?

On Fed16 frontend, I am seeing this in the mythfrontend log jus before the
lockup.

2012-02-29 19:17:15.779235 N  Player(0): Waited 11045ms for video buffers
AAALLAAfAAfAAAAAf
2012-02-29 19:17:15.885261 N  Player(0): Waited 11151ms for video buffers
AAALLAAfAAfAAAAAf
2012-02-29 19:17:15.947846 I  RingBuf(myth://
Videos at 192.168.0.9:6543/movie.2010.1080p.AC3.DTS-DMT/movie.1080p.AC3.DTS-DMT/movie.1080p.AC3.DTS-DMT.mkv):
Waited 11.8 seconds for data to become available... 7754 < 32768

Here is the version info:
mythtv-backend-0.25-0.1.git.4709.g7e6f5fa.fc16.x86_64

mythtv-frontend-0.25-0.1.git.4709.g7e6f5fa.fc16.x86_64
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://www.mythtv.org/pipermail/mythtv-users/attachments/20120301/d9f1f037/attachment.html