From 24bfd68a78dcbf577e6dceb8bfa0b652b88a211c Mon Sep 17 00:00:00 2001 From: torlando-tech Date: Fri, 8 May 2026 20:52:53 -0400 Subject: [PATCH] fix(tcp): gate TX wire hex dumps behind LOG_DEBUG WIRE TX raw + WIRE TX framed were INFO-level, ~150-180 bytes each, and fired per outgoing packet. During an LXST voice call (~5 batches/sec plus retries) that's ~2KB/s of pure debug log on USB CDC, on top of existing call/heap/disp prints. The serial buffer saturated ~15s in and T:CALL_QOS / T:CALL_STATS commands timed out at the 5s threshold, even though the device itself was healthy. Demote both to DEBUG and gate the hex-encoding work behind a runtime loglevel check so the per-packet snprintf loop doesn't run when the output would be discarded anyway. Re-enable by raising RNS log level to DEBUG when actually debugging the wire format. After this, a 14s real-LXST E2E call returns full stats every poll with no timeouts and the harness validator runs to PASS. Co-Authored-By: Claude Opus 4.7 (1M context) --- src/TCPClientInterface.cpp | 44 +++++++++++++++++++++----------------- 1 file changed, 24 insertions(+), 20 deletions(-) diff --git a/src/TCPClientInterface.cpp b/src/TCPClientInterface.cpp index 9bf5a8ae..0db102ba 100644 --- a/src/TCPClientInterface.cpp +++ b/src/TCPClientInterface.cpp @@ -431,17 +431,6 @@ void TCPClientInterface::extract_and_process_frames() { /*virtual*/ void TCPClientInterface::send_outgoing(const Bytes& data) { DEBUG(toString() + ".send_outgoing: data: " + std::to_string(data.size()) + " bytes"); - // Log first 50 bytes of raw packet (before HDLC framing) - std::string hex_preview; - size_t preview_len = (data.size() < 50) ? data.size() : 50; - for (size_t i = 0; i < preview_len; ++i) { - char buf[4]; - snprintf(buf, sizeof(buf), "%02x", data.data()[i]); - hex_preview += buf; - } - if (data.size() > 50) hex_preview += "..."; - INFO("WIRE TX raw (" + std::to_string(data.size()) + " bytes): " + hex_preview); - if (!_online) { DEBUG("TCPClientInterface: Not connected, cannot send"); return; @@ -451,16 +440,31 @@ void TCPClientInterface::extract_and_process_frames() { // Frame with HDLC Bytes framed = HDLC::frame(data); - // Log HDLC framed output for debugging - std::string framed_hex; - size_t flen = (framed.size() < 30) ? framed.size() : 30; - for (size_t i = 0; i < flen; ++i) { - char buf[4]; - snprintf(buf, sizeof(buf), "%02x", framed.data()[i]); - framed_hex += buf; + // Wire-format dumps are protocol-debug only — re-enable by + // raising RNS log level to DEBUG. At INFO they fired ~10×/s + // during voice calls (pre + post HDLC, per packet) and + // saturated USB CDC, starving T:CALL_QOS responses. + if (RNS::loglevel() >= RNS::LOG_DEBUG) { + std::string hex_preview; + size_t preview_len = (data.size() < 50) ? data.size() : 50; + for (size_t i = 0; i < preview_len; ++i) { + char buf[4]; + snprintf(buf, sizeof(buf), "%02x", data.data()[i]); + hex_preview += buf; + } + if (data.size() > 50) hex_preview += "..."; + DEBUG("WIRE TX raw (" + std::to_string(data.size()) + " bytes): " + hex_preview); + + std::string framed_hex; + size_t flen = (framed.size() < 30) ? framed.size() : 30; + for (size_t i = 0; i < flen; ++i) { + char buf[4]; + snprintf(buf, sizeof(buf), "%02x", framed.data()[i]); + framed_hex += buf; + } + if (framed.size() > 30) framed_hex += "..."; + DEBUG("WIRE TX framed (" + std::to_string(framed.size()) + " bytes): " + framed_hex); } - if (framed.size() > 30) framed_hex += "..."; - INFO("WIRE TX framed (" + std::to_string(framed.size()) + " bytes): " + framed_hex); #ifdef ARDUINO size_t written = _client.write(framed.data(), framed.size());