[erledigt] ThreadID bei Procedure

[Michl]

Seit einigen Jahren nutze ich ein eigenes Log, um Fehler beim Zusammenspielen verschiedener Threads besser finden zu können. Ein altes bekanntes Problem habe ich nun auf ein Minimalbeispiel reduzieren können.

Ich verstehe nicht, warum beim Aufruf einer Procedure beim Constructor eines Threads, trotz Inlining, die ThreadID vom MainThread zurückgegeben wird, anstatt der ThreadID vom Thread. Im Constructor selbst, wird die ThreadID vom Thread richtig zurückgegeben.

Kann mir jemand erklären, ob dies ein Feature oder ein Bug ist? Beispiel erstellt per Lazarus 2.2.2 (rev lazarus_2_2_2) FPC 3.2.2 x86_64-win64-win32/win64 anbei.

Code: Alles auswählen

  TTestThread = class(TThread)
  protected
    procedure Execute; override;
  public
    constructor Create;
  end;

  procedure Log(const AStr: String; AThreadId: TThreadID); inline;
...

procedure Log(const AStr: String; AThreadId: TThreadID);
begin
  WriteLn(AStr, ': ', ThreadID, ' - ', AThreadId);
end;

procedure TTestThread.Execute;
begin
  Log('Execute', ThreadID);
end;

constructor TTestThread.Create;
begin
  inherited Create(True);
  FreeOnTerminate := True;
  Log('Create', ThreadID);
end;  

...

  TestThread := TTestThread.Create;
  TestThread.Start;  

[PascalDragon]

Der Constructor und damit auch auch deine Log-Methode wird im Kontext des Hauptthreads aufgerufen. Die globale Variable ThreadID, welche du in Log ausgibst ist eben nun die ID des aktuell laufenden Threads (welches eben der Hauptthread ist). Das ThreadID welches du im Constructor an Log weitergibst ist aber ein Feld des Threadobjekts (und nicht die oben genannte, globale Variable), deshalb enthält diese bereits die ID des neu erstellten Threads. Innerhalb von Execute stimmt dann also beides überein (würdest du von hier eine Methode in einer anderen, existierenden TThread-Instanz aufrufen und dort ebenfalls Log aufrufen, dann wären die beiden Thread IDs wieder unterschiedlich).

Das hat also nichts mit Feature oder Bug zu tun, sondern damit, dass du nicht beachtet hast wo welches ThreadID herkommt und was es bedeutet.

[Michl]

Danke für die Erklärung! Soweit hatte ich es ja auch beobachtet. Nur hätte ich erwartet, daß durch das Inlining die Methode Bestandteil des aufrufenden Constructors würde und damit "im Kontext" stehen würde, wie z.B. bei einer Unterprozedur.

Code: Alles auswählen

constructor TTestThread.Create;

  procedure LLog(const AStr: String; AThreadId: TThreadID);
  begin
    WriteLn(AStr, ': ', ThreadID, ' - ', AThreadId);
  end;

begin
  inherited Create(True);
  FreeOnTerminate := True;
  LLog('Create', ThreadID);
end; 

OK, dann muss ich damit dealen.

[Socke]

Nur hätte ich erwartet, daß durch das Inlining die Methode Bestandteil des aufrufenden Constructors würde und damit "im Context" stehen würde, wie z.B. bei einer Subprozedur.

Bei Inlining wird nicht nur der Quelltext kopiert. Der Compiler beachtet die referenzierten Variablen etc. korrekt. Für reine Textersetzung kannst du Macros verwenden (oder C ).

[Warf]

Inlining verändert nicht die Funktionsweise von Code, also geinlinter Code soll genauso funktionieren wie nicht geinlinter code, einfach nur scheller

[Michl]

Für reine Textersetzung kannst du Macros verwenden

Ich weiß, mache ich auch.

