From 67e8baa5fbdf9ff9be3518802fa51bfd67dcf814 Mon Sep 17 00:00:00 2001 From: Pascal Raisig <praisig@ikf.uni-frankfurt.de> Date: Tue, 27 Jul 2021 11:17:19 +0000 Subject: [PATCH] Add cpu and wall time measurement per algo This commit adds the measurement of the cpu and wall time to the unpacking algo template/CbmRecoUnpack::unpack function. The values are printed add the end of the run and stored additionally in an output histogram. --- core/data/CbmTsEventHeader.h | 34 ++-- macro/run/run_unpack_tsa.C | 13 +- reco/base/CbmRecoUnpackAlgo.tmpl | 54 +++++- .../trd/unpack/CbmTrdUnpackAlgoBaseR.h | 3 + .../trd/unpack/CbmTrdUnpackAlgoR.cxx | 7 +- reco/steer/CbmRecoUnpack.cxx | 172 +++++++++++++++--- reco/steer/CbmRecoUnpack.h | 90 ++++++++- reco/steer/CbmSourceTsArchive.h | 3 + 8 files changed, 319 insertions(+), 57 deletions(-) diff --git a/core/data/CbmTsEventHeader.h b/core/data/CbmTsEventHeader.h index 70bed2b20b..beea415c68 100644 --- a/core/data/CbmTsEventHeader.h +++ b/core/data/CbmTsEventHeader.h @@ -31,14 +31,11 @@ public: /** @brief Get the number of digis in this Ts */ ULong64_t GetNDigisSts(ULong64_t) { return fNDigisSts; } /** @brief Get the number of digis in this Ts */ - ULong64_t GetNDigisTrd(ULong64_t) { return fNDigisTrd; } + ULong64_t GetNDigisTof(ULong64_t) { return fNDigisTof; } /** @brief Get the number of digis in this Ts */ - ULong64_t GetNDigisTrd2D(ULong64_t) { return fNDigisTrd2D; } + ULong64_t GetNDigisTrd1D(ULong64_t) { return fNDigisTrd; } /** @brief Get the number of digis in this Ts */ - ULong64_t GetNDigisTof(ULong64_t) { return fNDigisTof; } - - /** @brief Set the Ts Start Time @param value Start time of the TS */ - void SetTsStartTime(uint64_t value) { fTsStartTime = value; } + ULong64_t GetNDigisTrd2D(ULong64_t) { return fNDigisTrd2D; } /** @brief Set the number of digis in this Ts */ void SetNDigisPsd(ULong64_t value) { fNDigisPsd = value; } @@ -47,24 +44,31 @@ public: /** @brief Set the number of digis in this Ts */ void SetNDigisSts(ULong64_t value) { fNDigisSts = value; } /** @brief Set the number of digis in this Ts */ - void SetNDigisTrd(ULong64_t value) { fNDigisTrd = value; } + void SetNDigisTof(ULong64_t value) { fNDigisTof = value; } /** @brief Set the number of digis in this Ts */ - void SetNDigisTrd2D(ULong64_t value) { fNDigisTrd2D = value; } + void SetNDigisTrd1D(ULong64_t value) { fNDigisTrd = value; } /** @brief Set the number of digis in this Ts */ - void SetNDigisTof(ULong64_t value) { fNDigisTof = value; } + void SetNDigisTrd2D(ULong64_t value) { fNDigisTrd2D = value; } + /** @brief Set the Ts Start Time @param value Start time of the TS */ + void SetTsStartTime(uint64_t value) { fTsStartTime = value; } protected: /** Timeslice start time */ uint64_t fTsStartTime = 0; - ULong64_t fNDigisPsd = 0; - ULong64_t fNDigisRich = 0; - ULong64_t fNDigisSts = 0; - ULong64_t fNDigisTrd = 0; + /** @brief nDigis in "this" timeslice measured by the PSD */ + ULong64_t fNDigisPsd = 0; + /** @brief nDigis in "this" timeslice measured by the RICH */ + ULong64_t fNDigisRich = 0; + /** @brief nDigis in "this" timeslice measured by the STS */ + ULong64_t fNDigisSts = 0; + /** @brief nDigis in "this" timeslice measured by the TRD1D @remark the member is not renamed to fNDigisTrd1D for easier backwards compatibility */ + ULong64_t fNDigisTrd = 0; + /** @brief nDigis in "this" timeslice measured by the TRD2D */ ULong64_t fNDigisTrd2D = 0; - ULong64_t fNDigisTof = 0; - + /** @brief nDigis in "this" timeslice measured by the TOF */ + ULong64_t fNDigisTof = 0; ClassDef(CbmTsEventHeader, 3) }; diff --git a/macro/run/run_unpack_tsa.C b/macro/run/run_unpack_tsa.C index d391221afa..28aad42243 100644 --- a/macro/run/run_unpack_tsa.C +++ b/macro/run/run_unpack_tsa.C @@ -66,6 +66,15 @@ void run_unpack_tsa(std::string infile = "test.tsa", UInt_t runid = 0, const cha // ------------------------------------------------------------------------ + // ----- Performance profiling ---------------------------------------- + // Set to true if you want some minimal performance profiling output + bool doPerfProfiling = true; + // Define if you want a special path and name for the performance profiling output file + std::string perfProfFileName = outpath + filename; + perfProfFileName.replace(perfProfFileName.find(".tsa"), 4, ".perf.root"); + // ------------------------------------------------------------------------ + + // ----- CbmSetup ----------------------------------------------------- auto cbmsetup = CbmSetup::Instance(); cbmsetup->LoadSetup(setupName); @@ -130,7 +139,7 @@ void run_unpack_tsa(std::string infile = "test.tsa", UInt_t runid = 0, const cha std::string parfilesbasepathTrd = Form("%s/parameters/trd", srcDir.Data()); trd1Dconfig->SetParFilesBasePath(parfilesbasepathTrd); - trd1Dconfig->SetMonitor(GetTrdMonitor(outfilename)); + // trd1Dconfig->SetMonitor(GetTrdMonitor(outfilename)); // Get the spadic configuration true = avg baseline active / false plain sample 0 trd1Dconfig->SetSpadicObject(GetTrdSpadic(true)); trd1Dconfig->SetSystemTimeOffset(0); // [ns] value to be updated @@ -179,6 +188,8 @@ void run_unpack_tsa(std::string infile = "test.tsa", UInt_t runid = 0, const cha auto source = new CbmSourceTsArchive(infile.data()); source->SetCbmSourceType(CbmSourceTsArchive::eCbmSourceType::kOffline); auto unpack = source->GetRecoUnpack(); + unpack->SetDoPerfProfiling(doPerfProfiling); + unpack->SetOutputFilename(perfProfFileName); if (psdconfig) unpack->SetUnpackConfig(psdconfig); if (richconfig) unpack->SetUnpackConfig(richconfig); if (stsconfig) unpack->SetUnpackConfig(stsconfig); diff --git a/reco/base/CbmRecoUnpackAlgo.tmpl b/reco/base/CbmRecoUnpackAlgo.tmpl index 594075b390..b6c4159385 100644 --- a/reco/base/CbmRecoUnpackAlgo.tmpl +++ b/reco/base/CbmRecoUnpackAlgo.tmpl @@ -36,9 +36,12 @@ #include <algorithm> #include <cstddef> #include <cstdint> // for types +#include <iomanip> #include <memory> #include <vector> +#include <cmath> + template<typename TOutput, typename TOptOutA = std::nullptr_t, typename TOptOutB = std::nullptr_t> class CbmRecoUnpackAlgo { @@ -120,6 +123,18 @@ protected: /** @brief counter of created raw messages */ size_t fNrEpochMsgs = 0; + /** @brief Sum counter for used cpu time by this algo [µs].*/ + double fSumCpuTime = 0; + + /** @brief Sum counter for used wall time by this algo [µs].*/ + double fSumWallTime = 0; + + /** @brief Sum counter for size of the input data of this algo.*/ + double fSumInDataSize = 0; + + /** @brief Sum counter for size of the output data of this algo.*/ + double fSumOutDataSize = 0; + /** @brief counter for inf/error flags from the µSlices */ size_t fNrCrcValidFlags = 0; /** @brief counter for inf/error flags from the µSlices */ @@ -241,6 +256,9 @@ protected: public: // Runtime functions + /** @brief Add used cpu time, used in CbmRecoUnpack for performance profiling. @param value cpu time of last timeslice processing */ + void AddCpuTime(double value) { fSumCpuTime += value; } + /** * @brief Add a parameter container and the path to its ascii input. Note that all containers have to be derived from FairParGenericSet. * @param pair @@ -250,6 +268,9 @@ public: fParContVec.emplace_back(pair); } + /** @brief Add used wall time, used in CbmRecoUnpack for performance profiling. @param value wall time of last timeslice processing */ + void AddWallTime(double value) { fSumWallTime += value; } + /** * @brief Action at end of run. * @@ -257,10 +278,21 @@ public: void Finish() { LOG(info) << fName << "::Finish.-------------------------\n Unpack process : \n " << fNrProcessedTs - << " Timeslices with \n " << fNrCreatedRawMsgs << " Raw Messages,\n " << fNrCreatedDigis << " Digis,\n " - << fNrEpochMsgs << " Epoch Messages,\n " << fNrCreatedInfoMsgs << " Info Messages.\n " << fNrCrcValidFlags - << " CrcValidFlags \n " << fNrOverflowFlimFlags << " OverflowFlimFlags \n " << fNrOverflowUserFlags - << " OverflowUserFlags \n " << fNrDataErrorFlags << " DataErrorFlags \n "; + << " Timeslices with \n " << fNrCreatedRawMsgs << " Raw Messages,\n " << fNrCreatedDigis + << " Digis \n ...processed in walltime(cputime) " << std::setprecision(4) << fSumWallTime << "(" + << std::setprecision(4) << fSumCpuTime << ") µs \n " + << "-->" << std::setprecision(4) << fNrCreatedDigis / fSumWallTime << "(" << std::setprecision(4) + << fNrCreatedDigis / fSumCpuTime << ") Digis/µs <--> " << std::setprecision(4) + << fSumWallTime / fNrCreatedDigis << "(" << std::setprecision(4) << fSumCpuTime / fNrCreatedDigis + << ") µs/Digi.\n " + << "Processed amount of input data " << std::setprecision(4) << fSumInDataSize << " MB digested to " + << fSumOutDataSize << " MB output data <--> " << std::setprecision(4) << fSumInDataSize / fSumWallTime + << " MB/µs digested. \n"; + + + LOG(debug) << fNrEpochMsgs << " Epoch Messages,\n " << fNrCreatedInfoMsgs << " Info Messages.\n " + << fNrCrcValidFlags << " CrcValidFlags \n " << fNrOverflowFlimFlags << " OverflowFlimFlags \n " + << fNrOverflowUserFlags << " OverflowUserFlags \n " << fNrDataErrorFlags << " DataErrorFlags \n "; // Additional explicit finish of the derived class used during runtime. finish(); @@ -290,6 +322,13 @@ public: */ std::vector<TOptOutA>* GetOptOutBVec() { return fOptOutBVec; } + /** + * @brief Get the Output Obj Size + * + * @return size_t + */ + static size_t GetOutputObjSize() { return sizeof(TOutput); } + /** * @brief Get the requested parameter containers. To be defined in the derived classes! * Return the required parameter containers together with the paths to the ascii @@ -389,7 +428,12 @@ public: } } - fNrCreatedDigis += fOutputVec.size(); + auto ndigis = fOutputVec.size(); + fNrCreatedDigis += ndigis; + + // Get the input(output) data sizes + fSumInDataSize += ts->size_component(icomp) / 1.0e6; + fSumOutDataSize += ndigis * GetOutputObjSize() / 1.0e6; ++fNrProcessedTs; return fOutputVec; diff --git a/reco/detectors/trd/unpack/CbmTrdUnpackAlgoBaseR.h b/reco/detectors/trd/unpack/CbmTrdUnpackAlgoBaseR.h index 152948e9ae..10070038e7 100644 --- a/reco/detectors/trd/unpack/CbmTrdUnpackAlgoBaseR.h +++ b/reco/detectors/trd/unpack/CbmTrdUnpackAlgoBaseR.h @@ -192,6 +192,9 @@ protected: /** @brief Number of eom frames outside of a SOM frame range */ size_t fNrWildEom = 0; + /** @brief Number of missing EOM frames to finish a SOM frame */ + size_t fNrMissingEom = 0; + /** @brief Number of wild null words, should only appear at the end of a µSlice */ size_t fNrWildNul = 0; diff --git a/reco/detectors/trd/unpack/CbmTrdUnpackAlgoR.cxx b/reco/detectors/trd/unpack/CbmTrdUnpackAlgoR.cxx index d960a16b80..bb836c75e7 100644 --- a/reco/detectors/trd/unpack/CbmTrdUnpackAlgoR.cxx +++ b/reco/detectors/trd/unpack/CbmTrdUnpackAlgoR.cxx @@ -162,9 +162,9 @@ std::int16_t CbmTrdUnpackAlgoR::extractSample(size_t* adcbuffer, size_t* nadcbit void CbmTrdUnpackAlgoR::finishDerived() { LOG(info) << fName << " \n " << fNrWildRda << " unexpected RDA frames,\n " << fNrWildNul - << " unexpected NUL frames, \n " << fNrWildEom << " unexpected EOM frames, \n " << fNrElinkMis - << " SOM to RDA/EOM eLink mismatches, \n " << fNrNonMajorTsMsb << " non-major ts_msbs and \n " - << fNrUnknownWords << " unknown frames."; + << " unexpected NUL frames, \n " << fNrWildEom << " unexpected EOM frames, \n " << fNrMissingEom + << " missing EOM frames, \n " << fNrElinkMis << " SOM to RDA/EOM eLink mismatches, \n " << fNrNonMajorTsMsb + << " non-major ts_msbs and \n " << fNrUnknownWords << " unknown frames." << std::endl; } // ---- getInfoType ---- @@ -476,6 +476,7 @@ bool CbmTrdUnpackAlgoR::unpack(const fles::Timeslice* ts, std::uint16_t icomp, U else { // We move the word counter backwards by one, such that the unexpected message can correctly be digested iword--; + ++fNrMissingEom; LOG(debug) << fName << "::unpack() We had a SOM message and hence, desparately need an EOM message but none came. This " diff --git a/reco/steer/CbmRecoUnpack.cxx b/reco/steer/CbmRecoUnpack.cxx index c5e02f9be4..aa4b4a562f 100644 --- a/reco/steer/CbmRecoUnpack.cxx +++ b/reco/steer/CbmRecoUnpack.cxx @@ -7,6 +7,7 @@ #include "CbmRecoUnpack.h" +#include "CbmRecoUnpackConfig.tmpl" #include "CbmTrdDigi.h" #include "CbmTsEventHeader.h" @@ -16,8 +17,10 @@ #include <Logger.h> #include <RtypesCore.h> +#include <TH1.h> #include <cstddef> +#include <cstdint> #include <memory> #include <utility> #include <vector> @@ -32,7 +35,7 @@ CbmRecoUnpack::CbmRecoUnpack() {} // ---------------------------------------------------------------------------- -// ----- Initialisation --------------------------------------------------- +// ----- Finish ----------------------------------------------------------- void CbmRecoUnpack::Finish() { LOG(info) << "CbmRecoUnpack::Finish() I do let the unpackers talk first :\n"; @@ -43,6 +46,9 @@ void CbmRecoUnpack::Finish() if (fTofConfig) fTofConfig->GetUnpacker()->Finish(); if (fTrd1DConfig) fTrd1DConfig->GetUnpacker()->Finish(); if (fTrd2DConfig) fTrd2DConfig->GetUnpacker()->Finish(); + + // Create some default performance profiling histograms and write them to a file + if (fDoPerfProf) performanceProfiling(); } // ---------------------------------------------------------------------------- @@ -54,7 +60,6 @@ Bool_t CbmRecoUnpack::Init() FairRootManager* ioman = FairRootManager::Instance(); assert(ioman); - auto eh = FairRun::Instance()->GetEventHeader(); if (eh->IsA() == CbmTsEventHeader::Class()) fCbmTsEventHeader = static_cast<CbmTsEventHeader*>(eh); else @@ -62,17 +67,32 @@ Bool_t CbmRecoUnpack::Init() << "CbmRecoUnpack::Init() no CbmTsEventHeader was added to the run. Without it, we can not store the UTC of the " "Timeslices correctly. Hence, this causes a fatal. Please add it in the steering macro to the Run."; - // --- Psd - if (fPsdConfig) fPsdConfig->Init(ioman); + if (fPsdConfig) { + fPsdConfig->Init(ioman); + initPerformanceMaps(fkFlesPsd, "PSD"); + } // --- Rich - if (fRichConfig) fRichConfig->Init(ioman); + if (fRichConfig) { + fRichConfig->Init(ioman); + initPerformanceMaps(fkFlesRich, "RICH"); + } + // --- Sts - if (fStsConfig) fStsConfig->Init(ioman); + if (fStsConfig) { + fStsConfig->Init(ioman); + initPerformanceMaps(fkFlesSts, "STS"); + } // --- Tof - if (fTofConfig) fTofConfig->Init(ioman); + if (fTofConfig) { + fTofConfig->Init(ioman); + initPerformanceMaps(fkFlesTof, "TOF"); + } // --- Trd - if (fTrd1DConfig) fTrd1DConfig->Init(ioman); + if (fTrd1DConfig) { + fTrd1DConfig->Init(ioman); + initPerformanceMaps(fkFlesTrd, "TRD1D"); + } // --- TRD2D if (fTrd2DConfig) { if (fTrd1DConfig) { @@ -89,6 +109,7 @@ Bool_t CbmRecoUnpack::Init() else { fTrd2DConfig->Init(ioman); } + initPerformanceMaps(fkFlesTrd2D, "TRD2D"); } // This is an ugly work around, because the TRD and TRD2D want to access the same vector and there is no function to retrieve a writeable vector<obj> from the FairRootManager, especially before the branches are created, as far as I am aware. The second option workaround is in in Init() to look for the fasp config and create a separate branch for fasp created CbmTrdDigis PR 072021 @@ -97,6 +118,99 @@ Bool_t CbmRecoUnpack::Init() // ---------------------------------------------------------------------------- +// ----- initPerformanceMaps ---------------------------------------------- +void CbmRecoUnpack::initPerformanceMaps(std::uint16_t subsysid, std::string name) +{ + if (fDoPerfProf) { + fNameMap.emplace(std::make_pair(subsysid, std::make_pair(name, 0))); + fTimeMap.emplace(std::make_pair(subsysid, std::make_pair(0, 0))); + fDataSizeMap.emplace(std::make_pair(subsysid, std::make_pair(0, 0))); + } +} +// ---------------------------------------------------------------------------- + + +// ----- performanceProfiling --------------------------------------------- +void CbmRecoUnpack::performanceProfiling() +{ + std::unique_ptr<TH1D> hProducedDigis = + std::unique_ptr<TH1D>(new TH1D("ProducedDigis", "ProducedDigis", fNameMap.size(), -0.5, fNameMap.size() - 0.5)); + hProducedDigis->SetXTitle("Subsystem"); + hProducedDigis->SetYTitle("N-Digis"); + std::unique_ptr<TH1D> hSpeedPerf = std::unique_ptr<TH1D>( + new TH1D("SpeedPerformance", "SpeedPerformance", fNameMap.size() * 2, -0.5, fNameMap.size() * 2 - 0.5)); + hSpeedPerf->SetXTitle("Subsystem"); + hSpeedPerf->SetYTitle("Unpacking performance [#mus/Digi]"); + std::unique_ptr<TH1D> hDataPerf = std::unique_ptr<TH1D>( + new TH1D("DataPerformance", "DataPerformance", fNameMap.size() * 2, -0.5, fNameMap.size() * 2 - 0.5)); + hDataPerf->SetXTitle("Subsystem"); + hDataPerf->SetYTitle("Data [MB]"); + size_t iunpackerbin = 1; + for (auto namepair : fNameMap) { + + // Speed performance + auto timeit = fTimeMap.find(namepair.first); + double cpu = timeit->second.first / namepair.second.second; + double wall = timeit->second.second / namepair.second.second; + + // Data performance + auto datait = fDataSizeMap.find(namepair.first); + double indata = datait->second.first; + double outdata = datait->second.second; + + + // N-Digis + std::string label = namepair.second.first; + hProducedDigis->GetXaxis()->SetBinLabel(iunpackerbin, label.data()); + hProducedDigis->SetBinContent(iunpackerbin, namepair.second.second); + + // Cpu time + label = namepair.second.first; + label += " cpu"; + hSpeedPerf->GetXaxis()->SetBinLabel(iunpackerbin * 2 - 1, label.data()); + hSpeedPerf->SetBinContent(iunpackerbin * 2 - 1, cpu); + // Wall time + label = namepair.second.first; + label += " wall"; + hSpeedPerf->GetXaxis()->SetBinLabel(iunpackerbin * 2, label.data()); + hSpeedPerf->SetBinContent(iunpackerbin * 2, wall); + + // In data + label = namepair.second.first; + label += " in"; + hDataPerf->GetXaxis()->SetBinLabel(iunpackerbin * 2 - 1, label.data()); + hDataPerf->SetBinContent(iunpackerbin * 2 - 1, indata); + + // Out data + label = namepair.second.first; + label += " out"; + hDataPerf->GetXaxis()->SetBinLabel(iunpackerbin * 2, label.data()); + hDataPerf->SetBinContent(iunpackerbin * 2, outdata); + + ++iunpackerbin; + } + + /// Save old global file and folder pointer to avoid messing with FairRoot + TFile* oldFile = gFile; + TDirectory* oldDir = gDirectory; + + /// (Re-)Create ROOT file to store the histos + TFile histofile(fOutfilename.data(), "RECREATE"); + + histofile.cd(); + hProducedDigis->Write(); + hSpeedPerf->Write(); + hDataPerf->Write(); + + /// Restore old global file and folder pointer to avoid messing with FairRoot + gFile = oldFile; + gDirectory = oldDir; + + // histofile->Close(); + histofile.Close(); +} +// ---------------------------------------------------------------------------- + // ----- Reset ------------------------------------------------------------ void CbmRecoUnpack::Reset() { @@ -136,39 +250,47 @@ void CbmRecoUnpack::Unpack(unique_ptr<Timeslice> ts) switch (systemId) { case fkFlesPsd: { - if (fPsdConfig) - fCbmTsEventHeader->SetNDigisPsd( - unpack(×lice, component, fPsdConfig, fPsdConfig->GetOptOutAVec(), fPsdConfig->GetOptOutBVec())); + if (fPsdConfig) { + fCbmTsEventHeader->SetNDigisPsd(unpack(systemId, ×lice, component, fPsdConfig, + fPsdConfig->GetOptOutAVec(), fPsdConfig->GetOptOutBVec())); + } + break; } case fkFlesRich: { - if (fRichConfig) - fCbmTsEventHeader->SetNDigisRich( - unpack(×lice, component, fRichConfig, fRichConfig->GetOptOutAVec(), fRichConfig->GetOptOutBVec())); + if (fRichConfig) { + fCbmTsEventHeader->SetNDigisRich(unpack(systemId, ×lice, component, fRichConfig, + fRichConfig->GetOptOutAVec(), fRichConfig->GetOptOutBVec())); + } break; } case fkFlesSts: { - if (fStsConfig) - fCbmTsEventHeader->SetNDigisSts( - unpack(×lice, component, fStsConfig, fStsConfig->GetOptOutAVec(), fStsConfig->GetOptOutBVec())); + if (fStsConfig) { + fCbmTsEventHeader->SetNDigisSts(unpack(systemId, ×lice, component, fStsConfig, + fStsConfig->GetOptOutAVec(), fStsConfig->GetOptOutBVec())); + } break; } case fkFlesTof: { - if (fTofConfig) - fCbmTsEventHeader->SetNDigisTof( - unpack(×lice, component, fTofConfig, fTofConfig->GetOptOutAVec(), fTofConfig->GetOptOutBVec())); + if (fTofConfig) { + fCbmTsEventHeader->SetNDigisTof(unpack(systemId, ×lice, component, fTofConfig, + fTofConfig->GetOptOutAVec(), fTofConfig->GetOptOutBVec())); + } break; } case fkFlesTrd: { - if (fTrd1DConfig) - fCbmTsEventHeader->SetNDigisTrd( - unpack(×lice, component, fTrd1DConfig, fTrd1DConfig->GetOptOutAVec(), fTrd1DConfig->GetOptOutBVec())); + if (fTrd1DConfig) { + fCbmTsEventHeader->SetNDigisTrd1D(unpack(systemId, ×lice, component, fTrd1DConfig, + fTrd1DConfig->GetOptOutAVec(), fTrd1DConfig->GetOptOutBVec())); + } break; } case fkFlesTrd2D: { if (fTrd2DConfig) - fCbmTsEventHeader->SetNDigisTrd2D( - unpack(×lice, component, fTrd2DConfig, fTrd2DConfig->GetOptOutAVec(), fTrd2DConfig->GetOptOutBVec())); + if (fTrd2DConfig) { + fCbmTsEventHeader->SetNDigisTrd2D(unpack(systemId, ×lice, component, fTrd2DConfig, + fTrd2DConfig->GetOptOutAVec(), fTrd2DConfig->GetOptOutBVec())); + } break; } default: { diff --git a/reco/steer/CbmRecoUnpack.h b/reco/steer/CbmRecoUnpack.h index 1584918b06..5b9ffeefcd 100644 --- a/reco/steer/CbmRecoUnpack.h +++ b/reco/steer/CbmRecoUnpack.h @@ -20,11 +20,16 @@ #include <Timeslice.hpp> #include <RtypesCore.h> +#include <THnSparse.h> #include <TObject.h> #include <type_traits> // this is std::lib used for template is_member_function_pointer +#include <chrono> #include <cstddef> +#include <cstdint> +#include <ctime> #include <memory> +#include <utility> #include <vector> @@ -69,6 +74,23 @@ public: */ void SetDebugPrintout(bool value = true) { fDoDebugPrints = value; } + /** + * @brief (De)Activate the performance profiling based on histograms + * + * @param value + */ + void SetDoPerfProfiling(bool value = true) { fDoPerfProf = value; } + + /** + * @brief Set the performance profiling Output Filename + * + * @param value + */ + void SetOutputFilename(std::string value) + { + if (!value.empty()) fOutfilename = value; + } + /** @brief Set the Psd Unpack Config @param config */ void SetUnpackConfig(std::shared_ptr<CbmPsdUnpackConfig> config) { fPsdConfig = config; } @@ -79,7 +101,7 @@ public: void SetUnpackConfig(std::shared_ptr<CbmStsUnpackConfig> config) { fStsConfig = config; } // /** @brief Set the Tof Unpack Config @param config */ - // void SetUnpackConfig(std::shared_ptr<CbmTofUnpackConfig> config) { fTofConfig = config; } + void SetUnpackConfig(std::shared_ptr<CbmTofUnpackConfig> config) { fTofConfig = config; } /** @brief Set the Trd Unpack Config @param config */ void SetUnpackConfig(std::shared_ptr<CbmTrdUnpackConfig> config) { fTrd1DConfig = config; } @@ -87,9 +109,6 @@ public: /** @brief Set the Trd2D Unpack Config @param config */ void SetUnpackConfig(std::shared_ptr<CbmTrdUnpackConfigFasp2D> config) { fTrd2DConfig = config; } - /** @brief Set the Tof Unpack Config @param config */ - void SetUnpackConfig(std::shared_ptr<CbmTofUnpackConfig> config) { fTofConfig = config; } - /** @brief Trigger the unpacking procedure **/ void Unpack(std::unique_ptr<fles::Timeslice> ts); @@ -97,14 +116,37 @@ private: static constexpr std::uint16_t fkFlesMvd = static_cast<std::uint16_t>(fles::SubsystemIdentifier::MVD); static constexpr std::uint16_t fkFlesSts = static_cast<std::uint16_t>(fles::SubsystemIdentifier::STS); static constexpr std::uint16_t fkFlesRich = static_cast<std::uint16_t>(fles::SubsystemIdentifier::RICH); + static constexpr std::uint16_t fkFlesPsd = static_cast<std::uint16_t>(fles::SubsystemIdentifier::PSD); static constexpr std::uint16_t fkFlesMuch = static_cast<std::uint16_t>(fles::SubsystemIdentifier::MUCH); static constexpr std::uint16_t fkFlesTrd = static_cast<std::uint16_t>(fles::SubsystemIdentifier::TRD); static constexpr std::uint16_t fkFlesTrd2D = static_cast<std::uint16_t>(fles::SubsystemIdentifier::TRD2D); static constexpr std::uint16_t fkFlesTof = static_cast<std::uint16_t>(fles::SubsystemIdentifier::RPC); - static constexpr std::uint16_t fkFlesPsd = static_cast<std::uint16_t>(fles::SubsystemIdentifier::PSD); /** @brief Flag if extended debug output is to be printed or not*/ - bool fDoDebugPrints = false; + bool fDoDebugPrints = false; //! + + /** @brief Flag if performance profiling should be activated or not.*/ + bool fDoPerfProf = false; //! + + /** @brief Map to store a name for the unpackers and the processed amount of digis, key = fkFlesId*/ + std::map<std::uint16_t, std::pair<std::string, size_t>> fNameMap = {}; //! + + /** @brief Map to store the cpu and wall time, key = fkFlesId*/ + std::map<std::uint16_t, std::pair<double, double>> fTimeMap = {}; //! + + /** @brief Map to store the in and out data amount, key = fkFlesId*/ + std::map<std::uint16_t, std::pair<double, double>> fDataSizeMap = {}; //! + + /** @brief Run the performance profiling based on the fTimeMap and fDataSizeMap members. */ + void performanceProfiling(); + + /** + * @brief Init the performance profiling maps for a given unpacker + * + * @param subsysid Subsystem Identifier casted to std::uint16_t + * @param name Name of the unpacker + */ + void initPerformanceMaps(std::uint16_t subsysid, std::string name); /** @brief Sort a vector timewise vector type has to provide GetTime() */ template<typename TVecobj> @@ -145,11 +187,16 @@ private: * @param algo Algorithm to be used for this component * @param outtargetvec Target vector for the output elements * @param optoutputvecs Target vectors for optional outputs + * @return std::pair<ndigis, std::pair<cputime, walltime>> */ template<class TConfig, class TOptOutA = std::nullptr_t, class TOptOutB = std::nullptr_t> - size_t unpack(const fles::Timeslice* ts, std::uint16_t icomp, TConfig config, + size_t unpack(const std::uint16_t subsysid, const fles::Timeslice* ts, std::uint16_t icomp, TConfig config, std::vector<TOptOutA>* optouttargetvecA = nullptr, std::vector<TOptOutB>* optouttargetvecB = nullptr) { + + auto wallstarttime = std::chrono::high_resolution_clock::now(); + std::clock_t cpustarttime = std::clock(); + auto algo = config->GetUnpacker(); std::vector<TOptOutA> optoutAvec = {}; std::vector<TOptOutB> optoutBvec = {}; @@ -188,11 +235,35 @@ private: optouttargetvecB->emplace_back(optoutB); } + std::clock_t cpuendtime = std::clock(); + auto wallendtime = std::chrono::high_resolution_clock::now(); + + // Cpu time in [µs] + auto cputime = 1e6 * (cpuendtime - cpustarttime) / CLOCKS_PER_SEC; + algo->AddCpuTime(cputime); + // Real time in [µs] + auto walltime = std::chrono::duration<double, std::micro>(wallendtime - wallstarttime).count(); + algo->AddWallTime(walltime); + // Check some numbers from this timeslice size_t nDigis = digivec.size(); LOG(debug) << "Component " << icomp << " connected to config " << config->GetName() << " n-Digis " << nDigis - << " processed in this timeslice."; + << " processed in walltime(cputime) = " << walltime << "(" << cputime << cputime << ") µs" + << "this timeslice."; + + if (fDoPerfProf) { + auto timeit = fTimeMap.find(subsysid); + timeit->second.first += cputime; + timeit->second.second += walltime; + + auto datait = fDataSizeMap.find(subsysid); + datait->second.first += ts->size_component(icomp) / 1.0e6; + datait->second.second += nDigis * algo->GetOutputObjSize() / 1.0e6; + + fNameMap.find(subsysid)->second.second += nDigis; + } + return nDigis; } // ---------------------------------------------------------------------------- @@ -218,6 +289,9 @@ private: /** @brief Pointer to the Timeslice start time used to write it to the output tree @remark since we hand this to the FairRootManager it also wants to delete it and we do not have to take care of deletion */ CbmTsEventHeader* fCbmTsEventHeader = nullptr; + /** @brief Name of the performance profiling output file */ + std::string fOutfilename = "CbmRecoUnpack.perf.root"; + ClassDef(CbmRecoUnpack, 1); }; diff --git a/reco/steer/CbmSourceTsArchive.h b/reco/steer/CbmSourceTsArchive.h index bf1677a5f3..c67cba991c 100644 --- a/reco/steer/CbmSourceTsArchive.h +++ b/reco/steer/CbmSourceTsArchive.h @@ -118,6 +118,9 @@ public: /** @brief Set the Cbm Source Type @param type @remark temporary fix see enum */ void SetCbmSourceType(eCbmSourceType type) { fCbmSourceType = type; } + /** @brief Provide dummy implementation of this virtual function as not relevant in our case **/ + Bool_t SpecifyRunId() { return kTRUE; } + private: /** List of input file names **/ std::vector<std::string> fFileNames = {}; -- GitLab