edm::service::Timing Class Reference

Inheritance diagram for edm::service::Timing:

Classes
struct	CountAndTime

Public Member Functions
void	addToCPUTime (double iTime) override
double	getTotalCPU () const override
	Timing (ParameterSet const &, ActivityRegistry &)
	~Timing () override
Public Member Functions inherited from edm::TimingServiceBase
	TimingServiceBase ()
virtual	~TimingServiceBase ()

Static Public Member Functions
static void	fillDescriptions (edm::ConfigurationDescriptions &descriptions)
Static Public Member Functions inherited from edm::TimingServiceBase
static void	jobStarted ()
static double	jobStartTime ()

Private Member Functions
void	accumulateTimeBegin (std::atomic< CountAndTime * > &countAndTime, double &accumulatedTime)
void	accumulateTimeEnd (std::atomic< CountAndTime * > &countAndTime, double &accumulatedTime)
void	lastPostEvent (double curr_event_time, unsigned int index, StreamContext const &iStream)
void	postBeginJob ()
double	postCommon () const
void	postEndJob ()
void	postEvent (StreamContext const &)
void	postEventSetupGet (eventsetup::ComponentDescription const *, eventsetup::EventSetupRecordKey const &, eventsetup::DataKey const &)
void	postGlobalBeginLumi (GlobalContext const &)
void	postGlobalBeginRun (GlobalContext const &)
void	postLockEventSetupGet (eventsetup::ComponentDescription const *, eventsetup::EventSetupRecordKey const &, eventsetup::DataKey const &)
void	postModule (ModuleDescription const &md)
void	postModuleEvent (StreamContext const &, ModuleCallingContext const &)
void	postModuleGlobal (GlobalContext const &, ModuleCallingContext const &)
void	postModuleStream (StreamContext const &, ModuleCallingContext const &)
void	postOpenFile (std::string const &, bool)
void	postSourceEvent (StreamID)
void	postSourceLumi (LuminosityBlockIndex)
void	postSourceRun (RunIndex)
void	preBeginJob (PathsAndConsumesOfModulesBase const &, ProcessContext const &)
void	preEvent (StreamContext const &)
void	preLockEventSetupGet (eventsetup::ComponentDescription const *, eventsetup::EventSetupRecordKey const &, eventsetup::DataKey const &)
void	preModule (ModuleDescription const &md)
void	preModuleGlobal (GlobalContext const &, ModuleCallingContext const &)
void	preModuleStream (StreamContext const &, ModuleCallingContext const &)
void	preOpenFile (std::string const &, bool)
void	preSourceEvent (StreamID)
void	preSourceLumi (LuminosityBlockIndex)
void	preSourceRun (RunIndex)

Private Attributes
double	accumulatedTimeForGet_
double	accumulatedTimeForLock_
std::atomic< unsigned long >	begin_lumi_count_
std::atomic< unsigned long >	begin_run_count_
bool	configuredInTopLevelProcess_
std::atomic< CountAndTime * >	countAndTimeForGet_
std::atomic< CountAndTime * >	countAndTimeForLock_
CountAndTime	countAndTimeZero_
std::vector< std::unique_ptr< std::atomic< unsigned int > > >	countSubProcessesPostEvent_
std::vector< std::unique_ptr< std::atomic< unsigned int > > >	countSubProcessesPreEvent_
std::vector< double >	curr_events_time_
double	curr_job_cpu_
double	curr_job_time_
std::atomic< double >	extra_job_cpu_
std::atomic< double >	last_run_cpu_
std::atomic< double >	last_run_time_
std::vector< double >	max_events_time_
std::vector< double >	min_events_time_
unsigned int	nStreams_
unsigned int	nSubProcesses_
unsigned int	nThreads_
bool	report_summary_
std::vector< double >	sum_events_time_
bool	summary_only_
double	threshold_
std::atomic< unsigned long >	total_event_count_

Detailed Description

Definition at line 46 of file Timing.cc.

Constructor & Destructor Documentation

edm::service::Timing::Timing	(	ParameterSet const &	iPS,
		ActivityRegistry &	iRegistry
	)