Mein Problem ist, daß ich die ThreadID zum zählen nutze, d.h. wenn beim Constructor eine andere ThreadID, als beim Destructor genutzt wird, dann ist das blöd.
Wenn ich mich richtig erinnere, hatte ich früher die tatsächlich aufrufende Methode ermittelt und darüber gezählt, später dann auf die einfachere Möglichkeit der ThreadID umgestellt.
Muss da mal in der Versionsgeschichte nachschauen bzw. darüber schlafen, wie ich das nun löse.

[PascalDragon]

Nur hätte ich erwartet, daß durch das Inlining die Methode Bestandteil des aufrufenden Constructors würde und damit "im Kontext" stehen würde, wie z.B. bei einer Unterprozedur.

Nein. Wie die anderen es bereits geschrieben haben: Inlining darf das Verhalten des Codes nicht ändern (eventuell abgesehen von Range Check & Overflow Exceptions) und wenn es das doch mal machen sollte, dann ist es ein Bug im Compiler, auf dessen Vorhandensein man sich nicht verlassen darf, denn früher oder später wird das dann gefixt werden.

Mein Problem ist, daß ich die ThreadID zum zählen nutze, d.h. wenn beim Constructor eine andere ThreadID, als beim Destructor genutzt wird, dann ist das blöd.

Das ist aber ein recht fragiles System. Wenn dein Threadobjekt zum Beispiel eine Methode hat, um ihm vom Hauptthread eine Aufgabe zuzuweisen (was dann zum Beispiel in eine Queue eingestellt wird) und du in dieser Methode ebenfalls über dein Log ausgibst, dann hast du wieder verschiedene Thread IDs. Du solltest also wirklich überlegen, ob das, was du da machst, wirklich so sinnvoll ist und dir nicht irgendwann in der Zukunft Probleme bereiten wird.

[Michl]

Nein. Wie die anderen es bereits geschrieben haben: Inlining darf das Verhalten des Codes nicht ändern

Ja, habe ich verstanden. Wie gesagt, ich hätte es anders erwartet, auch ohne Inlining, daß entweder der Constructor noch die zum MainThread gehörige ThreadID zurückliefert oder eben konsequenter Weise, wenn der Constructor eine Methode aufruft, dann eben dort auch die zum Thread gehörige ThreadID zurückgeliefert wird. Wenn es so sein soll, wie es zur Zeit ist, dann ist es halt so und ich werde damit zurechtkommen. Deshalb habe ich hier gefragt.

Das ist aber ein recht fragiles System.

Nein. Das Logging funktioniert seit fast zehn Jahren hier so bei einer Anwendung die 24/7 läuft. Die Urversion hatte ich hier mal vor langer Zeit gepostet. Zu finden seit einigen Jahren auch auf https://svn.code.sf.net/p/michlpackages ... nk/status/. (Den Code habe ich vor vielen Jahren geschrieben und müsste den mal überarbeiten - es fehlt an Zeit )

Wenn dein Threadobjekt zum Beispiel eine Methode hat, um ihm vom Hauptthread eine Aufgabe zuzuweisen (was dann zum Beispiel in eine Queue eingestellt wird) und du in dieser Methode ebenfalls über dein Log ausgibst, dann hast du wieder verschiedene Thread IDs.

Aber genau das ist der Witz der Übung!!! Ich erkenne welcher Thread, welche Methode aufruft und welche Methode welche Methode aufruft.

OK, weiß nicht, ob das von Interesse ist, vielleicht sollte ich es kurz erklären.
Normalerweise nehme ich beim Erstellen ein Makro (bei mir drei Tasten <S>, <A>, <Enter>), damit wird der komplette Logteil erstellt (incl. Methodenname). Sieht dann so z.B. aus (für jemanden, der nicht täglich damit arbeit, sicher unübersichtlich, für mich ist es gut):

Code: Alles auswählen

procedure TMainForm.Test(var TheMessage: TLMessage);
begin
  {$ifdef statvrmain} try
  if StatIn then StatLn('TMainForm.Test', '');
  {$endif}

  // Do Something

  {$ifdef statvrmain} finally StatOut; end; {$endif}
end;  

