Project

General

Profile

Bug #1310

TOF reducer runs slow

Added by Rogers, Chris about 8 years ago. Updated about 8 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Online reconstruction
Target version:
Start date:
13 July 2013
Due date:
% Done:

100%

Estimated time:
Workflow:
New Issue

Description

The TOF reducer is running very slow. After 56685 events in ckov reducer (and MAUS input), tof reducer has only processed 8974 events. I fixed this in the integration test by changing the rate at which the thing prints. I can do that again in the production version.


Files

4921_process_monitor.log (416 KB) 4921_process_monitor.log Rogers, Chris, 13 July 2013 06:11
maus-input-transform.log (16.5 MB) maus-input-transform.log Rogers, Chris, 13 July 2013 06:11
reconstruct_daq_ckov_reducer.log (4.09 MB) reconstruct_daq_ckov_reducer.log Rogers, Chris, 13 July 2013 06:11
reconstruct_daq_tof_reducer.log (662 KB) reconstruct_daq_tof_reducer.log Rogers, Chris, 13 July 2013 06:11
#1

Updated by Rogers, Chris about 8 years ago

Nb: I added a process monitor log with memory usages (snapshot every 60 seconds)

#2

Updated by Rogers, Chris about 8 years ago

Tried reducing refresh rate to refresh every 10 spills; lagging by about a factor 4; so trying now with refresh every 40 spills. A better way to do this may be to hand TCanvas around and display TCanvas in a ROOT GUI...

#3

Updated by Rogers, Chris about 8 years ago

Still lagging with refresh rate = 40; try refresh rate = 60

#4

Updated by Rogers, Chris about 8 years ago

Nb: a side-effect of this lagging is that the histograms don't refresh on start/stop because MAUS only detects end-of-run by peeking at the run number; if we are still plotting the old data we don't see the new run coming in yet.

#5

Updated by Rogers, Chris about 8 years ago

Refresh every 60 spills seems to be okay - that's every two minutes which is irritating but I guess not completely intolerable. Let's do some experiments on other refresh rates...

#6

Updated by Rogers, Chris about 8 years ago

Note that even with no output (i.e. image_list is just an empty python list) we still get ~ 3 minute lag over 1350 DAQ events (about 420 spills => 18 minutes running).

#7

Updated by Rogers, Chris about 8 years ago

Setting _update_histograms to return just [] and the reducer can keep up (over 1000 daq events). Setting _update_histograms to return [] after filling histograms but before printing anything and reducer can keep up (even with refresh rate set to 3). So it is really the print stage, and it happens regardless of whether we offer print to ROOT format or print to png format.

I think this means we have to change the API to pass data across in memory, using ROOT socket or similar as is done in the online (DAQ) monitor application. Fun!

#8

Updated by Rogers, Chris about 8 years ago

  • Status changed from Open to Closed
  • Assignee changed from Rajaram, Durga to Rogers, Chris
  • % Done changed from 0 to 100

Fine. So a workaround exists and appears to work even if it is a bit rubbish, so I am going to set this one as Closed - and open a new issue on the API, which is a bigger job (and won't get done by shifter training for example).

#9

Updated by Rogers, Chris about 8 years ago

Just to confirm - with refresh rate at 60 I get, after running cosmics for ~ 16 hours

==> reconstruct_daq_ckov_reducer.log <==
<08:58:20.589750> Read event 66178 reconstructed at 2013-07-16 08:58:18.264000)
Processed 66170 DAQ events from run 4928
<08:58:21.285621> Read event 66179 reconstructed at 2013-07-16 08:58:20.773000)
Processed 66171 DAQ events from run 4928
<08:58:23.816810> Read event 66180 reconstructed at 2013-07-16 08:58:23.332000)
Processed 66172 DAQ events from run 4928
<08:58:24.317817> Read event 66181 reconstructed at 2013-07-16 08:58:23.340000)
Processed 66173 DAQ events from run 4928
<08:58:24.829473> Read event 66182 reconstructed at 2013-07-16 08:58:23.351000)
Processed 66174 DAQ events from run 4928

==> reconstruct_daq_scalars_reducer.log <==
Failed to execute Output
Processed 66172 DAQ events from run 4928
<08:58:24.317431> Read event 66181 reconstructed at 2013-07-16 08:58:23.340000)
save to  /home/mice/MAUS/.maus_rogers-dev/third_party/install/lib/maus-apps-0.2/media/raw/scalers.json
Failed to execute Output
Processed 66173 DAQ events from run 4928
<08:58:24.829430> Read event 66182 reconstructed at 2013-07-16 08:58:23.351000)
save to  /home/mice/MAUS/.maus_rogers-dev/third_party/install/lib/maus-apps-0.2/media/raw/scalers.json
Failed to execute Output
Processed 66174 DAQ events from run 4928

==> reconstruct_daq_tof_reducer.log <==
<08:58:20.589570> Read event 66178 reconstructed at 2013-07-16 08:58:18.264000)
Processed 66170 DAQ events from run 4928
<08:58:21.285634> Read event 66179 reconstructed at 2013-07-16 08:58:20.773000)
Processed 66171 DAQ events from run 4928
<08:58:23.816414> Read event 66180 reconstructed at 2013-07-16 08:58:23.332000)
Processed 66172 DAQ events from run 4928
<08:58:24.317466> Read event 66181 reconstructed at 2013-07-16 08:58:23.340000)
Processed 66173 DAQ events from run 4928
<08:58:24.829426> Read event 66182 reconstructed at 2013-07-16 08:58:23.351000)
Processed 66174 DAQ events from run 4928

==> reconstruct_monitor_reducer.log <==
Processed 66171 DAQ events from run 4928
<08:58:23.816427> Read event 66180 reconstructed at 2013-07-16 08:58:23.332000)
Failed to execute Output
Processed 66172 DAQ events from run 4928
<08:58:24.317443> Read event 66181 reconstructed at 2013-07-16 08:58:23.340000)
Failed to execute Output
Processed 66173 DAQ events from run 4928
<08:58:24.829387> Read event 66182 reconstructed at 2013-07-16 08:58:23.351000)
Failed to execute Output
Processed 66174 DAQ events from run 4928
#10

Updated by Rajaram, Durga about 8 years ago

  • Target version changed from Future MAUS release to MAUS-v0.6.0

Also available in: Atom PDF