Logging

- Added BOOST logging in the style of dcdbpusher
- All logging-related functionality is in logging.h

CollectAgent/Makefile

@@ -4,6 +4,7 @@ CXXFLAGS =	-O2 -g --std=c++11 -Wall -Wno-unused-local-typedefs -Wno-deprecated-d
 
 OBJS =		collectagent.o \
 		configuration.o \
+		logging.o \
 		sensorcache.o \
 		simplemqttserver.o \
 		simplemqttserverthread.o \

CollectAgent/collectagent.cpp

@@ -61,6 +61,7 @@ DCDB::SensorDataStore *mySensorDataStore;
 DCDB::SensorConfig *mySensorConfig;
 DCDB::SensorCache mySensorCache;
 DCDB::SCError err;
+DCDBLog::logger_t lg;
 
 /* Normal termination (SIGINT, CTRL+C) */
 void sigHandler(int sig)
@@ -138,7 +139,7 @@ int mqttCallback(SimpleMQTTMessage *msg)
       // We use strncmp as it is the most efficient way to do it
       if (strlen(topic) > DCDB_MAP_LEN && strncmp(topic, DCDB_MAP, DCDB_MAP_LEN) == 0) {
           if ((len = msg->getPayloadLength()) == 0) {
-              cout << "Empty topic-to-name mapping message received\n";
+              LOG(error) << "Empty topic-to-name mapping message received";
               return 1;
           }
 
@@ -148,13 +149,13 @@ int mqttCallback(SimpleMQTTMessage *msg)
           // PublishSensor does most of the error checking for us
           switch (err) {
               case DCDB::SC_INVALIDPATTERN:
-                  std::cout << "Invalid sensor topic : " << msg->getTopic() << std::endl;
+                  LOG(error) << "Invalid sensor topic : " << msg->getTopic();
                   return 1;
               case DCDB::SC_INVALIDPUBLICNAME:
-                  std::cout << "Invalid sensor public name: " << sensorName << std::endl;
+                  LOG(error) << "Invalid sensor public name: " << sensorName;
                   return 1;
               case DCDB::SC_INVALIDSESSION:
-                  std::cout << "Cannot reach sensor data store." << std::endl;
+                  LOG(error) << "Cannot reach sensor data store.";
                   return 1;
               default:
                   break;
@@ -176,7 +177,7 @@ int mqttCallback(SimpleMQTTMessage *msg)
           }
               //...otherwise this message is malformed -> ignore...
           else {
-              cout << "Message malformed\n";
+              LOG(error) << "Message malformed";
               return 1;
           }
 
@@ -231,7 +232,7 @@ void usage() {
    012345678901234567890123456789012345678901234567890123456789012345678901234567890
    */
   cout << "Usage:" << endl;
-  cout << "  collectagent [-m<host>] [-r<host>] [-c<host>] [-C<interval>] [-u<username>] [-p<password>] [-t<ttl>] [-d] [-s] <path/to/configfiles/>" << endl;
+  cout << "  collectagent [-m<host>] [-r<host>] [-c<host>] [-C<interval>] [-u<username>] [-p<password>] [-t<ttl>] [-v<verbosity>] [-d] [-s] <path/to/configfiles/>" << endl;
   cout << "  collectagent -h" << endl;
   cout << endl;
   
@@ -243,6 +244,8 @@ void usage() {
   cout << "  -u<username>  Cassandra username      [default: none]" << endl;
   cout << "  -p<password>  Cassandra password      [default: none]" << endl;
   cout << "  -t<ttl>       Cassandra insert TTL    [default: " << defaults.cassandraSettings.ttl << "]" << endl;
+  cout << "  -v<level>     Set verbosity of output [default: " << defaults.logLevelCmd << "]" << endl
+       << "                Can be a number between 5 (all) and 0 (fatal)." << endl;
   cout << endl;
   cout << "  -d            Daemonize" << endl;
   cout << "  -s            Print message stats" <<endl;
@@ -262,7 +265,7 @@ int main(int argc, char* const argv[]) {
       }
 
       // Defining options
-      const char* opts = "m:r:c:C:u:p:t:dDsh";
+      const char* opts = "m:r:c:C:u:p:t:v:dDsh";
 
       // Same mechanism as in DCDBPusher - checking if help string is requested before loading config
       char ret;
@@ -279,9 +282,12 @@ int main(int argc, char* const argv[]) {
           }
       }
 
+      DCDBLog::initLogging();
+      auto cmdSink = DCDBLog::setupCmdLogger();
+
       Configuration config(argv[argc - 1]);
       if( !config.readGlobal() ) {
-          cout << "Failed to read global configuration!" << endl;
+          LOG(fatal) << "Failed to read global configuration!";
           exit(EXIT_FAILURE);
       }
 
@@ -322,6 +328,9 @@ int main(int argc, char* const argv[]) {
               case 't':
                   settings.cassandraSettings.ttl = stoul(optarg);
                   break;
+              case 'v':
+                  settings.logLevelCmd = DCDBLog::translateLogLevel(stoi(optarg));
+                  break;
               case 'd':
               case 'D':
                   settings.daemonize = 1;
@@ -336,6 +345,11 @@ int main(int argc, char* const argv[]) {
           }
       }
 
+      auto fileSink = DCDBLog::setupFileLogger(settings.tempDir, std::string("collectagent"));
+      //severity level may be overwritten (per option or config-file) --> set it according to globalSettings
+      fileSink->set_filter(boost::log::trivial::severity >= settings.logLevelFile);
+      cmdSink->set_filter(boost::log::trivial::severity >= settings.logLevelCmd);
+
       /*
        * Catch SIGINT signals to allow for proper server shutdowns.
        */
@@ -389,7 +403,7 @@ int main(int argc, char* const argv[]) {
       dcdbConn = new DCDB::Connection(cassandraHost, atoi(cassandraPort.c_str()), settings.cassandraSettings.username, settings.cassandraSettings.password);
 
       if (!dcdbConn->connect()) {
-          std::cout << "Cannot connect to Cassandra!" << std::endl;
+          LOG(fatal) << "Cannot connect to Cassandra!";
           exit(EXIT_FAILURE);
       }
 
@@ -418,7 +432,7 @@ int main(int argc, char* const argv[]) {
       ms.setMessageCallback(mqttCallback);
       ms.start();
 
-      cout << "MQTT Server running..." << std::endl;
+      LOG(info) << "MQTT Server running...";
       
       /*
        * Start the HTTP Server for the REST API
@@ -432,7 +446,7 @@ int main(int argc, char* const argv[]) {
       httpServer_t httpServer(httpOptions.address(restApiHost).port(restApiPort));
       httpThread = std::thread([&httpServer] { httpServer.run(); });
 
-      cout << "HTTP Server running..." << std::endl;
+      LOG(info) <<  "HTTP Server running...";
 
       /*
        * Run (hopefully) forever...
@@ -441,7 +455,7 @@ int main(int argc, char* const argv[]) {
       timeval start, end;
       double elapsed;
       
-      cout << "Collect Agent running..." << std::endl;
+      LOG(info) << "Collect Agent running...";
 
       while(keepRunning) {
           gettimeofday(&start, NULL);
@@ -452,27 +466,27 @@ int main(int argc, char* const argv[]) {
           elapsed += (end.tv_usec - start.tv_usec) / 1000.0;
           float publish = msgCtr?(pmsgCtr*100.0)/msgCtr:0;
           if (settings.statistics) {
-              cout << "Message rate: " << (msgCtr/elapsed)*1000.0 << " messages/second (" << publish << "% PUBLISH)\n";
+              LOG(info) << "Message rate: " << (msgCtr/elapsed)*1000.0 << " messages/second (" << publish << "% PUBLISH)";
           }
           msgCtr = 0;
           pmsgCtr = 0;
       }
 
-      cout << "Stopping...\n";
+      LOG(info) << "Stopping...";
 
       ms.stop();
-      cout << "MQTT Server stopped..." << std::endl;
+      LOG(info) << "MQTT Server stopped...";
       httpServer.stop();
       httpThread.join();
-      cout << "HTTP Server stopped..." << std::endl;
+      LOG(info) << "HTTP Server stopped...";
       delete mySensorDataStore;
       delete mySensorConfig;
       dcdbConn->disconnect();
       delete dcdbConn;
-      cout << "Collect Agent closed. Bye bye..." << std::endl;
+      LOG(info) << "Collect Agent closed. Bye bye...";
   }
   catch (const exception& e) {
-      cout << "Exception: " << e.what() << "\n";
+      LOG(fatal) << "Exception: " << e.what();
       abrt(EXIT_FAILURE, INTERR);
   }
 

CollectAgent/config/collectagent.conf

@@ -5,6 +5,8 @@ global {
 	cacheInterval        120
 	daemonize            false
 	statistics           true
+	verbosity 			 3
+	tempDir				 .
 }
 
 restAPI {

CollectAgent/configuration.cpp

@@ -42,8 +42,7 @@ bool Configuration::readGlobal() {
     try {
         boost::property_tree::read_info(globalConfig, cfg);
     } catch (boost::property_tree::info_parser_error& e) {
-        cout << "Error when reading collectagent.conf: " << e.what() << endl;
-        //LOG(error) << "Error when reading collectagent.conf: " << e.what();
+        LOG(error) << "Error when reading collectagent.conf: " << e.what();
         return false;
     }
 
@@ -58,14 +57,18 @@ bool Configuration::readGlobal() {
         } else if (boost::iequals(global.first, "cacheInterval")) {
             _global.cacheInterval = stoul(global.second.data());
         } else if (boost::iequals(global.first, "verbosity")) {
-            _global.logLevelFile = translateLogLevel(stoi(global.second.data()));
+            _global.logLevelFile = DCDBLog::translateLogLevel(stoi(global.second.data()));
+        } else if (boost::iequals(global.first, "tempDir")) {
+            _global.tempDir = global.second.data();
+            if (_global.tempDir[_global.tempDir.length()-1] != '/') {
+                _global.tempDir.append("/");
+            }
         } else if (boost::iequals(global.first, "daemonize")) {
             _global.daemonize = global.second.data() == "true";
         } else if (boost::iequals(global.first, "statistics")) {
             _global.statistics = global.second.data() == "true";
         } else {
-            cout << "  Value \"" << global.first << "\" not recognized. Omitting" << endl;
-            //LOG(warning) << "  Value \"" << global.first << "\" not recognized. Omitting";
+            LOG(warning) << "  Value \"" << global.first << "\" not recognized. Omitting";
         }
     }
 
@@ -80,8 +83,7 @@ bool Configuration::readGlobal() {
         } else if (boost::iequals(global.first, "ttl")) {
             _global.cassandraSettings.ttl = stoul(global.second.data());
         } else {
-            cout << "  Value \"" << global.first << "\" not recognized. Omitting" << endl;
-            //LOG(warning) << "  Value \"" << global.first << "\" not recognized. Omitting";
+            LOG(warning) << "  Value \"" << global.first << "\" not recognized. Omitting";
         }
     }
 
@@ -98,40 +100,13 @@ bool Configuration::readGlobal() {
         //} else if (boost::iequals(global.first, "authkey")) {
         //    //Avoid unnecessary "Value not recognized" message
         } else {
-            cout << "  Value \"" << global.first << "\" not recognized. Omitting" << endl;
-            //LOG(warning) << "  Value \"" << global.first << "\" not recognized. Omitting";
+            LOG(warning) << "  Value \"" << global.first << "\" not recognized. Omitting";
         }
     }
 
     return true;
 }
 
-boost::log::trivial::severity_level Configuration::translateLogLevel(int logLevel) {
-    switch (logLevel) {
-        case 0:
-            return boost::log::trivial::fatal;
-            break;
-        case 1:
-            return boost::log::trivial::error;
-            break;
-        case 2:
-            return boost::log::trivial::warning;
-            break;
-        case 3:
-            return boost::log::trivial::info;
-            break;
-        case 4:
-            return boost::log::trivial::debug;
-            break;
-        case 5:
-            return boost::log::trivial::trace;
-            break;
-        default:
-            return boost::log::trivial::info;
-            break;
-    }
-}
-
 globalCA_t& Configuration::getGlobal() {
     return _global;
 }

CollectAgent/configuration.h

@@ -13,12 +13,7 @@
 #include <boost/property_tree/info_parser.hpp>
 #include <boost/algorithm/string.hpp>
 
-//TODO: move somewhere else
-#include <boost/log/trivial.hpp>
-#include <boost/log/sources/severity_logger.hpp>
-
-// TODO: remove
-#include <iostream>
+#include "logging.h"
 
 #define LISTENHOST "localhost"
 #define LISTENPORT "1883"
@@ -39,6 +34,7 @@ typedef struct {
     bool statistics;
     std::string mqttListenAddress;
     std::string restListenAddress;
+    std::string tempDir;
     uint64_t messageThreads;
     uint64_t messageSlots;
     uint64_t cacheInterval;
@@ -70,14 +66,6 @@ public:
      */
     bool readGlobal();
 
-    /**
-     * Translate numeric verbosity level to boost::log severity level
-     * @param logLevel	The numeric verbosity level
-     * @return		    The boost::log severity level
-     */
-    boost::log::trivial::severity_level translateLogLevel(int logLevel);
-
-
     /**
      * Return global settings
      */
@@ -88,7 +76,7 @@ private:
     std::string _cfgFilePath;
     globalCA_t 	_global;
 
-    boost::log::sources::severity_logger<boost::log::trivial::severity_level> lg;
+    DCDBLog::logger_t lg;
 };
 
 #endif /* CONFIGURATION_H_ */

CollectAgent/logging.cpp

+//
+// Created by Netti, Alessio on 07.12.18.
+//
+
+#include "logging.h"
+
+void DCDBLog::initLogging() {
+    //Init logging environment
+    boost::log::add_common_attributes();
+}
+
+//Setup a command line logger
+//only print timestamp (without date), severity and message to terminal
+auto DCDBLog::setupCmdLogger() -> decltype(boost::log::add_console_log()) {
+    auto logger = boost::log::add_console_log(std::cout,
+          boost::log::keywords::format = (boost::log::expressions::stream
+                  << "[" << boost::log::expressions::format_date_time<boost::posix_time::ptime>("TimeStamp", "%H:%M:%S") << "]"
+                  << " <" << boost::log::trivial::severity << ">"
+                  << ": " << boost::log::expressions::smessage),
+          boost::log::keywords::filter = (boost::log::trivial::severity >= boost::log::trivial::info));
+    return logger;
+}
+
+//Setup logger to file; we now should know where the writable tempdir is
+//number logfiles ascending; rotate logfile every 10 MiB
+//format:	LineID [Timestamp] ThreadID <severity>: Message
+auto DCDBLog::setupFileLogger(std::string logPath, std::string logName) -> decltype(boost::log::add_file_log("")) {
+    auto logger = boost::log::add_file_log(
+            boost::log::keywords::file_name = logPath + logName + "_%N.log",
+            boost::log::keywords::rotation_size = 10 * 1024 * 1024,
+            boost::log::keywords::format = ( boost::log::expressions::stream
+                    << boost::log::expressions::attr< unsigned int >("LineID")
+                    << " [" << boost::log::expressions::format_date_time< boost::posix_time::ptime >("TimeStamp", "%Y-%m-%d, %H:%M:%S") << "]"
+                    << " " << boost::log::expressions::attr<boost::log::attributes::current_thread_id::value_type >("ThreadID")
+                    << " <" << boost::log::trivial::severity << ">"
+                    << ": " << boost::log::expressions::smessage),
+            boost::log::keywords::filter = (boost::log::trivial::severity >= boost::log::trivial::trace),
+            boost::log::keywords::auto_flush = true);
+    return logger;
+}
+
+boost::log::trivial::severity_level DCDBLog::translateLogLevel(int logLevel) {
+    switch (logLevel) {
+        case 0:
+            return boost::log::trivial::fatal;
+        case 1:
+            return boost::log::trivial::error;
+        case 2:
+            return boost::log::trivial::warning;
+        case 3:
+            return boost::log::trivial::info;
+        case 4:
+            return boost::log::trivial::debug;
+        case 5:
+            return boost::log::trivial::trace;
+        default:
+            return boost::log::trivial::info;
+    }
+}
\ No newline at end of file

CollectAgent/logging.h

+/*
+ * logging.h
+ *
+ *  Created on: 05.05.2018
+ *      Author: Micha Mueller, Alessio Netti
+ */
+
+#ifndef LOGGING_H_
+#define LOGGING_H_
+
+/*
+ * Simple header file to bundle all includes required for logging with boost::log.
+ * Simplifies logging: one has to include only this single header file which additionally
+ * offers shortcut macros for convenient logging.
+ */
+
+// Thanks Micha! I took the liberty to dump here all of the logic to setup logger instances so that it is eventually
+// easier to use and make uniform across collectagent and dcdbpusher
+
+#include <boost/log/trivial.hpp>
+#include <boost/log/sources/severity_logger.hpp>
+#include <boost/log/expressions.hpp>
+#include <boost/log/utility/setup/file.hpp>
+#include <boost/log/utility/setup/console.hpp>
+#include <boost/log/utility/setup/common_attributes.hpp>
+#include <boost/log/support/date_time.hpp>
+
+//further abbreviate the boost shortcut-macro
+//to use it, only a boost severity-logger named lg is required
+#define LOG(sev) BOOST_LOG_SEV(lg, boost::log::trivial::sev)
+
+namespace DCDBLog {
+
+// Handy typedef to instantiate loggers
+typedef boost::log::sources::severity_logger<boost::log::trivial::severity_level> logger_t;
+
+/**
+* @brief    Initialize the logging environment.
+**/
+void initLogging();
+
+/**
+* @brief        	Setup a command-line logger.
+*
+*                   Only prints timestamp (without date), severity and message to terminal.
+*
+* @return           BOOST command-line logger object
+**/
+auto setupCmdLogger() -> decltype(boost::log::add_console_log());
+
+
+/**
+* @brief        	Setup a file logger.
+*
+*                   Setup logger to file; we now should know where the writable tempdir is
+*                   number logfiles ascending; rotate logfile every 10 MiB
+*                   format:	LineID [Timestamp] ThreadID <severity>: Message
+*
+* @param  logPath   Path to which log files must be stored
+* @param  logName   Prefix used to name log files
+* @return           BOOST file logger object
+**/
+auto setupFileLogger(std::string logPath, std::string logName) -> decltype(boost::log::add_file_log(""));
+
+/**
+* @brief            Numeric verbosity level to boost::log severity level
+*
+* @param  logLevel	The numeric verbosity level
+* @return		    The boost::log severity level
+**/
+boost::log::trivial::severity_level translateLogLevel(int logLevel);
+
+}
+
+#endif /* LOGGING_H_ */

CollectAgent/simplemqttserver.cpp

@@ -104,12 +104,12 @@ void SimpleMQTTServer::initSockets(void)
        * Bind and listen on socket.
        */
       if (::bind(sock, ainfo_cur->ai_addr, ainfo_cur->ai_addrlen) == -1) {
-          cout << "Warning: could not bind to socket, ignoring socket.\n";
+          LOG(warning) << "Could not bind to socket, ignoring socket.";
           close(sock);
           continue;
       }
       if (listen(sock, SimpleMQTTMaxBacklog) == -1) {
-          cout << "Warning: could not listen on socket, ignoring socket.\n";
+          LOG(warning) << "Could not listen on socket, ignoring socket.";
           close(sock);
           continue;
       }

CollectAgent/simplemqttserver.h

@@ -42,6 +42,8 @@
 #include <boost/thread/mutex.hpp>
 #include <boost/thread/thread.hpp>
 
+#include "logging.h"
+
 #ifndef SIMPLEMQTTSERVER_H_
 #define SIMPLEMQTTSERVER_H_
 
@@ -107,6 +109,8 @@ protected:
   boost::ptr_list<SimpleMQTTServerAcceptThread> acceptThreads;
   SimpleMQTTMessageCallback messageCallback;
 
+  DCDBLog::logger_t lg;
+
   void init(std::string addr, std::string port);
   void initSockets(void);
 

CollectAgent/simplemqttserverthread.cpp

@@ -64,7 +64,7 @@ SimpleMQTTServerThread::SimpleMQTTServerThread()
 
   terminate = false;
   if (pthread_create(&t, NULL, launch, this) != 0) {
-      cout << "Error creating new MQTT server thread.\n";
+      LOG(error) << "Error creating new MQTT server thread.";
       abrt(EXIT_FAILURE, INTERR);
   }
 
@@ -83,7 +83,7 @@ SimpleMQTTServerThread::~SimpleMQTTServerThread()
    */
   terminate = true;
   if (pthread_join(t, NULL) != 0) {
-      cout << "Error joining thread.\n";
+      LOG(error) << "Error joining thread.";
       abrt(EXIT_FAILURE, INTERR);
   }
 
@@ -196,7 +196,7 @@ void SimpleMQTTServerAcceptThread::run()
                    * not exceed the maximum.
                    */
                   if (messageThreads.size() >= this->_maxThreads) {
-                    cout << "Warning: socket " << socket << " cannot accept more connections.\n";
+                    LOG(warning) << "Socket " << socket << " cannot accept more connections.";
                     // FIXME: There must be nicer ways to handle such situations...
                     close(newsock);
                     break;
@@ -365,7 +365,7 @@ void SimpleMQTTServerMessageThread::run()
                           if (!msg[connectionId]) {
                               msg[connectionId] = new SimpleMQTTMessage();
                               if (!msg[connectionId]) {
-                                  cout << "Warning: Out of memory! Discarding network input!\n";
+                                  LOG(warning) << "Out of memory! Discarding network input!";
                                   continue;
                               }
 #ifdef SimpleMQTTVerbose
@@ -425,7 +425,7 @@ void SimpleMQTTServerMessageThread::run()
                                   messageCallback(msg[connectionId]);
                                 }
                                 else {
-                                  cout << "Nothing to do.." << endl;
+                                  LOG(trace) << "Nothing to do..";
                                 }
                                 break;
                               }

CollectAgent/simplemqttserverthread.h

@@ -27,6 +27,8 @@
 #ifndef SIMPLEMQTTSERVERTHREAD_H_
 #define SIMPLEMQTTSERVERTHREAD_H_
 
+#include "logging.h"
+
 class SimpleMQTTServerThread
 {
 protected:
@@ -35,6 +37,8 @@ protected:
 
   boost::mutex cleanupMtx;
 
+  DCDBLog::logger_t lg;
+
   static void* launch(void* thisPtr);
   static void yield();
   virtual void run() = 0;