LArSoft  v09_90_00
Liquid Argon Software toolkit - https://larsoft.org/
Tracer_service.cc
Go to the documentation of this file.
1 // vim: set sw=2 expandtab :
2 
14 #include "art/Utilities/Globals.h"
21 #include "fhiclcpp/types/Atom.h"
22 #include "fhiclcpp/types/Name.h"
24 
25 #include <atomic>
26 #include <iostream>
27 #include <string>
28 
29 using namespace std;
30 using namespace std::string_literals;
31 
32 namespace art {
33 
34  class Tracer {
35  public:
36  struct Config {
37  fhicl::Atom<string> indentation{fhicl::Name{"indentation"}, "++"};
38  };
41 
42  private:
43  void log_with_indent(unsigned n, std::string const& message) const;
44 
45  void postBeginJob();
46  void postEndJob();
47 
48  void preBeginRun(Run const& run);
49  void postBeginRun(Run const& run);
50 
51  void preBeginSubRun(SubRun const& subRun);
52  void postBeginSubRun(SubRun const& subRun);
53 
54  void preEvent(Event const& ev, ScheduleContext);
55  void postEvent(Event const& ev, ScheduleContext);
56 
57  void preEndSubRun(SubRunID const& id, Timestamp const& ts);
58  void postEndSubRun(SubRun const& run);
59 
60  void preEndRun(RunID const& id, Timestamp const& ts);
61  void postEndRun(Run const& run);
62 
63  void preModuleConstruction(ModuleDescription const& md);
64  void postModuleConstruction(ModuleDescription const& md);
65 
66  void preModuleBeginJob(ModuleDescription const& md);
67  void postModuleBeginJob(ModuleDescription const& md);
68 
69  void preModuleBeginRun(ModuleContext const& mc);
70  void postModuleBeginRun(ModuleContext const& mc);
71 
72  void preModuleBeginSubRun(ModuleContext const& mc);
73  void postModuleBeginSubRun(ModuleContext const& mc);
74 
75  void preModuleEvent(ModuleContext const& mc);
76  void postModuleEvent(ModuleContext const& mc);
77 
78  void preModuleEndSubRun(ModuleContext const& mc);
79  void postModuleEndSubRun(ModuleContext const& mc);
80 
81  void preModuleEndRun(ModuleContext const& mc);
82  void postModuleEndRun(ModuleContext const& mc);
83 
84  void preModuleEndJob(ModuleDescription const& md);
85  void postModuleEndJob(ModuleDescription const& md);
86 
87  void preSourceEvent(ScheduleContext);
88  void postSourceEvent(Event const&, ScheduleContext);
89 
90  void preSourceSubRun();
91  void postSourceSubRun(SubRun const&);
92 
93  void preSourceRun();
94  void postSourceRun(Run const&);
95 
96  void preOpenFile();
97  void postOpenFile(string const& fn);
98 
99  void preCloseFile();
100  void postCloseFile();
101 
102  void postOpenOutputFile(string const& label);
103  void preCloseOutputFile(string const& label);
104  void postCloseOutputFile(OutputFileInfo const& info);
105 
106  void prePathBeginRun(string const& s);
107  void postPathBeginRun(string const& s, HLTPathStatus const& hlt);
108 
109  void prePathBeginSubRun(string const& s);
110  void postPathBeginSubRun(string const& s, HLTPathStatus const& hlt);
111 
112  void prePathEvent(PathContext const& pc);
113  void postPathEvent(PathContext const& pc, HLTPathStatus const& hlt);
114 
115  void prePathEndSubRun(string const& s);
116  void postPathEndSubRun(string const& s, HLTPathStatus const& hlt);
117 
118  void prePathEndRun(string const& s);
119  void postPathEndRun(string const& s, HLTPathStatus const& hlt);
120 
121  // Member Data
122  private:
123  string const indentation_;
124  std::atomic<unsigned int> depth_{};
125  };
126 
128  : indentation_{config().indentation()}
129  {
130  if (auto const nthreads = Globals::instance()->nthreads(); nthreads != 1) {
131  mf::LogWarning("Tracer") << "Because " << nthreads
132  << " threads have been configured, the tracing "
133  "messages will be interleaved.\n"
134  << "Please configure your job to use one thread "
135  "for a predictable output.";
136  }
137 
138  iRegistry.sPostBeginJob.watch(this, &Tracer::postBeginJob);
139  iRegistry.sPostEndJob.watch(this, &Tracer::postEndJob);
140  iRegistry.sPreModule.watch(this, &Tracer::preModuleEvent);
141  iRegistry.sPostModule.watch(this, &Tracer::postModuleEvent);
142  iRegistry.sPreModuleConstruction.watch(this,
144  iRegistry.sPostModuleConstruction.watch(this,
146  iRegistry.sPreModuleBeginJob.watch(this, &Tracer::preModuleBeginJob);
147  iRegistry.sPostModuleBeginJob.watch(this, &Tracer::postModuleBeginJob);
148  iRegistry.sPreModuleEndJob.watch(this, &Tracer::preModuleEndJob);
149  iRegistry.sPostModuleEndJob.watch(this, &Tracer::postModuleEndJob);
150  iRegistry.sPreModuleBeginRun.watch(this, &Tracer::preModuleBeginRun);
151  iRegistry.sPostModuleBeginRun.watch(this, &Tracer::postModuleBeginRun);
152  iRegistry.sPreModuleEndRun.watch(this, &Tracer::preModuleEndRun);
153  iRegistry.sPostModuleEndRun.watch(this, &Tracer::postModuleEndRun);
154  iRegistry.sPreModuleBeginSubRun.watch(this, &Tracer::preModuleBeginSubRun);
155  iRegistry.sPostModuleBeginSubRun.watch(this,
157  iRegistry.sPreModuleEndSubRun.watch(this, &Tracer::preModuleEndSubRun);
158  iRegistry.sPostModuleEndSubRun.watch(this, &Tracer::postModuleEndSubRun);
159  iRegistry.sPreProcessPath.watch(this, &Tracer::prePathEvent);
160  iRegistry.sPostProcessPath.watch(this, &Tracer::postPathEvent);
161  iRegistry.sPrePathBeginRun.watch(this, &Tracer::prePathBeginRun);
162  iRegistry.sPostPathBeginRun.watch(this, &Tracer::postPathBeginRun);
163  iRegistry.sPrePathEndRun.watch(this, &Tracer::prePathEndRun);
164  iRegistry.sPostPathEndRun.watch(this, &Tracer::postPathEndRun);
165  iRegistry.sPrePathBeginSubRun.watch(this, &Tracer::prePathBeginSubRun);
166  iRegistry.sPostPathBeginSubRun.watch(this, &Tracer::postPathBeginSubRun);
167  iRegistry.sPrePathEndSubRun.watch(this, &Tracer::prePathEndSubRun);
168  iRegistry.sPostPathEndSubRun.watch(this, &Tracer::postPathEndSubRun);
169  iRegistry.sPreProcessEvent.watch(this, &Tracer::preEvent);
170  iRegistry.sPostProcessEvent.watch(this, &Tracer::postEvent);
171  iRegistry.sPreBeginRun.watch(this, &Tracer::preBeginRun);
172  iRegistry.sPostBeginRun.watch(this, &Tracer::postBeginRun);
173  iRegistry.sPreEndRun.watch(this, &Tracer::preEndRun);
174  iRegistry.sPostEndRun.watch(this, &Tracer::postEndRun);
175  iRegistry.sPreBeginSubRun.watch(this, &Tracer::preBeginSubRun);
176  iRegistry.sPostBeginSubRun.watch(this, &Tracer::postBeginSubRun);
177  iRegistry.sPreEndSubRun.watch(this, &Tracer::preEndSubRun);
178  iRegistry.sPostEndSubRun.watch(this, &Tracer::postEndSubRun);
179  iRegistry.sPreSourceEvent.watch(this, &Tracer::preSourceEvent);
180  iRegistry.sPostSourceEvent.watch(this, &Tracer::postSourceEvent);
181  iRegistry.sPreOpenFile.watch(this, &Tracer::preOpenFile);
182  iRegistry.sPostOpenFile.watch(this, &Tracer::postOpenFile);
183  iRegistry.sPreCloseFile.watch(this, &Tracer::preCloseFile);
184  iRegistry.sPostCloseFile.watch(this, &Tracer::postCloseFile);
185  iRegistry.sPostOpenOutputFile.watch(this, &Tracer::postOpenOutputFile);
186  iRegistry.sPreCloseOutputFile.watch(this, &Tracer::preCloseOutputFile);
187  iRegistry.sPostCloseOutputFile.watch(this, &Tracer::postCloseOutputFile);
188  iRegistry.sPreSourceRun.watch(this, &Tracer::preSourceRun);
189  iRegistry.sPostSourceRun.watch(this, &Tracer::postSourceRun);
190  iRegistry.sPreSourceSubRun.watch(this, &Tracer::preSourceSubRun);
191  iRegistry.sPostSourceSubRun.watch(this, &Tracer::postSourceSubRun);
192  }
193 
194  void
195  Tracer::log_with_indent(unsigned n, std::string const& message) const
196  {
197  std::string printout;
198  for (; n != 0u; --n) {
199  printout.append(indentation_);
200  }
201  printout += ' ';
202  printout += message;
203  printout += '\n';
204  std::cout << printout;
205  }
206 
207  void
209  {
210  log_with_indent(1, "Job started");
211  }
212 
213  void
215  {
216  log_with_indent(1, "Job ended");
217  }
218 
219  void
221  {
222  log_with_indent(2, "source event");
223  }
224 
225  void
227  {
228  log_with_indent(2, "finished source event");
229  }
230 
231  void
233  {
234  log_with_indent(2, "source subRun");
235  }
236 
237  void
239  {
240  log_with_indent(2, "finished source subRun");
241  }
242 
243  void
245  {
246  log_with_indent(2, "source run");
247  }
248 
249  void
251  {
252  log_with_indent(2, "finished source run");
253  }
254 
255  void
257  {
258  log_with_indent(2, "open input file");
259  }
260 
261  void
262  Tracer::postOpenFile(string const& fn)
263  {
264  string const displayed_fn{fn.empty() ? "<none>"s : fn};
265  log_with_indent(2, "finished open input file: " + displayed_fn);
266  }
267 
268  void
270  {
271  log_with_indent(2, "close input file");
272  }
273 
274  void
276  {
277  log_with_indent(2, "finished close input file");
278  }
279 
280  void
281  Tracer::postOpenOutputFile(string const& label)
282  {
283  log_with_indent(2, "opened output file from " + label);
284  }
285 
286  void
287  Tracer::preCloseOutputFile(string const& label)
288  {
289  log_with_indent(2, "close output file from " + label);
290  }
291 
292  void
294  {
295  string const fn{info.fileName().empty() ? "<none>"s : info.fileName()};
297  2, "finished close output file " + fn + " from " + info.moduleLabel());
298  }
299 
300  void
302  {
303  depth_ = 0;
304  std::ostringstream msg;
305  msg << "processing event: " << ev.id() << " time: " << ev.time().value();
306  log_with_indent(2, msg.str());
307  }
308 
309  void
311  {
312  log_with_indent(2, "finished event");
313  }
314 
315  void
317  {
318  log_with_indent(3, "processing path for event: " + pc.pathName());
319  }
320 
321  void
323  {
324  log_with_indent(3, "finished path for event: " + pc.pathName());
325  }
326 
327  void
329  {
330  ++depth_;
331  log_with_indent(3 + depth_, "module for event: " + mc.moduleLabel());
332  }
333 
334  void
336  {
337  --depth_;
338  log_with_indent(4 + depth_, "finished for event: " + mc.moduleLabel());
339  }
340 
341  void
343  {
344  depth_ = 0;
345  std::ostringstream msg;
346  msg << "processing begin run: " << run.id()
347  << " time: " << run.beginTime().value();
348  log_with_indent(2, msg.str());
349  }
350 
351  void
353  {
354  log_with_indent(2, "finished begin run");
355  }
356 
357  void
358  Tracer::prePathBeginRun(string const& iName)
359  {
360  log_with_indent(3, "processing path for begin run: " + iName);
361  }
362 
363  void
364  Tracer::postPathBeginRun(string const& /*iName*/, HLTPathStatus const&)
365  {
366  log_with_indent(3, "finished path for begin run");
367  }
368 
369  void
371  {
372  ++depth_;
373  log_with_indent(3 + depth_, "module for begin run: " + mc.moduleLabel());
374  }
375 
376  void
378  {
379  --depth_;
380  log_with_indent(4 + depth_, "finished for begin run: " + mc.moduleLabel());
381  }
382 
383  void
384  art::Tracer::preEndRun(RunID const& iID, Timestamp const& iTime)
385  {
386  depth_ = 0;
387  std::ostringstream msg;
388  msg << "processing end run: " << iID << " time: " << iTime.value();
389  log_with_indent(2, msg.str());
390  }
391 
392  void
394  {
395  log_with_indent(2, "finished end run");
396  }
397 
398  void
399  Tracer::prePathEndRun(string const& iName)
400  {
401  log_with_indent(3, "processing path for end run: " + iName);
402  }
403 
404  void
405  Tracer::postPathEndRun(string const& /*iName*/, HLTPathStatus const&)
406  {
407  log_with_indent(3, "finished path for end run");
408  }
409 
410  void
412  {
413  ++depth_;
414  log_with_indent(3 + depth_, "module for end run: " + mc.moduleLabel());
415  }
416 
417  void
419  {
420  --depth_;
421  log_with_indent(4 + depth_, "finished for end run: " + mc.moduleLabel());
422  }
423 
424  void
426  {
427  depth_ = 0;
428  std::ostringstream msg;
429  msg << "processing begin subRun: " << subRun.id()
430  << " time: " << subRun.beginTime().value();
431  log_with_indent(2, msg.str());
432  }
433 
434  void
436  {
437  log_with_indent(2, "finished begin subRun");
438  }
439 
440  void
441  Tracer::prePathBeginSubRun(string const& iName)
442  {
443  log_with_indent(3, "processing path for begin subRun: " + iName);
444  }
445 
446  void
447  Tracer::postPathBeginSubRun(string const& /*iName*/, HLTPathStatus const&)
448  {
449  log_with_indent(3, "finished path for begin subRun");
450  }
451 
452  void
454  {
455  ++depth_;
456  log_with_indent(3 + depth_, "module for begin subRun: " + mc.moduleLabel());
457  }
458 
459  void
461  {
462  --depth_;
463  log_with_indent(4, "finished for begin subRun: " + mc.moduleLabel());
464  }
465 
466  void
467  art::Tracer::preEndSubRun(SubRunID const& iID, Timestamp const& iTime)
468  {
469  depth_ = 0;
470  std::ostringstream msg;
471  msg << "processing end subRun: " << iID << " time: " << iTime.value();
472  log_with_indent(2, msg.str());
473  }
474 
475  void
477  {
478  log_with_indent(2, "finished end subRun");
479  }
480 
481  void
482  Tracer::prePathEndSubRun(string const& iName)
483  {
484  log_with_indent(3, "processing path for end subRun: " + iName);
485  }
486 
487  void
488  Tracer::postPathEndSubRun(string const& /*iName*/, HLTPathStatus const&)
489  {
490  log_with_indent(3, "finished path for end subRun");
491  }
492 
493  void
495  {
496  ++depth_;
497  log_with_indent(3 + depth_, "module for end subRun: " + mc.moduleLabel());
498  }
499 
500  void
502  {
503  --depth_;
504  log_with_indent(4 + depth_, "finished for end subRun: " + mc.moduleLabel());
505  }
506 
507  void
509  {
510  log_with_indent(1, "constructing module: " + md.moduleLabel());
511  }
512 
513  void
515  {
516  log_with_indent(1, "construction finished: " + md.moduleLabel());
517  }
518 
519  void
521  {
522  log_with_indent(1, "beginJob module: " + md.moduleLabel());
523  }
524 
525  void
527  {
528  log_with_indent(1, "beginJob finished: " + md.moduleLabel());
529  }
530 
531  void
533  {
534  log_with_indent(1, "endJob module: " + md.moduleLabel());
535  }
536 
537  void
539  {
540  log_with_indent(1, "endJob finished: " + md.moduleLabel());
541  }
542 
543 } // namespace art
544 
void preModuleEndSubRun(ModuleContext const &mc)
void preModuleEndRun(ModuleContext const &mc)
void log_with_indent(unsigned n, std::string const &message) const
void postSourceSubRun(SubRun const &)
void postSourceRun(Run const &)
void preCloseOutputFile(string const &label)
void preModuleConstruction(ModuleDescription const &md)
RunID id() const
Definition: Run.cc:21
void postModuleConstruction(ModuleDescription const &md)
void preModuleBeginSubRun(ModuleContext const &mc)
void postPathBeginSubRun(string const &s, HLTPathStatus const &hlt)
std::string const & moduleLabel() const
void preEvent(Event const &ev, ScheduleContext)
void message(RunManager *runmanager)
Definition: ts_scorers.cc:74
void preEndRun(RunID const &id, Timestamp const &ts)
void postPathEndSubRun(string const &s, HLTPathStatus const &hlt)
STL namespace.
void postModuleBeginJob(ModuleDescription const &md)
void postModuleBeginRun(ModuleContext const &mc)
void postModuleBeginSubRun(ModuleContext const &mc)
void preBeginRun(Run const &run)
std::atomic< unsigned int > depth_
std::string const & moduleLabel() const
constexpr TimeValue_t value() const
Definition: Timestamp.h:23
Definition: Run.h:37
void preSourceEvent(ScheduleContext)
void preBeginSubRun(SubRun const &subRun)
void postEndSubRun(SubRun const &run)
Tracer(Parameters const &, ActivityRegistry &)
void preModuleBeginRun(ModuleContext const &mc)
auto const & pathName() const
Definition: PathContext.h:63
std::string const & fileName() const
void preModuleEvent(ModuleContext const &mc)
void postModuleEndRun(ModuleContext const &mc)
#define DECLARE_ART_SERVICE(svc, scope)
void postBeginRun(Run const &run)
void preModuleEndJob(ModuleDescription const &md)
void postModuleEvent(ModuleContext const &mc)
void preCloseFile()
void postOpenFile(string const &fn)
void postEndRun(Run const &run)
void postEvent(Event const &ev, ScheduleContext)
void prePathEndSubRun(string const &s)
void postModuleEndSubRun(ModuleContext const &mc)
void prePathBeginRun(string const &s)
void prePathEndRun(string const &s)
void postPathEndRun(string const &s, HLTPathStatus const &hlt)
#define DEFINE_ART_SERVICE(svc)
void postOpenOutputFile(string const &label)
void postModuleEndJob(ModuleDescription const &md)
void preModuleBeginJob(ModuleDescription const &md)
void postBeginJob()
void preSourceRun()
SubRunID id() const
Definition: SubRun.cc:25
MaybeLogger_< ELseverityLevel::ELsev_warning, false > LogWarning
void preSourceSubRun()
auto const & moduleLabel() const
Definition: ModuleContext.h:43
Timestamp time() const
Definition: Event.cc:47
Definition: MVAAlg.h:12
Char_t n[5]
Timestamp const & beginTime() const
Definition: Run.cc:33
void postCloseFile()
static Globals * instance()
Definition: Globals.cc:17
void preEndSubRun(SubRunID const &id, Timestamp const &ts)
Timestamp const & beginTime() const
Definition: SubRun.cc:43
void prePathEvent(PathContext const &pc)
void prePathBeginSubRun(string const &s)
void preOpenFile()
void postCloseOutputFile(OutputFileInfo const &info)
EventID id() const
Definition: Event.cc:23
void postPathEvent(PathContext const &pc, HLTPathStatus const &hlt)
string const indentation_
void postBeginSubRun(SubRun const &subRun)
void postSourceEvent(Event const &, ScheduleContext)
void postPathBeginRun(string const &s, HLTPathStatus const &hlt)