Definition at line 219 of file Timing.cc.

        : curr_job_time_(0.),
          curr_job_cpu_(0.),
          extra_job_cpu_(0.0),
          last_run_time_(0.0),
          last_run_cpu_(0.0),
          curr_events_time_(),
          summary_only_(iPS.getUntrackedParameter<bool>("summaryOnly")),
          report_summary_(iPS.getUntrackedParameter<bool>("useJobReport")),
          threshold_(iPS.getUntrackedParameter<double>("excessiveTimeThreshold")),
          max_events_time_(),
          min_events_time_(),
          total_event_count_(0),
          begin_lumi_count_(0),
          begin_run_count_(0),
          countAndTimeZero_{0, 0.0},
          countAndTimeForLock_{&countAndTimeZero_},
          accumulatedTimeForLock_{0.0},
          countAndTimeForGet_{&countAndTimeZero_},
          accumulatedTimeForGet_{0.0},
          configuredInTopLevelProcess_{false},
          nSubProcesses_{0} {
      iRegistry.watchPreBeginJob(this, &Timing::preBeginJob);
      iRegistry.watchPostBeginJob(this, &Timing::postBeginJob);
      iRegistry.watchPostEndJob(this, &Timing::postEndJob);

      iRegistry.watchPreEvent(this, &Timing::preEvent);
      iRegistry.watchPostEvent(this, &Timing::postEvent);

      iRegistry.watchPreLockEventSetupGet(this, &Timing::preLockEventSetupGet);
      iRegistry.watchPostLockEventSetupGet(this, &Timing::postLockEventSetupGet);
      iRegistry.watchPostEventSetupGet(this, &Timing::postEventSetupGet);

      bool checkThreshold = true;
      if (threshold_ <= 0.0) {
        //we need to ignore the threshold check
        threshold_ = std::numeric_limits<double>::max();
        checkThreshold = false;
      }

      if ((not summary_only_) || (checkThreshold)) {
        iRegistry.watchPreModuleEvent(this, &Timing::preModuleStream);
        iRegistry.watchPostModuleEvent(this, &Timing::postModuleEvent);
      }
      if (checkThreshold) {
        iRegistry.watchPreSourceEvent(this, &Timing::preSourceEvent);
        iRegistry.watchPostSourceEvent(this, &Timing::postSourceEvent);

        iRegistry.watchPreSourceLumi(this, &Timing::preSourceLumi);
        iRegistry.watchPostSourceLumi(this, &Timing::postSourceLumi);

        iRegistry.watchPreSourceRun(this, &Timing::preSourceRun);
        iRegistry.watchPostSourceRun(this, &Timing::postSourceRun);

        iRegistry.watchPreOpenFile(this, &Timing::preOpenFile);
        iRegistry.watchPostOpenFile(this, &Timing::postOpenFile);

        iRegistry.watchPreEventReadFromSource(this, &Timing::preModuleStream);
        iRegistry.watchPostEventReadFromSource(this, &Timing::postModuleStream);

        iRegistry.watchPreModuleConstruction(this, &Timing::preModule);
        iRegistry.watchPostModuleConstruction(this, &Timing::postModule);

        iRegistry.watchPreModuleBeginJob(this, &Timing::preModule);
        iRegistry.watchPostModuleBeginJob(this, &Timing::postModule);

        iRegistry.watchPreModuleEndJob(this, &Timing::preModule);
        iRegistry.watchPostModuleEndJob(this, &Timing::postModule);

        iRegistry.watchPreModuleStreamBeginRun(this, &Timing::preModuleStream);
        iRegistry.watchPostModuleStreamBeginRun(this, &Timing::postModuleStream);
        iRegistry.watchPreModuleStreamEndRun(this, &Timing::preModuleStream);
        iRegistry.watchPostModuleStreamEndRun(this, &Timing::postModuleStream);

        iRegistry.watchPreModuleStreamBeginLumi(this, &Timing::preModuleStream);
        iRegistry.watchPostModuleStreamBeginLumi(this, &Timing::postModuleStream);
        iRegistry.watchPreModuleStreamEndLumi(this, &Timing::preModuleStream);
        iRegistry.watchPostModuleStreamEndLumi(this, &Timing::postModuleStream);

        iRegistry.watchPreModuleGlobalBeginRun(this, &Timing::preModuleGlobal);
        iRegistry.watchPostModuleGlobalBeginRun(this, &Timing::postModuleGlobal);
        iRegistry.watchPreModuleGlobalEndRun(this, &Timing::preModuleGlobal);
        iRegistry.watchPostModuleGlobalEndRun(this, &Timing::postModuleGlobal);

        iRegistry.watchPreModuleGlobalBeginLumi(this, &Timing::preModuleGlobal);
        iRegistry.watchPostModuleGlobalBeginLumi(this, &Timing::postModuleGlobal);
        iRegistry.watchPreModuleGlobalEndLumi(this, &Timing::preModuleGlobal);
        iRegistry.watchPostModuleGlobalEndLumi(this, &Timing::postModuleGlobal);

        iRegistry.watchPreSourceConstruction(this, &Timing::preModule);
        iRegistry.watchPostSourceConstruction(this, &Timing::postModule);
      }

      iRegistry.watchPostGlobalBeginRun(this, &Timing::postGlobalBeginRun);
      iRegistry.watchPostGlobalBeginLumi(this, &Timing::postGlobalBeginLumi);

      iRegistry.preallocateSignal_.connect([this](service::SystemBounds const& iBounds) {
        nStreams_ = iBounds.maxNumberOfStreams();
        nThreads_ = iBounds.maxNumberOfThreads();
        curr_events_time_.resize(nStreams_, 0.);
        sum_events_time_.resize(nStreams_, 0.);
        max_events_time_.resize(nStreams_, 0.);
        min_events_time_.resize(nStreams_, 1.E6);
        for (unsigned int i = 0; i < nStreams_; ++i) {
          countSubProcessesPreEvent_.emplace_back(std::make_unique<std::atomic<unsigned int>>(0));
          countSubProcessesPostEvent_.emplace_back(std::make_unique<std::atomic<unsigned int>>(0));
        }
      });

      iRegistry.postGlobalEndRunSignal_.connect([this](edm::GlobalContext const&) {
        last_run_time_ = getTime();
        last_run_cpu_ = getCPU();
      });
    }

