ORF CARDOK (no entitlements) + timeout 5000ms

[roadwarrior291]

hallo leute,

ich hab ich heute wirklich den ganzen tag durch dieses forum gegraben, doch ich komm nicht dahinter was bei mir jz konkret der fehler ist, vllt kann mir hier ja bitte jemand helfen:

ich weiß, dass die fehlenden emms ein problem sind, nur weiß ich jz nicht, ob die emms jz nicht reinkommen, weil da ein timeout beim client kommt. oder ob das timeout wegen den fehlenden emms kommt und die nur nicht auf die karte geschrieben werden.

Infos

• smargo usb smartcardreader
  
• client yavdr mit vdr-plugin-dvbapi
• oscam und vdr auf der selben kiste
• das webif zeigt mir beim reader CARDOK (no entitlements) und er zeigt mir auch den client "vdr" mit status OK aber mit timeout 5000 ms
  
• die orf karte (C8..... -> 0D95) ist noch bis 2018 gültig (hab heute den orf.at-kartencheck gemacht)
• die karte war jz aber einige monate nicht in betrieb
• ich sehe im oscamlog alte entitlements von 2013, 2014 und 2015
• /tmp/emm.log ist leer

Spoiler: oscam.conf

[global]
serverip = 127.0.0.1
logfile = stdout
emmlogdir = /tmp/emm.log
lb_mode = 1

[anticasc]
enabled = 1
aclogfile = logfile

[cache]

[dvbapi]
enabled = 1
au = 1
pmt_mode = 0
request_mode = 1
listen_port = 2000
user = vdr
boxtype = pc

[webif]
httpport = 8889
serverip = 10.17.0.214
httpuser = name
httppwd = pass
httphelplang = de
httpallowed = 127.0.0.1,10.17.0.0-10.17.0.25

Spoiler: oscam.server

[reader]
enable = 1
Label = orfsat
device = /dev/ttyUSB0
protocol = mouse
caid = 0D95
smargopatch = 1
detect = cd
mhz = 450
cardmhz = 2700
group = 1
emmcache = 1,1,2
ecmwhitelist = 0D95:80,B8,F0
blockemm-u = 0
blockemm-s = 1
blockemm-g = 1
blockemm-unknown = 1
saveemm-u = 1
saveemm-s = 1
saveemm-g = 1

Spoiler: oscam.user

[account]
user = vdr
group = 1
au = 1

Spoiler: oscam.log

