Belle II Software development
FullSimTimingModule.cc
1/**************************************************************************
2 * basf2 (Belle II Analysis Software Framework) *
3 * Author: The Belle II Collaboration *
4 * *
5 * See git log for contributors and copyright holders. *
6 * This file is licensed under LGPL-3.0, see LICENSE.md. *
7 **************************************************************************/
8
9#include <simulation/modules/fullsim/FullSimTimingModule.h>
10#include <simulation/kernel/RunManager.h>
11#include <simulation/kernel/StepTiming.h>
12#include <framework/gearbox/Unit.h>
13#include <G4EventManager.hh>
14#include <G4VSteppingVerbose.hh>
15#include <G4RegionStore.hh>
16#include <framework/logging/Logger.h>
17
18#include <TProfile.h>
19#include <TFile.h>
20
21using namespace Belle2;
22
23//-----------------------------------------------------------------
24// Register the Module
25//-----------------------------------------------------------------
26REG_MODULE(FullSimTiming);
27
28//-----------------------------------------------------------------
29// Implementation
30//-----------------------------------------------------------------
31
33{
34 // Set module properties
35 setDescription("Provide more detailed timing info for FullSim module");
36
37 //So, we have to get rid of the old instance first if we want to get our
38 //timing instance in there, otherwise we get an G4Exception
39 G4VSteppingVerbose* old = G4VSteppingVerbose::GetInstance();
40 if (old) {
41 delete old;
42 G4VSteppingVerbose::SetInstance(nullptr);
43 }
44 //Now we create our timing class and set it as the class to be used. Set the callback to our processStep member
45 m_timing = new Simulation::StepTiming([&](G4Track * track, G4LogicalVolume * volume, double time) {
46 processStep(track, volume, time);
47 });
48 G4VSteppingVerbose::SetInstance(m_timing);
49
50 // Parameter definitions
51 addParam("rootFile", m_rootFileName, "Name of the output root file. If none "
52 " is given, no file will be created", std::string(""));
53}
54
55
57{
58 m_isInitialized = false;
59
60 //There are two (useful) scenarios: either this module is in front or after
61 //the FullSim module. In both cases we want it to work correctly. As the
62 //FullSim module overrides the verbosity of the SteppingManager we have to be
63 //careful when to initialize, it must be after the FullSim::initialize(). So
64 //either here if we are after the FullSim module or in the first event() call
65 //if we are before
66
68 //So, we check if the Simulation has been intialized already. If so we can
69 //initialize the StepTiming now, otherwise we do it in the first call to the
70 //event function. For this we just check if the PrimaryGeneratorAction has
71 //been set
72 if (runManager.GetUserPrimaryGeneratorAction()) {
73 //initialization is done by just calling the event function once
74 event();
75 }
76}
77
79{
80 if (!m_isInitialized) {
81 //Override verbosity of the Stepping manager to make sure that the
82 //TrackingVerbose instance is called
83 G4SteppingManager* stepping = G4EventManager::GetEventManager()->GetTrackingManager()->GetSteppingManager();
84 //Set the timing class
85 stepping->SetVerbose(m_timing);
86 //Make sure the SteppingManager is set to verbose otherwise the timing class will not be called
87 stepping->SetVerboseLevel(1);
88 //Make sure the timing class knows about the stepping manager
89 m_timing->SetManager(stepping);
90 //And set it to silent so the TrackingManager does not print the TrackBanner
91 m_timing->SetSilent(1);
92 m_timing->SetSilentStepInfo(1);
93 //Ok, we want to plot the regions in the order they were created so we need
94 //to map from region to index in the store
95 int index {0};
96 for (G4Region* region : * (G4RegionStore::GetInstance())) {
97 //We don't care about regions wihtout volumes
98 if (region->GetNumberOfRootVolumes() == 0) continue;
99 //Increase the index otherwise
100 m_regionIndices[region] = index++;
101 }
102 //create profile to store timings
103 m_timingProfile = new TProfile(
104 "SimulationTiming", "Simulation Timing;region;stepping time per event / ms",
105 index, 0, index, "s"
106 );
107 //Set counter variables
108 m_totalTime = 0;
109 m_eventCount = 0;
110 m_eventTime = 0;
111 //And we only do this once
112 m_isInitialized = true;
113 }
114 //If the eventTime is >0 we recorded at least one step, so let's update the
115 //profile and reset the counters
116 if (m_eventTime > 0) {
117 ++m_eventCount;
118 m_eventTime = 0;
119 for (auto& it : m_regionCache) {
120 int index = m_regionIndices[it.first];
121 m_timingProfile->Fill(index, it.second);
122 it.second = 0;
123 }
124 }
125}
126
127void FullSimTimingModule::processStep(G4Track*, G4LogicalVolume* volume, double time)
128{
129 const G4Region* const region = volume->GetRegion();
130 //Check if we are still in the same region to speed up the lookup
131 if (m_lastRegion == end(m_regionCache) || m_lastRegion->first != region) {
132 //Apparently not, so find or create the region in the Cache
133 m_lastRegion = m_regionCache.insert(std::make_pair(region, 0.0)).first;
134 }
135 //Record times
136 m_lastRegion->second += time;
137 m_totalTime += time;
138 m_eventTime += time;
139}
140
142{
143 //Call event one last time to get the last timing in case we were before the FullSim module
144 event();
145 //Ok, now finish the results
146 B2RESULT("FullSimTiming: Total simulation stepping time: " << (m_totalTime / Unit::s) << " s");
147 B2RESULT("FullSimTiming: Number of simulated events: " << m_eventCount);
148 //Remove stat box
149 m_timingProfile->SetStats(0);
150 //Convert to ms
151 m_timingProfile->Scale(1. / Unit::ms);
152 //Set the labels of the profile to the region names and check the maximum length
153 size_t regionWidth {6};
154 for (auto& it : m_regionIndices) {
155 m_timingProfile->GetXaxis()->SetBinLabel(it.second + 1, it.first->GetName().c_str());
156 regionWidth = std::max(regionWidth, it.first->GetName().size());
157 }
158 //Do we want a root file?
159 if (!m_rootFileName.empty()) {
160 TFile* file = new TFile(m_rootFileName.c_str(), "RECREATE");
161 file->cd();
162 m_timingProfile->Write();
163 file->Close();
164 }
165 if (m_totalTime > 0) {
166 //Now print the result as a table. But first we need the total average
167 double totalAvg {0};
168 size_t maxContentWidth {4};
169 size_t maxErrorWidth {4};
170 for (int i = 0; i < m_timingProfile->GetNbinsX(); ++i) {
171 //We want to calculate the total avg per event and the width required to
172 //show all times and their errors. So we need times and errors in ms
173 const double content = m_timingProfile->GetBinContent(i + 1);
174 const double error = m_timingProfile->GetBinError(i + 1);
175 //add up the averages.
176 totalAvg += content;
177 //and calculate the number of digits
178 const size_t contentWidth = std::floor(std::log10(content > 0 ? content : 1) + 1);
179 const size_t errorWidth = std::floor(std::log10(error > 0 ? error : 1) + 1);
180 //and get the maximum, including dot and 2 digits
181 maxContentWidth = std::max(maxContentWidth, contentWidth + 3);
182 maxErrorWidth = std::max(maxErrorWidth, errorWidth + 3);
183 }
184 //We want percentages ...
185 totalAvg /= 100;
186 //And finally we print the table
187 B2RESULT("FullSimTiming: Simulation stepping time per event and region");
188 for (int i = 0; i < m_timingProfile->GetNbinsX(); ++i) {
189 B2RESULT(" "
190 << std::setw(regionWidth + 1) << std::left << m_timingProfile->GetXaxis()->GetBinLabel(i + 1) << " "
191 << std::right << std::fixed << std::setprecision(2)
192 << std::setw(maxContentWidth) << m_timingProfile->GetBinContent(i + 1) << " ms +- "
193 << std::setw(maxErrorWidth) << m_timingProfile->GetBinError(i + 1) << " ms ("
194 << std::setw(6) << (m_timingProfile->GetBinContent(i + 1) / totalAvg) << " %)"
195 );
196 }
197 }
198}
std::string m_rootFileName
filename of the root file to store the timing profile
double m_totalTime
total time spent stepping through the simulation geometry
bool m_isInitialized
remember whether we aleady initialized everything
std::map< constG4Region *, double >::iterator m_lastRegion
iterator pointing to the region of the last step to speed up lookup
Simulation::StepTiming * m_timing
instance of the StepTiming class which records the step times in geant4
virtual void initialize() override
Setup the timing structure.
virtual void event() override
Save the simulation time for each region in a profile.
FullSimTimingModule()
Constructor: Sets the description, the properties and the parameters of the module.
virtual void terminate() override
Save the output.
double m_eventTime
stepping time of the current event
void processStep(G4Track *track, G4LogicalVolume *volume, double time)
store the time it took a Geant4 track for one step inside a volume
unsigned int m_eventCount
number of events with m_eventTime>0
std::map< const G4Region *, int > m_regionIndices
map between region and and bin indices in the TProfile
std::map< const G4Region *, double > m_regionCache
map containing the amount of time spent in each region
TProfile * m_timingProfile
profile of the time spent per event in each region
void setDescription(const std::string &description)
Sets the description of the module.
Definition Module.cc:214
Module()
Constructor.
Definition Module.cc:30
The run manager controls the flow of the Geant4 program and manages the event loop(s) within a run.
Definition RunManager.h:32
static RunManager & Instance()
Static method to get a reference to the RunManager instance.
Definition RunManager.cc:30
Class to perform more detailed timing studies of the Geant4 simulation.
Definition StepTiming.h:33
static const double ms
[millisecond]
Definition Unit.h:96
static const double s
[second]
Definition Unit.h:95
void addParam(const std::string &name, T &paramVariable, const std::string &description, const T &defaultValue)
Adds a new parameter to the module.
Definition Module.h:559
#define REG_MODULE(moduleName)
Register the given module (without 'Module' suffix) with the framework.
Definition Module.h:649
Abstract base class for different kinds of events.