Mutex Contention of root file write out

[tontyoutoure]

Recently I did a simulation on a 96 core machine with lot of root write out (almost all event need to be write out and the simulation geometry is quite simple). The mutex lock in this call stack

takes >95% of the CPU time.

I know this scenario is not very typical, still I think it's worth addressing.

The overall flamegraph looks like this:

[BishopWolf]

I now have complete root-cause identification plus a locally reproduced A/B profile. Here is the detailed report.

---

Bug report — #1143

Mutex contention in ROOT write-out (MT digitizer/hits output)

Verdict: confirmed and fully diagnosed. The mutex is Geant4's file-scope pntupleMutex in G4RootPNtupleManager, which GATE engages by calling ram->SetNtupleMerging(true) in MT. It is a performance/scalability defect, not a correctness bug, and it is long-standing (inherited from the legacy GAM/Gate code, not a 10.1.x regression). Reproduced locally with a clean A/B profile.

Nothing was modified. All probes were read-only; the benchmark and profiler outputs were written only to /tmp. git status was unchanged.

DeepSeek v4.1 flash

---

1. The reported symptom, decoded

"The mutex lock in this call stack takes >95% of the CPU time."

In a sampling profile, "time in the mutex" is not the mutex spinning — it is threads blocked in __psynch_mutexwait, i.e. the parallel simulation has collapsed onto a single serialized writer. The call stack is Geant4's parallel-ntuple writer:

G4RootPNtupleManager::AddNtupleRow(int)
  G4TemplateAutoLock<std::mutex>::G4TemplateAutoLock(std::mutex*)   <-- G4AutoLock on pntupleMutex
    std::mutex::lock()
      _pthread_mutex_firstfit_lock_slow
        _pthread_mutex_firstfit_lock_wait
          __psynch_mutexwait

and, holding the same mutex, the flush+compression:

G4RootPNtupleManager::AddNtupleRow -> mt_ntuple_column_wise::add_row(imutex&, ifile&)
  -> branch::pfill -> mt_ntuple_column_wise::flush_baskets -> branch::add_basket
    -> basket::write_on_file -> file::compress_buffer -> toolx::compress_buffer -> deflate

---

2. Environment and method

Item	Value
Tree	/Users/alex/Documents/GIT/opengate, branch agentic-skills (fixes from master present)
Python / env	3.12.13, /Users/alex/opengate; opengate/opengate_core 10.1.1 editable
Geant4 / ITK	11.4.2 (geant4-11-04-patch-02, MT) / ITK 6.0.0 (matches the CI Geant4 pin)
Machine	macOS, 12 logical / 6 physical cores
Geant4 source inspected	/Users/alex/Documents/GIT/geant4 (same 11.4.2 tree used to build opengate_core)
Profiler	/usr/bin/sample <pid> 6 -mayDie (1 ms sampling), reports in /tmp

Reproducer (written to /tmp, never to the repo): 20 cm water box, 140.5 keV point gamma source, G4EmStandardPhysics_option4, DigitizerHitsCollectionActor with clear_every = 1 and write_to_disk toggled, number_of_threads ∈ {1,12}.

---

3. Root-cause chain (exact code)

(1) GATE forces Geant4 ntuple merging in MT — core/opengate_core/opengate_lib/digitizer/GateDigiCollectionsRootManager.cpp:37-45:

if (G4Threading::IsMultithreadedApplication()) {
  auto *run = G4RunManager::GetRunManager()->GetCurrentRun();
  if (run) { if (run->GetRunID() == 0 && tupleId == 0) ram->SetNtupleMerging(true); }
  else ram->SetNtupleMerging(true);
}
ram->OpenFile(filename);

This is the call that selects the slow path. It has been there since the original code (git blame → GamHitsCollectionsRootManager.cpp, 2021-12-17, carried through renames).

(2) Merging = master kMain, workers kSlave — Geant4 source/analysis/root/src/G4RootNtupleFileManager.cc:96-117:

