Merge pull request #645 from majestrate/json-logging

json logging option

llarp/CMakeLists.txt

@@ -18,11 +18,13 @@ set(LIB_UTIL_SRC
   util/android_logger.cpp
   util/file_logger.cpp
   util/logic.cpp
+  util/loglevel.cpp
   util/mem.cpp
   util/memfn_traits.cpp
   util/memfn.cpp
   util/metrics_core.cpp
   util/metrics_types.cpp
+  util/json_logger.cpp
   util/ostream_logger.cpp
   util/syslog_logger.cpp
   util/win32_logger.cpp

llarp/config.cpp

@@ -77,7 +77,8 @@ namespace llarp
 
     std::for_each(logging.begin(), logging.end(),
                   std::bind(visitor, "logging", _1));
-
+    // end of logging section commit settings and go
+    functor("logging", "", "");
     std::for_each(lokid.begin(), lokid.end(), std::bind(visitor, "lokid", _1));
     std::for_each(router.begin(), router.end(),
                   std::bind(visitor, "router", _1));

llarp/router/router.cpp

@@ -16,6 +16,7 @@
 #include <util/logger.hpp>
 #include <util/memfn.hpp>
 #include <util/file_logger.hpp>
+#include <util/json_logger.hpp>
 #include <util/logger_syslog.hpp>
 #include <util/metrics.hpp>
 #include <util/str.hpp>
@@ -923,6 +924,19 @@ namespace llarp
     }
     else if(StrEq(section, "logging"))
     {
+      if(strlen(key) == 0 && strlen(val) == 0)
+      {
+        if(m_LogJSON)
+        {
+          LogContext::Instance().logStream = std::make_unique< JSONLogStream >(
+              diskworker(), m_LogFile, 100, m_LogFile != stdout);
+        }
+        else if(m_LogFile != stdout)
+        {
+          LogContext::Instance().logStream = std::make_unique< FileLogStream >(
+              diskworker(), m_LogFile, 100, true);
+        }
+      }
       if(StrEq(key, "type") && StrEq(val, "syslog"))
       {
         // TODO(despair): write event log syslog class
@@ -933,15 +947,18 @@ namespace llarp
         LogContext::Instance().logStream = std::make_unique< SysLogStream >();
 #endif
       }
+      if(StrEq(key, "type") && StrEq(val, "json"))
+      {
+        m_LogJSON = true;
+      }
       if(StrEq(key, "file"))
       {
         LogInfo("open log file: ", val);
         FILE *const logfile = ::fopen(val, "a");
         if(logfile)
         {
-          LogContext::Instance().logStream =
-              std::make_unique< FileLogStream >(diskworker(), logfile, 500);
-          LogInfo("started logging to ", val);
+          m_LogFile = logfile;
+          LogInfo("will log to file ", val);
         }
         else if(errno)
         {

llarp/router/router.hpp

@@ -305,6 +305,11 @@ namespace llarp
     // set to max value right now
     std::unordered_map< RouterID, llarp_time_t, PubKey::Hash > lokinetRouters;
 
+    // set to true if we are configured to run with json logging
+    bool m_LogJSON = false;
+    // the file we are logging to
+    FILE *m_LogFile = stdout;
+
     Router(struct llarp_threadpool *tp, llarp_ev_loop_ptr __netloop,
            std::shared_ptr< Logic > logic);
 

llarp/util/file_logger.cpp

@@ -6,7 +6,7 @@ namespace llarp
   namespace
   {
     static void
-    Flush(const std::deque< std::string > &lines, FILE *const f)
+    Flush(std::deque< std::string > lines, FILE *const f)
     {
       for(const auto &line : lines)
         fprintf(f, "%s\n", line.c_str());
@@ -14,15 +14,19 @@ namespace llarp
     }
   }  // namespace
   FileLogStream::FileLogStream(thread::ThreadPool *disk, FILE *f,
-                               llarp_time_t flushInterval)
-      : m_Disk(disk), m_File(f), m_FlushInterval(flushInterval)
+                               llarp_time_t flushInterval, bool closeFile)
+      : m_Disk(disk)
+      , m_File(f)
+      , m_FlushInterval(flushInterval)
+      , m_Close(closeFile)
   {
   }
 
   FileLogStream::~FileLogStream()
   {
     fflush(m_File);
-    fclose(m_File);
+    if(m_Close)
+      fclose(m_File);
   }
 
   bool
@@ -36,27 +40,11 @@ namespace llarp
 
   void
   FileLogStream::PreLog(std::stringstream &ss, LogLevel lvl, const char *fname,
-                        int lineno) const
+                        int lineno, const std::string &nodename) const
   {
-    switch(lvl)
-    {
-      case eLogNone:
-        break;
-      case eLogDebug:
-        ss << "[DBG] ";
-        break;
-      case eLogInfo:
-        ss << "[NFO] ";
-        break;
-      case eLogWarn:
-
-        ss << "[WRN] ";
-        break;
-      case eLogError:
-        ss << "[ERR] ";
-        break;
-    }
-    ss << "(" << thread_id_string() << ") " << log_timestamp() << " " << fname
+    ss << "[" << LogLevelToString(lvl) << "] ";
+    ss << "[" << nodename << "]"
+       << "(" << thread_id_string() << ") " << log_timestamp() << " " << fname
        << ":" << lineno << "\t";
   }
 
@@ -76,7 +64,10 @@ namespace llarp
   void
   FileLogStream::FlushLinesToDisk(llarp_time_t now)
   {
-    m_Disk->addJob(std::bind(&Flush, std::move(m_Lines), m_File));
+    FILE *const f = m_File;
+    std::deque< std::string > lines(m_Lines);
+    m_Disk->addJob([=]() { Flush(lines, f); });
+    m_Lines.clear();
     m_LastFlush = now;
   }
 }  // namespace llarp

