[vdr 2.4.6] ERROR: buffer overflow in cCaPidReceiver::Receive()

MegaV0lt · 22. Januar 2021

Code

Jan 21 16:21:19 vdr01 vdr[7700]: [10098] ERROR: buffer overflow in cCaPidReceiver::Receive()

Hab ich zufällig im Log gefunden. Das ganze ist beim Zappen über mehrere verschlüsselte Kanäle passiert, die nicht entschlüsselt werden.

Im Betrieb ist mir nichts weiter aufgefallen.

Hier ein Ausschnitt des Logs zu dem Zeitpunkt:

Code

Jan 21 16:21:10 vdr01 vdr[7700]: [7700] ChannelSid: 8015 Channel: TRACE LATINA
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] caid: 65535
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] cardsystem: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] reader: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] from: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] protocol: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] DvbapiInfoDraw
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] ChannelSid: 8015 Channel: TRACE LATINA
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] caid: 65535
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] cardsystem: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] reader: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] from: (null)
Jan 21 16:21:10 vdr01 vdr[7700]: [7700] protocol: (null)
Jan 21 16:21:15 vdr01 vdr[7700]: [7700] skinflatplus: create osd SUCCESS left: 0 top: 0 width: 1920 height: 1080
Jan 21 16:21:15 vdr01 vdr[7700]: [7700] imageloader LoadLogo: /usr/local/share/vdr/plugins/skinflatplus/logos//voyage obsolete.png could not be loaded
Jan 21 16:21:16 vdr01 vdr[2824]: Last message '[7700] imageloader L' repeated 1 times, suppressed by syslog-ng on vdr01
Jan 21 16:21:18 vdr01 vdr[7700]: [7700] switching to channel 661 S19.2E-1-1084-9414 (TRACE URBAN)
Jan 21 16:21:18 vdr01 vdr[7700]: [7700] CAM 1: unassigned from device 1
Jan 21 16:21:18 vdr01 vdr[7700]: [10050] device 1 TS buffer thread ended (pid=7700, tid=10050)
Jan 21 16:21:18 vdr01 vdr[7700]: [10049] buffer stats: 193452 (1%) used
Jan 21 16:21:18 vdr01 vdr[7700]: [10049] device 1 receiver thread ended (pid=7700, tid=10049)
Jan 21 16:21:18 vdr01 vdr[7700]: [7700] CAM 1: assigned to device 1
Jan 21 16:21:18 vdr01 vdr[7700]: [10098] device 1 receiver thread started (pid=7700, tid=10098, prio=high)
Jan 21 16:21:18 vdr01 vdr[7700]: [10099] device 1 TS buffer thread started (pid=7700, tid=10099, prio=high)
Jan 21 16:21:18 vdr01 vdr[7700]: audio/alsa: using pass-through device 'hw:NVidia,7'
Jan 21 16:21:18 vdr01 vdr[7700]: [7700] DVBAPI: 0.0 set CAM decrypt (SID 9414 (0x24C6), caLm 4, HasCaDescriptors 0)
Jan 21 16:21:18 vdr01 vdr[7700]: [7700] skinflatplus: create osd SUCCESS left: 0 top: 0 width: 1920 height: 1080
Jan 21 16:21:18 vdr01 vdr[7700]: audio/alsa: start delay 336ms
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] DvbapiInfoDraw
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] ChannelSid: 9414 Channel: TRACE URBAN
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] DvbapiInfoDraw
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] ChannelSid: 9414 Channel: TRACE URBAN
Jan 21 16:21:19 vdr01 vdr[7700]: [10098] ERROR: buffer overflow in cCaPidReceiver::Receive()
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] DvbapiInfoDraw
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] ChannelSid: 9414 Channel: TRACE URBAN
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] DvbapiInfoDraw
Jan 21 16:21:19 vdr01 vdr[7700]: [7700] ChannelSid: 9414 Channel: TRACE URBAN
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] DvbapiInfoDraw
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] ChannelSid: 9414 Channel: TRACE URBAN
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] retuning due to modification of channel 661 (TRACE URBAN)
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] switching to channel 661 S19.2E-1-1084-9414 (TRACE URBAN)
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] CAM 1: unassigned from device 1
Jan 21 16:21:20 vdr01 vdr[7700]: [10099] device 1 TS buffer thread ended (pid=7700, tid=10099)
Jan 21 16:21:20 vdr01 vdr[7700]: [10098] buffer stats: 189316 (1%) used
Jan 21 16:21:20 vdr01 vdr[7700]: [10098] device 1 receiver thread ended (pid=7700, tid=10098)
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] CAM 1: assigned to device 1
Jan 21 16:21:20 vdr01 vdr[7700]: [10110] device 1 receiver thread started (pid=7700, tid=10110, prio=high)
Jan 21 16:21:20 vdr01 vdr[7700]: [10111] device 1 TS buffer thread started (pid=7700, tid=10111, prio=high)
Jan 21 16:21:20 vdr01 vdr[7700]: audio/alsa: using pass-through device 'hw:NVidia,7'
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] DVBAPI: 0.0 set CAM decrypt (SID 9414 (0x24C6), caLm 4, HasCaDescriptors 1)
Jan 21 16:21:20 vdr01 vdr[7700]: [7700] skinflatplus: create osd SUCCESS left: 0 top: 0 width: 1920 height: 1080
Jan 21 16:21:21 vdr01 vdr[7700]: audio/alsa: start delay 336ms

