[skindesigner] Segfault bei schnellem Scrollen durch Aufnahmen wenn HDD noch nicht aufgewacht ist

Zitat von MarkusE

Du kannst mal im syslog nach "ERROR:" suchen, ev. findest Du da etwas relevantes.

Du kannst VDR patchen: in recordings.c

Code

for (cRecording *Recording = recordings->First(); Recording; ) {
         cRecording *r = Recording;
         Recording = recordings->Next(Recording);
         if (access(r->FileName(), F_OK) != 0)
            recordings->Del(r);
         }

Hier vor

Code

recordings->Del(r);

Die Ausgabe einer Meldung im syslog einbauen. Z.B.:

Code

esyslog("Delete recording %s", r->Name() );

Und dann im syslog nach "Delete recording" suchen.

Ev. dann noch in tools.c, in

Code

void cListGarbageCollector::Purge(bool Force)
{
  mutex.Lock();
  if (objects && (time(NULL) - lastPut > LIST_GARBAGE_COLLECTOR_TIMEOUT || Force)) {
     // We make sure that any object stays in the garbage collector for at least
     // LIST_GARBAGE_COLLECTOR_TIMEOUT seconds, to give objects that have pointers
     // to them a chance to drop these references before the object is finally
     // deleted.
     while (cListObject *Object = objects) {
           objects = Object->next;
           delete Object;
           }
     }
  mutex.Unlock();
}

Alles anzeigen

vor "delete Object" ein

Code

esyslog("Delete garbage collector object");

Alles anzeigen

Das schaue ich mir als Nächstes mal an.

Beim Üben im Umgang mit esyslog habe ich in epg.c mal paar Meldungen eingebaut:

tComponent *cComponents::GetComponent(int Index, uchar Stream, uchar Type)
{
esyslog("Index: %i Stream: %i Type: %i numComponents: %i", Index, Stream, Type, numComponents );
  for (int i = 0; i < numComponents; i++) {
esyslog("i: %i components.stream: %i components.type: %i", i, components[i].stream, components[i].type );
      if (components[i].stream == Stream && (
          Type == 0 || // don't care about the actual Type
          Stream == 2 && (components[i].type < 5) == (Type < 5) // fallback "Dolby" component according to the "Premiere pseudo standard"
         )) {
         if (!Index--)
            return &components[i];
         }
      }
  return NULL;
}

Der bt wirft jetzt Folgendes raus:

Thread 84 "detacher thread" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fe5a3e7b640 (LWP 3279)]
0x0000561f7e54d20b in cComponents::GetComponent (this=this@entry=0x561f804afa50, Index=Index@entry=0, Stream=Stream@entry=9 '\t', Type=Type@entry=0 '\000') at epg.c:101
101     esyslog("i: %i components.stream: %i components.type: %i", i, components[i].stream, components[i].type );
(gdb) bt full
#0  0x0000561f7e54d20b in cComponents::GetComponent(int, unsigned char, unsigned char) (this=this@entry=0x561f804afa50, Index=Index@entry=0, Stream=Stream@entry=9 '\t', Type=Type@entry=0 '\000') at epg.c:101
        i = 0
#1  0x00007fe5ad70280c in RecordingIsHD(cEvent const*, tChannelID) (event=event@entry=0x7fe59c5673a0, channelID=...) at coreengine/viewelement.c:604
        Component = <optimized out>
        Components = 0x561f804afa50
        isHD = false
        type = -1
#2  0x00007fe5ad743f90 in cCeMenuRecordings::Parse(bool) (this=0x561f7eb57fa0, forced=<optimized out>) at coreengine/listelements.c:2245
        startTime = 1499573400
        sStartTime = <optimized out>
        duration = 75
        isFolder = <optimized out>
        name = "\v\200\024\037\032V"
        buffer = "\v\200\024\037\032V"
        folderName = <incomplete type>
        usedRecording = 0x561f80e63ed0
        percSeen = <optimized out>
        framesSeen = <optimized out>
        framesTotal = <optimized out>
        recDuration = <optimized out>
        event = 0x7fe59c5673a0
        info = 0x561f80c08880
        channelID = {source = 509021960, nid = 22042, tid = 1073, sid = 28228, rid = 0, static InvalidID = {source = 0, nid = 0, tid = 0, sid = 0, rid = 0, static InvalidID = <same as static member of an already seen type>}}
        recDate = {_vptr.cString = 0x561f7e65c5e0 <vtable for cString+16>, s = 0x7fe59c565ef0 "So. 09.07.2017"}
        recTime = {_vptr.cString = 0x561f7e65c5e0 <vtable for cString+16>, s = 0x7fe59c567720 "06:10"}
        errors = 0
