Precisely timing the packets from CYW43/WizNET interfaces, as they enter mircoPython 'sock' module.

[mungewell]

I am trying to accurately time the packets received from the CYW43 (or WizNET) devices, such as used on the Pico-1W and Pico-2W.

I have a mostly working solution, using the rp2's PIO to monitor the IRQ line from the external device and trigger the DMA to read from the 1us counter, and then I can use this value after my self.sock.recvfrom() call returns the packet to the script.

However there are a couple of issues I have not found a solution to...

• Extra interrupts can (rarely) occur between packet(s) arriving and my self.sock.recvfrom() call.
• When monitoring multiple sockets (ie cycling around non blocking calls), I don't have a way to identify which packet caused which DMA-ed timestamp.

Thinking analogous to the timestamp shown in PCAP files, is there a way to (roughly) timestamp the packet as it enters the underlying microPython code? Even if I had to patch/recompile microPython... If I had a rough timestamp, I could compare and tie this to the list of (accurate) 1us timestamps.

Code snippet, DMA previously stored the timestamp into an array of the last 8 timestamps.

while (...):
    try:
        data, addr = self.sock.recvfrom(256)
    except OSError:
        break

    # Timestamp ASAP after packet received
    # --- START of time critical ---
    now = ticks_us()
    log("Wifi:", now)
    for i in range(len(wl_irq_data)):
        log("Wifi:", wl_irq_index, 0-i, wl_irq_data[(wl_irq_index - i) & 0b111])

And on PC I do ntpdig -p 2 192.168.2.101 (ie double read cause 2 IRQs)

[timepico] Wifi: 72332634
[timepico] Wifi: 18 0 [72331212, True]
[timepico] Wifi: 18 -1 [58389986, False]
[timepico] Wifi: 18 -2 [53966361, False]
[timepico] Wifi: 18 -3 [42116132, False]
[timepico] Wifi: 18 -4 [22637035, True]
[timepico] Wifi: 18 -5 [21752090, False]
[timepico] Wifi: 18 -6 [18718819, True]
[timepico] Wifi: 18 -7 [17351283, False]

[timepico] Wifi: 72347451
[timepico] Wifi: 19 0 [72345102, True]
[timepico] Wifi: 19 -1 [72331212, False]
[timepico] Wifi: 19 -2 [58389986, False]
[timepico] Wifi: 19 -3 [53966361, False]
[timepico] Wifi: 19 -4 [42116132, False]
[timepico] Wifi: 19 -5 [22637035, True]
[timepico] Wifi: 19 -6 [21752090, False]
[timepico] Wifi: 19 -7 [18718819, True]

[Pavel-Shcherbo]

Stock recvfrom() returns the data and peer address, without a receive timestamp. For a CYW43 build using lwIP, the useful place to add a software delivery timestamp is the UDP receive callback, before the packet waits for Python to read it.

In current upstream, _lwip_udp_incoming calls udp_raw_incoming. Each socket has its own incoming ring; each lwip_incoming_packet_t holds that datagram's pbuf, source address and port. lwip_raw_udp_receive later consumes that same entry.

For a firmware patch, I'd capture a C timestamp at the receive callback and store it in that queue entry, then expose it together with the datagram when it is dequeued. A single global/latest timestamp, or even one timestamp per socket, loses the association when more than one datagram is queued. Keep the metadata coupled to the packet on queue-full drops, and don't consume it on MSG_PEEK.

That gives the rough timestamp you describe, earlier than the Python loop, but it is not a wire/RF arrival timestamp. It can help narrow down the DMA candidates; it doesn't make an IRQ index a unique packet identifier. Your observed extra interrupts already prevent a simple one-to-one mapping.

Two details worth checking before implementing it:

• WizNET has two backends. network_wiznet5k.c selects either lwIP/MACRAW or the controller's provided socket stack. The latter goes through wiznet5k_socket_recvfrom, so the lwIP hook alone would not cover it.
• Clock wrap domains differ. RP2's mp_hal_ticks_us() reads time_us_32(), while Python time.ticks_us() masks it to MICROPY_PY_TIME_TICKS_PERIOD. Keep both timestamps in the same timer/wrap domain; do not mix raw DMA counter values with Python's masked ticks. Use wrap-aware differences, and respect the half-period limit when using ticks_diff.

Which MicroPython version and WizNET backend are you using? The queue details above are from commit 103d68e729; older firmware may differ. This is source inspection, not a compiled patch or a board timing measurement.

[mungewell]

I was able to make a small patch on the microPython source:
timestamp_udp.patch.zip

