[mythtv] mythplayer.cpp query

Wed Mar 14 09:43:21 UTC 2012

> On 13 Mar 2012, at 16:01, Stuart Morgan wrote:
>
>> On Tuesday 13 Mar 2012 15:25:02 Russell Gower wrote:
>>> Just to be clear, I'm not talking about channel changes, I'm talking about
>>> the delay when one program ends and the next one starts  - i.e the
>>> transition from 8441_20120312180956.mpg to 8441_20120312183001.mpg
>> I'm unable to reproduce a delay on programme transitions ... and historically
>> no-one has ever reported a delay there.
>>
>> Still if you are seeing a delay then something is going wrong.
> I'm really hoping this is a setup issue, it's persisted over 3 hardware "upgrades" and I've experienced it ever since the switch to creating individual recording files for live tv, so i'm doubt full.
>
> Bellow is an typical example from the frontend log - on this occasion SwitchToProgram took 7.6 seconds, during which the screen was frozen.
>
> 2012-03-13 09:15:01.343816 I  Player(0): SwitchToProgram - start
> 2012-03-13 09:15:01.510896 I  Player(0): LoadFilters(''..) ->  0x0
> 2012-03-13 09:15:01.510907 I  AO: Pause 1
> 2012-03-13 09:15:08.970497 I  RingBuf(/mythtv/kvm02/Recordings/8441_20120313091500.mpg): safe_read(... at 3820912, 373392) ->  0, took 300 ms (0Mbps)
> 2012-03-13 09:15:08.970538 I  RingBuf(/mythtv/kvm02/Recordings/8441_20120313091500.mpg): CalcReadAheadThresh(15256 Kb)
> 2012-03-13 09:15:08.970571 I  Player(0): Play(  1.0, normal 1, unpause audio 1)
> 2012-03-13 09:15:08.970600 I  AO: Pause 0
> 2012-03-13 09:15:08.970608 I  Player(0): SwitchToProgram - end
>
>
> _______________________________________________
> mythtv-dev mailing list
> mythtv-dev at mythtv.org
> http://www.mythtv.org/mailman/listinfo/mythtv-dev
it is definitely related to specific setup. 7.6 sec is terrible in your 
case. In my case it is noticeable but not so bad. I have combined setup 
of linux backend / frontend on one PC, 0.24-fixes almost up to date. 
Program switch here takes .23 sec. Just for reference i did same test on 
remote Windows based frontend, myth version here is .24.1+. Program 
switch here takes approximately 1.1 sec. Break on Windows is much more 
visible. On Linux is most disturbing audio break, it is points out that 
something is going slightly wrong. Video "hang" is almost not visible.

Here are logs from my frontends. Linux:
2012-03-14 09:35:00.774 Player(0): SwitchToProgram - start
2012-03-14 09:35:00.780 Player(0): LoadFilters(''..) -> 0x0
2012-03-14 09:35:00.795 Player(0): Play speed: rate: 25 speed: 0 skip: 0 
=> new interval 40000
2012-03-14 09:35:00.816 VDP: GetFilteredDeint(vdpauadvanced) : vdpau -> 
'vdpauadvanced'
2012-03-14 09:35:00.827 VidOutVDPAU: Enabled deinterlacing.
2012-03-14 09:35:00.829 
RingBuf(/var/lib/mythtv/livetv/31702_20120314093415.mpg): 
OpenFile(/var/lib/mythtv/livetv/31702_20120314093500.mpg, 10000 ms)
2012-03-14 09:35:00.944 Player(0): SwitchToProgram(void) discont: 0 
newtype: 0 newid: 4 decoderEof: 0
2012-03-14 09:35:00.944 AFD: Resetting byte context eof (livetv 1 was eof 0)
2012-03-14 09:35:00.944 Player(0): Play(  1.0, normal 1, unpause audio 1)
2012-03-14 09:35:01.006 Player(0): SwitchToProgram - end

