Faster version of GetEntry()?

ROOT
21

Hi,

if you cannot host it, maybe this works: 1fichier.com/en

Cheers, Axel.

22

Axel, please check your email.

23

Hi,

I get

root [0] TFile f("run646647.root")
x<�Ƿ�'�t_=y`~gz����l�77��h��Cer>: Unknown class �G�0<���Gq�y��� v��h��^���cA
Info in <TFile::GetStreamerInfoList>: cannot find the StreamerInfo record in file run646647.root

(And yes, these funny characters is really what I see). Even worse:

root [2] f.Map()
20101208/173012  At:100  N=124       TFile         
20101208/173013  At:224  N=1537      TBasket        CX = 20.03
20540000/000156  At:1761  N=1596101076                 CX =  0.00
Address = 1596102837	Nbytes = -1697158391	=====G A P===========
20540000/000156  At:3293261228  N=1         END

shows that the file is broken. Do you also see the unknown class error? What does f.Map() show in your case?

To ensure that I got the file intact let’s compare this:

$ md5sum run646647.root 
e12d291f7b70a4eb4ff37a5cca4036c3  run646647.root

Cheers, Axel.

24

Axel, apologies, this was my fault: when uploading the file onto the ftp server I forgot to do “binary”, so the file got corrupted in transfer (haven’t used ftp for 12 years!!).

I just uploaded the file again, and downloaded it to verify that it’s fine. Please do remember to “binary” before “get”-ing.

25

Hi,

as expected, the time is extremely constant. For slices of 10k entries I get:

root [0] 
Processing speed.C...
51928 entries/s
52201 entries/s
52138 entries/s
52145 entries/s
52221 entries/s
52231 entries/s
52174 entries/s
52191 entries/s
52213 entries/s
52154 entries/s
52181 entries/s
48908 entries/s

and for slices of 1M entries I get

root [0] 
Processing speed.C...
50650 entries/s
50426 entries/s
50148 entries/s
50478 entries/s
50245 entries/s
50433 entries/s
50483 entries/s
50046 entries/s
50429 entries/s

This is speed.C:

void speed(){
   TFile* f = TFile::Open("run646647.root");
   TTree *tree = (TTree*)f->Get("ptree");
   TStopwatch s;
   const int timeslice = 10000;
   Long64_t n = tree->GetEntries();
   for (Long64_t i = 0; i < n; ++i) {
      tree->GetEntry(i);
      if (i && !(i % timeslice)) {
         Double_t rt = s.RealTime();
         printf("%d entries/s\n", timeslice/rt);
         s.Start();
      }
   }
   delete f;
}

So the problem is most likely in your analysis code.

Cheers, Axel.

26

Yep, this is what I get when I run speed():

Beggining:

root [0] .L speed.C 
root [1] speed()
30700 entries/s
101462 entries/s
73073 entries/s
97007 entries/s
98910 entries/s
98550 entries/s
98046 entries/s
97080 entries/s
95480 entries/s
94586 entries/s
94199 entries/s
76993 entries/s
91829 entries/s
90166 entries/s
89668 entries/s
88897 entries/s
88753 entries/s
87458 entries/s
84056 entries/s
86177 entries/s
84679 entries/s
81539 entries/s
82634 entries/s
82299 entries/s
82107 entries/s
81131 entries/s
80836 entries/s
80171 entries/s
77271 entries/s
78803 entries/s
77428 entries/s
76838 entries/s
76869 entries/s
75342 entries/s

and this is the output for the last 100000 entries (modified the loop limits in speed.C):

root [0] .L speed.C 
root [1] speed()    
8796 entries/s
3527 entries/s
3337 entries/s
3304 entries/s
3315 entries/s
3346 entries/s
3345 entries/s
3320 entries/s
3325 entries/s
3320 entries/s

I am running ROOT version 5.22. And while we are at it, this is my hard drive info, just in case if you think it’s relevant:

…and the trimmed-down lshw output for CPU and memory:

27

Hi,

what happens if you copy (not move!) the file? Do you see the same behavior on the copy?

Cheers, Axel.

28

Axel, I am not sure what you mean by copy or move. All I do is open the file with TFile::Open…

29

VIVE L’AMOUR!
just an idea … try to search “dmesg” output and “/var/log/messages” for any disk errors. 8-[
Try to copy your root data file to another disk and re-run you test … :unamused:
I am stupid. No?
Pepe Le Pew.

30

Hi,

see, we agree :slight_smile: With “copy” I mean really copy. Create a second file with the same content on your disk. It’s most probably the disk that’s faulty / not performing consistently.

Cheers, Axel.

31

You mean something as simple as

>cp run646647.root test.root

and run the script? I tried it and there was no difference – the speed drops from ~100k/s to 3.5k/s.

32

Pepe, no disk related error msges in /var/log/messages.

33

Hi,

you ran the script on test.root, not on run646647.root?

Cheers, Axel.

34

I expected that question. :slight_smile:

Yes, I run it on test.root.

35

Hi,

sorry, then I am out of guesses. As I said I cannot reproduce it, i.e. it must be due to your installation / machine. Could be anything, hardware or software (e.g. OS).

Cheers, Axel.

36

Ok, I just run the same test on one of the octal core machines(16GB of memory) of our linux farm. Exact same symptoms: starts with ~75k entries/s and goes down to 3k entries/s.

This may be due to the (older) version 5.22. I will install a more recent version of root and will report on
what I get with it.

37

All right, I installed 5.28 and run the same test (on my computer). A few observations:

a) speeds have gone way up. Hurray!
b) the difference between the end and beginning of the tree is gone! 5.22 seems to have been the culprit.
c) a new anomaly has shown up – the read speed varies back and forth between 135k/s and 85k/s. See below:

