Monitoring of process information: updated version (Marian)
authorhristov <hristov@f7af4fe6-9843-0410-8265-dc069ae4e863>
Mon, 15 Oct 2007 14:52:45 +0000 (14:52 +0000)
committerhristov <hristov@f7af4fe6-9843-0410-8265-dc069ae4e863>
Mon, 15 Oct 2007 14:52:45 +0000 (14:52 +0000)
STEER/AliReconstruction.cxx
STEER/AliSysInfo.cxx
STEER/AliSysInfo.h
macros/PlotSys.C [new file with mode: 0644]

index 7822568..b91e0e1 100644 (file)
 
 #include "AliQADataMaker.h" 
 
-//#include "TMemStatManager.h" // memory snapshots
 #include "AliSysInfo.h" // memory snapshots
 
+
 ClassImp(AliReconstruction)
 
 
@@ -1056,7 +1056,7 @@ Bool_t AliReconstruction::RunLocalEventReconstruction(const TString& detectors)
 
     loader->WriteRecPoints("OVERWRITE");
     loader->UnloadRecPoints();
-     AliSysInfo::AddStamp(Form("LRec%s_%d",fgkDetectorName[iDet],eventNr));
+    AliSysInfo::AddStamp(Form("LRec%s_%d",fgkDetectorName[iDet],eventNr), iDet,1,eventNr);
   }
 
   if ((detStr.CompareTo("ALL") != 0) && !detStr.IsNull()) {
@@ -1263,13 +1263,14 @@ Bool_t AliReconstruction::RunTracking(AliESDEvent*& esd)
 
     // load clusters
     fLoader[iDet]->LoadRecPoints("read");
+    AliSysInfo::AddStamp(Form("RLoadCluster%s_%d",fgkDetectorName[iDet],eventNr),iDet,1, eventNr);
     TTree* tree = fLoader[iDet]->TreeR();
     if (!tree) {
       AliError(Form("Can't get the %s cluster tree", fgkDetectorName[iDet]));
       return kFALSE;
     }
     fTracker[iDet]->LoadClusters(tree);
-
+    AliSysInfo::AddStamp(Form("TLoadCluster%s_%d",fgkDetectorName[iDet],eventNr), iDet,2, eventNr);
     // run tracking
     if (fTracker[iDet]->Clusters2Tracks(esd) != 0) {
       AliError(Form("%s Clusters2Tracks failed", fgkDetectorName[iDet]));
@@ -1283,7 +1284,7 @@ Bool_t AliReconstruction::RunTracking(AliESDEvent*& esd)
       GetReconstructor(1)->FillESD((TTree*)NULL, (TTree*)NULL, esd);
       AliESDpid::MakePID(esd);
     } 
-     AliSysInfo::AddStamp(Form("Tracking0%s_%d",fgkDetectorName[iDet],eventNr));
+    AliSysInfo::AddStamp(Form("Tracking0%s_%d",fgkDetectorName[iDet],eventNr), iDet,3,eventNr);
   }
 
   // pass 2: ALL backwards
@@ -1295,13 +1296,14 @@ Bool_t AliReconstruction::RunTracking(AliESDEvent*& esd)
     if (iDet > 1) {     // all except ITS, TPC
       TTree* tree = NULL;
       fLoader[iDet]->LoadRecPoints("read");
+      AliSysInfo::AddStamp(Form("RLoadCluster0%s_%d",fgkDetectorName[iDet],eventNr), iDet,1, eventNr);
       tree = fLoader[iDet]->TreeR();
       if (!tree) {
        AliError(Form("Can't get the %s cluster tree", fgkDetectorName[iDet]));
        return kFALSE;
       }
       fTracker[iDet]->LoadClusters(tree); 
-       AliSysInfo::AddStamp(Form("LoadCluster0%s_%d",fgkDetectorName[iDet],eventNr));
+      AliSysInfo::AddStamp(Form("TLoadCluster0%s_%d",fgkDetectorName[iDet],eventNr), iDet,2, eventNr);
     }
 
     // run tracking
@@ -1323,7 +1325,7 @@ Bool_t AliReconstruction::RunTracking(AliESDEvent*& esd)
       GetReconstructor(1)->FillESD((TTree*)NULL, (TTree*)NULL, esd);
       AliESDpid::MakePID(esd);
     }
-     AliSysInfo::AddStamp(Form("Tracking1%s_%d",fgkDetectorName[iDet],eventNr));
+    AliSysInfo::AddStamp(Form("Tracking1%s_%d",fgkDetectorName[iDet],eventNr), iDet,3, eventNr);
   }
 
   // write space-points to the ESD in case alignment data output
