Add to TTreePerfStats details caching/read info for each basket

Author: pcanal

core/base/inc/TVirtualPerfStats.h

@@ -26,6 +26,7 @@
 
 
 class TFile;
+class TBranch;
 
 
 class TVirtualPerfStats : public TObject {
@@ -71,6 +72,12 @@ class TVirtualPerfStats : public TObject {
    virtual void SetNumEvents(Long64_t num) = 0;
    virtual Long64_t GetNumEvents() const = 0;
 
+   virtual void PrintBasketInfo(Option_t * option = "") const = 0;
+   virtual void SetLoaded(TBranch *b, size_t basketNumber) = 0;
+   virtual void SetLoadedMiss(TBranch *b, size_t basketNumber) = 0;
+   virtual void SetMissed(TBranch *b, size_t basketNumber) = 0;
+   virtual void SetUsed(TBranch *b, size_t basketNumber) = 0;
+
    static const char *EventType(EEventType type);
 
    ClassDef(TVirtualPerfStats,0)  // ABC for collecting PROOF statistics

proof/proofplayer/inc/TPerfStats.h

@@ -131,6 +131,12 @@ friend class TProofMonSender;
    void SetNumEvents(Long64_t num) { fNumEvents = num; }
    Long64_t GetNumEvents() const { return fNumEvents; }
 
+   void        PrintBasketInfo(Option_t * = "") const {}
+   void        SetLoaded(TBranch *, size_t) {}
+   void        SetLoadedMiss(TBranch *, size_t) {}
+   void        SetMissed(TBranch *, size_t) {}
+   void        SetUsed(TBranch *, size_t) {}
+
    static void Start(TList *input, TList *output);
    static void Stop();
    static void Setup(TList *input);

tree/tree/inc/TBranch.h

@@ -43,6 +43,7 @@ class TDirectory;
 class TFile;
 class TClonesArray;
 class TTreeCloner;
+class TTreeCache;
 
    const Int_t kDoNotProcess = BIT(10); // Active bit for branches
    const Int_t kIsClone      = BIT(11); // to indicate a TBranchClones
@@ -60,6 +61,7 @@ class TBranch : public TNamed , public TAttFill {
    using TIOFeatures = ROOT::TIOFeatures;
 
 protected:
+   friend class TTreeCache;
    friend class TTreeCloner;
    friend class TTree;
 

tree/tree/src/TBranch.cxx

@@ -39,6 +39,7 @@
 #include "TTreeCacheUnzip.h"
 #include "TVirtualMutex.h"
 #include "TVirtualPad.h"
+#include "TVirtualPerfStats.h"
 
 #include "TBranchIMTHelper.h"
 
@@ -1234,6 +1235,11 @@ TBasket* TBranch::GetBasket(Int_t basketnumber)
    }
 
    ++fNBaskets;
+
+   auto perfStats = GetTree()->GetPerfStats();
+   if (perfStats)
+      perfStats->SetUsed(this, basketnumber);
+
    fBaskets.AddAt(basket,basketnumber);
    return basket;
 }

tree/tree/src/TTreeCache.cxx

@@ -256,6 +256,7 @@ of effective system reads for a given file with a code like
 #include "TFriendElement.h"
 #include "TFile.h"
 #include "TMath.h"
+#include "TVirtualPerfStats.h"
 #include <limits.h>
 
 Int_t TTreeCache::fgLearnEntries = 100;
@@ -714,6 +715,10 @@ TBranch *TTreeCache::CalculateMissEntries(Long64_t pos, Int_t len, Bool_t all)
    Bool_t found_request = kFALSE;
    TBranch *resultBranch = nullptr;
    Long64_t entry = fTree->GetReadEntry();
+
+   std::vector<std::pair<TBranch*,Int_t>> basketsInfo;
+   auto perfStats = GetTree()->GetPerfStats();
+
    // printf("Will search %d branches for basket at %ld.\n", count, pos);
    for (int i = 0; i < count; i++) {
       TBranch *b =
@@ -730,12 +735,30 @@ TBranch *TTreeCache::CalculateMissEntries(Long64_t pos, Int_t len, Bool_t all)
       }
       // At this point, we are ready to push back a new offset
       fMissCache->fEntries.emplace_back(std::move(iopos));
+
+      if (R__unlikely(perfStats)) {
+         Int_t blistsize = b->GetWriteBasket();
+         Int_t basketNumber = -1;
+         for(Int_t bn = 0; bn < blistsize; ++bn) {
+            if (iopos.fPos == b->GetBasketSeek(bn)) {
+               basketNumber = bn;
+               break;
+            }
+         }
+         if (basketNumber >= 0)
+            basketsInfo.emplace_back(b, basketNumber);
+      }
    }
    if (R__unlikely(!found_request)) {
       // We have gone through all the branches in this file and the requested basket
       // doesn't appear to be in any of them.  Likely a logic error / bug.
       fMissCache->fEntries.clear();
    }
