LArSoft  v09_90_00
Liquid Argon Software toolkit - https://larsoft.org/
MessageLogger.cc
Go to the documentation of this file.
2 // vim: set sw=2 expandtab :
3 
4 #include "cetlib/BasicPluginFactory.h"
5 #include "cetlib/HorizontalRule.h"
6 #include "cetlib/bold_fontify.h"
7 #include "cetlib/plugin_libpath.h"
17 
18 #include <atomic>
19 #include <cstdlib>
20 #include <iostream>
21 #include <map>
22 #include <memory>
23 #include <mutex>
24 #include <sstream>
25 #include <string>
26 #include <type_traits>
27 #include <utility>
28 #include <vector>
29 
30 #include <arpa/inet.h>
31 #include <ifaddrs.h>
32 #include <netdb.h>
33 #include <netinet/in.h>
34 
35 using namespace std;
36 using namespace std::string_literals;
37 
38 namespace {
39  enum class destination_kind { ordinary, statistics };
40 }
41 
42 namespace mf {
43 
44  namespace {
45 
46  cet::search_path
47  getPluginPath()
48  {
49  if (getenv("MF_PLUGIN_PATH") != nullptr) {
50  return cet::search_path{"MF_PLUGIN_PATH"};
51  }
52  return cet::search_path{cet::plugin_libpath(), std::nothrow};
53  }
54 
55  atomic<bool> isStarted{false};
56  map<string const, unique_ptr<service::ELdestination>> destinations_;
57  bool cleanSlateConfiguration_{true};
58  atomic<bool> purgeMode_{false};
59  atomic<int> count_{0};
60  std::recursive_mutex msgMutex_{};
61  string hostname_;
62  string hostaddr_;
63  string application_;
64  long pid_{};
65 
66  // Any text you want. It goes into the message header in the module
67  // position.
68  thread_local string module_ = "Early";
69 
70  // Kind of pointless, arbitrarily set to an alternate spelling of
71  // the phase, or the {run|subrun|event} number by art::MFStatusUpdater.
72  // FIXME: The statistics gatherer attempts to parse this!
73  thread_local string iteration_ = "pre-events";
74 
75  int
76  initGlobalVars(string const& applicationName = "")
77  {
78  char hostname[1024] = {0};
79  hostname_ =
80  (gethostname(hostname, 1023) == 0) ? hostname : "Unknown Host";
81  hostent* host = nullptr;
82  host = gethostbyname(hostname);
83  if (host != nullptr) {
84  // Host lookup succeeded.
85  char* ip = inet_ntoa(*(struct in_addr*)host->h_addr);
86  hostaddr_ = ip;
87  } else {
88  // Loop over all network interfaces and use the first non-loopback
89  // address found.
90  ifaddrs* ifAddrStruct = nullptr;
91  if (getifaddrs(&ifAddrStruct)) {
92  // Failed, use the loopback address.
93  hostaddr_ = "127.0.0.1";
94  } else {
95  // Loop over all interfaces.
96  for (ifaddrs* ifa = ifAddrStruct; ifa != nullptr;
97  ifa = ifa->ifa_next) {
98  if (ifa->ifa_addr->sa_family == AF_INET) {
99  // This interface has a valid IPv4 address.
100  void* tmpAddrPtr = &((sockaddr_in*)ifa->ifa_addr)->sin_addr;
101  char addressBuffer[INET_ADDRSTRLEN];
102  inet_ntop(AF_INET, tmpAddrPtr, addressBuffer, INET_ADDRSTRLEN);
103  hostaddr_ = addressBuffer;
104  } else if (ifa->ifa_addr->sa_family == AF_INET6) {
105  // This interface has a valid IPv6 address.
106  void* tmpAddrPtr = &((sockaddr_in6*)ifa->ifa_addr)->sin6_addr;
107  char addressBuffer[INET6_ADDRSTRLEN];
108  inet_ntop(AF_INET6, tmpAddrPtr, addressBuffer, INET6_ADDRSTRLEN);
109  hostaddr_ = addressBuffer;
110  }
111  // Use the address if it is not a loopback address.
112  if (!empty(hostaddr_) && hostaddr_.compare("127.0.0.1") &&
113  hostaddr_.compare("::1")) {
114  break;
115  }
116  }
117  if (empty(hostaddr_)) {
118  // Failed to find anything, use the loopback address.
119  hostaddr_ = "127.0.0.1";
120  }
121  }
122  }
123  if (!empty(applicationName)) {
124  application_ = applicationName;
125  } else {
126  // get process name from '/proc/pid/cmdline'
127  stringstream ss;
128  ss << "//proc//" << pid_ << "//cmdline";
129  ifstream procfile{ss.str().c_str()};
130  string procinfo;
131  if (procfile.is_open()) {
132  // FIXME: This can fail with ERETRY!
133  procfile >> procinfo;
134  procfile.close();
135  }
136  auto end = procinfo.find('\0');
137  auto start = procinfo.find_last_of('/', end);
138  application_ = procinfo.substr(start + 1, end - start - 1);
139  }
140  pid_ = static_cast<long>(getpid());
141  return 0;
142  }
143 
144  // FIXME: Do not want to read from /proc/pid/cmdline if we do not have to!
145  // static int globalsInitializer = initGlobalVars();
146 
147  unique_ptr<service::ELdestination>
148  makePlugin_(cet::BasicPluginFactory& plugin_factory,
149  string const& libspec,
150  string const& psetname,
151  fhicl::ParameterSet const& pset)
152  {
153  unique_ptr<service::ELdestination> result;
154  try {
155  auto const pluginType = plugin_factory.pluginType(libspec);
156  if (pluginType ==
158  result =
159  plugin_factory.makePlugin<unique_ptr<service::ELdestination>>(
160  libspec, psetname, pset);
161  } else {
162  throw Exception(errors::Configuration, "MessageLoggerScribe: ")
163  << "unrecognized plugin type " << pluginType << "for plugin "
164  << libspec << ".\n";
165  }
166  }
167  catch (cet::exception const& e) {
168  throw Exception(errors::Configuration, "MessageLoggerScribe: ", e)
169  << "Exception caught while processing plugin spec.\n";
170  }
171  return result;
172  }
173 
174  string const default_destination_config_string = " type: cerr"
175  " categories: {"
176  " default: {"
177  " limit: -1"
178  " }"
179  " }"s;
181  default_destination_config()
182  {
183  return fhicl::ParameterSet::make(default_destination_config_string);
184  }
185 
187  default_destination_set_config()
188  {
189  string const config{"cerr: { "s + default_destination_config_string +
190  " }"s};
191  return fhicl::ParameterSet::make(config);
192  }
193 
194  void
195  sendMsgToDests(
196  ErrorObj& msg,
197  map<string const, unique_ptr<service::ELdestination>>& destinations)
198  {
199  if (empty(msg.xid().hostname())) {
200  msg.setHostName(GetHostName());
201  }
202  if (empty(msg.xid().hostaddr())) {
203  msg.setHostAddr(GetHostAddr());
204  }
205  if (empty(msg.xid().application())) {
207  }
208  if (msg.xid().pid() == 0) {
209  msg.setPID(GetPid());
210  }
211  if (empty(destinations)) {
212  cerr << "\nERROR LOGGED WITHOUT DESTINATION!\nAttaching destination "
213  "\"cerr\" by default\n\n";
214  destinations.emplace(
215  "cerr",
216  make_unique<service::ELostreamOutput>(
217  default_destination_set_config(), cet::ostream_handle{cerr}));
218  }
219  for (auto& destid_and_destination : destinations) {
220  destid_and_destination.second->log(msg);
221  }
222  }
223 
224  void
225  makeDestinations(fhicl::ParameterSet const& dests,
226  cet::BasicPluginFactory& plugin_factory,
227  destination_kind const configuration)
228  {
229  set<string> ids;
230  vector<string> config_errors;
231  for (auto const& psetname : dests.get_pset_names()) {
232  auto dest_pset = dests.get<fhicl::ParameterSet>(psetname);
233  if (dest_pset.is_empty()) {
234  dest_pset = default_destination_config();
235  }
236  // Grab the destination type and filename.
237  string dest_type{};
238  if (!dest_pset.get_if_present("type", dest_type)) {
240  << "No 'type' specified for destination '" << psetname << "'.\n";
241  }
242  if (configuration == destination_kind::statistics) {
243  if ((dest_type != "cout"s) && (dest_type != "cerr"s) &&
244  (dest_type != "file"s)) {
246  << "\n"
247  << "Unsupported type [ " << dest_type
248  << " ] chosen for statistics printout.\n"
249  << "Must choose ostream type: \"cout\", \"cerr\", or \"file\""
250  << "\n";
251  }
252  }
253  string outputId{dest_type};
254  if ((dest_type != "cout"s) && (dest_type != "cerr"s) &&
255  (dest_type != "syslog"s)) {
256  outputId += ":" + dest_pset.get<string>("filename", psetname);
257  }
258  if (!ids.emplace(outputId).second) {
259  // We have a duplicate.
260  if (configuration == destination_kind::statistics) {
262  << " Output identifier: \"" << outputId << "\""
263  << " already specified within ordinary/statistics block in FHiCL "
264  "file"
265  << "\n";
266  }
267  }
268  auto iter_id_dest = destinations_.find(outputId);
269  if (iter_id_dest != destinations_.end()) {
270  constexpr cet::HorizontalRule rule{76};
271  string const hrule{'\n' + rule('=') + '\n'};
272  ostringstream except_msg;
273  except_msg << hrule << "\n Duplicate name for a ";
274  if (configuration == destination_kind::ordinary) {
275  except_msg << "MessageLogger";
276  } else {
277  except_msg << "MessageLogger Statistics";
278  }
279  except_msg << " destination: \"" << outputId << '"';
280  ostringstream orig_config_msg;
281  orig_config_msg
282  << "\n Only original configuration instructions are used. \n"
283  << hrule;
284  if (cleanSlateConfiguration_) {
285  LogError("duplicateDestination")
286  << except_msg.str() << orig_config_msg.str();
287  } else {
288  LogWarning("duplicateDestination")
289  << except_msg.str() << orig_config_msg.str();
290  }
291  continue;
292  }
293  string const& libspec = dest_type;
294  try {
295  destinations_[outputId] =
296  makePlugin_(plugin_factory, libspec, psetname, dest_pset);
297  }
298  catch (fhicl::detail::validationException const& e) {
299  string msg{"Configuration error for destination: " +
300  cet::bold_fontify(psetname) + "\n\n"};
301  msg += e.what();
302  config_errors.push_back(std::move(msg));
303  }
304  }
305  if (!empty(config_errors)) {
306  string msg{"\nThe following messagefacility destinations have "
307  "configuration errors:\n\n"};
308  constexpr cet::HorizontalRule rule{60};
309  msg += rule('=');
310  msg += "\n\n";
311  auto start = cbegin(config_errors);
312  msg += *start;
313  ++start;
314  for (auto it = start, e = cend(config_errors); it != e; ++it) {
315  msg += rule('-');
316  msg += "\n\n";
317  msg += *it;
318  }
319  msg += rule('=');
320  msg += "\n\n";
321  throw Exception(errors::Configuration) << msg;
322  }
323  }
324 
325  void
326  configure(MFDestinationConfig::Config const& config,
327  cet::BasicPluginFactory& pluginFactory,
328  cet::BasicPluginFactory& pluginStatsFactory)
329  {
330  if (destinations_.size() > 1) {
331  LogWarning("multiLogConfig")
332  << "The message logger has been configured multiple times";
333  cleanSlateConfiguration_ = false;
334  }
335  fhicl::ParameterSet dest_psets;
336  fhicl::ParameterSet ordinaryDests;
337  if (!config.destinations.get_if_present(dest_psets)) {
338  dest_psets = default_destination_set_config();
339  }
340  ordinaryDests = dest_psets;
341  ordinaryDests.erase("statistics");
342  // Dial down the early destination once the ordinary destinations are
343  // filled.
344  destinations_["cerr_early"s]->setThreshold(ELhighestSeverity);
345  fhicl::ParameterSet default_statistics_config;
346  if (ordinaryDests.is_empty()) {
347  string const default_config{"file_stats: {\n"
348  " type: file\n"
349  " filename: \"err.log\"\n"
350  " threshold: WARNING\n"
351  "}\n"};
352  default_statistics_config = fhicl::ParameterSet::make(default_config);
353  }
354  makeDestinations(ordinaryDests, pluginFactory, destination_kind::ordinary);
355  auto statDests = dest_psets.get<fhicl::ParameterSet>(
356  "statistics", default_statistics_config);
357  makeDestinations(statDests, pluginStatsFactory, destination_kind::statistics);
358  }
359 
360  void
361  logMessage(ErrorObj* msg)
362  {
363  if (purgeMode_) {
364  // We are dropping all messages due to an earlier exception.
365  delete msg;
366  return;
367  }
368  std::lock_guard sentry{msgMutex_};
369  // Ok, no other thread active, process the current message.
370  try {
371  unique_ptr<ErrorObj> msgHolder{msg};
372  msg->setReactedTo(false);
373  sendMsgToDests(*msg, destinations_);
374  }
375  catch (cet::exception const& e) {
376  ++count_;
377  cerr << "MessageLoggerScribe caught " << count_
378  << " cet::exceptions, text = \n"
379  << e.what() << "\n";
380  if (count_ > 25) {
381  cerr << "MessageLogger will no longer be processing messages due to "
382  "errors (entering purge mode).\n";
383  purgeMode_ = true;
384  }
385  }
386  catch (...) {
387  cerr << "MessageLoggerScribe caught an unknown exception and will no "
388  "longer be processing messages. (entering purge mode)\n";
389  purgeMode_ = true;
390  }
391  }
392 
393  void
394  summarize()
395  try {
396  for (auto& destid_and_dest : destinations_) {
397  auto& dest = *destid_and_dest.second;
398  dest.summary();
399  }
400  }
401  catch (cet::exception const& e) {
402  cerr << "MessageLoggerScribe caught exception during summarize:\n"
403  << e.what() << "\n";
404  }
405  catch (...) {
406  cerr << "MessageLoggerScribe caught unknown exception type during "
407  "summarize. (Ignored)\n";
408  }
409 
410  } // unnamed namespace
411 
412  // Note: Safe to call from multiple threads.
413  bool
415  {
416  return isStarted.load();
417  }
418 
419  // Note: Safe to call from multiple threads.
420  void
422  {
423  if (isStarted.load()) {
424  logMessage(msg);
425  return;
426  }
427  if (msg->is_verbatim()) {
428  ostringstream buf;
429  buf << msg->fullText() << '\n';
430  cerr << buf.str();
431  } else {
432  ostringstream buf;
433  buf << "%MSG" << msg->xid().severity().getSymbol() << ' '
434  << msg->xid().id() << msg->idOverflow() << ": \n"
435  << msg->fullText() << "\n"
436  << "%MSG\n";
437  cerr << buf.str();
438  }
439  delete msg;
440  }
441 
442  // Note: Call this from single-threaded mode only!
443  void
445  {
446  if (isStarted.load()) {
447  summarize();
448  }
449  }
450 
451  // Note: Obsolete! Remove when user code migrated.
452  void
454  {}
455 
456  // Note: Call this from single-threaded mode only!
457  void
459  string const& applicationName)
460  {
461  if (isStarted.load()) {
462  return;
463  }
464 
465  cet::BasicPluginFactory pluginFactory{getPluginPath(), "mfPlugin"};
466  cet::BasicPluginFactory pluginStatsFactory{getPluginPath(),
467  "mfStatsPlugin"};
468 
469  // FIXME: We should not have to call StartMessageFacility() to get these
470  // initialized!
471  initGlobalVars(applicationName);
472  try {
473  destinations_["cerr_early"s] = makePlugin_(
474  pluginFactory, "cerr", "cerr_early", default_destination_config());
475  }
476  catch (fhicl::detail::validationException const& e) {
477  string msg{"\nConfiguration error for destination: " +
478  cet::bold_fontify("cerr_early") + "\n\n"};
479  msg += e.what();
480  throw Exception(errors::Configuration) << msg;
481  }
482  try {
483  // Note: We make all the destinations here.
484  configure(
486  MFConfig::Parameters{pset}().destinations()},
487  pluginFactory,
488  pluginStatsFactory);
489  }
490  catch (Exception const& ex) {
491  // FIXME: Hardly seems necessary to rethrow just to change the message to
492  // say it was during configure!
494  "Exception from MessageLoggerScribe::configure",
495  ex);
496  }
497  isStarted.store(true);
498  }
499 
500  // Note: Call this from single-threaded mode only!
501  void
503  {
504  isStarted.store(false);
505  // FIXME: The finish() call in all known uses does nothing, the destination
506  // dtor can probably handle this, remove!
507  for (auto& category_and_destination : destinations_) {
508  category_and_destination.second->finish();
509  }
510  }
511 
512  // Note: Call this from single-threaded mode only!
513  void
514  SetApplicationName(string const& applicationName)
515  {
516  application_ = applicationName;
517  }
518 
519  // Note: Call this from single-threaded mode only!
520  void
521  SetHostName(string const& hostname)
522  {
523  hostname_ = hostname;
524  }
525 
526  // Note: Call this from single-threaded mode only!
527  void
528  SetHostAddr(string const& hostaddr)
529  {
530  hostaddr_ = hostaddr;
531  }
532 
533  // Note: Call this from single-threaded mode only!
534  void
535  SetPid(long const pid)
536  {
537  pid_ = pid;
538  }
539 
540  // Note: Call this from single-threaded mode only!
541  string const&
543  {
544  return application_;
545  }
546 
547  // Note: Call this from single-threaded mode only!
548  string const&
550  {
551  return hostname_;
552  }
553 
554  // Note: Call this from single-threaded mode only!
555  string const&
557  {
558  return hostaddr_;
559  }
560 
561  // Note: Call this from single-threaded mode only!
562  long
564  {
565  return pid_;
566  }
567 
568  // Phase or {run|subrun|event} number.
569  // Note: Obsolete! Remove when user code migrated.
570  // Note: This is thread specific and thread safe.
571  void
572  SetContextIteration(string const& val)
573  {
574  iteration_ = val;
575  }
576 
577  // Phase or {run|subrun|event} number.
578  // Note: This is thread specific and thread safe.
579  void
580  SetIteration(string const& val)
581  {
582  iteration_ = val;
583  }
584 
585  string const&
587  {
588  return iteration_;
589  }
590 
591  // Note: Obsolete! Remove when user code migrated.
592  // Note: This is thread specific and thread safe.
593  void
594  SetContextSinglet(string const& val)
595  {
596  module_ = val;
597  }
598 
599  // Note: This is thread specific and thread safe.
600  void
601  SetModuleName(string const& val)
602  {
603  module_ = val;
604  }
605 
606  string const&
608  {
609  return module_;
610  }
611 
612  // Note: Call this from single-threaded mode only!
613  // FIXME: This does not give the same answer as before because it is no longer
614  // per-module!
615  // Note: Obsolete! Remove when user code migrated.
616  bool
618  {
619  return false;
620  }
621 
622  // Note: Call this from single-threaded mode only!
623  // FIXME: This does not give the same answer as before because it is no longer
624  // per-module!
625  // Note: Obsolete! Remove when user code migrated.
626  bool
628  {
629  return true;
630  }
631 
632  // Note: Call this from single-threaded mode only!
633  // FIXME: This does not give the same answer as before because it is no longer
634  // per-module!
635  // Note: Obsolete! Remove when user code migrated.
636  bool
638  {
639  return true;
640  }
641 
642  // This static global will be destroyed before any other
643  // file-local or global variables when this dll is unloaded
644  // (because it is the last in the file), and will take care
645  // of cleanup if the user forgot to call EndMessageFacility().
646  static struct FinalShutdown {
648  {
649  if (isStarted.load()) {
651  }
652  }
653  } ensureShutdown;
654 
655 } // namespace mf
fhicl::OptionalDelegatedParameter destinations
Definition: MFConfig.h:18
ELseverityLevel severity() const
Definition: ELextendedID.cc:33
void SetIteration(string const &val)
std::optional< T > get_if_present() const
void SetHostAddr(string const &hostaddr)
decltype(auto) constexpr cend(T &&obj)
ADL-aware version of std::cend.
Definition: StdUtils.h:93
void EndMessageFacility()
static ParameterSet make(intermediate_table const &tbl)
Definition: ParameterSet.cc:68
std::string const & application() const
Definition: ELextendedID.cc:63
virtual void setPID(long)
Definition: ErrorObj.cc:201
string const & GetModuleName()
STL namespace.
destination_kind
static struct mf::FinalShutdown ensureShutdown
MaybeLogger_< ELseverityLevel::ELsev_error, false > LogError
ELslProxy< ELhighestSeverityGen > constexpr ELhighestSeverity
void FlushMessageLog()
virtual void setHostName(std::string const &)
Definition: ErrorObj.cc:183
void SetContextIteration(string const &val)
bool is_verbatim() const
Definition: ErrorObj.cc:91
decltype(auto) constexpr end(T &&obj)
ADL-aware version of std::end.
Definition: StdUtils.h:77
std::string const & idOverflow() const
Definition: ErrorObj.cc:67
bool isMessageProcessingSetUp()
std::vector< std::string > get_pset_names() const
void StartMessageFacility(fhicl::ParameterSet const &pset, string const &applicationName)
bool isWarningEnabled()
std::string const & hostaddr() const
Definition: ELextendedID.cc:57
bool isInfoEnabled()
ELextendedID const & xid() const
Definition: ErrorObj.cc:61
cet::coded_exception< errors::error, detail::translate > Exception
Definition: exception.h:17
T get(std::string const &key) const
Definition: ParameterSet.h:314
bool isDebugEnabled()
virtual void setHostAddr(std::string const &)
Definition: ErrorObj.cc:189
std::string const & id() const
Definition: ELextendedID.cc:27
std::string fullText() const
Definition: ErrorObj.cc:110
virtual void setApplication(std::string const &)
Definition: ErrorObj.cc:195
double value
Definition: spectrum.C:18
void LogStatistics()
void SetHostName(string const &hostname)
cet::coded_exception< errors::ErrorCodes, ExceptionDetail::translate > Exception
Definition: Exception.h:66
string const & GetHostName()
bool is_empty() const
char const * what() const noexcept override
string const & GetIteration()
MaybeLogger_< ELseverityLevel::ELsev_warning, false > LogWarning
void SetContextSinglet(string const &val)
decltype(auto) constexpr cbegin(T &&obj)
ADL-aware version of std::cbegin.
Definition: StdUtils.h:85
virtual void setReactedTo(bool)
Definition: ErrorObj.cc:177
bool erase(std::string const &key)
void LogErrorObj(ErrorObj *msg)
long pid() const
Definition: ELextendedID.cc:69
Float_t e
Definition: plot.C:35
void SetModuleName(string const &val)
void SetApplicationName(string const &applicationName)
std::string const & hostname() const
Definition: ELextendedID.cc:51
void SetPid(long const pid)
cet::coded_exception< error, detail::translate > exception
Definition: exception.h:33
decltype(auto) constexpr empty(T &&obj)
ADL-aware version of std::empty.
Definition: StdUtils.h:109
std::string getSymbol() const
string const & GetApplicationName()
string const & GetHostAddr()
long GetPid()