Windows:
2012-03-14 09:59:56.859 Player(0): SwitchToProgram - start
2012-03-14 09:59:56.859 Player(0): LoadFilters(''..) -> 0x0
2012-03-14 09:59:56.890 Player(0): Play speed: rate: 25 speed: 0 skip: 0 
=> new interval 40000
2012-03-14 09:59:56.890 
RingBuf(myth://192.168.111.5:6543/31702_20120314095525.mpg): 
OpenFile(myth://192.168.111.5:6543/31702_20120314100000.mpg, 10000 ms)
2012-03-14 09:59:57.078 Player(0): SwitchToProgram(void) discont: 0 
newtype: 1 newid: 1 decoderEof: 0
2012-03-14 09:59:57.078 
RingBuf(myth://192.168.111.5:6543/31702_20120314100000.mpg) Warning: Not 
starting read ahead thread, already running
2012-03-14 09:59:57.718 AFD: Stream #0, has id 0x97 codec id MPEG2VIDEO, 
type Video, bitrate 15000000 at 0x35c1ad10
2012-03-14 09:59:57.734 VDP: Accepting: cmp(>= 0 0) dec(ffmpeg) cpus(0) 
skiploop(enabled) rend(direct3d) osd(direct3d) osdfade(enabled) 
deint(onefield,onefield) filt()
2012-03-14 09:59:57.734 VDP: LoadBestPreferences(2048x2048, 0)
2012-03-14 09:59:57.734 VDP: LoadBestPreferences(2048x2048, 60)
2012-03-14 09:59:57.734 VDP: LoadBestPreferences(720x576, 60)
2012-03-14 09:59:57.734 AFD: Using 0 CPUs for decoding
2012-03-14 09:59:57.734 AFD: InitVideoCodec() 0x35b3c3d0 id(MPEG2VIDEO) 
type (Video).
2012-03-14 09:59:57.734 AFD: Selected FPS is 25 (avg 25 stream 25 
container 90000 estimated 25)
2012-03-14 09:59:57.734 AFD: Using ffmpeg for video decoding
2012-03-14 09:59:57.734 AFD: Looking for decoder for MPEG2VIDEO
2012-03-14 09:59:57.734 AFD: Opened codec 0x35b3c3d0, id(MPEG2VIDEO) 
type(Video)
2012-03-14 09:59:57.734 AFD: Stream #1, has id 0xa0 codec id MP2, type 
Audio, bitrate 128000 at 0x35b9d2a0
2012-03-14 09:59:57.734 AFD: codec MP2 has 1 channels
2012-03-14 09:59:57.734 AFD: Looking for decoder for MP2
2012-03-14 09:59:57.734 AFD: Opened codec 0x35b3bc90, id(MP2) type(Audio)
2012-03-14 09:59:57.734 AFD: Stream #2, has id 0xa1 codec id MP2, type 
Audio, bitrate 128000 at 0x35c52c80
2012-03-14 09:59:57.734 AFD: codec MP2 has 1 channels
2012-03-14 09:59:57.734 AFD: Looking for decoder for MP2
2012-03-14 09:59:57.734 AFD: Opened codec 0x35b3b550, id(MP2) type(Audio)
2012-03-14 09:59:57.734 AFD: Stream #3, has id 0xa2 codec id MP2, type 
Audio, bitrate 128000 at 0x35bc6c70
2012-03-14 09:59:57.734 AFD: codec MP2 has 1 channels
2012-03-14 09:59:57.734 AFD: Looking for decoder for MP2
2012-03-14 09:59:57.734 AFD: Opened codec 0x35c636a0, id(MP2) type(Audio)
2012-03-14 09:59:57.734 AFD: Stream #4, has id 0xa3 codec id MP2, type 
Audio, bitrate 128000 at 0x35b3c1d0
2012-03-14 09:59:57.734 AFD: codec MP2 has 1 channels
2012-03-14 09:59:57.734 AFD: Looking for decoder for MP2
2012-03-14 09:59:57.734 AFD: Opened codec 0x35b9b770, id(MP2) type(Audio)
2012-03-14 09:59:57.734 AFD: Stream #5, has id 0xa5 codec id MP2, type 
Audio, bitrate 128000 at 0x35b3ba90
2012-03-14 09:59:57.734 AFD: codec MP2 has 1 channels
2012-03-14 09:59:57.734 AFD: Looking for decoder for MP2
2012-03-14 09:59:57.734 AFD: Opened codec 0x35d61550, id(MP2) type(Audio)
2012-03-14 09:59:57.781 Dec: Selected track #1 in the Unknown language(0)
2012-03-14 09:59:57.781 Dec: Resyncing position map. posmapStarted = 0 
livetv(1) watchingRec(0)
2012-03-14 09:59:57.796 Dec: Position map filled from DB to: 33
2012-03-14 09:59:57.796 Dec: SyncPositionMap watchingrecording, from DB: 
3 entries
2012-03-14 09:59:57.796 Player(0): Filling position map from 34 to end
2012-03-14 09:59:57.859 Dec: Position map filled from Encoder to: 57
2012-03-14 09:59:57.859 Dec: SyncPositionMap watchingrecording total: 5 
entries
2012-03-14 09:59:57.859 Dec: SyncPositionMap, new totframes: 57, new 
length: 2, posMap size: 5
2012-03-14 09:59:57.859 AFD: Partial position map found
2012-03-14 09:59:57.859 AFD: Successfully opened decoder for file: 
"myth://192.168.111.5:6543/31702_20120314100000.mpg". novideo(0)
2012-03-14 09:59:57.875 AFD: Resetting byte context eof (livetv 1 was eof 0)
2012-03-14 09:59:57.953 Player(0): Play(  1.0, normal 1, unpause audio 1)
2012-03-14 09:59:57.953 Dec: Resyncing position map. posmapStarted = 0 
livetv(1) watchingRec(1)
2012-03-14 09:59:57.953 Player(0): SwitchToProgram - end