This adds a new function which additionally returns the timestamp (in us), ie:

data, addr, timestamp = self.sock.recvfrom_ts(256)

It looks like the timestamps from self.sock.recvfrom_ts() when using a blocking socket are ~500us after the WL-IRQ timestamp, when using a non-blocking socket (obviously depends on how my script loops) I am seeing up-to 10ms... and I haven't even added monitoring the second socket.

Was it worth it? Maybe, I have seen once that the most recent WL-IRQ timestamp didn't match up with UDP timestamp. IE. there was an additional IRQ, which would have affected the NTP reply. I expect more, once the 2nd socket is monitored.

Matching masks alone would not align an independently running PIO counter.

Just for clarity, the timestamp is being read from the '1us counter' peripheral. It is NOT a counter generated in the PIO. I am using the PIO to monitor the IRQ line and trigger the DMA, that way it's timing is not affected by whatever the processor is doing...

[mungewell]

I left my code (single port, non-blocking) running overnight and got 2x instance (out of 500K packets) where the most recent WL-IRQ timestamp did not match the UDP timestamp... however I don't think the 'ticks_us()' is being recorded early enough in the underlying microPython code/patch.

Logic suggests that the time delta to the IRQ timestamp should be small, and the time delta to a ticks_us() made after the recvfrom_ts() should be large. At present they are (timestamp, delta, delta):

[timepico] Matched 915623533 4985 5360
[timepico] Matched 919679009 6804 7197
[timepico] Matched 923724218 6134 6500
[timepico] Matched 927799644 5178 5558
[timepico] Matched 931849629 4490 4868
[timepico] Matched 939863395 4887 5264
[timepico] Matched 947929054 3185 3563
[timepico] Matched 955982293 4053 4425
[timepico] Matched 963994519 3849 4223
[timepico] Matched 972047071 1332 1719

[Pavel-Shcherbo]

There is a separate matching issue worth eliminating before attributing those deltas to the C timestamp placement. In your published matching loop at 2451396, each eligible entry overwrites tstamp_irq and clears its valid flag, but the loop continues. With two eligible entries visited newest first, it therefore selects the older one and consumes both. If the intended rule is “newest eligible IRQ”, select/consume only that entry and stop searching. This still cannot establish that the selected IRQ belongs to the datagram. Also, the following if tstamp_irq: rejects a valid zero tick; is not None distinguishes it from no match.

I ran four small controls on the exact extracted Python matching loop with synthetic ring entries, using CPython and a wrap-aware ticks-difference stand-in: one match, two matches, future/expired entries, and tick zero. This was not a Pico/MicroPython/DMA test, and it does not establish the cause of your two overnight mismatches.

Your log expression measures both deltas from the chosen IRQ. Subtracting the first delta from the second gives the interval from the recorded UDP timestamp to the Python now sample: about 0.36–0.39 ms in the rows you posted. The columns themselves do not locate the earlier delay or prove that the C capture is misplaced; I have not inspected your firmware patch.

The callback timestamp discussed above is a software delivery timestamp. A 1 us counter resolution does not establish 1 us packet-arrival accuracy or a unique IRQ/packet association.

[mungewell]

each eligible entry overwrites tstamp_irq and clears its valid flag

Yes, I am (was) aware of this behaviour... the desire would be to narrow the window of acceptable timestamp matches (to say 100us) which would reduce the chance of 'de-listing' more than one. Definitely WIP and I will adjust as code improves...

is not None distinguishes it from no match.

Ack. Thanks.

[Pavel-Shcherbo]

For the proposed driver hook, the timestamp needs to be attached before netif->input(p, netif), not in its success branch. On success, lwIP owns the packet; it may already have delivered it to the UDP callback or freed it. The input path even returns ERR_OK after freeing a packet. Updating p afterwards is unsafe, and an independent do_timestamping() afterwards cannot retroactively attach metadata to a queued datagram.

I checked the library commits pinned by MicroPython v1.29.0: cyw43-driver 055d642 and lwIP 77dcd25. That lwIP version already provides LWIP_PBUF_CUSTOM_DATA and LWIP_PBUF_CUSTOM_DATA_INIT, explicitly for private data such as timestamps. A timestamp plus a separate validity flag can therefore be configured through those hooks rather than editing an unrelated fork's pbuf.h.

The metadata path would be: capture the counter at your chosen driver-entry point; allocate the pbuf and set its metadata before handing it to lwIP; then copy that metadata into the same lwip_incoming_packet_t slot as the pbuf in udp_raw_incoming. Your receive function can return the slot's timestamp together with that datagram. Keep it on peek and discard it with that packet on drop/dequeue. Use one consistent configuration when rebuilding the driver/lwIP/firmware, since the added fields change the struct layout.

