Profiling RDF computing performance

ROOT
1

ROOT Version: 6.40.00+
Platform: Various
Compiler: Various

Hello dear forum,

For a while I have been wondering if there is a ROOT-native tool to check for RDF which component takes the most time. Lately, I have been trying to optimise some analysis code and have found that significantly reducing the amount of Defines is not as impactful as I would have expected. I use 10 threads, which for this code amounts to ~5e4 evt/s. The Describe summary:

Property                Value
--------                -----
Columns in total          935
Columns from defines       52
Event loops run             1
Processing slots           10

So I am making sure I am not accidentally running the loop several times. About 30 filters are booked and 300 histograms are produced (the same ~10 per filter). I have a few ideas what could cause the bottleneck but without some performance diagnostic, it is hard to tell.

Of course there are the classic profiling tools (val-/callgrind, perf, gprof, …), but I wonder if RDF (or ROOT in general) might have something inbuilt, which could be especially convenient for C macros. Especially if the bottleneck is file reading speed (there is a lot of TChaining going on), the profilers might not show that.

2

Dear @eska ,

Thanks for reaching out to the forum! You might try rootreadspeed for a profiling of the I/O specifically, with hints as to where your application might be spending most of its time.

$: rootreadspeed -h
Usage:
 rootreadspeed --files fname1 [fname2 ...]
               --trees tname1 [tname2 ...]
               (--all-branches | --branches bname1 [bname2 ...] | --branches-regex bregex1 [bregex2 ...])
               [--threads nthreads]
               [--tasks-per-worker ntasks]
 rootreadspeed (--help|-h)
 
 Use -h for usage help, --help for detailed information.

Cheers,
Vincenzo

3

Dear Vincenzo,

thanks a lot for the reply! This is a very useful tool. Indeed I did some tests with different machines to get a better feeling. I paste the summaries below:

LXPLUS AMD EPYC-Genoa 16-core Processor

Total number of tasks:     100
Thread pool size:          10
Real time to setup MT run: 1.623782 s
CPU time to setup MT run:  2.41 s
Real time:                 48.1548 s
CPU time:                  303.24 s
Uncompressed data read:    31937783270 bytes
Compressed data read:      9254749192 bytes
Uncompressed throughput:   632.507 MB/s
                           63.2507 MB/s/thread for 10 threads
Compressed throughput:     183.284 MB/s
                           18.3284 MB/s/thread for 10 threads

CPU Efficiency:   62.972%
Reading data is likely balanced (more threads may help though).

For lxplus, i also tested the program performance for the exact same files (btw if there is a way to process remote data with low latency, please let me know, that would be a really interesting tool for me):

LXPLUS: Program performance 
real 1m21.613s
user 5m9.025s
sys 1m9.564s
===========
RDF processing:
[Total elapsed time: 0:54m  processed files: 25  processed events: 1227268  2.27e+04 evt/s]

So I basically just ran the program as a one-liner time root -b -q -l macro.C so in the total time, the compilation is included, and in the RDF processing time, the booking (and some I/O) is not included. I mention I/O because I know from processing locally where I have no data striping, the process before triggering the event loop takes way more time than on lxplus (as a function of the threads used, I assume to load the data into RAM from the same memory block). What is highly puzzling here is that, excluding the compile time – which was like 10 seconds – the total processing time with the program would be shorter? That seems like it could not be.

I tested the I/O performance on my local machines as well.

Apple M1 8-thread Processor

Total number of tasks:     100
Thread pool size:          8
Real time to setup MT run: 1.397564 s
CPU time to setup MT run:  2.22 s
Real time:                 61.6315 s
CPU time:                  257.97 s
Uncompressed data read:    31937783270 bytes
Compressed data read:      9254749192 bytes
Uncompressed throughput:   494.199 MB/s
                           61.7749 MB/s/thread for 8 threads
Compressed throughput:     143.206 MB/s
                           17.9008 MB/s/thread for 8 threads

CPU Efficiency:   52.3211%
Reading data is likely balanced (more threads may help though).

AMD Ryzen 5950X 16-core Processor

Total number of tasks: 175
Thread pool size:               16
Real time to setup MT run:      0.715807 s
CPU time to setup MT run:       0.42 s
Real time:                      19.3743 s
CPU time:                       228.09 s
Uncompressed data read:         31937783270 bytes
Compressed data read:           9254749192 bytes
Uncompressed throughput:        1572.1 MB/s
                                98.256 MB/s/thread for 16 threads
Compressed throughput:          455.553 MB/s
                                28.4721 MB/s/thread for 16 threads

CPU Efficiency:                 73.5801%

I’m still trying to get an intuition for the values, but based on the documentation, a similar real time as the program computing time would suggest it’s a resource issue. The real time is significantly lower than the CPU time, so the second condition is not met either which would mean it’s not a resource issue. The last condition I don’t fully understand but seems reasonably fast on all machines, but this might also be a lack of intuition on the numbers on my part.

Lastly, what does CPU efficiency mean? My assumption is that it probably refers to how “free” the machine resources are, which would make sense given shared resource on lxplus vs the specs of the other two machines but maybe I misunderstood.

But to come back to the initial question, I am pretty sure that there is an issue in how I interpret the data because RDF can run more than 50 times faster in the event loop if the program is “trivial”. Of course, depending on the complexity of information I need to extract, I don’t expect the same performance, but after all my goal was to identify the bottleneck in order to understand if something can be done. Is it safe to assume that it is not an I/O issue based on the results?

P.S.: Not to add much more to an already too long reply, but may I ask if there is an overview of all the ROOT-adjacent terminal commands? As some of them have been very useful to me (like hadd and rooteventselector and now rootreadspeed), it would be nice to have an easily accessible overview.