Unify logging (QC-224) (#222)

- Get rid of all cout/cerr in QC framework in favour of QCInfoLogger
- Introduce some of the changes I proposed in Qcinfologger to decrease verbosity, in particular ILOG(level) << xxx << ENDM

Author: Barthelemy

Framework/CMakeLists.txt

@@ -43,6 +43,7 @@ add_library(QualityControl
             src/CheckInterface.cxx
             src/DatabaseFactory.cxx
             src/CcdbDatabase.cxx
+            src/QcInfoLogger.cxx
             src/TaskFactory.cxx
             src/TaskRunner.cxx
             src/TaskRunnerFactory.cxx

Framework/include/QualityControl/QcInfoLogger.h

@@ -17,9 +17,9 @@
 #define QC_CORE_QCINFOLOGGER_H
 
 #include <InfoLogger/InfoLogger.hxx>
-#include "QualityControl/TaskInterface.h"
 
-typedef AliceO2::InfoLogger::InfoLogger infologger; // not to have to type the full stuff each time -> log::endm
+typedef AliceO2::InfoLogger::InfoLogger infologger; // not to have to type the full stuff each time
+typedef AliceO2::InfoLogger::InfoLoggerContext infoContext;
 
 namespace o2::quality_control::core
 {
@@ -30,6 +30,10 @@ namespace o2::quality_control::core
 /// and configure its own instance of InfoLogger.
 /// Independent InfoLogger instances can still be created when and if needed.
 /// Usage :   QcInfoLogger::GetInstance() << "blabla" << infologger::endm;
+///           ILOG(Info) << "info message" << ENDM; // short version
+///           ILOGI << "info message" << ENDM;      // shorter
+///           ILOG_INST << InfoLogger::InfoLoggerMessageOption{ InfoLogger::Fatal, 1, 1, "asdf", 3 }
+///                     << "fatal message with extra fields" << ENDM; // complex version
 ///
 /// \author Barthelemy von Haller
 class QcInfoLogger : public AliceO2::InfoLogger::InfoLogger
@@ -44,12 +48,7 @@ class QcInfoLogger : public AliceO2::InfoLogger::InfoLogger
   }
 
  private:
-  QcInfoLogger()
-  {
-    // TODO configure the QC infologger, e.g. proper facility
-    *this << "QC infologger initialized" << infologger::endm;
-  }
-
+  QcInfoLogger();
   ~QcInfoLogger() override = default;
 
   // Disallow copying
@@ -59,4 +58,14 @@ class QcInfoLogger : public AliceO2::InfoLogger::InfoLogger
 
 } // namespace o2::quality_control::core
 
+// Define the ILOG() macro.
+// Unfortunately it is not possible to have a zero argument MACRO here without generating warnings
+#define ILOG_INST o2::quality_control::core::QcInfoLogger::GetInstance()
+#define ILOG(severity) ILOG_INST << AliceO2::InfoLogger::InfoLogger::Severity::severity
+#define ILOGI ILOG_INST << AliceO2::InfoLogger::InfoLogger::Info
+#define ILOGW ILOG_INST << AliceO2::InfoLogger::InfoLogger::Warning
+#define ILOGE ILOG_INST << AliceO2::InfoLogger::InfoLogger::Error
+#define ILOGF ILOG_INST << AliceO2::InfoLogger::InfoLogger::Fatal
+#define ENDM AliceO2::InfoLogger::InfoLogger::endm;
+
 #endif // QC_CORE_QCINFOLOGGER_H

Framework/include/QualityControl/TaskFactory.h

@@ -20,6 +20,7 @@
 #include <memory>
 // QC
 #include "QualityControl/TaskConfig.h"
+#include "QualityControl/TaskInterface.h"
 
 namespace o2::quality_control::core
 {

Framework/src/CcdbDatabase.cxx

@@ -16,6 +16,7 @@
 #include "QualityControl/CcdbDatabase.h"
 #include "QualityControl/MonitorObject.h"
 #include "QualityControl/Version.h"
+#include "QualityControl/QcInfoLogger.h"
 #include "Common/Exceptions.h"
 // ROOT
 #include <TBufferJSON.h>
@@ -46,19 +47,19 @@ CcdbDatabase::~CcdbDatabase() { disconnect(); }
 void CcdbDatabase::loadDeprecatedStreamerInfos()
 {
   if (getenv("QUALITYCONTROL_ROOT") == nullptr) {
-    LOG(WARNING) << "QUALITYCONTROL_ROOT is not set thus the the streamerinfo ROOT file can't be found.\n"
-                 << "Consequently, old data might not be readable.";
+    ILOG(Warning) << "QUALITYCONTROL_ROOT is not set thus the the streamerinfo ROOT file can't be found.\n"
+                  << "Consequently, old data might not be readable." << ENDM;
     return;
   }
   string path = string(getenv("QUALITYCONTROL_ROOT")) + "/etc/";
   vector<string> filenames = { "streamerinfos.root", "streamerinfos_v017.root" };
   for (auto filename : filenames) {
     string localPath = path + filename;
-    LOG(INFO) << "Loading streamerinfos from : " << localPath;
+    ILOG(Info) << "Loading streamerinfos from : " << localPath << ENDM;
     TFile file(localPath.data(), "READ");
     if (file.IsZombie()) {
       string s = string("Cannot find ") + localPath;
-      LOG(ERROR) << s;
+      ILOG(Error) << s << ENDM;
       BOOST_THROW_EXCEPTION(DatabaseException() << errinfo_details(s));
     }
     TIter next(file.GetListOfKeys());
@@ -68,7 +69,7 @@ void CcdbDatabase::loadDeprecatedStreamerInfos()
       if (!cl->InheritsFrom("TStreamerInfo"))
         continue;
       auto* si = (TStreamerInfo*)key->ReadObj();
-      LOG(DEBUG) << "importing streamer info version " << si->GetClassVersion() << " for '" << si->GetName();
+      ILOG(Debug) << "importing streamer info version " << si->GetClassVersion() << " for '" << si->GetName() << ENDM;
       si->BuildCheck();
     }
   }
@@ -134,14 +135,14 @@ std::shared_ptr<core::MonitorObject> CcdbDatabase::retrieveMO(std::string taskNa
   if (object == nullptr) {
     // We could not open a TFile we should now try to open an object directly serialized
     object = ccdbApi.retrieve(path, metadata, when);
-    LOG(DEBUG) << "We could retrieve the object " << path << " as a streamed object.";
+    ILOG(Debug) << "We could retrieve the object " << path << " as a streamed object." << ENDM;
     if (object == nullptr) {
       return nullptr;
     }
   }
   std::shared_ptr<core::MonitorObject> mo(dynamic_cast<core::MonitorObject*>(object));
   if (mo == nullptr) {
-    LOG(ERROR) << "Could not cast the object " << taskName << "/" << objectName << " to MonitorObject";
+    ILOG(Error) << "Could not cast the object " << taskName << "/" << objectName << " to MonitorObject" << ENDM;
   }
   return mo;
 }
@@ -304,7 +305,7 @@ long CcdbDatabase::getCurrentTimestamp()
 
 void CcdbDatabase::truncate(std::string taskName, std::string objectName)
 {
-  LOG(INFO) << "truncating data for " << taskName << "/" << objectName;
+  ILOG(Info) << "truncating data for " << taskName << "/" << objectName << ENDM;
 
   ccdbApi.truncate(taskName + "/" + objectName);
 }

Framework/src/DataDumpGui.cxx

@@ -15,7 +15,7 @@
 ///
 
 #include "QualityControl/DataDumpGui.h"
-
+#include "QualityControl/QcInfoLogger.h"
 #include "imgui/BaseGui.h"
 #include "imgui/imgui.h"
 #include <Headers/DataHeader.h>
@@ -265,7 +265,7 @@ bool DataDumpGui::ConditionalRun()
 bool DataDumpGui::handleParts(FairMQParts& parts)
 {
   if (parts.Size() != 2) {
-    cout << "number of parts must be 2" << endl;
+    ILOG(Debug) << "number of parts must be 2" << ENDM;
     return false;
   }
 

Framework/src/MySqlDatabase.cxx

@@ -61,7 +61,7 @@ void MySqlDatabase::connect(std::string host, std::string database, std::string
     }
     BOOST_THROW_EXCEPTION(FatalException() << errinfo_details(s));
   } else {
-    QcInfoLogger::GetInstance() << "Connected to the database" << infologger::endm;
+    ILOG(Info) << "Connected to the database" << ENDM;
   }
 }
 
@@ -88,7 +88,7 @@ void MySqlDatabase::prepareTable(std::string table_name)
   if (!execute(query)) {
     BOOST_THROW_EXCEPTION(FatalException() << errinfo_details("Failed to create data table"));
   } else {
-    QcInfoLogger::GetInstance() << "Create data table " << table_name << infologger::endm;
+    ILOG(Info) << "Create data table " << table_name << ENDM;
   }
 }
 
