add disk worker based file flusher logger

make format

remove package.json

contrib/node/package.json

@@ -1,12 +0,0 @@
-{
-    "name": "lokinet",
-    "version": "0.0.0",
-    "description": "lokinet god awful node binding",
-    "main": "lokinet.js",
-    "private": true,
-    "gypfile": true,
-    "dependencies": {
-        "bindings": "~1.2.1",
-        "node-addon-api": "^1.0.0"
-    }
-}

llarp/CMakeLists.txt

@@ -16,6 +16,7 @@ set(LIB_UTIL_SRC
   util/json.cpp
   util/logger.cpp
   util/android_logger.cpp
+  util/file_logger.cpp
   util/ostream_logger.cpp
   util/syslog_logger.cpp
   util/win32_logger.cpp

llarp/ev/ev.cpp

@@ -54,6 +54,9 @@ llarp_ev_loop_run_single_process(llarp_ev_loop_ptr ev,
       ev->update_time();
       logic->tick_async(ev->time_now());
       llarp_threadpool_tick(tp);
+      // tick log stream at the VERY END of the tick cycle so that all logs
+      // flush
+      llarp::LogContext::Instance().logStream->Tick(ev->time_now());
     }
   }
 }

llarp/ev/ev_sun.hpp

@@ -78,8 +78,7 @@ namespace llarp
   };
 };  // namespace llarp
 
-struct llarp_poll_loop
-    : public llarp_ev_loop,
+struct llarp_poll_loop : public llarp_ev_loop,
                          public std::enable_shared_from_this< llarp_poll_loop >
 {
   upoll_t* upollfd;

llarp/profiling.cpp

@@ -76,7 +76,8 @@ namespace llarp
     return (pathSuccessCount * chances) > pathFailCount;
   }
 
-  static bool constexpr checkIsGood(uint64_t fails, uint64_t success, uint64_t chances)
+  static bool constexpr checkIsGood(uint64_t fails, uint64_t success,
+                                    uint64_t chances)
   {
     if(fails > 0)
       return success / fails > chances;
@@ -98,7 +99,7 @@ namespace llarp
   }
 
   bool
-  Profiling::IsBadForConnect(const RouterID & r, uint64_t chances)
+  Profiling::IsBadForConnect(const RouterID& r, uint64_t chances)
   {
     lock_t lock(&m_ProfilesMutex);
     auto itr = m_Profiles.find(r);
@@ -108,7 +109,7 @@ namespace llarp
   }
 
   bool
-  Profiling::IsBadForPath(const RouterID & r, uint64_t chances)
+  Profiling::IsBadForPath(const RouterID& r, uint64_t chances)
   {
     lock_t lock(&m_ProfilesMutex);
     auto itr = m_Profiles.find(r);

llarp/profiling.hpp

@@ -65,12 +65,12 @@ namespace llarp
 
     /// check if this rotuer should have paths built over it
     bool
-    IsBadForPath(const RouterID & r, uint64_t chances = 8)
+    IsBadForPath(const RouterID& r, uint64_t chances = 8)
         LOCK_RETURNED(m_ProfilesMutex);
 
     /// check if this router should be connected directly to
     bool
-    IsBadForConnect(const RouterID & r, uint64_t chances = 8)
+    IsBadForConnect(const RouterID& r, uint64_t chances = 8)
         LOCKS_EXCLUDED(m_ProfilesMutex);
 
     void

llarp/router/router.cpp

@@ -14,6 +14,7 @@
 #include <util/buffer.hpp>
 #include <util/encode.hpp>
 #include <util/logger.hpp>
+#include <util/file_logger.hpp>
 #include <util/logger_syslog.hpp>
 #include <util/metrics.hpp>
 #include <util/str.hpp>
@@ -847,6 +848,28 @@ namespace llarp
         LogContext::Instance().logStream = std::make_unique< SysLogStream >();
 #endif
       }
