Feature #3073

CA: configurable playback buffer/delay to tolerate late ECMs (NDS specific ECM handling)

Added by Richard Farnsworth almost 2 years ago. Updated over 1 year ago.

Status:FixedStart date:2015-09-09
Priority:NormalDue date:
Assignee:-% Done:

0%

Category:Descrambling
Target version:4.2

Description

Hi folks,

some pay tv providers send the new ECMs quite late. Sometimes we have only 1-2 seconds, before the old CW gets invalid.

Usually this is long enough, but sometimes not. Consider network hiccups, especially with WIFI, etc. The picture freezes in these cases.

Wouldn't it be cool to have a configurable delay (maybe per CA entry) to define a small timeshift to allow additional time for the CW to arrive? TVH would process ECMs immediately, but would actually need the new CW some seconds later.

Of course, playback would be behind time. Channel switching would be delayed also... but when I look a my logs I could prevent most of my freezes with 1s second additional time.

Thanks for listening.

Richard

descrambler.log (699 KB) B C, 2015-09-23 16:14

History

#1 Updated by Jaroslav Kysela almost 2 years ago

What's your worst latency and ECM key change time ?

#2 Updated by B C almost 2 years ago

I implemented a ring buffer in csa.dll during my gbox/windows time many years ago and it did a great job. Basically this could be very usefull for NDS, ECM to key change time is less than 700ms, with a key change time of about 7 seconds in most cases. I had an adaptive time for the stream delay, so it started eg with a 1 sec delay and if I detected the odd/even key change bevor the new key was here I did set a new offset which was a bit longer than the worst case at this time (up to 5sec). This way switching time on NDS channels was still acceptable and in case of very late keys it just did hick up 1 or 2 times. Maybe an original offset (short for switching performance) and a long offset if ECMs are late would be sufficient resulting in one/limited freezes only.

#3 Updated by Jaroslav Kysela almost 2 years ago

There's already a ring buffer in the descrambler code in tvh. But it's small (about 550K). Look for 'Fill a temporary buffer until the keys are known to make' string in src/descrambler/descrambler.c . It should be probably configurable.

On other side, very large buffer can desynchronize the ecm/key responses, because there's no mechanism to link ECM to the key response at the moment - so everything is implemented using comparing timestamps at the moment. It's issue of DVBAPI, the newcamd protocol has sequence numbers, so the linking can be detected with this protocol.

#4 Updated by B C almost 2 years ago

Regarding your linkage concerns, we know that the key is even/odd and what key we need, so as long as the buffer is smaller than a cw cycle, this should not be an issue. Thanks for the hint where to start in the code, might be interesting to play with it.

#5 Updated by Richard Farnsworth almost 2 years ago

What's your worst latency and ECM key change time ?

Experimented here with a Sky DE V14 smartcard. CW life time seems to be 7s each. However, the new ECM comes <1s before expriration of the old CW. Usually no issue, but for my setup it would be great to have a say 2-3s grace period/decryption delay. Of course <7s.

#6 Updated by Richard Farnsworth almost 2 years ago

OK, to be honest, I'm a noob. :(

Tried to increase the buffer by modifying (10x, 100x)...
https://github.com/tvheadend/tvheadend/blob/master/src/descrambler/descrambler.c#L475

Does not seem to change anything.

#7 Updated by Jaroslav Kysela almost 2 years ago

  • Target version set to 4.2

#8 Updated by Richard Farnsworth almost 2 years ago

Any hint or quick-hack how to increase the named ring buffer to cover 1-2s would be really appreciated.

#9 Updated by Jaroslav Kysela almost 2 years ago

Could you try this patch (and increase the buffer on line 475) ?

