10 #include <unordered_map>
11 #include <unordered_set>
14 #include <boost/range/irange.hpp>
17 #include <fmt/printf.h>
20 #include <nlohmann/json.hpp>
42 using namespace std::literals;
49 template <
class Rep,
class Period>
50 double ms(std::chrono::duration<Rep, Period> duration) {
51 return std::chrono::duration_cast<std::chrono::duration<double, std::milli>>(duration).
count();
55 template <
class Rep,
class Period>
56 double ms(boost::chrono::duration<Rep, Period> duration) {
57 return boost::chrono::duration_cast<boost::chrono::duration<double, boost::milli>>(duration).
count();
61 double ms(std::atomic<boost::chrono::nanoseconds::rep>
const& duration) {
62 return boost::chrono::duration_cast<boost::chrono::duration<double, boost::milli>>(
71 uint64_t kB(std::atomic<uint64_t>
const& bytes) {
return bytes.load() / 1024; }
95 time_thread +=
other.time_thread;
96 time_real +=
other.time_real;
97 allocated +=
other.allocated;
98 deallocated +=
other.deallocated;
105 allocated +=
other.allocated.load();
106 deallocated +=
other.deallocated.load();
128 : time_thread(0ul), time_real(0ul), allocated(0ul), deallocated(0ul) {}
144 time_thread =
other.time_thread.load();
145 time_real =
other.time_real.load();
146 allocated =
other.allocated.load();
147 deallocated =
other.deallocated.load();
152 time_thread +=
other.time_thread.load();
153 time_real +=
other.time_real.load();
154 allocated +=
other.allocated.load();
155 deallocated +=
other.deallocated.load();
160 time_thread +=
other.time_thread.count();
161 time_real +=
other.time_real.count();
162 allocated +=
other.allocated;
163 deallocated +=
other.deallocated;
174 return other + *
this;
190 has_acquire = has_acquire
or other.has_acquire;
211 active +=
other.active;
233 for (
auto&
path : endpaths)
241 for (
unsigned int i : boost::irange(0ul,
paths.size()))
244 for (
unsigned int i : boost::irange(0ul, endpaths.size()))
245 endpaths[
i] +=
other.endpaths[
i];
259 std::vector<GroupOfModules>
const& groups)
270 for (
auto& module : highlight)
281 overhead +=
other.overhead;
282 event +=
other.event;
283 assert(highlight.size() ==
other.highlight.size());
284 for (
unsigned int i : boost::irange(0ul, highlight.size()))
285 highlight[
i] +=
other.highlight[
i];
287 for (
unsigned int i : boost::irange(0ul,
modules.size()))
290 for (
unsigned int i : boost::irange(0ul,
processes.size()))
309 #ifdef DEBUG_THREAD_CONCURRENCY
310 id = std::this_thread::get_id();
311 #endif // DEBUG_THREAD_CONCURRENCY
319 #ifdef DEBUG_THREAD_CONCURRENCY
320 assert(std::this_thread::get_id() ==
id);
321 #endif // DEBUG_THREAD_CONCURRENCY
326 store.time_thread = new_time_thread - time_thread;
327 store.time_real = new_time_real - time_real;
328 store.allocated = new_allocated - allocated;
329 store.deallocated = new_deallocated - deallocated;
330 time_thread = new_time_thread;
331 time_real = new_time_real;
332 allocated = new_allocated;
333 deallocated = new_deallocated;
337 #ifdef DEBUG_THREAD_CONCURRENCY
338 assert(std::this_thread::get_id() ==
id);
339 #endif // DEBUG_THREAD_CONCURRENCY
344 store.time_thread += new_time_thread - time_thread;
345 store.time_real += new_time_real - time_real;
346 store.allocated += new_allocated - allocated;
347 store.deallocated += new_deallocated - deallocated;
348 time_thread = new_time_thread;
349 time_real = new_time_real;
350 allocated = new_allocated;
351 deallocated = new_deallocated;
355 #ifdef DEBUG_THREAD_CONCURRENCY
356 assert(std::this_thread::get_id() ==
id);
357 #endif // DEBUG_THREAD_CONCURRENCY
362 store.time_thread += boost::chrono::duration_cast<boost::chrono::nanoseconds>(new_time_thread - time_thread).count();
363 store.time_real += boost::chrono::duration_cast<boost::chrono::nanoseconds>(new_time_real - time_real).count();
364 store.allocated += new_allocated - allocated;
365 store.deallocated += new_deallocated - deallocated;
366 time_thread = new_time_thread;
367 time_real = new_time_real;
368 allocated = new_allocated;
369 deallocated = new_deallocated;
378 unsigned int lumisections,
382 std::string y_title_ms = fmt::sprintf(
"events / %.1f ms",
ranges.time_resolution);
383 std::string y_title_kB = fmt::sprintf(
"events / %.1f kB",
ranges.memory_resolution);
386 booker.
book1D(
name +
" time_thread",
title +
" processing time (cpu)", time_bins, 0.,
ranges.time_range);
387 time_thread_->
setXTitle(
"processing time [ms]");
388 time_thread_->setYTitle(y_title_ms);
390 time_real_ = booker.
book1D(
name +
" time_real",
title +
" processing time (real)", time_bins, 0.,
ranges.time_range);
391 time_real_->
setXTitle(
"processing time [ms]");
392 time_real_->setYTitle(y_title_ms);
395 allocated_ = booker.
book1D(
name +
" allocated",
title +
" allocated memory", mem_bins, 0.,
ranges.memory_range);
397 allocated_->setYTitle(y_title_kB);
400 booker.
book1D(
name +
" deallocated",
title +
" deallocated memory", mem_bins, 0.,
ranges.memory_range);
402 deallocated_->setYTitle(y_title_kB);
409 title +
" processing time (cpu) vs. lumisection",
417 time_thread_byls_->
setXTitle(
"lumisection");
418 time_thread_byls_->setYTitle(
"processing time [ms]");
421 title +
" processing time (real) vs. lumisection",
429 time_real_byls_->
setXTitle(
"lumisection");
430 time_real_byls_->setYTitle(
"processing time [ms]");
434 title +
" allocated memory vs. lumisection",
442 allocated_byls_->
setXTitle(
"lumisection");
443 allocated_byls_->setYTitle(
"memory [kB]");
446 title +
" deallocated memory vs. lumisection",
454 deallocated_byls_->
setXTitle(
"lumisection");
455 deallocated_byls_->setYTitle(
"memory [kB]");
461 TH1::StatOverflows(
true);
464 time_thread_->Fill(ms(
data.time_thread));
466 if (time_thread_byls_)
467 time_thread_byls_->Fill(lumisection, ms(
data.time_thread));
470 time_real_->Fill(ms(
data.time_real));
473 time_real_byls_->Fill(lumisection, ms(
data.time_real));
476 allocated_->Fill(kB(
data.allocated));
479 allocated_byls_->Fill(lumisection, kB(
data.allocated));
482 deallocated_->Fill(kB(
data.deallocated));
484 if (deallocated_byls_)
485 deallocated_byls_->Fill(lumisection, kB(
data.deallocated));
490 TH1::StatOverflows(
true);
495 if (time_thread_byls_)
505 allocated_->Fill(kB(
data.allocated));
508 allocated_byls_->Fill(lumisection, kB(
data.allocated));
511 deallocated_->Fill(kB(
data.deallocated));
513 if (deallocated_byls_)
514 deallocated_byls_->Fill(lumisection, kB(
data.deallocated));
519 unsigned int lumisection) {
521 TH1::StatOverflows(
true);
531 if (time_thread_byls_)
555 if (deallocated_byls_)
564 unsigned int lumisections,
570 total_.book(booker,
"path",
path.name_,
ranges, lumisections, byls);
572 unsigned int bins =
path.modules_and_dependencies_.size();
573 module_counter_ = booker.
book1DD(
"module_counter",
"module counter",
bins + 1, -0.5,
bins + 0.5);
575 module_time_thread_total_ =
576 booker.
book1DD(
"module_time_thread_total",
"total module time (cpu)",
bins, -0.5,
bins - 0.5);
577 module_time_thread_total_->
setYTitle(
"processing time [ms]");
578 module_time_real_total_ =
579 booker.
book1DD(
"module_time_real_total",
"total module time (real)",
bins, -0.5,
bins - 0.5);
580 module_time_real_total_->
setYTitle(
"processing time [ms]");
582 module_allocated_total_ =
583 booker.
book1DD(
"module_allocated_total",
"total allocated memory",
bins, -0.5,
bins - 0.5);
584 module_allocated_total_->
setYTitle(
"memory [kB]");
585 module_deallocated_total_ =
586 booker.
book1DD(
"module_deallocated_total",
"total deallocated memory",
bins, -0.5,
bins - 0.5);
587 module_deallocated_total_->
setYTitle(
"memory [kB]");
589 for (
unsigned int bin : boost::irange(0u,
bins)) {
590 auto const& module = job[
path.modules_and_dependencies_[
bin]];
592 module.scheduled_ ? module.module_.moduleLabel() : module.module_.moduleLabel() +
" (unscheduled)";
593 module_counter_->setBinLabel(
bin + 1,
label);
594 module_time_thread_total_->setBinLabel(
bin + 1,
label);
595 module_time_real_total_->setBinLabel(
bin + 1,
label);
597 module_allocated_total_->setBinLabel(
bin + 1,
label);
598 module_deallocated_total_->setBinLabel(
bin + 1,
label);
601 module_counter_->setBinLabel(
bins + 1,
"");
611 total_.fill(
path.total,
ls);
614 for (
unsigned int i = 0;
i <
path.last; ++
i) {
615 auto const& module =
data.modules[
description.modules_and_dependencies_[
i]];
617 module_counter_->Fill(
i);
619 if (module_time_thread_total_)
620 module_time_thread_total_->Fill(
i, ms(module.total.time_thread));
622 if (module_time_real_total_)
623 module_time_real_total_->Fill(
i, ms(module.total.time_real));
625 if (module_allocated_total_)
626 module_allocated_total_->Fill(
i, kB(module.total.allocated));
628 if (module_deallocated_total_)
629 module_deallocated_total_->Fill(
i, kB(module.total.deallocated));
631 if (module_counter_ and
path.status)
632 module_counter_->Fill(
path.last);
643 unsigned int lumisections,
647 event_.book(booker,
"process " +
process.name_,
"process " +
process.name_, event_ranges, lumisections, byls);
650 for (
unsigned int id : boost::irange(0ul, paths_.size())) {
651 paths_[
id].book(booker,
"path ", job,
process.paths_[
id], path_ranges, lumisections, byls);
653 for (
unsigned int id : boost::irange(0ul, endpaths_.size())) {
654 endpaths_[
id].book(booker,
"endpath ", job,
process.endPaths_[
id], path_ranges, lumisections, byls);
668 for (
unsigned int id : boost::irange(0ul, paths_.size()))
672 for (
unsigned int id : boost::irange(0ul, endpaths_.size()))
685 std::vector<GroupOfModules>
const& groups,
689 unsigned int lumisections,
697 event_.book(booker,
"event",
"Event", event_ranges, lumisections, byls);
699 event_ex_.book(booker,
"explicit",
"Event (explicit)", event_ranges, lumisections, byls);
701 overhead_.book(booker,
"overhead",
"Overhead", event_ranges, lumisections, byls);
703 modules_[job.
source().
id()].book(booker,
"source",
"Source", module_ranges, lumisections, byls);
706 lumi_.book(booker,
"lumi",
"LumiSection transitions", event_ranges, lumisections, byls);
708 run_.book(booker,
"run",
"Run transtions", event_ranges, lumisections,
false);
712 for (
unsigned int group : boost::irange(0ul, groups.size())) {
714 highlight_[
group].book(booker,
"highlight " +
label,
"Highlight " +
label, event_ranges, lumisections, byls);
718 for (
unsigned int pid : boost::irange(0ul, job.
processes().size())) {
720 processes_[pid].book(booker, job,
process, event_ranges, path_ranges, lumisections, bypath, byls);
724 for (
unsigned int id :
process.modules_) {
736 event_ex_.fill(
data.event,
ls);
740 for (
unsigned int group : boost::irange(0ul, highlight_.size()))
744 for (
unsigned int id : boost::irange(0ul, modules_.size()))
745 modules_[
id].fill(
data.modules[
id].total,
ls);
747 for (
unsigned int pid : boost::irange(0ul, processes_.size()))
788 config.getUntrackedParameter<
double>(
"dqmTimeResolution"),
789 config.getUntrackedParameter<
double>(
"dqmMemoryRange"),
790 config.getUntrackedParameter<
double>(
"dqmMemoryResolution")}),
791 dqm_path_ranges_({
config.getUntrackedParameter<
double>(
"dqmPathTimeRange"),
792 config.getUntrackedParameter<
double>(
"dqmPathTimeResolution"),
793 config.getUntrackedParameter<
double>(
"dqmPathMemoryRange"),
794 config.getUntrackedParameter<
double>(
"dqmPathMemoryResolution")}),
795 dqm_module_ranges_({
config.getUntrackedParameter<
double>(
"dqmModuleTimeRange"),
796 config.getUntrackedParameter<
double>(
"dqmModuleTimeResolution"),
797 config.getUntrackedParameter<
double>(
"dqmModuleMemoryRange"),
798 config.getUntrackedParameter<
double>(
"dqmModuleMemoryResolution")}),
799 dqm_lumisections_range_(
config.getUntrackedParameter<
unsigned int>(
"dqmLumiSectionsRange")),
802 highlight_module_psets_(
config.getUntrackedParameter<std::vector<edm::ParameterSet>>(
"highlightModules")),
803 highlight_modules_(highlight_module_psets_.size())
806 tbb::task_scheduler_observer::observe();
880 LogDebug(
"FastTimerService") <<
"The FastTimerService received is currently not monitoring the signal \"" << signal
886 if (unsupported_signals_.insert(signal).second)
887 edm::LogWarning(
"FastTimerService") <<
"The FastTimerService received the unsupported signal \"" << signal
889 <<
"Please report how to reproduce the issue to cms-hlt@cern.ch .";
893 ignoredSignal(__func__);
896 if (isFirstSubprocess(gc)) {
898 subprocess_global_run_check_[
index] = 0;
899 run_transition_[
index].reset();
900 run_summary_[
index].reset();
917 dqm_lumisections_range_,
918 enable_dqm_bymodule_,
921 enable_dqm_transitions_);
940 if (enable_dqm_bynproc_)
941 dqm_path_ += fmt::sprintf(
942 "/Running on %s with %d streams on %d threads",
processor_model, concurrent_streams_, concurrent_threads_);
946 auto safe_for_dqm =
"/ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789-+=_()# "s;
947 for (
auto&
c : dqm_path_)
948 if (safe_for_dqm.find(
c) == std::string::npos)
952 subprocess_event_check_ = std::make_unique<std::atomic<unsigned int>[]>(concurrent_streams_);
953 for (
unsigned int i = 0;
i < concurrent_streams_; ++
i)
954 subprocess_event_check_[
i] = 0;
955 subprocess_global_run_check_ = std::make_unique<std::atomic<unsigned int>[]>(concurrent_runs_);
956 for (
unsigned int i = 0;
i < concurrent_runs_; ++
i)
957 subprocess_global_run_check_[
i] = 0;
958 subprocess_global_lumi_check_ = std::make_unique<std::atomic<unsigned int>[]>(concurrent_lumis_);
959 for (
unsigned int i = 0;
i < concurrent_lumis_; ++
i)
960 subprocess_global_lumi_check_[
i] = 0;
963 lumi_transition_.resize(concurrent_lumis_);
964 run_transition_.resize(concurrent_runs_);
968 callgraph_.preSourceConstruction(module);
973 callgraph_.preBeginJob(pathsAndConsumes, context);
977 unsigned int modules = callgraph_.size();
980 for (
unsigned int group : boost::irange(0ul, highlight_module_psets_.size())) {
982 auto labels = highlight_module_psets_[
group].getUntrackedParameter<std::vector<std::string>>(
"modules");
985 highlight_modules_[
group].label = highlight_module_psets_[
group].getUntrackedParameter<
std::string>(
"label");
986 highlight_modules_[
group].modules.reserve(
labels.size());
989 auto const&
label = callgraph_.module(
i).moduleLabel();
991 highlight_modules_[
group].modules.push_back(
i);
994 highlight_module_psets_.clear();
998 streams_.resize(concurrent_streams_,
temp);
999 run_summary_.resize(concurrent_runs_,
temp);
1000 job_summary_ =
temp;
1005 enable_dqm_ =
false;
1006 edm::LogWarning(
"FastTimerService") <<
"The DQMStore is not avalable, the DQM plots will not be generated";
1011 plots_ = std::make_unique<PlotsPerJob>(callgraph_, highlight_modules_);
1022 ignoredSignal(__func__);
1025 if (isFirstSubprocess(gc)) {
1027 subprocess_global_lumi_check_[
index] = 0;
1028 lumi_transition_[
index].reset();
1037 ignoredSignal(__func__);
1041 bool last = isLastSubprocess(subprocess_global_lumi_check_[
index]);
1050 if (enable_dqm_transitions_) {
1066 ignoredSignal(__func__);
1070 bool last = isLastSubprocess(subprocess_global_run_check_[
index]);
1076 if (print_run_summary_) {
1081 if (enable_dqm_transitions_) {
1082 plots_->fill_run(run_transition_[
index]);
1093 thread().measure_and_accumulate(lumi_transition_[
index]);
1097 if (print_job_summary_) {
1101 if (write_json_summary_) {
1102 writeSummaryJSON(job_summary_, json_filename_);
1106 template <
typename T>
1108 out <<
"FastReport ";
1109 if (
label.size() < 60)
1110 for (
unsigned int i = (60 -
label.size()) / 2;
i > 0; --
i)
1112 out <<
' ' <<
label <<
" Summary ";
1113 if (
label.size() < 60)
1114 for (
unsigned int i = (59 -
label.size()) / 2;
i > 0; --
i)
1119 template <
typename T>
1121 out <<
"FastReport CPU time Real time Allocated Deallocated " <<
label <<
"\n";
1125 template <
typename T>
1127 out << fmt::sprintf(
"FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1128 ms(
data.time_thread),
1130 +static_cast<int64_t>(kB(
data.allocated)),
1131 -static_cast<int64_t>(kB(
data.deallocated)),
1135 template <
typename T>
1137 out << fmt::sprintf(
"FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1140 +static_cast<int64_t>(kB(
data.allocated)),
1141 -static_cast<int64_t>(kB(
data.deallocated)),
1145 template <
typename T>
1147 printHeader(
out,
"Event");
1148 printEventHeader(
out,
"Modules");
1149 auto const& source_d = callgraph_.source();
1150 auto const&
source =
data.modules[source_d.id()];
1151 printEventLine(
out,
source.total, source_d.moduleLabel());
1152 for (
unsigned int i = 0;
i < callgraph_.processes().size(); ++
i) {
1153 auto const& proc_d = callgraph_.processDescription(
i);
1155 printEventLine(
out,
proc.total,
"process " + proc_d.name_);
1156 for (
unsigned int m : proc_d.modules_) {
1157 auto const& module_d = callgraph_.module(
m);
1158 auto const& module =
data.modules[
m];
1159 printEventLine(
out, module.total,
" " + module_d.moduleLabel());
1162 printEventLine(
out,
data.total,
"total");
1164 printEventHeader(
out,
"Processes and Paths");
1165 printEventLine(
out,
source.total, source_d.moduleLabel());
1166 for (
unsigned int i = 0;
i < callgraph_.processes().size(); ++
i) {
1167 auto const& proc_d = callgraph_.processDescription(
i);
1169 printEventLine(
out,
proc.total,
"process " + proc_d.name_);
1170 for (
unsigned int p = 0;
p <
proc.paths.size(); ++
p) {
1171 auto const&
name = proc_d.paths_[
p].name_;
1173 printEventLine(
out,
path.active,
name +
" (only scheduled modules)");
1174 printEventLine(
out,
path.total,
name +
" (including dependencies)");
1176 for (
unsigned int p = 0;
p <
proc.endpaths.size(); ++
p) {
1177 auto const&
name = proc_d.endPaths_[
p].name_;
1179 printEventLine(
out,
path.active,
name +
" (only scheduled modules)");
1180 printEventLine(
out,
path.total,
name +
" (including dependencies)");
1183 printEventLine(
out,
data.total,
"total");
1185 for (
unsigned int group : boost::irange(0ul, highlight_modules_.size())) {
1186 printEventHeader(
out,
"Highlighted modules");
1188 auto const& module_d = callgraph_.module(
m);
1189 auto const& module =
data.modules[
m];
1190 printEventLine(
out, module.total,
" " + module_d.moduleLabel());
1197 template <
typename T>
1201 out <<
"FastReport CPU time avg. when run Real time avg. when run Alloc. avg. when run Dealloc. avg. when run ";
1204 out <<
"FastReport CPU time avg. Real time avg. Alloc. avg. Dealloc. avg. ";
1210 template <
typename T>
1213 out <<
"FastReport CPU time sched. / depend. Real time sched. / depend. Alloc. sched. / depend. Dealloc. sched. / depend. ";
1219 template <
typename T>
1221 out << fmt::sprintf(
1223 "FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1232 template <
typename T>
1235 out << fmt::sprintf(
1237 "FastReport %10.1f ms %10.1f ms %10.1f ms %10.1f ms %+10d kB %+10d kB %+10d kB %+10d kB %s\n",
1240 (active ? ms(
data.time_thread) / active : 0),
1242 (active ? ms(
data.time_real) / active : 0),
1244 (active ? +static_cast<int64_t>(kB(
data.allocated) / active) : 0),
1246 (active ? -static_cast<int64_t>(kB(
data.deallocated) / active) : 0),
1250 template <
typename T>
1255 out << fmt::sprintf(
1257 "FastReport %10.1f ms %10.1f ms %+10d kB %+10d kB %s\n",
1266 template <
typename T>
1269 out << fmt::sprintf(
1270 "FastReport %10.1f ms %10.1f ms %10.1f ms %10.1f ms %+10d kB %+10d kB %+10d kB %+10d kB %s\n",
1272 (active ? ms(
data.time_thread) / active : 0),
1274 (active ? ms(
data.time_real) / active : 0),
1276 (active ? +static_cast<int64_t>(kB(
data.allocated) / active) : 0),
1278 (active ? -static_cast<int64_t>(kB(
data.deallocated) / active) : 0),
1282 template <
typename T>
1285 out << fmt::sprintf(
1286 "FastReport %10.1f ms %10.1f ms %10.1f ms %10.1f ms %+10d kB %+10d kB %+10d kB %+10d kB %s\n",
1298 template <
typename T>
1301 printSummaryHeader(
out,
"Modules",
true);
1302 auto const& source_d = callgraph_.source();
1303 auto const&
source =
data.modules[source_d.id()];
1305 for (
unsigned int i = 0;
i < callgraph_.processes().size(); ++
i) {
1306 auto const& proc_d = callgraph_.processDescription(
i);
1308 printSummaryLine(
out,
proc.total,
data.events,
"process " + proc_d.name_);
1309 for (
unsigned int m : proc_d.modules_) {
1310 auto const& module_d = callgraph_.module(
m);
1311 auto const& module =
data.modules[
m];
1312 printSummaryLine(
out, module.total,
data.events, module.events,
" " + module_d.moduleLabel());
1315 printSummaryLine(
out,
data.total,
data.events,
"total");
1316 printSummaryLine(
out,
data.overhead,
data.events,
"other");
1318 printPathSummaryHeader(
out,
"Processes and Paths");
1319 printSummaryLine(
out,
source.total,
data.events, source_d.moduleLabel());
1320 for (
unsigned int i = 0;
i < callgraph_.processes().size(); ++
i) {
1321 auto const& proc_d = callgraph_.processDescription(
i);
1323 printSummaryLine(
out,
proc.total,
data.events,
"process " + proc_d.name_);
1324 for (
unsigned int p = 0;
p <
proc.paths.size(); ++
p) {
1325 auto const&
name = proc_d.paths_[
p].name_;
1329 for (
unsigned int p = 0;
p <
proc.endpaths.size(); ++
p) {
1330 auto const&
name = proc_d.endPaths_[
p].name_;
1335 printSummaryLine(
out,
data.total,
data.events,
"total");
1336 printSummaryLine(
out,
data.overhead,
data.events,
"other");
1338 for (
unsigned int group : boost::irange(0ul, highlight_modules_.size())) {
1339 printSummaryHeader(
out,
"Highlighted modules",
true);
1341 auto const& module_d = callgraph_.module(
m);
1342 auto const& module =
data.modules[
m];
1343 printSummaryLine(
out, module.total,
data.events, module.events, module_d.moduleLabel());
1350 template <
typename T>
1352 printEventHeader(
out,
"Transition");
1356 template <
typename T>
1360 T const&
data)
const {
1364 {
"time_thread", ms(
data.time_thread)},
1365 {
"time_real", ms(
data.time_real)},
1366 {
"mem_alloc", kB(
data.allocated)},
1367 {
"mem_free", kB(
data.deallocated)}};
1379 json{{
"time_thread",
"cpu time"}},
1380 json{{
"mem_alloc",
"allocated memory"}},
1381 json{{
"mem_free",
"deallocated memory"}}});
1384 j[
"total"] = encodeToJSON(
"Job", callgraph_.processDescription(0).name_,
data.events,
data.total +
data.overhead);
1388 for (
unsigned int i = 0;
i < callgraph_.size(); ++
i) {
1389 auto const& module = callgraph_.module(
i);
1390 auto const& data_m =
data.modules[
i];
1391 j[
"modules"].push_back(encodeToJSON(module, data_m));
1395 j[
"modules"].push_back(encodeToJSON(
"other",
"other",
data.events,
data.overhead));
1398 out << std::setw(2) <<
j << std::flush;
1414 unsigned int old_value =
check.fetch_add(1, std::memory_order_acq_rel);
1415 return (old_value == callgraph_.processes().size() - 1);
1421 ignoredSignal(__func__);
1425 auto&
stream = streams_[sid];
1426 auto&
process = callgraph_.processDescription(pid);
1430 for (
unsigned int id :
process.modules_)
1435 bool last = isLastSubprocess(subprocess_event_check_[sid]);
1440 stream.event_measurement.measure_and_store(
stream.event);
1443 unsigned int id = 0;
1447 for (
unsigned int group : boost::irange(0ul, highlight_modules_.size()))
1453 std::lock_guard<std::mutex> guard(summary_mutex_);
1458 if (print_event_summary_) {
1470 auto&
stream = streams_[sid];
1474 subprocess_event_check_[sid] = 0;
1477 auto& measurement = thread();
1478 measurement.measure_and_accumulate(
stream.overhead);
1479 stream.event_measurement = measurement;
1484 unsigned int id = md.
id();
1485 auto&
stream = streams_[sid];
1488 thread().measure_and_store(module.total);
1495 unsigned int id = pc.
pathID();
1496 auto&
stream = streams_[sid];
1498 data.status =
false;
1507 unsigned int id = pc.
pathID();
1508 auto&
stream = streams_[sid];
1512 pc.
isEndPath() ? callgraph_.processDescription(pid).endPaths_[
id] : callgraph_.processDescription(pid).paths_[
id];
1513 unsigned int index =
path.modules_on_path_.empty() ? 0 :
status.index() + 1;
1514 data.last =
path.modules_on_path_.empty() ? 0 :
path.last_dependency_of_module_[
status.index()];
1516 for (
unsigned int i = 0;
i <
index; ++
i) {
1517 auto const& module =
stream.modules[
path.modules_on_path_[
i]];
1518 data.active += module.total;
1520 for (
unsigned int i = 0;
i <
data.last; ++
i) {
1521 auto const& module =
stream.modules[
path.modules_and_dependencies_[
i]];
1522 data.total += module.total;
1528 auto&
stream = streams_[sid];
1529 thread().measure_and_accumulate(
stream.overhead);
1534 unsigned int id = md.
id();
1536 auto&
stream = streams_[sid];
1539 module.has_acquire =
true;
1540 thread().measure_and_store(module.total);
1545 auto&
stream = streams_[sid];
1546 thread().measure_and_accumulate(
stream.overhead);
1551 unsigned int id = md.
id();
1553 auto&
stream = streams_[sid];
1556 if (module.has_acquire) {
1557 thread().measure_and_accumulate(module.total);
1559 thread().measure_and_store(module.total);
1565 unsupportedSignal(__func__);
1569 unsupportedSignal(__func__);
1573 ignoredSignal(__func__);
1577 ignoredSignal(__func__);
1581 ignoredSignal(__func__);
1585 ignoredSignal(__func__);
1589 thread().measure_and_accumulate(overhead_);
1594 thread().measure_and_accumulate(run_transition_[
index]);
1598 thread().measure_and_accumulate(overhead_);
1603 thread().measure_and_accumulate(run_transition_[
index]);
1607 thread().measure_and_accumulate(overhead_);
1612 thread().measure_and_accumulate(lumi_transition_[
index]);
1616 thread().measure_and_accumulate(overhead_);
1621 thread().measure_and_accumulate(lumi_transition_[
index]);
1625 thread().measure_and_accumulate(overhead_);
1630 thread().measure_and_accumulate(run_transition_[
index]);
1634 thread().measure_and_accumulate(overhead_);
1639 thread().measure_and_accumulate(run_transition_[
index]);
1643 thread().measure_and_accumulate(overhead_);
1648 thread().measure_and_accumulate(lumi_transition_[
index]);
1652 thread().measure_and_accumulate(overhead_);
1657 thread().measure_and_accumulate(lumi_transition_[
index]);
1667 thread().measure_and_accumulate(overhead_);
1675 desc.addUntracked<
bool>(
"printEventSummary",
false);
1676 desc.addUntracked<
bool>(
"printRunSummary",
true);
1677 desc.addUntracked<
bool>(
"printJobSummary",
true);
1682 desc.addUntracked<
bool>(
"writeJSONSummary",
false);
1685 desc.addUntracked<
bool>(
"enableDQM",
true);
1686 desc.addUntracked<
bool>(
"enableDQMbyModule",
false);
1687 desc.addUntracked<
bool>(
"enableDQMbyPath",
false);
1688 desc.addUntracked<
bool>(
"enableDQMbyLumiSection",
false);
1689 desc.addUntracked<
bool>(
"enableDQMbyProcesses",
false);
1690 desc.addUntracked<
bool>(
"enableDQMTransitions",
false);
1691 desc.addUntracked<
double>(
"dqmTimeRange", 1000.);
1692 desc.addUntracked<
double>(
"dqmTimeResolution", 5.);
1693 desc.addUntracked<
double>(
"dqmMemoryRange", 1000000.);
1694 desc.addUntracked<
double>(
"dqmMemoryResolution", 5000.);
1695 desc.addUntracked<
double>(
"dqmPathTimeRange", 100.);
1696 desc.addUntracked<
double>(
"dqmPathTimeResolution", 0.5);
1697 desc.addUntracked<
double>(
"dqmPathMemoryRange", 1000000.);
1698 desc.addUntracked<
double>(
"dqmPathMemoryResolution", 5000.);
1699 desc.addUntracked<
double>(
"dqmModuleTimeRange", 40.);
1700 desc.addUntracked<
double>(
"dqmModuleTimeResolution", 0.2);
1701 desc.addUntracked<
double>(
"dqmModuleMemoryRange", 100000.);
1702 desc.addUntracked<
double>(
"dqmModuleMemoryResolution", 500.);
1703 desc.addUntracked<
unsigned>(
"dqmLumiSectionsRange", 2500);
1707 highlightModulesDescription.
addUntracked<std::vector<std::string>>(
"modules", {});
1708 highlightModulesDescription.addUntracked<
std::string>(
"label",
"producers");
1709 desc.addVPSetUntracked(
"highlightModules", highlightModulesDescription, {});
1714 ->setComment(
"This parameter is obsolete and will be ignored.");
1716 ->setComment(
"This parameter is obsolete and will be ignored.");
1718 ->setComment(
"This parameter is obsolete and will be ignored.");
1720 ->setComment(
"This parameter is obsolete and will be ignored.");
1722 ->setComment(
"This parameter is obsolete and will be ignored.");
1724 ->setComment(
"This parameter is obsolete and will be ignored.");
1726 ->setComment(
"This parameter is obsolete and will be ignored.");
1728 ->setComment(
"This parameter is obsolete and will be ignored.");
1730 ->setComment(
"This parameter is obsolete and will be ignored.");
1732 ->setComment(
"This parameter is obsolete and will be ignored.");
1734 ->setComment(
"This parameter is obsolete and will be ignored.");
1736 ->setComment(
"This parameter is obsolete and will be ignored.");
1738 ->setComment(
"This parameter is obsolete and will be ignored.");
1740 ->setComment(
"This parameter is obsolete and will be ignored.");
1742 descriptions.
add(
"FastTimerService",
desc);