31 replies to this topic

[greatred]

Hi,

 

today I realized that I`m not able to do any recording from Eurosport 2 HD | 13E | 11258H | 1:0:1:3B63:12C:13E:820000:0:0:0:

Recording is appearing in the movie list with 0-bytes size.

Timeshifting on the same channel is working fine.

Recording other services from same TP is working fine.

Below the output of enigma2 log:

<  2000.693> [RecordTimerEntry(name=Bayer 04 Leverkusen - Hamburger SV: Bundesliga - 26. kolejk, begin=Sun Mar 13 16:21:06 2016, serviceref=1:0:1:3B63:12C:13E:820000:0:0:0:, justplay=False)]
<  2000.700> [TIMER] record time changed, start prepare is now: Sun Mar 13 16:29:53 2016
<  2000.705> getResolvedKey config.usage.remote_fallback failed !! (Typo??)
e00000(DiSEqC reset)
e00003(DiSEqC peripherial power on)
e01038f2(?)
<  2000.708> [TimerSanityCheck] conflict not found!
<  2000.710> [Timer] Record RecordTimerEntry(name=Bayer 04 Leverkusen - Hamburger SV: Bundesliga - 26. kolejk, begin=Sun Mar 13 16:30:13 2016, serviceref=1:0:1:3B63:12C:13E:820000:0:0:0:, justplay=False)
<  2000.711> [TIMER] activating state 1
<  2000.720> [TIMER] Filename calculated as: '/media/hdd/movie/20160313 1630 - Eurosport 2 HD - Bayer 04 Leverkusen - Hamburger SV_ Bundesliga - 26_ kolejk'
<  2000.721> recording service: <enigma.eServiceReference; proxy of <Swig Object of type 'eServiceReference *' at 0x1e77f50> >
<  2000.722> [add callback]
<  2000.725> getResolvedKey config.usage.remote_fallback failed !! (Typo??)
<  2000.726> [eDVBResourceManager] use cached_channel
<  2000.726> [eDVBServicePMTHandler] allocate Channel: res 0
<  2000.726> [eDVBCIInterfaces] addPMTHandler 1:0:1:3B63:12C:13E:820000:0:0:0:
<  2000.732> [eDVBChannel] getDemux cap=01
<  2000.732> [eDVBServicePMTHandler] ok ... now we start!!
<  2000.732> [eDVBServiceRecord] RECORD service event 5
<  2000.734> [TIMER] record event 6
<  2000.735> [eDVBCAService] add demux 0 to slot 0 service 1:0:1:3B63:12C:13E:820000:0:0:0:
<  2000.735> [eDVBCAService] don't build/send the same CA PMT twice
<  2000.735> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<  2000.735> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  2000.753> [eDVBServiceRecord] RECORD service event 6
<  2000.753> [eDVBServiceRecord] tuned..
<  2000.753> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<  2000.754> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  2000.773> [TIMER] record event 2
<  2000.774> [eDVBChannel] getDemux cap=00
<  2000.776> [eEPGCache] saveEventToFile epg event id 52a
<  2000.778> [TIMER] prepare ok, waiting for begin
<  2000.785> [TIMER] activating state 2
<  2000.786> [TIMER] start recording
<  2000.794> [TIMER] record event 0
<  2000.795> AddPopup, id = None
<  2000.869> warning, skin is missing element WarningPixmap in <class 'Screens.MessageBox.MessageBox'>(A record has been started:
Bayer 04 Leverkusen - Hamburger SV: Bundesliga - 26. kolejk)<  2000.870>
<  2000.914> [eDVBServiceRecord] Recording to /media/hdd/movie/20160313 1630 - Eurosport 2 HD - Bayer 04 Leverkusen - Hamburger SV_ Bundesliga - 26_ kolejk.ts...
<  2000.915> [eDVBServiceRecord] start recording...
<  2000.915> [eDVBServiceRecord] RECORD: have 1 video stream(s) (021a), and 1 audio stream(s) (027e), and the pcr pid is 021a, and the text pid is ffffffff
<  2000.916> [eDVBServiceRecord] ADD PID: 0000
<  2000.916> [eDVBServiceRecord] ADD PID: 021a
<  2000.916> [eDVBServiceRecord] ADD PID: 027e
<  2000.973> [setIoPrio] realtime level 7 ok
<  2000.974> [eFilePushThreadRecorder] THREAD START
<  2000.976> [TIMER] record event 4
<  2000.996> after:
<  2000.997> [RecordTimerEntry(name=Bayer 04 Leverkusen - Hamburger SV: Bundesliga - 26. kolejk, begin=Sun Mar 13 16:30:13 2016, serviceref=1:0:1:3B63:12C:13E:820000:0:0:0:, justplay=False)]
<  2001.019> [eDVBServicePMTHandler] PATready
<  2001.020> [eDVBServicePMTHandler] use pmtpid 041d for service_id 3b63
<  2001.020> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<  2001.020> [eDVBSectionReader] DMX_SET_FILTER pid=1053
<  2001.040> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<  2001.040> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  2001.288> [eDVBServiceRecord] RECORD service event 5
<  2001.289> [eDVBServiceRecord] start recording...
<  2001.294> [eDVBServiceRecord] RECORD: have 1 video stream(s) (021a), and 11 audio stream(s) (027e, 02e2, 1507, 1508, 1509, 150a, 150b, 150c, 150d, 150e, 150f), and the pcr pid is 021a, and the text pid is ffffffff
<  2001.296> [eDVBServiceRecord] ADD PID: 02e2
<  2001.296> [eDVBServiceRecord] ADD PID: 041d
<  2001.297> [eDVBServiceRecord] ADD PID: 044f
<  2001.298> [eDVBServiceRecord] ADD PID: 04b3
<  2001.298> [eDVBServiceRecord] ADD PID: 04b4
<  2001.305> [eDVBServiceRecord] ADD PID: 04e6
<  2001.305> [eDVBServiceRecord] ADD PID: 0517
<  2001.305> [eDVBServiceRecord] ADD PID: 0518
<  2001.306> [eDVBServiceRecord] ADD PID: 0549
<  2001.306> [eDVBServiceRecord] ADD PID: 057b
<  2001.307> [eDVBServiceRecord] ADD PID: 057c
<  2001.308> [eDVBServiceRecord] ADD PID: 05df
<  2001.308> [eDVBServiceRecord] ADD PID: 0643
<  2001.309> [eDVBServiceRecord] ADD PID: 06a7
<  2001.310> [eDVBServiceRecord] ADD PID: 070b
<  2001.311> [eDVBServiceRecord] ADD PID: 076f
<  2001.311> [eDVBServiceRecord] ADD PID: 1507
<  2001.312> [eDVBServiceRecord] ADD PID: 1508
<  2001.313> [eDVBServiceRecord] ADD PID: 1509
<  2001.313> [eDVBServiceRecord] ADD PID: 150a
<  2001.314> [eDVBServiceRecord] ADD PID: 150b
<  2001.314> [eDVBServiceRecord] ADD PID: 150c
<  2001.315> [eDVBServiceRecord] ADD PID: 150d
<  2001.315> [eDVBServiceRecord] ADD PID: 150e
<  2001.316> [eDVBServiceRecord] ADD PID: 150f
<  2001.318> [TIMER] record event 4
<  2001.319> [TIMER] record event 6
<  2001.320> [eDVBCIInterfaces] gotPMT
<  2001.320> [eDVBCAService] don't build/send the same CA PMT twice
<  2001.320> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<  2001.321> [eDVBSectionReader] DMX_SET_FILTER pid=1053
<  2001.629> [eConsoleAppContainer] Starting /usr/bin/grab
<  2002.026> [eDVBServiceRecord] pcr of eit change: 157e3df86
<  2002.026> [eDVBServiceRecord] now running: Bayer 04 Leverkusen - Hamburger SV: Bundesliga - 26. kolejk (8100 seconds)
<  2002.027> [TIMER] record event 9
<  2002.028> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<  2002.028> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  2002.911> Timeout!

Vu+ Uno

openpli regulary updated

Internal HDD

Valid Subscription

 

Many thanks for looking into this.

[greatred]

Anyone else is able to reproduce this issue ?
I get the impression that the large amount of audio streams is playing a role here.
I tested another channel with many audio tracks (BabyTV | 13E | 10815H) and the issue is reproducable.

[janejak]

i have checked but no error here all ok, but i have duo2

[goldeneye]

Not a problem here! I can see a few errors in the log though..... Are you using the build in tuner or are you trying the fallback tuner (which isn't working in your case)?

[greatred]

That is the built-in tuner, no fallback tuner here. Like I said, I do not have any issues with recording other services from the same transponder, or even with timeshift on the services with many audio tracks. I checked other softcam aswell, unfortunately issue still persist.

[Robinson]

Anyone else is able to reproduce this issue ?

 

No problem on ET9000.

[greatred]

@goldeneye

 

You tested with a Vu UNO ?

[Erik Slagter]

Legal subscriber card?

[greatred]

Offcourse, legal subscriber card 0100:000068. Please point me to the right direction, how to produce more detailed enigma2 log ?

[Erik Slagter]

I guess you've also been bitten by the newer ECM pids (not necessarily Seca, more likely Viaccess, but also likely to be on this service), that CCcam chokes on.

[greatred]

right ..... and timeshift is working fine ? another service with 11 Audio Tracks is by accident affected as well ? My primary softcam is oscam I checked with cccam and was able to reproduce.

What do the last 8 lines from posted log output say ?

[greatred]

forgot to add that recording the same problematic channels via a PC DVB card is working fine, the same smartcard is providing ECM`s ..