Alles anzeigen

kls · 22. Januar 2021

Solange das nur ein einmaliges Ereignis war würde ich dem erstmal keine größere Bedeutung beimessen.

Sollte es wieder und reproduzierbar auftreten, melde dich bitte wieder.

MegaV0lt · 22. Januar 2021

OK. Werd ich machen

wirbel · 22. Januar 2021

Wäre interessant eine Warnung auszugeben, falls in ci.c:191 length > 1024. (oder buffer auf 4096 bytes zu vergrößern)

kls · 22. Januar 2021

In Zeile 121 heißt es, dass die CAT maximal 1024 Byte lang sein kann. Den Buffer zu vergrößern halte ich daher nicht für sinnvoll, da es ein eventuelles Problem wohl eher verschleiern würde.

Die Warnung fallls length > 1024 ist (da die Section-Length ja 12 Bit hat) wäre dagegen sicher sinnvoll.

MegaV0lt: magst du das mal testweise bei dir einbauen und versuchen, den Fall erneut zu forcieren?

wirbel · 22. Januar 2021

Die en-13818-1 sagt an der Stelle, dass section_length maximal 1021 bzw 0x3FD sein 'soll', aber eine Compliance zur Spec nicht gefordert wird.

kls · 22. Januar 2021

Interessant. OK, das würde natürlich für eine Vergrößerung des Buffers sprechen.

wirbel · 22. Januar 2021

Diff