edm::service::Timing::~Timing ( )

override

Definition at line 334 of file Timing.cc.

{}

Member Function Documentation

void edm::service::Timing::accumulateTimeBegin ( std::atomic< CountAndTime * > &  countAndTime, double &  accumulatedTime  )

private

Definition at line 633 of file Timing.cc.

References edm::service::Timing::CountAndTime::count_, and edm::service::getTime().

Referenced by postLockEventSetupGet(), and preLockEventSetupGet().

                                                                                                    {
      double newTime = getTime();
      auto newStat = std::make_unique<CountAndTime>(0, newTime);

      CountAndTime* oldStat = countAndTime.load();
      while (true) {
        if (oldStat == nullptr) {
          oldStat = countAndTime.load();
        } else if (countAndTime.compare_exchange_strong(oldStat, nullptr)) {
          break;
        }
      }

      newStat->count_ = oldStat->count_ + 1;
      if (oldStat->count_ != 0) {
        accumulatedTime += (newTime - oldStat->time_) * oldStat->count_;
      }
      countAndTime.store(newStat.release());
      if (oldStat != &countAndTimeZero_) {
        delete oldStat;
      }
    }

void edm::service::Timing::accumulateTimeEnd ( std::atomic< CountAndTime * > &  countAndTime, double &  accumulatedTime  )

private

Definition at line 656 of file Timing.cc.

References edm::service::Timing::CountAndTime::count_, cppFunctionSkipper::exception, edm::service::getTime(), edm::service::Timing::CountAndTime::time_, and LaserClient_cfi::Timing.

