Apr 22 11:02:04.717 [general.debug] logfile '/var/log/vdr-sc' opened
Apr 22 11:02:04.716 [general.info] SC version 1.0.0pre-AR-51c5add369d7 initializing (VDR 1.7.22)
Apr 22 11:02:04.720 [general.debug] capturing device 0/0 (subsystem ID 13c21019)
Apr 22 11:02:04.720 [general.debug] creating standard device 0/0
Apr 22 11:02:04.722 [general.debug] capturing device 1/0 (subsystem ID d4709022)
Apr 22 11:02:04.722 [general.debug] creating standard device 1/0
Apr 22 11:02:04.867 [general.info] SC version 1.0.0pre-AR-51c5add369d7 starting (VDR 1.7.22)
Apr 22 11:02:04.867 [core.load] ** Plugin config:
Apr 22 11:02:04.867 [core.load] ** Key updates (AU) are enabled (all CAIDs) (no prestart)
Apr 22 11:02:04.867 [core.load] ** Local systems DON'T take priority over cached remote
Apr 22 11:02:04.867 [core.load] ** Concurrent FF recordings are NOT allowed
Apr 22 11:02:04.867 [core.load] ** Force transfermode with digital audio
Apr 22 11:02:04.867 [core.load] ** ECM cache is set to enabled
Apr 22 11:02:04.867 [core.load] ** TsBufferSize is 4 MB
Apr 22 11:02:04.867 [core.load] ** ScCaps are 1 2 0 0 0 0 0 0 0 0
Apr 22 11:02:04.868 [general.info] loading cardclient config from /var/lib/vdr/plugins/sc/cardclient.conf
Apr 22 11:02:04.868 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:02:04.868 [cardclient.cccam2] logout from server initiated
Apr 22 11:02:04.868 [cardclient.cccam2extra] reader thread stopped
Apr 22 11:02:04.868 [cardclient.cccam2extra] network shut down
Apr 22 11:02:04.868 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:02:04.868 [cardclient.cccam2extra] logout done
Apr 22 11:02:04.868 [cardclient.core] hostname=localhost port=1200 emm=1 emmCaids 0000/0000
Apr 22 11:02:04.868 [cardclient.core] cccam2: username=xxx password=xxx
Apr 22 11:02:04.868 [cardclient.core] our nodeid: 09 2f a1 cb 90 11 fe 46
Apr 22 11:02:04.868 [cardclient.core] pretended CCcam version '2.0.11' build '2892'
Apr 22 11:02:04.868 [cardclient.core] client 'cccam2' ready
Apr 22 11:02:04.868 [cardclient.cccam2] logout from server initiated
Apr 22 11:02:04.868 [cardclient.cccam2extra] reader thread stopped
Apr 22 11:02:04.868 [cardclient.cccam2extra] network shut down
Apr 22 11:02:04.868 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:02:04.868 [cardclient.cccam2extra] logout done
Apr 22 11:02:04.869 [core.net] connecting to localhost:1200/tcp (127.0.0.1)
Apr 22 11:02:04.869 [general.error] socket: connect failed (late): Verbindungsaufbau abgelehnt
Apr 22 11:02:04.870 [general.info] loading keys from /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:02:04.870 [general.error] file /var/lib/vdr/plugins/sc/SoftCam.Key has error in line #5
Apr 22 11:02:04.870 [general.error] file /var/lib/vdr/plugins/sc/SoftCam.Key has error in line #6
Apr 22 11:02:04.870 [general.error] file /var/lib/vdr/plugins/sc/SoftCam.Key has error in line #7
Apr 22 11:02:04.870 [core.load] loaded 2 keys from /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:02:04.870 [general.info] loading ecm cache from /var/lib/vdr/plugins/sc/ecm.cache
Apr 22 11:02:04.870 [general.error] failed open /var/lib/vdr/plugins/sc/smartcard.conf: Datei oder Verzeichnis nicht gefunden
Apr 22 11:02:04.870 [general.error] failed open /var/lib/vdr/plugins/sc/cardslot.conf: Datei oder Verzeichnis nicht gefunden
Apr 22 11:02:04.870 [general.info] loading overrides from /var/lib/vdr/plugins/sc/override.conf
Apr 22 11:02:04.871 [core.override] ecmprio: S19.2E: - chain 1702 1833
Apr 22 11:02:04.871 [core.override] tunnel: 1833:S19.2E: - to 1702, rewriter nagra-beta(1001)
Apr 22 11:02:04.871 [core.load] loaded 2 overrides from /var/lib/vdr/plugins/sc/override.conf
Apr 22 11:02:04.871 [core.load] ** registered systems:
Apr 22 11:02:04.871 [core.load] ** Nagra (pri -10)
Apr 22 11:02:04.871 [core.load] ** Nagra2 (pri -10)
Apr 22 11:02:04.871 [core.load] ** Cryptoworks (pri -10)
Apr 22 11:02:04.871 [core.load] ** SC-Nagra (pri -5)
Apr 22 11:02:04.871 [core.load] ** ConstCW (pri -20)
Apr 22 11:02:04.871 [core.load] ** Cardclient (pri -15)
Apr 22 11:02:04.871 [core.load] ** SC-Cryptoworks (pri -5)
Apr 22 11:02:04.871 [general.info] Using software decryption on card 1/0
Apr 22 11:02:04.894 [core.ci] card 1/0, slot 0 (v= 1) caids: 0100 0500 09c4 1817 1818 1833 0d00 1819 1702 1811 0622 0648 0d05 1863 0d95 0d02 1810 09af 1722 1834 0624 09c7 0b00 0d03 0d70 0d96 1815 1830 1843 1861 0d22 1837 1860 0666 0960 0961 0963 098c 09b2 0d0f 1801 1836
Apr 22 11:02:04.894 [core.ci] 1/0: reset of slot 0 requested
Apr 22 11:02:04.894 [general.info] Budget mode forced on card 0/0
Apr 22 11:02:04.894 [general.info] Using software decryption on card 0/0
Apr 22 11:02:04.916 [core.ci] card 0/0, slot 0 (v= 1) caids: 0100 0500 09c4 1817 1818 1833 0d00 1819 1702 1811 0622 0648 0d05 1863 0d95 0d02 1810 09af 1722 1834 0624 09c7 0b00 0d03 0d70 0d96 1815 1830 1843 1861 0d22 1837 1860 0666 0960 0961 0963 098c 09b2 0d0f 1801 1836
Apr 22 11:02:04.916 [core.ci] 0/0: reset of slot 0 requested
Apr 22 11:02:05.796 [core.ci] 1/0.0: doReply changed, reset triggered
Apr 22 11:02:05.796 [core.ci] 1/0.0: now using CAIDs version 1
Apr 22 11:02:05.796 [core.ci] 1/0.0: status 'present'
Apr 22 11:02:05.919 [core.ci] 0/0.0: doReply changed, reset triggered
Apr 22 11:02:05.919 [core.ci] 0/0.0: now using CAIDs version 1
Apr 22 11:02:05.919 [core.ci] 0/0.0: status 'present'
Apr 22 11:02:05.947 [core.ci] 1/0.0: status 'reset'
Apr 22 11:02:05.969 [core.ci] 0/0.0: status 'reset'
Apr 22 11:02:06.548 [core.ci] 1/0.0: status 'ready'
Apr 22 11:02:06.921 [core.ci] 0/0.0: status 'ready'
Apr 22 11:02:07.000 [core.ci] 1/0.0 -> 00 01 82 01 01
Apr 22 11:02:07.000 [core.ci] 1/0.0 <- 00 01 83 01 01 80 02 01 80
Apr 22 11:02:07.000 [core.ci] 1/0.0 -> 00 01 81 01 01
Apr 22 11:02:07.000 [core.ci] 1/0.0 <- 00 01 a0 07 01 91 04 00 03 00 41 80 02 01 00
Apr 22 11:02:07.000 [core.ci] 1/0.0 -> 00 01 a0 0a 01 92 07 00 00 03 00 41 00 01
Apr 22 11:02:07.000 [core.ci] 1/0.0 -> 00 01 a0 09 01 90 02 00 01 9f 80 30 00
Apr 22 11:02:07.000 [core.ci] 1/0.0 sending CA info
Apr 22 11:02:07.000 [core.ci] 1/0.0 -> 00 01 81 01 01
Apr 22 11:02:07.000 [core.ci] 1/0.0 <- 00 01 a0 5d 01 90 02 00 01 9f 80 31 54 01 00 05 00 09 c4 18 17 18 18 18 33 0d 00 18 19 17 02 18 11 06 22 06 48 0d 05 18 63 0d 95 0d 02 18 10 09 af 17 22 18 34 06 24 09 c7 0b 00 0d 03 0d 70 0d 96 18 15 18 30 18 43 18 61 0d 22 18 37 18 60 06 66 09 60 09 61 09 63 09 8c 09 b2 0d 0f 18 01 18 36 80 02 01 00
Apr 22 11:02:07.022 [core.ci] 0/0.0 -> 00 01 82 01 01
Apr 22 11:02:07.022 [core.ci] 0/0.0 <- 00 01 83 01 01 80 02 01 80
Apr 22 11:02:07.022 [core.ci] 0/0.0 -> 00 01 81 01 01
Apr 22 11:02:07.022 [core.ci] 0/0.0 <- 00 01 a0 07 01 91 04 00 03 00 41 80 02 01 00
Apr 22 11:02:07.022 [core.ci] 0/0.0 -> 00 01 a0 0a 01 92 07 00 00 03 00 41 00 01
Apr 22 11:02:07.022 [core.ci] 0/0.0 -> 00 01 a0 09 01 90 02 00 01 9f 80 30 00
Apr 22 11:02:07.022 [core.ci] 0/0.0 sending CA info
Apr 22 11:02:07.022 [core.ci] 0/0.0 -> 00 01 81 01 01
Apr 22 11:02:07.022 [core.ci] 0/0.0 <- 00 01 a0 5d 01 90 02 00 01 9f 80 31 54 01 00 05 00 09 c4 18 17 18 18 18 33 0d 00 18 19 17 02 18 11 06 22 06 48 0d 05 18 63 0d 95 0d 02 18 10 09 af 17 22 18 34 06 24 09 c7 0b 00 0d 03 0d 70 0d 96 18 15 18 30 18 43 18 61 0d 22 18 37 18 60 06 66 09 60 09 61 09 63 09 8c 09 b2 0d 0f 18 01 18 36 80 02 01 00
Apr 22 11:02:08.003 [core.ci] 1/0.0 -> 00 01 a0 10 01 90 02 00 01 9f 80 32 07 03 00 00 01 00 01 03
Apr 22 11:02:08.003 [core.ci] 1/0.0 CA_PMT decoding len=7 lm=3 prg=0 len=1/1 ci_cmd(G)=03
Apr 22 11:02:08.003 [core.ci] 1/0.0 got CA pmt ciCmd=3 caLm=3
Apr 22 11:02:08.003 [core.ci] 1/0.0 answer to query
Apr 22 11:02:08.003 [core.ci] 1/0.0 -> 00 01 81 01 01
Apr 22 11:02:08.003 [core.ci] 1/0.0 <- 00 01 a0 0d 01 90 02 00 01 9f 80 33 04 00 00 00 81 80 02 01 00
Apr 22 11:02:08.025 [core.ci] 0/0.0 -> 00 01 a0 10 01 90 02 00 01 9f 80 32 07 03 00 00 01 00 01 03
Apr 22 11:02:08.025 [core.ci] 0/0.0 CA_PMT decoding len=7 lm=3 prg=0 len=1/1 ci_cmd(G)=03
Apr 22 11:02:08.025 [core.ci] 0/0.0 got CA pmt ciCmd=3 caLm=3
Apr 22 11:02:08.025 [core.ci] 0/0.0 answer to query
Apr 22 11:02:08.025 [core.ci] 0/0.0 -> 00 01 81 01 01
Apr 22 11:02:08.025 [core.ci] 0/0.0 <- 00 01 a0 0d 01 90 02 00 01 9f 80 33 04 00 00 00 81 80 02 01 00
Apr 22 11:02:08.177 [core.pids] 1/0: now tuned to source 5300ff40(S19.2E) transponder 1b2c7
Apr 22 11:02:08.204 [core.ci] 1/0.0 -> 00 01 a0 28 01 90 02 00 01 9f 80 32 1f 04 13 30 01 00 00 02 0b 68 00 00 04 0b 69 00 00 04 0b 6a 00 00 06 0b 6b 00 00 06 0b 6d 00 00
Apr 22 11:02:08.204 [core.ci] 1/0.0 CA_PMT decoding len=1f lm=4 prg=4912 len=0/19 pid=2,b68 len=0/14 pid=4,b69 len=0/f pid=4,b6a len=0/a pid=6,b6b len=0/5 pid=6,b6d len=0/0
Apr 22 11:02:08.204 [core.ci] 1/0.0 got CA pmt ciCmd=-1 caLm=4
Apr 22 11:02:08.204 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:02:08.204 [core.pids] 1/0: add SID 4912 (
zero=0 noshift=1)
Apr 22 11:02:08.204 [core.pids] 1/0: pids VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:02:08.204 [core.pids] Ca descriptors after simplify (pidCa=0)
Apr 22 11:02:08.204 [core.pids] prgca: <empty>
Apr 22 11:02:08.204 [core.pids] pidca 0b68: <empty>
Apr 22 11:02:08.204 [core.pids] pidca 0b69: <empty>
Apr 22 11:02:08.204 [core.pids] pidca 0b6a: <empty>
Apr 22 11:02:08.204 [core.pids] pidca 0b6b: <empty>
Apr 22 11:02:08.204 [core.pids] pidca 0b6d: <empty>
Apr 22 11:02:08.205 [core.pids] 1/0: SID=4912
zero=0 | sid=-/-/-
zero=-/-/- idle=-/-/-
Apr 22 11:02:08.205 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=1 idx=1)
Apr 22 11:02:08.205 [core.ecm] 1/0.1: setting new SID 4912
Apr 22 11:02:08.205 [core.pids] 1/0.1: pids on entry
Apr 22 11:02:08.205 [core.pids] 1/0.1: pids after delete
Apr 22 11:02:08.205 [core.pids] 1/0: descrambling pid 0b68 on index 1
Apr 22 11:02:08.205 [core.pids] 1/0: descrambling pid 0b69 on index 1
Apr 22 11:02:08.205 [core.pids] 1/0: descrambling pid 0b6a on index 1
Apr 22 11:02:08.205 [core.pids] 1/0: descrambling pid 0b6b on index 1
Apr 22 11:02:08.205 [core.pids] 1/0: descrambling pid 0b6d on index 1
Apr 22 11:02:08.205 [core.pids] 1/0.1: pids after add VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:02:08.205 [core.ecm] 1/0.1: is no longer idle
Apr 22 11:02:08.266 [core.ecm] 1/0.1: triggered SID -1/4912 idx -1/1 mode -1/0 -
Apr 22 11:02:08.266 [core.ecm] from cache: system Cryptoworks (0d05) id 0000 with ecm dd/80
Apr 22 11:02:08.266 [core.override] ecmprio: 0d05/0 pri -2
Apr 22 11:02:08.693 [core.ecm] 1/0.1: try system Cryptoworks (0d05) id 0000 with ecm dd (cached) (pri=-10)
Apr 22 11:02:08.693 [core.ecm] system: using key W 0D05 04 20 00 A9D7...
Apr 22 11:02:08.843 [core.ecm] 1/0.1: correct key found
Apr 22 11:02:09.809 [core.ci] 1/0.0 -> 00 01 a0 34 01 90 02 00 01 9f 80 32 2b 05 13 30 01 00 25 01 09 04 06 48 e0 79 09 04 0d 05 e0 dd 09 04 0d 95 e1 0f 09 04 17 02 e1 41 09 04 18 33 e1 a5 09 04 09 c4 e1 e1
Apr 22 11:02:09.809 [core.ci] 1/0.0 CA_PMT decoding len=2b lm=5 prg=4912 len=25/25 ci_cmd(G)=01
Apr 22 11:02:09.809 [core.ci] 1/0.0 got CA pmt ciCmd=1 caLm=5
Apr 22 11:02:09.810 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:02:09.810 [core.pids] 1/0: update SID 4912 (
zero=0 noshift=1)
Apr 22 11:02:09.810 [core.pids] 1/0: SID=4912
zero=0 | sid=1/4912/0
zero=-/-/- idle=-/-/-
Apr 22 11:02:09.810 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=0 idx=1)
Apr 22 11:02:09.810 [core.pids] 1/0.1: pids on entry VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:02:09.810 [core.pids] 1/0.1: pids after delete
Apr 22 11:02:09.810 [core.pids] 1/0.1: pids after add
Apr 22 11:02:09.810 [core.ecm] 1/0.1: is idle now
Apr 22 11:02:09.830 [core.pids] 1/0: tune to same source/transponder
Apr 22 11:02:09.911 [core.ci] 1/0.0 -> 00 01 a0 4d 01 90 02 00 01 9f 80 32 44 04 13 30 01 00 25 01 09 04 06 48 e0 79 09 04 0d 05 e0 dd 09 04 0d 95 e1 0f 09 04 17 02 e1 41 09 04 18 33 e1 a5 09 04 09 c4 e1 e1 02 0b 68 00 00 04 0b 69 00 00 04 0b 6a 00 00 06 0b 6b 00 00 06 0b 6d 00 00
Apr 22 11:02:09.911 [core.ci] 1/0.0 CA_PMT decoding len=44 lm=4 prg=4912 len=25/3e ci_cmd(G)=01 pid=2,b68 len=0/14 pid=4,b69 len=0/f pid=4,b6a len=0/a pid=6,b6b len=0/5 pid=6,b6d len=0/0
Apr 22 11:02:09.911 [core.ci] 1/0.0 got CA pmt ciCmd=1 caLm=4
Apr 22 11:02:09.911 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:02:09.911 [core.pids] 1/0: add SID 4912 (
zero=0 noshift=1)
Apr 22 11:02:09.911 [core.pids] 1/0: pids VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:02:09.911 [core.pids] Ca descriptors after simplify (pidCa=0)
Apr 22 11:02:09.911 [core.pids] prgca: 09 04 06 48 E0 79 09 04 0D 05 E0 DD 09 04 0D 95 E1 0F 09 04 17 02 E1 41 09 04 18 33 E1 A5 09 04 09 C4 E1 E1
Apr 22 11:02:09.912 [core.pids] pidca 0b68: <empty>
Apr 22 11:02:09.912 [core.pids] pidca 0b69: <empty>
Apr 22 11:02:09.912 [core.pids] pidca 0b6a: <empty>
Apr 22 11:02:09.912 [core.pids] pidca 0b6b: <empty>
Apr 22 11:02:09.912 [core.pids] pidca 0b6d: <empty>
Apr 22 11:02:09.912 [core.pids] 1/0: SID=4912
zero=0 | sid=1/4912/1
zero=-/-/- idle=1/4912/1
Apr 22 11:02:09.912 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=1 idx=1)
Apr 22 11:02:09.912 [core.pids] 1/0.1: pids on entry
Apr 22 11:02:09.912 [core.pids] 1/0.1: pids after delete
Apr 22 11:02:09.912 [core.pids] 1/0: descrambling pid 0b68 on index 1
Apr 22 11:02:09.912 [core.pids] 1/0: descrambling pid 0b69 on index 1
Apr 22 11:02:09.912 [core.pids] 1/0: descrambling pid 0b6a on index 1
Apr 22 11:02:09.912 [core.pids] 1/0: descrambling pid 0b6b on index 1
Apr 22 11:02:09.912 [core.pids] 1/0: descrambling pid 0b6d on index 1
Apr 22 11:02:09.912 [core.pids] 1/0.1: pids after add VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:02:09.913 [core.ecm] 1/0.1: is no longer idle
Apr 22 11:02:09.916 [core.ecm] 1/0.1: triggered SID 4912/4912 idx 1/1 mode 3/0 sync
Apr 22 11:02:09.917 [core.ecm] 1/0.1: new caDescr: 09 04 06 48 E0 79 09 04 0D 05 E0 DD 09 04 0D 95 E1 0F 09 04 17 02 E1 41 09 04 18 33 E1 A5 09 04 09 C4 E1 E1
Apr 22 11:02:10.215 [core.au] 1/0: chain caid 0648 -> Cardclient(-15) [0258-82/ff]
Apr 22 11:02:10.215 [core.au] 1/0: chain caid 1702 -> Cardclient(-15) [0263-82/ff]
Apr 22 11:02:10.215 [core.au] 1/0: chain caid 0d05 -> Cardclient(-15) [02bc-82/f9] [02bc-88/fe]
Apr 22 11:02:10.216 [core.au] 1/0: chain caid 0d95 -> Cardclient(-15) [02bd-82/f9] [02bd-88/fe]
Apr 22 11:02:10.216 [core.au] 1/0: chain caid 1833 -> Nagra2(-10) Cardclient(-15) [032b-82/fe]
Apr 22 11:02:10.216 [core.au] 1/0: chain caid 09c4 -> Cardclient(-15) [033e-82/ff]
Apr 22 11:02:10.216 [core.au] 1/0: starting chain 0648
Apr 22 11:02:10.216 [core.au] 1/0: starting chain 1702
Apr 22 11:02:10.216 [core.au] 1/0: starting chain 0d05
Apr 22 11:02:10.216 [core.au] 1/0: starting chain 0d95
Apr 22 11:02:10.217 [core.au] 1/0: starting chain 1833
Apr 22 11:02:10.217 [core.au] 1/0: starting chain 09c4
Apr 22 11:02:11.961 [core.override] ecmprio: 0d05/0 pri -2
Apr 22 11:03:04.277 [core.pids] 0/0: now tuned to source 5300ff40(S19.2E) transponder 1b097
Apr 22 11:03:08.321 [core.auStats] EMM packet load average (1/4/10min) 311 77 31 pks/s
Apr 22 11:03:25.285 [core.pids] 0/0: now tuned to source 5300ff40(S19.2E) transponder 1b0b5
Apr 22 11:03:27.835 [core.load] detected change of /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:03:27.835 [general.info] loading keys from /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:03:27.836 [core.load] loaded 2 keys from /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:03:28.419 [core.ci] 1/0.0 -> 00 01 a0 34 01 90 02 00 01 9f 80 32 2b 05 13 30 01 00 25 01 09 04 06 48 e0 79 09 04 0d 05 e0 dd 09 04 0d 95 e1 0f 09 04 17 02 e1 41 09 04 18 33 e1 a5 09 04 09 c4 e1 e1
Apr 22 11:03:28.419 [core.ci] 1/0.0 CA_PMT decoding len=2b lm=5 prg=4912 len=25/25 ci_cmd(G)=01
Apr 22 11:03:28.419 [core.ci] 1/0.0 got CA pmt ciCmd=1 caLm=5
Apr 22 11:03:28.419 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:03:28.419 [core.pids] 1/0: update SID 4912 (
zero=0 noshift=1)
Apr 22 11:03:28.419 [core.pids] 1/0: SID=4912
zero=0 | sid=1/4912/0
zero=-/-/- idle=-/-/-
Apr 22 11:03:28.419 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=0 idx=1)
Apr 22 11:03:28.420 [core.pids] 1/0.1: pids on entry VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:03:28.420 [core.pids] 1/0.1: pids after delete
Apr 22 11:03:28.420 [core.pids] 1/0.1: pids after add
Apr 22 11:03:28.420 [core.ecm] 1/0.1: is idle now
Apr 22 11:03:28.481 [core.au] 1/0: stopping chain 0648
Apr 22 11:03:28.481 [core.au] 1/0: stopping chain 1702
Apr 22 11:03:28.481 [core.au] 1/0: stopping chain 0d05
Apr 22 11:03:28.481 [core.au] 1/0: stopping chain 0d95
Apr 22 11:03:28.481 [core.au] 1/0: stopping chain 1833
Apr 22 11:03:28.481 [core.au] 1/0: stopping chain 09c4
Apr 22 11:03:31.827 [cardclient.cccam2] logout from server initiated
Apr 22 11:03:31.827 [cardclient.cccam2extra] reader thread stopped
Apr 22 11:03:31.827 [cardclient.cccam2extra] network shut down
Apr 22 11:03:31.827 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:03:31.827 [cardclient.cccam2extra] logout done
Apr 22 11:03:31.827 [general.debug] SC cleanup done
Apr 22 11:03:48.701 [general.debug] logfile '/var/log/vdr-sc' opened
Apr 22 11:03:48.701 [general.info] SC version 1.0.0pre-AR-51c5add369d7 initializing (VDR 1.7.22)
Apr 22 11:03:48.705 [general.debug] capturing device 0/0 (subsystem ID 13c21019)
Apr 22 11:03:48.705 [general.debug] creating standard device 0/0
Apr 22 11:03:48.707 [general.debug] capturing device 1/0 (subsystem ID d4709022)
Apr 22 11:03:48.707 [general.debug] creating standard device 1/0
Apr 22 11:03:48.847 [general.info] SC version 1.0.0pre-AR-51c5add369d7 starting (VDR 1.7.22)
Apr 22 11:03:48.847 [core.load] ** Plugin config:
Apr 22 11:03:48.847 [core.load] ** Key updates (AU) are enabled (all CAIDs) (no prestart)
Apr 22 11:03:48.847 [core.load] ** Local systems DON'T take priority over cached remote
Apr 22 11:03:48.847 [core.load] ** Concurrent FF recordings are NOT allowed
Apr 22 11:03:48.847 [core.load] ** Force transfermode with digital audio
Apr 22 11:03:48.847 [core.load] ** ECM cache is set to enabled
Apr 22 11:03:48.847 [core.load] ** TsBufferSize is 4 MB
Apr 22 11:03:48.847 [core.load] ** ScCaps are 1 2 0 0 0 0 0 0 0 0
Apr 22 11:03:48.847 [general.info] loading cardclient config from /var/lib/vdr/plugins/sc/cardclient.conf
Apr 22 11:03:48.847 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:03:48.847 [cardclient.cccam2] logout from server initiated
Apr 22 11:03:48.847 [cardclient.cccam2extra] reader thread stopped
Apr 22 11:03:48.847 [cardclient.cccam2extra] network shut down
Apr 22 11:03:48.847 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:03:48.847 [cardclient.cccam2extra] logout done
Apr 22 11:03:48.847 [cardclient.core] hostname=localhost port=1200 emm=1 emmCaids 0000/0000
Apr 22 11:03:48.847 [cardclient.core] cccam2: username=rainer password=womo
Apr 22 11:03:48.847 [cardclient.core] our nodeid: fb 61 30 34 e3 83 0d 5e
Apr 22 11:03:48.848 [cardclient.core] pretended CCcam version '2.0.11' build '2892'
Apr 22 11:03:48.848 [cardclient.core] client 'cccam2' ready
Apr 22 11:03:48.848 [cardclient.cccam2] logout from server initiated
Apr 22 11:03:48.848 [cardclient.cccam2extra] reader thread stopped
Apr 22 11:03:48.848 [cardclient.cccam2extra] network shut down
Apr 22 11:03:48.848 [cardclient.cccam2extra] cmd 0c crypt mode now 0
Apr 22 11:03:48.848 [cardclient.cccam2extra] logout done
Apr 22 11:03:48.848 [core.net] connecting to localhost:1200/tcp (127.0.0.1)
Apr 22 11:03:48.848 [general.error] socket: connect failed (late): Verbindungsaufbau abgelehnt
Apr 22 11:03:48.848 [general.info] loading keys from /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:03:48.848 [core.load] loaded 2 keys from /var/lib/vdr/plugins/sc/SoftCam.Key
Apr 22 11:03:48.849 [general.info] loading ecm cache from /var/lib/vdr/plugins/sc/ecm.cache
Apr 22 11:03:48.849 [general.error] failed open /var/lib/vdr/plugins/sc/smartcard.conf: Datei oder Verzeichnis nicht gefunden
Apr 22 11:03:48.849 [general.error] failed open /var/lib/vdr/plugins/sc/cardslot.conf: Datei oder Verzeichnis nicht gefunden
Apr 22 11:03:48.849 [general.info] loading overrides from /var/lib/vdr/plugins/sc/override.conf
Apr 22 11:03:48.849 [core.override] ecmprio: S19.2E: - chain 1702 1833
Apr 22 11:03:48.849 [core.override] tunnel: 1833:S19.2E: - to 1702, rewriter nagra-beta(1001)
Apr 22 11:03:48.849 [core.load] loaded 2 overrides from /var/lib/vdr/plugins/sc/override.conf
Apr 22 11:03:48.849 [core.load] ** registered systems:
Apr 22 11:03:48.849 [core.load] ** Nagra (pri -10)
Apr 22 11:03:48.849 [core.load] ** Nagra2 (pri -10)
Apr 22 11:03:48.849 [core.load] ** Cryptoworks (pri -10)
Apr 22 11:03:48.849 [core.load] ** SC-Nagra (pri -5)
Apr 22 11:03:48.849 [core.load] ** ConstCW (pri -20)
Apr 22 11:03:48.849 [core.load] ** Cardclient (pri -15)
Apr 22 11:03:48.849 [core.load] ** SC-Cryptoworks (pri -5)
Apr 22 11:03:48.849 [general.info] Using software decryption on card 1/0
Apr 22 11:03:48.861 [core.ci] card 1/0, slot 0 (v= 1) caids: 0100 0500 09c4 1817 1818 1833 0d00 1819 1702 1811 0622 0648 0d05 1863 0d95 0d02 1810 09af 1722 1834 0624 09c7 0b00 0d03 0d70 0d96 1815 1830 1843 1861 0d22 1837 1860 0666 0960 0961 0963 098c 09b2 0d0f 1801 1836
Apr 22 11:03:48.861 [core.ci] 1/0: reset of slot 0 requested
Apr 22 11:03:48.861 [general.info] Budget mode forced on card 0/0
Apr 22 11:03:48.861 [general.info] Using software decryption on card 0/0
Apr 22 11:03:48.883 [core.ci] card 0/0, slot 0 (v= 1) caids: 0100 0500 09c4 1817 1818 1833 0d00 1819 1702 1811 0622 0648 0d05 1863 0d95 0d02 1810 09af 1722 1834 0624 09c7 0b00 0d03 0d70 0d96 1815 1830 1843 1861 0d22 1837 1860 0666 0960 0961 0963 098c 09b2 0d0f 1801 1836
Apr 22 11:03:48.883 [core.ci] 0/0: reset of slot 0 requested
Apr 22 11:03:49.814 [core.ci] 1/0.0: doReply changed, reset triggered
Apr 22 11:03:49.814 [core.ci] 1/0.0: now using CAIDs version 1
Apr 22 11:03:49.814 [core.ci] 1/0.0: status 'present'
Apr 22 11:03:49.914 [core.ci] 1/0.0: status 'reset'
Apr 22 11:03:49.936 [core.ci] 0/0.0: doReply changed, reset triggered
Apr 22 11:03:49.936 [core.ci] 0/0.0: now using CAIDs version 1
Apr 22 11:03:49.936 [core.ci] 0/0.0: status 'present'
Apr 22 11:03:49.936 [core.ci] 0/0.0: status 'reset'
Apr 22 11:03:50.566 [core.ci] 1/0.0: status 'ready'
Apr 22 11:03:50.939 [core.ci] 0/0.0: status 'ready'
Apr 22 11:03:50.967 [core.ci] 1/0.0 -> 00 01 82 01 01
Apr 22 11:03:50.967 [core.ci] 1/0.0 <- 00 01 83 01 01 80 02 01 80
Apr 22 11:03:50.967 [core.ci] 1/0.0 -> 00 01 81 01 01
Apr 22 11:03:50.967 [core.ci] 1/0.0 <- 00 01 a0 07 01 91 04 00 03 00 41 80 02 01 00
Apr 22 11:03:50.967 [core.ci] 1/0.0 -> 00 01 a0 0a 01 92 07 00 00 03 00 41 00 01
Apr 22 11:03:50.967 [core.ci] 1/0.0 -> 00 01 a0 09 01 90 02 00 01 9f 80 30 00
Apr 22 11:03:50.968 [core.ci] 1/0.0 sending CA info
Apr 22 11:03:50.968 [core.ci] 1/0.0 -> 00 01 81 01 01
Apr 22 11:03:50.968 [core.ci] 1/0.0 <- 00 01 a0 5d 01 90 02 00 01 9f 80 31 54 01 00 05 00 09 c4 18 17 18 18 18 33 0d 00 18 19 17 02 18 11 06 22 06 48 0d 05 18 63 0d 95 0d 02 18 10 09 af 17 22 18 34 06 24 09 c7 0b 00 0d 03 0d 70 0d 96 18 15 18 30 18 43 18 61 0d 22 18 37 18 60 06 66 09 60 09 61 09 63 09 8c 09 b2 0d 0f 18 01 18 36 80 02 01 00
Apr 22 11:03:50.989 [core.ci] 0/0.0 -> 00 01 82 01 01
Apr 22 11:03:50.989 [core.ci] 0/0.0 <- 00 01 83 01 01 80 02 01 80
Apr 22 11:03:50.989 [core.ci] 0/0.0 -> 00 01 81 01 01
Apr 22 11:03:50.990 [core.ci] 0/0.0 <- 00 01 a0 07 01 91 04 00 03 00 41 80 02 01 00
Apr 22 11:03:50.990 [core.ci] 0/0.0 -> 00 01 a0 0a 01 92 07 00 00 03 00 41 00 01
Apr 22 11:03:50.990 [core.ci] 0/0.0 -> 00 01 a0 09 01 90 02 00 01 9f 80 30 00
Apr 22 11:03:50.990 [core.ci] 0/0.0 sending CA info
Apr 22 11:03:50.990 [core.ci] 0/0.0 -> 00 01 81 01 01
Apr 22 11:03:50.990 [core.ci] 0/0.0 <- 00 01 a0 5d 01 90 02 00 01 9f 80 31 54 01 00 05 00 09 c4 18 17 18 18 18 33 0d 00 18 19 17 02 18 11 06 22 06 48 0d 05 18 63 0d 95 0d 02 18 10 09 af 17 22 18 34 06 24 09 c7 0b 00 0d 03 0d 70 0d 96 18 15 18 30 18 43 18 61 0d 22 18 37 18 60 06 66 09 60 09 61 09 63 09 8c 09 b2 0d 0f 18 01 18 36 80 02 01 00
Apr 22 11:03:51.970 [core.ci] 1/0.0 -> 00 01 a0 10 01 90 02 00 01 9f 80 32 07 03 00 00 01 00 01 03
Apr 22 11:03:51.970 [core.ci] 1/0.0 CA_PMT decoding len=7 lm=3 prg=0 len=1/1 ci_cmd(G)=03
Apr 22 11:03:51.971 [core.ci] 1/0.0 got CA pmt ciCmd=3 caLm=3
Apr 22 11:03:51.971 [core.ci] 1/0.0 answer to query
Apr 22 11:03:51.971 [core.ci] 1/0.0 -> 00 01 81 01 01
Apr 22 11:03:51.971 [core.ci] 1/0.0 <- 00 01 a0 0d 01 90 02 00 01 9f 80 33 04 00 00 00 81 80 02 01 00
Apr 22 11:03:51.993 [core.ci] 0/0.0 -> 00 01 a0 10 01 90 02 00 01 9f 80 32 07 03 00 00 01 00 01 03
Apr 22 11:03:51.993 [core.ci] 0/0.0 CA_PMT decoding len=7 lm=3 prg=0 len=1/1 ci_cmd(G)=03
Apr 22 11:03:51.993 [core.ci] 0/0.0 got CA pmt ciCmd=3 caLm=3
Apr 22 11:03:51.993 [core.ci] 0/0.0 answer to query
Apr 22 11:03:51.993 [core.ci] 0/0.0 -> 00 01 81 01 01
Apr 22 11:03:51.993 [core.ci] 0/0.0 <- 00 01 a0 0d 01 90 02 00 01 9f 80 33 04 00 00 00 81 80 02 01 00
Apr 22 11:03:52.194 [core.pids] 1/0: now tuned to source 5300ff40(S19.2E) transponder 1b2c7
Apr 22 11:03:52.222 [core.ci] 1/0.0 -> 00 01 a0 28 01 90 02 00 01 9f 80 32 1f 04 13 30 01 00 00 02 0b 68 00 00 04 0b 69 00 00 04 0b 6a 00 00 06 0b 6b 00 00 06 0b 6d 00 00
Apr 22 11:03:52.222 [core.ci] 1/0.0 CA_PMT decoding len=1f lm=4 prg=4912 len=0/19 pid=2,b68 len=0/14 pid=4,b69 len=0/f pid=4,b6a len=0/a pid=6,b6b len=0/5 pid=6,b6d len=0/0
Apr 22 11:03:52.222 [core.ci] 1/0.0 got CA pmt ciCmd=-1 caLm=4
Apr 22 11:03:52.222 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:03:52.222 [core.pids] 1/0: add SID 4912 (
zero=0 noshift=1)
Apr 22 11:03:52.222 [core.pids] 1/0: pids VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:03:52.222 [core.pids] Ca descriptors after simplify (pidCa=0)
Apr 22 11:03:52.222 [core.pids] prgca: <empty>
Apr 22 11:03:52.222 [core.pids] pidca 0b68: <empty>
Apr 22 11:03:52.222 [core.pids] pidca 0b69: <empty>
Apr 22 11:03:52.222 [core.pids] pidca 0b6a: <empty>
Apr 22 11:03:52.222 [core.pids] pidca 0b6b: <empty>
Apr 22 11:03:52.222 [core.pids] pidca 0b6d: <empty>
Apr 22 11:03:52.222 [core.pids] 1/0: SID=4912
zero=0 | sid=-/-/-
zero=-/-/- idle=-/-/-
Apr 22 11:03:52.222 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=1 idx=1)
Apr 22 11:03:52.222 [core.ecm] 1/0.1: setting new SID 4912
Apr 22 11:03:52.223 [core.pids] 1/0.1: pids on entry
Apr 22 11:03:52.223 [core.pids] 1/0.1: pids after delete
Apr 22 11:03:52.223 [core.pids] 1/0: descrambling pid 0b68 on index 1
Apr 22 11:03:52.223 [core.pids] 1/0: descrambling pid 0b69 on index 1
Apr 22 11:03:52.223 [core.pids] 1/0: descrambling pid 0b6a on index 1
Apr 22 11:03:52.223 [core.pids] 1/0: descrambling pid 0b6b on index 1
Apr 22 11:03:52.223 [core.pids] 1/0: descrambling pid 0b6d on index 1
Apr 22 11:03:52.223 [core.pids] 1/0.1: pids after add VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:03:52.223 [core.ecm] 1/0.1: is no longer idle
Apr 22 11:03:52.283 [core.ecm] 1/0.1: triggered SID -1/4912 idx -1/1 mode -1/0 -
Apr 22 11:03:52.283 [core.ecm] from cache: system Cryptoworks (0d05) id 0000 with ecm dd/80
Apr 22 11:03:52.284 [core.override] ecmprio: 0d05/0 pri -2
Apr 22 11:03:52.326 [core.ecm] 1/0.1: try system Cryptoworks (0d05) id 0000 with ecm dd (cached) (pri=-10)
Apr 22 11:03:52.816 [core.ecm] system: using key W 0D05 04 20 00 A9D7...
Apr 22 11:03:52.966 [core.ecm] 1/0.1: correct key found
Apr 22 11:03:53.835 [core.ci] 1/0.0 -> 00 01 a0 34 01 90 02 00 01 9f 80 32 2b 05 13 30 01 00 25 01 09 04 06 48 e0 79 09 04 0d 05 e0 dd 09 04 0d 95 e1 0f 09 04 17 02 e1 41 09 04 18 33 e1 a5 09 04 09 c4 e1 e1
Apr 22 11:03:53.835 [core.ci] 1/0.0 CA_PMT decoding len=2b lm=5 prg=4912 len=25/25 ci_cmd(G)=01
Apr 22 11:03:53.835 [core.ci] 1/0.0 got CA pmt ciCmd=1 caLm=5
Apr 22 11:03:53.835 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:03:53.835 [core.pids] 1/0: update SID 4912 (
zero=0 noshift=1)
Apr 22 11:03:53.835 [core.pids] 1/0: SID=4912
zero=0 | sid=1/4912/0
zero=-/-/- idle=-/-/-
Apr 22 11:03:53.835 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=0 idx=1)
Apr 22 11:03:53.835 [core.pids] 1/0.1: pids on entry VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:03:53.835 [core.pids] 1/0.1: pids after delete
Apr 22 11:03:53.835 [core.pids] 1/0.1: pids after add
Apr 22 11:03:53.836 [core.ecm] 1/0.1: is idle now
Apr 22 11:03:53.849 [core.pids] 1/0: tune to same source/transponder
Apr 22 11:03:53.886 [core.ci] 1/0.0 -> 00 01 a0 4d 01 90 02 00 01 9f 80 32 44 04 13 30 01 00 25 01 09 04 06 48 e0 79 09 04 0d 05 e0 dd 09 04 0d 95 e1 0f 09 04 17 02 e1 41 09 04 18 33 e1 a5 09 04 09 c4 e1 e1 02 0b 68 00 00 04 0b 69 00 00 04 0b 6a 00 00 06 0b 6b 00 00 06 0b 6d 00 00
Apr 22 11:03:53.886 [core.ci] 1/0.0 CA_PMT decoding len=44 lm=4 prg=4912 len=25/3e ci_cmd(G)=01 pid=2,b68 len=0/14 pid=4,b69 len=0/f pid=4,b6a len=0/a pid=6,b6b len=0/5 pid=6,b6d len=0/0
Apr 22 11:03:53.886 [core.ci] 1/0.0 got CA pmt ciCmd=1 caLm=4
Apr 22 11:03:53.886 [core.ci] 1/0.0 set CAM decrypt (prg 4912)
Apr 22 11:03:53.886 [core.pids] 1/0: add SID 4912 (
zero=0 noshift=1)
Apr 22 11:03:53.886 [core.pids] 1/0: pids VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:03:53.886 [core.pids] Ca descriptors after simplify (pidCa=0)
Apr 22 11:03:53.886 [core.pids] prgca: 09 04 06 48 E0 79 09 04 0D 05 E0 DD 09 04 0D 95 E1 0F 09 04 17 02 E1 41 09 04 18 33 E1 A5 09 04 09 C4 E1 E1
Apr 22 11:03:53.886 [core.pids] pidca 0b68: <empty>
Apr 22 11:03:53.886 [core.pids] pidca 0b69: <empty>
Apr 22 11:03:53.886 [core.pids] pidca 0b6a: <empty>
Apr 22 11:03:53.886 [core.pids] pidca 0b6b: <empty>
Apr 22 11:03:53.887 [core.pids] pidca 0b6d: <empty>
Apr 22 11:03:53.887 [core.pids] 1/0: SID=4912
zero=0 | sid=1/4912/1
zero=-/-/- idle=1/4912/1
Apr 22 11:03:53.887 [core.pids] 1/0: found handler for SID 4912 (1/0.1 idle=1 idx=1)
Apr 22 11:03:53.887 [core.pids] 1/0.1: pids on entry
Apr 22 11:03:53.887 [core.pids] 1/0.1: pids after delete
Apr 22 11:03:53.887 [core.pids] 1/0: descrambling pid 0b68 on index 1
Apr 22 11:03:53.887 [core.pids] 1/0: descrambling pid 0b69 on index 1
Apr 22 11:03:53.887 [core.pids] 1/0: descrambling pid 0b6a on index 1
Apr 22 11:03:53.887 [core.pids] 1/0: descrambling pid 0b6b on index 1
Apr 22 11:03:53.887 [core.pids] 1/0: descrambling pid 0b6d on index 1
Apr 22 11:03:53.887 [core.pids] 1/0.1: pids after add VIDEO=0b68 AUDIO=0b69 AUDIO=0b6a DOLBY=0b6b DOLBY=0b6d
Apr 22 11:03:53.887 [core.ecm] 1/0.1: is no longer idle
Apr 22 11:03:53.914 [core.ecm] 1/0.1: triggered SID 4912/4912 idx 1/1 mode 3/0 sync
Apr 22 11:03:53.914 [core.ecm] 1/0.1: new caDescr: 09 04 06 48 E0 79 09 04 0D 05 E0 DD 09 04 0D 95 E1 0F 09 04 17 02 E1 41 09 04 18 33 E1 A5 09 04 09 C4 E1 E1
Apr 22 11:03:59.936 [core.au] 1/0: chain caid 0648 -> Cardclient(-15) [0258-82/ff]
Apr 22 11:03:59.936 [core.au] 1/0: chain caid 1702 -> Cardclient(-15) [0263-82/ff]
Apr 22 11:03:59.936 [core.au] 1/0: chain caid 0d05 -> Cardclient(-15) [02bc-82/f9] [02bc-88/fe]
Apr 22 11:03:59.936 [core.au] 1/0: chain caid 0d95 -> Cardclient(-15) [02bd-82/f9] [02bd-88/fe]
Apr 22 11:03:59.937 [core.au] 1/0: chain caid 1833 -> Nagra2(-10) Cardclient(-15) [032b-82/fe]
Apr 22 11:03:59.937 [core.au] 1/0: chain caid 09c4 -> Cardclient(-15) [033e-82/ff]
Apr 22 11:03:59.937 [core.au] 1/0: starting chain 0648
Apr 22 11:03:59.937 [core.au] 1/0: starting chain 1702
Apr 22 11:03:59.937 [core.au] 1/0: starting chain 0d05
Apr 22 11:03:59.937 [core.au] 1/0: starting chain 0d95
Apr 22 11:03:59.938 [core.au] 1/0: starting chain 1833
Apr 22 11:03:59.938 [core.au] 1/0: starting chain 09c4
Apr 22 11:04:01.963 [core.override] ecmprio: 0d05/0 pri -2
Apr 22 11:04:49.305 [core.pids] 0/0: now tuned to source 5300ff40(S19.2E) transponder 1b097
Apr 22 11:04:52.342 [core.auStats] EMM packet load average (1/4/10min) 234 58 23 pks/s