Skip to content

debug-2: macos test-wolfssl trace v2 (temporary, do not merge) - #162

Closed
danielinux wants to merge 16 commits into
wolfSSL:masterfrom
danielinux:macos-debug-2
Closed

debug-2: macos test-wolfssl trace v2 (temporary, do not merge)#162
danielinux wants to merge 16 commits into
wolfSSL:masterfrom
danielinux:macos-debug-2

Conversation

@danielinux

Copy link
Copy Markdown
Member

Temp branch: fenrir-fixes-2026-08-21 + unbuffered trace prints (RX/TX/TXgate/flush-retval/EAGAIN-FIFO-state/dispatch/loop heartbeat). Localizing the macOS test-wolfssl hang. Will be deleted.

flush_raw_tx and flush_packet_tx discarded the return of
wolfIP_ll_send_frame and popped the descriptor unconditionally, so a
retryable -WOLFIP_EAGAIN (loopback queue full, driver TX ring full)
silently dropped a frame that wolfIP_sock_sendto had already reported
as queued. Mirror flush_datagram_tx: break out of the drain loop on a
negative send result, leaving the descriptor at the FIFO head for the
next poll cycle.

Adds regression tests driving the mock link into -WOLFIP_EAGAIN for
both a raw socket and an AF_PACKET socket: the frame must not be
transmitted on the backpressured poll, the descriptor must survive in
the TX FIFO, and the next poll must retransmit it intact.
The raw and AF_PACKET loops in handle_socket_callbacks() cleared
r->events / p->events after the callback returned, inverting the order
dispatch_events() (UDP/ICMP) and the TCP path use. An event raised on
the same slot while the callback is executing (e.g. the callback closes
the socket and re-opens a new one in the reused slot) was wiped by the
stale post-callback clear, so a consumer waiting on it never woke.

Snapshot the events and clear the field before invoking the callback,
mirroring dispatch_events(). Adds regression tests for both socket
types: a callback that closes and re-opens the socket in place raises
CB_EVENT_WRITABLE on the reused slot; it must survive the poll and wake
the reopened socket's callback on the next one.
dns_callback validated that the complete RDATA lies inside the DNS
message but then passed the full message length to dns_copy_name, whose
label bound checks use that length. The inline portion of a PTR answer
name could therefore continue past the RDATA into the following record:
with rdlength 1 holding a label-length byte of 3 and "foo" in the
bytes after, the parser returned "foo" and invoked dns_ptr_cb with a
name the RDATA never contained.

dns_copy_name now takes the RDATA edge (rdata_end) as a sixth argument:
the initial inline portion (labels, terminators and both bytes of a
compression pointer) must fit in the RDATA, while pointer targets and
the post-jump name portion remain validated against the message length,
as RFC 1035 s4.1.4 allows. The PTR arm passes pos + rdlen; direct
buffer unit tests pass rdata_end == len (behavior unchanged).

Adds the finding's trigger as a regression test (undersized RDATA
followed by name-looking bytes must leave the query pending) plus a
companion test that a PTR RDATA legitimately ending in a compression
pointer still parses.
parse_http_request() splits the request target on '?' and populates
req.query unconditionally, before the method is validated against
GET/POST. A POST target with a query string ("POST /api?id=5") gets
req.query filled exactly like a GET, so the "(for GET requests)"
comment was false and could mislead a handler into skipping
httpd_get_request_arg() on POST.
test_multicast_igmp_query_spoofed_dropped only asserted that no frame
was sent synchronously after each spoofed query - but IGMP reports are
always deferred to a timer (RFC 3376 s5.2), so the assertion was
trivially true whether the query was dropped or accepted. Deleting the
TTL guard (ip->ttl != 1) or the destination guard (dst != IGMP_ALL_HOSTS
&& dst != group) survived the suite: the spoofed case silently armed a
report timer, the later compliant case coalesced into it per the s5.2
pending-response rule, and the single final poll emitted exactly one
report, satisfying the closing assertion.

Each spoofed case now also asserts that no report timer was armed
(s.mcast[i].tmr_report == NO_TIMER), then polls past the Max Resp
window (10 s) and asserts that still nothing was sent. Cases run at
distinct tick marks (t=0, 10001, 20001) so a report armed by a mutated
guard cannot be hidden by the compliant case's coalescing. The compliant
case now asserts the timer is armed and that exactly one report is
emitted.