[greatred]

Just tested FTA channel Euronews from Astra 19.2 E - issue persist

[greatred]

Starting Recording: 

<   420.315> [eDVBServicePlay] timeshift
<   420.380> [TIMER] record time changed, start prepare is now: Tue Mar 15 00:06:13 2016
<   420.383> [TIMER] record time changed, start prepare is now: Tue Mar 15 00:06:13 2016
<   420.391> getResolvedKey config.usage.remote_fallback failed !! (Typo??)
e00000(DiSEqC reset)
e00003(DiSEqC peripherial power on)
e01038f1(?)
<   420.397> [TimerSanityCheck] conflict not found!
<   420.402> getResolvedKey config.usage.remote_fallback failed !! (Typo??)
<   420.404> [TimerSanityCheck] conflict not found!
<   420.406> [Timer] Record RecordTimerEntry(name=EURONEWS, begin=Tue Mar 15 00:06:33 2016, serviceref=1:0:1:2013:24B8:13E:820000:0:0:0:, justplay=False)
<   420.408> [TIMER] activating state 1
<   420.759> [TIMER] Filename calculated as: '/media/hdd/movie/20160315 0006 - Euronews - EURONEWS'
<   420.760> recording service: <enigma.eServiceReference; proxy of <Swig Object of type 'eServiceReference *' at 0x1f13608> >
<   420.761> [add callback]
<   420.766> getResolvedKey config.usage.remote_fallback failed !! (Typo??)
<   420.767> [eDVBResourceManager] use cached_channel
<   420.767> [eDVBServicePMTHandler] allocate Channel: res 0
<   420.768> [eDVBCIInterfaces] addPMTHandler 1:0:1:2013:24B8:13E:820000:0:0:0:
<   420.768> [eDVBChannel] getDemux cap=01
<   420.768> [eDVBServicePMTHandler] ok ... now we start!!
<   420.768> [eDVBServiceRecord] RECORD service event 5
<   420.771> [TIMER] record event 6
<   420.771> [eDVBCAService] add demux 0 to slot 1 service 1:0:1:2013:24B8:13E:820000:0:0:0:
<   420.776> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<   420.776> [eDVBSectionReader] DMX_SET_FILTER pid=0
<   420.795> [eDVBServiceRecord] RECORD service event 6
<   420.795> [eDVBServiceRecord] tuned..
<   420.795> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<   420.796> [eDVBSectionReader] DMX_SET_FILTER pid=18
<   420.815> [TIMER] record event 2
<   420.816> [eDVBChannel] getDemux cap=00
<   420.828> [eEPGCache] saveEventToFile epg event id f72
<   420.836> [TIMER] prepare ok, waiting for begin
<   420.843> [TIMER] activating state 2
<   420.844> [TIMER] start recording
<   420.853> [TIMER] record event 0
<   420.855> AddPopup, id = None
<   421.006> warning, skin is missing element WarningPixmap in <class 'Screens.MessageBox.MessageBox'>(A record has been started:
EURONEWS)<   421.007>
<   421.065> [eDVBServiceRecord] Recording to /media/hdd/movie/20160315 0006 - Euronews - EURONEWS.ts...
<   421.069> [eDVBServiceRecord] start recording...
<   421.070> [eDVBServiceRecord] RECORD: have 1 video stream(s) (08ad), and 1 audio stream(s) (08b8), and the pcr pid is 08ad, and the text pid is 0300
<   421.071> [eDVBServiceRecord] ADD PID: 0000
<   421.071> [eDVBServiceRecord] ADD PID: 0300
<   421.071> [eDVBServiceRecord] ADD PID: 08ad
<   421.071> [eDVBServiceRecord] ADD PID: 08b8
<   421.269> [setIoPrio] realtime level 7 ok
<   421.270> [eFilePushThreadRecorder] THREAD START
<   421.272> [TIMER] record event 4
<   421.320> [eDVBServicePMTHandler] PATready
<   421.320> [eDVBServicePMTHandler] use pmtpid 040a for service_id 2013
<   421.320> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<   421.320> [eDVBSectionReader] DMX_SET_FILTER pid=1034
<   421.339> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<   421.339> [eDVBSectionReader] DMX_SET_FILTER pid=0
<   421.436> [eDVBServiceRecord] RECORD service event 5
<   421.436> [eDVBServiceRecord] start recording...
<   421.442> [eDVBServiceRecord] RECORD: have 1 video stream(s) (08ad), and 14 audio stream(s) (08b7, 08b8, 08b9, 08ba, 08bb, 08bc, 08bd, 08be, 08bf, 08c0, 08c1, 08c2, 08c3, 08c6), and the pcr pid is 08ad, and the text pid is 0300
<   421.445> [eDVBServiceRecord] ADD PID: 040a
<   421.448> [eDVBServiceRecord] ADD PID: 08b7
<   421.449> [eDVBServiceRecord] ADD PID: 08b9
<   421.450> [eDVBServiceRecord] ADD PID: 08ba
<   421.450> [eDVBServiceRecord] ADD PID: 08bb
<   421.451> [eDVBServiceRecord] ADD PID: 08bc
<   421.452> [eDVBServiceRecord] ADD PID: 08bd
<   421.452> [eDVBServiceRecord] ADD PID: 08be
<   421.452> [eDVBServiceRecord] ADD PID: 08bf
<   421.453> [eDVBServiceRecord] ADD PID: 08c0
<   421.453> [eDVBServiceRecord] ADD PID: 08c1
<   421.453> [eDVBServiceRecord] ADD PID: 08c2
<   421.454> [eDVBServiceRecord] ADD PID: 08c3
<   421.455> [eDVBServiceRecord] ADD PID: 08c6
<   421.457> [TIMER] record event 4
<   421.458> [TIMER] record event 6
<   421.459> [eDVBCIInterfaces] gotPMT
<   421.459> [eDVBCAService] don't build/send the same CA PMT twice
<   421.460> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<   421.460> [eDVBSectionReader] DMX_SET_FILTER pid=1034
<   422.407> [eDVBServiceRecord] pcr of eit change: 70f378c5
<   422.408> [eDVBServiceRecord] now running: EURONEWS (43200 seconds)
<   422.409> [TIMER] record event 9
<   422.410> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
<   422.411> [eDVBSectionReader] DMX_SET_FILTER pid=18
<   423.061> Timeout!

