Vlákna a eventy se míchají

[age.new]

Vážená komunito,

mohl bych se zeptat, zda moje chápání eventů u vláken je správné? Mám vytvořené ukládání textů do souboru ve vláknu. Těchto vláken může být více - což je příčina problému který moc nechápu. Každé vlákno si vytvoří vlastní privátní event

Kód: Delphi [Vybrat]

1. Event := CreateEvent(nil, False, False, nil);

. V execute části vlákna je jednoduchý kód:

Kód: Delphi [Vybrat]

1.    
2. repeat
3.   case WaitForSingleObject(Event, Timeout) of
4.     WAIT_TIMEOUT: Save;
5.     WAIT_OBJECT_0: begin
6.       Save;
7.       Self.Terminate;
8.     end;
9.   end;
10. until Self.Terminated or Application.Terminated;
11.  

Ukládání textu se provádí časově (určuje proměnná Timeout) a Event má sloužit k ukončení vlákna, tj. dojde k zapsání zbytku bufferu a terminuje. Pro ukončení vlákna mám tento kód:

Kód: Delphi [Vybrat]

1.   SetEvent(Event);
2.   Self.WaitFor;
3.   CloseHandle(Event);
4.  

Domníval jsem se, že WaitForSingleObject čeká na požadovaný Event, nebo vypršení časového limitu. Z nějakého mě neznámého důvodu však, když ukončím první vlákno vůbec (je jedno které), dojde k ukončení všech vláken naráz! Jakoby byl jeden event sdílený pro všechny vlákna, což ale není možné, protože každé vlákno si žije samo a má vlastní event na který čeká. Jak je tedy možné, že

Kód: Delphi [Vybrat]

1. SetEvent(Event);

u jednoho vlákna vyvolá

Kód: Delphi [Vybrat]

1. WAIT_OBJECT_0

u jiného vlákna, které ale má čekat na jiný event (s jiným handle)?

Nerozumím tomu...
   
Děkuji za pomoc.

[pf1957]

Jak je tedy možné, že

Kód: Delphi [Vybrat]

1. SetEvent(Event);

u jednoho vlákna vyvolá

Kód: Delphi [Vybrat]

1. WAIT_OBJECT_0

u jiného vlákna, které ale má čekat na jiný event (s jiným handle)?

No nejspis delas neco spatne v kodu, ktery jsi nam neukazal. Predne bych udelal uplny test vysledku WaitForXXX vcetne pripadneho GetLastError a doplnil logovani, na jake handle to vlastne v jednotlivych threadech ceka.

[age.new]

Dobrý den,

kód nemohu ukázat protože je to hodně obsáhlý kód a to důležité je rozseté po unitech a to jsem ukázal v prvním příspěvku. Zkusím to vysvětlit jinak:

1) Každý class (TThread) má privátní Event. Tento class vytvořím 3x, takže vzniknou tři vlákna pomocí, kdy každý má vlastní event

Kód: Delphi [Vybrat]

1. Event := CreateEvent(nil, False, False, nil);

s handle například 800, 801 a 802.

2) Execute každého z vláken čeká na svůj vlastní event pomocí

Kód: Delphi [Vybrat]

1. WaitForSingleObject(Event, Timeout)

... domnívám se, že toto je poměrně jasné.

Při zavírání aplikace mám toto:

Kód: Delphi [Vybrat]

1. Thread1.Free;
2. Thread2.Free;
3. Thread3.Free;
4.  

Každý destruktor vlákna zavolá vlastní event přes:

Kód: Delphi [Vybrat]

1. SetEvent(Event);
2. Self.WaitFor;
3. CloseHandle(Event);
4.  

Při trasování se na Thread1.Free; vyvolá SetEvent pouze Eventu s handlem 800. Následně ale všechny vlákna padnou do WAIT_OBJECT_0 části. Takže když se pak debuger posune na Thread2.Free; tak to vlákno je již terminované. Stejně pak i Thread3.Free;

Domníval jsem se, že Event se rozlišuje podle handle, které by mělo být unikátní. Ale vypadá to, že WaitForSingleObject vrátí WAIT_OBJECT_0 při jakémkoli SetEvent události.

Napadlo mě, zda se ty privátní Eventy nepletou. Kód

Kód: Delphi [Vybrat]

1. Event := CreateEvent(nil, False, False, nil);

nabízí možnost Event pojmenovat. Když je nil, nemůže pak docházet k výše uvedenému problému?