Mutation-checked (make unit-multicast): deleting the TTL guard fails
the case-1 NO_TIMER assert, deleting the destination guard fails the
case-2 NO_TIMER assert, && -> || fails the compliant case (plus the
existing refresh/flood tests), and != 1 -> == 1 fails case 1.
fifo_align_head_pos() wraps an unaligned head in {size-3, size-2, size-1}
to 0, but unlike the explicit end-of-buffer branch it never records the
wrap in h_wrap. When the FIFO is non-empty and h_wrap is 0, the collapsed
head==tail==0 && h_wrap==0 state is indistinguishable from the empty
state: the space test in fifo_push reports the whole buffer as free and
the next push writes a fresh descriptor at offset 0, clobbering every
previously queued descriptor (silent loss of UDP/ICMP/raw datagrams). A
second variant — a wrap write ending exactly on tail — left a non-empty
FIFO that reported empty and orphaned all live descriptors.

Record the wrap (h_wrap = pre-alignment head) in fifo_push when
alignment collapses a non-zero head to 0 on a non-empty, not-yet-wrapped
FIFO, and mirror the same rule in fifo_can_push_len so upstream capacity
checks agree with the fixed empty/full test. A rejected push mutates no
state; a recorded h_wrap is cleared by the existing fifo_pop drain path.

Regression tests: (1) a descriptor filling [0, size-2) with tail 0 must
make the next push fail with -1 and leave the queued descriptor intact;
(2) the wrap-lands-on-tail sequence must leave the FIFO reporting
non-empty with the oldest live descriptor still reachable via
fifo_peek. Both were verified to fail against the unfixed code (the push
returned 0 and clobbered / the FIFO reported empty) and pass with the
fix, across the plain, IP_MULTICAST and VLAN unit builds.
The addr_match expression relaxed all peer and destination validation
whenever a socket had no local address (local_ip == 0) while the DHCP
state machine was running: ((t->local_ip == 0) && DHCP_IS_RUNNING(s)).
That relaxation exists so the DHCP client socket can receive OFFER/ACK
before it owns an address, but as written it applied to every socket in
s->udpsockets[] - so a connected application socket created before the
interface had an address accepted datagrams from any source address and
port for as long as local_ip stayed 0 (initial acquisition and every
RENEWING/REBINDING cycle), bypassing the connected-peer filter.