[blzr]

since no one could confirm that problem on any other hardware (for me recordings using vuzero and et9500 are ok),

looks that only possible explanation could be some driver bug /?/

 

to confirm/deny this, some other vuuno user would need to test and tell...

[Erik Slagter]

If the problem can be leveraged by recording or timeshifting, it's definitely a timestamping/vbv/multiplexing problem at the provider. Some hardware/drivers can more or less cope with out-of-spec muxed streams, some can't (which is their good right).

[greatred]

blzr,Erik: many thanks for your input.

 Are the posted logs giving any hints ? Is there a way to increase the Debug Level ?

[malakudi]

This is a driver issue. I remember VU+ Duo to have this issue but it got fixed. I guess VU+ Uno suffers from this issue, maybe only latest driver are affected? Could you try some older drivers for VU+ Uno?

[greatred]

Ok I was about to reflash in order to exclude any kind of misconfiguration and then eventually start the dvb-driver rollercoaster ....
But before that I reviewed my concigured settings.
Long story short: Always include ECM in recordings is the key here.
Have no idea why this was enabled here since UNO is not capable of offline decoding
Nevertheless disabling the option solved issues described mentioned in this thread.
Now I bet blaming the drivers/hardware/providers/ECM must sound, sorry, ridiculous

Edited by greatred, 16 March 2016 - 00:10.

[greatred]

Guys don`t get my post wrong. No bad feelings here. Glad issue is solved but I`m worried that a setting can cause this kind of behavior.

I know what anyone can think now: if offline decoding is not supported on VU+ Uno, why am I wondering that things went wrong

Well, although offline decoding is not supported, saving ECM`s with recording should be /?/

That is at least what the config description is about:

 

https://github.com/O.../setup.xml#L165:

"Always include ECM messages in recordings. This overrides the individual timer settings globally.
It allows recordings to be always decrypted afterwards (sometimes called offline decoding), 
if supported by your receiver. Default: off."

Maybe it is only me, but reading the description I get the impression that the "if supported by your receiver" part applies to "to be always decrypted afterwards" 

I would never expect that the "offline decoding" support is needed from the start (at the point where things get recorded).

 

Is this some misleading/unfortunate naming and maybe it would be better to name it "Online decoding: yes/no"

or maybe it is some kind of bug ? Dunno.

 

greetings!