@@ -1344,11 +1346,12 @@ Bool_t AliReconstruction::RunTracking(AliESDEvent*& esd)
     if (fCheckPointLevel > 1) {
       WriteESD(esd, Form("%s.refit", fgkDetectorName[iDet]));
     }
-
+    AliSysInfo::AddStamp(Form("Tracking2%s_%d",fgkDetectorName[iDet],eventNr), iDet,3, eventNr);
     // unload clusters
     fTracker[iDet]->UnloadClusters();
+    AliSysInfo::AddStamp(Form("TUnloadCluster%s_%d",fgkDetectorName[iDet],eventNr), iDet,4, eventNr);
     fLoader[iDet]->UnloadRecPoints();
-     AliSysInfo::AddStamp(Form("Tracking2%s_%d",fgkDetectorName[iDet],eventNr));
+    AliSysInfo::AddStamp(Form("RUnloadCluster%s_%d",fgkDetectorName[iDet],eventNr), iDet,5, eventNr);
   }
   //
   // Propagate track to the vertex - if not done by ITS
@@ -1442,7 +1445,7 @@ Bool_t AliReconstruction::FillESD(AliESDEvent*& esd, const TString& detectors)
                   detStr.Data()));
     if (fStopOnError) return kFALSE;
   }
-   AliSysInfo::AddStamp(Form("FillESD%d",eventNr));
+  AliSysInfo::AddStamp(Form("FillESD%d",eventNr), 0,1, eventNr);
   eventNr++;
   return kTRUE;
 }
@@ -1762,6 +1765,7 @@ Bool_t AliReconstruction::CreateTrackers(const TString& detectors)
       AliWarning(Form("couldn't create a tracker for %s", detName.Data()));
       if (fStopOnError) return kFALSE;
     }
+    AliSysInfo::AddStamp(Form("LTracker%s",fgkDetectorName[iDet]), iDet,0);
   }
 
   return kTRUE;
@@ -2693,6 +2697,8 @@ void AliReconstruction::TNamedToFile(TTree* fTree, TString fName){
   out.close();
 
 }
+  
+
 
 //_____________________________________________________________________________
 AliQADataMaker * AliReconstruction::GetQADataMaker(Int_t iDet)
index 332e583..21ec4c6 100644 (file)
  **************************************************************************/
 
 
+//
+// Origin:  marian.ivanov@cern.ch
+//
+//  Make   a log file for the CPU and Memory usage
+//  
+//  The typical usage:
+//  Make a set of stamps in the code in the place of interest
+//  e.g. 
+//
+//  AliSysInfo::AddStamp("Start");
+//
+//  loader->UnloadRecPoints();
+//    AliSysInfo::AddStamp(Form("LRec%s_%d",fgkDetectorName[iDet],eventNr), iDet,1,eventNr);
+//
+
+// The log file can be transformed to the tree - to make a visualization
+// See $ALICE_ROOT/macros/PlotSysInfo.C as an example
+
+
 #include <Riostream.h>
 #include "AliLog.h"
 #include "TStopwatch.h"
@@ -23,6 +42,8 @@
 #include "TTimeStamp.h"
 #include "AliSysInfo.h"
 
+//#include "TMemStatManager.h"  //USE IFDEF
+
 
 ClassImp(AliSysInfo)
 
@@ -31,15 +52,20 @@ AliSysInfo* AliSysInfo::fInstance=0;
 AliSysInfo::AliSysInfo():
     TObject(),
     fSysWatch(0),
