Timer/plugins/FastTimerServiceClient.cc

0001 // C++ headers
0002 #include <string>
0003 #include <cstring>
0004
0005 // boost headers
0006 #include <boost/regex.hpp>
0007
0008 // Root headers
0009 #include <TH1D.h>
0010 #include <TH1F.h>
0011
0012 // CMSSW headers
0013 #include "FWCore/Framework/interface/Frameworkfwd.h"
0014 #include "FWCore/Framework/interface/Event.h"
0015 #include "FWCore/Framework/interface/Run.h"
0016 #include "FWCore/Framework/interface/LuminosityBlock.h"
0017 #include "FWCore/ParameterSet/interface/ParameterSet.h"
0018 #include "FWCore/ParameterSet/interface/ParameterSetDescription.h"
0019 #include "FWCore/ParameterSet/interface/ConfigurationDescriptions.h"
0020 #include "FWCore/ParameterSet/interface/Registry.h"
0021 #include "FWCore/ServiceRegistry/interface/Service.h"
0022 #include "DataFormats/Provenance/interface/ProcessHistory.h"
0023 #include "DQMServices/Core/interface/DQMStore.h"
0024 #include "DQMServices/Core/interface/DQMEDHarvester.h"
0025
0026 struct MEPSet {
0027   std::string folder;
0028   std::string name;
0029   int nbins;
0030   double xmin;
0031   double xmax;
0032 };
0033
0034 class FastTimerServiceClient : public DQMEDHarvester {
0035 public:
0036   explicit FastTimerServiceClient(edm::ParameterSet const&);
0037   ~FastTimerServiceClient() override = default;
0038
0039   static void fillDescriptions(edm::ConfigurationDescriptions& descriptions);
0040   static void fillLumiMePSetDescription(edm::ParameterSetDescription& pset);
0041   static void fillPUMePSetDescription(edm::ParameterSetDescription& pset);
0042
0043 private:
0044   void dqmEndLuminosityBlock(DQMStore::IBooker& booker,
0045                              DQMStore::IGetter& getter,
0046                              edm::LuminosityBlock const&,
0047                              edm::EventSetup const&) override;
0048   void dqmEndJob(DQMStore::IBooker& booker, DQMStore::IGetter& getter) override;
0049
0050   void fillSummaryPlots(DQMStore::IBooker& booker, DQMStore::IGetter& getter);
0051   void fillProcessSummaryPlots(DQMStore::IBooker& booker, DQMStore::IGetter& getter, std::string const& path);
0052   void fillPathSummaryPlots(DQMStore::IBooker& booker,
0053                             DQMStore::IGetter& getter,
0054                             double events,
0055                             std::string const& path);
0056   void fillPlotsVsLumi(DQMStore::IBooker& booker,
0057                        DQMStore::IGetter& getter,
0058                        std::string const& current_path,
0059                        std::string const& suffix,
0060                        MEPSet const& pset);
0061
0062   static MEPSet getHistoPSet(const edm::ParameterSet& pset);
0063
0064   std::string const dqm_path_;
0065
0066   bool const doPlotsVsOnlineLumi_;
0067   bool const doPlotsVsPixelLumi_;
0068   bool const doPlotsVsPU_;
0069
0070   MEPSet const onlineLumiMEPSet_;
0071   MEPSet const pixelLumiMEPSet_;
0072   MEPSet const puMEPSet_;
0073
0074   bool const fillEveryLumiSection_;
0075 };
0076
0077 FastTimerServiceClient::FastTimerServiceClient(edm::ParameterSet const& config)
0078     : dqm_path_(config.getUntrackedParameter<std::string>("dqmPath")),
0079       doPlotsVsOnlineLumi_(config.getParameter<bool>("doPlotsVsOnlineLumi")),
0080       doPlotsVsPixelLumi_(config.getParameter<bool>("doPlotsVsPixelLumi")),
0081       doPlotsVsPU_(config.getParameter<bool>("doPlotsVsPU")),
0082       onlineLumiMEPSet_(doPlotsVsOnlineLumi_ ? getHistoPSet(config.getParameter<edm::ParameterSet>("onlineLumiME"))
0083                                              : MEPSet{}),
0084       pixelLumiMEPSet_(doPlotsVsPixelLumi_ ? getHistoPSet(config.getParameter<edm::ParameterSet>("pixelLumiME"))
0085                                            : MEPSet{}),
0086       puMEPSet_(doPlotsVsPU_ ? getHistoPSet(config.getParameter<edm::ParameterSet>("puME")) : MEPSet{}),
0087       fillEveryLumiSection_(config.getParameter<bool>("fillEveryLumiSection")) {}
0088
0089 void FastTimerServiceClient::dqmEndJob(DQMStore::IBooker& booker, DQMStore::IGetter& getter) {
0090   fillSummaryPlots(booker, getter);
0091 }
0092
0093 void FastTimerServiceClient::dqmEndLuminosityBlock(DQMStore::IBooker& booker,
0094                                                    DQMStore::IGetter& getter,
0095                                                    edm::LuminosityBlock const& lumi,
0096                                                    edm::EventSetup const& setup) {
0097   if (fillEveryLumiSection_)
0098     fillSummaryPlots(booker, getter);
0099 }
0100
0101 void FastTimerServiceClient::fillSummaryPlots(DQMStore::IBooker& booker, DQMStore::IGetter& getter) {
0102   if (getter.get(dqm_path_ + "/event time_real")) {
0103     // the plots are directly in the configured folder
0104     fillProcessSummaryPlots(booker, getter, dqm_path_);
0105   } else {
0106     static const boost::regex running_n_processes(".*/Running .*");
0107
0108     booker.setCurrentFolder(dqm_path_);
0109     std::vector<std::string> subdirs = getter.getSubdirs();
0110     for (auto const& subdir : subdirs) {
0111       // the plots are in a per-number-of-processes folder
0112       if (boost::regex_match(subdir, running_n_processes)) {
0113         booker.setCurrentFolder(subdir);
0114         if (getter.get(subdir + "/event time_real"))
0115           fillProcessSummaryPlots(booker, getter, subdir);
0116
0117         std::vector<std::string> subsubdirs = getter.getSubdirs();
0118         for (auto const& subsubdir : subsubdirs) {
0119           if (getter.get(subsubdir + "/event time_real"))
0120             fillProcessSummaryPlots(booker, getter, subsubdir);
0121         }
0122       }
0123     }  // loop on subdirs
0124   }
0125 }
0126
0127 void FastTimerServiceClient::fillProcessSummaryPlots(DQMStore::IBooker& booker,
0128                                                      DQMStore::IGetter& getter,
0129                                                      std::string const& current_path) {
0130   MonitorElement* me = getter.get(current_path + "/event time_real");
0131   if (me == nullptr)
0132     // no FastTimerService DQM information
0133     return;
0134
0135   if (doPlotsVsOnlineLumi_)
0136     fillPlotsVsLumi(booker, getter, current_path, "vs_lumi", onlineLumiMEPSet_);
0137   if (doPlotsVsPixelLumi_)
0138     fillPlotsVsLumi(booker, getter, current_path, "vs_pixelLumi", pixelLumiMEPSet_);
0139   if (doPlotsVsPU_)
0140     fillPlotsVsLumi(booker, getter, current_path, "vs_pileup", puMEPSet_);
0141
0142   //  getter.setCurrentFolder(current_path);
0143
0144   double events = me->getTH1F()->GetEntries();
0145
0146   // look for per-process directories
0147   static const boost::regex process_name(".*/process .*");
0148
0149   booker.setCurrentFolder(current_path);  // ?!?!?
0150   std::vector<std::string> subdirs = getter.getSubdirs();
0151   for (auto const& subdir : subdirs) {
0152     if (boost::regex_match(subdir, process_name)) {
0153       getter.setCurrentFolder(subdir);
0154       // look for per-path plots inside each per-process directory
0155       std::vector<std::string> subsubdirs = getter.getSubdirs();
0156       for (auto const& subsubdir : subsubdirs) {
0157         if (getter.get(subsubdir + "/path time_real")) {
0158           fillPathSummaryPlots(booker, getter, events, subdir);
0159           break;
0160         }
0161       }
0162     }
0163   }  // loop on subdir
0164 }
0165
0166 void FastTimerServiceClient::fillPathSummaryPlots(DQMStore::IBooker& booker,
0167                                                   DQMStore::IGetter& getter,
0168                                                   double events,
0169                                                   std::string const& current_path) {
0170   // note: the following checks need to be kept separate, as any of these histograms might be missing
0171
0172   booker.setCurrentFolder(current_path);
0173   std::vector<std::string> subsubdirs = getter.getSubdirs();
0174   size_t npaths = subsubdirs.size();
0175
0176   MonitorElement* paths_time =
0177       booker.book1D("paths_time_real", "Total (real) time spent in each path", npaths, -0.5, double(npaths) - 0.5);
0178   MonitorElement* paths_thread =
0179       booker.book1D("paths_time_thread", "Total (thread) time spent in each path", npaths, -0.5, double(npaths) - 0.5);
0180   MonitorElement* paths_allocated =
0181       booker.book1D("paths_allocated", "Total allocated memory in each path", npaths, -0.5, double(npaths) - 0.5);
0182   MonitorElement* paths_deallocated =
0183       booker.book1D("paths_deallocated", "Total deallocated in each path", npaths, -0.5, double(npaths) - 0.5);
0184
0185   MonitorElement* me;
0186   double mean = -1.;
0187
0188   // extract the list of Paths and EndPaths from the summary plots
0189   int ibin = 1;
0190   for (auto const& subsubdir : subsubdirs) {
0191     std::string test = "/path ";
0192     if (subsubdir.find(test) == std::string::npos)
0193       continue;
0194
0195     static const boost::regex prefix(current_path + "/path ");
0196     std::string path = boost::regex_replace(subsubdir, prefix, "");
0197
0198     paths_time->setBinLabel(ibin, path);
0199     paths_thread->setBinLabel(ibin, path);
0200     paths_allocated->setBinLabel(ibin, path);
0201     paths_deallocated->setBinLabel(ibin, path);
0202
0203     if ((me = getter.get(subsubdir + "/path time_real"))) {
0204       mean = me->getMean();
0205       paths_time->setBinContent(ibin, mean);
0206     }
0207     if ((me = getter.get(subsubdir + "/path time_thread"))) {
0208       mean = me->getMean();
0209       paths_thread->setBinContent(ibin, mean);
0210     }
0211     if ((me = getter.get(subsubdir + "/path allocated"))) {
0212       mean = me->getMean();
0213       paths_allocated->setBinContent(ibin, mean);
0214     }
0215
0216     if ((me = getter.get(subsubdir + "/path deallocated"))) {
0217       mean = me->getMean();
0218       paths_deallocated->setBinContent(ibin, mean);
0219     }
0220
0221     ibin++;
0222   }
0223
0224   for (auto const& subsubdir : subsubdirs) {
0225     // for each path, fill histograms with
0226     //  - the average time spent in each module (total time spent in that module, averaged over all events)
0227     //  - the running time spent in each module (total time spent in that module, averaged over the events where that module actually ran)
0228     //  - the "efficiency" of each module (number of time a module succeded divided by the number of times the has run)
0229
0230     getter.setCurrentFolder(subsubdir);
0231     std::vector<std::string> allmenames = getter.getMEs();
0232     if (allmenames.empty())
0233       continue;
0234
0235     MonitorElement* me_counter = getter.get(subsubdir + "/module_counter");
0236     MonitorElement* me_real_total = getter.get(subsubdir + "/module_time_real_total");
0237     MonitorElement* me_thread_total = getter.get(subsubdir + "/module_time_thread_total");
0238
0239     if (me_counter == nullptr or me_real_total == nullptr)
0240       continue;
0241
0242     TH1D* counter = me_counter->getTH1D();
0243     TH1D* real_total = me_real_total->getTH1D();
0244     TH1D* thread_total = me_thread_total->getTH1D();
0245     uint32_t bins = counter->GetXaxis()->GetNbins() - 1;
0246     double min = counter->GetXaxis()->GetXmin();
0247     double max = counter->GetXaxis()->GetXmax() - 1;
0248
0249     TH1F* real_average;
0250     TH1F* real_running;
0251     TH1F* thread_average;
0252     TH1F* thread_running;
0253     TH1F* efficiency;
0254     MonitorElement* me;
0255
0256     booker.setCurrentFolder(subsubdir);
0257     me = getter.get(subsubdir + "/module_time_real_average");
0258     if (me) {
0259       real_average = me->getTH1F();
0260       assert(me->getTH1F()->GetXaxis()->GetXmin() == min);
0261       assert(me->getTH1F()->GetXaxis()->GetXmax() == max);
0262       real_average->Reset();
0263     } else {
0264       real_average = booker.book1D("module_time_real_average", "module real average timing", bins, min, max)->getTH1F();
0265       real_average->SetYTitle("average processing (real) time [ms]");
0266       for (uint32_t i = 1; i <= bins; ++i) {
0267         const char* module = counter->GetXaxis()->GetBinLabel(i);
0268         real_average->GetXaxis()->SetBinLabel(i, module);
0269       }
0270     }
0271
0272     me = getter.get(subsubdir + "/module_time_thread_average");
0273     if (me) {
0274       thread_average = me->getTH1F();
0275       assert(me->getTH1F()->GetXaxis()->GetXmin() == min);
0276       assert(me->getTH1F()->GetXaxis()->GetXmax() == max);
0277       thread_average->Reset();
0278     } else {
0279       thread_average =
0280           booker.book1D("module_time_thread_average", "module thread average timing", bins, min, max)->getTH1F();
0281       thread_average->SetYTitle("average processing (thread) time [ms]");
0282       for (uint32_t i = 1; i <= bins; ++i) {
0283         const char* module = counter->GetXaxis()->GetBinLabel(i);
0284         thread_average->GetXaxis()->SetBinLabel(i, module);
0285       }
0286     }
0287
0288     me = getter.get(subsubdir + "/module_time_real_running");
0289     if (me) {
0290       real_running = me->getTH1F();
0291       assert(me->getTH1F()->GetXaxis()->GetXmin() == min);
0292       assert(me->getTH1F()->GetXaxis()->GetXmax() == max);
0293       real_running->Reset();
0294     } else {
0295       real_running = booker.book1D("module_time_real_running", "module real running timing", bins, min, max)->getTH1F();
0296       real_running->SetYTitle("running processing (real) time [ms]");
0297       for (uint32_t i = 1; i <= bins; ++i) {
0298         const char* module = counter->GetXaxis()->GetBinLabel(i);
0299         real_running->GetXaxis()->SetBinLabel(i, module);
0300       }
0301     }
0302
0303     me = getter.get(subsubdir + "/module_time_thread_running");
0304     if (me) {
0305       thread_running = me->getTH1F();
0306       assert(me->getTH1F()->GetXaxis()->GetXmin() == min);
0307       assert(me->getTH1F()->GetXaxis()->GetXmax() == max);
0308       thread_running->Reset();
0309     } else {
0310       thread_running =
0311           booker.book1D("module_time_thread_running", "module thread running timing", bins, min, max)->getTH1F();
0312       thread_running->SetYTitle("running processing (thread) time [ms]");
0313       for (uint32_t i = 1; i <= bins; ++i) {
0314         const char* module = counter->GetXaxis()->GetBinLabel(i);
0315         thread_running->GetXaxis()->SetBinLabel(i, module);
0316       }
0317     }
0318
0319     me = getter.get(subsubdir + "/module_efficiency");
0320     if (me) {
0321       efficiency = me->getTH1F();
0322       assert(me->getTH1F()->GetXaxis()->GetXmin() == min);
0323       assert(me->getTH1F()->GetXaxis()->GetXmax() == max);
0324       efficiency->Reset();
0325     } else {
0326       efficiency = booker.book1D("module_efficiency", "module efficiency", bins, min, max)->getTH1F();
0327       efficiency->SetYTitle("filter efficiency");
0328       efficiency->SetMaximum(1.05);
0329       for (uint32_t i = 1; i <= bins; ++i) {
0330         const char* module = counter->GetXaxis()->GetBinLabel(i);
0331         efficiency->GetXaxis()->SetBinLabel(i, module);
0332       }
0333     }
0334
0335     for (uint32_t i = 1; i <= bins; ++i) {
0336       double n = counter->GetBinContent(i);
0337       double p = counter->GetBinContent(i + 1);
0338       if (n)
0339         efficiency->SetBinContent(i, p / n);
0340
0341       // real timing
0342       double t = real_total->GetBinContent(i);
0343       real_average->SetBinContent(i, t / events);
0344       if (n)
0345         real_running->SetBinContent(i, t / n);
0346
0347       // thread timing
0348       t = thread_total->GetBinContent(i);
0349       thread_average->SetBinContent(i, t / events);
0350       if (n)
0351         thread_running->SetBinContent(i, t / n);
0352     }
0353
0354     // vs lumi
0355     if (doPlotsVsOnlineLumi_)
0356       fillPlotsVsLumi(booker, getter, subsubdir, "vs_lumi", onlineLumiMEPSet_);
0357     if (doPlotsVsPixelLumi_)
0358       fillPlotsVsLumi(booker, getter, subsubdir, "vs_pixelLumi", pixelLumiMEPSet_);
0359     if (doPlotsVsPU_)
0360       fillPlotsVsLumi(booker, getter, subsubdir, "vs_pileup", puMEPSet_);
0361   }
0362 }
0363
0364 #include "FWCore/MessageLogger/interface/MessageLogger.h"
0365 void FastTimerServiceClient::fillPlotsVsLumi(DQMStore::IBooker& booker,
0366                                              DQMStore::IGetter& getter,
0367                                              std::string const& current_path,
0368                                              std::string const& suffix,
0369                                              MEPSet const& pset) {
0370   std::vector<std::string> menames;
0371
0372   static const boost::regex byls(".*byls");
0373   // get all MEs in the current_path
0374   getter.setCurrentFolder(current_path);
0375   std::vector<std::string> allmenames = getter.getMEs();
0376   for (auto const& m : allmenames) {
0377     // get only MEs vs LS
0378     if (boost::regex_match(m, byls))
0379       menames.push_back(m);
0380   }
0381   // if no MEs available, return
0382   if (menames.empty())
0383     return;
0384
0385   // get info for getting the lumi VS LS histogram
0386   std::string folder = pset.folder;
0387   std::string name = pset.name;
0388   int nbins = pset.nbins;
0389   double xmin = pset.xmin;
0390   double xmax = pset.xmax;
0391
0392   // get lumi/PU VS LS ME
0393   getter.setCurrentFolder(folder);
0394   MonitorElement* lumiVsLS = getter.get(folder + "/" + name);
0395   // if no ME available, return
0396   if (!lumiVsLS) {
0397     edm::LogWarning("FastTimerServiceClient") << "no " << name << " ME is available in " << folder << std::endl;
0398     return;
0399   }
0400
0401   // get range and binning for new MEs x-axis
0402   size_t size = lumiVsLS->getTProfile()->GetXaxis()->GetNbins();
0403   std::string xtitle = lumiVsLS->getTProfile()->GetYaxis()->GetTitle();
0404
0405   std::vector<double> lumi;
0406   std::vector<int> LS;
0407   for (size_t ibin = 1; ibin <= size; ++ibin) {
0408     // avoid to store points w/ no info
0409     if (lumiVsLS->getTProfile()->GetBinContent(ibin) == 0.)
0410       continue;
0411
0412     lumi.push_back(lumiVsLS->getTProfile()->GetBinContent(ibin));
0413     LS.push_back(lumiVsLS->getTProfile()->GetXaxis()->GetBinCenter(ibin));
0414   }
0415
0416   booker.setCurrentFolder(current_path);
0417   getter.setCurrentFolder(current_path);
0418   for (auto const& m : menames) {
0419     std::string label = m;
0420     label.erase(label.find("_byls"));
0421
0422     MonitorElement* me = getter.get(current_path + "/" + m);
0423     float ymin = 0.;
0424     float ymax = std::numeric_limits<float>::max();
0425     std::string ytitle = me->getTProfile()->GetYaxis()->GetTitle();
0426
0427     MonitorElement* meVsLumi = getter.get(current_path + "/" + label + "_" + suffix);
0428     if (meVsLumi) {
0429       assert(meVsLumi->getTProfile()->GetXaxis()->GetXmin() == xmin);
0430       assert(meVsLumi->getTProfile()->GetXaxis()->GetXmax() == xmax);
0431       meVsLumi->Reset();  // do I have to do it ?!?!?
0432     } else {
0433       meVsLumi = booker.bookProfile(label + "_" + suffix, label + "_" + suffix, nbins, xmin, xmax, ymin, ymax);
0434       //    TProfile* meVsLumi_p = meVsLumi->getTProfile();
0435       meVsLumi->getTProfile()->GetXaxis()->SetTitle(xtitle.c_str());
0436       meVsLumi->getTProfile()->GetYaxis()->SetTitle(ytitle.c_str());
0437     }
0438     for (size_t ils = 0; ils < LS.size(); ++ils) {
0439       int ibin = me->getTProfile()->GetXaxis()->FindBin(LS[ils]);
0440       double y = me->getTProfile()->GetBinContent(ibin);
0441
0442       meVsLumi->Fill(lumi[ils], y);
0443     }
0444   }
0445 }
0446
0447 void FastTimerServiceClient::fillLumiMePSetDescription(edm::ParameterSetDescription& pset) {
0448   pset.add<std::string>("folder", "HLT/LumiMonitoring");
0449   pset.add<std::string>("name", "lumiVsLS");
0450   pset.add<int>("nbins", 440);
0451   pset.add<double>("xmin", 0.);
0452   pset.add<double>("xmax", 22000.);
0453 }
0454
0455 void FastTimerServiceClient::fillPUMePSetDescription(edm::ParameterSetDescription& pset) {
0456   pset.add<std::string>("folder", "HLT/LumiMonitoring");
0457   pset.add<std::string>("name", "puVsLS");
0458   pset.add<int>("nbins", 260);
0459   pset.add<double>("xmin", 0.);
0460   pset.add<double>("xmax", 130.);
0461 }
0462
0463 MEPSet FastTimerServiceClient::getHistoPSet(const edm::ParameterSet& pset) {
0464   return MEPSet{
0465       pset.getParameter<std::string>("folder"),
0466       pset.getParameter<std::string>("name"),
0467       pset.getParameter<int>("nbins"),
0468       pset.getParameter<double>("xmin"),
0469       pset.getParameter<double>("xmax"),
0470   };
0471 }
0472
0473 void FastTimerServiceClient::fillDescriptions(edm::ConfigurationDescriptions& descriptions) {
0474   // The following says we do not know what parameters are allowed so do no validation
0475   // Please change this to state exactly what you do use, even if it is no parameters
0476   edm::ParameterSetDescription desc;
0477   desc.addUntracked<std::string>("dqmPath", "HLT/TimerService");
0478   desc.add<bool>("doPlotsVsOnlineLumi", true);
0479   desc.add<bool>("doPlotsVsPixelLumi", false);
0480   desc.add<bool>("doPlotsVsPU", true);
0481
0482   edm::ParameterSetDescription onlineLumiMEPSet;
0483   fillLumiMePSetDescription(onlineLumiMEPSet);
0484   desc.add<edm::ParameterSetDescription>("onlineLumiME", onlineLumiMEPSet);
0485
0486   edm::ParameterSetDescription pixelLumiMEPSet;
0487   fillLumiMePSetDescription(pixelLumiMEPSet);
0488   desc.add<edm::ParameterSetDescription>("pixelLumiME", pixelLumiMEPSet);
0489
0490   edm::ParameterSetDescription puMEPSet;
0491   fillPUMePSetDescription(puMEPSet);
0492   desc.add<edm::ParameterSetDescription>("puME", puMEPSet);
0493   desc.add<bool>("fillEveryLumiSection", true);
0494   descriptions.add("fastTimerServiceClient", desc);
0495 }
0496
0497 // declare this class as a framework plugin
0498 #include "FWCore/Framework/interface/MakerMacros.h"
0499 DEFINE_FWK_MODULE(FastTimerServiceClient);