ARTDAQ confusion at 10 kHz

[pavel1murat]

We're running in a configuration with the HW CFO sending an infinite 10 Hz HB+EWM train with 100 usec windows (CFO run plan - below) , so the input rate is 10 kHz.

• the ARTDAQ configuration includes a CFO reader, 6 BRs, each sending one fragment, 1 EB , and 1 DL
• the EB is running 4 filter processes, a filter implements a random prescale by x10
• the CFO reader limits the subrun size to 50,000 events

After about 2x10^5 input events (within a minute) the EB process starts complaining about the back-pressure, after that - about
events missing one of the fragments, and the output of the job fades down to zero...

%MSG
%MSG-i eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:07:49 CDT pre-events SharedMemoryEventManager.cc:1474
eb97 statistics:
  Event statistics: 206299 events released at 6869.93 events/sec, effective data rate = 31.7166 MB/sec, monitor window = 30.0293 sec, min::max event size = 0.00444031::0.00810242 MB
  Average time per event:  elapsed time = 0.000145562 sec
  Fragment statistics: 1445029 fragments received at 47954 fragments/sec, effective data rate = 31.3647 MB/sec, monitor window = 30.1337 sec, min::max fragment size = 8.39233e-05::0.00244904 MB
  Event counts: Run -- 206299 Total, 0 Incomplete.  Subrun -- 0 Total, 0 Incomplete. 
  Shared Memory: 250 buffers of 700000 B, 45 Empty, 186 Writing, 19 Full, 0 reading
%MSG
%MSG-i eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:07:56 CDT pre-events SharedMemoryEventManager.cc:1104
Will roll over to subrun 6 when I reach Sequence ID 250499
%MSG
%MSG-i eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:03 CDT pre-events SharedMemoryEventManager.cc:1104
Will roll over to subrun 7 when I reach Sequence ID 300399
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:07 CDT pre-events SharedMemoryEventManager.cc:263
eb97: Back-pressure condition: All Shared Memory buffers have been full for 1.00106 s! There are 4 art processes connected.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:08 CDT pre-events SharedMemoryEventManager.cc:263
eb97: Back-pressure condition: All Shared Memory buffers have been full for 2.00209 s! There are 4 art processes connected.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:09 CDT pre-events SharedMemoryEventManager.cc:263
eb97: Back-pressure condition: All Shared Memory buffers have been full for 3.00241 s! There are 4 art processes connected.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:10 CDT pre-events SharedMemoryEventManager.cc:263
eb97: Back-pressure condition: All Shared Memory buffers have been full for 4.00481 s! There are 4 art processes connected.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:11 CDT pre-events SharedMemoryEventManager.cc:1393
Event 316556 was opened 5.01496 s ago and has timed out (missing 1 Fragments).Scheduling release to art.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:11 CDT pre-events SharedMemoryEventManager.cc:1393
Event 316557 was opened 5.01499 s ago and has timed out (missing 1 Fragments).Scheduling release to art.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:11 CDT pre-events SharedMemoryEventManager.cc:1393
Event 316558 was opened 5.01492 s ago and has timed out (missing 1 Fragments).Scheduling release to art.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:11 CDT pre-events SharedMemoryEventManager.cc:1393
Event 316559 was opened 5.01485 s ago and has timed out (missing 1 Fragments).Scheduling release to art.
%MSG
%MSG-w eb97_SharedMemoryEventManager:  Early 01-Apr-2026 18:08:11 CDT pre-events SharedMemoryEventManager.cc:1393

The ARTDAQ filter logs show one clear inconsistency, as illustrated by the following excerpt. Given that the subrun size is limited by 50,000 events, events 316882 and 447644 can't have the same subrun number...

%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316870
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316874
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316861
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316878
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316882
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 447644
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316873
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |
%MSG
%MSG-d RANDOM:  ProcessEvent 01-Apr-2026 18:08:16 CDT  run: 120731 subRun: 7 event: 316888
RNGservice::takeSnapshot_() of the following engine labels:
 | RandomPrescaleFilter:0: |

[pavel1murat]

• to add, this problem is not excited when we run at input rate of 1, 2, or 5 kHz.
• At 5 kHz, the event builder times out in the end of the run , not being able to finish the end run transition within the alloted 60 seconds . The last output file gets properly closed.