[ 13:09:42 ] [ Box detect ] Box type 1
[ 13:09:42 ] [ Config ] Enabling SSL engine
[ 13:09:42 ] [ Config ] SSL engine disabled due to Certificate errors
[ 13:09:42 ] [ Config ] Option <newcamd_port> for device 0 (pcscd on USB) not present, defaulting to 15050
[ 13:09:42 ] [ Config ] Option <crypto-special> for device 0 (pcscd on USB) not present, defaulting to NO
[ 13:09:42 ] [ Config ] Pincode for device 0 (pcscd on USB): 0000
[ 13:09:42 ] [ Config ] 0 ECM priority: round
[ 13:09:42 ] [ Newcamd ] Server name : newcs-pcsc
[ 13:09:42 ] [ Newcamd ] Des key     : 0102030405060708091011121314
[ 13:09:42 ] [ Config ] Option <readers> not present for User: dummy, NO reader control enabled
[ 13:09:42 ] [ Newcamd ] User 2: dummy, Pass: dummy, Host localhost, Port: 12000, Au: On, Spider allowed: No, Sidoverride: No, level: 0
[ 13:09:42 ] [ httpd ] httpd-user: newcs, password: newcs, accesslevel: admin
[ 13:09:42 ] [ EMM Cache ] Initialising Cache with 20 entries
[ 13:09:42 ] [ ECM Cache ] Initialising dynamic Cache
[ 13:09:42 ] Calibrating delay loops
[ 13:09:42 ] usleep(5) takes: 0 s 5 us
[ 13:09:42 ] usleep(10) takes: 0 s 10 us
[ 13:09:42 ] usleep(100) takes: 0 s 100 us
[ 13:09:42 ] usleep(500) takes: 0 s 500 us
[ 13:09:42 ] Allocation memory for 200 regular users
[ 13:09:42 ] [ Loader ] Starting Telnet on port 1001
[ 13:09:42 ] [ SockSrv ] Server thread started
[ 13:09:42 ] [ Loader ] Started HTTP-server on port: 8080
[ 13:09:42 ] [ Loader ] Reader type 9 on node 0
[ 13:09:42 ] [ PC/SC ] Device 0: OmniKey CardMan 3121 00 00
[ 13:09:42 ] [ PC/SC ] Opening device OmniKey CardMan 3121 00 00 
[ 13:09:43 ] [ Loader ] Clearing all autosids on reader ...
[ 13:09:43 ] [ ATR ] T=0  1etu=13.02us  Guardtime:15etu  WWT:76800etu
[ 13:09:43 ] [ ATR ] Historical bytes: 3 [B0] [10] i [FF] J P p [00] [00] Z E [01] [00] [00] 
[ 13:09:43 ] [ Loader ] Init NDS card
[ 13:09:43 ] [ NDS ] BOXID: 90XXXXXX
[ 13:09:43 ] [ NDS ] CAID: 0926
[ 13:09:43 ] [ Keyman ] Adding key 2EXXX type 0 on Provider 000000 for caid 0926 ID=0
[ 13:09:43 ] [ Keyman ] Adding key 2EXXX type 1 on Provider 000000 for caid 0926 ID=0
[ 13:09:43 ] [ 0926 ] Init took: 0.504451
[ 13:09:43 ] [ Loader ] Card 0926 on port 0 ready
[ 13:09:43 ] [ Card queue 0 ] Starting...
[ 13:09:43 ] [ Loader ] Starting Newcamd Server on port 15000
[ 13:09:43 ] [ Newcamd:15000 ] rlogin for user dummy fd 9
[ 13:09:43 ] [ Newcamd ] recv: error! 111: Connection refused
[ 13:09:43 ] [ Newcamd:15000 ] User dummy logout
[ 13:09:43 ] [ Loader ] Starting Radegast Server on port 10001
[ 13:09:43 ] [ SockSrv ] Server thread started
[ 13:09:43 ] [ NewCS ] Ready to GO! :)
[ 13:09:43 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:09:43 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:09:47 ] [ Newcamd ] new connection from 127.0.0.1 on socket 10
[ 13:09:47 ] [ Newcamd:15000 ] Connection from 127.0.0.1
[ 13:09:47 ] [ Newcamd:15000 ] User dummy logged in, client: VDR-SC
[ 13:09:47 ] [ Newcamd:15000 ] Sending Card Information to dummy:
[ 13:09:47 ] [ Newcamd ] ProvID 0 Key 2EXXX on caid 0926 type 0
[ 13:09:47 ] [ Newcamd ] ProvID 0 Key 2EXXX on caid 0926 type 1
[ 13:09:50 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:09:50 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:09:50 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:09:50 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:09:50 ] [ Card queue 0 ] ECM added, sid 92, prio 7
[ 13:09:50 ] [ Card queue 0 ] Ecm run, sid 92, prio 7, queue len: 1, max len: 1
[ 13:09:50 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:09:50 ] [ NDS ] CW1: 0000000000000000
[ 13:09:50 ] [ NDS ] CW2: 0000000000000000
[ 13:09:50 ] [ 0926 ] Card ECM took: 0s 153404us
[ 13:09:50 ] [ Newcamd ] ECM -> dummy (NOT OK)
[ 13:09:50 ] [ SID ] Updating SID 0092 for Reader 0 (pcscd on USB) bad - SO is: 0
[ 13:09:50 ] [ SID ] Adding SID 0092 on Reader 0 (pcscd on USB) - SO is: 0 [Allow]
[ 13:09:50 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:09:50 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:09:50 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:09:50 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:09:50 ] [ Newcamd:15000 ] ECM from dummy rejected (too fast: 0 sec)
[ 13:09:52 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:09:52 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:09:52 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:09:52 ] [ Newcamd:15000 ] ECM from dummy rejected (too fast: 2 sec)
[ 13:09:52 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:09:52 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:09:52 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:09:52 ] [ Newcamd:15000 ] ECM from dummy rejected (too fast: 2 sec)
[ 13:09:53 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:09:53 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:09:53 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:09:53 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:09:53 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:09:53 ] [ 0926 ] Card EMM took: 0s 102809us
[ 13:09:53 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:09:53 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:09:54 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:09:54 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:09:54 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:09:54 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:09:54 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:09:54 ] [ 0926 ] Card EMM took: 0s 43132us
[ 13:09:54 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:09:54 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:09:54 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:09:54 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:09:56 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:09:56 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:09:56 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:09:56 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:09:56 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:09:56 ] [ 0926 ] Card EMM took: 0s 108171us
[ 13:09:56 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:09:56 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:00 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:00 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:00 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:00 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:00 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:00 ] [ 0926 ] Card EMM took: 0s 47616us
[ 13:10:00 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:10:00 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:02 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:02 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:02 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:02 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:10:02 ] [ Card queue 0 ] ECM added, sid 92, prio 8
[ 13:10:02 ] [ Card queue 0 ] Ecm run, sid 92, prio 8, queue len: 1, max len: 1
[ 13:10:02 ] [ 0926 ] Ecm Cache Check took: 0s 0us
[ 13:10:02 ] [ NDS ] CW1: 0000000000000000
[ 13:10:02 ] [ NDS ] CW2: 0000000000000000
[ 13:10:02 ] [ 0926 ] Card ECM took: 0s 122693us
[ 13:10:02 ] [ Newcamd ] ECM -> dummy (NOT OK)
[ 13:10:02 ] [ SID ] Updating SID 0092 for Reader 0 (pcscd on USB) bad - SO is: 0
[ 13:10:02 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:10:02 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:02 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:02 ] [ Newcamd:15000 ] Rejected SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:03 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:03 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:03 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:03 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:03 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:03 ] [ 0926 ] Card EMM took: 0s 103325us
[ 13:10:03 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:03 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:05 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:10:05 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:10:05 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:05 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:05 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:05 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:05 ] [ 0926 ] Emm Cache Check took: 0s 2us
[ 13:10:05 ] [ 0926 ] Card EMM took: 0s 108368us
[ 13:10:05 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:05 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:06 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:06 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:06 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:06 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:06 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:06 ] [ 0926 ] Card EMM took: 0s 46830us
[ 13:10:06 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:06 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:09 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:09 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:09 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:09 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:09 ] [ 0926 ] Emm Cache Check took: 0s 2us
[ 13:10:09 ] [ 0926 ] Card EMM took: 0s 48174us
[ 13:10:09 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:09 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:12 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:12 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:12 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:12 ] [ 0926 ] Ecm Cache Check took: 0s 5us
[ 13:10:12 ] [ Card queue 0 ] ECM added, sid 92, prio 15
[ 13:10:12 ] [ Card queue 0 ] Ecm run, sid 92, prio 15, queue len: 1, max len: 1
[ 13:10:12 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:10:12 ] [ NDS ] CW1: 0000000000000000
[ 13:10:12 ] [ NDS ] CW2: 0000000000000000
[ 13:10:12 ] [ 0926 ] Card ECM took: 0s 120020us
[ 13:10:12 ] [ Newcamd ] ECM -> dummy (NOT OK)
[ 13:10:12 ] [ SID ] Updating SID 0092 for Reader 0 (pcscd on USB) bad - SO is: 0
[ 13:10:12 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:10:12 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:12 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:12 ] [ Newcamd:15000 ] Rejected SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:13 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:13 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:13 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:13 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:13 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:13 ] [ 0926 ] Card EMM took: 0s 109076us
[ 13:10:13 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:13 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:15 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:15 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:15 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:15 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:15 ] [ 0926 ] Emm Cache Check took: 0s 0us
[ 13:10:15 ] [ 0926 ] Card EMM took: 0s 107543us
[ 13:10:15 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:15 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:16 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:10:16 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:10:18 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:18 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:18 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:18 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:18 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:18 ] [ 0926 ] Card EMM took: 0s 101736us
[ 13:10:18 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:18 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:19 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:19 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:19 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:19 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:19 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:19 ] [ 0926 ] Card EMM took: 0s 43250us
[ 13:10:19 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:19 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:22 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:22 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:22 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:22 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:22 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:22 ] [ 0926 ] Card EMM took: 0s 47548us
[ 13:10:22 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:22 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:22 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:22 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:22 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:22 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:10:22 ] [ Card queue 0 ] ECM added, sid 92, prio 20
[ 13:10:22 ] [ Card queue 0 ] Ecm run, sid 92, prio 20, queue len: 1, max len: 1
[ 13:10:22 ] [ 0926 ] Ecm Cache Check took: 0s 2us
[ 13:10:22 ] [ NDS ] CW1: 0000000000000000
[ 13:10:22 ] [ NDS ] CW2: 0000000000000000
[ 13:10:22 ] [ 0926 ] Card ECM took: 0s 128113us
[ 13:10:22 ] [ Newcamd ] ECM -> dummy (NOT OK)
[ 13:10:22 ] [ SID ] Updating SID 0092 for Reader 0 (pcscd on USB) bad - SO is: 0
[ 13:10:22 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:10:22 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:22 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:22 ] [ Newcamd:15000 ] Rejected SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:25 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:25 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:25 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:25 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:25 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:25 ] [ 0926 ] Card EMM took: 0s 61896us
[ 13:10:25 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:25 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:27 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:10:27 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:10:29 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:29 ] [ 0926 ] Emm Cache Check took: 0s 9us
[ 13:10:29 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:29 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:29 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:29 ] [ 0926 ] Card EMM took: 0s 108084us
[ 13:10:29 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:29 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:32 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:32 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:32 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:32 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:32 ] [ 0926 ] Emm Cache Check took: 0s 0us
[ 13:10:32 ] [ 0926 ] Card EMM took: 0s 104419us
[ 13:10:32 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:32 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:32 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:32 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:32 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:32 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:10:32 ] [ Card queue 0 ] ECM added, sid 92, prio 25
[ 13:10:32 ] [ Card queue 0 ] Ecm run, sid 92, prio 25, queue len: 1, max len: 1
[ 13:10:32 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:10:32 ] [ NDS ] CW1: 0EBDFA2510FD32E9
[ 13:10:32 ] [ NDS ] CW2: 26B27F59827E5DD0
[ 13:10:32 ] [ 0926 ] Card ECM took: 0s 127810us
[ 13:10:32 ] [ Newcamd ] ECM -> dummy (OK)
[ 13:10:32 ] [ SID ] Updating SID 0092 for Reader 0 (pcscd on USB) ok - SO is: 0
[ 13:10:32 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:10:35 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:35 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:35 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:35 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:35 ] [ 0926 ] Emm Cache Check took: 0s 2us
[ 13:10:35 ] [ 0926 ] Card EMM took: 0s 60384us
[ 13:10:35 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:35 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:38 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:10:38 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:10:39 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:39 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:39 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:39 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:39 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:39 ] [ 0926 ] Card EMM took: 0s 108078us
[ 13:10:39 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:10:39 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:42 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:42 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:42 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:42 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:42 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:42 ] [ 0926 ] Card EMM took: 0s 104121us
[ 13:10:42 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:10:42 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:42 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:42 ] [ SID ] Checking for SID 0092 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:42 ] [ Newcamd:15000 ] Accepted SID 0092 on Reader 0 (pcscd on USB) from dummy
[ 13:10:42 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:10:42 ] [ Card queue 0 ] ECM added, sid 92, prio 30
[ 13:10:42 ] [ Card queue 0 ] Ecm run, sid 92, prio 30, queue len: 1, max len: 1
[ 13:10:42 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:10:42 ] [ NDS ] CW1: 4C07BF1096AE3456
[ 13:10:42 ] [ NDS ] CW2: 2AD0C72DE3A55A40
[ 13:10:42 ] [ 0926 ] Card ECM took: 0s 126134us
[ 13:10:42 ] [ Newcamd ] ECM -> dummy (OK)
[ 13:10:42 ] [ SID ] Updating SID 0092 for Reader 0 (pcscd on USB) ok - SO is: 0
[ 13:10:42 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:10:44 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:44 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:44 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:44 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:44 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:44 ] [ 0926 ] Card EMM took: 0s 107722us
[ 13:10:44 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:10:44 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:46 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:46 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:46 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:46 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:46 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:46 ] [ 0926 ] Card EMM took: 0s 103001us
[ 13:10:46 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:10:46 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:49 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:10:49 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:10:49 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:49 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:10:49 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:49 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:49 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:49 ] [ 0926 ] Card EMM took: 0s 103924us
[ 13:10:49 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:49 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:55 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:55 ] [ SID ] Checking for SID 0093 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:55 ] [ Newcamd:15000 ] Accepted SID 0093 on Reader 0 (pcscd on USB) from dummy
[ 13:10:55 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:10:55 ] [ Card queue 0 ] ECM added, sid 93, prio 29
[ 13:10:55 ] [ Card queue 0 ] Ecm run, sid 93, prio 29, queue len: 1, max len: 1
[ 13:10:55 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:10:55 ] [ NDS ] CW1: 0000000000000000
[ 13:10:55 ] [ NDS ] CW2: 0000000000000000
[ 13:10:55 ] [ 0926 ] Card ECM took: 0s 126228us
[ 13:10:55 ] [ Newcamd ] ECM -> dummy (NOT OK)
[ 13:10:55 ] [ SID ] Updating SID 0093 for Reader 0 (pcscd on USB) bad - SO is: 0
[ 13:10:55 ] [ SID ] Adding SID 0093 on Reader 0 (pcscd on USB) - SO is: 0 [Allow]
[ 13:10:55 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:10:55 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:10:55 ] [ SID ] Checking for SID 0093 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:10:55 ] [ Newcamd:15000 ] Accepted SID 0093 on Reader 0 (pcscd on USB) from dummy
[ 13:10:55 ] [ Newcamd:15000 ] ECM from dummy rejected (too fast: 0 sec)
[ 13:10:56 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:56 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:56 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:56 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:56 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:10:56 ] [ 0926 ] Card EMM took: 0s 61889us
[ 13:10:56 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:56 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:10:58 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:10:58 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:10:58 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:10:58 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:10:58 ] [ 0926 ] Emm Cache Check took: 0s 3us
[ 13:10:58 ] [ 0926 ] Card EMM took: 0s 108271us
[ 13:10:58 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:10:58 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:11:00 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:11:00 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:11:00 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:11:00 ] [ 0926 ] Emm Cache Check took: 0s 7us
[ 13:11:00 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:11:00 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:11:00 ] [ 0926 ] Emm Cache Check took: 0s 2us
[ 13:11:00 ] [ 0926 ] Card EMM took: 0s 41363us
[ 13:11:00 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:11:00 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:11:02 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:11:02 ] [ SID ] Checking for SID 0093 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:11:02 ] [ Newcamd:15000 ] Accepted SID 0093 on Reader 0 (pcscd on USB) from dummy
[ 13:11:02 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:11:02 ] [ Card queue 0 ] ECM added, sid 93, prio 50
[ 13:11:02 ] [ Card queue 0 ] Ecm run, sid 93, prio 50, queue len: 1, max len: 1
[ 13:11:02 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:11:02 ] [ NDS ] CW1: 87CC68A8530C576F
[ 13:11:02 ] [ NDS ] CW2: 575082A9F38D91C1
[ 13:11:02 ] [ 0926 ] Card ECM took: 0s 122549us
[ 13:11:02 ] [ Newcamd ] ECM -> dummy (OK)
[ 13:11:02 ] [ SID ] Updating SID 0093 for Reader 0 (pcscd on USB) ok - SO is: 0
[ 13:11:02 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:11:04 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:11:04 ] [ 0926 ] Emm Cache Check took: 0s 6us
[ 13:11:04 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:11:04 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:11:04 ] [ 0926 ] Emm Cache Check took: 0s 3us
[ 13:11:04 ] [ 0926 ] Card EMM took: 0s 49284us
[ 13:11:04 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:11:04 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:11:06 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:11:06 ] [ 0926 ] Emm Cache Check took: 0s 9us
[ 13:11:06 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:11:06 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:11:06 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:11:06 ] [ 0926 ] Card EMM took: 0s 107272us
[ 13:11:06 ] [ 0926 ] Emm Cache Add took: 0s 1us
[ 13:11:06 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:11:11 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:11:11 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:11:12 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:11:12 ] [ SID ] Checking for SID 0093 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:11:12 ] [ Newcamd:15000 ] Accepted SID 0093 on Reader 0 (pcscd on USB) from dummy
[ 13:11:12 ] [ 0926 ] Ecm Cache Check took: 0s 4us
[ 13:11:12 ] [ Card queue 0 ] ECM added, sid 93, prio 45
[ 13:11:12 ] [ Card queue 0 ] Ecm run, sid 93, prio 45, queue len: 1, max len: 1
[ 13:11:12 ] [ 0926 ] Ecm Cache Check took: 0s 1us
[ 13:11:13 ] [ NDS ] CW1: 0000000000000000
[ 13:11:13 ] [ NDS ] CW2: 0000000000000000
[ 13:11:13 ] [ 0926 ] Card ECM took: 0s 127274us
[ 13:11:13 ] [ Newcamd ] ECM -> dummy (NOT OK)
[ 13:11:13 ] [ SID ] Updating SID 0093 for Reader 0 (pcscd on USB) bad - SO is: 0
[ 13:11:13 ] [ 0926 ] Ecm Cache Add took: 0s 0us
[ 13:11:13 ] [ Newcamd:15000 ] ECM <- dummy
[ 13:11:13 ] [ SID ] Checking for SID 0093 for Reader 0 (pcscd on USB) - SO is: 0 
[ 13:11:13 ] [ Newcamd:15000 ] Accepted SID 0093 on Reader 0 (pcscd on USB) from dummy
[ 13:11:13 ] [ Newcamd:15000 ] ECM from dummy rejected (too fast: 0 sec)
[ 13:11:21 ] [ Newcamd:15000 ] EMM <- dummy
[ 13:11:21 ] [ 0926 ] Emm Cache Check took: 0s 8us
[ 13:11:21 ] [ Card queue 0 ] EMM added, sid 0, prio 255
[ 13:11:21 ] [ Card queue 0 ] Emm run, sid 0, prio 255, queue len: 1, max len: 1
[ 13:11:21 ] [ 0926 ] Emm Cache Check took: 0s 1us
[ 13:11:21 ] [ 0926 ] Card EMM took: 0s 105010us
[ 13:11:21 ] [ 0926 ] Emm Cache Add took: 0s 0us
[ 13:11:21 ] [ SID ] Unblocking sids for Reader 0 (pcscd on USB) 
[ 13:11:22 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:11:22 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:11:33 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:11:33 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0
[ 13:11:41 ] [ Newcamd:15000 ] User dummy logout
[ 13:11:44 ] [ ECM Cache ] Cleaning dynamic Cache, size: 0 ...
[ 13:11:44 ] [ ECM Cache ] Cleaning dynamic Cache done, size: 0