a couple small quic fixes and much debugging

contrib/liblokinet/tcp_connect.cpp

@@ -69,7 +69,8 @@ main(int argc, char* argv[])
   }
 
   // log level debug for quic
-  llarp::log::set_level("quic", llarp::log::Level::debug);
+  llarp::log::set_level("quic", llarp::log::Level::trace);
+  std::cout << "\n\nquic log level: " << llarp::log::to_string(llarp::log::get_level("quic")) << "\n\n";
 
   auto addr_c = lokinet_address(ctx);
   std::string addr{addr_c};
@@ -84,7 +85,7 @@ main(int argc, char* argv[])
 
   std::string target{argv[1]};
   target += ":12345";
-  lokinet_outbound_stream(&stream_res, target.c_str(), nullptr, ctx);
+  lokinet_outbound_stream(&stream_res, target.c_str(), "127.0.0.1:54321", ctx);
 
   if (stream_res.error)
   {

llarp/lokinet_shared.cpp

@@ -714,8 +714,9 @@ extern "C"
         }
         try
         {
+          // FIXME: callback for client-land?
           auto [addr, id] = quic->open(
-              remotehost, remoteport, [](auto) {}, localAddr);
+              remotehost, remoteport, [](bool success) {}, localAddr);
           auto [host, port] = split_host_port(addr.ToString());
           ctx->outbound_stream(id);
           stream_okay(result, host, port, id);

llarp/quic/connection.cpp

@@ -245,6 +245,7 @@ namespace llarp::quic
       log::trace(logcat, "{} called", __PRETTY_FUNCTION__);
       return static_cast<Connection*>(user_data)->stream_opened({stream_id});
     }
+
     int
     stream_close_cb(
         ngtcp2_conn* conn,
@@ -258,6 +259,19 @@ namespace llarp::quic
       static_cast<Connection*>(user_data)->stream_closed({stream_id}, app_error_code);
       return 0;
     }
+    int
+    stream_reset_cb(
+        ngtcp2_conn* conn,
+        int64_t stream_id,
+        uint64_t final_size,
+        uint64_t app_error_code,
+        void* user_data,
+        void* stream_user_data)
+    {
+      log::trace(logcat, "{} called", __PRETTY_FUNCTION__);
+      static_cast<Connection*>(user_data)->stream_closed({stream_id}, app_error_code);
+      return 0;
+    }
 
     // (client only)
     int
@@ -394,6 +408,7 @@ namespace llarp::quic
     cb.acked_stream_data_offset = acked_stream_data_offset;
     cb.stream_open = stream_open;
     cb.stream_close = stream_close_cb;
+    cb.stream_reset = stream_reset_cb;
     cb.extend_max_local_streams_bidi = extend_max_local_streams_bidi;
     cb.rand = rand;
     cb.get_new_connection_id = get_new_connection_id;
@@ -419,7 +434,7 @@ namespace llarp::quic
     // streams they initiate to us):
     tparams.initial_max_stream_data_bidi_local = STREAM_BUFFER;
     tparams.initial_max_stream_data_bidi_remote = STREAM_BUFFER;
-    // Max *cumulative* streams we support on a connection:
+    // Max *concurrent* streams we support on a connection:
     tparams.initial_max_streams_bidi = STREAM_LIMIT;
     tparams.initial_max_streams_uni = 0;
     tparams.max_idle_timeout = std::chrono::nanoseconds(IDLE_TIMEOUT).count();
@@ -759,6 +774,12 @@ namespace llarp::quic
   Connection::schedule_retransmit()
   {
     auto exp = ngtcp2_conn_get_expiry(*this);
+    auto expiry = std::chrono::nanoseconds{static_cast<std::chrono::nanoseconds::rep>(exp)};
+    auto ngtcp2_expiry_delta = std::chrono::duration_cast<std::chrono::milliseconds>(
+        expiry - get_time().time_since_epoch());
+
+    log::trace(logcat, "ngtcp2_conn_get_expiry: {}ms from now", ngtcp2_expiry_delta);
+
     if (exp == std::numeric_limits<decltype(exp)>::max())
     {
       log::trace(logcat, "no retransmit currently needed");
@@ -766,11 +787,7 @@ namespace llarp::quic
       return;
     }
 
-    auto expiry = std::chrono::nanoseconds{static_cast<std::chrono::nanoseconds::rep>(exp)};
-    auto expires_in = std::max(
-        0ms,
-        std::chrono::duration_cast<std::chrono::milliseconds>(
-            expiry - get_time().time_since_epoch()));
+    auto expires_in = std::max(0ms, ngtcp2_expiry_delta);
     log::trace(logcat, "Next retransmit in {}ms", expires_in.count());
     retransmit_timer->stop();
     retransmit_timer->start(expires_in, 0ms);

llarp/quic/endpoint.cpp

@@ -162,7 +162,10 @@ namespace llarp::quic
       log::warning(logcat, "read pkt error: {}", ngtcp2_strerror(rv));
 
     if (rv == NGTCP2_ERR_DRAINING)
+    {
+      log::debug(logcat, "Draining connection {}", conn.base_cid);
       start_draining(conn);
+    }
     else if (rv == NGTCP2_ERR_DROP_CONN)
       delete_conn(conn.base_cid);
 
@@ -319,8 +322,13 @@ namespace llarp::quic
       {
         Connection& conn = **conn_ptr;
         auto exp = ngtcp2_conn_get_expiry(conn);
-        if (exp >= now_ts || conn.draining)
+
+        // a bit of buffer on the expiration time in case the last call to
+        // ngtcp2_conn_get_expiry() returned ~0ms from now and the connection
+        // hasn't had time to handle it yet.  2ms should do.
+        if (exp >= (now_ts - 2'000'000) || conn.draining)
           continue;
+        log::debug(logcat, "Draining connection {}", it->first);
         start_draining(conn);
       }
     }

llarp/quic/tunnel.cpp

@@ -601,7 +601,11 @@ namespace llarp::quic
     conn->on_stream_available = [this, id = row.first](Connection&) {
       log::debug(logcat, "QUIC connection :{} established; streams now available", id);
       if (auto it = client_tunnels_.find(id); it != client_tunnels_.end())
+      {
         flush_pending_incoming(it->second);
+        if (it->second.open_cb)
+          it->second.open_cb(true);
+      }
     };
   }