diff --git a/src/descrambler/descrambler.c b/src/descrambler/descrambler.c
index c0fa6a8..83b7e71 100644
--- a/src/descrambler/descrambler.c
+++ b/src/descrambler/descrambler.c
@@ -540,6 +540,10 @@ descrambler_table_callback
           dr = t->s_descramble;
           if (dr) {
             dr->dr_ecm_start = dispatch_clock;
+            if (ptr[0] == 0x80)
+              dr->dr_key_valid &= ~0x40;
+            elif (ptr[0] == 0x81)
+              dr->dr_key_valid &= ~0x80;
             tvhtrace("descrambler", "ECM message (section %d, len %d, pid %d) for service \"%s\"",
                      des->number, len, mt->mt_pid, t->s_dvb_svcname);
           }

#10 Updated by Jaroslav Kysela almost 2 years ago

Change the 'elif' to 'else if' (sorry python habits).

#11 Updated by B C almost 2 years ago

I tried your patch but even with a quite small buffer (7500*188, < 1.5MB), it will break decryption quite often with invalid stream key. The desired functionality IMHO should include the following functionality.

  • apply this buffer only for certain CAIDs (or better ca system, ATM it only is desireable for NDS, so anything starting with 09XX)
  • if buffering, start with a (configurable) small (or w/o) buffer so it does not cause delays while channel switching
  • if a CW arrives late, readjust the buffer to a configurable bigger value, so it will tolerate these late CWs as longe as the channel is not changed.

#12 Updated by B C almost 2 years ago

just some backround info why the CA system is important. In the case of NDS, the new CW arrives really short bevor it is needed, so a buffer won't harm for almost a whole cw cycle (7 sec). On the other hand most other CA systems send the new CW shortly after the old is invalid, which, when delaying eg for 1 second, would still be valid, but overwritten by the new one. The patch did work fine with NDS, but it failed on CW and Nagra (all locals). I remember getting glitches on CW for ORF when it was possible to emulate this card and the answer came faster than expected. That's why there is a possibility to delay the CW answer in OSCAM.

#13 Updated by Jaroslav Kysela almost 2 years ago

The patch was indented only for a test for NDS. So, if I understand correctly, it works (with the invalid key messages which should be ignored) with NDS ? I need to rethink the descrambling for this type of ECM handling.

Do you know, if NDS is combined with other systems ? Basically, if a simple CAID check for 09xx is enough to switch the ECM logic.

#14 Updated by B C almost 2 years ago

Yes it did work at first sight, but I will have to verify this a little bit more as I'm not facing any delays out of the spec with my local. I will configure OSCAM to do the bad stuff in the evening and check if it actually does still work if I delay the answer for 1 second. As there are simulcrypt channels, the ECM / buffer logic needs to cope with that, so actually do this only if the actual used CA system is NDS. The short ECM to CW time is valid for all SKY Europe channels, but IIRC Viasat might have a more relaxed timing, which would make it necessary to match multiple full CAIDs, I will check this as well.
Another approach for setting/enabling the buffer might be to let it kick in at the time where the first CW arrives late, this would cause a one time glitch at the first late CW at which time the delay between new ECM and new key would already be known, and based on weather offset is < 1 sec buffer the streeam for a few MBs.
And last but not least, as we already have the possibility to lock the ECM PID per channel, add another option here to enable buffering by default.

#15 Updated by Richard Farnsworth almost 2 years ago

Thanks for the feedback!

Tried the patch with buffer set to 20000*188, ~3.5MB. My test channel streams with ~8000kb/s, so the buffer should be good for >3s.

However, an ECM delay of 1500ms keeps being an issue.

Regards,
Richard

#16 Updated by B C almost 2 years ago

I also was not successful with this patch, I did set a delay in OSCAM and did get glitches.

#17 Updated by Jaroslav Kysela almost 2 years ago

Do you see any "invalid key messages" in log ? Provide "descrambler" trace log...

#18 Updated by B C almost 2 years ago

yes, I get them for every CW change. My buffer was set to 7500 * 188 Bytes, bit rate of the channel is about 5mbit, log is from a 2 second delayed CW. Still working without delay.

