CMS 3D CMS Logo
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Properties Friends Macros Pages
FastTimerService.cc
Go to the documentation of this file.
1 // FIXME
2 // we are by-passing the ME's when filling the plots, so we might need to call the ME's update() by hand
3 
4 
5 // system headers
6 #ifdef __linux
7 #include <time.h>
8 #else
9 typedef int clockid_t;
10 #define CLOCK_REALTIME 0
11 #define CLOCK_MONOTONIC 1
12 #define CLOCK_PROCESS_CPUTIME_ID 2
13 #define CLOCK_THREAD_CPUTIME_ID 3
14 #endif
15 
16 // C++ headers
17 #include <cmath>
18 #include <limits>
19 #include <iostream>
20 #include <iomanip>
21 #include <string>
22 #include <sstream>
23 #include <unordered_set>
24 #include <unordered_map>
25 
26 // boost headers
27 #include <boost/format.hpp>
28 
29 // CMSSW headers
30 #include "FWCore/ServiceRegistry/interface/ActivityRegistry.h"
31 #include "FWCore/ServiceRegistry/interface/Service.h"
32 #include "FWCore/ParameterSet/interface/ParameterSet.h"
33 #include "FWCore/ParameterSet/interface/ParameterSetDescription.h"
34 #include "FWCore/ParameterSet/interface/ConfigurationDescriptions.h"
35 #include "FWCore/Framework/interface/Event.h"
36 #include "FWCore/Framework/interface/LuminosityBlock.h"
37 #include "FWCore/Framework/interface/TriggerNamesService.h"
38 #include "FWCore/MessageLogger/interface/MessageLogger.h"
39 #include "DataFormats/Common/interface/HLTPathStatus.h"
40 #include "DataFormats/Provenance/interface/EventID.h"
41 #include "DataFormats/Provenance/interface/Timestamp.h"
42 #include "DataFormats/Provenance/interface/ModuleDescription.h"
43 #include "DataFormats/Scalers/interface/LumiScalers.h"
44 #include "DQMServices/Core/interface/DQMStore.h"
45 #include "DQMServices/Core/interface/MonitorElement.h"
46 #include "HLTrigger/Timer/interface/FastTimerService.h"
47 #include "HLTrigger/Timer/interface/CPUAffinity.h"
48 
49 
50 // file-static methods to fill a vector of strings with "(dup.) (...)" entries
51 static
52 void fill_dups(std::vector<std::string> & dups, unsigned int size) {
53  dups.reserve(size);
54  for (unsigned int i = dups.size(); i < size; ++i)
55  dups.push_back( (boost::format("(dup.) (%d)") % i).str() );
56 }
57 
58 
59 FastTimerService::FastTimerService(const edm::ParameterSet & config, edm::ActivityRegistry & registry) :
60  // configuration
61  m_timer_id( config.getUntrackedParameter<bool>( "useRealTimeClock" ) ? CLOCK_REALTIME : CLOCK_THREAD_CPUTIME_ID),
62  m_is_cpu_bound( false ),
63  m_enable_timing_paths( config.getUntrackedParameter<bool>( "enableTimingPaths" ) ),
64  m_enable_timing_modules( config.getUntrackedParameter<bool>( "enableTimingModules" ) ),
65  m_enable_timing_exclusive( config.getUntrackedParameter<bool>( "enableTimingExclusive" ) ),
66  m_enable_timing_summary( config.getUntrackedParameter<bool>( "enableTimingSummary" ) ),
67  m_skip_first_path( config.getUntrackedParameter<bool>( "skipFirstPath" ) ),
68  // dqm configuration
69  m_enable_dqm( config.getUntrackedParameter<bool>( "enableDQM" ) ),
70  m_enable_dqm_bypath_active( config.getUntrackedParameter<bool>( "enableDQMbyPathActive" ) ),
71  m_enable_dqm_bypath_total( config.getUntrackedParameter<bool>( "enableDQMbyPathTotal" ) ),
72  m_enable_dqm_bypath_overhead( config.getUntrackedParameter<bool>( "enableDQMbyPathOverhead" ) ),
73  m_enable_dqm_bypath_details( config.getUntrackedParameter<bool>( "enableDQMbyPathDetails" ) ),
74  m_enable_dqm_bypath_counters( config.getUntrackedParameter<bool>( "enableDQMbyPathCounters" ) ),
75  m_enable_dqm_bypath_exclusive( config.getUntrackedParameter<bool>( "enableDQMbyPathExclusive" ) ),
76  m_enable_dqm_bymodule( config.getUntrackedParameter<bool>( "enableDQMbyModule" ) ),
77  m_enable_dqm_bymoduletype( config.getUntrackedParameter<bool>( "enableDQMbyModuleType" ) ),
78  m_enable_dqm_summary( config.getUntrackedParameter<bool>( "enableDQMSummary" ) ),
79  m_enable_dqm_byluminosity( config.getUntrackedParameter<bool>( "enableDQMbyLuminosity" ) ),
80  m_enable_dqm_byls( config.existsAs<bool>("enableDQMbyLumiSection", false) ?
81  config.getUntrackedParameter<bool>("enableDQMbyLumiSection") :
82  ( edm::LogWarning("Configuration") << "enableDQMbyLumi is deprecated, please use enableDQMbyLumiSection instead", config.getUntrackedParameter<bool>("enableDQMbyLumi") )
83  ),
84  m_enable_dqm_bynproc( config.getUntrackedParameter<bool>( "enableDQMbyProcesses" ) ),
85  m_nproc_enabled( false ),
86  m_dqm_eventtime_range( config.getUntrackedParameter<double>( "dqmTimeRange" ) ), // ms
87  m_dqm_eventtime_resolution( config.getUntrackedParameter<double>( "dqmTimeResolution" ) ), // ms
88  m_dqm_pathtime_range( config.getUntrackedParameter<double>( "dqmPathTimeRange" ) ), // ms
89  m_dqm_pathtime_resolution( config.getUntrackedParameter<double>( "dqmPathTimeResolution" ) ), // ms
90  m_dqm_moduletime_range( config.getUntrackedParameter<double>( "dqmModuleTimeRange" ) ), // ms
91  m_dqm_moduletime_resolution( config.getUntrackedParameter<double>( "dqmModuleTimeResolution" ) ), // ms
92  m_dqm_luminosity_range( config.getUntrackedParameter<double>( "dqmLuminosityRange" ) / 1.e30), // cm-2 s-1
93  m_dqm_luminosity_resolution( config.getUntrackedParameter<double>( "dqmLuminosityResolution" ) / 1.e30), // cm-2 s-1
94  m_dqm_ls_range( config.getUntrackedParameter<uint32_t>( "dqmLumiSectionsRange" ) ), // lumisections
95  m_dqm_path( config.getUntrackedParameter<std::string>("dqmPath" ) ),
96  m_luminosity_label( config.getUntrackedParameter<edm::InputTag>("luminosityProduct") ), // SCAL unpacker
97  m_supported_processes( config.getUntrackedParameter<std::vector<unsigned int> >("supportedProcesses") ), // 8, 24, 32
98  // caching
99  m_first_path(0), // these are initialized at prePathBeginRun(),
100  m_last_path(0), // to make sure we cache the correct pointers
101  m_first_endpath(0),
102  m_last_endpath(0),
103  m_is_first_module(false),
104  m_is_first_event(true),
105  // per-event accounting
106  m_event(0.),
107  m_presource(0.),
108  m_source(0.),
109  m_postsource(0.),
110  m_all_paths(0.),
111  m_all_endpaths(0.),
112  m_interpaths(0.),
113  // per-job summary
114  m_summary_events(0),
115  m_summary_event(0.),
116  m_summary_presource(0.),
117  m_summary_source(0.),
118  m_summary_postsource(0.),
119  m_summary_all_paths(0.),
120  m_summary_all_endpaths(0.),
121  m_summary_interpaths(0.),
122  // DQM - these are initialized at preBeginRun(), to make sure the DQM service has been loaded
123  m_dqms(0),
124  // event summary plots
125  m_dqm_event(0),
126  m_dqm_presource (0),
127  m_dqm_source(0),
128  m_dqm_postsource (0),
129  m_dqm_all_paths(0),
130  m_dqm_all_endpaths(0),
131  m_dqm_interpaths(0),
132  // event summary plots - summed over nodes with the same number of processes
133  m_dqm_nproc_event(0),
134  m_dqm_nproc_source(0),
135  m_dqm_nproc_all_paths(0),
136  m_dqm_nproc_all_endpaths(0),
137  m_dqm_nproc_interpaths(0),
138  // plots by path
139  m_dqm_paths_active_time(0),
140  m_dqm_paths_total_time(0),
141  m_dqm_paths_exclusive_time(0),
142  m_dqm_paths_interpaths(0),
143  // plots per lumisection
144  m_dqm_byls_event(0),
145  m_dqm_byls_presource(0),
146  m_dqm_byls_source(0),
147  m_dqm_byls_postsource(0),
148  m_dqm_byls_all_paths(0),
149  m_dqm_byls_all_endpaths(0),
150  m_dqm_byls_interpaths(0),
151  // plots per lumisection - summed over nodes with the same number of processes
152  m_dqm_nproc_byls_event(0),
153  m_dqm_nproc_byls_presource(0),
154  m_dqm_nproc_byls_source(0),
155  m_dqm_nproc_byls_postsource(0),
156  m_dqm_nproc_byls_all_paths(0),
157  m_dqm_nproc_byls_all_endpaths(0),
158  m_dqm_nproc_byls_interpaths(0),
159  // plots vs. instantaneous luminosity
160  m_dqm_byluminosity_event(0),
161  m_dqm_byluminosity_presource(0),
162  m_dqm_byluminosity_source(0),
163  m_dqm_byluminosity_postsource(0),
164  m_dqm_byluminosity_all_paths(0),
165  m_dqm_byluminosity_all_endpaths(0),
166  m_dqm_byluminosity_interpaths(0),
167  // plots vs. instantaneous luminosity - summed over nodes with the same number of processes
168  m_dqm_nproc_byluminosity_event(0),
169  m_dqm_nproc_byluminosity_presource(0),
170  m_dqm_nproc_byluminosity_source(0),
171  m_dqm_nproc_byluminosity_postsource(0),
172  m_dqm_nproc_byluminosity_all_paths(0),
173  m_dqm_nproc_byluminosity_all_endpaths(0),
174  m_dqm_nproc_byluminosity_interpaths(0),
175  // per-path and per-module accounting
176  m_current_path(0),
177  m_paths(),
178  m_modules(),
179  m_moduletypes(),
180  m_fast_modules(),
181  m_fast_moduletypes()
182 {
183  // enable timers if required by DQM plots
184  m_enable_timing_paths = m_enable_timing_paths or
185  m_enable_dqm_bypath_active or
186  m_enable_dqm_bypath_total or
187  m_enable_dqm_bypath_overhead or
188  m_enable_dqm_bypath_details or
189  m_enable_dqm_bypath_counters or
190  m_enable_dqm_bypath_exclusive;
191 
192  m_enable_timing_modules = m_enable_timing_modules or
193  m_enable_dqm_bymodule or
194  m_enable_dqm_bymoduletype or
195  m_enable_dqm_bypath_total or
196  m_enable_dqm_bypath_overhead or
197  m_enable_dqm_bypath_details or
198  m_enable_dqm_bypath_counters or
199  m_enable_dqm_bypath_exclusive;
200 
201  m_enable_timing_exclusive = m_enable_timing_exclusive or
202  m_enable_dqm_bypath_exclusive;
203 
204  registry.watchPreModuleBeginJob( this, & FastTimerService::preModuleBeginJob );
205  registry.watchPreBeginRun( this, & FastTimerService::preBeginRun );
206  registry.watchPostEndJob( this, & FastTimerService::postEndJob );
207  registry.watchPrePathBeginRun( this, & FastTimerService::prePathBeginRun) ;
208  registry.watchPreProcessEvent( this, & FastTimerService::preProcessEvent );
209  registry.watchPostProcessEvent( this, & FastTimerService::postProcessEvent );
210  registry.watchPreSource( this, & FastTimerService::preSource );
211  registry.watchPostSource( this, & FastTimerService::postSource );
212  // watch per-path events
213  registry.watchPreProcessPath( this, & FastTimerService::preProcessPath );
214  registry.watchPostProcessPath( this, & FastTimerService::postProcessPath );
215  // watch per-module events if enabled
216  if (m_enable_timing_modules) {
217  registry.watchPreModule( this, & FastTimerService::preModule );
218  registry.watchPostModule( this, & FastTimerService::postModule );
219  }
220 
221 #if defined(__APPLE__) || defined (__MACH__)
222  host_get_clock_service(mach_host_self(), CALENDAR_CLOCK, &m_clock_port);
223 #endif // defined(__APPLE__) || defined(__MACH__)
224 }
225 
226 FastTimerService::~FastTimerService()
227 {
228 #if defined(__APPLE__) || defined (__MACH__)
229  mach_port_deallocate(mach_task_self(), m_clock_port);
230 #endif // defined(__APPLE__) || defined(__MACH__)
231 }
232 
233 void FastTimerService::preBeginRun( edm::RunID const &, edm::Timestamp const & )
234 {
235  //edm::LogImportant("FastTimerService") << __func__ << "()";
236 
237  // check if the process is bound to a single CPU.
238  // otherwise, the results of the CLOCK_THREAD_CPUTIME_ID timer might be inaccurate
239 #ifdef __linux
240  // cpu affinity is currently only supported on LINUX
241  m_is_cpu_bound = CPUAffinity::isCpuBound();
242  if ((m_timer_id != CLOCK_REALTIME) and not m_is_cpu_bound) {
243  clockid_t clock;
244  if (clock_getcpuclockid(0, & clock) == ENOENT)
245  // the process is NOT bound to a single CPU, and the system does not support a consistent time source across multiple CPUs
246  edm::LogError("FastTimerService") << "this process is NOT bound to a single CPU, the results of the FastTimerService may be undefined";
247  }
248 #endif
249 
250  edm::service::TriggerNamesService & tns = * edm::Service<edm::service::TriggerNamesService>();
251  uint32_t size_p = tns.getTrigPaths().size();
252  uint32_t size_e = tns.getEndPaths().size();
253  uint32_t size = size_p + size_e;
254  for (uint32_t i = 0; i < size_p; ++i) {
255  std::string const & label = tns.getTrigPath(i);
256  m_paths[label].index = i;
257  }
258  for (uint32_t i = 0; i < size_e; ++i) {
259  std::string const & label = tns.getEndPath(i);
260  m_paths[label].index = size_p + i;
261  }
262 
263  // associate to each path all the modules it contains
264  for (uint32_t i = 0; i < tns.getTrigPaths().size(); ++i)
265  fillPathMap( tns.getTrigPath(i), tns.getTrigPathModules(i) );
266  for (uint32_t i = 0; i < tns.getEndPaths().size(); ++i)
267  fillPathMap( tns.getEndPath(i), tns.getEndPathModules(i) );
268 
269  if (m_enable_dqm)
270  // load the DQM store
271  m_dqms = edm::Service<DQMStore>().operator->();
272 
273  if (m_dqms) {
274  // book MonitorElement's
275  int eventbins = (int) std::ceil(m_dqm_eventtime_range / m_dqm_eventtime_resolution);
276  int pathbins = (int) std::ceil(m_dqm_pathtime_range / m_dqm_pathtime_resolution);
277  int modulebins = (int) std::ceil(m_dqm_moduletime_range / m_dqm_moduletime_resolution);
278  int lumibins = (int) std::ceil(m_dqm_luminosity_range / m_dqm_luminosity_resolution);
279 
280  // event summary plots
281  if (m_enable_dqm_summary) {
282  m_dqms->setCurrentFolder(m_dqm_path);
283  m_dqm_event = m_dqms->book1D("event", "Event processing time", eventbins, 0., m_dqm_eventtime_range)->getTH1F();
284  m_dqm_event ->StatOverflows(true);
285  m_dqm_event ->SetXTitle("processing time [ms]");
286  m_dqm_presource = m_dqms->book1D("presource", "Pre-Source processing time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
287  m_dqm_presource ->StatOverflows(true);
288  m_dqm_presource ->SetXTitle("processing time [ms]");
289  m_dqm_source = m_dqms->book1D("source", "Source processing time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
290  m_dqm_source ->StatOverflows(true);
291  m_dqm_source ->SetXTitle("processing time [ms]");
292  m_dqm_postsource = m_dqms->book1D("postsource", "Post-Source processing time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
293  m_dqm_postsource ->StatOverflows(true);
294  m_dqm_postsource ->SetXTitle("processing time [ms]");
295  m_dqm_all_paths = m_dqms->book1D("all_paths", "Paths processing time", eventbins, 0., m_dqm_eventtime_range)->getTH1F();
296  m_dqm_all_paths ->StatOverflows(true);
297  m_dqm_all_paths ->SetXTitle("processing time [ms]");
298  m_dqm_all_endpaths = m_dqms->book1D("all_endpaths", "EndPaths processing time", pathbins, 0., m_dqm_pathtime_range)->getTH1F();
299  m_dqm_all_endpaths ->StatOverflows(true);
300  m_dqm_all_endpaths ->SetXTitle("processing time [ms]");
301  m_dqm_interpaths = m_dqms->book1D("interpaths", "Time spent between paths", pathbins, 0., m_dqm_eventtime_range)->getTH1F();
302  m_dqm_interpaths ->StatOverflows(true);
303  m_dqm_interpaths ->SetXTitle("processing time [ms]");
304  }
305 
306  // event summary plots - summed over nodes with the same number of processes
307  if (m_enable_dqm_summary and m_enable_dqm_bynproc) {
308  TH1F * plot;
309  for (int n : m_supported_processes) {
310  m_dqms->setCurrentFolder( (boost::format("%s/Running %d processes") % m_dqm_path % n).str() );
311  plot = m_dqms->book1D("event", "Event processing time", eventbins, 0., m_dqm_eventtime_range)->getTH1F();
312  plot->StatOverflows(true);
313  plot->SetXTitle("processing time [ms]");
314  plot = m_dqms->book1D("presource", "Pre-Source processing time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
315  plot->StatOverflows(true);
316  plot->SetXTitle("processing time [ms]");
317  plot = m_dqms->book1D("source", "Source processing time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
318  plot->StatOverflows(true);
319  plot->SetXTitle("processing time [ms]");
320  plot = m_dqms->book1D("postsource", "Post-Source processing time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
321  plot->StatOverflows(true);
322  plot->SetXTitle("processing time [ms]");
323  plot = m_dqms->book1D("all_paths", "Paths processing time", eventbins, 0., m_dqm_eventtime_range)->getTH1F();
324  plot->StatOverflows(true);
325  plot->SetXTitle("processing time [ms]");
326  plot = m_dqms->book1D("all_endpaths", "EndPaths processing time", pathbins, 0., m_dqm_pathtime_range)->getTH1F();
327  plot->StatOverflows(true);
328  plot->SetXTitle("processing time [ms]");
329  plot = m_dqms->book1D("interpaths", "Time spent between paths", pathbins, 0., m_dqm_eventtime_range)->getTH1F();
330  plot->StatOverflows(true);
331  plot->SetXTitle("processing time [ms]");
332  }
333  }
334 
335  // plots by path
336  m_dqms->setCurrentFolder(m_dqm_path);
337  m_dqm_paths_active_time = m_dqms->bookProfile("paths_active_time", "Additional time spent in each path", size, -0.5, size-0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
338  m_dqm_paths_active_time ->StatOverflows(true);
339  m_dqm_paths_active_time ->SetYTitle("processing time [ms]");
340  m_dqm_paths_total_time = m_dqms->bookProfile("paths_total_time", "Total time spent in each path", size, -0.5, size-0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
341  m_dqm_paths_total_time ->StatOverflows(true);
342  m_dqm_paths_total_time ->SetYTitle("processing time [ms]");
343  m_dqm_paths_exclusive_time = m_dqms->bookProfile("paths_exclusive_time", "Exclusive time spent in each path", size, -0.5, size-0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
344  m_dqm_paths_exclusive_time ->StatOverflows(true);
345  m_dqm_paths_exclusive_time ->SetYTitle("processing time [ms]");
346  m_dqm_paths_interpaths = m_dqms->bookProfile("paths_interpaths", "Time spent between each path", size, -0.5, size-0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
347  m_dqm_paths_interpaths ->StatOverflows(true);
348  m_dqm_paths_interpaths ->SetYTitle("processing time [ms]");
349 
350  for (uint32_t i = 0; i < size_p; ++i) {
351  std::string const & label = tns.getTrigPath(i);
352  m_dqm_paths_active_time ->GetXaxis()->SetBinLabel(i + 1, label.c_str());
353  m_dqm_paths_total_time ->GetXaxis()->SetBinLabel(i + 1, label.c_str());
354  m_dqm_paths_exclusive_time ->GetXaxis()->SetBinLabel(i + 1, label.c_str());
355  m_dqm_paths_interpaths ->GetXaxis()->SetBinLabel(i + 1, label.c_str());
356  }
357  for (uint32_t i = 0; i < size_e; ++i) {
358  std::string const & label = tns.getEndPath(i);
359  m_dqm_paths_active_time ->GetXaxis()->SetBinLabel(i + size_p + 1, label.c_str());
360  m_dqm_paths_total_time ->GetXaxis()->SetBinLabel(i + size_p + 1, label.c_str());
361  m_dqm_paths_exclusive_time ->GetXaxis()->SetBinLabel(i + size_p + 1, label.c_str());
362  m_dqm_paths_interpaths ->GetXaxis()->SetBinLabel(i + size_p + 1, label.c_str());
363  }
364 
365  // per-lumisection plots
366  if (m_enable_dqm_byls) {
367  m_dqms->setCurrentFolder(m_dqm_path);
368  m_dqm_byls_event = m_dqms->bookProfile("event_byls", "Event processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
369  m_dqm_byls_event ->StatOverflows(true);
370  m_dqm_byls_event ->SetXTitle("lumisection");
371  m_dqm_byls_event ->SetYTitle("processing time [ms]");
372  m_dqm_byls_presource = m_dqms->bookProfile("presource_byls", "Pre-Source processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
373  m_dqm_byls_presource ->StatOverflows(true);
374  m_dqm_byls_presource ->SetXTitle("lumisection");
375  m_dqm_byls_presource ->SetYTitle("processing time [ms]");
376  m_dqm_byls_source = m_dqms->bookProfile("source_byls", "Source processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
377  m_dqm_byls_source ->StatOverflows(true);
378  m_dqm_byls_source ->SetXTitle("lumisection");
379  m_dqm_byls_source ->SetYTitle("processing time [ms]");
380  m_dqm_byls_postsource = m_dqms->bookProfile("postsource_byls", "Post-Source processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
381  m_dqm_byls_postsource ->StatOverflows(true);
382  m_dqm_byls_postsource ->SetXTitle("lumisection");
383  m_dqm_byls_postsource ->SetYTitle("processing time [ms]");
384  m_dqm_byls_all_paths = m_dqms->bookProfile("all_paths_byls", "Paths processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
385  m_dqm_byls_all_paths ->StatOverflows(true);
386  m_dqm_byls_all_paths ->SetXTitle("lumisection");
387  m_dqm_byls_all_paths ->SetYTitle("processing time [ms]");
388  m_dqm_byls_all_endpaths = m_dqms->bookProfile("all_endpaths_byls", "EndPaths processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
389  m_dqm_byls_all_endpaths ->StatOverflows(true);
390  m_dqm_byls_all_endpaths ->SetXTitle("lumisection");
391  m_dqm_byls_all_endpaths ->SetYTitle("processing time [ms]");
392  m_dqm_byls_interpaths = m_dqms->bookProfile("interpaths_byls", "Time spent between paths, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
393  m_dqm_byls_interpaths ->StatOverflows(true);
394  m_dqm_byls_interpaths ->SetXTitle("lumisection");
395  m_dqm_byls_interpaths ->SetYTitle("processing time [ms]");
396  }
397 
398  // per-lumisection plots
399  if (m_enable_dqm_byls and m_enable_dqm_bynproc) {
400  TProfile * plot;
401  for (int n : m_supported_processes) {
402  m_dqms->setCurrentFolder( (boost::format("%s/Running %d processes") % m_dqm_path % n).str() );
403  plot = m_dqms->bookProfile("event_byls", "Event processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
404  plot->StatOverflows(true);
405  plot->SetXTitle("lumisection");
406  plot->SetYTitle("processing time [ms]");
407  plot = m_dqms->bookProfile("presource_byls", "Pre-Source processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
408  plot->StatOverflows(true);
409  plot->SetXTitle("lumisection");
410  plot->SetYTitle("processing time [ms]");
411  plot = m_dqms->bookProfile("source_byls", "Source processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
412  plot->StatOverflows(true);
413  plot->SetXTitle("lumisection");
414  plot->SetYTitle("processing time [ms]");
415  plot = m_dqms->bookProfile("postsource_byls", "Post-Source processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
416  plot->StatOverflows(true);
417  plot->SetXTitle("lumisection");
418  plot->SetYTitle("processing time [ms]");
419  plot = m_dqms->bookProfile("all_paths_byls", "Paths processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
420  plot->StatOverflows(true);
421  plot->SetXTitle("lumisection");
422  plot->SetYTitle("processing time [ms]");
423  plot = m_dqms->bookProfile("all_endpaths_byls", "EndPaths processing time, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
424  plot->StatOverflows(true);
425  plot->SetXTitle("lumisection");
426  plot->SetYTitle("processing time [ms]");
427  plot = m_dqms->bookProfile("interpaths_byls", "Time spent between paths, by LumiSection", m_dqm_ls_range, 0.5, m_dqm_ls_range+0.5, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
428  plot->StatOverflows(true);
429  plot->SetXTitle("lumisection");
430  plot->SetYTitle("processing time [ms]");
431  }
432  }
433 
434  // plots vs. instantaneous luminosity
435  if (m_enable_dqm_byluminosity) {
436  m_dqms->setCurrentFolder(m_dqm_path);
437  m_dqm_byluminosity_event = m_dqms->bookProfile("event_byluminosity", "Event processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
438  m_dqm_byluminosity_event ->StatOverflows(true);
439  m_dqm_byluminosity_event ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
440  m_dqm_byluminosity_event ->SetYTitle("processing time [ms]");
441  m_dqm_byluminosity_presource = m_dqms->bookProfile("presource_byluminosity", "Pre-Source processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
442  m_dqm_byluminosity_presource ->StatOverflows(true);
443  m_dqm_byluminosity_presource ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
444  m_dqm_byluminosity_presource ->SetYTitle("processing time [ms]");
445  m_dqm_byluminosity_source = m_dqms->bookProfile("source_byluminosity", "Source processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
446  m_dqm_byluminosity_source ->StatOverflows(true);
447  m_dqm_byluminosity_source ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
448  m_dqm_byluminosity_source ->SetYTitle("processing time [ms]");
449  m_dqm_byluminosity_postsource = m_dqms->bookProfile("postsource_byluminosity", "Post-Source processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
450  m_dqm_byluminosity_postsource ->StatOverflows(true);
451  m_dqm_byluminosity_postsource ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
452  m_dqm_byluminosity_postsource ->SetYTitle("processing time [ms]");
453  m_dqm_byluminosity_all_paths = m_dqms->bookProfile("all_paths_byluminosity", "Paths processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
454  m_dqm_byluminosity_all_paths ->StatOverflows(true);
455  m_dqm_byluminosity_all_paths ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
456  m_dqm_byluminosity_all_paths ->SetYTitle("processing time [ms]");
457  m_dqm_byluminosity_all_endpaths = m_dqms->bookProfile("all_endpaths_byluminosity", "EndPaths processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
458  m_dqm_byluminosity_all_endpaths ->StatOverflows(true);
459  m_dqm_byluminosity_all_endpaths ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
460  m_dqm_byluminosity_all_endpaths ->SetYTitle("processing time [ms]");
461  m_dqm_byluminosity_interpaths = m_dqms->bookProfile("interpaths_byluminosity", "Time spent between paths vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
462  m_dqm_byluminosity_interpaths ->StatOverflows(true);
463  m_dqm_byluminosity_interpaths ->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
464  m_dqm_byluminosity_interpaths ->SetYTitle("processing time [ms]");
465  }
466 
467  // plots vs. instantaneous luminosity
468  if (m_enable_dqm_byluminosity and m_enable_dqm_bynproc) {
469  TProfile * plot;
470  for (int n : m_supported_processes) {
471  m_dqms->setCurrentFolder( (boost::format("%s/Running %d processes") % m_dqm_path % n).str() );
472  plot = m_dqms->bookProfile("event_byluminosity", "Event processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
473  plot->StatOverflows(true);
474  plot->SetYTitle("processing time [ms]");
475  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
476  plot = m_dqms->bookProfile("presource_byluminosity", "Pre-Source processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
477  plot->StatOverflows(true);
478  plot->SetYTitle("processing time [ms]");
479  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
480  plot = m_dqms->bookProfile("source_byluminosity", "Source processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
481  plot->StatOverflows(true);
482  plot->SetYTitle("processing time [ms]");
483  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
484  plot = m_dqms->bookProfile("postsource_byluminosity", "Post-Source processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
485  plot->StatOverflows(true);
486  plot->SetYTitle("processing time [ms]");
487  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
488  plot = m_dqms->bookProfile("all_paths_byluminosity", "Paths processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, eventbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
489  plot->StatOverflows(true);
490  plot->SetYTitle("processing time [ms]");
491  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
492  plot = m_dqms->bookProfile("all_endpaths_byluminosity", "EndPaths processing time vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
493  plot->StatOverflows(true);
494  plot->SetYTitle("processing time [ms]");
495  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
496  plot = m_dqms->bookProfile("interpaths_byluminosity", "Time spent between paths vs. instantaneous luminosity", lumibins, 0., m_dqm_luminosity_range, pathbins, 0., std::numeric_limits<double>::infinity(), " ")->getTProfile();
497  plot->StatOverflows(true);
498  plot->SetYTitle("processing time [ms]");
499  plot->SetXTitle("instantaneous luminosity [10^{30} cm^{-2}s^{-1}]");
500  }
501  }
502 
503  // per-path and per-module accounting
504  if (m_enable_timing_paths) {
505  m_dqms->setCurrentFolder((m_dqm_path + "/Paths"));
506  for (auto & keyval: m_paths) {
507  std::string const & pathname = keyval.first;
508  PathInfo & pathinfo = keyval.second;
509 
510  if (m_enable_dqm_bypath_active) {
511  pathinfo.dqm_active = m_dqms->book1D(pathname + "_active", pathname + " active time", pathbins, 0., m_dqm_pathtime_range)->getTH1F();
512  pathinfo.dqm_active ->StatOverflows(true);
513  pathinfo.dqm_active ->SetXTitle("processing time [ms]");
514  }
515 
516  if (m_enable_dqm_bypath_total) {
517  pathinfo.dqm_total = m_dqms->book1D(pathname + "_total", pathname + " total time", pathbins, 0., m_dqm_pathtime_range)->getTH1F();
518  pathinfo.dqm_total ->StatOverflows(true);
519  pathinfo.dqm_total ->SetXTitle("processing time [ms]");
520  }
521 
522  if (m_enable_dqm_bypath_overhead) {
523  pathinfo.dqm_premodules = m_dqms->book1D(pathname + "_premodules", pathname + " pre-modules overhead", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
524  pathinfo.dqm_premodules ->StatOverflows(true);
525  pathinfo.dqm_premodules ->SetXTitle("processing time [ms]");
526  pathinfo.dqm_intermodules = m_dqms->book1D(pathname + "_intermodules", pathname + " inter-modules overhead", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
527  pathinfo.dqm_intermodules ->StatOverflows(true);
528  pathinfo.dqm_intermodules ->SetXTitle("processing time [ms]");
529  pathinfo.dqm_postmodules = m_dqms->book1D(pathname + "_postmodules", pathname + " post-modules overhead", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
530  pathinfo.dqm_postmodules ->StatOverflows(true);
531  pathinfo.dqm_postmodules ->SetXTitle("processing time [ms]");
532  pathinfo.dqm_overhead = m_dqms->book1D(pathname + "_overhead", pathname + " overhead time", modulebins, 0., m_dqm_moduletime_range)->getTH1F();
533  pathinfo.dqm_overhead ->StatOverflows(true);
534  pathinfo.dqm_overhead ->SetXTitle("processing time [ms]");
535  }
536 
537  if (m_enable_dqm_bypath_details or m_enable_dqm_bypath_counters) {
538  // book histograms for modules-in-paths statistics
539 
540  // find histograms X-axis labels
541  uint32_t id;
542  std::vector<std::string> const & modules = ((id = tns.findTrigPath(pathname)) != tns.getTrigPaths().size()) ? tns.getTrigPathModules(id) :
543  ((id = tns.findEndPath(pathname)) != tns.getEndPaths().size()) ? tns.getEndPathModules(id) :
544  std::vector<std::string>();
545 
546  static std::vector<std::string> dup;
547  if (modules.size() > dup.size())
548  fill_dups(dup, modules.size());
549 
550  std::vector<const char *> labels(modules.size(), nullptr);
551  for (uint32_t i = 0; i < modules.size(); ++i)
552  labels[i] = (pathinfo.modules[i]) ? modules[i].c_str() : dup[i].c_str();
553 
554  // book counter histograms
555  if (m_enable_dqm_bypath_counters) {
556  pathinfo.dqm_module_counter = m_dqms->book1D(pathname + "_module_counter", pathname + " module counter", modules.size(), -0.5, modules.size() - 0.5)->getTH1F();
557  // find module labels
558  for (uint32_t i = 0; i < modules.size(); ++i) {
559  pathinfo.dqm_module_counter->GetXaxis()->SetBinLabel( i+1, labels[i] );
560  }
561  }
562  // book detailed timing histograms
563  if (m_enable_dqm_bypath_details) {
564  pathinfo.dqm_module_active = m_dqms->book1D(pathname + "_module_active", pathname + " module active", modules.size(), -0.5, modules.size() - 0.5)->getTH1F();
565  pathinfo.dqm_module_active ->SetYTitle("cumulative processing time [ms]");
566  pathinfo.dqm_module_total = m_dqms->book1D(pathname + "_module_total", pathname + " module total", modules.size(), -0.5, modules.size() - 0.5)->getTH1F();
567  pathinfo.dqm_module_total ->SetYTitle("cumulative processing time [ms]");
568  // find module labels
569  for (uint32_t i = 0; i < modules.size(); ++i) {
570  pathinfo.dqm_module_active ->GetXaxis()->SetBinLabel( i+1, labels[i] );
571  pathinfo.dqm_module_total ->GetXaxis()->SetBinLabel( i+1, labels[i] );
572  }
573  }
574  }
575 
576  // book exclusive path time histograms
577  if (m_enable_dqm_bypath_exclusive) {
578  pathinfo.dqm_exclusive = m_dqms->book1D(pathname + "_exclusive", pathname + " exclusive time", pathbins, 0., m_dqm_pathtime_range)->getTH1F();
579  pathinfo.dqm_exclusive ->StatOverflows(true);
580  pathinfo.dqm_exclusive ->SetXTitle("processing time [ms]");
581  }
582 
583  }
584  }
585 
586  if (m_enable_dqm_bymodule) {
587  m_dqms->setCurrentFolder((m_dqm_path + "/Modules"));
588  for (auto & keyval: m_modules) {
589  std::string const & label = keyval.first;
590  ModuleInfo & module = keyval.second;
591  module.dqm_active = m_dqms->book1D(label, label, modulebins, 0., m_dqm_moduletime_range)->getTH1F();
592  module.dqm_active->StatOverflows(true);
593  module.dqm_active->SetXTitle("processing time [ms]");
594  }
595  }
596 
597  if (m_enable_dqm_bymoduletype) {
598  m_dqms->setCurrentFolder((m_dqm_path + "/ModuleTypes"));
599  for (auto & keyval: m_moduletypes) {
600  std::string const & label = keyval.first;
601  ModuleInfo & module = keyval.second;
602  module.dqm_active = m_dqms->book1D(label, label, modulebins, 0., m_dqm_moduletime_range)->getTH1F();
603  module.dqm_active->StatOverflows(true);
604  module.dqm_active->SetXTitle("processing time [ms]");
605  }
606  }
607 
608  }
609 }
610 
611 void FastTimerService::setNumberOfProcesses(unsigned int procs) {
612  // the service is not configured to support plots by number of processes
613  if (not m_enable_dqm or not m_enable_dqm_bynproc)
614  return;
615 
616  // the DQM store has not been configured yet
617  if (not m_dqms)
618  return;
619 
620  // check if the service is configured to support this number of processes
621  if (std::find(m_supported_processes.begin(), m_supported_processes.end(), procs) == m_supported_processes.end()) {
622  m_nproc_enabled = false;
623  // event summary plots - summed over nodes with the same number of processes
624  m_dqm_nproc_event = 0;
625  m_dqm_nproc_presource = 0;
626  m_dqm_nproc_source = 0;
627  m_dqm_nproc_postsource = 0;
628  m_dqm_nproc_all_paths = 0;
629  m_dqm_nproc_all_endpaths = 0;
630  m_dqm_nproc_interpaths = 0;
631  // plots per lumisection - summed over nodes with the same number of processes
632  m_dqm_nproc_byls_event = 0;
633  m_dqm_nproc_byls_presource = 0;
634  m_dqm_nproc_byls_source = 0;
635  m_dqm_nproc_byls_postsource = 0;
636  m_dqm_nproc_byls_all_paths = 0;
637  m_dqm_nproc_byls_all_endpaths = 0;
638  m_dqm_nproc_byls_interpaths = 0;
639  // plots vs. instantaneous luminosity - summed over nodes with the same number of processes
640  m_dqm_nproc_byluminosity_event = 0;
641  m_dqm_nproc_byluminosity_presource = 0;
642  m_dqm_nproc_byluminosity_source = 0;
643  m_dqm_nproc_byluminosity_postsource = 0;
644  m_dqm_nproc_byluminosity_all_paths = 0;
645  m_dqm_nproc_byluminosity_all_endpaths = 0;
646  m_dqm_nproc_byluminosity_interpaths = 0;
647  } else {
648  m_nproc_enabled = true;
649  // event summary plots - summed over nodes with the same number of processes
650  m_dqm_nproc_event = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "event" ).str() )->getTH1F();
651  m_dqm_nproc_presource = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "presource" ).str() )->getTH1F();
652  m_dqm_nproc_source = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "source" ).str() )->getTH1F();
653  m_dqm_nproc_postsource = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "postsource" ).str() )->getTH1F();
654  m_dqm_nproc_all_paths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "all_paths" ).str() )->getTH1F();
655  m_dqm_nproc_all_endpaths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "all_endpaths" ).str() )->getTH1F();
656  m_dqm_nproc_interpaths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "interpaths" ).str() )->getTH1F();
657  // plots per lumisection - summed over nodes with the same number of processes
658  m_dqm_nproc_byls_event = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "event_byls" ).str() )->getTProfile();
659  m_dqm_nproc_byls_presource = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "presource_byls" ).str() )->getTProfile();
660  m_dqm_nproc_byls_source = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "source_byls" ).str() )->getTProfile();
661  m_dqm_nproc_byls_postsource = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "postsource_byls" ).str() )->getTProfile();
662  m_dqm_nproc_byls_all_paths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "all_paths_byls" ).str() )->getTProfile();
663  m_dqm_nproc_byls_all_endpaths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "all_endpaths_byls" ).str() )->getTProfile();
664  m_dqm_nproc_byls_interpaths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "interpaths_byls" ).str() )->getTProfile();
665  // plots vs. instantaneous luminosity - summed over nodes with the same number of processes
666  m_dqm_nproc_byluminosity_event = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "event_byluminosity" ).str() )->getTProfile();
667  m_dqm_nproc_byluminosity_presource = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "presource_byluminosity" ).str() )->getTProfile();
668  m_dqm_nproc_byluminosity_source = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "source_byluminosity" ).str() )->getTProfile();
669  m_dqm_nproc_byluminosity_postsource = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "postsource_byluminosity" ).str() )->getTProfile();
670  m_dqm_nproc_byluminosity_all_paths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "all_paths_byluminosity" ).str() )->getTProfile();
671  m_dqm_nproc_byluminosity_all_endpaths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "all_endpaths_byluminosity").str() )->getTProfile();
672  m_dqm_nproc_byluminosity_interpaths = m_dqms->get( (boost::format("%s/Running %d processes/%s") % m_dqm_path % procs % "interpaths_byluminosity" ).str() )->getTProfile();
673  }
674 }
675 
676 void FastTimerService::postEndJob() {
677  //edm::LogImportant("FastTimerService") << __func__ << "()";
678 
679  if (m_enable_timing_summary) {
680  // print a timing sumary for the whle job
681  edm::service::TriggerNamesService & tns = * edm::Service<edm::service::TriggerNamesService>();
682 
683  std::ostringstream out;
684  out << std::fixed << std::setprecision(6);
685  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << '\n';
686  out << "FastReport " << std::right << std::setw(10) << m_summary_presource / (double) m_summary_events << " Pre-Source" << '\n';
687  out << "FastReport " << std::right << std::setw(10) << m_summary_source / (double) m_summary_events << " Source" << '\n';
688  out << "FastReport " << std::right << std::setw(10) << m_summary_postsource / (double) m_summary_events << " Post-Source" << '\n';
689  out << "FastReport " << std::right << std::setw(10) << m_summary_event / (double) m_summary_events << " Event" << '\n';
690  out << "FastReport " << std::right << std::setw(10) << m_summary_all_paths / (double) m_summary_events << " all Paths" << '\n';
691  out << "FastReport " << std::right << std::setw(10) << m_summary_all_endpaths / (double) m_summary_events << " all EndPaths" << '\n';
692  out << "FastReport " << std::right << std::setw(10) << m_summary_interpaths / (double) m_summary_events << " between paths" << '\n';
693  if (m_enable_timing_modules) {
694  double modules_total = 0.;
695  for (auto & keyval: m_modules)
696  modules_total += keyval.second.summary_active;
697  out << "FastReport " << std::right << std::setw(10) << modules_total / (double) m_summary_events << " all Modules" << '\n';
698  }
699  out << '\n';
700  if (m_enable_timing_paths and not m_enable_timing_modules) {
701  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Path" << '\n';
702  for (auto const & name: tns.getTrigPaths())
703  out << "FastReport "
704  << std::right << std::setw(10) << m_paths[name].summary_active / (double) m_summary_events << " "
705  << name << '\n';
706  out << '\n';
707  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active EndPath" << '\n';
708  for (auto const & name: tns.getEndPaths())
709  out << "FastReport "
710  << std::right << std::setw(10) << m_paths[name].summary_active / (double) m_summary_events << " "
711  << name << '\n';
712  } else if (m_enable_timing_paths and m_enable_timing_modules) {
713  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Pre- Inter- Post-mods Overhead Total Path" << '\n';
714  for (auto const & name: tns.getTrigPaths()) {
715  out << "FastReport "
716  << std::right << std::setw(10) << m_paths[name].summary_active / (double) m_summary_events << " "
717  << std::right << std::setw(10) << m_paths[name].summary_premodules / (double) m_summary_events << " "
718  << std::right << std::setw(10) << m_paths[name].summary_intermodules / (double) m_summary_events << " "
719  << std::right << std::setw(10) << m_paths[name].summary_postmodules / (double) m_summary_events << " "
720  << std::right << std::setw(10) << m_paths[name].summary_overhead / (double) m_summary_events << " "
721  << std::right << std::setw(10) << m_paths[name].summary_total / (double) m_summary_events << " "
722  << name << '\n';
723  }
724  out << '\n';
725  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Pre- Inter- Post-mods Overhead Total EndPath" << '\n';
726  for (auto const & name: tns.getEndPaths()) {
727  out << "FastReport "
728  << std::right << std::setw(10) << m_paths[name].summary_active / (double) m_summary_events << " "
729  << std::right << std::setw(10) << m_paths[name].summary_premodules / (double) m_summary_events << " "
730  << std::right << std::setw(10) << m_paths[name].summary_intermodules / (double) m_summary_events << " "
731  << std::right << std::setw(10) << m_paths[name].summary_postmodules / (double) m_summary_events << " "
732  << std::right << std::setw(10) << m_paths[name].summary_overhead / (double) m_summary_events << " "
733  << std::right << std::setw(10) << m_paths[name].summary_total / (double) m_summary_events << " "
734  << name << '\n';
735  }
736  }
737  out << '\n';
738  if (m_enable_timing_modules) {
739  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Module" << '\n';
740  for (auto & keyval: m_modules) {
741  std::string const & label = keyval.first;
742  ModuleInfo const & module = keyval.second;
743  out << "FastReport " << std::right << std::setw(10) << module.summary_active / (double) m_summary_events << " " << label << '\n';
744  }
745  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Module" << '\n';
746  out << '\n';
747  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Module" << '\n';
748  for (auto & keyval: m_moduletypes) {
749  std::string const & label = keyval.first;
750  ModuleInfo const & module = keyval.second;
751  out << "FastReport " << std::right << std::setw(10) << module.summary_active / (double) m_summary_events << " " << label << '\n';
752  }
753  out << "FastReport " << (m_timer_id == CLOCK_REALTIME ? "(real time) " : "(CPU time) ") << " Active Module" << '\n';
754  }
755  out << '\n';
756  edm::LogVerbatim("FastReport") << out.str();
757  }
758 
759  // needed for the DAQ when reconfiguring between runs
760  reset();
761 }
762 
763 void FastTimerService::reset() {
764  // transient dqm configuration
765  m_nproc_enabled = false;
766  // caching
767  m_first_path = 0; // these are initialized at prePathBeginRun(),
768  m_last_path = 0; // to make sure we cache the correct pointers
769  m_first_endpath = 0;
770  m_last_endpath = 0;
771  m_is_first_module = false;
772  m_is_first_event = true;
773  // per-event accounting
774  m_event = 0.;
775  m_presource = 0.;
776  m_source = 0.;
777  m_postsource = 0.;
778  m_all_paths = 0.;
779  m_all_endpaths = 0.;
780  m_interpaths = 0.;
781  // per-job summary
782  m_summary_events = 0;
783  m_summary_event = 0.;
784  m_summary_presource = 0.;
785  m_summary_source = 0.;
786  m_summary_postsource = 0.;
787  m_summary_all_paths = 0.;
788  m_summary_all_endpaths = 0.;
789  m_summary_interpaths = 0.;
790  // DQM - the DAQ destroys and re-creates the DQM and DQMStore services at each reconfigure, so we don't need to clean them up
791  m_dqms = 0;
792  // event summary plots
793  m_dqm_event = 0;
794  m_dqm_presource = 0;
795  m_dqm_source = 0;
796  m_dqm_postsource = 0;
797  m_dqm_all_paths = 0;
798  m_dqm_all_endpaths = 0;
799  m_dqm_interpaths = 0;
800  // event summary plots - summed over nodes with the same number of processes
801  m_dqm_nproc_event = 0;
802  m_dqm_nproc_presource = 0;
803  m_dqm_nproc_source = 0;
804  m_dqm_nproc_postsource = 0;
805  m_dqm_nproc_all_paths = 0;
806  m_dqm_nproc_all_endpaths = 0;
807  m_dqm_nproc_interpaths = 0;
808  // plots by path
809  m_dqm_paths_active_time = 0;
810  m_dqm_paths_total_time = 0;
811  m_dqm_paths_exclusive_time = 0;
812  m_dqm_paths_interpaths = 0;
813  // plots per lumisection
814  m_dqm_byls_event = 0;
815  m_dqm_byls_presource = 0;
816  m_dqm_byls_source = 0;
817  m_dqm_byls_postsource = 0;
818  m_dqm_byls_all_paths = 0;
819  m_dqm_byls_all_endpaths = 0;
820  m_dqm_byls_interpaths = 0;
821  // plots per lumisection - summed over nodes with the same number of processes
822  m_dqm_nproc_byls_event = 0;
823  m_dqm_nproc_byls_presource = 0;
824  m_dqm_nproc_byls_source = 0;
825  m_dqm_nproc_byls_postsource = 0;
826  m_dqm_nproc_byls_all_paths = 0;
827  m_dqm_nproc_byls_all_endpaths = 0;
828  m_dqm_nproc_byls_interpaths = 0;
829  // plots vs. instantaneous luminosity
830  m_dqm_byluminosity_event = 0;
831  m_dqm_byluminosity_presource = 0;
832  m_dqm_byluminosity_source = 0;
833  m_dqm_byluminosity_postsource = 0;
834  m_dqm_byluminosity_all_paths = 0;
835  m_dqm_byluminosity_all_endpaths = 0;
836  m_dqm_byluminosity_interpaths = 0;
837  // plots vs. instantaneous luminosity - summed over nodes with the same number of processes
838  m_dqm_nproc_byluminosity_event = 0;
839  m_dqm_nproc_byluminosity_presource = 0;
840  m_dqm_nproc_byluminosity_source = 0;
841  m_dqm_nproc_byluminosity_postsource = 0;
842  m_dqm_nproc_byluminosity_all_paths = 0;
843  m_dqm_nproc_byluminosity_all_endpaths = 0;
844  m_dqm_nproc_byluminosity_interpaths = 0;
845  // per-path and per-module accounting
846  m_current_path = 0;
847  m_paths.clear(); // this should destroy all PathInfo objects and reset the associated plots
848  m_modules.clear(); // this should destroy all ModuleInfo objects and reset the associated plots
849  m_moduletypes.clear(); // this should destroy all ModuleInfo objects and reset the associated plots
850  m_fast_modules.clear();
851  m_fast_moduletypes.clear();
852 }
853 
854 void FastTimerService::preModuleBeginJob(edm::ModuleDescription const & module) {
855  //edm::LogImportant("FastTimerService") << __func__ << "(" << & module << ")";
856  //edm::LogImportant("FastTimerService") << "module type " << module.moduleName() << " label " << module.moduleLabel() << " @ " << & module;
857 
858  // allocate a counter for each module and module type
859  m_fast_modules[& module] = & m_modules[module.moduleLabel()];;
860  m_fast_moduletypes[& module] = & m_moduletypes[module.moduleName()];
861 }
862 
863 void FastTimerService::preProcessEvent(edm::EventID const & id, edm::Timestamp const & stamp) {
864  //edm::LogImportant("FastTimerService") << __func__ << "(...)";
865 
866  // new event, reset the per-event counter
867  start(m_timer_event);
868 
869  // account the time spent after the source
870  m_postsource = delta(m_timer_source.second, m_timer_event.first);
871  m_summary_postsource += m_postsource;
872 
873  // clear the event counters
874  m_event = 0;
875  m_all_paths = 0;
876  m_all_endpaths = 0;
877  m_interpaths = 0;
878  for (auto & keyval : m_paths) {
879  keyval.second.time_active = 0.;
880  keyval.second.time_premodules = 0.;
881  keyval.second.time_intermodules = 0.;
882  keyval.second.time_postmodules = 0.;
883  keyval.second.time_total = 0.;
884  }
885  for (auto & keyval : m_modules) {
886  keyval.second.time_active = 0.;
887  keyval.second.has_just_run = false;
888  keyval.second.is_exclusive = false;
889  }
890  for (auto & keyval : m_moduletypes) {
891  keyval.second.time_active = 0.;
892  keyval.second.has_just_run = false;
893  keyval.second.is_exclusive = false;
894  }
895 
896  // copy the start event timestamp as the end of the previous path
897  // used by the inter-path overhead measurement
898  m_timer_path.second = m_timer_event.first;
899 }
900 
901 void FastTimerService::postProcessEvent(edm::Event const & event, edm::EventSetup const & setup) {
902  //edm::LogImportant("FastTimerService") << __func__ << "(...)";
903 
904  if (m_enable_timing_exclusive) {
905  for (auto & keyval: m_paths) {
906  PathInfo & pathinfo = keyval.second;
907  float exclusive = pathinfo.time_overhead;
908 
909  for (uint32_t i = 0; i <= pathinfo.last_run; ++i) {
910  ModuleInfo * module = pathinfo.modules[i];
911  if (module == 0)
912  // this is a module occurring more than once in the same path, skip it after the first occurrence
913  continue;
914  if (module->is_exclusive)
915  exclusive += module->time_active;
916  }
917  m_dqm_paths_exclusive_time->Fill(pathinfo.index, exclusive * 1000.);
918  if (m_enable_dqm_bypath_exclusive) {
919  pathinfo.dqm_exclusive->Fill(exclusive * 1000.);
920  }
921  }
922  }
923 
924  // fill plots for per-event time by module
925  if (m_dqms and m_enable_dqm_bymodule) {
926  for (auto & keyval : m_modules) {
927  ModuleInfo & module = keyval.second;
928  module.dqm_active->Fill(module.time_active * 1000.);
929  }
930  }
931  // fill plots for per-event time by module type
932  if (m_dqms and m_enable_dqm_bymoduletype) {
933  for (auto & keyval : m_moduletypes) {
934  ModuleInfo & module = keyval.second;
935  module.dqm_active->Fill(module.time_active * 1000.);
936  }
937  }
938 
939  // stop the per-event timer, and account event time
940  stop(m_timer_event);
941  m_event = delta(m_timer_event);
942  m_summary_event += m_event;
943  // the last part of inter-path overhead is the time between the end of the last (end)path and the end of the event processing
944  double interpaths = delta(m_timer_path.second, m_timer_event.second);
945  m_interpaths += interpaths;
946  m_summary_interpaths += m_interpaths;
947  if (m_dqms) {
948  m_dqm_paths_interpaths->Fill(m_paths.size(), interpaths * 1000.);
949 
950  if (m_enable_dqm_summary) {
951  m_dqm_event ->Fill(m_event * 1000.);
952  m_dqm_presource ->Fill(m_presource * 1000.);
953  m_dqm_source ->Fill(m_source * 1000.);
954  m_dqm_postsource ->Fill(m_postsource * 1000.);
955  m_dqm_all_paths ->Fill(m_all_paths * 1000.);
956  m_dqm_all_endpaths ->Fill(m_all_endpaths * 1000.);
957  m_dqm_interpaths ->Fill(m_interpaths * 1000.);
958 
959  if (m_nproc_enabled) {
960  m_dqm_nproc_event ->Fill(m_event * 1000.);
961  m_dqm_nproc_presource ->Fill(m_presource * 1000.);
962  m_dqm_nproc_source ->Fill(m_source * 1000.);
963  m_dqm_nproc_postsource ->Fill(m_postsource * 1000.);
964  m_dqm_nproc_all_paths ->Fill(m_all_paths * 1000.);
965  m_dqm_nproc_all_endpaths ->Fill(m_all_endpaths * 1000.);
966  m_dqm_nproc_interpaths ->Fill(m_interpaths * 1000.);
967  }
968  }
969 
970  if (m_enable_dqm_byls) {
971  unsigned int ls = event.getLuminosityBlock().luminosityBlock();
972  m_dqm_byls_event ->Fill(ls, m_event * 1000.);
973  m_dqm_byls_presource ->Fill(ls, m_presource * 1000.);
974  m_dqm_byls_source ->Fill(ls, m_source * 1000.);
975  m_dqm_byls_postsource ->Fill(ls, m_postsource * 1000.);
976  m_dqm_byls_all_paths ->Fill(ls, m_all_paths * 1000.);
977  m_dqm_byls_all_endpaths ->Fill(ls, m_all_endpaths * 1000.);
978  m_dqm_byls_interpaths ->Fill(ls, m_interpaths * 1000.);
979 
980  if (m_nproc_enabled) {
981  m_dqm_nproc_byls_event ->Fill(ls, m_event * 1000.);
982  m_dqm_nproc_byls_presource ->Fill(ls, m_presource * 1000.);
983  m_dqm_nproc_byls_source ->Fill(ls, m_source * 1000.);
984  m_dqm_nproc_byls_postsource ->Fill(ls, m_postsource * 1000.);
985  m_dqm_nproc_byls_all_paths ->Fill(ls, m_all_paths * 1000.);
986  m_dqm_nproc_byls_all_endpaths ->Fill(ls, m_all_endpaths * 1000.);
987  m_dqm_nproc_byls_interpaths ->Fill(ls, m_interpaths * 1000.);
988  }
989  }
990 
991  if (m_enable_dqm_byluminosity) {
992  float luminosity = 0.;
993  edm::Handle<LumiScalersCollection> h_luminosity;
994  if (event.getByLabel(m_luminosity_label, h_luminosity) and not h_luminosity->empty())
995  luminosity = h_luminosity->front().instantLumi(); // in units of 1e30 cm-2s-1
996 
997  m_dqm_byluminosity_event ->Fill(luminosity, m_event * 1000.);
998  m_dqm_byluminosity_presource ->Fill(luminosity, m_presource * 1000.);
999  m_dqm_byluminosity_source ->Fill(luminosity, m_source * 1000.);
1000  m_dqm_byluminosity_postsource ->Fill(luminosity, m_postsource * 1000.);
1001  m_dqm_byluminosity_all_paths ->Fill(luminosity, m_all_paths * 1000.);
1002  m_dqm_byluminosity_all_endpaths ->Fill(luminosity, m_all_endpaths * 1000.);
1003  m_dqm_byluminosity_interpaths ->Fill(luminosity, m_interpaths * 1000.);
1004 
1005  if (m_nproc_enabled) {
1006  m_dqm_nproc_byluminosity_event ->Fill(luminosity, m_event * 1000.);
1007  m_dqm_nproc_byluminosity_presource ->Fill(luminosity, m_presource * 1000.);
1008  m_dqm_nproc_byluminosity_source ->Fill(luminosity, m_source * 1000.);
1009  m_dqm_nproc_byluminosity_postsource ->Fill(luminosity, m_postsource * 1000.);
1010  m_dqm_nproc_byluminosity_all_paths ->Fill(luminosity, m_all_paths * 1000.);
1011  m_dqm_nproc_byluminosity_all_endpaths ->Fill(luminosity, m_all_endpaths * 1000.);
1012  m_dqm_nproc_byluminosity_interpaths ->Fill(luminosity, m_interpaths * 1000.);
1013  }
1014  }
1015  }
1016 
1017  // done processing the first event
1018  m_is_first_event = false;
1019 }
1020 
1021 void FastTimerService::preSource() {
1022  //edm::LogImportant("FastTimerService") << __func__ << "()";
1023 
1024  start(m_timer_source);
1025 
1026  // account the time spent before the source
1027  m_presource = (m_is_first_event) ? 0. : delta(m_timer_event.second, m_timer_source.first);
1028  m_summary_presource += m_presource;
1029 
1030  // clear the event counters
1031  m_source = 0.;
1032  m_postsource = 0.;
1033 
1034  // keep track of the total number of events
1035  ++m_summary_events;
1036 }
1037 
1038 void FastTimerService::postSource() {
1039  //edm::LogImportant("FastTimerService") << __func__ << "()";
1040 
1041  stop(m_timer_source);
1042  m_source = delta(m_timer_source);
1043  m_summary_source += m_source;
1044 }
1045 
1046 void FastTimerService::prePathBeginRun(std::string const & path ) {
1047  //edm::LogImportant("FastTimerService") << __func__ << "(" << path << ")";
1048 
1049  // cache the pointers to the names of the first and last path and endpath
1050  edm::service::TriggerNamesService & tns = * edm::Service<edm::service::TriggerNamesService>();
1051  if (not m_skip_first_path and not tns.getTrigPaths().empty()) {
1052  if (path == tns.getTrigPaths().front())
1053  m_first_path = & path;
1054  if (path == tns.getTrigPaths().back())
1055  m_last_path = & path;
1056  }
1057  else if (m_skip_first_path and tns.getTrigPaths().size() > 1) {
1058  if (path == tns.getTrigPaths().at(1))
1059  m_first_path = & path;
1060  if (path == tns.getTrigPaths().back())
1061  m_last_path = & path;
1062  }
1063  if (not tns.getEndPaths().empty()) {
1064  if (path == tns.getEndPaths().front())
1065  m_first_endpath = & path;
1066  if (path == tns.getEndPaths().back())
1067  m_last_endpath = & path;
1068  }
1069 }
1070 
1071 void FastTimerService::preProcessPath(std::string const & path ) {
1072  //edm::LogImportant("FastTimerService") << __func__ << "(" << path << ")";
1073 
1074  // prepare to measure the time spent between the beginning of the path and the execution of the first module
1075  m_is_first_module = true;
1076 
1077  PathMap<PathInfo>::iterator keyval = m_paths.find(path);
1078  if (keyval != m_paths.end()) {
1079  m_current_path = & keyval->second;
1080 
1081  if (m_enable_timing_modules) {
1082  // reset the status of this path's modules
1083  for (ModuleInfo * module: m_current_path->modules)
1084  if (module)
1085  module->has_just_run = false;
1086  }
1087  } else {
1088  // should never get here
1089  m_current_path = 0;
1090  edm::LogError("FastTimerService") << "FastTimerService::preProcessPath: unexpected path " << path;
1091  }
1092 
1093  // time each (end)path
1094  start(m_timer_path);
1095 
1096  if (& path == m_first_path) {
1097  // this is the first path, start the "all paths" counter
1098  m_timer_paths.first = m_timer_path.first;
1099  } else if (& path == m_first_endpath) {
1100  // this is the first endpath, start the "all paths" counter
1101  m_timer_endpaths.first = m_timer_path.first;
1102  }
1103 
1104  // measure the inter-path overhead as the time elapsed since the end of preiovus path
1105  // (or the beginning of the event, if this is the first path - see preProcessEvent)
1106  double interpaths = delta(m_timer_path.second, m_timer_path.first);
1107  m_interpaths += interpaths;
1108  if (m_dqms) {
1109  m_dqm_paths_interpaths->Fill(m_current_path->index, interpaths * 1000.);
1110  }
1111 }
1112 
1113 void FastTimerService::postProcessPath(std::string const & path, edm::HLTPathStatus const & status) {
1114  //edm::LogImportant("FastTimerService") << __func__ << "(" << path << ", ...)";
1115 
1116  // time each (end)path
1117  stop(m_timer_path);
1118 
1119  double active = delta(m_timer_path);
1120 
1121  // if enabled, account each (end)path
1122  if (m_enable_timing_paths) {
1123 
1124  PathInfo & pathinfo = * m_current_path;
1125  pathinfo.time_active = active;
1126  pathinfo.summary_active += active;
1127 
1128  if (m_dqms) {
1129  m_dqm_paths_active_time->Fill(pathinfo.index, active * 1000.);
1130  if (m_enable_dqm_bypath_active) {
1131  pathinfo.dqm_active->Fill(active * 1000.);
1132  }
1133  }
1134 
1135  // measure the time spent between the execution of the last module and the end of the path
1136  if (m_enable_timing_modules) {
1137  double pre = 0.; // time spent before the first active module
1138  double inter = 0.; // time spent between active modules
1139  double post = 0.; // time spent after the last active module
1140  double overhead = 0.; // time spent before, between, or after modules
1141  double current = 0.; // time spent in modules active in the current path
1142  double total = active; // total per-path time, including modules already run as part of other paths
1143 
1144  // implementation note:
1145  // "active" has already measured all the time spent in this path
1146  // "current" will be the sum of the time spent inside each module while running this path, so that
1147  // "overhead" will be active - current
1148  // "total" will be active + the sum of the time spent in non-active modules
1149 
1150  uint32_t last_run = status.index(); // index of the last module run in this path
1151  for (uint32_t i = 0; i <= last_run; ++i) {
1152  ModuleInfo * module = pathinfo.modules[i];
1153 
1154  // fill counter histograms - also for duplicate modules, to properly extract rejection information
1155  if (m_enable_dqm_bypath_counters) {
1156  pathinfo.dqm_module_counter->Fill(i);
1157  }
1158 
1159  if (module == 0)
1160  // this is a module occurring more than once in the same path, skip it after the first occurrence
1161  continue;
1162 
1163  if (module->has_just_run) {
1164  current += module->time_active;
1165  module->is_exclusive = true;
1166  } else {
1167  total += module->time_active;
1168  module->is_exclusive = false;
1169  }
1170 
1171  // fill detailed timing histograms
1172  if (m_enable_dqm_bypath_details) {
1173  // fill the total time for all non-duplicate modules
1174  pathinfo.dqm_module_total->Fill(i, module->time_active * 1000.);
1175  if (module->has_just_run) {
1176  // fill the active time only for module actually running in this path
1177  pathinfo.dqm_module_active->Fill(i, module->time_active * 1000.);
1178  }
1179  }
1180 
1181  }
1182 
1183  if (status.accept())
1184  if (m_enable_dqm_bypath_counters) {
1185  pathinfo.dqm_module_counter->Fill(pathinfo.modules.size());
1186  }
1187 
1188  if (m_is_first_module) {
1189  // no modules were active during this path, account all the time as overhead
1190  pre = 0.;
1191  inter = 0.;
1192  post = active;
1193  overhead = active;
1194  } else {
1195  // extract overhead information
1196  pre = delta(m_timer_path.first, m_timer_first_module);
1197  post = delta(m_timer_module.second, m_timer_path.second);
1198  inter = active - pre - current - post;
1199  // take care of numeric precision and rounding errors - the timer is less precise than nanosecond resolution
1200  if (std::abs(inter) < 1e-9)
1201  inter = 0.;
1202  overhead = active - current;
1203  // take care of numeric precision and rounding errors - the timer is less precise than nanosecond resolution
1204  if (std::abs(overhead) < 1e-9)
1205  overhead = 0.;
1206  }
1207 
1208  pathinfo.time_premodules = pre;
1209  pathinfo.time_intermodules = inter;
1210  pathinfo.time_postmodules = post;
1211  pathinfo.time_overhead = overhead;
1212  pathinfo.time_total = total;
1213  pathinfo.summary_premodules += pre;
1214  pathinfo.summary_intermodules += inter;
1215  pathinfo.summary_postmodules += post;
1216  pathinfo.summary_overhead += overhead;
1217  pathinfo.summary_total += total;
1218  pathinfo.last_run = last_run;
1219  if (m_dqms) {
1220  if (m_enable_dqm_bypath_overhead) {
1221  pathinfo.dqm_premodules ->Fill(pre * 1000.);
1222  pathinfo.dqm_intermodules->Fill(inter * 1000.);
1223  pathinfo.dqm_postmodules ->Fill(post * 1000.);
1224  pathinfo.dqm_overhead ->Fill(overhead * 1000.);
1225  }
1226  m_dqm_paths_total_time->Fill(pathinfo.index, total * 1000.);
1227  if (m_enable_dqm_bypath_total) {
1228  pathinfo.dqm_total ->Fill(total * 1000.);
1229  }
1230  }
1231  }
1232  }
1233 
1234  if (& path == m_last_path) {
1235  // this is the last path, stop and account the "all paths" counter
1236  m_timer_paths.second = m_timer_path.second;
1237  m_all_paths = delta(m_timer_paths);
1238  m_summary_all_paths += m_all_paths;
1239  } else if (& path == m_last_endpath) {
1240  // this is the last endpath, stop and account the "all endpaths" counter
1241  m_timer_endpaths.second = m_timer_path.second;
1242  m_all_endpaths = delta(m_timer_endpaths);
1243  m_summary_all_endpaths += m_all_endpaths;
1244  }
1245 
1246 }
1247 
1248 void FastTimerService::preModule(edm::ModuleDescription const & module) {
1249  //edm::LogImportant("FastTimerService") << __func__ << "(" << & module << ")";
1250 
1251  // this is ever called only if m_enable_timing_modules = true
1252  assert(m_enable_timing_modules);
1253 
1254  // time each module
1255  start(m_timer_module);
1256 
1257  if (m_is_first_module) {
1258  m_is_first_module = false;
1259 
1260  // measure the time spent between the beginning of the path and the execution of the first module
1261  m_timer_first_module = m_timer_module.first;
1262  }
1263 }
1264 
1265 void FastTimerService::postModule(edm::ModuleDescription const & module) {
1266  //edm::LogImportant("FastTimerService") << __func__ << "(" << & module << ")";
1267 
1268  // this is ever called only if m_enable_timing_modules = true
1269  assert(m_enable_timing_modules);
1270 
1271  // time and account each module
1272  stop(m_timer_module);
1273 
1274  { // if-scope
1275  ModuleMap<ModuleInfo*>::iterator keyval = m_fast_modules.find(& module);
1276  if (keyval != m_fast_modules.end()) {
1277  double time = delta(m_timer_module);
1278  ModuleInfo & module = * keyval->second;
1279  module.has_just_run = true;
1280  module.time_active = time;
1281  module.summary_active += time;
1282  // plots are filled post event processing
1283  } else {
1284  // should never get here
1285  edm::LogError("FastTimerService") << "FastTimerService::postModule: unexpected module " << module.moduleLabel();
1286  }
1287  }
1288 
1289  { // if-scope
1290  ModuleMap<ModuleInfo*>::iterator keyval = m_fast_moduletypes.find(& module);
1291  if (keyval != m_fast_moduletypes.end()) {
1292  double time = delta(m_timer_module);
1293  ModuleInfo & module = * keyval->second;
1294  // module.has_just_run is not useful here
1295  module.time_active += time;
1296  module.summary_active += time;
1297  // plots are filled post event processing
1298  } else {
1299  // should never get here
1300  edm::LogError("FastTimerService") << "FastTimerService::postModule: unexpected module " << module.moduleLabel();
1301  }
1302  }
1303 
1304 }
1305 
1306 // associate to a path all the modules it contains
1307 void FastTimerService::fillPathMap(std::string const & name, std::vector<std::string> const & modules) {
1308  std::vector<ModuleInfo *> & pathmap = m_paths[name].modules;
1309  pathmap.clear();
1310  pathmap.reserve( modules.size() );
1311  std::unordered_set<ModuleInfo const *> pool; // keep track of inserted modules
1312  for (auto const & module: modules) {
1313  // fix the name of negated or ignored modules
1314  std::string const & label = (module[0] == '!' or module[0] == '-') ? module.substr(1) : module;
1315 
1316  auto const & it = m_modules.find(label);
1317  if (it == m_modules.end()) {
1318  // no matching module was found
1319  pathmap.push_back( 0 );
1320  } else if (pool.insert(& it->second).second) {
1321  // new module
1322  pathmap.push_back(& it->second);
1323  } else {
1324  // duplicate module
1325  pathmap.push_back( 0 );
1326  }
1327 
1328  }
1329 }
1330 
1331 
1332 // query the current module/path/event
1333 // Note: these functions incur in a "per-call timer overhead" (see above), currently of the order of 340ns
1334 
1335 // return the time spent since the last preModule() event
1336 double FastTimerService::currentModuleTime() const {
1337  struct timespec now;
1338  gettime(now);
1339  return delta(m_timer_module.first, now);
1340 }
1341 
1342 // return the time spent since the last preProcessPath() event
1343 double FastTimerService::currentPathTime() const {
1344  struct timespec now;
1345  gettime(now);
1346  return delta(m_timer_path.first, now);
1347 }
1348 
1349 // return the time spent since the last preProcessEvent() event
1350 double FastTimerService::currentEventTime() const {
1351  struct timespec now;
1352  gettime(now);
1353  return delta(m_timer_event.first, now);
1354 }
1355 
1356 // query the time spent in a module (available after the module has run)
1357 double FastTimerService::queryModuleTime(const edm::ModuleDescription & module) const {
1358  ModuleMap<ModuleInfo *>::const_iterator keyval = m_fast_modules.find(& module);
1359  if (keyval != m_fast_modules.end()) {
1360  return keyval->second->time_active;
1361  } else {
1362  edm::LogError("FastTimerService") << "FastTimerService::queryModuleTime: unexpected module " << module.moduleLabel();
1363  return 0.;
1364  }
1365 }
1366 
1367 // query the time spent in a module (available after the module has run
1368 double FastTimerService::queryModuleTimeByLabel(const std::string & label) const {
1369  auto const & keyval = m_modules.find(label);
1370  if (keyval != m_modules.end()) {
1371  return keyval->second.time_active;
1372  } else {
1373  // module not found
1374  edm::LogError("FastTimerService") << "FastTimerService::queryModuleTimeByLabel: unexpected module " << label;
1375  return 0.;
1376  }
1377 }
1378 
1379 // query the time spent in a module (available after the module has run
1380 double FastTimerService::queryModuleTimeByType(const std::string & type) const {
1381  auto const & keyval = m_moduletypes.find(type);
1382  if (keyval != m_moduletypes.end()) {
1383  return keyval->second.time_active;
1384  } else {
1385  // module not found
1386  edm::LogError("FastTimerService") << "FastTimerService::queryModuleTimeByType: unexpected module type " << type;
1387  return 0.;
1388  }
1389 }
1390 
1391 // query the time spent in a path (available after the path has run)
1392 double FastTimerService::queryPathActiveTime(const std::string & path) const {
1393  PathMap<PathInfo>::const_iterator keyval = m_paths.find(path);
1394  if (keyval != m_paths.end()) {
1395  return keyval->second.time_active;
1396  } else {
1397  edm::LogError("FastTimerService") << "FastTimerService::queryPathActiveTime: unexpected path " << path;
1398  return 0.;
1399  }
1400 }
1401 
1402 // query the total time spent in a path (available after the path has run)
1403 double FastTimerService::queryPathTotalTime(const std::string & path) const {
1404  PathMap<PathInfo>::const_iterator keyval = m_paths.find(path);
1405  if (keyval != m_paths.end()) {
1406  return keyval->second.time_total;
1407  } else {
1408  edm::LogError("FastTimerService") << "FastTimerService::queryPathTotalTime: unexpected path " << path;
1409  return 0.;
1410  }
1411 }
1412 
1413 // query the time spent in the current event's source (available during event processing)
1414 double FastTimerService::querySourceTime() const {
1415  return m_source;
1416 }
1417 
1418 // query the time spent in the current event's paths (available during endpaths)
1419 double FastTimerService::queryPathsTime() const {
1420  return m_all_paths;
1421 }
1422 
1423 // query the time spent in the current event's endpaths (available after all endpaths have run)
1424 double FastTimerService::queryEndPathsTime() const {
1425  return m_all_endpaths;
1426 }
1427 
1428 // query the time spent processing the current event (available after the event has been processed)
1429 double FastTimerService::queryEventTime() const {
1430  return m_event;
1431 }
1432 
1433 // describe the module's configuration
1434 void FastTimerService::fillDescriptions(edm::ConfigurationDescriptions & descriptions) {
1435  edm::ParameterSetDescription desc;
1436  desc.addUntracked<bool>( "useRealTimeClock", true);
1437  desc.addUntracked<bool>( "enableTimingPaths", true);
1438  desc.addUntracked<bool>( "enableTimingModules", true);
1439  desc.addUntracked<bool>( "enableTimingExclusive", false);
1440  desc.addUntracked<bool>( "enableTimingSummary", false);
1441  desc.addUntracked<bool>( "skipFirstPath", false),
1442  desc.addUntracked<bool>( "enableDQM", true);
1443  desc.addUntracked<bool>( "enableDQMbyPathActive", false);
1444  desc.addUntracked<bool>( "enableDQMbyPathTotal", true);
1445  desc.addUntracked<bool>( "enableDQMbyPathOverhead", false);
1446  desc.addUntracked<bool>( "enableDQMbyPathDetails", false);
1447  desc.addUntracked<bool>( "enableDQMbyPathCounters", true);
1448  desc.addUntracked<bool>( "enableDQMbyPathExclusive", false);
1449  desc.addUntracked<bool>( "enableDQMbyModule", false);
1450  desc.addUntracked<bool>( "enableDQMbyModuleType", false);
1451  desc.addUntracked<bool>( "enableDQMSummary", false);
1452  desc.addUntracked<bool>( "enableDQMbyLuminosity", false);
1453  desc.addNode(
1454  edm::ParameterDescription<bool>( "enableDQMbyLumiSection", false, false) or
1455  edm::ParameterDescription<bool>( "enableDQMbyLumi", false, false)
1456  );
1457  desc.addUntracked<bool>( "enableDQMbyProcesses", false);
1458  desc.addUntracked<double>( "dqmTimeRange", 1000. ); // ms
1459  desc.addUntracked<double>( "dqmTimeResolution", 5. ); // ms
1460  desc.addUntracked<double>( "dqmPathTimeRange", 100. ); // ms
1461  desc.addUntracked<double>( "dqmPathTimeResolution", 0.5); // ms
1462  desc.addUntracked<double>( "dqmModuleTimeRange", 40. ); // ms
1463  desc.addUntracked<double>( "dqmModuleTimeResolution", 0.2); // ms
1464  desc.addUntracked<double>( "dqmLuminosityRange", 1.e34 ); // cm-2 s-1
1465  desc.addUntracked<double>( "dqmLuminosityResolution", 1.e31 ); // cm-2 s-1
1466  desc.addUntracked<uint32_t>( "dqmLumiSectionsRange", 2500 ); // ~ 16 hours
1467  desc.addUntracked<std::string>( "dqmPath", "HLT/TimerService");
1468  desc.addUntracked<edm::InputTag>( "luminosityProduct", edm::InputTag("hltScalersRawToDigi"));
1469  desc.addUntracked<std::vector<unsigned int> >("supportedProcesses", { 8, 24, 32 });
1470  descriptions.add("FastTimerService", desc);
1471 }
FastTimerService::prePathBeginRun
void prePathBeginRun(std::string const &)
Definition: FastTimerService.cc:1046
FastTimerService::m_timer_path
std::pair< struct timespec, struct timespec > m_timer_path
Definition: FastTimerService.h:409
type
type
Definition: HCALResponse.h:21
i
int i
Definition: DBlmapReader.cc:9
FastTimerService::m_dqm_eventtime_resolution
const double m_dqm_eventtime_resolution
Definition: FastTimerService.h:294
edm::service::TriggerNamesService::getTrigPathModules
Strings const & getTrigPathModules(std::string const &name) const
Definition: TriggerNamesService.h:84
FastTimerService::m_dqm_byls_all_endpaths
TProfile * m_dqm_byls_all_endpaths
Definition: FastTimerService.h:366
edm::service::TriggerNamesService::getTrigPath
std::string const & getTrigPath(size_type const i) const
Definition: TriggerNamesService.h:59
FastTimerService::m_enable_dqm_byluminosity
const bool m_enable_dqm_byluminosity
Definition: FastTimerService.h:289
FastTimerService::m_dqm_ls_range
const uint32_t m_dqm_ls_range
Definition: FastTimerService.h:301
fill_dups
static void fill_dups(std::vector< std::string > &dups, unsigned int size)
Definition: FastTimerService.cc:52
FastTimerService::queryModuleTimeByType
double queryModuleTimeByType(const std::string &) const
Definition: FastTimerService.cc:1380
FastTimerService::m_fast_moduletypes
ModuleMap< ModuleInfo * > m_fast_moduletypes
Definition: FastTimerService.h:402
FastTimerService::m_dqm_byls_source
TProfile * m_dqm_byls_source
Definition: FastTimerService.h:363
edm::ParameterSetDescription::addUntracked
ParameterDescriptionBase * addUntracked(U const &iLabel, T const &value)
Definition: ParameterSetDescription.h:94
FastTimerService::m_dqm_nproc_byls_all_paths
TProfile * m_dqm_nproc_byls_all_paths
Definition: FastTimerService.h:374
FastTimerService::queryEventTime
double queryEventTime() const
Definition: FastTimerService.cc:1429
edm::ActivityRegistry::watchPostEndJob
void watchPostEndJob(PostEndJob::slot_type const &iSlot)
Definition: ActivityRegistry.h:63
FastTimerService::m_timer_event
std::pair< struct timespec, struct timespec > m_timer_event
Definition: FastTimerService.h:405
edm::service::TriggerNamesService::getEndPaths
Strings const & getEndPaths() const
Definition: TriggerNamesService.h:80
DQMStore::book1D
MonitorElement * book1D(const char *name, const char *title, int nchX, double lowX, double highX)
Book 1D histogram.
Definition: DQMStore.cc:722
or
The Signals That Services Can Subscribe To This is based on ActivityRegistry and is current per Services can connect to the signals distributed by the ActivityRegistry in order to monitor the activity of the application Each possible callback has some defined which we here list in angle e< void, edm::EventIDconst &, edm::Timestampconst & > We also list in braces which AR_WATCH_USING_METHOD_ is used for those or
Definition: Activities.doc:12
FastTimerService::m_timer_id
const clockid_t m_timer_id
Definition: FastTimerService.h:270
FastTimerService::m_dqm_byls_presource
TProfile * m_dqm_byls_presource
Definition: FastTimerService.h:362
FastTimerService::m_dqm_luminosity_resolution
const double m_dqm_luminosity_resolution
Definition: FastTimerService.h:300
FastTimerService::m_dqm_nproc_byls_presource
TProfile * m_dqm_nproc_byls_presource
Definition: FastTimerService.h:371
FastTimerService::queryModuleTimeByLabel
double queryModuleTimeByLabel(const std::string &) const
Definition: FastTimerService.cc:1368
FastTimerService::m_dqm_byluminosity_interpaths
TProfile * m_dqm_byluminosity_interpaths
Definition: FastTimerService.h:385
FastTimerService::m_dqm_nproc_byluminosity_source
TProfile * m_dqm_nproc_byluminosity_source
Definition: FastTimerService.h:390
FastTimerService::preProcessEvent
void preProcessEvent(edm::EventID const &, edm::Timestamp const &)
Definition: FastTimerService.cc:863
FastTimerService::m_enable_dqm_bypath_counters
const bool m_enable_dqm_bypath_counters
Definition: FastTimerService.h:284
FastTimerService::postProcessEvent
void postProcessEvent(edm::Event const &, edm::EventSetup const &)
Definition: FastTimerService.cc:901
FastTimerService::m_skip_first_path
const bool m_skip_first_path
Definition: FastTimerService.h:276
edm::ActivityRegistry::watchPostModule
void watchPostModule(PostModule::slot_type const &iSlot)
Definition: ActivityRegistry.h:394
FastTimerService::m_last_path
std::string const * m_last_path
Definition: FastTimerService.h:308
FastTimerService::m_dqm_nproc_byls_interpaths
TProfile * m_dqm_nproc_byls_interpaths
Definition: FastTimerService.h:376
FastTimerService::m_dqm_nproc_byluminosity_postsource
TProfile * m_dqm_nproc_byluminosity_postsource
Definition: FastTimerService.h:391
edm::ActivityRegistry::watchPreProcessEvent
void watchPreProcessEvent(PreProcessEvent::slot_type const &iSlot)
Definition: ActivityRegistry.h:164
FastTimerService::postModule
void postModule(edm::ModuleDescription const &)
Definition: FastTimerService.cc:1265
FastTimerService::m_enable_dqm_bypath_exclusive
const bool m_enable_dqm_bypath_exclusive
Definition: FastTimerService.h:285
FastTimerService::queryPathTotalTime
double queryPathTotalTime(const std::string &) const
Definition: FastTimerService.cc:1403
FastTimerService::m_moduletypes
std::unordered_map< std::string, ModuleInfo > m_moduletypes
Definition: FastTimerService.h:400
FastTimerService::m_dqm_pathtime_range
const double m_dqm_pathtime_range
Definition: FastTimerService.h:295
edm::ModuleDescription::moduleName
std::string const & moduleName() const
Definition: ModuleDescription.h:49
abs
#define abs(x)
Definition: mlp_lapack.h:159
FastTimerService::m_first_endpath
std::string const * m_first_endpath
Definition: FastTimerService.h:309
edm::ParameterSetDescription::addNode
ParameterDescriptionNode * addNode(ParameterDescriptionNode const &node)
Definition: ParameterSetDescription.cc:61
FastTimerService::m_luminosity_label
const edm::InputTag m_luminosity_label
Definition: FastTimerService.h:303
CPUAffinity::isCpuBound
static bool isCpuBound()
Definition: CPUAffinity.cc:60
CLOCK_THREAD_CPUTIME_ID
#define CLOCK_THREAD_CPUTIME_ID
Definition: FastTimerService.cc:13
FastTimerService::m_current_path
PathInfo * m_current_path
Definition: FastTimerService.h:397
FastTimerService::m_dqm_byluminosity_presource
TProfile * m_dqm_byluminosity_presource
Definition: FastTimerService.h:380
spr::find
void find(edm::Handle< EcalRecHitCollection > &hits, DetId thisDet, std::vector< EcalRecHitCollection::const_iterator > &hit, bool debug=false)
Definition: FindCaloHit.cc:7
FastTimerService::setNumberOfProcesses
void setNumberOfProcesses(unsigned int)
Definition: FastTimerService.cc:611
edm::ModuleDescription::moduleLabel
std::string const & moduleLabel() const
Definition: ModuleDescription.h:50
FastTimerService::m_timer_endpaths
std::pair< struct timespec, struct timespec > m_timer_endpaths
Definition: FastTimerService.h:408
AlCaHLTBitMon_QueryRunRegistry.string
string string
Definition: AlCaHLTBitMon_QueryRunRegistry.py:255
edm::ActivityRegistry::watchPreModule
void watchPreModule(PreModule::slot_type const &iSlot)
Definition: ActivityRegistry.h:386
FastTimerService::m_dqm_nproc_byluminosity_presource
TProfile * m_dqm_nproc_byluminosity_presource
Definition: FastTimerService.h:389
FastTimerService::queryEndPathsTime
double queryEndPathsTime() const
Definition: FastTimerService.cc:1424
fetchall_from_DQM_v2.pool
tuple pool
Definition: fetchall_from_DQM_v2.py:139
reco_calib_source_client_cfg.labels
tuple labels
Definition: reco_calib_source_client_cfg.py:80
FastTimerService::m_dqm_nproc_byluminosity_event
TProfile * m_dqm_nproc_byluminosity_event
Definition: FastTimerService.h:388
FastTimerService::m_dqm_nproc_byluminosity_all_paths
TProfile * m_dqm_nproc_byluminosity_all_paths
Definition: FastTimerService.h:392
FastTimerService::m_dqm_byls_postsource
TProfile * m_dqm_byls_postsource
Definition: FastTimerService.h:364
FastTimerService::m_dqm_byls_interpaths
TProfile * m_dqm_byls_interpaths
Definition: FastTimerService.h:367
FastTimerService::preModuleBeginJob
void preModuleBeginJob(edm::ModuleDescription const &)
Definition: FastTimerService.cc:854
FastTimerService::m_enable_dqm_bynproc
const bool m_enable_dqm_bynproc
Definition: FastTimerService.h:291
FastTimerService::querySourceTime
double querySourceTime() const
Definition: FastTimerService.cc:1414
edm::service::TriggerNamesService::getEndPathModules
Strings const & getEndPathModules(std::string const &name) const
Definition: TriggerNamesService.h:97
edm::ActivityRegistry::watchPostProcessEvent
void watchPostProcessEvent(PostProcessEvent::slot_type const &iSlot)
Definition: ActivityRegistry.h:172
edm::service::TriggerNamesService::findTrigPath
size_type findTrigPath(std::string const &name) const
Definition: TriggerNamesService.h:60
FastTimerService::stop
void stop(std::pair< struct timespec, struct timespec > &times) const
Definition: FastTimerService.h:437
edm::ActivityRegistry::watchPrePathBeginRun
void watchPrePathBeginRun(PrePathBeginRun::slot_type const &iSlot)
Definition: ActivityRegistry.h:260
FastTimerService::m_timer_paths
std::pair< struct timespec, struct timespec > m_timer_paths
Definition: FastTimerService.h:407
FastTimerService::m_dqm_byluminosity_postsource
TProfile * m_dqm_byluminosity_postsource
Definition: FastTimerService.h:382
FastTimerService::m_enable_dqm_byls
const bool m_enable_dqm_byls
Definition: FastTimerService.h:290
clockid_t
int clockid_t
Definition: FastTimerService.h:8
FastTimerService::m_dqm_moduletime_resolution
const double m_dqm_moduletime_resolution
Definition: FastTimerService.h:298
FastTimerService::m_dqm_byluminosity_source
TProfile * m_dqm_byluminosity_source
Definition: FastTimerService.h:381
FastTimerService::preModule
void preModule(edm::ModuleDescription const &)
Definition: FastTimerService.cc:1248
FastTimerService::m_enable_dqm
const bool m_enable_dqm
Definition: FastTimerService.h:279
FastTimerService::m_dqm_nproc_byluminosity_all_endpaths
TProfile * m_dqm_nproc_byluminosity_all_endpaths
Definition: FastTimerService.h:393
FastTimerService::fillDescriptions
static void fillDescriptions(edm::ConfigurationDescriptions &descriptions)
Definition: FastTimerService.cc:1434
FastTimerService::FastTimerService
FastTimerService(const edm::ParameterSet &, edm::ActivityRegistry &)
Definition: FastTimerService.cc:59
FastTimerService::m_first_path
std::string const * m_first_path
Definition: FastTimerService.h:307
FastTimerService::m_dqm_nproc_byls_source
TProfile * m_dqm_nproc_byls_source
Definition: FastTimerService.h:372
FastTimerService::m_dqm_nproc_byls_all_endpaths
TProfile * m_dqm_nproc_byls_all_endpaths
Definition: FastTimerService.h:375
FastTimerService::m_last_endpath
std::string const * m_last_endpath
Definition: FastTimerService.h:310
FastTimerService::queryPathActiveTime
double queryPathActiveTime(const std::string &) const
Definition: FastTimerService.cc:1392
infinity
const double infinity
Definition: CSCChamberFitter.cc:10
FastTimerService::start
void start(std::pair< struct timespec, struct timespec > &times) const
Definition: FastTimerService.h:432
FastTimerService::m_paths
PathMap< PathInfo > m_paths
Definition: FastTimerService.h:398
edm::ActivityRegistry::watchPreSource
void watchPreSource(PreSource::slot_type const &iSlot)
Definition: ActivityRegistry.h:81
FastTimerService::m_timer_first_module
struct timespec m_timer_first_module
Definition: FastTimerService.h:411
FastTimerService::m_enable_dqm_bypath_details
const bool m_enable_dqm_bypath_details
Definition: FastTimerService.h:283
DQMStore::bookProfile
MonitorElement * bookProfile(const char *name, const char *title, int nchX, double lowX, double highX, int nchY, double lowY, double highY, const char *option="s")
Definition: DQMStore.cc:1036
CLOCK_REALTIME
#define CLOCK_REALTIME
Definition: FastTimerService.cc:10
FastTimerService::m_enable_dqm_bypath_overhead
const bool m_enable_dqm_bypath_overhead
Definition: FastTimerService.h:282
event
How EventSelector::AcceptEvent() decides whether to accept an event for output otherwise it is excluding the probing of A single or multiple positive and the trigger will pass if any such matching triggers are PASS or EXCEPTION[A criterion thatmatches no triggers at all is detected and causes a throw.] A single negative with an expectation of appropriate bit checking in the decision and the trigger will pass if any such matching triggers are FAIL or EXCEPTION A wildcarded negative criterion that matches more than one trigger in the trigger but the state exists so we define the behavior If all triggers are the negative crieriion will lead to accepting the event(this again matches the behavior of"!*"before the partial wildcard feature was incorporated).The per-event"cost"of each negative criterion with multiple relevant triggers is about the same as!*was in the past
edm::service::TriggerNamesService::findEndPath
size_type findEndPath(std::string const &name) const
Definition: TriggerNamesService.h:82
edm::ActivityRegistry::watchPreModuleBeginJob
void watchPreModuleBeginJob(PreModuleBeginJob::slot_type const &iSlot)
Definition: ActivityRegistry.h:354
FastTimerService::m_dqm_nproc_byls_event
TProfile * m_dqm_nproc_byls_event
Definition: FastTimerService.h:370
edm::Event::getByLabel
bool getByLabel(InputTag const &tag, Handle< PROD > &result) const
Definition: Event.h:361
FastTimerService::m_dqm_path
const std::string m_dqm_path
Definition: FastTimerService.h:302
FastTimerService::m_dqm_byluminosity_all_endpaths
TProfile * m_dqm_byluminosity_all_endpaths
Definition: FastTimerService.h:384
dbtoconf.out
tuple out
Definition: dbtoconf.py:99
FastTimerService::m_modules
std::unordered_map< std::string, ModuleInfo > m_modules
Definition: FastTimerService.h:399
FastTimerService::m_dqm_nproc_byls_postsource
TProfile * m_dqm_nproc_byls_postsource
Definition: FastTimerService.h:373
FastTimerService::m_fast_modules
ModuleMap< ModuleInfo * > m_fast_modules
Definition: FastTimerService.h:401
FastTimerService::m_enable_dqm_bymodule
const bool m_enable_dqm_bymodule
Definition: FastTimerService.h:286
FastTimerService::m_dqm_moduletime_range
const double m_dqm_moduletime_range
Definition: FastTimerService.h:297
FastTimerService::m_dqm_byluminosity_all_paths
TProfile * m_dqm_byluminosity_all_paths
Definition: FastTimerService.h:383
FastTimerService::queryModuleTime
double queryModuleTime(const edm::ModuleDescription &) const
Definition: FastTimerService.cc:1357
inter
int inter
Definition: CascadeWrapper.h:31
MonitorElement::getTH1F
TH1F * getTH1F(void) const
Definition: MonitorElement.cc:1486
FastTimerService::m_dqm_paths_exclusive_time
TProfile * m_dqm_paths_exclusive_time
Definition: FastTimerService.h:357
FastTimerService::currentModuleTime
double currentModuleTime() const
Definition: FastTimerService.cc:1336
edm::ConfigurationDescriptions::add
void add(std::string const &label, ParameterSetDescription const &psetDescription)
Definition: ConfigurationDescriptions.cc:65
FastTimerService::m_dqm_byls_all_paths
TProfile * m_dqm_byls_all_paths
Definition: FastTimerService.h:365
FastTimerService::queryPathsTime
double queryPathsTime() const
Definition: FastTimerService.cc:1419
FastTimerService::m_enable_timing_summary
const bool m_enable_timing_summary
Definition: FastTimerService.h:275
edm::HLTPathStatus::accept
bool accept() const
has this path accepted the event?
Definition: HLTPathStatus.h:63
FastTimerService::m_enable_dqm_bymoduletype
const bool m_enable_dqm_bymoduletype
Definition: FastTimerService.h:287
FastTimerService::m_timer_module
std::pair< struct timespec, struct timespec > m_timer_module
Definition: FastTimerService.h:410
FastTimerService::m_enable_dqm_summary
const bool m_enable_dqm_summary
Definition: FastTimerService.h:288
edm::ActivityRegistry::watchPostSource
void watchPostSource(PostSource::slot_type const &iSlot)
Definition: ActivityRegistry.h:89
FastTimerService::m_dqm_byls_event
TProfile * m_dqm_byls_event
Definition: FastTimerService.h:361
FastTimerService::gettime
void gettime(struct timespec &stamp) const
Definition: FastTimerService.h:417
edm::service::TriggerNamesService::getEndPath
std::string const & getEndPath(size_type const i) const
Definition: TriggerNamesService.h:81
FastTimerService::m_enable_dqm_bypath_total
const bool m_enable_dqm_bypath_total
Definition: FastTimerService.h:281
edm::service::TriggerNamesService::getTrigPaths
Strings const & getTrigPaths() const
Definition: TriggerNamesService.h:58
MonitorElement::getTProfile
TProfile * getTProfile(void) const
Definition: MonitorElement.cc:1542
FastTimerService::fillPathMap
void fillPathMap(std::string const &name, std::vector< std::string > const &modules)
Definition: FastTimerService.cc:1307
FastTimerService::m_enable_dqm_bypath_active
const bool m_enable_dqm_bypath_active
Definition: FastTimerService.h:280
FastTimerService::m_summary_events
unsigned int m_summary_events
Definition: FastTimerService.h:324
FastTimerService::postProcessPath
void postProcessPath(std::string const &, edm::HLTPathStatus const &)
Definition: FastTimerService.cc:1113
FastTimerService::m_supported_processes
const std::vector< unsigned int > m_supported_processes
Definition: FastTimerService.h:304
FastTimerService::m_dqm_byluminosity_event
TProfile * m_dqm_byluminosity_event
Definition: FastTimerService.h:379
FastTimerService::PathInfo::modules
std::vector< ModuleInfo * > modules
Definition: FastTimerService.h:176
FastTimerService::m_dqm_paths_active_time
TProfile * m_dqm_paths_active_time
Definition: FastTimerService.h:355
FastTimerService::m_dqm_luminosity_range
const double m_dqm_luminosity_range
Definition: FastTimerService.h:299
FastTimerService::m_dqm_nproc_all_endpaths
TH1F * m_dqm_nproc_all_endpaths
Definition: FastTimerService.h:351
FastTimerService::m_dqm_paths_total_time
TProfile * m_dqm_paths_total_time
Definition: FastTimerService.h:356
PhysicsTools::registry
static Interceptor::Registry registry("Interceptor")
ntuplemaker.status
tuple status
Definition: ntuplemaker.py:245
FastTimerService::m_dqm_nproc_byluminosity_interpaths
TProfile * m_dqm_nproc_byluminosity_interpaths
Definition: FastTimerService.h:394
module
Definition: vlib.h:209
FastTimerService::currentEventTime
double currentEventTime() const
Definition: FastTimerService.cc:1350
edm::ActivityRegistry::watchPreProcessPath
void watchPreProcessPath(PreProcessPath::slot_type const &iSlot)
Definition: ActivityRegistry.h:244
HcalObjRepresent::setup
void setup(std::vector< TH2F > &depth, std::string name, std::string units="")
Definition: HcalObjRepresent.h:628
FastTimerService::preProcessPath
void preProcessPath(std::string const &)
Definition: FastTimerService.cc:1071
FastTimerService::m_timer_source
std::pair< struct timespec, struct timespec > m_timer_source
Definition: FastTimerService.h:406
findQualityFiles.size
tuple size
Write out results.
Definition: findQualityFiles.py:442
FastTimerService::delta
static double delta(const struct timespec &first, const struct timespec &second)
Definition: FastTimerService.h:443
DQMStore::setCurrentFolder
void setCurrentFolder(const std::string &fullpath)
Definition: DQMStore.cc:434
FastTimerService::m_dqm_paths_interpaths
TProfile * m_dqm_paths_interpaths
Definition: FastTimerService.h:358
FastTimerService::preBeginRun
void preBeginRun(edm::RunID const &, edm::Timestamp const &)
Definition: FastTimerService.cc:233
edm::ActivityRegistry::watchPostProcessPath
void watchPostProcessPath(PostProcessPath::slot_type const &iSlot)
Definition: ActivityRegistry.h:252
edm::ActivityRegistry::watchPreBeginRun
void watchPreBeginRun(PreBeginRun::slot_type const &iSlot)
Definition: ActivityRegistry.h:180
FastTimerService::m_dqm_eventtime_range
const double m_dqm_eventtime_range
Definition: FastTimerService.h:293
FastTimerService::m_dqm_pathtime_resolution
const double m_dqm_pathtime_resolution
Definition: FastTimerService.h:296
FastTimerService::currentPathTime
double currentPathTime() const
Definition: FastTimerService.cc:1343
edm::HLTPathStatus::index
unsigned int index() const
get index of module giving the status of this path
Definition: HLTPathStatus.h:56
Generated for CMSSW Reference Manual by doxygen 1.8.5