-------------------------------------------------------------------------------
>> OSCam << cardserver started at Fri May 1 19:55:51 2015
-------------------------------------------------------------------------------
2015/05/01 19:55:51 0 s >> OSCam << cardserver started, version 1.20-unstable_svn, build r9524 (mips-openwrt-linux-uclibc-ssl-libusb-pcsc)
2015/05/01 19:55:51 0 s creating pidfile /tmp/.oscam/oscam.pid with pid 21930
2015/05/01 19:55:51 0 s services reloaded: 0 services freed, 0 services loaded, rejected 0
2015/05/01 19:55:51 0 s userdb reloaded: 2 accounts loaded, 0 expired, 0 disabled
2015/05/01 19:55:51 0 s signal handling initialized
2015/05/01 19:55:51 0 s monitor: initialized (fd=5, port=1000)
2015/05/01 19:55:51 0 s newcamd: initialized (fd=6, port=44066, ip=192.168.1.1)
2015/05/01 19:55:51 0 s -> CAID: 098C PROVID: 000000
2015/05/01 19:55:51 0 s newcamd: initialized (fd=7, port=44067, ip=192.168.1.1)
2015/05/01 19:55:51 0 s -> CAID: 098C PROVID: 000000
2015/05/01 19:55:51 0 s newcamd: initialized (fd=8, port=44068, ip=192.168.1.1)
2015/05/01 19:55:51 0 s -> CAID: 098C PROVID: 000000
2015/05/01 19:55:51 0 s cccam: initialized (fd=10, port=12000)
2015/05/01 19:55:51 0 s SkyGermany [mouse] creating thread for device /dev/ttyUSB1
2015/05/01 19:55:51 0 s HDplusHD02 [mouse] creating thread for device /dev/ttyUSB0
2015/05/01 19:55:51 0 s waiting for local card init
2015/05/01 19:55:51 627238 h webif: decompressed 72428 bytes back into 201640 bytes
2015/05/01 19:55:51 627238 h HTTP Server running. ip=0.0.0.0 port=9898
2015/05/01 19:55:51 664880 r HDplusHD02 [mouse] Reader initialized (device=/dev/ttyUSB0, detect=cd, mhz=357, cardmhz=368)
2015/05/01 19:55:51 623768 r SkyGermany [mouse] Reader initialized (device=/dev/ttyUSB1, detect=cd, mhz=600, cardmhz=357)
2015/05/01 19:55:52 623768 r SkyGermany [mouse] card detected
2015/05/01 19:55:53 623768 r SkyGermany [mouse] ATR: 3F FD 15 25 02 50 80 0F 41 B0 0A 69 FF 4A 50 F0 00 00 50 31 03
2015/05/01 19:55:53 623768 r SkyGermany [mouse] Init card protocol T0, FI=1, F=372, D=16, N=2
2015/05/01 19:55:53 623768 r SkyGermany [mouse] Setting baudrate to 153600 bps
2015/05/01 19:55:53 623768 r SkyGermany [mouse] Calculated work ETU is 3.88 us reader mhz = 600
2015/05/01 19:55:53 623768 r SkyGermany [mouse] ATR Fsmax is 5 MHz, clocking card to wanted user cardspeed off 6.00 MHz (specified in reader->mhz)
2015/05/01 19:55:54 623768 r SkyGermany [mouse] Card type: P1TV
2015/05/01 19:55:54 623768 r SkyGermany [mouse] Rom version: 20AA
2015/05/01 19:55:55 623768 r SkyGermany [mouse] parental lock setting: FF FF FF FF
2015/05/01 19:55:55 623768 r SkyGermany [mouse] type: VideoGuard Sky Austria/Germany (098C), caid: 098C
2015/05/01 19:55:55 623768 r SkyGermany [mouse] serial: ########, BoxID: ########, baseyear: 2004
2015/05/01 19:55:55 623768 r SkyGermany [mouse] ready for requests
2015/05/01 19:55:55 623768 r SkyGermany [mouse] found card system videoguard2
2015/05/01 19:55:55 623768 r SkyGermany [videoguard2] THIS WAS A SUCCESFULL START ATTEMPT No 1 out of max alloted of 1
2015/05/01 19:55:55 623768 r SkyGermany [videoguard2] card detected
2015/05/01 19:55:55 623768 r SkyGermany [videoguard2] type: VideoGuard Sky Austria/Germany (098C)
2015/05/01 19:55:56 0 s init for all local cards done
2015/05/01 19:57:22 627238 h all debug_level=1
2015/05/01 19:57:22 627238 h WebIf: Origin checked. Result: access from 192.168.1.100 => allowed
2015/05/01 19:57:26 627238 h all debug_level=3
2015/05/01 19:57:26 627238 h WebIf: Origin checked. Result: access from 192.168.1.100 => allowed
2015/05/01 19:57:31 627238 h all debug_level=259
2015/05/01 19:57:31 627238 h WebIf: Origin checked. Result: access from 192.168.1.100 => allowed
2015/05/01 19:57:41 627238 h WebIf: Received stale header from 192.168.1.100 (nonce=ec5670bea0afd9dc24663190f816ef18, expectednonce=62c9aadab55304cb57982c861516956c, opaque=fb24c2e83badafa8f5246aac424c096e).
2015/05/01 19:57:41 627238 h WebIf: Origin checked. Result: access from 192.168.1.100 => allowed
2015/05/01 19:57:55 0 --- Skipped 10 duplicated log lines ---
2015/05/01 19:57:55 0 s [OSCAM] new event 1 occurred on fd 6 after 3230 ms inactivity
2015/05/01 19:57:55 0 s start client thread action 25
2015/05/01 19:57:55 66EA28 c data from add_job action=25 client c anonymous
2015/05/01 19:57:55 66EA28 c client connected to 44066 port
2015/05/01 19:57:55 66EA28 c encrypted newcamd:44066-client 217.235.157.209 granted (htpc-mirco, au=auto (2 reader))
2015/05/01 19:57:55 66EA28 c user htpc-mirco authenticated successfully (ACamd)
2015/05/01 19:57:55 66EA28 c AU enabled for user htpc-mirco on reader SkyGermany
2015/05/01 19:57:56 66EA28 c [OSCAM-WORK] new event 1 occurred on fd 20 after 1647 ms inactivity
2015/05/01 19:57:56 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NEW REQUEST!
2015/05/01 19:57:56 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:3E24E9BDC486C90A17F316EABB31B51D: n=1 valid readers: SkyGermanyL
2015/05/01 19:57:56 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:57:56 66EA28 c loadbalancer: mode 1, nbest 1, nfb 1, max_reopen ALL, retrylimit 0ms
2015/05/01 19:57:56 66EA28 c loadbalancer: reader SkyGermany need starting statistics --> ACTIVE
2015/05/01 19:57:56 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:57:56 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:3E24E9BDC486C90A17F316EABB31B51D: n=1 selected readers: SkyGermanyL
2015/05/01 19:57:56 66EA28 c [GET_CW] wait_time 0 caid 098C prov 000000 srvid 002B rc 100 cacheex cl mode 0 ex1rdr 0
2015/05/01 19:57:56 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] wait_time 0 - client cacheex mode 0, reader avail for ecm 1, hitcache 0
2015/05/01 19:57:56 66EA28 c request_cw stage=2 to reader SkyGermany ecm hash=3E24E9BDC486C90A17F316EABB31B51D
2015/05/01 19:57:56 66EA28 c start reader thread action 5
2015/05/01 19:57:56 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [write_ecm_request] reader SkyGermany --> SENT 1
2015/05/01 19:57:56 623768 r data from add_job action=5 client r SkyGermany
2015/05/01 19:57:56 623768 r ecm:
2015/05/01 19:57:56 623768 80 70 95 00 00 01 1D 88 01 8F 37 01 2F AA 55 05
2015/05/01 19:57:56 623768 20 01 00 00 80 40 52 FA C1 AE 0C A3 56 75 0E 03
2015/05/01 19:57:56 623768 02 05 02 D1 73 7D 0B 0C 43 30 69 00 D6 6A 02 48
2015/05/01 19:57:56 623768 00 00 90 64 C1 01 86 EB BB 26 A9 59 DC 21 98 C4
2015/05/01 19:57:56 623768 C8 54 AC D8 7D 16 65 2D 42 B9 33 37 C4 F5 A0 D5
2015/05/01 19:57:56 623768 FD EF 2D 71 58 DA 0A D3 D0 07 65 B2 1A AF C9 04
2015/05/01 19:57:56 623768 04 23 FF 5A E6 1B 68 80 C4 06 D6 FC A6 83 77 DD
2015/05/01 19:57:56 623768 D7 2F 9A 8B CD 0B 6A F6 C0 3D 06 90 CF 9B 35 C9
2015/05/01 19:57:56 623768 1A B6 C8 60 48 BD 06 EF 3D 47 10 AC 09 91 10 79
2015/05/01 19:57:56 623768 50 DC 8A 52 2C 5B EF 1C
2015/05/01 19:57:56 623768 r SkyGermany [videoguard2] TRACE: SW1: 90
2015/05/01 19:57:56 623768 r SkyGermany [videoguard2] TRACE: SW2: 00
2015/05/01 19:57:56 623768 r SkyGermany [videoguard2] TRACE: SW1: 90
2015/05/01 19:57:56 623768 r SkyGermany [videoguard2] TRACE: SW2: 00
2015/05/01 19:57:56 623768 r SkyGermany [videoguard2] classD3 ins54: status 90 00 = ok but cw=00 -> channel not subscribed
2015/05/01 19:57:56 623768 r {client htpc-mirco, caid 098C, srvid 002B} [write_ecm_answer] cyclecheck passed! Reader: SkyGermany rc: 4
2015/05/01 19:57:56 623768 r {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [write_ecm_answer] reader SkyGermany rc 4, ecm time 88 ms (94 ms)
2015/05/01 19:57:56 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [send_dcw] rc 4 from reader SkyGermany
2015/05/01 19:57:56 66EA28 c htpc-mirco (098C&000000/012F/002B/98:3E24E9BDC486C90A17F316EABB31B51D): not found (95 ms) by SkyGermany
2015/05/01 19:57:56 66EA28 c cw:
2015/05/01 19:57:56 66EA28 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2015/05/01 19:57:56 623768 r add client job action 32 queue length 0 htpc-mirco
2015/05/01 19:57:56 623768 r starting thread housekeeping lb stats
2015/05/01 19:57:56 623768 r housekeeping lb stats thread started
2015/05/01 19:57:56 623768 r loadbalancer: adding stat for reader SkyGermany: rc 4 098C&000000/012F/002B/98:3E24E9BDC486C90A17F316EABB31B51D time 88ms fail 1
2015/05/01 19:57:56 623768 r SkyGermany [videoguard2] TRACE: ecm answer for ecm hash 3E24E9BDC486C90A17F316EABB31B51D rc=4
2015/05/01 19:57:56 0 loadbalancer cleanup: removed 0 entries
2015/05/01 19:58:00 66EA28 c [OSCAM-WORK] new event 1 occurred on fd 20 after 4001 ms inactivity
2015/05/01 19:58:00 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NEW REQUEST!
2015/05/01 19:58:00 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:0E3F39D2313633CEEB2A4406FAB99E09: n=1 valid readers: SkyGermanyL
2015/05/01 19:58:00 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:58:00 66EA28 c loadbalancer: mode 1, nbest 1, nfb 1, max_reopen ALL, retrylimit 0ms
2015/05/01 19:58:00 66EA28 c loadbalancer: NO VALID MATCHING READER FOUND!
2015/05/01 19:58:00 66EA28 c loadbalancer: reader SkyGermany blocked for 30 seconds (fail_factor 1), retrying in 27 seconds
2015/05/01 19:58:00 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:58:00 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:0E3F39D2313633CEEB2A4406FAB99E09: n=0 selected readers:
2015/05/01 19:58:00 66EA28 c [GET_CW] wait_time 0 caid 098C prov 000000 srvid 002B rc 100 cacheex cl mode 0 ex1rdr 0
2015/05/01 19:58:00 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] wait_time 0 - client cacheex mode 0, reader avail for ecm 1, hitcache 0
2015/05/01 19:58:00 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NO Readers and NO wait_time... not_found!
2015/05/01 19:58:00 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [send_dcw] rc 4 from reader -
2015/05/01 19:58:00 66EA28 c htpc-mirco (098C&000000/012F/002B/98:0E3F39D2313633CEEB2A4406FAB99E09): rejected group (5 ms) (no matching reader)
2015/05/01 19:58:00 66EA28 c cw:
2015/05/01 19:58:00 66EA28 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2015/05/01 19:58:01 0 add client job action 31 queue length 1 htpc-mirco
2015/05/01 19:58:03 627238 h WebIf: Received stale header from 192.168.1.100 (nonce=62c9aadab55304cb57982c861516956c, expectednonce=c057ef4f4ffc863efe9967d818a5ec89, opaque=fb24c2e83badafa8f5246aac424c096e).
2015/05/01 19:58:03 627238 h WebIf: Origin checked. Result: access from 192.168.1.100 => allowed
2015/05/01 19:58:07 0 --- Skipped 6 duplicated log lines ---
2015/05/01 19:58:07 66EA28 c [OSCAM-WORK] new event 1 occurred on fd 20 after 6998 ms inactivity
2015/05/01 19:58:07 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NEW REQUEST!
2015/05/01 19:58:07 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:58543BCDB8450B0B5CC50EA576153C5C: n=1 valid readers: SkyGermanyL
2015/05/01 19:58:07 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:58:07 66EA28 c loadbalancer: mode 1, nbest 1, nfb 1, max_reopen ALL, retrylimit 0ms
2015/05/01 19:58:07 66EA28 c loadbalancer: NO VALID MATCHING READER FOUND!
2015/05/01 19:58:07 66EA28 c loadbalancer: reader SkyGermany blocked for 30 seconds (fail_factor 1), retrying in 20 seconds
2015/05/01 19:58:07 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:58:07 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:58543BCDB8450B0B5CC50EA576153C5C: n=0 selected readers:
2015/05/01 19:58:07 66EA28 c [GET_CW] wait_time 0 caid 098C prov 000000 srvid 002B rc 100 cacheex cl mode 0 ex1rdr 0
2015/05/01 19:58:07 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] wait_time 0 - client cacheex mode 0, reader avail for ecm 1, hitcache 0
2015/05/01 19:58:07 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NO Readers and NO wait_time... not_found!
2015/05/01 19:58:07 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [send_dcw] rc 4 from reader -
2015/05/01 19:58:07 66EA28 c htpc-mirco (098C&000000/012F/002B/98:58543BCDB8450B0B5CC50EA576153C5C): rejected group (4 ms) (no matching reader)
2015/05/01 19:58:07 66EA28 c cw:
2015/05/01 19:58:07 66EA28 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2015/05/01 19:58:13 627238 h WebIf: Origin checked. Result: access from 192.168.1.100 => allowed
2015/05/01 19:58:14 0 --- Skipped 5 duplicated log lines ---
2015/05/01 19:58:14 66EA28 c [OSCAM-WORK] new event 1 occurred on fd 20 after 7003 ms inactivity
2015/05/01 19:58:14 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NEW REQUEST!
2015/05/01 19:58:14 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:1036AB06C45DA7B43B531E184AB0F6BE: n=1 valid readers: SkyGermanyL
2015/05/01 19:58:14 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:58:14 66EA28 c loadbalancer: mode 1, nbest 1, nfb 1, max_reopen ALL, retrylimit 0ms
2015/05/01 19:58:14 66EA28 c loadbalancer: NO VALID MATCHING READER FOUND!
2015/05/01 19:58:14 66EA28 c loadbalancer: reader SkyGermany blocked for 30 seconds (fail_factor 1), retrying in 13 seconds
2015/05/01 19:58:14 66EA28 c loadbalancer: --------------------------------------------
2015/05/01 19:58:14 66EA28 c loadbalancer: client htpc-mirco for 098C&000000/012F/002B/98:1036AB06C45DA7B43B531E184AB0F6BE: n=0 selected readers:
2015/05/01 19:58:14 66EA28 c [GET_CW] wait_time 0 caid 098C prov 000000 srvid 002B rc 100 cacheex cl mode 0 ex1rdr 0
2015/05/01 19:58:14 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] wait_time 0 - client cacheex mode 0, reader avail for ecm 1, hitcache 0
2015/05/01 19:58:14 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [get_cw] NO Readers and NO wait_time... not_found!
2015/05/01 19:58:14 66EA28 c {client htpc-mirco, caid 098C, prid 000000, srvid 002B} [send_dcw] rc 4 from reader -
2015/05/01 19:58:14 66EA28 c htpc-mirco (098C&000000/012F/002B/98:1036AB06C45DA7B43B531E184AB0F6BE): rejected group (5 ms) (no matching reader)
2015/05/01 19:58:14 66EA28 c cw:
2015/05/01 19:58:14 66EA28 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2015/05/01 19:58:17 627238 h all debug_level=0
2015/05/01 19:58:21 66EA28 c htpc-mirco (098C&000000/012F/002B/98:FD4180EF7624DA5B7DAE05F2710D3DB8): rejected group (1 ms) (no matching reader)
2015/05/01 19:58:28 623768 r SkyGermany [videoguard2] classD3 ins54: status 90 00 = ok but cw=00 -> channel not subscribed
2015/05/01 19:58:28 66EA28 c htpc-mirco (098C&000000/012F/002B/98:0246ED4358197452A0D89831A13C160D): not found (41 ms) by SkyGermany
2015/05/01 19:58:35 66EA28 c htpc-mirco (098C&000000/012F/002B/98:B92F8CBD59DE307D5DA075DD34A49CCD): rejected group (1 ms) (no matching reader)
2015/05/01 19:58:42 66EA28 c htpc-mirco (098C&000000/012F/002B/98:ECAE1FC06CE78D10C2D8DD1AEEF75118): rejected group (0 ms) (no matching reader)
2015/05/01 19:58:49 66EA28 c htpc-mirco (098C&000000/012F/002B/98:177829643FBAB5393321974CF78B50F3): rejected group (0 ms) (no matching reader)
2015/05/01 19:58:56 66EA28 c htpc-mirco (098C&000000/012F/002B/98:0B5D30F1BF298F43B55DD59C84199CC9): rejected group (0 ms) (no matching reader)
2015/05/01 19:59:03 66EA28 c htpc-mirco (098C&000000/012F/002B/98:3F39796D19E0C47376F447D0433D7654): rejected group (0 ms) (no matching reader)
2015/05/01 19:59:10 66EA28 c htpc-mirco (098C&000000/012F/002B/98:25D6C9F7BBE7EDBEE2D5B0E03A1E314F): rejected group (0 ms) (no matching reader)
2015/05/01 19:59:17 66EA28 c htpc-mirco (098C&000000/012F/002B/98:2350DC7F999A374B74BEFD7A288A1A5A): rejected group (1 ms) (no matching reader)
2015/05/01 19:59:24 66EA28 c htpc-mirco (098C&000000/012F/002B/98:55124A55806689171A57E52D6E795488): rejected group (0 ms) (no matching reader)
2015/05/01 19:59:31 623768 r SkyGermany [videoguard2] classD3 ins54: status 90 00 = ok but cw=00 -> channel not subscribed
2015/05/01 19:59:31 66EA28 c htpc-mirco (098C&000000/012F/002B/98:A3F8C997E8FA196DC6D977D4117CFFAC): not found (63 ms) by SkyGermany