diff --git a/testing/nat/scripts/nat-test.sh b/testing/nat/scripts/nat-test.sh index 0d9f8052..284edd57 100755 --- a/testing/nat/scripts/nat-test.sh +++ b/testing/nat/scripts/nat-test.sh @@ -64,7 +64,13 @@ send_stun_probe() { local stun_host="$2" local stun_port="$3" - docker exec "$container" python3 - "$stun_host" "$stun_port" <<'PY' 2>&1 || true + # `-i` is required: without it docker attaches no stdin, `python3 -` reads an + # empty program, and the probe silently does nothing while exiting 0. + # Coverage gap, deliberate and not discharged: this probe is diagnostic only, + # all four callers sitting inside dump_* helpers on failure paths, so nothing + # reds if the flag is removed again. The `|| true` stays for the same reason: + # a diagnostic dump must not abort part-way because one probe failed. + docker exec -i "$container" python3 - "$stun_host" "$stun_port" <<'PY' 2>&1 || true import os import socket import struct diff --git a/testing/nat/scripts/nostr-relay-test.sh b/testing/nat/scripts/nostr-relay-test.sh index 7f2e1ce2..a075d05a 100755 --- a/testing/nat/scripts/nostr-relay-test.sh +++ b/testing/nat/scripts/nostr-relay-test.sh @@ -165,15 +165,25 @@ dump_diagnostics() { } # Publish a malformed Kind-37195 (overlay-advert) event directly to the -# relay. The event is signed with a fresh ephemeral keypair (so the -# relay accepts it on the wire) but its `content` is gibberish that -# cannot deserialize as OverlayAdvert. Both consumer daemons must log a -# parse error and stay alive. +# relay. The event is signed with a fresh ephemeral keypair, so the relay +# accepts it on the wire, and both consumer daemons must reject it and +# stay alive. +# +# Which rejection they take is not what the event's gibberish `content` +# suggests. `parse_overlay_advert_event` looks for the `protocol` tag +# first (src/nostr/runtime.rs:1665-1671) and this event carries only `d` +# and `app`, so it fails with `missing required protocol tag` and never +# reaches the `serde_json::from_str` at :1679. The content is therefore +# belt and braces rather than the thing under test. +# +# Neither branch logs anything: see the coverage-gap note in run_test. publish_malformed_advert() { local relay_host="$1" local relay_port="$2" - docker exec "$NODE_A" python3 - "$relay_host" "$relay_port" <<'PY' + # `-i` is required: without it docker attaches no stdin, `python3 -` reads an + # empty program, runs nothing and exits 0, so the stimulus is never injected. + docker exec -i "$NODE_A" python3 - "$relay_host" "$relay_port" <<'PY' import base64 import hashlib import json @@ -281,6 +291,13 @@ while int.from_bytes(secret, "big") == 0 or int.from_bytes(secret, "big") >= N: pubkey = xonly_pubkey(secret).hex() created_at = int(time.time()) +# Both of these must match the consumers' subscription filter, which is +# kind + identifier and no author clause (src/nostr/runtime.rs:1042-1044). +# The literals are ADVERT_KIND and ADVERT_IDENTIFIER in src/nostr/types.rs +# and are duplicated here rather than derived, so changing either there +# silently stops this event reaching the daemons while the relay goes on +# accepting it. `next` uses `fips-overlay-v1-next`, which is the one line +# that differs between the branches' copies of this script. kind = 37195 tags = [ ["d", "fips-overlay-v1"], @@ -355,13 +372,75 @@ else: frame += mask + masked sock.sendall(bytes(frame)) -# Read the relay's OK/NOTICE response (best-effort). -sock.settimeout(3) +# The relay's verdict decides whether the stimulus was delivered at all. +# strfry verifies the event id and the BIP-340 signature and answers +# ["OK",,false,"invalid: ..."] on refusal; a refused event is never +# stored and never broadcast, so the consumers never see it and phase 3 +# proves nothing. Reading the reply and continuing regardless is what let +# that pass unnoticed. +# +# The timeout is 10s rather than 3s: this is a loopback docker network to a +# local relay, and a missing ack is a failure below, so the margin is there +# to keep that from becoming a flake. +sock.settimeout(10) + + +def server_frame_payload(buf): + """Return the payload of the first server frame in buf, or None.""" + # Decoded rather than pattern-matched: a payload of 91 bytes puts a + # literal '[' in the length byte, so searching for the JSON would find + # the header instead of the body. + if len(buf) < 2: + return None + n = buf[1] & 0x7F + off = 2 + if n == 126: + if len(buf) < 4: + return None + n = struct.unpack("!H", buf[2:4])[0] + off = 4 + elif n == 127: + if len(buf) < 10: + return None + n = struct.unpack("!Q", buf[2:10])[0] + off = 10 + if buf[1] & 0x80: + # A server must not mask, but tolerate one that does. + mask = buf[off:off + 4] + off += 4 + body = bytes(b ^ mask[i % 4] for i, b in enumerate(buf[off:off + n])) + else: + body = buf[off:off + n] + return body if len(body) == n else None + + +def relay_verdict(reply, want_id): + """Classify the relay's answer to our EVENT. Only "accepted" means stored.""" + payload = server_frame_payload(reply) + if payload is None: + return "unreadable-frame" + try: + msg = json.loads(payload.decode("utf-8", "replace")) + except ValueError: + return "unparsable-frame" + # NIP-01: an OK is FOUR elements, ["OK", , , ], + # and the message is mandatory even on success. Matching a substring such + # as `,true]` therefore never fires against a conformant relay, which is + # why this parses the array instead. + if isinstance(msg, list) and len(msg) >= 3 and msg[0] == "OK" and msg[1] == want_id: + return "accepted" if msg[2] is True else "rejected" + if isinstance(msg, list) and msg and msg[0] == "NOTICE": + return "notice" + return "unrecognised-frame" + + +verdict = "no-ack" try: reply = sock.recv(4096) print("relay reply:", reply[:200]) + verdict = relay_verdict(reply, event_id.hex()) except socket.timeout: - print("relay reply: ") + print("relay reply: ") # Polite close (opcode 0x88 = close), then drop. try: @@ -369,7 +448,9 @@ try: except OSError: pass sock.close() -print("malformed advert published") +print("malformed advert published:", verdict) +if verdict != "accepted": + raise SystemExit(3) PY } @@ -441,7 +522,31 @@ run_test() { echo "" echo "=== nostr-relay-test: phase 3 (malformed advert) ===" - publish_malformed_advert "$RELAY_HOST" "$RELAY_PORT" + # The publisher's verdict line is the evidence that the relay STORED the + # event. Without this check the phase passes whether or not anything was + # published: the assertions below re-test properties that phases 1 and 2 + # already established, so they all hold when the stimulus is absent. + # + # Accepted by the relay is one hop short of received by the consumers. + # A daemon whose relay socket is down at that moment, or whose `d` tag no + # longer matches the one published above, never sees a stored event and + # this check still passes. That hop is unguarded. + local publish_out + if ! publish_out="$(publish_malformed_advert "$RELAY_HOST" "$RELAY_PORT" 2>&1)"; then + printf '%s\n' "$publish_out" + echo "malformed-advert publisher failed: nothing was published, so" >&2 + echo "phase 3 would prove nothing about ingest." >&2 + dump_diagnostics + return 1 + fi + printf '%s\n' "$publish_out" + if ! grep -q "malformed advert published: accepted" <<<"$publish_out"; then + echo "malformed-advert publisher reported no accepted relay verdict:" >&2 + echo "the relay did not store the event, so it reached no consumer" >&2 + echo "and phase 3 would prove nothing about the reject path." >&2 + dump_diagnostics + return 1 + fi # Give consumers a moment to ingest and reject. sleep 5 @@ -451,6 +556,11 @@ run_test() { assert_no_panic "$NODE_A" || { dump_diagnostics; return 1; } assert_no_panic "$NODE_B" || { dump_diagnostics; return 1; } + # Coverage gap, deliberate and not discharged: this phase asserts that + # the daemons did not crash on the malformed advert, not that they + # rejected it. The reject path emits no log - src/nostr/runtime.rs:755 + # discards the error with `let Ok(advert) =` and no diagnostic - so + # there is nothing observable from outside the process to assert on. # Existing peer link must still be healthy (consumer didn't tear # down on a bad advert). if ! docker exec "$NODE_A" ping6 -c 3 -W 5 "${NPUB_B}.fips" >/dev/null; then diff --git a/testing/native-api/client.py b/testing/native-api/client.py index b377b9a6..f5f41af8 100755 --- a/testing/native-api/client.py +++ b/testing/native-api/client.py @@ -12,6 +12,7 @@ it exits. Kinds of step: RPC step: {"command": str, "params": {...}?, "expect": {"dotted.key": val}?, + "settle": bool?, "keep_fd": name?, "keep_listener": name?, "keep_flow": name?} Sends a command and checks the reply. `keep_fd` stores a flow descriptor under that name, `keep_listener` a listener descriptor; @@ -76,6 +77,13 @@ from typing import Any FLOW = "flow" LISTENER = "listener" +# How long a settling step keeps re-asking, and how long it pauses between +# tries. The wait is for a task hop on a host that may be loaded, so it is +# seconds rather than milliseconds; it is bounded because a datagram that +# never arrives has to end the run red rather than hold it open. +SETTLE_SECONDS = 5.0 +SETTLE_PAUSE = 0.02 + def recvfds(sock: socket.socket, bufsize: int, maxfds: int) -> tuple[bytes, list[int]]: """One recvmsg, returning its payload and whatever descriptors it carried. @@ -287,7 +295,16 @@ def store(client: Client, step: dict, body: dict, fd: int | None) -> list[str]: def run_rpc(client: Client, step: dict) -> list[str]: - """Send one command and report what did not hold.""" + """Send one command and report what did not hold. + + A step naming `settle` is asked again until its expectations hold or the + deadline passes. What `stats` reports is advanced by the daemon's per-flow + reader task, and nothing orders that task against the client's write on the + flow descriptor: one ask can be answered while a datagram is still queued in + the kernel socket buffer, and it reads back as zero. Re-asking is the only + barrier this protocol offers, and the deadline is what keeps a datagram that + never arrives a failure rather than a hang. + """ command = step["command"] try: params = substitute(step.get("params"), client.flows) @@ -295,8 +312,23 @@ def run_rpc(client: Client, step: dict) -> list[str]: except KeyError as error: return [str(error)] - reply, fd = client.call(command, params) - problems = check(reply, expect) + settle = bool(step.get("settle")) + if settle and (step.get("keep_fd") or step.get("keep_listener")): + # Every ask but the last is discarded, and a discarded reply's + # descriptor has no owner. Refusing beats closing one a later step + # meant to keep. + return ["settle: a step that keeps a descriptor cannot be re-asked"] + + deadline = time.monotonic() + SETTLE_SECONDS + while True: + reply, fd = client.call(command, params) + problems = check(reply, expect) + if not problems or not settle or time.monotonic() >= deadline: + break + if fd is not None: + os.close(fd) + time.sleep(SETTLE_PAUSE) + problems += store(client, step, reply, fd) if problems: diff --git a/testing/native-api/test.sh b/testing/native-api/test.sh index 8569c582..2badf346 100755 --- a/testing/native-api/test.sh +++ b/testing/native-api/test.sh @@ -409,11 +409,17 @@ check_descriptor_carries_datagrams() { # Three writes must reach the daemon as three datagrams. The byte count # matters as much as the datagram count: a boundary loss would show up as # one datagram of nine bytes rather than three of three. + # + # The read settles. The daemon counts a datagram on the flow's own reader + # task, and nothing orders that task against the client's write, so a single + # ask can be answered while the writes are still queued in the kernel and + # read back as zero. Re-asking is the only barrier the protocol offers; the + # deadline keeps a datagram that never arrives a failure rather than a hang. local script='[ {"command":"connect","params":{"peer":"'"$PEER"'","remote_port":4242}, "keep_fd":"a","keep_flow":"a","expect":{"status":"ok"}}, {"fd":"a","write":"00ff10","repeat":3}, - {"command":"stats","params":{"flow_id":"@a"}, + {"command":"stats","params":{"flow_id":"@a"},"settle":true, "expect":{"status":"ok","data.rx_datagrams":3,"data.rx_bytes":9,"data.closed":false}} ]' if run_client "$script"; then @@ -452,34 +458,43 @@ check_close_reaches_the_daemon() { # The node forgets a released flow, so `stats` answers for it the way it # answers for any name it does not hold. The step before the close is what # makes that discriminating: the same flow answered a moment earlier, so the - # refusal afterwards can only be the release. The sleep is the task hop - # between the daemon reading end of file and giving the entry back. + # refusal afterwards can only be the release. Both reads settle: the same + # task hop that delays a datagram count also delays the daemon noticing end + # of file, and a bounded re-ask is a barrier where a fixed sleep was a guess. local script='[ {"command":"connect","params":{"peer":"'"$PEER"'","remote_port":4242}, "keep_fd":"a","keep_flow":"a","expect":{"status":"ok"}}, {"fd":"a","write":"aa"}, - {"command":"stats","params":{"flow_id":"@a"}, + {"command":"stats","params":{"flow_id":"@a"},"settle":true, "expect":{"status":"ok","data.closed":false,"data.rx_datagrams":1}}, {"fd":"a","close":true}, - {"sleep":1}, - {"command":"stats","params":{"flow_id":"@a"},"expect":{"status":"error"}} + {"command":"stats","params":{"flow_id":"@a"},"settle":true, + "expect":{"status":"error"}} ]' if run_client "$script"; then pass "the daemon saw the close and gave the flow back" else - fail "the daemon did not release the closed flow" + fail "the close script did not hold; the failing step is above" fi } check_flows_are_independent() { log "Two flows on one connection stay separate" + # Flow a's read settles; flow b's cannot and is left as it is. A settling + # step re-asks until its expectation HOLDS, and "b counted 0" holds on the + # first ask whether or not b's reader task has ever run. So this stays a + # false green: if traffic ever did cross, b could read 0 for the same + # scheduling reason and the check would pass. Closing it needs a positive + # claim on b, writing a known count there and settling it, which is a + # larger change than this one. local script='[ {"command":"connect","params":{"peer":"'"$PEER"'","remote_port":4242}, "keep_fd":"a","keep_flow":"a","expect":{"status":"ok"}}, {"command":"connect","params":{"peer":"'"$PEER2"'","remote_port":4243}, "keep_fd":"b","keep_flow":"b","expect":{"status":"ok"}}, {"fd":"a","write":"11","repeat":2}, - {"command":"stats","params":{"flow_id":"@a"},"expect":{"data.rx_datagrams":2}}, + {"command":"stats","params":{"flow_id":"@a"},"settle":true, + "expect":{"data.rx_datagrams":2}}, {"command":"stats","params":{"flow_id":"@b"},"expect":{"data.rx_datagrams":0}}, {"command":"inject","params":{"flow_id":"@b","data":"22"},"expect":{"status":"ok"}}, {"fd":"b","read":1,"expect_bytes":"22"}, @@ -488,7 +503,7 @@ check_flows_are_independent() { if run_client "$script"; then pass "each flow saw only its own traffic" else - fail "traffic crossed between flows" + fail "the two-flow script did not hold; the failing step is above" fi }