+   if (R__unlikely(perfStats)) {
+      for(auto &info : basketsInfo) {
+         perfStats->SetLoadedMiss(info.first, info.second);
+      }
+   }
    return resultBranch;
 }
 
@@ -1011,6 +1034,7 @@ Bool_t TTreeCache::FillBuffer()
    Int_t prevNtot;
    Int_t minBasket = 0;  // We will use this to avoid re-checking the first baskets in the 2nd (or more) run in the while loop.
    Long64_t maxReadEntry = minEntry; // If we are stopped before the end of the 2nd pass, this marker will where we need to start next time.
+   auto perfStats = GetTree()->GetPerfStats();
    do {
       prevNtot = fNtotCurrentBuf;
       Int_t nextMinBasket = INT_MAX;
@@ -1101,6 +1125,11 @@ Bool_t TTreeCache::FillBuffer()
                      }
                   }
                }
+
+               if (R__unlikely(perfStats)) {
+                  perfStats->SetLoaded(b, j);
+               }
+
                if (fEnablePrefetching){
                   if (fFirstBuffer) {
                      TFileCacheRead::Prefetch(pos,len);
@@ -1337,23 +1366,47 @@ Int_t TTreeCache::ReadBufferNormal(char *buf, Long64_t pos, Int_t len){
       return 1;
    }
 
+   static const auto recordMiss = [](TVirtualPerfStats *perfStats, TObjArray *branches, Bool_t bufferFilled, Long64_t basketpos) {
+      if (gDebug > 6)
+         ::Info("TTreeCache::ReadBufferNormal", "Cache miss after an %s FillBuffer: pos=%lld", bufferFilled ? "active" : "inactive", basketpos);
+      for (Int_t i=0; i<branches->GetEntries(); ++i) {
+         TBranch *b = (TBranch*)branches->UncheckedAt(i);
+         Int_t blistsize = b->GetListOfBaskets()->GetSize();
+         for(Int_t j = 0; j < blistsize; ++j) {
+            if (basketpos == b->GetBasketSeek(j)) {
+               if (gDebug > 6)
+                  ::Info("TTreeCache::ReadBufferNormal","   Missing basket: %d for %s", j, b->GetName());
+               perfStats->SetMissed(b, j);
+            }
+         }
+      }
+   };
+
    //not found in cache. Do we need to fill the cache?
    Bool_t bufferFilled = FillBuffer();
    if (bufferFilled) {
       Int_t res = TFileCacheRead::ReadBuffer(buf,pos,len);
 
       if (res == 1)
          fNReadOk++;
-      else if (res == 0)
+      else if (res == 0) {
          fNReadMiss++;
+         auto perfStats = GetTree()->GetPerfStats();
+         if (perfStats)
+            recordMiss(perfStats, fBranches, bufferFilled, pos);
+      }
 
       return res;
    }
+
    if (CheckMissCache(buf, pos, len)) {
       return 1;
    }
 
    fNReadMiss++;
+   auto perfStats = GetTree()->GetPerfStats();
+   if (perfStats)
+      recordMiss(perfStats, fBranches, bufferFilled, pos);
 
    return 0;
 }

tree/treeplayer/inc/TTreePerfStats.h

@@ -23,6 +23,7 @@
 
 #include "TVirtualPerfStats.h"
 #include "TString.h"
+#include <vector>
 
 
 class TBrowser;
@@ -35,6 +36,14 @@ class TGaxis;
 class TText;
 class TTreePerfStats : public TVirtualPerfStats {
 
+public:
+   struct BasketInfo {
+      UInt_t fUsed = {0};       // Number of times the basket was requested from the disk.
+      UInt_t fLoaded = {0};     // Number of times the basket was put in the primary TTreeCache
+      UInt_t fLoadedMiss = {0}; // Number of times the basket was put in the secondary cache
+      UInt_t fMissed = {0};     // Number of times the basket was read directly from the file.
+   };
+
 protected:
    Int_t         fTreeCacheSize; //TTreeCache buffer size
    Int_t         fNleaves;       //Number of leaves in the tree
@@ -59,6 +68,11 @@ class TTreePerfStats : public TVirtualPerfStats {
    TGaxis       *fRealTimeAxis;  //pointer to TGaxis object showing real-time
    TText        *fHostInfoText;  //Graphics Text object with the fHostInfo data
 
+
+   std::vector<std::vector<BasketInfo> > fBasketsInfo; // Details on which baskets was used, cached, 'miss-cached' or read uncached.Browse
+
+   BasketInfo& GetBasketInfo(TBranch *b, size_t basketNumber);
+
 public:
    TTreePerfStats();
    TTreePerfStats(const char *name, TTree *T);
@@ -117,7 +131,13 @@ class TTreePerfStats : public TVirtualPerfStats {
    virtual void     SetTreeCacheSize(Int_t nbytes) {fTreeCacheSize = nbytes;}
    virtual void     SetUnzipTime(Double_t uztime) {fUnzipTime = uztime;}
 
-   ClassDef(TTreePerfStats,6)  // TTree I/O performance measurement
+   virtual void     PrintBasketInfo(Option_t * option = "") const;
+   virtual void     SetLoaded(TBranch *b, size_t basketNumber) { ++GetBasketInfo(b, basketNumber).fLoaded; }
+   virtual void     SetLoadedMiss(TBranch *b, size_t basketNumber) { ++GetBasketInfo(b, basketNumber).fLoadedMiss; }
+   virtual void     SetMissed(TBranch *b, size_t basketNumber) { ++GetBasketInfo(b, basketNumber).fMissed; }
+   virtual void     SetUsed(TBranch *b, size_t basketNumber) { ++GetBasketInfo(b, basketNumber).fUsed; }
+
+   ClassDef(TTreePerfStats,7)  // TTree I/O performance measurement
 };
 
 #endif

tree/treeplayer/src/TTreePerfStats.cxx

@@ -85,6 +85,7 @@ The Physical disk speed is DiskIO + DiskIO*ReadExtra/100.
 #include "Riostream.h"
 #include "TFile.h"
 #include "TTree.h"
+#include "TTreeCache.h"
 #include "TAxis.h"
 #include "TBrowser.h"
 #include "TVirtualPad.h"
@@ -338,6 +339,41 @@ void TTreePerfStats::Finish()
    }
 }
 
+////////////////////////////////////////////////////////////////////////////////
+/// Return the BasketInfo corresponding to the given branch and basket.
+
+TTreePerfStats::BasketInfo &TTreePerfStats::GetBasketInfo(TBranch *br, size_t basketNumber)
+{
+   static BasketInfo fallback;
+
+   // First find the branch index.
+   TFile *file = fTree->GetCurrentFile();
+   if (!file)
+      return fallback;
+
+  TTreeCache *cache = dynamic_cast<TTreeCache*>(file->GetCacheRead(fTree));
+  if (!cache)
+     return fallback;
+
+  auto branches = cache->GetCachedBranches();
+  Int_t index = -1;
+  for(Int_t i = 0; i < branches->GetEntries(); ++i) {
+    if (br == branches->UncheckedAt(i)) {
+       index = i;
+       break;
+    }
+  }
+  if (index < 0)
+     return fallback;
+  if (fBasketsInfo.size() <= (size_t)index)
+     fBasketsInfo.resize(index+1);
+
+  auto &brvec(fBasketsInfo[index]);
+  if (brvec.size() <= basketNumber)
+    brvec.resize(basketNumber+1);
+
+  return brvec[basketNumber];
+}
 
 ////////////////////////////////////////////////////////////////////////////////
 /// Draw the TTree I/O perf graph.
@@ -429,6 +465,7 @@ void TTreePerfStats::Print(Option_t * option) const
    TString opts(option);
    opts.ToLower();
    Bool_t unzip = opts.Contains("unzip");
+   Bool_t basket = opts.Contains("basket");
    TTreePerfStats *ps = (TTreePerfStats*)this;
    ps->Finish();
 
@@ -457,8 +494,75 @@ void TTreePerfStats::Print(Option_t * option) const
       printf("ReadStrCP = %7.3f MBytes/s\n",1e-6*fCompress*fBytesRead/(fCpuTime-fUnzipTime));
       printf("ReadZipCP = %7.3f MBytes/s\n",1e-6*fCompress*fBytesRead/fUnzipTime);
    }