2017/01/13 17:52:06 58F394B4 r (reader) orfsat [mouse] card detected
2017/01/13 17:52:06 58F394B4 r (reader) orfsat [mouse] type: CryptoWorks
2017/01/13 17:52:06 58F394B4 r (reader) orfsat [mouse] card system not supported
2017/01/13 17:52:06 58F394B4 r (reader) orfsat [mouse] Normal mode failed, reverting to Deprecated Mode
2017/01/13 17:52:06 58F394B4 r (reader) orfsat [mouse] Buffers readed 0 bytes total time_us 75115
2017/01/13 17:52:07 58F394B4 r (reader) orfsat [mouse] ATR: 3B 78 12 00 00 54 C4 03 00 8F F1 90 00
2017/01/13 17:52:07 58F394B4 r (reader) orfsat [mouse] Init card protocol T0, FI=1, F=372, D=2, N=0
2017/01/13 17:52:07 58F394B4 r (reader) orfsat [mouse] Calculated work ETU is 82.67 us reader mhz = 450
2017/01/13 17:52:07 58F394B4 r (reader) orfsat [mouse] Buffers readed 0 bytes total time_us 75106
2017/01/13 17:52:07 58F394B4 r (reader) orfsat [mouse] ATR Fsmax is 5 MHz, clocking card to wanted user cardspeed off 4.50 MHz (specified in reader->mhz)
2017/01/13 17:52:08 58F394B4 r (reader) orfsat [mouse] card detected
2017/01/13 17:52:08 58F394B4 r (reader) orfsat [mouse] type: CryptoWorks
2017/01/13 17:52:08 58F394B4 r (reader) orfsat [mouse] type: CryptoWorks, caid: 0D95, ascii serial: #########, hex serial: ##########
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [mouse] issuer: CryptoWorks, id: 04, bios: v3, pin: unknown, mfid: 3F00
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [mouse] providers: 4 (04,08,0C,10)
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [mouse] found card system cryptoworks
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [cryptoworks] THIS WAS A SUCCESSFUL START ATTEMPT No 1 out of max alloted of 1
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [cryptoworks] provider: 1, id: 04, name: Operator: FFFF
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [cryptoworks] chid: 000D, date: 2013/08/28 - 2013/09/27, name: Product 000D
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [cryptoworks] chid: 7FF7, date: 2014/09/14 - 2014/09/24, name: Product 7FF7
2017/01/13 17:52:09 58F394B4 r (reader) orfsat [cryptoworks] chid: 0001, date: 2014/09/13 - 2015/05/21, name: Product 0001
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] chid: 0002, date: 2014/09/14 - 2015/05/22, name: Product 0002
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] chid: 7FFB, date: 2014/07/22 - 2014/08/21, name: Product 7FFB
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] chid: FFD8, date: 2014/02/23 - 2014/03/25, name: Product FFD8
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] chid: FFE0, date: 2014/09/13 - 2015/05/21, name: Product FFE0
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] provider: 2, id: 08, name: Operator: FFFF
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] chid: 001D, date: 2013/08/28 - 2013/11/28, name: Product 001D
2017/01/13 17:52:10 58F394B4 r (reader) orfsat [cryptoworks] provider: 3, id: 0C, name: Operator: FFFF
2017/01/13 17:52:11 58F394B4 r (reader) orfsat [cryptoworks] provider: 4, id: 10, name: Operator: FFFF
2017/01/13 17:52:11 58F394B4 r (reader) orfsat [cryptoworks] chid: 0031, date: 2014/05/28 - 2014/08/28, name: Product 0031
2017/01/13 17:52:11 58F394B4 r (reader) orfsat [cryptoworks] ready for requests
2017/01/13 17:52:12 00000000 s (main) init for all local cards done
2017/01/13 17:52:12 00000000 s (emmcache) loaded 0 emmcache records from /usr/local/etc/oscam.emmcache in 0 ms
2017/01/13 17:52:12 00000000 s (emmcache) loaded 0 emmstat records from /usr/local/etc/oscam.emmstat in 0 ms
2017/01/13 17:52:12 00000000 s (anticasc) anti cascading log initialized
2017/01/13 17:52:12 78A00753 c (client) plain dvbapi-client granted (vdr, au=auto (1 reader))
2017/01/13 17:52:12 78A00753 c (dvbapi) dvbapi channelcache loaded from /usr/local/etc/oscam.ccache
2017/01/13 17:52:12 78A00753 c (dvbapi) Using TCP listen socket, API forced to DVBAPIv3 (0), userconfig boxtype: 11
2017/01/13 17:52:13 78A00753 c (dvbapi) Client connected: 'vdr-plugin-dvbapi 2.2.3-GIT-7a42b22 / VDR 2.2.0' (protocol version = 2)
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0648 ECM_PID: 0078 PROVID: 000000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 1 CAID: 0650 ECM_PID: 007A PROVID: 000000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 2 CAID: 0D95 ECM_PID: 010E PROVID: 000000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 3 CAID: 0D98 ECM_PID: 0110 PROVID: 000000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 4 CAID: 0500 ECM_PID: 01CD PROVID: 051900
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 5 CAID: 09C4 ECM_PID: 01E0 PROVID: 000000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 ecmpid 6 CAID: 098C ECM_PID: 01EA PROVID: 000000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 stream Videostream (MPEG-2)(type: 02 pid: 0780 length: 0)
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 stream Data-/Audiostream (Subtitles/VBI and AC-3)(type: 06 pid: 0781 length: 0)
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 stream Data-/Audiostream (Subtitles/VBI and AC-3)(type: 06 pid: 0782 length: 0)
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 found 7 ECMpids and 3 STREAMpids in caPMT
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 serving srvid 132F (0648@000000:132F unknown) on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/01/13 17:52:13 78A00753 c (dvbapi) Demuxer 0 trying to descramble PID 2 CAID 0D95 PROVID 000000 ECMPID 010E ANY CHID PMTPID 0000 VPID 0780
2017/01/13 17:52:17 78A00753 c (dvbapi) Demuxer 0 stop descrambling program number 132F (0648@000000:132F unknown)
2017/01/13 17:52:19 78A00753 c (ecm) vdr (0D95@000004/0000/132F/B8:BE1FD7919718522FE10F53A8A3EA5B4C): timeout (5000 ms) by orfsat

