/
githubmirror
/
cmssw
Обзор
Документация
Войти
/
githubmirror
/
cmssw
Код
Запросы
0
Пакеты
0
Релизы
0
Аналитика
Безопасность
master
PerfTools/AllocMonitor/plugins/moduleAlloc_setupFile.cc
1 102 строки
50 KB
Christopher Jones
Add ESModule constructor info to ModuleAlloc file
02 дек 2025, 01:57
02 дек 2025, 01:57
7ae5a70
Код
Авторство
О чём код?
#include "moduleAlloc_setupFile.h" #include "monitor_file_utilities.h" #include <chrono> #include <numeric> #include <sstream> #include <type_traits> #include <cassert> #include <typeindex> #include "FWCore/Concurrency/interface/ThreadSafeOutputFileStream.h" #include "DataFormats/Provenance/interface/EventID.h" #include "DataFormats/Provenance/interface/LuminosityBlockID.h" #include "DataFormats/Provenance/interface/ModuleDescription.h" #include "DataFormats/Provenance/interface/RunID.h" #include "DataFormats/Provenance/interface/Timestamp.h" #include "FWCore/ServiceRegistry/interface/GlobalContext.h" #include "FWCore/ServiceRegistry/interface/ModuleCallingContext.h" #include "FWCore/ServiceRegistry/interface/ESModuleCallingContext.h" #include "FWCore/ServiceRegistry/interface/PathContext.h" #include "FWCore/ServiceRegistry/interface/ProcessContext.h" #include "FWCore/ServiceRegistry/interface/StreamContext.h" #include "FWCore/ServiceRegistry/interface/ActivityRegistry.h" #include "FWCore/Framework/interface/IOVSyncValue.h" #include "FWCore/Framework/interface/ESRecordsToProductResolverIndices.h" #include "FWCore/AbstractServices/interface/TimingServiceBase.h" #include "ThreadAllocInfo.h" using namespace edm::moduleAlloc::monitor_file_utilities; namespace { using duration_t = std::chrono::microseconds; using clock_t = std::chrono::steady_clock; auto const now = clock_t::now; enum class Step : char { preSourceTransition = 'S', postSourceTransition = 's', preModuleEventAcquire = 'A', postModuleEventAcquire = 'a', preModuleTransition = 'M', preEventReadFromSource = 'R', postEventReadFromSource = 'r', preModuleEventDelayedGet = 'D', postModuleEventDelayedGet = 'd', postModuleTransition = 'm', preESModule = 'N', postESModule = 'n', preESModuleAcquire = 'B', postESModuleAcquire = 'b', preFrameworkTransition = 'F', postFrameworkTransition = 'f' }; constexpr bool isPostTransition(Step s) { switch (s) { case Step::postSourceTransition: case Step::postModuleEventAcquire: case Step::postEventReadFromSource: case Step::postModuleEventDelayedGet: case Step::postModuleTransition: case Step::postESModule: case Step::postESModuleAcquire: case Step::postFrameworkTransition: return true; default: return false; } return false; } enum class Phase : short { destruction = -16, endJob = -12, endStream = -11, writeProcessBlock = -10, endProcessBlock = -9, globalWriteRun = -7, globalEndRun = -6, streamEndRun = -5, globalWriteLumi = -4, globalEndLumi = -3, streamEndLumi = -2, clearEvent = -1, Event = 0, streamBeginLumi = 2, globalBeginLumi = 3, streamBeginRun = 5, globalBeginRun = 6, accessInputProcessBlock = 8, beginProcessBlock = 9, openFile = 10, beginStream = 11, beginJob = 12, esSync = 13, esSyncEnqueue = 14, getNextTransition = 15, construction = 16, startTracing = 17 }; std::ostream& operator<<(std::ostream& os, Step const s) { os << static_cast<std::underlying_type_t<Step>>(s); return os; } std::ostream& operator<<(std::ostream& os, Phase const s) { os << static_cast<std::underlying_type_t<Phase>>(s); return os; } template <Step S, typename... ARGS> std::string assembleMessage(ARGS const... args) { std::ostringstream oss; oss << S; concatenate(oss, args...); oss << '\n'; return oss.str(); } template <Step S, typename... ARGS> std::string assembleAllocMessage(edm::service::moduleAlloc::ThreadAllocInfo const& info, ARGS const... args) { std::ostringstream oss; oss << S; concatenate(oss, args...); concatenate(oss, info.nAllocations_, info.nDeallocations_, info.presentActual_, info.minActual_, info.maxActual_, info.maxSingleAlloc_); oss << '\n'; return oss.str(); } Phase toTransitionImpl(edm::StreamContext const& iContext) { using namespace edm; switch (iContext.transition()) { case StreamContext::Transition::kBeginStream: return Phase::beginStream; case StreamContext::Transition::kBeginRun: return Phase::streamBeginRun; case StreamContext::Transition::kBeginLuminosityBlock: return Phase::streamBeginLumi; case StreamContext::Transition::kEvent: return Phase::Event; case StreamContext::Transition::kEndLuminosityBlock: return Phase::streamEndLumi; case StreamContext::Transition::kEndRun: return Phase::streamEndRun; case StreamContext::Transition::kEndStream: return Phase::endStream; default: break; } assert(false); return Phase::Event; } auto toTransition(edm::StreamContext const& iContext) -> std::underlying_type_t<Phase> { return static_cast<std::underlying_type_t<Phase>>(toTransitionImpl(iContext)); } Phase toTransitionImpl(edm::GlobalContext const& iContext) { using namespace edm; switch (iContext.transition()) { case GlobalContext::Transition::kBeginProcessBlock: return Phase::beginProcessBlock; case GlobalContext::Transition::kAccessInputProcessBlock: return Phase::accessInputProcessBlock; case GlobalContext::Transition::kBeginRun: return Phase::globalBeginRun; case GlobalContext::Transition::kBeginLuminosityBlock: return Phase::globalBeginLumi; case GlobalContext::Transition::kEndLuminosityBlock: return Phase::globalEndLumi; case GlobalContext::Transition::kWriteLuminosityBlock: return Phase::globalWriteLumi; case GlobalContext::Transition::kEndRun: return Phase::globalEndRun; case GlobalContext::Transition::kWriteRun: return Phase::globalWriteRun; case GlobalContext::Transition::kEndProcessBlock: return Phase::endProcessBlock; case GlobalContext::Transition::kWriteProcessBlock: return Phase::writeProcessBlock; default: break; } assert(false); return Phase::Event; } auto toTransition(edm::GlobalContext const& iContext) -> std::underlying_type_t<Phase> { return static_cast<std::underlying_type_t<Phase>>(toTransitionImpl(iContext)); } unsigned int toTransitionIndex(edm::GlobalContext const& iContext) { if (iContext.transition() == edm::GlobalContext::Transition::kBeginProcessBlock or iContext.transition() == edm::GlobalContext::Transition::kEndProcessBlock or iContext.transition() == edm::GlobalContext::Transition::kWriteProcessBlock or iContext.transition() == edm::GlobalContext::Transition::kAccessInputProcessBlock) { return 0; } if (iContext.transition() == edm::GlobalContext::Transition::kBeginRun or iContext.transition() == edm::GlobalContext::Transition::kEndRun or iContext.transition() == edm::GlobalContext::Transition::kWriteRun) { return iContext.runIndex(); } return iContext.luminosityBlockIndex(); } using namespace edm::service::moduleAlloc; template <Step S> struct ESModuleState { ESModuleState(std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile, decltype(now()) beginTime, std::shared_ptr<std::vector<std::type_index>> recordIndices, Filter const* iFilter) : logFile_{logFile}, recordIndices_{recordIndices}, beginTime_{beginTime}, filter_(iFilter) {} void operator()(edm::eventsetup::EventSetupRecordKey const& iKey, edm::ESModuleCallingContext const& iContext) const { using namespace edm; auto const t = std::chrono::duration_cast<duration_t>(now() - beginTime_).count(); auto top = iContext.getTopModuleCallingContext(); short int phase = 0; unsigned long phaseID = 0xFFFFFFFF; if (top->type() == ParentContext::Type::kGlobal) { auto global = top->globalContext(); phase = toTransition(*global); phaseID = toTransitionIndex(*global); } else if (top->type() == ParentContext::Type::kStream) { auto stream = top->getStreamContext(); phase = toTransition(*stream); phaseID = stream_id(*stream); } else if (top->type() == ParentContext::Type::kPlaceInPath) { auto stream = top->getStreamContext(); phase = toTransition(*stream); phaseID = stream_id(*stream); } auto recordIndex = findRecordIndices(iKey); if constexpr (isPostTransition(S)) { auto info = filter_->stopOnThread(-1 * (iContext.componentDescription()->id_ + 1)); if (info) { auto msg = assembleAllocMessage<S>( *info, phase, phaseID, iContext.componentDescription()->id_ + 1, recordIndex, iContext.callID(), t); logFile_->write(std::move(msg)); } } else { if (filter_->startOnThread(-1 * (iContext.componentDescription()->id_ + 1))) { auto msg = assembleMessage<S>( phase, phaseID, iContext.componentDescription()->id_ + 1, recordIndex, iContext.callID(), t); logFile_->write(std::move(msg)); } } } private: int findRecordIndices(edm::eventsetup::EventSetupRecordKey const& iKey) const { auto index = std::type_index(iKey.type().value()); auto itFind = std::find(recordIndices_->begin(), recordIndices_->end(), index); return itFind - recordIndices_->begin(); } std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile_; std::shared_ptr<std::vector<std::type_index>> recordIndices_; decltype(now()) beginTime_; Filter const* filter_; }; template <Step S> struct GlobalEDModuleState { GlobalEDModuleState(std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile, decltype(now()) beginTime, Filter const* iFilter) : logFile_{logFile}, beginTime_{beginTime}, filter_(iFilter) {} void operator()(edm::GlobalContext const& gc, edm::ModuleCallingContext const& mcc) { using namespace edm; auto const t = std::chrono::duration_cast<duration_t>(now() - beginTime_).count(); if constexpr (isPostTransition(S)) { auto id = module_id(mcc); auto info = filter_->stopOnThread(id); if (info) { auto msg = assembleAllocMessage<S>(*info, toTransition(gc), toTransitionIndex(gc), id, module_callid(mcc), t); logFile_->write(std::move(msg)); } } else { auto id = module_id(mcc); if (filter_->startOnThread(id)) { auto msg = assembleMessage<S>(toTransition(gc), toTransitionIndex(gc), module_id(mcc), module_callid(mcc), t); logFile_->write(std::move(msg)); } } } private: std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile_; decltype(now()) beginTime_; Filter const* filter_; }; template <Step S> struct StreamEDModuleState { StreamEDModuleState(std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile, decltype(now()) beginTime, Filter const* iFilter) : logFile_{logFile}, beginTime_{beginTime}, filter_(iFilter) {} void operator()(edm::StreamContext const& sc, edm::ModuleCallingContext const& mcc) { using namespace edm; auto const t = std::chrono::duration_cast<duration_t>(now() - beginTime_).count(); if constexpr (isPostTransition(S)) { auto id = module_id(mcc); auto info = filter_->stopOnThread(id); if (info) { auto msg = assembleAllocMessage<S>(*info, toTransition(sc), stream_id(sc), module_id(mcc), module_callid(mcc), t); logFile_->write(std::move(msg)); } } else { auto id = module_id(mcc); if (filter_->startOnThread(id)) { auto msg = assembleMessage<S>(toTransition(sc), stream_id(sc), id, module_callid(mcc), t); logFile_->write(std::move(msg)); } } } private: std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile_; decltype(now()) beginTime_; Filter const* filter_; }; struct ModuleCtrDtr { long long beginConstruction = 0; long long endConstruction = 0; edm::service::moduleAlloc::ThreadAllocInfo constructionAllocInfo; long long beginDestruction = 0; long long endDestruction = 0; edm::service::moduleAlloc::ThreadAllocInfo destructionAllocInfo; }; } // namespace namespace edm::service::moduleAlloc { void setupFile(std::string const& iFileName, edm::ActivityRegistry& iRegistry, Filter const* iFilter) { auto beginModuleAlloc = now(); using namespace std::chrono; if (iFileName.empty()) { return; } auto logFile = std::make_shared<edm::ThreadSafeOutputFileStream>(iFileName); auto beginTime = TimingServiceBase::jobStartTime(); auto esModuleCtrDtrPtr = std::make_shared<std::vector<ModuleCtrDtr>>(); auto& esModuleCtrDtr = *esModuleCtrDtrPtr; auto esModuleLabelsPtr = std::make_shared<std::vector<std::string>>(); auto& esModuleLabels = *esModuleLabelsPtr; auto esModuleTypesPtr = std::make_shared<std::vector<std::string>>(); auto& esModuleTypes = *esModuleTypesPtr; //acquire names for all the ED and ES modules iRegistry.watchPreESModuleConstruction( [&esModuleLabels, &esModuleTypes, &esModuleCtrDtr, beginTime, iFilter](auto const& iDescription) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto const mid = iDescription.id_ + 1; //NOTE: we want the id to start at 1 not 0 if (esModuleLabels.size() <= mid) { esModuleLabels.resize(mid + 1); esModuleTypes.resize(mid + 1); esModuleCtrDtr.resize(mid + 1); } if (not iDescription.label_.empty()) { esModuleLabels[mid] = iDescription.label_; } else { esModuleLabels[mid] = iDescription.type_; } esModuleTypes[mid] = iDescription.type_; esModuleCtrDtr.back().beginConstruction = t; iFilter->startOnThread(-1 * mid); }); iRegistry.watchPostESModuleConstruction([&esModuleCtrDtr, beginTime, iFilter](auto const& md) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto const mid = md.id_ + 1; esModuleCtrDtr[mid].endConstruction = t; auto alloc = iFilter->stopOnThread(-1 * mid); if (alloc) { esModuleCtrDtr[mid].constructionAllocInfo = *alloc; } }); auto moduleCtrDtrPtr = std::make_shared<std::vector<ModuleCtrDtr>>(); auto& moduleCtrDtr = *moduleCtrDtrPtr; auto moduleLabelsPtr = std::make_shared<std::vector<std::string>>(); auto moduleTypesPtr = std::make_shared<std::vector<std::string>>(); auto& moduleLabels = *moduleLabelsPtr; auto& moduleTypes = *moduleTypesPtr; iRegistry.watchPreModuleConstruction( [&moduleLabels, &moduleTypes, &moduleCtrDtr, beginTime, iFilter](ModuleDescription const& md) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto const mid = md.id(); if (mid < moduleLabels.size()) { moduleLabels[mid] = md.moduleLabel(); moduleTypes[mid] = md.moduleName(); moduleCtrDtr[mid].beginConstruction = t; } else { moduleLabels.resize(mid + 1); moduleLabels.back() = md.moduleLabel(); moduleTypes.resize(mid + 1); moduleTypes.back() = md.moduleName(); moduleCtrDtr.resize(mid + 1); moduleCtrDtr.back().beginConstruction = t; } iFilter->startOnThread(mid); }); iRegistry.watchPostModuleConstruction([&moduleCtrDtr, beginTime, iFilter](auto const& md) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); moduleCtrDtr[md.id()].endConstruction = t; auto alloc = iFilter->stopOnThread(md.id()); if (alloc) { moduleCtrDtr[md.id()].constructionAllocInfo = *alloc; } }); auto addDataInDtr = std::make_shared<bool>(false); iRegistry.watchPreModuleDestruction([&moduleCtrDtr, beginTime, iFilter, addDataInDtr, logFile](auto const& md) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); if (*addDataInDtr) { if (iFilter->keepModuleInfo(md.id())) { auto bmsg = assembleMessage<Step::preModuleTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::destruction), 0, md.id(), 0, 0, 0, t); logFile->write(std::move(bmsg)); } } else { moduleCtrDtr[md.id()].beginDestruction = t; } iFilter->startOnThread(md.id()); }); iRegistry.watchPostModuleDestruction([&moduleCtrDtr, beginTime, iFilter, addDataInDtr, logFile](auto const& md) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); if (not *addDataInDtr) { moduleCtrDtr[md.id()].endDestruction = t; } auto info = iFilter->stopOnThread(md.id()); if (info) { if (*addDataInDtr) { if (iFilter->keepModuleInfo(md.id())) { auto emsg = assembleAllocMessage<Step::postModuleTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::destruction), 0, md.id(), 0, 0, 0, t); logFile->write(std::move(emsg)); } } else { moduleCtrDtr[md.id()].destructionAllocInfo = *info; } } }); auto sourceCtrPtr = std::make_shared<ModuleCtrDtr>(); auto& sourceCtr = *sourceCtrPtr; auto sourceTypePtr = std::make_shared<std::string>("Unknown"); iRegistry.watchPreSourceConstruction([&sourceCtr, sourceTypePtr, beginTime, iFilter](auto const& md) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); sourceCtr.beginConstruction = t; // Capture source module type information *sourceTypePtr = md.moduleName(); iFilter->startOnThread(); }); iRegistry.watchPostSourceConstruction([&sourceCtr, beginTime, iFilter](auto const&) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); sourceCtr.endConstruction = t; auto info = iFilter->stopOnThread(); if (info) { sourceCtr.constructionAllocInfo = *info; } }); auto recordIndices = std::make_shared<std::vector<std::type_index>>(); iRegistry.watchEventSetupConfiguration( [logFile, recordIndices](auto const& recordsToResolvers, auto const&) mutable { std::ostringstream oss; auto recordKeys = recordsToResolvers.recordKeys(); std::sort(recordKeys.begin(), recordKeys.end()); std::vector<std::string> recordNames; //want id to start at 1 not 0 recordNames.reserve(recordKeys.size() + 1); recordNames.emplace_back(""); recordIndices->reserve(recordKeys.size() + 1); recordIndices->push_back(std::type_index(typeid(void))); for (auto const& r : recordKeys) { recordNames.push_back(r.name()); recordIndices->push_back(std::type_index(r.type().value())); } moduleIdToLabel(oss, recordNames, 'R', "Record ID", "Record name"); logFile->write(oss.str()); }); iRegistry.watchPreBeginJob([logFile, iFilter, moduleLabelsPtr, moduleTypesPtr, esModuleLabelsPtr, esModuleTypesPtr, moduleCtrDtrPtr, esModuleCtrDtrPtr, sourceCtrPtr, sourceTypePtr = std::move(sourceTypePtr), beginTime, beginModuleAlloc, addDataInDtr](auto&) mutable { *addDataInDtr = true; { std::ostringstream oss; moduleIdToLabelAndType( oss, *moduleLabelsPtr, *moduleTypesPtr, 'M', "EDModule ID", "Module label", "Module type"); logFile->write(oss.str()); moduleLabelsPtr.reset(); moduleTypesPtr.reset(); } { std::ostringstream oss; moduleIdToLabelAndType( oss, *esModuleLabelsPtr, *esModuleTypesPtr, 'N', "ESModule ID", "ESModule label", "ESModule type"); logFile->write(oss.str()); esModuleLabelsPtr.reset(); esModuleTypesPtr.reset(); } { std::ostringstream oss; std::vector<std::string> sourceTypeList{1, *sourceTypePtr}; std::vector<std::string> sourceNames{1, "source"}; moduleIdToLabelAndType(oss, sourceNames, sourceTypeList, 'S', "Source ID", "Source label", "Source type"); logFile->write(oss.str()); sourceTypePtr.reset(); } { auto const moduleAllocStart = duration_cast<duration_t>(beginModuleAlloc - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::startTracing), 0, 0, 0, 0, moduleAllocStart); logFile->write(std::move(msg)); } if (not iFilter->globalKeep()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, 0, 0, 0, t); logFile->write(std::move(msg)); return; } { std::vector<int> indices(esModuleCtrDtrPtr->size()); std::iota(indices.begin(), indices.end(), 0); std::sort(indices.begin(), indices.end(), [&esModuleCtrDtrPtr](int l, int r) { return (*esModuleCtrDtrPtr)[l].beginConstruction < (*esModuleCtrDtrPtr)[r].beginConstruction; }); for (auto index : indices) { if (not iFilter->keepModuleInfo(-1 * index)) { continue; } auto const& ctr = (*esModuleCtrDtrPtr)[index]; if (ctr.beginConstruction != 0 and ctr.endConstruction != 0) { auto msg = assembleMessage<Step::preESModule>( static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, index, 0, 0, ctr.beginConstruction); logFile->write(std::move(msg)); auto emsg = assembleAllocMessage<Step::postESModule>( ctr.constructionAllocInfo, static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, index, 0, 0, ctr.endConstruction); logFile->write(std::move(emsg)); ++index; } } } //NOTE: the source construction can run concurently with module construction so we need to properly // interleave its timing in with the modules auto srcBeginConstruction = sourceCtrPtr->beginConstruction; auto srcEndConstruction = sourceCtrPtr->endConstruction; auto srcAllocInfo = sourceCtrPtr->constructionAllocInfo; sourceCtrPtr.reset(); auto handleSource = [&srcBeginConstruction, &srcEndConstruction, &logFile, &srcAllocInfo](long long iTime) mutable { if (srcBeginConstruction != 0 and srcBeginConstruction < iTime) { auto bmsg = assembleMessage<Step::preSourceTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, srcBeginConstruction); logFile->write(std::move(bmsg)); srcBeginConstruction = 0; } if (srcEndConstruction != 0 and srcEndConstruction < iTime) { auto bmsg = assembleAllocMessage<Step::postSourceTransition>( srcAllocInfo, static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, srcEndConstruction); logFile->write(std::move(bmsg)); srcEndConstruction = 0; } }; { std::vector<int> indices(moduleCtrDtrPtr->size()); std::iota(indices.begin(), indices.end(), 0); std::sort(indices.begin(), indices.end(), [&moduleCtrDtrPtr](auto const& l, auto const& r) { return (*moduleCtrDtrPtr)[l].beginConstruction < (*moduleCtrDtrPtr)[r].beginConstruction; }); for (auto const id : indices) { auto const& ctr = (*moduleCtrDtrPtr)[id]; if (ctr.beginConstruction != 0) { handleSource(ctr.beginConstruction); if (iFilter->keepModuleInfo(id)) { auto bmsg = assembleMessage<Step::preModuleTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, id, 0, ctr.beginConstruction); logFile->write(std::move(bmsg)); } handleSource(ctr.endConstruction); if (iFilter->keepModuleInfo(id)) { auto const& allocInfo = ctr.constructionAllocInfo; auto emsg = assembleAllocMessage<Step::postModuleTransition>( allocInfo, static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, id, 0, ctr.endConstruction); logFile->write(std::move(emsg)); } } } std::iota(indices.begin(), indices.end(), 0); std::sort(indices.begin(), indices.end(), [&moduleCtrDtrPtr](auto const& l, auto const& r) { return (*moduleCtrDtrPtr)[l].beginDestruction < (*moduleCtrDtrPtr)[r].beginDestruction; }); for (auto const id : indices) { auto const& dtr = (*moduleCtrDtrPtr)[id]; if (dtr.beginDestruction != 0) { handleSource(dtr.beginDestruction); if (iFilter->keepModuleInfo(id)) { auto bmsg = assembleMessage<Step::preModuleTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::destruction), 0, id, 0, 0, 0, dtr.beginDestruction); logFile->write(std::move(bmsg)); } handleSource(dtr.endDestruction); if (iFilter->keepModuleInfo(id)) { auto emsg = assembleAllocMessage<Step::postModuleTransition>( dtr.destructionAllocInfo, static_cast<std::underlying_type_t<Phase>>(Phase::destruction), 0, id, 0, 0, 0, dtr.endDestruction); logFile->write(std::move(emsg)); } } } moduleCtrDtrPtr.reset(); } auto const t = duration_cast<duration_t>(now() - beginTime).count(); handleSource(t); auto msg = assembleMessage<Step::preFrameworkTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, 0, 0, 0, t); logFile->write(std::move(msg)); }); iRegistry.watchPostBeginJob([logFile, beginTime]() { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::postFrameworkTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, 0, 0, 0, t); logFile->write(std::move(msg)); }); iRegistry.watchPreEndJob([logFile, beginTime]() { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, 0, 0, 0, t); logFile->write(std::move(msg)); }); iRegistry.watchPostEndJob([logFile, beginTime]() { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::postFrameworkTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, 0, 0, 0, t); logFile->write(std::move(msg)); }); iRegistry.watchPreEvent([logFile, beginTime](auto const& sc) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::Event), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), sc.eventID().event(), t); logFile->write(std::move(msg)); }); iRegistry.watchPostEvent([logFile, beginTime](auto const& sc) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::postFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::Event), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), sc.eventID().event(), t); logFile->write(std::move(msg)); }); iRegistry.watchPreClearEvent([logFile, beginTime, iFilter](auto const& sc) { if (iFilter->startOnThread()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::clearEvent), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), sc.eventID().event(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPostClearEvent([logFile, beginTime, iFilter](auto const& sc) { auto info = iFilter->stopOnThread(); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postFrameworkTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::clearEvent), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), sc.eventID().event(), t); logFile->write(std::move(msg)); } }); { auto preGlobal = [logFile, beginTime](GlobalContext const& gc) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>(toTransition(gc), toTransitionIndex(gc), gc.luminosityBlockID().run(), gc.luminosityBlockID().luminosityBlock(), 0, t); logFile->write(std::move(msg)); }; iRegistry.watchPreBeginProcessBlock(preGlobal); iRegistry.watchPreEndProcessBlock(preGlobal); iRegistry.watchPreWriteProcessBlock(preGlobal); iRegistry.watchPreAccessInputProcessBlock(preGlobal); iRegistry.watchPreGlobalBeginRun(preGlobal); iRegistry.watchPreGlobalBeginLumi(preGlobal); iRegistry.watchPreGlobalEndLumi(preGlobal); iRegistry.watchPreGlobalWriteLumi(preGlobal); iRegistry.watchPreGlobalEndRun(preGlobal); iRegistry.watchPreGlobalWriteRun(preGlobal); } { auto postGlobal = [logFile, beginTime](GlobalContext const& gc) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::postFrameworkTransition>(toTransition(gc), toTransitionIndex(gc), gc.luminosityBlockID().run(), gc.luminosityBlockID().luminosityBlock(), 0, t); logFile->write(std::move(msg)); }; iRegistry.watchPostBeginProcessBlock(postGlobal); iRegistry.watchPostEndProcessBlock(postGlobal); iRegistry.watchPostWriteProcessBlock(postGlobal); iRegistry.watchPostAccessInputProcessBlock(postGlobal); iRegistry.watchPostGlobalBeginRun(postGlobal); iRegistry.watchPostGlobalBeginLumi(postGlobal); iRegistry.watchPostGlobalEndLumi(postGlobal); iRegistry.watchPostGlobalWriteLumi(postGlobal); iRegistry.watchPostGlobalEndRun(postGlobal); iRegistry.watchPostGlobalWriteRun(postGlobal); } { auto preStream = [logFile, beginTime](StreamContext const& sc) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preFrameworkTransition>( toTransition(sc), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), 0, t); logFile->write(std::move(msg)); }; iRegistry.watchPreStreamBeginRun(preStream); iRegistry.watchPreStreamBeginLumi(preStream); iRegistry.watchPreStreamEndLumi(preStream); iRegistry.watchPreStreamEndRun(preStream); } { auto postStream = [logFile, beginTime](StreamContext const& sc) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::postFrameworkTransition>( toTransition(sc), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), 0, t); logFile->write(std::move(msg)); }; iRegistry.watchPostStreamBeginRun(postStream); iRegistry.watchPostStreamBeginLumi(postStream); iRegistry.watchPostStreamEndLumi(postStream); iRegistry.watchPostStreamEndRun(postStream); } { iRegistry.watchPreOpenFile([logFile, beginTime, iFilter](std::string const&) { if (iFilter->startOnThread()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preSourceTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::openFile), 0, t); logFile->write(std::move(msg)); } }); iRegistry.watchPostOpenFile([logFile, beginTime, iFilter](std::string const&) { auto info = iFilter->stopOnThread(); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postSourceTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::openFile), 0, t); logFile->write(std::move(msg)); } }); iRegistry.watchPreSourceEvent([logFile, beginTime, iFilter](StreamID id) { if (iFilter->startOnThread()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preSourceTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::Event), id.value(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPostSourceEvent([logFile, beginTime, iFilter](StreamID id) { auto info = iFilter->stopOnThread(); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postSourceTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::Event), id.value(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPreSourceRun([logFile, beginTime, iFilter](RunIndex id) { if (iFilter->startOnThread()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preSourceTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginRun), id.value(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPostSourceRun([logFile, beginTime, iFilter](RunIndex id) { auto info = iFilter->stopOnThread(); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postSourceTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginRun), id.value(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPreSourceLumi([logFile, beginTime, iFilter](auto id) { if (iFilter->startOnThread()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preSourceTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginLumi), id.value(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPostSourceLumi([logFile, beginTime, iFilter](auto id) { auto info = iFilter->stopOnThread(); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postSourceTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginLumi), id.value(), t); logFile->write(std::move(msg)); } }); iRegistry.watchPreSourceNextTransition([logFile, beginTime, iFilter]() { if (iFilter->startOnThread()) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preSourceTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::getNextTransition), t); logFile->write(std::move(msg)); } }); iRegistry.watchPostSourceNextTransition([logFile, beginTime, iFilter]() { auto info = iFilter->stopOnThread(); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postSourceTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::getNextTransition), t); logFile->write(std::move(msg)); } }); //ED Modules iRegistry.watchPreModuleBeginJob([logFile, beginTime, iFilter](auto const& md) { if (iFilter->startOnThread(md.id())) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preModuleTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, md.id(), 0, t); logFile->write(std::move(msg)); } }); iRegistry.watchPostModuleBeginJob([logFile, beginTime, iFilter](auto const& md) { auto info = iFilter->stopOnThread(md.id()); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postModuleTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, md.id(), 0, t); logFile->write(std::move(msg)); } }); iRegistry.watchPreModuleBeginStream(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleBeginStream( StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleEndStream(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleEndStream(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleEndJob([logFile, beginTime, iFilter](auto const& md) { if (iFilter->startOnThread(md.id())) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleMessage<Step::preModuleTransition>( static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, md.id(), 0, t); logFile->write(std::move(msg)); } }); iRegistry.watchPostModuleEndJob([logFile, beginTime, iFilter](auto const& md) { auto info = iFilter->stopOnThread(md.id()); if (info) { auto const t = duration_cast<duration_t>(now() - beginTime).count(); auto msg = assembleAllocMessage<Step::postModuleTransition>( *info, static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, md.id(), 0, t); logFile->write(std::move(msg)); } }); iRegistry.watchPreModuleEvent(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleEvent(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleEventAcquire( StreamEDModuleState<Step::preModuleEventAcquire>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleEventAcquire( StreamEDModuleState<Step::postModuleEventAcquire>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleEventDelayedGet( StreamEDModuleState<Step::preModuleEventDelayedGet>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleEventDelayedGet( StreamEDModuleState<Step::postModuleEventDelayedGet>(logFile, beginTime, iFilter)); iRegistry.watchPreEventReadFromSource( StreamEDModuleState<Step::preEventReadFromSource>(logFile, beginTime, iFilter)); iRegistry.watchPostEventReadFromSource( StreamEDModuleState<Step::postEventReadFromSource>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleTransform(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleTransform(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleTransformAcquiring( StreamEDModuleState<Step::preModuleEventAcquire>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleTransformAcquiring( StreamEDModuleState<Step::postModuleEventAcquire>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleStreamBeginRun( StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleStreamBeginRun( StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleStreamEndRun(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleStreamEndRun( StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleStreamBeginLumi( StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleStreamBeginLumi( StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleStreamEndLumi( StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleStreamEndLumi( StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleBeginProcessBlock( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleBeginProcessBlock( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleAccessInputProcessBlock( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleAccessInputProcessBlock( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleEndProcessBlock( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleEndProcessBlock( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleGlobalBeginRun( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleGlobalBeginRun( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleGlobalEndRun(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleGlobalEndRun( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleGlobalBeginLumi( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleGlobalBeginLumi( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleGlobalEndLumi( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleGlobalEndLumi( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleWriteProcessBlock( GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleWriteProcessBlock( GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleWriteRun(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleWriteRun(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPreModuleWriteLumi(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime, iFilter)); iRegistry.watchPostModuleWriteLumi(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime, iFilter)); //ES Modules iRegistry.watchPreESModule(ESModuleState<Step::preESModule>(logFile, beginTime, recordIndices, iFilter)); iRegistry.watchPostESModule(ESModuleState<Step::postESModule>(logFile, beginTime, recordIndices, iFilter)); iRegistry.watchPreESModuleAcquire( ESModuleState<Step::preESModuleAcquire>(logFile, beginTime, recordIndices, iFilter)); iRegistry.watchPostESModuleAcquire( ESModuleState<Step::postESModuleAcquire>(logFile, beginTime, recordIndices, iFilter)); } std::ostringstream oss; oss << "# Transition Type Symbol\n"; oss << "#------------------------ ------\n"; oss << "# startTracing " << Phase::startTracing << "\n" << "# construction " << Phase::construction << "\n" << "# getNextTransition " << Phase::getNextTransition << "\n" << "# beginJob " << Phase::beginJob << "\n" << "# beginStream " << Phase::beginStream << "\n" << "# openFile " << Phase::openFile << "\n" << "# beginProcessBlock " << Phase::beginProcessBlock << "\n" << "# accessInputProcessBlock " << Phase::accessInputProcessBlock << "\n" << "# globalBeginRun " << Phase::globalBeginRun << "\n" << "# streamBeginRun " << Phase::streamBeginRun << "\n" << "# globalBeginLumi " << Phase::globalBeginLumi << "\n" << "# streamBeginLumi " << Phase::streamBeginLumi << "\n" << "# Event " << Phase::Event << "\n" << "# clearEvent " << Phase::clearEvent << "\n" << "# streamEndLumi " << Phase::streamEndLumi << "\n" << "# globalEndLumi " << Phase::globalEndLumi << "\n" << "# globalWriteLumi " << Phase::globalWriteLumi << "\n" << "# streamEndRun " << Phase::streamEndRun << "\n" << "# globalEndRun " << Phase::globalEndRun << "\n" << "# globalWriteRun " << Phase::globalWriteRun << "\n" << "# endProcessBlock " << Phase::endProcessBlock << "\n" << "# writeProcessBlock " << Phase::writeProcessBlock << "\n" << "# endStream " << Phase::endStream << "\n" << "# endJob " << Phase::endJob << "\n" << "# destruction " << Phase::destruction << "\n\n"; constexpr std::string_view kTransition = " <Transition type> <Transition ID>"; constexpr std::string_view kTransitionInfo = " <Run #> <LumiBlock #> <Event #>"; constexpr std::string_view kTime = " <Time since begin of cmsRun (us)>"; constexpr std::string_view kEDModule = " <EDModule ID> <Call ID>"; constexpr std::string_view kESModule = " <ESModule ID> <Record ID> <Call ID>"; constexpr std::string_view kAllocInfo = " <# allocs> <# deallocs> <additional bytes> <min bytes> <max bytes> <max allocation bytes>"; oss << "# Step Symbol Entries\n" << "# -------------------------- ------ ------------------------------------------\n" << "# preSourceTransition " << Step::preSourceTransition << kTransition << kTime << "\n" << "# postSourceTransition " << Step::postSourceTransition << kTransition << kTime << " " << kAllocInfo << "\n" << "# preModuleEventAcquire " << Step::preModuleEventAcquire << kTransition << kEDModule << kTime << "\n" << "# postModuleEventAcquire " << Step::postModuleEventAcquire << kTransition << kEDModule << kTime << kAllocInfo << "\n" << "# preModuleTransition " << Step::preModuleTransition << kTransition << kEDModule << kTime << "\n" << "# preEventReadFromSource " << Step::preEventReadFromSource << kTransition << kEDModule << kTime << "\n" << "# postEventReadFromSource " << Step::postEventReadFromSource << kTransition << kEDModule << kTime << kAllocInfo << "\n" << "# postModuleTransition " << Step::postModuleTransition << kTransition << kEDModule << kTime << kAllocInfo << "\n" << "# preESModuleTransition " << Step::preESModule << kTransition << kESModule << kTime << "\n" << "# postESModuleTransition " << Step::postESModule << kTransition << kESModule << kTime << kAllocInfo << "\n" << "# preFrameworkTransition " << Step::preFrameworkTransition << kTransition << kTransitionInfo << kTime << "\n" << "# preFrameworkTransition " << Step::preFrameworkTransition << " " << Phase::clearEvent << " <Transition ID>" << kTransitionInfo << kTime << kAllocInfo << "\n" << "# postFrameworkTransition " << Step::postFrameworkTransition << kTransition << kTransitionInfo << kTime << "\n"; logFile->write(oss.str()); return; } } // namespace edm::service::moduleAlloc