2015-09-23 15:42:27.092 mpegts: 11992.5H in Astra 1 19.2 - tuning on STV090x Multistandard : DVB-S #2
2015-09-23 15:42:27.300 capmt: OSCAM Spaz (local): Starting CAPMT server for service "13th Street HD" on adapter 2 seq 0x0003
2015-09-23 15:42:27.300 subscription: 0007: "192.168.0.6 [  | Kodi Media Center ]" subscribing on channel "13th Street HD", weight: 150, adapter: "STV090x Multistandard : DVB-S #2", network: "Astra 1 19.2", mux: "11992.5H", provider: "SKY", service: "13th Street HD", profile="htsp", hostname="192.168.0.6", username="192.168.0.6", client="Kodi Media Center" 
2015-09-23 15:42:28.601 descrambler: cannot decode packets for service "13th Street HD" 
2015-09-23 15:42:29.823 descrambler: Obtained keys from capmt-192.168.0.128-9000 for service "13th Street HD" 
2015-09-23 15:42:29.854 TS: Astra 1 19.2/11992.5H/13th Street HD: TELETEXT @ #32 Continuity counter error (total 1)
2015-09-23 15:42:30.657 descrambler: 13th Street HD even stream key is not valid
2015-09-23 15:42:32.074 TS: Astra 1 19.2/11992.5H/13th Street HD: H264 @ #767 Continuity counter error (total 1)
2015-09-23 15:42:32.074 TS: Astra 1 19.2/11992.5H/13th Street HD: AC3 @ #771 Continuity counter error (total 1)
2015-09-23 15:42:32.074 TS: Astra 1 19.2/11992.5H/13th Street HD: AC3 @ #772 Continuity counter error (total 1)
2015-09-23 15:42:37.663 descrambler: ECM late (5 seconds) for service "13th Street HD" 
2015-09-23 15:42:39.080 descrambler: cannot decode packets for service "13th Street HD" 
2015-09-23 15:42:39.088 descrambler: Obtained keys from capmt-192.168.0.128-9000 for service "13th Street HD" 
2015-09-23 15:42:44.669 descrambler: 13th Street HD even stream key is not valid
2015-09-23 15:42:46.067 TS: Astra 1 19.2/11992.5H/13th Street HD: TELETEXT @ #32 Continuity counter error (total 4)
2015-09-23 15:42:46.068 TS: Astra 1 19.2/11992.5H/13th Street HD: H264 @ #767 Continuity counter error (total 3)
2015-09-23 15:42:46.068 TS: Astra 1 19.2/11992.5H/13th Street HD: AC3 @ #771 Continuity counter error (total 3)
2015-09-23 15:42:46.068 TS: Astra 1 19.2/11992.5H/13th Street HD: AC3 @ #772 Continuity counter error (total 3)
2015-09-23 15:42:46.073 parser: transport stream AC3, DTS discontinuity. DTS = 1488690, last = 1385010
2015-09-23 15:42:46.075 parser: transport stream AC3, DTS discontinuity. DTS = 1497600, last = 1393920
2015-09-23 15:42:51.656 descrambler: ECM late (5 seconds) for service "13th Street HD" 
2015-09-23 15:42:52.210 descrambler: cannot decode packets for service "13th Street HD" 
2015-09-23 15:42:53.061 descrambler: Obtained keys from capmt-192.168.0.128-9000 for service "13th Street HD" 
2015-09-23 15:42:53.084 parser: transport stream AC3, DTS discontinuity. DTS = 2116800, last = 2013120
2015-09-23 15:42:53.086 parser: transport stream AC3, DTS discontinuity. DTS = 2122290, last = 2018610
2015-09-23 15:42:58.663 descrambler: 13th Street HD even stream key is not valid
2015-09-23 15:43:00.081 TS: Astra 1 19.2/11992.5H/13th Street HD: TELETEXT @ #32 Continuity counter error (total 7)
2015-09-23 15:43:00.081 TS: Astra 1 19.2/11992.5H/13th Street HD: H264 @ #767 Continuity counter error (total 5)
2015-09-23 15:43:00.081 TS: Astra 1 19.2/11992.5H/13th Street HD: AC3 @ #771 Continuity counter error (total 5)
2015-09-23 15:43:00.081 TS: Astra 1 19.2/11992.5H/13th Street HD: AC3 @ #772 Continuity counter error (total 5)
2015-09-23 15:43:00.082 parser: transport stream H264, DTS discontinuity. DTS = 2815355, last = 2712755
2015-09-23 15:43:00.088 parser: transport stream AC3, DTS discontinuity. DTS = 2764800, last = 2646720
2015-09-23 15:43:00.089 parser: transport stream AC3, DTS discontinuity. DTS = 2770290, last = 2652210
2015-09-23 15:43:05.669 descrambler: ECM late (5 seconds) for service "13th Street HD" 
2015-09-23 15:43:06.142 descrambler: cannot decode packets for service "13th Street HD" 
2015-09-23 15:43:07.055 descrambler: Obtained keys from capmt-192.168.0.128-9000 for service "13th Street HD" 
2015-09-23 15:43:07.074 parser: transport stream AC3, DTS discontinuity. DTS = 3384000, last = 3280320
2015-09-23 15:43:07.074 parser: transport stream AC3, DTS discontinuity. DTS = 3389490, last = 3285810
2015-09-23 15:43:11.338 subscription: 0007: "192.168.0.6 [  | Kodi Media Center ]" unsubscribing from "13th Street HD", hostname="192.168.0.6", username="192.168.0.6", client="Kodi Media Center" 
2015-09-23 15:43:11.339 capmt: OSCAM Spaz (local): Removing CAPMT Server from service "13th Street HD" on adapter 2

