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