Mandelbug auf die Schliche kommen

[Medium]

Ich habe in einem unserer Programme ein verflucht ekeliges Problem, dass einem Mandelbug fast nahe kommt. (Ein wenig Heisenbug ist auch dabei, da das Problem im Debugger noch nie auftauchte bisher.)

Letztlich ist das Problem, dass das Programm einfach irgendwann mitten drin einfach stehen bleibt, und nicht mehr reagiert. Dies tut es vornehmlich dann, wenn es gerade nicht bedient wird (hab ich aber auch schon gesehen). Es ist keine Endlosschleife - ich vermute hier eher ein böses Zusammenspiel aus Sockets, Threads und VCL, obgleich ich schon sehr aufgepasst habe Critical Sections entsprechend einzusetzen. Interessant ist vor allem, dass das Problem auf manchen Rechnern sehr oft vorkommt, auf anderen hingegen noch nie beobachtet wurde :?

Interessant ist vor allem, dass das Programm teils über Tage am Stück ohne zu murren immer ein und die selbe Tätigkeit ausführt, und irgendwann aus dem Nichts heraus knallt es dann. Keiner war am PC, die vom Programm verarbeiteten Daten sind immer gleichförmig (ein paar Werte aus einer SPS darstellen), keine sonstigen besonderen Umstände. Einfach "puff".
Im Taskmanager hat das Programm dann 0% CPU Last, normal viel Speicher, und die gewohnte Anzahl Threads und andere Resourcen. Es scheint also zumindest schon mal nichts "überzulaufen".

Da ich keinem zumuten kann das Teil für mich zu debuggen, würde ich gerne ein paar Ideen einholen, wie ich der Sache am besten Herr werden könnte. Insbesondere ist problematisch dabei, dass ich das Problem auf meinem Entwicklungs-PC einfach nicht habe! Zur Zeit hätte ich aber noch übers Wochenende einen PC vom Kunden hier, bei dem es recht zuverlässig zumindest 3-4 Mal am Tag passiert, so dass das die Gelegenheit wäre.

Wie debugged man so etwas so, dass man zumindest schon mal grob weiss, in welchem Modul man überhaupt anfangen müsste nach dem konkreten Problem zu suchen?

[Elvis]

Verpacke deine critical sections in eine eigene Klasse. Wann immer jemand ein lock will, starte einen Timeout (fast vollkommen egal wie du den implementierst) . Wenn der abläuft, wirf eine Exception. Denn lange laufende locks sind fast immer ein Indikator für ein deadlock.
Wenn du (conditional compiling nur für debug builds!) in deiner CriticalSection-Implementierung eine Liste aller aktuell offenen locks vorhältst, kannsu einfacher sehen wo sich die Schlange in den Schwanz beißt.

[Medium]

Das ist schon mal eine gute Idee, die ich auch gerade fix umgesetzt habe. Danke! Mal sehen, ob da ggf. schon mehr zu sehen ist. Ich hoffe, dass mein Problem-PC fix wieder "Mist" macht :)

[divBy0]

So ein ähnliches Problem hatte ich bei einer unsere Visualisierungen auch mal. Es hatte damals nur einen PC betroffen, auf allen anderen lief es problemlos. Nach längerer Standzeit kam die Meldung "Programm funktioniert nicht mehr", ohne Fehlermeldung, ohne Exception, ohne Logeintrag.
Ich hatte mir per Syslog dann viele, viele Meldung ausgeben lassen (in Threads, CriticalSections, DB-Zugriffen, Indy TCP, usw.)und im Endeffekt hatte das Problem mit dem DHCP-Server des Kunden zu tun, da dieser aus irgendeinem Grund immer zwei verschiedene IP-Adressen verteilt hatte. Die Verbindung zur SPS fand das nicht so toll... Nach Umstellung auf feste IP-Adressen (wie es bei allen Kunden üblich ist) gab es keine Probleme mehr.

[Medium]

Der Hänger trat wieder auf, jedoch leider nicht in einer CS - der Timeout kam nicht. Die SPS-Verbindung macht ein separates Programm, dass die Daten in eine DB schaufelt, und die Clients (die Problemkinder) via Socket auf neue Daten aufmerksam macht. Die Clients lesen diese daraufhin aus der DB und versorgen die nötigen Controls.

Detailexkurs: Das Lesen aus der DB passiert dabei in je einem Thread pro Anlagenbild. Der Lesethread füllt (eine per CS geschützte) Liste an Controls die Updates bekommen, mitsamt der neuen Werte und der Properties. Dann wird dem Formular eine Message geposted, woraufhin dieses dann im Mainthread Kontext diese Liste (ebenfalls innerhalb der CS) abarbeitet bis sie leer ist.
Genau diese Update-Routine habe ich jetzt mit ausgiebigem Logging bestückt, um zu schauen ob sich da nicht ggf. ein Control verschluckt. Zuvor hatte ich meine Socketkommunikation "verloggt", da hier ebenfalls Listen in einer CS befüllt werden. Hier lief aber bis zum Hänger alles sauber.

