Services/plugins/Tracer.cc

0001 // -*- C++ -*-
0002 //
0003 // Package:     Services
0004 // Class  :     Tracer
0005 //
0006 // Implementation:
0007 //     <Notes on implementation>
0008 //
0009 // Original Author:  Chris Jones
0010 //         Created:  Thu Sep  8 14:17:58 EDT 2005
0011 //
0012
0013 #include "FWCore/Framework/interface/ComponentDescription.h"
0014 #include "FWCore/Framework/interface/DataKey.h"
0015 #include "FWCore/Framework/interface/EventSetupRecordKey.h"
0016 #include "FWCore/Framework/interface/IOVSyncValue.h"
0017
0018 #include "FWCore/ServiceRegistry/interface/ServiceMaker.h"
0019
0020 #include "FWCore/ParameterSet/interface/ParameterSet.h"
0021 #include "FWCore/ServiceRegistry/interface/ActivityRegistry.h"
0022
0023 #include "FWCore/MessageLogger/interface/MessageLogger.h"
0024 #include "FWCore/ServiceRegistry/interface/ConsumesInfo.h"
0025 #include "FWCore/ServiceRegistry/interface/PathsAndConsumesOfModulesBase.h"
0026 #include "FWCore/ServiceRegistry/interface/SystemBounds.h"
0027 #include "FWCore/Utilities/interface/BranchType.h"
0028 #include "FWCore/Utilities/interface/Exception.h"
0029 #include "FWCore/Utilities/interface/ProductKindOfType.h"
0030 #include "FWCore/Utilities/interface/TimeOfDay.h"
0031
0032 #include "DataFormats/Provenance/interface/EventID.h"
0033 #include "DataFormats/Provenance/interface/LuminosityBlockID.h"
0034 #include "DataFormats/Provenance/interface/ModuleDescription.h"
0035 #include "DataFormats/Provenance/interface/RunID.h"
0036 #include "DataFormats/Provenance/interface/Timestamp.h"
0037
0038 #include "FWCore/ParameterSet/interface/ConfigurationDescriptions.h"
0039 #include "FWCore/ParameterSet/interface/ParameterSetDescription.h"
0040 #include "FWCore/ServiceRegistry/interface/GlobalContext.h"
0041 #include "FWCore/ServiceRegistry/interface/ModuleCallingContext.h"
0042 #include "FWCore/ServiceRegistry/interface/ESModuleCallingContext.h"
0043 #include "FWCore/ServiceRegistry/interface/PathContext.h"
0044 #include "FWCore/ServiceRegistry/interface/ProcessContext.h"
0045 #include "FWCore/ServiceRegistry/interface/StreamContext.h"
0046 #include "DataFormats/Common/interface/HLTPathStatus.h"
0047
0048 #include <iostream>
0049 #include <vector>
0050
0051 #include <string>
0052 #include <set>
0053
0054 namespace edm {
0055   class ConfigurationDescriptions;
0056   class GlobalContext;
0057   class HLTPathStatus;
0058   class LuminosityBlock;
0059   class ModuleCallingContext;
0060   class ModuleDescription;
0061   class PathContext;
0062   class PathsAndConsumesOfModulesBase;
0063   class ProcessContext;
0064   class Run;
0065   class StreamContext;
0066
0067   namespace service {
0068     class Tracer {
0069     public:
0070       Tracer(const ParameterSet&, ActivityRegistry&);
0071
0072       static void fillDescriptions(edm::ConfigurationDescriptions& descriptions);
0073
0074       void preallocate(service::SystemBounds const&);
0075
0076       void preBeginJob(PathsAndConsumesOfModulesBase const&, ProcessContext const&);
0077       void postBeginJob();
0078       void postEndJob();
0079
0080       void preSourceEvent(StreamID);
0081       void postSourceEvent(StreamID);
0082
0083       void preSourceLumi(LuminosityBlockIndex);
0084       void postSourceLumi(LuminosityBlockIndex);
0085
0086       void preSourceRun(RunIndex);
0087       void postSourceRun(RunIndex);
0088
0089       void preSourceProcessBlock();
0090       void postSourceProcessBlock(std::string const&);
0091
0092       void preOpenFile(std::string const&);
0093       void postOpenFile(std::string const&);
0094
0095       void preCloseFile(std::string const& lfn);
0096       void postCloseFile(std::string const&);
0097
0098       void preModuleBeginStream(StreamContext const&, ModuleCallingContext const&);
0099       void postModuleBeginStream(StreamContext const&, ModuleCallingContext const&);
0100
0101       void preModuleEndStream(StreamContext const&, ModuleCallingContext const&);
0102       void postModuleEndStream(StreamContext const&, ModuleCallingContext const&);
0103
0104       void preBeginProcessBlock(GlobalContext const&);
0105       void postBeginProcessBlock(GlobalContext const&);
0106
0107       void preAccessInputProcessBlock(GlobalContext const&);
0108       void postAccessInputProcessBlock(GlobalContext const&);
0109
0110       void preEndProcessBlock(GlobalContext const&);
0111       void postEndProcessBlock(GlobalContext const&);
0112
0113       void preWriteProcessBlock(GlobalContext const&);
0114       void postWriteProcessBlock(GlobalContext const&);
0115
0116       void preGlobalBeginRun(GlobalContext const&);
0117       void postGlobalBeginRun(GlobalContext const&);
0118
0119       void preGlobalEndRun(GlobalContext const&);
0120       void postGlobalEndRun(GlobalContext const&);
0121
0122       void preGlobalWriteRun(GlobalContext const&);
0123       void postGlobalWriteRun(GlobalContext const&);
0124
0125       void preStreamBeginRun(StreamContext const&);
0126       void postStreamBeginRun(StreamContext const&);
0127
0128       void preStreamEndRun(StreamContext const&);
0129       void postStreamEndRun(StreamContext const&);
0130
0131       void preGlobalBeginLumi(GlobalContext const&);
0132       void postGlobalBeginLumi(GlobalContext const&);
0133
0134       void preGlobalEndLumi(GlobalContext const&);
0135       void postGlobalEndLumi(GlobalContext const&);
0136
0137       void preGlobalWriteLumi(GlobalContext const&);
0138       void postGlobalWriteLumi(GlobalContext const&);
0139
0140       void preStreamBeginLumi(StreamContext const&);
0141       void postStreamBeginLumi(StreamContext const&);
0142
0143       void preStreamEndLumi(StreamContext const&);
0144       void postStreamEndLumi(StreamContext const&);
0145
0146       void preEvent(StreamContext const&);
0147       void postEvent(StreamContext const&);
0148
0149       void prePathEvent(StreamContext const&, PathContext const&);
0150       void postPathEvent(StreamContext const&, PathContext const&, HLTPathStatus const&);
0151
0152       void preModuleConstruction(ModuleDescription const& md);
0153       void postModuleConstruction(ModuleDescription const& md);
0154
0155       void preModuleDestruction(ModuleDescription const& md);
0156       void postModuleDestruction(ModuleDescription const& md);
0157
0158       void preModuleBeginJob(ModuleDescription const& md);
0159       void postModuleBeginJob(ModuleDescription const& md);
0160
0161       void preModuleEndJob(ModuleDescription const& md);
0162       void postModuleEndJob(ModuleDescription const& md);
0163
0164       void preModuleEventPrefetching(StreamContext const&, ModuleCallingContext const&);
0165       void postModuleEventPrefetching(StreamContext const&, ModuleCallingContext const&);
0166       void preModuleEvent(StreamContext const&, ModuleCallingContext const&);
0167       void postModuleEvent(StreamContext const&, ModuleCallingContext const&);
0168       void preModuleEventAcquire(StreamContext const&, ModuleCallingContext const&);
0169       void postModuleEventAcquire(StreamContext const&, ModuleCallingContext const&);
0170       void preModuleEventDelayedGet(StreamContext const&, ModuleCallingContext const&);
0171       void postModuleEventDelayedGet(StreamContext const&, ModuleCallingContext const&);
0172       void preEventReadFromSource(StreamContext const&, ModuleCallingContext const&);
0173       void postEventReadFromSource(StreamContext const&, ModuleCallingContext const&);
0174
0175       void preModuleStreamPrefetching(StreamContext const&, ModuleCallingContext const&);
0176       void postModuleStreamPrefetching(StreamContext const&, ModuleCallingContext const&);
0177
0178       void preModuleStreamBeginRun(StreamContext const&, ModuleCallingContext const&);
0179       void postModuleStreamBeginRun(StreamContext const&, ModuleCallingContext const&);
0180       void preModuleStreamEndRun(StreamContext const&, ModuleCallingContext const&);
0181       void postModuleStreamEndRun(StreamContext const&, ModuleCallingContext const&);
0182
0183       void preModuleStreamBeginLumi(StreamContext const&, ModuleCallingContext const&);
0184       void postModuleStreamBeginLumi(StreamContext const&, ModuleCallingContext const&);
0185       void preModuleStreamEndLumi(StreamContext const&, ModuleCallingContext const&);
0186       void postModuleStreamEndLumi(StreamContext const&, ModuleCallingContext const&);
0187
0188       void preModuleBeginProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0189       void postModuleBeginProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0190       void preModuleAccessInputProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0191       void postModuleAccessInputProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0192       void preModuleEndProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0193       void postModuleEndProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0194
0195       void preModuleGlobalPrefetching(GlobalContext const&, ModuleCallingContext const&);
0196       void postModuleGlobalPrefetching(GlobalContext const&, ModuleCallingContext const&);
0197
0198       void preModuleGlobalBeginRun(GlobalContext const&, ModuleCallingContext const&);
0199       void postModuleGlobalBeginRun(GlobalContext const&, ModuleCallingContext const&);
0200       void preModuleGlobalEndRun(GlobalContext const&, ModuleCallingContext const&);
0201       void postModuleGlobalEndRun(GlobalContext const&, ModuleCallingContext const&);
0202
0203       void preModuleGlobalBeginLumi(GlobalContext const&, ModuleCallingContext const&);
0204       void postModuleGlobalBeginLumi(GlobalContext const&, ModuleCallingContext const&);
0205       void preModuleGlobalEndLumi(GlobalContext const&, ModuleCallingContext const&);
0206       void postModuleGlobalEndLumi(GlobalContext const&, ModuleCallingContext const&);
0207
0208       void preModuleWriteProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0209       void postModuleWriteProcessBlock(GlobalContext const&, ModuleCallingContext const&);
0210
0211       void preModuleWriteRun(GlobalContext const&, ModuleCallingContext const&);
0212       void postModuleWriteRun(GlobalContext const&, ModuleCallingContext const&);
0213
0214       void preModuleWriteLumi(GlobalContext const&, ModuleCallingContext const&);
0215       void postModuleWriteLumi(GlobalContext const&, ModuleCallingContext const&);
0216
0217       void preSourceConstruction(ModuleDescription const& md);
0218       void postSourceConstruction(ModuleDescription const& md);
0219
0220       void preESModulePrefetching(eventsetup::EventSetupRecordKey const&, ESModuleCallingContext const&);
0221       void postESModulePrefetching(eventsetup::EventSetupRecordKey const&, ESModuleCallingContext const&);
0222       void preESModule(eventsetup::EventSetupRecordKey const&, ESModuleCallingContext const&);
0223       void postESModule(eventsetup::EventSetupRecordKey const&, ESModuleCallingContext const&);
0224       void preESModuleAcquire(eventsetup::EventSetupRecordKey const&, ESModuleCallingContext const&);
0225       void postESModuleAcquire(eventsetup::EventSetupRecordKey const&, ESModuleCallingContext const&);
0226
0227     private:
0228       std::string indention_;
0229       std::set<std::string> dumpContextForLabels_;
0230       bool dumpNonModuleContext_;
0231       bool dumpPathsAndConsumes_;
0232       bool printTimestamps_;
0233       bool dumpEventSetupInfo_;
0234     };
0235   }  // namespace service
0236 }  // namespace edm
0237
0238 using namespace edm::service;
0239
0240 namespace {
0241
0242   class TimeStamper {
0243   public:
0244     TimeStamper(bool enable) : enabled_(enable) {}
0245
0246     friend std::ostream& operator<<(std::ostream& out, TimeStamper const& timestamp) {
0247       if (timestamp.enabled_)
0248         out << std::setprecision(2) << edm::TimeOfDay() << "  ";
0249       return out;
0250     }
0251
0252   private:
0253     bool enabled_;
0254   };
0255
0256 }  // namespace
0257
0258 Tracer::Tracer(ParameterSet const& iPS, ActivityRegistry& iRegistry)
0259     : indention_(iPS.getUntrackedParameter<std::string>("indention")),
0260       dumpContextForLabels_(),
0261       dumpNonModuleContext_(iPS.getUntrackedParameter<bool>("dumpNonModuleContext")),
0262       dumpPathsAndConsumes_(iPS.getUntrackedParameter<bool>("dumpPathsAndConsumes")),
0263       printTimestamps_(iPS.getUntrackedParameter<bool>("printTimestamps")),
0264       dumpEventSetupInfo_(iPS.getUntrackedParameter<bool>("dumpEventSetupInfo")) {
0265   for (std::string& label : iPS.getUntrackedParameter<std::vector<std::string>>("dumpContextForLabels"))
0266     dumpContextForLabels_.insert(std::move(label));
0267
0268   iRegistry.watchPreallocate(this, &Tracer::preallocate);
0269
0270   iRegistry.watchPreBeginJob(this, &Tracer::preBeginJob);
0271   iRegistry.watchPostBeginJob(this, &Tracer::postBeginJob);
0272   iRegistry.watchPostEndJob(this, &Tracer::postEndJob);
0273
0274   iRegistry.watchPreSourceEvent(this, &Tracer::preSourceEvent);
0275   iRegistry.watchPostSourceEvent(this, &Tracer::postSourceEvent);
0276
0277   iRegistry.watchPreSourceLumi(this, &Tracer::preSourceLumi);
0278   iRegistry.watchPostSourceLumi(this, &Tracer::postSourceLumi);
0279
0280   iRegistry.watchPreSourceRun(this, &Tracer::preSourceRun);
0281   iRegistry.watchPostSourceRun(this, &Tracer::postSourceRun);
0282
0283   iRegistry.watchPreSourceProcessBlock(this, &Tracer::preSourceProcessBlock);
0284   iRegistry.watchPostSourceProcessBlock(this, &Tracer::postSourceProcessBlock);
0285
0286   iRegistry.watchPreOpenFile(this, &Tracer::preOpenFile);
0287   iRegistry.watchPostOpenFile(this, &Tracer::postOpenFile);
0288
0289   iRegistry.watchPreCloseFile(this, &Tracer::preCloseFile);
0290   iRegistry.watchPostCloseFile(this, &Tracer::postCloseFile);
0291
0292   iRegistry.watchPreModuleBeginStream(this, &Tracer::preModuleBeginStream);
0293   iRegistry.watchPostModuleBeginStream(this, &Tracer::postModuleBeginStream);
0294
0295   iRegistry.watchPreModuleEndStream(this, &Tracer::preModuleEndStream);
0296   iRegistry.watchPostModuleEndStream(this, &Tracer::postModuleEndStream);
0297
0298   iRegistry.watchPreBeginProcessBlock(this, &Tracer::preBeginProcessBlock);
0299   iRegistry.watchPostBeginProcessBlock(this, &Tracer::postBeginProcessBlock);
0300
0301   iRegistry.watchPreAccessInputProcessBlock(this, &Tracer::preAccessInputProcessBlock);
0302   iRegistry.watchPostAccessInputProcessBlock(this, &Tracer::postAccessInputProcessBlock);
0303
0304   iRegistry.watchPreEndProcessBlock(this, &Tracer::preEndProcessBlock);
0305   iRegistry.watchPostEndProcessBlock(this, &Tracer::postEndProcessBlock);
0306
0307   iRegistry.watchPreWriteProcessBlock(this, &Tracer::preWriteProcessBlock);
0308   iRegistry.watchPostWriteProcessBlock(this, &Tracer::postWriteProcessBlock);
0309
0310   iRegistry.watchPreGlobalBeginRun(this, &Tracer::preGlobalBeginRun);
0311   iRegistry.watchPostGlobalBeginRun(this, &Tracer::postGlobalBeginRun);
0312
0313   iRegistry.watchPreGlobalEndRun(this, &Tracer::preGlobalEndRun);
0314   iRegistry.watchPostGlobalEndRun(this, &Tracer::postGlobalEndRun);
0315
0316   iRegistry.watchPreGlobalWriteRun(this, &Tracer::preGlobalWriteRun);
0317   iRegistry.watchPostGlobalWriteRun(this, &Tracer::postGlobalWriteRun);
0318
0319   iRegistry.watchPreStreamBeginRun(this, &Tracer::preStreamBeginRun);
0320   iRegistry.watchPostStreamBeginRun(this, &Tracer::postStreamBeginRun);
0321
0322   iRegistry.watchPreStreamEndRun(this, &Tracer::preStreamEndRun);
0323   iRegistry.watchPostStreamEndRun(this, &Tracer::postStreamEndRun);
0324
0325   iRegistry.watchPreGlobalBeginLumi(this, &Tracer::preGlobalBeginLumi);
0326   iRegistry.watchPostGlobalBeginLumi(this, &Tracer::postGlobalBeginLumi);
0327
0328   iRegistry.watchPreGlobalEndLumi(this, &Tracer::preGlobalEndLumi);
0329   iRegistry.watchPostGlobalEndLumi(this, &Tracer::postGlobalEndLumi);
0330
0331   iRegistry.watchPreGlobalWriteLumi(this, &Tracer::preGlobalWriteLumi);
0332   iRegistry.watchPostGlobalWriteLumi(this, &Tracer::postGlobalWriteLumi);
0333
0334   iRegistry.watchPreStreamBeginLumi(this, &Tracer::preStreamBeginLumi);
0335   iRegistry.watchPostStreamBeginLumi(this, &Tracer::postStreamBeginLumi);
0336
0337   iRegistry.watchPreStreamEndLumi(this, &Tracer::preStreamEndLumi);
0338   iRegistry.watchPostStreamEndLumi(this, &Tracer::postStreamEndLumi);
0339
0340   iRegistry.watchPreEvent(this, &Tracer::preEvent);
0341   iRegistry.watchPostEvent(this, &Tracer::postEvent);
0342
0343   iRegistry.watchPrePathEvent(this, &Tracer::prePathEvent);
0344   iRegistry.watchPostPathEvent(this, &Tracer::postPathEvent);
0345
0346   iRegistry.watchPreModuleConstruction(this, &Tracer::preModuleConstruction);
0347   iRegistry.watchPostModuleConstruction(this, &Tracer::postModuleConstruction);
0348
0349   iRegistry.watchPreModuleDestruction(this, &Tracer::preModuleDestruction);
0350   iRegistry.watchPostModuleDestruction(this, &Tracer::postModuleDestruction);
0351
0352   iRegistry.watchPreModuleBeginJob(this, &Tracer::preModuleBeginJob);
0353   iRegistry.watchPostModuleBeginJob(this, &Tracer::postModuleBeginJob);
0354
0355   iRegistry.watchPreModuleEndJob(this, &Tracer::preModuleEndJob);
0356   iRegistry.watchPostModuleEndJob(this, &Tracer::postModuleEndJob);
0357
0358   iRegistry.watchPreModuleEventPrefetching(this, &Tracer::preModuleEventPrefetching);
0359   iRegistry.watchPostModuleEventPrefetching(this, &Tracer::postModuleEventPrefetching);
0360   iRegistry.watchPreModuleEvent(this, &Tracer::preModuleEvent);
0361   iRegistry.watchPostModuleEvent(this, &Tracer::postModuleEvent);
0362   iRegistry.watchPreModuleEventAcquire(this, &Tracer::preModuleEventAcquire);
0363   iRegistry.watchPostModuleEventAcquire(this, &Tracer::postModuleEventAcquire);
0364   iRegistry.watchPreModuleEventDelayedGet(this, &Tracer::preModuleEventDelayedGet);
0365   iRegistry.watchPostModuleEventDelayedGet(this, &Tracer::postModuleEventDelayedGet);
0366   iRegistry.watchPreEventReadFromSource(this, &Tracer::preEventReadFromSource);
0367   iRegistry.watchPostEventReadFromSource(this, &Tracer::postEventReadFromSource);
0368
0369   iRegistry.watchPreModuleStreamPrefetching(this, &Tracer::preModuleStreamPrefetching);
0370   iRegistry.watchPostModuleStreamPrefetching(this, &Tracer::postModuleStreamPrefetching);
0371
0372   iRegistry.watchPreModuleStreamBeginRun(this, &Tracer::preModuleStreamBeginRun);
0373   iRegistry.watchPostModuleStreamBeginRun(this, &Tracer::postModuleStreamBeginRun);
0374   iRegistry.watchPreModuleStreamEndRun(this, &Tracer::preModuleStreamEndRun);
0375   iRegistry.watchPostModuleStreamEndRun(this, &Tracer::postModuleStreamEndRun);
0376
0377   iRegistry.watchPreModuleStreamBeginLumi(this, &Tracer::preModuleStreamBeginLumi);
0378   iRegistry.watchPostModuleStreamBeginLumi(this, &Tracer::postModuleStreamBeginLumi);
0379   iRegistry.watchPreModuleStreamEndLumi(this, &Tracer::preModuleStreamEndLumi);
0380   iRegistry.watchPostModuleStreamEndLumi(this, &Tracer::postModuleStreamEndLumi);
0381
0382   iRegistry.watchPreModuleBeginProcessBlock(this, &Tracer::preModuleBeginProcessBlock);
0383   iRegistry.watchPostModuleBeginProcessBlock(this, &Tracer::postModuleBeginProcessBlock);
0384   iRegistry.watchPreModuleAccessInputProcessBlock(this, &Tracer::preModuleAccessInputProcessBlock);
0385   iRegistry.watchPostModuleAccessInputProcessBlock(this, &Tracer::postModuleAccessInputProcessBlock);
0386   iRegistry.watchPreModuleEndProcessBlock(this, &Tracer::preModuleEndProcessBlock);
0387   iRegistry.watchPostModuleEndProcessBlock(this, &Tracer::postModuleEndProcessBlock);
0388
0389   iRegistry.watchPreModuleGlobalPrefetching(this, &Tracer::preModuleGlobalPrefetching);
0390   iRegistry.watchPostModuleGlobalPrefetching(this, &Tracer::postModuleGlobalPrefetching);
0391
0392   iRegistry.watchPreModuleGlobalBeginRun(this, &Tracer::preModuleGlobalBeginRun);
0393   iRegistry.watchPostModuleGlobalBeginRun(this, &Tracer::postModuleGlobalBeginRun);
0394   iRegistry.watchPreModuleGlobalEndRun(this, &Tracer::preModuleGlobalEndRun);
0395   iRegistry.watchPostModuleGlobalEndRun(this, &Tracer::postModuleGlobalEndRun);
0396
0397   iRegistry.watchPreModuleGlobalBeginLumi(this, &Tracer::preModuleGlobalBeginLumi);
0398   iRegistry.watchPostModuleGlobalBeginLumi(this, &Tracer::postModuleGlobalBeginLumi);
0399   iRegistry.watchPreModuleGlobalEndLumi(this, &Tracer::preModuleGlobalEndLumi);
0400   iRegistry.watchPostModuleGlobalEndLumi(this, &Tracer::postModuleGlobalEndLumi);
0401
0402   iRegistry.watchPreModuleWriteProcessBlock(this, &Tracer::preModuleWriteProcessBlock);
0403   iRegistry.watchPostModuleWriteProcessBlock(this, &Tracer::postModuleWriteProcessBlock);
0404
0405   iRegistry.watchPreModuleWriteRun(this, &Tracer::preModuleWriteRun);
0406   iRegistry.watchPostModuleWriteRun(this, &Tracer::postModuleWriteRun);
0407
0408   iRegistry.watchPreModuleWriteLumi(this, &Tracer::preModuleWriteLumi);
0409   iRegistry.watchPostModuleWriteLumi(this, &Tracer::postModuleWriteLumi);
0410
0411   iRegistry.watchPreSourceConstruction(this, &Tracer::preSourceConstruction);
0412   iRegistry.watchPostSourceConstruction(this, &Tracer::postSourceConstruction);
0413
0414   iRegistry.watchPreESModulePrefetching(this, &Tracer::preESModulePrefetching);
0415   iRegistry.watchPostESModulePrefetching(this, &Tracer::postESModulePrefetching);
0416   iRegistry.watchPreESModule(this, &Tracer::preESModule);
0417   iRegistry.watchPostESModule(this, &Tracer::postESModule);
0418   iRegistry.watchPreESModuleAcquire(this, &Tracer::preESModuleAcquire);
0419   iRegistry.watchPostESModuleAcquire(this, &Tracer::postESModuleAcquire);
0420
0421   iRegistry.preSourceEarlyTerminationSignal_.connect([this](edm::TerminationOrigin iOrigin) {
0422     LogAbsolute out("Tracer");
0423     out << TimeStamper(printTimestamps_);
0424     out << indention_ << indention_ << " early termination before processing transition";
0425   });
0426   iRegistry.preStreamEarlyTerminationSignal_.connect(
0427       [this](edm::StreamContext const& iContext, edm::TerminationOrigin iOrigin) {
0428         LogAbsolute out("Tracer");
0429         out << TimeStamper(printTimestamps_);
0430         if (iContext.eventID().luminosityBlock() == 0) {
0431           out << indention_ << indention_ << " early termination of run: stream = " << iContext.streamID()
0432               << " run = " << iContext.eventID().run();
0433         } else {
0434           if (iContext.eventID().event() == 0) {
0435             out << indention_ << indention_ << " early termination of stream lumi: stream = " << iContext.streamID()
0436                 << " run = " << iContext.eventID().run() << " lumi = " << iContext.eventID().luminosityBlock();
0437           } else {
0438             out << indention_ << indention_ << " early termination of event: stream = " << iContext.streamID()
0439                 << " run = " << iContext.eventID().run() << " lumi = " << iContext.eventID().luminosityBlock()
0440                 << " event = " << iContext.eventID().event();
0441           }
0442         }
0443         out << " : time = " << iContext.timestamp().value();
0444       });
0445   iRegistry.preGlobalEarlyTerminationSignal_.connect(
0446       [this](edm::GlobalContext const& iContext, edm::TerminationOrigin iOrigin) {
0447         LogAbsolute out("Tracer");
0448         out << TimeStamper(printTimestamps_);
0449         if (iContext.luminosityBlockID().value() == 0) {
0450           out << indention_ << indention_ << " early termination of global run " << iContext.luminosityBlockID().run();
0451         } else {
0452           out << indention_ << indention_
0453               << " early termination of global lumi run = " << iContext.luminosityBlockID().run()
0454               << " lumi = " << iContext.luminosityBlockID().luminosityBlock();
0455         }
0456         out << " : time = " << iContext.timestamp().value();
0457       });
0458
0459   iRegistry.esSyncIOVQueuingSignal_.connect([this](edm::IOVSyncValue const& iSync) {
0460     LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_
0461                           << " queuing: EventSetup synchronization " << iSync.eventID();
0462   });
0463   iRegistry.preESSyncIOVSignal_.connect([this](edm::IOVSyncValue const& iSync) {
0464     LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_
0465                           << " pre: EventSetup synchronizing " << iSync.eventID();
0466   });
0467   iRegistry.postESSyncIOVSignal_.connect([this](edm::IOVSyncValue const& iSync) {
0468     LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_
0469                           << " post: EventSetup synchronizing " << iSync.eventID();
0470   });
0471 }
0472
0473 void Tracer::fillDescriptions(edm::ConfigurationDescriptions& descriptions) {
0474   edm::ParameterSetDescription desc;
0475   desc.addUntracked<std::string>("indention", "++")
0476       ->setComment("Prefix characters for output. The characters are repeated to form the indentation.");
0477   desc.addUntracked<std::vector<std::string>>("dumpContextForLabels", std::vector<std::string>{})
0478       ->setComment(
0479           "Prints context information to cout for the module transitions associated with these modules' labels");
0480   desc.addUntracked<bool>("dumpNonModuleContext", false)
0481       ->setComment("Prints context information to cout for the transitions not associated with any module label");
0482   desc.addUntracked<bool>("dumpPathsAndConsumes", false)
0483       ->setComment(
0484           "Prints information to cout about paths, endpaths, products consumed by modules and the dependencies between "
0485           "modules created by the products they consume");
0486   desc.addUntracked<bool>("printTimestamps", false)->setComment("Prints a time stamp for every transition");
0487   desc.addUntracked<bool>("dumpEventSetupInfo", false)
0488       ->setComment(
0489           "Prints info 3 times when an event setup cache is filled, before the lock, after the lock, and after "
0490           "filling");
0491   descriptions.add("Tracer", desc);
0492   descriptions.setComment(
0493       "This service prints each phase the framework is processing, e.g. constructing a module,running a module, etc.");
0494 }
0495
0496 void Tracer::preallocate(service::SystemBounds const& bounds) {
0497   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_
0498                         << " preallocate: " << bounds.maxNumberOfConcurrentRuns() << " concurrent runs, "
0499                         << bounds.maxNumberOfConcurrentLuminosityBlocks() << " concurrent luminosity sections, "
0500                         << bounds.maxNumberOfStreams() << " streams";
0501 }
0502
0503 void Tracer::preBeginJob(PathsAndConsumesOfModulesBase const& pathsAndConsumes, ProcessContext const& pc) {
0504   LogAbsolute out("Tracer");
0505   out << TimeStamper(printTimestamps_) << indention_ << " starting: begin job";
0506   if (dumpPathsAndConsumes_) {
0507     out << "\n"
0508         << "Process name = " << pc.processName() << "\n";
0509     out << "paths:\n";
0510     std::vector<std::string> const& paths = pathsAndConsumes.paths();
0511     for (auto const& path : paths) {
0512       out << "  " << path << "\n";
0513     }
0514     out << "end paths:\n";
0515     std::vector<std::string> const& endpaths = pathsAndConsumes.endPaths();
0516     for (auto const& endpath : endpaths) {
0517       out << "  " << endpath << "\n";
0518     }
0519     for (unsigned int j = 0; j < paths.size(); ++j) {
0520       std::vector<ModuleDescription const*> const& modulesOnPath = pathsAndConsumes.modulesOnPath(j);
0521       out << "modules on path " << paths.at(j) << ":\n";
0522       for (auto const& desc : modulesOnPath) {
0523         out << "  " << desc->moduleLabel() << "\n";
0524       }
0525     }
0526     for (unsigned int j = 0; j < endpaths.size(); ++j) {
0527       std::vector<ModuleDescription const*> const& modulesOnEndPath = pathsAndConsumes.modulesOnEndPath(j);
0528       out << "modules on end path " << endpaths.at(j) << ":\n";
0529       for (auto const& desc : modulesOnEndPath) {
0530         out << "  " << desc->moduleLabel() << "\n";
0531       }
0532     }
0533     std::vector<ModuleDescription const*> const& allModules = pathsAndConsumes.allModules();
0534     out << "All modules and modules in the current process whose products they consume:\n";
0535     out << "(This does not include modules from previous processes or the source)\n";
0536     out << "(Exclusively considers Event products, not Run, Lumi, or ProcessBlock products)\n";
0537     for (auto const& module : allModules) {
0538       out << "  " << module->moduleName() << "/\'" << module->moduleLabel() << "\'";
0539       unsigned int moduleID = module->id();
0540       if (pathsAndConsumes.moduleDescription(moduleID) != module) {
0541         throw cms::Exception("TestFailure") << "Tracer::preBeginJob, moduleDescription returns incorrect value";
0542       }
0543       std::vector<ModuleDescription const*> const& modulesWhoseProductsAreConsumedBy =
0544           pathsAndConsumes.modulesWhoseProductsAreConsumedBy(moduleID);
0545       if (!modulesWhoseProductsAreConsumedBy.empty()) {
0546         out << " consumes products from these modules:\n";
0547         for (auto const& producingModule : modulesWhoseProductsAreConsumedBy) {
0548           out << "    " << producingModule->moduleName() << "/\'" << producingModule->moduleLabel() << "\'\n";
0549         }
0550       } else {
0551         out << "\n";
0552       }
0553     }
0554     out << "All modules (listed by class and label) and all their consumed products.\n";
0555     out << "Consumed products are listed by type, label, instance, process.\n";
0556     out << "For products not in the event, \'processBlock\', \'run\' or \'lumi\' is added to indicate the TTree they "
0557            "are from.\n";
0558     out << "For products that are declared with mayConsume, \'may consume\' is added.\n";
0559     out << "For products consumed for Views, \'element type\' is added\n";
0560     out << "For products only read from previous processes, \'skip current process\' is added\n";
0561     for (auto const* module : allModules) {
0562       out << "  " << module->moduleName() << "/\'" << module->moduleLabel() << "\'";
0563       std::vector<ConsumesInfo> consumesInfo = pathsAndConsumes.consumesInfo(module->id());
0564       if (!consumesInfo.empty()) {
0565         out << " consumes:\n";
0566         for (auto const& info : consumesInfo) {
0567           out << "    " << info.type() << " \'" << info.label() << "\' \'" << info.instance();
0568           out << "\' \'" << info.process() << "\'";
0569           if (info.branchType() == InLumi) {
0570             out << ", lumi";
0571           } else if (info.branchType() == InRun) {
0572             out << ", run";
0573           } else if (info.branchType() == InProcess) {
0574             out << ", processBlock";
0575           }
0576           if (!info.alwaysGets()) {
0577             out << ", may consume";
0578           }
0579           if (info.kindOfType() == ELEMENT_TYPE) {
0580             out << ", element type";
0581           }
0582           if (info.skipCurrentProcess()) {
0583             out << ", skip current process";
0584           }
0585           out << "\n";
0586         }
0587       } else {
0588         out << "\n";
0589       }
0590     }
0591   }
0592 }
0593
0594 void Tracer::postBeginJob() {
0595   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << " finished: begin job";
0596 }
0597
0598 void Tracer::postEndJob() {
0599   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << " finished: end job";
0600 }
0601
0602 void Tracer::preSourceEvent(StreamID sid) {
0603   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_ << " starting: source event";
0604 }
0605
0606 void Tracer::postSourceEvent(StreamID sid) {
0607   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_ << " finished: source event";
0608 }
0609
0610 void Tracer::preSourceLumi(LuminosityBlockIndex index) {
0611   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_ << " starting: source lumi";
0612 }
0613
0614 void Tracer::postSourceLumi(LuminosityBlockIndex index) {
0615   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_ << " finished: source lumi";
0616 }
0617
0618 void Tracer::preSourceRun(RunIndex index) {
0619   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_ << " starting: source run";
0620 }
0621
0622 void Tracer::postSourceRun(RunIndex index) {
0623   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_ << " finished: source run";
0624 }
0625
0626 void Tracer::preSourceProcessBlock() {
0627   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_
0628                         << " starting: source process block";
0629 }
0630
0631 void Tracer::postSourceProcessBlock(std::string const& processName) {
0632   LogAbsolute("Tracer") << TimeStamper(printTimestamps_) << indention_ << indention_
0633                         << " finished: source process block " << processName;
0634 }
0635
0636 void Tracer::preOpenFile(std::string const& lfn) {
0637   LogAbsolute out("Tracer");
0638   out << TimeStamper(printTimestamps_);
0639   out << indention_ << indention_ << " starting: open input file: lfn = " << lfn;
0640 }
0641
0642 void Tracer::postOpenFile(std::string const& lfn) {
0643   LogAbsolute out("Tracer");
0644   out << TimeStamper(printTimestamps_);
0645   out << indention_ << indention_ << " finished: open input file: lfn = " << lfn;
0646 }
0647
0648 void Tracer::preCloseFile(std::string const& lfn) {
0649   LogAbsolute out("Tracer");
0650   out << TimeStamper(printTimestamps_);
0651   out << indention_ << indention_ << " starting: close input file: lfn = " << lfn;
0652 }
0653 void Tracer::postCloseFile(std::string const& lfn) {
0654   LogAbsolute out("Tracer");
0655   out << TimeStamper(printTimestamps_);
0656   out << indention_ << indention_ << " finished: close input file: lfn = " << lfn;
0657 }
0658
0659 void Tracer::preModuleBeginStream(StreamContext const& sc, ModuleCallingContext const& mcc) {
0660   ModuleDescription const& desc = *mcc.moduleDescription();
0661   LogAbsolute out("Tracer");
0662   out << TimeStamper(printTimestamps_);
0663   out << indention_ << indention_ << " starting: begin stream for module: stream = " << sc.streamID() << " label = '"
0664       << desc.moduleLabel() << "' id = " << desc.id();
0665   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
0666     out << "\n" << sc;
0667     out << mcc;
0668   }
0669 }
0670
0671 void Tracer::postModuleBeginStream(StreamContext const& sc, ModuleCallingContext const& mcc) {
0672   ModuleDescription const& desc = *mcc.moduleDescription();
0673   LogAbsolute out("Tracer");
0674   out << TimeStamper(printTimestamps_);
0675   out << indention_ << indention_ << " finished: begin stream for module: stream = " << sc.streamID() << " label = '"
0676       << desc.moduleLabel() << "' id = " << desc.id();
0677   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
0678     out << "\n" << sc;
0679     out << mcc;
0680   }
0681 }
0682
0683 void Tracer::preModuleEndStream(StreamContext const& sc, ModuleCallingContext const& mcc) {
0684   ModuleDescription const& desc = *mcc.moduleDescription();
0685   LogAbsolute out("Tracer");
0686   out << TimeStamper(printTimestamps_);
0687   out << indention_ << indention_ << " starting: end stream for module: stream = " << sc.streamID() << " label = '"
0688       << desc.moduleLabel() << "' id = " << desc.id();
0689   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
0690     out << "\n" << sc;
0691     out << mcc;
0692   }
0693 }
0694
0695 void Tracer::postModuleEndStream(StreamContext const& sc, ModuleCallingContext const& mcc) {
0696   ModuleDescription const& desc = *mcc.moduleDescription();
0697   LogAbsolute out("Tracer");
0698   out << TimeStamper(printTimestamps_);
0699   out << indention_ << indention_ << " finished: end stream for module: stream = " << sc.streamID() << " label = '"
0700       << desc.moduleLabel() << "' id = " << desc.id();
0701   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
0702     out << "\n" << sc;
0703     out << mcc;
0704   }
0705 }
0706
0707 void Tracer::preBeginProcessBlock(GlobalContext const& gc) {
0708   LogAbsolute out("Tracer");
0709   out << indention_ << indention_ << " starting: begin process block";
0710   if (dumpNonModuleContext_) {
0711     out << "\n" << gc;
0712   }
0713 }
0714
0715 void Tracer::postBeginProcessBlock(GlobalContext const& gc) {
0716   LogAbsolute out("Tracer");
0717   out << indention_ << indention_ << " finished: begin process block";
0718   if (dumpNonModuleContext_) {
0719     out << "\n" << gc;
0720   }
0721 }
0722
0723 void Tracer::preAccessInputProcessBlock(GlobalContext const& gc) {
0724   LogAbsolute out("Tracer");
0725   out << indention_ << indention_ << " starting: access input process block";
0726   if (dumpNonModuleContext_) {
0727     out << "\n" << gc;
0728   }
0729 }
0730
0731 void Tracer::postAccessInputProcessBlock(GlobalContext const& gc) {
0732   LogAbsolute out("Tracer");
0733   out << indention_ << indention_ << " finished: access input process block";
0734   if (dumpNonModuleContext_) {
0735     out << "\n" << gc;
0736   }
0737 }
0738
0739 void Tracer::preEndProcessBlock(GlobalContext const& gc) {
0740   LogAbsolute out("Tracer");
0741   out << indention_ << indention_ << " starting: end process block";
0742   if (dumpNonModuleContext_) {
0743     out << "\n" << gc;
0744   }
0745 }
0746
0747 void Tracer::postEndProcessBlock(GlobalContext const& gc) {
0748   LogAbsolute out("Tracer");
0749   out << indention_ << indention_ << " finished: end process block";
0750   if (dumpNonModuleContext_) {
0751     out << "\n" << gc;
0752   }
0753 }
0754
0755 void Tracer::preWriteProcessBlock(GlobalContext const& gc) {
0756   LogAbsolute out("Tracer");
0757   out << indention_ << indention_ << " starting: write process block";
0758   if (dumpNonModuleContext_) {
0759     out << "\n" << gc;
0760   }
0761 }
0762
0763 void Tracer::postWriteProcessBlock(GlobalContext const& gc) {
0764   LogAbsolute out("Tracer");
0765   out << indention_ << indention_ << " finished: write process block";
0766   if (dumpNonModuleContext_) {
0767     out << "\n" << gc;
0768   }
0769 }
0770
0771 void Tracer::preGlobalBeginRun(GlobalContext const& gc) {
0772   LogAbsolute out("Tracer");
0773   out << TimeStamper(printTimestamps_);
0774   out << indention_ << indention_ << " starting: global begin run " << gc.luminosityBlockID().run()
0775       << " : time = " << gc.timestamp().value();
0776   if (dumpNonModuleContext_) {
0777     out << "\n" << gc;
0778   }
0779 }
0780
0781 void Tracer::postGlobalBeginRun(GlobalContext const& gc) {
0782   LogAbsolute out("Tracer");
0783   out << TimeStamper(printTimestamps_);
0784   out << indention_ << indention_ << " finished: global begin run " << gc.luminosityBlockID().run()
0785       << " : time = " << gc.timestamp().value();
0786   if (dumpNonModuleContext_) {
0787     out << "\n" << gc;
0788   }
0789 }
0790
0791 void Tracer::preGlobalEndRun(GlobalContext const& gc) {
0792   LogAbsolute out("Tracer");
0793   out << TimeStamper(printTimestamps_);
0794   out << indention_ << indention_ << " starting: global end run " << gc.luminosityBlockID().run()
0795       << " : time = " << gc.timestamp().value();
0796   if (dumpNonModuleContext_) {
0797     out << "\n" << gc;
0798   }
0799 }
0800
0801 void Tracer::postGlobalEndRun(GlobalContext const& gc) {
0802   LogAbsolute out("Tracer");
0803   out << TimeStamper(printTimestamps_);
0804   out << indention_ << indention_ << " finished: global end run " << gc.luminosityBlockID().run()
0805       << " : time = " << gc.timestamp().value();
0806   if (dumpNonModuleContext_) {
0807     out << "\n" << gc;
0808   }
0809 }
0810
0811 void Tracer::preGlobalWriteRun(GlobalContext const& gc) {
0812   LogAbsolute out("Tracer");
0813   out << TimeStamper(printTimestamps_);
0814   out << indention_ << indention_ << " starting: global write run " << gc.luminosityBlockID().run()
0815       << " : time = " << gc.timestamp().value();
0816   if (dumpNonModuleContext_) {
0817     out << "\n" << gc;
0818   }
0819 }
0820
0821 void Tracer::postGlobalWriteRun(GlobalContext const& gc) {
0822   LogAbsolute out("Tracer");
0823   out << TimeStamper(printTimestamps_);
0824   out << indention_ << indention_ << " finished: global write run " << gc.luminosityBlockID().run()
0825       << " : time = " << gc.timestamp().value();
0826   if (dumpNonModuleContext_) {
0827     out << "\n" << gc;
0828   }
0829 }
0830
0831 void Tracer::preStreamBeginRun(StreamContext const& sc) {
0832   LogAbsolute out("Tracer");
0833   out << TimeStamper(printTimestamps_);
0834   out << indention_ << indention_ << " starting: begin run: stream = " << sc.streamID()
0835       << " run = " << sc.eventID().run() << " time = " << sc.timestamp().value();
0836   if (dumpNonModuleContext_) {
0837     out << "\n" << sc;
0838   }
0839 }
0840
0841 void Tracer::postStreamBeginRun(StreamContext const& sc) {
0842   LogAbsolute out("Tracer");
0843   out << TimeStamper(printTimestamps_);
0844   out << indention_ << indention_ << " finished: begin run: stream = " << sc.streamID()
0845       << " run = " << sc.eventID().run() << " time = " << sc.timestamp().value();
0846   if (dumpNonModuleContext_) {
0847     out << "\n" << sc;
0848   }
0849 }
0850
0851 void Tracer::preStreamEndRun(StreamContext const& sc) {
0852   LogAbsolute out("Tracer");
0853   out << TimeStamper(printTimestamps_);
0854   out << indention_ << indention_ << " starting: end run: stream = " << sc.streamID() << " run = " << sc.eventID().run()
0855       << " time = " << sc.timestamp().value();
0856   if (dumpNonModuleContext_) {
0857     out << "\n" << sc;
0858   }
0859 }
0860
0861 void Tracer::postStreamEndRun(StreamContext const& sc) {
0862   LogAbsolute out("Tracer");
0863   out << TimeStamper(printTimestamps_);
0864   out << indention_ << indention_ << " finished: end run: stream = " << sc.streamID() << " run = " << sc.eventID().run()
0865       << " time = " << sc.timestamp().value();
0866   if (dumpNonModuleContext_) {
0867     out << "\n" << sc;
0868   }
0869 }
0870
0871 void Tracer::preGlobalBeginLumi(GlobalContext const& gc) {
0872   LogAbsolute out("Tracer");
0873   out << TimeStamper(printTimestamps_);
0874   out << indention_ << indention_ << " starting: global begin lumi: run = " << gc.luminosityBlockID().run()
0875       << " lumi = " << gc.luminosityBlockID().luminosityBlock() << " time = " << gc.timestamp().value();
0876   if (dumpNonModuleContext_) {
0877     out << "\n" << gc;
0878   }
0879 }
0880
0881 void Tracer::postGlobalBeginLumi(GlobalContext const& gc) {
0882   LogAbsolute out("Tracer");
0883   out << TimeStamper(printTimestamps_);
0884   out << indention_ << indention_ << " finished: global begin lumi: run = " << gc.luminosityBlockID().run()
0885       << " lumi = " << gc.luminosityBlockID().luminosityBlock() << " time = " << gc.timestamp().value();
0886   if (dumpNonModuleContext_) {
0887     out << "\n" << gc;
0888   }
0889 }
0890
0891 void Tracer::preGlobalEndLumi(GlobalContext const& gc) {
0892   LogAbsolute out("Tracer");
0893   out << TimeStamper(printTimestamps_);
0894   out << indention_ << indention_ << " starting: global end lumi: run = " << gc.luminosityBlockID().run()
0895       << " lumi = " << gc.luminosityBlockID().luminosityBlock() << " time = " << gc.timestamp().value();
0896   if (dumpNonModuleContext_) {
0897     out << "\n" << gc;
0898   }
0899 }
0900
0901 void Tracer::postGlobalEndLumi(GlobalContext const& gc) {
0902   LogAbsolute out("Tracer");
0903   out << TimeStamper(printTimestamps_);
0904   out << indention_ << indention_ << " finished: global end lumi: run = " << gc.luminosityBlockID().run()
0905       << " lumi = " << gc.luminosityBlockID().luminosityBlock() << " time = " << gc.timestamp().value();
0906   if (dumpNonModuleContext_) {
0907     out << "\n" << gc;
0908   }
0909 }
0910
0911 void Tracer::preGlobalWriteLumi(GlobalContext const& gc) {
0912   LogAbsolute out("Tracer");
0913   out << TimeStamper(printTimestamps_);
0914   out << indention_ << indention_ << " starting: global write lumi: run = " << gc.luminosityBlockID().run()
0915       << " lumi = " << gc.luminosityBlockID().luminosityBlock() << " time = " << gc.timestamp().value();
0916   if (dumpNonModuleContext_) {
0917     out << "\n" << gc;
0918   }
0919 }
0920
0921 void Tracer::postGlobalWriteLumi(GlobalContext const& gc) {
0922   LogAbsolute out("Tracer");
0923   out << TimeStamper(printTimestamps_);
0924   out << indention_ << indention_ << " finished: global write lumi: run = " << gc.luminosityBlockID().run()
0925       << " lumi = " << gc.luminosityBlockID().luminosityBlock() << " time = " << gc.timestamp().value();
0926   if (dumpNonModuleContext_) {
0927     out << "\n" << gc;
0928   }
0929 }
0930
0931 void Tracer::preStreamBeginLumi(StreamContext const& sc) {
0932   LogAbsolute out("Tracer");
0933   out << TimeStamper(printTimestamps_);
0934   out << indention_ << indention_ << " starting: begin lumi: stream = " << sc.streamID()
0935       << " run = " << sc.eventID().run() << " lumi = " << sc.eventID().luminosityBlock()
0936       << " time = " << sc.timestamp().value();
0937   if (dumpNonModuleContext_) {
0938     out << "\n" << sc;
0939   }
0940 }
0941
0942 void Tracer::postStreamBeginLumi(StreamContext const& sc) {
0943   LogAbsolute out("Tracer");
0944   out << TimeStamper(printTimestamps_);
0945   out << indention_ << indention_ << " finished: begin lumi: stream = " << sc.streamID()
0946       << " run = " << sc.eventID().run() << " lumi = " << sc.eventID().luminosityBlock()
0947       << " time = " << sc.timestamp().value();
0948   if (dumpNonModuleContext_) {
0949     out << "\n" << sc;
0950   }
0951 }
0952
0953 void Tracer::preStreamEndLumi(StreamContext const& sc) {
0954   LogAbsolute out("Tracer");
0955   out << TimeStamper(printTimestamps_);
0956   out << indention_ << indention_ << " starting: end lumi: stream = " << sc.streamID()
0957       << " run = " << sc.eventID().run() << " lumi = " << sc.eventID().luminosityBlock()
0958       << " time = " << sc.timestamp().value();
0959   if (dumpNonModuleContext_) {
0960     out << "\n" << sc;
0961   }
0962 }
0963
0964 void Tracer::postStreamEndLumi(StreamContext const& sc) {
0965   LogAbsolute out("Tracer");
0966   out << TimeStamper(printTimestamps_);
0967   out << indention_ << indention_ << " finished: end lumi: stream = " << sc.streamID()
0968       << " run = " << sc.eventID().run() << " lumi = " << sc.eventID().luminosityBlock()
0969       << " time = " << sc.timestamp().value();
0970   if (dumpNonModuleContext_) {
0971     out << "\n" << sc;
0972   }
0973 }
0974
0975 void Tracer::preEvent(StreamContext const& sc) {
0976   LogAbsolute out("Tracer");
0977   out << TimeStamper(printTimestamps_);
0978   out << indention_ << indention_ << " starting: processing event : stream = " << sc.streamID()
0979       << " run = " << sc.eventID().run() << " lumi = " << sc.eventID().luminosityBlock()
0980       << " event = " << sc.eventID().event() << " time = " << sc.timestamp().value();
0981   if (dumpNonModuleContext_) {
0982     out << "\n" << sc;
0983   }
0984 }
0985
0986 void Tracer::postEvent(StreamContext const& sc) {
0987   LogAbsolute out("Tracer");
0988   out << TimeStamper(printTimestamps_);
0989   out << indention_ << indention_ << " finished: processing event : stream = " << sc.streamID()
0990       << " run = " << sc.eventID().run() << " lumi = " << sc.eventID().luminosityBlock()
0991       << " event = " << sc.eventID().event() << " time = " << sc.timestamp().value();
0992   if (dumpNonModuleContext_) {
0993     out << "\n" << sc;
0994   }
0995 }
0996
0997 void Tracer::prePathEvent(StreamContext const& sc, PathContext const& pc) {
0998   LogAbsolute out("Tracer");
0999   out << TimeStamper(printTimestamps_);
1000   out << indention_ << indention_ << indention_ << " starting: processing path '" << pc.pathName()
1001       << "' : stream = " << sc.streamID();
1002   if (dumpNonModuleContext_) {
1003     out << "\n" << sc;
1004     out << pc;
1005   }
1006 }
1007
1008 void Tracer::postPathEvent(StreamContext const& sc, PathContext const& pc, HLTPathStatus const& hlts) {
1009   LogAbsolute out("Tracer");
1010   out << TimeStamper(printTimestamps_);
1011   out << indention_ << indention_ << indention_ << " finished: processing path '" << pc.pathName()
1012       << "' : stream = " << sc.streamID();
1013   if (dumpNonModuleContext_) {
1014     out << "\n" << sc;
1015     out << pc;
1016   }
1017 }
1018
1019 void Tracer::preModuleConstruction(ModuleDescription const& desc) {
1020   LogAbsolute out("Tracer");
1021   out << TimeStamper(printTimestamps_);
1022   out << indention_ << indention_ << " starting: constructing module with label '" << desc.moduleLabel()
1023       << "' id = " << desc.id();
1024   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1025     out << "\n" << desc;
1026   }
1027 }
1028
1029 void Tracer::postModuleConstruction(ModuleDescription const& desc) {
1030   LogAbsolute out("Tracer");
1031   out << TimeStamper(printTimestamps_);
1032   out << indention_ << indention_ << " finished: constructing module with label '" << desc.moduleLabel()
1033       << "' id = " << desc.id();
1034   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1035     out << "\n" << desc;
1036   }
1037 }
1038
1039 void Tracer::preModuleDestruction(ModuleDescription const& desc) {
1040   LogAbsolute out("Tracer");
1041   out << TimeStamper(printTimestamps_);
1042   out << indention_ << indention_ << " starting: destructing module with label '" << desc.moduleLabel()
1043       << "' id = " << desc.id();
1044   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1045     out << "\n" << desc;
1046   }
1047 }
1048
1049 void Tracer::postModuleDestruction(ModuleDescription const& desc) {
1050   LogAbsolute out("Tracer");
1051   out << TimeStamper(printTimestamps_);
1052   out << indention_ << indention_ << " finished: destructing module with label '" << desc.moduleLabel()
1053       << "' id = " << desc.id();
1054   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1055     out << "\n" << desc;
1056   }
1057 }
1058
1059 void Tracer::preModuleBeginJob(ModuleDescription const& desc) {
1060   LogAbsolute out("Tracer");
1061   out << TimeStamper(printTimestamps_);
1062   out << indention_ << indention_;
1063   out << " starting: begin job for module with label '" << desc.moduleLabel() << "' id = " << desc.id();
1064   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1065     out << "\n" << desc;
1066   }
1067 }
1068
1069 void Tracer::postModuleBeginJob(ModuleDescription const& desc) {
1070   LogAbsolute out("Tracer");
1071   out << TimeStamper(printTimestamps_);
1072   out << indention_ << indention_;
1073   out << " finished: begin job for module with label '" << desc.moduleLabel() << "' id = " << desc.id();
1074   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1075     out << "\n" << desc;
1076   }
1077 }
1078
1079 void Tracer::preModuleEndJob(ModuleDescription const& desc) {
1080   LogAbsolute out("Tracer");
1081   out << TimeStamper(printTimestamps_);
1082   out << indention_ << indention_;
1083   out << " starting: end job for module with label '" << desc.moduleLabel() << "' id = " << desc.id();
1084   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1085     out << "\n" << desc;
1086   }
1087 }
1088
1089 void Tracer::postModuleEndJob(ModuleDescription const& desc) {
1090   LogAbsolute out("Tracer");
1091   out << TimeStamper(printTimestamps_);
1092   out << indention_ << indention_;
1093   out << " finished: end job for module with label '" << desc.moduleLabel() << "' id = " << desc.id();
1094   if (dumpContextForLabels_.find(desc.moduleLabel()) != dumpContextForLabels_.end()) {
1095     out << "\n" << desc;
1096   }
1097 }
1098
1099 void Tracer::preModuleEventPrefetching(StreamContext const& sc, ModuleCallingContext const& mcc) {
1100   LogAbsolute out("Tracer");
1101   out << TimeStamper(printTimestamps_);
1102   unsigned int nIndents = mcc.depth() + 4;
1103   for (unsigned int i = 0; i < nIndents; ++i) {
1104     out << indention_;
1105   }
1106   out << " starting: prefetching before processing event for module: stream = " << sc.streamID() << " label = '"
1107       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1108   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1109     out << "\n" << sc;
1110     out << mcc;
1111   }
1112 }
1113
1114 void Tracer::postModuleEventPrefetching(StreamContext const& sc, ModuleCallingContext const& mcc) {
1115   LogAbsolute out("Tracer");
1116   out << TimeStamper(printTimestamps_);
1117   unsigned int nIndents = mcc.depth() + 4;
1118   for (unsigned int i = 0; i < nIndents; ++i) {
1119     out << indention_;
1120   }
1121   out << " finished: prefetching before processing event for module: stream = " << sc.streamID() << " label = '"
1122       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1123   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1124     out << "\n" << sc;
1125     out << mcc;
1126   }
1127 }
1128
1129 void Tracer::preModuleEvent(StreamContext const& sc, ModuleCallingContext const& mcc) {
1130   LogAbsolute out("Tracer");
1131   out << TimeStamper(printTimestamps_);
1132   unsigned int nIndents = mcc.depth() + 4;
1133   for (unsigned int i = 0; i < nIndents; ++i) {
1134     out << indention_;
1135   }
1136   out << " starting: processing event for module: stream = " << sc.streamID() << " label = '"
1137       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1138   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1139     out << "\n" << sc;
1140     out << mcc;
1141   }
1142 }
1143
1144 void Tracer::postModuleEvent(StreamContext const& sc, ModuleCallingContext const& mcc) {
1145   LogAbsolute out("Tracer");
1146   out << TimeStamper(printTimestamps_);
1147   unsigned int nIndents = mcc.depth() + 4;
1148   for (unsigned int i = 0; i < nIndents; ++i) {
1149     out << indention_;
1150   }
1151   out << " finished: processing event for module: stream = " << sc.streamID() << " label = '"
1152       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1153   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1154     out << "\n" << sc;
1155     out << mcc;
1156   }
1157 }
1158
1159 void Tracer::preModuleEventAcquire(StreamContext const& sc, ModuleCallingContext const& mcc) {
1160   LogAbsolute out("Tracer");
1161   out << TimeStamper(printTimestamps_);
1162   unsigned int nIndents = mcc.depth() + 4;
1163   for (unsigned int i = 0; i < nIndents; ++i) {
1164     out << indention_;
1165   }
1166   out << " starting: processing event acquire for module: stream = " << sc.streamID() << " label = '"
1167       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1168 }
1169
1170 void Tracer::postModuleEventAcquire(StreamContext const& sc, ModuleCallingContext const& mcc) {
1171   LogAbsolute out("Tracer");
1172   out << TimeStamper(printTimestamps_);
1173   unsigned int nIndents = mcc.depth() + 4;
1174   for (unsigned int i = 0; i < nIndents; ++i) {
1175     out << indention_;
1176   }
1177   out << " finished: processing event acquire for module: stream = " << sc.streamID() << " label = '"
1178       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1179 }
1180
1181 void Tracer::preModuleEventDelayedGet(StreamContext const& sc, ModuleCallingContext const& mcc) {
1182   LogAbsolute out("Tracer");
1183   out << TimeStamper(printTimestamps_);
1184   unsigned int nIndents = mcc.depth() + 4;
1185   for (unsigned int i = 0; i < nIndents; ++i) {
1186     out << indention_;
1187   }
1188   out << " starting: delayed processing event for module: stream = " << sc.streamID() << " label = '"
1189       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1190   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1191     out << "\n" << sc;
1192     out << mcc;
1193   }
1194 }
1195
1196 void Tracer::postModuleEventDelayedGet(StreamContext const& sc, ModuleCallingContext const& mcc) {
1197   LogAbsolute out("Tracer");
1198   out << TimeStamper(printTimestamps_);
1199   unsigned int nIndents = mcc.depth() + 4;
1200   for (unsigned int i = 0; i < nIndents; ++i) {
1201     out << indention_;
1202   }
1203   out << " finished: delayed processing event for module: stream = " << sc.streamID() << " label = '"
1204       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1205   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1206     out << "\n" << sc;
1207     out << mcc;
1208   }
1209 }
1210
1211 void Tracer::preEventReadFromSource(StreamContext const& sc, ModuleCallingContext const& mcc) {
1212   LogAbsolute out("Tracer");
1213   out << TimeStamper(printTimestamps_);
1214   unsigned int nIndents = mcc.depth() + 5;
1215   for (unsigned int i = 0; i < nIndents; ++i) {
1216     out << indention_;
1217   }
1218   out << " starting: event delayed read from source: stream = " << sc.streamID() << " label = '"
1219       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1220 }
1221
1222 void Tracer::postEventReadFromSource(StreamContext const& sc, ModuleCallingContext const& mcc) {
1223   LogAbsolute out("Tracer");
1224   out << TimeStamper(printTimestamps_);
1225   unsigned int nIndents = mcc.depth() + 5;
1226   for (unsigned int i = 0; i < nIndents; ++i) {
1227     out << indention_;
1228   }
1229   out << " finished: event delayed read from source: stream = " << sc.streamID() << " label = '"
1230       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1231 }
1232
1233 void Tracer::preModuleStreamPrefetching(StreamContext const& sc, ModuleCallingContext const& mcc) {
1234   LogAbsolute out("Tracer");
1235   out << TimeStamper(printTimestamps_);
1236   unsigned int nIndents = mcc.depth() + 4;
1237   for (unsigned int i = 0; i < nIndents; ++i) {
1238     out << indention_;
1239   }
1240   out << " starting: prefetching before processing " << transitionName(sc.transition())
1241       << " for module: stream = " << sc.streamID() << " label = '" << mcc.moduleDescription()->moduleLabel()
1242       << "' id = " << mcc.moduleDescription()->id();
1243   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1244     out << "\n" << sc;
1245     out << mcc;
1246   }
1247 }
1248
1249 void Tracer::postModuleStreamPrefetching(StreamContext const& sc, ModuleCallingContext const& mcc) {
1250   LogAbsolute out("Tracer");
1251   out << TimeStamper(printTimestamps_);
1252   unsigned int nIndents = mcc.depth() + 4;
1253   for (unsigned int i = 0; i < nIndents; ++i) {
1254     out << indention_;
1255   }
1256   out << " finished: prefetching before processing " << transitionName(sc.transition())
1257       << " for module: stream = " << sc.streamID() << " label = '" << mcc.moduleDescription()->moduleLabel()
1258       << "' id = " << mcc.moduleDescription()->id();
1259   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1260     out << "\n" << sc;
1261     out << mcc;
1262   }
1263 }
1264
1265 void Tracer::preModuleStreamBeginRun(StreamContext const& sc, ModuleCallingContext const& mcc) {
1266   LogAbsolute out("Tracer");
1267   out << TimeStamper(printTimestamps_);
1268   unsigned int nIndents = mcc.depth() + 3;
1269   for (unsigned int i = 0; i < nIndents; ++i) {
1270     out << indention_;
1271   }
1272   out << " starting: begin run for module: stream = " << sc.streamID() << " label = '"
1273       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1274   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1275     out << "\n" << sc;
1276     out << mcc;
1277   }
1278 }
1279
1280 void Tracer::postModuleStreamBeginRun(StreamContext const& sc, ModuleCallingContext const& mcc) {
1281   LogAbsolute out("Tracer");
1282   out << TimeStamper(printTimestamps_);
1283   unsigned int nIndents = mcc.depth() + 3;
1284   for (unsigned int i = 0; i < nIndents; ++i) {
1285     out << indention_;
1286   }
1287   out << " finished: begin run for module: stream = " << sc.streamID() << " label = '"
1288       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1289   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1290     out << "\n" << sc;
1291     out << mcc;
1292   }
1293 }
1294
1295 void Tracer::preModuleStreamEndRun(StreamContext const& sc, ModuleCallingContext const& mcc) {
1296   LogAbsolute out("Tracer");
1297   out << TimeStamper(printTimestamps_);
1298   unsigned int nIndents = mcc.depth() + 3;
1299   for (unsigned int i = 0; i < nIndents; ++i) {
1300     out << indention_;
1301   }
1302   out << " starting: end run for module: stream = " << sc.streamID() << " label = '"
1303       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1304   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1305     out << "\n" << sc;
1306     out << mcc;
1307   }
1308 }
1309
1310 void Tracer::postModuleStreamEndRun(StreamContext const& sc, ModuleCallingContext const& mcc) {
1311   LogAbsolute out("Tracer");
1312   out << TimeStamper(printTimestamps_);
1313   unsigned int nIndents = mcc.depth() + 3;
1314   for (unsigned int i = 0; i < nIndents; ++i) {
1315     out << indention_;
1316   }
1317   out << " finished: end run for module: stream = " << sc.streamID() << " label = '"
1318       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1319   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1320     out << "\n" << sc;
1321     out << mcc;
1322   }
1323 }
1324
1325 void Tracer::preModuleStreamBeginLumi(StreamContext const& sc, ModuleCallingContext const& mcc) {
1326   LogAbsolute out("Tracer");
1327   out << TimeStamper(printTimestamps_);
1328   unsigned int nIndents = mcc.depth() + 3;
1329   for (unsigned int i = 0; i < nIndents; ++i) {
1330     out << indention_;
1331   }
1332   out << " starting: begin lumi for module: stream = " << sc.streamID() << " label = '"
1333       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1334   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1335     out << "\n" << sc;
1336     out << mcc;
1337   }
1338 }
1339
1340 void Tracer::postModuleStreamBeginLumi(StreamContext const& sc, ModuleCallingContext const& mcc) {
1341   LogAbsolute out("Tracer");
1342   out << TimeStamper(printTimestamps_);
1343   unsigned int nIndents = mcc.depth() + 3;
1344   for (unsigned int i = 0; i < nIndents; ++i) {
1345     out << indention_;
1346   }
1347   out << " finished: begin lumi for module: stream = " << sc.streamID() << " label = '"
1348       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1349   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1350     out << "\n" << sc;
1351     out << mcc;
1352   }
1353 }
1354
1355 void Tracer::preModuleStreamEndLumi(StreamContext const& sc, ModuleCallingContext const& mcc) {
1356   LogAbsolute out("Tracer");
1357   out << TimeStamper(printTimestamps_);
1358   unsigned int nIndents = mcc.depth() + 3;
1359   for (unsigned int i = 0; i < nIndents; ++i) {
1360     out << indention_;
1361   }
1362   out << " starting: end lumi for module: stream = " << sc.streamID() << " label = '"
1363       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1364   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1365     out << "\n" << sc;
1366     out << mcc;
1367   }
1368 }
1369
1370 void Tracer::postModuleStreamEndLumi(StreamContext const& sc, ModuleCallingContext const& mcc) {
1371   LogAbsolute out("Tracer");
1372   out << TimeStamper(printTimestamps_);
1373   unsigned int nIndents = mcc.depth() + 3;
1374   for (unsigned int i = 0; i < nIndents; ++i) {
1375     out << indention_;
1376   }
1377   out << " finished: end lumi for module: stream = " << sc.streamID() << " label = '"
1378       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1379   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1380     out << "\n" << sc;
1381     out << mcc;
1382   }
1383 }
1384
1385 void Tracer::preModuleGlobalPrefetching(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1386   LogAbsolute out("Tracer");
1387   out << TimeStamper(printTimestamps_);
1388   unsigned int nIndents = mcc.depth() + 4;
1389   for (unsigned int i = 0; i < nIndents; ++i) {
1390     out << indention_;
1391   }
1392   out << " starting: prefetching before processing " << transitionName(gc.transition()) << " for module: label = '"
1393       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1394   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1395     out << "\n" << gc;
1396     out << mcc;
1397   }
1398 }
1399
1400 void Tracer::postModuleGlobalPrefetching(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1401   LogAbsolute out("Tracer");
1402   out << TimeStamper(printTimestamps_);
1403   unsigned int nIndents = mcc.depth() + 4;
1404   for (unsigned int i = 0; i < nIndents; ++i) {
1405     out << indention_;
1406   }
1407   out << " finished: prefetching before processing " << transitionName(gc.transition()) << " for module: label = '"
1408       << mcc.moduleDescription()->moduleLabel() << "' id = " << mcc.moduleDescription()->id();
1409   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1410     out << "\n" << gc;
1411     out << mcc;
1412   }
1413 }
1414
1415 void Tracer::preModuleBeginProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1416   LogAbsolute out("Tracer");
1417   unsigned int nIndents = mcc.depth() + 3;
1418   for (unsigned int i = 0; i < nIndents; ++i) {
1419     out << indention_;
1420   }
1421   out << " starting: begin process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1422       << "' id = " << mcc.moduleDescription()->id();
1423   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1424     out << "\n" << gc;
1425     out << mcc;
1426   }
1427 }
1428
1429 void Tracer::postModuleBeginProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1430   LogAbsolute out("Tracer");
1431   unsigned int nIndents = mcc.depth() + 3;
1432   for (unsigned int i = 0; i < nIndents; ++i) {
1433     out << indention_;
1434   }
1435   out << " finished: begin process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1436       << "' id = " << mcc.moduleDescription()->id();
1437   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1438     out << "\n" << gc;
1439     out << mcc;
1440   }
1441 }
1442
1443 void Tracer::preModuleAccessInputProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1444   LogAbsolute out("Tracer");
1445   unsigned int nIndents = mcc.depth() + 3;
1446   for (unsigned int i = 0; i < nIndents; ++i) {
1447     out << indention_;
1448   }
1449   out << " starting: access input process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1450       << "' id = " << mcc.moduleDescription()->id();
1451   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1452     out << "\n" << gc;
1453     out << mcc;
1454   }
1455 }
1456
1457 void Tracer::postModuleAccessInputProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1458   LogAbsolute out("Tracer");
1459   unsigned int nIndents = mcc.depth() + 3;
1460   for (unsigned int i = 0; i < nIndents; ++i) {
1461     out << indention_;
1462   }
1463   out << " finished: access input process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1464       << "' id = " << mcc.moduleDescription()->id();
1465   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1466     out << "\n" << gc;
1467     out << mcc;
1468   }
1469 }
1470
1471 void Tracer::preModuleEndProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1472   LogAbsolute out("Tracer");
1473   unsigned int nIndents = mcc.depth() + 3;
1474   for (unsigned int i = 0; i < nIndents; ++i) {
1475     out << indention_;
1476   }
1477   out << " starting: end process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1478       << "' id = " << mcc.moduleDescription()->id();
1479   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1480     out << "\n" << gc;
1481     out << mcc;
1482   }
1483 }
1484
1485 void Tracer::postModuleEndProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1486   LogAbsolute out("Tracer");
1487   unsigned int nIndents = mcc.depth() + 3;
1488   for (unsigned int i = 0; i < nIndents; ++i) {
1489     out << indention_;
1490   }
1491   out << " finished: end process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1492       << "' id = " << mcc.moduleDescription()->id();
1493   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1494     out << "\n" << gc;
1495     out << mcc;
1496   }
1497 }
1498
1499 void Tracer::preModuleGlobalBeginRun(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1500   LogAbsolute out("Tracer");
1501   out << TimeStamper(printTimestamps_);
1502   unsigned int nIndents = mcc.depth() + 3;
1503   for (unsigned int i = 0; i < nIndents; ++i) {
1504     out << indention_;
1505   }
1506   out << " starting: global begin run for module: label = '" << mcc.moduleDescription()->moduleLabel()
1507       << "' id = " << mcc.moduleDescription()->id();
1508   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1509     out << "\n" << gc;
1510     out << mcc;
1511   }
1512 }
1513
1514 void Tracer::postModuleGlobalBeginRun(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1515   LogAbsolute out("Tracer");
1516   out << TimeStamper(printTimestamps_);
1517   unsigned int nIndents = mcc.depth() + 3;
1518   for (unsigned int i = 0; i < nIndents; ++i) {
1519     out << indention_;
1520   }
1521   out << " finished: global begin run for module: label = '" << mcc.moduleDescription()->moduleLabel()
1522       << "' id = " << mcc.moduleDescription()->id();
1523   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1524     out << "\n" << gc;
1525     out << mcc;
1526   }
1527 }
1528
1529 void Tracer::preModuleGlobalEndRun(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1530   LogAbsolute out("Tracer");
1531   out << TimeStamper(printTimestamps_);
1532   unsigned int nIndents = mcc.depth() + 3;
1533   for (unsigned int i = 0; i < nIndents; ++i) {
1534     out << indention_;
1535   }
1536   out << " starting: global end run for module: label = '" << mcc.moduleDescription()->moduleLabel()
1537       << "' id = " << mcc.moduleDescription()->id();
1538   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1539     out << "\n" << gc;
1540     out << mcc;
1541   }
1542 }
1543
1544 void Tracer::postModuleGlobalEndRun(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1545   LogAbsolute out("Tracer");
1546   out << TimeStamper(printTimestamps_);
1547   unsigned int nIndents = mcc.depth() + 3;
1548   for (unsigned int i = 0; i < nIndents; ++i) {
1549     out << indention_;
1550   }
1551   out << " finished: global end run for module: label = '" << mcc.moduleDescription()->moduleLabel()
1552       << "' id = " << mcc.moduleDescription()->id();
1553   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1554     out << "\n" << gc;
1555     out << mcc;
1556   }
1557 }
1558
1559 void Tracer::preModuleGlobalBeginLumi(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1560   LogAbsolute out("Tracer");
1561   out << TimeStamper(printTimestamps_);
1562   unsigned int nIndents = mcc.depth() + 3;
1563   for (unsigned int i = 0; i < nIndents; ++i) {
1564     out << indention_;
1565   }
1566   out << " starting: global begin lumi for module: label = '" << mcc.moduleDescription()->moduleLabel()
1567       << "' id = " << mcc.moduleDescription()->id();
1568   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1569     out << "\n" << gc;
1570     out << mcc;
1571   }
1572 }
1573
1574 void Tracer::postModuleGlobalBeginLumi(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1575   LogAbsolute out("Tracer");
1576   out << TimeStamper(printTimestamps_);
1577   unsigned int nIndents = mcc.depth() + 3;
1578   for (unsigned int i = 0; i < nIndents; ++i) {
1579     out << indention_;
1580   }
1581   out << " finished: global begin lumi for module: label = '" << mcc.moduleDescription()->moduleLabel()
1582       << "' id = " << mcc.moduleDescription()->id();
1583   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1584     out << "\n" << gc;
1585     out << mcc;
1586   }
1587 }
1588
1589 void Tracer::preModuleGlobalEndLumi(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1590   LogAbsolute out("Tracer");
1591   out << TimeStamper(printTimestamps_);
1592   unsigned int nIndents = mcc.depth() + 3;
1593   for (unsigned int i = 0; i < nIndents; ++i) {
1594     out << indention_;
1595   }
1596   out << " starting: global end lumi for module: label = '" << mcc.moduleDescription()->moduleLabel()
1597       << "' id = " << mcc.moduleDescription()->id();
1598   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1599     out << "\n" << gc;
1600     out << mcc;
1601   }
1602 }
1603
1604 void Tracer::postModuleGlobalEndLumi(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1605   LogAbsolute out("Tracer");
1606   out << TimeStamper(printTimestamps_);
1607   unsigned int nIndents = mcc.depth() + 3;
1608   for (unsigned int i = 0; i < nIndents; ++i) {
1609     out << indention_;
1610   }
1611   out << " finished: global end lumi for module: label = '" << mcc.moduleDescription()->moduleLabel()
1612       << "' id = " << mcc.moduleDescription()->id();
1613   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1614     out << "\n" << gc;
1615     out << mcc;
1616   }
1617 }
1618
1619 void Tracer::preModuleWriteProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1620   LogAbsolute out("Tracer");
1621   unsigned int nIndents = mcc.depth() + 3;
1622   for (unsigned int i = 0; i < nIndents; ++i) {
1623     out << indention_;
1624   }
1625   out << " starting: write process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1626       << "' id = " << mcc.moduleDescription()->id();
1627   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1628     out << "\n" << gc;
1629     out << mcc;
1630   }
1631 }
1632
1633 void Tracer::postModuleWriteProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1634   LogAbsolute out("Tracer");
1635   unsigned int nIndents = mcc.depth() + 3;
1636   for (unsigned int i = 0; i < nIndents; ++i) {
1637     out << indention_;
1638   }
1639   out << " finished: write process block for module: label = '" << mcc.moduleDescription()->moduleLabel()
1640       << "' id = " << mcc.moduleDescription()->id();
1641   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1642     out << "\n" << gc;
1643     out << mcc;
1644   }
1645 }
1646
1647 void Tracer::preModuleWriteRun(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1648   LogAbsolute out("Tracer");
1649   out << TimeStamper(printTimestamps_);
1650   unsigned int nIndents = mcc.depth() + 3;
1651   for (unsigned int i = 0; i < nIndents; ++i) {
1652     out << indention_;
1653   }
1654   out << " starting: write run for module: label = '" << mcc.moduleDescription()->moduleLabel()
1655       << "' id = " << mcc.moduleDescription()->id();
1656   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1657     out << "\n" << gc;
1658     out << mcc;
1659   }
1660 }
1661
1662 void Tracer::postModuleWriteRun(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1663   LogAbsolute out("Tracer");
1664   out << TimeStamper(printTimestamps_);
1665   unsigned int nIndents = mcc.depth() + 3;
1666   for (unsigned int i = 0; i < nIndents; ++i) {
1667     out << indention_;
1668   }
1669   out << " finished: write run for module: label = '" << mcc.moduleDescription()->moduleLabel()
1670       << "' id = " << mcc.moduleDescription()->id();
1671   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1672     out << "\n" << gc;
1673     out << mcc;
1674   }
1675 }
1676
1677 void Tracer::preModuleWriteLumi(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1678   LogAbsolute out("Tracer");
1679   out << TimeStamper(printTimestamps_);
1680   unsigned int nIndents = mcc.depth() + 3;
1681   for (unsigned int i = 0; i < nIndents; ++i) {
1682     out << indention_;
1683   }
1684   out << " starting: write lumi for module: label = '" << mcc.moduleDescription()->moduleLabel()
1685       << "' id = " << mcc.moduleDescription()->id();
1686   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1687     out << "\n" << gc;
1688     out << mcc;
1689   }
1690 }
1691
1692 void Tracer::postModuleWriteLumi(GlobalContext const& gc, ModuleCallingContext const& mcc) {
1693   LogAbsolute out("Tracer");
1694   out << TimeStamper(printTimestamps_);
1695   unsigned int nIndents = mcc.depth() + 3;
1696   for (unsigned int i = 0; i < nIndents; ++i) {
1697     out << indention_;
1698   }
1699   out << " finished: write lumi for module: label = '" << mcc.moduleDescription()->moduleLabel()
1700       << "' id = " << mcc.moduleDescription()->id();
1701   if (dumpContextForLabels_.find(mcc.moduleDescription()->moduleLabel()) != dumpContextForLabels_.end()) {
1702     out << "\n" << gc;
1703     out << mcc;
1704   }
1705 }
1706
1707 void Tracer::preSourceConstruction(ModuleDescription const& desc) {
1708   LogAbsolute out("Tracer");
1709   out << TimeStamper(printTimestamps_);
1710   out << indention_;
1711   out << " starting: constructing source: " << desc.moduleName();
1712   if (dumpNonModuleContext_) {
1713     out << "\n" << desc;
1714   }
1715 }
1716
1717 void Tracer::postSourceConstruction(ModuleDescription const& desc) {
1718   LogAbsolute out("Tracer");
1719   out << TimeStamper(printTimestamps_);
1720   out << indention_;
1721   out << " finished: constructing source: " << desc.moduleName();
1722   if (dumpNonModuleContext_) {
1723     out << "\n" << desc;
1724   }
1725 }
1726
1727 void Tracer::preESModulePrefetching(eventsetup::EventSetupRecordKey const& iKey, ESModuleCallingContext const& mcc) {
1728   LogAbsolute out("Tracer");
1729   out << TimeStamper(printTimestamps_);
1730   unsigned int nIndents = mcc.depth() + 4;
1731   for (unsigned int i = 0; i < nIndents; ++i) {
1732     out << indention_;
1733   }
1734   out << " starting: prefetching for esmodule: label = '" << mcc.componentDescription()->label_
1735       << "' type = " << mcc.componentDescription()->type_ << " in record = " << iKey.name();
1736 }
1737
1738 void Tracer::postESModulePrefetching(eventsetup::EventSetupRecordKey const& iKey, ESModuleCallingContext const& mcc) {
1739   LogAbsolute out("Tracer");
1740   out << TimeStamper(printTimestamps_);
1741   unsigned int nIndents = mcc.depth() + 4;
1742   for (unsigned int i = 0; i < nIndents; ++i) {
1743     out << indention_;
1744   }
1745   out << " finished: prefetching for esmodule: label = '" << mcc.componentDescription()->label_
1746       << "' type = " << mcc.componentDescription()->type_ << " in record = " << iKey.name();
1747 }
1748
1749 void Tracer::preESModule(eventsetup::EventSetupRecordKey const& iKey, ESModuleCallingContext const& mcc) {
1750   LogAbsolute out("Tracer");
1751   out << TimeStamper(printTimestamps_);
1752   unsigned int nIndents = mcc.depth() + 4;
1753   for (unsigned int i = 0; i < nIndents; ++i) {
1754     out << indention_;
1755   }
1756   out << " starting: processing esmodule: label = '" << mcc.componentDescription()->label_
1757       << "' type = " << mcc.componentDescription()->type_ << " in record = " << iKey.name();
1758 }
1759
1760 void Tracer::postESModule(eventsetup::EventSetupRecordKey const& iKey, ESModuleCallingContext const& mcc) {
1761   LogAbsolute out("Tracer");
1762   out << TimeStamper(printTimestamps_);
1763   unsigned int nIndents = mcc.depth() + 4;
1764   for (unsigned int i = 0; i < nIndents; ++i) {
1765     out << indention_;
1766   }
1767   out << " finished: processing esmodule: label = '" << mcc.componentDescription()->label_
1768       << "' type = " << mcc.componentDescription()->type_ << " in record = " << iKey.name();
1769 }
1770
1771 void Tracer::preESModuleAcquire(eventsetup::EventSetupRecordKey const& iKey, ESModuleCallingContext const& mcc) {
1772   LogAbsolute out("Tracer");
1773   out << TimeStamper(printTimestamps_);
1774   unsigned int nIndents = mcc.depth() + 4;
1775   for (unsigned int i = 0; i < nIndents; ++i) {
1776     out << indention_;
1777   }
1778   out << " starting: processing esmodule acquire: label = '" << mcc.componentDescription()->label_
1779       << "' type = " << mcc.componentDescription()->type_ << " in record = " << iKey.name();
1780 }
1781
1782 void Tracer::postESModuleAcquire(eventsetup::EventSetupRecordKey const& iKey, ESModuleCallingContext const& mcc) {
1783   LogAbsolute out("Tracer");
1784   out << TimeStamper(printTimestamps_);
1785   unsigned int nIndents = mcc.depth() + 4;
1786   for (unsigned int i = 0; i < nIndents; ++i) {
1787     out << indention_;
1788   }
1789   out << " finished: processing esmodule acquire: label = '" << mcc.componentDescription()->label_
1790       << "' type = " << mcc.componentDescription()->type_ << " in record = " << iKey.name();
1791 }
1792
1793 using edm::service::Tracer;
1794 DEFINE_FWK_SERVICE(Tracer);