Spoiler: vdr-plugin-dvbapi.log

Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: 0.0 CA_PMT decoding len=15 lm=4 prg=4911 len=0
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: pid=2,0780 len=0 (0x0)
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: pid=6,0781 len=0 (0x0)
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: pid=6,0782 len=0 (0x0)
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: 0.0 got CA pmt ciCmd=-1 caLm=4
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: 0.0 answer to query suppressed
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: 0.0 set CAM decrypt (SID 4911 (0x132F), caLm 4, HasCaDescriptors 0)
Jan 13 17:18:09 hdvdr vdr: [1053] DVBAPI: CA_PMT doesn't contain CA descriptors
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 CA_PMT decoding len=3c lm=5 prg=4911 len=36
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: ci_cmd(G)=01
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 got CA pmt ciCmd=1 caLm=5
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 answer to query suppressed
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 set CAM decrypt (SID 4911 (0x132F), caLm 5, HasCaDescriptors 1)
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: SendStopDescrambling
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: Write, sock=50
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: socket_fd=50 len=8 wrote=8
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 CA_PMT decoding len=6 lm=3 prg=0 len=0
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 got CA pmt ciCmd=-1 caLm=3
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 answer to query suppressed
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 stop decrypt
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 CA_PMT decoding len=4b lm=4 prg=4911 len=36
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: ci_cmd(G)=01
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: pid=2,0780 len=0 (0x0)
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: pid=6,0781 len=0 (0x0)
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: pid=6,0782 len=0 (0x0)
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 got CA pmt ciCmd=1 caLm=4
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 answer to query suppressed
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: 0.0 set CAM decrypt (SID 4911 (0x132F), caLm 4, HasCaDescriptors 1)
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: send: channelSid=0x132f (4911)
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: Write, sock=50
Jan 13 17:18:11 hdvdr vdr: [1053] DVBAPI: socket_fd=50 len=85 wrote=85
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_SET_FILTER request, adapter_index=0, pid=0, demux_idx=0, filter_num=0
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=0000 start=1, demux=0, filter=0
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: --> FILTER: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: --> MASK: FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: inserting new filter, demux=0, filter_num=0
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_SET_FILTER request, adapter_index=0, pid=1, demux_idx=0, filter_num=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=0001 start=1, demux=0, filter=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: --> FILTER: 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: --> MASK: FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: inserting new filter, demux=0, filter_num=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_STOP request, adapter_index=0, pid=1, demux_idx=0, filter_num=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=0001 start=0, demux=0, filter=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: deleting filter, demux=0, filter_num=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: deleted the last filter for pid=0001, removing list
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_SET_FILTER request, adapter_index=0, pid=10E, demux_idx=0, filter_num=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=010E start=1, demux=0, filter=1
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: --> FILTER: 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: --> MASK: F0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:11 hdvdr vdr: [1404] DVBAPI: SetFilter: inserting new filter, demux=0, filter_num=1
Jan 13 17:18:12 hdvdr vdr: [7473] DVBAPI: Analyze: saving first part of data, tablelen=181
Jan 13 17:18:12 hdvdr vdr: [7473] DVBAPI: Analyze: PUSI=0, to_copy=1
Jan 13 17:18:12 hdvdr vdr: [7473] DVBAPI: Analyze: filter data assembled, sending len=184
Jan 13 17:18:12 hdvdr vdr: [7473] DVBAPI: Write, sock=50
Jan 13 17:18:12 hdvdr vdr: [7473] DVBAPI: socket_fd=50 len=190 wrote=190
Jan 13 17:18:12 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_SET_FILTER request, adapter_index=0, pid=10E, demux_idx=0, filter_num=1
Jan 13 17:18:12 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=010E start=1, demux=0, filter=1
Jan 13 17:18:12 hdvdr vdr: [1404] DVBAPI: --> FILTER: 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:12 hdvdr vdr: [1404] DVBAPI: --> MASK: FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 13 17:18:12 hdvdr vdr: [1404] DVBAPI: SetFilter: filter update, demux=0, filter_num=1
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 CA_PMT decoding len=3c lm=5 prg=4911 len=36
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: ci_cmd(G)=01
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 got CA pmt ciCmd=1 caLm=5
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 answer to query suppressed
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 set CAM decrypt (SID 4911 (0x132F), caLm 5, HasCaDescriptors 1)
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: SendStopDescrambling
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: Write, sock=50
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: socket_fd=50 len=8 wrote=8
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 CA_PMT decoding len=6 lm=3 prg=0 len=0
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 got CA pmt ciCmd=-1 caLm=3
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_STOP request, adapter_index=0, pid=0, demux_idx=0, filter_num=0
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 answer to query suppressed
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=0000 start=0, demux=0, filter=0
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: SetFilter: deleting filter, demux=0, filter_num=0
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: SetFilter: deleted the last filter for pid=0000, removing list
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: Action: Got DMX_STOP request, adapter_index=0, pid=10E, demux_idx=0, filter_num=1
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: SetFilter: adapter=0 set FILTER pid=010E start=0, demux=0, filter=1
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: SetFilter: deleting filter, demux=0, filter_num=1
Jan 13 17:18:15 hdvdr vdr: [1404] DVBAPI: SetFilter: deleted the last filter for pid=010E, removing list
Jan 13 17:18:15 hdvdr vdr: [7473] DVBAPI: 0.0 stop decrypt

 

[czutok]

schreibe mal
protocol = mouse

auf

protocol = smargo
oder
protocol = smartreader

nach umschreibung , oscam komplet rebooten und schauen was pasiert

 

[filius00]

emmlogdir = /tmp/emm.log

Mit diesem Eintrag kannst du auch kein Logg erwarten!
Lösche die Zeile komplett aus der Conf!
Emm`s verlängern Karten und haben mit deinen Timeouts eher nichts zu tun.
Wenn du irgendwo eine Scam am laufen hast stecke die Karte mal um und schalte
auf ORF 2, dann sollte sie wieder umgehend hell werden.

 

[roadwarrior291]

WOW! so einfach wars??? DANKE!!!! funktioniert! das umstellen auf protocol = smargo wars!!!! DANKE!!!!!

 

[czutok]

für danke haben wir unter jedem beitrag "Gefällt mir" taste