Beim hineinkommen in die Methode wird ein Zähler um die ThreadID erhöht (StatIn), beim Verlassen (StatOut) verringert (beim Create und Destroy wollte ich schlauer sein und nur einmal erhöhen und verringern - geht nicht, wie erläutert). Wenn ich denke, daß es für das Log wichtig ist, gebe ich noch dem Logtext (StatLn) beim Hineinkommen in die Methode oder beim Verlassen Variablen (z.B. Parameter oder ein Result einer Funktion) usw. mit.

Das Ganze wird über IPC in ein externes Programm übermittelt, wo ich die ganze Zeit nachverfolgen kann, was die eigentliche Anwendung macht.
Bei einem Absturz oder sonstigen Fehlern sehe ich genau, was zuletzt gemacht wurde.
Ein drittes Programm, kann ein Logfile lesen, es wird links in einem VTV die chronologische Abfolge gezeigt, rechts in einem VTV die Abfolge der jeweiligen Threads. Beide VTV sind synchronisiert, sodaß man immer sehen kann, welcher Thread was gemacht hat.
Die Anwendung selbst besteht zur Zeit aus vier Einzelprogrammen, die alle auf den gleichen Log zugreifen. Das ist auch gut so, da die Programme alle auf eine PostgreSQL Datenbank zugreifen und dort sich gegenseitig Aufgaben zuweisen.

Wie gesagt, ich finde es komfortabel und hat sich neben dem Debuggen als eine für mich sehr wichtige Fehlersuchmöglichkeit erwiesen, besonders bei Fehlern, die erst nach tagelangem Laufen einer Anwendung auftreten.

[PascalDragon]

Wenn dein Threadobjekt zum Beispiel eine Methode hat, um ihm vom Hauptthread eine Aufgabe zuzuweisen (was dann zum Beispiel in eine Queue eingestellt wird) und du in dieser Methode ebenfalls über dein Log ausgibst, dann hast du wieder verschiedene Thread IDs.

Aber genau das ist der Witz der Übung!!! Ich erkenne welcher Thread, welche Methode aufruft und welche Methode welche Methode aufruft.

Und warum soll es dann beim Aufruf eines Konstruktors anders sein? Der Hauptthread ruft den Konstruktor auf, dass heißt die aktuelle, globale ThreadID ist auch die des Hauptthreads und das ThreadID Feld der Instanz hat die ID des neu erstellten Threads. Genau so ist es auch, wenn du eine beliebige andere Methode der Instanz aus einem anderen Thread heraus aufrufst.

[Socke]

Ich erkenne welcher Thread, welche Methode aufruft und welche Methode welche Methode aufruft.

Dann sollte doch System.ThreadID immer richtig sein?! TThread.ThreadID bezieht sich ja nie auf den aktuellen Kontext sondern auf das Thread-Objekt; es stellt damit die Referenz des Betriebssystems auf diesen Thread dar. Die Methoden des Objekts können von beliebigen anderen Threads (auch dem Mainthread) aufgerufen werden.

[Michl]

Und warum soll es dann beim Aufruf eines Konstruktors anders sein?

Wie schon gesagt, wenn im Constructor die ThreadID vom neu erstellten Thread zurückgegeben wird, hätte ich dies auch für Hilfsmethoden, die der Contructor aufruft erwartet.

Es ist halt eben so, daß der Constructor hier die Ausnahme bildet, da alle nachfolgenden Methoden (z.B. Execute, Destroy), wenn sie Hilfsmethoden aufrufen, diese Hilfmethoden die ThreadID des aufrufenden Threads zurückliefert.

Genau so ist es auch, wenn du eine beliebige andere Methode der Instanz aus einem anderen Thread heraus aufrufst.

Wie meinst du das? Rufe ich z.B. eine Methode von einem Objekt, was im MainThread erstellt wurde auf, liefert dort ThreadID die die vom Thread, nicht vom MainThread zurück - was auch gut so ist.

