Meldung "classD1 ins32: failed"

[parasonic]

Das Verhalten gibt also schon länger.

Das stimmt, immer wieder mal, aber sehr selten.

Ich frag mich ob es wirklich so egal ist?

Mir ist aufgefallen dass diese Meldung in den letzten Tagen bei mir vermehrt auftritt, zumindest auf CAID 09C4 = lokale V13 Karte.
Am 2.4. sowie am 5.4. habe ich den "ins32: failed" wieder für 10-15 Minuten im Log gehabt.
Schaut man sich die Oscam Sourcen an, dann dann liegt die Quelle dieser Meldung in "videoguard2_poll_status" (reader_videoguard2.c), und dort in der Antwort der Karte auf den ins5C "status check". ins5C wird in diesem "status loop" regelmässig abgefragt, normalerweise alle 12 Sekunden, wenn der Reader nix wichtigeres zu tun hat.
Im normalen Betrieb gibt die Karte hier ein 00 00 00 00 als Status zurück. Oscam tut daraufhin nichts ("Status: normal").
Ist diese Antwort allerdings NICHT Null, dann geht Oscam einen etwas anderen "Codepfad". Im Laufe dieses "anderen Codepfads" steht am Ende eine ins32 ...

Dieser Code wurde (vermutlich) mal aus irgendeinem älteren Firmware-Dump o.ä. abgeschaut / "nachempfunden". Evtl. ist der also einfach veraltet, gar nicht mehr passend zu den jetzigen SkyDE SAT-Karten...? Weil ausser weitere ins mit noch mehr Statusdaten abzufragen, und am Schluss den ins32 zu senden, tut dieser Code eigentlich gar nichts weiter.

ABER.

Ich habe mal aus Neugier das Log in Debug-Level 4 angeschaut, während dieser "bekloppten 15 Minuten", in denen die Meldung auftaucht.
Darin zeigt sich:

a) das SW der Karte auf die ECM-Anfragen ist während dieser 15 Minuten [91 20], und nicht wie sonst immer [90 20]. Für JEDES ECM in dieser Zeit.
b) ECM-Zeiten sind währenddessen leicht erhöht um ~5-10ms (auch OHNE Debug-Logging aktiviert zu haben)
c) Die Antwort auf den ins5C (Status-Check) lautet dann Hex 11 0B 00 01 [91 20]. Normal wäre 00 00 00 00 [90 20]

Also, "irgendwas" geht da doch vor sich!

Jetzt stelle ich mir zwei Fragen:

1.) passiert das bei allen V13ern zur gleichen Zeit? Bei mir heute zwischen 18:15 - 18:25 - Karte lief dabei auf SyFy HD. Danach alles wieder "normal".
2.) passiert das bei allen Karten, oder NUR bei V13? Nur in DE, oder auch bei anderen NDS Providern?

Weiss jemand von den "alten Hasen", was der abweichende Status bedeuten könnte?
Kann jemand bestätigen / Feedback geben, ob heute oder am 02.04. diese Meldung auch wieder im Log auftauchte?

Nicht dass die da gerade am rumtesten sind, und uns bald ein COVID-13 bevorsteht.... :flushed:

Spoiler