@@ -116,8 +116,8 @@ void MySqlDatabase::storeMO(std::shared_ptr<o2::quality_control::core::MonitorOb
 
 void MySqlDatabase::storeQueue()
 {
-  QcInfoLogger::GetInstance() << "Database queue will now be processed (" << queueSize << " objects)"
-                              << infologger::endm;
+  ILOG(Info) << "Database queue will now be processed (" << queueSize << " objects)"
+             << ENDM;
 
   for (auto& kv : mMonitorObjectsQueue) {
     storeForMonitorObject(kv.first);
@@ -191,8 +191,8 @@ void MySqlDatabase::storeForMonitorObject(std::string name)
     return;
   }
 
-  cout << "** Store for task " << name << endl;
-  cout << "        # objects : " << objects.size() << endl;
+  ILOG(Info) << "** Store for task " << name << ENDM;
+  ILOG(Info) << "        # objects : " << objects.size() << ENDM;
 
   // build statement string
   string table_name = "data_" + name;
@@ -346,7 +346,7 @@ std::shared_ptr<o2::quality_control::core::MonitorObject> MySqlDatabase::retriev
     try {
       mo = std::shared_ptr<MonitorObject>((MonitorObject*)(mess.ReadObjectAny(mess.GetClass())));
     } catch (...) {
-      QcInfoLogger::GetInstance() << "Node: unable to parse TObject from MySQL" << infologger::endm;
+      ILOG(Info) << "Node: unable to parse TObject from MySQL" << ENDM;
       throw;
     }
   }
@@ -406,7 +406,7 @@ void MySqlDatabase::addIndex(string table, string column)
   if (res) {
     delete (res);
   } else {
-    cerr << "Couldn't create the index on table " << table << " on column " << column << endl;
+    ILOG(Error) << "Couldn't create the index on table " << table << " on column " << column << ENDM;
   }
 }
 
