May 7 13:09:47.777 : Version: 0.0.2-937d8d619cdd May 7 13:09:47.779 CAM: initializing plugin: SoftCam (0.8.7-Unknown): A software emulated CAM May 7 13:09:47.780 CAM(general.info): SC version 0.8.7-Unknown initializing May 7 13:09:47.780 CAM: starting plugin: May 7 13:09:47.781 CAM(general.info): SC version 0.8.7-Unknown starting May 7 13:09:47.781 CAM(core.load): ** Plugin config: May 7 13:09:47.782 CAM(core.load): ** Key updates (AU) are enabled (active CAIDs) (no prestart) May 7 13:09:47.783 CAM(core.load): ** Local systems DON'T take priority over cached remote May 7 13:09:47.784 CAM(core.load): ** Concurrent FF recordings are NOT allowed May 7 13:09:47.784 CAM(core.load): ** Force transfermode with digital audio May 7 13:09:47.785 CAM(core.load): ** ScCaps are 1 2 0 0 0 0 0 0 0 0 May 7 13:09:47.786 CAM(core.load): ** Ignored CAIDs 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 May 7 13:09:47.787 CAM(general.error): Failed to open file './sc_files/SoftCam.Key': No such file or directory May 7 13:09:47.788 CAM(core.load): loaded 0 keys from ./sc_files/SoftCam.Key May 7 13:09:47.788 CAM(general.error): no keys loaded for softcam! May 7 13:09:47.789 CAM(core.load): ** registered systems: May 7 13:09:47.790 CAM(core.load): ** Cardclient (pri -15) May 7 13:09:47.790 CAM(core.load): ** Conax (pri -10) May 7 13:09:47.791 CAM(core.load): ** ConstCW (pri -20) May 7 13:09:47.792 CAM(core.load): ** Cryptoworks (pri -10) May 7 13:09:47.792 CAM(core.load): ** Irdeto (pri -10) May 7 13:09:47.793 CAM(core.load): ** Nagra (pri -10) May 7 13:09:47.793 CAM(core.load): ** Nagra2 (pri -10) May 7 13:09:47.794 CAM(core.load): ** SC-Conax (pri -5) May 7 13:09:47.795 CAM(core.load): ** SC-Cryptoworks (pri -5) May 7 13:09:47.795 CAM(core.load): ** SC-Irdeto (pri -5) May 7 13:09:47.796 CAM(core.load): ** SC-Nagra (pri -5) May 7 13:09:47.796 CAM(core.load): ** SC-Seca (pri -5) May 7 13:09:47.797 CAM(core.load): ** SC-Viaccess (pri -5) May 7 13:09:47.798 CAM(core.load): ** SC-VideoGuard2 (pri -5) May 7 13:09:47.798 CAM(core.load): ** Seca (pri -10) May 7 13:09:47.799 CAM(core.load): ** @SHL (pri -10) May 7 13:09:47.800 CAM(core.load): ** Viaccess (pri -10) May 7 13:09:47.800 CAM(general.info): loading cardclient config from ./sc_files/cardclient.conf May 7 13:09:47.801 CAM(cardclient.newcamd): now using protocol version 525 (cdLen=8) May 7 13:09:47.802 CAM(cardclient.core): hostname=localhost port=15000 emm=1 emmCaids 0926/ffff May 7 13:09:47.802 CAM(cardclient.core): Newcamd: username=dummy password=dummy key=0102030405060708091011121314 May 7 13:09:47.803 CAM(core.net): netwatch up May 7 13:09:47.805 CAM(core.net): connecting to localhost:15000/tcp (127.0.0.1) May 7 13:09:47.808 CAM(cardclient.login): Newcamd: CaID=0926 admin=1 srvUA=000000000002E5BF provider 000000/000000000002E500 May 7 13:09:47.810 CAM(cardclient.core): client 'Newcamd' ready May 7 13:09:47.812 CAM(cardclient.core): created 1 client(s) May 7 13:09:47.812 CAM(core.load): loaded 0 Irdeto cards from ./sc_files/Ird-Beta.KID May 7 13:09:47.813 CAM(core.load): loaded 0 Seca cards from ./sc_files/Seca.KID May 7 13:09:47.814 CAM(core.load): loaded 0 Viaccess cards from ./sc_files/Viaccess.KID May 7 13:09:47.814 CAM(general.info): loading ca cache from ./sc_files/ca.cache May 7 13:09:47.815 CAM(general.warn): no smartcard interface defined! May 7 13:09:48.817 frontend: Starting thread on /dev/dvb/adapter1/frontend1 The thread scheduling parameters indicate: policy = 0 priority = 0 May 7 13:09:48.826 dvr: Starting thread on /dev/dvb/adapter1/dvr1 The thread scheduling parameters indicate: policy = 1 priority = 99 May 7 13:09:48.826 demux: Starting thread on /dev/dvb/adapter1/demux1 The thread scheduling parameters indicate: policy = 0 priority = 0 May 7 13:09:48.846 : Listening on port 5456 May 7 13:09:50.054 CHANNEL: Tuning frontend May 7 13:09:50.059 CAM: Got MSG_RESETSID May 7 13:09:50.063 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:09:50.620 CAM(core.pids): 0: now tuned to source 8000 transponder 92 May 7 13:09:50.621 CAM: SC completed Tune cmd May 7 13:09:50.622 CAM: Adding pid 2354 for sid 146 to pidlist May 7 13:09:50.622 CAM: Adding pid 2356 for sid 146 to pidlist May 7 13:09:50.623 CAM: Adding pid 2355 for sid 146 to pidlist May 7 13:09:50.624 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:09:50.625 CAM(core.pids): 0: pids typ5=0932 typ5=0934 typ5=0933 May 7 13:09:50.627 CAM(core.pids): 0: SID=146 zero=0 | sid=-/-/- zero=-/-/- idle=-/-/- May 7 13:09:50.627 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=1 idx=1) May 7 13:09:50.628 CAM(core.ecm): 0.1: setting new SID 146 May 7 13:09:50.629 CAM(core.pids): 0.1: pids on entry May 7 13:09:50.629 CAM(core.pids): 0.1: pids after delete May 7 13:09:50.630 CAM(core.pids): 0: descrambling pid 0932 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:09:50.632 CAM: Sending (1) key P 1 PID: 2354 May 7 13:09:50.633 CSA: Got command(1): P idx: 1 pid: 2354 May 7 13:09:50.633 CAM(core.pids): 0: descrambling pid 0934 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:09:50.635 CAM: Sending (1) key P 1 PID: 2356 May 7 13:09:50.636 CSA: Got command(1): P idx: 1 pid: 2356 May 7 13:09:50.636 CAM(core.pids): 0: descrambling pid 0933 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:09:50.638 CAM: Sending (1) key P 1 PID: 2355 May 7 13:09:50.639 CSA: Got command(1): P idx: 1 pid: 2355 May 7 13:09:50.639 CAM(core.pids): 0.1: pids after add typ5=0932 typ5=0934 typ5=0933 May 7 13:09:50.640 CAM(core.ecm): 0.1: is no longer idle May 7 13:09:50.641 MSG: Got unprocessed message type: 1 May 7 13:09:50.798 CAM(core.ecm): 0.1: triggered SID -1/146 idx -1/1 mode -1/0 - May 7 13:09:50.803 CAM(core.ecm): from cache: system Cardclient (0926) id 0000 with ecm 935/80 May 7 13:09:50.803 CAM(core.ecm): 0.1: got CaDescriptors for SID 146 (len=6) May 7 13:09:50.804 CAM(core.ecm): 0.1: descriptor 09 26 e9 35 May 7 13:09:50.805 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 935 (already present) May 7 13:09:50.806 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 935 (cached) (pri=-15) May 7 13:09:50.811 CAM(cardclient.core): cc-loop May 7 13:09:50.812 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:09:50.906 CAM(core.au): 0: chain caid 0926 -> Cardclient(-15) [00c0-82/ff/00] May 7 13:09:50.911 CAM(core.au): 0: starting chain 0926 May 7 13:09:50.967 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:09:50.971 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (158 ms) May 7 13:09:50.972 CAM(cardclient.core): cc-loop May 7 13:09:50.972 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:09:50.974 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:09:50.975 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (2 ms) May 7 13:09:51.014 CAM(core.ecm): 0.1: got CaDescriptors for SID 146 (len=6) May 7 13:09:51.015 CAM(core.ecm): 0.1: descriptor 09 26 e9 35 May 7 13:09:51.015 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 935 (already present) May 7 13:09:51.016 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 935 (cached) (pri=-15) May 7 13:09:51.114 CAM(cardclient.core): cc-loop May 7 13:09:51.115 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:09:51.215 CAM(cardclient.core): cc-loop May 7 13:09:51.217 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:09:51.316 CAM(core.ecm): 0.1: got CaDescriptors for SID 146 (len=6) May 7 13:09:51.317 CAM(core.ecm): 0.1: descriptor 09 26 e9 35 May 7 13:09:51.318 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 935 (already present) May 7 13:09:51.319 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 935 (cached) (pri=-15) May 7 13:09:52.820 CAM(cardclient.core): cc-loop May 7 13:09:52.821 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:09:52.822 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:09:52.823 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (1 ms) May 7 13:09:52.910 CAM(cardclient.core): cc-loop May 7 13:09:52.911 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:09:52.912 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:09:52.913 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (1 ms) May 7 13:09:53.012 CAM(core.ecm): 0.1: got CaDescriptors for SID 146 (len=6) May 7 13:09:53.013 CAM(core.ecm): 0.1: descriptor 09 26 e9 35 May 7 13:09:53.013 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 935 (already present) May 7 13:09:53.014 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 935 (cached) (pri=-15) May 7 13:09:53.015 CAM(core.ecm): 0.1: stopping message log until valid key is found May 7 13:10:02.811 CAM(cardclient.core): cc-loop May 7 13:10:02.815 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:02.939 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:02.940 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (125 ms) May 7 13:10:02.941 CAM(cardclient.core): cc-loop May 7 13:10:02.942 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:02.943 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:02.944 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (1 ms) May 7 13:10:12.812 CAM(cardclient.core): cc-loop May 7 13:10:12.813 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:12.935 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:12.936 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (122 ms) May 7 13:10:12.936 CAM(cardclient.core): cc-loop May 7 13:10:12.937 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:12.938 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:12.939 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (1 ms) May 7 13:10:22.812 CAM(cardclient.core): cc-loop May 7 13:10:22.814 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:22.944 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:22.945 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (130 ms) May 7 13:10:22.946 CAM(cardclient.core): cc-loop May 7 13:10:22.947 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:22.948 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:22.949 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (1 ms) May 7 13:10:32.814 CAM(cardclient.core): cc-loop May 7 13:10:32.815 CAM(cardclient.core): now trying client Newcamd (localhost:15000) Called cSascDvbDevice::SetCaDescr May 7 13:10:32.946 CAM: Sending key(-1) E 1 ebd...3f May 7 13:10:32.947 CSA: Got command(1): E idx: 1 pid: 0 key: 0ebd...3f Called cSascDvbDevice::SetCaDescr May 7 13:10:32.949 CAM: Sending key(-1) O 1 26b2...5d May 7 13:10:32.949 CSA: Got command(1): O idx: 1 pid: 0 key: 26b2...5d May 7 13:10:32.950 CAM(core.ecm): 0.1: correct key found May 7 13:10:32.955 CSA: Creating csa for rb: 1 Called cSascDvbDevice::SetCaDescr May 7 13:10:35.015 CAM: Sending key(-1) E 1 ebd...3f May 7 13:10:35.016 CSA: Got command(1): E idx: 1 pid: 0 key: 0ebd...3f Called cSascDvbDevice::SetCaDescr May 7 13:10:35.017 CAM: Sending key(-1) O 1 26b2...5d May 7 13:10:35.018 CSA: Got command(1): O idx: 1 pid: 0 key: 26b2...5d May 7 13:10:36.515 CAM: Got MSG_REMOVESID with sid: 146 May 7 13:10:36.515 CSA: Removing csa for rb: 1 May 7 13:10:36.521 CAM: Mapped sid to 2355 May 7 13:10:36.527 CAM: Mapped sid to 2356 May 7 13:10:36.528 CAM: Mapped sid to 2354 May 7 13:10:36.529 CAM: Got MSG_RESETSID May 7 13:10:36.529 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:36.530 CAM(core.pids): 0: pids typ5=0934 typ5=0932 May 7 13:10:36.531 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:36.531 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:36.532 CAM(core.pids): 0.1: pids on entry typ5=0932 typ5=0934 typ5=0933 May 7 13:10:36.533 CAM(core.pids): 0.1: pids after delete typ5=0932 typ5=0934 May 7 13:10:36.534 CAM(core.pids): 0.1: pids after add typ5=0932 typ5=0934 May 7 13:10:36.535 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:36.535 CAM(core.pids): 0: pids typ5=0932 May 7 13:10:36.536 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:36.537 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:36.538 CAM(core.pids): 0.1: pids on entry typ5=0932 typ5=0934 May 7 13:10:36.538 CAM(core.pids): 0.1: pids after delete typ5=0932 May 7 13:10:36.539 CAM(core.pids): 0.1: pids after add typ5=0932 May 7 13:10:36.540 CAM(core.pids): 0: update SID 146 (zero=0 noshift=1) May 7 13:10:36.541 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:36.541 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:36.542 CAM(core.pids): 0.1: pids on entry typ5=0932 May 7 13:10:36.543 CAM(core.pids): 0.1: pids after delete May 7 13:10:36.543 CAM(core.pids): 0.1: pids after add May 7 13:10:36.544 CAM(core.ecm): 0.1: is idle now May 7 13:10:36.545 CAM(core.ecm): 0.1: stop May 7 13:10:36.546 CAM(core.au): 0: stopping chain 0926 May 7 13:10:36.546 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:10:36.578 CAM(core.ecm): 0.1: triggered SID 146/-1 idx 1/1 mode 3/0 sync May 7 13:10:38.386 CHANNEL: Tuning frontend May 7 13:10:38.391 CHANNEL: Skipping cache reset since tuning matches last tune May 7 13:10:38.672 CAM(core.pids): 0: tune to same source/transponder May 7 13:10:38.674 CAM: SC completed Tune cmd May 7 13:10:38.675 CAM: Adding pid 2354 for sid 146 to pidlist May 7 13:10:38.676 CAM: Adding pid 2356 for sid 146 to pidlist May 7 13:10:38.676 CAM: Adding pid 2355 for sid 146 to pidlist May 7 13:10:38.677 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:38.678 CAM(core.pids): 0: pids typ5=0932 typ5=0934 typ5=0933 May 7 13:10:38.679 CAM(core.pids): 0: SID=146 zero=0 | sid=-/-/- zero=-/-/- idle=1/-1/1 May 7 13:10:38.679 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=1 idx=1) May 7 13:10:38.680 CAM(core.ecm): 0.1: setting new SID 146 May 7 13:10:38.680 CAM(core.pids): 0.1: pids on entry May 7 13:10:38.681 CAM(core.pids): 0.1: pids after delete May 7 13:10:38.682 CAM(core.pids): 0: descrambling pid 0932 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:38.683 CAM: Sending (1) key P 1 PID: 2354 May 7 13:10:38.684 CSA: Got command(1): P idx: 1 pid: 2354 May 7 13:10:38.685 CAM(core.pids): 0: descrambling pid 0934 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:38.686 CAM: Sending (1) key P 1 PID: 2356 May 7 13:10:38.687 CSA: Got command(1): P idx: 1 pid: 2356 May 7 13:10:38.688 CAM(core.pids): 0: descrambling pid 0933 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:38.689 CAM: Sending (1) key P 1 PID: 2355 May 7 13:10:38.690 CSA: Got command(1): P idx: 1 pid: 2355 May 7 13:10:38.691 CAM(core.pids): 0.1: pids after add typ5=0932 typ5=0934 typ5=0933 May 7 13:10:38.691 CAM(core.ecm): 0.1: is no longer idle May 7 13:10:38.692 MSG: Got unprocessed message type: 1 May 7 13:10:38.742 CAM(core.ecm): 0.1: triggered SID -1/146 idx 1/1 mode -1/0 - May 7 13:10:38.746 CAM(core.ecm): from cache: system Cardclient (0926) id 0000 with ecm 935/80 May 7 13:10:38.747 CAM(core.ecm): 0.1: got CaDescriptors for SID 146 (len=6) May 7 13:10:38.748 CAM(core.ecm): 0.1: descriptor 09 26 e9 35 May 7 13:10:38.749 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 935 (already present) May 7 13:10:38.750 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 935 (cached) (pri=-15) May 7 13:10:38.820 CAM(cardclient.core): cc-loop May 7 13:10:38.821 CAM(cardclient.core): now trying client Newcamd (localhost:15000) Called cSascDvbDevice::SetCaDescr May 7 13:10:38.823 CAM: Sending key(-1) E 1 ebd...3f May 7 13:10:38.824 CSA: Got command(1): E idx: 1 pid: 0 key: 0ebd...3f Called cSascDvbDevice::SetCaDescr May 7 13:10:38.826 CAM: Sending key(-1) O 1 26b2...5d May 7 13:10:38.826 CSA: Got command(1): O idx: 1 pid: 0 key: 26b2...5d May 7 13:10:38.827 CAM(core.ecm): 0.1: correct key found May 7 13:10:38.831 CSA: Creating csa for rb: 1 May 7 13:10:38.872 CAM(core.au): 0: chain caid 0926 -> Cardclient(-15) [00c0-82/ff/00] May 7 13:10:38.874 CAM(core.au): 0: starting chain 0926 Called cSascDvbDevice::SetCaDescr May 7 13:10:40.923 CAM: Sending key(-1) E 1 ebd...3f May 7 13:10:40.924 CSA: Got command(1): E idx: 1 pid: 0 key: 0ebd...3f Called cSascDvbDevice::SetCaDescr May 7 13:10:40.926 CAM: Sending key(-1) O 1 26b2...5d May 7 13:10:40.926 CSA: Got command(1): O idx: 1 pid: 0 key: 26b2...5d Called cSascDvbDevice::SetCaDescr May 7 13:10:42.946 CAM: Sending key(-1) E 1 4c7...78 May 7 13:10:42.946 CSA: Got command(1): E idx: 1 pid: 0 key: 4c07...78 Called cSascDvbDevice::SetCaDescr May 7 13:10:42.950 CAM: Sending key(-1) O 1 2ad0...e2 May 7 13:10:42.950 CSA: Got command(1): O idx: 1 pid: 0 key: 2ad0...e2 May 7 13:10:44.158 CAM: Got MSG_REMOVESID with sid: 146 May 7 13:10:44.158 CSA: Removing csa for rb: 1 May 7 13:10:44.163 CAM: Mapped sid to 2355 May 7 13:10:44.171 CAM: Mapped sid to 2356 May 7 13:10:44.172 CAM: Mapped sid to 2354 May 7 13:10:44.173 CAM: Got MSG_RESETSID May 7 13:10:44.173 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:44.174 CAM(core.pids): 0: pids typ5=0934 typ5=0932 May 7 13:10:44.175 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:44.175 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:44.176 CAM(core.pids): 0.1: pids on entry typ5=0932 typ5=0934 typ5=0933 May 7 13:10:44.176 CAM(core.pids): 0.1: pids after delete typ5=0932 typ5=0934 May 7 13:10:44.177 CAM(core.pids): 0.1: pids after add typ5=0932 typ5=0934 May 7 13:10:44.178 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:44.178 CAM(core.pids): 0: pids typ5=0932 May 7 13:10:44.178 CAM(core.ecm): 0.1: triggered SID 146/146 idx 1/1 mode 3/0 sync May 7 13:10:44.183 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:44.187 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:44.188 CAM(core.pids): 0.1: pids on entry typ5=0932 typ5=0934 May 7 13:10:44.189 CAM(core.pids): 0.1: pids after delete typ5=0932 May 7 13:10:44.190 CAM(core.pids): 0.1: pids after add typ5=0932 May 7 13:10:44.190 CAM(core.pids): 0: update SID 146 (zero=0 noshift=1) May 7 13:10:44.191 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:44.192 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:44.193 CAM(core.pids): 0.1: pids on entry typ5=0932 May 7 13:10:44.193 CAM(core.pids): 0.1: pids after delete May 7 13:10:44.194 CAM(core.pids): 0.1: pids after add May 7 13:10:44.195 CAM(core.ecm): 0.1: is idle now May 7 13:10:44.195 CAM(core.ecm): 0.1: stop May 7 13:10:44.196 CAM(core.au): 0: stopping chain 0926 May 7 13:10:44.196 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:10:44.220 CAM(core.ecm): 0.1: triggered SID 146/-1 idx 1/1 mode 3/0 sync May 7 13:10:44.704 CHANNEL: Tuning frontend May 7 13:10:44.706 CHANNEL: Skipping cache reset since tuning matches last tune May 7 13:10:44.992 CAM(core.pids): 0: tune to same source/transponder May 7 13:10:44.995 CAM: SC completed Tune cmd May 7 13:10:44.995 CAM: Adding pid 2354 for sid 146 to pidlist May 7 13:10:44.996 CAM: Adding pid 2356 for sid 146 to pidlist May 7 13:10:44.997 CAM: Adding pid 2355 for sid 146 to pidlist May 7 13:10:44.997 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:44.998 CAM(core.pids): 0: pids typ5=0932 typ5=0934 typ5=0933 May 7 13:10:44.999 CAM(core.pids): 0: SID=146 zero=0 | sid=-/-/- zero=-/-/- idle=1/-1/1 May 7 13:10:44.999 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=1 idx=1) May 7 13:10:45.000 CAM(core.ecm): 0.1: setting new SID 146 May 7 13:10:45.001 CAM(core.pids): 0.1: pids on entry May 7 13:10:45.001 CAM(core.pids): 0.1: pids after delete May 7 13:10:45.002 CAM(core.pids): 0: descrambling pid 0932 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:45.004 CAM: Sending (1) key P 1 PID: 2354 May 7 13:10:45.005 CSA: Got command(1): P idx: 1 pid: 2354 May 7 13:10:45.006 CAM(core.pids): 0: descrambling pid 0934 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:45.008 CAM: Sending (1) key P 1 PID: 2356 May 7 13:10:45.008 CSA: Got command(1): P idx: 1 pid: 2356 May 7 13:10:45.009 CAM(core.pids): 0: descrambling pid 0933 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:45.011 CAM: Sending (1) key P 1 PID: 2355 May 7 13:10:45.012 CSA: Got command(1): P idx: 1 pid: 2355 May 7 13:10:45.012 CAM(core.pids): 0.1: pids after add typ5=0932 typ5=0934 typ5=0933 May 7 13:10:45.013 CAM(core.ecm): 0.1: is no longer idle May 7 13:10:45.014 MSG: Got unprocessed message type: 1 May 7 13:10:45.062 CAM(core.ecm): 0.1: triggered SID -1/146 idx 1/1 mode -1/0 - May 7 13:10:45.067 CAM(core.ecm): from cache: system Cardclient (0926) id 0000 with ecm 935/80 May 7 13:10:45.067 CAM(core.ecm): 0.1: got CaDescriptors for SID 146 (len=6) May 7 13:10:45.068 CAM(core.ecm): 0.1: descriptor 09 26 e9 35 May 7 13:10:45.069 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 935 (already present) May 7 13:10:45.069 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 935 (cached) (pri=-15) May 7 13:10:45.118 CAM(cardclient.core): cc-loop May 7 13:10:45.119 CAM(cardclient.core): now trying client Newcamd (localhost:15000) Called cSascDvbDevice::SetCaDescr May 7 13:10:45.121 CAM: Sending key(-1) E 1 4c7...78 May 7 13:10:45.122 CSA: Got command(1): E idx: 1 pid: 0 key: 4c07...78 Called cSascDvbDevice::SetCaDescr May 7 13:10:45.123 CAM: Sending key(-1) O 1 2ad0...e2 May 7 13:10:45.124 CSA: Got command(1): O idx: 1 pid: 0 key: 2ad0...e2 May 7 13:10:45.125 CAM(core.ecm): 0.1: correct key found May 7 13:10:45.128 CSA: Creating csa for rb: 1 May 7 13:10:45.522 CAM(core.au): 0: chain caid 0926 -> Cardclient(-15) [00c0-82/ff/00] May 7 13:10:45.526 CAM(core.au): 0: starting chain 0926 Called cSascDvbDevice::SetCaDescr May 7 13:10:47.219 CAM: Sending key(-1) E 1 4c7...78 May 7 13:10:47.220 CSA: Got command(1): E idx: 1 pid: 0 key: 4c07...78 Called cSascDvbDevice::SetCaDescr May 7 13:10:47.222 CAM: Sending key(-1) O 1 2ad0...e2 May 7 13:10:47.223 CSA: Got command(1): O idx: 1 pid: 0 key: 2ad0...e2 May 7 13:10:50.776 CAM: Got MSG_REMOVESID with sid: 146 May 7 13:10:50.776 CSA: Removing csa for rb: 1 May 7 13:10:50.782 CAM: Mapped sid to 2355 May 7 13:10:50.787 CAM: Mapped sid to 2356 May 7 13:10:50.788 CAM: Mapped sid to 2354 May 7 13:10:50.789 CAM: Got MSG_RESETSID May 7 13:10:50.789 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:50.790 CAM(core.pids): 0: pids typ5=0934 typ5=0932 May 7 13:10:50.791 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:50.791 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:50.792 CAM(core.pids): 0.1: pids on entry typ5=0932 typ5=0934 typ5=0933 May 7 13:10:50.793 CAM(core.pids): 0.1: pids after delete typ5=0932 typ5=0934 May 7 13:10:50.793 CAM(core.pids): 0.1: pids after add typ5=0932 typ5=0934 May 7 13:10:50.794 CAM(core.pids): 0: update SID 146 (zero=0 noshift=0) May 7 13:10:50.795 CAM(core.pids): 0: pids typ5=0932 May 7 13:10:50.795 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:50.796 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:50.796 CAM(core.pids): 0.1: pids on entry typ5=0932 typ5=0934 May 7 13:10:50.797 CAM(core.pids): 0.1: pids after delete typ5=0932 May 7 13:10:50.798 CAM(core.pids): 0.1: pids after add typ5=0932 May 7 13:10:50.798 CAM(core.pids): 0: update SID 146 (zero=0 noshift=1) May 7 13:10:50.808 CAM(core.auStats): EMM packet load average (1/4/10min) 40 10 4 pks/s May 7 13:10:50.820 CAM(core.ecm): 0.1: triggered SID 146/146 idx 1/1 mode 3/0 sync May 7 13:10:50.830 CAM(core.pids): 0: SID=146 zero=0 | sid=1/146/0 zero=-/-/- idle=-/-/- May 7 13:10:50.835 CAM(core.pids): 0: found handler for SID 146 (0.1 idle=0 idx=1) May 7 13:10:50.836 CAM(core.pids): 0.1: pids on entry typ5=0932 May 7 13:10:50.837 CAM(core.pids): 0.1: pids after delete May 7 13:10:50.838 CAM(core.pids): 0.1: pids after add May 7 13:10:50.839 CAM(core.ecm): 0.1: is idle now May 7 13:10:50.839 CAM(core.ecm): 0.1: stop May 7 13:10:50.840 CAM(core.au): 0: stopping chain 0926 May 7 13:10:50.841 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:10:50.890 CAM(core.ecm): 0.1: triggered SID 146/-1 idx 1/1 mode 3/-1 sync May 7 13:10:55.046 CHANNEL: Tuning frontend May 7 13:10:55.050 CHANNEL: Skipping cache reset since tuning matches last tune May 7 13:10:55.333 CAM(core.pids): 0: now tuned to source 8000 transponder 93 May 7 13:10:55.334 CAM: SC completed Tune cmd May 7 13:10:55.335 CAM: Adding pid 2369 for sid 147 to pidlist May 7 13:10:55.336 CAM: Adding pid 2372 for sid 147 to pidlist May 7 13:10:55.336 CAM: Adding pid 2371 for sid 147 to pidlist May 7 13:10:55.337 CAM: Adding pid 2370 for sid 147 to pidlist May 7 13:10:55.338 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:10:55.338 CAM(core.pids): 0: pids typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:10:55.339 CAM(core.pids): 0: SID=147 zero=0 | sid=-/-/- zero=-/-/- idle=1/-1/1 May 7 13:10:55.340 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=1 idx=1) May 7 13:10:55.341 CAM(core.ecm): 0.1: setting new SID 147 May 7 13:10:55.341 CAM(core.pids): 0.1: pids on entry May 7 13:10:55.343 CAM(core.pids): 0.1: pids after delete May 7 13:10:55.343 CAM(core.pids): 0: descrambling pid 0941 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:55.345 CAM: Sending (1) key P 1 PID: 2369 May 7 13:10:55.346 CSA: Got command(1): P idx: 1 pid: 2369 May 7 13:10:55.347 CAM(core.pids): 0: descrambling pid 0944 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:55.349 CAM: Sending (1) key P 1 PID: 2372 May 7 13:10:55.349 CSA: Got command(1): P idx: 1 pid: 2372 May 7 13:10:55.350 CAM(core.pids): 0: descrambling pid 0943 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:55.352 CAM: Sending (1) key P 1 PID: 2371 May 7 13:10:55.353 CSA: Got command(1): P idx: 1 pid: 2371 May 7 13:10:55.354 CAM(core.pids): 0: descrambling pid 0942 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:10:55.356 CAM: Sending (1) key P 1 PID: 2370 May 7 13:10:55.357 CSA: Got command(1): P idx: 1 pid: 2370 May 7 13:10:55.358 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:10:55.358 CAM(core.ecm): 0.1: is no longer idle May 7 13:10:55.359 MSG: Got unprocessed message type: 1 May 7 13:10:55.394 CAM(core.ecm): 0.1: triggered SID -1/147 idx 1/1 mode -1/0 - May 7 13:10:55.398 CAM(core.ecm): from cache: system Cardclient (0926) id 0000 with ecm 945/80 May 7 13:10:55.399 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:10:55.400 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:10:55.401 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:10:55.402 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:10:55.476 CAM(cardclient.core): cc-loop May 7 13:10:55.476 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:55.496 CAM(core.au): 0: chain caid 0926 -> Cardclient(-15) [00c0-82/ff/00] May 7 13:10:55.499 CAM(core.au): 0: starting chain 0926 May 7 13:10:55.604 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:55.607 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (130 ms) May 7 13:10:55.608 CAM(cardclient.core): cc-loop May 7 13:10:55.608 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:55.610 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:10:55.611 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (2 ms) May 7 13:10:55.668 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:10:55.669 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:10:55.669 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:10:55.670 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:10:55.768 CAM(cardclient.core): cc-loop May 7 13:10:55.769 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:55.869 CAM(cardclient.core): cc-loop May 7 13:10:55.870 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:10:55.970 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:10:55.971 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:10:55.972 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:10:55.973 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:02.873 CAM(cardclient.core): cc-loop May 7 13:11:02.874 CAM(cardclient.core): now trying client Newcamd (localhost:15000) Called cSascDvbDevice::SetCaDescr May 7 13:11:03.000 CAM: Sending key(-1) E 1 87cc...b6 May 7 13:11:03.001 CSA: Got command(1): E idx: 1 pid: 0 key: 87cc...b6 Called cSascDvbDevice::SetCaDescr May 7 13:11:03.031 CAM: Sending key(-1) O 1 5750...11 May 7 13:11:03.032 CSA: Got command(1): O idx: 1 pid: 0 key: 5750...11 May 7 13:11:03.033 CAM(core.ecm): 0.1: correct key found May 7 13:11:03.034 CSA: Creating csa for rb: 1 Called cSascDvbDevice::SetCaDescr May 7 13:11:05.075 CAM: Sending key(-1) E 1 87cc...b6 May 7 13:11:05.076 CSA: Got command(1): E idx: 1 pid: 0 key: 87cc...b6 Called cSascDvbDevice::SetCaDescr May 7 13:11:05.078 CAM: Sending key(-1) O 1 5750...11 May 7 13:11:05.079 CSA: Got command(1): O idx: 1 pid: 0 key: 5750...11 May 7 13:11:10.286 CAM: Got MSG_REMOVESID with sid: 147 May 7 13:11:10.286 CSA: Removing csa for rb: 1 May 7 13:11:10.291 CAM: Mapped sid to 2370 May 7 13:11:10.299 CAM: Mapped sid to 2371 May 7 13:11:10.300 CAM: Mapped sid to 2372 May 7 13:11:10.300 CAM: Mapped sid to 2369 May 7 13:11:10.301 CAM: Got MSG_RESETSID May 7 13:11:10.302 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:10.303 CAM(core.pids): 0: pids typ5=0943 typ5=0944 typ5=0941 May 7 13:11:10.303 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:10.304 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:10.305 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:10.305 CAM(core.pids): 0.1: pids after delete typ5=0941 typ5=0944 typ5=0943 May 7 13:11:10.306 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 typ5=0943 May 7 13:11:10.307 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:10.307 CAM(core.pids): 0: pids typ5=0944 typ5=0941 May 7 13:11:10.308 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:10.309 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:10.309 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 typ5=0943 May 7 13:11:10.310 CAM(core.pids): 0.1: pids after delete typ5=0941 typ5=0944 May 7 13:11:10.311 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 May 7 13:11:10.311 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:10.312 CAM(core.pids): 0: pids typ5=0941 May 7 13:11:10.313 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:10.313 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:10.314 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 May 7 13:11:10.315 CAM(core.pids): 0.1: pids after delete typ5=0941 May 7 13:11:10.316 CAM(core.pids): 0.1: pids after add typ5=0941 May 7 13:11:10.316 CAM(core.pids): 0: update SID 147 (zero=0 noshift=1) May 7 13:11:10.317 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:10.318 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:10.319 CAM(core.pids): 0.1: pids on entry typ5=0941 May 7 13:11:10.319 CAM(core.pids): 0.1: pids after delete May 7 13:11:10.320 CAM(core.pids): 0.1: pids after add May 7 13:11:10.321 CAM(core.ecm): 0.1: is idle now May 7 13:11:10.321 CAM(core.ecm): 0.1: stop May 7 13:11:10.322 CAM(core.au): 0: stopping chain 0926 May 7 13:11:10.323 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:11:10.330 CAM(core.ecm): 0.1: triggered SID 147/-1 idx 1/1 mode 3/0 sync May 7 13:11:12.354 CHANNEL: Tuning frontend May 7 13:11:12.359 CHANNEL: Skipping cache reset since tuning matches last tune May 7 13:11:12.640 CAM(core.pids): 0: tune to same source/transponder May 7 13:11:12.642 CAM: SC completed Tune cmd May 7 13:11:12.643 CAM: Adding pid 2369 for sid 147 to pidlist May 7 13:11:12.644 CAM: Adding pid 2372 for sid 147 to pidlist May 7 13:11:12.644 CAM: Adding pid 2371 for sid 147 to pidlist May 7 13:11:12.645 CAM: Adding pid 2370 for sid 147 to pidlist May 7 13:11:12.646 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:12.647 CAM(core.pids): 0: pids typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:12.647 CAM(core.pids): 0: SID=147 zero=0 | sid=-/-/- zero=-/-/- idle=1/-1/1 May 7 13:11:12.648 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=1 idx=1) May 7 13:11:12.649 CAM(core.ecm): 0.1: setting new SID 147 May 7 13:11:12.649 CAM(core.pids): 0.1: pids on entry May 7 13:11:12.650 CAM(core.pids): 0.1: pids after delete May 7 13:11:12.650 CAM(core.pids): 0: descrambling pid 0941 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:12.652 CAM: Sending (1) key P 1 PID: 2369 May 7 13:11:12.653 CSA: Got command(1): P idx: 1 pid: 2369 May 7 13:11:12.653 CAM(core.pids): 0: descrambling pid 0944 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:12.655 CAM: Sending (1) key P 1 PID: 2372 May 7 13:11:12.656 CSA: Got command(1): P idx: 1 pid: 2372 May 7 13:11:12.657 CAM(core.pids): 0: descrambling pid 0943 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:12.659 CAM: Sending (1) key P 1 PID: 2371 May 7 13:11:12.660 CSA: Got command(1): P idx: 1 pid: 2371 May 7 13:11:12.661 CAM(core.pids): 0: descrambling pid 0942 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:12.662 CAM: Sending (1) key P 1 PID: 2370 May 7 13:11:12.663 CSA: Got command(1): P idx: 1 pid: 2370 May 7 13:11:12.664 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:12.664 CAM(core.ecm): 0.1: is no longer idle May 7 13:11:12.665 MSG: Got unprocessed message type: 1 May 7 13:11:12.674 CAM(core.ecm): 0.1: triggered SID -1/147 idx 1/1 mode -1/0 - May 7 13:11:12.679 CAM(core.ecm): from cache: system Cardclient (0926) id 0000 with ecm 945/80 May 7 13:11:12.680 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:11:12.680 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:11:12.681 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:11:12.682 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:12.878 CAM(cardclient.core): cc-loop May 7 13:11:12.879 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:13.008 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:11:13.009 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (129 ms) May 7 13:11:13.010 CAM(cardclient.core): cc-loop May 7 13:11:13.011 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:13.012 CAM(cardclient.ecm): Newcamd: card was not able to decode the channel May 7 13:11:13.013 CAM(cardclient.core): client Newcamd (localhost:15000) ECM failed (2 ms) May 7 13:11:13.069 CAM(core.au): 0: chain caid 0926 -> Cardclient(-15) [00c0-82/ff/00] May 7 13:11:13.071 CAM(core.au): 0: starting chain 0926 May 7 13:11:13.072 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:11:13.074 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:11:13.075 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:11:13.076 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:13.170 CAM(cardclient.core): cc-loop May 7 13:11:13.172 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:13.272 CAM(cardclient.core): cc-loop May 7 13:11:13.273 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:13.372 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:11:13.373 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:11:13.374 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:11:13.374 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:13.977 CAM: Got MSG_REMOVESID with sid: 147 May 7 13:11:13.977 CSA: Removing csa for rb: 1 May 7 13:11:13.982 CAM: Mapped sid to 2370 May 7 13:11:13.991 CAM: Mapped sid to 2371 May 7 13:11:13.992 CAM: Mapped sid to 2372 May 7 13:11:13.992 CAM: Mapped sid to 2369 May 7 13:11:13.993 CAM: Got MSG_RESETSID May 7 13:11:13.994 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:13.994 CAM(core.pids): 0: pids typ5=0943 typ5=0944 typ5=0941 May 7 13:11:13.995 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:13.996 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:13.996 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:13.997 CAM(core.pids): 0.1: pids after delete typ5=0941 typ5=0944 typ5=0943 May 7 13:11:13.998 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 typ5=0943 May 7 13:11:13.998 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:13.999 CAM(core.pids): 0: pids typ5=0944 typ5=0941 May 7 13:11:14.000 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:14.000 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:14.001 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 typ5=0943 May 7 13:11:14.002 CAM(core.pids): 0.1: pids after delete typ5=0941 typ5=0944 May 7 13:11:14.002 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 May 7 13:11:14.003 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:14.003 CAM(core.pids): 0: pids typ5=0941 May 7 13:11:14.004 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:14.005 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:14.006 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 May 7 13:11:14.006 CAM(core.pids): 0.1: pids after delete typ5=0941 May 7 13:11:14.007 CAM(core.pids): 0.1: pids after add typ5=0941 May 7 13:11:14.008 CAM(core.pids): 0: update SID 147 (zero=0 noshift=1) May 7 13:11:14.008 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:14.009 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:14.009 CAM(core.pids): 0.1: pids on entry typ5=0941 May 7 13:11:14.010 CAM(core.pids): 0.1: pids after delete May 7 13:11:14.011 CAM(core.pids): 0.1: pids after add May 7 13:11:14.011 CAM(core.ecm): 0.1: is idle now May 7 13:11:14.012 CAM(core.ecm): 0.1: stop May 7 13:11:14.012 CAM(core.au): 0: stopping chain 0926 May 7 13:11:14.013 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:11:14.026 CAM(core.ecm): 0.1: triggered SID 147/-1 idx 1/1 mode 3/0 - May 7 13:11:18.438 CHANNEL: Tuning frontend May 7 13:11:18.443 CHANNEL: Skipping cache reset since tuning matches last tune May 7 13:11:18.724 CAM(core.pids): 0: tune to same source/transponder May 7 13:11:18.726 CAM: SC completed Tune cmd May 7 13:11:18.727 CAM: Adding pid 2369 for sid 147 to pidlist May 7 13:11:18.728 CAM: Adding pid 2372 for sid 147 to pidlist May 7 13:11:18.728 CAM: Adding pid 2371 for sid 147 to pidlist May 7 13:11:18.729 CAM: Adding pid 2370 for sid 147 to pidlist May 7 13:11:18.730 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:18.730 CAM(core.pids): 0: pids typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:18.731 CAM(core.pids): 0: SID=147 zero=0 | sid=-/-/- zero=-/-/- idle=1/-1/1 May 7 13:11:18.732 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=1 idx=1) May 7 13:11:18.732 CAM(core.ecm): 0.1: setting new SID 147 May 7 13:11:18.733 CAM(core.pids): 0.1: pids on entry May 7 13:11:18.734 CAM(core.pids): 0.1: pids after delete May 7 13:11:18.734 CAM(core.pids): 0: descrambling pid 0941 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:18.736 CAM: Sending (1) key P 1 PID: 2369 May 7 13:11:18.737 CSA: Got command(1): P idx: 1 pid: 2369 May 7 13:11:18.738 CAM(core.pids): 0: descrambling pid 0944 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:18.740 CAM: Sending (1) key P 1 PID: 2372 May 7 13:11:18.740 CSA: Got command(1): P idx: 1 pid: 2372 May 7 13:11:18.741 CAM(core.pids): 0: descrambling pid 0943 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:18.743 CAM: Sending (1) key P 1 PID: 2371 May 7 13:11:18.744 CSA: Got command(1): P idx: 1 pid: 2371 May 7 13:11:18.744 CAM(core.pids): 0: descrambling pid 0942 on index 1 Called cSascDvbDevice::SetCaPid May 7 13:11:18.746 CAM: Sending (1) key P 1 PID: 2370 May 7 13:11:18.747 CSA: Got command(1): P idx: 1 pid: 2370 May 7 13:11:18.748 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:18.748 CAM(core.ecm): 0.1: is no longer idle May 7 13:11:18.749 MSG: Got unprocessed message type: 1 May 7 13:11:18.770 CAM(core.ecm): 0.1: triggered SID -1/147 idx 1/1 mode -1/0 - May 7 13:11:18.774 CAM(core.ecm): from cache: system Cardclient (0926) id 0000 with ecm 945/80 May 7 13:11:18.775 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:11:18.776 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:11:18.778 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:11:18.779 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:18.869 CAM(cardclient.core): cc-loop May 7 13:11:18.870 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:18.970 CAM(cardclient.core): cc-loop May 7 13:11:18.971 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:19.071 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:11:19.072 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:11:19.073 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:11:19.074 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:19.172 CAM(cardclient.core): cc-loop May 7 13:11:19.172 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:19.242 CAM(core.au): 0: chain caid 0926 -> Cardclient(-15) [00c0-82/ff/00] May 7 13:11:19.246 CAM(core.au): 0: starting chain 0926 May 7 13:11:19.273 CAM(cardclient.core): cc-loop May 7 13:11:19.274 CAM(cardclient.core): now trying client Newcamd (localhost:15000) May 7 13:11:19.374 CAM(core.ecm): 0.1: got CaDescriptors for SID 147 (len=6) May 7 13:11:19.375 CAM(core.ecm): 0.1: descriptor 09 26 e9 45 May 7 13:11:19.375 CAM(core.ecm): 0.1: found 0926 (Cardclient) id 0000 with ecm 945 (already present) May 7 13:11:19.376 CAM(core.ecm): 0.1: try system Cardclient (0926) id 0000 with ecm 945 (cached) (pri=-15) May 7 13:11:22.469 CAM: Got MSG_REMOVESID with sid: 147 May 7 13:11:22.470 CSA: Removing csa for rb: 1 May 7 13:11:22.471 CAM: Mapped sid to 2370 May 7 13:11:22.478 CAM: Mapped sid to 2371 May 7 13:11:22.479 CAM: Mapped sid to 2372 May 7 13:11:22.480 CAM: Mapped sid to 2369 May 7 13:11:22.481 CAM: Got MSG_RESETSID May 7 13:11:22.482 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:22.483 CAM(core.pids): 0: pids typ5=0943 typ5=0944 typ5=0941 May 7 13:11:22.483 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:22.484 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:22.485 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 typ5=0943 typ5=0942 May 7 13:11:22.486 CAM(core.pids): 0.1: pids after delete typ5=0941 typ5=0944 typ5=0943 May 7 13:11:22.487 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 typ5=0943 May 7 13:11:22.487 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:22.488 CAM(core.pids): 0: pids typ5=0944 typ5=0941 May 7 13:11:22.489 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:22.490 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:22.491 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 typ5=0943 May 7 13:11:22.491 CAM(core.pids): 0.1: pids after delete typ5=0941 typ5=0944 May 7 13:11:22.492 CAM(core.pids): 0.1: pids after add typ5=0941 typ5=0944 May 7 13:11:22.493 CAM(core.pids): 0: update SID 147 (zero=0 noshift=0) May 7 13:11:22.494 CAM(core.pids): 0: pids typ5=0941 May 7 13:11:22.494 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:22.495 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:22.496 CAM(core.pids): 0.1: pids on entry typ5=0941 typ5=0944 May 7 13:11:22.497 CAM(core.pids): 0.1: pids after delete typ5=0941 May 7 13:11:22.497 CAM(core.pids): 0.1: pids after add typ5=0941 May 7 13:11:22.502 CAM(core.pids): 0: update SID 147 (zero=0 noshift=1) May 7 13:11:22.503 CAM(core.pids): 0: SID=147 zero=0 | sid=1/147/0 zero=-/-/- idle=-/-/- May 7 13:11:22.504 CAM(core.pids): 0: found handler for SID 147 (0.1 idle=0 idx=1) May 7 13:11:22.504 CAM(core.pids): 0.1: pids on entry typ5=0941 May 7 13:11:22.505 CAM(core.pids): 0.1: pids after delete May 7 13:11:22.506 CAM(core.pids): 0.1: pids after add May 7 13:11:22.506 CAM(core.ecm): 0.1: is idle now May 7 13:11:22.507 CAM(core.ecm): 0.1: stop May 7 13:11:22.508 CAM(core.au): 0: stopping chain 0926 May 7 13:11:22.508 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:11:22.530 CAM(core.ecm): 0.1: triggered SID 147/-1 idx 1/1 mode 3/0 - May 7 13:11:26.254 CHANNEL: Tuning frontend May 7 13:11:26.259 CHANNEL: Skipping cache reset since tuning matches last tune May 7 13:11:26.462 CAM: Got MSG_RESETSID May 7 13:11:26.463 CSA: Removing csa for rb: 1 May 7 13:11:26.467 CSA: Got command(1): I idx: 0 pid: 0 May 7 13:11:41.484 CAM(core.net): netwatch down May 7 13:11:41.486 CAM(general.debug): SC cleanup done May 7 13:11:41.487 : Exiting...