Wie auch immer, ich kann einfach die ThreadID als Parameter den Logmethoden mitgeben oder mir fällt noch was anderes ein.

[Michl]

Dann sollte doch System.ThreadID immer richtig sein?!

Habe es mal probiert. Es ist auf jeden Fall konsequenter, da im Constructor und den Hilfsmethoden immer die ThreadID vom aufrufenden Thread zurückgegeben wird.

Leider hilft es mir beim anfänglichen Problem nicht, da im Beispiel im Constructor die MainThreadID geliefert wird, im Destructor die ThreadID. Es ist zum Zählen für mich somit nicht geeignet.

Danke trotzdem! Wie gesagt, ich muss da drüber nachdenken (bin jetzt auch für ein paar Tage offline, vielleicht habe ich danach DIE Eingebung ).

[Socke]

Leider hilft es mir beim anfänglichen Problem nicht, da im Beispiel im Constructor die MainThreadID geliefert wird, im Destructor die ThreadID. Es ist zum Zählen für mich somit nicht geeignet.

Es liegt nicht am Destructor sondern daran, dass du den Destruktur aus dem Thread heraus aufrufst (FreeOnTerminate?). Rufst du ihn aus dem Mainthread auf, passt alles.

[PascalDragon]

Und warum soll es dann beim Aufruf eines Konstruktors anders sein?

Wie schon gesagt, wenn im Constructor die ThreadID vom neu erstellten Thread zurückgegeben wird, hätte ich dies auch für Hilfsmethoden, die der Contructor aufruft erwartet.

Es ist halt eben so, daß der Constructor hier die Ausnahme bildet, da alle nachfolgenden Methoden (z.B. Execute, Destroy), wenn sie Hilfsmethoden aufrufen, diese Hilfmethoden die ThreadID des aufrufenden Threads zurückliefert.

Weil diese im Kontext des neuen Threads aufgerufen werden!

Genau so ist es auch, wenn du eine beliebige andere Methode der Instanz aus einem anderen Thread heraus aufrufst.

Wie meinst du das? Rufe ich z.B. eine Methode von einem Objekt, was im MainThread erstellt wurde auf, liefert dort ThreadID die die vom Thread, nicht vom MainThread zurück - was auch gut so ist.

Nochmal in aller Deutlichkeit:

Es gibt die Thread Variable System.ThreadID. Diese enthält immer die ID des Threads, welcher aktuell ausgeführt wird. (1)
Außerdem gibt es noch die Eigenschaft Classes.TThread.ThreadID. Dies ist eine Eigenschaft der Instanz und gibt die ID des Threads an, der zur Instanz des Threadobjekts dazu gehört. (2)

Wenn du im Konstruktor den Bezeichner ThreadID nutzt, dann löst das auf die Eigenschaft und nicht die Variable auf, das heißt du hast hier die ID des neuen Threads. Wenn du in deiner Log-Funktion, welche ja nicht Teil deiner abgeleiteten TThread-Klasse ist, ThreadID nutzt, dann löst das die Variable auf und nicht die Eigenschaft weil die Funktion schließlich keine Ahnung von deinem Threadobjekt hat. Aus (1) und (2) folgen nun, dass hier verschiedene Werte drinstehen.

Rufst du Log innerhalb der Execute Methode auf, welche im Kontext des Threads läuft, und gibst ThreadID weiter, so sind beide gleich, wie aus (1) und (2) folgt.

Und da du FreeOnTerminate auf True setzt, wird auch der Destruktor im Kontext des Threads aufgerufen, also sind (1) und (2) wieder identisch.

Hier mal als Beispiel, damit du vielleichst noch besser verstehen kannst was ich meine (und was auch noch mehr Situationen zeigt, in denen (1) und (2) verschieden sind):

Code: Alles auswählen

program tthrd;

{$mode objfpc}{$H+}

uses
{$ifdef unix}
  cthreads,
{$endif}
  SysUtils, Classes;

