Merge pull request #523 from majestrate/master

recent stability pokes

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/dht/context.cpp

@@ -329,7 +329,10 @@ namespace llarp
       if(left)
         return;
       Context* ctx = static_cast< Context* >(u);
-      ctx->Explore(1);
+      const auto num =
+          std::min(ctx->router->NumberOfConnectedRouters(), size_t(4));
+      if(num)
+        ctx->Explore(num);
       ctx->router->logic()->call_later({orig, ctx, &handle_explore_timer});
     }
 

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

llarp/ev/ev_win32.hpp

@@ -114,22 +114,6 @@ struct llarp_win32_loop : public llarp_ev_loop
   udp_listen(llarp_udp_io* l, const sockaddr* src);
 
   ~llarp_win32_loop();
-
-  bool
-  running() const;
-
-  bool
-  init();
-
-  int
-  tick(int ms);
-
-  int
-  run();
-
-  int
-  udp_bind(const sockaddr* addr);
-
   bool
   close_ev(llarp::ev_io* ev);
 

llarp/nodedb.cpp

@@ -18,13 +18,16 @@ static const std::string RC_FILE_EXT = ".signed";
 bool
 llarp_nodedb::Remove(const llarp::RouterID &pk)
 {
-  llarp::util::Lock lock(&access);
-  auto itr = entries.find(pk);
-  if(itr == entries.end())
+  bool removed = false;
+  RemoveIf([&](const llarp::RouterContact &rc) -> bool {
+    if(rc.pubkey == pk)
+    {
+      removed = true;
+      return true;
+    }
     return false;
-  entries.erase(itr);
-  fs::remove(fs::path(getRCFilePath(pk)));
-  return true;
+  });
+  return removed;
 }
 
 void

llarp/path/path.cpp

@@ -462,8 +462,9 @@ namespace llarp
     void
     Path::EnterState(PathStatus st, llarp_time_t now)
     {
-      if(st == ePathTimeout && _status == ePathBuilding)
+      if(st == ePathExpired && _status == ePathBuilding)
       {
+        _status = st;
         m_PathSet->HandlePathBuildTimeout(this);
       }
       else if(st == ePathBuilding)
@@ -481,6 +482,10 @@ namespace llarp
         _status = st;
         m_PathSet->HandlePathDied(this);
       }
+      else if(st == ePathEstablished && _status == ePathTimeout)
+      {
+        LogInfo("path ", Name(), " reanimated");
+      }
       _status = st;
     }
 
@@ -551,12 +556,11 @@ namespace llarp
           if(dlt >= path::build_timeout)
           {
             r->routerProfiling().MarkPathFail(this);
-            EnterState(ePathTimeout, now);
+            EnterState(ePathExpired, now);
             return;
           }
         }
       }
-
       // check to see if this path is dead
       if(_status == ePathEstablished)
       {
@@ -624,7 +628,7 @@ namespace llarp
     bool
     Path::Expired(llarp_time_t now) const
     {
-      if(_status == ePathEstablished)
+      if(_status == ePathEstablished || _status == ePathTimeout)
         return now >= ExpireTime();
       else if(_status == ePathBuilding)
         return false;

llarp/path/pathbuilder.cpp

@@ -216,8 +216,7 @@ namespace llarp
         router->ForEachPeer(
             [&](const ILinkSession* s, bool) {
               const PubKey k(s->GetPubKey());
-              if(got || router->IsBootstrapNode(k)
-                 || router->routerProfiling().IsBad(k))
+              if(got || router->IsBootstrapNode(k))
                 return;
               cur = s->GetRemoteRC();
               got = true;
@@ -232,7 +231,7 @@ namespace llarp
         --tries;
         if(db->select_random_hop_excluding(cur, exclude))
         {
-          if(!router->routerProfiling().IsBad(cur.pubkey))
+          if(!router->routerProfiling().IsBadForPath(cur.pubkey))
             return true;
           exclude.insert(cur.pubkey);
         }
@@ -276,6 +275,8 @@ namespace llarp
     bool
     Builder::ShouldBuildMore(llarp_time_t now) const
     {
+      if(IsStopped())
+        return false;
       if(llarp::randint() % 3 >= 1)
         return PathSet::ShouldBuildMore(now) && !BuildCooldownHit(now);
       return false;

llarp/path/pathbuilder.hpp

@@ -13,7 +13,7 @@ namespace llarp
   namespace path
   {
     // milliseconds waiting between builds on a path
-    constexpr llarp_time_t MIN_PATH_BUILD_INTERVAL = 5 * 1000;
+    constexpr llarp_time_t MIN_PATH_BUILD_INTERVAL = 1000;
 
     struct Builder : public PathSet, public util::IStateful
     {

llarp/profiling.cpp

@@ -52,19 +52,17 @@ namespace llarp
     connectTimeoutCount /= 2;
     pathSuccessCount /= 2;
     pathFailCount /= 2;
-    lastUpdated = llarp::time_now_ms();
+    lastDecay = llarp::time_now_ms();
   }
 
   void
   RouterProfile::Tick()
   {
-    // 5 minutes
-    static constexpr llarp_time_t updateInterval = path::default_lifetime / 2;
-    auto now                                     = llarp::time_now_ms();
-    if(lastUpdated < now && now - lastUpdated > updateInterval)
-    {
+    // 15 seconds
+    static constexpr llarp_time_t updateInterval = 15 * 1000;
+    const auto now                               = llarp::time_now_ms();
+    if(lastDecay < now && now - lastDecay > updateInterval)
       Decay();
-    }
   }
 
   bool
@@ -76,6 +74,48 @@ namespace llarp
     return (pathSuccessCount * chances) > pathFailCount;
   }
 
+  static bool constexpr checkIsGood(uint64_t fails, uint64_t success,
+                                    uint64_t chances)
+  {
+    if(fails > 0 && (fails + success) >= chances)
+      return (success / fails) > 2;
+    if(success == 0)
+      return fails < chances;
+    return true;
+  }
+
+  bool
+  RouterProfile::IsGoodForConnect(uint64_t chances) const
+  {
+    return checkIsGood(connectTimeoutCount, connectGoodCount, chances);
+  }
+
+  bool
+  RouterProfile::IsGoodForPath(uint64_t chances) const
+  {
+    return checkIsGood(pathFailCount, pathSuccessCount, chances);
+  }
+
+  bool
+  Profiling::IsBadForConnect(const RouterID& r, uint64_t chances)
+  {
+    lock_t lock(&m_ProfilesMutex);
+    auto itr = m_Profiles.find(r);
+    if(itr == m_Profiles.end())
+      return false;
+    return !itr->second.IsGoodForConnect(chances);
+  }
+
+  bool
+  Profiling::IsBadForPath(const RouterID& r, uint64_t chances)
+  {
+    lock_t lock(&m_ProfilesMutex);
+    auto itr = m_Profiles.find(r);
+    if(itr == m_Profiles.end())
+      return false;
+    return !itr->second.IsGoodForPath(chances);
+  }
+
   bool
   Profiling::IsBad(const RouterID& r, uint64_t chances)
   {

llarp/profiling.hpp

@@ -19,6 +19,7 @@ namespace llarp
     uint64_t pathSuccessCount       = 0;
     uint64_t pathFailCount          = 0;
     llarp_time_t lastUpdated        = 0;
+    llarp_time_t lastDecay          = 0;
 
     RouterProfile() : IBEncodeMessage(){};
 
@@ -33,6 +34,12 @@ namespace llarp
     bool
     IsGood(uint64_t chances) const;
 
+    bool
+    IsGoodForConnect(uint64_t chances) const;
+
+    bool
+    IsGoodForPath(uint64_t chances) const;
+
     /// decay stats
     void
     Decay();
@@ -52,10 +59,21 @@ namespace llarp
     {
     }
 
+    /// generic variant
     bool
     IsBad(const RouterID& r, uint64_t chances = 8)
         LOCKS_EXCLUDED(m_ProfilesMutex);
 
+    /// check if this rotuer should have paths built over it
+    bool
+    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)
+        LOCKS_EXCLUDED(m_ProfilesMutex);
+
     void
     MarkTimeout(const RouterID& r) LOCKS_EXCLUDED(m_ProfilesMutex);
 

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>
@@ -71,15 +72,16 @@ struct TryConnectJob
   void
   AttemptTimedout()
   {
-    router->routerProfiling().MarkTimeout(rc.pubkey);
     if(ShouldRetry())
     {
       Attempt();
       return;
     }
+    router->routerProfiling().MarkTimeout(rc.pubkey);
     if(router->routerProfiling().IsBad(rc.pubkey))
     {
-      router->nodedb()->Remove(rc.pubkey);
+      if(!router->IsBootstrapNode(rc.pubkey))
+        router->nodedb()->Remove(rc.pubkey);
     }
     // delete this
     router->pendingEstablishJobs.erase(rc.pubkey);
@@ -638,7 +640,7 @@ namespace llarp
       // try connecting async
       TryConnectAsync(rc, 5);
     }
-    else if(IsServiceNode() || !routerProfiling().IsBad(remote))
+    else if(IsServiceNode())
     {
       if(dht()->impl->HasRouterLookup(remote))
         return;
@@ -846,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"))
     {
@@ -1102,7 +1126,7 @@ namespace llarp
         if(!routerProfiling().IsBad(rc.pubkey))
           return false;
         routerProfiling().ClearProfile(rc.pubkey);
-        return true;
+        return !IsBootstrapNode(rc.pubkey);
       });
     }
     paths.TickPaths(now);
@@ -1146,9 +1170,6 @@ namespace llarp
       {
         for(const auto &rc : bootstrapRCList)
         {
-          if(HasPendingConnectJob(rc.pubkey))
-            continue;
-          TryConnectAsync(rc, 4);
           dht()->impl->ExploreNetworkVia(dht::Key_t{rc.pubkey});
         }
       }
@@ -1411,6 +1432,9 @@ namespace llarp
     llarp_threadpool_start(tp);
     llarp_threadpool_start(disk);
 
+    for(const auto &rc : bootstrapRCList)
+      this->nodedb()->InsertAsync(rc);
+
     routerProfiling().Load(routerProfilesFile.c_str());
 
     Addr publicAddr(this->addrInfo);
@@ -1690,12 +1714,8 @@ namespace llarp
          && !(self->HasSessionTo(other.pubkey)
               || self->HasPendingConnectJob(other.pubkey)))
       {
-        for(const auto &rc : self->bootstrapRCList)
-        {
-          if(rc.pubkey == other.pubkey)
-            return want > 0;
-        }
-        self->TryConnectAsync(other, 5);
+        if(!self->IsBootstrapNode(other.pubkey))
+          self->TryConnectAsync(other, 5);
         --want;
       }
       return want > 0;

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

@@ -113,7 +113,7 @@ namespace llarp
       m_IntroSet.I.clear();
       for(const auto& intro : I)
       {
-        if(router->routerProfiling().IsBad(intro.router))
+        if(router->routerProfiling().IsBadForPath(intro.router))
           continue;
         m_IntroSet.I.push_back(intro);
       }
@@ -1431,7 +1431,7 @@ namespace llarp
                                    if(c)
                                      c->UpdateIntroSet(true);
                                  },
-                                 5000, false);
+                                 5000, true);
     }
 
     bool