Referenced by postEventSetupGet(), and postLockEventSetupGet().

                                                                                                  {
      double newTime = getTime();

      CountAndTime* oldStat = countAndTime.load();
      while (true) {
        if (oldStat == nullptr) {
          oldStat = countAndTime.load();
        } else if (countAndTime.compare_exchange_strong(oldStat, nullptr)) {
          break;
        }
      }

      if (oldStat->count_ == 1) {
        accumulatedTime += newTime - oldStat->time_;
        countAndTime.store(&countAndTimeZero_);
      } else {
        try {
          auto newStat = std::make_unique<CountAndTime>(oldStat->count_ - 1, newTime);
          accumulatedTime += (newTime - oldStat->time_) * oldStat->count_;
          countAndTime.store(newStat.release());
        } catch (std::exception&) {
          countAndTime.store(oldStat);
          throw;
        }
      }
      delete oldStat;
    }

void edm::service::Timing::addToCPUTime ( double  iTime )

overridevirtual

Extra CPU time used by a job but not seen by cmsRun The value should be in seconds. This function is safe to call from multiple threads

Implements edm::TimingServiceBase.

Definition at line 336 of file Timing.cc.

                                          {
      //For accounting purposes we effectively can say we started earlier
      double expected = extra_job_cpu_.load();
      while (not extra_job_cpu_.compare_exchange_strong(expected, expected + iTime)) {
      }
    }

void edm::service::Timing::fillDescriptions ( edm::ConfigurationDescriptions &  descriptions )

static

Definition at line 345 of file Timing.cc.

References edm::ConfigurationDescriptions::add(), edm::ParameterSetDescription::addUntracked(), edm::ConfigurationDescriptions::setComment(), and edm::ParameterDescriptionNode::setComment().

                                                                         {
      ParameterSetDescription desc;
      desc.addUntracked<bool>("summaryOnly", false)->setComment("If 'true' do not report timing for each event");
      desc.addUntracked<bool>("useJobReport", true)->setComment("If 'true' write summary information to JobReport");
      desc.addUntracked<double>("excessiveTimeThreshold", 0.)
          ->setComment(
              "Amount of time in seconds before reporting a module or source has taken excessive time. A value of 0.0 "
              "turns off this reporting.");
      descriptions.add("Timing", desc);
      descriptions.setComment("This service reports the time it takes to run each module in a job.");
    }

double edm::service::Timing::getTotalCPU ( ) const

overridevirtual

CPU time used by this process and all its children. The value returned should be in seconds.

Implements edm::TimingServiceBase.

Definition at line 343 of file Timing.cc.

References edm::service::getCPU().

{ return getCPU(); }

void edm::service::Timing::lastPostEvent ( double  curr_event_time, unsigned int  index, StreamContext const &  iStream  )

private

Definition at line 517 of file Timing.cc.

References edm::StreamContext::eventID(), and total_event_count_.

Referenced by postEvent().

                                                                                                       {
      sum_events_time_[index] += curr_event_time;

      if (not summary_only_) {
        auto const& eventID = iStream.eventID();
        LogPrint("TimeEvent") << "TimeEvent> " << eventID.event() << " " << eventID.run() << " " << curr_event_time;
      }
      if (curr_event_time > max_events_time_[index])
        max_events_time_[index] = curr_event_time;
      if (curr_event_time < min_events_time_[index])
        min_events_time_[index] = curr_event_time;
      ++total_event_count_;
    }

void edm::service::Timing::postBeginJob ( )

private

Definition at line 365 of file Timing.cc.

References edm::service::getCPU(), and edm::service::getTime().

                              {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      curr_job_time_ = getTime();
      curr_job_cpu_ = getCPU();

      if (not summary_only_) {
        LogImportant("TimeReport") << "TimeReport> Report activated"
                                   << "\n"
                                   << "TimeReport> Report columns headings for events: "
                                   << "eventnum runnum timetaken\n"
                                   << "TimeReport> Report columns headings for modules: "
                                   << "eventnum runnum modulelabel modulename timetakeni\n"
                                   << "TimeReport> JobTime=" << curr_job_time_ << " JobCPU=" << curr_job_cpu_ << "\n";
      }
    }

double edm::service::Timing::postCommon ( ) const

private

Definition at line 594 of file Timing.cc.

References edm::service::popStack(), and OrderedSet::t.