+   if (basket)
+      PrintBasketInfo(option);
 }
 
+////////////////////////////////////////////////////////////////////////////////
+/// Print the TTree basket information
+
+void TTreePerfStats::PrintBasketInfo(Option_t * option) const {
+
+   TString opts(option);
+   opts.ToLower();
+   Bool_t all = opts.Contains("allbasketinfo");
+
+   TFile *file = fTree->GetCurrentFile();
+   if (!file)
+      return;
+
+   TTreeCache *cache = dynamic_cast<TTreeCache*>(file->GetCacheRead(fTree));
+   if (!cache)
+      return;
+
+   auto branches = cache->GetCachedBranches();
+   for(size_t i = 0; i < fBasketsInfo.size(); ++i) {
+      const char *branchname = branches->At(i)->GetName();
+
+      printf("  br=%ld %s read not cached: ", i, branchname);
+      if (fBasketsInfo[i].size() == 0) {
+         printf("none");
+      } else for(size_t j = 0; j < fBasketsInfo[i].size(); ++j) {
+         if (fBasketsInfo[i][j].fMissed) printf("%ld ", j);
+      }
+      printf("\n");
+
+      printf("  br=%ld %s cached more than once: ", i, branchname);
+      for(size_t j = 0; j < fBasketsInfo[i].size(); ++j) {
+         auto &info( fBasketsInfo[i][j] );
+         if ((info.fLoaded + info.fLoadedMiss) > 1)
+            printf("%ld[%d,%d] ", j, info.fLoaded, info.fLoadedMiss);
+      }
+      printf("\n");
+
+      printf("  br=%ld %s cached but not used: ", i, branchname);
+      for(size_t j = 0; j < fBasketsInfo[i].size(); ++j) {
+         auto &info( fBasketsInfo[i][j] );
+         if ( (info.fLoaded + info.fLoadedMiss) && !info.fUsed) {
+            if (info.fLoadedMiss)
+               printf("%ld[%d,%d] ", j, info.fLoaded, info.fLoadedMiss);
+            else
+               printf("%ld ", j);
+         }
+      }
+      printf("\n");
+
+      if (all) {
+         printf("  br=%ld %s: ", i, branchname);
+         for(size_t j = 0; j < fBasketsInfo[i].size(); ++j) {
+            auto &info( fBasketsInfo[i][j] );
+            printf("%ld[%d,%d,%d,%d] ", j, info.fUsed, info.fLoaded, info.fLoadedMiss, info.fMissed);
+         }
+         printf("\n");
+      }
+   }
+   for(Int_t i = fBasketsInfo.size(); i < branches->GetEntries(); ++i) {
+      printf("  br=%d %s: no basket information\n", i, branches->At(i)->GetName());
+   }
+
+}
+
+
 ////////////////////////////////////////////////////////////////////////////////
 /// Save this object to filename