Project

General

Profile

Help me understand tvheadend descrambler logs

Added by talentless talentless over 2 years ago

Hello

I need some help understanding tvheadend descrambler logs to understand why sometimes my image freezes.

When that happens, I always get

2022-08-21 03:22:19.402 descrambler: cannot decode packets for service <SERVICE>

and then the client unsubscribes and subscribes again, and all continues well until the same thing happens again a few minutes later. From the client, the viewing experience is perceived as a ~10s freeze every few minutes.

Everything appears normal in the cam side:

2022-08-21 03:10:11 5DF143F1 c      (ecm) tvheadend (DATA=1810@000000/0000/7828 ECM_L:8E CW=<CW> HOP=00): found (1612 ms) by "" (P/10/10/16)
2022-08-21 03:10:26 5DF143F1 c      (ecm) tvheadend (DATA=1810@000000/0000/7828 ECM_L:8E CW=<CW> HOP=00): found (1596 ms) by "" (P/5/5/16)
2022-08-21 03:10:41 5DF143F1 c      (ecm) tvheadend (DATA=1810@000000/0000/7828 ECM_L:8E CW=<CW> HOP=00): found (1198 ms) by "1" (P/7/7/16)
2022-08-21 03:10:57 5DF143F1 c      (ecm) tvheadend (DATA=1810@000000/0000/7828 ECM_L:8E CW=<CW> HOP=00): found (1660 ms) by "" (P/5/5/16)
2022-08-21 03:11:03 5DF143F1 c   (dvbapi) Demuxer 0 stopped descrambling for program 7828 (M. DEPORTES HD)
2022-08-21 03:11:03 5DF143F1 c   (dvbapi) Demuxer 0 ecmpid 0 CAID: 1810 ECM_PID: 08C5 PROVID: 000000 
2022-08-21 03:11:03 5DF143F1 c   (dvbapi) Demuxer 0 found 1 ECM pids and 4 STREAM pids in CA PMT
2022-08-21 03:11:03 5DF143F1 c   (dvbapi) Demuxer 0 found channel in cache and matching prio -> start descrambling ecmpid 0 
2022-08-21 03:11:03 5DF143F1 c   (dvbapi) Demuxer 0 trying to descramble PID 0 CAID 1810 PROVID 000000 ECMPID 08C5 ANY CHID PMTPID 040A VPID 00A1

These are the traces on tvheadend side with descrambler, cwc and capmt subsystems, which basically don't help me understand what is going on. Could somebody explain them to me? Thanks!