Referenced by postModule(), postModuleEvent(), postModuleGlobal(), postModuleStream(), postOpenFile(), postSourceEvent(), postSourceLumi(), and postSourceRun().

                                    {
      if (!configuredInTopLevelProcess_) {
        return 0.0;
      }
      double t = popStack();
      if (t > threshold_) {
        LogError("ExcessiveTime")
            << "ExcessiveTime: Module used " << t
            << " seconds of time which exceeds the error threshold configured in the Timing Service of " << threshold_
            << " seconds.";
      }
      return t;
    }

void edm::service::Timing::postEndJob ( )

private

Definition at line 383 of file Timing.cc.

References curr_job_cpu_, curr_job_time_, edm::service::d2str(), extra_job_cpu_, edm::service::getCPU(), edm::service::getTime(), edm::TimingServiceBase::jobStartTime(), OrderedSet::t, total_event_count_, and edm::service::ui2str().

                            {
      if (!configuredInTopLevelProcess_) {
        LogImportant("TimeReport") << "\nTimeReport> This instance of the Timing Service will be disabled because it "
                                      "is configured in a SubProcess.\n"
                                   << "If multiple instances of the TimingService were configured only the one in the "
                                      "top level process will function.\n"
                                   << "The other instance(s) will simply print this message and do nothing.\n\n";
        return;
      }

      const double job_end_time = getTime();
      const double job_end_cpu = getCPU();
      double total_job_time = job_end_time - jobStartTime();

      double total_job_cpu = job_end_cpu + extra_job_cpu_;

      const double total_initialization_time = curr_job_time_ - jobStartTime();
      const double total_initialization_cpu = curr_job_cpu_;

      if (0.0 == jobStartTime()) {
        //did not capture beginning time
        total_job_time = job_end_time - curr_job_time_;
        total_job_cpu = job_end_cpu + extra_job_cpu_ - curr_job_cpu_;
      }

      double min_event_time = *(std::min_element(min_events_time_.begin(), min_events_time_.end()));
      double max_event_time = *(std::max_element(max_events_time_.begin(), max_events_time_.end()));

      auto total_loop_time = last_run_time_ - curr_job_time_;
      auto total_loop_cpu = last_run_cpu_ + extra_job_cpu_ - curr_job_cpu_;

      if (last_run_time_ == 0.0) {
        total_loop_time = 0.0;
        total_loop_cpu = 0.0;
      }

      double sum_all_events_time = 0;
      for (auto t : sum_events_time_) {
        sum_all_events_time += t;
      }

      double average_event_time = 0.0;
      if (total_event_count_ != 0) {
        average_event_time = sum_all_events_time / total_event_count_;
      }

      double event_throughput = 0.0;
      if (total_loop_time != 0.0) {
        event_throughput = total_event_count_ / total_loop_time;
      }

      LogImportant("TimeReport") << "TimeReport> Time report complete in " << total_job_time << " seconds"
                                 << "\n"
                                 << " Time Summary: \n"
                                 << " - Min event:   " << min_event_time << "\n"
                                 << " - Max event:   " << max_event_time << "\n"
                                 << " - Avg event:   " << average_event_time << "\n"
                                 << " - Total loop:  " << total_loop_time << "\n"
                                 << " - Total init:  " << total_initialization_time << "\n"
                                 << " - Total job:   " << total_job_time << "\n"
                                 << " - EventSetup Lock:   " << accumulatedTimeForLock_ << "\n"
                                 << " - EventSetup Get:   " << accumulatedTimeForGet_ << "\n"
                                 << " Event Throughput: " << event_throughput << " ev/s\n"
                                 << " CPU Summary: \n"
                                 << " - Total loop:  " << total_loop_cpu << "\n"
                                 << " - Total init:  " << total_initialization_cpu << "\n"
                                 << " - Total extra: " << extra_job_cpu_ << "\n"
                                 << " - Total job:   " << total_job_cpu << "\n"
                                 << " Processing Summary: \n"
                                 << " - Number of Events:  " << total_event_count_ << "\n"
                                 << " - Number of Global Begin Lumi Calls:  " << begin_lumi_count_ << "\n"
                                 << " - Number of Global Begin Run Calls: " << begin_run_count_ << "\n";

      if (report_summary_) {
        Service<JobReport> reportSvc;
        std::map<std::string, std::string> reportData;

        reportData.insert(std::make_pair("MinEventTime", d2str(min_event_time)));
        reportData.insert(std::make_pair("MaxEventTime", d2str(max_event_time)));
        reportData.insert(std::make_pair("AvgEventTime", d2str(average_event_time)));
        reportData.insert(std::make_pair("EventThroughput", d2str(event_throughput)));
        reportData.insert(std::make_pair("TotalJobTime", d2str(total_job_time)));
        reportData.insert(std::make_pair("TotalJobCPU", d2str(total_job_cpu)));
        reportData.insert(std::make_pair("TotalLoopTime", d2str(total_loop_time)));
        reportData.insert(std::make_pair("TotalLoopCPU", d2str(total_loop_cpu)));
        reportData.insert(std::make_pair("TotalInitTime", d2str(total_initialization_time)));
        reportData.insert(std::make_pair("TotalInitCPU", d2str(total_initialization_cpu)));
        reportData.insert(std::make_pair("NumberOfStreams", ui2str(nStreams_)));
        reportData.insert(std::make_pair("NumberOfThreads", ui2str(nThreads_)));
        reportData.insert(std::make_pair("EventSetup Lock", d2str(accumulatedTimeForLock_)));
        reportData.insert(std::make_pair("EventSetup Get", d2str(accumulatedTimeForGet_)));
        reportSvc->reportPerformanceSummary("Timing", reportData);

        std::map<std::string, std::string> reportData1;
        reportData1.insert(std::make_pair("NumberEvents", ui2str(total_event_count_)));
        reportData1.insert(std::make_pair("NumberBeginLumiCalls", ui2str(begin_lumi_count_)));
        reportData1.insert(std::make_pair("NumberBeginRunCalls", ui2str(begin_run_count_)));
        reportSvc->reportPerformanceSummary("ProcessingSummary", reportData1);
      }
    }

