Revisit/reduce quic logging

Demote many things to Trace.

llarp/quic/connection.cpp

@@ -355,7 +355,7 @@ namespace llarp::quic
 
     if (!send_data.empty())
     {
-      LogDebug("Sending packet: ", buffer_printer{send_data});
+      LogTrace("Sending packet: ", buffer_printer{send_data});
       rv = endpoint.send_packet(path.remote, send_data, send_pkt_info.ecn);
     }
     return rv;
@@ -437,8 +437,6 @@ namespace llarp::quic
 
     cb.recv_client_initial = recv_client_initial;
 
-    LogDebug("header.type = ", header.type);
-
     // ConnectionIDs are a little complicated:
     // - when a client creates a new connection to us, it creates a random source connection ID
     //   *and* a random destination connection id.  The server won't have that connection ID, of
@@ -589,7 +587,7 @@ namespace llarp::quic
 
     auto send_packet = [&](auto nwrite) -> bool {
       send_buffer_size = nwrite;
-      LogDebug("Sending ", send_buffer_size, "B packet");
+      LogTrace("Sending ", send_buffer_size, "B packet");
 
       // FIXME: update remote addr? ecn?
       auto sent = send();
@@ -606,7 +604,7 @@ namespace llarp::quic
         // FIXME: disconnect?
         return false;
       }
-      LogDebug("packet away!");
+      LogTrace("packet away!");
       return true;
     };
 
@@ -664,18 +662,18 @@ namespace llarp::quic
 
         auto [nwrite, consumed] =
             add_stream_data(stream.id(), vecs.data(), vecs.size(), extra_flags);
