From 5a777f0cf03a2960961fb645015cf5da007eea09 Mon Sep 17 00:00:00 2001 From: "W. David Dagenhart" Date: Mon, 12 Jul 2021 22:14:56 +0200 Subject: [PATCH] Improve MessageLogger context for ProcessBlock Affects only MessageLogger context strings. Handle the case where ProcessBlock transitions go into a nonblocking wait and TBB runs another module on the same thread. Handles this context the same as for Run transitions. --- .../MessageService/plugins/MessageLogger.cc | 83 ++++++++++++------- FWCore/MessageService/plugins/MessageLogger.h | 1 + .../test/unit_test_outputs/u33_all.log | 8 +- 3 files changed, 57 insertions(+), 35 deletions(-) diff --git a/FWCore/MessageService/plugins/MessageLogger.cc b/FWCore/MessageService/plugins/MessageLogger.cc index 717b0a6e0bf5e..b7bc68d2cbc45 100644 --- a/FWCore/MessageService/plugins/MessageLogger.cc +++ b/FWCore/MessageService/plugins/MessageLogger.cc @@ -53,7 +53,7 @@ namespace { "@beginLumi", "@endLumi", "@endRun", - "@kEndProcessBlock", + "@endProcessBlock", "@endJob", "@writeProcessBlock", "@writeRun", @@ -207,11 +207,13 @@ namespace edm { iRegistry.watchPreallocate([this](edm::service::SystemBounds const& iBounds) { //reserve the proper amount of space to record the transition info + constexpr unsigned int maxNumberOfConcurrentProcessBlocks = 1; this->transitionInfoCache_.resize(iBounds.maxNumberOfStreams() + iBounds.maxNumberOfConcurrentLuminosityBlocks() + - iBounds.maxNumberOfConcurrentRuns()); + iBounds.maxNumberOfConcurrentRuns() + maxNumberOfConcurrentProcessBlocks); lumiInfoBegin_ = iBounds.maxNumberOfStreams(); runInfoBegin_ = lumiInfoBegin_ + iBounds.maxNumberOfConcurrentLuminosityBlocks(); + processBlockInfoBegin_ = runInfoBegin_ + iBounds.maxNumberOfConcurrentRuns(); setMaxLoggedErrorsSummaryIndicies(iBounds.maxNumberOfStreams()); }); @@ -337,9 +339,14 @@ namespace edm { establishModule(lumiInfoBegin_ + globalContext->luminosityBlockIndex(), iModContext, s_globalTransitionNames[static_cast(tran)]); - } else { + } else if (tran == GlobalContext::Transition::kBeginRun or tran == GlobalContext::Transition::kEndRun) { establishModule( runInfoBegin_ + globalContext->runIndex(), iModContext, s_globalTransitionNames[static_cast(tran)]); + } else { + assert(tran == GlobalContext::Transition::kBeginProcessBlock || + tran == GlobalContext::Transition::kAccessInputProcessBlock || + tran == GlobalContext::Transition::kEndProcessBlock); + establishModule(processBlockInfoBegin_, iModContext, s_globalTransitionNames[static_cast(tran)]); } } else { auto stream = iModContext.getStreamContext(); @@ -455,9 +462,14 @@ namespace edm { establishModule(lumiInfoBegin_ + globalContext->luminosityBlockIndex(), *previous, s_globalTransitionNames[static_cast(tran)]); - } else { + } else if (tran == GlobalContext::Transition::kBeginRun or tran == GlobalContext::Transition::kEndRun) { establishModule( runInfoBegin_ + globalContext->runIndex(), *previous, s_globalTransitionNames[static_cast(tran)]); + } else { + assert(tran == GlobalContext::Transition::kBeginProcessBlock || + tran == GlobalContext::Transition::kAccessInputProcessBlock || + tran == GlobalContext::Transition::kEndProcessBlock); + establishModule(processBlockInfoBegin_, *previous, s_globalTransitionNames[static_cast(tran)]); } } else { auto stream = previous->getStreamContext(); @@ -617,34 +629,34 @@ namespace edm { //Global - void MessageLogger::preModuleBeginProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) { - ModuleDescription const& desc = *mcc.moduleDescription(); - establishModule(desc, "@beginProcessBlock"); + void MessageLogger::preModuleBeginProcessBlock(GlobalContext const&, ModuleCallingContext const& mod) { + establishModule(processBlockInfoBegin_, + mod, + s_globalTransitionNames[static_cast(GlobalContext::Transition::kBeginProcessBlock)]); } - void MessageLogger::postModuleBeginProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) { - ModuleDescription const& desc = *mcc.moduleDescription(); - unEstablishModule(desc, "After module BeginProcessBlock"); + void MessageLogger::postModuleBeginProcessBlock(GlobalContext const&, ModuleCallingContext const& mod) { + unEstablishModule(mod, "AfterModBeginProcessBlock"); } - void MessageLogger::preModuleAccessInputProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) { - ModuleDescription const& desc = *mcc.moduleDescription(); - establishModule(desc, "@accessInputProcessBlock"); + void MessageLogger::preModuleAccessInputProcessBlock(GlobalContext const&, ModuleCallingContext const& mod) { + establishModule(processBlockInfoBegin_, + mod, + s_globalTransitionNames[static_cast(GlobalContext::Transition::kAccessInputProcessBlock)]); } - void MessageLogger::postModuleAccessInputProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) { - ModuleDescription const& desc = *mcc.moduleDescription(); - unEstablishModule(desc, "After module AccessInputProcessBlock"); + void MessageLogger::postModuleAccessInputProcessBlock(GlobalContext const&, ModuleCallingContext const& mod) { + unEstablishModule(mod, "AfterModAccessInputProcessBlock"); } - void MessageLogger::preModuleEndProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) { - ModuleDescription const& desc = *mcc.moduleDescription(); - establishModule(desc, "@endProcessBlock"); + void MessageLogger::preModuleEndProcessBlock(GlobalContext const&, ModuleCallingContext const& mod) { + establishModule(processBlockInfoBegin_, + mod, + s_globalTransitionNames[static_cast(GlobalContext::Transition::kEndProcessBlock)]); } - void MessageLogger::postModuleEndProcessBlock(GlobalContext const& gc, ModuleCallingContext const& mcc) { - ModuleDescription const& desc = *mcc.moduleDescription(); - unEstablishModule(desc, "After module EndProcessBlock"); + void MessageLogger::postModuleEndProcessBlock(GlobalContext const&, ModuleCallingContext const& mod) { + unEstablishModule(mod, "AfterModEndProcessBlock"); } void MessageLogger::preModuleGlobalBeginRun(GlobalContext const& context, ModuleCallingContext const& mod) { @@ -796,30 +808,39 @@ namespace edm { } void MessageLogger::preBeginProcessBlock(GlobalContext const& gc) { - edm::MessageDrop::instance()->runEvent = "pre-events"; - edm::MessageDrop::instance()->setSinglet("BeginProcessBlock"); + auto& buffer = transitionInfoCache_[processBlockInfoBegin_]; + auto v = fill_buffer(buffer, "pre-events"); + edm::MessageDrop::instance()->runEvent = v; + edm::MessageDrop::instance()->setSinglet("PreBeginProcessBlock"); } void MessageLogger::postBeginProcessBlock(GlobalContext const& gc) { - edm::MessageDrop::instance()->setSinglet("After BeginProcessBlock"); + edm::MessageDrop::instance()->runEvent = "PostBeginProcessBlock"; + edm::MessageDrop::instance()->setSinglet("PostBeginProcessBlock"); } void MessageLogger::preAccessInputProcessBlock(GlobalContext const& gc) { - edm::MessageDrop::instance()->runEvent = "pre-events"; - edm::MessageDrop::instance()->setSinglet("AccessInputProcessBlock"); + auto& buffer = transitionInfoCache_[processBlockInfoBegin_]; + auto v = fill_buffer(buffer, "pre-events"); + edm::MessageDrop::instance()->runEvent = v; + edm::MessageDrop::instance()->setSinglet("PreAccessInputProcessBlock"); } void MessageLogger::postAccessInputProcessBlock(GlobalContext const& gc) { - edm::MessageDrop::instance()->setSinglet("After AccessInputProcessBlock"); + edm::MessageDrop::instance()->runEvent = "PostAccessInputProcessBlock"; + edm::MessageDrop::instance()->setSinglet("PostAccessInputProcessBlock"); } void MessageLogger::preEndProcessBlock(GlobalContext const& gc) { - edm::MessageDrop::instance()->runEvent = "post-events"; - edm::MessageDrop::instance()->setSinglet("EndProcessBlock"); + auto& buffer = transitionInfoCache_[processBlockInfoBegin_]; + auto v = fill_buffer(buffer, "post-events"); + edm::MessageDrop::instance()->runEvent = v; + edm::MessageDrop::instance()->setSinglet("PreEndProcessBlock"); } void MessageLogger::postEndProcessBlock(GlobalContext const& gc) { - edm::MessageDrop::instance()->setSinglet("After EndProcessBlock"); + edm::MessageDrop::instance()->runEvent = "PostEndProcessBlock"; + edm::MessageDrop::instance()->setSinglet("PostEndProcessBlock"); } void MessageLogger::preGlobalBeginRun(GlobalContext const& iContext) // change log 14 diff --git a/FWCore/MessageService/plugins/MessageLogger.h b/FWCore/MessageService/plugins/MessageLogger.h index f4cc573f66b28..70ae7fdb7e440 100644 --- a/FWCore/MessageService/plugins/MessageLogger.h +++ b/FWCore/MessageService/plugins/MessageLogger.h @@ -166,6 +166,7 @@ namespace edm { std::vector> transitionInfoCache_; unsigned int lumiInfoBegin_ = 0; unsigned int runInfoBegin_ = 0; + unsigned int processBlockInfoBegin_ = 0; std::set debugEnabledModules_; std::map suppression_levels_; diff --git a/FWCore/MessageService/test/unit_test_outputs/u33_all.log b/FWCore/MessageService/test/unit_test_outputs/u33_all.log index bff3ce8219516..5a6c2a2d44224 100644 --- a/FWCore/MessageService/test/unit_test_outputs/u33_all.log +++ b/FWCore/MessageService/test/unit_test_outputs/u33_all.log @@ -4,7 +4,7 @@ T1 beginJob warning with identifier 11 event 0 %MSG-w cat_BJ: UTC_V1:ssm_1b@beginJob pre-events T1 beginJob warning with identifier 12 event 0 %MSG -%MSG-e TestMessageLogger: BeginProcessBlock pre-events +%MSG-e TestMessageLogger: PreBeginProcessBlock pre-events test message from TestService::preBeginProcessBlock %MSG %MSG-i cat_BPB: UTC_V1:ssm_1a@beginProcessBlock pre-events @@ -105,7 +105,7 @@ test message from TestService::preGlobalEndLumi %MSG-e TestMessageLogger: PreGlobalEndRun End Run: 1 test message from TestService::preGlobalEndRun %MSG -%MSG-e TestMessageLogger: EndProcessBlock post-events +%MSG-e TestMessageLogger: PreEndProcessBlock post-events test message from TestService::preEndProcessBlock %MSG %MSG-i cat_EPB: UTC_V1:ssm_1a@endProcessBlock post-events @@ -139,8 +139,8 @@ MessageLogger Summary 16 cat_BJ -w UTC_V1:ssm_1b@be 1 1 17 cat_BL -w UTC_V1:ssm_1a@be 1 1 18 cat_BL -w UTC_V1:ssm_1b@be 1 1 - 19 TestMessageLogger -e BeginProcessBloc 1 1 - 20 TestMessageLogger -e EndProcessBlock 1 1 + 19 TestMessageLogger -e PreBeginProcessB 1 1 + 20 TestMessageLogger -e PreEndProcessBlo 1 1 21 TestMessageLogger -e PreGlobalBeginLu 1 1 22 TestMessageLogger -e PreGlobalBeginRu 1 1 23 TestMessageLogger -e PreGlobalEndLumi 1 1