void edm::service::Timing::postEvent ( StreamContext const &  iStream )

private

Definition at line 501 of file Timing.cc.

References KineDebug3::count(), edm::service::getTime(), lastPostEvent(), edm::StreamContext::streamID(), and edm::StreamID::value().

                                                       {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      auto index = iStream.streamID().value();
      if (nSubProcesses_ == 0u) {
        lastPostEvent(getTime() - curr_events_time_[index], index, iStream);
      } else {
        unsigned int count = ++(*countSubProcessesPostEvent_[index]);
        if (count == (nSubProcesses_ + 1)) {
          lastPostEvent(getTime() - curr_events_time_[index], index, iStream);
          *countSubProcessesPostEvent_[index] = 0;
        }
      }
    }

void edm::service::Timing::postEventSetupGet ( eventsetup::ComponentDescription const *  , eventsetup::EventSetupRecordKey const &  , eventsetup::DataKey const &    )

private

Definition at line 627 of file Timing.cc.

References accumulateTimeEnd().

                                                             {
      accumulateTimeEnd(countAndTimeForGet_, accumulatedTimeForGet_);
    }

void edm::service::Timing::postGlobalBeginLumi ( GlobalContext const &  gc )

private

Definition at line 579 of file Timing.cc.

References begin_lumi_count_, edm::ProcessContext::isSubProcess(), and edm::GlobalContext::processContext().

                                                            {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      if (!gc.processContext()->isSubProcess()) {
        ++begin_lumi_count_;
      }
    }

void edm::service::Timing::postGlobalBeginRun ( GlobalContext const &  gc )

private

Definition at line 570 of file Timing.cc.

References begin_run_count_, edm::ProcessContext::isSubProcess(), and edm::GlobalContext::processContext().

                                                           {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      if (!gc.processContext()->isSubProcess()) {
        ++begin_run_count_;
      }
    }

void edm::service::Timing::postLockEventSetupGet ( eventsetup::ComponentDescription const *  , eventsetup::EventSetupRecordKey const &  , eventsetup::DataKey const &    )

private

Definition at line 617 of file Timing.cc.