#19 Updated by Jaroslav Kysela almost 2 years ago

Pls, use "--trace descrambler" to see the details from tvh.

#20 Updated by B C almost 2 years ago

stupid me, as I actually made it, but only posted the debug output. here it is

#21 Updated by Richard Farnsworth over 1 year ago

Seeing that perexg is quite busy fixing other stuff... @BC, have you been able to find a possible fix or workarounf late NDS ECMs? I'm really annoyed by the hiccups in my setup, especially in recordings I would like to archive... :(

#22 Updated by Jaroslav Kysela over 1 year ago

Richard, try latest v4.1-517-ge9c9344 . It works here.

#23 Updated by Jaroslav Kysela over 1 year ago

  • Subject changed from CA: configurable playback buffer/delay to tolerate late ECMs to CA: configurable playback buffer/delay to tolerate late ECMs (NDS specific ECM handling)

#25 Updated by Richard Farnsworth over 1 year ago

Cool stuff, thanks a LOT. Will try as soon as I'm home this night!

Thanks,
Rich.

#26 Updated by Jaroslav Kysela over 1 year ago

Unfortunately, it seems that the "quick ECM" (I named the behaviour when ECM changes right before the key is used) detection should be improved. I broke other users with this commit which uses only simple 09xx check. Appearently, it affects only specific CAIDs.. And it seems that there are combinations of NDS / other CAIDs in the current broadcasts.

#27 Updated by Jaroslav Kysela over 1 year ago

Fixed in https://tvheadend.org/projects/tvheadend/repository/revisions/595cd1de9008bd9d4ca8cf86d235b21267af3417/diff/ - quick CAIDs are configurable (data/conf/descrambler file).

I know only about 09C4 (Sky DE) and 09CD (Sky IT) caids handled in the "quick ECM" mode at the moment.

#28 Updated by B C over 1 year ago

Sky DE/AT is also on 098C, Sky UK on 0963, I will check if Sky IT and Sky UK are still using some old IDs in parallel
Testing soon, thanks for all your efforts

#29 Updated by Richard Farnsworth over 1 year ago

Do you have an example how data/conf/descrambler could look like?

#31 Updated by Jaroslav Kysela over 1 year ago

@B C: I'm not sure if the older NDS CAIDs do work in the "quick ECM" mode. They require some testing... It might be that only 09Cx CAIDs are "quick".