That describes the simple path, not a complete patch: copying, changed pbuf heads, and fragmented/reassembled datagrams need an explicit metadata-propagation rule. This is pinned-source inspection only; I have not built or tested this firmware path. Capturing at driver entry also still measures software ingress, not RF arrival with proven 1 us accuracy.

[RONALD-REX-7]

High-Precision Packet Timestamping in MicroPython on RP2040/RP2350 (CYW43 / W5500)

The root issue you are encountering stems from the architectural gap between the physical link layer (IRQ/DMA) and the lwIP socket queue in MicroPython.

On the Pico W, the CYW43439 shares the wireless IRQ line (WL_GPIO2 / PIN_WL_HOST_WAKE) for multiple events:

1. Frame reception (RX)
2. Credit/flow control updates
3. Wi-Fi link status changes and beacon tracking
4. Multicast/broadcast traffic dropped by lwIP filters

Because of this, an IRQ burst does not guarantee a valid UDP packet arriving at self.sock.recvfrom(), and MicroPython's garbage collector / bytecode dispatch adds non-deterministic latency ($50\mu\text{s} - 2\text{ms}$) between hardware IRQ and Python user-space.

Here are the two ways to solve this cleanly:

---

Solution 1: Direct lwIP Ingress Timestamping via a MicroPython User C Module (Recommended)

If you are willing to rebuild MicroPython (or compile as a dynamic .mpy native C module), you can hook directly into lwIP's packet ingress hook where pbuf is allocated.

In the RP2 port (ports/rp2/):
When a frame arrives from cyw43_driver, it enters lwIP via cyw43_cb_process_ethernet():

// Inside ports/rp2/cyw43_driver (or your custom lwIP hook)
#include "hardware/timer.h"

// In the packet input callback:
void my_packet_hook(struct pbuf *p) {
    uint32_t hw_timestamp = timer_hw->timerawl; // 1us hardware counter
    // Tag the custom payload or store in a 16-entry ring buffer keyed by (port, seq/id):
    record_ingress_ts(p, hw_timestamp);
}

How to expose this to Python without rewriting usocket:

Instead of modifying modsocket.c, create an external C module (or user_c_module) that binds a raw lwIP UDP PCB for your specific time port (e.g. UDP port 123 for NTP):

#include "lwip/udp.h"
#include "hardware/timer.h"

static struct udp_pcb *time_pcb;
static volatile uint32_t last_packet_time_us = 0;
static uint8_t last_payload[256];
static uint16_t last_len = 0;

static void time_udp_recv_cb(void *arg, struct udp_pcb *pcb, struct pbuf *p,
                             const ip_addr_t *addr, u16_t port) {
    if (p != NULL) {
        // Latch hardware counter immediately upon entering lwIP interrupt/callback
        last_packet_time_us = timer_hw->timerawl;
        last_len = pbuf_copy_partial(p, last_payload, sizeof(last_payload), 0);
        pbuf_free(p);
    }
}

This guarantees $< 2\mu\text{s}$ latency and zero ambiguity regarding which packet triggered the timestamp, completely bypassing socket queue jitter.

---

Solution 2: Filtering False IRQs on WizNET W5500 (No C Rebuild)

If you are using the SPI-attached W5500:

1. The global /INT pin on the W5500 asserts for SEND_OK, TIMEOUT, RECV, and DISCON.
2. By default, the chip asserts for transmit completion as well. In the W5500 register configuration, mask the socket interrupt register (Sn_IMR) so that only RECV (0x04) asserts the hardware interrupt pin:
   $$\text{Sn_IMR} = 0\text{x}04 \quad (\text{Receive Interrupt Only})$$
3. This eliminates false positive IRQs from transmission and link beacons, ensuring that the DMA timestamp ring buffer matches incoming packets 1:1.

---

Solution 3: Correlating User-Space Socket Reads with DMA Ring Buffer

If staying in pure MicroPython with PIO/DMA:
To tie the correct DMA timestamp to sock.recvfrom():

1. Record now = time.ticks_us() immediately after recvfrom() returns.
2. In your DMA array of timestamps, search backwards for the timestamp $T_{\text{DMA}}$ satisfying:
   $$10\mu\text{s} \le (now - T_{\text{DMA}}) \le 3000\mu\text{s}$$
   (Discard any timestamp occurring after now or older than $5\text{ms}$).
