Services/plugins/tracer_setupFile.cc

0001 #include "tracer_setupFile.h"
0002 #include "monitor_file_utilities.h"
0003
0004 #include <chrono>
0005
0006 #include <sstream>
0007 #include <type_traits>
0008 #include <cassert>
0009 #include <typeindex>
0010
0011 #include "FWCore/Concurrency/interface/ThreadSafeOutputFileStream.h"
0012
0013 #include "DataFormats/Provenance/interface/EventID.h"
0014 #include "DataFormats/Provenance/interface/LuminosityBlockID.h"
0015 #include "DataFormats/Provenance/interface/ModuleDescription.h"
0016 #include "DataFormats/Provenance/interface/RunID.h"
0017 #include "DataFormats/Provenance/interface/Timestamp.h"
0018
0019 #include "FWCore/ServiceRegistry/interface/GlobalContext.h"
0020 #include "FWCore/ServiceRegistry/interface/ModuleCallingContext.h"
0021 #include "FWCore/ServiceRegistry/interface/ESModuleCallingContext.h"
0022 #include "FWCore/ServiceRegistry/interface/PathContext.h"
0023 #include "FWCore/ServiceRegistry/interface/ProcessContext.h"
0024 #include "FWCore/ServiceRegistry/interface/StreamContext.h"
0025 #include "FWCore/ServiceRegistry/interface/ActivityRegistry.h"
0026
0027 #include "FWCore/Framework/interface/IOVSyncValue.h"
0028 #include "FWCore/Framework/interface/EventSetupRecordKey.h"
0029 #include "FWCore/Framework/interface/ESRecordsToProductResolverIndices.h"
0030 #include "FWCore/AbstractServices/interface/TimingServiceBase.h"
0031
0032 using namespace edm::service::monitor_file_utilities;
0033
0034 namespace {
0035   using duration_t = std::chrono::microseconds;
0036   using steady_clock = std::chrono::steady_clock;
0037
0038   enum class Step : char {
0039     preSourceTransition = 'S',
0040     postSourceTransition = 's',
0041     preModulePrefetching = 'P',
0042     postModulePrefetching = 'p',
0043     preModuleEventAcquire = 'A',
0044     postModuleEventAcquire = 'a',
0045     preModuleTransition = 'M',
0046     preEventReadFromSource = 'R',
0047     postEventReadFromSource = 'r',
0048     preModuleEventDelayedGet = 'D',
0049     postModuleEventDelayedGet = 'd',
0050     postModuleTransition = 'm',
0051     preESModulePrefetching = 'Q',
0052     postESModulePrefetching = 'q',
0053     preESModule = 'N',
0054     postESModule = 'n',
0055     preESModuleAcquire = 'B',
0056     postESModuleAcquire = 'b',
0057     preFrameworkTransition = 'F',
0058     postFrameworkTransition = 'f'
0059   };
0060
0061   enum class Phase : short {
0062     destruction = -16,
0063     endJob = -12,
0064     endStream = -11,
0065     writeProcessBlock = -10,
0066     endProcessBlock = -9,
0067     globalWriteRun = -7,
0068     globalEndRun = -6,
0069     streamEndRun = -5,
0070     globalWriteLumi = -4,
0071     globalEndLumi = -3,
0072     streamEndLumi = -2,
0073     clearEvent = -1,
0074     Event = 0,
0075     streamBeginLumi = 2,
0076     globalBeginLumi = 3,
0077     streamBeginRun = 5,
0078     globalBeginRun = 6,
0079     accessInputProcessBlock = 8,
0080     beginProcessBlock = 9,
0081     openFile = 10,
0082     beginStream = 11,
0083     beginJob = 12,
0084     esSync = 13,
0085     esSyncEnqueue = 14,
0086     getNextTransition = 15,
0087     construction = 16,
0088     startTracing = 17
0089   };
0090
0091   std::ostream& operator<<(std::ostream& os, Step const s) {
0092     os << static_cast<std::underlying_type_t<Step>>(s);
0093     return os;
0094   }
0095
0096   std::ostream& operator<<(std::ostream& os, Phase const s) {
0097     os << static_cast<std::underlying_type_t<Phase>>(s);
0098     return os;
0099   }
0100
0101   template <Step S, typename... ARGS>
0102   std::string assembleMessage(ARGS const... args) {
0103     std::ostringstream oss;
0104     oss << S;
0105     concatenate(oss, args...);
0106     oss << '\n';
0107     return oss.str();
0108   }
0109
0110   Phase toTransitionImpl(edm::StreamContext const& iContext) {
0111     using namespace edm;
0112     switch (iContext.transition()) {
0113       case StreamContext::Transition::kBeginStream:
0114         return Phase::beginStream;
0115       case StreamContext::Transition::kBeginRun:
0116         return Phase::streamBeginRun;
0117       case StreamContext::Transition::kBeginLuminosityBlock:
0118         return Phase::streamBeginLumi;
0119       case StreamContext::Transition::kEvent:
0120         return Phase::Event;
0121       case StreamContext::Transition::kEndLuminosityBlock:
0122         return Phase::streamEndLumi;
0123       case StreamContext::Transition::kEndRun:
0124         return Phase::streamEndRun;
0125       case StreamContext::Transition::kEndStream:
0126         return Phase::endStream;
0127       default:
0128         break;
0129     }
0130     assert(false);
0131     return Phase::Event;
0132   }
0133
0134   auto toTransition(edm::StreamContext const& iContext) -> std::underlying_type_t<Phase> {
0135     return static_cast<std::underlying_type_t<Phase>>(toTransitionImpl(iContext));
0136   }
0137
0138   Phase toTransitionImpl(edm::GlobalContext const& iContext) {
0139     using namespace edm;
0140     switch (iContext.transition()) {
0141       case GlobalContext::Transition::kBeginProcessBlock:
0142         return Phase::beginProcessBlock;
0143       case GlobalContext::Transition::kAccessInputProcessBlock:
0144         return Phase::accessInputProcessBlock;
0145       case GlobalContext::Transition::kBeginRun:
0146         return Phase::globalBeginRun;
0147       case GlobalContext::Transition::kBeginLuminosityBlock:
0148         return Phase::globalBeginLumi;
0149       case GlobalContext::Transition::kEndLuminosityBlock:
0150         return Phase::globalEndLumi;
0151       case GlobalContext::Transition::kWriteLuminosityBlock:
0152         return Phase::globalWriteLumi;
0153       case GlobalContext::Transition::kEndRun:
0154         return Phase::globalEndRun;
0155       case GlobalContext::Transition::kWriteRun:
0156         return Phase::globalWriteRun;
0157       case GlobalContext::Transition::kEndProcessBlock:
0158         return Phase::endProcessBlock;
0159       case GlobalContext::Transition::kWriteProcessBlock:
0160         return Phase::writeProcessBlock;
0161       default:
0162         break;
0163     }
0164     assert(false);
0165     return Phase::Event;
0166   }
0167   auto toTransition(edm::GlobalContext const& iContext) -> std::underlying_type_t<Phase> {
0168     return static_cast<std::underlying_type_t<Phase>>(toTransitionImpl(iContext));
0169   }
0170
0171   unsigned int toTransitionIndex(edm::GlobalContext const& iContext) {
0172     if (iContext.transition() == edm::GlobalContext::Transition::kBeginProcessBlock or
0173         iContext.transition() == edm::GlobalContext::Transition::kEndProcessBlock or
0174         iContext.transition() == edm::GlobalContext::Transition::kWriteProcessBlock or
0175         iContext.transition() == edm::GlobalContext::Transition::kAccessInputProcessBlock) {
0176       return 0;
0177     }
0178     if (iContext.transition() == edm::GlobalContext::Transition::kBeginRun or
0179         iContext.transition() == edm::GlobalContext::Transition::kEndRun or
0180         iContext.transition() == edm::GlobalContext::Transition::kWriteRun) {
0181       return iContext.runIndex();
0182     }
0183     return iContext.luminosityBlockIndex();
0184   }
0185
0186   template <Step S>
0187   struct ESModuleState {
0188     ESModuleState(std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile,
0189                   decltype(steady_clock::now()) beginTime,
0190                   std::shared_ptr<std::vector<std::type_index>> recordIndices)
0191         : logFile_{logFile}, recordIndices_{recordIndices}, beginTime_{beginTime} {}
0192
0193     void operator()(edm::eventsetup::EventSetupRecordKey const& iKey,
0194                     edm::ESModuleCallingContext const& iContext) const {
0195       using namespace edm;
0196       auto const t = std::chrono::duration_cast<duration_t>(steady_clock::now() - beginTime_).count();
0197       auto top = iContext.getTopModuleCallingContext();
0198       short int phase = 0;
0199       unsigned long phaseID = 0xFFFFFFFF;
0200       if (top->type() == ParentContext::Type::kGlobal) {
0201         auto global = top->globalContext();
0202         phase = toTransition(*global);
0203         phaseID = toTransitionIndex(*global);
0204       } else if (top->type() == ParentContext::Type::kStream) {
0205         auto stream = top->getStreamContext();
0206         phase = toTransition(*stream);
0207         phaseID = stream_id(*stream);
0208       } else if (top->type() == ParentContext::Type::kPlaceInPath) {
0209         auto stream = top->getStreamContext();
0210         phase = toTransition(*stream);
0211         phaseID = stream_id(*stream);
0212       }
0213       auto recordIndex = findRecordIndices(iKey);
0214       long long requestingModuleID;
0215       decltype(iContext.moduleCallingContext()->callID()) requestingCallID;
0216       if (iContext.type() == ESParentContext::Type::kModule) {
0217         requestingModuleID = iContext.moduleCallingContext()->moduleDescription()->id();
0218         requestingCallID = iContext.moduleCallingContext()->callID();
0219       } else {
0220         requestingModuleID =
0221             -1 * static_cast<long long>(iContext.esmoduleCallingContext()->componentDescription()->id_ + 1);
0222         requestingCallID = iContext.esmoduleCallingContext()->callID();
0223       }
0224       auto msg = assembleMessage<S>(phase,
0225                                     phaseID,
0226                                     iContext.componentDescription()->id_ + 1,
0227                                     recordIndex,
0228                                     iContext.callID(),
0229                                     requestingModuleID,
0230                                     requestingCallID,
0231                                     t);
0232       logFile_->write(std::move(msg));
0233     }
0234
0235   private:
0236     int findRecordIndices(edm::eventsetup::EventSetupRecordKey const& iKey) const {
0237       auto index = std::type_index(iKey.type().value());
0238       auto itFind = std::find(recordIndices_->begin(), recordIndices_->end(), index);
0239       return itFind - recordIndices_->begin();
0240     }
0241
0242     std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile_;
0243     std::shared_ptr<std::vector<std::type_index>> recordIndices_;
0244     decltype(steady_clock::now()) beginTime_;
0245   };
0246
0247   template <Step S>
0248   struct GlobalEDModuleState {
0249     GlobalEDModuleState(std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile,
0250                         decltype(steady_clock::now()) beginTime)
0251         : logFile_{logFile}, beginTime_{beginTime} {}
0252
0253     void operator()(edm::GlobalContext const& gc, edm::ModuleCallingContext const& mcc) {
0254       using namespace edm;
0255       auto const t = std::chrono::duration_cast<duration_t>(steady_clock::now() - beginTime_).count();
0256       long requestingModuleID = 0;
0257       decltype(mcc.parent().moduleCallingContext()->callID()) requestingCallID = 0;
0258       if (mcc.type() == ParentContext::Type::kModule) {
0259         requestingModuleID = module_id(*mcc.parent().moduleCallingContext());
0260         requestingCallID = mcc.parent().moduleCallingContext()->callID();
0261       }
0262       auto msg = assembleMessage<S>(toTransition(gc),
0263                                     toTransitionIndex(gc),
0264                                     module_id(mcc),
0265                                     module_callid(mcc),
0266                                     requestingModuleID,
0267                                     requestingCallID,
0268                                     t);
0269       logFile_->write(std::move(msg));
0270     }
0271
0272   private:
0273     std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile_;
0274     decltype(steady_clock::now()) beginTime_;
0275   };
0276
0277   template <Step S>
0278   struct StreamEDModuleState {
0279     StreamEDModuleState(std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile,
0280                         decltype(steady_clock::now()) beginTime)
0281         : logFile_{logFile}, beginTime_{beginTime} {}
0282
0283     void operator()(edm::StreamContext const& sc, edm::ModuleCallingContext const& mcc) {
0284       using namespace edm;
0285       auto const t = std::chrono::duration_cast<duration_t>(steady_clock::now() - beginTime_).count();
0286       long requestingModuleID = 0;
0287       decltype(mcc.parent().moduleCallingContext()->callID()) requestingCallID = 0;
0288       if (mcc.type() == ParentContext::Type::kModule) {
0289         requestingModuleID = module_id(*mcc.parent().moduleCallingContext());
0290         requestingCallID = mcc.parent().moduleCallingContext()->callID();
0291       }
0292       auto msg = assembleMessage<S>(
0293           toTransition(sc), stream_id(sc), module_id(mcc), module_callid(mcc), requestingModuleID, requestingCallID, t);
0294       logFile_->write(std::move(msg));
0295     }
0296
0297   private:
0298     std::shared_ptr<edm::ThreadSafeOutputFileStream> logFile_;
0299     decltype(steady_clock::now()) beginTime_;
0300   };
0301
0302   struct ModuleCtrDtr {
0303     long long beginConstruction = 0;
0304     long long endConstruction = 0;
0305     long long beginDestruction = 0;
0306     long long endDestruction = 0;
0307   };
0308 }  // namespace
0309
0310 namespace edm::service::tracer {
0311   void setupFile(std::string const& iFileName, edm::ActivityRegistry& iRegistry) {
0312     auto beginTracer = steady_clock::now();
0313     using namespace std::chrono;
0314
0315     if (iFileName.empty()) {
0316       return;
0317     }
0318
0319     auto logFile = std::make_shared<edm::ThreadSafeOutputFileStream>(iFileName);
0320
0321     auto beginTime = TimingServiceBase::jobStartTime();
0322
0323     auto esModuleLabelsPtr = std::make_shared<std::vector<std::string>>();
0324     auto& esModuleLabels = *esModuleLabelsPtr;
0325     //acquire names for all the ED and ES modules
0326     iRegistry.watchPostESModuleRegistration([&esModuleLabels](auto const& iDescription) {
0327       if (esModuleLabels.size() <= iDescription.id_ + 1) {
0328         esModuleLabels.resize(iDescription.id_ + 2);
0329       }
0330       //NOTE: we want the id to start at 1 not 0
0331       if (not iDescription.label_.empty()) {
0332         esModuleLabels[iDescription.id_ + 1] = iDescription.label_;
0333       } else {
0334         esModuleLabels[iDescription.id_ + 1] = iDescription.type_;
0335       }
0336     });
0337     auto moduleCtrDtrPtr = std::make_shared<std::vector<ModuleCtrDtr>>();
0338     auto& moduleCtrDtr = *moduleCtrDtrPtr;
0339     auto moduleLabelsPtr = std::make_shared<std::vector<std::string>>();
0340     auto& moduleLabels = *moduleLabelsPtr;
0341     iRegistry.watchPreModuleConstruction([&moduleLabels, &moduleCtrDtr, beginTime](ModuleDescription const& md) {
0342       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0343
0344       auto const mid = md.id();
0345       if (mid < moduleLabels.size()) {
0346         moduleLabels[mid] = md.moduleLabel();
0347         moduleCtrDtr[mid].beginConstruction = t;
0348       } else {
0349         moduleLabels.resize(mid + 1);
0350         moduleLabels.back() = md.moduleLabel();
0351         moduleCtrDtr.resize(mid + 1);
0352         moduleCtrDtr.back().beginConstruction = t;
0353       }
0354     });
0355     iRegistry.watchPostModuleConstruction([&moduleCtrDtr, beginTime](auto const& md) {
0356       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0357       moduleCtrDtr[md.id()].endConstruction = t;
0358     });
0359
0360     iRegistry.watchPreModuleDestruction([&moduleCtrDtr, beginTime](auto const& md) {
0361       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0362       moduleCtrDtr[md.id()].beginDestruction = t;
0363     });
0364     iRegistry.watchPostModuleDestruction([&moduleCtrDtr, beginTime](auto const& md) {
0365       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0366       moduleCtrDtr[md.id()].endDestruction = t;
0367     });
0368
0369     auto sourceCtrPtr = std::make_shared<ModuleCtrDtr>();
0370     auto& sourceCtr = *sourceCtrPtr;
0371     iRegistry.watchPreSourceConstruction([&sourceCtr, beginTime](auto const&) {
0372       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0373       sourceCtr.beginConstruction = t;
0374     });
0375     iRegistry.watchPostSourceConstruction([&sourceCtr, beginTime](auto const&) {
0376       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0377       sourceCtr.endConstruction = t;
0378     });
0379
0380     auto recordIndices = std::make_shared<std::vector<std::type_index>>();
0381     iRegistry.watchEventSetupConfiguration(
0382         [logFile, recordIndices](auto const& recordsToResolvers, auto const&) mutable {
0383           std::ostringstream oss;
0384
0385           auto recordKeys = recordsToResolvers.recordKeys();
0386           std::sort(recordKeys.begin(), recordKeys.end());
0387           std::vector<std::string> recordNames;
0388           //want id to start at 1 not 0
0389           recordNames.reserve(recordKeys.size() + 1);
0390           recordNames.emplace_back("");
0391           recordIndices->reserve(recordKeys.size() + 1);
0392           recordIndices->push_back(std::type_index(typeid(void)));
0393           for (auto const& r : recordKeys) {
0394             recordNames.push_back(r.name());
0395             recordIndices->push_back(std::type_index(r.type().value()));
0396           }
0397
0398           moduleIdToLabel(oss, recordNames, 'R', "Record ID", "Record name");
0399           logFile->write(oss.str());
0400         });
0401
0402     iRegistry.watchPreBeginJob([logFile,
0403                                 moduleLabelsPtr,
0404                                 esModuleLabelsPtr,
0405                                 moduleCtrDtrPtr,
0406                                 sourceCtrPtr,
0407                                 beginTime,
0408                                 beginTracer](auto&) mutable {
0409       {
0410         std::ostringstream oss;
0411         moduleIdToLabel(oss, *moduleLabelsPtr, 'M', "EDModule ID", "Module label");
0412         logFile->write(oss.str());
0413         moduleLabelsPtr.reset();
0414       }
0415       {
0416         std::ostringstream oss;
0417         moduleIdToLabel(oss, *esModuleLabelsPtr, 'N', "ESModule ID", "ESModule label");
0418         logFile->write(oss.str());
0419         esModuleLabelsPtr.reset();
0420       }
0421       {
0422         auto const tracerStart = duration_cast<duration_t>(beginTracer - beginTime).count();
0423         auto msg = assembleMessage<Step::preFrameworkTransition>(
0424             static_cast<std::underlying_type_t<Phase>>(Phase::startTracing), 0, 0, 0, 0, tracerStart);
0425         logFile->write(std::move(msg));
0426       }
0427       //NOTE: the source construction can run concurently with module construction so we need to properly
0428       // interleave its timing in with the modules
0429       auto srcBeginConstruction = sourceCtrPtr->beginConstruction;
0430       auto srcEndConstruction = sourceCtrPtr->endConstruction;
0431       sourceCtrPtr.reset();
0432       auto handleSource = [&srcBeginConstruction, &srcEndConstruction, &logFile](long long iTime) mutable {
0433         if (srcBeginConstruction != 0 and srcBeginConstruction < iTime) {
0434           auto bmsg = assembleMessage<Step::preSourceTransition>(
0435               static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, srcBeginConstruction);
0436           logFile->write(std::move(bmsg));
0437           srcBeginConstruction = 0;
0438         }
0439         if (srcEndConstruction != 0 and srcEndConstruction < iTime) {
0440           auto bmsg = assembleMessage<Step::postSourceTransition>(
0441               static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, srcEndConstruction);
0442           logFile->write(std::move(bmsg));
0443           srcEndConstruction = 0;
0444         }
0445       };
0446       {
0447         std::sort(moduleCtrDtrPtr->begin(), moduleCtrDtrPtr->end(), [](auto const& l, auto const& r) {
0448           return l.beginConstruction < r.beginConstruction;
0449         });
0450         int id = 0;
0451         for (auto const& ctr : *moduleCtrDtrPtr) {
0452           if (ctr.beginConstruction != 0) {
0453             handleSource(ctr.beginConstruction);
0454             auto bmsg = assembleMessage<Step::preModuleTransition>(
0455                 static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, id, 0, 0, 0, ctr.beginConstruction);
0456             logFile->write(std::move(bmsg));
0457             handleSource(ctr.endConstruction);
0458             auto emsg = assembleMessage<Step::postModuleTransition>(
0459                 static_cast<std::underlying_type_t<Phase>>(Phase::construction), 0, id, 0, 0, 0, ctr.endConstruction);
0460             logFile->write(std::move(emsg));
0461           }
0462           ++id;
0463         }
0464         id = 0;
0465         std::sort(moduleCtrDtrPtr->begin(), moduleCtrDtrPtr->end(), [](auto const& l, auto const& r) {
0466           return l.beginDestruction < r.beginDestruction;
0467         });
0468         for (auto const& dtr : *moduleCtrDtrPtr) {
0469           if (dtr.beginDestruction != 0) {
0470             handleSource(dtr.beginDestruction);
0471             auto bmsg = assembleMessage<Step::preModuleTransition>(
0472                 static_cast<std::underlying_type_t<Phase>>(Phase::destruction), 0, id, 0, 0, 0, dtr.beginDestruction);
0473             logFile->write(std::move(bmsg));
0474             handleSource(dtr.endDestruction);
0475             auto emsg = assembleMessage<Step::postModuleTransition>(
0476                 static_cast<std::underlying_type_t<Phase>>(Phase::destruction), 0, id, 0, 0, 0, dtr.endDestruction);
0477             logFile->write(std::move(emsg));
0478           }
0479           ++id;
0480         }
0481         moduleCtrDtrPtr.reset();
0482       }
0483       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0484       handleSource(t);
0485       auto msg = assembleMessage<Step::preFrameworkTransition>(
0486           static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, 0, 0, 0, t);
0487       logFile->write(std::move(msg));
0488     });
0489     iRegistry.watchPostBeginJob([logFile, beginTime]() {
0490       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0491       auto msg = assembleMessage<Step::postFrameworkTransition>(
0492           static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, 0, 0, 0, t);
0493       logFile->write(std::move(msg));
0494     });
0495
0496     iRegistry.watchPreEndJob([logFile, beginTime]() {
0497       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0498       auto msg = assembleMessage<Step::preFrameworkTransition>(
0499           static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, 0, 0, 0, t);
0500       logFile->write(std::move(msg));
0501     });
0502     iRegistry.watchPostEndJob([logFile, beginTime]() {
0503       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0504       auto msg = assembleMessage<Step::postFrameworkTransition>(
0505           static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, 0, 0, 0, t);
0506       logFile->write(std::move(msg));
0507     });
0508
0509     iRegistry.watchPreEvent([logFile, beginTime](auto const& sc) {
0510       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0511       auto msg = assembleMessage<Step::preFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::Event),
0512                                                                stream_id(sc),
0513                                                                sc.eventID().run(),
0514                                                                sc.eventID().luminosityBlock(),
0515                                                                sc.eventID().event(),
0516                                                                t);
0517       logFile->write(std::move(msg));
0518     });
0519     iRegistry.watchPostEvent([logFile, beginTime](auto const& sc) {
0520       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0521       auto msg =
0522           assembleMessage<Step::postFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::Event),
0523                                                          stream_id(sc),
0524                                                          sc.eventID().run(),
0525                                                          sc.eventID().luminosityBlock(),
0526                                                          sc.eventID().event(),
0527                                                          t);
0528       logFile->write(std::move(msg));
0529     });
0530
0531     iRegistry.watchPreClearEvent([logFile, beginTime](auto const& sc) {
0532       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0533       auto msg =
0534           assembleMessage<Step::preFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::clearEvent),
0535                                                         stream_id(sc),
0536                                                         sc.eventID().run(),
0537                                                         sc.eventID().luminosityBlock(),
0538                                                         sc.eventID().event(),
0539                                                         t);
0540       logFile->write(std::move(msg));
0541     });
0542     iRegistry.watchPostClearEvent([logFile, beginTime](auto const& sc) {
0543       auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0544       auto msg =
0545           assembleMessage<Step::postFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::clearEvent),
0546                                                          stream_id(sc),
0547                                                          sc.eventID().run(),
0548                                                          sc.eventID().luminosityBlock(),
0549                                                          sc.eventID().event(),
0550                                                          t);
0551       logFile->write(std::move(msg));
0552     });
0553
0554     {
0555       auto preGlobal = [logFile, beginTime](GlobalContext const& gc) {
0556         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0557         auto msg = assembleMessage<Step::preFrameworkTransition>(toTransition(gc),
0558                                                                  toTransitionIndex(gc),
0559                                                                  gc.luminosityBlockID().run(),
0560                                                                  gc.luminosityBlockID().luminosityBlock(),
0561                                                                  0,
0562                                                                  t);
0563         logFile->write(std::move(msg));
0564       };
0565       iRegistry.watchPreBeginProcessBlock(preGlobal);
0566       iRegistry.watchPreEndProcessBlock(preGlobal);
0567       iRegistry.watchPreWriteProcessBlock(preGlobal);
0568       iRegistry.watchPreAccessInputProcessBlock(preGlobal);
0569       iRegistry.watchPreGlobalBeginRun(preGlobal);
0570       iRegistry.watchPreGlobalBeginLumi(preGlobal);
0571       iRegistry.watchPreGlobalEndLumi(preGlobal);
0572       iRegistry.watchPreGlobalWriteLumi(preGlobal);
0573       iRegistry.watchPreGlobalEndRun(preGlobal);
0574       iRegistry.watchPreGlobalWriteRun(preGlobal);
0575     }
0576     {
0577       auto postGlobal = [logFile, beginTime](GlobalContext const& gc) {
0578         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0579         auto msg = assembleMessage<Step::postFrameworkTransition>(toTransition(gc),
0580                                                                   toTransitionIndex(gc),
0581                                                                   gc.luminosityBlockID().run(),
0582                                                                   gc.luminosityBlockID().luminosityBlock(),
0583                                                                   0,
0584                                                                   t);
0585         logFile->write(std::move(msg));
0586       };
0587       iRegistry.watchPostBeginProcessBlock(postGlobal);
0588       iRegistry.watchPostEndProcessBlock(postGlobal);
0589       iRegistry.watchPostWriteProcessBlock(postGlobal);
0590       iRegistry.watchPostAccessInputProcessBlock(postGlobal);
0591       iRegistry.watchPostGlobalBeginRun(postGlobal);
0592       iRegistry.watchPostGlobalBeginLumi(postGlobal);
0593       iRegistry.watchPostGlobalEndLumi(postGlobal);
0594       iRegistry.watchPostGlobalWriteLumi(postGlobal);
0595       iRegistry.watchPostGlobalEndRun(postGlobal);
0596       iRegistry.watchPostGlobalWriteRun(postGlobal);
0597     }
0598     {
0599       auto preStream = [logFile, beginTime](StreamContext const& sc) {
0600         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0601         auto msg = assembleMessage<Step::preFrameworkTransition>(
0602             toTransition(sc), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), 0, t);
0603         logFile->write(std::move(msg));
0604       };
0605       iRegistry.watchPreStreamBeginRun(preStream);
0606       iRegistry.watchPreStreamBeginLumi(preStream);
0607       iRegistry.watchPreStreamEndLumi(preStream);
0608       iRegistry.watchPreStreamEndRun(preStream);
0609     }
0610     {
0611       auto postStream = [logFile, beginTime](StreamContext const& sc) {
0612         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0613         auto msg = assembleMessage<Step::postFrameworkTransition>(
0614             toTransition(sc), stream_id(sc), sc.eventID().run(), sc.eventID().luminosityBlock(), 0, t);
0615         logFile->write(std::move(msg));
0616       };
0617       iRegistry.watchPostStreamBeginRun(postStream);
0618       iRegistry.watchPostStreamBeginLumi(postStream);
0619       iRegistry.watchPostStreamEndLumi(postStream);
0620       iRegistry.watchPostStreamEndRun(postStream);
0621     }
0622     {
0623       iRegistry.watchESSyncIOVQueuing([logFile, beginTime](IOVSyncValue const& sv) {
0624         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0625         auto msg = assembleMessage<Step::preFrameworkTransition>(
0626             static_cast<std::underlying_type_t<Phase>>(Phase::esSyncEnqueue),
0627             -1,
0628             sv.eventID().run(),
0629             sv.eventID().luminosityBlock(),
0630             0,
0631             t);
0632         logFile->write(std::move(msg));
0633       });
0634       iRegistry.watchPreESSyncIOV([logFile, beginTime](IOVSyncValue const& sv) {
0635         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0636         auto msg =
0637             assembleMessage<Step::preFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::esSync),
0638                                                           -1,
0639                                                           sv.eventID().run(),
0640                                                           sv.eventID().luminosityBlock(),
0641                                                           0,
0642                                                           t);
0643         logFile->write(std::move(msg));
0644       });
0645       iRegistry.watchPostESSyncIOV([logFile, beginTime](IOVSyncValue const& sv) {
0646         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0647         auto msg =
0648             assembleMessage<Step::postFrameworkTransition>(static_cast<std::underlying_type_t<Phase>>(Phase::esSync),
0649                                                            -1,
0650                                                            sv.eventID().run(),
0651                                                            sv.eventID().luminosityBlock(),
0652                                                            0,
0653                                                            t);
0654         logFile->write(std::move(msg));
0655       });
0656     }
0657     {
0658       iRegistry.watchPreOpenFile([logFile, beginTime](std::string const&) {
0659         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0660         auto msg = assembleMessage<Step::preSourceTransition>(
0661             static_cast<std::underlying_type_t<Phase>>(Phase::openFile), 0, t);
0662         logFile->write(std::move(msg));
0663       });
0664       iRegistry.watchPostOpenFile([logFile, beginTime](std::string const&) {
0665         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0666         auto msg = assembleMessage<Step::postSourceTransition>(
0667             static_cast<std::underlying_type_t<Phase>>(Phase::openFile), 0, t);
0668         logFile->write(std::move(msg));
0669       });
0670       iRegistry.watchPreSourceEvent([logFile, beginTime](StreamID id) {
0671         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0672         auto msg = assembleMessage<Step::preSourceTransition>(
0673             static_cast<std::underlying_type_t<Phase>>(Phase::Event), id.value(), t);
0674         logFile->write(std::move(msg));
0675       });
0676       iRegistry.watchPostSourceEvent([logFile, beginTime](StreamID id) {
0677         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0678         auto msg = assembleMessage<Step::postSourceTransition>(
0679             static_cast<std::underlying_type_t<Phase>>(Phase::Event), id.value(), t);
0680         logFile->write(std::move(msg));
0681       });
0682
0683       iRegistry.watchPreSourceRun([logFile, beginTime](RunIndex id) {
0684         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0685         auto msg = assembleMessage<Step::preSourceTransition>(
0686             static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginRun), id.value(), t);
0687         logFile->write(std::move(msg));
0688       });
0689       iRegistry.watchPostSourceRun([logFile, beginTime](RunIndex id) {
0690         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0691         auto msg = assembleMessage<Step::postSourceTransition>(
0692             static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginRun), id.value(), t);
0693         logFile->write(std::move(msg));
0694       });
0695
0696       iRegistry.watchPreSourceLumi([logFile, beginTime](auto id) {
0697         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0698         auto msg = assembleMessage<Step::preSourceTransition>(
0699             static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginLumi), id.value(), t);
0700         logFile->write(std::move(msg));
0701       });
0702       iRegistry.watchPostSourceLumi([logFile, beginTime](auto id) {
0703         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0704         auto msg = assembleMessage<Step::postSourceTransition>(
0705             static_cast<std::underlying_type_t<Phase>>(Phase::globalBeginLumi), id.value(), t);
0706         logFile->write(std::move(msg));
0707       });
0708
0709       iRegistry.watchPreSourceNextTransition([logFile, beginTime]() {
0710         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0711         auto msg = assembleMessage<Step::preSourceTransition>(
0712             static_cast<std::underlying_type_t<Phase>>(Phase::getNextTransition), t);
0713         logFile->write(std::move(msg));
0714       });
0715       iRegistry.watchPostSourceNextTransition([logFile, beginTime]() {
0716         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0717         auto msg = assembleMessage<Step::postSourceTransition>(
0718             static_cast<std::underlying_type_t<Phase>>(Phase::getNextTransition), t);
0719         logFile->write(std::move(msg));
0720       });
0721
0722       //ED Modules
0723       iRegistry.watchPreModuleBeginJob([logFile, beginTime](auto const& md) {
0724         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0725         auto msg = assembleMessage<Step::preModuleTransition>(
0726             static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, md.id(), 0, 0, 0, t);
0727         logFile->write(std::move(msg));
0728       });
0729       iRegistry.watchPostModuleBeginJob([logFile, beginTime](auto const& md) {
0730         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0731         auto msg = assembleMessage<Step::postModuleTransition>(
0732             static_cast<std::underlying_type_t<Phase>>(Phase::beginJob), 0, md.id(), 0, 0, 0, t);
0733         logFile->write(std::move(msg));
0734       });
0735
0736       iRegistry.watchPreModuleBeginStream(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0737       iRegistry.watchPostModuleBeginStream(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0738
0739       iRegistry.watchPreModuleEndStream(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0740       iRegistry.watchPostModuleEndStream(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0741
0742       iRegistry.watchPreModuleEndJob([logFile, beginTime](auto const& md) {
0743         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0744         auto msg = assembleMessage<Step::preModuleTransition>(
0745             static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, md.id(), 0, 0, 0, t);
0746         logFile->write(std::move(msg));
0747       });
0748       iRegistry.watchPostModuleEndJob([logFile, beginTime](auto const& md) {
0749         auto const t = duration_cast<duration_t>(steady_clock::now() - beginTime).count();
0750         auto msg = assembleMessage<Step::postModuleTransition>(
0751             static_cast<std::underlying_type_t<Phase>>(Phase::endJob), 0, md.id(), 0, 0, 0, t);
0752         logFile->write(std::move(msg));
0753       });
0754
0755       iRegistry.watchPreModuleEventPrefetching(StreamEDModuleState<Step::preModulePrefetching>(logFile, beginTime));
0756       iRegistry.watchPostModuleEventPrefetching(StreamEDModuleState<Step::postModulePrefetching>(logFile, beginTime));
0757
0758       iRegistry.watchPreModuleEvent(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0759       iRegistry.watchPostModuleEvent(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0760       iRegistry.watchPreModuleEventAcquire(StreamEDModuleState<Step::preModuleEventAcquire>(logFile, beginTime));
0761       iRegistry.watchPostModuleEventAcquire(StreamEDModuleState<Step::postModuleEventAcquire>(logFile, beginTime));
0762       iRegistry.watchPreModuleEventDelayedGet(StreamEDModuleState<Step::preModuleEventDelayedGet>(logFile, beginTime));
0763       iRegistry.watchPostModuleEventDelayedGet(
0764           StreamEDModuleState<Step::postModuleEventDelayedGet>(logFile, beginTime));
0765       iRegistry.watchPreEventReadFromSource(StreamEDModuleState<Step::preEventReadFromSource>(logFile, beginTime));
0766       iRegistry.watchPostEventReadFromSource(StreamEDModuleState<Step::postEventReadFromSource>(logFile, beginTime));
0767
0768       iRegistry.watchPreModuleTransform(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0769       iRegistry.watchPostModuleTransform(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0770       iRegistry.watchPreModuleTransformPrefetching(StreamEDModuleState<Step::preModulePrefetching>(logFile, beginTime));
0771       iRegistry.watchPostModuleTransformPrefetching(
0772           StreamEDModuleState<Step::postModulePrefetching>(logFile, beginTime));
0773       iRegistry.watchPreModuleTransformAcquiring(StreamEDModuleState<Step::preModuleEventAcquire>(logFile, beginTime));
0774       iRegistry.watchPostModuleTransformAcquiring(
0775           StreamEDModuleState<Step::postModuleEventAcquire>(logFile, beginTime));
0776
0777       iRegistry.watchPreModuleStreamPrefetching(StreamEDModuleState<Step::preModulePrefetching>(logFile, beginTime));
0778       iRegistry.watchPostModuleStreamPrefetching(StreamEDModuleState<Step::postModulePrefetching>(logFile, beginTime));
0779
0780       iRegistry.watchPreModuleStreamBeginRun(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0781       iRegistry.watchPostModuleStreamBeginRun(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0782       iRegistry.watchPreModuleStreamEndRun(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0783       iRegistry.watchPostModuleStreamEndRun(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0784
0785       iRegistry.watchPreModuleStreamBeginLumi(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0786       iRegistry.watchPostModuleStreamBeginLumi(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0787       iRegistry.watchPreModuleStreamEndLumi(StreamEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0788       iRegistry.watchPostModuleStreamEndLumi(StreamEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0789
0790       iRegistry.watchPreModuleBeginProcessBlock(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0791       iRegistry.watchPostModuleBeginProcessBlock(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0792       iRegistry.watchPreModuleAccessInputProcessBlock(
0793           GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0794       iRegistry.watchPostModuleAccessInputProcessBlock(
0795           GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0796       iRegistry.watchPreModuleEndProcessBlock(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0797       iRegistry.watchPostModuleEndProcessBlock(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0798
0799       iRegistry.watchPreModuleGlobalPrefetching(GlobalEDModuleState<Step::preModulePrefetching>(logFile, beginTime));
0800       iRegistry.watchPostModuleGlobalPrefetching(GlobalEDModuleState<Step::postModulePrefetching>(logFile, beginTime));
0801
0802       iRegistry.watchPreModuleGlobalBeginRun(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0803       iRegistry.watchPostModuleGlobalBeginRun(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0804       iRegistry.watchPreModuleGlobalEndRun(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0805       iRegistry.watchPostModuleGlobalEndRun(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0806
0807       iRegistry.watchPreModuleGlobalBeginLumi(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0808       iRegistry.watchPostModuleGlobalBeginLumi(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0809       iRegistry.watchPreModuleGlobalEndLumi(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0810       iRegistry.watchPostModuleGlobalEndLumi(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0811
0812       iRegistry.watchPreModuleWriteProcessBlock(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0813       iRegistry.watchPostModuleWriteProcessBlock(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0814
0815       iRegistry.watchPreModuleWriteRun(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0816       iRegistry.watchPostModuleWriteRun(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0817
0818       iRegistry.watchPreModuleWriteLumi(GlobalEDModuleState<Step::preModuleTransition>(logFile, beginTime));
0819       iRegistry.watchPostModuleWriteLumi(GlobalEDModuleState<Step::postModuleTransition>(logFile, beginTime));
0820
0821       //ES Modules
0822       iRegistry.watchPreESModulePrefetching(
0823           ESModuleState<Step::preESModulePrefetching>(logFile, beginTime, recordIndices));
0824       iRegistry.watchPostESModulePrefetching(
0825           ESModuleState<Step::postESModulePrefetching>(logFile, beginTime, recordIndices));
0826       iRegistry.watchPreESModule(ESModuleState<Step::preESModule>(logFile, beginTime, recordIndices));
0827       iRegistry.watchPostESModule(ESModuleState<Step::postESModule>(logFile, beginTime, recordIndices));
0828       iRegistry.watchPreESModuleAcquire(ESModuleState<Step::preESModuleAcquire>(logFile, beginTime, recordIndices));
0829       iRegistry.watchPostESModuleAcquire(ESModuleState<Step::postESModuleAcquire>(logFile, beginTime, recordIndices));
0830     }
0831
0832     std::ostringstream oss;
0833     oss << "# Transition              Symbol\n";
0834     oss << "#------------------------ ------\n";
0835     oss << "# startTracing            " << Phase::startTracing << "\n"
0836         << "# construction            " << Phase::construction << "\n"
0837         << "# getNextTransition       " << Phase::getNextTransition << "\n"
0838         << "# esSyncEnqueue           " << Phase::esSyncEnqueue << "\n"
0839         << "# esSync                  " << Phase::esSync << "\n"
0840         << "# beginJob                " << Phase::beginJob << "\n"
0841         << "# beginStream             " << Phase::beginStream << "\n"
0842         << "# openFile                " << Phase::openFile << "\n"
0843         << "# beginProcessBlock       " << Phase::beginProcessBlock << "\n"
0844         << "# accessInputProcessBlock " << Phase::accessInputProcessBlock << "\n"
0845         << "# globalBeginRun          " << Phase::globalBeginRun << "\n"
0846         << "# streamBeginRun          " << Phase::streamBeginRun << "\n"
0847         << "# globalBeginLumi         " << Phase::globalBeginLumi << "\n"
0848         << "# streamBeginLumi         " << Phase::streamBeginLumi << "\n"
0849         << "# Event                   " << Phase::Event << "\n"
0850         << "# clearEvent              " << Phase::clearEvent << "\n"
0851         << "# streamEndLumi           " << Phase::streamEndLumi << "\n"
0852         << "# globalEndLumi           " << Phase::globalEndLumi << "\n"
0853         << "# globalWriteLumi         " << Phase::globalWriteLumi << "\n"
0854         << "# streamEndRun            " << Phase::streamEndRun << "\n"
0855         << "# globalEndRun            " << Phase::globalEndRun << "\n"
0856         << "# globalWriteRun          " << Phase::globalWriteRun << "\n"
0857         << "# endProcessBlock         " << Phase::endProcessBlock << "\n"
0858         << "# writeProcessBlock       " << Phase::writeProcessBlock << "\n"
0859         << "# endStream               " << Phase::endStream << "\n"
0860         << "# endJob                  " << Phase::endJob << "\n"
0861         << "# destruction             " << Phase::destruction << "\n\n";
0862     oss << "# Step                       Symbol Entries\n"
0863         << "# -------------------------- ------ ------------------------------------------\n"
0864         << "# preSourceTransition           " << Step::preSourceTransition
0865         << "   <Transition type> <Transition ID> <Time since begin of cmsRun (us)>\n"
0866         << "# postSourceTransition          " << Step::postSourceTransition
0867         << "   <Transition type> <Transition ID> <Time since begin of cmsRun (us)>\n"
0868         << "# preModulePrefetching          " << Step::preModulePrefetching
0869         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0870            "Call ID> <Time since begin of "
0871            "cmsRun "
0872            "(us)>\n"
0873         << "# postModulePrefetching         " << Step::postModulePrefetching
0874         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0875            "Call ID> <Time since begin of "
0876            "cmsRun "
0877            "(us)>\n"
0878         << "# preModuleEventAcquire         " << Step::preModuleEventAcquire
0879         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0880            "Call ID> <Time since begin of "
0881            "cmsRun "
0882            "(us)>\n"
0883         << "# postModuleEventAcquire        " << Step::postModuleEventAcquire
0884         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0885            "Call ID> <Time since begin of "
0886            "cmsRun "
0887            "(us)>\n"
0888         << "# preModuleTransition           " << Step::preModuleTransition
0889         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0890            "Call ID> <Time since begin of "
0891            "cmsRun "
0892            "(us)>\n"
0893         << "# preEventReadFromSource        " << Step::preEventReadFromSource
0894         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0895            "Call ID> <Time since begin of "
0896            "cmsRun "
0897            "(us)>\n"
0898         << "# postEventReadFromSource       " << Step::postEventReadFromSource
0899         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID or 0> <Requesting "
0900            "Call ID> <Time since begin of "
0901            "cmsRun "
0902            "(us)>\n"
0903         << "# postModuleTransition          " << Step::postModuleTransition
0904         << "   <Transition type> <Transition ID> <EDModule ID> <Call ID> <Requesting EDModule ID> <Requesting Call ID> "
0905            "<Time since begin of cmsRun "
0906            "(us)>\n"
0907         << "# preESModulePrefetching        " << Step::preESModulePrefetching
0908         << "   <Transition type> <Transition ID> <ESModule ID> <Record ID> <Call ID> <Requesting module ID (+ED, -ES)> "
0909            "<Requesting Call ID> "
0910            "<Time "
0911            "since of cmsRun (us)>\n"
0912         << "# postESModulePrefetching       " << Step::postESModulePrefetching
0913         << "   <Transition type> <Transition ID> <ESModule ID> <Record ID> <Call ID> <Requesting module ID (+ED, -ES)> "
0914            "<Requesting Call ID> "
0915            "<Time "
0916            "since of cmsRun (us)>\n"
0917         << "# preESModuleTransition         " << Step::preESModule
0918         << "   <TransitionType> <Transition ID> <ESModule ID> <Record ID> <Call ID> <Requesting module ID (+ED, -ES)> "
0919            "<Requesting Call ID> "
0920            "<Time "
0921            "since of cmsRun (us)>\n"
0922         << "# postESModuleTransition        " << Step::postESModule
0923         << "   <TransitionType> <Transition ID> <ESModule ID> <Record ID> <Call ID> <Requesting module ID (+ED, -ES)> "
0924            "<Requesting Call ID> "
0925            "<Time "
0926            "since of cmsRun (us)>\n"
0927         << "# preFrameworkTransition        " << Step::preFrameworkTransition
0928         << "   <Transition type> <Transition ID> <Run#> <LumiBlock#> <Event #> <Time since begin of cmsRun (ms)>\n"
0929         << "# postFrameworkTransition       " << Step::postFrameworkTransition
0930         << "   <Transition type> <Transition ID> <Run#> <LumiBlock#> <Event #> <Time since begin of cmsRun (ms)>\n";
0931     logFile->write(oss.str());
0932     return;
0933   }
0934 }  // namespace edm::service::tracer