CMS 3D CMS Logo

 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Properties Friends Macros Groups Pages
FastTimerService.cc
Go to the documentation of this file.
1 // C++ headers
2 #include <cmath>
3 #include <fstream>
4 #include <iomanip>
5 #include <iostream>
6 #include <limits>
7 #include <mutex>
8 #include <sstream>
9 #include <string>
10 #include <unordered_map>
11 #include <unordered_set>
12 
13 // boost headers
14 #include <boost/range/irange.hpp>
15 
16 // {fmt} headers
17 #include <fmt/printf.h>
18 
19 // JSON headers
20 #include <nlohmann/json.hpp>
22 
23 // CMSSW headers
41 #include "FastTimerService.h"
42 
43 using namespace std::literals;
44 
46 
47 namespace {
48 
49  // convert any std::chrono::duration to milliseconds
50  template <class Rep, class Period>
51  double ms(std::chrono::duration<Rep, Period> duration) {
52  return std::chrono::duration_cast<std::chrono::duration<double, std::milli>>(duration).count();
53  }
54 
55  // convert any boost::chrono::duration to milliseconds
56  template <class Rep, class Period>
57  double ms(boost::chrono::duration<Rep, Period> duration) {
58  return boost::chrono::duration_cast<boost::chrono::duration<double, boost::milli>>(duration).count();
59  }
60 
61  // convert a std::atomic<boost::chrono::nanoseconds::rep> to milliseconds
62  double ms(std::atomic<boost::chrono::nanoseconds::rep> const& duration) {
63  return boost::chrono::duration_cast<boost::chrono::duration<double, boost::milli>>(
64  boost::chrono::nanoseconds(duration.load()))
65  .count();
66  }
67 
68  // convert from bytes to kilobytes, rounding down
69  uint64_t kB(uint64_t bytes) { return bytes / 1024; }
70 
71  // convert from bytes to kilobytes, rounding down
72  uint64_t kB(std::atomic<uint64_t> const& bytes) { return bytes.load() / 1024; }
73 
74 } // namespace
75 
77 
78 // resources being monitored by the service
79 
80 // Resources
81 
83  : time_thread(boost::chrono::nanoseconds::zero()),
84  time_real(boost::chrono::nanoseconds::zero()),
85  allocated(0ul),
86  deallocated(0ul) {}
87 
89  time_thread = boost::chrono::nanoseconds::zero();
91  allocated = 0ul;
92  deallocated = 0ul;
93 }
94 
96  time_thread += other.time_thread;
97  time_real += other.time_real;
98  allocated += other.allocated;
99  deallocated += other.deallocated;
100  return *this;
101 }
102 
104  time_thread += boost::chrono::nanoseconds(other.time_thread.load());
105  time_real += boost::chrono::nanoseconds(other.time_real.load());
106  allocated += other.allocated.load();
107  deallocated += other.deallocated.load();
108  return *this;
109 }
110 
112  Resources result(*this);
113  result += other;
114  return result;
115 }
116 
118  Resources result(*this);
119  result += other;
120  return result;
121 }
122 
123 // AtomicResources
124 // operation on the whole object are not atomic, as the operations
125 // on the individual fields could be interleaved; however, accumulation
126 // of results should yield the correct result.
127 
129  : time_thread(0ul), time_real(0ul), allocated(0ul), deallocated(0ul) {}
130 
132  : time_thread(other.time_thread.load()),
133  time_real(other.time_real.load()),
134  allocated(other.allocated.load()),
135  deallocated(other.deallocated.load()) {}
136 
138  time_thread = 0ul;
139  time_real = 0ul;
140  allocated = 0ul;
141  deallocated = 0ul;
142 }
143 
145  time_thread = other.time_thread.load();
146  time_real = other.time_real.load();
147  allocated = other.allocated.load();
148  deallocated = other.deallocated.load();
149  return *this;
150 }
151 
153  time_thread += other.time_thread.load();
154  time_real += other.time_real.load();
155  allocated += other.allocated.load();
156  deallocated += other.deallocated.load();
157  return *this;
158 }
159 
161  time_thread += other.time_thread.count();
162  time_real += other.time_real.count();
163  allocated += other.allocated;
164  deallocated += other.deallocated;
165  return *this;
166 }
167 
169  AtomicResources result(*this);
170  result += other;
171  return result;
172 }
173 
175  return other + *this;
176 }
177 
178 // ResourcesPerModule
179 
181 
183  total.reset();
184  events = 0;
185  has_acquire = false;
186 }
187 
189  total += other.total;
190  events += other.events;
191  has_acquire = has_acquire or other.has_acquire;
192  return *this;
193 }
194 
196  ResourcesPerModule const& other) const {
197  ResourcesPerModule result(*this);
198  result += other;
199  return result;
200 }
201 
202 // ResourcesPerPath
203 
205  active.reset();
206  total.reset();
207  last = 0;
208  status = false;
209 }
210 
212  active += other.active;
213  total += other.total;
214  last = 0; // summing these makes no sense, reset them instead
215  status = false;
216  return *this;
217 }
218 
220  ResourcesPerPath result(*this);
221  result += other;
222  return result;
223 }
224 
225 // ResourcesPerProcess
226 
228  : total(), paths(process.paths_.size()), endpaths(process.endPaths_.size()) {}
229 
231  total.reset();
232  for (auto& path : paths)
233  path.reset();
234  for (auto& path : endpaths)
235  path.reset();
236 }
237 
239  ResourcesPerProcess const& other) {
240  total += other.total;
241  assert(paths.size() == other.paths.size());
242  for (unsigned int i : boost::irange(0ul, paths.size()))
243  paths[i] += other.paths[i];
244  assert(endpaths.size() == other.endpaths.size());
245  for (unsigned int i : boost::irange(0ul, endpaths.size()))
246  endpaths[i] += other.endpaths[i];
247  return *this;
248 }
249 
251  ResourcesPerProcess const& other) const {
253  result += other;
254  return result;
255 }
256 
257 // ResourcesPerJob
258 
260  std::vector<GroupOfModules> const& groups)
261  : total(), overhead(), event(), highlight(groups.size()), modules(job.size()), processes(), events(0) {
262  processes.reserve(job.processes().size());
263  for (auto const& process : job.processes())
264  processes.emplace_back(process);
265 }
266 
268  total.reset();
269  overhead.reset();
270  event.reset();
271  for (auto& module : highlight)
272  module.reset();
273  for (auto& module : modules)
274  module.reset();
275  for (auto& process : processes)
276  process.reset();
277  events = 0;
278 }
279 
281  total += other.total;
282  overhead += other.overhead;
283  event += other.event;
284  assert(highlight.size() == other.highlight.size());
285  for (unsigned int i : boost::irange(0ul, highlight.size()))
286  highlight[i] += other.highlight[i];
287  assert(modules.size() == other.modules.size());
288  for (unsigned int i : boost::irange(0ul, modules.size()))
289  modules[i] += other.modules[i];
290  assert(processes.size() == other.processes.size());
291  for (unsigned int i : boost::irange(0ul, processes.size()))
292  processes[i] += other.processes[i];
293  events += other.events;
294  return *this;
295 }
296 
298  ResourcesPerJob result(*this);
299  result += other;
300  return result;
301 }
302 
303 // per-thread measurements
304 
305 // Measurement
306 
308 
310 #ifdef DEBUG_THREAD_CONCURRENCY
311  id = std::this_thread::get_id();
312 #endif // DEBUG_THREAD_CONCURRENCY
313  time_thread = boost::chrono::thread_clock::now();
315  allocated = memory_usage::allocated();
316  deallocated = memory_usage::deallocated();
317 }
318 
320 #ifdef DEBUG_THREAD_CONCURRENCY
321  assert(std::this_thread::get_id() == id);
322 #endif // DEBUG_THREAD_CONCURRENCY
323  auto new_time_thread = boost::chrono::thread_clock::now();
324  auto new_time_real = boost::chrono::high_resolution_clock::now();
325  auto new_allocated = memory_usage::allocated();
326  auto new_deallocated = memory_usage::deallocated();
327  store.time_thread = new_time_thread - time_thread;
328  store.time_real = new_time_real - time_real;
329  store.allocated = new_allocated - allocated;
330  store.deallocated = new_deallocated - deallocated;
331  time_thread = new_time_thread;
332  time_real = new_time_real;
333  allocated = new_allocated;
334  deallocated = new_deallocated;
335 }
336 
338 #ifdef DEBUG_THREAD_CONCURRENCY
339  assert(std::this_thread::get_id() == id);
340 #endif // DEBUG_THREAD_CONCURRENCY
341  auto new_time_thread = boost::chrono::thread_clock::now();
342  auto new_time_real = boost::chrono::high_resolution_clock::now();
343  auto new_allocated = memory_usage::allocated();
344  auto new_deallocated = memory_usage::deallocated();
345  store.time_thread += new_time_thread - time_thread;
346  store.time_real += new_time_real - time_real;
347  store.allocated += new_allocated - allocated;
348  store.deallocated += new_deallocated - deallocated;
349  time_thread = new_time_thread;
350  time_real = new_time_real;
351  allocated = new_allocated;
352  deallocated = new_deallocated;
353 }
354 
356 #ifdef DEBUG_THREAD_CONCURRENCY
357  assert(std::this_thread::get_id() == id);
358 #endif // DEBUG_THREAD_CONCURRENCY
359  auto new_time_thread = boost::chrono::thread_clock::now();
360  auto new_time_real = boost::chrono::high_resolution_clock::now();
361  auto new_allocated = memory_usage::allocated();
362  auto new_deallocated = memory_usage::deallocated();
363  store.time_thread += boost::chrono::duration_cast<boost::chrono::nanoseconds>(new_time_thread - time_thread).count();
364  store.time_real += boost::chrono::duration_cast<boost::chrono::nanoseconds>(new_time_real - time_real).count();
365  store.allocated += new_allocated - allocated;
366  store.deallocated += new_deallocated - deallocated;
367  time_thread = new_time_thread;
368  time_real = new_time_real;
369  allocated = new_allocated;
370  deallocated = new_deallocated;
371 }
372 
374 
376  std::string const& name,
377  std::string const& title,
378  PlotRanges const& ranges,
379  unsigned int lumisections,
380  bool byls) {
381  int time_bins = (int)std::ceil(ranges.time_range / ranges.time_resolution);
382  int mem_bins = (int)std::ceil(ranges.memory_range / ranges.memory_resolution);
383  std::string y_title_ms = fmt::sprintf("events / %.1f ms", ranges.time_resolution);
384  std::string y_title_kB = fmt::sprintf("events / %.1f kB", ranges.memory_resolution);
385 
386  // MonitorElement::setStatOverflows(kTRUE) includes underflows and overflows in the computation of mean and RMS
387  time_thread_ =
388  booker.book1D(name + " time_thread", title + " processing time (cpu)", time_bins, 0., ranges.time_range);
389  time_thread_->setXTitle("processing time [ms]");
390  time_thread_->setYTitle(y_title_ms);
391  time_thread_->setStatOverflows(kTRUE);
392 
393  time_real_ = booker.book1D(name + " time_real", title + " processing time (real)", time_bins, 0., ranges.time_range);
394  time_real_->setXTitle("processing time [ms]");
395  time_real_->setYTitle(y_title_ms);
396  time_real_->setStatOverflows(kTRUE);
397 
399  allocated_ = booker.book1D(name + " allocated", title + " allocated memory", mem_bins, 0., ranges.memory_range);
400  allocated_->setXTitle("memory [kB]");
401  allocated_->setYTitle(y_title_kB);
402  allocated_->setStatOverflows(kTRUE);
403 
404  deallocated_ =
405  booker.book1D(name + " deallocated", title + " deallocated memory", mem_bins, 0., ranges.memory_range);
406  deallocated_->setXTitle("memory [kB]");
407  deallocated_->setYTitle(y_title_kB);
408  deallocated_->setStatOverflows(kTRUE);
409  }
410 
411  if (not byls)
412  return;
413 
414  time_thread_byls_ = booker.bookProfile(name + " time_thread_byls",
415  title + " processing time (cpu) vs. lumisection",
416  lumisections,
417  0.5,
418  lumisections + 0.5,
419  time_bins,
420  0.,
422  " ");
423  time_thread_byls_->setXTitle("lumisection");
424  time_thread_byls_->setYTitle("processing time [ms]");
425  time_thread_byls_->setStatOverflows(kTRUE);
426 
427  time_real_byls_ = booker.bookProfile(name + " time_real_byls",
428  title + " processing time (real) vs. lumisection",
429  lumisections,
430  0.5,
431  lumisections + 0.5,
432  time_bins,
433  0.,
435  " ");
436  time_real_byls_->setXTitle("lumisection");
437  time_real_byls_->setYTitle("processing time [ms]");
438  time_real_byls_->setStatOverflows(kTRUE);
439 
441  allocated_byls_ = booker.bookProfile(name + " allocated_byls",
442  title + " allocated memory vs. lumisection",
443  lumisections,
444  0.5,
445  lumisections + 0.5,
446  mem_bins,
447  0.,
449  " ");
450  allocated_byls_->setXTitle("lumisection");
451  allocated_byls_->setYTitle("memory [kB]");
452  allocated_byls_->setStatOverflows(kTRUE);
453 
454  deallocated_byls_ = booker.bookProfile(name + " deallocated_byls",
455  title + " deallocated memory vs. lumisection",
456  lumisections,
457  0.5,
458  lumisections + 0.5,
459  mem_bins,
460  0.,
462  " ");
463  deallocated_byls_->setXTitle("lumisection");
464  deallocated_byls_->setYTitle("memory [kB]");
465  deallocated_byls_->setStatOverflows(kTRUE);
466  }
467 }
468 
469 void FastTimerService::PlotsPerElement::fill(Resources const& data, unsigned int lumisection) {
470  if (time_thread_)
471  time_thread_->Fill(ms(data.time_thread));
472 
473  if (time_thread_byls_)
474  time_thread_byls_->Fill(lumisection, ms(data.time_thread));
475 
476  if (time_real_)
477  time_real_->Fill(ms(data.time_real));
478 
479  if (time_real_byls_)
480  time_real_byls_->Fill(lumisection, ms(data.time_real));
481 
482  if (allocated_)
483  allocated_->Fill(kB(data.allocated));
484 
485  if (allocated_byls_)
486  allocated_byls_->Fill(lumisection, kB(data.allocated));
487 
488  if (deallocated_)
489  deallocated_->Fill(kB(data.deallocated));
490 
491  if (deallocated_byls_)
492  deallocated_byls_->Fill(lumisection, kB(data.deallocated));
493 }
494 
495 void FastTimerService::PlotsPerElement::fill(AtomicResources const& data, unsigned int lumisection) {
496  if (time_thread_)
497  time_thread_->Fill(ms(boost::chrono::nanoseconds(data.time_thread.load())));
498 
499  if (time_thread_byls_)
500  time_thread_byls_->Fill(lumisection, ms(boost::chrono::nanoseconds(data.time_thread.load())));
501 
502  if (time_real_)
503  time_real_->Fill(ms(boost::chrono::nanoseconds(data.time_real.load())));
504 
505  if (time_real_byls_)
506  time_real_byls_->Fill(lumisection, ms(boost::chrono::nanoseconds(data.time_real.load())));
507 
508  if (allocated_)
509  allocated_->Fill(kB(data.allocated));
510 
511  if (allocated_byls_)
512  allocated_byls_->Fill(lumisection, kB(data.allocated));
513 
514  if (deallocated_)
515  deallocated_->Fill(kB(data.deallocated));
516 
517  if (deallocated_byls_)
518  deallocated_byls_->Fill(lumisection, kB(data.deallocated));
519 }
520 
522  Resources const& part,
523  unsigned int lumisection) {
524  float total;
525  float fraction;
526 
527  total = ms(data.time_thread);
528  fraction = (total > 0.) ? (ms(part.time_thread) / total) : 0.;
529  if (time_thread_)
530  time_thread_->Fill(total, fraction);
531 
532  if (time_thread_byls_)
533  time_thread_byls_->Fill(lumisection, total, fraction);
534 
535  total = ms(data.time_real);
536  fraction = (total > 0.) ? (ms(part.time_real) / total) : 0.;
537  if (time_real_)
538  time_real_->Fill(total, fraction);
539 
540  if (time_real_byls_)
541  time_real_byls_->Fill(lumisection, total, fraction);
542 
543  total = kB(data.allocated);
544  fraction = (total > 0.) ? (kB(part.allocated) / total) : 0.;
545  if (allocated_)
546  allocated_->Fill(total, fraction);
547 
548  if (allocated_byls_)
549  allocated_byls_->Fill(lumisection, total, fraction);
550 
551  total = kB(data.deallocated);
552  fraction = (total > 0.) ? (kB(part.deallocated) / total) : 0.;
553  if (deallocated_)
554  deallocated_->Fill(total, fraction);
555 
556  if (deallocated_byls_)
557  deallocated_byls_->Fill(lumisection, total, fraction);
558 }
559 
561  std::string const& prefixDir,
562  ProcessCallGraph const& job,
564  PlotRanges const& ranges,
565  unsigned int lumisections,
566  bool byls) {
567  const std::string basedir = booker.pwd();
568  booker.setCurrentFolder(basedir + "/" + prefixDir + path.name_);
569 
570  total_.book(booker, "path", path.name_, ranges, lumisections, byls);
571 
572  // MonitorElement::setStatOverflows(kTRUE) includes underflows and overflows in the computation of mean and RMS
573  unsigned int bins = path.modules_and_dependencies_.size();
574  module_counter_ = booker.book1DD("module_counter", "module counter", bins + 1, -0.5, bins + 0.5);
575  module_counter_->setYTitle("events");
576  module_counter_->setStatOverflows(kTRUE);
577  module_time_thread_total_ =
578  booker.book1DD("module_time_thread_total", "total module time (cpu)", bins, -0.5, bins - 0.5);
579  module_time_thread_total_->setYTitle("processing time [ms]");
580  module_time_thread_total_->setStatOverflows(kTRUE);
581  module_time_real_total_ =
582  booker.book1DD("module_time_real_total", "total module time (real)", bins, -0.5, bins - 0.5);
583  module_time_real_total_->setYTitle("processing time [ms]");
584  module_time_real_total_->setStatOverflows(kTRUE);
586  module_allocated_total_ =
587  booker.book1DD("module_allocated_total", "total allocated memory", bins, -0.5, bins - 0.5);
588  module_allocated_total_->setYTitle("memory [kB]");
589  module_allocated_total_->setStatOverflows(kTRUE);
590  module_deallocated_total_ =
591  booker.book1DD("module_deallocated_total", "total deallocated memory", bins, -0.5, bins - 0.5);
592  module_deallocated_total_->setYTitle("memory [kB]");
593  module_deallocated_total_->setStatOverflows(kTRUE);
594  }
595  for (unsigned int bin : boost::irange(0u, bins)) {
596  auto const& module = job[path.modules_and_dependencies_[bin]];
597  std::string const& label =
598  module.scheduled_ ? module.module_.moduleLabel() : module.module_.moduleLabel() + " (unscheduled)";
599  module_counter_->setBinLabel(bin + 1, label);
600  module_time_thread_total_->setBinLabel(bin + 1, label);
601  module_time_real_total_->setBinLabel(bin + 1, label);
603  module_allocated_total_->setBinLabel(bin + 1, label);
604  module_deallocated_total_->setBinLabel(bin + 1, label);
605  }
606  }
607  module_counter_->setBinLabel(bins + 1, "");
608 
609  booker.setCurrentFolder(basedir);
610 }
611 
613  ResourcesPerJob const& data,
614  ResourcesPerPath const& path,
615  unsigned int ls) {
616  // fill the total path time
617  total_.fill(path.total, ls);
618 
619  // fill the modules that actually ran and the total time spent in each od them
620  for (unsigned int i = 0; i < path.last; ++i) {
621  auto const& module = data.modules[description.modules_and_dependencies_[i]];
622  if (module_counter_)
623  module_counter_->Fill(i);
624 
625  if (module_time_thread_total_)
626  module_time_thread_total_->Fill(i, ms(module.total.time_thread));
627 
628  if (module_time_real_total_)
629  module_time_real_total_->Fill(i, ms(module.total.time_real));
630 
631  if (module_allocated_total_)
632  module_allocated_total_->Fill(i, kB(module.total.allocated));
633 
634  if (module_deallocated_total_)
635  module_deallocated_total_->Fill(i, kB(module.total.deallocated));
636  }
637  if (module_counter_ and path.status)
638  module_counter_->Fill(path.last);
639 }
640 
642  : event_(), paths_(process.paths_.size()), endpaths_(process.endPaths_.size()) {}
643 
645  ProcessCallGraph const& job,
647  PlotRanges const& event_ranges,
648  PlotRanges const& path_ranges,
649  unsigned int lumisections,
650  bool bypath,
651  bool byls) {
652  const std::string basedir = booker.pwd();
653  event_.book(booker, "process " + process.name_, "process " + process.name_, event_ranges, lumisections, byls);
654  if (bypath) {
655  booker.setCurrentFolder(basedir + "/process " + process.name_ + " paths");
656  for (unsigned int id : boost::irange(0ul, paths_.size())) {
657  paths_[id].book(booker, "path ", job, process.paths_[id], path_ranges, lumisections, byls);
658  }
659  for (unsigned int id : boost::irange(0ul, endpaths_.size())) {
660  endpaths_[id].book(booker, "endpath ", job, process.endPaths_[id], path_ranges, lumisections, byls);
661  }
662  booker.setCurrentFolder(basedir);
663  }
664 }
665 
667  ResourcesPerJob const& data,
669  unsigned int ls) {
670  // fill process event plots
671  event_.fill(process.total, ls);
672 
673  // fill all paths plots
674  for (unsigned int id : boost::irange(0ul, paths_.size()))
675  paths_[id].fill(description.paths_[id], data, process.paths[id], ls);
676 
677  // fill all endpaths plots
678  for (unsigned int id : boost::irange(0ul, endpaths_.size()))
679  endpaths_[id].fill(description.endPaths_[id], data, process.endpaths[id], ls);
680 }
681 
682 FastTimerService::PlotsPerJob::PlotsPerJob(ProcessCallGraph const& job, std::vector<GroupOfModules> const& groups)
683  : event_(), event_ex_(), overhead_(), highlight_(groups.size()), modules_(job.size()), processes_() {
684  processes_.reserve(job.processes().size());
685  for (auto const& process : job.processes())
686  processes_.emplace_back(process);
687 }
688 
690  ProcessCallGraph const& job,
691  std::vector<GroupOfModules> const& groups,
692  PlotRanges const& event_ranges,
693  PlotRanges const& path_ranges,
694  PlotRanges const& module_ranges,
695  unsigned int lumisections,
696  bool bymodule,
697  bool bypath,
698  bool byls,
699  bool transitions) {
700  const std::string basedir = booker.pwd();
701 
702  // event summary plots
703  event_.book(booker, "event", "Event", event_ranges, lumisections, byls);
704 
705  event_ex_.book(booker, "explicit", "Event (explicit)", event_ranges, lumisections, byls);
706 
707  overhead_.book(booker, "overhead", "Overhead", event_ranges, lumisections, byls);
708 
709  modules_[job.source().id()].book(booker, "source", "Source", module_ranges, lumisections, byls);
710 
711  if (transitions) {
712  lumi_.book(booker, "lumi", "LumiSection transitions", event_ranges, lumisections, byls);
713 
714  run_.book(booker, "run", "Run transtions", event_ranges, lumisections, false);
715  }
716 
717  // plot the time spent in few given groups of modules
718  for (unsigned int group : boost::irange(0ul, groups.size())) {
719  auto const& label = groups[group].label;
720  highlight_[group].book(booker, "highlight " + label, "Highlight " + label, event_ranges, lumisections, byls);
721  }
722 
723  // plots per subprocess (event, modules, paths and endpaths)
724  for (unsigned int pid : boost::irange(0ul, job.processes().size())) {
725  auto const& process = job.processDescription(pid);
726  processes_[pid].book(booker, job, process, event_ranges, path_ranges, lumisections, bypath, byls);
727 
728  if (bymodule) {
729  booker.setCurrentFolder(basedir + "/process " + process.name_ + " modules");
730  for (unsigned int id : process.modules_) {
731  auto const& module_name = job.module(id).moduleLabel();
732  modules_[id].book(booker, module_name, module_name, module_ranges, lumisections, byls);
733  }
734  booker.setCurrentFolder(basedir);
735  }
736  }
737 }
738 
740  // fill total event plots
741  event_.fill(data.total, ls);
742  event_ex_.fill(data.event, ls);
743  overhead_.fill(data.overhead, ls);
744 
745  // fill highltight plots
746  for (unsigned int group : boost::irange(0ul, highlight_.size()))
747  highlight_[group].fill_fraction(data.total, data.highlight[group], ls);
748 
749  // fill modules plots
750  for (unsigned int id : boost::irange(0ul, modules_.size()))
751  modules_[id].fill(data.modules[id].total, ls);
752 
753  for (unsigned int pid : boost::irange(0ul, processes_.size()))
754  processes_[pid].fill(job.processDescription(pid), data, data.processes[pid], ls);
755 }
756 
758  // fill run transition plots
759  run_.fill(data, 0);
760 }
761 
763  // fill lumisection transition plots
764  lumi_.fill(data, ls);
765 }
766 
768 
770  : // configuration
771  callgraph_(),
772  // job configuration
774  concurrent_runs_(0),
777  print_event_summary_(config.getUntrackedParameter<bool>("printEventSummary")),
778  print_run_summary_(config.getUntrackedParameter<bool>("printRunSummary")),
779  print_job_summary_(config.getUntrackedParameter<bool>("printJobSummary")),
780  // JSON configuration
781  //write_json_per_event_(config.getUntrackedParameter<bool>("writeJSONByEvent")),
782  //write_json_per_ls_(config.getUntrackedParameter<bool>("writeJSONByLumiSection")),
783  //write_json_per_run_(config.getUntrackedParameter<bool>("writeJSONByRun")),
784  write_json_summary_(config.getUntrackedParameter<bool>("writeJSONSummary")),
785  json_filename_(config.getUntrackedParameter<std::string>("jsonFileName")),
786  // DQM configuration
787  enable_dqm_(config.getUntrackedParameter<bool>("enableDQM")),
788  enable_dqm_bymodule_(config.getUntrackedParameter<bool>("enableDQMbyModule")),
789  enable_dqm_bypath_(config.getUntrackedParameter<bool>("enableDQMbyPath")),
790  enable_dqm_byls_(config.getUntrackedParameter<bool>("enableDQMbyLumiSection")),
791  enable_dqm_bynproc_(config.getUntrackedParameter<bool>("enableDQMbyProcesses")),
792  enable_dqm_transitions_(config.getUntrackedParameter<bool>("enableDQMTransitions")),
793  dqm_event_ranges_({config.getUntrackedParameter<double>("dqmTimeRange"), // ms
794  config.getUntrackedParameter<double>("dqmTimeResolution"), // ms
795  config.getUntrackedParameter<double>("dqmMemoryRange"), // kB
796  config.getUntrackedParameter<double>("dqmMemoryResolution")}), // kB
797  dqm_path_ranges_({config.getUntrackedParameter<double>("dqmPathTimeRange"), // ms
798  config.getUntrackedParameter<double>("dqmPathTimeResolution"), // ms
799  config.getUntrackedParameter<double>("dqmPathMemoryRange"), // kB
800  config.getUntrackedParameter<double>("dqmPathMemoryResolution")}), // kB
801  dqm_module_ranges_({config.getUntrackedParameter<double>("dqmModuleTimeRange"), // ms
802  config.getUntrackedParameter<double>("dqmModuleTimeResolution"), // ms
803  config.getUntrackedParameter<double>("dqmModuleMemoryRange"), // kB
804  config.getUntrackedParameter<double>("dqmModuleMemoryResolution")}), // kB
805  dqm_lumisections_range_(config.getUntrackedParameter<unsigned int>("dqmLumiSectionsRange")),
806  dqm_path_(config.getUntrackedParameter<std::string>("dqmPath")),
807  // highlight configuration
808  highlight_module_psets_(config.getUntrackedParameter<std::vector<edm::ParameterSet>>("highlightModules")),
809  highlight_modules_(highlight_module_psets_.size()) // filled in postBeginJob()
810 {
811  // start observing when a thread enters or leaves the TBB global thread arena
812  tbb::task_scheduler_observer::observe();
813 
814  // register EDM call backs
815  registry.watchPreallocate(this, &FastTimerService::preallocate);
816  registry.watchPreBeginJob(this, &FastTimerService::preBeginJob);
817  registry.watchPostBeginJob(this, &FastTimerService::postBeginJob);
818  registry.watchPostEndJob(this, &FastTimerService::postEndJob);
819  registry.watchPreGlobalBeginRun(this, &FastTimerService::preGlobalBeginRun);
820  //registry.watchPostGlobalBeginRun( this, & FastTimerService::postGlobalBeginRun );
821  //registry.watchPreGlobalEndRun( this, & FastTimerService::preGlobalEndRun );
822  registry.watchPostGlobalEndRun(this, &FastTimerService::postGlobalEndRun);
823  registry.watchPreStreamBeginRun(this, &FastTimerService::preStreamBeginRun);
824  //registry.watchPostStreamBeginRun( this, & FastTimerService::postStreamBeginRun );
825  //registry.watchPreStreamEndRun( this, & FastTimerService::preStreamEndRun );
826  registry.watchPostStreamEndRun(this, &FastTimerService::postStreamEndRun);
827  registry.watchPreGlobalBeginLumi(this, &FastTimerService::preGlobalBeginLumi);
828  //registry.watchPostGlobalBeginLumi( this, & FastTimerService::postGlobalBeginLumi );
829  //registry.watchPreGlobalEndLumi( this, & FastTimerService::preGlobalEndLumi );
830  registry.watchPostGlobalEndLumi(this, &FastTimerService::postGlobalEndLumi);
831  registry.watchPreStreamBeginLumi(this, &FastTimerService::preStreamBeginLumi);
832  //registry.watchPostStreamBeginLumi( this, & FastTimerService::postStreamBeginLumi );
833  //registry.watchPreStreamEndLumi( this, & FastTimerService::preStreamEndLumi );
834  registry.watchPostStreamEndLumi(this, &FastTimerService::postStreamEndLumi);
835  registry.watchPreEvent(this, &FastTimerService::preEvent);
836  registry.watchPostEvent(this, &FastTimerService::postEvent);
837  registry.watchPrePathEvent(this, &FastTimerService::prePathEvent);
838  registry.watchPostPathEvent(this, &FastTimerService::postPathEvent);
839  registry.watchPreSourceConstruction(this, &FastTimerService::preSourceConstruction);
840  //registry.watchPostSourceConstruction( this, & FastTimerService::postSourceConstruction);
841  registry.watchPreSourceRun(this, &FastTimerService::preSourceRun);
842  registry.watchPostSourceRun(this, &FastTimerService::postSourceRun);
843  registry.watchPreSourceLumi(this, &FastTimerService::preSourceLumi);
844  registry.watchPostSourceLumi(this, &FastTimerService::postSourceLumi);
845  registry.watchPreSourceEvent(this, &FastTimerService::preSourceEvent);
846  registry.watchPostSourceEvent(this, &FastTimerService::postSourceEvent);
847  //registry.watchPreModuleConstruction( this, & FastTimerService::preModuleConstruction);
848  //registry.watchPostModuleConstruction( this, & FastTimerService::postModuleConstruction);
849  //registry.watchPreModuleBeginJob( this, & FastTimerService::preModuleBeginJob );
850  //registry.watchPostModuleBeginJob( this, & FastTimerService::postModuleBeginJob );
851  //registry.watchPreModuleEndJob( this, & FastTimerService::preModuleEndJob );
852  //registry.watchPostModuleEndJob( this, & FastTimerService::postModuleEndJob );
853  //registry.watchPreModuleBeginStream( this, & FastTimerService::preModuleBeginStream );
854  //registry.watchPostModuleBeginStream( this, & FastTimerService::postModuleBeginStream );
855  //registry.watchPreModuleEndStream( this, & FastTimerService::preModuleEndStream );
856  //registry.watchPostModuleEndStream( this, & FastTimerService::postModuleEndStream );
857  registry.watchPreModuleGlobalBeginRun(this, &FastTimerService::preModuleGlobalBeginRun);
858  registry.watchPostModuleGlobalBeginRun(this, &FastTimerService::postModuleGlobalBeginRun);
859  registry.watchPreModuleGlobalEndRun(this, &FastTimerService::preModuleGlobalEndRun);
860  registry.watchPostModuleGlobalEndRun(this, &FastTimerService::postModuleGlobalEndRun);
861  registry.watchPreModuleGlobalBeginLumi(this, &FastTimerService::preModuleGlobalBeginLumi);
862  registry.watchPostModuleGlobalBeginLumi(this, &FastTimerService::postModuleGlobalBeginLumi);
863  registry.watchPreModuleGlobalEndLumi(this, &FastTimerService::preModuleGlobalEndLumi);
864  registry.watchPostModuleGlobalEndLumi(this, &FastTimerService::postModuleGlobalEndLumi);
865  registry.watchPreModuleStreamBeginRun(this, &FastTimerService::preModuleStreamBeginRun);
866  registry.watchPostModuleStreamBeginRun(this, &FastTimerService::postModuleStreamBeginRun);
867  registry.watchPreModuleStreamEndRun(this, &FastTimerService::preModuleStreamEndRun);
868  registry.watchPostModuleStreamEndRun(this, &FastTimerService::postModuleStreamEndRun);
869  registry.watchPreModuleStreamBeginLumi(this, &FastTimerService::preModuleStreamBeginLumi);
870  registry.watchPostModuleStreamBeginLumi(this, &FastTimerService::postModuleStreamBeginLumi);
871  registry.watchPreModuleStreamEndLumi(this, &FastTimerService::preModuleStreamEndLumi);
872  registry.watchPostModuleStreamEndLumi(this, &FastTimerService::postModuleStreamEndLumi);
873  //registry.watchPreModuleEventPrefetching( this, & FastTimerService::preModuleEventPrefetching );
874  //registry.watchPostModuleEventPrefetching( this, & FastTimerService::postModuleEventPrefetching );
875  registry.watchPreModuleEventAcquire(this, &FastTimerService::preModuleEventAcquire);
876  registry.watchPostModuleEventAcquire(this, &FastTimerService::postModuleEventAcquire);
877  registry.watchPreModuleEvent(this, &FastTimerService::preModuleEvent);
878  registry.watchPostModuleEvent(this, &FastTimerService::postModuleEvent);
879  registry.watchPreModuleEventDelayedGet(this, &FastTimerService::preModuleEventDelayedGet);
880  registry.watchPostModuleEventDelayedGet(this, &FastTimerService::postModuleEventDelayedGet);
881  //registry.watchPreEventReadFromSource( this, & FastTimerService::preEventReadFromSource );
882  //registry.watchPostEventReadFromSource( this, & FastTimerService::postEventReadFromSource );
883 }
884 
885 void FastTimerService::ignoredSignal(const std::string& signal) const {
886  LogDebug("FastTimerService") << "The FastTimerService received is currently not monitoring the signal \"" << signal
887  << "\".\n";
888 }
889 
891  // warn about each signal only once per job
892  if (unsupported_signals_.insert(signal).second)
893  edm::LogWarning("FastTimerService") << "The FastTimerService received the unsupported signal \"" << signal
894  << "\".\n"
895  << "Please report how to reproduce the issue to cms-hlt@cern.ch .";
896 }
897 
899  ignoredSignal(__func__);
900 
901  // reset the run counters only during the main process being run
902  if (isFirstSubprocess(gc)) {
903  auto index = gc.runIndex();
904  subprocess_global_run_check_[index] = 0;
905  run_transition_[index].reset();
906  run_summary_[index].reset();
907 
908  // book the DQM plots
909  if (enable_dqm_) {
910  // define a callback to book the MonitorElements
911  auto bookTransactionCallback = [&, this](dqm::reco::DQMStore::IBooker& booker, dqm::reco::DQMStore::IGetter&) {
912  auto scope = dqm::reco::DQMStore::IBooker::UseRunScope(booker);
913  // we should really do this, but only DQMStore is allowed to touch it
914  // We could move to postGlobalBeginRun, then the DQMStore has sure set it up.
915  //booker.setRunLumi(gc.luminosityBlockID());
916  booker.setCurrentFolder(dqm_path_);
917  plots_->book(booker,
918  callgraph_,
920  dqm_event_ranges_,
924  enable_dqm_bymodule_,
925  enable_dqm_bypath_,
926  enable_dqm_byls_,
927  enable_dqm_transitions_);
928  };
929 
930  // book MonitorElements for this stream
931  edm::Service<dqm::legacy::DQMStore>()->meBookerGetter(bookTransactionCallback);
932  }
933  }
934 }
935 
936 void FastTimerService::postGlobalBeginRun(edm::GlobalContext const& gc) { ignoredSignal(__func__); }
937 
938 void FastTimerService::preStreamBeginRun(edm::StreamContext const& sc) { ignoredSignal(__func__); }
939 
941  concurrent_lumis_ = bounds.maxNumberOfConcurrentLuminosityBlocks();
942  concurrent_runs_ = bounds.maxNumberOfConcurrentRuns();
943  concurrent_streams_ = bounds.maxNumberOfStreams();
944  concurrent_threads_ = bounds.maxNumberOfThreads();
945 
946  if (enable_dqm_bynproc_)
947  dqm_path_ += fmt::sprintf(
948  "/Running on %s with %d streams on %d threads", processor_model, concurrent_streams_, concurrent_threads_);
949 
950  // clean characters that are deemed unsafe for DQM
951  // see the definition of `s_safe` in DQMServices/Core/src/DQMStore.cc
952  auto safe_for_dqm = "/ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789-+=_()# "s;
953  for (auto& c : dqm_path_)
954  if (safe_for_dqm.find(c) == std::string::npos)
955  c = '_';
956 
957  // allocate atomic variables to keep track of the completion of each step, process by process
958  subprocess_event_check_ = std::make_unique<std::atomic<unsigned int>[]>(concurrent_streams_);
959  for (unsigned int i = 0; i < concurrent_streams_; ++i)
960  subprocess_event_check_[i] = 0;
961  subprocess_global_run_check_ = std::make_unique<std::atomic<unsigned int>[]>(concurrent_runs_);
962  for (unsigned int i = 0; i < concurrent_runs_; ++i)
963  subprocess_global_run_check_[i] = 0;
964  subprocess_global_lumi_check_ = std::make_unique<std::atomic<unsigned int>[]>(concurrent_lumis_);
965  for (unsigned int i = 0; i < concurrent_lumis_; ++i)
966  subprocess_global_lumi_check_[i] = 0;
967 
968  // allocate buffers to keep track of the resources spent in the lumi and run transitions
969  lumi_transition_.resize(concurrent_lumis_);
970  run_transition_.resize(concurrent_runs_);
971 }
972 
974  callgraph_.preSourceConstruction(module);
975 }
976 
978  edm::ProcessContext const& context) {
979  callgraph_.preBeginJob(pathsAndConsumes, context);
980 }
981 
983  unsigned int modules = callgraph_.size();
984 
985  // module highlights
986  for (unsigned int group : boost::irange(0ul, highlight_module_psets_.size())) {
987  // copy and sort for faster search via std::binary_search
988  auto labels = highlight_module_psets_[group].getUntrackedParameter<std::vector<std::string>>("modules");
989  std::sort(labels.begin(), labels.end());
990 
991  highlight_modules_[group].label = highlight_module_psets_[group].getUntrackedParameter<std::string>("label");
992  highlight_modules_[group].modules.reserve(labels.size());
993  // convert the module labels in module ids
994  for (unsigned int i = 0; i < modules; ++i) {
995  auto const& label = callgraph_.module(i).moduleLabel();
996  if (std::binary_search(labels.begin(), labels.end(), label))
997  highlight_modules_[group].modules.push_back(i);
998  }
999  }
1000  highlight_module_psets_.clear();
1001 
1002  // allocate the resource counters for each stream, process, path and module
1004  streams_.resize(concurrent_streams_, temp);
1005  run_summary_.resize(concurrent_runs_, temp);
1006  job_summary_ = temp;
1007 
1008  // check that the DQMStore service is available
1009  if (enable_dqm_ and not edm::Service<dqm::legacy::DQMStore>().isAvailable()) {
1010  // the DQMStore is not available, disable all DQM plots
1011  enable_dqm_ = false;
1012  edm::LogWarning("FastTimerService") << "The DQMStore is not avalable, the DQM plots will not be generated";
1013  }
1014 
1015  // allocate the structures to hold pointers to the DQM plots
1016  if (enable_dqm_) {
1017  plots_ = std::make_unique<PlotsPerJob>(callgraph_, highlight_modules_);
1018  }
1019 }
1020 
1021 void FastTimerService::postStreamBeginRun(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1022 
1023 void FastTimerService::preStreamEndRun(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1024 
1025 void FastTimerService::postStreamEndRun(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1026 
1028  ignoredSignal(__func__);
1029 
1030  // reset the lumi counters only during the main process being run
1031  if (isFirstSubprocess(gc)) {
1032  auto index = gc.luminosityBlockIndex();
1033  subprocess_global_lumi_check_[index] = 0;
1034  lumi_transition_[index].reset();
1035  }
1036 }
1037 
1038 void FastTimerService::postGlobalBeginLumi(edm::GlobalContext const& gc) { ignoredSignal(__func__); }
1039 
1040 void FastTimerService::preGlobalEndLumi(edm::GlobalContext const& gc) { ignoredSignal(__func__); }
1041 
1043  ignoredSignal(__func__);
1044 
1045  // handle the summaries only after the last subprocess has run
1046  auto index = gc.luminosityBlockIndex();
1047  bool last = isLastSubprocess(subprocess_global_lumi_check_[index]);
1048  if (not last)
1049  return;
1050 
1051  edm::LogVerbatim out("FastReport");
1052  auto const& label =
1053  fmt::sprintf("run %d, lumisection %d", gc.luminosityBlockID().run(), gc.luminosityBlockID().luminosityBlock());
1054  printTransition(out, lumi_transition_[index], label);
1055 
1056  if (enable_dqm_transitions_) {
1057  plots_->fill_lumi(lumi_transition_[index], gc.luminosityBlockID().luminosityBlock());
1058  }
1059 }
1060 
1061 void FastTimerService::preStreamBeginLumi(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1062 
1063 void FastTimerService::postStreamBeginLumi(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1064 
1065 void FastTimerService::preStreamEndLumi(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1066 
1067 void FastTimerService::postStreamEndLumi(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1068 
1069 void FastTimerService::preGlobalEndRun(edm::GlobalContext const& gc) { ignoredSignal(__func__); }
1070 
1072  ignoredSignal(__func__);
1073 
1074  // handle the summaries only after the last subprocess has run
1075  auto index = gc.runIndex();
1076  bool last = isLastSubprocess(subprocess_global_run_check_[index]);
1077  if (not last)
1078  return;
1079 
1080  edm::LogVerbatim out("FastReport");
1081  auto const& label = fmt::sprintf("Run %d", gc.luminosityBlockID().run());
1082  if (print_run_summary_) {
1083  printSummary(out, run_summary_[index], label);
1084  }
1085  printTransition(out, run_transition_[index], label);
1086 
1087  if (enable_dqm_transitions_) {
1088  plots_->fill_run(run_transition_[index]);
1089  }
1090 }
1091 
1092 void FastTimerService::preSourceRun(edm::RunIndex index) { thread().measure_and_accumulate(overhead_); }
1093 
1094 void FastTimerService::postSourceRun(edm::RunIndex index) { thread().measure_and_accumulate(run_transition_[index]); }
1095 
1096 void FastTimerService::preSourceLumi(edm::LuminosityBlockIndex index) { thread().measure_and_accumulate(overhead_); }
1097 
1099  thread().measure_and_accumulate(lumi_transition_[index]);
1100 }
1101 
1103  // stop observing to avoid potential race conditions at exit
1104  tbb::task_scheduler_observer::observe(false);
1105  guard_.finalize();
1106  if (print_job_summary_) {
1107  edm::LogVerbatim out("FastReport");
1108  printSummary(out, job_summary_, "Job");
1109  }
1110  if (write_json_summary_) {
1111  writeSummaryJSON(job_summary_, json_filename_);
1112  }
1113 }
1114 
1115 template <typename T>
1117  out << "FastReport ";
1118  if (label.size() < 60)
1119  for (unsigned int i = (60 - label.size()) / 2; i > 0; --i)
1120  out << '-';
1121  out << ' ' << label << " Summary ";
1122  if (label.size() < 60)
1123  for (unsigned int i = (59 - label.size()) / 2; i > 0; --i)
1124  out << '-';
1125  out << '\n';
1126 }
1127 
1128 template <typename T>
1130  out << "FastReport CPU time Real time Allocated Deallocated " << label << "\n";
1131  // FastReport ########.# ms ########.# ms +######### kB -######### kB ...
1132 }
1133 
1134 template <typename T>
1136  out << fmt::sprintf("FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1137  ms(data.time_thread),
1138  ms(data.time_real),
1139  +static_cast<int64_t>(kB(data.allocated)),
1140  -static_cast<int64_t>(kB(data.deallocated)),
1141  label);
1142 }
1143 
1144 template <typename T>
1146  out << fmt::sprintf("FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1147  ms(boost::chrono::nanoseconds(data.time_thread.load())),
1148  ms(boost::chrono::nanoseconds(data.time_real.load())),
1149  +static_cast<int64_t>(kB(data.allocated)),
1150  -static_cast<int64_t>(kB(data.deallocated)),
1151  label);
1152 }
1153 
1154 template <typename T>
1156  printHeader(out, "Event");
1157  printEventHeader(out, "Modules");
1158  auto const& source_d = callgraph_.source();
1159  auto const& source = data.modules[source_d.id()];
1160  printEventLine(out, source.total, source_d.moduleLabel());
1161  for (unsigned int i = 0; i < callgraph_.processes().size(); ++i) {
1162  auto const& proc_d = callgraph_.processDescription(i);
1163  auto const& proc = data.processes[i];
1164  printEventLine(out, proc.total, "process " + proc_d.name_);
1165  for (unsigned int m : proc_d.modules_) {
1166  auto const& module_d = callgraph_.module(m);
1167  auto const& module = data.modules[m];
1168  printEventLine(out, module.total, " " + module_d.moduleLabel());
1169  }
1170  }
1171  printEventLine(out, data.total, "total");
1172  out << '\n';
1173  printEventHeader(out, "Processes and Paths");
1174  printEventLine(out, source.total, source_d.moduleLabel());
1175  for (unsigned int i = 0; i < callgraph_.processes().size(); ++i) {
1176  auto const& proc_d = callgraph_.processDescription(i);
1177  auto const& proc = data.processes[i];
1178  printEventLine(out, proc.total, "process " + proc_d.name_);
1179  for (unsigned int p = 0; p < proc.paths.size(); ++p) {
1180  auto const& name = proc_d.paths_[p].name_;
1181  auto const& path = proc.paths[p];
1182  printEventLine(out, path.active, name + " (only scheduled modules)");
1183  printEventLine(out, path.total, name + " (including dependencies)");
1184  }
1185  for (unsigned int p = 0; p < proc.endpaths.size(); ++p) {
1186  auto const& name = proc_d.endPaths_[p].name_;
1187  auto const& path = proc.endpaths[p];
1188  printEventLine(out, path.active, name + " (only scheduled modules)");
1189  printEventLine(out, path.total, name + " (including dependencies)");
1190  }
1191  }
1192  printEventLine(out, data.total, "total");
1193  out << '\n';
1194  for (unsigned int group : boost::irange(0ul, highlight_modules_.size())) {
1195  printEventHeader(out, "Highlighted modules");
1196  for (unsigned int m : highlight_modules_[group].modules) {
1197  auto const& module_d = callgraph_.module(m);
1198  auto const& module = data.modules[m];
1199  printEventLine(out, module.total, " " + module_d.moduleLabel());
1200  }
1201  printEventLine(out, data.highlight[group], highlight_modules_[group].label);
1202  out << '\n';
1203  }
1204 }
1205 
1206 template <typename T>
1207 void FastTimerService::printSummaryHeader(T& out, std::string const& label, bool detailed) const {
1208  // clang-format off
1209  if (detailed)
1210  out << "FastReport CPU time avg. when run Real time avg. when run Alloc. avg. when run Dealloc. avg. when run ";
1211  // FastReport ########.# ms ########.# ms ########.# ms ########.# ms +######### kB +######### kB -######### kB -######### kB ...
1212  else
1213  out << "FastReport CPU time avg. Real time avg. Alloc. avg. Dealloc. avg. ";
1214  // FastReport ########.# ms ########.# ms +######### kB -######### kB ...
1215  out << label << '\n';
1216  // clang-format on
1217 }
1218 
1219 template <typename T>
1221  // clang-format off
1222  out << "FastReport CPU time sched. / depend. Real time sched. / depend. Alloc. sched. / depend. Dealloc. sched. / depend. ";
1223  // FastReport ########.# ms ########.# ms ########.# ms ########.# ms +######### kB +######### kB -######### kB -######### kB ...
1224  out << label << '\n';
1225  // clang-format on
1226 }
1227 
1228 template <typename T>
1230  out << fmt::sprintf(
1231  // clang-format off
1232  "FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1233  // clang-format on
1234  (events ? ms(data.time_thread) / events : 0),
1235  (events ? ms(data.time_real) / events : 0),
1236  (events ? +static_cast<int64_t>(kB(data.allocated) / events) : 0),
1237  (events ? -static_cast<int64_t>(kB(data.deallocated) / events) : 0),
1238  label);
1239 }
1240 
1241 template <typename T>
1243  T& out, AtomicResources const& data, uint64_t events, uint64_t active, std::string const& label) const {
1244  out << fmt::sprintf(
1245  // clang-format off
1246  "FastReport %10.1f ms %10.1f ms %10.1f ms %10.1f ms %+10d kB %+10d kB %+10d kB %+10d kB %s\n",
1247  // clang-format on
1248  (events ? ms(data.time_thread) / events : 0),
1249  (active ? ms(data.time_thread) / active : 0),
1250  (events ? ms(data.time_real) / events : 0),
1251  (active ? ms(data.time_real) / active : 0),
1252  (events ? +static_cast<int64_t>(kB(data.allocated) / events) : 0),
1253  (active ? +static_cast<int64_t>(kB(data.allocated) / active) : 0),
1254  (events ? -static_cast<int64_t>(kB(data.deallocated) / events) : 0),
1255  (active ? -static_cast<int64_t>(kB(data.deallocated) / active) : 0),
1256  label);
1257 }
1258 
1259 template <typename T>
1261  AtomicResources const& data,
1262  uint64_t events,
1263  std::string const& label) const {
1264  out << fmt::sprintf(
1265  // clang-format off
1266  "FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1267  // clang-format on
1268  (events ? ms(data.time_thread) / events : 0),
1269  (events ? ms(data.time_real) / events : 0),
1270  (events ? +static_cast<int64_t>(kB(data.allocated) / events) : 0),
1271  (events ? -static_cast<int64_t>(kB(data.deallocated) / events) : 0),
1272  label);
1273 }
1274 
1275 template <typename T>
1277  T& out, Resources const& data, uint64_t events, uint64_t active, std::string const& label) const {
1278  out << fmt::sprintf(
1279  "FastReport %10.1f ms %10.1f ms %10.1f ms %10.1f ms %+10d kB %+10d kB %+10d kB %+10d kB %s\n",
1280  (events ? ms(data.time_thread) / events : 0),
1281  (active ? ms(data.time_thread) / active : 0),
1282  (events ? ms(data.time_real) / events : 0),
1283  (active ? ms(data.time_real) / active : 0),
1284  (events ? +static_cast<int64_t>(kB(data.allocated) / events) : 0),
1285  (active ? +static_cast<int64_t>(kB(data.allocated) / active) : 0),
1286  (events ? -static_cast<int64_t>(kB(data.deallocated) / events) : 0),
1287  (active ? -static_cast<int64_t>(kB(data.deallocated) / active) : 0),
1288  label);
1289 }
1290 
1291 template <typename T>
1293  T& out, Resources const& data, Resources const& total, uint64_t events, std::string const& label) const {
1294  out << fmt::sprintf(
1295  "FastReport %10.1f ms %10.1f ms %10.1f ms %10.1f ms %+10d kB %+10d kB %+10d kB %+10d kB %s\n",
1296  (events ? ms(data.time_thread) / events : 0),
1297  (events ? ms(total.time_thread) / events : 0),
1298  (events ? ms(data.time_real) / events : 0),
1299  (events ? ms(total.time_real) / events : 0),
1300  (events ? +static_cast<int64_t>(kB(data.allocated) / events) : 0),
1301  (events ? +static_cast<int64_t>(kB(total.allocated) / events) : 0),
1302  (events ? -static_cast<int64_t>(kB(data.deallocated) / events) : 0),
1303  (events ? -static_cast<int64_t>(kB(total.deallocated) / events) : 0),
1304  label);
1305 }
1306 
1307 template <typename T>
1309  printHeader(out, label);
1310  printSummaryHeader(out, "Modules", true);
1311  auto const& source_d = callgraph_.source();
1312  auto const& source = data.modules[source_d.id()];
1313  printSummaryLine(out, source.total, data.events, source.events, source_d.moduleLabel());
1314  for (unsigned int i = 0; i < callgraph_.processes().size(); ++i) {
1315  auto const& proc_d = callgraph_.processDescription(i);
1316  auto const& proc = data.processes[i];
1317  printSummaryLine(out, proc.total, data.events, "process " + proc_d.name_);
1318  for (unsigned int m : proc_d.modules_) {
1319  auto const& module_d = callgraph_.module(m);
1320  auto const& module = data.modules[m];
1321  printSummaryLine(out, module.total, data.events, module.events, " " + module_d.moduleLabel());
1322  }
1323  }
1324  printSummaryLine(out, data.total, data.events, "total");
1325  printSummaryLine(out, data.overhead, data.events, "other");
1326  out << '\n';
1327  printPathSummaryHeader(out, "Processes and Paths");
1328  printSummaryLine(out, source.total, data.events, source_d.moduleLabel());
1329  for (unsigned int i = 0; i < callgraph_.processes().size(); ++i) {
1330  auto const& proc_d = callgraph_.processDescription(i);
1331  auto const& proc = data.processes[i];
1332  printSummaryLine(out, proc.total, data.events, "process " + proc_d.name_);
1333  for (unsigned int p = 0; p < proc.paths.size(); ++p) {
1334  auto const& name = proc_d.paths_[p].name_;
1335  auto const& path = proc.paths[p];
1336  printPathSummaryLine(out, path.active, path.total, data.events, " " + name);
1337  }
1338  for (unsigned int p = 0; p < proc.endpaths.size(); ++p) {
1339  auto const& name = proc_d.endPaths_[p].name_;
1340  auto const& path = proc.endpaths[p];
1341  printPathSummaryLine(out, path.active, path.total, data.events, " " + name);
1342  }
1343  }
1344  printSummaryLine(out, data.total, data.events, "total");
1345  printSummaryLine(out, data.overhead, data.events, "other");
1346  out << '\n';
1347  for (unsigned int group : boost::irange(0ul, highlight_modules_.size())) {
1348  printSummaryHeader(out, "Highlighted modules", true);
1349  for (unsigned int m : highlight_modules_[group].modules) {
1350  auto const& module_d = callgraph_.module(m);
1351  auto const& module = data.modules[m];
1352  printSummaryLine(out, module.total, data.events, module.events, module_d.moduleLabel());
1353  }
1354  printSummaryLine(out, data.highlight[group], data.events, highlight_modules_[group].label);
1355  out << '\n';
1356  }
1357 }
1358 
1359 template <typename T>
1361  printEventHeader(out, "Transition");
1362  printEventLine(out, data, label);
1363 }
1364 
1365 template <typename T>
1367  std::string const& label,
1368  unsigned int events,
1369  T const& data) const {
1370  return json{{"type", type},
1371  {"label", label},
1372  {"events", events},
1373  {"time_thread", ms(data.time_thread)},
1374  {"time_real", ms(data.time_real)},
1375  {"mem_alloc", kB(data.allocated)},
1376  {"mem_free", kB(data.deallocated)}};
1377 }
1378 
1379 json FastTimerService::encodeToJSON(edm::ModuleDescription const& module, ResourcesPerModule const& data) const {
1380  return encodeToJSON(module.moduleName(), module.moduleLabel(), data.events, data.total);
1381 }
1382 
1384  json j;
1385 
1386  // write a description of the resources
1387  j["resources"] = json::array({json{{"time_real", "real time"}},
1388  json{{"time_thread", "cpu time"}},
1389  json{{"mem_alloc", "allocated memory"}},
1390  json{{"mem_free", "deallocated memory"}}});
1391 
1392  // write the resources used by the job
1393  j["total"] = encodeToJSON("Job", callgraph_.processDescription(0).name_, data.events, data.total + data.overhead);
1394 
1395  // write the resources used by every module
1396  j["modules"] = json::array();
1397  for (unsigned int i = 0; i < callgraph_.size(); ++i) {
1398  auto const& module = callgraph_.module(i);
1399  auto const& data_m = data.modules[i];
1400  j["modules"].push_back(encodeToJSON(module, data_m));
1401  }
1402 
1403  // add an entry for the "overhead"
1404  j["modules"].push_back(encodeToJSON("other", "other", data.events, data.overhead));
1405 
1406  std::ofstream out(filename);
1407  out << std::setw(2) << j << std::flush;
1408 }
1409 
1410 // check if this is the first process being signalled
1412  return (not sc.processContext()->isSubProcess());
1413 }
1414 
1416  return (not gc.processContext()->isSubProcess());
1417 }
1418 
1419 // check if this is the last process being signalled
1420 bool FastTimerService::isLastSubprocess(std::atomic<unsigned int>& check) {
1421  // release-acquire semantic guarantees that all writes in this and other threads are visible
1422  // after this operation; full sequentially-consistent ordering is (probably) not needed.
1423  unsigned int old_value = check.fetch_add(1, std::memory_order_acq_rel);
1424  return (old_value == callgraph_.processes().size() - 1);
1425 }
1426 
1427 void FastTimerService::preEvent(edm::StreamContext const& sc) { ignoredSignal(__func__); }
1428 
1430  ignoredSignal(__func__);
1431 
1432  unsigned int pid = callgraph_.processId(*sc.processContext());
1433  unsigned int sid = sc.streamID();
1434  auto& stream = streams_[sid];
1435  auto& process = callgraph_.processDescription(pid);
1436 
1437  // measure the event resources as the sum of all modules' resources
1438  auto& data = stream.processes[pid].total;
1439  for (unsigned int id : process.modules_)
1440  data += stream.modules[id].total;
1441  stream.total += data;
1442 
1443  // handle the summaries and fill the plots only after the last subprocess has run
1444  bool last = isLastSubprocess(subprocess_event_check_[sid]);
1445  if (not last)
1446  return;
1447 
1448  // measure the event resources explicitly
1449  stream.event_measurement.measure_and_store(stream.event);
1450 
1451  // add to the event resources those used by source (which is not part of any process)
1452  unsigned int id = 0;
1453  stream.total += stream.modules[id].total;
1454 
1455  // highlighted modules
1456  for (unsigned int group : boost::irange(0ul, highlight_modules_.size()))
1457  for (unsigned int i : highlight_modules_[group].modules)
1458  stream.highlight[group] += stream.modules[i].total;
1459 
1460  // avoid concurrent access to the summary objects
1461  {
1462  std::lock_guard<std::mutex> guard(summary_mutex_);
1463  job_summary_ += stream;
1464  run_summary_[sc.runIndex()] += stream;
1465  }
1466 
1467  if (print_event_summary_) {
1468  edm::LogVerbatim out("FastReport");
1469  printEvent(out, stream);
1470  }
1471 
1472  if (enable_dqm_) {
1473  plots_->fill(callgraph_, stream, sc.eventID().luminosityBlock());
1474  }
1475 }
1476 
1478  // clear the event counters
1479  auto& stream = streams_[sid];
1480  stream.reset();
1481  ++stream.events;
1482 
1483  subprocess_event_check_[sid] = 0;
1484 
1485  // reuse the same measurement for the Source module and for the explicit begin of the Event
1486  auto& measurement = thread();
1487  measurement.measure_and_accumulate(stream.overhead);
1488  stream.event_measurement = measurement;
1489 }
1490 
1492  edm::ModuleDescription const& md = callgraph_.source();
1493  unsigned int id = md.id();
1494  auto& stream = streams_[sid];
1495  auto& module = stream.modules[id];
1496 
1497  thread().measure_and_store(module.total);
1498  ++stream.modules[id].events;
1499 }
1500 
1502  unsigned int sid = sc.streamID().value();
1503  unsigned int pid = callgraph_.processId(*sc.processContext());
1504  unsigned int id = pc.pathID();
1505  auto& stream = streams_[sid];
1506  auto& data = pc.isEndPath() ? stream.processes[pid].endpaths[id] : stream.processes[pid].paths[id];
1507  data.status = false;
1508  data.last = 0;
1509 }
1510 
1512  edm::PathContext const& pc,
1513  edm::HLTPathStatus const& status) {
1514  unsigned int sid = sc.streamID().value();
1515  unsigned int pid = callgraph_.processId(*sc.processContext());
1516  unsigned int id = pc.pathID();
1517  auto& stream = streams_[sid];
1518  auto& data = pc.isEndPath() ? stream.processes[pid].endpaths[id] : stream.processes[pid].paths[id];
1519 
1520  auto const& path =
1521  pc.isEndPath() ? callgraph_.processDescription(pid).endPaths_[id] : callgraph_.processDescription(pid).paths_[id];
1522  unsigned int index = path.modules_on_path_.empty() ? 0 : status.index() + 1;
1523  data.last = path.modules_on_path_.empty() ? 0 : path.last_dependency_of_module_[status.index()];
1524 
1525  for (unsigned int i = 0; i < index; ++i) {
1526  auto const& module = stream.modules[path.modules_on_path_[i]];
1527  data.active += module.total;
1528  }
1529  for (unsigned int i = 0; i < data.last; ++i) {
1530  auto const& module = stream.modules[path.modules_and_dependencies_[i]];
1531  data.total += module.total;
1532  }
1533 }
1534 
1536  unsigned int sid = sc.streamID().value();
1537  auto& stream = streams_[sid];
1538  thread().measure_and_accumulate(stream.overhead);
1539 }
1540 
1542  edm::ModuleDescription const& md = *mcc.moduleDescription();
1543  unsigned int id = md.id();
1544  unsigned int sid = sc.streamID().value();
1545  auto& stream = streams_[sid];
1546  auto& module = stream.modules[id];
1547 
1548  module.has_acquire = true;
1549  thread().measure_and_store(module.total);
1550 }
1551 
1553  unsigned int sid = sc.streamID().value();
1554  auto& stream = streams_[sid];
1555  thread().measure_and_accumulate(stream.overhead);
1556 }
1557 
1559  edm::ModuleDescription const& md = *mcc.moduleDescription();
1560  unsigned int id = md.id();
1561  unsigned int sid = sc.streamID().value();
1562  auto& stream = streams_[sid];
1563  auto& module = stream.modules[id];
1564 
1565  if (module.has_acquire) {
1566  thread().measure_and_accumulate(module.total);
1567  } else {
1568  thread().measure_and_store(module.total);
1569  }
1570  ++module.events;
1571 }
1572 
1574  unsupportedSignal(__func__);
1575 }
1576 
1578  unsupportedSignal(__func__);
1579 }
1580 
1582  ignoredSignal(__func__);
1583 }
1584 
1586  ignoredSignal(__func__);
1587 }
1588 
1590  ignoredSignal(__func__);
1591 }
1592 
1594  ignoredSignal(__func__);
1595 }
1596 
1598  thread().measure_and_accumulate(overhead_);
1599 }
1600 
1602  auto index = gc.runIndex();
1603  thread().measure_and_accumulate(run_transition_[index]);
1604 }
1605 
1607  thread().measure_and_accumulate(overhead_);
1608 }
1609 
1611  auto index = gc.runIndex();
1612  thread().measure_and_accumulate(run_transition_[index]);
1613 }
1614 
1616  thread().measure_and_accumulate(overhead_);
1617 }
1618 
1620  auto index = gc.luminosityBlockIndex();
1621  thread().measure_and_accumulate(lumi_transition_[index]);
1622 }
1623 
1625  thread().measure_and_accumulate(overhead_);
1626 }
1627 
1629  auto index = gc.luminosityBlockIndex();
1630  thread().measure_and_accumulate(lumi_transition_[index]);
1631 }
1632 
1634  thread().measure_and_accumulate(overhead_);
1635 }
1636 
1638  auto index = sc.runIndex();
1639  thread().measure_and_accumulate(run_transition_[index]);
1640 }
1641 
1643  thread().measure_and_accumulate(overhead_);
1644 }
1645 
1647  auto index = sc.runIndex();
1648  thread().measure_and_accumulate(run_transition_[index]);
1649 }
1650 
1652  thread().measure_and_accumulate(overhead_);
1653 }
1654 
1656  auto index = sc.luminosityBlockIndex();
1657  thread().measure_and_accumulate(lumi_transition_[index]);
1658 }
1659 
1661  thread().measure_and_accumulate(overhead_);
1662 }
1663 
1665  auto index = sc.luminosityBlockIndex();
1666  thread().measure_and_accumulate(lumi_transition_[index]);
1667 }
1668 
1670  auto err = ::pthread_key_create(&key_, retire_thread);
1671  if (err) {
1672  throw cms::Exception("FastTimerService") << "ThreadGuard key creation failed: " << ::strerror(err);
1673  }
1674 }
1675 
1676 // If this is a new thread, register it and return true
1678  auto ptr = ::pthread_getspecific(key_);
1679 
1680  if (not ptr) {
1681  auto p = thread_resources_.emplace_back(std::make_shared<specific_t>(r));
1682  auto pp = new std::shared_ptr<specific_t>(*p);
1683  auto err = ::pthread_setspecific(key_, pp);
1684  if (err) {
1685  throw cms::Exception("FastTimerService") << "ThreadGuard pthread_setspecific failed: " << ::strerror(err);
1686  }
1687  return true;
1688  }
1689  return false;
1690 }
1691 
1692 std::shared_ptr<FastTimerService::ThreadGuard::specific_t>* FastTimerService::ThreadGuard::ptr(void* p) {
1693  return static_cast<std::shared_ptr<specific_t>*>(p);
1694 }
1695 
1696 // called when a thread exits
1698  auto ps = ptr(p);
1699  auto expected = true;
1700  if ((*ps)->live_.compare_exchange_strong(expected, false)) {
1701  // account any resources used or freed by the thread before leaving the TBB pool
1702  (*ps)->measurement_.measure_and_accumulate((*ps)->resource_);
1703  }
1704  delete ps;
1705 }
1706 
1707 // finalize all threads that have not retired
1709  for (auto& p : thread_resources_) {
1710  auto expected = true;
1711  if (p->live_.compare_exchange_strong(expected, false)) {
1712  p->measurement_.measure_and_accumulate(p->resource_);
1713  }
1714  }
1715 }
1716 
1718  return (*ptr(::pthread_getspecific(key_)))->measurement_;
1719 }
1720 
1723  // initialise the measurement point for a thread that has newly joined the TBB pool
1724  thread().measure();
1725  }
1726 }
1727 
1729 
1731 
1732 // describe the module's configuration
1735  desc.addUntracked<bool>("printEventSummary", false);
1736  desc.addUntracked<bool>("printRunSummary", true);
1737  desc.addUntracked<bool>("printJobSummary", true);
1738  // JSON configuration
1739  //desc.addUntracked<bool>("writeJSONByEvent", false);
1740  //desc.addUntracked<bool>("writeJSONByLumiSection", false);
1741  //desc.addUntracked<bool>("writeJSONByRun", false);
1742  desc.addUntracked<bool>("writeJSONSummary", false);
1743  desc.addUntracked<std::string>("jsonFileName", "resources.json");
1744  // DQM configuration
1745  desc.addUntracked<bool>("enableDQM", true);
1746  desc.addUntracked<bool>("enableDQMbyModule", false);
1747  desc.addUntracked<bool>("enableDQMbyPath", false);
1748  desc.addUntracked<bool>("enableDQMbyLumiSection", false);
1749  desc.addUntracked<bool>("enableDQMbyProcesses", false);
1750  desc.addUntracked<bool>("enableDQMTransitions", false);
1751  desc.addUntracked<double>("dqmTimeRange", 1000.); // ms
1752  desc.addUntracked<double>("dqmTimeResolution", 5.); // ms
1753  desc.addUntracked<double>("dqmMemoryRange", 1000000.); // kB
1754  desc.addUntracked<double>("dqmMemoryResolution", 5000.); // kB
1755  desc.addUntracked<double>("dqmPathTimeRange", 100.); // ms
1756  desc.addUntracked<double>("dqmPathTimeResolution", 0.5); // ms
1757  desc.addUntracked<double>("dqmPathMemoryRange", 1000000.); // kB
1758  desc.addUntracked<double>("dqmPathMemoryResolution", 5000.); // kB
1759  desc.addUntracked<double>("dqmModuleTimeRange", 40.); // ms
1760  desc.addUntracked<double>("dqmModuleTimeResolution", 0.2); // ms
1761  desc.addUntracked<double>("dqmModuleMemoryRange", 100000.); // kB
1762  desc.addUntracked<double>("dqmModuleMemoryResolution", 500.); // kB
1763  desc.addUntracked<unsigned>("dqmLumiSectionsRange", 2500); // ~ 16 hours
1764  desc.addUntracked<std::string>("dqmPath", "HLT/TimerService");
1765 
1766  edm::ParameterSetDescription highlightModulesDescription;
1767  highlightModulesDescription.addUntracked<std::vector<std::string>>("modules", {});
1768  highlightModulesDescription.addUntracked<std::string>("label", "producers");
1769  desc.addVPSetUntracked("highlightModules", highlightModulesDescription, {});
1770 
1771  // # OBSOLETE - these parameters are ignored, they are left only not to break old configurations
1772  // they will not be printed in the generated cfi.py file
1773  desc.addOptionalNode(edm::ParameterDescription<bool>("useRealTimeClock", true, false), false)
1774  ->setComment("This parameter is obsolete and will be ignored.");
1775  desc.addOptionalNode(edm::ParameterDescription<bool>("enableTimingPaths", true, false), false)
1776  ->setComment("This parameter is obsolete and will be ignored.");
1777  desc.addOptionalNode(edm::ParameterDescription<bool>("enableTimingModules", true, false), false)
1778  ->setComment("This parameter is obsolete and will be ignored.");
1779  desc.addOptionalNode(edm::ParameterDescription<bool>("enableTimingExclusive", false, false), false)
1780  ->setComment("This parameter is obsolete and will be ignored.");
1781  desc.addOptionalNode(edm::ParameterDescription<bool>("enableTimingSummary", false, false), false)
1782  ->setComment("This parameter is obsolete and will be ignored.");
1783  desc.addOptionalNode(edm::ParameterDescription<bool>("skipFirstPath", false, false), false)
1784  ->setComment("This parameter is obsolete and will be ignored.");
1785  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyPathActive", false, false), false)
1786  ->setComment("This parameter is obsolete and will be ignored.");
1787  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyPathTotal", true, false), false)
1788  ->setComment("This parameter is obsolete and will be ignored.");
1789  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyPathOverhead", false, false), false)
1790  ->setComment("This parameter is obsolete and will be ignored.");
1791  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyPathDetails", false, false), false)
1792  ->setComment("This parameter is obsolete and will be ignored.");
1793  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyPathCounters", true, false), false)
1794  ->setComment("This parameter is obsolete and will be ignored.");
1795  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyPathExclusive", false, false), false)
1796  ->setComment("This parameter is obsolete and will be ignored.");
1797  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMbyModuleType", false, false), false)
1798  ->setComment("This parameter is obsolete and will be ignored.");
1799  desc.addOptionalNode(edm::ParameterDescription<bool>("enableDQMSummary", false, false), false)
1800  ->setComment("This parameter is obsolete and will be ignored.");
1801 
1802  descriptions.add("FastTimerService", desc);
1803 }
1804 
1805 // declare FastTimerService as a framework Service
void preGlobalBeginRun(edm::GlobalContext const &)
void preModuleEventDelayedGet(edm::StreamContext const &, edm::ModuleCallingContext const &)
const bool print_run_summary_
unsigned int maxNumberOfThreads() const
Definition: SystemBounds.h:38
constexpr int32_t ceil(float num)
list processes
Run mode ##.
void fill(Resources const &, unsigned int lumisection)
void setComment(std::string const &value)
T getUntrackedParameter(std::string const &, T const &) const
void postStreamBeginRun(edm::StreamContext const &)
LuminosityBlockIndex const & luminosityBlockIndex() const
Definition: StreamContext.h:61
void postGlobalEndLumi(edm::GlobalContext const &)
void postGlobalBeginLumi(edm::GlobalContext const &)
void on_scheduler_entry(bool worker) final
void postStreamEndLumi(edm::StreamContext const &)
tuple array
Definition: mps_check.py:216
void on_scheduler_exit(bool worker) final
void postModuleGlobalEndLumi(edm::GlobalContext const &, edm::ModuleCallingContext const &)
const edm::EventSetup & c
void preEventReadFromSource(edm::StreamContext const &, edm::ModuleCallingContext const &)
void preGlobalEndRun(edm::GlobalContext const &)
void preBeginJob(edm::PathsAndConsumesOfModulesBase const &, edm::ProcessContext const &)
void fill_lumi(AtomicResources const &, unsigned int lumisection)
void preSourceLumi(edm::LuminosityBlockIndex)
void printSummary(T &out, ResourcesPerJob const &data, std::string const &label) const
boost::date_time::subsecond_duration< boost::posix_time::time_duration, 1000000000 > nanoseconds
AtomicResources operator+(AtomicResources const &other) const
unsigned int concurrent_threads_
std::vector< unsigned int > modules_and_dependencies_
void postEventReadFromSource(edm::StreamContext const &, edm::ModuleCallingContext const &)
ParameterDescriptionBase * addUntracked(U const &iLabel, T const &value)
uint16_t *__restrict__ id
const PlotRanges dqm_event_ranges_
void postModuleGlobalEndRun(edm::GlobalContext const &, edm::ModuleCallingContext const &)
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
void preSourceRun(edm::RunIndex)
void postModuleEvent(edm::StreamContext const &, edm::ModuleCallingContext const &)
tuple pp
Definition: createTree.py:17
void unsupportedSignal(const std::string &signal) const
virtual void setCurrentFolder(std::string const &fullpath)
Definition: DQMStore.cc:32
const bool write_json_summary_
void book(dqm::reco::DQMStore::IBooker &, ProcessCallGraph const &, ProcessCallGraph::ProcessType const &, PlotRanges const &event_ranges, PlotRanges const &path_ranges, unsigned int lumisections, bool bypath, bool byls)
PlotsPerJob(ProcessCallGraph const &job, std::vector< GroupOfModules > const &groups)
nlohmann::json json
PlotsPerProcess(ProcessCallGraph::ProcessType const &)
void preGlobalEndLumi(edm::GlobalContext const &)
std::vector< ResourcesPerPath > endpaths
virtual std::string pwd()
Definition: DQMStore.cc:16
LuminosityBlockID const & luminosityBlockID() const
Definition: GlobalContext.h:60
AtomicResources overhead_
const std::string json_filename_
bool isFirstSubprocess(edm::StreamContext const &)
def ls
Definition: eostools.py:349
const bool enable_dqm_bynproc_
unsigned int concurrent_runs_
list status
Definition: mps_update.py:107
void writeSummaryJSON(ResourcesPerJob const &data, std::string const &filename) const
boost::chrono::nanoseconds time_real
std::string const & moduleName() const
std::atomic< uint64_t > deallocated
void postSourceRun(edm::RunIndex)
std::atomic< uint64_t > allocated
RunIndex const & runIndex() const
Definition: StreamContext.h:60
void postPathEvent(edm::StreamContext const &, edm::PathContext const &, edm::HLTPathStatus const &)
void preModuleGlobalBeginLumi(edm::GlobalContext const &, edm::ModuleCallingContext const &)
uint32_t T const *__restrict__ uint32_t const *__restrict__ int32_t int Histo::index_type cudaStream_t stream
ResourcesPerProcess & operator+=(ResourcesPerProcess const &other)
void book(dqm::reco::DQMStore::IBooker &, std::string const &, ProcessCallGraph const &, ProcessCallGraph::PathType const &, PlotRanges const &ranges, unsigned int lumisections, bool byls)
assert(be >=bs)
LuminosityBlockNumber_t luminosityBlock() const
Definition: EventID.h:39
const bool print_job_summary_
std::string const & moduleLabel() const
const bool enable_dqm_bypath_
edm::ModuleDescription const & source() const
void book(dqm::reco::DQMStore::IBooker &, ProcessCallGraph const &, std::vector< GroupOfModules > const &, PlotRanges const &event_ranges, PlotRanges const &path_ranges, PlotRanges const &module_ranges, unsigned int lumisections, bool bymodule, bool bypath, bool byls, bool transitions)
Measurement & thread()
dqm_lumisections_range_(config.getUntrackedParameter< unsigned int >("dqmLumiSectionsRange"))
void printSummary(const std::map< unsigned int, SiStripDetSummary::Values > &map)
tuple result
Definition: mps_fire.py:311
void postStreamBeginLumi(edm::StreamContext const &)
RunIndex const & runIndex() const
Definition: GlobalContext.h:61
unsigned int maxNumberOfStreams() const
Definition: SystemBounds.h:35
ResourcesPerProcess operator+(ResourcesPerProcess const &other) const
ResourcesPerJob operator+(ResourcesPerJob const &other) const
std::vector< ResourcesPerModule > modules
bool isEndPath() const
Definition: PathContext.h:35
char const * label
void printEvent(T &out, ResourcesPerJob const &) const
void printHeader(T &out, std::string const &label) const
void postModuleStreamEndLumi(edm::StreamContext const &, edm::ModuleCallingContext const &)
MonitorElement * book1DD(TString const &name, TString const &title, int nchX, double lowX, double highX, FUNC onbooking=NOOP())
Definition: DQMStore.h:155
void printPathSummaryHeader(T &out, std::string const &label) const
ResourcesPerJob & operator+=(ResourcesPerJob const &other)
void printSummaryHeader(T &out, std::string const &label, bool detailed) const
virtual void setXTitle(std::string const &title)
void fill(ProcessCallGraph::ProcessType const &, ResourcesPerJob const &, ResourcesPerProcess const &, unsigned int ls)
void prePathEvent(edm::StreamContext const &, edm::PathContext const &)
LuminosityBlockIndex const & luminosityBlockIndex() const
Definition: GlobalContext.h:62
MonitorElement * bookProfile(TString const &name, TString const &title, int nchX, double lowX, double highX, int, double lowY, double highY, char const *option="s", FUNC onbooking=NOOP())
Definition: DQMStore.h:322
const std::string processor_model
void printEventHeader(T &out, std::string const &label) const
static void fillDescriptions(edm::ConfigurationDescriptions &descriptions)
FastTimerService(const edm::ParameterSet &, edm::ActivityRegistry &)
void preModuleStreamEndLumi(edm::StreamContext const &, edm::ModuleCallingContext const &)
void postEvent(edm::StreamContext const &)
def load
Definition: svgfig.py:547
void postGlobalEndRun(edm::GlobalContext const &)
static uint64_t deallocated()
Definition: memory_usage.cc:88
ModuleDescription const * moduleDescription() const
void fill_fraction(Resources const &, Resources const &, unsigned int lumisection)
std::vector< ProcessType > const & processes() const
ResourcesPerModule operator+(ResourcesPerModule const &other) const
const double infinity
void postStreamEndRun(edm::StreamContext const &)
std::vector< PathType > paths_
void preModuleEvent(edm::StreamContext const &, edm::ModuleCallingContext const &)
RunNumber_t run() const
ResourcesPerPath & operator+=(ResourcesPerPath const &other)
ProcessType const & processDescription(unsigned int) const
ParameterDescriptionNode * addOptionalNode(ParameterDescriptionNode const &node, bool writeToCfi)
unsigned int concurrent_lumis_
bool register_thread(FastTimerService::AtomicResources &r)
void printSummaryLine(T &out, Resources const &data, uint64_t events, std::string const &label) const
unsigned int pathID() const
Definition: PathContext.h:32
const bool enable_dqm_transitions_
ProcessContext const * processContext() const
Definition: StreamContext.h:63
void printEventLine(T &out, Resources const &data, std::string const &label) const
std::atomic< boost::chrono::nanoseconds::rep > time_thread
Resources operator+(Resources const &other) const
void measure_and_store(Resources &store) noexcept
std::vector< Resources > highlight
const bool enable_dqm_bymodule_
void printPathSummaryLine(T &out, Resources const &data, Resources const &total, uint64_t events, std::string const &label) const
string ranges
Definition: diffTwoXMLs.py:79
StreamID const & streamID() const
Definition: StreamContext.h:54
void book(dqm::reco::DQMStore::IBooker &, std::string const &name, std::string const &title, PlotRanges const &ranges, unsigned int lumisections, bool byls)
void fill_run(AtomicResources const &)
#define DEFINE_FWK_SERVICE(type)
Definition: ServiceMaker.h:96
static bool is_available()
Definition: memory_usage.cc:84
tuple group
Definition: watchdog.py:82
const bool enable_dqm_byls_
std::vector< PlotsPerProcess > processes_
void postModuleEventAcquire(edm::StreamContext const &, edm::ModuleCallingContext const &)
void postModuleEventDelayedGet(edm::StreamContext const &, edm::ModuleCallingContext const &)
const bool print_event_summary_
virtual void setYTitle(std::string const &title)
unsigned int value() const
Definition: StreamID.h:43
highlight_modules_(highlight_module_psets_.size())
unsigned int maxNumberOfConcurrentLuminosityBlocks() const
Definition: SystemBounds.h:37
static std::shared_ptr< specific_t > * ptr(void *p)
unsigned long long uint64_t
Definition: Time.h:13
void postModuleStreamBeginLumi(edm::StreamContext const &, edm::ModuleCallingContext const &)
void printTransition(T &out, AtomicResources const &data, std::string const &label) const
void preModuleStreamEndRun(edm::StreamContext const &, edm::ModuleCallingContext const &)
void postModuleStreamEndRun(edm::StreamContext const &, edm::ModuleCallingContext const &)
part
Definition: HCALResponse.h:20
static uint64_t allocated()
Definition: memory_usage.cc:86
void postModuleStreamBeginRun(edm::StreamContext const &, edm::ModuleCallingContext const &)
void preSourceEvent(edm::StreamID)
static void retire_thread(void *t)
boost::chrono::nanoseconds time_thread
LuminosityBlockNumber_t luminosityBlock() const
void add(std::string const &label, ParameterSetDescription const &psetDescription)
dqm_path_(config.getUntrackedParameter< std::string >("dqmPath"))
void preEvent(edm::StreamContext const &)
dqm_path_ranges_({config.getUntrackedParameter< double >("dqmPathTimeRange"), config.getUntrackedParameter< double >("dqmPathTimeResolution"), config.getUntrackedParameter< double >("dqmPathMemoryRange"), config.getUntrackedParameter< double >("dqmPathMemoryResolution")})
void postGlobalBeginRun(edm::GlobalContext const &)
ProcessContext const * processContext() const
Definition: GlobalContext.h:64
void preStreamBeginLumi(edm::StreamContext const &)
ResourcesPerProcess(ProcessCallGraph::ProcessType const &process)
void ignoredSignal(const std::string &signal) const
void postSourceEvent(edm::StreamID)
void preModuleStreamBeginLumi(edm::StreamContext const &, edm::ModuleCallingContext const &)
tuple config
parse the configuration file
void preStreamEndRun(edm::StreamContext const &)
char data[epos_bytes_allocation]
Definition: EPOS_Wrapper.h:79
std::atomic< boost::chrono::nanoseconds::rep > time_real
void preModuleStreamBeginRun(edm::StreamContext const &, edm::ModuleCallingContext const &)
tuple events
Definition: patZpeak.py:20
void preStreamEndLumi(edm::StreamContext const &)
void measure_and_accumulate(Resources &store) noexcept
ResourcesPerModule & operator+=(ResourcesPerModule const &other)
std::vector< PathType > endPaths_
void event_()
tuple filename
Definition: lut2db_cfg.py:20
void postModuleEventPrefetching(edm::StreamContext const &, edm::ModuleCallingContext const &)
void preModuleGlobalEndLumi(edm::GlobalContext const &, edm::ModuleCallingContext const &)
edm::ModuleDescription const & module(unsigned int module) const
void preGlobalBeginLumi(edm::GlobalContext const &)
unsigned int maxNumberOfConcurrentRuns() const
Definition: SystemBounds.h:36
AtomicResources & operator+=(AtomicResources const &other)
Resources & operator+=(Resources const &other)
void preModuleEventPrefetching(edm::StreamContext const &, edm::ModuleCallingContext const &)
void preSourceConstruction(edm::ModuleDescription const &)
void preModuleEventAcquire(edm::StreamContext const &, edm::ModuleCallingContext const &)
void preModuleGlobalEndRun(edm::GlobalContext const &, edm::ModuleCallingContext const &)
EventID const & eventID() const
Definition: StreamContext.h:59
void postSourceLumi(edm::LuminosityBlockIndex)
dqm_module_ranges_({config.getUntrackedParameter< double >("dqmModuleTimeRange"), config.getUntrackedParameter< double >("dqmModuleTimeResolution"), config.getUntrackedParameter< double >("dqmModuleMemoryRange"), config.getUntrackedParameter< double >("dqmModuleMemoryResolution")})
void postModuleGlobalBeginRun(edm::GlobalContext const &, edm::ModuleCallingContext const &)
std::vector< ResourcesPerProcess > processes
tuple last
Definition: dqmdumpme.py:56
Log< level::Warning, false > LogWarning
MonitorElement * book1D(TString const &name, TString const &title, int const nchX, double const lowX, double const highX, FUNC onbooking=NOOP())
Definition: DQMStore.h:98
UseScope< MonitorElementData::Scope::RUN > UseRunScope
Definition: DQMStore.h:464
AtomicResources & operator=(AtomicResources const &other)
tuple process
Definition: LaserDQM_cfg.py:3
highlight_module_psets_(config.getUntrackedParameter< std::vector< edm::ParameterSet >>("highlightModules"))
ProcessCallGraph callgraph_
long double T
void postModuleGlobalBeginLumi(edm::GlobalContext const &, edm::ModuleCallingContext const &)
void preStreamBeginRun(edm::StreamContext const &)
std::vector< ResourcesPerPath > paths
bool isSubProcess() const
ResourcesPerPath operator+(ResourcesPerPath const &other) const
void preModuleGlobalBeginRun(edm::GlobalContext const &, edm::ModuleCallingContext const &)
ParameterDescriptionBase * addVPSetUntracked(U const &iLabel, ParameterSetDescription const &validator, std::vector< ParameterSet > const &defaults)
static std::string const source
Definition: EdmProvDump.cc:46
tuple size
Write out results.
unsigned int concurrent_streams_
bool isLastSubprocess(std::atomic< unsigned int > &check)
void preallocate(edm::service::SystemBounds const &)
tuple module
Definition: callgraph.py:69
void fill(ProcessCallGraph const &, ResourcesPerJob const &, unsigned int ls)
unsigned int id() const
#define LogDebug(id)
json encodeToJSON(std::string const &type, std::string const &label, unsigned int events, T const &data) const
void fill(ProcessCallGraph::PathType const &, ResourcesPerJob const &, ResourcesPerPath const &, unsigned int lumisection)
unsigned int index() const
Definition: HLTPathStatus.h:52