-        LogDebug(
+        LogTrace(
             "add_stream_data for stream ", stream.id(), " returned [", nwrite, ",", consumed, "]");
 
         if (nwrite > 0)
         {
           if (consumed >= 0)
           {
-            LogDebug("consumed ", consumed, " bytes from stream ", stream.id());
+            LogTrace("consumed ", consumed, " bytes from stream ", stream.id());
             stream.wrote(consumed);
           }
 
-          LogDebug("Sending stream data packet");
+          LogTrace("Sending stream data packet");
           if (!send_packet(nwrite))
             return;
           ++stream_packets;
@@ -686,14 +684,14 @@ namespace llarp::quic
         switch (nwrite)
         {
           case 0:
-            LogDebug(
+            LogTrace(
                 "Done stream writing to ",
                 stream.id(),
                 " (either stream is congested or we have nothing else to send right now)");
             assert(consumed <= 0);
             break;
           case NGTCP2_ERR_WRITE_MORE:
-            LogDebug(
+            LogTrace(
                 "consumed ", consumed, " bytes from stream ", stream.id(), " and have space left");
             stream.wrote(consumed);
             if (stream.unsent() > 0)
@@ -723,11 +721,11 @@ namespace llarp::quic
     for (;;)
     {
       auto [nwrite, consumed] = add_stream_data(StreamID{}, nullptr, 0);
-      LogDebug("add_stream_data for non-stream returned [", nwrite, ",", consumed, "]");
+      LogTrace("add_stream_data for non-stream returned [", nwrite, ",", consumed, "]");
       assert(consumed <= 0);
       if (nwrite == NGTCP2_ERR_WRITE_MORE)
       {
-        LogDebug("Writing non-stream data, and have space left");
+        LogTrace("Writing non-stream data, and have space left");
         continue;
       }
       if (nwrite < 0)
@@ -737,14 +735,14 @@ namespace llarp::quic
       }
       if (nwrite == 0)
       {
-        LogDebug("Nothing else to write for non-stream data for now (or we are congested)");
+        LogTrace("Nothing else to write for non-stream data for now (or we are congested)");
         ngtcp2_conn_stat cstat;
         ngtcp2_conn_get_conn_stat(*this, &cstat);
-        LogDebug("Current unacked bytes in flight: ", cstat.bytes_in_flight);
+        LogTrace("Current unacked bytes in flight: ", cstat.bytes_in_flight);
         break;
       }
 
-      LogDebug("Sending non-stream data packet");
+      LogTrace("Sending non-stream data packet");
       if (!send_packet(nwrite))
         return;
     }

llarp/quic/endpoint.cpp

@@ -31,7 +31,7 @@ namespace llarp::quic
     expiry_timer->on<uvw::TimerEvent>([this](const auto&, auto&) { check_timeouts(); });
     expiry_timer->start(250ms, 250ms);
 
-    LogDebug("Created endpoint");
+    LogDebug("Created QUIC endpoint");
   }
 
   Endpoint::~Endpoint()
@@ -57,30 +57,30 @@ namespace llarp::quic
 
     Packet pkt{Path{local, src}, data, ngtcp2_pkt_info{.ecn = ecn}};
 
-    LogDebug("[", pkt.path, ",ecn=", pkt.info.ecn, "]: received ", data.size(), " bytes");
+    LogTrace("[", pkt.path, ",ecn=", pkt.info.ecn, "]: received ", data.size(), " bytes");
 
     handle_packet(pkt);
 
-    LogDebug("Done handling packet");
+    LogTrace("Done handling packet");
   }
 
   void
   Endpoint::handle_packet(const Packet& p)
   {
-    LogDebug("Handling incoming quic packet: ", buffer_printer{p.data});
+    LogTrace("Handling incoming quic packet: ", buffer_printer{p.data});
     auto maybe_dcid = handle_packet_init(p);
     if (!maybe_dcid)
       return;
     auto& dcid = *maybe_dcid;
 
     // See if we have an existing connection already established for it
-    LogDebug("Incoming connection id ", dcid);
+    LogTrace("Incoming connection id ", dcid);
     auto [connptr, alias] = get_conn(dcid);
     if (!connptr)
     {
       if (alias)
       {
-        LogDebug("CID is an expired alias; dropping");
+        LogDebug("Incoming packet QUIC CID is an expired alias; dropping");
         return;
       }
       connptr = accept_initial_connection(p);
@@ -88,9 +88,9 @@ namespace llarp::quic
         return;
     }
     if (alias)
-      llarp::LogDebug("CID is alias for primary CID ", connptr->base_cid);
+      LogTrace("CID is alias for primary CID ", connptr->base_cid);
     else
-      llarp::LogDebug("CID is primary CID");
+      LogTrace("CID is primary CID");
 
     handle_conn_packet(*connptr, p);
   }
@@ -151,13 +151,13 @@ namespace llarp::quic
     }
 
     // FIXME - reset idle timer?
-    LogDebug("Done with incoming packet");
+    LogTrace("Done with incoming packet");
   }
 
   io_result
   Endpoint::read_packet(const Packet& p, Connection& conn)
   {
-    LogDebug("Reading packet from ", p.path);
+    LogTrace("Reading packet from ", p.path);
     auto rv =
         ngtcp2_conn_read_pkt(conn, p.path, &p.info, u8data(p.data), p.data.size(), get_timestamp());
 
@@ -187,8 +187,7 @@ namespace llarp::quic
 
     if (service_endpoint.SendToOrQueue(to, outgoing, service::ProtocolType::QUIC))
     {
-      LogDebug("[", to, "]: sent ", outgoing.size(), " bytes");
-      LogTrace("Full quic data: ", buffer_printer{outgoing});
+      LogTrace("[", to, "]: sent ", buffer_printer{outgoing});
     }
     else
     {

llarp/quic/stream.cpp

@@ -168,7 +168,7 @@ namespace llarp::quic
     //
     assert(bytes <= unacked_size && unacked_size <= size);
 
-    LogDebug("Acked ", bytes, " bytes of ", unacked_size, "/", size, " unacked/total");
+    LogTrace("Acked ", bytes, " bytes of ", unacked_size, "/", size, " unacked/total");
 
     unacked_size -= bytes;
     size -= bytes;
@@ -299,7 +299,7 @@ namespace llarp::quic
     //     [  áaarrrrrr  ]  or  [rr     áaar]
     // to:
     //     [  áaaaaarrr  ]  or  [aa     áaaa]
-    LogDebug("wrote ", bytes, ", unsent=", unsent());
+    LogTrace("wrote ", bytes, ", unsent=", unsent());
     assert(bytes <= unsent());
     unacked_size += bytes;
   }

llarp/quic/tunnel.cpp

@@ -256,7 +256,7 @@ namespace llarp::quic
       auto tunnel_to = allow_connection(lokinet_addr, port);
       if (not tunnel_to)
         return false;
-      LogDebug("quic stream from ", lokinet_addr, " to ", port, " tunnelling to ", *tunnel_to);
+      LogInfo("quic stream from ", lokinet_addr, " to ", port, " tunnelling to ", *tunnel_to);
 
       auto tcp = get_loop()->resource<uvw::TCPHandle>();
       auto error_handler = tcp->once<uvw::ErrorEvent>(
@@ -488,7 +488,7 @@ namespace llarp::quic
           "Unable to open an outgoing quic connection: too many existing connections"};
     (next_pseudo_port_ = pport)++;
 
-    LogDebug("Bound TCP tunnel ", saddr, " for quic client :", pport);
+    LogInfo("Bound TCP tunnel ", saddr, " for quic client :", pport);
 
     // We are emplacing into client_tunnels_ here: beyond this point we must not throw until we
     // return (or if we do, make sure we remove this row from client_tunnels_ first).