Děkuji.

[age.new]

Vytvořil jsem si test a vše co se stará o vlákna vytáhl přesně tak, jak to mám v hlavní aplikaci. A vše funguje správně. Button 2, 3 a 4 zavírá jen to vlákno které vyvolá vlastní Event. Nechápu tedy, proč mi to v hlavní aplikaci blbne

Kód: Delphi [Vybrat]

1. unit Unit1;
2.  
3. interface
4.  
5. uses
6.   Winapi.Windows, Winapi.Messages, System.SysUtils, System.Variants, System.Classes, Vcl.Graphics,
7.   Vcl.Controls, Vcl.Forms, Vcl.Dialogs, Vcl.StdCtrls;
8.  
9. type
10.   TThreadTest = class (TThread)
11.   private
12.     Event: THandle;
13.   protected
14.     procedure Execute; override;
15.   public
16.     constructor Create;
17.     destructor Destroy; override;
18.   end;
19.  
20.   TForm1 = class(TForm)
21.     Button1: TButton;
22.     Button2: TButton;
23.     Button3: TButton;
24.     Button4: TButton;
25.     procedure Button1Click(Sender: TObject);
26.     procedure Button2Click(Sender: TObject);
27.     procedure Button3Click(Sender: TObject);
28.     procedure Button4Click(Sender: TObject);
29.   public
30.     ThreadTest1: TThreadTest;
31.     ThreadTest2: TThreadTest;
32.     ThreadTest3: TThreadTest;
33.   end;
34.  
35. var
36.   Form1: TForm1;
37.  
38. implementation
39.  
40. {$R *.dfm}
41.  
42. constructor TThreadTest.Create;
43. begin
44.   Event := CreateEvent(nil, False, False, nil);
45.  
46.   inherited Create(false);
47.   FreeOnTerminate := false;
48. end;
49.  
50. destructor TThreadTest.Destroy;
51. begin
52.   SetEvent(Event);
53.   WaitFor;
54.   CloseHandle(Event);
55.  
56.   inherited Destroy;
57. end;
58.  
59. procedure TThreadTest.Execute;
60. begin
61.   repeat
62.     case WaitForSingleObject(Event, 1000) of
63.       WAIT_TIMEOUT: ;
64.       WAIT_OBJECT_0: Self.Terminate;
65.     end;
66.   until Self.Terminated or Application.Terminated;
67. end;
68.  
69. procedure TForm1.Button1Click(Sender: TObject);
70. begin
71.   // create all
72.   ThreadTest1 := TThreadTest.Create;
73.   ThreadTest2 := TThreadTest.Create;
74.   ThreadTest3 := TThreadTest.Create;
75. end;
76.  
77. procedure TForm1.Button2Click(Sender: TObject);
78. begin
79.   // free 1
80.   ThreadTest1.Free;
81. end;
82.  
83. procedure TForm1.Button3Click(Sender: TObject);
84. begin
85.   // free 2
86.   ThreadTest2.Free;
87. end;
88.  
89. procedure TForm1.Button4Click(Sender: TObject);
90. begin
91.   // free 3
92.   ThreadTest3.Free;
93. end;
94.  
95. end.
96.  

[age.new]

Tak už vím čím to je. Problém je v tom, že jsem volal destruktor vláken v destruktoru hlavního formuláře. V tuto chvíli se nastaví Application.Terminated na true a všechny vlákna padnou v until části repeat cyklu:

Kód: Delphi [Vybrat]

1.   repeat
2.     case WaitForSingleObject(Event, 1000) of
3.       WAIT_TIMEOUT: ;
4.       WAIT_OBJECT_0: Terminate;
5.     end;
6.   until Terminated or Application.Terminated;
7.  

[pf1957]

Tak už vím čím to je. Problém je v tom, že jsem volal destruktor vláken v destruktoru hlavního formuláře. V tuto chvíli se nastaví Application.Terminated na true a všechny vlákna padnou v until části repeat cyklu:

Kdyz se pracuje se thready, tak je treba
a) psat ciste, coz mj. znamena, ze zadna hodnota nezustatne neosetrena napr. viz tvuj case, zadne volani API funkce nezustane bez kontroly, jak dopadlo atd.
b) A ty kontroly vetsinou predstavuji, ze se to srozumitelne zaprotokoluje, protoze debugger je vetsinou na dve veci, jelikoz se pri praci dost casto jedna o nejake synchronizacni chyby vyskytujici se jednou za cas napr. pri nejakem soubehu (race condition)