--- ci.c.orig   2021-01-22 16:00:21.403430549 +0100
+++ ci.c        2021-01-22 16:02:32.406932688 +0100
@@ -189,6 +189,7 @@
      if (TsPayloadStart(Data)) {
         if (Data[5] == SI::TableIdCAT) {
            length = (int(Data[6] & 0x0F) << 8) | Data[7]; // section length (12 bit field)
+           if (length > 0x3FD) esyslog("ERROR: UNEXPECTED: CAT section_length = %d", length);
            if (length > 5) {
               int v = (Data[10] & 0x3E) >> 1; // version number
               if (v != catVersion) {

HelmutB · 22. Januar 2021

Ob es nicht einfach nur ein Datenfeher war? Ich habe die aktuelle CAT auf 12090V (TRACE URBAN / SID 9414) als Hexdump.

Sie ist 221 Bytes gross.

Code

Jan 22 16:05:25 ... vdr[10123]: switching to channel 1196 S19.2E-1-1084-9414 (TRACE URBAN)
...
Jan 22 16:05:27 ... vdr[10123]: //// CAT: len 221/DD ///
Jan 22 16:05:27 ... vdr[10123]: 0x000000: 47 40 01 1c 00 01 b0 dd ff ff d5 00 00 09 07 18   G@....°ÝÿÿÕ.....
Jan 22 16:05:27 ... vdr[10123]: 0x000010: 11 f4 49 02 fe 22 09 07 18 11 f6 4e 02 33 41 09   .ôI.þ"....öN.3A.
Jan 22 16:05:27 ... vdr[10123]: 0x000020: 07 18 11 f6 47 02 33 17 09 07 18 11 f6 46 02 33   ...öG.3.....öF.3
Jan 22 16:05:27 ... vdr[10123]: 0x000030: 15 09 07 18 11 f6 45 02 33 11 09 0b 18 63 f6 50   .....öE.3....cöP
Jan 22 16:05:27 ... vdr[10123]: 0x000040: 06 33 41 33 42 33 43 09 0b 18 83 f6 5d 06 33 41   .3A3B3C....ö].3A
Jan 22 16:05:27 ... vdr[10123]: 0x000050: 33 11 33 15 09 0c 05 00 f6 9e 13 01 20 14 03 04   3.3.....ö... ...
Jan 22 16:05:27 ... vdr[10123]: 0x000060: 28 20 09 0c 05 00 f6 8d 13 01 20 14 03 03 29 20   ( ....ö... ...) 
Jan 22 16:05:27 ... vdr[10123]: 0x000070: 09 0c 05 00 f6 99 13 01 20 14 03 03 29 20 09 0c   ....ö... ...) ..
Jan 22 16:05:27 ... vdr[10123]: 0x000080: 05 00 f6 8f 13 01 20 14 03 03 29 40 09 11 05 00   ..ö... ...)@....
Jan 22 16:05:27 ... vdr[10123]: 0x000090: f6 88 13 01 20 14 03 02 36 00 14 03 06 0e 00 09   ö... ...6.......
Jan 22 16:05:27 ... vdr[10123]: 0x0000a0: 11 05 00 f6 8c 13 01 20 14 03 03 0b 00 14 03 03   ...ö... ........
Jan 22 16:05:27 ... vdr[10123]: 0x0000b0: 28 30 09 0c 05 00 f6 94 13 01 20 14               (0....ö... .
Jan 22 16:05:27 ... vdr[10123]: //// CAT: len 41/29 n 41/29 ///
Jan 22 16:05:27 ... vdr[10123]: 0x000000: 47 00 01 1d 03 04 33 30 09 0c 05 00 f6 9d 13 01   G.....30....ö...
Jan 22 16:05:27 ... vdr[10123]: 0x000010: 20 14 03 05 1b 00 09 11 05 00 f5 86 13 01 20 14    .........õ... .
Jan 22 16:05:27 ... vdr[10123]: 0x000020: 03 04 26 30 14 03 06 0d 00 29 4c 28 1a ff ff ff   ..&0.....)L(.ÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000030: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000040: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000050: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000060: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000070: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000080: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x000090: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x0000a0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff   ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: 0x0000b0: ff ff ff ff ff ff ff ff ff ff ff ff               ÿÿÿÿÿÿÿÿÿÿÿÿ
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5193 (1449) to 259 (0103)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5710 (164E) to 260 (0104)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5703 (1647) to 261 (0105)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5702 (1646) to 262 (0106)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5701 (1645) to 263 (0107)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5712 (1650) to 264 (0108)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5725 (165D) to 265 (0109)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5790 (169E) to 266 (010A)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5773 (168D) to 267 (010B)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5785 (1699) to 268 (010C)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5775 (168F) to 269 (010D)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5768 (1688) to 270 (010E)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5772 (168C) to 271 (010F)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5780 (1694) to 272 (0110)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5789 (169D) to 273 (0111)
Jan 22 16:05:27 ... vdr[10123]: CAM 1/1: mapped PID 5510 (1586) to 274 (0112)

Alles anzeigen

LG Helmut

MegaV0lt · 22. Januar 2021

kls

Mach ich gerne. Allerdings geht das erst wieder ab Montag. Wenn es hilft, kann ich auch den 2.5.1er VDR drauf machen...

PS: Datenfehler kann schon sein. Passiert beim durchprobieren / Zappen

HelmutB · 22. Januar 2021

Möglicherweise war ein unerwartetes 'PayLoadStart' mit einer noch unvollständigie Multi-Packet CAT die Ursache.

Wenn hier nun ein Paket mit 'PayLoadStart' eintrifft, wird 'length' wieder auf die CAT-Gesamtlänge gesetzt, 'pbuf' bleibt aber - bei gleicher 'catVersion' - unverändert. Das Ganze läuft dann asynchron weiter - das 2. Paket schiebt 'pbuf* weiter, 'length' wird dabei aber nicht 0. Dann wieder das 1. Paket, ändert nur 'length' usw. Nach ein paar Durchäufen ist der Buffer voll.

Mit MTD wird außerdem nur diese unvollständige CAT an das CAM übertragen.

Hier ein Patch, der diesen Fehler verhindern sollte:

Diff

--- a/ci.c.orig    2020-08-17 12:26:18.000000000 +0200
+++ b/ci.c    2021-01-22 21:23:31.763380083 +0100
@@ -188,6 +188,11 @@ void cCaPidReceiver::Receive(const uchar
      const uchar *p = NULL;
      if (TsPayloadStart(Data)) {
         if (Data[5] == SI::TableIdCAT) {
+           if (bufp) {
+              dsyslog("CAT: skip incomplete multi-packet CAT"),
+              catVersion = -1;
+              bufp = NULL;
+              }
            length = (int(Data[6] & 0x0F) << 8) | Data[7]; // section length (12 bit field)
            if (length > 5) {
               int v = (Data[10] & 0x3E) >> 1; // version number

Alles anzeigen

Da ich Multi-packet CATs nur bei französischen (CSAT) und spanischen Providern gesehen habe, wird sich die ordnungsgemässe Funktion aber gar nicht so leicht feststellen lassen.
LG Helmut

MegaV0lt · 25. Januar 2021

Hab jetzt den VDR 2.51 mit dem Patch vdr-2.4.6-fix-incomplete-multipacket-cat.patch drauf. Bis jetzt konnte ich die Meldung nicht mehr Provozieren...

[vdr 2.4.6] ERROR: buffer overflow in cCaPidReceiver::Receive()

Jetzt mitmachen!

Teilen