+      if(StrEq(key, "file"))
+      {
+        LogInfo("open log file: ", val);
+        FILE *logfile = ::fopen(val, "a");
+        if(logfile)
+        {
+          LogContext::Instance().logStream =
+              std::make_unique< FileLogStream >(diskworker(), logfile, 500);
+          LogInfo("started logging to ", val);
+        }
+        else if(errno)
+        {
+          LogError("could not open log file at '", val, "': ", strerror(errno));
+          errno = 0;
+        }
+        else
+        {
+          LogError("failed to open log file at '", val,
+                   "' for an unknown reason, bailing tf out kbai");
+          ::abort();
+        }
+      }
     }
     else if(StrEq(section, "lokid"))
     {

llarp/router/router.hpp

@@ -86,6 +86,11 @@ namespace llarp
     // path to write our self signed rc to
     fs::path our_rc_file = "rc.signed";
 
+    // use file based logging?
+    bool m_UseFileLogging = false;
+    // default log file path
+    fs::path logfile = "lokinet.log";
+
     // our router contact
     RouterContact _rc;
 

llarp/service/endpoint.cpp

@@ -1460,10 +1460,11 @@ namespace llarp
           size_t tries = 5;
           do
           {
-            nodedb->select_random_hop_excluding(hops[hop], {hops[hop - 1].pubkey, remote});
+            nodedb->select_random_hop_excluding(hops[hop],
+                                                {hops[hop - 1].pubkey, remote});
             --tries;
-          } while(
-              m_Endpoint->Router()->routerProfiling().IsBadForPath(hops[hop].pubkey)
+          } while(m_Endpoint->Router()->routerProfiling().IsBadForPath(
+                      hops[hop].pubkey)
                   && tries > 0);
           return tries > 0;
         }

llarp/util/android_logger.cpp

@@ -36,8 +36,7 @@ namespace llarp
   }
 
   void
-  AndroidLogStream::Print(LogLevel lvl, const char* tag,
-                          const std::string& msg) const
+  AndroidLogStream::Print(LogLevel lvl, const char* tag, const std::string& msg)
   {
     std::string str("lokinet|");
     str += tag;

llarp/util/android_logger.hpp

@@ -13,7 +13,12 @@ namespace llarp
            int lineno) const override;
 
     void
-    Log(LogLevel lvl, const std::string& msg) const override;
+    Log(LogLevel lvl, const std::string& msg) override;
+
+    void
+    PostLog(std::stringstream&) const override{};
+
+    void Tick(llarp_time_t) override;
   };
 }  // namespace llarp
 

llarp/util/file_logger.cpp

@@ -0,0 +1,89 @@
+#include <util/file_logger.hpp>
+#include <util/logger_internal.hpp>
+
+namespace llarp
+{
+  FileLogStream::FileLogStream(llarp_threadpool *disk, FILE *f,
+                               llarp_time_t flushInterval)
+      : m_Disk(disk), m_File(f), m_FlushInterval(flushInterval)
+  {
+  }
+
+  FileLogStream::~FileLogStream()
+  {
+    fflush(m_File);
+    fclose(m_File);
+  }
+
+  bool
+  FileLogStream::ShouldFlush(llarp_time_t now) const
+  {
+    if(m_LastFlush >= now)
+      return false;
+    const auto dlt = now - m_LastFlush;
+    return dlt >= m_FlushInterval;
+  }
+
+  void
+  FileLogStream::PreLog(std::stringstream &ss, LogLevel lvl, const char *fname,
+                        int lineno) 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
+       << ":" << lineno << "\t";
+  }
+
+  void
+  FileLogStream::Print(LogLevel, const char *, const std::string &msg)
+  {
+    m_Lines.emplace_back(msg);
+  }
+
+  void
+  FileLogStream::Tick(llarp_time_t now)
+  {
+    if(ShouldFlush(now))
+      FlushLinesToDisk(now);
+  }
+
+  void
+  FileLogStream::FlushLinesToDisk(llarp_time_t now)
+  {
+    FlushEvent *ev = new FlushEvent(std::move(m_Lines), m_File);
+    llarp_threadpool_queue_job(m_Disk, {ev, &FlushEvent::HandleFlush});
+    m_LastFlush = now;
+  }
+
+  void
+  FileLogStream::FlushEvent::HandleFlush(void *user)
+  {
+    static_cast< FileLogStream::FlushEvent * >(user)->Flush();
+  }
+
+  void
+  FileLogStream::FlushEvent::Flush()
+  {
+    for(const auto &line : lines)
+      fprintf(f, "%s\n", line.c_str());
+    fflush(f);
+    delete this;
+  }
+
+}  // namespace llarp

llarp/util/file_logger.hpp