2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] cardreader_do_ecm: cardreader_do_checkhealth returned rc=1
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] write to cardreader
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   D1 40 00 80 81 00 7E 0A 76 78 FB CF 46 B5 46 4B
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   00 00 90 72 C1 01 D7 3C 31 DD 8C 46 41 3A 50 BC
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   10 3A 8C 81 CA 0B 56 E6 41 11 7B FF B7 49 84 05
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   8A 12 A0 2A 0D 78 2A 03 9E EF 58 1B 9F 72 CA 27
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   3B 95 55 C6 A7 A6 00 6E 5B A3 C8 31 C4 A4 FE A1
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   01 19 CB 75 91 B5 F6 31 A0 6C 60 57 75 3F 52 EE
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   73 D4 E7 BF 6A D1 83 92 CA BE E9 38 D7 B5 29 C0
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   81 28 9C B0 60 7D 6F 92 F7 C3 2B 2B F0 0E 77 9E
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   29 B4 B6 53 5F 08
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Answer from cardreader:
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   91 20
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] write to cardreader
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   D3 54 00 00 58
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Answer from cardreader:
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   E3 4A 94 8A CB A0 F1 76 0D 64 58 E9 2A 16 D4 A6
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   77 F0 8B 99 40 35 B1 15 A1 03 14 34 CD DA 63 34
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   32 FA 4C D1 79 6F D2 79 E6 D1 6B FA CB 92 C2 EB
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   16 C5 38 EB 85 47 16 81 89 18 AD 56 46 AA CA 03
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   25 5A F9 89 A3 D9 76 B6 C4 5A F4 C5 16 5E EF 2C
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   08 CA AD D5 31 3F 56 56 91 20
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Decrypted payload
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   xx xx xx xx xx xx xx xx 00 00 00 38 00 01 22 02
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   00 80 0E 02 01 00 0F 04 00 00 00 00 20 04 00 00
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   00 00 25 11 00 00 00 00 00 00 00 00 00 00 00 00
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   00 00 00 00 00 2A 04 00 38 00 00 55 01 83 56 08
2020/04/05 18:17:22 6BE5AEA0 r   (reader)   00 00 00 00 00 00 00 00
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] classD3 ins54: CW is crypted, trying to decrypt unique pairing mode 0x83
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] crypted CW is: xxxxxxxxxxxxxxxx0000000000000000
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] use k1(DES) for CW decryption in unique pairing mode
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] decrypted CW is: 17EA069B5800E0350000000000000000
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] cardreader_do_ecm: after csystem->do_ecm rc=1
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] cardreader_do_ecm: ret rc=1
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] cardreader_process_ecm: cardreader_do_ecm returned rc=1 (ERROR=0)
2020/04/05 18:17:22 6BE5AEA0 r   (reader) smargoV13 [videoguard2] ecm hash: 73621C2EBC783049797A9A8C4957C8D7 real time: 150 ms
2020/04/05 18:17:22 08C50957 c      (ecm) oscam (09C4&/0C25/1B52/007E/A7:73621C2EBC783049797A9A8C4957C8D7:0F06000000000000:17EA069B5800E0350000000000000000): found (152 ms) by smargoV13 - Syfy HD
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] write to cardreader
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   D1 5C 00 00 04
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Answer from cardreader:
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   11 0B 00 01 91 20
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] write to cardreader
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   D1 5E 00 0B 01
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Answer from cardreader:
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   03 90 20
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] write to cardreader
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   D1 78 03 00 18
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Answer from cardreader:
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   10 90 97 12 0F FF FF FF FF FF 01 10 90 97 12 0F
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   FF FF FF FF FF 01 8F 00 90 20
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] write to cardreader
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   D1 32 00 00 01 25
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] Answer from cardreader:
2020/04/05 18:17:26 6BE5AEA0 r   (reader)   90 20
2020/04/05 18:17:26 6BE5AEA0 r   (reader) smargoV13 [videoguard2] classD1 ins32: failed
2020/04/05 18:17:29 6BE5AEA0 r   (reader) smargoV13 [videoguard2] cardreader_do_ecm: cardreader_do_checkhealth returned rc=1

P.S. Sende ich so ein ECM (siehe Spoiler) nochmal, dann gibt es wieder normale ECM Zeit, SW 90 20, und ins5C ist ebenfalls "normal". Komisch, oder? Haben etwa auch Smartkarten "ihre dollen 5 Minuten"...?

 

[Reiner123]

das habe ich jetzt gerade aus meinem log raus gesucht. Glaube auch, das ist kein Zufall.

Spoiler

2020/04/05 10:36:30 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed
2020/04/05 10:48:06 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed

2020/04/05 22:36:33 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed
2020/04/05 22:48:09 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed

2020/04/07 02:36:26 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed
2020/04/07 02:48:14 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed

2020/04/07 06:36:27 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed
2020/04/07 06:48:03 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed

 

[parasonic]

Danke für das Feedback. Wurde die Karte zu den Zeiten benutzt also hat ECMs verarbeitet?

Bei mir war seit 5.4. nichts mehr, aber Karte bekommt hier auch eher sporadisch ECM...

 

[Reiner123]

beides, Karte aktiv und auch idle
Interessant ist doch die nahezu identische Uhrzeit die Minuten betreffend, und die gleichbleibende Dauer von ca. 12 min.

 

[satelli]

Ich lasse jetzt auch mal auf 2 Karten loggen.

 

[parasonic]

beides, Karte aktiv und auch idle

OK!? Bei mir fängt das definitiv immer nur in Momenten an, wo die Karte aktiv genutzt wird. Und hört nach ziemlich genau 11-12 Minuten wieder auf.
Fängt es bei Dir aus heiterem Himmel an, wenn Karte *komplett idle* (also auch zu Beginn des "Phänomens" idle)?
Also wenn ja, dann kann es mit ECM ja eigentlich gar nix zu tun haben. (OT: "heiterer Himmel"... lustiges Wortspiel...)

Und die Frage ob das nur v13er betrifft oder nicht... das ist definitiv NICHT so.
Habe es mittlerweile auch auf v14 gesehen, allerdings nur 8 Minuten lang die v14 ist halt schneller

Sehr komisch alles.

P.S. bei mir ist die Uhrzeit nicht statisch, sondern hängt eher an der Zeit wann ich die Karte "benutze"....

 

[Reiner123]

erst wieder selbe Minuten und aller 12 Stunden für 12 min! Zwar nicht 100% aber immerhin.

2020/04/07 14:36:27 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed
2020/04/07 14:48:03 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed

 

[parasonic]

Auf welchem Sender warst du als das los ging?

 

[Reiner123]

Das ist auch vollkommen egal, passiert auf allen und auch ohne Sender.

 

[satelli]

Wie meinst du "ohne Sender" ?
Ohne ECM/EMM ?

 

[parasonic]

Ist bei mir nicht so. Fängt hier immer nur dann an, wenn die Karte aktiv benutzt wird.
Naja, wenn es bei Dir wirklich aus "heiterem Himmel" los geht, dann wird's eher nicht von den ECM getriggert (das war meine Vermutung).
Dann wohl doch kein COVID-13, nochmal Glück gehabt :grinning:

EDIT: habe auch mal ältere Logs angeschaut. Bei der gleichen Karte passiert das tatsächlich *immer zu ähnlicher Minute*!
Andere Stunde, aber immer wieder der gleiche "Intervall"!

zieht man die die 12 Sekunden Oscam-Status-Check-Intervall in Betracht, dann sieht es fast immer gleich aus! Sehr komisch!

 

[Reiner123]

wird wohl irgendwo ein Bug in Oscam sein. Wenn die Karte aktiv ist, dann passiert das öfter:

2020/04/07 18:36:27 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed
2020/04/07 18:48:03 41A19F75 r (reader) V13 [videoguard2] classD1 ins32: failed

aber Min. Zeit identisch.

 

[parasonic]

ein Bug in Oscam

Nö das glaub ich nicht.
Das "Phänomen" hängt ja komplett von der Kartenantwort auf die 5C ab... Oscar tut genau was er tun soll...

 

[Reiner123]

also unsere Karten sind doch in Quarantäne? Zumindest meine. Woher hat die dann den Virus?

 

[parasonic]

:mask: Wird natürlich während Home-Office mehr genutzt als sonst. Hier HS-only.
Trotzdem komisch. Bin mal gespannt ob noch andere was dazu sagen.
Betrifft es die V13 mehr als neuere Karten...? Hier ja.