#3  0x00007fe5ad6d3dd1 in cDetacher::Action() (this=0x561f7fb3ff20) at coreengine/animation.c:48
#4  0x0000561f7e5d4131 in cThread::StartThread(cThread*) (Thread=0x561f7fb3ff20) at thread.c:293
#5  0x00007fe5aebcd84a in  () at /lib64/libc.so.6
#6  0x00007fe5aec50cec in  () at /lib64/libc.so.6

Das syslog spricht jetzt bis zum Crash Folgendes:

Sep  2 19:37:56 vdr vdr[2910]: [2910] Index: 0 Stream: 7 Type: 0 numComponents: 6
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 0 components.stream: 1 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 1 components.stream: 2 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 2 components.stream: 2 components.type: 72
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 3 components.stream: 3 components.type: 32
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 4 components.stream: 2 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 5 components.stream: 3 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] Index: 0 Stream: 1 Type: 0 numComponents: 6
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 0 components.stream: 1 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] Index: 0 Stream: 5 Type: 0 numComponents: 6
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 0 components.stream: 1 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 1 components.stream: 2 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 2 components.stream: 2 components.type: 72
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 3 components.stream: 3 components.type: 32
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 4 components.stream: 2 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 5 components.stream: 3 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] Index: 0 Stream: 9 Type: 0 numComponents: 6
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 0 components.stream: 1 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 1 components.stream: 2 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 2 components.stream: 2 components.type: 72
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 3 components.stream: 3 components.type: 32
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 4 components.stream: 2 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [2910] i: 5 components.stream: 3 components.type: 3
Sep  2 19:37:56 vdr vdr[2910]: [3279] detacher thread thread started (pid=2910, tid=3279, prio=high)
Sep  2 19:37:56 vdr vdr[2910]: [3279] Index: 0 Stream: 9 Type: 0 numComponents: 509021215

Auffällig ist der Wert numComponents der völlig aus der Reihe tanzt.

Zitat von MarkusE

Sag ich doch, da liegt was im Argen ...

Bau doch mal meine Meldungen ein

Mache ich als Nächstes.

Es laufen bloß gerade paar Aufnahmen.

Da spiele ich lieber nicht am System.

Zitat von MarkusE

Du kannst mal im syslog nach "ERROR:" suchen, ev. findest Du da etwas relevantes.

Du kannst VDR patchen: in recordings.c

Code

for (cRecording *Recording = recordings->First(); Recording; ) {
         cRecording *r = Recording;
         Recording = recordings->Next(Recording);
         if (access(r->FileName(), F_OK) != 0)
            recordings->Del(r);
         }

Hier vor

Code

recordings->Del(r);

Die Ausgabe einer Meldung im syslog einbauen. Z.B.:

Code

esyslog("Delete recording %s", r->Name() );

Und dann im syslog nach "Delete recording" suchen.

Ev. dann noch in tools.c, in

Code

void cListGarbageCollector::Purge(bool Force)
{
  mutex.Lock();
  if (objects && (time(NULL) - lastPut > LIST_GARBAGE_COLLECTOR_TIMEOUT || Force)) {
     // We make sure that any object stays in the garbage collector for at least
     // LIST_GARBAGE_COLLECTOR_TIMEOUT seconds, to give objects that have pointers
     // to them a chance to drop these references before the object is finally
     // deleted.
     while (cListObject *Object = objects) {
           objects = Object->next;
           delete Object;
           }
     }
  mutex.Unlock();
}

Alles anzeigen

vor "delete Object" ein

Code

esyslog("Delete garbage collector object");

Alles anzeigen

Ich habe beide Meldungen eingebaut.

Bei einem Test, ohne tvscraper, der zum Absturz führte, sind diese Meldungen nicht im syslog aufgetreten.

