Forums » Descrambling »
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.