3. When multiple non-blocking sockets are polled, check select.poll(0) on the socket file descriptor; do not read timestamps on sockets returning EAGAIN / EWOULDBLOCK.

[mungewell]

Direct lwIP Ingress Timestamping

Absolutely willing to rebuild '.uf2', I'll look into your suggestions. Thank you.

Filtering False IRQs

I am expecting that I can use the time value for filter, providing that IRQs are not too plentiful to overflow the array. Can make array bigger, but then would take more time to process...

I've pushed my (temporary/work-in-progress) branch, so you can see what I have done so far. The processing of packets is in the serve_once() function in app.py.
https://github.com/mungewell/TimePico/tree/20261105_sWL-IRQ_fifo

The combination of DMA and ISR results in an array of recent IRQ timestamps, and then I filter that down to find one that closely matches UDP timestamp.

BTW I'm looking for 1us accuracy...

[mungewell]

I see:
https://github.com/georgerobotics/cyw43-driver/blob/main/src/cyw43_lwip.c#L247

Which (to me) suggests adding something like. The issue I guess is how to make the timestamp 'travel' with the packet through the rest of the code, so that it can be rendered out when I call recv_from_ts().

void cyw43_cb_process_ethernet(void *cb_data, int itf, size_t len, const uint8_t *buf) {
    cyw43_t *self = cb_data;
    struct netif *netif = &self->netif[itf];
    #if CYW43_NETUTILS
    if (self->trace_flags) {
        cyw43_ethernet_trace(self, netif, len, buf, NETUTILS_TRACE_NEWLINE);
    }
    #endif
    if (netif->flags & NETIF_FLAG_LINK_UP) {
        struct pbuf *p = pbuf_alloc(PBUF_RAW, len, PBUF_POOL);
        if (p != NULL) {
            pbuf_take(p, buf, len);
            if (netif->input(p, netif) != ERR_OK) {
                pbuf_free(p);
            // } remove and add pseudo code
            } else {
               do_timestamping();
            } // end of add
        }
    }
}

[EDIT]

Since I'm rebuilding everything, I can (maybe) add an extra field to struct pbuf to hold a timestamp.
https://github.com/ARMmbed/lwip/blob/master/src/include/lwip/pbuf.h#L142

[mungewell]

I implemented a hacky-patch to cyw43_cb_process_ethernet() based on the above and confirm that the 'UDP timestamps' are typically ~500us after the hardware (PIO-DMA) timestamps. This is fantastic, and I am able to perform matching of the two with a 600us 'window'.

Monitoring 2 non-blocking ports, while serving (aggressive) NTP client and 2nd peer device.

[timepico] Peer Matched 488041973 437 11093
[timepico] NPT timestamp matched 491677733 465 5267
[timepico] Peer Matched 492256342 462 7365
[timepico] NPT timestamp matched 492683578 469 4574
[timepico] Peers: PONG 192.168.2.101 1794101321611301 : 1143 187
[timepico] Peer Matched 493033733 425 12784
[timepico] NTP timestamp lookup skipped
[timepico] NPT timestamp matched 496762673 460 6731
[timepico] Peer Matched 497259923 468 6887
[timepico] Peers: PONG 192.168.2.101 1794101326613877 : 996 102
[timepico] Peer Matched 498036282 440 6703
[timepico] NPT timestamp matched 500808128 459 9076
[timepico] Peer Matched 502265269 453 4536
[timepico] Peers: PONG 192.168.2.101 1794101331617602 : 841 38

On an overnight run I saw 4x 'no match', suspect that this was a slightly higher delay... but that's acceptable rate, for over 10K packets served.

I saw 165x incidents where the match was not the most recent hardware timestamp. This situation is important to catch as it would affect the contents of the served NTP packet(s).

$ grep "No" *.cap
minicom_100.cap:[timepico] NTP No timestamp match 1849295288
minicom_100.cap:[timepico] Peer No Match 1945256610
minicom_101.cap:[timepico] NTP No timestamp match -1766334506
minicom_101.cap:[timepico] Peer No Match 1259933335

$ grep "skip" *.cap | wc
    165     825    9240

I'll continue to implement a more 'proper' patch, as this might be helpful to others wanting to achieve similar... I'll sign off (for now) with a pretty picture. 2x TimePico (mini NTP servers) are holding PC's time to RMS Offset of 1.27us.

[mungewell]

As promised here's a slightly nicer patch to microPython to add the timestamps to CYW43 packets:
20261109_recvfrom_ts.zip

I don't have WizNet devices at present, but I expect I'll do another patch using the same technique.