Ich habe in skindesigner die problematischen Funktionen deaktiviert und noch einmal mit tvscraper getestet.

Damit kein Absturz jedoch auch keine der eingebauten Meldungen...

Danke MarkusE

Ich werde Versuchen, den Code zu verstehen und dem Problem mit dem skindesigner auf die Spur zu kommen...

Zitat von kamel5

heifisch ,

kannst Du bitte mal den beigefügten Patch für skindesigner bei Dir einspielen und schauen, ob es dann noch an der gleichen Stelle abstürzt.

Durch den Patch wird die Funktion "RecordingIsHD()" etwas umgebaut, so das hier während des Aufrufes von "cComponents" ein LOCK_RECORDINGS_READ gehalten wird. Somit sollte zumindest die betroffene Recording während der Wartezeit nicht mehr verschwinden. Vielleicht bringt uns das ja etwas weiter oder bringt eine bessere Fehlermeldung.

Die anderen Abfragen sind von dem Patch nicht betroffen.

Alles anzeigen

Mache ich, dauert nur ein wenig.

Bezüglich der <optimized out> Meldungen im bt wollte ich mal wissen was da stehen würde und habe gemäß dem mal die Optimierungs-Flags von -O2 auf -O0 gesetzt.

Damit konnte ich aber den Absturz nicht reproduzieren.

Dabei ist mir aufgefallen, dass die Flags in meinem System nicht so gesetzt waren, wie ich es eigentlich wollte.

Ich baue gerade mein System neu mit folgenden Flags:

-march=native -O2 -pipe -ftree-vectorize -fomit-frame-pointer

Ich hoffe, dass ich im Anschluss den Absturz reproduzieren kann um dann zu testen, ob Dein Patch hilft das Problem zu beseitigen.

Im Notfall muss ich die relevanten Sachen mit den alten Flags noch mal bauen...

Ich melde mich wenn ich neue Erkenntnisse habe.

Vielen Dank und Gruß

Heiko

Zitat von kamel5

Wenn Du das dann testest, kannst Du bitte mal noch folgendes prüfen:

Wenn im Aufzeichnungsmenü eine Aufnahme markiert ist und die Platte nicht läuft, mal mit der blauen Taste die Info-Seite aufrufen. Gibt es dann auch einen Absturz? Dabei werden die gleichen Funktionen benutzt.

Erstmal hierzu:

Nach der Kompilier-Orgie konnte ich die Abstürze wieder mit der beschrieben Vorgehensweise reproduzieren.

- Platte in Standby,

- Taste rot für Aufnahmemenü und Taste ok um in das Verzeichnis zu kommen an das die HDD gemountet ist,

- Taste Down gedrückt halten,

Der Absturz kommt nicht immer und wenn, dann bei verschiedenen Aufnahmen.

Manchmal nach mehreren Versuchen, kann ich auch durch die gesamte Liste scrollen ohne Absturz.

Dann muss ich den VDR neu starten oder rebooten.

Beim Test mit der blauen Taste konnte ich keinen Absturz provozieren.

Das heißt aber nicht, dass er auf diesem Weg nicht auftreten könnte.

Hier entsteht ja nicht so viel "Stress" wie beim Scrollen durch die Aufnahme-Liste.

Lediglich das OSD wird komplett schwarz bis die Platte hoch gelaufen ist und es wird die Info-Seite korrekt angezeigt.

Zitat von kamel5

heifisch ,

kannst Du bitte mal den beigefügten Patch für skindesigner bei Dir einspielen und schauen, ob es dann noch an der gleichen Stelle abstürzt.

Durch den Patch wird die Funktion "RecordingIsHD()" etwas umgebaut, so das hier während des Aufrufes von "cComponents" ein LOCK_RECORDINGS_READ gehalten wird. Somit sollte zumindest die betroffene Recording während der Wartezeit nicht mehr verschwinden. Vielleicht bringt uns das ja etwas weiter oder bringt eine bessere Fehlermeldung.

Die anderen Abfragen sind von dem Patch nicht betroffen.

Alles anzeigen

Mit diesem Patch gibt es keinen Absturz mehr bei der Funktion "RecordingIsHD()".

