[mythtv-users] Transcoded recordings playback fails: audio failure, video stutters (was Last MythTV Gentoo ebuild... buffer issues)

Mon Dec 19 00:40:35 UTC 2011

On 12/18/11 4:37 PM, jk90090 wrote:
> On 12/18/11 4:20 PM, Roger Heflin wrote:
>> Check your network using on the backend/frontend when this is happening.
>>
>> There is an old feature in myth that had it stream from the backend to
>> the frontend within myth vs with nfs.
>>
>> One of my frontends was setup (a long time ago) to stream that way and
>> matched what you are seeing and the network bandwidth being used was
>> way too high (50Mbyte/s for something that should have been
>> <1mbyte/second)).
>>
> Thanks for the suggestion, but this doesn't seem to be the case.  I 
> copied the nuv to an SMB share that I have mounted for Videos, went 
> into videos, same bad results.  I renamed it to avi, and used mplayer 
> for playback which worked flawlessly.  I even copied the file to the 
> local directory, again same.  Basically the internal player is the one 
> having the trouble, regardless of location.  *Shrug*.  I'll give it a 
> shot anyways, but I don't mount the Recordings directory on my frontend.
>
> -J
>
>
For those keeping an eye, here's an excerpt of debug level output from 
the frontend during the local file playback:

