23:23:59.376895 CAM: Found a FF card 23:24:00.378761 frontend: Starting thread on /dev/dvb/adapter1/frontend1 The thread scheduling parameters indicate: policy = 0 priority = 0 23:24:00.383734 dvr: Starting thread on /dev/dvb/adapter1/dvr1 The thread scheduling parameters indicate: policy = 1 priority = 99 23:24:00.383858 demux: Starting thread on /dev/dvb/adapter1/demux1 The thread scheduling parameters indicate: policy = 0 priority = 0 23:24:00.384105 : Listening on port 5456 23:24:09.215826 CSA: Got command(1): I idx: 0 pid: 0 23:24:09.216097 CSA: Got command(1): I idx: 0 pid: 0 23:24:10.326850 CHANNEL: Tuning frontend 23:24:10.327017 CSA: Got command(1): I idx: 0 pid: 0 23:24:17.174810 CSA: Got command(1): I idx: 0 pid: 0 23:24:34.452379 CSA: Got command(1): I idx: 0 pid: 0 23:24:34.452658 CSA: Got command(1): I idx: 0 pid: 0 23:24:35.537884 CHANNEL: Tuning frontend 23:24:35.538073 CSA: Got command(1): I idx: 0 pid: 0 23:24:41.999446 CSA: Removing csa for rb: 1 Jul 18 23:24:42 [core.pids] 0: now tuned to source 1 transponder 1d7 23:24:42.142593 CAM: SC completed Tune cmd Jul 18 23:24:42 [core.pids] 0: update SID 471 (zero=1 noshift=0) Jul 18 23:24:42 [core.pids] 0: pids typ5=1822 typ5=1823 typ5=1824 Jul 18 23:24:42 [core.pids] 0: SID=471 zero=1 | sid=-/-/- zero=-/-/- idle=-/-/- Jul 18 23:24:42 [core.pids] 0: found handler for SID 471 (0.0 idle=1 idx=0) Jul 18 23:24:42 [core.ecm] 0.0: setting new SID 471 Jul 18 23:24:42 [core.pids] 0.0: pids on entry Jul 18 23:24:42 [core.pids] 0.0: pids after delete Jul 18 23:24:42 [core.pids] 0: descrambling pid 1822 on index 0 Called cSascDvbDevice::SetCaPid 23:24:42.142822 CSA: Got command(1): P idx: 0 pid: 6178 Jul 18 23:24:42 [core.pids] 0: descrambling pid 1823 on index 0 Called cSascDvbDevice::SetCaPid 23:24:42.142858 CSA: Got command(1): P idx: 0 pid: 6179 Jul 18 23:24:42 [core.pids] 0: descrambling pid 1824 on index 0 Called cSascDvbDevice::SetCaPid 23:24:42.142889 CSA: Got command(1): P idx: 0 pid: 6180 Jul 18 23:24:42 [core.pids] 0.0: pids after add typ5=1822 typ5=1823 typ5=1824 Jul 18 23:24:42 [core.ecm] 0.0: is no longer idle 23:24:42.143158 MSG: Got unprocessed message type: 1 23:24:42.143200 MSG: Got unprocessed message type: 1 Jul 18 23:24:42 [core.ecm] 0.0: triggered SID -1/471 idx -1/0 mode -1/0 - Jul 18 23:24:42 [core.ecm] from cache: system Nagra2 (1810) id 0000 with ecm 12d/80 called cSascDvbDevice::GetPrgCaids Jul 18 23:24:42 [core.ecm] 0.0: got CaDescriptors for SID 471 (len=36) Jul 18 23:24:42 [core.ecm] 0.0: descriptor 18 10 e1 2d Jul 18 23:24:42 [core.ecm] 0.0: found 1810 (Nagra2) id 0000 with ecm 12d (already present) Jul 18 23:24:42 [core.ecm] 0.0: descriptor 18 01 e1 2d Jul 18 23:24:42 [core.ecm] 0.0: found 1801 (Nagra2) id 0000 with ecm 12d (dup) (new) Jul 18 23:24:42 [core.ecm] 0.0: descriptor 18 10 e1 2d Jul 18 23:24:42 [core.ecm] 0.0: found 1810 (Nagra2) id 0000 with ecm 12d (already present) Jul 18 23:24:42 [core.ecm] 0.0: descriptor 18 01 e1 2d Jul 18 23:24:42 [core.ecm] 0.0: found 1801 (Nagra2) id 0000 with ecm 12d (dup) (already present) Jul 18 23:24:42 [core.ecm] 0.0: descriptor 18 10 e1 2d Jul 18 23:24:42 [core.ecm] 0.0: found 1810 (Nagra2) id 0000 with ecm 12d (already present) Jul 18 23:24:42 [core.ecm] 0.0: descriptor 18 01 e1 2d Jul 18 23:24:42 [core.ecm] 0.0: found 1801 (Nagra2) id 0000 with ecm 12d (dup) (already present) Jul 18 23:24:42 [core.ecm] 0.0: try system Nagra2 (1810) id 0000 with ecm 12d (cached) (pri=-10) Jul 18 23:24:42 [nagra.emu] mapmem: new map off=0000 size=10000 Jul 18 23:24:42 [nagra.ecm] provider 0101 capabilities MECM Bx Jul 18 23:24:42 [nagra.map] 0101: calling function 3B Jul 18 23:24:42 [nagra.map] 0101: calling function 43 Jul 18 23:24:42 [nagra.map] 0101: calling function 44 Jul 18 23:24:42 [core.ecm] system: using key N 0101 01 5B27... Jul 18 23:24:42 [core.au] 0: chain caid 1800 -> Nagra(-10) [0020-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1801 -> Nagra2(-10) [0120-82/fe/00] Jul 18 23:24:42 [core.au] 0: chain caid 1810 -> Nagra2(-10) [0120-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1820 -> Nagra2(-10) [0350-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1821 -> Nagra2(-10) [0351-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1822 -> Nagra2(-10) [0352-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1823 -> Nagra2(-10) [0353-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1824 -> Nagra2(-10) [0354-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1825 -> Nagra2(-10) [0355-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1826 -> Nagra2(-10) [0356-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1827 -> Nagra2(-10) [0357-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1828 -> Nagra2(-10) [0358-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 1829 -> Nagra2(-10) [0359-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 182a -> Nagra2(-10) [035a-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 182b -> Nagra2(-10) [035b-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 182c -> Nagra2(-10) [035c-82/ff/00] Jul 18 23:24:42 [core.au] 0: chain caid 182d -> Nagra2(-10) [035d-82/ff/00] Jul 18 23:24:42 [core.au] 0: starting chain 1810 Called cSascDvbDevice::SetCaDescr 23:24:42.686110 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:24:42.686128 CAM: CA_SET_DESCR failed (Invalid argument) Jul 18 23:24:42 [core.ecm] 0.0: correct key found Called cSascDvbDevice::SetCaDescr 23:24:45.165161 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:24:45.165181 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:24:49.043663 CAM: CA_SET_DESCR failed (Invalid argument) Jul 18 23:25:02 [nagra.map] 0101: calling function 3B Jul 18 23:25:02 [nagra.map] 0101: calling function 43 Jul 18 23:25:02 [nagra.map] 0101: calling function 44 Called cSascDvbDevice::SetCaDescr 23:25:03.252015 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:25:18.250060 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:25:33.273134 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:25:48.476152 CAM: CA_SET_DESCR failed (Invalid argument) Jul 18 23:26:03 [nagra.map] 0101: calling function 3B Jul 18 23:26:03 [nagra.map] 0101: calling function 43 Jul 18 23:26:03 [nagra.map] 0101: calling function 44 Called cSascDvbDevice::SetCaDescr 23:26:03.577199 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:26:18.357371 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:26:33.566353 CAM: CA_SET_DESCR failed (Invalid argument) Jul 18 23:26:33 [nagra.emu] mapmem: new map off=0000 size=10000 Jul 18 23:26:33 [nagra.emu] maprom: new map off=4000 size=18000 Jul 18 23:26:33 [nagra.emu] maprom: new map off=8000 size=14000 Jul 18 23:26:33 [nagra.emu] maprom: new map off=8000 size=c000 Jul 18 23:26:33 [nagra.emu] maprom: new map off=8000 size=4000 Jul 18 23:26:33 [nagra.emu] maprom: new map off=3000 size=4800 Jul 18 23:26:33 [nagra.emu] maprom: new map off=8000 size=4000 Jul 18 23:26:33 [nagra.emu] 6805: setting breakpoint at 0x0000 Jul 18 23:26:33 [nagra.emu] 6805: setting breakpoint at 0x9569 Jul 18 23:26:33 [nagra.emu] 6805: setting breakpoint at 0xa822 Jul 18 23:26:33 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:33 [nagra.disasm80] 00:0093 00 00 00 00 0fff V..... a601b748 00000000 LDA #01 Jul 18 23:26:33 [nagra.disasm80] 00:0095 01 00 00 00 0fff V..... b7484c8d 00000000 STA 48 Jul 18 23:26:33 [nagra.disasm80] 00:0097 01 00 00 00 0fff V..... 4c8d00a8 00000000 INC A Jul 18 23:26:33 [nagra.disasm80] 00:0098 02 00 00 00 0fff V..... 8d00a822 00000000 PJSR a822 Jul 18 23:26:33 [nagra.emu] 6805: breakpoint at a822 (count=4) Jul 18 23:26:33 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:33 [nagra.disasm80] 00:009c 02 00 00 00 0fff V..... 3f44a6b7 00000000 CLR 44 Jul 18 23:26:33 [nagra.disasm80] 00:009e 02 00 00 00 0fff V...Z. a6b7b745 00000000 LDA #b7 Jul 18 23:26:33 [nagra.disasm80] 00:00a0 b7 00 00 00 0fff V..N.. b745a60f 00000000 STA 45 Jul 18 23:26:33 [nagra.disasm80] 00:00a2 b7 00 00 00 0fff V..N.. a60f8d00 00000000 LDA #0f Jul 18 23:26:33 [nagra.disasm80] 00:00a4 0f 00 00 00 0fff V..... 8d00a822 00000000 PJSR a822 Jul 18 23:26:33 [nagra.emu] 6805: breakpoint at a822 (count=5) Jul 18 23:26:33 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:33 [nagra.disasm80] 00:00a8 0f 00 00 00 0fff V..... a6d0b745 00000000 LDA #d0 Jul 18 23:26:33 [nagra.disasm80] 00:00aa d0 00 00 00 0fff V..N.. b745a60f 00000000 STA 45 Jul 18 23:26:33 [nagra.disasm80] 00:00ac d0 00 00 00 0fff V..N.. a60f8d00 00000000 LDA #0f Jul 18 23:26:33 [nagra.disasm80] 00:00ae 0f 00 00 00 0fff V..... 8d00a822 00000000 PJSR a822 Jul 18 23:26:33 [nagra.emu] 6805: breakpoint at a822 (count=4) Jul 18 23:26:33 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:33 [nagra.disasm80] 00:00b2 0f 00 00 00 0fff V..... a62dcc95 00000000 LDA #2d Jul 18 23:26:33 [nagra.disasm80] 00:00b4 2d 00 00 00 0fff V..... cc956900 00000000 JMP 9569 Jul 18 23:26:33 [nagra.emu] 6805: breakpoint at 9569 (count=2) Jul 18 23:26:36 [nagra.emu] 6805: setting breakpoint at 0x0000 Jul 18 23:26:36 [nagra.emu] 6805: setting breakpoint at 0x9569 Jul 18 23:26:36 [nagra.emu] 6805: setting breakpoint at 0xa822 Jul 18 23:26:36 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:36 [nagra.disasm80] 00:0093 2d 00 00 00 0fff V..... a601b748 00000000 LDA #01 Jul 18 23:26:36 [nagra.disasm80] 00:0095 01 00 00 00 0fff V..... b7484c8d 00000000 STA 48 Jul 18 23:26:36 [nagra.disasm80] 00:0097 01 00 00 00 0fff V..... 4c8d00a8 00000000 INC A Jul 18 23:26:36 [nagra.disasm80] 00:0098 02 00 00 00 0fff V..... 8d00a822 00000000 PJSR a822 Jul 18 23:26:36 [nagra.emu] 6805: breakpoint at a822 (count=4) Jul 18 23:26:36 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:36 [nagra.disasm80] 00:009c 02 00 00 00 0fff V..... 3f44a6b7 00000000 CLR 44 Jul 18 23:26:36 [nagra.disasm80] 00:009e 02 00 00 00 0fff V...Z. a6b7b745 00000000 LDA #b7 Jul 18 23:26:36 [nagra.disasm80] 00:00a0 b7 00 00 00 0fff V..N.. b745a60f 00000000 STA 45 Jul 18 23:26:36 [nagra.disasm80] 00:00a2 b7 00 00 00 0fff V..N.. a60f8d00 00000000 LDA #0f Jul 18 23:26:36 [nagra.disasm80] 00:00a4 0f 00 00 00 0fff V..... 8d00a822 00000000 PJSR a822 Jul 18 23:26:36 [nagra.emu] 6805: breakpoint at a822 (count=5) Jul 18 23:26:36 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:36 [nagra.disasm80] 00:00a8 0f 00 00 00 0fff V..... a6d1b745 00000000 LDA #d1 Jul 18 23:26:36 [nagra.disasm80] 00:00aa d1 00 00 00 0fff V..N.. b745a60f 00000000 STA 45 Jul 18 23:26:36 [nagra.disasm80] 00:00ac d1 00 00 00 0fff V..N.. a60f8d00 00000000 LDA #0f Jul 18 23:26:36 [nagra.disasm80] 00:00ae 0f 00 00 00 0fff V..... 8d00a822 00000000 PJSR a822 Jul 18 23:26:36 [nagra.emu] 6805: breakpoint at a822 (count=4) Jul 18 23:26:36 [nagra.disasm80] cr:-pc- aa xx yy dr -sp- VHINZC -mem@pc- -mem@sp- Jul 18 23:26:36 [nagra.disasm80] 00:00b2 0f 00 00 00 0fff V..... a62dcc95 00000000 LDA #2d Jul 18 23:26:36 [nagra.disasm80] 00:00b4 2d 00 00 00 0fff V..... cc956948 00000000 JMP 9569 Jul 18 23:26:36 [nagra.emu] 6805: breakpoint at 9569 (count=2) Called cSascDvbDevice::SetCaDescr 23:26:48.497467 CAM: CA_SET_DESCR failed (Invalid argument) 23:26:54.361224 CSA: Removing csa for rb: 1 Jul 18 23:27:03 [nagra.map] 0101: calling function 3B Jul 18 23:27:03 [nagra.map] 0101: calling function 43 Jul 18 23:27:03 [nagra.map] 0101: calling function 44 Called cSascDvbDevice::SetCaDescr 23:27:03.872377 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:27:18.726556 CAM: CA_SET_DESCR failed (Invalid argument) Called cSascDvbDevice::SetCaDescr 23:27:33.410727 CAM: CA_SET_DESCR failed (Invalid argument) Jul 18 23:27:42 [core.auStats] EMM packet load average (1/4/10min) 0 0 0 pks/s