more debug logging

timed out paths are not expired

include/llarp/path.hpp

@@ -236,7 +236,7 @@ namespace llarp
       llarp::service::Introduction intro;
 
       llarp_time_t buildStarted;
-      PathStatus status;
+      PathStatus _status;
 
       Path(const std::vector< RouterContact >& routers);
 
@@ -261,6 +261,19 @@ namespace llarp
         m_CheckForDead = func;
       }
 
+      void
+      EnterState(PathStatus st)
+      {
+        if(st == ePathTimeout)
+          llarp::LogInfo("path ", Name(), " has timed out");
+        else if(st == ePathBuilding)
+        {
+          llarp::LogInfo("path ", Name(), " is building");
+          buildStarted = llarp_time_now_ms();
+        }
+        _status = st;
+      }
+
       llarp_time_t
       ExpireTime() const
       {
@@ -329,6 +342,9 @@ namespace llarp
       RouterID
       Upstream() const;
 
+      std::string
+      Name() const;
+
      protected:
       llarp::routing::InboundMessageParser m_InboundMessageParser;
 

llarp/path.cpp

@@ -371,7 +371,7 @@ namespace llarp
     bool
     Path::IsReady() const
     {
-      return intro.latency > 0 && status == ePathEstablished;
+      return intro.latency > 0 && _status == ePathEstablished;
     }
 
     RouterID
@@ -401,10 +401,10 @@ namespace llarp
       if(m_CheckForDead)
       {
         if(m_CheckForDead(this, dlt))
-          status = ePathTimeout;
+          EnterState(ePathTimeout);
       }
       else if(dlt >= 10000)
-        status = ePathTimeout;
+        EnterState(ePathTimeout);
     }
 
     bool
@@ -430,14 +430,24 @@ namespace llarp
     bool
     Path::Expired(llarp_time_t now) const
     {
-      if(status == ePathEstablished)
+      if(_status == ePathEstablished)
         return now - buildStarted > hops[0].lifetime;
-      else if(status == ePathBuilding)
+      else if(_status == ePathBuilding)
         return now - buildStarted > PATH_BUILD_TIMEOUT;
+      else if(_status == ePathTimeout)
+        return false;
       else
         return true;
     }
 
+    std::string
+    Path::Name() const
+    {
+      std::stringstream ss;
+      ss << "TX=" << TXID() << " RX=" << RXID();
+      return ss.str();
+    }
+
     bool
     Path::HandleDownstream(llarp_buffer_t buf, const TunnelNonce& Y,
                            llarp_router* r)
@@ -511,12 +521,12 @@ namespace llarp
     Path::HandlePathConfirmMessage(
         const llarp::routing::PathConfirmMessage* msg, llarp_router* r)
     {
-      if(status == ePathBuilding)
+      if(_status == ePathBuilding)
       {
         // finish initializing introduction
         intro.expiresAt = buildStarted + hops[0].lifetime;
         // confirm that we build the path
-        status = ePathEstablished;
+        EnterState(ePathEstablished);
         llarp::LogInfo("path is confirmed tx=", TXID(), " rx=", RXID(),
                        " took ", llarp_time_now_ms() - buildStarted, " ms");
         if(m_BuiltHook)
@@ -550,7 +560,7 @@ namespace llarp
     Path::HandlePathLatencyMessage(
         const llarp::routing::PathLatencyMessage* msg, llarp_router* r)
     {
-      if(msg->L == m_LastLatencyTestID && status == ePathEstablished)
+      if(msg->L == m_LastLatencyTestID && _status == ePathEstablished)
       {
         intro.latency = llarp_time_now_ms() - m_LastLatencyTestTime;
         llarp::LogInfo("path latency is ", intro.latency, " ms for tx=", TXID(),

llarp/pathbuilder.cpp

@@ -143,8 +143,7 @@ namespace llarp
       return;
     }
 
-    ctx->path->status       = llarp::path::ePathBuilding;
-    ctx->path->buildStarted = llarp_time_now_ms();
+    ctx->path->EnterState(llarp::path::ePathBuilding);
     // persist session with router until this path is done
     router->PersistSessionUntil(remote, ctx->path->ExpireTime());
     // add own path

llarp/pathset.cpp

@@ -22,7 +22,8 @@ namespace llarp
     {
       for(auto& item : m_Paths)
       {
-        if(item.second->status == ePathEstablished)
+        auto st = item.second->_status;
+        if(st == ePathTimeout || st == ePathEstablished)
         {
           item.second->Tick(now, r);
         }
@@ -103,7 +104,7 @@ namespace llarp
       auto itr     = m_Paths.begin();
       while(itr != m_Paths.end())
       {
-        if(itr->second->status == st)
+        if(itr->second->_status == st)
           ++count;
         ++itr;
       }

llarp/service/endpoint.cpp

@@ -832,25 +832,30 @@ namespace llarp
       if(itr == m_PendingTraffic.end())
       {
         m_PendingTraffic.insert(std::make_pair(remote, PendingBufferQueue()));
-        EnsurePathToService(remote,
-                            [&](Address addr, OutboundContext* ctx) {
-                              if(ctx)
-                              {
-                                auto itr = m_PendingTraffic.find(addr);
-                                if(itr != m_PendingTraffic.end())
-                                {
-                                  while(itr->second.size())
-                                  {
-                                    auto& front = itr->second.front();
-                                    ctx->AsyncEncryptAndSendTo(front.Buffer(),
-                                                               front.protocol);
-                                    itr->second.pop();
-                                  }
-                                }
-                              }
-                              m_PendingTraffic.erase(addr);
-                            },
-                            10000);
+        EnsurePathToService(
+            remote,
+            [&](Address addr, OutboundContext* ctx) {
+              if(ctx)
+              {
+                auto itr = m_PendingTraffic.find(addr);
+                if(itr != m_PendingTraffic.end())
+                {
+                  while(itr->second.size())
+                  {
+                    auto& front = itr->second.front();
+                    ctx->AsyncEncryptAndSendTo(front.Buffer(), front.protocol);
+                    itr->second.pop();
+                  }
+                }
+              }
+              else
+              {
+                llarp::LogWarn("failed to obtain outbound context to ", addr,
+                               " within timeout");
+              }
+              m_PendingTraffic.erase(addr);
+            },
+            10000);
       }
       m_PendingTraffic[remote].emplace(data, t);
       return true;
@@ -860,9 +865,13 @@ namespace llarp
     Endpoint::OutboundContext::ShiftIntroduction()
     {
       bool shifted = false;
+      auto now     = llarp_time_t();
       for(const auto& intro : currentIntroSet.I)
       {
         m_Parent->EnsureRouterIsKnown(selectedIntro.router);
+        // check for stale intro
+        if(intro.expiresAt < now)
+          continue;
         if(selectedIntro.expiresAt < intro.expiresAt)
         {
           selectedIntro = intro;
@@ -881,6 +890,10 @@ namespace llarp
       if(!path)
       {
         llarp::LogError(Name(), " No Path to ", selectedIntro.router, " yet");
+        if(selectedIntro.ExpiresSoon(llarp_time_now_ms()))
+        {
+          ShiftIntroduction();
+        }
         return;
       }
       if(sequenceNo)