2011-12-18 16:38:27.343942 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1200128, 2048) -- begin
2011-12-18 16:38:27.343987 I [16487/16841] RingBuffer ringbuffer.cpp:879 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1200128, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.344000 D [16487/16841] RingBuffer ringbuffer.cpp:892 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K 
requested   2K in read
2011-12-18 16:38:27.344007 D [16487/16841] RingBuffer ringbuffer.cpp:943 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read 
ahead loop
2011-12-18 16:38:27.345563 I [16487/16843] Decoder 
audio/audiooutputbase.cpp:1095 (SetAudiotime) - AO: SetAudiotime 
atc=47752884 tc=47752985 f=4096 pfu=-4352 pfs=-512
2011-12-18 16:38:27.345799 I [16487/16843] Decoder 
audio/audiooutputbase.cpp:1331 (AddData) - AO: AddData frames=1152, 
bytes=4608, used=25729, free=3046271, timecode=47752985 needsupmix=1
2011-12-18 16:38:27.345818 D [16487/16843] Decoder freesurround.cpp:363 
(putFrames) - FreeSurround::putFrames 1152 #ch 2 used 1152 generated 0
2011-12-18 16:38:27.345832 I [16487/16843] Decoder 
audio/audiooutputbase.cpp:1095 (SetAudiotime) - AO: SetAudiotime 
atc=47752860 tc=47752985 f=0 pfu=-5504 pfs=-512
2011-12-18 16:38:27.345848 D [16487/16843] Decoder ringbuffer.cpp:1188 
(ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
ReadPriv(..12, normal) @1198721 -- begin
2011-12-18 16:38:27.345867 D [16487/16843] Decoder ringbuffer.cpp:1272 
(ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
ReadPriv(..12, normal) -- copying data
2011-12-18 16:38:27.345876 D [16487/16843] Decoder ringbuffer.cpp:1287 
(ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
ReadPriv(..12, normal) -- checksum 5687
2011-12-18 16:38:27.345890 D [16487/16843] Decoder ringbuffer.cpp:1188 
(ReadPriv) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
ReadPriv(..34077, normal) @1198733 -- begin
2011-12-18 16:38:27.352057 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1202176, 2048) -- begin
2011-12-18 16:38:27.352068 I [16487/16487] CoreContext 
mythplayer.cpp:1824 (AVSync) - Player(1): AVSync show
2011-12-18 16:38:27.352118 I [16487/16841] RingBuffer ringbuffer.cpp:879 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1202176, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.352134 D [16487/16841] RingBuffer ringbuffer.cpp:892 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K 
requested   2K in read
2011-12-18 16:38:27.352143 D [16487/16841] RingBuffer ringbuffer.cpp:943 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read 
ahead loop
2011-12-18 16:38:27.355434 I [16487/16842] AudioOutputBase 
audio/audiooutputbase.cpp:1046 (GetAudiotime) - AO: GetAudiotime 
audt=47752726 atc=47752860 mb=25728 sb=0 tb=25728 sr=48000 obpf=4 bpf=24 
sf=1 -1722167296 -89
2011-12-18 16:38:27.355463 I [16487/16842] AudioOutputBase 
audio/audiooutputalsa.cpp:526 (WriteAudio) - WriteAudio: Preparing 9600 
bytes (2400 frames)
2011-12-18 16:38:27.355512 I [16487/16842] AudioOutputBase 
audio/audiooutputbase.cpp:1046 (GetAudiotime) - AO: GetAudiotime 
audt=47752726 atc=47752860 mb=16128 sb=19200 tb=35328 sr=48000 obpf=4 
bpf=24 sf=1 -762167296 -39
2011-12-18 16:38:27.355527 I [16487/16842] AudioOutputBase 
audio/audiooutputalsa.cpp:526 (WriteAudio) - WriteAudio: Preparing 9600 
bytes (2400 frames)
2011-12-18 16:38:27.355543 I [16487/16842] AudioOutputBase 
audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for 
buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.359473 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1204224, 2048) -- begin
2011-12-18 16:38:27.359509 I [16487/16841] RingBuffer ringbuffer.cpp:879 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1204224, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.359523 D [16487/16841] RingBuffer ringbuffer.cpp:892 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K 
requested   2K in read
2011-12-18 16:38:27.359532 D [16487/16841] RingBuffer ringbuffer.cpp:943 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read 
ahead loop
2011-12-18 16:38:27.367627 I [16487/16842] AudioOutputBase 
audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for 
buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.367649 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1206272, 2048) -- begin
2011-12-18 16:38:27.367689 I [16487/16841] RingBuffer ringbuffer.cpp:879 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1206272, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.367714 D [16487/16841] RingBuffer ringbuffer.cpp:892 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K 
requested   2K in read
2011-12-18 16:38:27.367723 D [16487/16841] RingBuffer ringbuffer.cpp:943 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read 
ahead loop
2011-12-18 16:38:27.368724 I [16487/16487] CoreContext 
audio/audiooutputbase.cpp:1046 (GetAudiotime) - AO: GetAudiotime 
audt=47752726 atc=47752860 mb=6528 sb=26080 tb=32608 sr=48000 obpf=4 
bpf=24 sf=1 -1034167296 -53
2011-12-18 16:38:27.368760 I [16487/16487] CoreContext 
mythplayer.cpp:1908 (AVSync) - Player(1): A/V timecodes audio 47752726 
video 47752773 frameinterval 33367 avdel 47 avg -20082 tcoffset 60 avp 0 
avpen 0 avdc 0
2011-12-18 16:38:27.368817 I [16487/16487] CoreContext 
mythplayer.cpp:2018 (SetBuffering) - Player(1): Waiting for video buffers...
2011-12-18 16:38:27.375767 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1208320, 2048) -- begin
2011-12-18 16:38:27.375803 I [16487/16841] RingBuffer ringbuffer.cpp:879 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1208320, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.375816 D [16487/16841] RingBuffer ringbuffer.cpp:892 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K 
requested   2K in read
2011-12-18 16:38:27.375824 D [16487/16841] RingBuffer ringbuffer.cpp:943 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read 
ahead loop
2011-12-18 16:38:27.379866 I [16487/16842] AudioOutputBase 
audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for 
buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.383923 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1210368, 2048) -- begin
2011-12-18 16:38:27.383966 I [16487/16841] RingBuffer ringbuffer.cpp:879 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1210368, 2048) -> 2048, took 0 ms (1000Mbps)
2011-12-18 16:38:27.383981 D [16487/16841] RingBuffer ringbuffer.cpp:892 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): rbwpos +=   2K 
requested   2K in read
2011-12-18 16:38:27.383990 D [16487/16841] RingBuffer ringbuffer.cpp:943 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): @ end of read 
ahead loop
2011-12-18 16:38:27.392077 I [16487/16842] AudioOutputBase 
audio/audiooutputbase.cpp:1621 (OutputAudioLoop) - AO: audio waiting for 
buffer to fill: have 6528 want 9600
2011-12-18 16:38:27.392825 D [16487/16841] RingBuffer ringbuffer.cpp:858 
(run) - RingBuf(/mythtv/video/2041_20111208213000.nuv): 
safe_read(... at 1212416, 2048) -- begin