Mailing List Archive: MythTV: Users

Failed to get A/V sync when using VDPAU

Index | Next | Previous | View Threaded

peper03 at yahoo

Aug 30, 2012, 2:12 PM

Post #1 of 4 (545 views)
Permalink

Failed to get A/V sync when using VDPAU

Hi,

Is anyone else having getting the error message 'Failed to get A/V sync'
when trying to play back a recording? I don't get it all the time but
it's often enough that it's irritating. It doesn't seem to matter
whether I select HD or SD material.

I'm running Mythbuntu 12.04 as a combined BE/FE with Myth
v0.25.2-16-gd519276. The graphics card is an NVidia GeForce 8400 GS
using the 295.40 drivers.

Here's an excerpt from the frontend log:

Aug 30 21:19:57 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:987
(TV) TV: Creating TV object
Aug 30 21:19:57 dvr mythfrontend[2139]: N CoreContext
mythmainwindow.cpp:2591 (PauseIdleTimer) Resuming idle timer
Aug 30 21:19:57 dvr mythfrontend[2139]: N CoreContext
mythmainwindow.cpp:2586 (PauseIdleTimer) Suspending idle timer
Aug 30 21:19:57 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:1206
(Init) TV: Created TvPlayWindow.
Aug 30 21:19:57 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2121
(HandleStateChange) TV: Attempting to change from None to
WatchingPreRecorded
Aug 30 21:19:57 dvr mythfrontend[2139]: N CoreContext
audioplayer.cpp:167 (ReinitAudio) AudioPlayer: Enabling Audio
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x19d7b70,
id(H264) type(Video)
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:1960 (ScanStreams) AFD: codec MP2 has 2 channels
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x34bf430,
id(MP2) type(Audio)
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x7fb7840,
id(DVB_SUBTITLE) type(Subtitle)
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:1960 (ScanStreams) AFD: codec AC3 has 6 channels
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x50ca800,
id(AC3) type(Audio)
Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
audio/audiooutputbase.cpp:791 (Reconfigure) AO: Opening audio device
'iec958:CARD=Intel,DEV=0' ch 2(6) sr 48000 sf signed 16 bit reenc 1
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythpainter_ogl.cpp:62 (ClearCache) Clearing OpenGL painter cache.
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythrender_vdpau.cpp:1675 (CreatePresentationSurfaces) VDPAU: Created 2
output surfaces.
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythrender_vdpau.cpp:401 (Create) VDPAU: Created VDPAU render device
1920x1080
Aug 30 21:19:59 dvr mythfrontend[2139]: N CoreContext mythplayer.cpp:506
(CheckExtraAudioDecode) Player(4): Forcing decode extra audio option on
(Video method requires it).
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythplayer.cpp:1737 (InitAVSync) Player(4): Video timing method: USleep
with busy wait
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:5169
(StartPlayer) TV: Created player.
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2360
(HandleStateChange) TV: Changing from None to WatchingPreRecorded
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2451
(HandleStateChange) TV: Main UI disabled.
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:378
(StartTV) TV: Entering main playback loop.
Aug 30 21:19:59 dvr mythfrontend[2139]: I Decoder videoout_vdpau.cpp:627
(DrawSlice) VidOutVDPAU: Added 2 new buffers. New buffer size 16 (4
decode and 12 process)
Aug 30 21:19:59 dvr mythfrontend[2139]: E Decoder
mythrender_vdpau.cpp:734 (CreateDecoder) VDPAU: Error at
mythrender_vdpau.cpp:734 (#23, The system does not have enough resources
to complete the requested operation at this time.)
Aug 30 21:19:59 dvr mythfrontend[2139]: E Decoder videoout_vdpau.cpp:670
(DrawSlice) VidOutVDPAU: Failed to create decoder.
Aug 30 21:19:59 dvr mythfrontend[2139]: E Decoder videoout_vdpau.cpp:560
(DrawSlice) VidOutVDPAU: IsErrored() in DrawSlice
Aug 30 21:19:59 dvr mythfrontend[2139]: E CoreContext
videoout_vdpau.cpp:384 (ProcessFrame) VidOutVDPAU: IsErrored() in
ProcessFrame
Aug 30 21:19:59 dvr mythfrontend[2139]: E CoreContext
mythplayer.cpp:1782 (AVSync) Player(4): AVSync: Unknown error in
videoOutput, aborting playback.
Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2121
(HandleStateChange) TV: Attempting to change from WatchingPreRecorded to
None
Aug 30 21:19:59 dvr mythfrontend[2139]: W CoreContext
mythplayer.cpp:2958 (PauseDecoder) Player(4): Waited 100ms for decoder
to pause
Aug 30 21:20:09 mythfrontend[2139]: last message repeated 99 times
Aug 30 21:20:09 dvr mythfrontend[2139]: I CoreContext
mythpainter_vdpau.cpp:111 (ClearCache) VDPAU Painter: Clearing VDPAU
painter cache.
Aug 30 21:20:09 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2360
(HandleStateChange) TV: Changing from WatchingPreRecorded to None