2022-08-21 03:10:42.047 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:42.351 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:42.351 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:42.461 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:42.461 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:42.747 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:42.747 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.042 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.042 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.245 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.245 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.552 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.552 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.752 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:43.752 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.042 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.043 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.252 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.252 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.562 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.563 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.756 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:44.756 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.040 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.040 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.240 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.241 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.548 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.548 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.754 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:45.754 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.041 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.041 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.246 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.246 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.483 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE> Transport error indicator (total 6)
2022-08-21 03:10:46.486 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: H264 @ #161 Continuity counter error (total 15)
2022-08-21 03:10:46.486 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: MPEG2AUDIO @ #88 Continuity counter error (total 1)
2022-08-21 03:10:46.508 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: MPEG2AUDIO @ #87 Continuity counter error (total 1)
2022-08-21 03:10:46.556 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.556 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.753 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:46.753 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.045 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.045 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.243 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.243 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.538 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.538 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.742 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:47.742 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.052 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.053 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.348 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.348 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.551 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.551 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.759 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:48.759 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.048 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.049 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.354 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.355 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.560 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.560 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.741 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:49.742 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.045 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.046 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.202 [  TRACE]:descrambler: stream key[0] changed to odd for service "<SERVICE>" 
2022-08-21 03:10:50.203 [  TRACE]:descrambler: update key[0] interval for "Red DVB-S/10935.5V/<SERVICE>" to 10711ms
2022-08-21 03:10:50.260 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.261 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.553 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.554 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.740 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:50.740 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.051 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.052 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.346 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.347 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.535 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.535 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.760 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:51.760 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:52.046 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:52.046 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:52.204 [  TRACE]:descrambler: stream key[0] changed to even for service "<SERVICE>" 
2022-08-21 03:10:52.204 [  DEBUG]:descrambler: no key for service='<SERVICE>'
2022-08-21 03:10:52.204 [  TRACE]:descrambler: capmt-10.8.5.5-9000: key state changed from RESOLVED to READY for "Red DVB-S/10935.5V/<SERVICE>" 
2022-08-21 03:10:52.204 [  TRACE]:descrambler: service "Red DVB-S/10935.5V/<SERVICE>": 1 descramblers (0 ok 0 failed 0 fatal)
2022-08-21 03:10:52.204 [  TRACE]:descrambler: flush table data for service "<SERVICE>" 
2022-08-21 03:10:52.204 [  TRACE]:descrambler: stream key[0] changed to even for service "<SERVICE>" 
2022-08-21 03:10:52.204 [  TRACE]:descrambler: update key[0] interval for "Red DVB-S/10935.5V/<SERVICE>" to 5000ms
2022-08-21 03:10:52.235 [  TRACE]:descrambler: ECM message 81:30 (section 132, len 142, pid 2245) for service "<SERVICE>" 
2022-08-21 03:10:52.362 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:52.535 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:52.754 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:53.043 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:53.259 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:53.551 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:53.743 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:54.059 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:54.344 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:54.484 [  TRACE]:descrambler: stream key[0] changed to odd for service "<SERVICE>" 
2022-08-21 03:10:54.484 [  TRACE]:descrambler: update key[0] interval for "Red DVB-S/10935.5V/<SERVICE>" to 5000ms
2022-08-21 03:10:54.553 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:54.741 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:55.041 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:55.131 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: MPEG2AUDIO @ #86 Continuity counter error (total 2)
2022-08-21 03:10:55.136 [  ERROR]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:55.251 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:55.341 [  TRACE]:capmt: filter match pid 2245 len 142 emm 0
2022-08-21 03:10:55.341 [  TRACE]:capmt: ncam: Sending message to socket 22 (sid 65536)
2022-08-21 03:10:55.341 [  TRACE]:capmt: FF FF 00 00 00 00 80 30 8B 07 84 00 9A 5A BD E7 .......0.....Z..
2022-08-21 03:10:55.341 [  TRACE]:capmt: 3A E3 ED 6A 45 D0 02 EA 97 6A 70 BC DA 15 F8 09 :..jE....jp.....
2022-08-21 03:10:55.341 [  TRACE]:capmt: 5A D6 35 9F 18 D5 CB 86 07 E2 F2 4A BE 5A 34 9B Z.5........J.Z4.
2022-08-21 03:10:55.342 [  TRACE]:capmt: A0 74 CA 0F 9C D5 0B A1 D0 6F 80 33 B9 35 54 2C .t.......o.3.5T,
2022-08-21 03:10:55.342 [  TRACE]:capmt: AF AA EC FC 00 D7 86 C5 17 D0 C9 86 61 77 E0 0C ............aw..
2022-08-21 03:10:55.342 [  TRACE]:capmt: B5 81 2C 24 88 90 84 AE BD 75 E0 D0 1F BE 06 B8 ..,$.....u......
2022-08-21 03:10:55.342 [  TRACE]:capmt: DC 56 7E 6C AA 1C 43 58 DD 3A 1A 94 37 DD 01 DD .V~l..CX.:..7...
2022-08-21 03:10:55.342 [  TRACE]:capmt: FA 25 2C 59 ED 9C 75 CB AC 36 47 E0 F9 24 79 71 .%,Y..u..6G..$yq
2022-08-21 03:10:55.342 [  TRACE]:capmt: 4B 0C 7E 67 FC 61 8A BD 1C 94 32 D5 A2 78 93 0B K.~g.a....2..x..
2022-08-21 03:10:55.342 [  TRACE]:capmt: 03 00 00 80                                     ....            
2022-08-21 03:10:55.342 [  TRACE]:descrambler: ECM message 80:30 (section 132, len 142, pid 2245) for service "<SERVICE>" 
2022-08-21 03:10:55.343 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:10:55.343 [  TRACE]:capmt: 40 3C 6F 2B 00 00 00 08 C5 81 00 00 00 00 00 00 @<o+............
2022-08-21 03:10:55.343 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00 ................
2022-08-21 03:10:55.343 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:10:55.343 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:10:55.343 [  TRACE]:capmt: 04                                              .               
2022-08-21 03:10:55.343 [  TRACE]:capmt: ncam: setting filter: adapter=0, demux=0, filter=0, pid=2245
2022-08-21 03:10:55.343 [  TRACE]:capmt: 81 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:10:55.343 [  TRACE]:capmt: FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:10:55.343 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:10:55.404 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:55.679 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:55.964 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:56.254 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:56.541 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: H264 @ #161 Continuity counter error (total 207)
2022-08-21 03:10:56.541 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: MPEG2AUDIO @ #88 Continuity counter error (total 95)
2022-08-21 03:10:56.541 [WARNING]:TS: Red DVB-S/10935.5V/<SERVICE>: MPEG2AUDIO @ #87 Continuity counter error (total 87)
2022-08-21 03:10:56.545 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:56.814 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:57.003 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:10:57.003 [  TRACE]:capmt: 40 10 6F 86 00 00 00 00 00 00 00 00 00 94 E9 A6 @.o.............
2022-08-21 03:10:57.003 [  TRACE]:capmt: 23 68 F7 FF 5E                                  #h..^           
2022-08-21 03:10:57.003 [  DEBUG]:capmt: ncam: CA_SET_DESCR adapter 0 par 0 idx 0 94e9a62368f7ff5e
2022-08-21 03:10:57.003 [  DEBUG]:descrambler: Obtained CSA keys from capmt-10.8.5.5-9000 for service "<SERVICE>" 
2022-08-21 03:10:57.003 [  TRACE]:descrambler: Obtained CSA keys 94E9A62368F7FF5E:0000000000000000 pid 0000 from capmt-10.8.5.5-9000 for service "<SERVICE>" 
2022-08-21 03:10:57.003 [  TRACE]:descrambler: capmt-10.8.5.5-9000: key state changed from READY to RESOLVED for "Red DVB-S/10935.5V/<SERVICE>" 
2022-08-21 03:10:57.003 [  TRACE]:descrambler: service "Red DVB-S/10935.5V/<SERVICE>": 1 descramblers (1 ok 0 failed 0 fatal)
2022-08-21 03:10:57.003 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:10:57.003 [  TRACE]:capmt: FF FF 00 03 00 78 28 18 10 08 C5 00 00 00 00 00 .....x(.........
2022-08-21 03:10:57.003 [  TRACE]:capmt: 00 06 7C 05 6E 61 67 72 61 1B 22 6D 61 69 6E 5F ..|.nagra."<SERV
2022-08-21 03:10:57.003 [  TRACE]:capmt: 63 61 72 64 73 68 61 72 69 6E 67 2E 63 63 5F 32 ER>
2022-08-21 03:10:57.003 [  TRACE]:capmt: 30 31 35 31 22 09 72 75 62 31 31 2E 63 6F 6D 07 0151".<SERVER>.
2022-08-21 03:10:57.003 [  TRACE]:capmt: 6E 65 77 63 61 6D 64 00                         newcamd.        
2022-08-21 03:10:57.003 [  DEBUG]:descrambler: info - service='<SERVICE>' caid=1810(nagra) provid=000000 ecmtime=1660 hops=0 reader='"<READER>"' from='SERVER>' protocol='newcamd'
2022-08-21 03:10:57.003 [  DEBUG]:capmt: ncam: ECM_INFO: adapter=0 sid=30760 caid=1810(nagra) pid=08C5 provid=000000 ecmtime=1660 hops=0 reader="main_cardsharing.cc_20151" from=rub11.com protocol=newcamd
2022-08-21 03:10:57.131 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:57.275 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:57.466 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:57.580 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:57.782 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:57.828 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:58.066 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:58.194 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:58.359 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:58.543 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:58.593 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:58.687 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:58.963 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:59.057 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:59.142 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:59.363 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:59.452 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:59.585 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:10:59.863 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:10:59.863 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:00.055 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:00.226 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:00.345 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:00.543 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:00.583 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:00.774 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:00.958 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:01.066 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:01.241 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:01.344 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:01.558 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:01.596 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:01.744 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:01.901 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:01.973 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:02.266 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:02.309 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:02.555 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:02.678 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:02.762 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:03.017 [  TRACE]:descrambler: cannot decode packets for service "<SERVICE>" 
2022-08-21 03:11:03.053 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:03.167 [   INFO]:htsp: 10.8.1.12 [  | Kodi Media Center ]: Disconnected
2022-08-21 03:11:03.167 [   INFO]:subscription: 003B: "10.8.1.12 [  | Kodi Media Center ]" unsubscribing from "<SERVICE>", hostname="10.8.1.12", username="10.8.1.12", client="Kodi Media Center" 
2022-08-21 03:11:03.173 [  TRACE]:descrambler: mux 0x7fabdfd910 - flush tables
2022-08-21 03:11:03.174 [  DEBUG]:capmt: ncam: Removing CAPMT Server from service "<SERVICE>" on adapter 0
2022-08-21 03:11:03.174 [  DEBUG]:capmt: ncam: capmt_enumerate_services: no subscribed services, closing socket, fd=22
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 0
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 1
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 2
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 3
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 4
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 5
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 6
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 7
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 8
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 9
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 10
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 11
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 12
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 13
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 14
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 15
2022-08-21 03:11:03.174 [  TRACE]:capmt: ncam: pid flush for adapter 0
2022-08-21 03:11:03.176 [  TRACE]:capmt: ncam: Sending message to socket 22 (sid 0)
2022-08-21 03:11:03.176 [  TRACE]:capmt: 9F 80 3F 04 83 02 00 FF                         ..?.....        
2022-08-21 03:11:03.176 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:03.176 [  TRACE]:capmt: 40 08 6F 87 00 00 00 00 56 FF FF FF FF          @.o.....V....   
2022-08-21 03:11:03.177 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 86 (0x0056)
2022-08-21 03:11:03.177 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:03.177 [  TRACE]:capmt: 40 08 6F 87 00 00 00 00 A1 FF FF FF FF          @.o..........   
2022-08-21 03:11:03.177 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 161 (0x00a1)
2022-08-21 03:11:03.178 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:03.178 [  TRACE]:capmt: 40 08 6F 87 00 00 00 00 58 FF FF FF FF 40 08 6F @[email protected]
2022-08-21 03:11:03.178 [  TRACE]:capmt: 87 00 00 00 00 57 FF FF FF FF 00 00 6F 2A 00 00 .....W......o*..
2022-08-21 03:11:03.178 [  TRACE]:capmt: 00 08 C5                                        ...             
2022-08-21 03:11:03.178 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 88 (0x0058)
2022-08-21 03:11:03.178 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 87 (0x0057)
2022-08-21 03:11:03.178 [  TRACE]:capmt: ncam: stopping filter: adapter=0, demux=0, filter=0, pid=2245
2022-08-21 03:11:03.181 [   INFO]:htsp: Got connection from 10.8.1.12
2022-08-21 03:11:03.181 [   INFO]:htsp: 10.8.1.12: Welcomed client software: Kodi Media Center (HTSPv34)
2022-08-21 03:11:03.183 [   INFO]:htsp: 10.8.1.12 [ Kodi Media Center ]: Identified as user ''
2022-08-21 03:11:03.641 [   INFO]:mpegts: 10935.5V in Red DVB-S - tuning on Montage Technology M88DS3103 #0 : DVB-S #0
2022-08-21 03:11:03.649 [   INFO]:capmt: ncam: Starting CAPMT server for service "<SERVICE>" on adapter 0
2022-08-21 03:11:03.649 [  DEBUG]:capmt: ncam: New caid 0x1810:0x000000 (pid 0x08C5) for service "<SERVICE>" 
2022-08-21 03:11:03.649 [  TRACE]:descrambler: capmt-10.8.5.5-9000: key state changed from INIT to READY for "Red DVB-S/10935.5V/<SERVICE>" 
2022-08-21 03:11:03.649 [  TRACE]:descrambler: service "Red DVB-S/10935.5V/<SERVICE>": 1 descramblers (0 ok 0 failed 0 fatal)
2022-08-21 03:11:03.649 [  DEBUG]:capmt: ncam: adding ECMPID=0x8C5 (2245), CAID=0x1810 (6160) PROVID=0x0 (0), SID=30760, ADAPTER=0
2022-08-21 03:11:03.649 [  DEBUG]:capmt: ncam: Trying to obtain key for service "<SERVICE>" 
2022-08-21 03:11:03.649 [   INFO]:subscription: 003C: "10.8.1.12 [  | Kodi Media Center ]" subscribing on channel "<SERVICE>", weight: 100, adapter: "Montage Technology M88DS3103 #0 : DVB-S #0", network: "Red DVB-S", mux: "10935.5V", provider: "<PROVIDER>", service: "<SERVICE>", profile="htsp", hostname="10.8.1.12", username="10.8.1.12", client="Kodi Media Center" 
2022-08-21 03:11:03.649 [  TRACE]:capmt: ncam: Sending message to socket 22 (sid 30760)
2022-08-21 03:11:03.649 [  TRACE]:capmt: 9F 80 32 82 00 36 03 78 28 1F 00 1C 01 81 08 00 ..2..6.x(.......
2022-08-21 03:11:03.649 [  TRACE]:capmt: 00 00 00 04 28 00 01 82 02 01 00 84 02 04 0A 83 ....(...........
2022-08-21 03:11:03.649 [  TRACE]:capmt: 01 00 09 04 18 10 08 C5 04 00 56 00 00 1B 00 A1 ..........V.....
2022-08-21 03:11:03.649 [  TRACE]:capmt: 00 00 04 00 58 00 00 04 00 57 00 00             ....X....W..    
2022-08-21 03:11:03.651 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:03.651 [  TRACE]:capmt: 40 3C 6F 2B 00 00 00 08 C5 80 00 00 00 00 00 00 @<o+............
2022-08-21 03:11:03.651 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 F0 00 00 00 00 00 00 ................
2022-08-21 03:11:03.651 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:03.651 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 0B B8 00 00 00 ................
2022-08-21 03:11:03.651 [  TRACE]:capmt: 04                                              .               
2022-08-21 03:11:03.651 [  TRACE]:capmt: ncam: setting filter: adapter=0, demux=0, filter=0, pid=2245
2022-08-21 03:11:03.651 [  TRACE]:capmt: 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:03.651 [  TRACE]:capmt: F0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:03.651 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:03.651 [  TRACE]:capmt: ncam: adding pid 2245 adapter 0, tuner 0x7fad439010, mmi 0x7fa5d14330, mux 0x7fabdfd910
2022-08-21 03:11:03.651 [  TRACE]:descrambler: mux 0x7fabdfd910 open pid 08C5 (2245) (flags 0x0100) for 0x7fad064568
2022-08-21 03:11:04.365 [  TRACE]:capmt: filter match pid 2245 len 142 emm 0
2022-08-21 03:11:04.365 [  TRACE]:descrambler: ECM message 80:30 (section 132, len 142, pid 2245) for service "<SERVICE>" 
2022-08-21 03:11:04.365 [  TRACE]:capmt: ncam: Sending message to socket 22 (sid 65536)
2022-08-21 03:11:04.365 [  TRACE]:capmt: FF FF 00 00 00 00 80 30 8B 07 84 00 9A 5A BD E7 .......0.....Z..
2022-08-21 03:11:04.365 [  TRACE]:capmt: 3A E3 ED 6A 45 D0 02 EA 97 6A 70 BC DA 15 F8 09 :..jE....jp.....
2022-08-21 03:11:04.365 [  TRACE]:capmt: 5A D6 35 9F 18 D5 CB 86 07 E2 F2 4A BE 5A 34 9B Z.5........J.Z4.
2022-08-21 03:11:04.365 [  TRACE]:capmt: A0 74 CA 0F 9C D5 0B A1 D0 6F 80 33 B9 35 54 2C .t.......o.3.5T,
2022-08-21 03:11:04.365 [  TRACE]:capmt: AF AA EC FC 00 D7 86 C5 17 D0 C9 86 61 77 E0 0C ............aw..
2022-08-21 03:11:04.365 [  TRACE]:capmt: B5 81 2C 24 88 90 84 AE BD 75 E0 D0 1F BE 06 B8 ..,$.....u......
2022-08-21 03:11:04.365 [  TRACE]:capmt: DC 56 7E 6C AA 1C 43 58 DD 3A 1A 94 37 DD 01 DD .V~l..CX.:..7...
2022-08-21 03:11:04.365 [  TRACE]:capmt: FA 25 2C 59 ED 9C 75 CB AC 36 47 E0 F9 24 79 71 .%,Y..u..6G..$yq
2022-08-21 03:11:04.365 [  TRACE]:capmt: 4B 0C 7E 67 FC 61 8A BD 1C 94 32 D5 A2 78 93 0B K.~g.a....2..x..
2022-08-21 03:11:04.365 [  TRACE]:capmt: 03 00 00 80                                     ....            
2022-08-21 03:11:04.365 [  TRACE]:descrambler: CAT data (len 17)
2022-08-21 03:11:04.365 [  TRACE]:descrambler: 09 09 01 00 E0 C1 01 E0 C4 41 06 09 04 18 10 E0 .........A......
2022-08-21 03:11:04.365 [  TRACE]:descrambler: 9B                                              .               
2022-08-21 03:11:04.366 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:04.366 [  TRACE]:capmt: 40 3C 6F 2B 00 00 00 08 C5 81 00 00 00 00 00 00 @<o+............
2022-08-21 03:11:04.366 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00 ................
2022-08-21 03:11:04.366 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:04.366 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:04.366 [  TRACE]:capmt: 04                                              .               
2022-08-21 03:11:04.366 [  TRACE]:capmt: ncam: setting filter: adapter=0, demux=0, filter=0, pid=2245
2022-08-21 03:11:04.366 [  TRACE]:capmt: 81 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:04.366 [  TRACE]:capmt: FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:04.366 [  TRACE]:capmt: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
2022-08-21 03:11:04.427 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:04.427 [  TRACE]:capmt: 40 08 6F 87 00 00 00 00 56 FF FF FF FF 40 08 6F @[email protected]
2022-08-21 03:11:04.427 [  TRACE]:capmt: 87 00 00 00 00 56 00 00 00 00 40 08 6F 87 00 00 [email protected]...
2022-08-21 03:11:04.427 [  TRACE]:capmt: 00 00 A1 FF FF FF FF 40 08 6F 87 00 00 00 00 A1 [email protected]......
2022-08-21 03:11:04.427 [  TRACE]:capmt: 00 00 00 00 40 08 6F 87 00 00 00 00 58 FF FF FF [email protected]...
2022-08-21 03:11:04.427 [  TRACE]:capmt: FF 40 08 6F 87 00 00 00 00 58 00 00 00 00 40 08 [email protected]....@.
2022-08-21 03:11:04.427 [  TRACE]:capmt: 6F 87 00 00 00 00 57 FF FF FF FF 40 08 6F 87 00 [email protected]..
2022-08-21 03:11:04.427 [  TRACE]:capmt: 00 00 00 57 00 00 00 00                         ...W....        
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 86 (0x0056)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index 0 pid 86 (0x0056)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 161 (0x00a1)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index 0 pid 161 (0x00a1)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 88 (0x0058)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index 0 pid 88 (0x0058)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index -1 pid 87 (0x0057)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_PID adapter 0 index 0 pid 87 (0x0057)
2022-08-21 03:11:04.427 [  TRACE]:capmt: ncam: Received message from socket 22
2022-08-21 03:11:04.427 [  TRACE]:capmt: 40 10 6F 86 00 00 00 00 00 00 00 00 00 94 E9 A6 @.o.............
2022-08-21 03:11:04.427 [  TRACE]:capmt: 23 68 F7 FF 5E 40 10 6F 86 00 00 00 00 00 00 00 #h..^@.o........
2022-08-21 03:11:04.427 [  TRACE]:capmt: 00 01 73 50 B9 7C B0 0F 92 51 FF FF 00 03 00 78 ..sP.|...Q.....x
2022-08-21 03:11:04.427 [  TRACE]:capmt: 28 18 10 08 C5 00 00 00 00 00 00 00 00 05 6E 61 (.............na
2022-08-21 03:11:04.427 [  TRACE]:capmt: 67 72 61 05 43 61 63 68 65 06 63 61 63 68 65 31 gra.Cache.cache1
2022-08-21 03:11:04.427 [  TRACE]:capmt: 04 6E 6F 6E 65 00                               .none.          
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_DESCR adapter 0 par 0 idx 0 94e9a62368f7ff5e
2022-08-21 03:11:04.427 [  DEBUG]:descrambler: Obtained CSA keys from capmt-10.8.5.5-9000 for service "<SERVICE>" 
2022-08-21 03:11:04.427 [  TRACE]:descrambler: Obtained CSA keys 94E9A62368F7FF5E:0000000000000000 pid 0000 from capmt-10.8.5.5-9000 for service "<SERVICE>" 
2022-08-21 03:11:04.427 [  TRACE]:descrambler: capmt-10.8.5.5-9000: key state changed from READY to RESOLVED for "Red DVB-S/10935.5V/<SERVICE>" 
2022-08-21 03:11:04.427 [  TRACE]:descrambler: service "Red DVB-S/10935.5V/<SERVICE>": 1 descramblers (1 ok 0 failed 0 fatal)
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: CA_SET_DESCR adapter 0 par 1 idx 0 7350b97cb00f9251
2022-08-21 03:11:04.427 [  DEBUG]:descrambler: Both keys received, marking ECM start for odd key for service "<SERVICE>" 
2022-08-21 03:11:04.427 [  TRACE]:descrambler: Obtained CSA keys 0000000000000000:7350B97CB00F9251 pid 0000 from capmt-10.8.5.5-9000 for service "<SERVICE>" 
2022-08-21 03:11:04.427 [  DEBUG]:descrambler: info - service='<SERVICE>' caid=1810(nagra) provid=000000 ecmtime=0 hops=0 reader='Cache' from='cache1' protocol='none'
2022-08-21 03:11:04.427 [  DEBUG]:capmt: ncam: ECM_INFO: adapter=0 sid=30760 caid=1810(nagra) pid=08C5 provid=000000 ecmtime=0 hops=0 reader=Cache from=cache1 protocol=none
2022-08-21 03:11:04.448 [  TRACE]:descrambler: stream key[0] changed to odd for service "<SERVICE>" 
2022-08-21 03:11:04.646 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:04.647 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:04.956 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:04.956 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.158 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.158 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.460 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.461 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.648 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.648 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.963 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:05.963 [  TRACE]:descrambler: ECM: Odd key[0] for service "<SERVICE>" still valid
2022-08-21 03:11:06.160 [  TRACE]:descrambler: ECM: Even key[0] for service "<SERVICE>" still valid

Replies (2)

RE: Help me understand tvheadend descrambler logs - Added by saen acro over 2 years ago

In oscam add this to ECM log format:

c&0p/i/d/s/l:h.e_w HOP:j

long zero responses cannot descramble ;(

RE: Help me understand tvheadend descrambler logs - Added by talentless talentless over 2 years ago

Hello, thanks. In this case I was getting non-zero CW in oscam, I just replaced it with <CW> in the logs out of precaution. Is there any other sign which shows I was getting all zeros response in the logs?

But in any case I would be interested how to interpret from tvheadend logs that it probably got a bad CW. I don't recognize in those logs when an old CW turns invalid, when a new CW is obtained, which CW is that and when it starts trying to use it.

If I would have to guess, several things are confusing:

1. "no key for service" is logged at the same time "Even key0 for service still valid" is logged, which seems contradictory
2. The ECM message is sent after decoding error, and if this is because both keys turned invalid, isn't it too late? I would expect some overlap when a key can be requested while the old one still being valid. I would guess the even & odd keys have something to do with this but probably not.
2. If I had to guess that the odd key turned invalid while the even was still valid, and than it tried to request a new one, it got "Obtained CSA keys 94E9A62368F7FF5E:0000000000000000" which looks to me like an valid even key but zero odd key. I did not see zero in the oscam logs.

    (1-2/2)