Warning, /FWCore/MessageService/doc/flush-and-end.txt is written in an unsupported language. File is not indexed.
0001 Actions and Circumstances Relevant to Incomplete Log Problem
0002 ------------------------------------------------------------
0003
0004 The Problem:
0005 ------------
0006 (Document in progress)
0007
0008
0009 In about 10% of the production jobs, some of the LogInfo messages issued at the
0010 end involving branch information are failing to emerge. This necessitates
0011 re-running the job, for a net loss of up to 10% of the work done.
0012
0013 The problem "can't be happening" based on what the logger does, but it is. Dave
0014 Evans worte a stand-along program to issue huge bunches of messages to try to
0015 provoke a repeatable version of the bad behavior, which we could hope to debug,
0016 but could not get it to happen.
0017
0018
0019 What the Current Code Does:
0020 ---------------------------
0021
0022 (This is as of 10/1/07)
0023
0024 All the various flushes (stream and queue), thread joins, and end-sequence
0025 actions are described here:
0026
0027 Very early in main() of cmsRun, theMessageServicePresence is instantiated.
0028 The ctor of MessageServicePresence instantiates scribe, which is a
0029 boost::thread, instructing it to execute runMessageLoggerScribe.
0030
0031 Just after that, the jobReport is created on the heap and a unique_ptr to
0032 JobReport is given to ServiceRegistry, retaining jobReportToken.
0033
0034 Next, the services are pushed onto defaultServices, with MessageLogger first.
0035 Then the forcedServises are created; JobReport is the first of those.
0036
0037 Then black magic happens leading to the CFG command to the logger. It
0038 happens in the statement
0039 std::unique_ptr<edm::EventProcessor>
0040 procP(new
0041 edm::EventProcessor(processDesc, jobReportToken,
0042 edm::serviceregistry::kTokenOverrides));
0043 which instantiates a new edm::EventProcessor:
0044 The ctor of EventProcessor calls init().
0045 EventPrecessor::init() calls ServiceRegistry::createSet to create the services.
0046 ServiceRegistry::createSet instantiates a new ServicesManager, passing in
0047 (among other things) a vector of ParameterSet.
0048 ServicesManager has filled a list of "makers", done some complicated
0049 bookkeeping, and called CreateServices().
0050 In CreateServices, itmaker invokes add on its second part. The loop this is in
0051 is controlled by requestedCreationOrder, which has typeinfo for
0052 edm::service::MessageLogger first (InitRootHandlers is second).
0053 ServicesManager::MakerHolder::add calls maker_-> make
0054 ServiceMaker<T> with T = edm::service::MessageLogger calls pService
0055 passsing in maker.make(iPS, iAR), which directly calls AllArgsMaker<T>::make
0056 AllArgsMaker<T>::make(const edm::ParameterSet& iPS,edm::ActivityRegistry& iAR)
0057 with T = edm::service::MessageLogger creates a new MessageLogger
0058 ctor of MessageLogger in main thread issues the following commands on the
0059 MessageLoggerQ: MLqJOB, MLqMOD, MLqCFG
0060
0061 Now the job is going in earnest. When the dtor of any of the various
0062 Log objects happens, a MLqLOG command is issued. The processing goes
0063 through the log() method, which is encased in a try/catch. The first of
0064 such messages will print to cerr, including the words "will no longer be
0065 processing." ( After the first, it will be in purge mode, and others will not
0066 emerge.)
0067
0068
0069
0070
0071
0072
0073
0074
0075
0076
0077
0078
0079 JobReport service terminates before MessageServicePresence goes away - evidence
0080 is the fact that the <END> message from the framework job report does come out.
0081
0082
0083
0084
0085 would freeze if queue is full
