Loggen mit Anzeige in Programm mit mehreren Threads

[s.h.a.r.k]

Guten Abend zusammen ;)

ich habe im Moment das Problem, dass mein Programm immer wieder ein einen Deadlock rein läuft, da auf der Synchronize()-Methode auf den MainThread gewartet wird, dieser aber gerade im Zustand wartend ist, da er auf die Freigabe einer CriticalSection wartet. Hier nochmal der Ablauf, wie ich glaube, dass er zum Deadlock führt:

1. Thread (ungleich MainThread) betritt Methode Log() und tritt in CriticalSection ein.
2. MainThread will auch einen Log-Eintrag schreiben, muss aber wohl warten, da sich schon ein Thread in der CriticalSection befindet.
3. In der Thread-Methode werden EventListener benachrichtigt, was via Synchronize gemacht wird, da unter Umständen visuelle Komponenten benachrichtigt werden können.
4. Da der MainThread gerade noch auf die Zuteilung wartet, kann dieser die Benachrichtigungen nicht abarbeiten -> Deadlock

Habt ihr auch eine entsprechende Log-Klasse?! Welche Lösungen nutzt ihr?

Man könnte es ja via Messages lösen, wobei ich dann wieder das Problem mit der Speicherfreigabe habe, da ich ja einen Record verschicke und ich nicht voraussetzen will, dass der EventListener den Record freigibt oder darin ein Flag im Record setzt. Ebenso würde dann das EventDispatcher/-Listener-Konzept nicht mehr so recht aufgehen und ich müsste alles überarbeiten.

Bisher habe ich leider noch keine andere Idee, wie ich das Problem lösen kann... Bin echt froh um jeden Gedanken.

[sx2008]

Wie sieht denn die Log-Methode aus?
Im Prinzip müsste das so aussehen:

Delphi-Quellcode:

procedure TLogger.LogMessage(const msg:string);
begin
  EnterCriticalSection(FCriticalSection); 
  try  
    InternalLogMessage(msg);
  finally
    LeaveCriticalSection(FCriticalSection);
  end;
end;

Die Critical Section FCriticalSection darf nur zum Absichern des Zugriffs auf die Logausgabe verwendet werden.

[s.h.a.r.k]

Jo, das ist korrekt. Ich habe es allerdings also globale Methode bzw. als Klassenmethode. Dazu kommt dann die CriticalSection als Klassenvariable des LogControllers. Und hier die beiden "InteralLog"-Methoden:

Delphi-Quellcode:

procedure TLogController.DoAfterWrite(const ALogRecord: TLogRecord);
begin
  FCriticalSection.Enter();
  try
    // save record for synchronized call
    FSyncAfterWriteLogRecord := ALogRecord;

    // synchronized call of event listener
    if (GetCurrentThreadId() = System.MainThreadID) then
      SyncDoAfterWrite()
    else
      Synchronize(SyncDoAfterWrite);
  finally
    FCriticalSection.Leave();
  end;
end;

procedure TLogController.SyncDoAfterWrite();
var
  i : Integer;
  mt : PMethod;
begin
  for i := 0 to FOnWriteLogListener.Count - 1 do
  begin
    mt := FOnWriteLogListener[i];
    if ((Assigned(mt)) and (Assigned(mt))) then
    begin
      try
        // call method
        TOnAfterWrite(mt^)(FSyncAfterWriteLogRecord);
      except
        {$MESSAGE 'Baustelle'}
      end;
    end;
  end;
end;

Und genau das Synchronize macht das Problem, so wie ich beschrieben habe -> Deadlock.

[himitsu]

Du mischst hier 2 Sperr-Funktionen, welche sich gegenseitig behindern können,
was eigentlich keine Probleme verursachen muß,
allerdings nur, wenn die Reihenfolge andersrum ist.

Synchronize sperrt einen ganzen Thread, wärend die CriticalSection nur eine Funktion sperrt.

Also erst Synchronize und darin dann die CriticalSection (wobei man sich die CS dann auch ganz sparen kann), das würde gehn und nicht in deinem Deadlock enden.


Also entweder di synchronisierst/sperrst nur über Synchronize
oder du darfst nicht beide Vaianten verschachteln.

Bei deinem DoAfterWrite darfst du z.B. innerhalb des Synchronize-Aufrufs nicht auf das FCriticalSection zugreifen, denn wenn dieses in einem anderem Thread gesperrt wurde, dann weiß das synchronisierte FCriticalSection (innerhalb von Synchronize) nicht, daß es eigentlich zum selben Abarbeitungspfad gehört, und sperrt natürlich, da es ja nun zu einem anderem Thread gehört.