The line that strikes me is:

The system does not have enough resources to complete the requested
operation at this time.)

from the driver. I would say 75-80% of the time everything works fine,
so the card is perfectly capable of handling playback.

It usually gets cleared up if I exit MythFrontend and start it again.
Sometimes that's not enough and I have to kill MythWelcome as well.

Is it possible that some VDPAU resources are sometimes not being cleaned
up properly?

In this particular case, we had been watching a recording and wanted to
watch another. The first recording had not been a problem. After it
finished, I moved around the menus a bit and then got this error when I
tried to start the next recording.

Occasionally, the popup 'Failed to get A/V sync' appears and
MythFrontend locks up completely. I have to kill the process to
continue. The only thing that seems to be different in this case is
that a tiny square appears in the top left corner of the popup, in case
that gives anyone a clue as to what may be going wrong.

If other traces are required I'll do my best to get them. I haven't
worked out yet exactly what causes this but it shouldn't take too long
before it re-occurs.

Any help/tips would be gratefully received!

Richard.
_______________________________________________
mythtv-users mailing list
mythtv-users [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-users

stephengrobertson at gmail

Aug 30, 2012, 2:42 PM

Post #2 of 4 (514 views)
Permalink

Re: Failed to get A/V sync when using VDPAU [In reply to]

On 30 Aug 2012 22:12, "Richard" <peper03 [at] yahoo> wrote:
>
> Hi,
>
> Is anyone else having getting the error message 'Failed to get A/V sync'
when trying to play back a recording? I don't get it all the time but it's
often enough that it's irritating. It doesn't seem to matter whether I
select HD or SD material.
>
> I'm running Mythbuntu 12.04 as a combined BE/FE with Myth
v0.25.2-16-gd519276. The graphics card is an NVidia GeForce 8400 GS using
the 295.40 drivers.
>
> Here's an excerpt from the frontend log:
>
> Aug 30 21:19:57 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:987
(TV) TV: Creating TV object
> Aug 30 21:19:57 dvr mythfrontend[2139]: N CoreContext
mythmainwindow.cpp:2591 (PauseIdleTimer) Resuming idle timer
> Aug 30 21:19:57 dvr mythfrontend[2139]: N CoreContext
mythmainwindow.cpp:2586 (PauseIdleTimer) Suspending idle timer
> Aug 30 21:19:57 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:1206
(Init) TV: Created TvPlayWindow.
> Aug 30 21:19:57 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2121
(HandleStateChange) TV: Attempting to change from None to
WatchingPreRecorded
> Aug 30 21:19:57 dvr mythfrontend[2139]: N CoreContext audioplayer.cpp:167
(ReinitAudio) AudioPlayer: Enabling Audio
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x19d7b70,
id(H264) type(Video)
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:1960 (ScanStreams) AFD: codec MP2 has 2 channels
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x34bf430, id(MP2)
type(Audio)
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x7fb7840,
id(DVB_SUBTITLE) type(Subtitle)
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:1960 (ScanStreams) AFD: codec AC3 has 6 channels
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
avformatdecoder.cpp:2102 (ScanStreams) AFD: Opened codec 0x50ca800, id(AC3)
type(Audio)
> Aug 30 21:19:58 dvr mythfrontend[2139]: I CoreContext
audio/audiooutputbase.cpp:791 (Reconfigure) AO: Opening audio device
'iec958:CARD=Intel,DEV=0' ch 2(6) sr 48000 sf signed 16 bit reenc 1
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythpainter_ogl.cpp:62 (ClearCache) Clearing OpenGL painter cache.
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythrender_vdpau.cpp:1675 (CreatePresentationSurfaces) VDPAU: Created 2
output surfaces.
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext
mythrender_vdpau.cpp:401 (Create) VDPAU: Created VDPAU render device
1920x1080
> Aug 30 21:19:59 dvr mythfrontend[2139]: N CoreContext mythplayer.cpp:506
(CheckExtraAudioDecode) Player(4): Forcing decode extra audio option on
(Video method requires it).
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext mythplayer.cpp:1737
(InitAVSync) Player(4): Video timing method: USleep with busy wait
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:5169
(StartPlayer) TV: Created player.
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2360
(HandleStateChange) TV: Changing from None to WatchingPreRecorded
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2451
(HandleStateChange) TV: Main UI disabled.
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:378
(StartTV) TV: Entering main playback loop.
> Aug 30 21:19:59 dvr mythfrontend[2139]: I Decoder videoout_vdpau.cpp:627
(DrawSlice) VidOutVDPAU: Added 2 new buffers. New buffer size 16 (4 decode
and 12 process)
> Aug 30 21:19:59 dvr mythfrontend[2139]: E Decoder
mythrender_vdpau.cpp:734 (CreateDecoder) VDPAU: Error at
mythrender_vdpau.cpp:734 (#23, The system does not have enough resources to
complete the requested operation at this time.)
> Aug 30 21:19:59 dvr mythfrontend[2139]: E Decoder videoout_vdpau.cpp:670
(DrawSlice) VidOutVDPAU: Failed to create decoder.
> Aug 30 21:19:59 dvr mythfrontend[2139]: E Decoder videoout_vdpau.cpp:560
(DrawSlice) VidOutVDPAU: IsErrored() in DrawSlice
> Aug 30 21:19:59 dvr mythfrontend[2139]: E CoreContext
videoout_vdpau.cpp:384 (ProcessFrame) VidOutVDPAU: IsErrored() in
ProcessFrame
> Aug 30 21:19:59 dvr mythfrontend[2139]: E CoreContext mythplayer.cpp:1782
(AVSync) Player(4): AVSync: Unknown error in videoOutput, aborting playback.
> Aug 30 21:19:59 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2121
(HandleStateChange) TV: Attempting to change from WatchingPreRecorded to
None
> Aug 30 21:19:59 dvr mythfrontend[2139]: W CoreContext mythplayer.cpp:2958
(PauseDecoder) Player(4): Waited 100ms for decoder to pause
> Aug 30 21:20:09 mythfrontend[2139]: last message repeated 99 times
> Aug 30 21:20:09 dvr mythfrontend[2139]: I CoreContext
mythpainter_vdpau.cpp:111 (ClearCache) VDPAU Painter: Clearing VDPAU
painter cache.
> Aug 30 21:20:09 dvr mythfrontend[2139]: I CoreContext tv_play.cpp:2360
(HandleStateChange) TV: Changing from WatchingPreRecorded to None
>
>
> The line that strikes me is:
>
> The system does not have enough resources to complete the requested
operation at this time.)
>
> from the driver. I would say 75-80% of the time everything works fine,
so the card is perfectly capable of handling playback.
>
> It usually gets cleared up if I exit MythFrontend and start it again.
Sometimes that's not enough and I have to kill MythWelcome as well.
>
> Is it possible that some VDPAU resources are sometimes not being cleaned
up properly?
>
> In this particular case, we had been watching a recording and wanted to
watch another. The first recording had not been a problem. After it
finished, I moved around the menus a bit and then got this error when I
tried to start the next recording.
>
> Occasionally, the popup 'Failed to get A/V sync' appears and MythFrontend
locks up completely. I have to kill the process to continue. The only
thing that seems to be different in this case is that a tiny square appears
in the top left corner of the popup, in case that gives anyone a clue as to
what may be going wrong.
>
> If other traces are required I'll do my best to get them. I haven't
worked out yet exactly what causes this but it shouldn't take too long
before it re-occurs.
>
> Any help/tips would be gratefully received!
>
> Richard.