A kdybys to tak mel napsane, tak bys na to videl okamzite.

[age.new]

Jak psát čistě? Zajímalo by mě to zaprotokolování - co to znamená? Jediné co jsem schopný dostat z běhu aplikace je log, který musím sám vytvořit a spravovat. Ne vše ale lze logovat. Hodil by se mi log zásobníku, ale nemám zájem kupovat si komponentu, nebo implementovat několik "cizích" zdrojáků kvůli jedné funkci.

[pf1957]

Jak psát čistě?

Ciste je ciste, ne Quick & Dirty stylem :-) Vzdyt jsem ti to slovne popsal, takze takova minimalisticka podoba (psana rucne a spis pro nas framework nez pro cisty Delphi, event predpokladam zapouzdrenou do vlastniho, ne Delphi TEvent objektu). Pro nazornost jsem ten preamble identifikujici event nevyclenil  do subroutiny, ale kopiroval:

Kód: Delphi [Vybrat]

1. var
2.   WaitResult: dword;
3. repeat
4.     WaitResult := WaitForSingleObject(FEvent.Handle, 1000);
5.     iLog.TraceFmt(self.ThreadName, 'Result of waiting for event %p (%s): %8.8x', [FEvent.Handle, FEvent.Name, WaitResult]);
6.     case WaitResult of
7.       WAIT_TIMEOUT: ;
8.       WAIT_OBJECT_0: Terminate;
9.       else iLog.Warning(self.ThreadName, 'Result of waiting for event %p (%s) has been fucked-up', [FEvent.Handle, FEvent.Name]);
10.     end;
11.   until Terminated or Application.Terminated;

Ale samozrejme, za takhle napsany soft bych udrzovat nechtel, takze bych tomu venoval daleko vic usili, protoze se to pise jednou, ale cte tisickrat a u slozitejsich softu, kde o neco jde, se to tisickrat vyplati, napr.

Kód: Delphi [Vybrat]

1. Log.Info(self.ThreadName, 'The thread has been started-up, going to wait for event %p (%s)',[FEvent.Handle, FEvent.Name]);
2. repeat
3.     WaitResult := WaitForSingleObject(FEvent.Handle, maxEventXyzWaitTimeout);
4.     iLog.Trace(self.ThreadName, 'Result of waiting for event %p (%d): %8.8x', [FEvent.Handle, FEvent.Name, WaitResult]);
5.     case WaitResult of
6.       WAIT_TIMEOUT:
7.         iLog.Trace(self.ThreadName, 'Waiting for event %p (%s) has timeouted, no action is taken', [FEvent.Handle, FEvent.Name]);
8.       WAIT_OBJECT_0:
9.         begin
10.           iLog.Trace(self.ThreadName, 'Event %p (%s) has been signaled, going to ...', [FEvent.Handle, FEvent.Name]);
11.           ....
12.         end;
13.        WAIT_ABANDONED_0:
14.         begin
15.           iLog.Error(self.ThreadName, 'Event %p (%s) has been abandoned', [FEvent.Handle, FEvent.Name]);
16.           ....
17.         end;
18.        WAIT_FAILED:
19.         begin
20.           Err := GetlastError;
21.           iLog.Error(self.ThreadName, 'Waiting for Event %p (%s) has failed with error %8.8x (%s)', [FEvent.Handle, FEvent.Name, Err, VerboseOSError(Err)]);
22.           ....
23.         end;
24.       else
25.         Log.Warning(self.ThreadName, 'Waiting for Event %p (%s): unexpected result code %8.8x', [FEvent.Handle, FEvent.Name, WaitResult]);
26.     end;
27.     if Terminated then
28.       begin
29.         Log.Info(self.ThreadName, 'The thread has been terminated, leaving waiting loop');
30.         break;
31.       end;
32.     if Application.Terminated then
33.       begin
34.         Log.Info(self.ThreadName, 'The Application has been terminated, leaving waiting loop');
35.         break;
36.       end;
37.   until FALSE;
38.  

Zajímalo by mě to zaprotokolování - co to znamená? Jediné co jsem schopný dostat z běhu aplikace je log, který musím sám vytvořit a spravovat.

pouzil jsem cesky termin pro logovani ;-) Samozrejme, ze rucne. Zpravidla tech logu mivame nekolik (= nekolik souboru), nektere (zapisujici napr. trace dat) jsou asynchronni, kterym se to strci do fronty a obsah se renderuje, az je na to cas.