References accumulateTimeBegin(), and accumulateTimeEnd().

                                                                 {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      accumulateTimeEnd(countAndTimeForLock_, accumulatedTimeForLock_);
      accumulateTimeBegin(countAndTimeForGet_, accumulatedTimeForGet_);
    }

void edm::service::Timing::postModule ( ModuleDescription const &  md )

private

Definition at line 562 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::postModuleEvent ( StreamContext const &  iStream, ModuleCallingContext const &  iModule  )

private

Definition at line 531 of file Timing.cc.

References edm::StreamContext::eventID(), edm::ModuleCallingContext::moduleDescription(), postCommon(), and OrderedSet::t.

                                                                                                  {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      auto const& eventID = iStream.eventID();
      auto const& desc = *(iModule.moduleDescription());
      double t = postCommon();
      if (not summary_only_) {
        LogPrint("TimeModule") << "TimeModule> " << eventID.event() << " " << eventID.run() << " " << desc.moduleLabel()
                               << " " << desc.moduleName() << " " << t;
      }
    }

void edm::service::Timing::postModuleGlobal ( GlobalContext const &  , ModuleCallingContext const &  mcc  )

private

Definition at line 568 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::postModuleStream ( StreamContext const &  , ModuleCallingContext const &  mcc  )

private

Definition at line 592 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::postOpenFile ( std::string const &  lfn, bool  b  )

private

Definition at line 558 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::postSourceEvent ( StreamID  sid )

private

Definition at line 546 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::postSourceLumi ( LuminosityBlockIndex  index )

private

Definition at line 550 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::postSourceRun ( RunIndex  index )

private

Definition at line 554 of file Timing.cc.

References postCommon().

{ postCommon(); }

void edm::service::Timing::preBeginJob ( PathsAndConsumesOfModulesBase const &  pathsAndConsumes, ProcessContext const &  pc  )

private

Definition at line 357 of file Timing.cc.

References edm::ProcessContext::isSubProcess(), and nSubProcesses_.

                                                                                                            {
      if (pc.isSubProcess()) {
        ++nSubProcesses_;
      } else {
        configuredInTopLevelProcess_ = true;
      }
    }

void edm::service::Timing::preEvent ( StreamContext const &  iStream )

private

Definition at line 484 of file Timing.cc.

References KineDebug3::count(), edm::service::getTime(), edm::StreamContext::streamID(), and edm::StreamID::value().

                                                      {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      auto index = iStream.streamID().value();
      if (nSubProcesses_ == 0u) {
        curr_events_time_[index] = getTime();
      } else {
        unsigned int count = ++(*countSubProcessesPreEvent_[index]);
        if (count == 1) {
          curr_events_time_[index] = getTime();
        } else if (count == (nSubProcesses_ + 1)) {
          *countSubProcessesPreEvent_[index] = 0;
        }
      }
    }

void edm::service::Timing::preLockEventSetupGet ( eventsetup::ComponentDescription const *  , eventsetup::EventSetupRecordKey const &  , eventsetup::DataKey const &    )

private

Definition at line 608 of file Timing.cc.

References accumulateTimeBegin().

                                                                {
      if (!configuredInTopLevelProcess_) {
        return;
      }
      accumulateTimeBegin(countAndTimeForLock_, accumulatedTimeForLock_);
    }

void edm::service::Timing::preModule ( ModuleDescription const &  md )

private

Definition at line 560 of file Timing.cc.

References edm::service::pushStack().

{ pushStack(configuredInTopLevelProcess_); }

void edm::service::Timing::preModuleGlobal ( GlobalContext const &  , ModuleCallingContext const &    )

private

Definition at line 564 of file Timing.cc.

References edm::service::pushStack().

                                                                                  {
      pushStack(configuredInTopLevelProcess_);
    }

void edm::service::Timing::preModuleStream ( StreamContext const &  , ModuleCallingContext const &    )

private

Definition at line 588 of file Timing.cc.

References edm::service::pushStack().

                                                                                  {
      pushStack(configuredInTopLevelProcess_);
    }

void edm::service::Timing::preOpenFile ( std::string const &  lfn, bool  b  )