Nothing very useful to add other than yes I see that too. Though I'm on
ubuntu 12.04 and 0.26. I've not had a chance to investigate very far.

Stephen

peper03 at yahoo

Sep 9, 2012, 11:22 AM

Post #3 of 4 (460 views)
Permalink

Re: Failed to get A/V sync when using VDPAU [In reply to]

On 30/08/12 23:42, Stephen Robertson wrote:
>
> On 30 Aug 2012 22:12, "Richard" <peper03 [at] yahoo
> <mailto:peper03 [at] yahoo>> wrote:
> >
> > Hi,
> >
> > Is anyone else having getting the error message 'Failed to get A/V
> sync' when trying to play back a recording? I don't get it all the time
> but it's often enough that it's irritating. It doesn't seem to matter
> whether I select HD or SD material.
> >
> > I'm running Mythbuntu 12.04 as a combined BE/FE with Myth
> v0.25.2-16-gd519276. The graphics card is an NVidia GeForce 8400 GS
> using the 295.40 drivers.
> >

<long log snipped>

> >
> > The line that strikes me is:
> >
> > The system does not have enough resources to complete the requested
> operation at this time.)
> >
> > from the driver. I would say 75-80% of the time everything works
> fine, so the card is perfectly capable of handling playback.
> >
> > It usually gets cleared up if I exit MythFrontend and start it again.
> Sometimes that's not enough and I have to kill MythWelcome as well.
> >
> > Is it possible that some VDPAU resources are sometimes not being
> cleaned up properly?
> >
> > In this particular case, we had been watching a recording and wanted
> to watch another. The first recording had not been a problem. After it
> finished, I moved around the menus a bit and then got this error when I
> tried to start the next recording.
> >
> > Occasionally, the popup 'Failed to get A/V sync' appears and
> MythFrontend locks up completely. I have to kill the process to
> continue. The only thing that seems to be different in this case is
> that a tiny square appears in the top left corner of the popup, in case
> that gives anyone a clue as to what may be going wrong.
> >
> > If other traces are required I'll do my best to get them. I haven't
> worked out yet exactly what causes this but it shouldn't take too long
> before it re-occurs.
> >
> > Any help/tips would be gratefully received!
> >
> > Richard.
>
> Nothing very useful to add other than yes I see that too. Though I'm on
> ubuntu 12.04 and 0.26. I've not had a chance to investigate very far.

As the responses have been overwhelming, there are obviously lots of
people having this problem :)

I *do* seem to have found a cure if not the reason directly. The paint
engine under Setup->Appearance was set to 'Auto'. I tried changing this
to 'Qt' a day or two ago and since then have not had the error message
any more (for the record and for anyone in future who searches, the
error message was 'Failed to initialize A/V sync').

I'm aware that my video card is not the beefiest around but it seems odd
that it sometimes works and sometimes not (although it seems to have
become less reliable in the last week or two, which makes no sense
because I've not consciously updated anything that could/should affect
it). Playing back using OpenGL worked but put a much bigger load on the
CPU and I found I couldn't play HD recordings back above about 1.1x
speed, whereas 1.3x or more is no problem with VDPAU.

Anyway, if others *are* having this problem, try changing the paint
engine setting.

Richard.
_______________________________________________
mythtv-users mailing list
mythtv-users [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-users

peper03 at yahoo

Sep 17, 2012, 11:39 AM

Post #4 of 4 (424 views)
Permalink

Re: Failed to get A/V sync when using VDPAU [In reply to]

On 09/09/12 20:22, Richard wrote:
> I *do* seem to have found a cure if not the reason directly. The paint
> engine under Setup->Appearance was set to 'Auto'. I tried changing this
> to 'Qt' a day or two ago and since then have not had the error message
> any more (for the record and for anyone in future who searches, the
> error message was 'Failed to initialize A/V sync').
>
> I'm aware that my video card is not the beefiest around but it seems odd
> that it sometimes works and sometimes not (although it seems to have
> become less reliable in the last week or two, which makes no sense
> because I've not consciously updated anything that could/should affect
> it). Playing back using OpenGL worked but put a much bigger load on the
> CPU and I found I couldn't play HD recordings back above about 1.1x
> speed, whereas 1.3x or more is no problem with VDPAU.

Ok, I've had another light poke around as the latest version of the
Mythbuntu theme doesn't look at all good with QT.

Parsing the output from nvidia-sli to get the memory usage of the
graphics card, the problem *seems* to be caused by insufficient free memory.

When using OpenGL for the menus and VDPAU for video, and everything
works, approx. 220MB are in use. Before I start playback, graphics
memory usage is usually around 150MB. Moving round the the menus (e.g.
from Watch Recordings to looking at Recording Rules and back to Watch
Recordings), the baseline memory usage is higher (say around 180MB).
This seems to be when playback fails. As the card only has 256MB, these
last 30MB or so become critical.

How are textures created and released? This problem doesn't always
occur and sometimes playback still works in spite of higher memory usage
(of course you only need to have 1 byte too little for it to fail).
Exiting playback seems to help bring the memory usage back down again,
but not always (or not enough).

Is there some sort of delayed garbage collection for graphical widgets,
which would mean that resources are not necessarily freed immediately?

I'm guessing that the QT engine simply needs slightly less memory, or
frees the memory more punctually and that's why that works.

I'm happy to poke around in the code but I've no idea of the
architecture, so I don't really know what I should be looking for.

Any ideas/hints etc. are gratefully received!

Richard.

_______________________________________________
mythtv-users mailing list
mythtv-users [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-users

Index | Next | Previous | View Threaded

Interested in having your list archived? Contact Gossamer Threads