Wie erwartet, jedoch in der Funktion "RecordingIsUHD().

bt:

Thread 63 "detacher thread" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7f51f4c7a640 (LWP 3249)]
0x000055f04a7b33fc in cComponents::GetComponent (this=<optimized out>, Index=Index@entry=0, Stream=Stream@entry=9 '\t', Type=Type@entry=0 '\000') at epg.c:100
100           if (components[i].stream == Stream && (
(gdb) bt full
#0  0x000055f04a7b33fc in cComponents::GetComponent(int, unsigned char, unsigned char) (this=<optimized out>, Index=Index@entry=0, Stream=Stream@entry=9 '\t', Type=Type@entry=0 '\000') at epg.c:100
        i = <optimized out>
#1  0x00007f51fe72c3d6 in RecordingIsUHD(cEvent const*, tChannelID) (event=event@entry=0x55f060473030, channelID=...) at coreengine/viewelement.c:689
        Component = <optimized out>
        Components = <optimized out>
        isUHD = false
        type = -1
#2  0x00007f51fe76e940 in cCeMenuRecordings::Parse(bool) (this=0x55f04cacc810, forced=<optimized out>) at coreengine/listelements.c:2245
        startTime = 1564094400
        sStartTime = <optimized out>
        duration = <optimized out>
        isFolder = <optimized out>
        name = "c1A?\365U"
        buffer = "c1A?\365U"
        folderName = <incomplete type>
        usedRecording = 0x55f060473710
        percSeen = <optimized out>
        framesSeen = <optimized out>
        framesTotal = <optimized out>
        recDuration = <optimized out>
        event = 0x55f060473030
        info = 0x55f04e3508b0
        channelID = {source = 289834144, nid = 22005, tid = 33, sid = 51, rid = 0, static InvalidID = {source = 0, nid = 0, tid = 0, sid = 0, rid = 0, static InvalidID = <same as static member of an already seen type>}}
        recDate = {_vptr.cString = 0x55f04a8bc5c0 <vtable for cString+16>, s = 0x7f51ec55efd0 "Fr. 26.07.2019"}
        recTime = {_vptr.cString = 0x55f04a8bc5c0 <vtable for cString+16>, s = 0x7f51ec568520 "00:40"}
        errors = 0
#3  0x00007f51fe6fd781 in cDetacher::Action() (this=0x55f04e337d50) at coreengine/animation.c:48
#4  0x000055f04a834f21 in cThread::StartThread(cThread*) (Thread=0x55f04e337d50) at thread.c:293
#5  0x00007f51ffbfb48a in  () at /lib64/libc.so.6
#6  0x00007f51ffc7e29c in  () at /lib64/libc.so.6

Also scheint der Patch das Problem zumindest in der Funktion "RecordingIsHD()" zu lösen.

Sieht gut aus!

Ich habe jetzt einige Routinen durchgeführt, die vor dem Patch zu einem Absturz führten, jedoch konnte ich damit keinen Absturz mehr provozieren.

Ich behalte das weiter im Auge.

Vielen Dank für die schnelle Lösung!

Gruß

Heiko

Zitat von kamel5

Die Änderung habe ich vorerst hier im develop Branch commited:

gitlab.com/kamel5/skindesigner

Bitte testen. Wenn sich keine Auffälligkeiten ergeben, werde ich das dann im Oktober in den master Branch übernehmen.

Läuft schon seit gestern Abend...

Vielen Dank noch mal!

edit:

Ich sehe gerade,Du hast noch was dran gemacht?

Das würde ich heute Abend noch einmal aktualisieren...

Zitat von MarkusE

Ich bin ja glücklich, dass ihr den Fehler korrigieren konntet.

Auch wenn ich es nicht verstehe.

Wenn VDR die c++ Objekte löscht, hätte es (mit meinem Patch) dafür eigentlich Einträge im Log geben müssen.

Und wenn VDR die c++ Objeckte nicht löscht, dann ist das Sperren eigentlich nicht notwendig.

Na ja, vieleicht habe ich ja etwas übersehen, oder VDR löscht die c++ Objekte an einer anderen Stelle ...

Soll ich da noch einmal in die Spur gehen?