From cbae337f15cbe189ca3e7498c7b3c236091ebad8 Mon Sep 17 00:00:00 2001 From: 2xB <2xB@users.noreply.github.com> Date: Mon, 1 Jul 2024 16:59:27 +0200 Subject: [PATCH] Kassiopeia: Add processing duration as output fields To understand which steps and tracks take long to calculate, this commit adds new output fields `processing_duration` to Tracks, Steps, Events and Runs. This replaces the old processing time calculation of KSRuns used to print the estimated remaining time into the log since that can re-use the newly added timings. However this excludes a minor bit of clean-up code after the run processing from the respective timing. --- .../gh-pages/source/kassiopeia_output.rst | 10 ++++++-- Kassiopeia/Simulation/CMakeLists.txt | 2 ++ Kassiopeia/Simulation/Include/KSEvent.h | 3 ++- Kassiopeia/Simulation/Include/KSRun.h | 3 ++- Kassiopeia/Simulation/Include/KSStep.h | 4 +++- Kassiopeia/Simulation/Include/KSTimed.h | 23 +++++++++++++++++++ Kassiopeia/Simulation/Include/KSTrack.h | 3 ++- Kassiopeia/Simulation/Source/KSEvent.cxx | 5 +++- Kassiopeia/Simulation/Source/KSRoot.cxx | 23 ++++++++++++++++--- Kassiopeia/Simulation/Source/KSRun.cxx | 7 +++--- Kassiopeia/Simulation/Source/KSStep.cxx | 5 +++- Kassiopeia/Simulation/Source/KSTimed.cxx | 16 +++++++++++++ Kassiopeia/Simulation/Source/KSTrack.cxx | 5 +++- 13 files changed, 94 insertions(+), 15 deletions(-) create mode 100644 Kassiopeia/Simulation/Include/KSTimed.h create mode 100644 Kassiopeia/Simulation/Source/KSTimed.cxx diff --git a/Documentation/gh-pages/source/kassiopeia_output.rst b/Documentation/gh-pages/source/kassiopeia_output.rst index df3a110de..59f3e5a76 100644 --- a/Documentation/gh-pages/source/kassiopeia_output.rst +++ b/Documentation/gh-pages/source/kassiopeia_output.rst @@ -143,8 +143,8 @@ output is written after the completion of each step. Similary, at the track leve to the initial and final parameters of a track, i.e. the state at particle generation and termination. The standard output fields for the particle are defined at the end of the file -:gh-code:`Kassiopeia/Operators/Source/KSParticle.cxx` while the step and track output fields can be found in -:gh-code:`Kassiopeia/Operators/Source/KSStep.cxx` and :gh-code:`Kassiopeia/Operators/Source/KSTrack.cxx`, respectively. +:gh-code:`Kassiopeia/Simulation/Source/KSParticle.cxx` while the step and track output fields can be found in +:gh-code:`Kassiopeia/Simulation/Source/KSStep.cxx` and :gh-code:`Kassiopeia/Simulation/Source/KSTrack.cxx`, respectively. Other specialized output fields are also available for some propagation or interaction terms. Output fields @@ -296,6 +296,8 @@ overview of the different fields and their types. +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Number of Turns | ``number_of_turns`` | ``unsigned int`` | ``KSRun`` | Number of particle turns/reflections during run | +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ +| Processing Duration| ``processing_duration`` | ``double`` | ``KSRun`` | Computing time used for run | ++--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Event ID | ``event_id`` | ``int`` | ``KSEvent`` | Event ID of current event | +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Event Count | ``event_count`` | ``int`` | ``KSEvent`` | Total number of events | @@ -338,6 +340,8 @@ overview of the different fields and their types. +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Generator Radius | ``generator_radius`` | ``double`` | ``KSEvent`` | Maximum radius of the generated particles (in m) | +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ +| Processing Duration| ``processing_duration`` | ``double`` | ``KSEvent`` | Computing time used for event | ++--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Track ID | ``event_id`` | ``int`` | ``KSTrack`` | Track ID of current track | +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Track Count | ``event_count`` | ``int`` | ``KSTrack`` | Total number of tracks | @@ -440,6 +444,8 @@ overview of the different fields and their types. +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ | Intermed. Particle | ``trajectory_particle`` | ``KSParticle`` | ``KSStep`` | Pointer to initial particle before propagation | +--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ +| Processing Duration| ``processing_duration`` | ``double`` | ``KSStep`` | Computing time used for step | ++--------------------+-------------------------------------+------------------+----------------------------+----------------------------------------------------------+ Vector and matrix type can be accessed by their components in the written output data. For example, when the ``position`` element is used, the corresponding fields in the output data can be found under the names ``position_x``, ``position_y``, diff --git a/Kassiopeia/Simulation/CMakeLists.txt b/Kassiopeia/Simulation/CMakeLists.txt index 935c0dafc..77ff9eced 100644 --- a/Kassiopeia/Simulation/CMakeLists.txt +++ b/Kassiopeia/Simulation/CMakeLists.txt @@ -26,6 +26,7 @@ set( SIMULATION_HEADER_BASENAMES KSRootTerminator.h KSRootWriter.h KSRoot.h + KSTimed.h ) set( SIMULATION_HEADER_PATH ${CMAKE_CURRENT_SOURCE_DIR}/Include @@ -62,6 +63,7 @@ set( SIMULATION_SOURCE_BASENAMES KSRootTerminator.cxx KSRootWriter.cxx KSRoot.cxx + KSTimed.cxx ) set( SIMULATION_SOURCE_PATH ${CMAKE_CURRENT_SOURCE_DIR}/Source diff --git a/Kassiopeia/Simulation/Include/KSEvent.h b/Kassiopeia/Simulation/Include/KSEvent.h index 43c3d5b3c..e88cc8aa1 100644 --- a/Kassiopeia/Simulation/Include/KSEvent.h +++ b/Kassiopeia/Simulation/Include/KSEvent.h @@ -4,12 +4,13 @@ #include "KField.h" #include "KSComponentTemplate.h" #include "KSParticle.h" +#include "KSTimed.h" namespace Kassiopeia { class KSRun; -class KSEvent : public KSComponentTemplate +class KSEvent : public KSComponentTemplate, public KSTimed { public: KSEvent(); diff --git a/Kassiopeia/Simulation/Include/KSRun.h b/Kassiopeia/Simulation/Include/KSRun.h index 32f438f7d..1011c4e92 100644 --- a/Kassiopeia/Simulation/Include/KSRun.h +++ b/Kassiopeia/Simulation/Include/KSRun.h @@ -3,11 +3,12 @@ #include "KField.h" #include "KSComponentTemplate.h" +#include "KSTimed.h" namespace Kassiopeia { -class KSRun : public KSComponentTemplate +class KSRun : public KSComponentTemplate, public KSTimed { public: KSRun(); diff --git a/Kassiopeia/Simulation/Include/KSStep.h b/Kassiopeia/Simulation/Include/KSStep.h index 1c88b4066..6ac69a964 100644 --- a/Kassiopeia/Simulation/Include/KSStep.h +++ b/Kassiopeia/Simulation/Include/KSStep.h @@ -4,13 +4,14 @@ #include "KField.h" #include "KSComponentTemplate.h" #include "KSParticle.h" +#include "KSTimed.h" namespace Kassiopeia { class KSTrack; -class KSStep : public KSComponentTemplate +class KSStep : public KSComponentTemplate, public KSTimed { public: KSStep(); @@ -122,6 +123,7 @@ class KSStep : public KSComponentTemplate public: K_REFS(KSParticleQueue, ParticleQueue) + }; } // namespace Kassiopeia diff --git a/Kassiopeia/Simulation/Include/KSTimed.h b/Kassiopeia/Simulation/Include/KSTimed.h new file mode 100644 index 000000000..66d57edcf --- /dev/null +++ b/Kassiopeia/Simulation/Include/KSTimed.h @@ -0,0 +1,23 @@ +#ifndef Kassiopeia_KSTimed_h_ +#define Kassiopeia_KSTimed_h_ + +#include + +namespace Kassiopeia +{ + +class KSTimed { + private: + std::chrono::steady_clock::time_point fTimeStart; + double fProcessingDuration = -1; + + public: + void StartTiming(); + void EndTiming(); + + const double& GetProcessingDuration() const {return fProcessingDuration;}; +}; + +} + +#endif diff --git a/Kassiopeia/Simulation/Include/KSTrack.h b/Kassiopeia/Simulation/Include/KSTrack.h index ffcb7fb92..e73f09baf 100644 --- a/Kassiopeia/Simulation/Include/KSTrack.h +++ b/Kassiopeia/Simulation/Include/KSTrack.h @@ -4,12 +4,13 @@ #include "KField.h" #include "KSComponentTemplate.h" #include "KSParticle.h" +#include "KSTimed.h" namespace Kassiopeia { class KSEvent; -class KSTrack : public KSComponentTemplate +class KSTrack : public KSComponentTemplate, public KSTimed { public: KSTrack(); diff --git a/Kassiopeia/Simulation/Source/KSEvent.cxx b/Kassiopeia/Simulation/Source/KSEvent.cxx index 0612bc7a4..229cee39c 100644 --- a/Kassiopeia/Simulation/Source/KSEvent.cxx +++ b/Kassiopeia/Simulation/Source/KSEvent.cxx @@ -29,6 +29,7 @@ KSEvent::KSEvent() : {} KSEvent::KSEvent(const KSEvent& aCopy) : KSComponent(aCopy), + KSTimed(aCopy), fEventId(aCopy.fEventId), fEventCount(aCopy.fEventCount), fParentRunId(aCopy.fParentRunId), @@ -54,6 +55,7 @@ KSEvent::KSEvent(const KSEvent& aCopy) : {} KSEvent& KSEvent::operator=(const KSEvent& aCopy) { + KSTimed::operator=(aCopy); fEventId = aCopy.fEventId; fEventCount = aCopy.fEventCount; fParentRunId = aCopy.fParentRunId; @@ -105,6 +107,7 @@ STATICINT sKSEventDict = KSDictionary::AddComponent(&KSEvent::GetGeneratorMinTime, "generator_min_time") + KSDictionary::AddComponent(&KSEvent::GetGeneratorMaxTime, "generator_max_time") + KSDictionary::AddComponent(&KSEvent::GetGeneratorLocation, "generator_location") + - KSDictionary::AddComponent(&KSEvent::GetGeneratorRadius, "generator_radius"); + KSDictionary::AddComponent(&KSEvent::GetGeneratorRadius, "generator_radius") + + KSDictionary::AddComponent(&KSEvent::GetProcessingDuration, "processing_duration"); } // namespace Kassiopeia diff --git a/Kassiopeia/Simulation/Source/KSRoot.cxx b/Kassiopeia/Simulation/Source/KSRoot.cxx index 98167b894..1f072b00e 100644 --- a/Kassiopeia/Simulation/Source/KSRoot.cxx +++ b/Kassiopeia/Simulation/Source/KSRoot.cxx @@ -418,6 +418,8 @@ void KSRoot::ExecuteRun() //clear any previous GSL errors KGslErrorHandler::GetInstance().ClearError(); + fRun->StartTiming(); + // send report runmsg(eNormal) << "processing run " << fRun->GetRunId() << " ..." << eom; @@ -468,6 +470,8 @@ void KSRoot::ExecuteRun() fRootRunModifier->ExecutePostRunModification(); } + fRun->EndTiming(); + // write run fRun->PushUpdate(); fRootRunModifier->PushUpdate(); @@ -501,7 +505,7 @@ void KSRoot::ExecuteEvent() fEvent->NumberOfTurns() = 0; fEventIndex++; - auto tClockStart = chrono::steady_clock::now(); + fEvent->StartTiming(); fRootEventModifier->ExecutePreEventModification(); @@ -579,6 +583,8 @@ void KSRoot::ExecuteEvent() fRootEventModifier->ExecutePostEventModification(); + fEvent->EndTiming(); + // write event fEvent->PushUpdate(); fRootEventModifier->PushUpdate(); @@ -589,8 +595,7 @@ void KSRoot::ExecuteEvent() fRootEventModifier->PushDeupdate(); // determine time spent for event processing - auto tClockEnd = chrono::steady_clock::now(); - auto tTimeSpan = chrono::duration_cast>(tClockEnd - tClockStart).count(); + auto tTimeSpan = fEvent->GetProcessingDuration(); fTotalExecTime += tTimeSpan; @@ -623,6 +628,8 @@ void KSRoot::ExecuteTrack() fTrack->DiscreteSecondaries() = 0; fTrack->NumberOfTurns() = 0; + fTrack->StartTiming(); + fRootTrackModifier->ExecutePreTrackModification(); // send report @@ -702,6 +709,8 @@ void KSRoot::ExecuteTrack() fRootTrackModifier->ExecutePostTrackModification(); + fTrack->EndTiming(); + // write track @@ -766,6 +775,8 @@ void KSRoot::ExecuteStep() fStep->SurfaceNavigationName().clear(); fStep->SurfaceNavigationFlag() = false; + fStep->StartTiming(); + // run pre-step modification bool hasPreModified = fRootStepModifier->ExecutePreStepModification(); if (hasPreModified) { @@ -922,6 +933,8 @@ void KSRoot::ExecuteStep() } } + fStep->EndTiming(); + // push update fStep->PushUpdate(); fRootTrajectory->PushUpdate(); @@ -975,6 +988,8 @@ void KSRoot::ExecuteStep() } } + fStep->EndTiming(); + // push update fStep->PushUpdate(); fRootSurfaceInteraction->PushUpdate(); @@ -1002,6 +1017,8 @@ void KSRoot::ExecuteStep() fStep->FinalParticle().SetActive(false); + fStep->EndTiming(); + // push update fStep->PushUpdate(); fRootSurfaceInteraction->PushUpdate(); diff --git a/Kassiopeia/Simulation/Source/KSRun.cxx b/Kassiopeia/Simulation/Source/KSRun.cxx index bb52dab64..fe26f65b5 100644 --- a/Kassiopeia/Simulation/Source/KSRun.cxx +++ b/Kassiopeia/Simulation/Source/KSRun.cxx @@ -22,6 +22,7 @@ KSRun::KSRun() : {} KSRun::KSRun(const KSRun& aCopy) : KSComponent(aCopy), + KSTimed(aCopy), fRunId(aCopy.fRunId), fRunCount(aCopy.fRunCount), fTotalEvents(aCopy.fTotalEvents), @@ -38,6 +39,7 @@ KSRun::KSRun(const KSRun& aCopy) : {} KSRun& KSRun::operator=(const KSRun& aCopy) { + KSTimed::operator=(aCopy); fRunId = aCopy.fRunId; fRunCount = aCopy.fRunCount; fTotalEvents = aCopy.fTotalEvents; @@ -72,7 +74,6 @@ STATICINT sKSRunDict = KSDictionary::AddComponent(&KSRun::GetDiscreteSecondaries, "discrete_secondaries") + KSDictionary::AddComponent(&KSRun::GetDiscreteEnergyChange, "discrete_energy_change") + KSDictionary::AddComponent(&KSRun::GetDiscreteMomentumChange, "discrete_momentum_change") + - KSDictionary::AddComponent(&KSRun::GetNumberOfTurns, "number_of_turns"); - - + KSDictionary::AddComponent(&KSRun::GetNumberOfTurns, "number_of_turns") + + KSDictionary::AddComponent(&KSRun::GetProcessingDuration, "processing_duration"); } // namespace Kassiopeia diff --git a/Kassiopeia/Simulation/Source/KSStep.cxx b/Kassiopeia/Simulation/Source/KSStep.cxx index 10d9386b1..b442f78be 100644 --- a/Kassiopeia/Simulation/Source/KSStep.cxx +++ b/Kassiopeia/Simulation/Source/KSStep.cxx @@ -45,6 +45,7 @@ KSStep::KSStep() : {} KSStep::KSStep(const KSStep& aCopy) : KSComponent(aCopy), + KSTimed(aCopy), fStepId(aCopy.fStepId), fStepCount(aCopy.fStepCount), fParentTrackId(aCopy.fParentTrackId), @@ -84,6 +85,7 @@ KSStep::KSStep(const KSStep& aCopy) : {} KSStep& KSStep::operator=(const KSStep& aCopy) { + KSTimed::operator=(aCopy); fStepId = aCopy.fStepId; fStepCount = aCopy.fStepCount; fParentTrackId = aCopy.fParentTrackId; @@ -163,5 +165,6 @@ STATICINT sKSStepDict = KSDictionary::AddComponent(&KSStep::GetTrajectoryParticle, "trajectory_particle") + KSDictionary::AddComponent(&KSStep::GetInteractionParticle, "interaction_particle") + KSDictionary::AddComponent(&KSStep::GetNavigationParticle, "navigation_particle") + - KSDictionary::AddComponent(&KSStep::GetFinalParticle, "final_particle"); + KSDictionary::AddComponent(&KSStep::GetFinalParticle, "final_particle") + + KSDictionary::AddComponent(&KSStep::GetProcessingDuration, "processing_duration"); } // namespace Kassiopeia diff --git a/Kassiopeia/Simulation/Source/KSTimed.cxx b/Kassiopeia/Simulation/Source/KSTimed.cxx new file mode 100644 index 000000000..ac1e20f78 --- /dev/null +++ b/Kassiopeia/Simulation/Source/KSTimed.cxx @@ -0,0 +1,16 @@ +#include "KSTimed.h" + +namespace Kassiopeia +{ + +void KSTimed::StartTiming() { + fTimeStart = std::chrono::steady_clock::now(); + fProcessingDuration = -1; +} + +void KSTimed::EndTiming() { + std::chrono::steady_clock::time_point tTimeEnd = std::chrono::steady_clock::now(); + fProcessingDuration = std::chrono::duration_cast>(tTimeEnd - fTimeStart).count(); +} + +} diff --git a/Kassiopeia/Simulation/Source/KSTrack.cxx b/Kassiopeia/Simulation/Source/KSTrack.cxx index f1fb89447..60d957eae 100644 --- a/Kassiopeia/Simulation/Source/KSTrack.cxx +++ b/Kassiopeia/Simulation/Source/KSTrack.cxx @@ -26,6 +26,7 @@ KSTrack::KSTrack() : {} KSTrack::KSTrack(const KSTrack& aCopy) : KSComponent(aCopy), + KSTimed(aCopy), fTrackId(aCopy.fTrackId), fTrackCount(aCopy.fTrackCount), fParentEventId(aCopy.fParentEventId), @@ -46,6 +47,7 @@ KSTrack::KSTrack(const KSTrack& aCopy) : {} KSTrack& KSTrack::operator=(const KSTrack& aCopy) { + KSTimed::operator=(aCopy); fTrackId = aCopy.fTrackId; fTrackCount = aCopy.fTrackCount; fParentEventId = aCopy.fParentEventId; @@ -87,6 +89,7 @@ STATICINT sKSTrackDict = KSDictionary::AddComponent(&KSTrack::GetCreatorName, "creator_name") + KSDictionary::AddComponent(&KSTrack::GetTerminatorName, "terminator_name") + KSDictionary::AddComponent(&KSTrack::GetInitialParticle, "initial_particle") + - KSDictionary::AddComponent(&KSTrack::GetFinalParticle, "final_particle"); + KSDictionary::AddComponent(&KSTrack::GetFinalParticle, "final_particle") + + KSDictionary::AddComponent(&KSTrack::GetProcessingDuration, "processing_duration"); } // namespace Kassiopeia