All based on win32

Pretext:
I have an issue with a crash in PopThreadQueueHead called by CheckSynchronize.  (3.0.2)
It happens in the Lazarus IDE, but at a low percentage only. (And not yet in the debugger)
I don't think the below is related, but I found it while looking around.

Potential Issue: (3.0.2 and trunk 37936)

I have not looked very deep into the threading internals, so I may have missed something, but I thought I just bring it up for review.

rtl\objpas\classes\classes.inc
     class procedure TThread.Synchronize(AThread: TThread; AMethod: TThreadMethod);
contains those lines (outside a CriticalSection):
    ThreadQueueAppend(AThread.FSynchronizeEntry);

     AThread.FSynchronizeEntry^.Method := Nil;
     AThread.FSynchronizeEntry^.Next := Nil;   // outside of critical
section

ThreadQueueAppend will enter a CriticalSection.
It will add the passed in FSynchronizeEntry (param aEntry) to ThreadQueueHead/Tail. For this it may use another entries Next pointer.

So what happens, if 2 (or more) threads call TThread.Synchronize?

What happens if
- thread 1, has just finished the line
ThreadQueueAppend(AThread.FSynchronizeEntry);
- thread 2 now calls synchronize, and
   - as soon as thread1 leaves the CriticalSection in ThreadQueueAppend => thread2 enters that CriticalSection
- thread2 adds it entry to the list, assigning it the Next^ of thread 1's entry
- now thread1 continues, it sets Next^ to nil, removing the reference to thread 2's entry.

Thread 2 would no longer be in the list.
That also means, if thread 2's entry has a Next^, then this may not be set to nil, if the entry it points to is removed?

Do you happen to have the exact location of the crash?

The queue head is only modified inside ThreadQueueAppend() and PopThreadQueueHead() (well, and RemoveQueuedEvents()) of which all use the ThreadQueueLock while working on the queue. Once ThreadQueueAppend() inside Synchronize() is executed the event is already processed (because ThreadQueueAppend() is a blocking call in that case) and the work on AThread.FSynchronizeEntry is merely cleanup to avoid any misbehaviour (at that time the entry is already no longer part of the queue).

Regards,
Sven

See below. It seems to be a timing issue. Happens only at startup of the IDE (sofar).

TApplication.HandleException Access violation
  Stack trace:
  $004AEF98 line 370 of ../objpas/classes/classes.inc   $004AF116 line 423 of ../objpas/classes/classes.inc   $00576A98 line 2012 of win32/win32callback.inc
  $005783D9 line 2696 of win32/win32callback.inc
  $7618FD92
  $7618FE6A
  $761901AD
  $7619024B
  $005796C1 line 407 of win32/win32object.inc
  $00444007 line 1276 of include/application.inc
  $00444562 line 1413 of include/application.inc
  $0049B800 line 54 of include/interfacebase.inc
  $0044451B line 1401 of include/application.inc

Would you please test whether my change in r38115 (applied to 3.0.2) makes any difference? Calling RemoveQueuedEvents() with a thread, but no method (which happens during a thread's destruction) was up to then a way to corrupt the queue. (Well, it could still corrupt the queue if a thread instance is freed while its blocked inside a Synchronize call, but that is asking for a whole different sort of trouble anyway)

Regards,
Sven

Thanks.
I will apply the patch. And wait if the error still happens.

Well, I am back faster than I thought, applied the patch, rebuild the IDE, and it still happened.
Well this time I was able to get it while the IDE was already running. But exact same stack.

I used a breakpoint on ThreadQueueAppend to see what threads are involved ( I figure, this must be called, for the error to happen)

During startup, the only threads I could detect, are online-package-manager. This is new, and I havent had it installed for long, so quite possible (given that I havent seen the crash until recently).

The other location, was in a thread running the compiler, when the IDE compiles a project. This code been there for longer.

-----------------
In the online package manager, as far as I was able to get by now, it is possible that an exception occurred somewhere.
I can't get it to happen in the debugger, probably because the debugger changes timings.

I have been able to force an error in the opm, and get a different error in checkSyncronize.  (30% chance in the debugger)

Maybe it is the same, just a diff timing....  If the debugger had not interfered, collecting info, then maybe the destroy would have been a tick later, in PopThreadQueueHead
Dont know for sure.....

Also, even if the below is related, this may not explain the error while compiling.

When I cause an exception inside the sub-thread, then in the main thread, I get
  procedure ExecuteThreadQueueEntry(aEntry: TThread.PThreadQueueEntry);   begin
    if Assigned(aEntry^.Method) then
      aEntry^.Method()    /// aentry points to F0F0F0F0

But the important thing here is, the sub thread that send the event is in REMOVE_FREED_FIXED_CHUNKS called from its destroy.

So yes it seem the thread gets destroyed, while the event is still in the queue.

-----------------------
To go more into detail. Though I havent yet fully figured it.....

There are actually 4 threads (thread id)
- main (1)
- threadtimer (this will create the 2 other threads) (2)
- threadtimer for timeout (3)
- opm thread (4)

the below order of events is established by breakpoints that where hit during debugging

timout -> ThreadQueueAppend
opm -> ThreadQueueAppend
main -> checksynchronize
  ...     PopThreadQueueHead  (before the "while" in CheckSynchronize // new call to CheckSynchronize)
  ...    an exception occured inside the event (this should be the event of the timeout timer)
  ...     PopThreadQueueHead   (inside/end of "while" in CheckSynchronize // still SAME call to CheckSynchronize) opm -> leaves it DoExecute loop // but if I am right, its event has not yet been executed...

Now it is getting weird (probably because opm is already freeing mem main has 3 further calls to  PopThreadQueueHead -> ALL (inside/end of "while" in CheckSynchronize // still SAME call to CheckSynchronize) The while loop should have exited, there are no matching ThreadQueueAppend (I do not have a stacktrace for opm2 at this time....)

After that the crash happens.  (opm2 is inside its destroy)

---------
I have no idea why or how the opm thread leaves it DoExecute, while it should still wait for its synchronize to finish.

The timout thread would probably have finished, since I did not find a try except around the synchronize in it.

Ok, I got it again in the debugger.

Since it is nor reproducible all the times, I am using auto continue breakpoints, and just record that they were hit. So I have limited data.

- After a long series of syncs ThreadQueueTail is nil.
- A thread calls ThreadQueueAppend (from within Syncronize)
- It then leaves it do execute

there was no CheckSyncronize in between the 2 last steps. the thread should be waiting for the main thread to sync. but it does not.

I captured the SyncEvent of the queue entries. (as seen in checkSyncronize). And there something strange goes on. The queue entries from 2 threads have the same SyncEvent

Maybe this is actually an issue in the application code.

The below is a method on a TTHread. This method is called before the thread is started, it does actually start it (last line)

procedure TThreadDownload.DownloadJSON(const ATimeOut: Integer = -1;
   const ASilent: Boolean = False);
begin
   FRemoteJSONFile :=
Options.RemoteRepository[Options.ActiveRepositoryIndex] + cRemoteJSONFile;
   FDownloadType := dtJSON;
   FSilent := ASilent;
   FTimer := TThreadTimer.Create;
   FTimer.Interval := ATimeOut;
   FTimer.OnTimer := @DoOnTimer;
   FTimer.StartTimer;
   Start;
end;

So when the ThreadTimer goes off, it calls DoOnTimer. But on the TThreadDownload object

And in DoOnTimer makes a call to Syncronize. (but DoOnTimer is a method of TThreadDownload)

Am I right, and it then uses the ID of the TThreadDownload? Even so it is running in the thread of the ThreadTimer?

So if TThreadDownload schedules its own Synchronize, before the event of ThreadTimer is processed, the TThreadDownload will falsely think, that it's event was processed when in reality it was the event of the timer.

Also then probably the event in FSynchronizeEntry is used twice in parallel, which it is not designed for?

Good find! Thank you for digging down to this.

While this might indeed best be fixed in the application code (and indeed it must be for correctly working on the 3.0.x series) I've implemented a fix in r38124 that will harden Synchronize() a bit better against such "abuse" (it will now execute the method using the correct thread instance).

Regards,
Sven

El 4/2/18 a les 20:17, Sven Barth via fpc-devel ha escrit:

I still think there's something wrong with thread in fpc 3.0.4.

I usually suspect that the bugs are in my code, and that's usually the case ;-), but I have a program with several threads, calling synchronize, that has worked flawlessly 24/7 for 6 years.

Due to some modifications required by the customer, 9 months ago I compiled it with fpc 3.0.4 (lazarus 1.8.4). The customer complains that, from time to time, it stops working. The UI is still responsive, everything seems to work but one of the elements doesn't work.

By looking at the logs it seems that one of the threads stops running. I thought that maybe the problem was an unhandled exception somewhere inside the thread[*], so I wrapped the Execute loop in a try..except block. No luck, no exceptions logged but it still stops working from time to time.

[*] note that I have around 20 instances of that same thread code running in another program (fpc 2.6.4) with no problem whatsoever, so I doubt that's the case, but one never knows.

Debugging the program here, I see the thread is stopped inside a synchronize call that is never executed.

Btw: is there a way to find where a thread is stopped/waiting? it's been a pain to find it, I had to assign a field almost after every instruction to know where it stops, e.g.

      FWhereAmI:=1;
      DoThis;
      FWhereAmI:=2;
      DoThat;
      FWhereAmi:=3;
      ....

so that, by putting a breakpoint in the main program when it checks if the thread has finished its job, I can examine the thread and see the value of its FWhereAmI field.

Of course I cannot reproduce the issue with a simpler test program :-/

I guess is one more project I have to revert to fpc 2.6.4/lazarus 1.6.4 :-(

I forgot: this is with win32

Bye

El 6/2/19 a les 9:01, Luca Olivetti ha escrit:

Debugging the program here, I see the thread is stopped inside a synchronize call that is never executed.

[....]

so that, by putting a breakpoint in the main program when it checks if the thread has finished its job, I can examine the thread and see the value of its FWhereAmI field.

And at that time I can see that both ThreadQueueHead and ThreadQueueTail are nil.

Bye

Luca Olivetti wrote

I still think there's something wrong with thread in fpc 3.0.4.

There is https://bugs.freepascal.org/view.php?id=34640 FIxed in 3.2 branch

If you can compile your app for linux, run it under valgrind, especially the helgrind tool.

Luca Olivetti wrote

I still think there's something wrong with thread in fpc 3.0.4.

There is https://bugs.freepascal.org/view.php?id=34640 FIxed in 3.2 branch

If you can compile your app for linux, run it under valgrind, especially the helgrind tool.

El 6/2/19 a les 14:08, Martin Frb ha escrit:

I'm not sure it's the same issue. The comment in the commit

https://svn.freepascal.org/cgi-bin/viewvc.cgi/branches/fixes_3_2/rtl/objpas/classes/classes.inc?r1=40688&r2=40687

says:

"for a Synchronize() call the record will stay valid, thus accessing SyncEvent later on (if issync is true) is okay"

so apparently that bug (and the corresponding fix) is only for the Queue case. In my case the problem is with Synchronize, the synchronized method is never called and the thread gets stuck there.

Bye

Am Mi., 6. Feb. 2019, 11:27 hat Luca Olivetti
geschrieben:

Of course I cannot reproduce the issue with a simpler test program :-/

Without a way to test it I can't do anything. So either you need to find the issue yourself or you need to manage to create a simpler example.

Regards,
Sven

El 6/2/19 a les 17:05, Sven Barth via fpc-devel ha escrit:

Yes, I know :-(

In my test program I instantiate 4 threads that call synchronize in a loop (with a Sleep(Random(20)) intermingled), while in the main thread a TTimer with interval 1 sleeps for 100 ms (to simulate a busy gui). It's been running for 7 hours already and of course it's still working fine.

In the "real" program I can provoke the issue after some time (ranging from a couple of minutes to half an hour).

With fpc 2.6.4 it's rock solid (or so it seems), so my workaround is

{$if FPC_FULLVERSION>=30000}
{$ERROR can't use fpc 3.x due to issues with TThread.Synchronize}
{$endif}

(that's just in case I inadvertently open the project with lazarus > 1.6.4)

:-(

Bye

Am Mi., 6. Feb. 2019, 18:45 hat Luca Olivetti
geschrieben:

Would you nevertheless try with 3.2, please? Just in case it happens to be the problem I had fixed in regards to Queue().

Regards,
Sven

El 6/2/19 a les 18:51, Sven Barth via fpc-devel ha escrit:

Would you nevertheless try with 3.2, please? Just in case it happens to be the problem I had fixed in regards to Queue().

The branch is fixes_3_2?

Apart from the issue reported by Martin
(https://bugs.freepascal.org/view.php?id=34640), are there other fixes? Because I don't think that change alone would fix my issue.

Bye

Luca Olivetti wrote

. In my case the problem is with Synchronize, the synchronized method is never called and the thread gets stuck there.

"synchronized method is never called"
So is the main thread running, and either idle, app.ProcessMessages, or CheckSynchronize?

The other issue (though that should be obvious) is never to wait on a thread, inside the synchronize event. (I.e. you can call Thread.Terminate; in a synced event, but must not call Thread.waitFor)

El 6/2/19 a les 19:29, Martin Frb ha escrit:

Yes, in fact the synchronize from other threads are executed with no problem

The other issue (though that should be obvious) is never to wait on a thread, inside the synchronize event. (I.e. you can call Thread.Terminate; in a synced event, but must not call Thread.waitFor)

I never do that

Bye

El 6/2/19 a les 19:19, Luca Olivetti ha escrit:

I summarily checked all commits to rtl/objpas/classes/classes.inc starting from revision 32835

https://svn.freepascal.org/cgi-bin/viewvc.cgi/branches/fixes_3_2/rtl/objpas/classes/classes.inc?r1=31752&r2=32825

(since that fix matches what I see in my 3.0.4 source)

and nothing strikes me as changing the way Synchronize works.

Perhaps I'll have to add some writeln to see how ThreadQueueHead and ThreadQueueTail are changing, but that could skew the timing and alter the result....

Bye

Actually from a further review of the source, there may be another issue:

TThread.Synchronize
will call
  ThreadQueueAppend(AThread.FSynchronizeEntry);

AThread.FSynchronizeEntry is the re-usable entry
(which is fine, only one synchronize call can be active in any given thread. (Unless you are in a synchronize event, and call MyWaitingThread.synchronize from inside the event....))

ThreadQueueAppend puts the FSynchronizeEntry at the end of the queue. It does NOT clear FSynchronizeEntry^.Next, it expects it to be nil already. => TThread.Synchronize will reset Next to nil *after* ThreadQueueAppend returns

ThreadQueueAppend waits for the synchronize call to finish.

But, if the sync event threw an exception, this exception is returned to the thread.
ThreadQueueAppend checks if an exception was returned and raises it.

In case of such an exception TThread.Synchronize will never get to execute
   AThread.FSynchronizeEntry^.Next := Nil;

The next time that thread calls TThread.Synchronize, the Next pointer is dirty.

--------------------
The below code demonstrates this (cheaply using "sleep" to ensure threads are executed in desired order....)

MySync2 Is called only once, yet the output is
x
x2
x
x2

program Project1;
{$mode objfpc}{$H+}
uses
   {$IFDEF UNIX}{$IFDEF UseCThreads}  cthreads,  {$ENDIF}{$ENDIF}
   Classes, sysutils;
type
   MT1= class(TThread)
     procedure Execute; override;
   private
     procedure MySync;
   end;

  { MT2 }

   MT2= class(TThread)
     procedure Execute; override;
   private
     procedure MySync2;
   end;
var
   T1: MT1;
   T2: MT2;

{ MT2 }

procedure MT2.Execute;
begin
   try
     Synchronize(@MySync2);
   except end;
   while true do sleep(100*1000);
end;
procedure MT2.MySync2;
begin
   writeln('x2 ');
   raise Exception.Create('Foo'); // prevent event^.Method from being
set to nil
end;
procedure MT1.Execute;
begin
   try
     Synchronize(@MySync);
   except end;
   Sleep(10*1000);
   try
     Synchronize(@MySync);
   except end;
   while true do sleep(100*1000);
end;
procedure MT1.MySync;
begin
   writeln('x');
   raise Exception.Create('Foo'); // prevent event^.Next from being set
to nil
end;
begin
   T1 := MT1.Create(False);
   Sleep(2*1000);
   T2 := MT2.Create(False);
   Sleep(2*1000);
   CheckSynchronize(30*1000);
   CheckSynchronize(30*1000);
   CheckSynchronize(30*1000);
   CheckSynchronize(30*1000);
   readln;
end.

Martin Frb wrote

Actually from a further review of the source, there may be another issue:

https://bugs.freepascal.org/view.php?id=35027

El 6/2/19 a les 22:26, Martin Frb ha escrit:

On 06/02/2019 22:04, Martin Frb wrote: > Actually from a further review of the source, there may be another issue: https://bugs.freepascal.org/view.php?id=35027

The fact that FSynchronizeEntry^.Next was set to nil after the call to ThreadQueueAppend worried me, but in fact it causes the opposite problem (i.e., the method called twice in case an exception is raised). I'm sure there was no exception in my thread: it's encased in a try..except with a breakpoint in the except branch and the exception logged (though the logging in turn uses synchronize).

Bye

Luca Olivetti wrote

and the exception logged (though the logging in turn uses synchronize).

What OS?

On Windows you can use  LazLogger.  (in Laz 2.0.0) It uses TThread.Queue by default, but you can replace TLazLoggerFileHandleMainThread with TLazLoggerFileHandleThreadSave in

function TLazLoggerFile.GetFileHandle: TLazLoggerFileHandle;
begin
   if FFileHandle = nil then
     FFileHandle := TLazLoggerFileHandleMainThread.Create;
   Result := FFileHandle;
end;

That means that writeln is called in the same thread. (works (at least) on windows, but make sure the handle is opened by the main thread, or it will be closed by whatever thread did open it, when that thread exits).

El 7/2/19 a les 0:10, Martin Frb ha escrit:

Thank you, but by "logged" I mean it is shown on a memo (actually a TSynEdit because it has much better performance under windows) in the main form.

i.e.:

procedure TRF182C.DoLog(category: TLogCategory; const msg: string);
begin
   FLogStep:=1;
   FLogCategory:=category;
   FLogMsg:=msg;
   FLogStep:=2;
   synchronize(@SyncLog);
   FLogStep:=1000;
end;
procedure TRF182C.SyncLog;
begin
   FLogStep:=3;
   FLogProc(self,FLogCategory,CLogCategoryName[FLogCategory]+' RF182C
'+FLogMsg);
   FLogStep:=4;
end;

Note the "FLogStep" added to see where the thread stopped. It always stops with FLogStep 2.
FLogProc is assigned in Create and it's a method of the main form that adds the message to a TSynEdit (a different one depending on the sender thread) and logs it to a file.
The thread is created when the application starts and it's terminated when it's closed (normally never).

Bye

I dare say, I would consider elevating this, especially as it's a feature being used by an end user and is pretty serious if a multi-threaded program can sometimes freeze due to a race hazard.

Unfortunately, I don't use threads enough to know for sure how the underlying classes work, otherwise I'd take it on myself.

Gareth aka. Kit

On Fri 15/02/19 11:52 , "Luca Olivetti" sent:
El 6/2/19 a les 18:51, Sven Barth via fpc-devel ha escrit:

Would you nevertheless try with 3.2, please? Just in case it happens to be the problem I had fixed in regards to Queue().

With fpc from the fixes_3_2 branch, revision 41310, and lazarus from the fixes_2_0 branch revision 60414 it has been running for hours with no issue.

Mind me, that's not an absolute guarantee that it's working: I had the same program compiled with fpc 3.0.4/lazarus 1.8.4 running all night without triggering the issue, then I tried to introduce some randomness in the companion test program (that simulates an hardware I/O module I use in the field) and I could trigger it in a few minutes.

However, even if it's really fixed, I'm still worried: the changes in the threading code should only be relevant for Queue, not for Synchronize.

I hope it's not just luck and there are fixes in other areas of the compiler/rtl/lazarus that are affecting the outcome.

Bye

El 6/2/19 a les 18:51, Sven Barth via fpc-devel ha escrit:

Would you nevertheless try with 3.2, please? Just in case it happens to be the problem I had fixed in regards to Queue().

With fpc from the fixes_3_2 branch, revision 41310, and lazarus from the fixes_2_0 branch revision 60414 it has been running for hours with no issue.

Mind me, that's not an absolute guarantee that it's working: I had the same program compiled with fpc 3.0.4/lazarus 1.8.4 running all night without triggering the issue, then I tried to introduce some randomness in the companion test program (that simulates an hardware I/O module I use in the field) and I could trigger it in a few minutes.

However, even if it's really fixed, I'm still worried: the changes in the threading code should only be relevant for Queue, not for Synchronize. I hope it's not just luck and there are fixes in other areas of the compiler/rtl/lazarus that are affecting the outcome.

Bye

El 15/2/19 a les 12:27, J. Gareth Moreton ha escrit:

I dare say, I would consider elevating this, especially as it's a feature being used by an end user and is pretty serious if a multi-threaded program can sometimes freeze due to a race hazard.

The problem is, as I said before, I cannot reproduce it with a simple program that basically does the same, so I cannot really elevate it: the developers would have nothing to work with.
It could even be a bug in my code but I find it difficult to believe since it has been working for many years now.

Bye