#32 Updated by Richard Farnsworth over 1 year ago

Hmm, looks like the new quick ecm feature does not kick in here?

I added 098C to the config, since this is how Sky DE is coming in here.

See in the log:
descrambler: adding CAID 098C as quick ECM (Sky DE)

This is how I see requests in oscam.log:
2015/10/02 07:55:19 5A6F1002 c (ecm) anonymous (098C@000000/0259/0081/98:A44A7816196229D1C475E63B90CBE82F): found (144 ms) by skyde2_cccam - Sky Sport HD 1

But nothing concerning quick ecm in the descrambler trace...

http://paste.ubuntu.com/12636707/

What am I missing?

Thanks,
Richard.

#33 Updated by B C over 1 year ago

I did not look at the logs but with a delay set to 1500ms I still get no glitshes, so basically it should work, just didn't have some time to test it.

@Jaroslav, I'm quite sure that the mentioned CAIDs are "quick"

#34 Updated by Jaroslav Kysela over 1 year ago

@Richard - I don't see any subscribed ECM PID from the capmt (dvbapi) server in your logs and TVH makes a decision based on this PID subscription. It's something new to me - it seems like an oscam bug or something is shared ? Could you try the latest oscam with "OSCam net protocol" mode in TVH ?

#36 Updated by B C over 1 year ago

looking good, Sky IT is also missing, but as I said I will do more testing in the evening

#37 Updated by Richard Farnsworth over 1 year ago

Cool! With OSCam net protocol the new code is used... and seems to work as expected. THANK YOU!

Sometimes playback gets stalled when zapping channels with Kodi. Need to check if this is related to this enhancement or a generel OSCam issue.

Just for my understanding... the configurable buffer is only filled while ECMs come in late? So I see at minumum a single stutter before it gets used? And then, how much is buffered, only while waiting for the ECM or is the code proacively buffering "more" to cope with future "longer" wait times?

Also, for recordings the buffer could be filled unconditionally, coudn't it? :)

Thanks a LOT! One of the most usable enhancements ever for me!

Rich.

#38 Updated by Jaroslav Kysela over 1 year ago

The buffering scheme is trivial - the current code always decodes all data when the key is available and buffers data up to specified amounf of TS packets in the general configuration when the key is not available.

I believe that client (player) should do proper buffering when the ECM is late. In this case, there's "time gap" in the stream delivery until the key is not received and then all descrambled data from the temporary buffer are flushed out (the temporary buffer becomes empty).

#39 Updated by Mario D over 1 year ago

It works great with sky-it 09cd!

#40 Updated by Mario D over 1 year ago

Perex, could you explain the meaning of the length of the buffer? Does it make sense to raise it? In case, does it create any kind of initial pause to do buffering when I synth on a channel?
I think this feature is almost unique among similar systems (vdr, enigma2, ...). So simple, so useful!

Thanks.

#41 Updated by Jaroslav Kysela over 1 year ago

The length of buffer is 'value * 188' to get bytes. You can use this value to compute the relationship with the stream bandwidth:

default buffer length in bytes - 9000 * 188 (TS packet size) - 1692000 bytes

10mbps - 1250000 bytes per sec - 1692000/1250000 is about 1.35 seconds
1mbps  -  125000 bytes per sec - 1692000/125000  is about 13.5 seconds

So, if you have HD channels and don't care to waste some megabytes of memory, you may increase the default value by 3-4 times.

And as I explained in my previous comment, the streaming time gaps depend entirely on the time when the key is received. TVH descrambles and sends the descrambled data to other streaming layers immediatelly when the key is received (valid).

#42 Updated by Jaroslav Kysela over 1 year ago

  • Status changed from New to Fixed

Closing as fixed.

#43 Updated by Mario D over 1 year ago

@B C: could you specify which option did you use to simulate delay in oscam? I would make more testing with other CAIDs.
@perex: is there any possibility that this kind of buffering could work on a nagra CAID (in my case DVB-T)?