@@ -1445,13 +1445,7 @@ namespace llarp
       {
         if(hop == 0)
         {
-          // first hop
-          if(router->NumberOfConnectedRouters())
-          {
-            if(!router->GetRandomConnectedRouter(hops[0]))
-              return false;
-          }
-          else
+          if(!SelectHop(nodedb, hops[0], hops[0], 0, path::ePathRoleAny))
             return false;
         }
         else if(hop == numHops - 1)
@@ -1466,11 +1460,12 @@ namespace llarp
           size_t tries = 5;
           do
           {
-            nodedb->select_random_hop(hops[hop - 1], hops[hop], hop);
+            nodedb->select_random_hop_excluding(hops[hop],
+                                                {hops[hop - 1].pubkey, remote});
             --tries;
-          } while(
-              m_Endpoint->Router()->routerProfiling().IsBad(hops[hop].pubkey)
-              && tries > 0);
+          } while(m_Endpoint->Router()->routerProfiling().IsBadForPath(
+                      hops[hop].pubkey)
+                  && tries > 0);
           return tries > 0;
         }
         return false;
@@ -1492,7 +1487,7 @@ namespace llarp
       {
         if(intro.ExpiresSoon(now))
           continue;
-        if(router->routerProfiling().IsBad(intro.router))
+        if(router->routerProfiling().IsBadForPath(intro.router))
           continue;
         auto itr = m_BadIntros.find(intro);
         if(itr == m_BadIntros.end() && intro.router == m_NextIntro.router)

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/bencode.cpp

@@ -77,7 +77,8 @@ bencode_write_uint64(llarp_buffer_t* buff, uint64_t i)
 {
 // NetBSDs also do this shit in long mode, wouldn't be surprised
 // if all the BSDs do by default
-#if !defined(__LP64__) || (__APPLE__ && __MACH__) || (__NetBSD__) || (__OpenBSD__)
+#if !defined(__LP64__) || (__APPLE__ && __MACH__) || (__NetBSD__) \
+    || (__OpenBSD__)
   if(!buff->writef("i%llu", i))
 #else
   if(!buff->writef("i%lu", i))

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/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);