Feature #3784
Ziggo problems (NL)
100%
Description
Ziggo changes their muxes so often, they have to be updated on a regular base.
The thing is, Ziggo is a shitty (DVB-C) provider, but where I live I've got no good other choise.
I know that it's not your propblem, but I'm sure you can help me to address this issue, time and energy permitting...
CASE:
Every other week, sometimes it takes (much) longer for them to screw up, I can't tune to the channels that I mapped anymore.
REMEDY:
Tune to a channel I've mapped (from Kodi livetv, either Jarvis or Krypton,no difference) and stop tuning.
Then tune again to the same channel and as a result the channel starts working again.
I have to repeat this action for each and every channel I've mapped.
All of the ~/.hts/tvheadend/input/dvb/networks/blabla/muxes are updated when I'm done, though I use only a couple of them.
THE GOOD NEWS:
TVH does a great job, it never faild to accurately update the muxes. (using various versions of the master branch, I'm now at master HEAD)
THE QUESTION:
Is it doable (within reason) to let TVH autotune to the mapped channels, without recording anything, let's say every 12 hours?
That would solve the problem I experience with my shitty provider.
BTW: although it's a shitty provider, they DO serve the absolute best quality where it comes to HDTV broadcasts where I live.
Again, it's not your problem, but I'd really appreciate you fixing this for me.
Thanks in advance.
Files
History
Updated by Jaroslav Kysela over 8 years ago
Updated by I think that we should determine why the subscription to the channel fails. Could you provide "--trace mpegts,service,cwc,capmt,descrambler" when tuning works and when it stops?
Updated by bas t over 8 years ago
Updated by OK, I'll first recompile TVH with --enable-trace
I'm recording some shows right now, so that'll be tomorrow.
Thanks for your rapid answer.
Updated by bas t over 8 years ago
I really wish I filed this issue just one day ago, since I had to go to the described procedure today on my backup system.
Now we'll have to wait until the subscription fails again.
There's no way to know how long that'll take..
Well, at least we've got a starting point.
Updated by bas t over 8 years ago
- File tvheadend.log tvheadend.log added
Startup and successful tuning log attatched.
So now we'll have to wait for the tuning failure.
Updated by bas t over 8 years ago
- File tvheadend.log.tar.gz tvheadend.log.tar.gz added
Well, that didn't take so long.
I added a trace log where I first tune to a channel and it failed. Then I tune to the same channel again and it works again.
Updated by Jaroslav Kysela over 8 years ago
Bad:
2016-05-10 07:43:08.192 [ DEBUG]:cwc: ECM state INIT 2016-05-10 07:43:08.192 [ DEBUG]:cwc: Insert preferred ECM (PID 303) for service "RTL 8 HD" 2016-05-10 07:43:08.192 [ TRACE]:descrambler: ECM message 81 (section 0, len 68, pid 303) for service "RTL 8 HD" 2016-05-10 07:43:08.192 [ TRACE]:descrambler: ECM message 81 (section 1, len 68, pid 303) for service "RTL 8 HD" 2016-05-10 07:43:08.192 [ TRACE]:descrambler: initial stream key set to odd for service "RTL 8 HD"
Good:
2016-05-10 07:44:09.738 [ DEBUG]:cwc: ECM state INIT 2016-05-10 07:44:09.738 [ DEBUG]:cwc: Insert preferred ECM (PID 302) for service "RTL 8 HD" 2016-05-10 07:44:09.738 [ TRACE]:cwc: sending message sid 19422 len 90 enq 1 2016-05-10 07:44:09.738 [ TRACE]:cwc: 00 00 44 F2 E9 82 AD F2 27 65 95 BC D3 9E 5E 36 ..D.....'e....^6 2016-05-10 07:44:09.738 [ TRACE]:cwc: A9 FD 5D EB 71 2D 74 11 1B 6C 49 E2 FD DF D1 E5 ..].q-t..lI..... 2016-05-10 07:44:09.738 [ TRACE]:cwc: 08 20 76 C8 7A A4 29 2D 86 64 50 7E 4E CF 0D 28 . v.z.)-.dP~N..( 2016-05-10 07:44:09.738 [ TRACE]:cwc: 41 6A 89 94 A7 46 5A 59 8E FA CB EA 09 94 CB 17 Aj...FZY........ 2016-05-10 07:44:09.738 [ TRACE]:cwc: 10 2B 35 CD 62 62 7A F1 D7 24 82 F7 34 34 AD 5D .+5.bbz..$..44.] 2016-05-10 07:44:09.738 [ TRACE]:cwc: 40 77 69 11 79 7C 11 EB C9 6D @wi.y|...m 2016-05-10 07:44:09.738 [ DEBUG]:cwc: Sending ECM (PID 302) section=0/1, for service "RTL 8 HD" (seqno: 27) 2016-05-10 07:44:09.738 [ TRACE]:descrambler: ECM message 80 (section 0, len 68, pid 302) for service "RTL 8 HD" 2016-05-10 07:44:09.738 [ TRACE]:cwc: sending message sid 19422 len 90 enq 1 2016-05-10 07:44:09.738 [ TRACE]:cwc: 00 00 03 60 64 DA 9C 22 DB 1C 3C 28 6E B0 C1 91 ...`d.."..<(n... 2016-05-10 07:44:09.738 [ TRACE]:cwc: 42 D6 98 1B 00 B9 06 73 6C 31 77 69 8C E4 66 3B B......sl1wi..f; 2016-05-10 07:44:09.738 [ TRACE]:cwc: AD 89 DD FB 5B ED 20 32 31 01 9C 06 A9 A2 9D 0A ....[. 21....... 2016-05-10 07:44:09.738 [ TRACE]:cwc: 77 07 B5 EF 88 5B 86 48 20 0B 73 0F 3F DF 2C 87 w....[.H .s.?.,. 2016-05-10 07:44:09.738 [ TRACE]:cwc: 86 DF E7 3B 25 05 4E 4F 0A 4F 05 15 81 06 CB 3A ...;%.NO.O.....: 2016-05-10 07:44:09.738 [ TRACE]:cwc: 32 2E 99 86 73 35 BC DB 4C E1 2...s5..L. 2016-05-10 07:44:09.738 [ DEBUG]:cwc: Sending ECM (PID 302) section=1/1, for service "RTL 8 HD" (seqno: 28) 2016-05-10 07:44:09.738 [ TRACE]:descrambler: ECM message 80 (section 1, len 68, pid 302) for service "RTL 8 HD" 2016-05-10 07:44:09.738 [ TRACE]:descrambler: initial stream key set to even for service "RTL 8 HD"
Updated by bas t over 8 years ago
So I guess this one is to blame:
cwc: Insert preferred ECM (PID 303) for service "RTL 8 HD"
But why should it send a wrong preferred ECM?
Updated by Jaroslav Kysela over 8 years ago
It looks that your provider changes the PID for ECM data at a time and tvh does not detect this situation, so the first tuning fails (old CAID PID for ECMs) and the next is fine (because it uses the actual CAID PID for ECMs). I tried to fix this in v4.1-2002-gbd6dcac .
Updated by bas t over 8 years ago
OK, so now I leave my backup system untouched. I'll try every day to see if tuning fails. When it does and my master backend is not affected anymore, I guess you hit the jackpot.
Well, in fact I hit the jackpot 'having' you as a dev.
Thank you so much!
Will report back.
Cheers!
Tycho.
Updated by Martijn Hoogenbosch over 8 years ago
Updated by bas t wrote:
OK, so now I leave my backup system untouched. I'll try every day to see if tuning fails. When it does and my master backend is not affected anymore, I guess you hit the jackpot.
Well, in fact I hit the jackpot 'having' you as a dev.
Thank you so much!Will report back.
Cheers!
Tycho.
The weird thing is, i have exactly the same provider and never run into the problems you are describing. So before things get fixed, it's a good idea why this happens to you. I'm using tvheadend-testing on a Synology. This is version 4.1.1996, but even on much older versions, i've never had the situation you are describing.
Updated by bas t over 8 years ago
Hi Martijn,
from the description + logs you can see that Ziggo changed the PID for ECM at least 2 times in the last 4 or 5 days. That is, where I live (Groningen)
That's a fact.
The reason you are not affected, or at least you don't notice that you are, might be that you have enabled 'idle scanning', which is the default.
This takes care of the problem. But only by hiding it.
Or that where you live, Ziggo behaves like it should, by not messing with their tables (I find that very hard to believe)
Or that in the version of TVH you use is older then something like the beginning of april this year. I don't remember suffering from this issue before that, and I don't believe that Ziggo started messing with their tables only this spring.
Updated by bas t over 8 years ago
- File rtl8hd.png rtl8hd.png added
Hi Jaroslav, I thought of other possible scenarios, please comment.
when Ziggo and UPC merged, all of the scrambled channels got extra CA PID's, because UPC uses Nagra2 encryption while Ziggo uses Irdeto.
So now we have 5 CA PID's on each channel to choose from, mine beeing 0604 (irdeto)
For RTL 8 HD, the channel I logged, this results in the following (Kudelski SA is the owner of Nagra):
ECM CA system id 0x1801 ( Kudelski SA ) with PID 52
ECM CA system id 0x1850 ( Kudelski SA ) with PID 53
ECM CA system id 0x0602 ( Irdeto ) with PID 202
ECM CA system id 0x0604 ( Irdeto ) with PID 302 <-- this one is mine!
ECM CA system id 0x0606 ( Irdeto ) with PID 402
Now what happens is that tvh will try all of these in this given order (if I recall correct), resulting in much slower tuning, unless your id is 0x1801
I don't like that, so I'm filtering all unwanted id's out and only leave in 0x0604.
You can see the details in the attached rtl8hd.png.
The id's never change, but the PID's can change whenever Ziggo likes to do so.
Here comes the guessing part.
Scenario 1:
Maybe TVH's cwc used the id's to obtain the correct PID and get the right data from oscam in the past and only recently started using the preferred ECM using the known PID.
Scenario 2:
When I dont't use the CA filter, TVH already tried to tune a couple of times before reaching the right id and by doing so, it updated the PID's for the channel prior to reaching 0x0604.
When I do use the filter, TVH has only one shot and that has to be right or the tuning fails.
(I'm going to test this scenario the first time I run into a changed PID)
Your thoughts?
Updated by Beralt Meppelink over 8 years ago
Updated by This issue is two-fold:
- Ziggo changed their CA system, adding CAID 0x0606 which contains EMM's for CAID 0x0604. I noticed that my card was no longer updated, since I used an exclusive CA stream filter for CAID 0x0604. Removing the filter helped to get the EMM's to the card again. I'm seriously wondering if this was a mistake on their end. Just a heads up for anyone using exclusive CA stream filters.
- Ziggo decided that switching the PID for CA streams was a very good move.
I'm also having problems with the PID switch not being detected. Tuning to live TV is easily solved by retuning, but sometimes recordings fail with "too many data errors" which obviously is due to the inability to descramble.
Time to pull, compile and test!
Updated by Beralt Meppelink over 8 years ago
Tested with 4.1-2025~g80c990d, and the wrong PID is selected on the first run after the PID move by the provider. So I debugged a wrong recording, focussing on the PMT update of the service:
Bad recording:
2016-05-12 10:17:54.706 dvr: "Toekomstmakers" on "RTL Z HD" recorder starting
2016-05-12 10:17:55.731 mpegts: 538MHz in Ziggo - open PID 012D (301) [32/0x7f48ac016310]
2016-05-12 10:17:55.808 pmt: caid 1801 (NagraVision) provider 00000000 pid 0037
2016-05-12 10:17:55.808 pmt: caid 1850 (NagraVision) provider 00000000 pid 0038
2016-05-12 10:17:55.808 pmt: caid 0602 (Irdeto) provider 00000000 pid 00CB
2016-05-12 10:17:55.808 pmt: caid 0604 (Irdeto) provider 00000000 pid 012F
2016-05-12 10:17:55.808 pmt: caid 0606 (Irdeto) provider 00000000 pid 0193
2016-05-12 10:17:55.808 pmt: Service "Ziggo/538MHz/RTL Z HD" PMT (version 28) updated, Stream deleted, New CA stream, New CAID, CAID deleted
2016-05-12 10:17:55.911 cwc: Insert preferred ECM (PID 301) for service "RTL Z HD"
Which is weird since the PMT is correctly updated with PID 0x012F (303), but the CAID PID change is not detected and the cwc thus used an old PID.
The next run contains these lines:
2016-05-12 10:28:17.463 pmt: caid 1801 (NagraVision) provider 00000000 pid 0037
2016-05-12 10:28:17.463 pmt: caid 1850 (NagraVision) provider 00000000 pid 0038
2016-05-12 10:28:17.463 pmt: caid 0602 (Irdeto) provider 00000000 pid 00CB
2016-05-12 10:28:17.463 pmt: caid 0604 (Irdeto) provider 00000000 pid 012F
2016-05-12 10:28:17.463 pmt: caid 0606 (Irdeto) provider 00000000 pid 0193
2016-05-12 10:28:17.463 pmt: Service "Ziggo/538MHz/RTL Z HD" PMT (version 28) updated, CAID PID changed
2016-05-12 10:28:17.495 cwc: Insert preferred ECM (PID 303) for service "RTL Z HD"
Where the CAID PID change is indeed detected, and the correct PID is used for the cwc.
So tuning twice still solves the problem because the PID change is only detected in the second tune. The reason why this occurs is because it detects a CAID change the first time, and this line: [[https://github.com/tvheadend/tvheadend/blob/master/src/input/mpegts/dvb_psi.c#L2047]] only sets CAID PID update change when the CAID is not updated.
So why is the CAID set to "New CAID, CAID deleted"? I don't have the pmt debug info of the run before the bad run, but I'm guessing that once the CAID PID is moved it first marks the CAID deleted, and CAID added, which is actually not a delete and added CAID but just a moved PID.
Does that help?
Updated by bas t over 8 years ago
I'm using an exclusive filter for CAID 0x0604 for 5 months now.
My cards are still working, so updated.
Updated by Martijn Hoogenbosch over 8 years ago
bas t wrote:
I'm using an exclusive filter for CAID 0x0604 for 5 months now.
My cards are still working, so updated.
I had the same problem as Beralt, so maybe there is a difference between locations. You are in Groningen, i'm in Utrecht... could be of impact?
Updated by Jaroslav Kysela over 8 years ago
Could you try v4.1-2027-gfc9f401 ? I see the issue. The 'on-the-fly' ECM PID changes were not handled for the cwc client.
Updated by Beralt Meppelink over 8 years ago
A short test seems to confirm that this issue is fixed:
2016-05-13 09:33:49.881 pmt: caid 0604 (Irdeto) provider 00000000 pid 012D
2016-05-13 09:33:49.881 pmt: Service "Ziggo/562MHz/National Geographic Channel HD" PMT (version 28) updated, Stream deleted, New CA stream, New CAID, CAID deleted
2016-05-13 09:33:50.032 cwc: Insert preferred ECM (PID 301) for service "National Geographic Channel HD
The cwc seems to get the right PID after the CAID PID change.
Updated by bas t over 8 years ago
- File 2016-05-11 00_18_45.png 2016-05-11 00_18_45.png added
Did the PID in fact change?
I've got a screenshot that I made two days ago, in which the preferred ECM is already set to PID 301 for National Geographic Channel HD
Updated by Beralt Meppelink over 8 years ago
It did change since the last time I tuned to National Geographic Channel HD. This is confirmed by the pmt debug line indicating a new CA stream, New CAID, CAID deleted. The deleted stream in this case is the old CA stream, the new one is shown in the line above (0x012D or 301).
Updated by Jaroslav Kysela over 8 years ago
Just a note: I fixed this issue also for CAPMT client - version v4.1-2036-g268d89f .
Updated by B.A. Derks over 8 years ago
Updated by 
I encountered this problem as well over the last couple of days and this problem still occurs after I installed version 4.1-2038.
2016-05-14 14:18:55.621 dvr: entry 6ea43807bb683c15b9cc7755d0c94e06 "Wielrennen" on "Eurosport 1 HD" starting at 2016-05-14 12:57:30, scheduled for recording by "192.168.178.12" 2016-05-14 14:18:55.621 dvr: "Wielrennen" on "Eurosport 1 HD" recorder starting 2016-05-14 14:18:55.621 mpegts: 370MHz in Ziggo - tuning on HDHomeRun DVB-C Tuner #0 (192.168.178.13) 2016-05-14 14:18:55.621 tvhdhomerun: tuning to a8qam256-6900:370000000 2016-05-14 14:18:55.628 capmt: Ziggo: Starting CAPMT server for service "Eurosport 1 HD" on adapter 0 2016-05-14 14:18:55.628 subscription: 0004: "DVR: Wielrennen" subscribing on channel "Eurosport 1 HD", weight: 300, adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "370MHz", provider: "Ziggo", service: "Eurosport 1 HD", profile="pass" 2016-05-14 14:18:56.003 dvr: /var/media/Captures/2016-05-14 13.00 - Wielrennen (Eurosport 1 HD).ts from adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "370MHz", provider: "Ziggo", service: "Eurosport 1 HD" 2016-05-14 14:18:56.003 dvr: # type lang resolution aspect ratio sample rate channels 2016-05-14 14:18:56.003 dvr: 1 H264 ? ? 2016-05-14 14:18:56.003 dvr: 2 MPEG2AUDIO dut ? ? 2016-05-14 14:18:56.003 dvr: 3 MPEG2AUDIO eng ? ? 2016-05-14 14:18:56.003 dvr: 9 CA 2016-05-14 14:18:56.003 dvr: 10 CA 2016-05-14 14:18:56.003 dvr: 11 CA 2016-05-14 14:18:56.003 dvr: 12 CA 2016-05-14 14:18:56.003 dvr: 13 CA 2016-05-14 14:18:56.003 dvr: 14 TELETEXT 2016-05-14 14:19:07.356 descrambler: ECM - key late (1013 ms) for service "Eurosport 1 HD" 2016-05-14 14:19:08.594 TS: Ziggo/370MHz/Eurosport 1 HD: H264 @ #2301 Continuity counter error (total 1) 2016-05-14 14:19:08.594 TS: Ziggo/370MHz/Eurosport 1 HD: MPEG2AUDIO @ #2312 Continuity counter error (total 1) 2016-05-14 14:19:08.594 TS: Ziggo/370MHz/Eurosport 1 HD: TELETEXT @ #2401 Continuity counter error (total 1) 2016-05-14 14:19:08.594 TS: Ziggo/370MHz/Eurosport 1 HD: MPEG2AUDIO @ #2311 Continuity counter error (total 1) 2016-05-14 14:19:08.595 descrambler: cannot decode packets for service "Eurosport 1 HD" 2016-05-14 14:19:18.657 descrambler: cannot decode packets for service "Eurosport 1 HD" 2016-05-14 14:20:04.266 subscription: 0004: "DVR: Wielrennen" unsubscribing from "Eurosport 1 HD" 2016-05-14 14:20:04.267 capmt: Ziggo: Removing CAPMT Server from service "Eurosport 1 HD" on adapter 0 2016-05-14 14:20:04.268 dvr: "Wielrennen" on "Eurosport 1 HD": End of program: Too many data errors 2016-05-14 14:20:04.268 dvr: delete entry 6ea43807bb683c15b9cc7755d0c94e06 "Wielrennen" on "Eurosport 1 HD" start time 2016-05-14 12:57:30, scheduled for recording by "192.168.178.12", retention "Forever" removal "Forever"
After restarting the recoding no problems what so ever
2016-05-14 14:20:11.924 dvr: entry 75842264d3cfd336de42e18a221a54c4 "Wielrennen" on "Eurosport 1 HD" starting at 2016-05-14 12:57:30, scheduled for recording by "192.168.178.12" 2016-05-14 14:20:11.924 dvr: "Wielrennen" on "Eurosport 1 HD" recorder starting 2016-05-14 14:20:11.925 mpegts: 370MHz in Ziggo - tuning on HDHomeRun DVB-C Tuner #0 (192.168.178.13) 2016-05-14 14:20:11.925 tvhdhomerun: tuning to a8qam256-6900:370000000 2016-05-14 14:20:11.930 capmt: Ziggo: Starting CAPMT server for service "Eurosport 1 HD" on adapter 0 2016-05-14 14:20:11.930 subscription: 0005: "DVR: Wielrennen" subscribing on channel "Eurosport 1 HD", weight: 300, adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "370MHz", provider: "Ziggo", service: "Eurosport 1 HD", profile="pass" 2016-05-14 14:20:12.270 dvr: /var/media/Captures/2016-05-14 13.00 - Wielrennen (Eurosport 1 HD).ts from adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "370MHz", provider: "Ziggo", service: "Eurosport 1 HD" 2016-05-14 14:20:12.270 dvr: # type lang resolution aspect ratio sample rate channels 2016-05-14 14:20:12.270 dvr: 1 H264 ? ? 2016-05-14 14:20:12.270 dvr: 2 MPEG2AUDIO dut ? ? 2016-05-14 14:20:12.270 dvr: 3 MPEG2AUDIO eng ? ? 2016-05-14 14:20:12.270 dvr: 9 CA 2016-05-14 14:20:12.270 dvr: 10 CA 2016-05-14 14:20:12.270 dvr: 11 CA 2016-05-14 14:20:12.270 dvr: 12 CA 2016-05-14 14:20:12.270 dvr: 13 CA 2016-05-14 14:20:12.270 dvr: 14 TELETEXT 2016-05-14 14:22:48.877 subscription: 0005: "DVR: Wielrennen" unsubscribing from "Eurosport 1 HD" 2016-05-14 14:22:48.879 capmt: Ziggo: Removing CAPMT Server from service "Eurosport 1 HD" on adapter 0 2016-05-14 14:22:48.881 dvr: "Wielrennen" on "Eurosport 1 HD": End of program: Aborted by user 2016-05-14 14:22:48.881 dvr: delete entry 75842264d3cfd336de42e18a221a54c4 "Wielrennen" on "Eurosport 1 HD" start time 2016-05-14 12:57:30, scheduled for recording by "192.168.178.12", retention "Forever" removal "Forever"
And the Oscam log of the recording
2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 0 CAID: 1801 ECM_PID: 0036 PROVID: 000000 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012F PROVID: 000000 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CB PROVID: 000000 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0037 PROVID: 000000 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 found 4 ECMpids and 1 STREAMpids in caPMT 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012F ANY CHID PMTPID 0000 VPID 08FD 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 continue decoding of SRVID 4B02 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 4 CAID: 0606 ECM_PID: 0194 PROVID: 000000 2016/05/14 14:18:55 3AA2CE3E c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/14 14:18:56 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:A6ED0CA1107264AE087866E5A0F47E45): found (170 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:19:06 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:8AC23B3979B74E5E8AD3C3077F538FC9): found (169 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:19:12 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/14 14:19:18 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (127 ms) 2016/05/14 14:19:26 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:438DD32CCE4500EF1A1A6ECD7A44BBDC): found (171 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:19:34 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/14 14:19:46 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:8E74A540BC3E802DE14A60CDB0996430): found (171 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:19:53 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (92 ms) 2016/05/14 14:19:53 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/14 14:20:04 3AA2CE3E c (dvbapi) Demuxer 0 stop descrambling program number 4B02 (Eurosport HD) 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0194 PROVID: 000000 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 0130 PROVID: 000000 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CC PROVID: 000000 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0039 PROVID: 000000 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1801 ECM_PID: 0038 PROVID: 000000 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/14 14:20:11 3AA2CE3E c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 0130 ANY CHID PMTPID 0000 VPID 08FD 2016/05/14 14:20:12 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:0B6FEC41F270F88F58162E961C87951A): found (171 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:20:12 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/14 14:20:16 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (121 ms) 2016/05/14 14:20:27 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:3D7F9891A78C0C43FB38335A82E12E08): found (169 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:20:34 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (89 ms) 2016/05/14 14:20:47 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:250A468CBE83B8A28BA6E819DF070B6B): found (170 ms) by ZiggoSmartReader - Eurosport HD 2016/05/14 14:20:52 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (119 ms) 2016/05/14 14:20:52 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/14 14:20:54 6899EB7A r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (126 ms) 2016/05/14 14:21:07 3AA2CE3E c (ecm) Ziggo (0604@000000/000B/4B02/44:FE4AD5CF2793A5F6C03B864F7E94450B): found (169 ms) by ZiggoSmartReader - Eurosport HD
The logfile from Oscam shows a different PMT for the first recording than for the second one. Different number of CA-streams, different order of the CA-streams and different ECM-pids for the CA-streams. Intermediately after finding 4 CA-streams Oscam finds the 5th CA-stream for the 1st recording.
I hope this info contributes to solve the problem with Ziggo changing ECM-pids in Utrecht.
Updated by B.A. Derks over 8 years ago
Unfortunately, v4.1-2040 does not solve the problem with the changed ECM-pids by Ziggo. I included the same kind of log fragments as this shows why this is a very nasty problem. As you can see, the log does not give any clue that there might be a problem with the recording. Only by trying to play the recording you notice that the recording is unplayable. AS you can see in the Oscam log, the ECM-pids did change between the first unplayable recoding and the second playable recording.
In this case the number of discovered CA-streams and the order of the CA-streams are the same for both recording.
tvheadend log unplayable recording
2016-05-15 17:29:34.991 dvr: "Overwinnaars - met Arie Boomsma" on "Net5 HD" recorder starting 2016-05-15 17:29:34.991 mpegts: 490MHz in Ziggo - tuning on HDHomeRun DVB-C Tuner #0 (192.168.178.13) 2016-05-15 17:29:34.991 tvhdhomerun: tuning to a8qam256-6900:490000000 2016-05-15 17:29:34.997 capmt: Ziggo: Starting CAPMT server for service "Net5 HD" on adapter 0 2016-05-15 17:29:34.997 subscription: 0006: "DVR: Overwinnaars - met Arie Boomsma" subscribing on channel "Net5 HD", weight: 300, adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "490MHz", provider: "UPC NL", service: "Net5 HD", profile="pass" 2016-05-15 17:29:35.347 dvr: /var/media/Captures/2016-05-15 16.50 - Overwinnaars - met Arie Boomsma (Net5 HD).ts from adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "490MHz", provider: "UPC NL", service: "Net5 HD" 2016-05-15 17:29:35.347 dvr: # type lang resolution aspect ratio sample rate channels 2016-05-15 17:29:35.347 dvr: 1 H264 ? ? 2016-05-15 17:29:35.347 dvr: 2 MPEG2AUDIO dut ? ? 2016-05-15 17:29:35.347 dvr: 3 AC3 dut ? ? 2016-05-15 17:29:35.347 dvr: 4 TELETEXT 2016-05-15 17:29:35.347 dvr: 5 DVBSUB dut 2016-05-15 17:29:35.347 dvr: 6 DVBSUB dut 2016-05-15 17:29:35.347 dvr: 7 CA 2016-05-15 17:29:35.347 dvr: 8 CA 2016-05-15 17:29:35.347 dvr: 9 CA 2016-05-15 17:29:35.347 dvr: 10 CA 2016-05-15 17:29:35.347 dvr: 11 CA 2016-05-15 17:30:57.808 subscription: 0006: "DVR: Overwinnaars - met Arie Boomsma" unsubscribing from "Net5 HD" 2016-05-15 17:30:57.809 capmt: Ziggo: Removing CAPMT Server from service "Net5 HD" on adapter 0 2016-05-15 17:30:57.810 dvr: "Overwinnaars - met Arie Boomsma" on "Net5 HD": End of program: Aborted by user 2016-05-15 17:30:57.810 dvr: delete entry f7b57e64c1c3b301a49dcd55dc49b340 "Overwinnaars - met Arie Boomsma" on "Net5 HD" start time 2016-05-15 16:47:30, scheduled for recording by "192.168.178.12", retention "Forever" removal "Forever"
tvheadend log playable recording
2016-05-15 17:31:10.322 dvr: entry 8fc113e54e94140f26ecef2d45ab28f9 "Overwinnaars - met Arie Boomsma" on "Net5 HD" starting at 2016-05-15 16:47:30, scheduled for recording by "192.168.178.12" 2016-05-15 17:31:10.322 dvr: "Overwinnaars - met Arie Boomsma" on "Net5 HD" recorder starting 2016-05-15 17:31:10.324 mpegts: 490MHz in Ziggo - tuning on HDHomeRun DVB-C Tuner #0 (192.168.178.13) 2016-05-15 17:31:10.324 tvhdhomerun: tuning to a8qam256-6900:490000000 2016-05-15 17:31:10.330 capmt: Ziggo: Starting CAPMT server for service "Net5 HD" on adapter 0 2016-05-15 17:31:10.331 subscription: 0007: "DVR: Overwinnaars - met Arie Boomsma" subscribing on channel "Net5 HD", weight: 300, adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "490MHz", provider: "UPC NL", service: "Net5 HD", profile="pass" 2016-05-15 17:31:10.689 dvr: /var/media/Captures/2016-05-15 16.50 - Overwinnaars - met Arie Boomsma (Net5 HD).ts from adapter: "HDHomeRun DVB-C Tuner #0 (192.168.178.13)", network: "Ziggo", mux: "490MHz", provider: "UPC NL", service: "Net5 HD" 2016-05-15 17:31:10.689 dvr: # type lang resolution aspect ratio sample rate channels 2016-05-15 17:31:10.689 dvr: 1 H264 ? ? 2016-05-15 17:31:10.689 dvr: 2 MPEG2AUDIO dut ? ? 2016-05-15 17:31:10.689 dvr: 3 AC3 dut ? ? 2016-05-15 17:31:10.689 dvr: 4 TELETEXT 2016-05-15 17:31:10.689 dvr: 5 DVBSUB dut 2016-05-15 17:31:10.689 dvr: 6 DVBSUB dut 2016-05-15 17:31:10.689 dvr: 12 CA 2016-05-15 17:31:10.689 dvr: 13 CA 2016-05-15 17:31:10.689 dvr: 14 CA 2016-05-15 17:31:10.689 dvr: 15 CA 2016-05-15 17:31:10.689 dvr: 16 CA 2016-05-15 17:32:20.736 subscription: 0007: "DVR: Overwinnaars - met Arie Boomsma" unsubscribing from "Net5 HD" 2016-05-15 17:32:20.737 capmt: Ziggo: Removing CAPMT Server from service "Net5 HD" on adapter 0 2016-05-15 17:32:20.739 dvr: "Overwinnaars - met Arie Boomsma" on "Net5 HD": End of program: Aborted by user 2016-05-15 17:32:20.739 dvr: delete entry 8fc113e54e94140f26ecef2d45ab28f9 "Overwinnaars - met Arie Boomsma" on "Net5 HD" start time 2016-05-15 16:47:30, scheduled for recording by "192.168.178.12", retention "Forever" removal "Forever"
oscam log of both recodings
2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0192 PROVID: 000000 2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012E PROVID: 000000 2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CA PROVID: 000000 2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0035 PROVID: 000000 2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1801 ECM_PID: 0034 PROVID: 000000 2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/15 17:29:34 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012E ANY CHID PMTPID 0000 VPID 0B55 2016/05/15 17:29:35 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:93A8B1C52292CC833C8895C532AE6100): found (173 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:29:47 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (122 ms) 2016/05/15 17:29:51 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (89 ms) 2016/05/15 17:29:51 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/15 17:29:55 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:B3F4BED11722416EB54B9B5BA249B9D5): found (169 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:30:06 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (127 ms) 2016/05/15 17:30:11 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/15 17:30:15 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:F32243AD0B3E78044BD38C13CD2F1A8B): found (171 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:30:30 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/15 17:30:35 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:28B427E2368204128B7E880C12C145D9): found (170 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:30:51 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/15 17:30:54 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (120 ms) 2016/05/15 17:30:55 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:A76CE929193B64DF8485576C30A541F3): found (170 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:30:57 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4A50 (Net 5 HD) 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0190 PROVID: 000000 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012C PROVID: 000000 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00C8 PROVID: 000000 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0031 PROVID: 000000 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1801 ECM_PID: 0030 PROVID: 000000 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/15 17:31:10 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012C ANY CHID PMTPID 0000 VPID 0B55 2016/05/15 17:31:11 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:A6D008B143437EB5061FBC7810B548D4): found (169 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:31:13 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:66C6FAADEE93BC31DCB638363F4FFA78): found (169 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:31:16 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=39 (hex: 0x27), cnt=0: written (90 ms) 2016/05/15 17:31:30 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (93 ms) 2016/05/15 17:31:33 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:B3FE3B5F17A64B44F00EFF620D440E65): found (171 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:31:51 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/15 17:31:53 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:9909532A37AC985DE907F709860593F7): found (170 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:31:56 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (122 ms) 2016/05/15 17:32:11 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/15 17:32:13 327C0007 c (ecm) Ziggo (0604@000000/000B/4A50/44:A3BE3B969029C77D56AB3BEB978BA305): found (170 ms) by ZiggoSmartReader - Net 5 HD 2016/05/15 17:32:20 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4A50 (Net 5 HD)
As I run out of channels which have not been refreshed already, I think it becomes necessary to have a way to manually modify the stored PMT (or ECM-pid only) of channels.
I sincerely hope you find a way to solve this nasty problem as it often does not manifest itself in the logs.
TIA
Updated by Beralt Meppelink over 8 years ago
B.A. Derks wrote:
Unfortunately, v4.1-2040 does not solve the problem with the changed ECM-pids by Ziggo. I included the same kind of log fragments as this shows why this is a very nasty problem. As you can see, the log does not give any clue that there might be a problem with the recording. Only by trying to play the recording you notice that the recording is unplayable. AS you can see in the Oscam log, the ECM-pids did change between the first unplayable recoding and the second playable recording.
Using caPMT might have caused two things to go unnoticed in your case. I have been using the cwc client which at least logged descrambling errors and marked data errors in the recordings. Given my recent experiences with caPMT I would highly recommend to switch to cwc if possible.
Updated by Jaroslav Kysela over 8 years ago
- Status changed from New to Fixed
- % Done changed from 0 to 100
Applied in changeset commit:tvheadend|dfffcb1f29f3d895e560b2aea53b1f2c4e842bdc.
Updated by Jaroslav Kysela over 8 years ago
CAPMT (dvbapi network client protocol) was fixed in v4.1-2042-gdfffcb1 . This ECM PID change is really complex issue for this protocol.
Updated by B.A. Derks over 8 years ago
Thank you Jaroslav for your effort to solve the ECM-pid change problem. I regret to inform you that, although you solved the problem of the changed ECM-pids by Ziggo, recordings of channels that are already refreshed now results in unplayable recordings. I first tried tvheadend v4.1-2045 and after that tvheadend v4.1-2042. As the tvheadend log does not show anything other than the usual info I left them out this time.
oscam log recording channel with changed ECM-pid result: playable recording
2016/05/17 05:41:40 327C0007 c (dvbapi) Client connected: 'Tvheadend 4.1-2045 ~ LibreELEC Tvh-addon v7.0.444' (protocol version = 2) 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0195 PROVID: 000000 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 0131 PROVID: 000000 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CD PROVID: 000000 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1801 ECM_PID: 0047 PROVID: 000000 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1850 ECM_PID: 0046 PROVID: 000000 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 found channel in cache and matching prio -> start descrambling ecmpid 1 2016/05/17 05:47:32 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 0131 ANY CHID PMTPID 0000 VPID 0ED9 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4E4F (0606@000000:4E4F unknown) 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0192 PROVID: 000000 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012E PROVID: 000000 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CA PROVID: 000000 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1801 ECM_PID: 0035 PROVID: 000000 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1850 ECM_PID: 0034 PROVID: 000000 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012E ANY CHID PMTPID 0000 VPID 0ED9 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 continue decoding of SRVID 4E4F 2016/05/17 05:47:33 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/17 05:47:33 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:83C4E77B80582AF94DA924ADD01C3E66): found (171 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:47:34 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:B9C6C7CF145DBF925B37284F31C627E4): found (170 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:47:54 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:C192857778917C02CF74AEC2AE9F59A4): found (169 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:48:11 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/17 05:48:14 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:8D84EE596E8545AB62762531C3A7019A): found (170 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:48:30 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/17 05:48:34 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:BE0C3B55142387149A6A90ADC22DCACC): found (171 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:48:37 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (131 ms) 2016/05/17 05:48:50 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/17 05:48:54 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:458870930D6F100AD7185CE3AC0667BC): found (171 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:49:10 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/17 05:49:14 327C0007 c (ecm) Ziggo (0604@000000/000B/4E4F/44:24AD3B23A2F574065EE5C723DEEF60D4): found (170 ms) by ZiggoSmartReader - SBS 9 HD 2016/05/17 05:49:19 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4E4F (SBS 9 HD)
oscam log of recording of channel with already refreshed ECM-pid result: unplayable recording
2016/05/17 06:09:15 327C0007 c (dvbapi) Client connected: 'Tvheadend 4.1-2042 ~ LibreELEC Tvh-addon v7.0.444' (protocol version = 2) 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0192 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012E PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CA PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0035 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1801 ECM_PID: 0034 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 found channel in cache and matching prio -> start descrambling ecmpid 1 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012E ANY CHID PMTPID 0000 VPID 0ED9 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4E3B (ARD HD) 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0192 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012E PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CA PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0035 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1801 ECM_PID: 0034 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 found channel in cache and matching prio -> start descrambling ecmpid 1 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012E ANY CHID PMTPID 0000 VPID 0ED9 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4E3B (ARD HD) 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0606 ECM_PID: 0192 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0604 ECM_PID: 012E PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0602 ECM_PID: 00CA PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 1850 ECM_PID: 0035 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 1801 ECM_PID: 0034 PROVID: 000000 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 found 5 ECMpids and 1 STREAMpids in caPMT 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 found channel in cache and matching prio -> start descrambling ecmpid 1 2016/05/17 06:11:13 327C0007 c (dvbapi) Demuxer 0 trying to descramble PID 1 CAID 0604 PROVID 000000 ECMPID 012E ANY CHID PMTPID 0000 VPID 0ED9 2016/05/17 06:11:14 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:E08FF91DDED44C353BE4E91F490F17FB): found (169 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:11:29 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:1059BDE7301FCBEB45A4F3158479B7DB): found (169 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:11:29 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/17 06:11:48 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (92 ms) 2016/05/17 06:11:49 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:3102DA2049562518B7B65181AD249EEE): found (170 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:12:00 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (122 ms) 2016/05/17 06:12:09 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:A9E65FEAF6B9FCA93A29835162D6ABF8): found (173 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:12:09 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/17 06:12:29 327C0007 c (-) -- Skipped 1 duplicated log lines -- 2016/05/17 06:12:29 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:1F41ED5E5FF5E11B36421BE953673B04): found (171 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:12:35 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (127 ms) 2016/05/17 06:12:49 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:ACC059B68B2744746CC45A564C84607E): found (170 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:12:49 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/17 06:13:09 327C0007 c (-) -- Skipped 1 duplicated log lines -- 2016/05/17 06:13:09 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:F4141E4F92CAEB3B2EA0048909611982): found (211 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:13:28 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/17 06:13:29 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:D11D432F64738CC59C75714725144DCC): found (172 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:13:37 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=shared, len=63 (hex: 0x3F), cnt=0: written (122 ms) 2016/05/17 06:13:49 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:AAFBB0E222523AC3BA5CD219E3C56086): found (171 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:13:49 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (90 ms) 2016/05/17 06:14:09 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:ACEC0B41AC57BB0F637715CDCBE00EEE): found (169 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:14:09 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (91 ms) 2016/05/17 06:14:28 69B2B97F r (reader) ZiggoSmartReader [irdeto] Ziggo emmtype=global, len=43 (hex: 0x2B), cnt=0: written (89 ms) 2016/05/17 06:14:29 327C0007 c (ecm) Ziggo (0604@000000/000B/4E3B/44:F9672335959EF4B73333CCC6D502AC23): found (169 ms) by ZiggoSmartReader - ARD HD 2016/05/17 06:14:35 327C0007 c (dvbapi) Demuxer 0 stop descrambling program number 4E3B (ARD HD)
I reverted back to tvheadend v4.1-2040 and recordings of the ARD HD and the SBS9 channel are both playable again, so nothing is damaged behind the tvheadend/oscam scene.
I hope this problem does not demotivates you too much.
TIA
Updated by Jaroslav Kysela over 8 years ago
I'm not sure what you mean with unplaylable.. Do you see any descrambling errors in the log? The keys are read fine.
Upgrade to v4.1-2046-g7985a96 (fixes multiple start/stop dvbapi requests) and provide traces from tvheadend for 'descrambler,capmt' subsystems - https://tvheadend.org/projects/tvheadend/wiki/Traces .
Updated by B.A. Derks over 8 years ago
I just installed nightly build v4.1-2047 and all kinds of recordings went fine. I noticed that this time around you changed the sequence numbering of the CA-streams with changed ECM-pids. During the time oscam needed to process the extra CA-streams with the changed ECM-pids, tvheadend showed a couple of times the 'descrambler: cannot decode packets for service ...' message in the syslog. The recording was not effected as it played flawlessly.
BTW, I now have no channels left over which are not refreshed yet, so further testing will have to wait for Ziggo changing ECM-pids again. For the time being I will stick with v1.4-2047 to see whether or not there are still noticeable irregularities.
Thank you for all the work you did to solve this ECM-pid changing problem.
PS. I do not know why yesterday's test recordings of channel ARD HD failed and resulted in unplayable video files. If you want me to, I'm willing to try it again with the v4.1-2042 and v4.1-2045 versions. As I do not know how to compile tvheadend as an add-on for LibreElec (and no guidance found for it on the internet), I will not be able to supply you with trace logs. The tvheadend syslog gave no indication what so ever that the the recordings were failing and resulting in unplayable video files. Maybe it was just an alpha particle that hit my computer.
Updated by bas t over 8 years ago
@ B.A. Derks
You said you're out of changed PID's, well enjoy, I've got an email from Ziggo today, stating (amongst others):
Uw zenderpakket krijgt ook een update
Er valt weer iets nieuws te ontdekken. Bekijk op uw persoonlijke pagina het overzicht van de zenders die plaatsmaken en onze nieuwste zenders. We voeren deze update automatisch voor u uit op 1 juli.
For the non-Dutch: this means that they are going to shuffel again bigtime with their muxes around the first of juli.
Can't wait to see that happen, and of course how tvh will respond.
Cheers to all!
Tycho.