Die SPS (bzw. alles in dem Netz) hat statische IPs, damit sind wir auch schon sonst zu oft auf die Nase gefallen :)

[Medium]

Joa, so als kleine Rückmeldung hier: Es ist doch ein voll ausgewachsener Heisenbug. Seit meinem letzten Beitrag läuft das Programm nun durchgehend ohne weiteres Auftreten des Problems. Da ich die Kiste morgen wieder abgeben muss, heisst das wohl erst Mal Logfile Größe begrenzen, und sie mit aktivem Logging in dieser Routine ausliefern. Entweder ist das dann ein mir Bauchweh bereitender Quasi-Fix (:?), oder irgend wann passiert es dann doch noch mal und liefert eine brauchbare Stelle zum Weiterforschen. Himmel, wie ich so einen Murks hasse! Danke dennoch schon mal euch beiden.

[Zacherl]

Eventuell tritt das Problem auch in einer CriticalSection auf, die du gar nicht selbst erstellst, sondern indirekt von den Socket Komponenten verwendet wird, etc. Du könntest mal die RtlEnterCriticalSection() und RtlLeaveCriticalSection() APIs hooken und dort den Timeout implementieren. Dann bekommst du zu hundert Prozent auch DeadLocks mit, die durch Fremdkomponenten oä. erzeugt werden.

[Sir Rufo]

Diese Art von Fehlern haben aber auch die Eigenart manchmal durch ein Logging zu verschwinden.

Vorher konnten alle Threads ungehindert wuseln und sich verknoten, mit dem Logging wird aber u.U. dort eine gewisse Ordnung geschaffen.

Nehmen wir mal an du loggst in eine Datei.
Damit immer nur ein Thread schreibt, nimmt man eine CS und schon hat man dem System eine andere Ordnung aufgezwungen, wo der Fehler evtl. nicht mehr auftaucht oder die Wahrscheinlichkeit erheblich reduziert wird.

[Morphie]

Könnte man nicht mittels Remote Debugger nachsehen wo es knallt?

[Medium]

@Zacherl: Die Socket-Kommunikation scheint nach aktuellen Erkenntnissen als Übeltäter auszuschließen zu sein. Es ist auch nur ein einfacher TClientSocket ohne Aufbauten und Schickschnack. Den würde ich vorerst als unschuldig und abgehakt ansehen glaube ich.

@Sir Rufo: Das war eine Befürchtung die ich hatte, wobei die CS-Struktur in etwa so aussieht:

Code:

procedure UpdateVCLControls;
begin
  EnterUpdateCS;
  try
    while UpdateList.Count > 0 do
    begin
      try
        LogSomething;
        DoSometingWithUpdateListItem(0);
        LogSomething;
        DoSometingWithUpdateListItem(0);
        ...
      finally
        UpdateList.Delete(0);
      end;
    end;
  finally
    LeaveUpdateCS;
  end;
end;

procedure LogSomething;
begin
  EnterLogCS;
  try
    Log;
  finally
    LeaveLogCS;
  end;
end;

Das Anfügen an die UpdateList würde daher imho durch die CS des Loggings eigentlich nicht weiter beeinflusst werden, da diese immer nur betreten und verlassen wird, während die UpdateList ohnehin schon gelockt ist. Dennoch: Lasse ich die LogSomething-Aufrufe weg, habe ich wieder meine sporadischen Hänger.

Die UpdateList ist eine TObjectList (OwnsObjects=true), die Items dieser Klasse trägt:

Delphi-Quellcode:

  TVCLUpdateData = class
  public
    Instance: TObject;
    ClassType: TClass;
    PropName: String;
    Value: Variant;
    constructor Create(aInstance: TObject; aType: TClass; aPropName: String; aValue: Variant);
  end;

Der UpdateThread füllt diese Liste anhand neuer Daten aus der Datenbank, wobei die Komponenten anhand ihres Names per FindComponent() ausfindig gemacht wurden (und auch die gesamte Programmdauer existieren). Es sind geprüfterweise immer gültige Referenzen.
Die Update-Loop (die Prozedur oben im Pseudocode) macht letztlich innerhalb der while-Schleife nur dieses:

Delphi-Quellcode:

SetPropValue((item.Instance as item.ClassType), item.PropName, item.Value);

(Mit zuvoriger Prüfung, ob item.Value ungleich NULL ist und die Instanz wirklich vom Typ "ClassType" ist.) "item" wird zuvor

Delphi-Quellcode:

UpdateList[0] as TVCLUpdateData

zugewiesen.
Die Update-Loop wird per PostMessage() vom UpdateThread angestoßen, nachdem dieser alle im aktuellen Zyklus anstehenden Updates gesammelt hat.

@Morphie: Leider bleibt der Debugger nicht an einer sinnvollen Stelle stehen. Da das Problem offenbar keine Exception auslöst, und ich nicht 6h durchsteppen kann bis der Fehler freundlicherweise mal auftritt (und es dann vermutlich auch nicht tut), hatte ich das aufgegeben :?