Compute is_dhcp (the socket's fd equals s->dhcp_udp_sd) and require it in
the relaxation clause, keeping peer_match in force for every other
socket regardless of local_ip. The DHCP socket is unconnected (peer_match
is already 1) and keeps local_ip 0, so OFFER/ACK delivery is unchanged.

Adds test_udp_dhcp_relaxation_scoped_to_dhcp_socket: a connected socket
with local_ip 0 must not receive a datagram from a non-connected peer
while DHCP runs, and the DHCP socket must still receive one from any
source. Verified RED (the app socket received the spoofed datagram
pre-fix) and GREEN. test_udp_try_recv_dhcp_running_local_zero, which
codified the old over-broad relaxation on a non-DHCP socket, now marks
its socket as the DHCP socket to keep asserting the intended
relaxation. Plain, IP_MULTICAST and VLAN unit builds pass.
…ener

In tcp_input the per-socket match gated the 4-tuple comparison on
state > TCP_LISTEN, so a TCP_LISTEN socket was matched on local port
alone. The SYN handler separately validates bound_local_ip, but a
non-SYN segment (data/ACK/FIN) for the same port and a different local
address on the same host fell through to the shared bookkeeping writes
- t->if_idx, t->last_pkt_ttl, matched = 1, and (for non-RST) t->sock.
tcp.peer_rwnd - before any destination-address check. That lets a peer
that only needs to know a specifically-bound listener's port corrupt the
listener's MTU/TTL bookkeeping, seed the initial window of a later
accepted child, and set matched so the RFC 793 unmatched-segment RST is
suppressed.

Add an else branch so a listener in TCP_LISTEN is skipped when its
bound_local_ip is a specific address that does not equal the segment's
destination. bound_local_ip (not local_ip) is the discriminator: a
0.0.0.0 bind leaves local_ip set to the interface/primary address as a
default source, so local_ip cannot tell a wildcard listener from a
specifically-bound one. Wildcard listeners are unaffected (no-op), and
the established-socket path (state > TCP_LISTEN) is unchanged.

Note on the finding's RST-blackhole claim: a TCP_CLOSED socket with a
non-zero src_port never reaches the port-match gate - close_socket() and
every RX-path teardown zero proto (first guard) or set CB_EVENT_CLOSED
(second guard) and always zero src_port, so a matchable TCP_CLOSED slot
only matches invalid port-0 segments. That part of the report does not
manifest; the local-address validation gap for listeners is real and is
what this commit closes.

Adds test_tcp_listen_requires_matching_local_ip: a non-SYN segment for a
bound listener's port but a different local address must not change
last_pkt_ttl, while one for the bound address still matches. Verified
RED (last_pkt_ttl became 64 pre-fix) and GREEN. Plain, IP_MULTICAST and
VLAN unit builds pass.
The per-socket match loop recomputed expected_len = ee16(udp->len) +
IP_HEADER_LEN + ETH_HEADER_LEN and bailed with
if ((int)frame_len < (int)expected_len) return;. That branch is
unreachable: the unconditional guard before the socket loop already
rejects any datagram where ee16(udp->len) > frame_len - ETH_HEADER_LEN -
IP_HEADER_LEN, i.e. it guarantees frame_len >= expected_len. frame_len is
pass-by-value and udp->len is not modified between the two, so the inner
comparison is always false for every caller (the dispatch path presents
an option-stripped IHL=5 header; the loopback multicast caller builds
frames where the two quantities are exactly equal).

Remove the dead comparison and its now-unused expected_len local. No
behavioral change; the plain, IP_MULTICAST and VLAN unit suites pass
unchanged.
The header described ssh_server_get_uptime as returning the SSH server
uptime in seconds, but the implementation returns the constant 0 until a
main-loop tick source is integrated, so the "uptime" SSH command always
reports zero. Correct the API-contract comment to state that it is a
placeholder returning 0. No behavioral change.
The WOLFTFTP_REQ_BUF_MAX comment totaled the worst-case RRQ/WRQ as
63 + MAX_FILENAME, assigning 12 bytes to the timeout option. But
timeout_s is an unclamped uint16_t serialized by wolftftp_append_opt,
which includes both key and value terminators: 65535 becomes
"timeout\0" (8) + "65535\0" (6) = 14 bytes. The correct total is
65 + MAX_FILENAME. The WOLFTFTP_REQ_BUF_MAX allocation (MAX_FILENAME +
128) already covers this with margin to spare, so no behavioral change -
the fix stops a maintainer from using the documented calculation to
reduce the margin below a valid maximal request.
dns_callback only parsed an incoming datagram as a DNS response when
(flags & DNS_FLAGS_RESPONSE_RD) == DNS_FLAGS_RESPONSE_RD, i.e. when both
the QR (query/response) and RD (recursion-desired) bits were set
(0x8100). Per RFC 1035 s4.1.1 the QR bit alone distinguishes a response
from a query; RD is merely the Recursion-Desired flag a server echoes
from the query. A conformant server that does not echo RD (a response
otherwise lacking the RD bit) therefore had its reply silently ignored,
letting the outstanding query time out and retransmit needlessly.

Add a DNS_FLAGS_RESPONSE macro for the QR bit and gate response parsing
on it. DNS_FLAGS_RESPONSE_RD is retained: it is still a valid QR|RD
response flags value used by the test helpers to build conformant
replies.

Adds test_dns_callback_qr_without_rd_is_accepted: a response with QR set
and RD clear must be parsed and the lookup delivered. Verified RED
(lookup not delivered pre-fix) and GREEN. Plain, IP_MULTICAST and VLAN
unit builds pass.
After dispatching a TCP socket callback, handle_socket_callbacks()
re-read ts->sock.tcp.state and, if TCP_CLOSED, disarmed the callback and
called close_socket(), which memsets the whole slot. ts is a fixed slot
address, so that check is purely positional. A close callback that closes
the socket via wolfIP_sock_close() (freeing the slot) and then allocates a
fresh one - tcp_new_socket() scans from index 0 for the first proto == 0
slot, so it can land in the very same slot - leaves the slot holding a
brand-new socket whose state is TCP_CLOSED by design. The positional reap
then destroyed that fresh socket (zeroing S, proto and the FIFO backing),
leaving the application with a permanently dead descriptor.

Capture the callback/callback_arg pair before invoking the callback and
only reap if both are unchanged afterward: a replaced slot carries a
different (or no) callback, so the reap no longer touches it. The normal
deferred-close path is unaffected - there the callback does not replace
the socket, so the pair is unchanged and the reap proceeds as before. A
socket the callback closed without re-creating is already memset (callback
NULL), so it is likewise left alone (close_socket would be a no-op).

Adds test_handle_socket_callbacks_keeps_recreated_socket: a socket left in
the RX-deferred close state (TCP_CLOSED + CB_EVENT_CLOSED) whose callback
closes it and re-creates a socket in the same slot must survive the
dispatcher's post-callback reap. Verified RED (slot proto zeroed pre-fix)
and GREEN. Plain, IP_MULTICAST and VLAN unit builds pass.
In the WOLFIP_RAWSOCKETS branch of wolfIP_sock_sendto(), total_len =
ETH_HEADER_LEN + (uint32_t)len narrows the public size_t len to uint32_t
before the total_len > LINK_MTU guard, but both payload copies - the
ipheader_include memcpy and the non-ipheader memcpy(rip->data, buf, len) -
use the original, un-narrowed len. On a 64-bit build a len of
UINT32_MAX + 100 narrows to 100 for the MTU check (which passes) while the
memcpy still attempts to copy the full, enormous len into the fixed-size
frame buffer, overflowing it.

Reject len > LINK_MTU as size_t before any narrowing conversion: a payload
larger than the frame capacity cannot be sent anyway, and the bound is far
below UINT32_MAX so the subsequent (uint32_t)len is exact and the
total_len arithmetic cannot wrap. No behavioral change for any valid
payload.

The unit build enables WOLFIP_RAWSOCKETS unconditionally (unit_shared.c),
so the test runs in all unit builds. test_raw_sendto_rejects_oversized_len
_before_narrowing pins the bound: the oversized length is refused with
-WOLFIP_EINVAL. Verified RED - with the bound check removed the same call
segfaults (signal 11) in the payload memcpy - and GREEN. Plain, IP_MULTICAST
and VLAN unit builds pass.
Copilot AI lite review requested due to automatic review settings August 21, 2026 20:15

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Temporary debugging + targeted correctness hardening across wolfIP core paths, with accompanying unit-test coverage additions (FIFO wrap edge, callback dispatch reentrancy, DHCP UDP demux scoping, listener local-IP matching, DNS response/name parsing bounds, and TX retry semantics).

Changes:

  • Add macOS-hang tracing (stdout printf/fflush) around TX/RX/dispatch/flush paths.
  • Fix/strengthen core behaviors: FIFO alignment wrap bookkeeping, DHCP UDP “local_ip==0” relaxation scoping, LISTEN socket local-IP matching for non-SYN segments, DNS response detection (QR-only) + PTR RDATA name bounds, raw/packet TX retry on -WOLFIP_EAGAIN, and raw sendto oversized-length rejection.
  • Add/extend unit tests to lock in the above regressions and tighten multicast spoofing assertions.

Reviewed changes

Copilot reviewed 15 out of 15 changed files in this pull request and generated 3 comments.

Show a summary per file
File Description
src/wolfip.c Core fixes + extensive temporary debug tracing; adds multiple regression hardenings (FIFO wrap, UDP demux, TCP LISTEN demux, DNS parsing, TX retry/backpressure handling, raw sendto length guard).
src/tftp/wolftftp.h Update RRQ/WRQ worst-case sizing commentary (timeout option width).
src/test/unit/unit.c Register new unit tests covering the newly added regressions/fixes.
src/test/unit/unit_tests_tcp_ack.c Add regression test for safe post-callback reaping when callback recreates socket in same slot.
src/test/unit/unit_tests_proto.c Add regression tests for TCP LISTEN local-IP matching, DHCP UDP relaxation scoping, and raw/packet TX -EAGAIN retry semantics.
src/test/unit/unit_tests_poll_dispatcher.c Add regression tests ensuring reraised events survive callback reentrancy for raw/packet sockets.
src/test/unit/unit_tests_multicast.c Strengthen IGMP spoofing tests to assert no deferred report timers are armed and no later send occurs.
src/test/unit/unit_tests_fifo.c Add FIFO regression tests for alignment-induced head wrap edge cases.
src/test/unit/unit_tests_dns_edges.c Add DNS regressions for QR-only response acceptance and PTR RDATA name-bounds enforcement; update dns_copy_name callsites.
src/test/unit/unit_tests_dns_dhcp.c Scope DHCP local_ip==0 relaxation test by setting dhcp_udp_sd.
src/test/unit/unit_tests_branches.c Add raw sendto oversized-length rejection regression test.
src/test/unit/unit_tests_api.c Update dns_copy_name callsites for new rdata_end parameter.
src/test/test_native_wolfssl.c Add unbuffered stdout and additional debug prints/heartbeat to localize macOS hang.
src/port/stm32h563/ssh_server.h Clarify ssh_server_get_uptime is currently a placeholder returning 0.
src/http/httpd.h Clarify query is present only if included in the request target.
Suppressed comments (5)

src/wolfip.c:1818

  • This debug frame parser reads Ethernet/IP bytes (fb[12], iph[0], iph[9], etc.) without first proving the buffer is long enough. If wolfIP_ll_send_frame is ever called with a short frame, this is undefined behavior / potential crash in DEBUG builds. Add minimum-length guards (and compile the block out unless DEBUG is enabled).
    {
        /* DEBUG (temporary, macos bisect): every frame leaving the stack */
        const uint8_t *fb = (const uint8_t *)buf;
        uint16_t et = (uint16_t)((fb[12] << 8) | fb[13]);
        if (et == 0x0800) {
            const uint8_t *iph = fb + ETH_HEADER_LEN;
            uint8_t ihl = (iph[0] & 0x0f) * 4;

src/wolfip.c:5523

  • Unconditional per-packet debug printf/fflush in the TCP demux loop can severely slow RX and perturb scheduling. Compile this out unless DEBUG is enabled.
            {
                /* DEBUG (temporary, macos bisect) */
                printf("dbg RX matched: sock=%d state=%d\n", i,
                       (int)t->sock.tcp.state);
                fflush(stdout);
            }

src/wolfip.c:6762

  • This send-EAGAIN debug printf/fflush is compiled in unconditionally and triggers in hot paths; it should be compiled out unless DEBUG is enabled.
                {
                    /* DEBUG (temporary, macos bisect) */
                    struct fifo *dbg_fb = (struct fifo *)&ts->sock.tcp.txbuf;
                    printf("dbg send-EAGAIN: %u.%u->%u.%u head=%u tail=%u "
                           "h_wrap=%u size=%u\n",
                           (unsigned)(ts->local_ip & 0xff), (unsigned)ts->src_port,
                           (unsigned)(ts->remote_ip & 0xff), (unsigned)ts->dst_port,
                           (unsigned)dbg_fb->head, (unsigned)dbg_fb->tail,
                           (unsigned)dbg_fb->h_wrap, (unsigned)dbg_fb->size);
                    fflush(stdout);
                }

src/wolfip.c:11390

  • The dispatcher debug printf/fflush is compiled in unconditionally and runs on every socket callback dispatch, which can materially change timing and spam logs. Compile this out unless DEBUG is enabled.
            {
                /* DEBUG (temporary, macos bisect) */
                printf("dbg dispatch: sock=%d ev=0x%04x state=%d\n", i,
                       (unsigned)events, (int)ts->sock.tcp.state);
                fflush(stdout);
            }

src/wolfip.c:11562

  • Unconditional printf/fflush in the TCP TX flush path runs once per attempted send and can significantly perturb throughput/timing (and drown CI logs). Compile this out unless DEBUG is enabled.
                    {
                        /* DEBUG (temporary, macos bisect) */
                        printf("dbg flush: ret=%d len=%u\n", (int)send_ret,
                               (unsigned)desc->len);
                        fflush(stdout);
                    }

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread src/wolfip.c
Comment on lines 32 to 35
#include "wolfip.h"
#include "config.h"
#include <stdio.h> /* DEBUG (temporary, macos bisect) */

Comment thread src/wolfip.c
Comment on lines +1776 to +1780
{
/* DEBUG (temporary, macos bisect) */
printf("dbg TXgate: len=%u mtu=%u\n", (unsigned)len, (unsigned)frame_mtu);
fflush(stdout);
}
Comment thread src/wolfip.c
Comment on lines +5457 to +5464
{
/* DEBUG (temporary, macos bisect): every TCP segment passing checksum */
printf("dbg RX tcp: %u->%u sport=%u dport=%u flags=0x%02x\n",
(unsigned)(tcp->ip.src & 0xff), (unsigned)(tcp->ip.dst & 0xff),
(unsigned)ee16(tcp->src_port), (unsigned)ee16(tcp->dst_port),
(unsigned)tcp->flags);
fflush(stdout);
}
@danielinux danielinux closed this Aug 21, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants