[mythtv-users] Audio glitches on EPG and local commercals
John Morris
jmorris at beau.org
Sun May 6 06:29:55 UTC 2012
On Sun, 2012-05-06 at 15:17 +1000, Jean-Yves Avenard wrote:
> On 6 May 2012 12:55, John Morris <jmorris at beau.org> wrote:
> > Lots of
> >
> > AO: Pause 1
> >
> > quickly followed by
> >
> > AO: Pause 0
> >
> > Eh? It is pausing the audio intentionally? Or am I reading that right?
>
> Audio is paused during playback if it didn't manage to decode enough
> video frames and is in need to catch up.
>
> You would have seen errors before that.
>
> try running myth with -v audio,playback and provide a full log
I was already capturing important, audio, playback so here is the area
right before pressing Guide to a few seconds after:
2012-05-06 01:07:38.251 Player(6): 2400 progressive frames seen.
'video_output' mean = '16679.77', std. dev. = '84.99', fps = '59.95'
'video_output' mean = '16680.11', std. dev. = '239.33', fps = '59.95'
'video_output' mean = '16679.75', std. dev. = '81.71', fps = '59.95'
'video_output' mean = '16680.02', std. dev. = '196.19', fps = '59.95'
2012-05-06 01:07:44.925 Player(6): 2800 progressive frames seen.
'video_output' mean = '16678.37', std. dev. = '741.90', fps = '59.96'
2012-05-06 01:07:45.291 ScreenSaverX11Private: Calling
gnome-screensaver-command --poke
'video_output' mean = '16659.67', std. dev. = '1083.97', fps = '60.03'
2012-05-06 01:07:47.243 pause_active: 0
2012-05-06 01:07:47.358 Display Rect left: 1410, top: 75, width: 450,
height: 255, aspect: 1.77778
2012-05-06 01:07:47.359 Video Rect left: 0, top: 0, width: 1280,
height: 720, aspect: 1.77778
2012-05-06 01:07:47.359 Display Rect left: 1410, top: 75, width: 450,
height: 255, aspect: 1.77778
2012-05-06 01:07:47.359 Video Rect left: 0, top: 0, width: 1280,
height: 720, aspect: 1.77778
2012-05-06 01:07:47.359 TV: DrawUnusedRects() -- begin
2012-05-06 01:07:47.359 TV: DrawUnusedRects() -- end
2012-05-06 01:07:47.360 TV: DrawUnusedRects() -- begin
2012-05-06 01:07:47.360 TV: DrawUnusedRects() -- end
2012-05-06 01:07:47.361 TV: DrawUnusedRects() -- begin
2012-05-06 01:07:47.361 TV: DrawUnusedRects() -- end
2012-05-06 01:07:47.396 TV: DrawUnusedRects() -- begin
2012-05-06 01:07:47.396 TV: DrawUnusedRects() -- end
2012-05-06 01:07:47.683 Player(6): Video is 6.23899 frames behind audio
(too slow), dropping frame t
o catch up.
2012-05-06 01:07:47.683 AO: Pause 1
2012-05-06 01:07:47.692 AO: OutputAudioLoop: audio paused
2012-05-06 01:07:47.692 ALSA, Error: WriteAudio: buffer underrun
2012-05-06 01:07:47.697 Player(6): Video is 8.95001 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 10.7285 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 11.8077 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 12.3773 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 12.5498 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 12.4244 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 12.0906 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 11.5854 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 10.9519 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 10.2369 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 9.4459 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 8.59791 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.698 Player(6): Video is 7.70719 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.699 Player(6): Video is 6.79938 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.699 Player(6): Video is 5.86375 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.699 Player(6): Video is 4.90727 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.699 Player(6): Video is 3.95019 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:07:47.699 Player(6): Waiting for video buffers...
2012-05-06 01:07:47.699 AO: Pause 1
2012-05-06 01:07:47.730 AO: Pause 0
2012-05-06 01:07:47.730 AO: Pause 0
2012-05-06 01:07:47.781 IsTunable(2810)
2012-05-06 01:07:47.786 AO: OutputAudioLoop: Play Event
2012-05-06 01:07:47.787 IsTunable(2810) -> true
Snipping a bunch of normal idle messages with the EPG just sitting there
while I cut/pasted the above, now I hit PageUp:
2012-05-06 01:12:18.752 IsTunable(2809)
2012-05-06 01:12:18.758 IsTunable(2809) -> true
2012-05-06 01:12:18.849 Player(6): 19200 progressive frames seen.
2012-05-06 01:12:18.871 Player(6): Video is 3.11437 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:12:18.871 AO: Pause 1
'video_output' mean = '17573.85', std. dev. = '8200.20', fps = '56.90'
2012-05-06 01:12:18.872 Player(6): Video is 3.71438 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:12:18.872 AO: Pause 1
2012-05-06 01:12:18.872 Player(6): Video is 3.92465 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:12:18.872 AO: Pause 1
2012-05-06 01:12:18.872 Player(6): Video is 3.82761 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:12:18.872 AO: Pause 1
2012-05-06 01:12:18.873 Player(6): Video is 3.51508 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:12:18.873 AO: Pause 1
2012-05-06 01:12:18.873 Player(6): Video is 3.04088 frames behind audio
(too slow), dropping frame to catch up.
2012-05-06 01:12:18.873 AO: Pause 1
2012-05-06 01:12:18.874 AO: Pause 0
2012-05-06 01:12:18.881 AO: OutputAudioLoop: Play Event
2012-05-06 01:12:19.046 Player(6): Waiting for video buffers...
2012-05-06 01:12:19.046 AO: Pause 1
2012-05-06 01:12:19.052 AO: OutputAudioLoop: audio paused
2012-05-06 01:12:19.146 Player(6): Waited 100ms for video buffers
AAAAAAAALAALAAAAA
2012-05-06 01:12:19.148 Player(6): Waited 100ms for video buffers
AAAAAAAALAALAAAAA
2012-05-06 01:12:19.152 AO: Pause 0
2012-05-06 01:12:19.152 AO: OutputAudioLoop: Play Event
2012-05-06 01:12:19.202 Player(6): Video is 5.77864 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.236 Player(6): Video is 8.91944 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.269 Player(6): Video is 11.0203 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.303 Player(6): Video is 12.3562 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.336 Player(6): Video is 13.0884 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.369 Player(6): Video is 13.3978 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.403 Player(6): Video is 13.3601 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.436 Player(6): Video is 13.077 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.469 Player(6): Video is 12.625 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.503 Player(6): Video is 12.0462 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.536 Player(6): Video is 11.3274 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.570 Player(6): Video is 10.5635 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.603 Player(6): Video is 9.75082 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.636 Player(6): Video is 8.88653 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.670 Player(6): Video is 7.99856 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.703 Player(6): Video is 7.06288 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.736 Player(6): Video is 6.12132 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.770 Player(6): Video is 5.1604 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.803 Player(6): Video is 4.18498 frames ahead of
audio,
doubling video frame interval to slow down.
2012-05-06 01:12:19.836 Player(6): Video is 3.21363 frames ahead of
audio,
doubling video frame interval to slow down.
'video_output' mean = '19991.35', std. dev. = '13610.29', fps = '50.02'
'video_output' mean = '16680.04', std. dev. = '83.46', fps = '59.95'
'video_output' mean = '16679.06', std. dev. = '82.62', fps = '59.96'
2012-05-06 01:12:25.843 Player(6): 19600 progressive frames seen.
'video_output' mean = '16680.35', std. dev. = '91.23', fps = '59.95'
'video_output' mean = '16679.26', std. dev. = '74.28', fps = '59.95'
'video_output' mean = '16680.06', std. dev. = '74.49', fps = '59.95'
'video_output' mean = '16679.75', std. dev. = '97.32', fps = '59.95'
2012-05-06 01:12:32.516 Player(6): 20000 progressive frames seen.
'video_output' mean = '16679.92', std. dev. = '86.07', fps = '59.95'
It is complaining of underruns but I already did the bit to increase the
buffer with:
# cat /proc/asound/card1/pcm3p/sub0/prealloc
320
The obvious problem is figuring out just what the heck sort of resource
starvation could be happening on this machine, it is more than enough
for the job. Painting the guide isn't exactly hard. But the larger
problem is that it looks like a case where it isn't making an optimal
decision in dealing with the first problem. A media player should keep
the audio streaming at all cost and with realtime priority it is hard to
imagine that not being possible. Cutting audio frames is almost as bad
but preferred to switching off the transmitter, especially on
multi-channel audio. Dropping video frames is almost always the right
decision over breaking the audio.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 198 bytes
Desc: This is a digitally signed message part
URL: <http://www.mythtv.org/pipermail/mythtv-users/attachments/20120506/a607fb45/attachment.sig>
More information about the mythtv-users
mailing list