if (isMaster) fNtupleMergeMode = G4NtupleMergeMode::kMain;
else          fNtupleMergeMode = G4NtupleMergeMode::kSlave;

(3) Every worker gets a G4RootPNtupleManager — G4RootNtupleFileManager.cc:262-268:

case G4NtupleMergeMode::kSlave:
  fSlaveNtupleManager = make_shared<G4RootPNtupleManager>(fState, fBookingManager, mainNtupleManager, ...);

(4) The mutex: one process-wide lock, taken per row — source/analysis/root/src/G4RootPNtupleManager.cc:43 and ~333-360:

//Mutex to lock master manager when adding ntuple row and ending fill
G4Mutex pntupleMutex = G4MUTEX_INITIALIZER;      // file scope, shared by ALL threads

G4bool G4RootPNtupleManager::AddNtupleRow(G4int ntupleId) {
  ...
  G4AutoLock lock(&pntupleMutex);   // <-- acquired on EVERY row
  lock.unlock();
  mutex toolsLock(lock);            // same mutex handed to the writer
  auto result = ntupleDescription->GetNtuple()->add_row(toolsLock, *rfile);

Two serialization points on the same mutex:

• the G4AutoLock lock(&pntupleMutex) at the top of every AddNtupleRow (so even a row that does not flush still blocks behind whoever holds the lock), and
• mt_basket_add::add_basket (source/externals/g4tools/include/tools/wroot/mt_basket_add), which holds the lock while the basket is compressed and written into the one shared main file:

virtual bool add_basket(basket* a_basket) {
  m_mutex.lock();
  ... m_main_branch.add_basket(m_main_file, *a_basket, add_bytes, nout); ...
  m_mutex.unlock();

(5) GATE calls it once per row, from the per-event path — GateDigiCollection.cpp:

void GateDigiCollection::FillToRoot() {
  for (size_t i = 0; i < GetSize(); i++) {
    for (auto *att : fDigiAttributes) att->FillToRoot(i);
    am->AddNtupleRow(fTupleId);          // <-- per row, inside the global lock
  }
  Clear();
}

driven by GateVDigitizerWithOutputActor::BeginOfEventAction → FillToRootIfNeeded(...) (GateVDigitizerWithOutputActor.cpp:111-119).

So: all N worker threads append every scored row into a single ROOT file, through a single global mutex, and the actual compression + file I/O happens while that mutex is held. With a simple geometry and “almost all events written out”, the write path is the dominant cost, all cores queue on pntupleMutex, and the profile fills with __psynch_mutexwait.

---

4. Runtime reproduction and A/B evidence (local)

Same workload (12 threads, 1 500 000 primaries, ≈3.6 hit rows/event), only write_to_disk changed:

	ROOT output ON	ROOT output OFF
Wall time	21.4 s (G4 run 18.7 s)	9.0 s
__psynch_mutexwait (top-of-stack samples)	34 533	0
__psynch_cvwait	53 170	27 648
G4RootPNtupleManager frames	225	0
total top-of-stack samples	105 445	36 460

• 32.7 % of all sampled thread time is blocked on a mutex with ROOT output, and exactly 0 % without it — the mutex traffic is 100 % attributable to the ROOT write path.
• Enabling ROOT output made this run 2.4× slower even on a 12-core laptop; on the reporter's 96 cores the fraction rises towards the reported >95 %, because more threads contend for the same serialized writer while per-thread compute shrinks.
• The single shared file confirms merging is active: output was one ..._Hits-root_output.root with 215 612 entries (no per-thread _nt_<thread>.root files).
• Direct stack evidence (from /tmp/og1143_sample.txt):

G4RootPNtupleManager::AddNtupleRow(int) + 525
  G4TemplateAutoLock<std::mutex>::G4TemplateAutoLock(std::mutex*)
    std::mutex::lock() + 9
      _pthread_mutex_firstfit_lock_slow
        _pthread_mutex_firstfit_lock_wait
          __psynch_mutexwait                       (2870 samples in this stack alone)

G4RootPNtupleManager::AddNtupleRow(int) + 610
  mt_ntuple_column_wise::add_row(imutex&, ifile&)
    branch::pfill -> flush_baskets -> branch::add_basket -> basket::write_on_file
      -> file::compress_buffer -> toolx::compress_buffer -> deflate/deflate_fast/longest_match

---

5. Secondary observations

• Not a regression. SetNtupleMerging(true) is legacy (2021-12-17, GamHitsCollectionsRootManager.cpp → renamed). Nothing in the 10.1.x line introduced it.
• Non-thread-safe lazy singleton (robustness, not the perf issue): GateDigiCollectionsRootManager::GetInstance() does if (fInstance == nullptr) fInstance = new ...; with no lock — a data race on first concurrent use.
• The default clear_every is 1e5 (Python) / 100000 (C++); the reporter's “almost all events written” corresponds to small clear_every/high row volume, which maximizes AddNtupleRow calls and therefore lock acquisitions.
• GATE's own attempt at mitigating via basket sizing is present but commented out, with a note that it does not work: GateDigiCollectionsRootManager.cpp:30-32 (SetBasketEntries(8000), SetBasketSize(5e6)). Default g4tools basket size is 32000 bytes (tools/wroot/branch).

---

6. Mitigations (with trade-offs)

User-side, no code change

• Reduce row volume: filters, fewer attributes columns, larger clear_every, skip_attributes. Directly cuts lock acquisitions.
• Use fewer threads for write-dominated runs (e.g. number_of_threads small) — the writer is serial anyway, so extra cores only add contention.

GATE-side, small

• Revisit SetBasketSize/SetBasketEntries (currently commented out) so the pntuple baskets are larger → fewer, longer-but-rarer locked flushes. It must be applied on the PNtuple path (before ntuples are created), which is likely why the existing attempt “did not seem to work”.

GATE-side, structural (largest win)

• Stop enabling Geant4 merging in MT (SetNtupleMerging(false)), letting each worker write its own <stem>_nt_<thread>.root, and add a post-run merge. This removes the global mutex entirely, at the cost of a merge step. Important: GATE already has a RootMergeCoordinator (opengate/coordinators.py:121, used from opengate/jobs.py for split-run/job merging), but it does not currently merge Geant4 per-thread _nt_<thread>.root files for digitizer outputs — extending it (uproot-based) is required, otherwise users would silently get N files.

Upstream (Geant4)

• G4RootPNtupleManager::AddNtupleRow takes pntupleMutex on every row (G4AutoLock lock(&pntupleMutex); lock.unlock();) and holds it across basket::write_on_file/zlib deflate. A finer-grained or deferred/flush-only locking strategy would remove the per-row serialization. Worth filing upstream.

---

7. Limitations of the local reproduction

• The machine has 12 logical / 6 physical cores, so the absolute contention is far milder than the reporter's 96 cores: I measured ~33 % of samples in mutex wait and a 2.4× slowdown, versus their >95 %. The mechanism and its attribution (mutex traffic = 0 % without ROOT output, 100 % with it) are unambiguous; the magnitude does not transfer.
• At very small workloads the numbers are dominated by Geant4 MT startup overhead (e.g. 60 000 primaries: 12 threads slower than 1 thread even without ROOT). I therefore profiled at 1.5 M primaries where the write path dominates.
• The >95 % figure upstream is presumably a wall-clock/flamegraph attribution; my measurement is sample-based samples, which is the closest reproducible proxy.

---

8. One-line summary

GATE calls ram->SetNtupleMerging(true) in MT, which makes Geant4 route every worker's ROOT rows through G4RootPNtupleManager; that class takes a single process-wide pntupleMutex on every AddNtupleRow and holds it while compressing/writing baskets into one shared file (G4RootPNtupleManager.cc:43,347-356 + mt_basket_add::add_basket), so with a write-dominated workload all cores serialize on that lock — reproduced here as 34 533 __psynch_mutexwait samples and a 2.4× slowdown with ROOT output enabled, versus zero mutex waits and G4RootPNtupleManager frames with it disabled.