llarp/util/file_logger.hpp

@@ -12,14 +12,14 @@ namespace llarp
   /// flushable file based log stream
   struct FileLogStream : public ILogStream
   {
-    FileLogStream(thread::ThreadPool* disk, FILE* f,
-                  llarp_time_t flushInterval);
+    FileLogStream(thread::ThreadPool* disk, FILE* f, llarp_time_t flushInterval,
+                  bool closefile = true);
 
     ~FileLogStream();
 
     void
-    PreLog(std::stringstream& out, LogLevel lvl, const char* fname,
-           int lineno) const override;
+    PreLog(std::stringstream& out, LogLevel lvl, const char* fname, int lineno,
+           const std::string& nodename) const override;
 
     void
     Print(LogLevel, const char*, const std::string& msg) override;
@@ -32,6 +32,9 @@ namespace llarp
     {
     }
 
+   protected:
+    std::deque< std::string > m_Lines;
+
    private:
     bool
     ShouldFlush(llarp_time_t now) const;
@@ -40,10 +43,10 @@ namespace llarp
     FlushLinesToDisk(llarp_time_t now);
 
     thread::ThreadPool* m_Disk;
-    FILE* m_File;
+    FILE* const m_File;
     const llarp_time_t m_FlushInterval;
     llarp_time_t m_LastFlush = 0;
-    std::deque< std::string > m_Lines;
+    const bool m_Close;
   };
 }  // namespace llarp
 

llarp/util/json.hpp