@@ -0,0 +1,61 @@
+#ifndef LLARP_UTIL_FILE_LOGGER_HPP
+#define LLARP_UTIL_FILE_LOGGER_HPP
+
+#include <util/logstream.hpp>
+#include <util/threadpool.h>
+#include <util/time.hpp>
+
+namespace llarp
+{
+  /// fluhsable file based log stream
+  struct FileLogStream : public ILogStream
+  {
+    FileLogStream(llarp_threadpool* disk, FILE* f, llarp_time_t flushInterval);
+
+    ~FileLogStream();
+
+    void
+    PreLog(std::stringstream& out, LogLevel lvl, const char* fname,
+           int lineno) const override;
+
+    void
+    Print(LogLevel, const char*, const std::string& msg) override;
+
+    void
+    Tick(llarp_time_t now) override;
+
+    void
+    PostLog(std::stringstream&) const override{};
+
+   private:
+    struct FlushEvent
+    {
+      FlushEvent(std::deque< std::string > l, FILE* file)
+          : lines(std::move(l)), f(file)
+      {
+      }
+
+      const std::deque< std::string > lines;
+      FILE* const f;
+
+      void
+      Flush();
+      static void
+      HandleFlush(void*);
+    };
+
+    bool
+    ShouldFlush(llarp_time_t now) const;
+
+    void
+    FlushLinesToDisk(llarp_time_t now);
+
+    llarp_threadpool* m_Disk;
+    FILE* m_File;
+    const llarp_time_t m_FlushInterval;
+    llarp_time_t m_LastFlush = 0;
+    std::deque< std::string > m_Lines;
+  };
+}  // namespace llarp
+
+#endif

llarp/util/logger_syslog.hpp

@@ -12,10 +12,12 @@ namespace llarp
            int lineno) const override;
 
     void
-    Print(LogLevel lvl, const char* tag, const std::string& msg) const override;
+    Print(LogLevel lvl, const char* tag, const std::string& msg) override;
 
     void
     PostLog(std::stringstream& ss) const override;
+
+    void Tick(llarp_time_t) override{};
   };
 }  // namespace llarp
 #endif

llarp/util/logstream.hpp

@@ -4,6 +4,8 @@
 #include <string>
 #include <util/loglevel.hpp>
 #include <sstream>
+#include <util/time.hpp>
+
 namespace llarp
 {
   /// logger stream interface
@@ -15,10 +17,14 @@ namespace llarp
     PreLog(std::stringstream& out, LogLevel lvl, const char* fname,
            int lineno) const = 0;
     virtual void
-    Print(LogLevel lvl, const char* filename, const std::string& msg) const = 0;
+    Print(LogLevel lvl, const char* filename, const std::string& msg) = 0;
 
     virtual void
     PostLog(std::stringstream& out) const = 0;
+
+    /// called every end of event loop tick
+    virtual void
+    Tick(llarp_time_t now) = 0;
   };
 
   using ILogStream_ptr = std::unique_ptr< ILogStream >;

llarp/util/ostream_logger.cpp

@@ -44,7 +44,7 @@ namespace llarp
   }
 
   void
-  OStreamLogStream::Print(LogLevel, const char*, const std::string& msg) const
+  OStreamLogStream::Print(LogLevel, const char*, const std::string& msg)
   {
     m_Out << msg;
   }

llarp/util/ostream_logger.hpp

@@ -19,11 +19,13 @@ namespace llarp
            int lineno) const override;
 
     void
-    Print(LogLevel lvl, const char* tag, const std::string& msg) const override;
+    Print(LogLevel lvl, const char* tag, const std::string& msg) override;
 
     virtual void
     PostLog(std::stringstream& ss) const override;
 
+    void Tick(llarp_time_t) override{};
+
    private:
     std::ostream& m_Out;
   };

llarp/util/syslog_logger.cpp

@@ -31,7 +31,7 @@ namespace llarp
   }
 
   void
-  SysLogStream::Print(LogLevel lvl, const char*, const std::string& msg) const
+  SysLogStream::Print(LogLevel lvl, const char*, const std::string& msg)
   {
     switch(lvl)
     {

llarp/util/threadpool.h

@@ -16,8 +16,8 @@ struct llarp_threadpool
   std::queue< std::function< void(void) > > jobs GUARDED_BY(m_access);
 
   llarp_threadpool(int workers, const char *name)
-      : impl(
-          std::make_unique< llarp::thread::ThreadPool >(workers, workers * 128))
+      : impl(std::make_unique< llarp::thread::ThreadPool >(workers,
+                                                           workers * 128))
   {
     (void)name;
   }

llarp/util/win32_logger.hpp

@@ -18,6 +18,8 @@ namespace llarp
     void
     PostLog(std::stringstream& s) const override;
 
+    void Tick(llarp_time_t) override{};
+
     bool isConsoleModern =
         true;  // qol fix so oldfag clients don't see ugly escapes
     HANDLE fd1 = GetStdHandle(STD_OUTPUT_HANDLE);