Ne vše ale lze logovat.

Nikdy se mi nestalo, ze by se neco nedalo logovat a zpravidla jsme v ostrem provozu ani ty logy uz nevypinali. A vzdycky, kdyz clovek narazi na nejaky problem, tak zjisti, ze logovani neni nikdy dost :-) Pravda, logy mame vlastni a dost jsme je pilovali. A evidentne nejsme sami - jak myslis, ze by napr. z logu BTS dokazali zpetne dopocitavat pozice mobilu s presnosti tusim ~40 m v ramci chytre karanteny pri tom masivnim trafficu v GSM sitich?

Hodil by se mi log zásobníku, ale nemám zájem kupovat si komponentu, nebo implementovat několik "cizích" zdrojáků kvůli jedné funkci.

20+ let na to pouziváme Vonešův JclDebug z JCL tj. JclGetExceptStackList() nebo JclCreateThreadStackTraceFromID() aj.

[age.new]

No ale to pak je skoro co řádek kódu to řádek logu. Když ten kód proběhne 1000x za minutu tak máte log ve stovkách MB. Pak jej musíte umazávat (cyklovat) a chybu, která se stala den nazpět ani nenajdete. Navíc hledejte něco v logu co má desetitisíce řádků ...

Líbí se mi ten "Set of" parametrů u iLog.Trace, který by se mi hodil implementovat. Jak jej předáváte do Trace procedury, resp. jaký je to typ proměnné?

Na export zásobníku z JclDebug jsem se díval a k jeho využití bych musel přidat do projektu hromadu externích zdrojáků. To se mi nezamlouvá. 

[pf1957]

No ale to pak je skoro co řádek kódu to řádek logu. Když ten kód proběhne 1000x za minutu tak máte log ve stovkách MB. Pak jej musíte umazávat (cyklovat) a chybu, která se stala den nazpět ani nenajdete. Navíc hledejte něco v logu co má desetitisíce řádků ...

Kdyz se to logovani stiha, tak je velikost to nejmensi. Vetsinou to delame na denni bazi, kdyz se v ramci "pulnocni" akce log zazipuje, pojmenuje s datumem a strci do archivu a zkrati se. Nekdy ten soubor segmentujeme napr. po 256 MB kvuli prohlizeci - mame vlastni prohlizec logu s regexy, ktery mj. umi collapsnout textovy soubor tak, ze jsou viditelne jen radky, ktere odpovidaji zadanemu filtru a ty lze pri zobrazovani expandnout/collapsnout jako vetev stromu - stejnou funkci mival MultiEdit od American Cybernetics. Nekde mame i automaticke hledani v tech archivech. Takze pri promyslene hierarchizaci hlaseni hledat neni problem. A toho logovani je tolik proto, aby kdyz clovek neco hleda, tak vedel, v jakem kontextu se to stalo tj. co prave program delal. Zejmena, kdyz stejny kod neco dela 1000x a parkrat se mu neco nepovede... Ale hledat se v tom da dost dobre i pomoci textoveho vieweru ve Faru.

Líbí se mi ten "Set of" parametrů u iLog.Trace, který by se mi hodil implementovat. Jak jej předáváte do Trace procedury, resp. jaký je to typ proměnné?

To je standardni pretizeni metody, aby clovek nemusel pouzivat ten Delphi like sufix Fmt:

Kód: Delphi [Vybrat]

1. procedure Trace(const AThreadName; const AMsg:String); overload;
2. procedure Trace(const AThreadName; const AMsg:String; const AArgs: array of const); overload;
3.  

s tim, ze pri implementaci se zpravidla vola

Kód: Delphi [Vybrat]

1. Trace(AThreadName, String.Format(AMsg,AArgs));

Na export zásobníku z JclDebug jsem se díval a k jeho využití bych musel přidat do projektu hromadu externích zdrojáků. To se mi nezamlouvá.

Ano, par unit z JCL. Ale to je jedna z mala knihoven, ktera rozsiruje standardni ubohoucke moznosti Delphi RTL o veci, ktere by si stejne kazdy programator nakonec musel napsat, aby vubec neco naprgal, alespon jeste nedavno tomu tak bylo. Ty novejsi verze Delphi uz jsou na tom trochu lepe.

[age.new]

Děkuji za odpověď. úplně jsem zapomněl na Format funkci. Implementuji si ji do logů a popisu chyb.