File indexing completed on 2024-04-06 12:18:46
0001 #include <TROOT.h>
0002 #include <TFile.h>
0003 #include <THashList.h>
0004 #include <TH2D.h>
0005 #include <TAttText.h>
0006 #include <TCanvas.h>
0007 #include <TStyle.h>
0008 #include <TTree.h>
0009 #include <TBranch.h>
0010 #include <TSystem.h>
0011 #include <THStack.h>
0012
0013 #include <boost/program_options.hpp>
0014 #include <cmath>
0015 #include <cstdio>
0016 #include <cstdlib>
0017 #include <fstream>
0018 #include <iostream>
0019 #include <string>
0020
0021 #include "DataFormats/HLTReco/interface/HLTPerformanceInfo.h"
0022 #include "DataFormats/Provenance/interface/EventAuxiliary.h"
0023 #include "FWCore/FWLite/interface/FWLiteEnabler.h"
0024 #include "DataFormats/Common/interface/Wrapper.h"
0025
0026
0027
0028
0029
0030
0031
0032 void printTiming(double cpu, double real) {
0033 std::cout << "Timing info: " << cpu << " (cpu) and " << real << " (wall) seconds" << std::endl;
0034 }
0035
0036 bool useEvent(int evt, std::vector<int> skip) {
0037 for (unsigned int i = 0; i < skip.size(); i++)
0038 if (evt == skip.at(i))
0039 return false;
0040 return true;
0041 }
0042
0043
0044
0045 bool acceptedEvt(std::vector<double> pathStatus) {
0046 for (unsigned int i = 0; i < pathStatus.size(); i++)
0047 if (pathStatus.at(i) == -1)
0048 return true;
0049 return false;
0050 }
0051
0052
0053
0054 bool useModuleByName(HLTPerformanceInfo::Module module, std::vector<std::string> skip) {
0055 for (unsigned int i = 0; i < skip.size(); i++)
0056 if (module.name() == skip.at(i))
0057 return false;
0058 return true;
0059 }
0060
0061
0062
0063 bool usePathByName(HLTPerformanceInfo::Path path, std::vector<std::string> skip) {
0064 for (unsigned int i = 0; i < skip.size(); i++)
0065 if (path.name() == skip.at(i))
0066 return false;
0067 return true;
0068 }
0069
0070
0071 void initialize(HLTPerformanceInfo hltPerf,
0072 std::vector<std::string> skipMod,
0073 std::vector<std::string> skipPath,
0074 std::vector<bool>* mod,
0075 std::vector<bool>* path,
0076 std::vector<std::vector<bool> >* mip,
0077 std::vector<std::string>* mNames,
0078 std::vector<std::string>* pNames,
0079 std::vector<std::vector<std::string> >* mipNames,
0080 int& nmods,
0081 int& npaths,
0082 std::vector<int>* nmips,
0083 std::vector<std::vector<int> >* mIdx,
0084 std::vector<std::vector<bool> >* unique,
0085 std::vector<std::vector<int> >* mipMapper,
0086 std::vector<int>* mIdxInt,
0087 std::vector<std::string> mInt,
0088 std::vector<int>* modExist) {
0089
0090
0091 mod->clear();
0092 mip->clear();
0093 std::vector<std::string> names;
0094 names.clear();
0095 std::vector<std::string> uniqueModInSkipPaths;
0096 uniqueModInSkipPaths.clear();
0097 nmods = 0;
0098 npaths = 0;
0099
0100
0101 for (size_t piter = 0; piter < hltPerf.numberOfPaths(); ++piter) {
0102 const HLTPerformanceInfo::Path p = hltPerf.getPath(piter);
0103 int ctr = 0;
0104 std::vector<bool> pathMod;
0105 pathMod.clear();
0106 std::vector<int> modIdx;
0107 modIdx.clear();
0108 std::vector<bool> onlyOne;
0109 onlyOne.clear();
0110 if (usePathByName(p, skipPath)) {
0111 for (size_t mm = 0; mm < hltPerf.getPath(piter).numberOfModules(); ++mm) {
0112 const HLTPerformanceInfo::Module& modIter = hltPerf.getModuleOnPath(mm, piter);
0113 if (useModuleByName(modIter, skipMod)) {
0114 pathMod.push_back(true);
0115 names.push_back(modIter.name());
0116 modIdx.push_back(hltPerf.moduleIndexInPath(modIter.name().c_str(), hltPerf.getPath(piter).name().c_str()));
0117 onlyOne.push_back(hltPerf.uniqueModule(modIter.name().c_str()));
0118 ctr++;
0119 } else {
0120 pathMod.push_back(false);
0121 }
0122 }
0123 } else if (!usePathByName(p, skipPath)) {
0124 for (size_t mm = 0; mm < hltPerf.getPath(piter).numberOfModules(); ++mm) {
0125 const HLTPerformanceInfo::Module& modIter = hltPerf.getModuleOnPath(mm, piter);
0126 if (useModuleByName(modIter, skipMod)) {
0127 if (hltPerf.uniqueModule(modIter.name().c_str())) {
0128 uniqueModInSkipPaths.push_back(modIter.name());
0129 }
0130 }
0131 }
0132 }
0133
0134 if (ctr > 0) {
0135 path->push_back(true);
0136 pNames->push_back(p.name());
0137 mipNames->push_back(names);
0138 mIdx->push_back(modIdx);
0139 unique->push_back(onlyOne);
0140 nmips->push_back(ctr);
0141 std::vector<int> mip2mIdx(ctr, -1);
0142 mipMapper->push_back(mip2mIdx);
0143 npaths++;
0144 } else {
0145 path->push_back(false);
0146 }
0147 mip->push_back(pathMod);
0148 names.clear();
0149 }
0150
0151
0152 for (size_t i = 0; i < hltPerf.numberOfModules(); ++i) {
0153 const HLTPerformanceInfo::Module& myModule = hltPerf.getModule(i);
0154 if (useModuleByName(myModule, skipMod)) {
0155 if (useModuleByName(myModule, uniqueModInSkipPaths)) {
0156 mod->push_back(true);
0157 mNames->push_back(myModule.name());
0158
0159 for (unsigned int i = 0; i < unsigned(npaths); i++)
0160 for (unsigned int j = 0; j < unsigned(nmips->at(i)); j++)
0161 if (mipNames->at(i).at(j) == myModule.name())
0162 mipMapper->at(i).at(j) = nmods;
0163 nmods++;
0164 } else {
0165 mod->push_back(false);
0166 }
0167 } else {
0168 mod->push_back(false);
0169 }
0170 }
0171
0172 modExist->resize(nmods, 0);
0173
0174 for (unsigned int i = 0; i < unsigned(npaths); i++) {
0175 for (unsigned int j = 0; j < unsigned(nmips->at(i)); j++) {
0176 int mipIndex = mipMapper->at(i).at(j);
0177 modExist->at(mipIndex)++;
0178 }
0179 }
0180
0181
0182 for (unsigned i = 0; i < mInt.size(); i++) {
0183 std::vector<std::string>::iterator modpointer = std::find(mNames->begin(), mNames->end(), mInt.at(i));
0184 if (modpointer != mNames->end()) {
0185 std::vector<std::string>::size_type indexValue = (modpointer - mNames->begin());
0186 mIdxInt->push_back(indexValue);
0187 }
0188 }
0189 }
0190
0191 double getTime(HLTPerformanceInfo::Module mod, bool useCPU) {
0192 if (useCPU)
0193 return mod.cputime();
0194 return mod.time();
0195 }
0196
0197 double calculateMiPTime(std::vector<double> modTimes, double pathStatus, int mipIndex, int mIdx) {
0198 double time = -1.;
0199 if (mipIndex >= 0)
0200 if ((pathStatus == -1.) || (pathStatus >= double(mIdx)))
0201 time = modTimes.at(mipIndex);
0202 return time;
0203 }
0204
0205 TH1D* createSummaryHistogram(
0206 std::string name, std::string title, unsigned int nbins, std::vector<std::string> labels, std::string yaxis) {
0207 TH1D* histo = new TH1D(name.c_str(), title.c_str(), int(nbins), 0., double(nbins));
0208 for (unsigned int i = 0; i < nbins; i++)
0209 histo->GetXaxis()->SetBinLabel(i + 1, labels.at(i).c_str());
0210
0211 histo->SetMinimum(0.);
0212 histo->GetYaxis()->SetTitle(yaxis.c_str());
0213 return histo;
0214 }
0215
0216 std::vector<TH1D*> createEventHistograms(std::string name,
0217 std::string title,
0218 unsigned int nHistos,
0219 std::vector<std::string> nameTag,
0220 int nbins,
0221 double min,
0222 double max) {
0223 std::vector<TH1D*> histos;
0224 histos.clear();
0225 for (unsigned int i = 0; i < nHistos; i++) {
0226 std::string fullName = name + "_" + nameTag.at(i);
0227 std::string fullTitle = title + " " + nameTag.at(i);
0228 TH1D* histo = new TH1D(fullName.c_str(), fullTitle.c_str(), nbins, min, max);
0229 histo->GetXaxis()->SetTitle("msec");
0230 histo->StatOverflows(kTRUE);
0231 histos.push_back(histo);
0232 }
0233 return histos;
0234 }
0235
0236 bool isFilterModule(HLTPerformanceInfo::Module module, std::vector<std::string> modList) {
0237 for (unsigned int i = 0; i < modList.size(); i++)
0238 if (module.name() == modList.at(i))
0239 return true;
0240 return false;
0241 }
0242
0243
0244
0245
0246
0247
0248
0249
0250
0251
0252
0253
0254
0255
0256
0257
0258
0259
0260
0261
0262
0263
0264
0265
0266
0267
0268
0269
0270
0271
0272
0273
0274
0275
0276
0277
0278
0279
0280
0281
0282
0283
0284
0285
0286
0287
0288
0289
0290
0291
0292
0293
0294
0295
0296
0297
0298
0299
0300
0301
0302
0303
0304
0305
0306
0307
0308
0309
0310
0311
0312
0313
0314
0315
0316
0317
0318
0319
0320
0321
0322
0323
0324
0325
0326
0327
0328
0329
0330
0331
0332
0333
0334
0335
0336
0337
0338
0339
0340
0341
0342
0343
0344
0345
0346
0347
0348
0349
0350
0351
0352
0353
0354
0355
0356
0357
0358
0359
0360
0361
0362
0363
0364
0365
0366
0367
0368
0369
0370
0371
0372
0373
0374
0375
0376
0377
0378
0379
0380
0381
0382
0383
0384
0385
0386
0387
0388
0389
0390
0391
0392
0393
0394
0395
0396
0397
0398
0399
0400
0401
0402
0403
0404
0405
0406
0407
0408
0409
0410
0411
0412
0413
0414
0415
0416
0417
0418
0419
0420
0421
0422
0423
0424
0425
0426
0427
0428
0429
0430
0431
0432
0433
0434
0435
0436
0437
0438
0439
0440
0441
0442
0443
0444
0445
0446
0447
0448
0449
0450
0451
0452
0453
0454
0455
0456
0457
0458
0459
0460
0461
0462
0463
0464
0465
0466
0467
0468
0469
0470
0471
0472
0473
0474
0475
0476
0477
0478
0479
0480
0481
0482
0483
0484
0485
0486
0487
0488
0489
0490
0491
0492
0493
0494
0495
0496
0497
0498
0499
0500
0501
0502
0503
0504
0505
0506
0507
0508
0509
0510
0511
0512
0513
0514
0515
0516
0517
0518
0519
0520
0521
0522
0523
0524
0525
0526
0527
0528
0529
0530
0531
0532 void slowestModules(TH1D* histo,
0533 std::vector<std::string>* mods,
0534 std::vector<double>* time,
0535 int nMods,
0536 std::vector<std::string> mNames) {
0537 mods->clear();
0538 mods->resize(3, "none");
0539 time->clear();
0540 time->resize(3, -1.);
0541
0542 for (unsigned int i = 0; i < unsigned(nMods); i++) {
0543 bool foundMax = false;
0544 for (unsigned int j = 0; j < 3; j++) {
0545 if (!foundMax && (histo->GetBinContent(i + 1) > time->at(j))) {
0546
0547 bool inList = false;
0548 for (unsigned int k = 0; k < j; k++)
0549 if (mNames.at(i) == mods->at(k))
0550 inList = true;
0551
0552 if (!inList) {
0553 foundMax = true;
0554 if (j == 0) {
0555 time->at(2) = time->at(1);
0556 mods->at(2) = mods->at(1);
0557 time->at(1) = time->at(0);
0558 mods->at(1) = mods->at(0);
0559 }
0560 if (j == 1) {
0561 time->at(2) = time->at(1);
0562 mods->at(2) = mods->at(1);
0563 }
0564
0565 time->at(j) = histo->GetBinContent(i + 1);
0566 mods->at(j) = mNames.at(i);
0567 }
0568 }
0569 }
0570 }
0571 }
0572
0573 void slowestModules(std::vector<TH1D*> histo,
0574 std::vector<std::string>* path,
0575 std::vector<std::string>* mip,
0576 std::vector<double>* time,
0577 int nPaths,
0578 std::vector<int> nmips,
0579 std::vector<std::string> pNames,
0580 std::vector<std::vector<std::string> > mipNames) {
0581 path->clear();
0582 path->resize(3, "none");
0583 mip->clear();
0584 mip->resize(3, "none");
0585 time->clear();
0586 time->resize(3, -1.);
0587
0588 for (unsigned int i = 0; i < unsigned(nPaths); i++) {
0589 for (unsigned int j = 0; j < unsigned(nmips.at(i)); j++) {
0590 bool foundMax = false;
0591 for (unsigned int k = 0; k < 3; k++) {
0592 if (!foundMax && (histo.at(i)->GetBinContent(j + 1) > time->at(k))) {
0593
0594 bool inList = false;
0595 for (unsigned int l = 0; l < k; l++)
0596 if (mipNames.at(i).at(j) == mip->at(l))
0597 inList = true;
0598
0599 if (!inList) {
0600 foundMax = true;
0601 if (k == 0) {
0602 time->at(2) = time->at(1);
0603 path->at(2) = path->at(1);
0604 mip->at(2) = mip->at(1);
0605 time->at(1) = time->at(0);
0606 path->at(1) = path->at(0);
0607 mip->at(1) = mip->at(0);
0608 }
0609 if (k == 1) {
0610 time->at(2) = time->at(1);
0611 path->at(2) = path->at(1);
0612 mip->at(2) = mip->at(1);
0613 }
0614
0615 time->at(k) = histo.at(i)->GetBinContent(j + 1);
0616 path->at(k) = pNames.at(i);
0617 mip->at(k) = mipNames.at(i).at(j);
0618 }
0619 }
0620 }
0621 }
0622 }
0623 }
0624
0625 int main(int argc, char** argv) {
0626
0627
0628
0629
0630
0631 gSystem->Load("libFWCoreFWLite");
0632 FWLiteEnabler::enable();
0633
0634
0635 std::string filename = "hlt.root";
0636 std::string outbase = "hltTimingSummary";
0637 std::string outname = outbase + ".root";
0638 std::string sumname;
0639 std::vector<std::string> skipTimingMod;
0640 skipTimingMod.clear();
0641 std::vector<std::string> skipTimingPath;
0642 skipTimingPath.clear();
0643 std::vector<std::string> squareOne;
0644 squareOne.clear();
0645 std::string strSpecificTotalTime;
0646 std::string excludeModName, excludePathName, startHere;
0647 std::string modPrintName;
0648 std::vector<std::string> modInterested;
0649 modInterested.clear();
0650
0651
0652 bool writeSummary = false;
0653 bool takeCPUtime = false;
0654
0655
0656
0657 double userMaxTime = -1.;
0658 double userBinWidth = -1.;
0659 bool skipFirstEvent = false;
0660 std::vector<std::pair<double, double> > specificTotalTime;
0661 int numberOfspecificTotalTime = 0;
0662
0663
0664 double totalTimeThreshold = -1.;
0665 double pathTimeThreshold = -1.;
0666 double moduleTimeThreshold = -1.;
0667
0668
0669 boost::program_options::options_description desc("Available options for hltTimingSummary");
0670 desc.add_options()("help,h", "Print this help message")(
0671 "infile,i", boost::program_options::value<std::string>(), "Input file name (Default is hlt.root)")(
0672 "outfile,o",
0673 boost::program_options::value<std::string>(),
0674 "Sets output files to <UserName>.root (default is hltTimingSummary)")(
0675 "summary,s",
0676 "Creates user-friendly timing summary file <UserName>-summary.txt. See \"-o\" option for <UserName>")(
0677 "cpu,c", "Results presented as CPU time (in msec). Default is wall clock.")(
0678 "time,t",
0679 boost::program_options::value<double>(),
0680 "All relevant histogram time axes run from 0 to <UserValue> (in msec)")(
0681 "bin,b",
0682 boost::program_options::value<double>(),
0683 "Bin size (in msec) for relevant timing histograms, specified by the user")(
0684 "noFirst,f", "Skip ANY event where a module is run for the first time (By default, run over all events)")
0685
0686
0687 ("recalc,r",
0688 boost::program_options::value<std::string>(),
0689 "Recalculate rejection factor starting from specified list of filters/modules")(
0690 "excludeMod,e",
0691 boost::program_options::value<std::string>(),
0692 "Exclude a list of modules from the timing calculation")(
0693 "excludePath,x",
0694 boost::program_options::value<std::string>(),
0695 "Exclude a list of paths from the timing calculation")(
0696 "timelimit,l",
0697 boost::program_options::value<double>(),
0698 "Events where total time exceeds user-specified limit (in msec) listed in summary file")(
0699 "modPrint,g",
0700 boost::program_options::value<std::string>(),
0701 "Print event and run number of the user's input modules")(
0702 "pathlimit,a",
0703 boost::program_options::value<double>(),
0704 "Events where any path time exceeds user-specified limit (in msec) listed in summary file")(
0705 "modulelimit,m",
0706 boost::program_options::value<double>(),
0707 "Events where any module time exceeds user-specified limit (in msec) listed in summary file")(
0708 "timeSpecific,q",
0709 boost::program_options::value<std::string>(),
0710 "Overplots events with total time exceeds user-specified limit (in msec) for each pathTime: "
0711 "minTime,maxTimeAminTime,maxTimeA... Example:23,45A200,300");
0712
0713 std::string usage = "\nSample hltTimingSummary usage::\n";
0714 usage += "\"hltTimingSummary -t 50 -b 5 -r filter1 -p 1\" ";
0715 usage += "inputs hlt.root, outputs hltTimingsummary.root,\n";
0716 usage += " Timing histograms run from 0 to 50 msec with 5 msec bins.\n";
0717 usage += " Rejection factor recalculated for paths including filter1.\n";
0718 usage += "\"hltTimingSummary -i in.root -f -e exclude.txt -o out -s\" ";
0719 usage += "inputs in.root, outputs out.root, out-summary.txt\n";
0720 usage += " Also skips events where modules are first run, and excludes \n";
0721 usage += " the modules listed in exclude.txt from timing calculations.\n\n";
0722 usage += "NOTE: To exclude files or use filters, the following formats are acceptable:\n";
0723 usage += " - A comma-separated list of modules (e.g. \"hltTimingSummary -e a,b,c\")\n";
0724 usage += " - A text file, where each excluded module appears on its own line\n";
0725 usage += " (e.g. \"hltTimingSummary -r file.txt\")\n";
0726
0727 boost::program_options::positional_options_description pos;
0728 boost::program_options::variables_map vmap;
0729
0730 try {
0731 boost::program_options::store(
0732 boost::program_options::command_line_parser(argc, argv).options(desc).positional(pos).run(), vmap);
0733 } catch (boost::program_options::error const& x) {
0734 std::cerr << "Unable to parse options:\n" << x.what() << "\n\n";
0735 std::cerr << desc << usage << std::endl;
0736 return 1;
0737 }
0738
0739 boost::program_options::notify(vmap);
0740 if (vmap.count("help")) {
0741 std::cout << desc << usage << std::endl;
0742 return 1;
0743 }
0744 if (vmap.count("infile")) {
0745 filename = vmap["infile"].as<std::string>();
0746 }
0747 if (vmap.count("outfile")) {
0748 outbase = vmap["outfile"].as<std::string>();
0749 outname = outbase + ".root";
0750 }
0751 if (vmap.count("summary") || vmap.count("timelimit") || vmap.count("pathlimit") || vmap.count("modulelimit")) {
0752 writeSummary = true;
0753 sumname = outbase + "-summary.txt";
0754 if (!vmap.count("summary"))
0755 std::cout << "Summary option not specified but time limit option(s) included. Summary file will be generated."
0756 << std::endl;
0757 if (vmap.count("timelimit"))
0758 totalTimeThreshold = vmap["timelimit"].as<double>();
0759 if (vmap.count("pathlimit"))
0760 pathTimeThreshold = vmap["pathlimit"].as<double>();
0761 if (vmap.count("modulelimit"))
0762 moduleTimeThreshold = vmap["modulelimit"].as<double>();
0763 }
0764 if (vmap.count("cpu")) {
0765 takeCPUtime = true;
0766 std::cout << "NOTE: You have elected to display results using CPU time." << std::endl;
0767 std::cout << " Due to resolution effects in CPUTimer, event histogram results " << std::endl;
0768 std::cout << " may not reflect reality. **Use at your own risk**" << std::endl << std::endl;
0769 }
0770 if (vmap.count("time")) {
0771 userMaxTime = vmap["time"].as<double>();
0772 }
0773 if (vmap.count("bin")) {
0774 userBinWidth = vmap["bin"].as<double>();
0775 }
0776 if (vmap.count("noFirst")) {
0777 skipFirstEvent = true;
0778 }
0779
0780
0781
0782 if (vmap.count("recalc")) {
0783 startHere = vmap["recalc"].as<std::string>();
0784 std::ifstream filterFile(startHere.c_str());
0785 if (filterFile.is_open()) {
0786 while (!filterFile.eof()) {
0787 std::string skipped;
0788 getline(filterFile, skipped);
0789
0790 size_t spos = skipped.find_first_not_of(' ');
0791 size_t epos = skipped.find_last_not_of(' ');
0792 if (spos != std::string::npos && epos != std::string::npos) {
0793 skipped = skipped.substr(spos, epos);
0794 squareOne.push_back(skipped);
0795 }
0796 }
0797 } else {
0798 size_t strStart = 0;
0799 for (size_t itr = startHere.find(',', 0); itr != std::string::npos; itr = startHere.find(',', itr)) {
0800 std::string skipped = startHere.substr(strStart, (itr - strStart));
0801 itr++;
0802 strStart = itr;
0803 squareOne.push_back(skipped);
0804 }
0805
0806 squareOne.push_back(startHere.substr(strStart, startHere.length()));
0807 }
0808 }
0809 if (vmap.count("excludeMod")) {
0810 excludeModName = vmap["excludeMod"].as<std::string>();
0811
0812 std::ifstream excludeModFile(excludeModName.c_str());
0813 if (excludeModFile.is_open()) {
0814 while (!excludeModFile.eof()) {
0815 std::string skipped;
0816 getline(excludeModFile, skipped);
0817
0818 size_t spos = skipped.find_first_not_of(' ');
0819 size_t epos = skipped.find_last_not_of(' ');
0820 if (spos != std::string::npos && epos != std::string::npos) {
0821 skipped = skipped.substr(spos, epos + 1);
0822 skipTimingMod.push_back(skipped);
0823 }
0824 }
0825 } else {
0826 size_t strStart = 0;
0827 for (size_t itr = excludeModName.find(',', 0); itr != std::string::npos; itr = excludeModName.find(',', itr)) {
0828 std::string skipped = excludeModName.substr(strStart, (itr - strStart));
0829 itr++;
0830 strStart = itr;
0831 skipTimingMod.push_back(skipped);
0832 }
0833
0834 skipTimingMod.push_back(excludeModName.substr(strStart, excludeModName.length()));
0835 }
0836 }
0837
0838 if (vmap.count("excludePath")) {
0839 excludePathName = vmap["excludePath"].as<std::string>();
0840
0841 std::ifstream excludePathFile(excludePathName.c_str());
0842 if (excludePathFile.is_open()) {
0843 while (!excludePathFile.eof()) {
0844 std::string skipped;
0845 getline(excludePathFile, skipped);
0846
0847 size_t spos = skipped.find_first_not_of(' ');
0848 size_t epos = skipped.find_last_not_of(' ');
0849 if (spos != std::string::npos && epos != std::string::npos) {
0850 skipped = skipped.substr(spos, epos + 1);
0851 skipTimingPath.push_back(skipped);
0852 }
0853 }
0854 } else {
0855 size_t strStart = 0;
0856 for (size_t itr = excludePathName.find(',', 0); itr != std::string::npos; itr = excludePathName.find(',', itr)) {
0857 std::string skipped = excludePathName.substr(strStart, (itr - strStart));
0858 itr++;
0859 strStart = itr;
0860 skipTimingPath.push_back(skipped);
0861 }
0862
0863 skipTimingPath.push_back(excludePathName.substr(strStart, excludePathName.length()));
0864 }
0865 }
0866
0867 if (vmap.count("modPrint")) {
0868 modPrintName = vmap["modPrint"].as<std::string>();
0869
0870 std::ifstream modPrintFile(modPrintName.c_str());
0871 if (modPrintFile.is_open()) {
0872 while (!modPrintFile.eof()) {
0873 std::string modname;
0874 getline(modPrintFile, modname);
0875
0876 size_t spos = modname.find_first_not_of(' ');
0877 size_t epos = modname.find_last_not_of(' ');
0878 if (spos != std::string::npos && epos != std::string::npos) {
0879 modname = modname.substr(spos, epos + 1);
0880 modInterested.push_back(modname);
0881 }
0882 }
0883 } else {
0884 size_t strStart = 0;
0885 for (size_t itr = modPrintName.find(',', 0); itr != std::string::npos; itr = modPrintName.find(',', itr)) {
0886 std::string modname = modPrintName.substr(strStart, (itr - strStart));
0887 itr++;
0888 strStart = itr;
0889 modInterested.push_back(modname);
0890 }
0891
0892 modInterested.push_back(modPrintName.substr(strStart, modPrintName.length()));
0893 }
0894 }
0895
0896 if (vmap.count("timeSpecific")) {
0897 strSpecificTotalTime = vmap["timeSpecific"].as<std::string>();
0898
0899 unsigned int strStart = 0;
0900 numberOfspecificTotalTime = 0;
0901
0902 for (size_t itr = strSpecificTotalTime.find('A', 0); itr != std::string::npos;
0903 itr = strSpecificTotalTime.find('A', itr)) {
0904 std::string strSpecificTimePair = strSpecificTotalTime.substr(strStart, (itr - strStart));
0905 size_t commaPos = strSpecificTimePair.find(',', 0);
0906 std::pair<double, double> specificTimePair;
0907 specificTimePair.first = atof(strSpecificTimePair.substr(0, commaPos).c_str());
0908 specificTimePair.second =
0909 atof(strSpecificTimePair.substr(commaPos + 1, strSpecificTimePair.length() - 1 - commaPos).c_str());
0910 specificTotalTime.push_back(specificTimePair);
0911 numberOfspecificTotalTime++;
0912 itr++;
0913 strStart = itr;
0914 }
0915
0916 std::string strSpecificTimePair = strSpecificTotalTime.substr(strStart, strSpecificTotalTime.length() - strStart);
0917 size_t commaPos = strSpecificTimePair.find(',', 0);
0918 std::pair<double, double> specificTimePair;
0919 specificTimePair.first = atof(strSpecificTimePair.substr(0, commaPos).c_str());
0920 specificTimePair.second =
0921 atof(strSpecificTimePair.substr(commaPos + 1, strSpecificTimePair.length() - 1 - commaPos).c_str());
0922 specificTotalTime.push_back(specificTimePair);
0923 numberOfspecificTotalTime++;
0924 }
0925
0926
0927 for (unsigned int i = 0; i < skipTimingMod.size(); i++) {
0928 for (unsigned int j = 0; j < squareOne.size(); j++) {
0929 if (skipTimingMod.at(i) == squareOne.at(j)) {
0930 std::cout << "NOTE: You requested that " << squareOne.at(j)
0931 << " be treated as a filter, but you also want it excluded from calculations" << std::endl;
0932 std::cout << "Please select either \"filter\" or \"exclude\" for this module." << std::endl;
0933 return 2;
0934 }
0935 }
0936 }
0937
0938 std::cout << "Opening file " << filename << std::endl;
0939 TFile* file = TFile::Open(filename.c_str());
0940 if (file == nullptr) {
0941 std::cout << "*** Error opening file: " << filename << " ***" << std::endl;
0942 std::cout << "\n\n" << desc << usage << std::endl;
0943 return 1;
0944 }
0945
0946 TTree* events = dynamic_cast<TTree*>(file->Get("Events"));
0947 assert(events);
0948
0949
0950 TIter iter(events->GetListOfBranches());
0951 std::string hltPerfInfoBranchName;
0952 TBranch* cand;
0953 TBranch::ResetCount();
0954 while ((cand = (TBranch*)iter())) {
0955 std::string branchName = cand->GetName();
0956 size_t loc = branchName.find("HLTPerformanceInfo");
0957
0958 if (loc != std::string::npos)
0959 hltPerfInfoBranchName = branchName;
0960 }
0961
0962 TBranch* TBPerfInfo = events->GetBranch(hltPerfInfoBranchName.c_str());
0963
0964 assert(TBPerfInfo);
0965
0966 edm::Wrapper<HLTPerformanceInfo>* HLTPerformanceWrapper = nullptr;
0967 TBPerfInfo->SetAddress((void*)&HLTPerformanceWrapper);
0968
0969
0970 TBranch* TBEvtAux = events->GetBranch("EventAuxiliary");
0971 assert(TBEvtAux);
0972 edm::EventAuxiliary* EvtAuxWrapper = new edm::EventAuxiliary;
0973 TBEvtAux->SetAddress((void*)&EvtAuxWrapper);
0974
0975
0976 TFile* outFile = new TFile(outname.c_str(), "recreate");
0977 std::ofstream txtfile;
0978 std::ofstream sumfile;
0979 if (!writeSummary) {
0980 std::cout << "Output to file: " << outname << std::endl;
0981 } else {
0982
0983 sumfile.open(sumname.c_str());
0984 }
0985
0986 int n_evts = events->GetEntries();
0987
0988
0989
0990
0991 std::vector<int> skipEvents;
0992
0993
0994 double longestEventTime = 0.;
0995 int longestEvent = -1;
0996 double sumTime = 0.;
0997 double sumTimeSq = 0.;
0998 double xmin = 0.;
0999 double xmax = 0.;
1000
1001
1002 std::vector<bool> useModule;
1003 std::vector<bool> usePath;
1004 std::vector<std::vector<bool> > useModuleInPath;
1005 std::vector<std::string> moduleNames;
1006 std::vector<std::string> pathNames;
1007 std::vector<std::vector<std::string> > moduleInPathNames;
1008 int numberOfModules = 0;
1009 int numberOfPaths = 0;
1010 std::vector<int> numberOfModulesInPath;
1011 std::vector<std::vector<int> > moduleIndexByPath;
1012 std::vector<std::vector<bool> > uniqueModule;
1013 std::vector<double> moduleIn;
1014 std::vector<std::vector<int> > numberOfModulesExecution;
1015 std::vector<int> moduleExistence;
1016
1017 std::vector<std::vector<double> > eventModuleTime;
1018 std::vector<std::vector<double> > eventPathStatus;
1019 std::vector<std::vector<double> > moduleInPathIn;
1020 std::vector<std::vector<double> > moduleInPathOut;
1021
1022 std::vector<double> moduleTimeSummaryVector;
1023 std::vector<double> pathTimeSummaryVector;
1024 std::vector<std::vector<double> > specificPathTimeSummaryVector;
1025 std::vector<double> incPathTimeSummaryVector;
1026 std::vector<std::vector<int> > globalModuleInPathMapper;
1027 std::vector<std::vector<double> > moduleInPathTimeSummaryVector;
1028
1029 std::vector<double> longestEventTimeByModule;
1030 std::vector<int> longestEventByModule;
1031 std::vector<int> pathFilterModule;
1032
1033 std::vector<std::pair<unsigned int, unsigned long long> > slowEventSummaryVector;
1034 std::vector<std::pair<unsigned int, unsigned long long> > slowPathSummaryVector;
1035 std::vector<std::pair<unsigned int, unsigned long long> > slowModuleSummaryVector;
1036 std::vector<int> modIdxInterested;
1037 std::vector<std::vector<std::pair<unsigned int, unsigned long long> > > slowModInterestedVector;
1038
1039
1040 bool init = false;
1041 int nSkips = 0;
1042 std::vector<double> eventTime(n_evts, 0.);
1043
1044 for (int ievt = 0; ievt < n_evts; ievt++) {
1045
1046 int pCtr = 0;
1047 int mCtr = 0;
1048
1049 int pIdx = 0;
1050 int mIdx = 0;
1051
1052
1053 if (!init) {
1054 init = true;
1055 TBPerfInfo->GetEntry(ievt);
1056 initialize((*(HLTPerformanceWrapper->product())),
1057 skipTimingMod,
1058 skipTimingPath,
1059 &useModule,
1060 &usePath,
1061 &useModuleInPath,
1062 &moduleNames,
1063 &pathNames,
1064 &moduleInPathNames,
1065 numberOfModules,
1066 numberOfPaths,
1067 &numberOfModulesInPath,
1068 &moduleIndexByPath,
1069 &uniqueModule,
1070 &globalModuleInPathMapper,
1071 &modIdxInterested,
1072 modInterested,
1073 &moduleExistence);
1074
1075 pathTimeSummaryVector.resize(numberOfPaths, 0.);
1076 std::vector<double> specificPathTimeSummaryVectorAtK(numberOfPaths, 0.);
1077 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1078 specificPathTimeSummaryVector.push_back(specificPathTimeSummaryVectorAtK);
1079 }
1080
1081 std::vector<std::pair<unsigned int, unsigned long long> > slowModInterestedVectorAtK;
1082 for (unsigned k = 0; k < modInterested.size(); k++) {
1083 slowModInterestedVector.push_back(slowModInterestedVectorAtK);
1084 }
1085 incPathTimeSummaryVector.resize(numberOfPaths, 0.);
1086 moduleTimeSummaryVector.resize(numberOfModules, 0.);
1087 moduleIn.resize(numberOfModules, 0.);
1088 longestEventTimeByModule.resize(numberOfModules, 0.);
1089 longestEventByModule.resize(numberOfModules, -1);
1090 pathFilterModule.resize(numberOfPaths, -1);
1091
1092
1093 std::vector<std::vector<double> > dMiP;
1094 std::vector<double> dMod(numberOfModules, -1.);
1095 std::vector<int> dModIdx(numberOfModules, 0);
1096 pCtr = 0;
1097 pIdx = 0;
1098
1099 for (size_t piter = 0; piter < (*HLTPerformanceWrapper)->numberOfPaths(); ++piter) {
1100 HLTPerformanceInfo::Path p = (*HLTPerformanceWrapper)->getPath(piter);
1101 if (usePath.at(pCtr)) {
1102
1103 if (!squareOne.empty()) {
1104 mCtr = 0;
1105 mIdx = 0;
1106
1107 for (size_t i = 0; i < (*HLTPerformanceWrapper)->getPath(piter).numberOfModules(); ++i) {
1108 const HLTPerformanceInfo::Module& myModule =
1109 (*HLTPerformanceWrapper)->getModule((*HLTPerformanceWrapper)->getPath(piter).getModuleIndex(i));
1110 if (useModuleInPath.at(pCtr).at(mCtr)) {
1111 if (isFilterModule(myModule, squareOne)) {
1112 if (pathFilterModule.at(pIdx) >= 0) {
1113 std::cout << "WARNING: Filter already set for path " << p.name() << ". Resetting to "
1114 << myModule.name() << std::endl;
1115 }
1116 pathFilterModule.at(pIdx) = mIdx;
1117 }
1118 mIdx++;
1119 }
1120 mCtr++;
1121 }
1122 }
1123
1124 std::vector<double> nMiPs(numberOfModulesInPath.at(pIdx), -1.);
1125 std::vector<double> zMiPs(numberOfModulesInPath.at(pIdx), 0.);
1126 dMiP.push_back(nMiPs);
1127 moduleInPathTimeSummaryVector.push_back(zMiPs);
1128 moduleInPathIn.push_back(zMiPs);
1129 moduleInPathOut.push_back(zMiPs);
1130 pIdx++;
1131 }
1132 pCtr++;
1133 }
1134
1135 eventModuleTime.resize(n_evts, dMod);
1136 numberOfModulesExecution.resize(n_evts, dModIdx);
1137 std::vector<double> dPath(numberOfPaths, -1.);
1138 eventPathStatus.resize(n_evts, dPath);
1139 skipEvents.resize(numberOfModules, -1);
1140 }
1141
1142
1143 TBPerfInfo->GetEntry(ievt);
1144
1145
1146 mCtr = 0;
1147 mIdx = 0;
1148 bool useThisEvent = true;
1149 if (skipFirstEvent && (nSkips < numberOfModules)) {
1150 for (size_t i = 0; i < (*HLTPerformanceWrapper)->numberOfModules(); ++i) {
1151 const HLTPerformanceInfo::Module& myModule = (*HLTPerformanceWrapper)->getModule(i);
1152 if (useModule.at(mCtr++)) {
1153
1154
1155 if (getTime((myModule), false) > 0) {
1156 if (skipEvents.at(mIdx) < 0) {
1157 skipEvents.at(mIdx) = ievt;
1158 if (useThisEvent)
1159 nSkips++;
1160 useThisEvent = false;
1161 }
1162 }
1163 mIdx++;
1164 }
1165 }
1166 }
1167
1168 if (!useThisEvent)
1169 continue;
1170
1171
1172 pCtr = 0;
1173 pIdx = 0;
1174 for (size_t piter = 0; piter < (*HLTPerformanceWrapper)->numberOfPaths(); ++piter) {
1175 const HLTPerformanceInfo::Path p = (*HLTPerformanceWrapper)->getPath(piter);
1176 if (usePath.at(pCtr)) {
1177 mCtr = 0;
1178 mIdx = 0;
1179 for (size_t mm = 0; mm < (*HLTPerformanceWrapper)->getPath(piter).numberOfModules(); ++mm) {
1180 if (useModuleInPath.at(pCtr).at(mCtr)) {
1181 if (moduleIndexByPath.at(pIdx).at(mIdx) <= int(p.status().index())) {
1182 int globalModuleIndex = globalModuleInPathMapper.at(pIdx).at(mIdx);
1183 numberOfModulesExecution.at(ievt).at(globalModuleIndex)++;
1184 mIdx++;
1185 }
1186 }
1187 mCtr++;
1188 }
1189 pIdx++;
1190 }
1191 pCtr++;
1192 }
1193
1194
1195 pCtr = 0;
1196 pIdx = 0;
1197 std::vector<bool> eventCounted(numberOfModules, false);
1198 for (size_t piter = 0; piter < (*HLTPerformanceWrapper)->numberOfPaths(); ++piter) {
1199 const HLTPerformanceInfo::Path p = (*HLTPerformanceWrapper)->getPath(piter);
1200
1201 if (usePath.at(pCtr)) {
1202 if (p.status().accept())
1203 eventPathStatus.at(ievt).at(pIdx) = -1;
1204
1205 mCtr = 0;
1206 mIdx = 0;
1207 for (size_t mm = 0; mm < (*HLTPerformanceWrapper)->getPath(piter).numberOfModules(); ++mm) {
1208 const HLTPerformanceInfo::Module& myModule = (*HLTPerformanceWrapper)->getModuleOnPath(mm, piter);
1209 if (useModuleInPath.at(pCtr).at(mCtr)) {
1210 if (moduleIndexByPath.at(pIdx).at(mIdx) <= int(p.status().index())) {
1211 int globalModuleIndex = globalModuleInPathMapper.at(pIdx).at(mIdx);
1212 if (numberOfModulesExecution.at(ievt).at(globalModuleIndex) > 0) {
1213 moduleInPathTimeSummaryVector.at(pIdx).at(mIdx) += getTime(myModule, takeCPUtime);
1214 pathTimeSummaryVector.at(pIdx) += getTime((myModule), takeCPUtime);
1215 }
1216 if (moduleExistence.at(globalModuleIndex) == 1)
1217 incPathTimeSummaryVector.at(pIdx) += getTime((myModule), takeCPUtime);
1218
1219
1220 moduleInPathIn.at(pIdx).at(mIdx)++;
1221
1222 if (globalModuleIndex >= 0) {
1223 if (!eventCounted.at(unsigned(globalModuleIndex))) {
1224 eventCounted.at(unsigned(globalModuleIndex)) = true;
1225 moduleIn.at(unsigned(globalModuleIndex))++;
1226 }
1227 }
1228
1229 bool modulePassed = false;
1230 if (p.status().accept())
1231 modulePassed = true;
1232 if (moduleIndexByPath.at(pIdx).at(mIdx) < int(p.status().index()))
1233 modulePassed = true;
1234 if (modulePassed) {
1235 moduleInPathOut.at(pIdx).at(mIdx)++;
1236 } else if (moduleIndexByPath.at(pIdx).at(mIdx) == int(p.status().index()) && !p.status().accept()) {
1237 eventPathStatus.at(ievt).at(pIdx) = double(mIdx);
1238 }
1239 mIdx++;
1240 }
1241 } else {
1242 if ((int(p.status().index()) == mCtr) && !p.status().accept()) {
1243
1244 eventPathStatus.at(ievt).at(pIdx) = double(mIdx) - 0.5;
1245 }
1246 }
1247 mCtr++;
1248 }
1249 pIdx++;
1250 }
1251 pCtr++;
1252 }
1253
1254
1255 mCtr = 0;
1256 mIdx = 0;
1257 for (size_t i = 0; i < (*HLTPerformanceWrapper)->numberOfModules(); ++i) {
1258 const HLTPerformanceInfo::Module& myModule = (*HLTPerformanceWrapper)->getModule(i);
1259 if (useModule.at(mCtr++)) {
1260 if (numberOfModulesExecution.at(ievt).at(mIdx) > 0) {
1261 moduleTimeSummaryVector.at(mIdx) += getTime((myModule), takeCPUtime);
1262 eventModuleTime.at(ievt).at(mIdx) = getTime((myModule), takeCPUtime);
1263 eventTime.at(ievt) += getTime((myModule), takeCPUtime);
1264
1265 if ((1000. * getTime((myModule), takeCPUtime)) > longestEventTimeByModule.at(mIdx)) {
1266 longestEventTimeByModule.at(mIdx) = 1000. * getTime((myModule), takeCPUtime);
1267 longestEventByModule.at(mIdx) = ievt;
1268 }
1269 } else {
1270 eventModuleTime.at(ievt).at(mIdx) = 0.;
1271 }
1272 mIdx++;
1273 }
1274 }
1275
1276 if (eventTime.at(ievt) > longestEventTime) {
1277 longestEventTime = eventTime.at(ievt);
1278 longestEvent = ievt;
1279 }
1280
1281 sumTime += eventTime.at(ievt);
1282 sumTimeSq += eventTime.at(ievt) * eventTime.at(ievt);
1283 }
1284
1285 int xscale = 4;
1286 if (longestEventTime == 0) {
1287 std::cout << "No modules appear to have run in any path. Exiting..." << std::endl;
1288 return 2;
1289 }
1290
1291 if (userMaxTime > 0) {
1292 xmax = userMaxTime;
1293 } else if (n_evts > 1) {
1294
1295 double subMean = (sumTime - longestEventTime) / double(n_evts - 1);
1296 double subRmsSq = (sumTimeSq - longestEventTime * longestEventTime) / double(n_evts - 1);
1297 double subSigma = sqrt(subRmsSq - subMean * subMean);
1298 double subReasMaxTime = subMean + 3. * subSigma;
1299
1300 while (pow(10, xscale--) > subReasMaxTime)
1301 ;
1302 xscale += 2;
1303 xmax = pow(10, xscale + 3);
1304
1305 if ((xmax / 5.) > (subReasMaxTime * 1000.))
1306 xmax = xmax / 5.;
1307 if ((xmax / 2.) > (subReasMaxTime * 1000.))
1308 xmax = xmax / 2.;
1309 }
1310
1311
1312 std::vector<int> reducedSkipEvents;
1313 for (unsigned int i = 0; i < skipEvents.size(); i++) {
1314 if (skipEvents.at(i) < 0)
1315 continue;
1316 bool newSkippedEvent = true;
1317 for (unsigned int j = 0; j < reducedSkipEvents.size(); j++) {
1318 if (reducedSkipEvents.at(j) == skipEvents.at(i))
1319 newSkippedEvent = false;
1320 if (!newSkippedEvent)
1321 break;
1322 }
1323 if (newSkippedEvent)
1324 reducedSkipEvents.push_back(skipEvents.at(i));
1325 }
1326
1327 if (skipFirstEvent)
1328 std::cout << "Skipping a total of " << reducedSkipEvents.size() << " events for module initialization" << std::endl;
1329
1330
1331 int numberOfXbins = 100;
1332 if (userBinWidth > 0) {
1333 int nBins = int((xmax - xmin) / userBinWidth);
1334 if ((xmax - xmin - nBins * userBinWidth) == 0.) {
1335 numberOfXbins = nBins;
1336 } else {
1337 numberOfXbins = nBins + 1;
1338 xmax = xmin + numberOfXbins * userBinWidth;
1339 }
1340 }
1341
1342
1343 double binWidth = (xmax - xmin) / double(numberOfXbins);
1344 std::cout << "Timing histograms span the range (" << xmin << "," << xmax << ") msec. Bin spacing: " << binWidth
1345 << " msec" << std::endl;
1346
1347 TH1D* totalTime = new TH1D("totalTime", "Total time for all modules per event", numberOfXbins, xmin, xmax);
1348 totalTime->StatOverflows(kTRUE);
1349 totalTime->GetXaxis()->SetTitle("msec");
1350
1351 TH1D* acceptedTotalTime =
1352 new TH1D("acceptedTotalTime", "Total time for all modules per accepted event", numberOfXbins, xmin, xmax);
1353 acceptedTotalTime->StatOverflows(kTRUE);
1354 acceptedTotalTime->GetXaxis()->SetTitle("msec");
1355
1356 TH1D* rejectedTotalTime =
1357 new TH1D("rejectedTotalTime", "Total time for all modules per rejected event", numberOfXbins, xmin, xmax);
1358 rejectedTotalTime->StatOverflows(kTRUE);
1359 rejectedTotalTime->GetXaxis()->SetTitle("msec");
1360
1361 TH1D* moduleTimeSummary =
1362 createSummaryHistogram("moduleTimeSummary", "Average time per module", numberOfModules, moduleNames, "msec");
1363 TH1D* moduleScaledTimeSummary = createSummaryHistogram(
1364 "moduleScaledTimeSummary", "Average running time per module", numberOfModules, moduleNames, "msec");
1365 TH1D* pathTimeSummary =
1366 createSummaryHistogram("pathTimeSummary", "Average time per path", numberOfPaths, pathNames, "msec");
1367
1368 std::vector<TH1D*> specificPathTimeSummary;
1369 if (numberOfspecificTotalTime > 0) {
1370 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1371 char nameBuffer[1000], titleBuffer[1000];
1372 snprintf(nameBuffer,
1373 1000,
1374 "specificPathTimeSummary_from_%.0f_ms_to_%.0f_ms",
1375 specificTotalTime.at(k).first,
1376 specificTotalTime.at(k).second);
1377 snprintf(titleBuffer,
1378 1000,
1379 "Average path time for event with total time from %.0f ms to %.0f ms",
1380 specificTotalTime.at(k).first,
1381 specificTotalTime.at(k).second);
1382 std::string name = nameBuffer;
1383 std::string title = titleBuffer;
1384 TH1D* specificPathTimeSummaryAtK = createSummaryHistogram(name, title, numberOfPaths, pathNames, "msec");
1385 specificPathTimeSummary.push_back(specificPathTimeSummaryAtK);
1386 }
1387 }
1388
1389 TH1D* incPathTimeSummary = createSummaryHistogram(
1390 "incPathTimeSummary", "Average incremental time per path", numberOfPaths, pathNames, "msec");
1391 TH1D* pathSuccessFraction =
1392 createSummaryHistogram("pathSuccessFraction", "Path success rate (%)", numberOfPaths, pathNames, "");
1393 TH1D* uniquePathSuccessFraction = createSummaryHistogram(
1394 "uniquePathSuccessFraction", "Fraction (%) of events passing due to a single path", numberOfPaths, pathNames, "");
1395 TH1D* pathRejection =
1396 createSummaryHistogram("pathRejection", "Rejection for each path", numberOfPaths, pathNames, "");
1397 TH1D* pathRejectAll =
1398 createSummaryHistogram("pathRejectAll", "Rejection for each path", numberOfPaths, pathNames, "");
1399
1400 std::vector<TH1D*> moduleInPathTimeSummary;
1401 std::vector<TH1D*> cumulativeModuleInPathTimeSummary;
1402 std::vector<TH1D*> moduleInPathScaledTimeSummary;
1403 std::vector<TH1D*> moduleInPathRejection;
1404 std::vector<TH1D*> moduleInPathRejectAll;
1405 std::vector<TH1D*> moduleInPathRejectTime;
1406 std::vector<TH1D*> failedModule;
1407 for (unsigned int i = 0; i < unsigned(numberOfPaths); i++) {
1408 std::string name = "moduleInPathTimeSummary_" + pathNames.at(i);
1409 std::string title = "Average module time for path " + pathNames.at(i);
1410 TH1D* histo = createSummaryHistogram(name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), "msec");
1411 moduleInPathTimeSummary.push_back(histo);
1412
1413 name = "cumulativeModuleInPathTimeSummary_" + pathNames.at(i);
1414 title = "Cumulative Average module time for path " + pathNames.at(i);
1415 histo = createSummaryHistogram(name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), "msec");
1416 cumulativeModuleInPathTimeSummary.push_back(histo);
1417
1418 name = "moduleInPathScaledTimeSummary_" + pathNames.at(i);
1419 title = "Average module running time for path " + pathNames.at(i);
1420 histo = createSummaryHistogram(name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), "msec");
1421 moduleInPathScaledTimeSummary.push_back(histo);
1422 name = "moduleInPathRejection_" + pathNames.at(i);
1423 title = "Rejection per module for path " + pathNames.at(i);
1424 histo = createSummaryHistogram(name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), "");
1425 moduleInPathRejection.push_back(histo);
1426 name = "moduleInPathRejectAll_" + pathNames.at(i);
1427 title = "Full rejection per module for path " + pathNames.at(i);
1428 histo = createSummaryHistogram(name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), "");
1429 moduleInPathRejectAll.push_back(histo);
1430 name = "moduleInPathRejectTime_" + pathNames.at(i);
1431 title = "(Rejection / avg. running time) per module for path " + pathNames.at(i);
1432 histo = createSummaryHistogram(name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), "(msec)^{-1}");
1433 moduleInPathRejectTime.push_back(histo);
1434
1435 name = "failedModule_" + pathNames.at(i);
1436 title = "Failure fraction (%) by module for path " + pathNames.at(i);
1437 histo = new TH1D(
1438 name.c_str(), title.c_str(), (1 + numberOfModulesInPath.at(i)), -1., double(numberOfModulesInPath.at(i)));
1439 histo->GetXaxis()->SetBinLabel(1, "SUCCESS");
1440 histo->SetMinimum(0.);
1441 for (unsigned int j = 0; j < unsigned(numberOfModulesInPath.at(i)); j++)
1442 histo->GetXaxis()->SetBinLabel(j + 2, moduleInPathNames.at(i).at(j).c_str());
1443 failedModule.push_back(histo);
1444 }
1445
1446 pathTimeSummary->GetYaxis()->SetTitle("msec");
1447 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1448 specificPathTimeSummary.at(k)->GetYaxis()->SetTitle("msec");
1449 }
1450 incPathTimeSummary->GetYaxis()->SetTitle("msec");
1451
1452
1453 int numberOfEvents = n_evts - reducedSkipEvents.size();
1454
1455
1456 for (unsigned int i = 0; i < unsigned(numberOfPaths); i++) {
1457 if (pathTimeSummaryVector.at(i) > 0.) {
1458 pathTimeSummary->Fill(double(i), (1000. * pathTimeSummaryVector.at(i) / double(numberOfEvents)));
1459 } else {
1460 pathTimeSummary->Fill(double(i), 0.);
1461 }
1462
1463 if (incPathTimeSummaryVector.at(i) > 0) {
1464 incPathTimeSummary->Fill(double(i), (1000. * incPathTimeSummaryVector.at(i) / double(numberOfEvents)));
1465 } else {
1466 incPathTimeSummary->Fill(double(i), 0.);
1467 }
1468
1469 std::vector<double> failures(numberOfModulesInPath.at(i), 0.);
1470 for (unsigned int j = 0; j < unsigned(numberOfModulesInPath.at(i)); j++) {
1471 moduleInPathTimeSummary.at(i)->Fill(double(j),
1472 (1000. * moduleInPathTimeSummaryVector.at(i).at(j) / double(numberOfEvents)));
1473
1474 double cumulativeModuleInPathTime = 0.;
1475 for (unsigned int h = 0; h <= j; h++) {
1476 cumulativeModuleInPathTime += 1000. * moduleInPathTimeSummaryVector.at(i).at(h) / double(numberOfEvents);
1477 }
1478 cumulativeModuleInPathTimeSummary.at(i)->Fill(double(j), cumulativeModuleInPathTime);
1479
1480 double avgScaledModuleTime = 1000. * moduleInPathTimeSummaryVector.at(i).at(j);
1481 if (moduleInPathIn.at(i).at(j) > 0) {
1482 avgScaledModuleTime = avgScaledModuleTime / double(moduleInPathIn.at(i).at(j));
1483 }
1484 moduleInPathScaledTimeSummary.at(i)->Fill(double(j), avgScaledModuleTime);
1485
1486 double moduleRejection = moduleInPathIn.at(i).at(j);
1487 if (moduleInPathOut.at(i).at(j) > 0) {
1488 moduleRejection = moduleRejection / moduleInPathOut.at(i).at(j);
1489 } else {
1490 moduleInPathRejectAll.at(i)->Fill(double(j), moduleRejection);
1491 }
1492
1493 moduleInPathRejection.at(i)->Fill(double(j), moduleRejection);
1494 if (avgScaledModuleTime > 0) {
1495 moduleInPathRejectTime.at(i)->Fill(double(j), moduleRejection / avgScaledModuleTime);
1496 } else {
1497 moduleInPathRejectTime.at(i)->Fill(double(j), -1.);
1498 }
1499 failedModule.at(i)->Fill(
1500 double(j), (100. * (moduleInPathIn.at(i).at(j) - moduleInPathOut.at(i).at(j)) / double(numberOfEvents)));
1501 }
1502
1503 failedModule.at(i)->Fill(
1504 -1., 100. * (moduleInPathOut.at(i).at(numberOfModulesInPath.at(i) - 1) / double(numberOfEvents)));
1505
1506
1507 double pathEventsIn = double(numberOfEvents);
1508 if (pathFilterModule.at(i) >= 0)
1509 pathEventsIn = moduleInPathOut.at(i).at(unsigned(pathFilterModule.at(i)));
1510 double pathEventsOut = moduleInPathOut.at(i).at(numberOfModulesInPath.at(i) - 1);
1511
1512 pathSuccessFraction->Fill(double(i), (100. * pathEventsOut / pathEventsIn));
1513 double rejectionFactor = pathEventsIn;
1514 if (pathEventsOut > 0) {
1515 rejectionFactor = rejectionFactor / pathEventsOut;
1516 } else {
1517 pathRejectAll->Fill(double(i), rejectionFactor);
1518 }
1519 pathRejection->Fill(double(i), rejectionFactor);
1520 }
1521 for (unsigned int i = 0; i < unsigned(numberOfModules); i++) {
1522 if (moduleTimeSummaryVector.at(i) > 0) {
1523 moduleTimeSummary->Fill(double(i), (1000. * moduleTimeSummaryVector.at(i) / double(numberOfEvents)));
1524 } else {
1525 moduleTimeSummary->Fill(double(i), 0.);
1526 }
1527 double scaledTime = 1000. * moduleTimeSummaryVector.at(i);
1528 if (moduleIn.at(i) > 0)
1529 scaledTime = scaledTime / moduleIn.at(i);
1530 moduleScaledTimeSummary->Fill(double(i), scaledTime);
1531 }
1532
1533 std::vector<TH1D*> pathTime =
1534 createEventHistograms("pathTime", "Per event time for path", numberOfPaths, pathNames, numberOfXbins, xmin, xmax);
1535
1536 std::vector<std::vector<TH1D*> > specificPathTime;
1537 if (numberOfspecificTotalTime > 0) {
1538 specificPathTime.push_back(pathTime);
1539 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1540 char nameBuffer[1000], titleBuffer[1000];
1541 snprintf(nameBuffer,
1542 1000,
1543 "specificPathTime_from_%.0f_ms_to_%.0f_ms",
1544 specificTotalTime.at(k).first,
1545 specificTotalTime.at(k).second);
1546 snprintf(titleBuffer,
1547 1000,
1548 "Per event time for path from %.0f msec to %.0f msec",
1549 specificTotalTime.at(k).first,
1550 specificTotalTime.at(k).second);
1551 std::string name = nameBuffer;
1552 std::string title = titleBuffer;
1553 std::vector<TH1D*> specificPathTimeAtK =
1554 createEventHistograms(name, title, numberOfPaths, pathNames, numberOfXbins, xmin, xmax);
1555 specificPathTime.push_back(specificPathTimeAtK);
1556 }
1557 }
1558
1559 std::vector<TH1D*> incPathTime = createEventHistograms(
1560 "incPathTime", "Per event incremental time for path", numberOfPaths, pathNames, numberOfXbins, xmin, xmax);
1561 std::vector<TH1D*> moduleTime = createEventHistograms(
1562 "moduleTime", "Time per event for module", numberOfModules, moduleNames, numberOfXbins, xmin, xmax);
1563 std::vector<TH1D*> moduleScaledTime = createEventHistograms(
1564 "moduleScaledTime", "Running time per event for module", numberOfModules, moduleNames, numberOfXbins, xmin, xmax);
1565
1566 std::vector<std::vector<TH1D*> > moduleInPathScaledTime;
1567 for (unsigned int i = 0; i < unsigned(numberOfPaths); i++) {
1568 std::string name = "moduleInPathScaledTime_" + pathNames.at(i);
1569 std::string title = "Running time per event for path " + pathNames.at(i) + ", module";
1570 std::vector<TH1D*> mipScaledTime = createEventHistograms(
1571 name, title, numberOfModulesInPath.at(i), moduleInPathNames.at(i), numberOfXbins, xmin, xmax);
1572 moduleInPathScaledTime.push_back(mipScaledTime);
1573 }
1574
1575 TH2D* pathVsPathSummary = new TH2D("pathVsPathSummary",
1576 "Relative path success",
1577 numberOfPaths,
1578 0.,
1579 double(numberOfPaths),
1580 numberOfPaths,
1581 0.,
1582 double(numberOfPaths));
1583 std::vector<std::vector<double> > pVp;
1584 std::vector<double> nPathSuccess(numberOfPaths, 0.);
1585 std::vector<double> uniquePathSuccessVector(numberOfPaths, 0.);
1586 for (unsigned int i = 0; i < unsigned(numberOfPaths); i++) {
1587 pVp.push_back(nPathSuccess);
1588 pathVsPathSummary->GetXaxis()->SetBinLabel(i + 1, pathNames.at(i).c_str());
1589 pathVsPathSummary->GetYaxis()->SetBinLabel(i + 1, pathNames.at(i).c_str());
1590 }
1591
1592
1593 for (unsigned int ievt = 0; ievt < unsigned(n_evts); ievt++) {
1594 int pCtr = 0;
1595 int pIdx = 0;
1596 int mCtr = 0;
1597 int mIdx = 0;
1598
1599
1600 TBPerfInfo->GetEntry(ievt);
1601
1602
1603 mCtr = 0;
1604 mIdx = 0;
1605 bool useThisEvent = true;
1606 if (skipFirstEvent && (nSkips < numberOfModules)) {
1607 for (size_t i = 0; i < (*HLTPerformanceWrapper)->numberOfModules(); ++i) {
1608 const HLTPerformanceInfo::Module& myModule = (*HLTPerformanceWrapper)->getModule(i);
1609 if (useModule.at(mCtr++)) {
1610
1611
1612 if (getTime((myModule), false) > 0) {
1613 if (skipEvents.at(mIdx) < 0) {
1614 skipEvents.at(mIdx) = ievt;
1615 if (useThisEvent)
1616 nSkips++;
1617 useThisEvent = false;
1618 }
1619 }
1620 mIdx++;
1621 }
1622 }
1623 }
1624
1625 if (!useThisEvent)
1626 continue;
1627
1628 if (numberOfspecificTotalTime > 0) {
1629 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1630 if (1000. * eventTime.at(ievt) > specificTotalTime.at(k).first &&
1631 1000. * eventTime.at(ievt) < specificTotalTime.at(k).second) {
1632 pCtr = 0;
1633 pIdx = 0;
1634 for (size_t piter = 0; piter < (*HLTPerformanceWrapper)->numberOfPaths(); ++piter) {
1635 const HLTPerformanceInfo::Path p = (*HLTPerformanceWrapper)->getPath(piter);
1636 if (usePath.at(pCtr)) {
1637 mCtr = 0;
1638 mIdx = 0;
1639 for (size_t mm = 0; mm < (*HLTPerformanceWrapper)->getPath(piter).numberOfModules(); ++mm) {
1640 const HLTPerformanceInfo::Module& myModule = (*HLTPerformanceWrapper)->getModuleOnPath(mm, piter);
1641 if (useModuleInPath.at(pCtr).at(mCtr)) {
1642 if (moduleIndexByPath.at(pIdx).at(mIdx) <= int(p.status().index())) {
1643 specificPathTimeSummaryVector.at(k).at(pIdx) += getTime((myModule), takeCPUtime);
1644 mIdx++;
1645 }
1646 }
1647 mCtr++;
1648 }
1649 pIdx++;
1650 }
1651 pCtr++;
1652 }
1653 }
1654 }
1655 }
1656 }
1657
1658
1659 for (unsigned int ievt = 0; ievt < unsigned(n_evts); ievt++) {
1660
1661 TBEvtAux->GetEntry(ievt);
1662
1663 std::pair<unsigned int, unsigned long long> eventInfo;
1664 eventInfo.first = EvtAuxWrapper->id().run();
1665 eventInfo.second = EvtAuxWrapper->id().event();
1666
1667 if (!useEvent(ievt, reducedSkipEvents))
1668 continue;
1669
1670 if (acceptedEvt(eventPathStatus.at(ievt))) {
1671 acceptedTotalTime->Fill(1000. * eventTime.at(ievt));
1672 } else if (!acceptedEvt(eventPathStatus.at(ievt))) {
1673 rejectedTotalTime->Fill(1000. * eventTime.at(ievt));
1674 }
1675 totalTime->Fill(1000. * eventTime.at(ievt));
1676 if ((totalTimeThreshold > 0) && ((1000. * eventTime.at(ievt)) > totalTimeThreshold))
1677 slowEventSummaryVector.push_back(eventInfo);
1678
1679
1680 std::vector<bool> moduleRan(numberOfModules, false);
1681 bool slowPathFound = false;
1682
1683 for (unsigned int i = 0; i < unsigned(numberOfPaths); i++) {
1684 double eventPathTime = 0.;
1685 double eventIncPathTime = 0.;
1686
1687 for (unsigned int j = 0; j < unsigned(numberOfModulesInPath.at(i)); j++) {
1688 double mipTime = calculateMiPTime(
1689 eventModuleTime.at(ievt), eventPathStatus.at(ievt).at(i), globalModuleInPathMapper.at(i).at(j), j);
1690
1691 if (mipTime >= 0) {
1692 eventPathTime += mipTime;
1693 int globalModuleIndex = globalModuleInPathMapper.at(i).at(j);
1694 moduleRan.at(unsigned(globalModuleIndex)) = true;
1695 moduleInPathScaledTime.at(i).at(j)->Fill(1000. * mipTime);
1696
1697 if (moduleExistence.at(globalModuleIndex) == 1)
1698 eventIncPathTime += mipTime;
1699 }
1700 }
1701
1702 pathTime.at(i)->Fill(1000. * eventPathTime);
1703 if (numberOfspecificTotalTime > 0) {
1704 specificPathTime.at(0).at(i) = pathTime.at(i);
1705 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1706 if (1000. * eventTime.at(ievt) > specificTotalTime.at(k).first &&
1707 1000. * eventTime.at(ievt) < specificTotalTime.at(k).second) {
1708 specificPathTime.at(k + 1).at(i)->SetFillColor(2 + numberOfspecificTotalTime - (k + 1));
1709 specificPathTime.at(k + 1).at(i)->Fill(1000. * eventPathTime);
1710 }
1711 }
1712 }
1713
1714 incPathTime.at(i)->Fill(1000. * eventIncPathTime);
1715 if ((pathTimeThreshold > 0) && ((1000. * eventPathTime) > pathTimeThreshold)) {
1716 if (!slowPathFound) {
1717 slowPathFound = true;
1718 slowPathSummaryVector.push_back(eventInfo);
1719 }
1720 }
1721
1722 if (eventPathStatus.at(ievt).at(i) == -1)
1723 nPathSuccess.at(i)++;
1724 bool uniqueSuccess = false;
1725 if (eventPathStatus.at(ievt).at(i) == -1) {
1726 uniqueSuccess = true;
1727 for (unsigned int j = 0; j < unsigned(numberOfPaths); j++) {
1728 if (eventPathStatus.at(ievt).at(j) == -1) {
1729 pVp.at(i).at(j)++;
1730 if (i != j)
1731 uniqueSuccess = false;
1732 }
1733 }
1734 }
1735 if (uniqueSuccess)
1736 uniquePathSuccessVector.at(i)++;
1737 }
1738
1739 bool slowModuleFound = false;
1740 for (int i = 0; i < numberOfModules; i++) {
1741 moduleTime.at(i)->Fill(1000. * eventModuleTime.at(ievt).at(i));
1742 if ((moduleTimeThreshold > 0) && ((1000. * eventModuleTime.at(ievt).at(i)) > moduleTimeThreshold)) {
1743 if (!slowModuleFound) {
1744 slowModuleSummaryVector.push_back(eventInfo);
1745 slowModuleFound = true;
1746 }
1747 }
1748
1749 if (moduleRan.at(i)) {
1750 moduleScaledTime.at(i)->Fill(1000. * eventModuleTime.at(ievt).at(i));
1751 for (unsigned int k = 0; k < unsigned(modIdxInterested.size()); k++) {
1752 if ((i == modIdxInterested.at(k)) && (moduleTimeThreshold > 0) &&
1753 ((1000. * eventModuleTime.at(ievt).at(i)) > moduleTimeThreshold))
1754 slowModInterestedVector.at(k).push_back(eventInfo);
1755 }
1756 }
1757 }
1758 }
1759
1760
1761 std::vector<int> n_specificEvts;
1762 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1763 int evtCtr = 0;
1764 for (unsigned int ievt = 0; ievt < unsigned(n_evts); ievt++) {
1765 if (1000. * eventTime.at(ievt) > specificTotalTime.at(k).first &&
1766 1000. * eventTime.at(ievt) < specificTotalTime.at(k).second) {
1767 evtCtr++;
1768 }
1769 }
1770 n_specificEvts.push_back(evtCtr);
1771 }
1772
1773 for (unsigned int i = 0; i < unsigned(numberOfPaths); i++) {
1774
1775 if (numberOfspecificTotalTime > 0) {
1776 for (int k = 0; k < numberOfspecificTotalTime; k++) {
1777 if (specificPathTimeSummaryVector.at(k).at(i) > 0.) {
1778 specificPathTimeSummary.at(k)->SetLineColor(2 + numberOfspecificTotalTime - (k + 1));
1779 specificPathTimeSummary.at(k)->Fill(
1780 double(i), (1000. * specificPathTimeSummaryVector.at(k).at(i) / double(n_specificEvts.at(k))));
1781 } else {
1782 specificPathTimeSummary.at(k)->Fill(double(i), 0.);
1783 }
1784 }
1785 }
1786
1787 uniquePathSuccessFraction->Fill(double(i), 100. * uniquePathSuccessVector.at(i) / double(numberOfEvents));
1788 for (unsigned int j = 0; j < unsigned(numberOfPaths); j++)
1789 pathVsPathSummary->Fill(double(i), double(j), (pVp.at(i).at(j) / nPathSuccess.at(i)));
1790 }
1791
1792
1793 std::vector<std::string> tocList;
1794 if (writeSummary) {
1795 sumfile << "hltTimingSummary output at a glance: " << std::endl;
1796 sumfile << std::endl;
1797 sumfile << "Input file: " << filename << std::endl;
1798 sumfile << "Output root file name: " << outname << std::endl;
1799 sumfile << std::endl;
1800
1801 if (takeCPUtime) {
1802 sumfile << "NOTE: Results obtained using CPU time." << std::endl;
1803 sumfile << " Due to resolution effects in CPUTimer, event histograms may not reflect reality." << std::endl;
1804 sumfile << " Please be aware of these limitations when drawing your conclusions." << std::endl << std::endl;
1805 }
1806
1807 if (numberOfspecificTotalTime > 0) {
1808 sumfile << "There are " << numberOfspecificTotalTime;
1809 if (numberOfspecificTotalTime == 1)
1810 sumfile << " range ";
1811 else
1812 sumfile << " ranges ";
1813 sumfile << "of specific total time: " << std::endl;
1814 for (int i = 0; i < numberOfspecificTotalTime; i++) {
1815 sumfile << "[ " << specificTotalTime.at(i).first << ", " << specificTotalTime.at(i).second << "]";
1816 if (i == numberOfspecificTotalTime - 1)
1817 sumfile << "\n";
1818 else
1819 sumfile << ", ";
1820 }
1821 sumfile << std::endl;
1822 }
1823
1824 if (skipFirstEvent) {
1825 sumfile << "Skipping " << reducedSkipEvents.size() << " event(s) due to module initialization:" << std::endl;
1826 sumfile << "Event";
1827 if (reducedSkipEvents.size() > 1)
1828 sumfile << "s";
1829 for (unsigned int i = 0; i < reducedSkipEvents.size(); i++) {
1830 if (i != 0)
1831 sumfile << ",";
1832 sumfile << " " << reducedSkipEvents.at(i);
1833 }
1834 sumfile << std::endl;
1835 sumfile << std::endl;
1836 }
1837 if (!skipTimingMod.empty()) {
1838 sumfile << "Not including any information from the following excluded modules: " << std::endl;
1839 for (unsigned int i = 0; i < skipTimingMod.size(); i++)
1840 sumfile << skipTimingMod.at(i) << std::endl;
1841 sumfile << std::endl;
1842 }
1843
1844 if (!squareOne.empty()) {
1845 sumfile << "The following module(s) were defined as filters by the user: " << std::endl;
1846 for (unsigned int i = 0; i < squareOne.size(); i++) {
1847 sumfile << squareOne.at(i) << ", found in path(s) ";
1848 int pCtr = 0;
1849 for (size_t piter = 0; piter < (*HLTPerformanceWrapper)->numberOfPaths(); ++piter) {
1850 const HLTPerformanceInfo::Path p = (*HLTPerformanceWrapper)->getPath(piter);
1851 for (size_t j = 0; j < (*HLTPerformanceWrapper)->numberOfModules(); ++j) {
1852 const HLTPerformanceInfo::Module& myModule = (*HLTPerformanceWrapper)->getModule(j);
1853 if (myModule.name() == squareOne.at(i)) {
1854 if (pCtr > 0)
1855 sumfile << ", ";
1856 sumfile << p.name();
1857 pCtr++;
1858 }
1859 }
1860 }
1861 sumfile << std::endl;
1862 }
1863 sumfile << std::endl;
1864 }
1865
1866 if (!slowEventSummaryVector.empty()) {
1867 sumfile << "The following " << slowEventSummaryVector.size();
1868 if (slowEventSummaryVector.size() == 1)
1869 sumfile << " event ";
1870 else
1871 sumfile << " events ";
1872 sumfile << "took longer than " << totalTimeThreshold << " msec to run: " << std::endl;
1873 sumfile << "(formatted for usage within the PoolSource module,i.e, Run:Event)" << std::endl;
1874 sumfile << std::endl;
1875 sumfile << "eventsToProcess = cms.untracked.VEventRange(" << std::endl;
1876 for (unsigned int i = 0; i < slowEventSummaryVector.size(); i++) {
1877 sumfile << "'" << slowEventSummaryVector.at(i).first << ":" << slowEventSummaryVector.at(i).second << "',"
1878 << std::endl;
1879 }
1880 sumfile << ")" << std::endl;
1881 sumfile << std::endl;
1882 }
1883
1884 if (!slowPathSummaryVector.empty()) {
1885 sumfile << "The following " << slowPathSummaryVector.size();
1886 if (slowPathSummaryVector.size() == 1)
1887 sumfile << " event ";
1888 else
1889 sumfile << " events ";
1890 sumfile << "had at least one path that took more than " << totalTimeThreshold << " msec to run: " << std::endl;
1891
1892 sumfile << "(formatted for usage within the PoolSource module,i.e, Run:Event)" << std::endl;
1893 sumfile << std::endl;
1894 sumfile << "eventsToProcess = cms.untracked.VEventRange(" << std::endl;
1895 for (unsigned int i = 0; i < slowPathSummaryVector.size(); i++) {
1896 sumfile << "'" << slowPathSummaryVector.at(i).first << ":" << slowPathSummaryVector.at(i).second << "',"
1897 << std::endl;
1898 }
1899 sumfile << ")" << std::endl;
1900 sumfile << std::endl;
1901 }
1902
1903 if (!slowModuleSummaryVector.empty()) {
1904 sumfile << "The following " << slowModuleSummaryVector.size();
1905 if (slowModuleSummaryVector.size() == 1)
1906 sumfile << " event ";
1907 else
1908 sumfile << " events ";
1909 sumfile << "had at least one module that took more than " << moduleTimeThreshold << " msec to run: " << std::endl;
1910 sumfile << "(formatted for usage within the PoolSource module,i.e, Run:Event)" << std::endl;
1911 sumfile << std::endl;
1912 sumfile << "eventsToProcess = cms.untracked.VEventRange(" << std::endl;
1913 for (unsigned int i = 0; i < slowModuleSummaryVector.size(); i++) {
1914 sumfile << "'" << slowModuleSummaryVector.at(i).first << ":" << slowModuleSummaryVector.at(i).second << "',"
1915 << std::endl;
1916 }
1917 sumfile << ")" << std::endl;
1918 sumfile << std::endl;
1919 }
1920
1921 if (!slowModInterestedVector.empty()) {
1922 for (unsigned i = 0; i < slowModInterestedVector.size(); i++) {
1923 sumfile << "The following " << slowModInterestedVector.at(i).size() - 1;
1924 if (slowModInterestedVector.at(i).size() - 1 == 1)
1925 sumfile << " event ";
1926 else
1927 sumfile << " events ";
1928 sumfile << "had the module " << modInterested.at(i) << " that took more than " << moduleTimeThreshold
1929 << " msec to run: " << std::endl;
1930 sumfile << "(formatted for usage within the PoolSource module,i.e, Run:Event)" << std::endl;
1931 sumfile << std::endl;
1932 sumfile << "eventsToProcess = cms.untracked.VEventRange(" << std::endl;
1933 for (unsigned int j = 1; j < slowModInterestedVector.at(i).size(); j++) {
1934 sumfile << "'" << slowModInterestedVector.at(i).at(j).first << ":"
1935 << slowModInterestedVector.at(i).at(j).second << "'," << std::endl;
1936 }
1937 sumfile << ")" << std::endl;
1938 sumfile << std::endl;
1939 }
1940 }
1941
1942 char value[330];
1943 sumfile << "Average path times are as follows (all in msec): " << std::endl;
1944 for (int i = 1; i <= pathTimeSummary->GetNbinsX(); i++) {
1945 snprintf(value, sizeof(value), "%9.4f", pathTimeSummary->GetBinContent(i));
1946 sumfile << value << " (path " << pathTimeSummary->GetXaxis()->GetBinLabel(i) << ")";
1947 sumfile << std::endl;
1948 }
1949 sumfile << std::endl;
1950
1951 snprintf(value, sizeof(value), "%9.4f", (1000. * longestEventTime));
1952 sumfile << "The slowest event (" << longestEvent << ") took " << value << " msec" << std::endl;
1953 sumfile << std::endl;
1954
1955 std::vector<std::string> slowPath;
1956 slowPath.clear();
1957 std::vector<std::string> slowMinP;
1958 slowMinP.clear();
1959 std::vector<double> slowTime;
1960 slowTime.clear();
1961
1962 sumfile << "The three slowest modules (running in any path) are: " << std::endl;
1963 slowestModules(moduleTimeSummary, &slowMinP, &slowTime, numberOfModules, moduleNames);
1964
1965 for (unsigned int i = 0; i < 3; i++) {
1966 if (slowTime.at(i) > 0) {
1967 snprintf(value, sizeof(value), "%9.4f", slowTime.at(i));
1968 sumfile << "Module " << slowMinP.at(i) << ", with average per event time: " << value << " msec" << std::endl;
1969 }
1970 }
1971 sumfile << std::endl;
1972
1973 sumfile << "The three slowest modules (by path) are: " << std::endl;
1974 slowestModules(moduleInPathTimeSummary,
1975 &slowPath,
1976 &slowMinP,
1977 &slowTime,
1978 numberOfPaths,
1979 numberOfModulesInPath,
1980 pathNames,
1981 moduleInPathNames);
1982
1983 for (unsigned int i = 0; i < 3; i++) {
1984 if (slowTime.at(i) > 0) {
1985 snprintf(value, sizeof(value), "%9.4f", slowTime.at(i));
1986 sumfile << "Module " << slowMinP.at(i) << " in path " << slowPath.at(i)
1987 << ", with average per event time: " << value << " msec" << std::endl;
1988 }
1989 }
1990 sumfile << std::endl;
1991
1992 slowPath.clear();
1993 slowMinP.clear();
1994 slowTime.clear();
1995 sumfile << "The three slowest RUNNING modules (by path) are: " << std::endl;
1996 slowestModules(moduleInPathScaledTimeSummary,
1997 &slowPath,
1998 &slowMinP,
1999 &slowTime,
2000 numberOfPaths,
2001 numberOfModulesInPath,
2002 pathNames,
2003 moduleInPathNames);
2004
2005 for (unsigned int i = 0; i < 3; i++) {
2006 if (slowTime.at(i) > 0) {
2007 snprintf(value, sizeof(value), "%9.4f", slowTime.at(i));
2008 sumfile << "Module " << slowMinP.at(i) << " in path " << slowPath.at(i)
2009 << ", with average running time: " << value << " msec" << std::endl;
2010 }
2011 }
2012 sumfile << std::endl;
2013
2014 sumfile << "A given module took the longest time to run in the following events:" << std::endl;
2015 for (unsigned int i = 0; i < unsigned(numberOfModules); i++) {
2016 if (longestEventTimeByModule.at(i) > 0) {
2017 snprintf(value, sizeof(value), "%9.4f", longestEventTimeByModule.at(i));
2018 sumfile << "Module " << moduleNames.at(i) << " was slowest in event " << longestEventByModule.at(i)
2019 << ", with time: " << value << " msec" << std::endl;
2020 }
2021 }
2022 sumfile << std::endl;
2023
2024 sumfile << "Timing histograms run from " << xmin << " to " << xmax << " msec";
2025 if (userMaxTime > 0)
2026 sumfile << ", which was specified by the user";
2027 sumfile << std::endl;
2028 sumfile << "The bin width for the timing histograms is " << (xmax - xmin) / double(numberOfXbins) << " msec";
2029 if (userBinWidth > 0)
2030 sumfile << ", which was specified by the user";
2031 sumfile << std::endl;
2032
2033 double oflow = 100. * totalTime->GetBinContent(numberOfXbins + 1) / totalTime->GetEntries();
2034 sumfile << oflow << "% (" << totalTime->GetBinContent(numberOfXbins + 1) << "/" << totalTime->GetEntries()
2035 << ") of all events fall outside the ";
2036 if (userMaxTime > 0)
2037 sumfile << "(user-specified) ";
2038 sumfile << "timing range" << std::endl;
2039 sumfile << std::endl;
2040 sumfile << "NOTE: The mean and rms values are calculated for all events (that INCLUDES overflows)" << std::endl;
2041 }
2042
2043 txtfile.close();
2044 sumfile.close();
2045 outFile->Write();
2046 outFile->Close();
2047 file->Close();
2048
2049 return 0;
2050 }