sowas würde aber gehn.

Delphi-Quellcode:

procedure TLogController.DoAfterWrite(const ALogRecord: TLogRecord);
begin
  FCriticalSection.Enter();
  try
    ...
  finally
    FCriticalSection.Leave();
  end;
  Synchronize(SyncDoAfterWrite);
end;

PS: dieses

Delphi-Quellcode:

if (GetCurrentThreadId() = System.MainThreadID) then

macht Synchronize intern auch.

[sx2008]

Hmm...es gibt nur eine Critical Section aber mehrere Resourcen die angesprochen werden.
Jedes Ziel müsste durch eine eigene Critical Section abgesichert werden.

Im Moment ist es so, dass jede Log-Aktion im Kontext des Hauptthreads ausgeführt wird.
Aber der Hauptthread kann blockieren und führt so zum Deadlock.

Ich vermute mal es gibt zwei Arten von OnWriteLogListener Event-Handler:
a.) Schreiben in eine Logdatei und b.) Ausgabe auf einem VCL Control.
Beiden Arten sind grundsätzlich verschieden und müssen unterschiedlich behandelt werden.

Zu a.): hier würde man einfach eine Critical Section pro Logdatei verwenden.
Zwischen dem Eintritt in die Critical Section und dem Austritt kann eigentlich nichts passieren; auf jeden Fall kann dazwischen nichts blockieren.

Zu b.): das wird schon kniffliger. Man braucht eine Queue in die die LogRecords eingefügt werden. Dann wird geschaut ob man sich im Hauptthread befindet.
Falls ja, solange LogRecords aus der Queue entfernen und auf's VCL-Control schreiben, bis sie leer ist.
Falls nein, wird eine Synchronize()-Botschaft an den Hauptthread geschickt,
der dann die Queue leert und weiterverarbeitet.

[taveuni]

Zitat:

Zitat von s.h.a.r.k (Beitrag 1031946)

Habt ihr auch eine entsprechende Log-Klasse?! Welche Lösungen nutzt ihr?

Wir nutzen mit Delphi immer noch THotLog http://mapage.noos.fr/qnno/pages/delphi_en.htm
Ist schon etwas in die Jahre gekommen aber funktioniert immer noch tadellos.
Allerdings nutzen wir Delphi 2007. Keine Ahnung ob das mit dem Unicode Gedöns einfach anzupassen
ist oder überhaupt nötig.

Gruss Werner

[Sir Rufo]

Einen Thread für die Ausgabe auszubremsen halte ich auch nicht für sehr geschickt, da die Performance sinkt.

Besser wäre es doch nach einem Log-Eintrag entsprechende nachrichten an die Fenster zu senden, die diese Log-Einträge anzeigen sollen. Dann braucht man auch kein Synchronize.

[s.h.a.r.k]

@Sir Rufo: dann habe ich aber das Problem, dass ich das EventListener-Konzept nicht mehr halten kann, welches ich aber sehr verständlich finde, eben auch sehr lesbar für andere Programmierer. Aber gut ich werde mir mal Gedanken über diese Nachrichten-System machen. Eine Basis-Klasse oder ein Interface als "Log-Listener", die die Messages annimmt und weiterleitet bzw. entsprechend verarbeitet würde es ja schon tun. Aber ich wollte ganz gerne komplett unabhängig sein.

Eine Idee, die auf Messages basieren würde, wäre es, einen internen Thread im LogController laufen zu lassen, der auf neue Einträge in einer internen Queue reagiert und somit parallel zu allen anderen läuft. Ist ein Log in der Queue vorhanden, so wird diese (synchronisiert) weiterleitet -> EventListener-Konzept bleibt bestehen. Der LogController, bei dem neue Logs gemeldet werden, schickt diesem internen Thread Messages mit den entsprechenden Log-Meldungen. Dieser interne Thread gibt diese Meldungen dann auch frei. Somit wird das Freigeben nicht an den Benutzer verlagert und ich brauche keine Basis-Klasse bzw. ein Interface.

Allerdings habe ich gedanklich folgendes Problem: Thread A schreibt einen Log und betritt somit die CriticalSection. Der MainThread kommt nun und will auch eine Log-Meldung absetzen, wobei dieser nun warten muss, da Thread A ja gerade in die Log-Queue schreibt. Genau in diesem Moment kommt nun der interne Thread des LogControllers und will synchronisiert eine Meldung schreiben, aber der MainThread ist ja gerade im wartenden Zustand... Kann das zu einem Deadlock führen?! :gruebel: