Problem 2212

A TOPAS user brought me a case where having more than 1 worker thread results in gradual but eventually severe slowdown of processing, that is, over time he sees the CPU usage going from 100% to 50% or less.
I have been able to consistently reproduce this.
The workers eventually spend almost all their time waiting on some sort of lock.
Here are the details:

Latest TOPAS, so based on Geant4.10.5.p1.
User reports issue was is not present in the TOPAS that was based on Geant4.10.4.
It is something new since Geant4.10.5.

I am unable to run any quick tests in Geant4.10.6 as it will require other work to bring TOPAS up to 10.6,
however I do not see anything in the 10.6 release notes that would seem to involve this issue, so suspect the issue is still present.

The setup is very simple.
A proton beam in vacuum hitting a small (cm scale) cylinder of water.
No scoring, no output at all except for reporting event number to console every 10K events.
User initially saw this in clinical protons, 100MeV range, then noted that he could make the problem occur in fewer events if he increased the energy to 1GeV. So for my tests I've been using 1GeV.

Physics list is the default modular physics list for TOPAS, which contains modules:
G4EMStandardPhysics_option4
G4HadronPhysicsQGSP_BIC_HP
G4DecayPhysics
G4IonBinaryCascadePhysics
G4HadronElasticPhysicsHP
G4StoppingPhysics

If I run a job with 7 worker threads on my Mac, then at the start, as expected, activity monitor shows the job uses 700%.
Then, over time, the CPUs start spending more and more of their time idle.
At 11 hours total CPU time, I'm seeing only 200% total CPU being used rather than the expected 700% even though there are tons more events still to be processed.

At first I thought maybe some workers were stuck, but from my console logs that report the event number every 10K events, I can see that all workers are still working at equal rates to each other. It just seems like the workers are spending most of their time waiting rather then using CPU.

I did some tests and saw that there is no issue if I only run one worker thread
(note that all of my TOPAS work is using Geant4 in MT mode, even if I only have one worker thread).
But the slowdown gets worse the more events are run (a very linear degradation),
and the slowdown gets worse the more worker threads are used.

Testing with 1, 2 and 4 workers, what I see at around 125M events is:
Job with 1 worker: still running 100%
Job with 2 workers: only getting 185%. So lost 15%/2threads = 7.5% per thread
Job with 4 workers: only getting 290%. So lost 110%/4threads = 27% per thread

Also of note: while one would expect the total CPU time (total over all threads) to be roughly the same for a 2 worker job or a 4 worker job, the 4 worker job actually took significantly more total CPU time to do the same total number of events.

The issue is resolved if the physics modules are reduced to only G4EMStandardPhysics_option0.
All workers then always stay at 100% CPU.

Similarly, the issue is resolved if the physics list is switched to FTFP_BERT
(this was an additional test requested of me by Makoto).

Issue is reproducible on both Linux and OSX.

I left one of the 4 worker tests running a long time until it got very badly affected, then did some sampling from Activity Monitor to see what the workers were doing.
Call Tree is attached.
If I'm reading this correctly, the majority of time is being spent in a mutex wait in the call chain:
G4BinaryCascade... G4PreCompoundModel... G4ExcitationHandler... G4IonTable

I don't see anything in the Geant4.10.6 release notes to indicate anything like this has already been seen and fixed.

I don't see any bug report that seems related.
Is this something you have seen?
I wonder if it is not noticed by others as this case is running a much higher number of events than one usually does.


On Makoto's request, I ran some memory leakage tests:
Again running in 7 worker threads.
Looked at memory as shown in OSX Activity Monitor, so this is the total including all worker threads and master.
Checked at 10M events, 20M events, 30M, 40M and 50M.
Ignoring the first 10M events, the job that had the CPU slowdown issue leaks 101M for each 10M events.
The leakage rate is very steady for each additional 10M events. That is, it is linear.

EM only test and FTFP_BERT tests leak much smaller amounts, maybe 100K for each 10M events (and it is possible that this
leak is in the TOPAS layer, not Geant4).

I apologize for not yet having a simple Geant4 setup for this. I instead attach the TOPAS parameter file.

I also attach the Activity Monitor call graph taking when the job has slowed to a crawl.