ATLAS Offline Software
TestActionTimerTool.cxx
Go to the documentation of this file.
1 /*
2  Copyright (C) 2002-2021 CERN for the benefit of the ATLAS collaboration
3 */
4 
5 #include "TestActionTimerTool.h"
6 #include "GaudiKernel/ITHistSvc.h"
7 #include "TH1D.h"
8 
9 namespace G4UA
10 {
11 
13  const std::string& name,
14  const IInterface* parent)
16  m_histSvc("THistSvc", name)
17  {
18  }
19 
21  {
22  ATH_CHECK(m_histSvc.retrieve());
23  return StatusCode::SUCCESS;
24  }
25 
26  std::unique_ptr<TestActionTimer>
28  {
29  ATH_MSG_DEBUG("Constructing a TestActionTimer");
30  auto action = std::make_unique<TestActionTimer>();
31  actionList.runActions.push_back( action.get() );
32  actionList.eventActions.push_back( action.get() );
33  actionList.steppingActions.push_back( action.get() );
34  return action;
35  }
36 
38  {
39  // Accumulate results across threads
43 
44  if(!report.time.empty()){
45  G4double sumVTime = 0.;
46  G4double sumPTime = 0.;
47  for (int i(0); i <= TestActionTimer::eOther; ++i) sumVTime += report.time[i];
48  for (int i(TestActionTimer::eElec); i < TestActionTimer::eMax; ++i) sumPTime += report.time[i];
49 
50  if (report.nev>0){
51  ATH_MSG_INFO("****** TestActionTimer: Beginning timer dump ******");
52 
53  G4double DeadTime = report.runTime - sumVTime;
54  G4double OtherPart = report.runTime - DeadTime - sumPTime;
55 
56  ATH_MSG_INFO("Timer\tEvent\tFraction");
57  ATH_MSG_INFO("EvtAve\t"<<report.runTime/report.nev<<"\t100");
58 
59  for (int i(0);i <= TestActionTimer::eOther; i++) {
60  ATH_MSG_INFO(report.timeName[i] << "\t" << report.time[i]/report.nev << "\t" << report.time[i]/report.runTime);
61  }
62  ATH_MSG_INFO("Dead\t" << DeadTime/report.nev << "\t" << DeadTime/report.runTime);
64  ATH_MSG_INFO(report.timeName[i] << "\t" << report.time[i]/report.nev << "\t" << report.time[i]/report.runTime);
65  }
66  ATH_MSG_INFO("OtherPart\t" << OtherPart/report.nev << "\t" << OtherPart/report.runTime);
67 
68  ATH_MSG_INFO("****** TestActionTimer: Major Subdet Times per Event *********");
69  ATH_MSG_INFO("EMB\t" << (report.time[TestActionTimer::eEMB])/report.nev);
70  ATH_MSG_INFO("EMEC\t" << (report.time[TestActionTimer::eEMEC])/report.nev);
72  ATH_MSG_INFO("HEC\t" << (report.time[TestActionTimer::eHEC])/report.nev);
73  ATH_MSG_INFO("Tile\t" << (report.time[TestActionTimer::eHCB])/report.nev);
75  ATH_MSG_INFO("Muons\t" << (report.time[TestActionTimer::eMu])/report.nev);
76  ATH_MSG_INFO("Oth.LAr\t" << (report.time[TestActionTimer::ePre]+report.time[TestActionTimer::TestActionTimer::eCry]+report.time[TestActionTimer::eLAr])/report.nev);
77  ATH_MSG_INFO("Other\t" << (report.time[TestActionTimer::eOther])/report.nev);
78  ATH_MSG_INFO("EvtAve\t" << (report.runTime)/report.nev);
79  ATH_MSG_INFO("******* TestActionTimer: Major Subdet Frac per Event *********");
80  ATH_MSG_INFO("EMB\t" << (report.time[TestActionTimer::eEMB])/report.runTime*100.);
81  ATH_MSG_INFO("EMEC\t" << (report.time[TestActionTimer::eEMEC])/report.runTime*100.);
83  ATH_MSG_INFO("HEC\t" << (report.time[TestActionTimer::eHEC])/report.runTime*100.);
84  ATH_MSG_INFO("Tile\t" << (report.time[TestActionTimer::eHCB])/report.runTime*100.);
86  ATH_MSG_INFO("Muons\t" << (report.time[TestActionTimer::eMu])/report.runTime*100.);
88  ATH_MSG_INFO("Other\t" << (report.time[TestActionTimer::eOther])/report.runTime*100.);
89  ATH_MSG_INFO("EvtAve\t" << (report.runTime)/report.nev);
90  ATH_MSG_INFO("******* TestActionTimer: Timer Information *********");
91  ATH_MSG_INFO("NOTE: in case of MT runs, the timings for the individual threads are added, i.e. it is");
92  ATH_MSG_INFO(" equivalent to running the N threads sequentially instead of in parallel.");
93  ATH_MSG_INFO("Timers were run over " << report.nev << " events, and the averages were taken by");
94  ATH_MSG_INFO("detector portion. Detectors are determined by volume name. Pieces include:");
95  ATH_MSG_INFO("EMB, EMEC, FCAL, HEC, Tile - the sampling portions of the calorimeters.");
96  ATH_MSG_INFO("Pixel, SCT, TRT - the sensitive portions of the tracker only");
97  ATH_MSG_INFO("InDetSvc - all remaining portions of the inner detector");
98  ATH_MSG_INFO("Oth.LAr - all remaining portions of the LAr, including preshower, solenoid,");
99  ATH_MSG_INFO("\tcryostats, and services.");
100  ATH_MSG_INFO("Other - volumes not listed, including ATLAS::ATLAS and CALO::CALO");
101  ATH_MSG_INFO("");
102  ATH_MSG_INFO("Dead time includes overhead per event (file i/o, event loading, timing overhead)");
103  ATH_MSG_INFO("");
104  ATH_MSG_INFO("All times are user+system time on your processor");
105  ATH_MSG_INFO("******* TestActionTimer: End of timer dump *********");
106 
107  TH1D * r_geo = new TH1D("GeoResults","GeoResults",TestActionTimer::eOther-TestActionTimer::eEMB+1,-0.5,float(TestActionTimer::eOther-TestActionTimer::eEMB+1)-0.5);
108  TH1D * r_part = new TH1D("ParticleResults","ParticleResults",TestActionTimer::eMax-TestActionTimer::eElec+1,-0.5,float(TestActionTimer::eMax-TestActionTimer::eElec+1)-0.5);
109 
110  report.runTime -= DeadTime;
111  for (int i(0); i <= TestActionTimer::eOther; ++i){
112  r_geo->Fill( i , report.time[i] / report.runTime*100. );
113  r_geo->GetXaxis()->SetBinLabel( i+1 , report.timeName[i].c_str() );
114  }
116  r_part->Fill( i-TestActionTimer::eElec , report.time[i] / report.runTime*100. );
117  r_part->GetXaxis()->SetBinLabel( i-TestActionTimer::eElec+1 , report.timeName[i].c_str() );
118  }
119  r_part->Fill( TestActionTimer::eMax-TestActionTimer::eElec , OtherPart / report.runTime*100. ); // Other particles don't get their own timer
120  r_part->GetXaxis()->SetBinLabel( TestActionTimer::eMax-TestActionTimer::eElec+1 , "Others" );
121  r_geo->SetXTitle("Detector Region");
122  r_part->SetXTitle("Particle Type");
123  r_geo->SetYTitle("Percent of Event Time");
124  r_part->SetYTitle("Percent of Event Time");
125 
126  if (m_histSvc){
127  if ( m_histSvc->regHist("/simTime/GeoResults",r_geo).isFailure() ||
128  m_histSvc->regHist("/simTime/ParticleResults",r_part).isFailure() ){
129  ATH_MSG_ERROR("Could not register histograms!");
130  }
131  }
132 
133  } else {
134 
135  ATH_MSG_INFO("******* TestActionTimer: Nothing to report, no events timed! *********");
136  }
137  } else {ATH_MSG_INFO("******* TestActionTimer: No timing information recoreded! *********");}
138  return StatusCode::SUCCESS;
139  }
140 
141 } // namespace G4UA
G4UA::TestActionTimer::eOther
@ eOther
Definition: TestActionTimer.h:98
G4UA::G4AtlasUserActions
Struct for passing around user actions.
Definition: IUserActionTool.h:32
G4UA::TestActionTimerTool::m_histSvc
ServiceHandle< ITHistSvc > m_histSvc
HistSvc to record timing histograms.
Definition: TestActionTimerTool.h:42
G4UA::TestActionTimer
User action to measure time spent in subdetectors.
Definition: TestActionTimer.h:54
ATH_MSG_INFO
#define ATH_MSG_INFO(x)
Definition: AthMsgStreamMacros.h:31
G4UA::TestActionTimer::eHEC
@ eHEC
Definition: TestActionTimer.h:97
G4UA
for nSW
Definition: CalibrationDefaultProcessing.h:19
G4UA::TestActionTimer::Report::merge
void merge(const Report &rep)
Definition: TestActionTimer.h:70
G4UA::TestActionTimerTool::makeAndFillAction
virtual std::unique_ptr< TestActionTimer > makeAndFillAction(G4AtlasUserActions &) override final
Create action for this thread.
Definition: TestActionTimerTool.cxx:27
G4UA::TestActionTimer::eHCB
@ eHCB
Definition: TestActionTimer.h:97
TH1D
Definition: rootspy.cxx:342
G4UA::TestActionTimer::eFC1
@ eFC1
Definition: TestActionTimer.h:97
checkTP.report
report
Definition: checkTP.py:127
G4UA::TestActionTimer::eEMEC
@ eEMEC
Definition: TestActionTimer.h:97
G4UA::TestActionTimer::eElec
@ eElec
Definition: TestActionTimer.h:99
G4UA::ThreadSpecificUserAction::accumulate
void accumulate(ResultType &result, Mapper mapOp, Reducer reduceOp)
Accumulate results across user actions with specified operations.
Definition: ThreadSpecificUserAction.h:88
G4UA::TestActionTimer::ePre
@ ePre
Definition: TestActionTimer.h:98
G4UA::TestActionTimer::eSct
@ eSct
Definition: TestActionTimer.h:98
G4UA::TestActionTimerTool::initialize
virtual StatusCode initialize() override
Initialize the tool.
Definition: TestActionTimerTool.cxx:20
G4UA::TestActionTimer::eITkPix
@ eITkPix
Definition: TestActionTimer.h:98
G4UA::TestActionTimer::eLAr
@ eLAr
Definition: TestActionTimer.h:97
G4UA::TestActionTimer::eFC23
@ eFC23
Definition: TestActionTimer.h:97
ATH_MSG_ERROR
#define ATH_MSG_ERROR(x)
Definition: AthMsgStreamMacros.h:33
lumiFormat.i
int i
Definition: lumiFormat.py:92
G4UA::TestActionTimer::getReport
const Report & getReport() const
Definition: TestActionTimer.h:85
EL::StatusCode
::StatusCode StatusCode
StatusCode definition for legacy code.
Definition: PhysicsAnalysis/D3PDTools/EventLoop/EventLoop/StatusCode.h:22
ATH_MSG_DEBUG
#define ATH_MSG_DEBUG(x)
Definition: AthMsgStreamMacros.h:29
G4UA::UserActionToolBase< TestActionTimer >::m_actions
ThreadSpecificUserAction< TestActionTimer > m_actions
Thread-specific storage of the user action.
Definition: UserActionToolBase.h:63
G4UA::TestActionTimer::eMax
@ eMax
Definition: TestActionTimer.h:99
test_pyathena.parent
parent
Definition: test_pyathena.py:15
G4UA::TestActionTimer::Report
this holds all the data from individual threads that needs to be merged at EoR
Definition: TestActionTimer.h:65
ATH_CHECK
#define ATH_CHECK
Definition: AthCheckMacros.h:40
TestActionTimerTool.h
G4UA::TestActionTimer::eMu
@ eMu
Definition: TestActionTimer.h:98
G4UA::TestActionTimer::eFCO
@ eFCO
Definition: TestActionTimer.h:97
G4UA::TestActionTimer::eSev
@ eSev
Definition: TestActionTimer.h:98
name
std::string name
Definition: Control/AthContainers/Root/debug.cxx:195
G4UA::TestActionTimer::eCry
@ eCry
Definition: TestActionTimer.h:97
G4UA::TestActionTimer::eITkStrip
@ eITkStrip
Definition: TestActionTimer.h:98
G4UA::TestActionTimer::eTrt
@ eTrt
Definition: TestActionTimer.h:98
G4UA::G4AtlasUserActions::runActions
std::vector< G4UserRunAction * > runActions
Definition: IUserActionTool.h:33
G4UA::TestActionTimer::eEMB
@ eEMB
Definition: TestActionTimer.h:97
G4UA::UserActionToolBase
abstract template utility base-class for G4 user-action tools.
Definition: UserActionToolBase.h:33
G4UA::TestActionTimer::ePx
@ ePx
Definition: TestActionTimer.h:98
python.CaloScaleNoiseConfig.action
action
Definition: CaloScaleNoiseConfig.py:77
python.CaloScaleNoiseConfig.type
type
Definition: CaloScaleNoiseConfig.py:78
if
if(febId1==febId2)
Definition: LArRodBlockPhysicsV0.cxx:569
G4UA::G4AtlasUserActions::eventActions
std::vector< G4UserEventAction * > eventActions
Definition: IUserActionTool.h:34
G4UA::TestActionTimerTool::TestActionTimerTool
TestActionTimerTool(const std::string &type, const std::string &name, const IInterface *parent)
Standard constructor.
Definition: TestActionTimerTool.cxx:12
G4UA::G4AtlasUserActions::steppingActions
std::vector< G4UserSteppingAction * > steppingActions
Definition: IUserActionTool.h:36
G4UA::TestActionTimerTool::finalize
virtual StatusCode finalize() override
Finalize the tool.
Definition: TestActionTimerTool.cxx:37