@@ -457,7 +457,7 @@ void MySqlDatabase::truncate(std::string taskName, std::string objectName)
     string s = string("Failed to delete object ") + objectName + " from task " + taskName;
     BOOST_THROW_EXCEPTION(FatalException() << errinfo_details(s));
   } else {
-    QcInfoLogger::GetInstance() << "Delete object " << objectName << " from task " << taskName << infologger::endm;
+    ILOG(Info) << "Delete object " << objectName << " from task " << taskName << ENDM;
   }
 }
 

Framework/src/PostProcessingRunner.cxx

@@ -39,33 +39,33 @@ PostProcessingRunner::~PostProcessingRunner()
 
 bool PostProcessingRunner::init()
 {
-  LOG(INFO) << "Initializing PostProcessingRunner";
+  ILOG(Info) << "Initializing PostProcessingRunner" << ENDM;
 
   try {
     // configuration of the database
     mDatabase = DatabaseFactory::create(mConfigFile->get<std::string>("qc.config.database.implementation"));
     mDatabase->connect(mConfigFile->getRecursiveMap("qc.config.database"));
-    LOG(INFO) << "Database that is going to be used : ";
-    LOG(INFO) << ">> Implementation : " << mConfigFile->get<std::string>("qc.config.database.implementation");
-    LOG(INFO) << ">> Host : " << mConfigFile->get<std::string>("qc.config.database.host");
+    ILOG(Info) << "Database that is going to be used : " << ENDM;
+    ILOG(Info) << ">> Implementation : " << mConfigFile->get<std::string>("qc.config.database.implementation") << ENDM;
+    ILOG(Info) << ">> Host : " << mConfigFile->get<std::string>("qc.config.database.host") << ENDM;
     mServices.registerService<DatabaseInterface>(mDatabase.get());
   } catch (
     std::string const& e) { // we have to catch here to print the exception because the device will make it disappear todo: is it still the case?
-    LOG(ERROR) << "exception : " << e;
+    ILOG(Error) << "exception : " << e << ENDM;
     throw;
   } catch (...) {
     std::string diagnostic = boost::current_exception_diagnostic_information();
-    LOG(ERROR) << "Unexpected exception, diagnostic information follows:\n"
-               << diagnostic;
+    ILOG(Error) << "Unexpected exception, diagnostic information follows:\n"
+                << diagnostic << ENDM;
     throw;
   }
 
   // setup user's task
-  LOG(INFO) << "Creating a user task '" << mConfig.taskName << "'";
+  ILOG(Info) << "Creating a user task '" << mConfig.taskName << "'" << ENDM;
   PostProcessingFactory f;
   mTask.reset(f.create(mConfig));
   if (mTask) {
-    LOG(INFO) << "The user task '" << mConfig.taskName << "' successfully created";
+    ILOG(Info) << "The user task '" << mConfig.taskName << "' successfully created" << ENDM;
 
     mState = TaskState::Created;
     mTask->setName(mConfig.taskName);
@@ -74,19 +74,19 @@ bool PostProcessingRunner::init()
     mInitTriggers = trigger_helpers::createTriggers(mConfig.initTriggers);
     return true;
   } else {
-    LOG(INFO) << "Failed to create the task '" << mConfig.taskName << "'";
+    ILOG(Info) << "Failed to create the task '" << mConfig.taskName << "'" << ENDM;
     // todo :maybe exceptions instead of return values
     return false;
   }
 }
 
 bool PostProcessingRunner::run()
 {
-  LOG(INFO) << "Running PostProcessingRunner";
+  ILOG(Info) << "Running PostProcessingRunner" << ENDM;
 
   if (mState == TaskState::Created) {
     if (Trigger trigger = trigger_helpers::tryTrigger(mInitTriggers)) {
-      LOG(INFO) << "Initializing user task";
+      ILOG(Info) << "Initializing user task" << ENDM;
 
       mTask->initialize(trigger, mServices);
 
@@ -98,22 +98,22 @@ bool PostProcessingRunner::run()
   if (mState == TaskState::Running) {
 
     if (Trigger trigger = trigger_helpers::tryTrigger(mUpdateTriggers)) {
-      LOG(INFO) << "Updating user task";
+      ILOG(Info) << "Updating user task" << ENDM;
       mTask->update(trigger, mServices);
     }
     if (Trigger trigger = trigger_helpers::tryTrigger(mStopTriggers)) {
-      LOG(INFO) << "Finalizing user task";
+      ILOG(Info) << "Finalizing user task" << ENDM;
       mTask->finalize(trigger, mServices);
       mState = TaskState::Finished; // maybe the task should monitor its state by itself?
     }
   }
   if (mState == TaskState::Finished) {
-    LOG(INFO) << "User task finished, returning...";
+    ILOG(Info) << "User task finished, returning..." << ENDM;
     return false;
   }
   if (mState == TaskState::INVALID) {
     // todo maybe exception?
-    LOG(INFO) << "User task state INVALID, returning...";
+    ILOG(Info) << "User task state INVALID, returning..." << ENDM;
     return false;
   }
 

Framework/src/QcInfoLogger.cxx

@@ -0,0 +1,32 @@
+// Copyright CERN and copyright holders of ALICE O2. This software is
+// distributed under the terms of the GNU General Public License v3 (GPL
+// Version 3), copied verbatim in the file "COPYING".
+//
+// See http://alice-o2.web.cern.ch/license for full licensing information.
+//
+// In applying this license CERN does not waive the privileges and immunities
+// granted to it by virtue of its status as an Intergovernmental Organization
+// or submit itself to any jurisdiction.
+
+///
+/// \file   QcInfoLogger.cxx
+/// \author Barthelemy von Haller
+///
+
+#include "QualityControl/QcInfoLogger.h"
+#include <InfoLogger/InfoLoggerFMQ.hxx>
+
+namespace o2::quality_control::core
+{
+
+QcInfoLogger::QcInfoLogger()
+{
+  infoContext context;
+  context.setField(infoContext::FieldName::Facility, "QC");
+  context.setField(infoContext::FieldName::System, "QC");
+  this->setContext(context);
+  //  setFMQLogsToInfoLogger(this); // disabled, see https://github.com/AliceO2Group/QualityControl/pull/222
+  *this << "QC infologger initialized" << infologger::endm;
+}
+
+} // namespace o2::quality_control::core

Framework/src/RepositoryBenchmark.cxx

@@ -85,8 +85,8 @@ void RepositoryBenchmark::InitTask()
     mDatabase->prepareTaskDataContainer(mTaskName);
   } catch (boost::exception& exc) {
     string diagnostic = boost::current_exception_diagnostic_information();
-    std::cerr << "Unexpected exception, diagnostic information follows:\n"
-              << diagnostic << endl;
+    ILOG(Error) << "Unexpected exception, diagnostic information follows:\n"
+                << diagnostic << ENDM;
     if (diagnostic == "No diagnostic information available.") {
       throw;
     }

Framework/src/ServiceDiscovery.cxx

@@ -13,7 +13,7 @@
 ///
 
 #include "QualityControl/ServiceDiscovery.h"
-#include <iostream>
+#include "QualityControl/QcInfoLogger.h"
 #include <string>
 #include <boost/asio.hpp>
 #include <boost/property_tree/ptree.hpp>
@@ -124,7 +124,7 @@ void ServiceDiscovery::runHealthServer(unsigned int port)
     }
   } catch (std::exception& e) {
     mThreadRunning = false;
-    std::cerr << e.what() << std::endl;
+    ILOG(Error) << e.what() << ENDM;
   }
 }
 
@@ -145,10 +145,10 @@ void ServiceDiscovery::send(const std::string& path, std::string&& post)
   response = curl_easy_perform(curl);
   curl_easy_getinfo(curl, CURLINFO_RESPONSE_CODE, &responseCode);
   if (response != CURLE_OK) {
-    std::cerr << "ServiceDiscovery: " << curl_easy_strerror(response) << ": " << uri << std::endl;
+    ILOG(Error) << "ServiceDiscovery: " << curl_easy_strerror(response) << ": " << uri << ENDM;
   }
   if (responseCode < 200 || responseCode > 206) {
-    std::cerr << "ServiceDiscovery: Response code: " << responseCode << std::endl;
+    ILOG(Error) << "ServiceDiscovery: Response code: " << responseCode << ENDM;
   }
 }
 } // namespace o2::quality_control::core