type

  { TThread1 }

  TThread1 = class(TThread)
  protected
    procedure Execute; override;
  public
    constructor Create;
    destructor Destroy; override;
    procedure Test;
  end;

  { TThread2 }

  TThread2 = class(TThread)
  protected
    fThread: TThread1;
    procedure Execute; override;
  public
    constructor Create(aThread: TThread1);
    destructor Destroy; override;
  end;

procedure Log(aThreadID: TThreadID; const aMessage: String);
begin
  Writeln(aMessage);
  Writeln('   Thread ID: Current = ', {System.}ThreadID, ', Instance = ', aThreadID);
end;

{ TThread1 }

procedure TThread1.Execute;
begin
  Log({Self.}ThreadID, 'TThread1.Execute');
end;

constructor TThread1.Create;
begin
  inherited Create(True);
  Log({Self.}ThreadID, 'TThread1.Create');
end;

destructor TThread1.Destroy;
begin
  Log({Self.}ThreadID, 'TThread1.Destroy');
  inherited Destroy;
end;

procedure TThread1.Test;
begin
  Log({Self.}THreadID, 'TThread1.Test');
end;

{ TThread2 }

procedure TThread2.Execute;
begin
  Log({Self.}ThreadID, 'TThread2.Execute Begin');
  fThread.Test;
  Log(fThread.ThreadID, 'TThread2.Execute After Test');
  fThread.Execute;
  Log({Self.}ThreadID, 'TThread2.Execute End');
end;

constructor TThread2.Create(aThread: TThread1);
begin
  inherited Create(True);
  fThread := aThread;
  Log({Self.}ThreadID, 'TThread2.Create');
end;

destructor TThread2.Destroy;
begin
  Log({Self.}ThreadID, 'TThread2.Destroy');
  inherited Destroy;
end;

var
  t1: TThread1;
  t2: TThread2;
begin
  t1 := TThread1.Create;
  Log(t1.ThreadID, 'After Create');
  t1.FreeOnTerminate := True;
  t1.Start;

  Sleep(500);
  Writeln;

  t1 := TThread1.Create;
  Log(t1.ThreadID, 'After Create 2');
  t1.Start;
  t1.WaitFor;
  t1.Free;

  Sleep(500);
  Writeln;

  t1 := TThread1.Create;
  t2 := TThread2.Create(t1);
  Log(t1.ThreadID, 'After Create 3 t1');
  Log(t2.ThreadID, 'After Create 3 t2');
  t2.Start;
  t2.WaitFor;
  t2.Free;
  t1.Free;
end.

Das führt dann zu folgender Ausgabe:

Code: Alles auswählen

TThread1.Create
   Thread ID: Current = 24392, Instance = 9228
After Create
   Thread ID: Current = 24392, Instance = 9228
TThread1.Execute
   Thread ID: Current = 9228, Instance = 9228
TThread1.Destroy
   Thread ID: Current = 9228, Instance = 9228

TThread1.Create
   Thread ID: Current = 24392, Instance = 22712
After Create 2
   Thread ID: Current = 24392, Instance = 22712
TThread1.Execute
   Thread ID: Current = 22712, Instance = 22712
TThread1.Destroy
   Thread ID: Current = 24392, Instance = 22712

TThread1.Create
   Thread ID: Current = 24392, Instance = 16832
TThread2.Create
   Thread ID: Current = 24392, Instance = 22808
After Create 3 t1
   Thread ID: Current = 24392, Instance = 16832
After Create 3 t2
   Thread ID: Current = 24392, Instance = 22808
TThread2.Execute Begin
   Thread ID: Current = 22808, Instance = 22808
TThread1.Test
   Thread ID: Current = 22808, Instance = 16832
TThread2.Execute After Test
   Thread ID: Current = 22808, Instance = 16832
TThread1.Execute
   Thread ID: Current = 22808, Instance = 16832
TThread2.Execute End
   Thread ID: Current = 22808, Instance = 22808
TThread2.Destroy
   Thread ID: Current = 24392, Instance = 22808
TThread1.Destroy
   Thread ID: Current = 24392, Instance = 16832