From 6efecea1fc48df58372acf6217981573110aae7a Mon Sep 17 00:00:00 2001 From: hristov Date: Mon, 15 Oct 2007 14:52:45 +0000 Subject: [PATCH] Monitoring of process information: updated version (Marian) --- STEER/AliReconstruction.cxx | 24 ++-- STEER/AliSysInfo.cxx | 82 +++++++++-- STEER/AliSysInfo.h | 12 +- macros/PlotSys.C | 274 ++++++++++++++++++++++++++++++++++++ 4 files changed, 365 insertions(+), 27 deletions(-) create mode 100644 macros/PlotSys.C diff --git a/STEER/AliReconstruction.cxx b/STEER/AliReconstruction.cxx index 7822568b967..b91e0e1c494 100644 --- a/STEER/AliReconstruction.cxx +++ b/STEER/AliReconstruction.cxx @@ -172,9 +172,9 @@ #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) diff --git a/STEER/AliSysInfo.cxx b/STEER/AliSysInfo.cxx index 332e58320e6..21ec4c6c693 100644 --- a/STEER/AliSysInfo.cxx +++ b/STEER/AliSysInfo.cxx @@ -14,6 +14,25 @@ **************************************************************************/ +// +// 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 #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; +} diff --git a/STEER/AliSysInfo.h b/STEER/AliSysInfo.h index c45a45a08cb..bc28a74456e 100644 --- a/STEER/AliSysInfo.h +++ b/STEER/AliSysInfo.h @@ -16,20 +16,24 @@ #include 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 index 00000000000..c595f7f5c51 --- /dev/null +++ b/macros/PlotSys.C @@ -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; +} -- 2.39.3