From 31b2c16b07e0ddaf112bc15e9fd4f1617b40696f Mon Sep 17 00:00:00 2001
From: Ian Gulliver <github@flamingcow.io>
Date: Tue, 7 Apr 2026 12:09:18 +0900
Subject: [PATCH] Debug log with dlog_if_slow, MACRAW ping working, wfi
 disabled

---
 firmware/include/debug_log.h   | 11 ++++++++++-
 firmware/include/ring_buffer.h |  5 +++++
 firmware/include/usb_cdc.h     |  2 +-
 firmware/lib/dispatch.cpp      | 19 ++++++++++++-------
 firmware/lib/net.cpp           | 12 ++++++++++--
 5 files changed, 38 insertions(+), 11 deletions(-)

diff --git a/firmware/include/debug_log.h b/firmware/include/debug_log.h
index 093f335..c0bc581 100644
--- a/firmware/include/debug_log.h
+++ b/firmware/include/debug_log.h
@@ -1,4 +1,5 @@
 #pragma once
+#include <functional>
 #include <string>
 #include <string_view>
 #include <vector>
@@ -13,7 +14,15 @@ struct log_entry {
 inline ring_buffer<log_entry, 32> g_debug_log;
 
 inline void dlog(std::string_view msg) {
-    g_debug_log.push(log_entry{static_cast<uint32_t>(time_us_32()), std::string(msg)});
+    g_debug_log.push_overwrite(log_entry{static_cast<uint32_t>(time_us_32()), std::string(msg)});
+}
+
+inline void dlog_if_slow(std::string_view label, uint32_t threshold_us, std::function<void()> fn) {
+    uint32_t t0 = time_us_32();
+    fn();
+    uint32_t elapsed = time_us_32() - t0;
+    if (elapsed > threshold_us)
+        dlog(std::string(label) + " " + std::to_string(elapsed) + "us");
 }
 
 inline std::vector<log_entry> dlog_drain() {
diff --git a/firmware/include/ring_buffer.h b/firmware/include/ring_buffer.h
index 6c380a5..6070c05 100644
--- a/firmware/include/ring_buffer.h
+++ b/firmware/include/ring_buffer.h
@@ -24,6 +24,11 @@ struct ring_buffer {
         data[(tail++) % N] = v;
     }
 
+    void push_overwrite(const T& v) {
+        if (free() == 0) head++;
+        data[(tail++) % N] = v;
+    }
+
     uint16_t peek(std::span<T> dst) const {
         uint16_t len = dst.size() < used() ? dst.size() : used();
         for (uint16_t i = 0; i < len; i++)
diff --git a/firmware/include/usb_cdc.h b/firmware/include/usb_cdc.h
index 827560b..cd82a16 100644
--- a/firmware/include/usb_cdc.h
+++ b/firmware/include/usb_cdc.h
@@ -6,7 +6,7 @@
 #include "ring_buffer.h"
 
 struct usb_cdc {
-    ring_buffer<uint8_t, 512> tx;
+    ring_buffer<uint8_t, 8192> tx;
 
     void send(std::span<const uint8_t> data) {
         tx.push(data);
diff --git a/firmware/lib/dispatch.cpp b/firmware/lib/dispatch.cpp
index 646ee08..bb54f82 100644
--- a/firmware/lib/dispatch.cpp
+++ b/firmware/lib/dispatch.cpp
@@ -31,11 +31,10 @@ void dispatch_schedule_ms(uint32_t ms, std::function<void()> fn) {
     static static_vector<uint8_t, 256> usb_rx_buf;
 
     while (true) {
-        tud_task();
-
-        usb.drain();
-        timers.run();
-        //net_poll();
+        dlog_if_slow("tud_task", 1000, [&]{ tud_task(); });
+        dlog_if_slow("drain", 1000, [&]{ usb.drain(); });
+        dlog_if_slow("timers", 1000, [&]{ timers.run(); });
+        dlog_if_slow("net_poll", 1000, [&]{ net_poll(); });
 
         while (tud_cdc_available()) {
             uint8_t byte;
@@ -54,7 +53,13 @@ void dispatch_schedule_ms(uint32_t ms, std::function<void()> fn) {
             auto it = handler_map.find(msg->type_id);
             if (it != handler_map.end()) {
                 for (auto& response : it->second(msg->message_id, msg->payload)) {
-                    usb.send(response);
+                    if (response.size() > usb.tx.free()) {
+                        auto err = encode_response(msg->message_id,
+                            DeviceError{2, "response too large: " + std::to_string(response.size())});
+                        usb.send(err);
+                    } else {
+                        usb.send(response);
+                    }
                 }
                 if (msg->type_id == RequestPICOBOOT::ext_id) {
                     sleep_ms(100);
@@ -63,6 +68,6 @@ void dispatch_schedule_ms(uint32_t ms, std::function<void()> fn) {
             }
         }
 
-        __wfi();
+        // __wfi();
     }
 }
diff --git a/firmware/lib/net.cpp b/firmware/lib/net.cpp
index 7e365eb..f032f87 100644
--- a/firmware/lib/net.cpp
+++ b/firmware/lib/net.cpp
@@ -1,7 +1,9 @@
 #include "net.h"
 #include <cstring>
 #include "pico/unique_id.h"
+#include "pico/time.h"
 #include "w6300.h"
+#include "debug_log.h"
 
 static net_state state;
 static w6300::socket_id raw_socket{0};
@@ -43,8 +45,10 @@ static bool ip_match(const uint8_t* dst) {
 }
 
 static void send_raw(const uint8_t* data, size_t len) {
-    w6300::ip_address dummy = {};
-    w6300::sendto(raw_socket, std::span<const uint8_t>{data, len}, dummy, w6300::port_num{0});
+    dlog_if_slow("send_raw", 1000, [&]{
+        w6300::ip_address dummy = {};
+        w6300::sendto(raw_socket, std::span<const uint8_t>{data, len}, dummy, w6300::port_num{0});
+    });
 }
 
 static void handle_arp(const uint8_t* frame, size_t len) {
@@ -54,6 +58,7 @@ static void handle_arp(const uint8_t* frame, size_t len) {
     if (read_u16(arp) != 1) return;
     if (read_u16(arp + 2) != ETHERTYPE_IPV4) return;
     if (arp[4] != 6 || arp[5] != 4) return;
+
     if (read_u16(arp + 6) != ARP_OP_REQUEST) return;
     if (!ip_match(arp + 24)) return;
 
@@ -88,6 +93,7 @@ static void handle_icmp(const uint8_t* frame, size_t len) {
     const uint8_t* icmp = ip + ip_hdr_len;
     size_t icmp_len = ip_total_len - ip_hdr_len;
     if (icmp_len < 8) return;
+
     if (icmp[0] != ICMP_ECHO_REQUEST) return;
 
     uint8_t reply[1514];
@@ -127,9 +133,11 @@ static void handle_ipv4(const uint8_t* frame, size_t len) {
 
 static void process_frame(const uint8_t* frame, size_t len) {
     if (len < 14) return;
+
     if (!mac_match(frame)) return;
 
     uint16_t ethertype = read_u16(frame + 12);
+
     switch (ethertype) {
     case ETHERTYPE_ARP:
         handle_arp(frame, len);