Added unpack_tsa_mcbm_with_eb.C to /macro/beamtime/mcbm2020. This extends the...

A new macro unpack_tsa_mcbm_with_eb.C, which combines unpack_tsa_mcbm.C and build_event_win.C, as requested. It uses the new event builder class. It was tested on run 831 using the input file /lustre/cbm/users/ploizeau/mcbm2020/data/831_pn02_0001.tsa and it was verified to generate the same output as a sequential run of the two original macros.

An non-understood feature is the following: During tests, the macro produces two entries in the output tree cbmsim;16 and cbmsim;17. The events which are stored in the later are the ones which match the output of the original macros. The former tree contains a slightly lower number of events, but the event time histories look very similar regardless, leading me to believe that this is at least partially the same data.

This feature is already present in the original macro unpack_tsa_mcbm.C, i.e. two separate cbmsim entries are produced (without a CbmEvent branch of course). Perhaps @p.-a.loizeau can comment on this. I'm guessing this isn't actually a problem.

Otherwise, the macro seems to do what it should. I set the merge request to WIP as this is likely only the first step. Input from @f.uhlig @v.friese and @p.-a.loizeau is desireable at this point.

On edit: Timings using TStopwatch is now implemented for CbmAlgoBuildRawEvents and CbmTaskBuildRawEvents.

added 3 commits

• 6abb0c26...00116898 - 2 commits from branch computing:master
• 417eef5d - Added unpack_tsa_mcbm_with_eb.C to /macro/beamtime/mcbm2020. This extends the...

Compare with previous version

changed the description

Dear @f.uhlig, @p.-a.loizeau,

you have been identified as code owner of at least one file which was changed with this merge request.

Please check the changes and approve them or request changes.

added CodeOwners label

unmarked as a Work In Progress

added 27 commits

• 417eef5d...4740197f - 26 commits from branch computing:master
• 78794384 - Added unpack_tsa_mcbm_with_eb.C to /macro/beamtime/mcbm2020. This extends the...

Compare with previous version

@v.friese @f.uhlig I have removed the WIP flag. I think this merge request can be merded in the present form. The macro in the current state is usable.

approved this merge request

added 6 commits

• 78794384...c3a119ac - 5 commits from branch computing:master
• 3f2af8b4 - Added unpack_tsa_mcbm_with_eb.C to /macro/beamtime/mcbm2020. This extends the...

Compare with previous version

added 3 commits

• d08c3ba4 - 1 commit from branch computing:master
• d574fb30 - Added unpack_tsa_mcbm_with_eb.C to /macro/beamtime/mcbm2020. This extends the...
• 73b348bf - CbmAlgoBuildRawEvents: Implemented timing using TStopwatch.

Compare with previous version

changed the description

@f.uhlig @v.friese @p.-a.loizeau

I added a TStopwatch object to CbmAlgoBuildRawEvents which is instantiated if the fbGetTimings flag is set, and which measures the total runtime of the event builder algorithm. It is started and stopped at the beginning and end of each iteration of ProcessTS(), and once during Init(), so it should obtain the pure runtime of the algorithm and nothing more.

If I run unpack_tsa_mcbm.C and subsequently unpack_tsa_mcbm_with_eb.C, using the same input file, I get

>>> unpack_tsa_mcbm: Macro finished successfully.
>>> unpack_tsa_mcbm: Output file is data/unp_mcbm_831.root
>>> unpack_tsa_mcbm: Real time 172.271 s, CPU time 164.08 s

and

[INFO] Event builder: Real time 14.6376 s, CPU time 14.68 s
>>> unpack_tsa_mcbm_with_eb: Macro finished successfully.
>>> unpack_tsa_mcbm_with_eb: Output file is data/unp_mcbm_831.root
>>> unpack_tsa_mcbm_with_eb: Real time 213.692 s, CPU time 211.8 s

This tells me the following:

1. Event building is a subleading contribution to the runtime when compared to unpacking.
2. The event builder task adds a fairly large overhead when compared to the event building algo alone.

The second is an indirect conclusion, drawn the mismatch of the sums. Most likely it has to do with the additional copy operation from the digi manager to the std::vector containers. I will investigate further.

added 1 commit

• 3032912b - CbmTaskBuildRawEvents: Implemented timing using TStopwatch.

Compare with previous version

I have now implemented timings also in the Task class. I am aware that something similar can probably be achieved using FairMonitor, but that seemed to be more complicated in the end. I wonder whether it would be a good idea to include a TStopwatch in the FairTask base class.

The output is now the following

[16:04:26][INFO] CbmAlgoBuildRawEvents: Real time 14.4777 s, CPU time 14.46 s
[16:04:26][INFO] CbmTaskBuildRawEvents: Real time 46.9437 s, CPU time 46.88 s
>>> unpack_tsa_mcbm_with_eb: Macro finished successfully.
>>> unpack_tsa_mcbm_with_eb: Output file is data/unp_mcbm_831.root
>>> unpack_tsa_mcbm_with_eb: Real time 220.531 s, CPU time 211.98 s

So yes indeed, the Task produces a lot of overhead in the present form.

changed the description

assigned to @v.friese

Waiting for approval by Pierre-Alain and Florian.

approved this merge request

added 5 commits

• bb84a71d - 1 commit from branch computing:master
• acf656fd - Added unpack_tsa_mcbm_with_eb.C to /macro/beamtime/mcbm2020. This extends the...
• 1be95d7f - CbmAlgoBuildRawEvents: Implemented timing using TStopwatch.
• 26702078 - CbmTaskBuildRawEvents: Implemented timing using TStopwatch.
• 96661dc8 - BuildRawEvents: More detailed information is produced when timing algo and task classes.

Compare with previous version

I just added some additional timing output, which makes the partitioning of the work load a little more clear.

The Init() functions of both the algo and the task are indeed negligible, and in my example run give:

12:07:58][INFO] CbmTaskBuildRawEvents::Init(): Real time 0.00158906 s, CPU time 0 s
[12:07:58][INFO] CbmAlgoBuildRawEvents::InitAlgo => Starting sequence
[12:07:58][INFO] CbmAlgoBuildRawEvents::Init(): Real time 0.0158029 s, CPU time 0.02 s
[12:07:58][INFO] CbmAlgoBuildRawEvents::InitAlgo => Done

On the other hand, an additional timer reveals that the copying of the digis from the digi manager to std::vector is indeed by far the most expensive step, with roughly twice the run time of the event builder itself:

[12:11:40][INFO] CbmAlgoBuildRawEvents: Real time 15.092 s, CPU time 15 s
[12:11:41][INFO] CbmTaskBuildRawEvents: Real time 46.9759 s, CPU time 46.93 s
[12:11:41][INFO] CbmTaskBuildRawEvents (digi copy only): Real time 31.7628 s, CPU time 31.81 s

I'm not sure that this will get better with larger time slices, as there will also be more stuff to copy. But I understand that this copy operation is in the end just a place holder. If there was a way to fetch std::vectors directly from the FairRootManager or DigiManager then we could get rid of it.