-    fTimer(0)    
+    fTimer(0),
+    fMemStat(0)
 {
   fTimer = new TStopwatch;
   fSysWatch  = new fstream("syswatch.log", ios_base::out|ios_base::trunc);
+
   //hname/C:sname/C:sec/I:mI.fMemUsed/F:mI.fSwapUsed/F:pI.fMemResident/F:pI.fMemVirtual/F:cI.fUser/F:cI.fSys/F:cI.fCpuUser/F:pI.fCpuSys/F
 
 
   (*fSysWatch) <<"hname"<<"/C:"               // hname - hostname  
                <<"sname"<<"/C:"              // stamp name
+               <<"id0"<<"/I:"                // 0 id
+               <<"id1"<<"/I:"                // 1 id
+               <<"id2"<<"/I:"                // 1 id
                <<"first"<<"/I:"              // first stamp
     //
               <<"stampSec"<<"/I:"         // time  - time stamp in seconds
@@ -81,20 +107,11 @@ AliSysInfo * AliSysInfo::Instance(){
 }
 
 
-void AliSysInfo::AddStamp(const char *stamp){
+void AliSysInfo::AddStamp(const char *sname, Int_t id0, Int_t id1, Int_t id2){
   //
   // 
   //
-  Instance()->Print(stamp);
-}
-
-
-void AliSysInfo::Print(Option_t* option ) const{
-  //
-  // 
   //
-  char sname[1000];
-  sprintf(sname,"n-%s",option);
   TTimeStamp stamp;
   CpuInfo_t  cpuInfo;
   MemInfo_t  memInfo;
@@ -113,9 +130,12 @@ void AliSysInfo::Print(Option_t* option ) const{
   static ProcInfo_t procInfoOld;  
 
 
-  (*fSysWatch) << hname   <<"\t"               // hname - hostname  
+  (*(Instance()->fSysWatch)) << hname   <<"\t"               // hname - hostname  
                << sname    <<"\t"              // stamp name
-               << first    <<"\t"              // first stamp
+               << id0      <<"\t"
+               << id1      <<"\t"
+               << id2      <<"\t"
+               << first    <<"\t"              // first stamp               
                //
               << stamp.GetSec()<<"\t"         // time  - time stamp in seconds
               << memInfo.fMemUsed<<"\t"       // system info 
@@ -142,7 +162,10 @@ void AliSysInfo::Print(Option_t* option ) const{
   stampOld   = stamp;
   cpuInfoOld = cpuInfo;
   memInfoOld = memInfo;
-  procInfoOld= procInfo; 
+  procInfoOld= procInfo;
+
+  //  if (fInstance->fMemStat) fInstance->fMemStat->AddStamps(sname);
   entry++;
 }
 
@@ -152,7 +175,38 @@ TTree * AliSysInfo::MakeTree(const char *lname){
   TTree * tree = new TTree;
   tree->ReadFile(lname);
   tree->SetAlias("deltaT","stampSec-stampOldSec");
+  tree->SetAlias("T","stampSec-first");
   tree->SetAlias("deltaVM","(pI.fMemVirtual-pIOld.fMemVirtual)*0.001");
+  tree->SetAlias("VM","pI.fMemVirtual*0.001");
   return tree;
 }
 
+
+Bool_t AliSysInfo::Contain(const char * str1, const char * str2){
+  //
+  //
+  //
+  TString str(str1);
+  return str.Contains(str2);
+}
+
+
+
+void AliSysInfo::OpenMemStat(){
+  //
+  //
+  //
+  //USE IFDEF if MEMSTAT ENABLED  
+  //  Instance()->fMemStat = TMemStatManager::GetInstance();
+  //   Instance()->fMemStat->SetAutoStamp(10000000, 10000000,1000000);
+  //   Instance()->fMemStat->Enable();  
+}
+
+void AliSysInfo::CloseMemStat(){
+  //
+  //
+  //
+  //USE IFDEF if MEMSTAT ENABLED
+  //if (Instance()->fMemStat  == TMemStatManager::GetInstance()) Instance()->fMemStat->Close();
+  //Instance()->fMemStat=0;
+}
index c45a45a..bc28a74 100644 (file)
 #include <TObject.h>
 class TStopwatch;
 class TTree;
+class TMemStatManager;
 
 class AliSysInfo : public TObject {
 public:
   AliSysInfo();
   static AliSysInfo * Instance();
-  static void AddStamp(const char *stamp);
-  void Print(Option_t* option = "") const;
+  static void AddStamp(const char *sname, Int_t id0=-1, Int_t id1=-1, Int_t id2=-1);
   static TTree * MakeTree(const char *lname);
+  static void OpenMemStat();
+  static void CloseMemStat();
+  static Bool_t Contain(const char * str1, const char * str2);
 private:
   AliSysInfo(const AliSysInfo& source);
   AliSysInfo& operator= (const AliSysInfo& rec);
 
-  fstream        *fSysWatch;       // system watch - Memory and CPU usage 
-  TStopwatch     *fTimer;          // timer
+  fstream         *fSysWatch;       // system watch - Memory and CPU usage 
+  TStopwatch      *fTimer;          // timer
+  TMemStatManager *fMemStat;      
   static AliSysInfo *   fInstance; //instance pointer
   ClassDef(AliSysInfo,0)
 };
diff --git a/macros/PlotSys.C b/macros/PlotSys.C
new file mode 100644 (file)
index 0000000..c595f7f
--- /dev/null
@@ -0,0 +1,274 @@
+/*
+  Origin:  marian.ivanov@cern.ch
+  Make sys watch default plots (see $ALICE_ROOT/STEER/AliSysInfo.cxx):
+  Input   -  syswatch.log  - text log file created by process to be monitored
+  Output  -  syswatch.root - root files with default histograms
+  Number of top violators - only top consumer displayed
+          
+  Default histogram:  
+               
+  TOP violateors      - CPU and Virtual memory usage
+  Detector reports    - CPU and Virtual memory usage per detector
+
+
+
+
+
+  Usage example:
+  .x ~/rootlogon.C
+  gROOT->LoadMacro("$ALICE_ROOT/macros/PlotSys.C+");
+  MakePlots("syswatch.log","syswatch.root",10);
+  TFile f("syswatch.root");
+  TBrowser b;
+*/
+
+#include "TMath.h"
+#include "TH1F.h"
+#include "TH2F.h"
+#include "TTree.h"
+#include "TFile.h"
+#include "TCut.h"
+#include "TStyle.h"
+#include "AliSysInfo.h"
+
+TObject * htemp; 
+TTree *tree=0;
+TFile *fout=0;
+TCut cutVM("cutVM","deltaVM>10");
+TCut cutDT("cutDT","deltaT>2"); 
+Int_t ctop=10;
+
+
+Float_t TopUsage(TTree* tree, const char *exp, const char*cut, Int_t order);
+void TopVM();
+void TopCPU();
+void TopVMDetector();
+void TopCPUDetector();
+
+void PInit(const char *log="syswatch.log", const char *out="syswatch.root"){
+  //
+  // Set Input output
+  //
+  tree = AliSysInfo::MakeTree(log);
+  fout = new TFile(out,"recreate");
+}
+
+
+
+void MakePlots(const char *log="syswatch.log", const char *out="syswatch.root", Int_t top=10){
+  //
+  //
+  //
+  ctop=top;
+  PInit(log,out);
+  gStyle->SetOptStat(0);
+  //
+  // Top users
+  //
+  TopVM();
+  TopCPU();
+  //
+  // Reports per detector
+  //
+  fout->mkdir("cpuDetector");
+  fout->mkdir("VMDetector");
+  //
+  fout->cd("VMDetector");
+  TopVMDetector();
+  //
+  fout->cd();
+  fout->cd("cpuDetector");
+  TopCPUDetector();
+
+  //
+  fout->Close();
+  ctop=top;
+  delete fout;
+}
+
+void TopVM(){
+  //
+  // select top user of virtual Memory 
+  // MakeReport - ASCII and histogram
+  // 
+  TH1 * his=0;
+  TH2 * his2=0;
+  Float_t thVM = TopUsage(tree,"deltaVM","",ctop);
+  cutVM = TCut("cutDT",Form("deltaVM>%f",thVM));
+  //
+  //
+  printf("<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n\n\n");
+  printf("TOP Virtual memory user\n");
+  tree->Scan("deltaVM:sname",cutVM,"colsize=20");
+  printf("<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n\n\n");
+  //
+  tree->Draw("deltaVM:sname>>hhh","1"+cutVM,"*");  
+  his2 = (TH2F*)(tree->GetHistogram())->Clone("dvmsname");
+  delete tree->GetHistogram();
+  his2->SetYTitle("Delta Virtual Memory (MBy)");
+  his2->SetMarkerStyle(22);
+  his2->SetMarkerSize(1); 
+  his2->Draw("l*");
+  his2->Write("DVMvsName");
+  delete his2;
+  //
+  tree->Draw("VM:sname>>hhh","id2<3"+cutVM,"*");
+  his2 = (TH2F*)(tree->GetHistogram())->Clone("vmsname");
+  delete tree->GetHistogram();
+  his2->SetYTitle("Delta Virtual Memory (MBy)");
+  his2->SetMarkerStyle(22);
+  his2->SetMarkerSize(1); 
+  his2->Draw("l*");
+  his2->Write("VMvsName");
+  delete his2;
+  //
+  //
+  tree->Draw("VM:T>>hhh","deltaVM>1","line*");
+  his = (TH1*)tree->GetHistogram()->Clone("vmt");
+  delete tree->GetHistogram();
+  his->SetXTitle("Time (sec)");
+  his->SetYTitle("Virtual Memory (MBy)");
+  his->GetYaxis()->SetTitleOffset(1.2); 
+  his->SetMarkerStyle(22);
+  his->SetMarkerSize(1); 
+  his->Draw();
+  his->Write("VMvsTime");
+  delete his;
+}
+
+void TopCPU(){  
+  //
+  // select top user of CPU 
+  // MakeReport - ASCII and histogram
+  // 
+  TH2 * his2=0;
+  Float_t thDT = TopUsage(tree,"deltaT","id2<3",ctop);
+  cutDT = TCut("cutDT",Form("deltaT>%f",thDT));
+  //
+  printf("<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n");
+  printf("/n/n/nTOP CPU user\n");
+  tree->Scan("deltaT:sname",cutDT,"colsize=20");
+  printf("<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n");
+  //
+  tree->Draw("deltaT:sname>>hhh","id2<3"+cutDT,"*"); 
+  his2 = (TH2F*)(tree->GetHistogram())->Clone("tsname"); 
+  delete tree->GetHistogram();
+  his2->SetName("VMsanme");
+  his2->SetYTitle("Delta CPU time(sec)");
+  his2->SetMarkerStyle(22);
+  his2->SetMarkerSize(1); 
+  his2->GetXaxis()->SetLabelSize(0.03);
+  his2->Draw("l*");
+  his2->Write("CPUvsName");
+  delete his2;
+}
+
+
+void TopVMDetector(){
+  //
+  // Draw usage of VM
+  //
+  TH2 * his2=0;
+  //
+  //
+  //detector part
+  //
+  for (Int_t idet=0; idet<12; idet++){
+    char cdet[100];
+    char cdvm[100];
+    sprintf(cdet,"id0==%d",idet);
+    char expr[100];
+    sprintf(expr,"deltaVM:sname>>hhh");  
+    //
+    Float_t thDVM = TopUsage(tree,"deltaVM",cdet,ctop);
+    sprintf(cdvm,"%s&&deltaT>%f",cdet, thDVM);
+
+
+    //
+    tree->Draw(expr,cdvm,"*"); 
+    his2 = (TH2F*)(tree->GetHistogram())->Clone("xxx");
+    delete tree->GetHistogram();
+    his2->SetYTitle("Delta Virtual Memory (MBy)");
+    his2->SetMarkerStyle(22);
+    his2->SetMarkerSize(1); 
+    his2->Draw("l*");
+    his2->Write(Form("DVMvsName_%d",idet));
+    delete his2;
+    //
+    //    
+    sprintf(expr,"VM:sname>>hhh");
+    tree->Draw(expr,cdvm,"*"); 
+    his2 = (TH2F*)(tree->GetHistogram())->Clone("yyy");
+    delete tree->GetHistogram();
+    his2->SetYTitle("Delta Virtual Memory (MBy)");
+    his2->SetMarkerStyle(22);
+    his2->SetMarkerSize(1); 
+    his2->Draw("l*");
+    his2->Write(Form("VMvsName_%d",idet));     
+    delete his2;
+  }
+}
+
+
+
+void TopCPUDetector(){
+  //
+  // Draw usage of CPU
+  //
+  TH2 * his2=0;
+  //
+  //
+  // CPU
+  //
+  for (Int_t idet=0; idet<12; idet++){
+    char cdet[100];
+    char cdtime[100];
+    sprintf(cdet,"id0==%d",idet);
+    char expr[100];
+    sprintf(expr,"deltaT:sname>>hhh");  
+    //
+    Float_t thDT = TopUsage(tree,"deltaT",cdet,ctop);
+    sprintf(cdtime,"%s&&deltaT>%f",cdet, thDT);
+    //
+    tree->Draw(expr,cdtime,"*"); 
+    his2 = (TH2F*)(tree->GetHistogram())->Clone("dtsname");
+    delete tree->GetHistogram();
+    his2->SetYTitle("Delta CPU time(sec)");
+    his2->SetMarkerStyle(22);
+    his2->SetMarkerSize(1); 
+    his2->GetXaxis()->SetLabelSize(0.03);
+    his2->Draw("l*");
+    his2->Write(Form("CPUvsName_%d",idet));
+    delete his2;
+  }
+}
+
+
+
+
+
+Float_t TopUsage(TTree* tree, const char *exp, const char*cut, Int_t order){
+  //
+  // 
+  // Find value for given order
+  // Used to select top violator
+  //
+  Int_t entries = tree->Draw(Form("%s>>hhh1",exp),cut,"goff");
+  if (entries<=1) {
+    if (tree->GetHistogram()) delete tree->GetHistogram(); 
+    printf("%s\t No entries\n",cut);
+    return -10000;
+  }
+  if (!tree->GetV1()) {
+    printf("%s\t No entries\n",cut);
+    return -10000; 
+  }
+  Int_t *index = new Int_t[entries];
+  TMath::Sort(entries, tree->GetV1(), index);
+  Int_t oindex = TMath::Min(order, entries);
+  Float_t val = tree->GetV1()[index[oindex-1]];
+  if (tree->GetHistogram()) delete tree->GetHistogram();
+  delete [] index;
+  return val;
+}