private

Definition at line 556 of file Timing.cc.

References edm::service::pushStack().

{ pushStack(configuredInTopLevelProcess_); }

void edm::service::Timing::preSourceEvent ( StreamID  sid )

private

Definition at line 544 of file Timing.cc.

References edm::service::pushStack().

{ pushStack(configuredInTopLevelProcess_); }

void edm::service::Timing::preSourceLumi ( LuminosityBlockIndex  index )

private

Definition at line 548 of file Timing.cc.

References edm::service::pushStack().

{ pushStack(configuredInTopLevelProcess_); }

void edm::service::Timing::preSourceRun ( RunIndex  index )

private

Definition at line 552 of file Timing.cc.

References edm::service::pushStack().

{ pushStack(configuredInTopLevelProcess_); }

Member Data Documentation

double edm::service::Timing::accumulatedTimeForGet_

private

Definition at line 143 of file Timing.cc.

double edm::service::Timing::accumulatedTimeForLock_

private

Definition at line 140 of file Timing.cc.

std::atomic<unsigned long> edm::service::Timing::begin_lumi_count_

private

Definition at line 132 of file Timing.cc.

Referenced by postGlobalBeginLumi().

std::atomic<unsigned long> edm::service::Timing::begin_run_count_

private

Definition at line 133 of file Timing.cc.

Referenced by postGlobalBeginRun().

bool edm::service::Timing::configuredInTopLevelProcess_

private

Definition at line 148 of file Timing.cc.

std::atomic<CountAndTime*> edm::service::Timing::countAndTimeForGet_

private

Definition at line 142 of file Timing.cc.

std::atomic<CountAndTime*> edm::service::Timing::countAndTimeForLock_

private

Definition at line 139 of file Timing.cc.

CountAndTime edm::service::Timing::countAndTimeZero_

private

Definition at line 137 of file Timing.cc.

std::vector<std::unique_ptr<std::atomic<unsigned int> > > edm::service::Timing::countSubProcessesPostEvent_

private

Definition at line 146 of file Timing.cc.

std::vector<std::unique_ptr<std::atomic<unsigned int> > > edm::service::Timing::countSubProcessesPreEvent_

private

Definition at line 145 of file Timing.cc.

std::vector<double> edm::service::Timing::curr_events_time_

private

Definition at line 121 of file Timing.cc.

double edm::service::Timing::curr_job_cpu_

private

Definition at line 116 of file Timing.cc.

Referenced by postEndJob().

double edm::service::Timing::curr_job_time_

private

Definition at line 115 of file Timing.cc.

Referenced by postEndJob().

std::atomic<double> edm::service::Timing::extra_job_cpu_

private

Definition at line 117 of file Timing.cc.

Referenced by postEndJob().

std::atomic<double> edm::service::Timing::last_run_cpu_

private

Definition at line 120 of file Timing.cc.

std::atomic<double> edm::service::Timing::last_run_time_

private

Definition at line 119 of file Timing.cc.

std::vector<double> edm::service::Timing::max_events_time_

private

Definition at line 128 of file Timing.cc.

std::vector<double> edm::service::Timing::min_events_time_

private

Definition at line 129 of file Timing.cc.

unsigned int edm::service::Timing::nStreams_

private

Definition at line 134 of file Timing.cc.

unsigned int edm::service::Timing::nSubProcesses_

private

Definition at line 149 of file Timing.cc.

Referenced by preBeginJob().

unsigned int edm::service::Timing::nThreads_

private

Definition at line 135 of file Timing.cc.

bool edm::service::Timing::report_summary_

private

Definition at line 123 of file Timing.cc.

std::vector<double> edm::service::Timing::sum_events_time_

private

Definition at line 130 of file Timing.cc.

bool edm::service::Timing::summary_only_

private

Definition at line 122 of file Timing.cc.

double edm::service::Timing::threshold_

private

Definition at line 124 of file Timing.cc.

std::atomic<unsigned long> edm::service::Timing::total_event_count_

private

Definition at line 131 of file Timing.cc.

Referenced by lastPostEvent(), and postEndJob().