Beginning:

12:03:~/data_vx511/root_pnpf1>root
root [0] .L speed.C
root [1] speed()   
29771 entries/s
118825 entries/s
83894 entries/s
131710 entries/s
132354 entries/s
131915 entries/s
131173 entries/s
132751 entries/s
132299 entries/s
132657 entries/s
133007 entries/s
133100 entries/s
132504 entries/s
132256 entries/s
131538 entries/s
123348 entries/s
85189 entries/s
82477 entries/s
84994 entries/s
85220 entries/s
84931 entries/s
84956 entries/s
84964 entries/s
84379 entries/s
84927 entries/s
85253 entries/s
84790 entries/s
85074 entries/s
84937 entries/s
85144 entries/s
85067 entries/s
84914 entries/s
85255 entries/s
121477 entries/s
127622 entries/s
132325 entries/s
132973 entries/s
124034 entries/s
127983 entries/s
133033 entries/s
131915 entries/s
132879 entries/s
127606 entries/s
132566 entries/s
133024 entries/s
132855 entries/s
131841 entries/s
94403 entries/s
132897 entries/s
132812 entries/s
133244 entries/s
132592 entries/s
126431 entries/s
103336 entries/s
132268 entries/s
133022 entries/s
126070 entries/s
91202 entries/s
84829 entries/s
82336 entries/s
85108 entries/s
80858 entries/s
82383 entries/s
85641 entries/s
85814 entries/s
85392 entries/s
82695 entries/s
85063 entries/s
84491 entries/s
85102 entries/s
82070 entries/s
81414 entries/s
84948 entries/s
85216 entries/s
87304 entries/s
120704 entries/s
128263 entries/s
121366 entries/s
133086 entries/s
132860 entries/s
109794 entries/s
132786 entries/s
132380 entries/s
132376 entries/s
132640 entries/s
128116 entries/s
132176 entries/s
133196 entries/s
132874 entries/s
120803 entries/s
108392 entries/s
133368 entries/s
132938 entries/s
132839 entries/s
116392 entries/s
118937 entries/s
132424 entries/s
133570 entries/s
133456 entries/s

End:

12:03:~/data_vx511/root_pnpf1>root
root [0] .L speed.C
root [1] speed()   
241568 entries/s
136384 entries/s
136730 entries/s
136627 entries/s
136632 entries/s
135093 entries/s
136279 entries/s
137183 entries/s
135725 entries/s
136720 entries/s
135662 entries/s
136289 entries/s
136488 entries/s
136381 entries/s
137172 entries/s
136321 entries/s
130172 entries/s
131223 entries/s
135626 entries/s
136008 entries/s
136665 entries/s
136343 entries/s
136904 entries/s
136941 entries/s
135825 entries/s
137020 entries/s
136693 entries/s
136926 entries/s
136326 entries/s
136668 entries/s
136152 entries/s
135880 entries/s
135069 entries/s
136958 entries/s
136679 entries/s
135961 entries/s
136860 entries/s
136556 entries/s
136341 entries/s
137018 entries/s
136556 entries/s
136368 entries/s
136755 entries/s
107107 entries/s
85439 entries/s
87528 entries/s
87544 entries/s
87880 entries/s
87422 entries/s
87537 entries/s
87724 entries/s
87677 entries/s
87447 entries/s
87264 entries/s
87713 entries/s
87658 entries/s
87584 entries/s
87624 entries/s
87759 entries/s
87412 entries/s
87228 entries/s
125272 entries/s
130313 entries/s
135222 entries/s
137266 entries/s
136455 entries/s
136200 entries/s
137014 entries/s
136403 entries/s
136586 entries/s
137251 entries/s
136343 entries/s
137027 entries/s
136755 entries/s
135886 entries/s
136334 entries/s
136043 entries/s
135314 entries/s
136930 entries/s
137082 entries/s
136412 entries/s
137257 entries/s
136416 entries/s
136528 entries/s
137049 entries/s
136470 entries/s
137364 entries/s
136128 entries/s
96267 entries/s
82671 entries/s
87409 entries/s
87828 entries/s
87871 entries/s
87225 entries/s
87895 entries/s
87816 entries/s
87484 entries/s
87412 entries/s
87565 entries/s
87500 entries/s
38

Hi.

Good to know! Yes, our newest ROOT is always better :wink:

The variations might be caused e.g. by

  • measurement inaccuracies
  • other processes interfering with I/O
  • OS’s read-ahead

Cheers, Axel.