@@ -12,6 +12,8 @@ namespace llarp
 {
   namespace json
   {
+    using Object = nlohmann::json;
+
     struct IParser
     {
       virtual ~IParser()
@@ -34,7 +36,7 @@ namespace llarp
       FeedData(const char* buf, size_t sz) = 0;
       /// parse internal buffer
       virtual Result
-      Parse(nlohmann::json& obj) const = 0;
+      Parse(Object& obj) const = 0;
     };
 
     /// create new parser

llarp/util/json_logger.cpp

@@ -0,0 +1,20 @@
+#include <util/json_logger.hpp>
+#include <util/json.hpp>
+
+namespace llarp
+{
+  void
+  JSONLogStream::AppendLog(LogLevel lvl, const char* fname, int lineno,
+                           const std::string& nodename, const std::string msg)
+  {
+    json::Object obj;
+    obj["time"]     = llarp::time_now_ms();
+    obj["nickname"] = nodename;
+    obj["file"]     = std::string(fname);
+    obj["line"]     = lineno;
+    obj["level"]    = LogLevelToString(lvl);
+    obj["message"]  = msg;
+    m_Lines.emplace_back(obj.dump());
+  }
+
+}  // namespace llarp

llarp/util/json_logger.hpp

@@ -0,0 +1,22 @@
+#ifndef LLARP_UTIL_JSON_LOGGER
+#define LLARP_UTIL_JSON_LOGGER
+
+#include <util/file_logger.hpp>
+
+namespace llarp
+{
+  struct JSONLogStream : public FileLogStream
+  {
+    JSONLogStream(thread::ThreadPool* disk, FILE* f, llarp_time_t flushInterval,
+                  bool closeFile)
+        : FileLogStream(disk, f, flushInterval, closeFile)
+    {
+    }
+
+    void
+    AppendLog(LogLevel lvl, const char* fname, int lineno,
+              const std::string& nodename, const std::string msg) override;
+  };
+}  // namespace llarp
+
+#endif

llarp/util/logger.hpp

@@ -85,7 +85,7 @@ namespace llarp
     LogContext();
     LogLevel minLevel = eLogInfo;
     ILogStream_ptr logStream;
-    std::string nodeName;
+    std::string nodeName = "lokinet";
 
     const llarp_time_t started;
 
@@ -106,12 +106,8 @@ namespace llarp
       return;
 
     std::stringstream ss;
-    log.logStream->PreLog(ss, lvl, fname, lineno);
-    if(log.nodeName.size())
-      LogAppend(ss, "[", log.nodeName, "] ");
     LogAppend(ss, std::forward< TArgs >(args)...);
-    log.logStream->PostLog(ss);
-    log.logStream->Print(lvl, fname, ss.str());
+    log.logStream->AppendLog(lvl, fname, lineno, log.nodeName, ss.str());
   }
   /*
     std::stringstream ss;

llarp/util/logger_syslog.hpp

@@ -8,8 +8,8 @@ namespace llarp
   struct SysLogStream : public ILogStream
   {
     void
-    PreLog(std::stringstream& s, LogLevel lvl, const char* fname,
-           int lineno) const override;
+    PreLog(std::stringstream& s, LogLevel lvl, const char* fname, int lineno,
+           const std::string& nodename) const override;
 
     void
     Print(LogLevel lvl, const char* tag, const std::string& msg) override;

llarp/util/loglevel.cpp

@@ -0,0 +1,22 @@
+#include <util/loglevel.hpp>
+
+namespace llarp
+{
+  std::string
+  LogLevelToString(LogLevel lvl)
+  {
+    switch(lvl)
+    {
+      case eLogDebug:
+        return "DBG";
+      case eLogInfo:
+        return "NFO";
+      case eLogWarn:
+        return "WRN";
+      case eLogError:
+        return "ERR";
+      default:
+        return "???";
+    }
+  }
+}  // namespace llarp

llarp/util/loglevel.hpp

@@ -1,5 +1,6 @@
 #ifndef LLARP_UTIL_LOG_LEVEL_HPP
 #define LLARP_UTIL_LOG_LEVEL_HPP
+#include <string>
 
 namespace llarp
 {
@@ -13,6 +14,9 @@ namespace llarp
     eLogNone
   };
 
+  std::string
+  LogLevelToString(LogLevel level);
+
 }  // namespace llarp
 
 #endif

llarp/util/logstream.hpp

@@ -16,14 +16,26 @@ namespace llarp
     }
 
     virtual void
-    PreLog(std::stringstream& out, LogLevel lvl, const char* fname,
-           int lineno) const = 0;
+    PreLog(std::stringstream& out, LogLevel lvl, const char* fname, int lineno,
+           const std::string& nodename) const = 0;
+
     virtual void
     Print(LogLevel lvl, const char* filename, const std::string& msg) = 0;
 
     virtual void
     PostLog(std::stringstream& out) const = 0;
 
+    virtual void
+    AppendLog(LogLevel lvl, const char* fname, int lineno,
+              const std::string& nodename, const std::string msg)
+    {
+      std::stringstream ss;
+      PreLog(ss, lvl, fname, lineno, nodename);
+      ss << msg;
+      PostLog(ss);
+      Print(lvl, fname, ss.str());
+    }
+
     /// called every end of event loop tick
     virtual void
     Tick(llarp_time_t now) = 0;

llarp/util/ostream_logger.cpp

@@ -9,7 +9,8 @@ namespace llarp
 
   void
   OStreamLogStream::PreLog(std::stringstream& ss, LogLevel lvl,
-                           const char* fname, int lineno) const
+                           const char* fname, int lineno,
+                           const std::string& nodename) const
   {
     switch(lvl)
     {
@@ -17,23 +18,20 @@ namespace llarp
         break;
       case eLogDebug:
         ss << (char)27 << "[0m";
-        ss << "[DBG] ";
         break;
       case eLogInfo:
         ss << (char)27 << "[1m";
-        ss << "[NFO] ";
         break;
       case eLogWarn:
         ss << (char)27 << "[1;33m";
-        ss << "[WRN] ";
         break;
       case eLogError:
         ss << (char)27 << "[1;31m";
-        ss << "[ERR] ";
         break;
     }
-
-    ss << "(" << thread_id_string() << ") " << log_timestamp() << " " << fname
+    ss << "[" << LogLevelToString(lvl) << "] ";
+    ss << "[" << nodename << "]"
+       << "(" << thread_id_string() << ") " << log_timestamp() << " " << fname
        << ":" << lineno << "\t";
   }
 

llarp/util/ostream_logger.hpp

@@ -15,8 +15,8 @@ namespace llarp
     }
 
     virtual void
-    PreLog(std::stringstream& s, LogLevel lvl, const char* fname,
-           int lineno) const override;
+    PreLog(std::stringstream& s, LogLevel lvl, const char* fname, int lineno,
+           const std::string& nodename) const override;
 
     void
     Print(LogLevel lvl, const char* tag, const std::string& msg) override;

llarp/util/syslog_logger.cpp

@@ -6,27 +6,11 @@ namespace llarp
 {
   void
   SysLogStream::PreLog(std::stringstream& ss, LogLevel lvl, const char* fname,
-                       int lineno) const
+                       int lineno, const std::string& nodename) const
   {
-    switch(lvl)
-    {
-      case eLogNone:
-        break;
-      case eLogDebug:
-        ss << "[DBG] ";
-        break;
-      case eLogInfo:
-        ss << "[NFO] ";
-        break;
-      case eLogWarn:
-        ss << "[WRN] ";
-        break;
-      case eLogError:
-        ss << "[ERR] ";
-        break;
-    }
-
-    ss << "(" << thread_id_string() << ") " << log_timestamp() << " " << fname
+    ss << "[" << LogLevelToString(lvl) << "] ";
+    ss << "[" << nodename << "]"
+       << "(" << thread_id_string() << ") " << log_timestamp() << " " << fname
        << ":" << lineno << "\t";
   }