From 94d6c23344e8104f0fcb946aa858abe0ac9bb115 Mon Sep 17 00:00:00 2001 From: "s.zharko@gsi.de" <s.zharko@gsi.de> Date: Thu, 21 Mar 2024 17:42:24 +0100 Subject: [PATCH] CA: bugfix in parallel treatment of CA-iteration index --- algo/ca/TrackingChain.cxx | 12 +- algo/ca/core/data/CaWindowData.h | 7 ++ algo/ca/core/pars/CaParameters.h | 3 +- algo/ca/core/tracking/CaFramework.h | 10 -- algo/ca/core/tracking/CaTrackFinder.cxx | 56 +++------ algo/ca/core/tracking/CaTrackFinderWindow.cxx | 76 ++++++------ .../ca/core/tracking/CaTripletConstructor.cxx | 10 +- algo/ca/core/utils/CaTrackingMonitor.h | 115 ++++++++++-------- algo/global/Reco.cxx | 6 +- 9 files changed, 148 insertions(+), 147 deletions(-) diff --git a/algo/ca/TrackingChain.cxx b/algo/ca/TrackingChain.cxx index ad5673eda2..1599bf88fe 100644 --- a/algo/ca/TrackingChain.cxx +++ b/algo/ca/TrackingChain.cxx @@ -84,11 +84,12 @@ TrackingChain::Output_t TrackingChain::Run(Input_t recoResults) { xpu::scoped_timer t_("CA"); // TODO: pass timings to monitoring for throughput? fCaMonitorData.Reset(); + fCaMonitorData.StartTimer(ca::ETimer::TrackingChain); // ----- Init input data --------------------------------------------------------------------------------------------- - fCaMonitorData.StartTimer(ca::ETimer::PrepareInput); + fCaMonitorData.StartTimer(ca::ETimer::PrepareInputData); this->PrepareInput(recoResults); - fCaMonitorData.StopTimer(ca::ETimer::PrepareInput); + fCaMonitorData.StopTimer(ca::ETimer::PrepareInputData); // ----- Run reconstruction ------------------------------------------------------------------------------------------ fCaFramework.SetMonitorData(fCaMonitorData); @@ -168,10 +169,12 @@ TrackingChain::Output_t TrackingChain::PrepareOutput() // QA if (fInputQa.IsSenderDefined()) { + fCaMonitorData.StartTimer(ca::ETimer::InputQa); fInputQa.RegisterInputData(&fCaFramework.GetInputData()); fInputQa.RegisterTracks(&output.tracks); fInputQa.RegisterRecoHitIndices(&fCaFramework.fRecoHits); fInputQa.Exec(); + fCaMonitorData.StopTimer(ca::ETimer::InputQa); } if (fOutputQa.IsSenderDefined()) { @@ -183,6 +186,7 @@ TrackingChain::Output_t TrackingChain::PrepareOutput() fCaMonitorData.StopTimer(ca::ETimer::OutputQa); } + fCaMonitorData.StopTimer(ca::ETimer::TrackingChain); fCaMonitor.AddMonitorData(fCaMonitorData); output.monitorData = fCaMonitorData; @@ -230,7 +234,7 @@ void TrackingChain::ReadHits(PartitionedSpan<const ca::HitTypes_t::at<DetID>> hi } int iStActive = (iStLocal != -1) ? fCaFramework.GetParameters().GetStationIndexActive(iStLocal, DetID) : -1; - size_t iOffset = hits.Offsets()[iPartition]; + //size_t iOffset = hits.Offsets()[iPartition]; if (iStActive < 0) { continue; // legit } @@ -244,7 +248,7 @@ void TrackingChain::ReadHits(PartitionedSpan<const ca::HitTypes_t::at<DetID>> hi ca::HitKeyIndex_t firstHitKey = fNofHitKeys; for (size_t iPartHit = 0; iPartHit < vHits.size(); ++iPartHit) { const auto& hit = vHits[iPartHit]; - int iHitExt = iOffset + iPartHit; + //int iHitExt = iOffset + iPartHit; // ---- Fill ca::Hit ca::Hit caHit; if constexpr (IsSts) { diff --git a/algo/ca/core/data/CaWindowData.h b/algo/ca/core/data/CaWindowData.h index b599ae6a03..a9c8e43667 100644 --- a/algo/ca/core/data/CaWindowData.h +++ b/algo/ca/core/data/CaWindowData.h @@ -149,6 +149,12 @@ namespace cbm::algo::ca /// \brief Accesses current iteration [[gnu::always_inline]] const Iteration* CurrentIteration() const { return fpCurrentIteration; } + /// \brief Accesses current iteration index (DEBUG) + [[gnu::always_inline]] int CurrentIterationIndex() const { return fCurrentIterationIndex; } + + /// \brief Accesses current iteration index (DEBUG) + [[gnu::always_inline]] void SetCurrentIterationIndex(int id) { fCurrentIterationIndex = id; } + /// \brief Accesses magnetic field in starting point (target or first station) [[gnu::always_inline]] ca::FieldValue<fvec>& TargB() { return fTargB; } @@ -197,6 +203,7 @@ namespace cbm::algo::ca /// \brief Current track-finder iteration const Iteration* fpCurrentIteration = nullptr; + int fCurrentIterationIndex = -1; // TODO: Get rid of this field, it can cause bugs ca::FieldValue<fvec> fTargB _fvecalignment{}; ///< field in the target point (modifiable, do not touch!!) ca::MeasurementXy<fvec> fTargetMeasurement _fvecalignment{}; ///< target constraint diff --git a/algo/ca/core/pars/CaParameters.h b/algo/ca/core/pars/CaParameters.h index 74b65e29c0..8831beb334 100644 --- a/algo/ca/core/pars/CaParameters.h +++ b/algo/ca/core/pars/CaParameters.h @@ -336,7 +336,8 @@ namespace cbm::algo::ca unsigned int fMaxDoubletsPerSinglet{150}; ///< Upper-bound cut on max number of doublets per one singlet unsigned int fMaxTripletPerDoublets{15}; ///< Upper-bound cut on max number of triplets per one doublet - alignas(constants::misc::Alignment) IterationsContainer_t fCAIterations{}; ///< L1 tracking iterations vector + alignas(constants::misc::Alignment) IterationsContainer_t fCAIterations{ + "ca::Parameters::fCAIterations"}; ///< L1 tracking iterations vector /************************* ** Geometry parameters ** diff --git a/algo/ca/core/tracking/CaFramework.h b/algo/ca/core/tracking/CaFramework.h index 5f8ca1ae09..7239170b0a 100644 --- a/algo/ca/core/tracking/CaFramework.h +++ b/algo/ca/core/tracking/CaFramework.h @@ -231,13 +231,6 @@ namespace cbm::algo::ca public: Vector<CaHitTimeInfo> fHitTimeInfo; - - /// ----- Data used during track finding ----- - /// - - - /// ---------- - double fCaRecoTime{0.}; // time of the track finder + fitter Vector<Track> fRecoTracks{"Framework::fRecoTracks"}; ///< reconstructed tracks @@ -246,9 +239,6 @@ namespace cbm::algo::ca fvec EventTime{0.f}; fvec Err{0.f}; - /// --- data used during finding iterations - unsigned int fCurrentIterationIndex{0}; ///< index of the corrent iteration, needed for debug output - public: std::vector<ca::WindowData> fvWData; ///< Intrnal data processed in a time-window std::vector<ca::TrackFinderWindow> fvTrackFinderWindow; ///< Track finder algorithm for the time window diff --git a/algo/ca/core/tracking/CaTrackFinder.cxx b/algo/ca/core/tracking/CaTrackFinder.cxx index 1575fccc67..1ab8b5399a 100644 --- a/algo/ca/core/tracking/CaTrackFinder.cxx +++ b/algo/ca/core/tracking/CaTrackFinder.cxx @@ -49,20 +49,18 @@ void TrackFinder::FindTracks() // It splits the input data into sub-timeslices // and runs the track finder over the sub-slices // + frAlgo.fMonitorData.StartTimer(ETimer::Tracking); + frAlgo.fMonitorData.StartTimer(ETimer::PrepareTimeslice); frAlgo.fMonitorData.IncrementCounter(ECounter::TrackingCall); frAlgo.fMonitorData.IncrementCounter(ECounter::RecoHit, frAlgo.fInputData.GetNhits()); - frAlgo.fMonitorData.StartTimer(ETimer::FindTracks); auto timerStart = std::chrono::high_resolution_clock::now(); - frAlgo.fMonitorData.StartTimer(ETimer::PrepareDataStreams); auto& wDataThread0 = frAlgo.fvWData[0]; // NOTE: Thread 0 must be always defined // ----- Reset data arrays ------------------------------------------------------------------------------------------- - frAlgo.fvMonitorDataThread[0].StartTimer(ETimer::PrepareDataStreams4); wDataThread0.HitKeyFlags().reset(frAlgo.fInputData.GetNhitKeys(), 0); - frAlgo.fvMonitorDataThread[0].StopTimer(ETimer::PrepareDataStreams4); frAlgo.fHitTimeInfo.reset(frAlgo.fInputData.GetNhits()); @@ -200,7 +198,6 @@ void TrackFinder::FindTracks() int nWindowsThread = nWindows / frAlgo.GetNofThreads(); float windowDelta = fWindowLength - fWindowOverlap - fWindowMargin; // cut data into sub-timeslices and process them one by one - float threadDuration = (fStatTsEnd - fStatTsStart) / frAlgo.GetNofThreads(); for (int iThread = 0; iThread < frAlgo.GetNofThreads(); ++iThread) { fvWindowStartThread[iThread] = fStatTsStart + iThread * nWindowsThread * windowDelta; fvWindowEndThread[iThread] = @@ -209,17 +206,17 @@ void TrackFinder::FindTracks() << fvWindowEndThread[iThread] / 1.e6 << " ms"; } fvWindowEndThread[frAlgo.GetNofThreads() - 1] = fStatTsEnd; - frAlgo.fMonitorData.StopTimer(ETimer::PrepareDataStreams); + frAlgo.fMonitorData.StopTimer(ETimer::PrepareTimeslice); // Save tracks frAlgo.fRecoTracks.clear(); frAlgo.fRecoHits.clear(); if (frAlgo.GetNofThreads() == 1) { this->FindTracksThread(0); - frAlgo.fMonitorData.StartTimer(ETimer::PrepareOutput); + frAlgo.fMonitorData.StartTimer(ETimer::StoreTracksFinal); frAlgo.fRecoTracks = std::move(fvRecoTracks[0]); frAlgo.fRecoHits = std::move(fvRecoHitIndices[0]); - frAlgo.fMonitorData.StopTimer(ETimer::PrepareOutput); + frAlgo.fMonitorData.StopTimer(ETimer::StoreTracksFinal); } else { std::vector<std::thread> vThreadList; @@ -232,7 +229,7 @@ void TrackFinder::FindTracks() th.join(); } } - frAlgo.fMonitorData.StartTimer(ETimer::PrepareOutput); + frAlgo.fMonitorData.StartTimer(ETimer::StoreTracksFinal); auto Operation = [](size_t acc, const auto& v) { return acc + v.size(); }; int nRecoTracks = std::accumulate(fvRecoTracks.begin(), fvRecoTracks.end(), 0, Operation); int nRecoHits = std::accumulate(fvRecoHitIndices.begin(), fvRecoHitIndices.end(), 0, Operation); @@ -242,10 +239,9 @@ void TrackFinder::FindTracks() frAlgo.fRecoTracks.insert(frAlgo.fRecoTracks.end(), fvRecoTracks[iTh].begin(), fvRecoTracks[iTh].end()); frAlgo.fRecoHits.insert(frAlgo.fRecoHits.end(), fvRecoHitIndices[iTh].begin(), fvRecoHitIndices[iTh].end()); } - frAlgo.fMonitorData.StopTimer(ETimer::PrepareOutput); + frAlgo.fMonitorData.StopTimer(ETimer::StoreTracksFinal); } - frAlgo.fMonitorData.StopTimer(ETimer::FindTracks); frAlgo.fMonitorData.IncrementCounter(ECounter::RecoTrack, frAlgo.fRecoTracks.size()); frAlgo.fMonitorData.IncrementCounter(ECounter::RecoHitUsed, frAlgo.fRecoHits.size()); @@ -270,24 +266,20 @@ void TrackFinder::FindTracks() tsHeader.Start() = fStatTsStart; tsHeader.End() = fStatTsEnd; + frAlgo.fMonitorData.StopTimer(ETimer::Tracking); + LOG(info) << "CA tracker: time slice finished. Reconstructed " << frAlgo.fRecoTracks.size() << " tracks with " << frAlgo.fRecoHits.size() << " hits. Processed " << statNhitsProcessedTotal << " hits in " << statNwindowsTotal << " time windows. Reco time " << frAlgo.fCaRecoTime / 1.e9 << " s"; - - int nWindowsReal = 0; - for (int iThread = 0; iThread < frAlgo.GetNofThreads(); ++iThread) { - LOG(info) << "Ca: thread " << iThread << ", " << fvStatNwindows[iThread] - << " windows processed, start window: " << nWindowsReal - << ", end window: " << ((nWindowsReal += fvStatNwindows[iThread]) - 1); - } } // --------------------------------------------------------------------------------------------------------------------- // void TrackFinder::FindTracksThread(int iThread) { - LOG(info) << "---- CA: searching for tracks on thread " << iThread; - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::FindTracksThread); + auto& monitor = frAlgo.fvMonitorDataThread[iThread]; + monitor.StartTimer(ETimer::TrackingThread); + monitor.StartTimer(ETimer::PrepareThread); // Init vectors auto& wData = frAlgo.fvWData[iThread]; @@ -298,34 +290,24 @@ void TrackFinder::FindTracksThread(int iThread) size_t nHitsExpected = 2 * nHitsTot; size_t nTracksExpected = 2 * nHitsTot / nStations; size_t nThreads = frAlgo.GetNofThreads(); - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareDataStreams1); fvRecoTracks[iThread].clear(); fvRecoTracks[iThread].reserve(nTracksExpected / nThreads); - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareDataStreams1); - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareDataStreams2); fvRecoHitIndices[iThread].clear(); fvRecoHitIndices[iThread].reserve(nHitsExpected / nThreads); - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareDataStreams2); - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareDataStreams3); frAlgo.fvTrackFinderWindow[iThread].InitTimeslice(); - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareDataStreams3); if (iThread != 0) { auto& wData0 = frAlgo.fvWData[0]; - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareDataStreams4); // slow ... wData.HitKeyFlags().clear(); wData.HitKeyFlags().reserve(nHitKeys); for (const auto& flag : wData0.HitKeyFlags()) { wData.HitKeyFlags().emplace_back(flag); } - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareDataStreams4); } - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareDataStreams5); for (int iS = 0; iS < nStations; ++iS) { wData.TsHitIndices(iS).clear(); wData.TsHitIndices(iS).reserve(nHitsTot); } - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareDataStreams5); } const int nDataStreams = frAlgo.fInputData.GetNdataStreams(); @@ -352,12 +334,13 @@ void TrackFinder::FindTracksThread(int iThread) } } - fvStatNwindows[iThread] = 0; fvStatNhitsProcessed[iThread] = 0; int statLastLogTimeChunk = -1; + monitor.StopTimer(ETimer::PrepareThread); + while (areUntouchedDataLeft) { frAlgo.fvMonitorDataThread[iThread].IncrementCounter(ECounter::SubTS); // select the sub-slice hits @@ -373,7 +356,7 @@ void TrackFinder::FindTracksThread(int iThread) int statNwindowHits = 0; - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareHitsWindow); + frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::PrepareWindow); for (int iStream = 0; iStream < nDataStreams; ++iStream) { for (ca::HitIndex_t caHitId = sliceFirstHit[iStream]; caHitId < sliceLastHit[iStream]; ++caHitId) { const CaHitTimeInfo& info = frAlgo.fHitTimeInfo[caHitId]; @@ -403,7 +386,6 @@ void TrackFinder::FindTracksThread(int iThread) } } fvStatNhitsProcessed[iThread] += statNwindowHits; - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareHitsWindow); // print the LOG for every 10 ms of data processed { @@ -434,9 +416,11 @@ void TrackFinder::FindTracksThread(int iThread) } } - frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::TrackFinderWindow); + frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::PrepareWindow); + + frAlgo.fvMonitorDataThread[iThread].StartTimer(ETimer::TrackingWindow); frAlgo.fvTrackFinderWindow[iThread].CaTrackFinderSlice(); - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::TrackFinderWindow); + frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::TrackingWindow); // save reconstructed tracks with no hits in the overlap region //if (fvWindowStartThread[iThread] > 13.23e6 && fvWindowStartThread[iThread] < 13.26e6) { @@ -497,7 +481,7 @@ void TrackFinder::FindTracksThread(int iThread) fvWindowStartThread[iThread] -= fWindowMargin; // do 5 ns margin } } - frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::FindTracksThread); + frAlgo.fvMonitorDataThread[iThread].StopTimer(ETimer::TrackingThread); } // --------------------------------------------------------------------------------------------------------------------- diff --git a/algo/ca/core/tracking/CaTrackFinderWindow.cxx b/algo/ca/core/tracking/CaTrackFinderWindow.cxx index de1582fb92..1d3f744ba2 100644 --- a/algo/ca/core/tracking/CaTrackFinderWindow.cxx +++ b/algo/ca/core/tracking/CaTrackFinderWindow.cxx @@ -183,8 +183,11 @@ void TrackFinderWindow::CaTrackFinderSlice() * CATrackFinder routine setting ***********************************/ + frMonitorData.StartTimer(ETimer::InitWindow); ReadWindowData(); + frMonitorData.StopTimer(ETimer::InitWindow); + frMonitorData.StartTimer(ETimer::PrepareGrid); for (int iS = 0; iS < frAlgo.GetParameters().GetNstationsActive(); ++iS) { bool timeUninitialised = 1; @@ -251,19 +254,22 @@ void TrackFinderWindow::CaTrackFinderSlice() frWData.HitKeyFlags()); /* clang-format on */ } - - - // ---- Loop over Track Finder iterations ----------------------------------------------------------------// - - for (frAlgo.fCurrentIterationIndex = 0; - frAlgo.fCurrentIterationIndex < frAlgo.GetParameters().GetCAIterations().size(); - ++frAlgo.fCurrentIterationIndex) { - - // current iteration of the CA tracker - const auto& caIteration = frAlgo.GetParameters().GetCAIterations()[frAlgo.fCurrentIterationIndex]; + frMonitorData.StopTimer(ETimer::PrepareGrid); + + // ----- Find tracks ----- + // + frMonitorData.StartTimer(ETimer::FindTracks); + // TODO: Get rid of fCurrentTierationIndex. If it is needed of logs, please used caIteration.GetName() + for (int iIteration = 0; iIteration < frAlgo.GetParameters().GetNcaIterations(); ++iIteration) { + + // ----- Prepare iteration + // + frMonitorData.StartTimer(ETimer::PrepareIteration); + const auto& caIteration = frAlgo.GetParameters().GetCAIterations()[iIteration]; frWData.SetCurrentIteration(&caIteration); + frWData.SetCurrentIterationIndex(iIteration); - if (frAlgo.fCurrentIterationIndex > 0) { + if (iIteration > 0) { for (int ista = 0; ista < frAlgo.GetParameters().GetNstationsActive(); ++ista) { frWData.Grid(ista).RemoveUsedHits(frWData.Hits(), frWData.HitKeyFlags()); } @@ -306,11 +312,11 @@ void TrackFinderWindow::CaTrackFinderSlice() frWData.TargetMeasurement().SetNdfY(1); } } + frMonitorData.StopTimer(ETimer::PrepareIteration); - - /// stage for triplets creation - - frMonitorData.StartTimer(ETimer::TripletConstructionWindow); + // ----- Triplets construction ----- + // + frMonitorData.StartTimer(ETimer::ConstructTriplets); ca::TripletConstructor constructor(frAlgo, frWData); @@ -339,11 +345,11 @@ void TrackFinderWindow::CaTrackFinderSlice() fvHitNofTriplets[ihitl] = fvTriplets[istal].size() - oldSize; } } // istal + frMonitorData.StopTimer(ETimer::ConstructTriplets); - frMonitorData.StopTimer(ETimer::TripletConstructionWindow); - - // search for neighbouring triplets - frMonitorData.StartTimer(ETimer::NeighboringTripletSearchWindow); + // ----- Search for neighbouring triplets ----- + // + frMonitorData.StartTimer(ETimer::SearchNeighbours); for (int istal = frAlgo.GetParameters().GetNstationsActive() - 2; istal >= iStFirst; istal--) { // start with downstream chambers @@ -392,14 +398,11 @@ void TrackFinderWindow::CaTrackFinderSlice() frMonitorData.IncrementCounter(ECounter::Triplet, fvTriplets[istal].size()); } // istal - frMonitorData.StopTimer(ETimer::NeighboringTripletSearchWindow); + frMonitorData.StopTimer(ETimer::SearchNeighbours); - - ///==================================================================== - ///= = - ///= Collect track candidates. CREATE TRACKS = - ///= = - ///==================================================================== + // ----- Collect track candidates and create tracks + // + frMonitorData.StartTimer(ETimer::CreateTracks); // min level to start triplet. So min track length = min_level+3. int min_level = std::min(caIteration.GetMinNhits(), caIteration.GetMinNhitsStation0()) - 3; @@ -514,7 +517,7 @@ void TrackFinderWindow::CaTrackFinderSlice() tr.SetAlive(true); if constexpr (fDebug) { std::stringstream s; - s << "iter " << frAlgo.fCurrentIterationIndex << ", track candidate " << fvTrackCandidates.size() - 1 + s << "iter " << frWData.CurrentIterationIndex() << ", track candidate " << fvTrackCandidates.size() - 1 << " found, L = " << best_tr.NofHits() << " chi2= " << best_tr.Chi2() << " hits: "; for (auto hitId : tr.Hits()) { s << hitId << " (mc " << frAlgo.GetMcTrackIdForCaHit(hitId) << ") "; @@ -624,7 +627,7 @@ void TrackFinderWindow::CaTrackFinderSlice() ca::Branch& tr = fvTrackCandidates[iCandidate]; if constexpr (fDebug) { - LOG(info) << "iter " << frAlgo.fCurrentIterationIndex << ", track candidate " << iCandidate + LOG(info) << "iter " << frWData.CurrentIterationIndex() << ", track candidate " << iCandidate << ": alive = " << tr.IsAlive(); } @@ -659,8 +662,9 @@ void TrackFinderWindow::CaTrackFinderSlice() } // tracks } // firstTripletLevel + frMonitorData.StopTimer(ETimer::CreateTracks); - + frMonitorData.StartTimer(ETimer::SuppressHitKeys); // suppress strips of suppressed hits for (unsigned int ih = 0; ih < frWData.Hits().size(); ih++) { if (frWData.IsHitSuppressed(ih)) { @@ -669,21 +673,23 @@ void TrackFinderWindow::CaTrackFinderSlice() frWData.IsHitKeyUsed(hit.BackKey()) = 1; } } + frMonitorData.StopTimer(ETimer::SuppressHitKeys); } // ---- Loop over Track Finder iterations: END -----------------------------------------------------------// + frMonitorData.StopTimer(ETimer::FindTracks); // Fit tracks - frMonitorData.StartTimer(ETimer::TrackFitterWindow); + frMonitorData.StartTimer(ETimer::FitTracks); fTrackFitter.FitCaTracks(); - frMonitorData.StopTimer(ETimer::TrackFitterWindow); + frMonitorData.StopTimer(ETimer::FitTracks); // Merge clones - frMonitorData.StartTimer(ETimer::CloneMergerWindow); + frMonitorData.StartTimer(ETimer::MergeClones); fCloneMerger.Exec(frWData.RecoTracks(), frWData.RecoHitIndices()); - frMonitorData.StopTimer(ETimer::CloneMergerWindow); + frMonitorData.StopTimer(ETimer::MergeClones); - frMonitorData.StartTimer(ETimer::TrackFitterWindow); + frMonitorData.StartTimer(ETimer::FitTracks); fTrackFitter.FitCaTracks(); - frMonitorData.StopTimer(ETimer::TrackFitterWindow); + frMonitorData.StopTimer(ETimer::FitTracks); } diff --git a/algo/ca/core/tracking/CaTripletConstructor.cxx b/algo/ca/core/tracking/CaTripletConstructor.cxx index d5c61e62c2..9476f0f8d6 100644 --- a/algo/ca/core/tracking/CaTripletConstructor.cxx +++ b/algo/ca/core/tracking/CaTripletConstructor.cxx @@ -349,10 +349,10 @@ void TripletConstructor::FindRightHit() const ca::Hit& h1 = frAlgo.fInputData.GetHit(ih1); LOG(info) << "\n====== Extrapolated Doublet : " - << " iter " << frAlgo.fCurrentIterationIndex << " hits: {" << fIstaL << "/" << ih0 << " " << fIstaM - << "/" << ih1 << " " << fIstaR << "/?} xyz: {" << h0.X() << " " << h0.Y() << " " << h0.Z() << "}, {" - << h1.X() << " " << h1.Y() << " " << h1.Z() << "} chi2 " << T2.GetChiSq()[0] << " ndf " << T2.Ndf()[0] - << " chi2time " << T2.ChiSqTime()[0] << " ndfTime " << T2.NdfTime()[0]; + << " iter " << frWData.CurrentIteration()->GetName() << " hits: {" << fIstaL << "/" << ih0 << " " + << fIstaM << "/" << ih1 << " " << fIstaR << "/?} xyz: {" << h0.X() << " " << h0.Y() << " " << h0.Z() + << "}, {" << h1.X() << " " << h1.Y() << " " << h1.Z() << "} chi2 " << T2.GetChiSq()[0] << " ndf " + << T2.Ndf()[0] << " chi2time " << T2.ChiSqTime()[0] << " ndfTime " << T2.NdfTime()[0]; LOG(info) << " extr. track: " << T2.ToString(0); } @@ -618,7 +618,7 @@ void TripletConstructor::FitTriplets() const ca::Hit& h2 = frAlgo.fInputData.GetHit(ih2); //const CbmL1MCTrack& mctr = CbmL1::Instance()->GetMcTracks()[mc1]; LOG(info) << "== fitted triplet: " - << " iter " << frAlgo.fCurrentIterationIndex << " hits: {" << fIstaL << "/" << ih0 << " " << fIstaM + << " iter " << frWData.CurrentIterationIndex() << " hits: {" << fIstaL << "/" << ih0 << " " << fIstaM << "/" << ih1 << " " << fIstaR << "/" << ih2 << "} xyz: {" << h0.X() << " " << h0.Y() << " " << h0.Z() << "}, {" << h1.X() << " " << h1.Y() << " " << h1.Z() << "}, {" << h2.X() << ", " << h2.Y() << ", " << h2.Z() << "} chi2 " << T.GetChiSq()[0] << " ndf " << T.Ndf()[0] << " chi2time " << T.ChiSqTime()[0] diff --git a/algo/ca/core/utils/CaTrackingMonitor.h b/algo/ca/core/utils/CaTrackingMonitor.h index 2af786c5cb..0ba75e3459 100644 --- a/algo/ca/core/utils/CaTrackingMonitor.h +++ b/algo/ca/core/utils/CaTrackingMonitor.h @@ -46,30 +46,36 @@ namespace cbm::algo::ca /// \enum ETimer /// \brief Timer keys for the CA algo monitor + /* clang-format off */ + // NOTE: SZh 21.03.2024: Disabling clang-format to indicate the scope of timers using the indent enum class ETimer { - //Tracking, - PrepareInput, - FindTracks, - PrepareDataStreams, - PrepareDataStreams1, - PrepareDataStreams2, - PrepareDataStreams3, - PrepareDataStreams4, - PrepareDataStreams5, - FindTracksThread, - PrepareHitsWindow, - TrackFinderWindow, - TrackFitterWindow, - CloneMergerWindow, - StoreTracksWindow, - PrepareOutput, - TripletConstructionWindow, - NeighboringTripletSearchWindow, - //InputQa, - OutputQa, + TrackingChain, + PrepareInputData, + Tracking, + PrepareTimeslice, + TrackingThread, + PrepareThread, + PrepareWindow, + TrackingWindow, + InitWindow, + PrepareGrid, + FindTracks, /// (iterations loop) + PrepareIteration, + ConstructTriplets, + SearchNeighbours, + CreateTracks, + SuppressHitKeys, + FitTracks, + MergeClones, + StoreTracksWindow, + StoreTracksFinal, + InputQa, + OutputQa, + kEND }; + /* clang-format on */ using TrackingMonitorData = MonitorData<ECounter, ETimer>; @@ -80,41 +86,44 @@ namespace cbm::algo::ca /// \brief Default constructor TrackingMonitor() : Monitor<ECounter, ETimer>("CA Framework Monitor") { - SetCounterName(ECounter::TrackingCall, "full_routine_calls"); - SetCounterName(ECounter::RecoTrack, "reco_tracks"); - SetCounterName(ECounter::RecoHit, "reco_hits"); + SetCounterName(ECounter::TrackingCall, "full routine calls"); + SetCounterName(ECounter::RecoTrack, "reco tracks"); + SetCounterName(ECounter::RecoHit, "reco hits"); SetCounterName(ECounter::Triplet, "triplets"); - SetCounterName(ECounter::RecoHitUsed, "used_reco_hits"); + SetCounterName(ECounter::RecoHitUsed, "used reco hits"); SetCounterName(ECounter::SubTS, "sub-timeslices"); - SetCounterName(ECounter::RecoMvdHit, "MVD_hits_in_tracks"); - SetCounterName(ECounter::RecoStsHit, "STS_hits_in_tracks"); - SetCounterName(ECounter::RecoMuchHit, "MUCH_hits_in_tracks"); - SetCounterName(ECounter::RecoTrdHit, "TRD_hits_in_tracks"); - SetCounterName(ECounter::RecoTofHit, "TOF_hits_in_tracks"); - SetCounterName(ECounter::UndefinedMvdHit, "undefined_MVD_hits"); - SetCounterName(ECounter::UndefinedStsHit, "undefined_STS_hits"); - SetCounterName(ECounter::UndefinedMuchHit, "undefined_MuCh_hits"); - SetCounterName(ECounter::UndefinedTrdHit, "undefined_TRD_hits"); - SetCounterName(ECounter::UndefinedTofHit, "undefined_TOF_hits"); - //SetTimerName(ETimer::Tracking, "full_tracking"); - SetTimerName(ETimer::PrepareInput, "input_data_initialization"); - SetTimerName(ETimer::PrepareOutput, "int._output_data_initialization"); - SetTimerName(ETimer::FindTracks, "find_tracks_procedure"); - SetTimerName(ETimer::PrepareDataStreams, "data_streams_preparation"); - SetTimerName(ETimer::PrepareDataStreams1, "data_streams_preparation_(1)"); - SetTimerName(ETimer::PrepareDataStreams2, "data_streams_preparation_(2)"); - SetTimerName(ETimer::PrepareDataStreams3, "data_streams_preparation_(3)"); - SetTimerName(ETimer::PrepareDataStreams4, "data_streams_preparation_(4)"); - SetTimerName(ETimer::PrepareDataStreams5, "data_streams_preparation_(5)"); - SetTimerName(ETimer::FindTracksThread, "find_tracks_on_thread"); - SetTimerName(ETimer::PrepareHitsWindow, "hit_preparation_in_window"); - SetTimerName(ETimer::TrackFinderWindow, "track_finder_in_window"); - SetTimerName(ETimer::TrackFitterWindow, "track_fitter_in_window"); - SetTimerName(ETimer::CloneMergerWindow, "clone_merger_in_window"); - SetTimerName(ETimer::TripletConstructionWindow, "triplet_construction_in_window"); - SetTimerName(ETimer::NeighboringTripletSearchWindow, "neighboring_triplets_w."); - SetTimerName(ETimer::StoreTracksWindow, "tracks_storing_in_window"); - SetTimerName(ETimer::OutputQa, "output_QA"); + SetCounterName(ECounter::RecoMvdHit, "MVD hits in tracks"); + SetCounterName(ECounter::RecoStsHit, "STS hits in tracks"); + SetCounterName(ECounter::RecoMuchHit, "MUCH hits in tracks"); + SetCounterName(ECounter::RecoTrdHit, "TRD hits in tracks"); + SetCounterName(ECounter::RecoTofHit, "TOF hits in tracks"); + SetCounterName(ECounter::UndefinedMvdHit, "undefined MVD hits"); + SetCounterName(ECounter::UndefinedStsHit, "undefined STS hits"); + SetCounterName(ECounter::UndefinedMuchHit, "undefined MuCh hits"); + SetCounterName(ECounter::UndefinedTrdHit, "undefined TRD hits"); + SetCounterName(ECounter::UndefinedTofHit, "undefined TOF hits"); + + SetTimerName(ETimer::PrepareInputData, "input data preparation"); + SetTimerName(ETimer::Tracking, "algorithm execution"); + SetTimerName(ETimer::PrepareTimeslice, "timeslice preparation"); + SetTimerName(ETimer::TrackingThread, "tracking on one thread"); + SetTimerName(ETimer::PrepareThread, "thread preparation"); + SetTimerName(ETimer::PrepareWindow, "window preparation"); + SetTimerName(ETimer::TrackingWindow, "tracking in one window"); + SetTimerName(ETimer::InitWindow, "window initialization"); + SetTimerName(ETimer::PrepareGrid, "grid preparation"); + SetTimerName(ETimer::FindTracks, "track finding"); + SetTimerName(ETimer::PrepareIteration, "iteration preparation"); + SetTimerName(ETimer::ConstructTriplets, "triplet constrcution"); + SetTimerName(ETimer::SearchNeighbours, "neighbors search"); + SetTimerName(ETimer::CreateTracks, "track creation"); + SetTimerName(ETimer::SuppressHitKeys, "used hit key suppression"); + SetTimerName(ETimer::FitTracks, "track fitter"); + SetTimerName(ETimer::MergeClones, "clone merger"); + SetTimerName(ETimer::StoreTracksWindow, "track storing in window"); + SetTimerName(ETimer::StoreTracksFinal, "final track storing"); + SetTimerName(ETimer::InputQa, "input QA"); + SetTimerName(ETimer::OutputQa, "output QA"); SetRatioKeys({ECounter::TrackingCall, ECounter::SubTS, ECounter::RecoTrack}); } diff --git a/algo/global/Reco.cxx b/algo/global/Reco.cxx index 7605cc9c90..27321d89b2 100644 --- a/algo/global/Reco.cxx +++ b/algo/global/Reco.cxx @@ -462,9 +462,9 @@ void Reco::QueueTrackingMetrics(const ca::TrackingMonitorData& monitor) } GetMonitor().QueueMetric("cbmreco", {{"hostname", fles::system::current_hostname()}, {"child", Opts().ChildId()}}, - {{"caRecoTimeTotal", monitor.GetTimer(ca::ETimer::FindTracks).GetTotalMs()}, - {"caTrackFinderTime", monitor.GetTimer(ca::ETimer::TrackFinderWindow).GetTotalMs()}, - {"caTrackFitterTime", monitor.GetTimer(ca::ETimer::TrackFitterWindow).GetTotalMs()}, + {{"caRecoTimeTotal", monitor.GetTimer(ca::ETimer::TrackingChain).GetTotalMs()}, + {"caTrackFinderTime", monitor.GetTimer(ca::ETimer::FindTracks).GetTotalMs()}, + {"caTrackFitterTime", monitor.GetTimer(ca::ETimer::FitTracks).GetTotalMs()}, {"caNofRecoTracks", monitor.GetCounterValue(ca::ECounter::RecoTrack)}, {"caNofRecoHitsTotal", monitor.GetCounterValue(ca::ECounter::RecoHit)}, {"caNofRecoHitsUsed", monitor.GetCounterValue(ca::ECounter::RecoHitUsed)}, -- GitLab