#44 Updated by B C over 1 year ago

go to Config --> DVB-Api, there you have Delayer.

Regarding your nagra buffering, normally the new ECM should arrive shortly after the CW has changed, so if that is not different with Silvios flavour of nagra, a buffer would be necessary to hold more than a complete CW cycle which would complicate CW matching a bit. It should be enough to add the CA id to data/conf/descrambler to test if buffering can help in your case (unless there is not some check for 09xx in the first place in the code). What is your current CW cycle time and what is the worst key offset it can cope with?

#45 Updated by Mario D over 1 year ago

I'm testing the suggested oscam feature without success:

cat ~/.oscam/oscam.conf | grep -i delay
delayer                       = 3000

Even restarting oscam, using NDS 09cd card, I can still note good ecm timing: 200-400ms in tvheadend log. What I'm doing wrong?!

#46 Updated by B C over 1 year ago

the log won't change, it's the time all CW responses will be delayed. No matter if the card answers within 200ms or 800ms (thats what you are seeing in the log), the actual CW will be delivered to the DVB-Api client no earlier than the delayer time. You should see this when you enable DVB-Api logging in OSCAM. For me I can delay 098c up to 1500ms without any problems, higher values are freezing every CW cycle as expected. Without the buffer maximum delay was < 700

#47 Updated by Mario D over 1 year ago

Ok, the ecm timing reported by (new) tvheadend and oscam are the real ones: without the extra delay introduced by 'delayer' parameter.
Using an NDS 09CD CAID on an SD channel, with a buffer of 9000 TS packets, I get few data errors even using delayer of about 5000-6000 ms. With longer delay, I get regular data errors.
Using a nagra 183D CAID (the italian TivuSat) on DVB-S (Hotbird 13°), inserting the CAID in the 'descrambler' file, the descrambling breaks with errors in decoding even if all is fine on oscam-side. The new buffering breaks stuff with nagra cards as suggested by @perex.

#48 Updated by B C over 1 year ago

you must not touch a full cw cycle, so for nds with ecms close to the cw change that is the cyle time (about 7 seconds on sky it) - ecm offset, so that is about 6 seconds. when the new ecm arrives shortly after the cw change the new cw arrives befor it is needed and you get a glich till it is valid if you buffer. so in case of tivusat cw can arrive up to about 6seconds after the new ecm if they also have a 7 second cycle. buffering is counter productive in that case.

#49 Updated by Mario D over 1 year ago

I'm not to sure to understand the sense of your explanation but it looks strange that a "too big" buffer could create problems in reproduction. Consider that I'm using a 90000 TS packages (10 times the default value) buffer now with 09cd. Previous tests were carried using the default value (9000).

#50 Updated by B C over 1 year ago

quite simple described, you use only a fraction of the buffer, the later the cw arrives the more you use the buffer BUT it does only work as long as the buffer is less than the CW cycle length, as there is currently no logic in the code to sync the cw with the matching region. Although this might seem like it could be improved, it is unlikely that if your CWs arrive later than a CW cycle, that you get constantly CWs anyway.

#51 Updated by Mario D over 1 year ago

In my tests with tivusat (nagra), inserting the CAID 183D in the 'descrambler' file, I get regular glitch even with 'delayer=0' (good ECM timing from oscam), so enabling the 'quick ecm' buffering breaks the decoding. That's what I mean.

#52 Updated by Jaroslav Kysela over 1 year ago

Mario, your CAID is not "quick ECM". The other CAIDs has plenty time to get the key (around 10 seconds - 8 second is safe). The TS buffer is used only at start of streaming in standard descrambling. The ECM is sent approx. 10 seconds before the key is required (used for descrambling) for standardly behaving CAIDs. So, don't try to solve an issue which does not even exist :-)

I mean with words "big buffer" that if encrypted data in the buffer might be for older keys which are never delivered, so the content of the buffer might be descrambled using a wrong key (newer) in this case.

Also available in: Atom PDF