[VDR 2.6.1] SVDRP POLL TIMERS: timeout while waiting for response

  • Ich poste mein Thema von hier mit mehr Details nochmals in VDR Core in der Hoffnung, kls hat einen Tipp.

    Ich glaube inzwischen nicht mehr, dass das was mit epgd zu tun hat, außer vielleicht, dass er zusätzliche Last auf den svdrp Schnittstelle erzeugt und damit die Meldung häufiger kommt.

    Umgebung: Zwei vdr 2.6.1 Backends, die über Peering mit einander verbunden sind.

    Ich bekomme im 10-20 Minutentakt folgende Meldung ins Syslog:

    Code
    1. Jun 24 19:14:51 user.err VDR-2204 vdr: [439] SVDRP VDR-2204 < 10.1.5.143:6419 timeout while waiting for response from 'VDR-2204-Dev'
    2. Jun 24 19:14:51 user.err VDR-2204 vdr: [439] ERROR: can't send 'POLL VDR-2204 TIMERS' to 'VDR-2204-Dev'
    3. Jun 24 19:25:11 user.err VDR-2204 vdr: [439] SVDRP VDR-2204 < 10.1.5.143:6419 timeout while waiting for response from 'VDR-2204-Dev'
    4. Jun 24 19:25:11 user.err VDR-2204 vdr: [439] ERROR: can't send 'POLL VDR-2204 TIMERS' to 'VDR-2204-Dev'

    Ich habe mal versucht den Timeout näher zu analysieren (Syslog von der Gegenseite zum ersten Eintrag, mit zusätzlich eingebauten Meldungen):

    Dadurch, dass der MutexLock 5s braucht, gibt es auf der Gegenseite einen Timeout. Hochsetzen des Timeouts bringt nichts, dann braucht der MutexLock entsprechend länger ?!

    Ich habe nur Timeout zu POLL TIMERS im syslog, keine andern. Das Peering funktioniert aber ohne Einschränkungen, da der Befehl nur sporadisch in den Timeout läuft.

    Mit ist es nicht gelungen, rauszufinden, wer/was diesen Lock hält und warum genau für die Dauer des Timeouts. kls hast du einen Tipp, wo es hängt ?

    Als Anlage die Änderungen um die zusätzlichen Logs zu erzeugen.

    Files

    • logs.patch

      (5.59 kB, downloaded 19 times, last: )
    VDR
  • Ich glaube, ich habe den Auslösers des Timeouts gefunden: Das Problem tritt auf, wenn beide VDRs fast zeitgleich einen POLL TIMERS aufführen. Dann gibt es wohl einen Deadlock in irgendeinem Lock. Der Timeout des Clients löst ihn dann zwar auf, aber dann ist auch der Serverrequest so weit verzögert, dass die zugehörige Anfrage auch in den Timeout läuft. Damit bringt es auch nichts, den Timeout zu erhöhen.

    VDR1:

    VDR2:

    Ich suche noch nach einer Lösung, jegliche Hilfe oder Tipps sind willkommen.

    VDR
  • kls ,

    vielen Dank, dass du dir das nach deinem Urlaub anschaust.

    Mit der Ursache bin ich wohl auf der richtigen Spur, angehängter proof of concept reduziert die Timeouts um ca. Faktor 10. Ein kleiner Rest bleibt aber übrig. Ich nenne es bewusst nicht Fix, weil der Code so sicher nicht zur Übernahme geeignet ist. Dazu verstehe ich die Locks in svdrp immer noch zu wenig.

    Schönen Rest-Urlaub noch.

    Files

    • poc.patch

      (2.21 kB, downloaded 24 times, last: )
    VDR
  • Und hier noch eine bessere Variante, die jetzt alle Timeouts beseitigt. Die Idee dazu ist, bei einem Deadlock den Lock vom svdp Client Request aus timen zu lassen, um dann den Server Request bedienen zu können. Mit dem angehängten Patch habe ich jetzt seit 12h keinen Timeout mehr, es sind aber natürlich noch ein paar zusätzliche Debug Meldungen drin.

    Files

    • poc2.patch

      (3.36 kB, downloaded 29 times, last: )
    VDR