From 2371460bfda1210cc2765380d42cd2eb7552aeda Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 15:51:55 +0100 Subject: [PATCH 1/9] fix(mysterium): flag nodes whose router rewrites UDP ports instead of showing them healthy A router that rewrites the source port of some outgoing UDP flows (a fibre box that reserves ports in pairs, a SIP ALG) leaves a Mysterium node online, passing its own port check and logging "Method:manual Success:true", while every session ends after about a minute having carried nothing. The worker now asks the node itself, read-only, for Mysterium's monitoring status and its last five sessions (docker.health_probe), and the 30-minute sweep lists the node under Needs fixing when monitoring reads "failed" or those sessions are all a minute long and empty. The guide explains the failure, ships a two-port STUN test, and lists the fixes in order of risk. --- Dockerfile.worker | 3 + app/catalog.py | 7 +- app/health_probe.py | 159 +++++++++++++++++ app/main.py | 67 ++++++- app/worker_api.py | 20 +++ docs/guides/mysterium.md | 111 +++++++++++- scripts/stun_port_pair.py | 133 ++++++++++++++ services/_schema.yml | 17 +- services/bandwidth/mysterium.yml | 46 +++++ tests/test_mysterium_health_probe.py | 254 +++++++++++++++++++++++++++ 10 files changed, 807 insertions(+), 10 deletions(-) create mode 100644 app/health_probe.py create mode 100644 scripts/stun_port_pair.py create mode 100644 tests/test_mysterium_health_probe.py diff --git a/Dockerfile.worker b/Dockerfile.worker index d08db592..c95ec62c 100644 --- a/Dockerfile.worker +++ b/Dockerfile.worker @@ -82,6 +82,9 @@ COPY --chown=cashpilot:root app/procnet.py ./app/ COPY --chown=cashpilot:root app/payout_read.py ./app/ # Reads a node's own earnings figures from inside it (Mysterium, issue #488). COPY --chown=cashpilot:root app/node_read.py ./app/ +# Asks a running node how it is doing from inside it (docker.health_probe); +# catalog.py also validates the declaration with it. +COPY --chown=cashpilot:root app/health_probe.py ./app/ COPY --chown=cashpilot:root app/arch.py ./app/ COPY --chown=cashpilot:root app/catalog.py ./app/ # catalog.py validates each entry's rating block with it (the rules ship in services/). diff --git a/app/catalog.py b/app/catalog.py index af540897..664885f4 100644 --- a/app/catalog.py +++ b/app/catalog.py @@ -18,7 +18,7 @@ import yaml -from app import arch, ratings +from app import arch, health_probe, ratings logger = logging.getLogger(__name__) @@ -312,6 +312,11 @@ def _validate(data: dict[str, Any], path: Path) -> list[str]: errors.append( f"{path.name}: docker.health_signals[{i}]: state account_disabled cannot have window_hours" ) + if "health_probe" in docker: + # A probe that cannot be read is no check at all: the node would + # look fine for want of a working regex. + for problem in health_probe.spec_errors(docker["health_probe"]): + errors.append(f"{path.name}: docker.health_probe: {problem}") ports = docker.get("ports") if isinstance(ports, list): # A bad mapping used to load fine and then 500 the deploy, on diff --git a/app/health_probe.py b/app/health_probe.py new file mode 100644 index 00000000..1d45f100 --- /dev/null +++ b/app/health_probe.py @@ -0,0 +1,159 @@ +"""Ask a running node how it is doing, from inside its container (worker side). + +Some failures never reach a log line the tail can catch and leave the +container healthy: a Mysterium node behind a router that rewrites the UDP +source port of some of its connections registers, passes its own port check +and is offered to buyers, and every session it gets ends after about a minute +having carried nothing. The node's own API knows: its monitoring status reads +"failed" and its recent sessions are all short and empty. + +The catalog declares the read in ``docker.health_probe``: + + health_probe: + command: ["sh", "-c", "..."] # run inside the container, read-only + checks: + - pattern: '...' # regex on the command's output + means: "..." # shown under Needs fixing + - items: '...' # regex for one item of a list + pattern: '...' # what makes an item bad + min_matches: 3 # items needed before judging + means: "..." + +A check without ``items`` holds when ``pattern`` matches the output at least +``min_matches`` times (default 1). With ``items`` it holds when the output has +at least ``min_matches`` items and every one of them matches ``pattern``: one +good item clears it, and too few items say nothing. Patterns are +case-sensitive, like ``collector.node_read``. + +Read-only by construction, like ``app/node_read.py``: the command comes from +the catalog in this image, never from a request, and only the indexes of the +checks that hold leave the worker, never the output. +""" + +from __future__ import annotations + +import concurrent.futures +import logging +import re +from typing import Any + +logger = logging.getLogger(__name__) + +#: Seconds one container's read may take before it is reported as unread. +READ_TIMEOUT = 15 + +_pool = concurrent.futures.ThreadPoolExecutor(max_workers=4, thread_name_prefix="health-probe") + + +def _min_matches(check: dict[str, Any]) -> int | None: + value = check.get("min_matches", 1) + if isinstance(value, bool) or not isinstance(value, int) or value < 1: + return None + return value + + +def spec_errors(spec: Any) -> list[str]: + """What is wrong with a ``docker.health_probe`` declaration; empty when it is usable.""" + if not isinstance(spec, dict): + return ["must be a mapping"] + errors: list[str] = [] + command = spec.get("command") + if not (isinstance(command, list) and command and all(isinstance(p, str) for p in command)): + errors.append("command must be a non-empty list of strings") + checks = spec.get("checks") + if not (isinstance(checks, list) and checks): + return [*errors, "checks must be a non-empty list"] + for i, check in enumerate(checks): + if not isinstance(check, dict): + errors.append(f"checks[{i}] must be a mapping") + continue + for field in ("pattern", "items"): + value = check.get(field) + if value is None and field == "items": + continue + try: + if not isinstance(value, str) or not value: + raise TypeError + re.compile(value) + except (re.error, TypeError): + errors.append(f"checks[{i}].{field} must be a non-empty regular expression") + if not isinstance(check.get("means"), str) or not check["means"].strip(): + errors.append(f"checks[{i}].means must be a non-empty string") + if _min_matches(check) is None: + errors.append(f"checks[{i}].min_matches must be a positive integer") + return errors + + +def probes(services: list[dict[str, Any]]) -> dict[str, dict[str, Any]]: + """slug -> its declared probe, for services that declare a well-formed one.""" + out: dict[str, dict[str, Any]] = {} + for svc in services: + spec = (svc.get("docker") or {}).get("health_probe") + if spec is None: + continue + if spec_errors(spec): + logger.warning("Ignoring %s docker.health_probe: %s", svc.get("slug"), "; ".join(spec_errors(spec))) + continue + out[svc["slug"]] = spec + return out + + +def holds(output: bytes | str | None, check: dict[str, Any]) -> bool: + """Whether one check holds on the command's output.""" + text = output.decode(errors="replace") if isinstance(output, bytes) else (output or "") + needed = _min_matches(check) or 1 + pattern = re.compile(check["pattern"]) + if not check.get("items"): + return sum(1 for _ in pattern.finditer(text)) >= needed + items = [m.group(0) for m in re.finditer(check["items"], text)] + return len(items) >= needed and all(pattern.search(item) for item in items) + + +def judge(output: bytes | str | None, spec: dict[str, Any]) -> list[int]: + """The indexes of the checks that hold on the command's output.""" + return [i for i, check in enumerate(spec["checks"]) if holds(output, check)] + + +def _read_one(container: Any, spec: dict[str, Any]) -> list[int] | None: + code, output = container.exec_run(spec["command"]) + if code != 0: + return None + return judge(output, spec) + + +def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: + """One row per running managed copy of a service that declares a probe. + + A row carries ``hits``, the indexes of the checks that hold, when the read + worked, and ``error`` when it did not: an unread node is no verdict, never + a healthy one. + """ + # Imported here: the UI imports this module for nothing but the catalog + # check, and has no Docker. + from app import orchestrator + + rows: list[dict[str, Any]] = [] + for slug, spec in sorted(probes(services).items()): + try: + copies = orchestrator.service_instances(slug) + except Exception as exc: # noqa: BLE001 - one service never fails the rest + logger.warning("Could not list %s containers for the health probe: %s", slug, exc) + continue + for container in copies: + if getattr(container, "status", "") != "running": + continue + row: dict[str, Any] = {"slug": slug, "instance": orchestrator._instance_of(container)} + try: + hits = _pool.submit(_read_one, container, spec).result(timeout=READ_TIMEOUT) + except concurrent.futures.TimeoutError: + row["error"] = "timed out" + except Exception as exc: # noqa: BLE001 + logger.warning("Health probe failed for %s: %s", slug, exc) + row["error"] = "read failed" + else: + if hits is None: + row["error"] = "the node did not answer" + else: + row["hits"] = hits + rows.append(row) + return rows diff --git a/app/main.py b/app/main.py index ef86f843..e22b2a13 100644 --- a/app/main.py +++ b/app/main.py @@ -1932,6 +1932,10 @@ async def _check_stale_workers() -> None: # The startup sweep and the scheduled one must not overlap: the older would # finish last and put back stale hints. _windowed_lock = asyncio.Lock() +#: The part of _windowed_hints that came from a node's health probe +#: (docker.health_probe), per copy, so a probe that could not be read this +#: time keeps its last verdict without holding back the log signals. +_probe_hints: dict[tuple[str, int, int], list[str]] = {} _DOCKER_POOLS = ipaddress.ip_network("172.16.0.0/12") @@ -1967,11 +1971,12 @@ async def _render_signal_means(signal: dict[str, Any], slug: str, worker: dict[s recorded_env = {k: str(v) for k, v in ((recorded or {}).get("env") or {}).items() if str(v)} env.update(recorded_env) env["HOST_ADDRESS"] = _private_ipv4((worker or {}).get("url", "")) or "this machine's LAN address" + env["WORKER_NAME"] = str((worker or {}).get("name") or "this machine") text = " ".join(str(signal.get("means") or "").split()) # A copy deployed before a setting existed does not run with its default yet # (Mysterium without UDP_PORTS picks from 10000:60000), so naming the default # alone would send the operator to forward a range the node does not use. - used = set(re.findall(r"\$\{(\w+)\}", text)) - {"HOST_ADDRESS"} + used = set(re.findall(r"\$\{(\w+)\}", text)) - {"HOST_ADDRESS", "WORKER_NAME"} if recorded is not None and any(key not in recorded_env for key in used): text = ( "This copy was deployed before CashPilot set these values, so it does not use them yet: " @@ -1990,22 +1995,43 @@ async def _check_windowed_signals() -> None: await _sweep_windowed_signals() +async def _health_probe_rows(wid: int, cache: dict[int, list[dict[str, Any]] | None]) -> list[dict[str, Any]] | None: + """What a worker's /api/health-probes says, asked once per sweep; None when it did not answer. + + A worker from before the endpoint answers 404, which is no verdict. + """ + if wid not in cache: + try: + result = await _proxy_to_worker(wid, "GET", "/api/health-probes", timeout=60) + rows = result.get("probes") if isinstance(result, dict) else None + cache[wid] = rows if isinstance(rows, list) else None + except Exception as exc: # noqa: BLE001 - one worker never fails the sweep + logger.info("Health probes unread on worker %s: %s", wid, exc) + cache[wid] = None + return cache[wid] + + async def _sweep_windowed_signals() -> None: - global _windowed_hints + global _windowed_hints, _probe_hints try: containers = await _get_all_worker_containers() except Exception as exc: logger.warning("Windowed signal check skipped: %s", exc) return hints: dict[tuple[str, int, int], list[str]] = {} + probe_hints: dict[tuple[str, int, int], list[str]] = {} + probe_rows: dict[int, list[dict[str, Any]] | None] = {} workers: dict[int, dict[str, Any] | None] = {} for c in containers: slug = egress.container_slug(c) wid = c.get("_worker_id") if not slug or wid is None or str(c.get("status", "")).lower() != "running": continue - signals = [s for s in producer_state.signals_for(catalog.get_service(slug)) if producer_state.is_windowed(s)] - if not signals: + service = catalog.get_service(slug) + signals = [s for s in producer_state.signals_for(service) if producer_state.is_windowed(s)] + probe = ((service or {}).get("docker") or {}).get("health_probe") + checks = probe.get("checks") if isinstance(probe, dict) and isinstance(probe.get("checks"), list) else [] + if not signals and not checks: continue instance = int(c.get("instance") or 1) key = (slug, wid, instance) @@ -2029,14 +2055,43 @@ async def _sweep_windowed_signals() -> None: continue if producer_state.windowed_hit(resp.get("logs", ""), signal): found.append(await _render_signal_means(signal, slug, workers[wid])) + if checks: + rows = await _health_probe_rows(wid, probe_rows) + row = next( + ( + r + for r in rows or [] + if isinstance(r, dict) + and r.get("slug") == slug + and r.get("instance") == instance + and isinstance(r.get("hits"), list) + ), + None, + ) + if row is None: + # Not read this time (worker busy, node slow to answer): the + # last verdict stands, as for the log signals. + probed = _probe_hints.get(key, []) + else: + probed = [ + await _render_signal_means(checks[i], slug, workers[wid]) + for i in row["hits"] + if isinstance(i, int) and not isinstance(i, bool) and 0 <= i < len(checks) + ] + if probed: + probe_hints[key] = probed + found += probed except Exception as exc: logger.warning("Windowed signal check failed for %s on worker %s: %s", slug, wid, exc) if key in _windowed_hints: hints[key] = _windowed_hints[key] + if key in _probe_hints: + probe_hints[key] = _probe_hints[key] continue if found: hints[key] = found _windowed_hints = hints + _probe_hints = probe_hints async def _raise_worker_offline_alert(w: dict[str, Any]) -> None: @@ -6073,7 +6128,9 @@ async def api_producer_state(request: Request, slug: str, worker_id: int | None # cost of the rest of the verdict. with contextlib.suppress(Exception): address_mismatch = await _advertised_address_mismatch(matches, worker_id) - if signals and running: + # A health probe's verdicts ride in the same sweep hints as the windowed log signals. + probed = bool(((service or {}).get("docker") or {}).get("health_probe")) + if (signals or probed) and running: wid = worker_id if worker_id is not None else (matches[0].get("_worker_id") if matches else None) if wid is not None: # The sweep's verdicts first, so a failed tail read below cannot drop them. diff --git a/app/worker_api.py b/app/worker_api.py index c2434c89..70d7689f 100644 --- a/app/worker_api.py +++ b/app/worker_api.py @@ -44,6 +44,7 @@ activity, egress, fleet_key, + health_probe, isolation_check, lan_fence, node_read, @@ -2335,6 +2336,25 @@ async def api_node_earnings(request: Request) -> dict[str, Any]: return {"nodes": rows} +@app.get("/api/health-probes") +async def api_health_probes(request: Request) -> dict[str, Any]: + """Which declared health checks hold for each node on this worker. + + Only for services whose catalog entry declares ``docker.health_probe`` + (Mysterium's monitoring status and recent sessions). Read-only, and only + the indexes of the checks that hold leave the worker: see + app/health_probe.py. + """ + _verify_api_key(request) + if not _catalog_get_services: + return {"probes": []} + try: + rows = await asyncio.to_thread(health_probe.read_all, _catalog_get_services()) + except RuntimeError as exc: + raise HTTPException(status_code=503, detail=str(exc)) + return {"probes": rows} + + @app.get("/api/update/info") async def api_update_info(request: Request) -> dict[str, Any]: """Whether this install can update itself, and what it runs (issue #342).""" diff --git a/docs/guides/mysterium.md b/docs/guides/mysterium.md index 405b455c..fc869f95 100644 --- a/docs/guides/mysterium.md +++ b/docs/guides/mysterium.md @@ -212,10 +212,14 @@ its brackets, so compare them with your range. docker logs cashpilot-mysterium 2>&1 | grep -o 'Method:[a-z]* Success:[a-z]*' | sort | uniq -c ``` -`Method:manual Success:true` means sessions reach the node through the forward. +`Method:manual Success:true` means buyers' packets reach the node through the +forward. It does not prove the sessions work: that also needs the node's +answers to leave from the ports it advertised, and a router that rewrites UDP +source ports breaks that while this line stays `true` (see +[Routers that rewrite UDP source ports](#routers-that-rewrite-udp-source-ports)). Only `Method:manual Success:false` lines, each followed by -`Method:holepunching`, mean they do not. The node's `/nat/type` keeps -reporting `prcone` even when forwarding works, so don't go by it. +`Method:holepunching`, mean the forward does not work. The node's `/nat/type` keeps +reporting `prcone` whether forwarding works or not, so don't go by it. CashPilot checks this too, every 30 minutes. When a node has had at least five failed direct connections and not one successful one in the last 6 hours, the @@ -224,6 +228,107 @@ The item clears by itself once a session connects directly. A node with no sessions yet is not flagged. The dashboard reloads its list every hour, or when you open it. +On the same 30-minute round the worker also asks the node itself, read-only, +for Mysterium's monitoring status and its last five sessions. It lists the node +under **Needs fixing** when the monitoring status is `failed`, and when those +five sessions each ended after about a minute having carried no data. Both +point at the problem in the next section when nothing else is listed for the node. + +### Routers that rewrite UDP source ports + +**Symptom.** The node is online, its port check says `All ports [...] are +reachable` and the log shows `Method:manual Success:true`, yet it earns +nothing. Every session ends after about 60 seconds with 0 bytes either way: + +```bash +docker exec cashpilot-mysterium wget -qO- \ + 'http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=10' \ + | grep -o '"duration":[0-9]*,"bytes_received":[0-9]*,"bytes_sent":[0-9]*' +``` + +`/node/monitoring-status` answers `{"status":"failed"}`, +`/node/monitoring-agent-statuses` shows `connect_fail` with no +`tun_device_problem`, the node's STUN check logs `NATType:restricted` where a +working line gives `full` +(`docker logs cashpilot-mysterium 2>&1 | grep -o 'NATType:[a-z]*' | sort | uniq -c`), +and Mysterium's discovery stops offering the node to most buyers. A missing +`SETUID`/`SETGID` or `/dev/net/tun` looks much the same; rule those out first +with [the section below](#running-but-not-earning-monitoring-failed-quality-0). + +**Cause.** The router in front of the machine changes the source port of some +outgoing UDP flows. Inbound works, so every check that only tests inbound +passes. But the node advertises the ports it listens on and answers from them, +and when the router sends an answer out from a different port, the buyer's +client drops it. The session is set up, never carries a byte, and times out. + +One pattern seen on some ISP fibre boxes (an ONT with a built-in router): the +box reserves outgoing UDP ports in pairs. When it maps port P it also holds P +XOR 1 (23000 and 23001, 23002 and 23003, and so on), and a later flow from the +partner port leaves with a random port. Others do it for every port, or only +when a SIP ALG or the box's own VoIP service owns a range. + +**Why a narrow range makes it near certain.** Each session takes about two +ports from `UDP_PORTS`. In a range of 30 ports the node keeps reusing the same +few pairs, so a session's second port is almost always the partner of a port +already mapped, and gets rewritten. With the node's wide default (10000 to +60000, no `--udp.ports`) collisions are rare enough that a pairing router goes +unnoticed, which is why a node can work for months and fail the day its range +is narrowed. + +**Confirm it.** Ask a public STUN server which port it sees, from pairs of +neighbouring ports, inside the node's network namespace. CashPilot ships +a small script for this with no dependencies beyond Python 3, +[`scripts/stun_port_pair.py`](https://github.com/GeiserX/CashPilot/blob/main/scripts/stun_port_pair.py). +Run it in a throwaway container that shares the node's network, on the machine +running the node: + +```bash +curl -fsSLo /tmp/stun_port_pair.py \ + https://raw.githubusercontent.com/GeiserX/CashPilot/main/scripts/stun_port_pair.py +docker run --rm --network container:cashpilot-mysterium \ + -v /tmp/stun_port_pair.py:/t.py:ro python:3.15.2-alpine python /t.py +``` + +On a router that pairs ports, the even port of each pair comes back rewritten: + +``` +34101 -> 34101 kept +34100 -> 46948 REWRITTEN +34103 -> 34103 kept +34102 -> 46950 REWRITTEN +``` + +On a working line every port comes back with its own number. The script exits +0 when every port kept its number, 1 when one was rewritten and 2 when no STUN +server answered. It only sends a few packets to a public STUN server; it does +not touch the node. `--start` picks the first port to test (default 34100); +keep it outside `UDP_PORTS`, whose ports the node holds. + +**Fix.** In order, from least to most disruptive: + +1. **Turn off the router's SIP ALG and, if you do not use it, its own VoIP or + phone service.** Both rewrite UDP flows. Look under NAT, ALG, VoIP or + Telephony in the router's admin page. Some ISP boxes hide the setting; the + ISP's support can usually change it. +2. **Look for a setting that keeps ports.** Some routers call it port + preservation, endpoint-independent mapping, "full cone" NAT or NAT type 1. + Turn it on if it is there. +3. **Bridge mode with your own router.** Put the ISP box in bridge mode (some + ISPs call it ONT mode or "router off") and do NAT on a router of your own + that keeps source ports; most Linux-based routers and OpenWrt do. Then + forward `UDP_PORTS` on your router instead. This takes the whole house + offline for a few minutes and may need the ISP's help. +4. **A much wider `UDP_PORTS` range.** Fewer collisions, never none: the + sessions that land on a reserved partner still fail. Each published port + costs about 2.5 MB of memory in Docker's port proxy, the range must stay + free of other programs (see *Port forwarding*), and you forward the whole + range on the router. A range of 1,000 ports costs about 2.5 GB, which is + why this comes last. + +Run the script again after each change. Once every port keeps its number, +Mysterium's monitoring re-scores the node within a few hours, the next sessions +carry data, and the **Needs fixing** item clears by itself. + ### WebUI address The node runs in its own network namespace on CashPilot's fenced bridge. Its diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py new file mode 100644 index 00000000..885af579 --- /dev/null +++ b/scripts/stun_port_pair.py @@ -0,0 +1,133 @@ +#!/usr/bin/env python3 +"""Does the router in front of this machine keep UDP source ports, or rewrite some? + +A Mysterium node advertises the UDP ports it listens on and expects buyers' +packets to reach it, and its answers to leave, on those same ports. Some +routers keep a port's number only for some ports: a few fibre boxes reserve +ports in pairs (P and P XOR 1), so once one of a pair is in use the other +leaves with a random number. The node's own reachability check still passes, +because inbound traffic works; the sessions fail. + +This sends a STUN binding request from pairs of neighbouring source ports and +prints the port the internet saw for each. Every port should come back with +its own number. Run it in the node's network namespace (docs/guides/mysterium.md, +"Routers that rewrite UDP source ports"), with no other dependency than +Python 3: + + docker run --rm --network container:cashpilot-mysterium \\ + -v "$PWD/scripts/stun_port_pair.py:/t.py:ro" python:3.13-alpine python /t.py + +Exit status: 0 when every port kept its number, 1 when one was rewritten, +2 when no STUN server answered. Read-only: it sends a few UDP packets to a +public STUN server and changes nothing. +""" + +from __future__ import annotations + +import argparse +import os +import socket +import struct +import sys + +MAGIC = 0x2112A442 +SERVERS = [("stun.l.google.com", 19302), ("stun.cloudflare.com", 3478)] + + +def _mapped_port(data: bytes, txid: bytes) -> int | None: + """The port in a STUN binding success response, or None.""" + if len(data) < 20: + return None + kind, length, cookie = struct.unpack("!HHI", data[:8]) + if kind != 0x0101 or cookie != MAGIC or data[8:20] != txid: + return None + pos, end = 20, min(len(data), 20 + length) + plain = None + while pos + 4 <= end: + attr, size = struct.unpack("!HH", data[pos : pos + 4]) + value = data[pos + 4 : pos + 4 + size] + if attr == 0x0020 and len(value) >= 4: # XOR-MAPPED-ADDRESS + return struct.unpack("!H", value[2:4])[0] ^ (MAGIC >> 16) + if attr == 0x0001 and len(value) >= 4: # MAPPED-ADDRESS + plain = struct.unpack("!H", value[2:4])[0] + pos += 4 + size + (-size % 4) + return plain + + +def probe(sock: socket.socket, server: tuple[str, int], tries: int = 3) -> int | None: + """The source port the STUN server saw for packets from ``sock``.""" + for _ in range(tries): + txid = os.urandom(12) + sock.sendto(struct.pack("!HHI", 0x0001, 0, MAGIC) + txid, server) + try: + while True: + data, _ = sock.recvfrom(2048) + port = _mapped_port(data, txid) + if port is not None: + return port + except TimeoutError: + continue + return None + + +def _server() -> tuple[str, int] | None: + for host, port in SERVERS: + try: + return (socket.gethostbyname(host), port) + except OSError: + continue + return None + + +def main() -> int: + parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) + parser.add_argument("--start", type=int, default=34100, help="first port to test (default 34100)") + parser.add_argument("--pairs", type=int, default=4, help="neighbouring pairs to test (default 4)") + args = parser.parse_args() + server = _server() + if server is None: + print("No STUN server could be resolved: check this namespace's DNS.") + return 2 + first = args.start & ~1 + rewritten = answered = 0 + socks = [] + try: + for n in range(args.pairs): + even = first + 2 * n + # The odd port first, then its even partner while the first is still + # open: a router that reserves pairs gives the second one away. + for port in (even + 1, even): + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) + sock.settimeout(2) + socks.append(sock) + try: + sock.bind(("0.0.0.0", port)) + except OSError as exc: + print(f"{port}: could not bind ({exc.strerror}), skipped") + continue + seen = probe(sock, server) + if seen is None: + print(f"{port}: no answer") + continue + answered += 1 + kept = seen == port + rewritten += not kept + print(f"{port} -> {seen} {'kept' if kept else 'REWRITTEN'}") + finally: + for sock in socks: + sock.close() + if not answered: + print(f"No answer from {server[0]}:{server[1]}: outbound UDP may be blocked.") + return 2 + if rewritten: + print( + f"\n{rewritten} of {answered} ports left with a different number. The router rewrites " + "UDP source ports, and a Mysterium node behind it fails its sessions." + ) + return 1 + print(f"\nAll {answered} ports kept their number.") + return 0 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/services/_schema.yml b/services/_schema.yml index cec8eae8..0701e4c6 100644 --- a/services/_schema.yml +++ b/services/_schema.yml @@ -115,10 +115,25 @@ # instead of the log tail; checked every 30 minutes, # shown as "Needs fixing" on the dashboard. ${VAR} in # means is filled from that copy's env, ${HOST_ADDRESS} -# with the box's LAN address +# with the box's LAN address, ${WORKER_NAME} with +# the worker's name # Only add a pattern you have actually seen in that service's logs. A guessed regex # that never matches is dead weight; one that matches the wrong line tells the user # something false. +# health_probe: (optional) ask the running node how it is doing, from inside its +# container, for failures no log line shows (app/health_probe.py). The worker runs +# the command every 30 minutes and sends back only which checks hold; each one is +# shown as "Needs fixing" for that box, ${VAR} filled as in health_signals. +# command: ["sh", "-c", "..."] read-only, run inside the container +# checks: +# - pattern: '...' regex on the output, case-sensitive; holds when it +# matches at least min_matches times +# items: '...' (optional) regex for one item of a list: then the +# check holds when there are at least min_matches +# items and every one matches pattern +# min_matches: 1 (optional) positive integer +# means: "..." shown to the user +# Same rule as health_signals: only checks against answers you have seen. # advertised_address_env: ADDRESS (optional) the env var holding the address # the NETWORK dials this service back at ("host:port" or "host"). The # worker copies that ONE variable's value into heartbeat container entries diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index 5ffded44..97de72d6 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -160,6 +160,52 @@ docker: same range on both sides) to ${HOST_ADDRESS}. This clears by itself once a session connects directly. state: failing + # What the node itself says, read by the worker every 30 minutes + # (app/health_probe.py): Mysterium's monitoring status, then the last 5 + # completed sessions it provided in the past 14 days, newest first. Seen live + # (Nov 2026) on two nodes behind routers that rewrite the UDP source port of + # some connections: monitoring "failed", and every session ending after 55 + # to 62 s with 0 bytes, while the node logged "Method:manual Success:true" + # and "All ports reachable". A node on a working line reads "success" and + # its sessions carry data. /nat/type answers "prcone" on both, so it is not + # read. Only GETs on the node's loopback; nothing here changes the node. + health_probe: + command: + - sh + - -c + - >- + d=$(date -u -d @$(( $(date +%s) - 1209600 )) +%Y-%m-%d) + && wget -qO- -T 5 http://127.0.0.1:4050/node/monitoring-status + && echo + && wget -qO- -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=5&date_from=$d" + checks: + - pattern: '\{"status":"failed"\}' + means: >- + Mysterium's monitoring marks the node on ${WORKER_NAME} as failed, so + it is left out of the node list most buyers pick from, even when its + own check says every port is reachable. When nothing else is listed + for this node, a common cause is the router in front of + ${WORKER_NAME} rewriting the UDP source port of some of the node's + connections. Run the two-port test in the guide: + https://geiserx.github.io/CashPilot/guides/mysterium/#routers-that-rewrite-udp-source-ports + # Each item is one session object (they hold no nested objects); a bad + # one lasted 40 to 89 s and moved no byte either way. Five in a row: a + # working node also gets the odd empty session, but those end within a + # few seconds, and its next real one clears the check. + - items: '\{"id":[^{}]*"direction":"Provided"[^{}]*\}' + pattern: '"duration":[4-8][0-9],"bytes_received":0,"bytes_sent":0,' + min_matches: 5 + means: >- + The last five VPN sessions of the node on ${WORKER_NAME} each ended + after about a minute having moved no data, so it earns + nothing while it looks online. The likely cause is the router in + front of ${WORKER_NAME}: it rewrites the UDP source port of some of + the node's connections (some fibre boxes reserve ports in pairs, and + in a narrow forwarded range nearly every session hits one), so + buyers drop the node's answers. Run the two-port test and see the + fixes in the guide: + https://geiserx.github.io/CashPilot/guides/mysterium/#routers-that-rewrite-udp-source-ports + This clears once a session carries data. requirements: residential_ip: false diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py new file mode 100644 index 00000000..9f298d4a --- /dev/null +++ b/tests/test_mysterium_health_probe.py @@ -0,0 +1,254 @@ +"""A Mysterium node behind a router that rewrites UDP source ports is flagged, not shown healthy. + +Some routers change the source port of part of a node's outgoing UDP flows (a +fibre box that reserves ports in pairs, a SIP ALG). Inbound still works, so the +node's own port check passes and its log says "Method:manual Success:true", +but buyers drop its answers: every session ends after about a minute having +carried nothing. Two nodes sat like that for ten days with nothing on the +dashboard. The node's own API shows it: Mysterium's monitoring status reads +"failed" and its last sessions are all a minute long and empty. The worker +reads both inside the node (docker.health_probe) and the sweep lists the node +under Needs fixing. +""" + +from __future__ import annotations + +import asyncio +import json +import os +from unittest.mock import AsyncMock, MagicMock, patch + +os.environ.setdefault("CASHPILOT_API_KEY", "test-fleet-key") + +import pytest +from fastapi import HTTPException +from fastapi.testclient import TestClient + +from app import catalog, health_probe, main, worker_api + +GUIDE = "https://geiserx.github.io/CashPilot/guides/mysterium/#routers-that-rewrite-udp-source-ports" + + +def _session(n: int, duration: int, received: int, sent: int) -> dict: + """One item of TequilAPI's GET /sessions, with its real field order (myst 1.39.9).""" + return { + "id": f"00000000-0000-4000-8000-{n:012d}", + "direction": "Provided", + "consumer_id": "0x" + "1" * 40, + "hermes_id": "0x" + "2" * 40, + "provider_id": "0x" + "3" * 40, + "service_type": "wireguard", + "consumer_country": "DE", + "provider_country": "NL", + "created_at": f"2026-11-0{n % 9 + 1}T10:00:00Z", + "duration": duration, + "bytes_received": received, + "bytes_sent": sent, + "tokens": 6238559818402, + "status": "Completed", + "ip_type": "", + } + + +def _answer(status: str, sessions: list[dict]) -> str: + """What the catalog command prints: the monitoring status, then the sessions page.""" + page = {"items": sessions, "page": 1, "page_size": 5, "total_items": len(sessions), "total_pages": 1} + return json.dumps({"status": status}, separators=(",", ":")) + "\n" + json.dumps(page, separators=(",", ":")) + + +DEAD = [_session(i, 61, 0, 0) for i in range(5)] +# A working node: real traffic, plus the odd empty session that ends at once. +WORKING = [ + _session(0, 2, 6340, 3920), + _session(1, 1, 0, 0), + _session(2, 1270, 222980, 166168), + _session(3, 10, 401020, 83700), + _session(4, 1, 0, 0), +] +FAILING = _answer("failed", DEAD) +HEALTHY = _answer("success", WORKING) + + +def _spec(): + return catalog.get_service("mysterium")["docker"]["health_probe"] + + +def test_the_failing_node_trips_both_checks(): + assert health_probe.judge(FAILING, _spec()) == [0, 1] + assert health_probe.judge(FAILING.encode(), _spec()) == [0, 1] + + +def test_negative_control_a_healthy_node_raises_nothing(): + assert health_probe.judge(HEALTHY, _spec()) == [] + + +def test_monitoring_failed_alone_is_flagged_without_the_session_check(): + assert health_probe.judge(_answer("failed", WORKING), _spec()) == [0] + assert health_probe.judge(_answer("pending", DEAD[:4]), _spec()) == [] + + +def test_four_dead_sessions_are_not_yet_a_pattern(): + assert health_probe.judge(_answer("success", DEAD[:4]), _spec()) == [] + assert health_probe.judge(_answer("success", []), _spec()) == [] + + +def test_one_session_that_carried_data_clears_it(): + assert health_probe.judge(_answer("success", [_session(9, 3600, 10_000, 2_000), *DEAD[:4]]), _spec()) == [] + + +@pytest.mark.parametrize( + ("duration", "received", "sent", "dead"), + [ + (55, 0, 0, True), + (89, 0, 0, True), + (1, 0, 0, False), # gone at once: a buyer that changed its mind, seen on working nodes + (90, 0, 0, False), + (61, 124, 0, False), + (61, 0, 628, False), + ], +) +def test_a_dead_session_is_about_a_minute_long_and_empty(duration, received, sent, dead): + sessions = [*DEAD[:4], _session(7, duration, received, sent)] + assert (1 in health_probe.judge(_answer("success", sessions), _spec())) is dead + + +def test_the_probe_only_reads_the_node(): + """Nothing in it may change the node: plain GETs on the node's own loopback.""" + script = " ".join(_spec()["command"]) + assert "--post" not in script and "-X" not in script and "curl" not in script + urls = [w.strip('"') for w in script.split() if "http" in w] + assert urls and all(u.startswith("http://127.0.0.1:4050/") for u in urls) + assert {u.split("?")[0].split("4050")[1] for u in urls} == {"/node/monitoring-status", "/sessions"} + + +def test_the_finding_names_the_cause_and_the_guide_section(): + for check in _spec()["checks"]: + assert "${WORKER_NAME}" in check["means"] + assert "rewrit" in check["means"] and GUIDE in check["means"] + + +@pytest.mark.parametrize( + "spec", + [ + None, + {"command": "wget x", "checks": [{"pattern": "a", "means": "m"}]}, + {"command": ["sh"], "checks": []}, + {"command": ["sh"], "checks": [{"pattern": "(", "means": "m"}]}, + {"command": ["sh"], "checks": [{"pattern": "a", "items": "(", "means": "m"}]}, + {"command": ["sh"], "checks": [{"pattern": "a", "means": " "}]}, + {"command": ["sh"], "checks": [{"pattern": "a", "means": "m", "min_matches": 0}]}, + {"command": ["sh"], "checks": [{"pattern": "a", "means": "m", "min_matches": True}]}, + ], +) +def test_a_malformed_probe_is_rejected_and_never_read(spec): + assert health_probe.spec_errors(spec) + assert health_probe.probes([{"slug": "x", "docker": {"health_probe": spec}}]) == {} + + +def test_the_catalog_entry_is_well_formed(): + assert health_probe.spec_errors(_spec()) == [] + + +# --- The worker's read --------------------------------------------------------- + + +def test_the_worker_sends_back_only_which_checks_hold(): + good, bad, stopped = MagicMock(status="running"), MagicMock(status="running"), MagicMock(status="exited") + good.exec_run.return_value = (0, FAILING.encode()) + bad.exec_run.return_value = (1, b"wget: can't connect") + with ( + patch("app.orchestrator.service_instances", return_value=[good, bad, stopped]), + patch("app.orchestrator._instance_of", side_effect=[1, 2]), + ): + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert rows == [ + {"slug": "mysterium", "instance": 1, "hits": [0, 1]}, + {"slug": "mysterium", "instance": 2, "error": "the node did not answer"}, + ] + stopped.exec_run.assert_not_called() + assert "consumer_id" not in json.dumps(rows), "the node's answer never leaves the worker" + + +def test_the_worker_endpoint_serves_the_rows(): + client = TestClient(worker_api.app) + row = {"slug": "mysterium", "instance": 1, "hits": [1]} + with ( + patch("app.worker_api._verify_api_key"), + patch("app.worker_api.health_probe.read_all", return_value=[row]), + ): + resp = client.get("/api/health-probes") + assert resp.status_code == 200 and resp.json() == {"probes": [row]} + + +# --- The UI's sweep ------------------------------------------------------------ + +WORKER = {"id": 7, "name": "attic-nas", "status": "online", "url": "http://192.168.50.100:8081"} +RUNNING = {"slug": "mysterium", "status": "running", "instance": 1, "_worker_id": 7} + + +def _sweep(probes=None, *, probe_error=None, logs=""): + calls = [] + + async def _proxy(wid, method, path, params=None, **kw): + calls.append(path) + if path == "/api/health-probes": + if probe_error: + raise probe_error + return {"probes": probes or []} + return {"logs": logs, "filtered": True} + + with ( + patch("app.main._get_all_worker_containers", new_callable=AsyncMock, return_value=[RUNNING]), + patch("app.main.database.get_worker", new_callable=AsyncMock, return_value=WORKER), + patch( + "app.main.database.get_deployment_spec", + new_callable=AsyncMock, + return_value={"env": {"UDP_PORTS": "23000:23029"}}, + ), + patch("app.main._proxy_to_worker", side_effect=_proxy), + ): + asyncio.run(main._check_windowed_signals()) + return main._windowed_hints.get(("mysterium", 7, 1), []), calls + + +@pytest.fixture(autouse=True) +def _clean_hints(): + main._windowed_hints, main._probe_hints = {}, {} + yield + main._windowed_hints, main._probe_hints = {}, {} + + +def test_the_sweep_lists_a_failing_node_by_box_with_the_guide(): + hints, calls = _sweep([{"slug": "mysterium", "instance": 1, "hits": [0, 1]}]) + assert len(hints) == 2 + assert all("attic-nas" in h and GUIDE in h and "${" not in h for h in hints) + assert "about a minute having moved no data" in hints[1] + assert calls.count("/api/health-probes") == 1 + + +def test_negative_control_the_sweep_says_nothing_for_a_healthy_node(): + hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "hits": []}]) + assert hints == [] + + +def test_an_unread_probe_keeps_the_last_verdict_and_a_healthy_read_clears_it(): + _sweep([{"slug": "mysterium", "instance": 1, "hits": [1]}]) + hints, _ = _sweep(probe_error=HTTPException(status_code=504, detail="slow")) + assert len(hints) == 1, "a blip must not clear a real problem" + hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + assert len(hints) == 1 + hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "hits": []}]) + assert hints == [] + + +def test_an_old_worker_without_the_endpoint_gives_no_verdict_and_keeps_the_log_signals(): + hints, _ = _sweep(probe_error=HTTPException(status_code=404, detail="Not Found")) + assert hints == [] + failed = "DBG event={Identity:0xabc Method:manual Success:false}" + hints, _ = _sweep(probe_error=HTTPException(status_code=404, detail="Not Found"), logs="\n".join([failed] * 5)) + assert len(hints) == 1 and "forward the UDP port range 23000:23029" in hints[0] + + +def test_out_of_range_hits_are_ignored(): + hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "hits": [5, -1, True, "0"]}]) + assert hints == [] From 6f62998877a7fac4bdc4618d4a7380b89695a6be Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 16:01:22 +0100 Subject: [PATCH 2/9] fix(mysterium): keep the dead-session check on while the node is still broken - Read the five newest provided sessions of any age: a 14-day window empties out once discovery stops offering the node, and the check cleared itself. - Run the two reads independently, so a slow monitoring status (it asks the remote quality oracle) never costs the local sessions read. - Bound the probe with timeout 12 (required by the schema now), so a hung docker exec cannot hold a pool thread for good. - Drop a verdict after 24 h of unread probes; a node the worker keeps reporting as unreadable gets a hint saying so instead. - Monitoring-failed hint sends to the /dev/net/tun and SETUID check first. - STUN script tells a pairing router apart from a NAT that rewrites every port (symmetric NAT, CGNAT, VPN, Docker Desktop); the guide says to run it on Linux Docker Engine. - Guide and UDP_PORTS help: a narrow range fails on pairing routers; fix list ordered as we would try them with each cost; range capped at 1,000 ports below 32768; CashPilot always pins --udp.ports. --- app/health_probe.py | 15 +++++++- app/main.py | 53 +++++++++++++++++++-------- docs/guides/mysterium.md | 46 +++++++++++++++--------- scripts/stun_port_pair.py | 28 +++++++++++---- services/_schema.yml | 3 +- services/bandwidth/mysterium.yml | 28 ++++++++++----- tests/test_mysterium_health_probe.py | 54 +++++++++++++++++++++++----- 7 files changed, 170 insertions(+), 57 deletions(-) diff --git a/app/health_probe.py b/app/health_probe.py index 1d45f100..802f7b79 100644 --- a/app/health_probe.py +++ b/app/health_probe.py @@ -10,7 +10,7 @@ The catalog declares the read in ``docker.health_probe``: health_probe: - command: ["sh", "-c", "..."] # run inside the container, read-only + command: ["timeout", "12", "sh", "-c", "..."] # run inside the container, read-only checks: - pattern: '...' # regex on the command's output means: "..." # shown under Needs fixing @@ -25,6 +25,11 @@ good item clears it, and too few items say nothing. Patterns are case-sensitive, like ``collector.node_read``. +The command must start with ``timeout `` below READ_TIMEOUT. +``exec_run`` has no timeout of its own: a read that hung would keep its pool +thread after the worker stopped waiting, and four of them would leave every +later read queued behind them for the worker's lifetime. + Read-only by construction, like ``app/node_read.py``: the command comes from the catalog in this image, never from a request, and only the indexes of the checks that hold leave the worker, never the output. @@ -60,6 +65,14 @@ def spec_errors(spec: Any) -> list[str]: command = spec.get("command") if not (isinstance(command, list) and command and all(isinstance(p, str) for p in command)): errors.append("command must be a non-empty list of strings") + elif not ( + len(command) > 2 + and command[0] == "timeout" + and command[1].isascii() + and command[1].isdigit() + and 0 < int(command[1]) < READ_TIMEOUT + ): + errors.append(f"command must start with timeout , under {READ_TIMEOUT}") checks = spec.get("checks") if not (isinstance(checks, list) and checks): return [*errors, "checks must be a non-empty list"] diff --git a/app/main.py b/app/main.py index e22b2a13..694a3637 100644 --- a/app/main.py +++ b/app/main.py @@ -1936,6 +1936,12 @@ async def _check_stale_workers() -> None: #: (docker.health_probe), per copy, so a probe that could not be read this #: time keeps its last verdict without holding back the log signals. _probe_hints: dict[tuple[str, int, int], list[str]] = {} +#: Per copy, when its probe was last read (or, for a copy never read, when the +#: worker first reported it unreadable). A last verdict outlives an unread +#: probe by at most PROBE_STALE_SECONDS; after that it is dropped, and a copy +#: the worker keeps reporting as unreadable gets a hint saying so instead. +_probe_read_at: dict[tuple[str, int, int], float] = {} +PROBE_STALE_SECONDS = 24 * 3600 _DOCKER_POOLS = ipaddress.ip_network("172.16.0.0/12") @@ -2012,7 +2018,7 @@ async def _health_probe_rows(wid: int, cache: dict[int, list[dict[str, Any]] | N async def _sweep_windowed_signals() -> None: - global _windowed_hints, _probe_hints + global _windowed_hints, _probe_hints, _probe_read_at try: containers = await _get_all_worker_containers() except Exception as exc: @@ -2020,6 +2026,7 @@ async def _sweep_windowed_signals() -> None: return hints: dict[tuple[str, int, int], list[str]] = {} probe_hints: dict[tuple[str, int, int], list[str]] = {} + probe_read_at: dict[tuple[str, int, int], float] = {} probe_rows: dict[int, list[dict[str, Any]] | None] = {} workers: dict[int, dict[str, Any] | None] = {} for c in containers: @@ -2057,22 +2064,37 @@ async def _sweep_windowed_signals() -> None: found.append(await _render_signal_means(signal, slug, workers[wid])) if checks: rows = await _health_probe_rows(wid, probe_rows) - row = next( - ( - r - for r in rows or [] - if isinstance(r, dict) - and r.get("slug") == slug - and r.get("instance") == instance - and isinstance(r.get("hits"), list) - ), - None, - ) + mine = [ + r + for r in rows or [] + if isinstance(r, dict) and r.get("slug") == slug and r.get("instance") == instance + ] + row = next((r for r in mine if isinstance(r.get("hits"), list)), None) + now = time.time() if row is None: # Not read this time (worker busy, node slow to answer): the - # last verdict stands, as for the log signals. - probed = _probe_hints.get(key, []) + # last verdict stands, as for the log signals, but not for + # ever. A copy the worker reports as unreadable for longer + # than that says so, rather than keeping an old verdict or + # showing nothing. + unread = next((str(r.get("error")) for r in mine if r.get("error")), None) + since = _probe_read_at.get(key, now if unread else None) + if since is not None: + probe_read_at[key] = since + if since is None or now - since < PROBE_STALE_SECONDS: + probed = _probe_hints.get(key, []) + elif unread: + worker_name = str((workers[wid] or {}).get("name") or "this machine") + probed = [ + f"CashPilot has not been able to read this node's own API on {worker_name} " + f"for {int((now - since) // 3600)} hours ({unread}), so its monitoring " + "status and recent sessions are unchecked. Check that the node runs " + "normally and look at its logs." + ] + else: + probed = [] else: + probe_read_at[key] = now probed = [ await _render_signal_means(checks[i], slug, workers[wid]) for i in row["hits"] @@ -2087,11 +2109,14 @@ async def _sweep_windowed_signals() -> None: hints[key] = _windowed_hints[key] if key in _probe_hints: probe_hints[key] = _probe_hints[key] + if key in _probe_read_at: + probe_read_at[key] = _probe_read_at[key] continue if found: hints[key] = found _windowed_hints = hints _probe_hints = probe_hints + _probe_read_at = probe_read_at async def _raise_worker_offline_alert(w: dict[str, Any]) -> None: diff --git a/docs/guides/mysterium.md b/docs/guides/mysterium.md index fc869f95..68cf5d72 100644 --- a/docs/guides/mysterium.md +++ b/docs/guides/mysterium.md @@ -101,8 +101,11 @@ Keep the range below 32768. Ports 32768 to 60999 are Linux's ephemeral range: an Each session takes about two ports, so the default 30 ports carry about 15 sessions at once, more than a home node gets. Every published port costs about 2.5 MB of memory on the machine (Docker starts two small proxy processes per -port; 101 ports measured about 250 MB), so a wider range only costs more. A -range of 20 to 30 ports is enough. The default was `56000:56100` through +port; 101 ports measured about 250 MB). A range of 20 to 30 ports is enough on +most routers. On a router that reserves UDP ports in pairs, a narrow range +makes sessions fail; see +[Routers that rewrite UDP source ports](#routers-that-rewrite-udp-source-ports). +The default was `56000:56100` through 2.0.6 and `56000:56029` in 2.0.7 and 2.1.0, both inside the ephemeral range. A node keeps the range it has on record on a redeploy. To move it, set `UDP_PORTS` to a free range below 32768 other than the default, such as `23100:23129`, change @@ -231,8 +234,9 @@ you open it. On the same 30-minute round the worker also asks the node itself, read-only, for Mysterium's monitoring status and its last five sessions. It lists the node under **Needs fixing** when the monitoring status is `failed`, and when those -five sessions each ended after about a minute having carried no data. Both -point at the problem in the next section when nothing else is listed for the node. +five sessions each ended after about a minute having carried no data. Once a +missing `/dev/net/tun` or `SETUID`/`SETGID` is ruled out, both point at the +problem in the next section. ### Routers that rewrite UDP source ports @@ -273,14 +277,17 @@ few pairs, so a session's second port is almost always the partner of a port already mapped, and gets rewritten. With the node's wide default (10000 to 60000, no `--udp.ports`) collisions are rare enough that a pairing router goes unnoticed, which is why a node can work for months and fail the day its range -is narrowed. +is narrowed. CashPilot always passes `--udp.ports`, so that wide default is not +an option here; the range is `UDP_PORTS`. **Confirm it.** Ask a public STUN server which port it sees, from pairs of neighbouring ports, inside the node's network namespace. CashPilot ships a small script for this with no dependencies beyond Python 3, [`scripts/stun_port_pair.py`](https://github.com/GeiserX/CashPilot/blob/main/scripts/stun_port_pair.py). Run it in a throwaway container that shares the node's network, on the machine -running the node: +running the node. The test only means something on a Linux host with Docker +Engine: Docker Desktop (macOS, Windows) puts its own NAT in front of every +container, which rewrites every port whatever the router does. ```bash curl -fsSLo /tmp/stun_port_pair.py \ @@ -298,32 +305,37 @@ On a router that pairs ports, the even port of each pair comes back rewritten: 34102 -> 46950 REWRITTEN ``` -On a working line every port comes back with its own number. The script exits +On a working line every port comes back with its own number. When every port +comes back rewritten, the script says so separately: that is a NAT which +rewrites every port (a symmetric NAT, carrier-grade NAT, a VPN, or Docker +Desktop's own NAT), where port forwarding cannot work either. The script exits 0 when every port kept its number, 1 when one was rewritten and 2 when no STUN server answered. It only sends a few packets to a public STUN server; it does not touch the node. `--start` picks the first port to test (default 34100); keep it outside `UDP_PORTS`, whose ports the node holds. -**Fix.** In order, from least to most disruptive: +**Fix.** In the order we would try them: 1. **Turn off the router's SIP ALG and, if you do not use it, its own VoIP or phone service.** Both rewrite UDP flows. Look under NAT, ALG, VoIP or Telephony in the router's admin page. Some ISP boxes hide the setting; the - ISP's support can usually change it. + ISP's support can usually change it. Cost: one router setting. 2. **Look for a setting that keeps ports.** Some routers call it port preservation, endpoint-independent mapping, "full cone" NAT or NAT type 1. - Turn it on if it is there. + Turn it on if it is there. Cost: one router setting. 3. **Bridge mode with your own router.** Put the ISP box in bridge mode (some ISPs call it ONT mode or "router off") and do NAT on a router of your own that keeps source ports; most Linux-based routers and OpenWrt do. Then - forward `UDP_PORTS` on your router instead. This takes the whole house - offline for a few minutes and may need the ISP's help. + forward `UDP_PORTS` on your router instead. Cost: the whole house goes + offline for a few minutes, and it may need the ISP's help. 4. **A much wider `UDP_PORTS` range.** Fewer collisions, never none: the - sessions that land on a reserved partner still fail. Each published port - costs about 2.5 MB of memory in Docker's port proxy, the range must stay - free of other programs (see *Port forwarding*), and you forward the whole - range on the router. A range of 1,000 ports costs about 2.5 GB, which is - why this comes last. + sessions that land on a reserved partner still fail. CashPilot caps the + range at 1,000 ports and it must stay below 32768 (for example + `23000:23999`). Cost: one redeploy and a router forward edit, but each + published port takes about 2.5 MB of memory in Docker's port proxy, so + 1,000 ports take about 2.5 GB, and the range must stay free of other + programs (see *Port forwarding*). That memory, not the disruption, is why + this comes last. Run the script again after each change. Once every port keeps its number, Mysterium's monitoring re-scores the node within a few hours, the next sessions diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py index 885af579..08a0267b 100644 --- a/scripts/stun_port_pair.py +++ b/scripts/stun_port_pair.py @@ -11,15 +11,20 @@ This sends a STUN binding request from pairs of neighbouring source ports and prints the port the internet saw for each. Every port should come back with its own number. Run it in the node's network namespace (docs/guides/mysterium.md, -"Routers that rewrite UDP source ports"), with no other dependency than -Python 3: +"Routers that rewrite UDP source ports"), on a Linux host with Docker Engine +(Docker Desktop's own NAT rewrites every port), with no other dependency than +Python 3. From the root of a CashPilot checkout: docker run --rm --network container:cashpilot-mysterium \\ - -v "$PWD/scripts/stun_port_pair.py:/t.py:ro" python:3.13-alpine python /t.py + -v "$PWD/scripts/stun_port_pair.py:/t.py:ro" python:3.15.2-alpine python /t.py + +or fetch the script to /tmp first, as the guide shows. Exit status: 0 when every port kept its number, 1 when one was rewritten, -2 when no STUN server answered. Read-only: it sends a few UDP packets to a -public STUN server and changes nothing. +2 when no STUN server answered. A rewritten port is reported as a pairing +router when some ports kept their number, and as a NAT that rewrites every +port when none did. Read-only: it sends a few UDP packets to a public STUN +server and changes nothing. """ from __future__ import annotations @@ -119,10 +124,19 @@ def main() -> int: if not answered: print(f"No answer from {server[0]}:{server[1]}: outbound UDP may be blocked.") return 2 + if rewritten == answered: + print( + f"\nAll {answered} ports left with a different number. Something in the path rewrites " + "every UDP source port: a symmetric NAT, carrier-grade NAT, a VPN, or Docker Desktop's " + "own NAT (run this on a Linux host with Docker Engine, not Docker Desktop). Port " + "forwarding cannot work through it either." + ) + return 1 if rewritten: print( - f"\n{rewritten} of {answered} ports left with a different number. The router rewrites " - "UDP source ports, and a Mysterium node behind it fails its sessions." + f"\n{rewritten} of {answered} ports left with a different number while others kept " + "theirs. The router rewrites some UDP source ports (some fibre boxes reserve ports in " + "pairs), and a Mysterium node behind it fails its sessions." ) return 1 print(f"\nAll {answered} ports kept their number.") diff --git a/services/_schema.yml b/services/_schema.yml index 0701e4c6..55b47042 100644 --- a/services/_schema.yml +++ b/services/_schema.yml @@ -124,7 +124,8 @@ # container, for failures no log line shows (app/health_probe.py). The worker runs # the command every 30 minutes and sends back only which checks hold; each one is # shown as "Needs fixing" for that box, ${VAR} filled as in health_signals. -# command: ["sh", "-c", "..."] read-only, run inside the container +# command: ["timeout", "12", "sh", "-c", "..."] read-only, run inside the +# container; must start with timeout , s < 15 # checks: # - pattern: '...' regex on the output, case-sensitive; holds when it # matches at least min_matches times diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index 97de72d6..1c439545 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -53,7 +53,9 @@ docker: same range on your router. Each session takes about two ports, so the default 30 carry about 15 sessions at once, more than a home node gets. Every published port costs about 2.5 MB of memory in Docker's port - proxy, so a wider range only costs more. Keep it below 32768: ports + proxy. On a router that reserves UDP ports in pairs, a narrow range + makes sessions fail: see "Routers that rewrite UDP source ports" in + the Mysterium guide. Keep it below 32768: ports 32768-60999 are Linux's ephemeral range, where any program on the host can hold one for a moment, and one taken port fails the node's start. A node that already has a range keeps it. @@ -162,7 +164,14 @@ docker: state: failing # What the node itself says, read by the worker every 30 minutes # (app/health_probe.py): Mysterium's monitoring status, then the last 5 - # completed sessions it provided in the past 14 days, newest first. Seen live + # completed sessions it provided, of any age (the node returns them newest + # first). No date window: a broken node stops being offered, new sessions + # stop arriving, and a window would empty out and clear the check while the + # node is still broken. The two reads are independent, so a slow or failing + # monitoring status (the node asks Mysterium's quality oracle for it) never + # costs the sessions read, which needs only the node's own database; the run + # fails only when the sessions read does. timeout 12 bounds the whole run + # inside the 15 s the worker waits. Seen live # (Nov 2026) on two nodes behind routers that rewrite the UDP source port of # some connections: monitoring "failed", and every session ending after 55 # to 62 s with 0 bytes, while the node logged "Method:manual Success:true" @@ -171,20 +180,23 @@ docker: # read. Only GETs on the node's loopback; nothing here changes the node. health_probe: command: + - timeout + - "12" - sh - -c - >- - d=$(date -u -d @$(( $(date +%s) - 1209600 )) +%Y-%m-%d) - && wget -qO- -T 5 http://127.0.0.1:4050/node/monitoring-status - && echo - && wget -qO- -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=5&date_from=$d" + wget -qO- -T 5 http://127.0.0.1:4050/node/monitoring-status; + echo; + wget -qO- -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=5" checks: - pattern: '\{"status":"failed"\}' means: >- Mysterium's monitoring marks the node on ${WORKER_NAME} as failed, so it is left out of the node list most buyers pick from, even when its - own check says every port is reachable. When nothing else is listed - for this node, a common cause is the router in front of + own check says every port is reachable. First make sure the node has + /dev/net/tun and SETUID/SETGID, which fail it the same way: + https://geiserx.github.io/CashPilot/guides/mysterium/#running-but-not-earning-monitoring-failed-quality-0 + With those in place, a common cause is the router in front of ${WORKER_NAME} rewriting the UDP source port of some of the node's connections. Run the two-port test in the guide: https://geiserx.github.io/CashPilot/guides/mysterium/#routers-that-rewrite-udp-source-ports diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index 9f298d4a..aca753ce 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -116,7 +116,7 @@ def test_the_probe_only_reads_the_node(): """Nothing in it may change the node: plain GETs on the node's own loopback.""" script = " ".join(_spec()["command"]) assert "--post" not in script and "-X" not in script and "curl" not in script - urls = [w.strip('"') for w in script.split() if "http" in w] + urls = [w.strip('";') for w in script.split() if "http" in w] assert urls and all(u.startswith("http://127.0.0.1:4050/") for u in urls) assert {u.split("?")[0].split("4050")[1] for u in urls} == {"/node/monitoring-status", "/sessions"} @@ -132,12 +132,15 @@ def test_the_finding_names_the_cause_and_the_guide_section(): [ None, {"command": "wget x", "checks": [{"pattern": "a", "means": "m"}]}, - {"command": ["sh"], "checks": []}, - {"command": ["sh"], "checks": [{"pattern": "(", "means": "m"}]}, - {"command": ["sh"], "checks": [{"pattern": "a", "items": "(", "means": "m"}]}, - {"command": ["sh"], "checks": [{"pattern": "a", "means": " "}]}, - {"command": ["sh"], "checks": [{"pattern": "a", "means": "m", "min_matches": 0}]}, - {"command": ["sh"], "checks": [{"pattern": "a", "means": "m", "min_matches": True}]}, + # exec_run has no timeout: an unbounded command could hold a pool thread for ever. + {"command": ["sh", "-c", "x"], "checks": [{"pattern": "a", "means": "m"}]}, + {"command": ["timeout", "15", "sh"], "checks": [{"pattern": "a", "means": "m"}]}, + {"command": ["timeout", "12", "sh"], "checks": []}, + {"command": ["timeout", "12", "sh"], "checks": [{"pattern": "(", "means": "m"}]}, + {"command": ["timeout", "12", "sh"], "checks": [{"pattern": "a", "items": "(", "means": "m"}]}, + {"command": ["timeout", "12", "sh"], "checks": [{"pattern": "a", "means": " "}]}, + {"command": ["timeout", "12", "sh"], "checks": [{"pattern": "a", "means": "m", "min_matches": 0}]}, + {"command": ["timeout", "12", "sh"], "checks": [{"pattern": "a", "means": "m", "min_matches": True}]}, ], ) def test_a_malformed_probe_is_rejected_and_never_read(spec): @@ -149,6 +152,21 @@ def test_the_catalog_entry_is_well_formed(): assert health_probe.spec_errors(_spec()) == [] +def test_the_session_read_has_no_date_window_and_does_not_hang_on_the_status_read(): + """A date window empties out on a broken node no one is offered any more, and the + check would clear itself; the status read (which asks a remote oracle) must not + cost the local sessions read.""" + script = _spec()["command"][-1] + assert "date_from" not in script and "date " not in script + status, sessions = script.split("monitoring-status", 1) + assert "&&" not in script and sessions.lstrip().startswith(";") + + +def test_the_monitoring_finding_sends_to_the_tun_check_first(): + means = _spec()["checks"][0]["means"] + assert "/dev/net/tun" in means and "#running-but-not-earning-monitoring-failed-quality-0" in means + + # --- The worker's read --------------------------------------------------------- @@ -213,9 +231,9 @@ async def _proxy(wid, method, path, params=None, **kw): @pytest.fixture(autouse=True) def _clean_hints(): - main._windowed_hints, main._probe_hints = {}, {} + main._windowed_hints, main._probe_hints, main._probe_read_at = {}, {}, {} yield - main._windowed_hints, main._probe_hints = {}, {} + main._windowed_hints, main._probe_hints, main._probe_read_at = {}, {}, {} def test_the_sweep_lists_a_failing_node_by_box_with_the_guide(): @@ -241,6 +259,24 @@ def test_an_unread_probe_keeps_the_last_verdict_and_a_healthy_read_clears_it(): assert hints == [] +def test_a_verdict_does_not_outlive_a_day_of_unread_probes(): + _sweep([{"slug": "mysterium", "instance": 1, "hits": [1]}]) + later = main.time.time() + main.PROBE_STALE_SECONDS + 3600 + with patch("app.main.time.time", return_value=later): + hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + assert len(hints) == 1 and "has not been able to read" in hints[0] and "attic-nas" in hints[0] + assert "about a minute" not in hints[0], "the stale verdict is gone" + with patch("app.main.time.time", return_value=later): + hints, _ = _sweep(probe_error=HTTPException(status_code=504, detail="slow")) + assert hints == [], "a worker that does not answer at all drops the stale verdict without a claim" + + +def test_a_short_unread_spell_names_nothing_new(): + _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + assert hints == [] + + def test_an_old_worker_without_the_endpoint_gives_no_verdict_and_keeps_the_log_signals(): hints, _ = _sweep(probe_error=HTTPException(status_code=404, detail="Not Found")) assert hints == [] From bab606721c7a9d73e01dea368636cac6ac5b2358 Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 16:25:08 +0100 Subject: [PATCH 3/9] fix(mysterium): keep each health check's verdict when only part of the node can be read A stalled Docker exec stream no longer holds a probe pool thread: the probe runs on its own client with a socket timeout, and timed-out queued work is cancelled. The worker answers within a batch budget and returns the copies it read in time. The UI handles a failed log read and the probe separately, ignores hits from another catalog version (a definition fingerprint), and keeps the last verdict per check, so a failed sessions read no longer drops a monitoring status of "failed". The node now judges the five sessions that completed last, not the five that started last, and its loopback reads skip any inherited proxy. The two-port STUN test reports a network error as no answer, falls back to the next STUN server, and exits 3 when a pair could not be tested in full. The guide shows how to tell the host's own NAT from the router. --- app/health_probe.py | 111 +++++++-- app/main.py | 177 +++++++++----- docs/guides/mysterium.md | 31 ++- scripts/stun_port_pair.py | 82 +++++-- services/_schema.yml | 4 + services/bandwidth/mysterium.yml | 42 +++- tests/test_mysterium_health_probe.py | 343 ++++++++++++++++++++++++--- 7 files changed, 640 insertions(+), 150 deletions(-) diff --git a/app/health_probe.py b/app/health_probe.py index 802f7b79..897494ec 100644 --- a/app/health_probe.py +++ b/app/health_probe.py @@ -17,6 +17,9 @@ - items: '...' # regex for one item of a list pattern: '...' # what makes an item bad min_matches: 3 # items needed before judging + answered: '...' # (optional) regex the output holds when this + # check's read worked; without it the check + # is unread, not clear means: "..." A check without ``items`` holds when ``pattern`` matches the output at least @@ -25,10 +28,15 @@ good item clears it, and too few items say nothing. Patterns are case-sensitive, like ``collector.node_read``. -The command must start with ``timeout `` below READ_TIMEOUT. -``exec_run`` has no timeout of its own: a read that hung would keep its pool -thread after the worker stopped waiting, and four of them would leave every -later read queued behind them for the worker's lifetime. +A check with ``answered`` is judged only when its marker is in the output, +so a command that reads two things can lose one without losing the other's +verdict. A check whose marker is missing is reported in ``unread``. + +The command must start with ``timeout `` below READ_TIMEOUT, which +ends the command in the container. The exec itself runs on a Docker client of +this module's own with a READ_TIMEOUT socket timeout: a stream that stalls +(the daemon or the socket proxy stops sending) raises instead of holding its +pool thread, so stalled reads cannot fill the pool for the worker's lifetime. Read-only by construction, like ``app/node_read.py``: the command comes from the catalog in this image, never from a request, and only the indexes of the @@ -38,19 +46,26 @@ from __future__ import annotations import concurrent.futures +import hashlib +import json import logging import re +import time from typing import Any logger = logging.getLogger(__name__) #: Seconds one container's read may take before it is reported as unread. READ_TIMEOUT = 15 +#: Seconds one /api/health-probes answer may take in all. The UI waits 60 s for +#: it; copies not read by then are reported unread, and the rest still go back. +BATCH_BUDGET = 40 _pool = concurrent.futures.ThreadPoolExecutor(max_workers=4, thread_name_prefix="health-probe") def _min_matches(check: dict[str, Any]) -> int | None: + """A check's min_matches, or None when it is not a positive integer.""" value = check.get("min_matches", 1) if isinstance(value, bool) or not isinstance(value, int) or value < 1: return None @@ -80,9 +95,9 @@ def spec_errors(spec: Any) -> list[str]: if not isinstance(check, dict): errors.append(f"checks[{i}] must be a mapping") continue - for field in ("pattern", "items"): + for field in ("pattern", "items", "answered"): value = check.get(field) - if value is None and field == "items": + if value is None and field != "pattern": continue try: if not isinstance(value, str) or not value: @@ -122,30 +137,69 @@ def holds(output: bytes | str | None, check: dict[str, Any]) -> bool: return len(items) >= needed and all(pattern.search(item) for item in items) +def _text(output: bytes | str | None) -> str: + """The command's output as text.""" + return output.decode(errors="replace") if isinstance(output, bytes) else (output or "") + + +def unanswered(output: bytes | str | None, spec: dict[str, Any]) -> list[int]: + """The indexes of the checks whose ``answered`` marker is missing from the output.""" + text = _text(output) + return [i for i, c in enumerate(spec["checks"]) if c.get("answered") and not re.search(c["answered"], text)] + + def judge(output: bytes | str | None, spec: dict[str, Any]) -> list[int]: - """The indexes of the checks that hold on the command's output.""" - return [i for i, check in enumerate(spec["checks"]) if holds(output, check)] + """The indexes of the checks that hold on the command's output (unread ones never do).""" + unread = set(unanswered(output, spec)) + return [i for i, check in enumerate(spec["checks"]) if i not in unread and holds(output, check)] + + +def fingerprint(spec: dict[str, Any]) -> str: + """A short hash of a probe declaration. + + The worker sends it with its hits, and the UI uses the hits only when it + loads the same declaration: during an upgrade the two often run different + catalogs, and an index into another version's checks names the wrong cause. + """ + return hashlib.sha256(json.dumps(spec, sort_keys=True, separators=(",", ":")).encode()).hexdigest()[:16] + + +def _client() -> Any: + """A Docker client whose socket reads give up after READ_TIMEOUT seconds.""" + import docker + + return docker.from_env(timeout=READ_TIMEOUT) -def _read_one(container: Any, spec: dict[str, Any]) -> list[int] | None: - code, output = container.exec_run(spec["command"]) - if code != 0: +def _read_one(client: Any, container_id: str, spec: dict[str, Any]) -> dict[str, list[int]] | None: + """Run the probe in one container: hits and unread checks, or None when nothing was read.""" + api = client.api + exec_id = api.exec_create(container_id, spec["command"])["Id"] + output = api.exec_start(exec_id) + if api.exec_inspect(exec_id).get("ExitCode") != 0: return None - return judge(output, spec) + unread = unanswered(output, spec) + if len(unread) == len(spec["checks"]): + return None + return {"hits": judge(output, spec), "unread": unread} def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: """One row per running managed copy of a service that declares a probe. - A row carries ``hits``, the indexes of the checks that hold, when the read - worked, and ``error`` when it did not: an unread node is no verdict, never - a healthy one. + A row carries ``definition`` (see fingerprint) and, when the read worked, + ``hits``, the indexes of the checks that hold, and ``unread``, those it + could not judge; ``error`` when it did not work at all: an unread node is + no verdict, never a healthy one. Copies not reached within BATCH_BUDGET + are reported unread, so the ones read in time still count. """ # Imported here: the UI imports this module for nothing but the catalog # check, and has no Docker. from app import orchestrator rows: list[dict[str, Any]] = [] + deadline = time.monotonic() + BATCH_BUDGET + client = None for slug, spec in sorted(probes(services).items()): try: copies = orchestrator.service_instances(slug) @@ -155,18 +209,35 @@ def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: for container in copies: if getattr(container, "status", "") != "running": continue - row: dict[str, Any] = {"slug": slug, "instance": orchestrator._instance_of(container)} + row: dict[str, Any] = { + "slug": slug, + "instance": orchestrator._instance_of(container), + "definition": fingerprint(spec), + } + rows.append(row) + left = min(READ_TIMEOUT, deadline - time.monotonic()) + if left <= 0: + row["error"] = "not reached in time" + continue + future = None try: - hits = _pool.submit(_read_one, container, spec).result(timeout=READ_TIMEOUT) + if client is None: + client = _client() + future = _pool.submit(_read_one, client, container.id, spec) + read = future.result(timeout=left) except concurrent.futures.TimeoutError: + # Still queued: never run it. Running: the client's socket + # timeout ends it. + future.cancel() row["error"] = "timed out" except Exception as exc: # noqa: BLE001 logger.warning("Health probe failed for %s: %s", slug, exc) row["error"] = "read failed" else: - if hits is None: + if read is None: row["error"] = "the node did not answer" else: - row["hits"] = hits - rows.append(row) + row.update(read) + # A read that timed out may still be using the client; it is dropped, not + # closed, so that read ends on its own socket timeout. return rows diff --git a/app/main.py b/app/main.py index 694a3637..fabb6519 100644 --- a/app/main.py +++ b/app/main.py @@ -51,6 +51,7 @@ egress, exchange_rates, fleet_key, + health_probe, ipgeo, lan_isolation, login_rate_limit, @@ -1932,15 +1933,18 @@ async def _check_stale_workers() -> None: # The startup sweep and the scheduled one must not overlap: the older would # finish last and put back stale hints. _windowed_lock = asyncio.Lock() -#: The part of _windowed_hints that came from a node's health probe -#: (docker.health_probe), per copy, so a probe that could not be read this -#: time keeps its last verdict without holding back the log signals. +#: The part of _windowed_hints that came from the log signals, per copy, so a +#: log read that fails keeps its last verdict without holding back the probe. +_signal_hints: dict[tuple[str, int, int], list[str]] = {} +#: The part that came from a node's health probe (docker.health_probe), per +#: copy, kept when the sweep could not get to the probe at all. _probe_hints: dict[tuple[str, int, int], list[str]] = {} -#: Per copy, when its probe was last read (or, for a copy never read, when the -#: worker first reported it unreadable). A last verdict outlives an unread -#: probe by at most PROBE_STALE_SECONDS; after that it is dropped, and a copy -#: the worker keeps reporting as unreadable gets a hint saying so instead. -_probe_read_at: dict[tuple[str, int, int], float] = {} +#: Per copy, per probe check: (whether it held, when it was last read). A check +#: never read gets (False, when the worker first reported it unreadable). A +#: last verdict outlives an unread check by at most PROBE_STALE_SECONDS; after +#: that it is dropped, and a copy the worker keeps reporting as unreadable gets +#: a hint saying so instead. +_probe_state: dict[tuple[str, int, int], dict[int, tuple[bool, float]]] = {} PROBE_STALE_SECONDS = 24 * 3600 @@ -2017,16 +2021,69 @@ async def _health_probe_rows(wid: int, cache: dict[int, list[dict[str, Any]] | N return cache[wid] +def _probe_step( + spec: dict[str, Any], mine: list[dict[str, Any]], last: dict[int, tuple[bool, float]], now: float +) -> tuple[dict[int, tuple[bool, float]], list[int], str | None]: + """Fold one sweep's worker rows for a copy into its per-check probe state. + + ``mine`` holds the worker's rows for this copy (empty when the worker did + not answer). Returns the new state, the indexes of the checks to show, and, + when a check has gone unread for PROBE_STALE_SECONDS while the worker kept + reporting it unreadable, why it could not be read. + """ + checks = spec["checks"] + row = next((r for r in mine if isinstance(r.get("hits"), list)), None) + reason = None + if row is not None and row.get("definition") != health_probe.fingerprint(spec): + # Another catalog version on the worker: its indexes may point at + # other checks here, so it is no verdict, empty hits included. + reason = "the worker runs another version of CashPilot" + row = None + + def _indexes(values: Any) -> set[int]: + """The valid check indexes in a worker list; anything else is ignored.""" + return {i for i in values or [] if isinstance(i, int) and not isinstance(i, bool) and 0 <= i < len(checks)} + + read: dict[int, bool] = {} + if row is not None: + unread = _indexes(row.get("unread")) + hits = _indexes(row["hits"]) + read = {i: i in hits for i in range(len(checks)) if i not in unread} + if unread: + reason = "the node did not answer every read" + elif reason is None: + reason = next((str(r.get("error")) for r in mine if r.get("error")), None) + state: dict[int, tuple[bool, float]] = {} + for i in range(len(checks)): + if i in read: + state[i] = (read[i], now) + elif i in last: + state[i] = last[i] + elif reason is not None: + state[i] = (False, now) + held = [i for i, (hit, since) in sorted(state.items()) if hit and now - since < PROBE_STALE_SECONDS] + stale = [since for i, (_, since) in state.items() if i not in read and now - since >= PROBE_STALE_SECONDS] + if reason is None or not stale: + return state, held, None + return state, held, f"{reason}, for {int((now - min(stale)) // 3600)} hours" + + async def _sweep_windowed_signals() -> None: - global _windowed_hints, _probe_hints, _probe_read_at + """Re-read every running copy's windowed log signals and health probe. + + Each part fails on its own: a log read that fails keeps the last log + verdicts and still lets the probe update, and the other way round. + """ + global _windowed_hints, _signal_hints, _probe_hints, _probe_state try: containers = await _get_all_worker_containers() except Exception as exc: logger.warning("Windowed signal check skipped: %s", exc) return hints: dict[tuple[str, int, int], list[str]] = {} + signal_hints: dict[tuple[str, int, int], list[str]] = {} probe_hints: dict[tuple[str, int, int], list[str]] = {} - probe_read_at: dict[tuple[str, int, int], float] = {} + probe_state: dict[tuple[str, int, int], dict[int, tuple[bool, float]]] = {} probe_rows: dict[int, list[dict[str, Any]] | None] = {} workers: dict[int, dict[str, Any] | None] = {} for c in containers: @@ -2037,15 +2094,30 @@ async def _sweep_windowed_signals() -> None: service = catalog.get_service(slug) signals = [s for s in producer_state.signals_for(service) if producer_state.is_windowed(s)] probe = ((service or {}).get("docker") or {}).get("health_probe") - checks = probe.get("checks") if isinstance(probe, dict) and isinstance(probe.get("checks"), list) else [] - if not signals and not checks: + spec = probe if isinstance(probe, dict) and not health_probe.spec_errors(probe) else None + if not signals and spec is None: continue instance = int(c.get("instance") or 1) key = (slug, wid, instance) - found: list[str] = [] + + def _keep(k: tuple[str, int, int] = key) -> None: + """Carry this copy's last verdicts over unchanged.""" + for new, old in ((signal_hints, _signal_hints), (probe_hints, _probe_hints), (probe_state, _probe_state)): + if k in old: + new[k] = old[k] + try: if wid not in workers: workers[wid] = await database.get_worker(wid) + except Exception as exc: + logger.warning("Windowed signal check failed for %s on worker %s: %s", slug, wid, exc) + _keep() + kept = [*signal_hints.get(key, []), *probe_hints.get(key, [])] + if kept: + hints[key] = kept + continue + logged: list[str] = [] + try: for signal in signals: params: dict[str, Any] = { "lines": 1000, @@ -2061,62 +2133,45 @@ async def _sweep_windowed_signals() -> None: if not resp.get("filtered"): continue if producer_state.windowed_hit(resp.get("logs", ""), signal): - found.append(await _render_signal_means(signal, slug, workers[wid])) - if checks: + logged.append(await _render_signal_means(signal, slug, workers[wid])) + except Exception as exc: + logger.warning("Windowed log check failed for %s on worker %s: %s", slug, wid, exc) + logged = _signal_hints.get(key, []) + if logged: + signal_hints[key] = logged + probed: list[str] = [] + if spec is not None: + try: rows = await _health_probe_rows(wid, probe_rows) mine = [ r for r in rows or [] if isinstance(r, dict) and r.get("slug") == slug and r.get("instance") == instance ] - row = next((r for r in mine if isinstance(r.get("hits"), list)), None) - now = time.time() - if row is None: - # Not read this time (worker busy, node slow to answer): the - # last verdict stands, as for the log signals, but not for - # ever. A copy the worker reports as unreadable for longer - # than that says so, rather than keeping an old verdict or - # showing nothing. - unread = next((str(r.get("error")) for r in mine if r.get("error")), None) - since = _probe_read_at.get(key, now if unread else None) - if since is not None: - probe_read_at[key] = since - if since is None or now - since < PROBE_STALE_SECONDS: - probed = _probe_hints.get(key, []) - elif unread: - worker_name = str((workers[wid] or {}).get("name") or "this machine") - probed = [ - f"CashPilot has not been able to read this node's own API on {worker_name} " - f"for {int((now - since) // 3600)} hours ({unread}), so its monitoring " - "status and recent sessions are unchecked. Check that the node runs " - "normally and look at its logs." - ] - else: - probed = [] - else: - probe_read_at[key] = now - probed = [ - await _render_signal_means(checks[i], slug, workers[wid]) - for i in row["hits"] - if isinstance(i, int) and not isinstance(i, bool) and 0 <= i < len(checks) - ] - if probed: - probe_hints[key] = probed - found += probed - except Exception as exc: - logger.warning("Windowed signal check failed for %s on worker %s: %s", slug, wid, exc) - if key in _windowed_hints: - hints[key] = _windowed_hints[key] - if key in _probe_hints: - probe_hints[key] = _probe_hints[key] - if key in _probe_read_at: - probe_read_at[key] = _probe_read_at[key] - continue - if found: - hints[key] = found + state, held, unreadable = _probe_step(spec, mine, _probe_state.get(key, {}), time.time()) + probed = [await _render_signal_means(spec["checks"][i], slug, workers[wid]) for i in held] + if unreadable: + worker_name = str((workers[wid] or {}).get("name") or "this machine") + probed.append( + f"CashPilot has not been able to read this node's own API on {worker_name} " + f"({unreadable}), so part of what it checks on the node is unchecked. " + "Check that the node runs normally and look at its logs." + ) + if state: + probe_state[key] = state + except Exception as exc: + logger.warning("Health probe check failed for %s on worker %s: %s", slug, wid, exc) + probed = _probe_hints.get(key, []) + if key in _probe_state: + probe_state[key] = _probe_state[key] + if probed: + probe_hints[key] = probed + if logged or probed: + hints[key] = [*logged, *probed] _windowed_hints = hints + _signal_hints = signal_hints _probe_hints = probe_hints - _probe_read_at = probe_read_at + _probe_state = probe_state async def _raise_worker_offline_alert(w: dict[str, Any]) -> None: diff --git a/docs/guides/mysterium.md b/docs/guides/mysterium.md index 68cf5d72..8af252aa 100644 --- a/docs/guides/mysterium.md +++ b/docs/guides/mysterium.md @@ -232,9 +232,9 @@ sessions yet is not flagged. The dashboard reloads its list every hour, or when you open it. On the same 30-minute round the worker also asks the node itself, read-only, -for Mysterium's monitoring status and its last five sessions. It lists the node -under **Needs fixing** when the monitoring status is `failed`, and when those -five sessions each ended after about a minute having carried no data. Once a +for Mysterium's monitoring status and the five sessions that completed last. It +lists the node under **Needs fixing** when the monitoring status is `failed`, +and when those five sessions each ended after about a minute having carried no data. Once a missing `/dev/net/tun` or `SETUID`/`SETGID` is ruled out, both point at the problem in the next section. @@ -309,11 +309,32 @@ On a working line every port comes back with its own number. When every port comes back rewritten, the script says so separately: that is a NAT which rewrites every port (a symmetric NAT, carrier-grade NAT, a VPN, or Docker Desktop's own NAT), where port forwarding cannot work either. The script exits -0 when every port kept its number, 1 when one was rewritten and 2 when no STUN -server answered. It only sends a few packets to a public STUN server; it does +0 when every pair was tested and every port kept its number, 1 when one was +rewritten, 2 when no STUN server answered, and 3 when nothing was rewritten +but some pair could not be tested in full (a port that would not bind or got +no answer), so the result says nothing about pairing; run it again with +another `--start`. It tries Google's STUN server first and Cloudflare's when +Google does not answer. It only sends a few packets to a public STUN server; it does not touch the node. `--start` picks the first port to test (default 34100); keep it outside `UDP_PORTS`, whose ports the node holds. +**Rule out the host's own NAT.** The container's packets also pass Docker's +NAT on the host before they reach the router. That NAT keeps the source port +unless two flows clash on it, which is rare, but then it picks another one and +the script reports `REWRITTEN` with a router that is fine. A pairing router +rewrites some port every run, a clash does not repeat, so run the script twice. +To see it directly, look at the host's connection table within a minute of a +run (as root on the host, with the `conntrack` tool installed): + +```bash +conntrack -L -p udp --orig-port-src 34100 +``` + +The second half of the line is the answer as the host expects it. When its +`dport=` is still `34100`, the host sent the packet out on its own port and +the rewrite happened past it, at the router. When it differs, the host's NAT +changed it, and the test says nothing about the router. + **Fix.** In the order we would try them: 1. **Turn off the router's SIP ALG and, if you do not use it, its own VoIP or diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py index 08a0267b..4ae1db18 100644 --- a/scripts/stun_port_pair.py +++ b/scripts/stun_port_pair.py @@ -20,8 +20,11 @@ or fetch the script to /tmp first, as the guide shows. -Exit status: 0 when every port kept its number, 1 when one was rewritten, -2 when no STUN server answered. A rewritten port is reported as a pairing +Exit status: 0 when every pair was tested and every port kept its number, +1 when one was rewritten, 2 when no STUN server answered, 3 when no port was +rewritten but some pair could not be tested in full (a port that did not bind +or got no answer), so the pairing was not checked: run it again with another +--start. A rewritten port is reported as a pairing router when some ports kept their number, and as a NAT that rewrites every port when none did. Read-only: it sends a few UDP packets to a public STUN server and changes nothing. @@ -60,11 +63,15 @@ def _mapped_port(data: bytes, txid: bytes) -> int | None: def probe(sock: socket.socket, server: tuple[str, int], tries: int = 3) -> int | None: - """The source port the STUN server saw for packets from ``sock``.""" + """The source port the STUN server saw for packets from ``sock``; None for no answer. + + A network error (no route, the packet refused) is no answer too, never a + traceback, which would exit 1 and read as a rewritten port. + """ for _ in range(tries): txid = os.urandom(12) - sock.sendto(struct.pack("!HHI", 0x0001, 0, MAGIC) + txid, server) try: + sock.sendto(struct.pack("!HHI", 0x0001, 0, MAGIC) + txid, server) while True: data, _ = sock.recvfrom(2048) port = _mapped_port(data, txid) @@ -72,33 +79,34 @@ def probe(sock: socket.socket, server: tuple[str, int], tries: int = 3) -> int | return port except TimeoutError: continue + except OSError: + return None return None -def _server() -> tuple[str, int] | None: +def _servers() -> list[tuple[str, int]]: + """Every STUN server in SERVERS that resolves, in order.""" + found = [] for host, port in SERVERS: try: - return (socket.gethostbyname(host), port) + found.append((socket.gethostbyname(host), port)) except OSError: continue - return None + return found -def main() -> int: - parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) - parser.add_argument("--start", type=int, default=34100, help="first port to test (default 34100)") - parser.add_argument("--pairs", type=int, default=4, help="neighbouring pairs to test (default 4)") - args = parser.parse_args() - server = _server() - if server is None: - print("No STUN server could be resolved: check this namespace's DNS.") - return 2 - first = args.start & ~1 - rewritten = answered = 0 +def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int]: + """Test ``pairs`` neighbouring pairs from ``start`` against one server. + + Returns (ports answered, ports rewritten, pairs with both ports answered). + """ + first = start & ~1 + rewritten = answered = complete = 0 socks = [] try: - for n in range(args.pairs): + for n in range(pairs): even = first + 2 * n + both = True # The odd port first, then its even partner while the first is still # open: a router that reserves pairs gives the second one away. for port in (even + 1, even): @@ -106,23 +114,47 @@ def main() -> int: sock.settimeout(2) socks.append(sock) try: + # A client socket on a chosen source port, so the test knows + # which port it sent from; it only sends to the STUN server. sock.bind(("0.0.0.0", port)) except OSError as exc: print(f"{port}: could not bind ({exc.strerror}), skipped") + both = False continue seen = probe(sock, server) if seen is None: print(f"{port}: no answer") + both = False continue answered += 1 kept = seen == port rewritten += not kept print(f"{port} -> {seen} {'kept' if kept else 'REWRITTEN'}") + complete += both finally: for sock in socks: sock.close() + return answered, rewritten, complete + + +def main() -> int: + """Run the test against the first STUN server that answers; the exit status is the verdict.""" + parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) + parser.add_argument("--start", type=int, default=34100, help="first port to test (default 34100)") + parser.add_argument("--pairs", type=int, default=4, help="neighbouring pairs to test (default 4)") + args = parser.parse_args() + servers = _servers() + if not servers: + print("No STUN server could be resolved: check this namespace's DNS.") + return 2 + answered = rewritten = complete = 0 + for server in servers: + answered, rewritten, complete = run(server, args.start, args.pairs) + if answered: + break + print(f"No answer from {server[0]}:{server[1]}.") if not answered: - print(f"No answer from {server[0]}:{server[1]}: outbound UDP may be blocked.") + print("No STUN server answered: outbound UDP may be blocked.") return 2 if rewritten == answered: print( @@ -136,9 +168,17 @@ def main() -> int: print( f"\n{rewritten} of {answered} ports left with a different number while others kept " "theirs. The router rewrites some UDP source ports (some fibre boxes reserve ports in " - "pairs), and a Mysterium node behind it fails its sessions." + "pairs), and a Mysterium node behind it fails its sessions. Run it again: a pairing " + "router rewrites some port every time, while a rare clash in this machine's own NAT " + "does not repeat (the guide shows how to check the host)." ) return 1 + if complete < args.pairs: + print( + f"\nEvery port that answered kept its number, but only {complete} of {args.pairs} pairs " + "were tested in full, so the pairing was not checked. Run it again with another --start." + ) + return 3 print(f"\nAll {answered} ports kept their number.") return 0 diff --git a/services/_schema.yml b/services/_schema.yml index 55b47042..5b68d7ab 100644 --- a/services/_schema.yml +++ b/services/_schema.yml @@ -133,6 +133,10 @@ # check holds when there are at least min_matches # items and every one matches pattern # min_matches: 1 (optional) positive integer +# answered: '...' (optional) regex the output holds when this check's +# read worked; without it the check is unread and +# keeps its last verdict, so one failed read in a +# command that reads several costs only its checks # means: "..." shown to the user # Same rule as health_signals: only checks against answers you have seen. # advertised_address_env: ADDRESS (optional) the env var holding the address diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index 1c439545..a9481300 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -163,14 +163,19 @@ docker: a session connects directly. state: failing # What the node itself says, read by the worker every 30 minutes - # (app/health_probe.py): Mysterium's monitoring status, then the last 5 - # completed sessions it provided, of any age (the node returns them newest - # first). No date window: a broken node stops being offered, new sessions - # stop arriving, and a window would empty out and clear the check while the - # node is still broken. The two reads are independent, so a slow or failing - # monitoring status (the node asks Mysterium's quality oracle for it) never - # costs the sessions read, which needs only the node's own database; the run - # fails only when the sessions read does. timeout 12 bounds the whole run + # (app/health_probe.py): Mysterium's monitoring status, then the 5 sessions + # it provided that completed last, of any age. The node lists sessions by + # start time, newest first, so a long session that started before a run of + # short ones but ended after them would fall off a plain page of 5: the + # command reads 25 and keeps the 5 with the latest end (start + duration). + # No date window: a broken node stops being offered, new sessions stop + # arriving, and a window would empty out and clear the check while the node + # is still broken. The two reads are independent, and each prints a marker + # only when it worked ("answered" below): a slow or failing monitoring status + # (the node asks Mysterium's quality oracle for it) never costs the sessions + # verdict, and a failed sessions read never costs the monitoring one; a check + # whose read failed keeps its last verdict. -Y off keeps an inherited + # http_proxy away from the loopback reads. timeout 12 bounds the whole run # inside the 15 s the worker waits. Seen live # (Nov 2026) on two nodes behind routers that rewrite the UDP source port of # some connections: monitoring "failed", and every session ending after 55 @@ -184,12 +189,22 @@ docker: - "12" - sh - -c - - >- - wget -qO- -T 5 http://127.0.0.1:4050/node/monitoring-status; - echo; - wget -qO- -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=5" + - |- + if m=$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then + echo "monitoring read: $m" + fi + if s=$(wget -qO- -Y off -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=25"); then + echo "sessions read:" + echo "$s" | sed 's/},{/}\n{/g' | awk ' + match($0, /"created_at":"[^"]+"/) { + t = substr($0, RSTART + 14, 19); gsub(/[-T:]/, " ", t) + d = 0; if (match($0, /"duration":[0-9]+/)) d = substr($0, RSTART + 11, RLENGTH - 11) + print mktime(t) + d, $0 + }' | sort -rn | head -5 + fi checks: - - pattern: '\{"status":"failed"\}' + - pattern: 'monitoring read: \{"status":"failed"\}' + answered: 'monitoring read: ' means: >- Mysterium's monitoring marks the node on ${WORKER_NAME} as failed, so it is left out of the node list most buyers pick from, even when its @@ -207,6 +222,7 @@ docker: - items: '\{"id":[^{}]*"direction":"Provided"[^{}]*\}' pattern: '"duration":[4-8][0-9],"bytes_received":0,"bytes_sent":0,' min_matches: 5 + answered: 'sessions read:' means: >- The last five VPN sessions of the node on ${WORKER_NAME} each ended after about a minute having moved no data, so it earns diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index aca753ce..c52210d1 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -14,8 +14,14 @@ from __future__ import annotations import asyncio +import importlib.util import json import os +import socket +import tempfile +import threading +import time +from pathlib import Path from unittest.mock import AsyncMock, MagicMock, patch os.environ.setdefault("CASHPILOT_API_KEY", "test-fleet-key") @@ -50,10 +56,19 @@ def _session(n: int, duration: int, received: int, sent: int) -> dict: } -def _answer(status: str, sessions: list[dict]) -> str: - """What the catalog command prints: the monitoring status, then the sessions page.""" - page = {"items": sessions, "page": 1, "page_size": 5, "total_items": len(sessions), "total_pages": 1} - return json.dumps({"status": status}, separators=(",", ":")) + "\n" + json.dumps(page, separators=(",", ":")) +def _answer(status: str | None, sessions: list[dict] | None) -> str: + """What the catalog command prints: each read that worked, behind its marker. + + The sessions come one per line behind their end time, as the command's awk + prints them; None leaves a read out, as when it failed. + """ + out = [] + if status is not None: + out.append("monitoring read: " + json.dumps({"status": status}, separators=(",", ":"))) + if sessions is not None: + out.append("sessions read:") + out += [f"{1793806663 - i} " + json.dumps(x, separators=(",", ":")) for i, x in enumerate(sessions)] + return "\n".join(out) DEAD = [_session(i, 61, 0, 0) for i in range(5)] @@ -70,29 +85,35 @@ def _answer(status: str, sessions: list[dict]) -> str: def _spec(): + """The Mysterium catalog entry's probe.""" return catalog.get_service("mysterium")["docker"]["health_probe"] def test_the_failing_node_trips_both_checks(): + """A node with monitoring "failed" and five dead sessions trips both checks.""" assert health_probe.judge(FAILING, _spec()) == [0, 1] assert health_probe.judge(FAILING.encode(), _spec()) == [0, 1] def test_negative_control_a_healthy_node_raises_nothing(): + """A working node trips neither check.""" assert health_probe.judge(HEALTHY, _spec()) == [] def test_monitoring_failed_alone_is_flagged_without_the_session_check(): + """Each check stands on its own.""" assert health_probe.judge(_answer("failed", WORKING), _spec()) == [0] assert health_probe.judge(_answer("pending", DEAD[:4]), _spec()) == [] def test_four_dead_sessions_are_not_yet_a_pattern(): + """Fewer than five sessions say nothing.""" assert health_probe.judge(_answer("success", DEAD[:4]), _spec()) == [] assert health_probe.judge(_answer("success", []), _spec()) == [] def test_one_session_that_carried_data_clears_it(): + """One session that moved data clears the session check.""" assert health_probe.judge(_answer("success", [_session(9, 3600, 10_000, 2_000), *DEAD[:4]]), _spec()) == [] @@ -108,6 +129,7 @@ def test_one_session_that_carried_data_clears_it(): ], ) def test_a_dead_session_is_about_a_minute_long_and_empty(duration, received, sent, dead): + """Only a session of about a minute with no bytes either way counts as dead.""" sessions = [*DEAD[:4], _session(7, duration, received, sent)] assert (1 in health_probe.judge(_answer("success", sessions), _spec())) is dead @@ -116,12 +138,13 @@ def test_the_probe_only_reads_the_node(): """Nothing in it may change the node: plain GETs on the node's own loopback.""" script = " ".join(_spec()["command"]) assert "--post" not in script and "-X" not in script and "curl" not in script - urls = [w.strip('";') for w in script.split() if "http" in w] + urls = [w.strip('";)') for w in script.split() if "http" in w] assert urls and all(u.startswith("http://127.0.0.1:4050/") for u in urls) assert {u.split("?")[0].split("4050")[1] for u in urls} == {"/node/monitoring-status", "/sessions"} def test_the_finding_names_the_cause_and_the_guide_section(): + """Each finding names the box, the cause and the guide section.""" for check in _spec()["checks"]: assert "${WORKER_NAME}" in check["means"] assert "rewrit" in check["means"] and GUIDE in check["means"] @@ -144,25 +167,52 @@ def test_the_finding_names_the_cause_and_the_guide_section(): ], ) def test_a_malformed_probe_is_rejected_and_never_read(spec): + """A declaration that cannot be read safely is refused by the catalog and the worker.""" assert health_probe.spec_errors(spec) assert health_probe.probes([{"slug": "x", "docker": {"health_probe": spec}}]) == {} def test_the_catalog_entry_is_well_formed(): + """The shipped Mysterium probe passes the checks.""" assert health_probe.spec_errors(_spec()) == [] def test_the_session_read_has_no_date_window_and_does_not_hang_on_the_status_read(): """A date window empties out on a broken node no one is offered any more, and the check would clear itself; the status read (which asks a remote oracle) must not - cost the local sessions read.""" + cost the local sessions read, nor the other way round.""" script = _spec()["command"][-1] assert "date_from" not in script and "date " not in script - status, sessions = script.split("monitoring-status", 1) - assert "&&" not in script and sessions.lstrip().startswith(";") + status, sessions = script.split("\nfi\n", 1) + assert "monitoring-status" in status and status.startswith("if ") and sessions.startswith("if ") + assert [c.get("answered") for c in _spec()["checks"]] == ["monitoring read: ", "sessions read:"] + + +def test_one_failed_read_costs_only_its_own_checks(): + """A failed sessions read must not throw away a monitoring status of "failed".""" + output = _answer("failed", None) + assert health_probe.judge(output, _spec()) == [0] + assert health_probe.unanswered(output, _spec()) == [1] + assert health_probe.unanswered(_answer(None, DEAD), _spec()) == [0] + assert health_probe.judge(_answer(None, DEAD), _spec()) == [1] + + +def test_the_loopback_reads_skip_any_inherited_proxy(): + """Both loopback reads turn off BusyBox wget proxy use.""" + script = _spec()["command"][-1] + assert script.count("wget ") == script.count("wget -qO- -Y off ") == 2 + + +def test_the_sessions_judged_are_the_five_that_ended_last(): + """TequilAPI lists sessions by start time; a long session that started first + but ended after a run of short ones must still be among those judged.""" + script = _spec()["command"][-1] + assert "page_size=25" in script + assert "mktime(t) + d" in script and "sort -rn | head -5" in script def test_the_monitoring_finding_sends_to_the_tun_check_first(): + """The monitoring finding points at the tun and SETUID check first.""" means = _spec()["checks"][0]["means"] assert "/dev/net/tun" in means and "#running-but-not-earning-monitoring-failed-quality-0" in means @@ -170,26 +220,136 @@ def test_the_monitoring_finding_sends_to_the_tun_check_first(): # --- The worker's read --------------------------------------------------------- +class _Api: + """The low-level Docker API calls the probe makes, answering per container id.""" + + def __init__(self, answers): + """Map container id to (exit code, output), or to a callable producing the output.""" + self.answers = answers + self.ran = [] + + def exec_create(self, container_id, cmd): + """Record the exec; its id is the container id.""" + self.ran.append(container_id) + return {"Id": container_id} + + def exec_start(self, exec_id): + """The container's output.""" + answer = self.answers[exec_id] + if callable(answer): + return answer() + return answer[1] + + def exec_inspect(self, exec_id): + """The container's exit code.""" + answer = self.answers[exec_id] + return {"ExitCode": 0 if callable(answer) else answer[0]} + + +def _containers(*names, status="running"): + """Fake containers with the given ids.""" + return [MagicMock(status=status, id=n) for n in names] + + def test_the_worker_sends_back_only_which_checks_hold(): - good, bad, stopped = MagicMock(status="running"), MagicMock(status="running"), MagicMock(status="exited") - good.exec_run.return_value = (0, FAILING.encode()) - bad.exec_run.return_value = (1, b"wget: can't connect") + """Only check indexes, the unread ones and the definition leave the worker.""" + api = _Api( + { + "good": (0, FAILING.encode()), + "bad": (1, b"wget: can't connect"), + "half": (0, _answer("failed", None).encode()), + } + ) + good, bad, half = _containers("good", "bad", "half") + stopped = MagicMock(status="exited", id="stopped") + definition = health_probe.fingerprint(_spec()) with ( - patch("app.orchestrator.service_instances", return_value=[good, bad, stopped]), - patch("app.orchestrator._instance_of", side_effect=[1, 2]), + patch("app.orchestrator.service_instances", return_value=[good, bad, half, stopped]), + patch("app.orchestrator._instance_of", side_effect=[1, 2, 3]), + patch("app.health_probe._client", return_value=MagicMock(api=api)), ): rows = health_probe.read_all([catalog.get_service("mysterium")]) assert rows == [ - {"slug": "mysterium", "instance": 1, "hits": [0, 1]}, - {"slug": "mysterium", "instance": 2, "error": "the node did not answer"}, + {"slug": "mysterium", "instance": 1, "definition": definition, "hits": [0, 1], "unread": []}, + {"slug": "mysterium", "instance": 2, "definition": definition, "error": "the node did not answer"}, + {"slug": "mysterium", "instance": 3, "definition": definition, "hits": [0], "unread": [1]}, ] - stopped.exec_run.assert_not_called() + assert "stopped" not in api.ran assert "consumer_id" not in json.dumps(rows), "the node's answer never leaves the worker" +def test_a_stalled_exec_stream_does_not_hold_a_pool_thread(monkeypatch): + """A Docker socket that accepts the exec and never answers must not keep a pool + thread: four of them would leave every later read queued for good.""" + import docker + + folder = tempfile.mkdtemp(dir="/tmp") + path = os.path.join(folder, "d.sock") + server = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) + server.bind(path) + server.listen(32) + held = [] + + def _accept(): + """Accept connections and never answer them.""" + while True: + try: + held.append(server.accept()[0]) + except OSError: + return + + threading.Thread(target=_accept, daemon=True).start() + release = threading.Event() + stalled = MagicMock(status="running", id="stalled") + stalled.exec_run.side_effect = lambda *a, **k: (release.wait(30), (0, b""))[1] + monkeypatch.setattr(health_probe, "READ_TIMEOUT", 1) + monkeypatch.setattr(health_probe, "probes", lambda services: {"mysterium": _spec()}) + monkeypatch.setattr( + health_probe, "_client", lambda: docker.DockerClient(base_url=f"unix://{path}", timeout=1, version="1.41") + ) + try: + with ( + patch("app.orchestrator.service_instances", return_value=[stalled]), + patch("app.orchestrator._instance_of", return_value=1), + ): + for _ in range(5): + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert "hits" not in rows[0] and rows[0]["error"] in {"timed out", "read failed"} + assert health_probe._pool.submit(lambda: "free").result(timeout=4) == "free" + finally: + release.set() + server.close() + for conn in held: + conn.close() + + +def test_copies_read_before_the_batch_deadline_still_go_back(monkeypatch): + """The UI waits 60 s for the whole answer; one slow copy must not cost the others.""" + release = threading.Event() + api = _Api( + {"fast": (0, FAILING.encode()), "slow": lambda: (release.wait(10), FAILING.encode())[1], "late": (0, b"")} + ) + monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0.5) + try: + with ( + patch("app.orchestrator.service_instances", return_value=_containers("fast", "slow", "late")), + patch("app.orchestrator._instance_of", side_effect=[1, 2, 3]), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + started = time.monotonic() + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert time.monotonic() - started < 2 + finally: + release.set() + assert rows[0]["hits"] == [0, 1] + assert rows[1]["error"] == "timed out" and rows[2]["error"] == "not reached in time" + assert "late" not in api.ran + + def test_the_worker_endpoint_serves_the_rows(): + """The worker endpoint returns what read_all reads.""" client = TestClient(worker_api.app) - row = {"slug": "mysterium", "instance": 1, "hits": [1]} + row = {"slug": "mysterium", "instance": 1, "definition": "x", "hits": [1], "unread": []} with ( patch("app.worker_api._verify_api_key"), patch("app.worker_api.health_probe.read_all", return_value=[row]), @@ -204,15 +364,29 @@ def test_the_worker_endpoint_serves_the_rows(): RUNNING = {"slug": "mysterium", "status": "running", "instance": 1, "_worker_id": 7} -def _sweep(probes=None, *, probe_error=None, logs=""): +def _row(hits=None, *, error=None, unread=(), definition=None): + """One row of the worker's /api/health-probes for the copy under test.""" + row = {"slug": "mysterium", "instance": 1, "definition": definition or health_probe.fingerprint(_spec())} + if error: + row["error"] = error + else: + row.update(hits=list(hits or []), unread=list(unread)) + return row + + +def _sweep(probes=None, *, probe_error=None, logs="", log_error=None): + """Run one sweep against fake worker answers; returns the copy's hints and the paths called.""" calls = [] async def _proxy(wid, method, path, params=None, **kw): + """Answer like the worker would.""" calls.append(path) if path == "/api/health-probes": if probe_error: raise probe_error return {"probes": probes or []} + if log_error: + raise log_error return {"logs": logs, "filtered": True} with ( @@ -231,13 +405,15 @@ async def _proxy(wid, method, path, params=None, **kw): @pytest.fixture(autouse=True) def _clean_hints(): - main._windowed_hints, main._probe_hints, main._probe_read_at = {}, {}, {} + """Each test starts and ends with no sweep state.""" + main._windowed_hints, main._signal_hints, main._probe_hints, main._probe_state = {}, {}, {}, {} yield - main._windowed_hints, main._probe_hints, main._probe_read_at = {}, {}, {} + main._windowed_hints, main._signal_hints, main._probe_hints, main._probe_state = {}, {}, {}, {} def test_the_sweep_lists_a_failing_node_by_box_with_the_guide(): - hints, calls = _sweep([{"slug": "mysterium", "instance": 1, "hits": [0, 1]}]) + """Both findings show, naming the box and the guide.""" + hints, calls = _sweep([_row([0, 1])]) assert len(hints) == 2 assert all("attic-nas" in h and GUIDE in h and "${" not in h for h in hints) assert "about a minute having moved no data" in hints[1] @@ -245,25 +421,28 @@ def test_the_sweep_lists_a_failing_node_by_box_with_the_guide(): def test_negative_control_the_sweep_says_nothing_for_a_healthy_node(): - hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "hits": []}]) + """A healthy read shows nothing.""" + hints, _ = _sweep([_row([])]) assert hints == [] def test_an_unread_probe_keeps_the_last_verdict_and_a_healthy_read_clears_it(): - _sweep([{"slug": "mysterium", "instance": 1, "hits": [1]}]) + """A blip keeps the last verdict; a healthy read clears it.""" + _sweep([_row([1])]) hints, _ = _sweep(probe_error=HTTPException(status_code=504, detail="slow")) assert len(hints) == 1, "a blip must not clear a real problem" - hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + hints, _ = _sweep([_row(error="timed out")]) assert len(hints) == 1 - hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "hits": []}]) + hints, _ = _sweep([_row([])]) assert hints == [] def test_a_verdict_does_not_outlive_a_day_of_unread_probes(): - _sweep([{"slug": "mysterium", "instance": 1, "hits": [1]}]) + """After a day unread the old verdict goes and the unreadable node is named.""" + _sweep([_row([1])]) later = main.time.time() + main.PROBE_STALE_SECONDS + 3600 with patch("app.main.time.time", return_value=later): - hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + hints, _ = _sweep([_row(error="timed out")]) assert len(hints) == 1 and "has not been able to read" in hints[0] and "attic-nas" in hints[0] assert "about a minute" not in hints[0], "the stale verdict is gone" with patch("app.main.time.time", return_value=later): @@ -272,12 +451,14 @@ def test_a_verdict_does_not_outlive_a_day_of_unread_probes(): def test_a_short_unread_spell_names_nothing_new(): - _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) - hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "error": "timed out"}]) + """A node unread for less than a day gets no new finding.""" + _sweep([_row(error="timed out")]) + hints, _ = _sweep([_row(error="timed out")]) assert hints == [] def test_an_old_worker_without_the_endpoint_gives_no_verdict_and_keeps_the_log_signals(): + """A worker without the endpoint costs no log signal.""" hints, _ = _sweep(probe_error=HTTPException(status_code=404, detail="Not Found")) assert hints == [] failed = "DBG event={Identity:0xabc Method:manual Success:false}" @@ -286,5 +467,107 @@ def test_an_old_worker_without_the_endpoint_gives_no_verdict_and_keeps_the_log_s def test_out_of_range_hits_are_ignored(): - hints, _ = _sweep([{"slug": "mysterium", "instance": 1, "hits": [5, -1, True, "0"]}]) + """Hit values that are not valid indexes are ignored.""" + hints, _ = _sweep([_row([5, -1, True, "0"])]) assert hints == [] + + +FAILED_LOG = "\n".join(["DBG event={Identity:0xabc Method:manual Success:false}"] * 5) + + +def test_a_failed_log_read_still_lets_the_probe_update(): + """A failed log read keeps the log verdict and still updates the probe.""" + hints, _ = _sweep([_row([])], logs=FAILED_LOG) + assert len(hints) == 1 and "forward the UDP port range" in hints[0] + hints, _ = _sweep([_row([1])], log_error=HTTPException(status_code=504, detail="slow")) + assert len(hints) == 2, "the log verdict stands and the new probe verdict shows" + assert "forward the UDP port range" in hints[0] and "about a minute having moved no data" in hints[1] + hints, _ = _sweep([_row([])], log_error=HTTPException(status_code=504, detail="slow")) + assert len(hints) == 1 and "forward the UDP port range" in hints[0], "a healthy probe clears its own part" + + +def test_hits_from_another_probe_definition_are_no_verdict(): + """During an upgrade the worker may run another catalog: its indexes may name + another check, and its empty hits prove nothing.""" + _sweep([_row([1])]) + hints, _ = _sweep([_row([], definition="another")]) + assert len(hints) == 1 and "about a minute having moved no data" in hints[0] + hints, _ = _sweep([_row([0, 1], definition="another")]) + assert len(hints) == 1, "an index from another definition never shows" + hints, _ = _sweep([{k: v for k, v in _row([0]).items() if k != "definition"}]) + assert len(hints) == 1 and "about a minute" in hints[0] + + +def test_an_unread_check_keeps_its_verdict_while_the_other_updates(): + """A check the worker could not read keeps its verdict; the other updates.""" + hints, _ = _sweep([_row([0, 1])]) + assert len(hints) == 2 + hints, _ = _sweep([_row([], unread=[0])]) + assert len(hints) == 1 and "monitoring marks the node" in hints[0] + hints, _ = _sweep([_row([1], unread=[0])]) + assert len(hints) == 2 + + +def test_a_check_unread_for_a_day_says_so(): + """A check unread for a day is reported as unreadable.""" + _sweep([_row([0, 1])]) + later = main.time.time() + main.PROBE_STALE_SECONDS + 3600 + with patch("app.main.time.time", return_value=later): + hints, _ = _sweep([_row([1], unread=[0])]) + assert len(hints) == 2 and "about a minute" in hints[0] + assert "has not been able to read" in hints[1] and "did not answer every read" in hints[1] + + +# --- The two-port STUN test ---------------------------------------------------- + + +def _stun(): + """Load scripts/stun_port_pair.py as a module.""" + path = Path(__file__).resolve().parents[1] / "scripts" / "stun_port_pair.py" + spec = importlib.util.spec_from_file_location("stun_port_pair", path) + module = importlib.util.module_from_spec(spec) + spec.loader.exec_module(module) + return module + + +def test_a_network_error_is_no_answer_not_a_rewritten_port(): + """A send or receive error is no answer, never a traceback that exits 1.""" + stun = _stun() + sock = MagicMock() + sock.sendto.side_effect = OSError(101, "Network is unreachable") + assert stun.probe(sock, ("192.0.2.1", 3478)) is None + sock = MagicMock() + sock.recvfrom.side_effect = ConnectionRefusedError(111, "Connection refused") + assert stun.probe(sock, ("192.0.2.1", 3478)) is None + + +def test_a_silent_stun_server_falls_back_to_the_next(monkeypatch, capsys): + """A STUN server that never answers hands over to the next one.""" + stun = _stun() + first, second = ("192.0.2.1", 19302), ("192.0.2.2", 3478) + tried = [] + + def _run(server, start, pairs): + """The first server is silent, the second answers.""" + tried.append(server) + return (0, 0, 0) if server == first else (8, 0, 4) + + monkeypatch.setattr(stun, "_servers", lambda: [first, second]) + monkeypatch.setattr(stun, "run", _run) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py"]) + assert stun.main() == 0 and tried == [first, second] + monkeypatch.setattr(stun, "run", lambda *a: (0, 0, 0)) + assert stun.main() == 2 + + +@pytest.mark.parametrize( + ("result", "code"), + [((8, 0, 4), 0), ((6, 0, 2), 3), ((4, 0, 0), 3), ((6, 1, 2), 1), ((8, 8, 4), 1)], +) +def test_an_incomplete_pair_is_inconclusive_not_clean(monkeypatch, result, code): + """No rewrite with an untested pair exits 3, never 0.""" + stun = _stun() + monkeypatch.setattr(stun, "_servers", lambda: [("192.0.2.1", 3478)]) + monkeypatch.setattr(stun, "run", lambda *a: result) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py"]) + assert stun.main() == code From ffe5b8d167ca0f5dea333dbcc0557744284699e3 Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 16:58:37 +0100 Subject: [PATCH 4/9] fix(mysterium): let the health probe run behind the socket proxy and end a stalled exec stream The shipped socket proxy only runs exec commands the policy lists, and the policy never listed docker.health_probe, so every probe read would have been refused and the node shown as unreadable. The policy now takes the probe command from the catalog like the other node reads, and the compose files carry the regenerated policy. docker-py's exec reader waits on the socket with no timeout, so a client socket timeout never bounded the stream. The probe now reads the raw exec socket itself against a deadline, closes the connection when it gives up, and never queues a read behind busy threads. The sessions read widens from 25 to 100, so a long session that ended last is almost never missed. --- app/health_probe.py | 100 ++++++++-- app/socket_policy.py | 4 + .../casaos/CashPilot/docker-compose.yml | 5 +- .../runtipi/cashpilot/docker-compose.yml | 5 +- docker-compose.build.yml | 5 +- docker-compose.fleet.yml | 5 +- docker-compose.worker.yml | 5 +- docker-compose.yml | 5 +- scripts/socket_proxy_policy.py | 4 +- services/bandwidth/mysterium.yml | 8 +- tests/test_mysterium_health_probe.py | 178 ++++++++++++++---- 11 files changed, 261 insertions(+), 63 deletions(-) diff --git a/app/health_probe.py b/app/health_probe.py index 897494ec..2f6854eb 100644 --- a/app/health_probe.py +++ b/app/health_probe.py @@ -33,10 +33,14 @@ verdict. A check whose marker is missing is reported in ``unread``. The command must start with ``timeout `` below READ_TIMEOUT, which -ends the command in the container. The exec itself runs on a Docker client of -this module's own with a READ_TIMEOUT socket timeout: a stream that stalls -(the daemon or the socket proxy stops sending) raises instead of holding its -pool thread, so stalled reads cannot fill the pool for the worker's lifetime. +ends the command in the container. That does not bound the exec stream: if the +daemon or the socket proxy stops sending, docker-py's own reader waits on the +socket with no timeout (``docker.utils.socket.read`` polls without one). So the +exec runs on a client of this module's own with a READ_TIMEOUT socket timeout +for the API calls, and its output is read here from the raw socket against a +READ_TIMEOUT deadline (_read_stream). A stalled read ends and frees its thread, +and at most as many reads as the pool has threads are ever in flight or queued +(_slots): a copy that finds them all taken is reported unread, never queued. Read-only by construction, like ``app/node_read.py``: the command comes from the catalog in this image, never from a request, and only the indexes of the @@ -46,10 +50,15 @@ from __future__ import annotations import concurrent.futures +import contextlib import hashlib import json import logging import re +import select +import socket +import struct +import threading import time from typing import Any @@ -61,7 +70,10 @@ #: it; copies not read by then are reported unread, and the rest still go back. BATCH_BUDGET = 40 -_pool = concurrent.futures.ThreadPoolExecutor(max_workers=4, thread_name_prefix="health-probe") +_POOL_SIZE = 4 +_pool = concurrent.futures.ThreadPoolExecutor(max_workers=_POOL_SIZE, thread_name_prefix="health-probe") +#: One per read submitted and not finished, so the pool's queue never grows. +_slots = threading.BoundedSemaphore(_POOL_SIZE) def _min_matches(check: dict[str, Any]) -> int | None: @@ -171,11 +183,64 @@ def _client() -> Any: return docker.from_env(timeout=READ_TIMEOUT) +def _recv(sock: Any, deadline: float) -> bytes: + """One chunk from the exec socket, waiting no later than ``deadline``; b"" at its end.""" + left = deadline - time.monotonic() + if left <= 0 or not select.select([sock], [], [], left)[0]: + raise TimeoutError("the exec stream stalled") + if hasattr(sock, "recv"): + return sock.recv(65536) + return sock.read(65536) or b"" + + +def _read_stream(sock: Any, deadline: float) -> bytes: + """The stdout and stderr of a non-tty exec, read from its raw socket by ``deadline``. + + The stream is Docker's multiplexed format: an 8-byte header (stream, three + zero bytes, payload size) before each payload. + """ + data = b"" + while True: + chunk = _recv(sock, deadline) + if not chunk: + break + data += chunk + out, pos = [], 0 + while pos + 8 <= len(data): + size = struct.unpack(">I", data[pos + 4 : pos + 8])[0] + out.append(data[pos + 8 : pos + 8 + size]) + pos += 8 + size + return b"".join(out) + + +def _close_exec_socket(sock: Any) -> None: + """Close an exec's hijacked connection now, whatever state the read left it in. + + A read that hit its deadline leaves the exec running on the other end, so + the connection is shut down first rather than left to the garbage + collector. Closing only the socket would leave the HTTP response docker-py + hangs on it to fail on its own close later, so that is closed too. + """ + raw = getattr(sock, "_sock", sock) + with contextlib.suppress(OSError): + raw.shutdown(socket.SHUT_RDWR) + response = getattr(sock, "_response", None) + for thing in (response, sock, raw): + if thing is not None: + with contextlib.suppress(Exception): + thing.close() + + def _read_one(client: Any, container_id: str, spec: dict[str, Any]) -> dict[str, list[int]] | None: """Run the probe in one container: hits and unread checks, or None when nothing was read.""" + deadline = time.monotonic() + READ_TIMEOUT api = client.api exec_id = api.exec_create(container_id, spec["command"])["Id"] - output = api.exec_start(exec_id) + sock = api.exec_start(exec_id, socket=True) + try: + output = _read_stream(sock, deadline) + finally: + _close_exec_socket(sock) if api.exec_inspect(exec_id).get("ExitCode") != 0: return None unread = unanswered(output, spec) @@ -219,16 +284,23 @@ def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: if left <= 0: row["error"] = "not reached in time" continue - future = None + if not _slots.acquire(blocking=False): + # Every thread still busy with an earlier read: say so rather + # than queue behind it. + row["error"] = "busy with earlier reads" + continue try: - if client is None: - client = _client() - future = _pool.submit(_read_one, client, container.id, spec) + try: + if client is None: + client = _client() + future = _pool.submit(_read_one, client, container.id, spec) + except BaseException: + _slots.release() + raise + future.add_done_callback(lambda _f: _slots.release()) read = future.result(timeout=left) except concurrent.futures.TimeoutError: - # Still queued: never run it. Running: the client's socket - # timeout ends it. - future.cancel() + # The read ends by its own deadline and frees its slot then. row["error"] = "timed out" except Exception as exc: # noqa: BLE001 logger.warning("Health probe failed for %s: %s", slug, exc) @@ -239,5 +311,5 @@ def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: else: row.update(read) # A read that timed out may still be using the client; it is dropped, not - # closed, so that read ends on its own socket timeout. + # closed, so that read ends by its own deadline. return rows diff --git a/app/socket_policy.py b/app/socket_policy.py index 77261db7..c2d7d316 100644 --- a/app/socket_policy.py +++ b/app/socket_policy.py @@ -213,6 +213,10 @@ def catalog_commands(services_dir: Path = SERVICES_DIR) -> list[list[str]]: for reader in (collector.get("node_read"), payout.get("address_read"), svc.get("node_read")): if isinstance(reader, dict) and isinstance(reader.get("command"), list): found.append([str(a) for a in reader["command"]]) + # The worker's health probe (app/health_probe.py), run in the node. + probe = (svc.get("docker") or {}).get("health_probe") + if isinstance(probe, dict) and isinstance(probe.get("command"), list): + found.append([str(a) for a in probe["command"]]) firewall = (svc.get("docker") or {}).get("node_firewall") if isinstance(firewall, dict) and firewall.get("chain"): found.append(["sh", "-c", CHAIN_READ.format(chain=firewall["chain"])]) diff --git a/contrib/app-stores/casaos/CashPilot/docker-compose.yml b/contrib/app-stores/casaos/CashPilot/docker-compose.yml index 33528c29..885ce096 100644 --- a/contrib/app-stores/casaos/CashPilot/docker-compose.yml +++ b/contrib/app-stores/casaos/CashPilot/docker-compose.yml @@ -125,7 +125,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -170,7 +170,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c # The folders the proxy allows, so the worker can say what to set before # the proxy refuses a host-folder bind. Empty means none. - CASHPILOT_COMPOSE_DIR= @@ -302,6 +302,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$$$id/beneficiary\""] + - ["timeout", "12", "sh", "-c", "if m=$$$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$$$m\"\nfi\nif s=$$$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$$$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$$$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$$$0, /\"duration\":[0-9]+/)) d = substr($$$$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$$$0\n }' | sort -rn | head -5\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$$$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$$$T iptables-legacy -t nat -S MYST 2>/dev/null; $$$$T iptables -t nat -S MYST 2>/dev/null; else case \"$$$$($$$$T iptables -V 2>/dev/null)\" in *nf_tables*) $$$$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/contrib/app-stores/runtipi/cashpilot/docker-compose.yml b/contrib/app-stores/runtipi/cashpilot/docker-compose.yml index 398acb60..4b691069 100644 --- a/contrib/app-stores/runtipi/cashpilot/docker-compose.yml +++ b/contrib/app-stores/runtipi/cashpilot/docker-compose.yml @@ -90,7 +90,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -121,7 +121,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c # The values the proxy gets, so the worker can say what to set before the # proxy refuses a host-folder bind. - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -226,6 +226,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.build.yml b/docker-compose.build.yml index 30d05bc4..a4425aa8 100644 --- a/docker-compose.build.yml +++ b/docker-compose.build.yml @@ -134,7 +134,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -168,7 +168,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -287,6 +287,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.fleet.yml b/docker-compose.fleet.yml index b81e92e0..b250ecce 100644 --- a/docker-compose.fleet.yml +++ b/docker-compose.fleet.yml @@ -141,7 +141,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -225,7 +225,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -352,6 +352,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.worker.yml b/docker-compose.worker.yml index 52e8845c..4644d2a7 100644 --- a/docker-compose.worker.yml +++ b/docker-compose.worker.yml @@ -93,7 +93,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -129,7 +129,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -245,6 +245,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.yml b/docker-compose.yml index 773496ef..0bf6fba4 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -156,7 +156,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -233,7 +233,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=4c547983d8a0aaa1 + - CASHPILOT_PROXY_POLICY=f10d7a78647d921c # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -356,6 +356,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/scripts/socket_proxy_policy.py b/scripts/socket_proxy_policy.py index 76a9c469..fe967903 100644 --- a/scripts/socket_proxy_policy.py +++ b/scripts/socket_proxy_policy.py @@ -6,8 +6,8 @@ the policy travels with the file that pins the CashPilot release. This script is the one place the policy is written: app/socket_policy.py builds it from its template plus the exec commands the catalog declares (every ``node_read`` and -``address_read``, and the isolation check's chain read for every -``node_firewall``), and this writes the same block into each compose file, with +``address_read``, every ``docker.health_probe``, and the isolation check's +chain read for every ``node_firewall``), and this writes the same block into each compose file, with its fingerprint in the worker's CASHPILOT_PROXY_POLICY. python scripts/socket_proxy_policy.py # rewrite the compose files diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index a9481300..4e007901 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -167,7 +167,11 @@ docker: # it provided that completed last, of any age. The node lists sessions by # start time, newest first, so a long session that started before a run of # short ones but ended after them would fall off a plain page of 5: the - # command reads 25 and keeps the 5 with the latest end (start + duration). + # command reads 100 and keeps the 5 with the latest end (start + duration). + # A session that started before all 100 is still missed; the API has no + # end-time order or filter, and reading the whole history grows without + # bound. A home node gets a few sessions a day, so that takes one session + # outlasting a hundred others. # No date window: a broken node stops being offered, new sessions stop # arriving, and a window would empty out and clear the check while the node # is still broken. The two reads are independent, and each prints a marker @@ -193,7 +197,7 @@ docker: if m=$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then echo "monitoring read: $m" fi - if s=$(wget -qO- -Y off -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=25"); then + if s=$(wget -qO- -Y off -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100"); then echo "sessions read:" echo "$s" | sed 's/},{/}\n{/g' | awk ' match($0, /"created_at":"[^"]+"/) { diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index c52210d1..3a8b83ec 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -17,7 +17,11 @@ import importlib.util import json import os +import re import socket +import socket as _socket +import struct +import subprocess import tempfile import threading import time @@ -172,6 +176,14 @@ def test_a_malformed_probe_is_rejected_and_never_read(spec): assert health_probe.probes([{"slug": "x", "docker": {"health_probe": spec}}]) == {} +def test_the_socket_proxy_lets_the_worker_run_the_probe(): + """Behind the shipped socket proxy only listed exec commands run; an unlisted + probe would be refused on every read and the node shown as unreadable.""" + from app import socket_policy + + assert _spec()["command"] in socket_policy.catalog_commands() + + def test_the_catalog_entry_is_well_formed(): """The shipped Mysterium probe passes the checks.""" assert health_probe.spec_errors(_spec()) == [] @@ -207,10 +219,34 @@ def test_the_sessions_judged_are_the_five_that_ended_last(): """TequilAPI lists sessions by start time; a long session that started first but ended after a run of short ones must still be among those judged.""" script = _spec()["command"][-1] - assert "page_size=25" in script + assert "page_size=100" in script assert "mktime(t) + d" in script and "sort -rn | head -5" in script +def _awk_has_mktime() -> bool: + """Whether this machine's awk has mktime, as BusyBox's and mawk's do (macOS's does not).""" + probe = subprocess.run(["awk", 'BEGIN { print mktime("2026 11 04 15 36 42") }'], capture_output=True, text=True) + return probe.returncode == 0 and probe.stdout.strip().isdigit() + + +@pytest.mark.skipif(not _awk_has_mktime(), reason="this awk has no mktime") +def test_a_long_session_that_ended_last_is_judged_though_it_started_first(): + """Runs the catalog's own sessions pipeline on a page in the API's order.""" + script = _spec()["command"][-1] + pipeline = script[script.index('echo "$s" | ') + len('echo "$s" | ') : script.rindex("\nfi")] + dead = [_session(i, 61, 0, 0) | {"created_at": f"2026-11-08T1{i // 6}:{i % 6}0:00Z"} for i in range(30)] + long_good = _session(99, 40 * 3600, 900_000, 400_000) | {"created_at": "2026-11-07T00:00:00Z"} + page = {"items": [*reversed(dead), long_good], "page": 1, "page_size": 100, "total_items": 31, "total_pages": 1} + env = {**os.environ, "s": json.dumps(page, separators=(",", ":"))} + out = subprocess.run(["sh", "-c", 'echo "$s" | ' + pipeline], capture_output=True, text=True, env=env, check=True) + assert len(out.stdout.splitlines()) == 5 and "00000000-0000-4000-8000-000000000099" in out.stdout + assert health_probe.judge(_answer("success", None) + "\nsessions read:\n" + out.stdout, _spec()) == [] + dead_only = {**page, "items": list(reversed(dead))} + env["s"] = json.dumps(dead_only, separators=(",", ":")) + out = subprocess.run(["sh", "-c", 'echo "$s" | ' + pipeline], capture_output=True, text=True, env=env, check=True) + assert health_probe.judge("sessions read:\n" + out.stdout, _spec()) == [1] + + def test_the_monitoring_finding_sends_to_the_tun_check_first(): """The monitoring finding points at the tun and SETUID check first.""" means = _spec()["checks"][0]["means"] @@ -220,30 +256,51 @@ def test_the_monitoring_finding_sends_to_the_tun_check_first(): # --- The worker's read --------------------------------------------------------- +def _frames(output: bytes) -> bytes: + """Docker's multiplexed exec stream for ``output``, split over two stdout frames.""" + half = len(output) // 2 + return b"".join(struct.pack(">BxxxI", 1, len(part)) + part for part in (output[:half], output[half:])) + + class _Api: - """The low-level Docker API calls the probe makes, answering per container id.""" + """The low-level Docker API calls the probe makes, answering per container id. + + An answer is (exit code, output), or None for an exec stream that never + sends: its socket stays silent until ``hang`` is set. + """ def __init__(self, answers): - """Map container id to (exit code, output), or to a callable producing the output.""" + """Map container id to its answer.""" self.answers = answers self.ran = [] + self.hang = threading.Event() def exec_create(self, container_id, cmd): """Record the exec; its id is the container id.""" self.ran.append(container_id) return {"Id": container_id} - def exec_start(self, exec_id): - """The container's output.""" + def exec_start(self, exec_id, socket=False): + """The raw socket of the exec stream, as docker-py hands it out.""" + assert socket, "the probe must read the raw socket, never docker-py's unbounded reader" + ours, theirs = _socket.socketpair() answer = self.answers[exec_id] - if callable(answer): - return answer() - return answer[1] + if answer is None: + + def _close_later(): + self.hang.wait(30) + theirs.close() + + threading.Thread(target=_close_later, daemon=True).start() + else: + theirs.sendall(_frames(answer[1])) + theirs.close() + return ours def exec_inspect(self, exec_id): """The container's exit code.""" answer = self.answers[exec_id] - return {"ExitCode": 0 if callable(answer) else answer[0]} + return {"ExitCode": 0 if answer is None else answer[0]} def _containers(*names, status="running"): @@ -278,30 +335,62 @@ def test_the_worker_sends_back_only_which_checks_hold(): assert "consumer_id" not in json.dumps(rows), "the node's answer never leaves the worker" -def test_a_stalled_exec_stream_does_not_hold_a_pool_thread(monkeypatch): - """A Docker socket that accepts the exec and never answers must not keep a pool - thread: four of them would leave every later read queued for good.""" - import docker - - folder = tempfile.mkdtemp(dir="/tmp") - path = os.path.join(folder, "d.sock") +def _fake_docker(path: str, stop: threading.Event) -> socket.socket: + """A Docker API on a unix socket that creates the exec, starts its stream, then never sends.""" server = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) server.bind(path) server.listen(32) - held = [] + + def _serve(conn): + """Answer one connection's requests until the exec stream starts.""" + buf = b"" + while not stop.is_set(): + while b"\r\n\r\n" not in buf: + chunk = conn.recv(65536) + if not chunk: + return + buf += chunk + head, buf = buf.split(b"\r\n\r\n", 1) + length = int(re.search(rb"(?i)content-length: *(\d+)", head).group(1)) if b"ength:" in head else 0 + while len(buf) < length: + buf += conn.recv(65536) + buf = buf[length:] + if b"/exec/stalled-exec/start" in head: + conn.sendall( + b"HTTP/1.1 101 UPGRADED\r\nContent-Type: application/vnd.docker.raw-stream\r\n" + b"Connection: Upgrade\r\nUpgrade: tcp\r\n\r\n" + ) + stop.wait(30) # the stream has started and never sends a byte + return + body = b'{"Id":"stalled-exec"}' + conn.sendall( + b"HTTP/1.1 201 Created\r\nContent-Type: application/json\r\n" + + f"Content-Length: {len(body)}\r\n\r\n".encode() + + body + ) def _accept(): - """Accept connections and never answer them.""" + """Serve every connection on its own thread.""" while True: try: - held.append(server.accept()[0]) + conn = server.accept()[0] except OSError: return + threading.Thread(target=_serve, args=(conn,), daemon=True).start() threading.Thread(target=_accept, daemon=True).start() - release = threading.Event() - stalled = MagicMock(status="running", id="stalled") - stalled.exec_run.side_effect = lambda *a, **k: (release.wait(30), (0, b""))[1] + return server + + +def test_a_stalled_exec_stream_does_not_hold_a_pool_thread(monkeypatch): + """The daemon creates the exec and starts its stream, then never sends: the read + must end by its deadline and free its thread, or four of them leave every + later read queued for good. docker-py's own reader polls with no timeout.""" + import docker + + path = os.path.join(tempfile.mkdtemp(dir="/tmp"), "d.sock") + stop = threading.Event() + server = _fake_docker(path, stop) monkeypatch.setattr(health_probe, "READ_TIMEOUT", 1) monkeypatch.setattr(health_probe, "probes", lambda services: {"mysterium": _spec()}) monkeypatch.setattr( @@ -309,26 +398,49 @@ def _accept(): ) try: with ( - patch("app.orchestrator.service_instances", return_value=[stalled]), + patch("app.orchestrator.service_instances", return_value=_containers("stalled")), patch("app.orchestrator._instance_of", return_value=1), ): - for _ in range(5): + for _ in range(6): rows = health_probe.read_all([catalog.get_service("mysterium")]) assert "hits" not in rows[0] and rows[0]["error"] in {"timed out", "read failed"} - assert health_probe._pool.submit(lambda: "free").result(timeout=4) == "free" + time.sleep(0.3) + time.sleep(1.5) + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert rows[0]["error"] != "busy with earlier reads", "every stalled read ended and gave back its slot" + assert health_probe._pool.submit(lambda: "free").result(timeout=2) == "free" finally: - release.set() + stop.set() server.close() - for conn in held: - conn.close() + + +def test_reads_never_queue_behind_busy_threads(monkeypatch): + """With every thread on a read that has not ended, the next copy is reported + busy at once instead of waiting in the pool's queue.""" + api = _Api({f"c{i}": None for i in range(6)}) + monkeypatch.setattr(health_probe, "READ_TIMEOUT", 0.2) + monkeypatch.setattr(health_probe, "probes", lambda services: {"mysterium": _spec()}) + monkeypatch.setattr(health_probe, "_recv", lambda sock, deadline: (api.hang.wait(30), b"")[1]) + try: + with ( + patch("app.orchestrator.service_instances", return_value=_containers(*api.answers)), + patch("app.orchestrator._instance_of", side_effect=range(1, 7)), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert [r["error"] for r in rows] == ["timed out"] * 4 + ["busy with earlier reads"] * 2 + assert api.ran == ["c0", "c1", "c2", "c3"] + finally: + api.hang.set() + deadline = time.monotonic() + 3 + while time.monotonic() < deadline and not health_probe._slots.acquire(blocking=False): + time.sleep(0.05) + health_probe._slots.release() def test_copies_read_before_the_batch_deadline_still_go_back(monkeypatch): """The UI waits 60 s for the whole answer; one slow copy must not cost the others.""" - release = threading.Event() - api = _Api( - {"fast": (0, FAILING.encode()), "slow": lambda: (release.wait(10), FAILING.encode())[1], "late": (0, b"")} - ) + api = _Api({"fast": (0, FAILING.encode()), "slow": None, "late": (0, b"")}) monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0.5) try: with ( @@ -340,7 +452,7 @@ def test_copies_read_before_the_batch_deadline_still_go_back(monkeypatch): rows = health_probe.read_all([catalog.get_service("mysterium")]) assert time.monotonic() - started < 2 finally: - release.set() + api.hang.set() assert rows[0]["hits"] == [0, 1] assert rows[1]["error"] == "timed out" and rows[2]["error"] == "not reached in time" assert "late" not in api.ran From cea9326eaa6c0db375fcb84e1bf8e3f1e2cd3841 Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 17:23:36 +0100 Subject: [PATCH 5/9] fix(mysterium): keep probe answers inside the UI's wait and say when the socket proxy refuses them Listing the copies now runs on the probe's own short-timeout client and within the batch budget, so a stalled listing cannot outlast the UI's wait. The next call starts with the first copy the last one did not reach, so a slow copy cannot keep the later ones unread. A read the socket proxy refuses says so, and names the update when the proxy's policy is older than the worker, instead of sending the operator to the node's logs. The policy also picks up probes in .yaml catalog files, which the catalog loads too. The two-port test rejects ports outside 1 to 65535 with its own exit status instead of reading them as a rewrite, and no longer claims a forward cannot work when it only measured ports with no forward. --- app/health_probe.py | 97 ++++++++++++------- app/main.py | 9 +- app/orchestrator.py | 5 +- app/socket_policy.py | 3 +- docs/guides/mysterium.md | 8 +- scripts/stun_port_pair.py | 24 ++++- tests/test_mysterium_health_probe.py | 133 +++++++++++++++++++++++++++ 7 files changed, 233 insertions(+), 46 deletions(-) diff --git a/app/health_probe.py b/app/health_probe.py index 2f6854eb..c728ff06 100644 --- a/app/health_probe.py +++ b/app/health_probe.py @@ -74,6 +74,9 @@ _pool = concurrent.futures.ThreadPoolExecutor(max_workers=_POOL_SIZE, thread_name_prefix="health-probe") #: One per read submitted and not finished, so the pool's queue never grows. _slots = threading.BoundedSemaphore(_POOL_SIZE) +#: Per service, the copy the next read_all starts with: the first one the last +#: call did not reach, so a slow copy cannot keep the later ones unread. +_resume: dict[str, int] = {} def _min_matches(check: dict[str, Any]) -> int | None: @@ -249,14 +252,32 @@ def _read_one(client: Any, container_id: str, spec: dict[str, Any]) -> dict[str, return {"hits": judge(output, spec), "unread": unread} +def _read_error(exc: Exception, slug: str) -> str: + """Why a read raised, as the worker reports it to the UI.""" + from app import orchestrator + + if orchestrator.proxy_refusal(exc) is None: + logger.warning("Health probe failed for %s: %s", slug, exc) + return "read failed" + logger.warning("The socket proxy refused the %s health probe: %s", slug, exc) + if orchestrator.proxy_policy_fix() is not None: + return ( + "the Docker socket proxy refused the read because its policy is older than this " + "worker; update it as the worker's status page shows" + ) + return "the Docker socket proxy refused the read" + + def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: """One row per running managed copy of a service that declares a probe. A row carries ``definition`` (see fingerprint) and, when the read worked, ``hits``, the indexes of the checks that hold, and ``unread``, those it could not judge; ``error`` when it did not work at all: an unread node is - no verdict, never a healthy one. Copies not reached within BATCH_BUDGET - are reported unread, so the ones read in time still count. + no verdict, never a healthy one. Listing the copies and reading them both + fit in BATCH_BUDGET: copies not reached are reported unread, so the ones + read in time still count, and the next call starts with the first copy + this one did not reach, so every copy gets its turn. """ # Imported here: the UI imports this module for nothing but the catalog # check, and has no Docker. @@ -266,50 +287,56 @@ def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: deadline = time.monotonic() + BATCH_BUDGET client = None for slug, spec in sorted(probes(services).items()): + if time.monotonic() >= deadline: + # Not listed: the UI keeps these copies' last verdicts. + break try: - copies = orchestrator.service_instances(slug) + if client is None: + client = _client() + # On this module's client, so a stalled listing ends in READ_TIMEOUT. + copies = orchestrator.service_instances(slug, client=client) except Exception as exc: # noqa: BLE001 - one service never fails the rest logger.warning("Could not list %s containers for the health probe: %s", slug, exc) continue - for container in copies: - if getattr(container, "status", "") != "running": - continue - row: dict[str, Any] = { - "slug": slug, - "instance": orchestrator._instance_of(container), - "definition": fingerprint(spec), - } - rows.append(row) + running = [c for c in copies if getattr(c, "status", "") == "running"] + mine = [ + {"slug": slug, "instance": orchestrator._instance_of(c), "definition": fingerprint(spec)} for c in running + ] + rows.extend(mine) + start = _resume.pop(slug, 0) % len(running) if running else 0 + for i in [*range(start, len(running)), *range(start)]: + row = mine[i] left = min(READ_TIMEOUT, deadline - time.monotonic()) if left <= 0: row["error"] = "not reached in time" - continue - if not _slots.acquire(blocking=False): + elif not _slots.acquire(blocking=False): # Every thread still busy with an earlier read: say so rather # than queue behind it. row["error"] = "busy with earlier reads" - continue - try: - try: - if client is None: - client = _client() - future = _pool.submit(_read_one, client, container.id, spec) - except BaseException: - _slots.release() - raise - future.add_done_callback(lambda _f: _slots.release()) - read = future.result(timeout=left) - except concurrent.futures.TimeoutError: - # The read ends by its own deadline and frees its slot then. - row["error"] = "timed out" - except Exception as exc: # noqa: BLE001 - logger.warning("Health probe failed for %s: %s", slug, exc) - row["error"] = "read failed" else: - if read is None: - row["error"] = "the node did not answer" - else: - row.update(read) + row.update(_read_in_pool(client, running[i].id, spec, left, slug)) + if row.get("error") in ("not reached in time", "busy with earlier reads"): + _resume.setdefault(slug, i) # A read that timed out may still be using the client; it is dropped, not # closed, so that read ends by its own deadline. return rows + + +def _read_in_pool(client: Any, container_id: str, spec: dict[str, Any], left: float, slug: str) -> dict[str, Any]: + """Run one read on the pool, holding the slot already taken, and wait up to ``left`` seconds.""" + try: + try: + future = _pool.submit(_read_one, client, container_id, spec) + except BaseException: + _slots.release() + raise + future.add_done_callback(lambda _f: _slots.release()) + read = future.result(timeout=left) + except concurrent.futures.TimeoutError: + # The read ends by its own deadline and frees its slot then. + return {"error": "timed out"} + except Exception as exc: # noqa: BLE001 + return {"error": _read_error(exc, slug)} + if read is None: + return {"error": "the node did not answer"} + return read diff --git a/app/main.py b/app/main.py index fabb6519..2cbe3dad 100644 --- a/app/main.py +++ b/app/main.py @@ -2152,10 +2152,15 @@ def _keep(k: tuple[str, int, int] = key) -> None: probed = [await _render_signal_means(spec["checks"][i], slug, workers[wid]) for i in held] if unreadable: worker_name = str((workers[wid] or {}).get("name") or "this machine") + # A refusal by the socket proxy names its own fix; the node is not the problem. + advice = ( + "" + if "socket proxy" in unreadable + else " Check that the node runs normally and look at its logs." + ) probed.append( f"CashPilot has not been able to read this node's own API on {worker_name} " - f"({unreadable}), so part of what it checks on the node is unchecked. " - "Check that the node runs normally and look at its logs." + f"({unreadable}), so part of what it checks on the node is unchecked.{advice}" ) if state: probe_state[key] = state diff --git a/app/orchestrator.py b/app/orchestrator.py index 59f96064..b9235d4f 100644 --- a/app/orchestrator.py +++ b/app/orchestrator.py @@ -481,12 +481,13 @@ def is_proxied(container: Any) -> bool: return False -def service_instances(slug: str) -> list[Any]: +def service_instances(slug: str, client: Any = None) -> list[Any]: """Every managed container of ``slug`` on this worker, first copy first. Proxied copies and tunnels are not copies of the service; see is_proxied. + ``client`` lets a caller list on its own client, with its own timeout. """ - client = _get_client() + client = client or _get_client() found = client.containers.list(all=True, filters={"label": [f"{LABEL_SERVICE}={slug}", f"{LABEL_MANAGED}=true"]}) return sorted((c for c in found if not is_proxied(c)), key=_instance_of) diff --git a/app/socket_policy.py b/app/socket_policy.py index c2d7d316..c3a4ca1a 100644 --- a/app/socket_policy.py +++ b/app/socket_policy.py @@ -204,7 +204,8 @@ def catalog_commands(services_dir: Path = SERVICES_DIR) -> list[list[str]]: from app.isolation_check import CHAIN_READ found: list[list[str]] = list(FIXED_COMMANDS) - for path in sorted(services_dir.rglob("*.yml")): + # Both extensions, as app/catalog.py loads both. + for path in sorted([*services_dir.rglob("*.yml"), *services_dir.rglob("*.yaml")]): if path.name.startswith("_"): continue svc = yaml.safe_load(path.read_text()) or {} diff --git a/docs/guides/mysterium.md b/docs/guides/mysterium.md index 8af252aa..931f6371 100644 --- a/docs/guides/mysterium.md +++ b/docs/guides/mysterium.md @@ -308,12 +308,16 @@ On a router that pairs ports, the even port of each pair comes back rewritten: On a working line every port comes back with its own number. When every port comes back rewritten, the script says so separately: that is a NAT which rewrites every port (a symmetric NAT, carrier-grade NAT, a VPN, or Docker -Desktop's own NAT), where port forwarding cannot work either. The script exits +Desktop's own NAT). The test only measures ports with no forward, so it does +not say whether your forward of `UDP_PORTS` reaches the node: the node's own +port check does, and behind carrier-grade NAT or a VPN no forward reaches it. +The script exits 0 when every pair was tested and every port kept its number, 1 when one was rewritten, 2 when no STUN server answered, and 3 when nothing was rewritten but some pair could not be tested in full (a port that would not bind or got no answer), so the result says nothing about pairing; run it again with -another `--start`. It tries Google's STUN server first and Cloudflare's when +another `--start`. It exits 4 when `--start` and `--pairs` do not give real +ports. It tries Google's STUN server first and Cloudflare's when Google does not answer. It only sends a few packets to a public STUN server; it does not touch the node. `--start` picks the first port to test (default 34100); keep it outside `UDP_PORTS`, whose ports the node holds. diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py index 4ae1db18..fa1fdd66 100644 --- a/scripts/stun_port_pair.py +++ b/scripts/stun_port_pair.py @@ -24,7 +24,8 @@ 1 when one was rewritten, 2 when no STUN server answered, 3 when no port was rewritten but some pair could not be tested in full (a port that did not bind or got no answer), so the pairing was not checked: run it again with another ---start. A rewritten port is reported as a pairing +--start, and 4 when --start and --pairs do not give real ports (1 to 65535). A +rewritten port is reported as a pairing router when some ports kept their number, and as a NAT that rewrites every port when none did. Read-only: it sends a few UDP packets to a public STUN server and changes nothing. @@ -37,6 +38,7 @@ import socket import struct import sys +from typing import NoReturn MAGIC = 0x2112A442 SERVERS = [("stun.l.google.com", 19302), ("stun.cloudflare.com", 3478)] @@ -137,12 +139,24 @@ def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int] return answered, rewritten, complete +class _Parser(argparse.ArgumentParser): + """argparse with its own exit status for bad arguments, 4: its usual 2 means no STUN answer here.""" + + def error(self, message: str) -> NoReturn: + """Print the usage and the problem, then exit 4.""" + self.print_usage(sys.stderr) + self.exit(4, f"{self.prog}: error: {message}\n") + + def main() -> int: """Run the test against the first STUN server that answers; the exit status is the verdict.""" - parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) + parser = _Parser(description=__doc__.split("\n\n")[0]) parser.add_argument("--start", type=int, default=34100, help="first port to test (default 34100)") parser.add_argument("--pairs", type=int, default=4, help="neighbouring pairs to test (default 4)") args = parser.parse_args() + first = args.start & ~1 + if args.pairs < 1 or first < 1 or first + 2 * args.pairs - 1 > 65535: + parser.error("--start and --pairs must give ports from 1 to 65535 (pairs start on an even port)") servers = _servers() if not servers: print("No STUN server could be resolved: check this namespace's DNS.") @@ -160,8 +174,10 @@ def main() -> int: print( f"\nAll {answered} ports left with a different number. Something in the path rewrites " "every UDP source port: a symmetric NAT, carrier-grade NAT, a VPN, or Docker Desktop's " - "own NAT (run this on a Linux host with Docker Engine, not Docker Desktop). Port " - "forwarding cannot work through it either." + "own NAT (run this on a Linux host with Docker Engine, not Docker Desktop). This " + "only measures ports with no forward: whether a forward of UDP_PORTS reaches the " + "node is a separate check (the node's own port check, and none works behind " + "carrier-grade NAT or a VPN)." ) return 1 if rewritten: diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index 3a8b83ec..0e8ceaa8 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -288,6 +288,7 @@ def exec_start(self, exec_id, socket=False): if answer is None: def _close_later(): + """End the silent stream once the test lets go.""" self.hang.wait(30) theirs.close() @@ -458,6 +459,91 @@ def test_copies_read_before_the_batch_deadline_still_go_back(monkeypatch): assert "late" not in api.ran +def test_the_next_call_starts_with_the_copy_this_one_did_not_reach(monkeypatch): + """A slow copy that eats the budget every time must not leave the later ones unread for good.""" + api = _Api({"fast": (0, FAILING.encode()), "slow": None, "late": (0, FAILING.encode())}) + monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0.5) + try: + with ( + patch("app.orchestrator.service_instances", return_value=_containers("fast", "slow", "late")), + patch("app.orchestrator._instance_of", side_effect=[1, 2, 3, 1, 2, 3]), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + health_probe.read_all([catalog.get_service("mysterium")]) + assert api.ran == ["fast", "slow"] + rows = health_probe.read_all([catalog.get_service("mysterium")]) + finally: + api.hang.set() + assert api.ran[2] == "late", "the copy the first call never reached goes first" + assert [r["instance"] for r in rows] == [1, 2, 3], "rows keep the copies' order" + assert rows[2]["hits"] == [0, 1] + + +def test_listing_the_copies_uses_the_probe_client_and_the_budget(monkeypatch): + """A stalled container listing on the shared client (60 s) would outlast the UI's wait.""" + probe_client = MagicMock(api=_Api({})) + listed = [] + + def _list(slug, client=None): + """Record which client listed the copies.""" + listed.append(client) + return [] + + with ( + patch("app.orchestrator.service_instances", side_effect=_list), + patch("app.health_probe._client", return_value=probe_client), + ): + health_probe.read_all([catalog.get_service("mysterium")]) + assert listed == [probe_client] + monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0) + assert health_probe.read_all([catalog.get_service("mysterium")]) == [] + assert len(listed) == 1, "no listing starts once the budget is spent" + + +def _proxy_403(): + """The APIError docker-py raises when sockguard refuses a call.""" + import docker + + response = MagicMock(status_code=403) + response.json.return_value = {"message": "request denied by sockguard policy", "reason": "exec command not allowed"} + return docker.errors.APIError("403 Client Error", response=response) + + +@pytest.mark.parametrize(("stale", "says_update"), [(True, True), (False, False)]) +def test_a_proxy_refusal_says_so_and_names_the_fix_when_the_policy_is_old(stale, says_update): + """A refused read says the proxy refused it, and names the update when the policy is stale.""" + refused = MagicMock(api=MagicMock(**{"exec_create.side_effect": _proxy_403()})) + with ( + patch("app.orchestrator.service_instances", return_value=_containers("node")), + patch("app.orchestrator._instance_of", return_value=1), + patch("app.orchestrator.proxy_policy_fix", return_value={"release": "x"} if stale else None), + patch("app.health_probe._client", return_value=refused), + ): + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert "socket proxy refused" in rows[0]["error"] + assert ("status page" in rows[0]["error"]) is says_update + + +def test_a_proxy_refusal_does_not_send_the_operator_to_the_node_logs(): + """A refusal by the proxy names its own fix, not the node's logs.""" + _sweep([_row(error="the Docker socket proxy refused the read")]) + later = main.time.time() + main.PROBE_STALE_SECONDS + 3600 + with patch("app.main.time.time", return_value=later): + hints, _ = _sweep([_row(error="the Docker socket proxy refused the read")]) + assert len(hints) == 1 and "socket proxy refused" in hints[0] and "logs" not in hints[0] + + +def test_a_probe_in_a_yaml_file_reaches_the_proxy_policy(tmp_path): + """app/catalog.py loads .yaml as well as .yml, so the policy must list both.""" + from app import socket_policy + + svc = tmp_path / "bandwidth" / "newnode.yaml" + svc.parent.mkdir() + command = ["timeout", "5", "cat", "/x"] + svc.write_text(json.dumps({"slug": "newnode", "docker": {"health_probe": {"command": command}}})) + assert command in socket_policy.catalog_commands(tmp_path) + + def test_the_worker_endpoint_serves_the_rows(): """The worker endpoint returns what read_all reads.""" client = TestClient(worker_api.app) @@ -515,6 +601,14 @@ async def _proxy(wid, method, path, params=None, **kw): return main._windowed_hints.get(("mysterium", 7, 1), []), calls +@pytest.fixture(autouse=True) +def _no_carried_turn(): + """Each test starts read_all with the first copy.""" + health_probe._resume.clear() + yield + health_probe._resume.clear() + + @pytest.fixture(autouse=True) def _clean_hints(): """Each test starts and ends with no sweep state.""" @@ -683,3 +777,42 @@ def test_an_incomplete_pair_is_inconclusive_not_clean(monkeypatch, result, code) monkeypatch.setattr(stun, "run", lambda *a: result) monkeypatch.setattr("sys.argv", ["stun_port_pair.py"]) assert stun.main() == code + + +@pytest.mark.parametrize( + ("args", "code"), + [ + (["--start", "1"], 4), + (["--start", "65535", "--pairs", "2"], 4), + (["--pairs", "0"], 4), + (["--start", "70000"], 4), + ], +) +def test_ports_that_do_not_exist_are_an_input_error_not_a_verdict(monkeypatch, args, code): + """Port 0 binds anywhere and ports past 65535 raise: neither may read as a rewrite.""" + stun = _stun() + monkeypatch.setattr(stun, "run", lambda *a: pytest.fail("no port may be tested")) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py", *args]) + with pytest.raises(SystemExit) as stop: + stun.main() + assert stop.value.code == code + + +def test_the_highest_real_pair_is_still_tested(monkeypatch): + """65534 and 65535 are real ports and still tested.""" + stun = _stun() + monkeypatch.setattr(stun, "_servers", lambda: [("192.0.2.1", 3478)]) + monkeypatch.setattr(stun, "run", lambda server, start, pairs: (2, 0, 1)) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py", "--start", "65534", "--pairs", "1"]) + assert stun.main() == 0 + + +def test_every_port_rewritten_makes_no_claim_about_a_forward(monkeypatch, capsys): + """The test measures ports with no forward, so it says nothing about one.""" + stun = _stun() + monkeypatch.setattr(stun, "_servers", lambda: [("192.0.2.1", 3478)]) + monkeypatch.setattr(stun, "run", lambda *a: (8, 8, 4)) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py"]) + assert stun.main() == 1 + out = capsys.readouterr().out + assert "cannot work" not in out and "only measures ports with no forward" in out From 52313ab24f87fca8634248e499c4703f3265a67c Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 17:43:48 +0100 Subject: [PATCH 6/9] test(mysterium): remove the stalled-exec test's socket folder after the run --- tests/test_mysterium_health_probe.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index 0e8ceaa8..3ca3fd71 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -18,6 +18,7 @@ import json import os import re +import shutil import socket import socket as _socket import struct @@ -389,7 +390,9 @@ def test_a_stalled_exec_stream_does_not_hold_a_pool_thread(monkeypatch): later read queued for good. docker-py's own reader polls with no timeout.""" import docker - path = os.path.join(tempfile.mkdtemp(dir="/tmp"), "d.sock") + # /tmp, not tmp_path: a unix socket path must stay under about 100 characters. + folder = tempfile.mkdtemp(dir="/tmp") + path = os.path.join(folder, "d.sock") stop = threading.Event() server = _fake_docker(path, stop) monkeypatch.setattr(health_probe, "READ_TIMEOUT", 1) @@ -413,6 +416,7 @@ def test_a_stalled_exec_stream_does_not_hold_a_pool_thread(monkeypatch): finally: stop.set() server.close() + shutil.rmtree(folder, ignore_errors=True) def test_reads_never_queue_behind_busy_threads(monkeypatch): From d3c5ab9b8d2879ac3be5a91f77143eed57efd3f8 Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 17:58:57 +0100 Subject: [PATCH 7/9] docs(mysterium): name the real trigger, an inbound packet that switches the port's mapping Measured on an affected node: a wider UDP_PORTS range does not help (1,000 ports rewrote none at idle, the narrow range only a few percent). What breaks sessions is that once any packet from outside reaches a port, the router rewrites the source port of later flows from it to other addresses, and every session starts with such a packet from the node's own port check. Port-pair reservation is real but secondary. The guide now explains that, drops the wider range as a fix, gives the start and removal cost of many published ports and the deploy limit past about 350, and lists bridge mode with an endpoint-independent router, then an untested port-check workaround. The decisive test (one packet in from another network, then STUN from that port) is a manual step; the script and the catalog texts say the same. --- docs/guides/mysterium.md | 154 +++++++++++++++++---------- scripts/stun_port_pair.py | 29 ++--- services/bandwidth/mysterium.yml | 26 +++-- tests/test_mysterium_health_probe.py | 5 +- 4 files changed, 131 insertions(+), 83 deletions(-) diff --git a/docs/guides/mysterium.md b/docs/guides/mysterium.md index 931f6371..3da2cf9f 100644 --- a/docs/guides/mysterium.md +++ b/docs/guides/mysterium.md @@ -99,11 +99,15 @@ the router is the same as when the node shared the host's network. Keep the range below 32768. Ports 32768 to 60999 are Linux's ephemeral range: any program on the machine (a DNS lookup, a game client, a browser) can hold one of them for a moment. On the host's network the node just skipped a taken port, but Docker publishes the range as a whole, so one taken port fails the node's start. The worker then puts the previous node back and says which port was taken. Each session takes about two ports, so the default 30 ports carry about 15 -sessions at once, more than a home node gets. Every published port costs about -2.5 MB of memory on the machine (Docker starts two small proxy processes per -port; 101 ports measured about 250 MB). A range of 20 to 30 ports is enough on -most routers. On a router that reserves UDP ports in pairs, a narrow range -makes sessions fail; see +sessions at once, more than a home node gets. A range of 20 to 30 ports is +enough. A wider one costs more and fixes nothing. With Docker's default +userland proxy every published port costs about 2.5 MB of memory (Docker +starts two small proxy processes per port; 101 ports measured about 250 MB); +with `"userland-proxy": false` there are no such processes. Either way the +node's start and removal take longer with every port: 101 ports took 3.7 s to +start and 7.1 s to remove, 300 took 11.7 s and 19.2 s, 1,000 took 51 s and +84 s. Past about 350 ports a deploy runs over the socket proxy's 30-second +limit and fails. A node whose sessions all fail is not short of ports; see [Routers that rewrite UDP source ports](#routers-that-rewrite-udp-source-ports). The default was `56000:56100` through 2.0.6 and `56000:56029` in 2.0.7 and 2.1.0, both inside the ephemeral range. A node keeps @@ -259,35 +263,70 @@ and Mysterium's discovery stops offering the node to most buyers. A missing `SETUID`/`SETGID` or `/dev/net/tun` looks much the same; rule those out first with [the section below](#running-but-not-earning-monitoring-failed-quality-0). -**Cause.** The router in front of the machine changes the source port of some -outgoing UDP flows. Inbound works, so every check that only tests inbound -passes. But the node advertises the ports it listens on and answers from them, -and when the router sends an answer out from a different port, the buyer's -client drops it. The session is set up, never carries a byte, and times out. - -One pattern seen on some ISP fibre boxes (an ONT with a built-in router): the -box reserves outgoing UDP ports in pairs. When it maps port P it also holds P -XOR 1 (23000 and 23001, 23002 and 23003, and so on), and a later flow from the -partner port leaves with a random port. Others do it for every port, or only -when a SIP ALG or the box's own VoIP service owns a range. - -**Why a narrow range makes it near certain.** Each session takes about two -ports from `UDP_PORTS`. In a range of 30 ports the node keeps reusing the same -few pairs, so a session's second port is almost always the partner of a port -already mapped, and gets rewritten. With the node's wide default (10000 to -60000, no `--udp.ports`) collisions are rare enough that a pairing router goes -unnoticed, which is why a node can work for months and fail the day its range -is narrowed. CashPilot always passes `--udp.ports`, so that wide default is not -an option here; the range is `UDP_PORTS`. - -**Confirm it.** Ask a public STUN server which port it sees, from pairs of -neighbouring ports, inside the node's network namespace. CashPilot ships -a small script for this with no dependencies beyond Python 3, +**Cause.** The router in front of the machine uses an address-dependent +mapping that switches on after inbound traffic. While nothing has come in on +an external port P, outgoing flows from P keep their number. Once any packet +from outside arrives at P, every later outgoing flow from P to a different +address leaves with a rewritten source port. It happens whether or not the +packet reaches anything: ports the host's firewall drops are affected too. + +Every Mysterium session does exactly that. Before a session the node's port +check has an echo server send a packet in to the session port, so that port +is now marked. The node then answers the buyer from that port, the router +rewrites the answer's source port, and the buyer's client drops it, since it +came from a port the node never offered. The session is set up, never carries +a byte, and times out. Inbound works throughout, so every check that only +tests inbound passes. A wider `UDP_PORTS` range does not help: each session +marks its own port before it uses it. + +Some of these boxes (often an ISP fibre box with a built-in router) also +reserve outgoing UDP ports in pairs: when they map port P they hold P XOR 1 +(23000 and 23001, 23002 and 23003), and a later flow from the partner port +leaves with a random port. That is real but secondary. On its own it rewrote +only a few percent of ports, and almost none in a wide range. + +**Confirm it.** The decisive test is to send one packet in to a port from +another network, then ask a public STUN server which port it sees for a flow +out from that same port. It needs a second machine outside your home network +(a phone hotspot, a VPS, a friend's line) and a few minutes with the node +stopped, because the node holds every port in `UDP_PORTS`. CashPilot ships a +small script for the STUN half, with no dependencies beyond Python 3: [`scripts/stun_port_pair.py`](https://github.com/GeiserX/CashPilot/blob/main/scripts/stun_port_pair.py). -Run it in a throwaway container that shares the node's network, on the machine -running the node. The test only means something on a Linux host with Docker -Engine: Docker Desktop (macOS, Windows) puts its own NAT in front of every -container, which rewrites every port whatever the router does. +Run it on a Linux host with Docker Engine: Docker Desktop (macOS, Windows) puts +its own NAT in front of every container, which rewrites every port whatever +the router does. + +1. Pick two even ports in `UDP_PORTS`, say `23010` and `23020`, and stop the + node: `docker stop cashpilot-mysterium`. +2. From the outside machine, send one packet to `23020` on your public address + (and nothing to `23010`): + `echo x | nc -u -w1 23020`. +3. Within a minute, on the node's machine, run the script from both ports on + the host's network: + + ```bash + curl -fsSLo /tmp/stun_port_pair.py \ + https://raw.githubusercontent.com/GeiserX/CashPilot/main/scripts/stun_port_pair.py + docker run --rm --network host -v /tmp/stun_port_pair.py:/t.py:ro \ + python:3.15.2-alpine sh -c 'python /t.py --start 23010 --pairs 1; python /t.py --start 23020 --pairs 1' + ``` + +4. Start the node again: `docker start cashpilot-mysterium`. + +On a router with this mapping, `23020` comes back `REWRITTEN` and `23010` +comes back `kept`. On a working router both keep their number. If `23010` is +rewritten too, run steps 1 to 4 again with two other ports, since the pairing +effect below can hit one now and then. If every port comes back rewritten, +something rewrites every port; see below. + +Run without the inbound packet, the script finds only the secondary pairing +effect. It still works for that, inside the node's network namespace with the +node running: + +```bash +docker run --rm --network container:cashpilot-mysterium \ + -v /tmp/stun_port_pair.py:/t.py:ro python:3.15.2-alpine python /t.py +``` ```bash curl -fsSLo /tmp/stun_port_pair.py \ @@ -296,7 +335,7 @@ docker run --rm --network container:cashpilot-mysterium \ -v /tmp/stun_port_pair.py:/t.py:ro python:3.15.2-alpine python /t.py ``` -On a router that pairs ports, the even port of each pair comes back rewritten: +On a router that also pairs ports, the even port of each pair comes back rewritten: ``` 34101 -> 34101 kept @@ -325,8 +364,9 @@ keep it outside `UDP_PORTS`, whose ports the node holds. **Rule out the host's own NAT.** The container's packets also pass Docker's NAT on the host before they reach the router. That NAT keeps the source port unless two flows clash on it, which is rare, but then it picks another one and -the script reports `REWRITTEN` with a router that is fine. A pairing router -rewrites some port every run, a clash does not repeat, so run the script twice. +the script reports `REWRITTEN` with a router that is fine. The router's +rewrite repeats, a clash does not, so run the script twice. (The decisive test +above runs on the host's network and does not pass Docker's NAT at all.) To see it directly, look at the host's connection table within a minute of a run (as root on the host, with the `conntrack` tool installed): @@ -339,30 +379,28 @@ The second half of the line is the answer as the host expects it. When its the rewrite happened past it, at the router. When it differs, the host's NAT changed it, and the test says nothing about the router. -**Fix.** In the order we would try them: +**Fix.** A wider `UDP_PORTS` range does not help on this kind of router (see +*Cause*). In the order we would try them: -1. **Turn off the router's SIP ALG and, if you do not use it, its own VoIP or - phone service.** Both rewrite UDP flows. Look under NAT, ALG, VoIP or - Telephony in the router's admin page. Some ISP boxes hide the setting; the - ISP's support can usually change it. Cost: one router setting. -2. **Look for a setting that keeps ports.** Some routers call it port - preservation, endpoint-independent mapping, "full cone" NAT or NAT type 1. - Turn it on if it is there. Cost: one router setting. -3. **Bridge mode with your own router.** Put the ISP box in bridge mode (some +1. **Bridge mode with your own router.** Put the ISP box in bridge mode (some ISPs call it ONT mode or "router off") and do NAT on a router of your own - that keeps source ports; most Linux-based routers and OpenWrt do. Then - forward `UDP_PORTS` on your router instead. Cost: the whole house goes - offline for a few minutes, and it may need the ISP's help. -4. **A much wider `UDP_PORTS` range.** Fewer collisions, never none: the - sessions that land on a reserved partner still fail. CashPilot caps the - range at 1,000 ports and it must stay below 32768 (for example - `23000:23999`). Cost: one redeploy and a router forward edit, but each - published port takes about 2.5 MB of memory in Docker's port proxy, so - 1,000 ports take about 2.5 GB, and the range must stay free of other - programs (see *Port forwarding*). That memory, not the disruption, is why - this comes last. - -Run the script again after each change. Once every port keeps its number, + that keeps source ports and maps independently of the endpoint (what is + often called endpoint-independent mapping or "full cone" NAT); most + Linux-based routers and OpenWrt do. Then forward `UDP_PORTS` on your router + instead. If the ISP box itself has a setting by one of those names, turning + it on may be enough. Cost: the whole house goes offline for a few minutes, + and it may need the ISP's help. +2. **Untested: turn off the node's port check.** Mysterium's node has a hidden + flag, `--port-check-servers`. Set empty, the node skips the check whose + inbound packet marks the port, and falls back to hole punching. We have not + tried it, and many buyers fail at hole punching. It only removes the node's + own packet: a port scanner, or a buyer whose first packet reaches the port + before the node answers, marks the port all the same. CashPilot runs the + node with a fixed command, so this means running the node by hand, and a + redeploy from CashPilot drops the flag. + +Run the decisive test again after each change. Once a port that got an inbound +packet keeps its number, Mysterium's monitoring re-scores the node within a few hours, the next sessions carry data, and the **Needs fixing** item clears by itself. diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py index fa1fdd66..212ac77f 100644 --- a/scripts/stun_port_pair.py +++ b/scripts/stun_port_pair.py @@ -3,17 +3,21 @@ A Mysterium node advertises the UDP ports it listens on and expects buyers' packets to reach it, and its answers to leave, on those same ports. Some -routers keep a port's number only for some ports: a few fibre boxes reserve -ports in pairs (P and P XOR 1), so once one of a pair is in use the other -leaves with a random number. The node's own reachability check still passes, -because inbound traffic works; the sessions fail. +routers switch a port to an address-dependent mapping once any packet from +outside has arrived on it: from then on, a flow out of that port to another +address leaves with a rewritten source port. Every session starts with such a +packet (the node's own port check), so the node's answers are rewritten and +buyers drop them, while every inbound check passes. Some of these routers also +reserve ports in pairs (P and P XOR 1), a secondary effect. This sends a STUN binding request from pairs of neighbouring source ports and prints the port the internet saw for each. Every port should come back with -its own number. Run it in the node's network namespace (docs/guides/mysterium.md, -"Routers that rewrite UDP source ports"), on a Linux host with Docker Engine -(Docker Desktop's own NAT rewrites every port), with no other dependency than -Python 3. From the root of a CashPilot checkout: +its own number. On its own it finds the pairing effect. The decisive test +needs one packet sent in to a port from another network first, then this +script run from that port on the host's network; docs/guides/mysterium.md, +"Routers that rewrite UDP source ports", gives the steps. Run it on a Linux +host with Docker Engine (Docker Desktop's own NAT rewrites every port), with +no other dependency than Python 3. From the root of a CashPilot checkout: docker run --rm --network container:cashpilot-mysterium \\ -v "$PWD/scripts/stun_port_pair.py:/t.py:ro" python:3.15.2-alpine python /t.py @@ -183,10 +187,11 @@ def main() -> int: if rewritten: print( f"\n{rewritten} of {answered} ports left with a different number while others kept " - "theirs. The router rewrites some UDP source ports (some fibre boxes reserve ports in " - "pairs), and a Mysterium node behind it fails its sessions. Run it again: a pairing " - "router rewrites some port every time, while a rare clash in this machine's own NAT " - "does not repeat (the guide shows how to check the host)." + "theirs. If a packet from outside reached those ports first, the router rewrites the " + "source port of later flows from a port that got inbound traffic, and a Mysterium " + "node behind it fails its sessions. If nothing came in first, the router reserves " + "ports in pairs, or this machine's own NAT clashed once: run it again, a clash does " + "not repeat (the guide shows how to check the host and the decisive test)." ) return 1 if complete < args.pairs: diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index 4e007901..ce4a4613 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -52,10 +52,13 @@ docker: The UDP ports the node uses for VPN sessions, as start:end. Forward this same range on your router. Each session takes about two ports, so the default 30 carry about 15 sessions at once, more than a home node gets. - Every published port costs about 2.5 MB of memory in Docker's port - proxy. On a router that reserves UDP ports in pairs, a narrow range - makes sessions fail: see "Routers that rewrite UDP source ports" in - the Mysterium guide. Keep it below 32768: ports + A wider range fixes nothing and costs more: every published port + slows the node's start and removal (300 ports take about 12 s to + start), past about 350 a deploy runs over the socket proxy's time + limit and fails, and with Docker's default userland proxy each port + also takes about 2.5 MB of memory. Sessions that all fail are a + router problem, not too few ports: see "Routers that rewrite UDP + source ports" in the Mysterium guide. Keep it below 32768: ports 32768-60999 are Linux's ephemeral range, where any program on the host can hold one for a moment, and one taken port fails the node's start. A node that already has a range keeps it. @@ -216,8 +219,9 @@ docker: /dev/net/tun and SETUID/SETGID, which fail it the same way: https://geiserx.github.io/CashPilot/guides/mysterium/#running-but-not-earning-monitoring-failed-quality-0 With those in place, a common cause is the router in front of - ${WORKER_NAME} rewriting the UDP source port of some of the node's - connections. Run the two-port test in the guide: + ${WORKER_NAME} rewriting the UDP source port of the node's answers + once a packet from outside has reached that port. See the test in + the guide: https://geiserx.github.io/CashPilot/guides/mysterium/#routers-that-rewrite-udp-source-ports # Each item is one session object (they hold no nested objects); a bad # one lasted 40 to 89 s and moved no byte either way. Five in a row: a @@ -231,11 +235,11 @@ docker: The last five VPN sessions of the node on ${WORKER_NAME} each ended after about a minute having moved no data, so it earns nothing while it looks online. The likely cause is the router in - front of ${WORKER_NAME}: it rewrites the UDP source port of some of - the node's connections (some fibre boxes reserve ports in pairs, and - in a narrow forwarded range nearly every session hits one), so - buyers drop the node's answers. Run the two-port test and see the - fixes in the guide: + front of ${WORKER_NAME}: once a packet from outside reaches a port, + it rewrites the source port of the node's later answers from that + port, and every session starts with such a packet (the node's own + port check), so buyers drop the node's answers. A wider port range + does not help. See the test and the fixes in the guide: https://geiserx.github.io/CashPilot/guides/mysterium/#routers-that-rewrite-udp-source-ports This clears once a session carries data. diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index 3ca3fd71..057b48e1 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -1,7 +1,8 @@ """A Mysterium node behind a router that rewrites UDP source ports is flagged, not shown healthy. -Some routers change the source port of part of a node's outgoing UDP flows (a -fibre box that reserves ports in pairs, a SIP ALG). Inbound still works, so the +Some routers rewrite the source port of a node's answers from a port that has +had a packet in from outside, and every session starts with one (the node's +own port check). Inbound still works, so the node's own port check passes and its log says "Method:manual Success:true", but buyers drop its answers: every session ends after about a minute having carried nothing. Two nodes sat like that for ten days with nothing on the From e50d4e1eb749cef96375b8eb6c9daec6247d78d6 Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 19:33:19 +0100 Subject: [PATCH 8/9] fix(mysterium): keep what a probe finished, give every service a turn, and drop the failed workaround A command cut short by its timeout now keeps the checks whose marker made it out, and the sessions marker comes after its data, so a partial read never passes for a healthy one. The next batch starts with the first service the last one did not reach, and listing the copies is bounded by the batch's remaining time, so the rows already read still reach the UI. The UI keeps a retained verdict only for the probe definition it was read against. The STUN test gives each try its own deadline, keeps one pair of sockets open at a time, exits 5 when it cannot open one, and no longer says a VPN rules out a forward. The guide stops the node from CashPilot for the decisive test, and reports that switching the node to hole punching was tried on an affected node and did not help. --- app/health_probe.py | 79 ++++++-- app/main.py | 21 +- .../casaos/CashPilot/docker-compose.yml | 6 +- .../runtipi/cashpilot/docker-compose.yml | 6 +- docker-compose.build.yml | 6 +- docker-compose.fleet.yml | 6 +- docker-compose.worker.yml | 6 +- docker-compose.yml | 6 +- docs/guides/mysterium.md | 35 ++-- scripts/stun_port_pair.py | 52 +++-- services/bandwidth/mysterium.yml | 7 +- tests/test_mysterium_health_probe.py | 189 +++++++++++++++++- 12 files changed, 331 insertions(+), 88 deletions(-) diff --git a/app/health_probe.py b/app/health_probe.py index c728ff06..4b825095 100644 --- a/app/health_probe.py +++ b/app/health_probe.py @@ -51,6 +51,7 @@ import concurrent.futures import contextlib +import functools import hashlib import json import logging @@ -77,6 +78,9 @@ #: Per service, the copy the next read_all starts with: the first one the last #: call did not reach, so a slow copy cannot keep the later ones unread. _resume: dict[str, int] = {} +#: The service the next read_all starts with: the first one the last call did +#: not finish, so a slow service cannot keep the later ones unread. +_resume_service: str | None = None def _min_matches(check: dict[str, Any]) -> int | None: @@ -163,9 +167,9 @@ def unanswered(output: bytes | str | None, spec: dict[str, Any]) -> list[int]: return [i for i, c in enumerate(spec["checks"]) if c.get("answered") and not re.search(c["answered"], text)] -def judge(output: bytes | str | None, spec: dict[str, Any]) -> list[int]: +def judge(output: bytes | str | None, spec: dict[str, Any], unread: list[int] | None = None) -> list[int]: """The indexes of the checks that hold on the command's output (unread ones never do).""" - unread = set(unanswered(output, spec)) + unread = set(unanswered(output, spec) if unread is None else unread) return [i for i, check in enumerate(spec["checks"]) if i not in unread and holds(output, check)] @@ -244,12 +248,15 @@ def _read_one(client: Any, container_id: str, spec: dict[str, Any]) -> dict[str, output = _read_stream(sock, deadline) finally: _close_exec_socket(sock) - if api.exec_inspect(exec_id).get("ExitCode") != 0: - return None unread = unanswered(output, spec) + if api.exec_inspect(exec_id).get("ExitCode") != 0: + # The command failed or ran out of time part way. A check whose marker + # made it out was read in full (the marker comes after its data); a + # check without a marker cannot tell, so it counts as unread. + unread = sorted({*unread, *(i for i, c in enumerate(spec["checks"]) if not c.get("answered"))}) if len(unread) == len(spec["checks"]): return None - return {"hits": judge(output, spec), "unread": unread} + return {"hits": judge(output, spec, unread), "unread": unread} def _read_error(exc: Exception, slug: str) -> str: @@ -275,26 +282,48 @@ def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: ``hits``, the indexes of the checks that hold, and ``unread``, those it could not judge; ``error`` when it did not work at all: an unread node is no verdict, never a healthy one. Listing the copies and reading them both - fit in BATCH_BUDGET: copies not reached are reported unread, so the ones - read in time still count, and the next call starts with the first copy - this one did not reach, so every copy gets its turn. + fit in BATCH_BUDGET: what is not reached is reported unread or not listed, + and the rows already read still go back. The next call starts with the + first service, and within it the first copy, this one did not reach, so a + slow service or copy cannot keep the others unread. """ # Imported here: the UI imports this module for nothing but the catalog # check, and has no Docker. from app import orchestrator + global _resume_service rows: list[dict[str, Any]] = [] deadline = time.monotonic() + BATCH_BUDGET client = None - for slug, spec in sorted(probes(services).items()): - if time.monotonic() >= deadline: + declared = sorted(probes(services).items()) + names = [slug for slug, _ in declared] + if _resume_service in names: + k = names.index(_resume_service) + declared = declared[k:] + declared[:k] + _resume_service = None + + def _unreached(slug: str) -> None: + """Remember the first service this call did not finish.""" + global _resume_service + if _resume_service is None: + _resume_service = slug + + for slug, spec in declared: + left = min(READ_TIMEOUT, deadline - time.monotonic()) + if left <= 0 or not _slots.acquire(blocking=False): # Not listed: the UI keeps these copies' last verdicts. + _unreached(slug) break try: if client is None: client = _client() - # On this module's client, so a stalled listing ends in READ_TIMEOUT. - copies = orchestrator.service_instances(slug, client=client) + # On the pool and this module's client, so a stalled listing ends + # within the batch's remaining time. + copies = _run_in_pool(functools.partial(orchestrator.service_instances, slug, client=client), left) + except TimeoutError: + logger.warning("Listing %s containers for the health probe ran out of time", slug) + _unreached(slug) + break except Exception as exc: # noqa: BLE001 - one service never fails the rest logger.warning("Could not list %s containers for the health probe: %s", slug, exc) continue @@ -317,22 +346,32 @@ def read_all(services: list[dict[str, Any]]) -> list[dict[str, Any]]: row.update(_read_in_pool(client, running[i].id, spec, left, slug)) if row.get("error") in ("not reached in time", "busy with earlier reads"): _resume.setdefault(slug, i) + _unreached(slug) # A read that timed out may still be using the client; it is dropped, not # closed, so that read ends by its own deadline. return rows +def _run_in_pool(fn: Any, left: float) -> Any: + """Run ``fn`` on the pool in the slot already taken, waiting up to ``left`` seconds. + + Raises TimeoutError when it takes longer; the work then ends by its own + timeout and gives the slot back. + """ + try: + future = _pool.submit(fn) + except BaseException: + _slots.release() + raise + future.add_done_callback(lambda _f: _slots.release()) + return future.result(timeout=left) + + def _read_in_pool(client: Any, container_id: str, spec: dict[str, Any], left: float, slug: str) -> dict[str, Any]: """Run one read on the pool, holding the slot already taken, and wait up to ``left`` seconds.""" try: - try: - future = _pool.submit(_read_one, client, container_id, spec) - except BaseException: - _slots.release() - raise - future.add_done_callback(lambda _f: _slots.release()) - read = future.result(timeout=left) - except concurrent.futures.TimeoutError: + read = _run_in_pool(functools.partial(_read_one, client, container_id, spec), left) + except TimeoutError: # The read ends by its own deadline and frees its slot then. return {"error": "timed out"} except Exception as exc: # noqa: BLE001 diff --git a/app/main.py b/app/main.py index 2cbe3dad..d5e828b1 100644 --- a/app/main.py +++ b/app/main.py @@ -1944,7 +1944,10 @@ async def _check_stale_workers() -> None: #: last verdict outlives an unread check by at most PROBE_STALE_SECONDS; after #: that it is dropped, and a copy the worker keeps reporting as unreadable gets #: a hint saying so instead. -_probe_state: dict[tuple[str, int, int], dict[int, tuple[bool, float]]] = {} +#: Kept with the fingerprint of the probe definition it was read against +#: (health_probe.fingerprint): after a catalog change an old index could name +#: another check, so state from another definition is dropped, not reused. +_probe_state: dict[tuple[str, int, int], tuple[str, dict[int, tuple[bool, float]]]] = {} PROBE_STALE_SECONDS = 24 * 3600 @@ -2083,7 +2086,7 @@ async def _sweep_windowed_signals() -> None: hints: dict[tuple[str, int, int], list[str]] = {} signal_hints: dict[tuple[str, int, int], list[str]] = {} probe_hints: dict[tuple[str, int, int], list[str]] = {} - probe_state: dict[tuple[str, int, int], dict[int, tuple[bool, float]]] = {} + probe_state: dict[tuple[str, int, int], tuple[str, dict[int, tuple[bool, float]]]] = {} probe_rows: dict[int, list[dict[str, Any]] | None] = {} workers: dict[int, dict[str, Any] | None] = {} for c in containers: @@ -2141,6 +2144,10 @@ def _keep(k: tuple[str, int, int] = key) -> None: signal_hints[key] = logged probed: list[str] = [] if spec is not None: + definition = health_probe.fingerprint(spec) + kept_definition, kept_state = _probe_state.get(key, (None, {})) + if kept_definition != definition: + kept_state = {} try: rows = await _health_probe_rows(wid, probe_rows) mine = [ @@ -2148,7 +2155,7 @@ def _keep(k: tuple[str, int, int] = key) -> None: for r in rows or [] if isinstance(r, dict) and r.get("slug") == slug and r.get("instance") == instance ] - state, held, unreadable = _probe_step(spec, mine, _probe_state.get(key, {}), time.time()) + state, held, unreadable = _probe_step(spec, mine, kept_state, time.time()) probed = [await _render_signal_means(spec["checks"][i], slug, workers[wid]) for i in held] if unreadable: worker_name = str((workers[wid] or {}).get("name") or "this machine") @@ -2163,12 +2170,12 @@ def _keep(k: tuple[str, int, int] = key) -> None: f"({unreadable}), so part of what it checks on the node is unchecked.{advice}" ) if state: - probe_state[key] = state + probe_state[key] = (definition, state) except Exception as exc: logger.warning("Health probe check failed for %s on worker %s: %s", slug, wid, exc) - probed = _probe_hints.get(key, []) - if key in _probe_state: - probe_state[key] = _probe_state[key] + if kept_state: + probed = _probe_hints.get(key, []) + probe_state[key] = (definition, kept_state) if probed: probe_hints[key] = probed if logged or probed: diff --git a/contrib/app-stores/casaos/CashPilot/docker-compose.yml b/contrib/app-stores/casaos/CashPilot/docker-compose.yml index 885ce096..7d4fadca 100644 --- a/contrib/app-stores/casaos/CashPilot/docker-compose.yml +++ b/contrib/app-stores/casaos/CashPilot/docker-compose.yml @@ -125,7 +125,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -170,7 +170,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 # The folders the proxy allows, so the worker can say what to set before # the proxy refuses a host-folder bind. Empty means none. - CASHPILOT_COMPOSE_DIR= @@ -302,7 +302,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$$$m\"\nfi\nif s=$$$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$$$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$$$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$$$0, /\"duration\":[0-9]+/)) d = substr($$$$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$$$0\n }' | sort -rn | head -5\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$$$m\"\nfi\nif s=$$$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$$$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$$$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$$$0, /\"duration\":[0-9]+/)) d = substr($$$$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$$$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$$$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$$$T iptables-legacy -t nat -S MYST 2>/dev/null; $$$$T iptables -t nat -S MYST 2>/dev/null; else case \"$$$$($$$$T iptables -V 2>/dev/null)\" in *nf_tables*) $$$$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/contrib/app-stores/runtipi/cashpilot/docker-compose.yml b/contrib/app-stores/runtipi/cashpilot/docker-compose.yml index 4b691069..81d6a17c 100644 --- a/contrib/app-stores/runtipi/cashpilot/docker-compose.yml +++ b/contrib/app-stores/runtipi/cashpilot/docker-compose.yml @@ -90,7 +90,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -121,7 +121,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 # The values the proxy gets, so the worker can say what to set before the # proxy refuses a host-folder bind. - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -226,7 +226,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.build.yml b/docker-compose.build.yml index a4425aa8..0161bf7b 100644 --- a/docker-compose.build.yml +++ b/docker-compose.build.yml @@ -134,7 +134,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -168,7 +168,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -287,7 +287,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.fleet.yml b/docker-compose.fleet.yml index b250ecce..6df25a5b 100644 --- a/docker-compose.fleet.yml +++ b/docker-compose.fleet.yml @@ -141,7 +141,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -225,7 +225,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -352,7 +352,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.worker.yml b/docker-compose.worker.yml index 4644d2a7..12b9993c 100644 --- a/docker-compose.worker.yml +++ b/docker-compose.worker.yml @@ -93,7 +93,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -129,7 +129,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -245,7 +245,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.yml b/docker-compose.yml index 0bf6fba4..7d8f9c1c 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -156,7 +156,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -233,7 +233,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=f10d7a78647d921c + - CASHPILOT_PROXY_POLICY=54821ddd893d3689 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -356,7 +356,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"sessions read:\"\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docs/guides/mysterium.md b/docs/guides/mysterium.md index 3da2cf9f..a43494fc 100644 --- a/docs/guides/mysterium.md +++ b/docs/guides/mysterium.md @@ -297,7 +297,9 @@ its own NAT in front of every container, which rewrites every port whatever the router does. 1. Pick two even ports in `UDP_PORTS`, say `23010` and `23020`, and stop the - node: `docker stop cashpilot-mysterium`. + node with **Stop** on CashPilot's dashboard. A plain `docker stop` is not + recorded as a stop you meant, so the worker can start the node again in + the middle of the test. 2. From the outside machine, send one packet to `23020` on your public address (and nothing to `23010`): `echo x | nc -u -w1 23020`. @@ -311,7 +313,7 @@ the router does. python:3.15.2-alpine sh -c 'python /t.py --start 23010 --pairs 1; python /t.py --start 23020 --pairs 1' ``` -4. Start the node again: `docker start cashpilot-mysterium`. +4. Start the node again with **Start** on the dashboard. On a router with this mapping, `23020` comes back `REWRITTEN` and `23010` comes back `kept`. On a working router both keep their number. If `23010` is @@ -349,14 +351,15 @@ comes back rewritten, the script says so separately: that is a NAT which rewrites every port (a symmetric NAT, carrier-grade NAT, a VPN, or Docker Desktop's own NAT). The test only measures ports with no forward, so it does not say whether your forward of `UDP_PORTS` reaches the node: the node's own -port check does, and behind carrier-grade NAT or a VPN no forward reaches it. +port check does. Behind carrier-grade NAT no forward reaches it; behind a VPN +only one whose provider forwards UDP ports to you. The script exits 0 when every pair was tested and every port kept its number, 1 when one was rewritten, 2 when no STUN server answered, and 3 when nothing was rewritten but some pair could not be tested in full (a port that would not bind or got no answer), so the result says nothing about pairing; run it again with another `--start`. It exits 4 when `--start` and `--pairs` do not give real -ports. It tries Google's STUN server first and Cloudflare's when +ports, and 5 when the machine would not open a socket. It tries Google's STUN server first and Cloudflare's when Google does not answer. It only sends a few packets to a public STUN server; it does not touch the node. `--start` picks the first port to test (default 34100); keep it outside `UDP_PORTS`, whose ports the node holds. @@ -380,7 +383,7 @@ the rewrite happened past it, at the router. When it differs, the host's NAT changed it, and the test says nothing about the router. **Fix.** A wider `UDP_PORTS` range does not help on this kind of router (see -*Cause*). In the order we would try them: +*Cause*). What works: 1. **Bridge mode with your own router.** Put the ISP box in bridge mode (some ISPs call it ONT mode or "router off") and do NAT on a router of your own @@ -390,16 +393,18 @@ changed it, and the test says nothing about the router. instead. If the ISP box itself has a setting by one of those names, turning it on may be enough. Cost: the whole house goes offline for a few minutes, and it may need the ISP's help. -2. **Untested: turn off the node's port check.** Mysterium's node has a hidden - flag, `--port-check-servers`. Set empty, the node skips the check whose - inbound packet marks the port, and falls back to hole punching. We have not - tried it, and many buyers fail at hole punching. It only removes the node's - own packet: a port scanner, or a buyer whose first packet reaches the port - before the node answers, marks the port all the same. CashPilot runs the - node with a fixed command, so this means running the node by hand, and a - redeploy from CashPilot drops the flag. - -Run the decisive test again after each change. Once a port that got an inbound + +Tried without success: skipping the node's port check. With +`traversal = "holepunching"` in the node's `config-mainnet.toml`, the node +skips the manual method and its port check, and falls back to hole punching. +On an affected node it ran for 90 minutes: every config exchange logged +`Method:holepunching Success:true`, yet no buyer ever acknowledged and no +session started, and monitoring stayed failed. The attempts stopped after the +node's config reply over NATS, before any packet between the peers, so part of +the cause may be on the buyer's side; it is not fully explained yet. We do not +recommend it. + +Run the decisive test again after the change. Once a port that got an inbound packet keeps its number, Mysterium's monitoring re-scores the node within a few hours, the next sessions carry data, and the **Needs fixing** item clears by itself. diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py index 212ac77f..77df1085 100644 --- a/scripts/stun_port_pair.py +++ b/scripts/stun_port_pair.py @@ -28,7 +28,8 @@ 1 when one was rewritten, 2 when no STUN server answered, 3 when no port was rewritten but some pair could not be tested in full (a port that did not bind or got no answer), so the pairing was not checked: run it again with another ---start, and 4 when --start and --pairs do not give real ports (1 to 65535). A +--start, 4 when --start and --pairs do not give real ports (1 to 65535), and 5 +when the machine would not open a socket, so nothing was tested. A rewritten port is reported as a pairing router when some ports kept their number, and as a NAT that rewrites every port when none did. Read-only: it sends a few UDP packets to a public STUN @@ -42,6 +43,7 @@ import socket import struct import sys +import time from typing import NoReturn MAGIC = 0x2112A442 @@ -68,17 +70,21 @@ def _mapped_port(data: bytes, txid: bytes) -> int | None: return plain -def probe(sock: socket.socket, server: tuple[str, int], tries: int = 3) -> int | None: +def probe(sock: socket.socket, server: tuple[str, int], tries: int = 3, wait: float = 2) -> int | None: """The source port the STUN server saw for packets from ``sock``; None for no answer. A network error (no route, the packet refused) is no answer too, never a - traceback, which would exit 1 and read as a rewritten port. + traceback, which would exit 1 and read as a rewritten port. Each try ends + ``wait`` seconds after its request whatever arrives meanwhile: datagrams + that are not the answer cannot keep it waiting. """ for _ in range(tries): txid = os.urandom(12) + deadline = time.monotonic() + wait try: sock.sendto(struct.pack("!HHI", 0x0001, 0, MAGIC) + txid, server) - while True: + while (left := deadline - time.monotonic()) > 0: + sock.settimeout(left) data, _ = sock.recvfrom(2048) port = _mapped_port(data, txid) if port is not None: @@ -101,6 +107,10 @@ def _servers() -> list[tuple[str, int]]: return found +class NoSocket(Exception): + """This machine would not give the test a socket (out of file descriptors, or no permission).""" + + def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int]: """Test ``pairs`` neighbouring pairs from ``start`` against one server. @@ -108,16 +118,19 @@ def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int] """ first = start & ~1 rewritten = answered = complete = 0 - socks = [] - try: - for n in range(pairs): - even = first + 2 * n - both = True + for n in range(pairs): + even = first + 2 * n + both = True + # Only one pair is open at a time, so --pairs never runs out of sockets. + socks = [] + try: # The odd port first, then its even partner while the first is still # open: a router that reserves pairs gives the second one away. for port in (even + 1, even): - sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) - sock.settimeout(2) + try: + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) + except OSError as exc: + raise NoSocket(exc.strerror or str(exc)) from exc socks.append(sock) try: # A client socket on a chosen source port, so the test knows @@ -136,10 +149,10 @@ def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int] kept = seen == port rewritten += not kept print(f"{port} -> {seen} {'kept' if kept else 'REWRITTEN'}") - complete += both - finally: - for sock in socks: - sock.close() + finally: + for sock in socks: + sock.close() + complete += both return answered, rewritten, complete @@ -167,7 +180,11 @@ def main() -> int: return 2 answered = rewritten = complete = 0 for server in servers: - answered, rewritten, complete = run(server, args.start, args.pairs) + try: + answered, rewritten, complete = run(server, args.start, args.pairs) + except NoSocket as exc: + print(f"Could not open a UDP socket ({exc}): nothing was tested.") + return 5 if answered: break print(f"No answer from {server[0]}:{server[1]}.") @@ -180,8 +197,7 @@ def main() -> int: "every UDP source port: a symmetric NAT, carrier-grade NAT, a VPN, or Docker Desktop's " "own NAT (run this on a Linux host with Docker Engine, not Docker Desktop). This " "only measures ports with no forward: whether a forward of UDP_PORTS reaches the " - "node is a separate check (the node's own port check, and none works behind " - "carrier-grade NAT or a VPN)." + "node is a separate check, and the node's own port check is the one to read." ) return 1 if rewritten: diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index ce4a4613..64fa45c6 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -181,7 +181,8 @@ docker: # only when it worked ("answered" below): a slow or failing monitoring status # (the node asks Mysterium's quality oracle for it) never costs the sessions # verdict, and a failed sessions read never costs the monitoring one; a check - # whose read failed keeps its last verdict. -Y off keeps an inherited + # whose read failed keeps its last verdict. Each marker comes after its + # data, so a run that timeout cuts short never passes for a full read. -Y off keeps an inherited # http_proxy away from the loopback reads. timeout 12 bounds the whole run # inside the 15 s the worker waits. Seen live # (Nov 2026) on two nodes behind routers that rewrite the UDP source port of @@ -201,13 +202,13 @@ docker: echo "monitoring read: $m" fi if s=$(wget -qO- -Y off -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100"); then - echo "sessions read:" echo "$s" | sed 's/},{/}\n{/g' | awk ' match($0, /"created_at":"[^"]+"/) { t = substr($0, RSTART + 14, 19); gsub(/[-T:]/, " ", t) d = 0; if (match($0, /"duration":[0-9]+/)) d = substr($0, RSTART + 11, RLENGTH - 11) print mktime(t) + d, $0 }' | sort -rn | head -5 + echo "sessions read: all" fi checks: - pattern: 'monitoring read: \{"status":"failed"\}' @@ -230,7 +231,7 @@ docker: - items: '\{"id":[^{}]*"direction":"Provided"[^{}]*\}' pattern: '"duration":[4-8][0-9],"bytes_received":0,"bytes_sent":0,' min_matches: 5 - answered: 'sessions read:' + answered: 'sessions read: all' means: >- The last five VPN sessions of the node on ${WORKER_NAME} each ended after about a minute having moved no data, so it earns diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index 057b48e1..2f5be0d4 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -15,6 +15,7 @@ from __future__ import annotations import asyncio +import copy import importlib.util import json import os @@ -63,17 +64,17 @@ def _session(n: int, duration: int, received: int, sent: int) -> dict: def _answer(status: str | None, sessions: list[dict] | None) -> str: - """What the catalog command prints: each read that worked, behind its marker. + """What the catalog command prints: each read that worked, with its marker. The sessions come one per line behind their end time, as the command's awk - prints them; None leaves a read out, as when it failed. + prints them, then their marker; None leaves a read out, as when it failed. """ out = [] if status is not None: out.append("monitoring read: " + json.dumps({"status": status}, separators=(",", ":"))) if sessions is not None: - out.append("sessions read:") out += [f"{1793806663 - i} " + json.dumps(x, separators=(",", ":")) for i, x in enumerate(sessions)] + out.append("sessions read: all") return "\n".join(out) @@ -199,7 +200,8 @@ def test_the_session_read_has_no_date_window_and_does_not_hang_on_the_status_rea assert "date_from" not in script and "date " not in script status, sessions = script.split("\nfi\n", 1) assert "monitoring-status" in status and status.startswith("if ") and sessions.startswith("if ") - assert [c.get("answered") for c in _spec()["checks"]] == ["monitoring read: ", "sessions read:"] + assert sessions.rstrip().endswith('echo "sessions read: all"\nfi'), "the marker comes after the data" + assert [c.get("answered") for c in _spec()["checks"]] == ["monitoring read: ", "sessions read: all"] def test_one_failed_read_costs_only_its_own_checks(): @@ -235,18 +237,18 @@ def _awk_has_mktime() -> bool: def test_a_long_session_that_ended_last_is_judged_though_it_started_first(): """Runs the catalog's own sessions pipeline on a page in the API's order.""" script = _spec()["command"][-1] - pipeline = script[script.index('echo "$s" | ') + len('echo "$s" | ') : script.rindex("\nfi")] + pipeline = script[script.index('echo "$s" | ') + len('echo "$s" | ') : script.index("| head -5") + len("| head -5")] dead = [_session(i, 61, 0, 0) | {"created_at": f"2026-11-08T1{i // 6}:{i % 6}0:00Z"} for i in range(30)] long_good = _session(99, 40 * 3600, 900_000, 400_000) | {"created_at": "2026-11-07T00:00:00Z"} page = {"items": [*reversed(dead), long_good], "page": 1, "page_size": 100, "total_items": 31, "total_pages": 1} env = {**os.environ, "s": json.dumps(page, separators=(",", ":"))} out = subprocess.run(["sh", "-c", 'echo "$s" | ' + pipeline], capture_output=True, text=True, env=env, check=True) assert len(out.stdout.splitlines()) == 5 and "00000000-0000-4000-8000-000000000099" in out.stdout - assert health_probe.judge(_answer("success", None) + "\nsessions read:\n" + out.stdout, _spec()) == [] + assert health_probe.judge(_answer("success", None) + "\n" + out.stdout + "sessions read: all", _spec()) == [] dead_only = {**page, "items": list(reversed(dead))} env["s"] = json.dumps(dead_only, separators=(",", ":")) out = subprocess.run(["sh", "-c", 'echo "$s" | ' + pipeline], capture_output=True, text=True, env=env, check=True) - assert health_probe.judge("sessions read:\n" + out.stdout, _spec()) == [1] + assert health_probe.judge(out.stdout + "sessions read: all", _spec()) == [1] def test_the_monitoring_finding_sends_to_the_tun_check_first(): @@ -549,6 +551,88 @@ def test_a_probe_in_a_yaml_file_reaches_the_proxy_policy(tmp_path): assert command in socket_policy.catalog_commands(tmp_path) +def test_a_read_cut_short_keeps_the_checks_it_finished(): + """timeout ends the command during the sessions read: the monitoring verdict + already printed stands, and the unfinished sessions read counts as unread, + never as healthy.""" + cut = ("monitoring read: " + '{"status":"failed"}\n' + "1793806663 " + json.dumps(DEAD[0])).encode() + api = _Api({"cut": (124, cut), "nothing": (124, b"")}) + with ( + patch("app.orchestrator.service_instances", return_value=_containers("cut", "nothing")), + patch("app.orchestrator._instance_of", side_effect=[1, 2]), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + rows = health_probe.read_all([catalog.get_service("mysterium")]) + assert rows[0]["hits"] == [0] and rows[0]["unread"] == [1] + assert rows[1]["error"] == "the node did not answer" + + +def test_a_check_without_a_marker_is_unread_when_the_command_fails(): + spec = {"command": ["timeout", "5", "true"], "checks": [{"pattern": "bad", "means": "m"}]} + api = _Api({"x": (1, b"")}) + assert health_probe._read_one(MagicMock(api=api), "x", spec) is None + + +def _two_services(): + """Two services that declare the same probe, so a batch can run out between them.""" + spec = _spec() + return [{"slug": "aaa", "docker": {"health_probe": spec}}, {"slug": "bbb", "docker": {"health_probe": spec}}] + + +def test_the_next_batch_starts_with_the_service_this_one_did_not_reach(monkeypatch): + """A slow first service that eats the budget every time must not leave the next one unread.""" + api = _Api({"slow": None, "fast": (0, FAILING.encode())}) + listed = [] + + def _list(slug, client=None): + """aaa's only copy never answers; bbb's answers at once.""" + listed.append(slug) + return _containers("slow" if slug == "aaa" else "fast") + + monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0.5) + try: + with ( + patch("app.orchestrator.service_instances", side_effect=_list), + patch("app.orchestrator._instance_of", return_value=1), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + first = health_probe.read_all(_two_services()) + api.hang.set() + second = health_probe.read_all(_two_services()) + finally: + api.hang.set() + assert [r["slug"] for r in first] == ["aaa"] and listed[:1] == ["aaa"] + assert listed[1] == "bbb", "the service the first batch never reached goes first" + assert second[0]["slug"] == "bbb" and second[0]["hits"] == [0, 1] + + +def test_a_stalled_listing_ends_with_the_batch_and_keeps_the_rows_read(monkeypatch): + """The UI waits 60 s in all; a listing that hangs must not cost the rows already read.""" + release = threading.Event() + api = _Api({"fast": (0, FAILING.encode())}) + + def _list(slug, client=None): + """aaa lists at once; bbb's listing hangs.""" + if slug == "bbb": + release.wait(10) + return [] + return _containers("fast") + + monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0.5) + try: + with ( + patch("app.orchestrator.service_instances", side_effect=_list), + patch("app.orchestrator._instance_of", return_value=1), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + started = time.monotonic() + rows = health_probe.read_all(_two_services()) + took = time.monotonic() - started + finally: + release.set() + assert took < 2 and [r["slug"] for r in rows] == ["aaa"] and rows[0]["hits"] == [0, 1] + + def test_the_worker_endpoint_serves_the_rows(): """The worker endpoint returns what read_all reads.""" client = TestClient(worker_api.app) @@ -719,6 +803,19 @@ def test_an_unread_check_keeps_its_verdict_while_the_other_updates(): assert len(hints) == 2 +def test_a_verdict_kept_from_another_definition_is_dropped(): + """After a catalog change an old index could name another check: an unread + probe must not keep a verdict read against another definition.""" + _sweep([_row([1])]) + changed = copy.deepcopy(catalog.get_service("mysterium")) + changed["docker"]["health_probe"]["checks"].reverse() + with patch("app.main.catalog.get_service", return_value=changed): + hints, _ = _sweep( + [_row(error="timed out", definition=health_probe.fingerprint(changed["docker"]["health_probe"]))] + ) + assert hints == [], "the session verdict must not come back as the monitoring one" + + def test_a_check_unread_for_a_day_says_so(): """A check unread for a day is reported as unreadable.""" _sweep([_row([0, 1])]) @@ -812,6 +909,74 @@ def test_the_highest_real_pair_is_still_tested(monkeypatch): assert stun.main() == 0 +def test_stray_datagrams_cannot_keep_a_try_waiting(): + """Each try ends on its own deadline, whatever arrives meanwhile.""" + stun = _stun() + started = time.monotonic() + + class _Noisy: + """A socket that receives a datagram that is not the answer, again and again.""" + + def settimeout(self, value): + """Accept the timeout.""" + + def sendto(self, data, server): + """Send nothing.""" + + def recvfrom(self, size): + """Something that is not a STUN answer, at once, until the test gives up.""" + if time.monotonic() - started > 3: + raise RuntimeError("the try never ended") + return b"not stun", ("192.0.2.9", 1) + + assert stun.probe(_Noisy(), ("192.0.2.1", 3478), tries=2, wait=0.2) is None + assert time.monotonic() - started < 1.5 + + +def test_no_socket_is_its_own_status_and_pairs_close_as_they_go(monkeypatch): + """Running out of sockets is no rewrite (exit 5), and a long run keeps only one pair open.""" + stun = _stun() + real = socket.socket + + def _refuse(*a, **k): + """This machine is out of file descriptors.""" + raise OSError(24, "Too many open files") + + monkeypatch.setattr(stun, "_servers", lambda: [("192.0.2.1", 3478)]) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py"]) + monkeypatch.setattr(stun.socket, "socket", _refuse) + assert stun.main() == 5 + monkeypatch.setattr(stun.socket, "socket", real) + open_now = peak = 0 + + class _Counted: + """A UDP socket that counts how many are open at once.""" + + def __init__(self, *a, **k): + """Open one.""" + nonlocal open_now, peak + open_now += 1 + peak = max(peak, open_now) + self.port = 0 + + def settimeout(self, value): + """Accept the timeout.""" + + def bind(self, address): + """Remember the port.""" + self.port = address[1] + + def close(self): + """Close one.""" + nonlocal open_now + open_now -= 1 + + monkeypatch.setattr(stun.socket, "socket", _Counted) + monkeypatch.setattr(stun, "probe", lambda sock, server: sock.port) + assert stun.run(("192.0.2.1", 3478), 30000, 50) == (100, 0, 50) + assert peak == 2 and open_now == 0 + + def test_every_port_rewritten_makes_no_claim_about_a_forward(monkeypatch, capsys): """The test measures ports with no forward, so it says nothing about one.""" stun = _stun() @@ -821,3 +986,13 @@ def test_every_port_rewritten_makes_no_claim_about_a_forward(monkeypatch, capsys assert stun.main() == 1 out = capsys.readouterr().out assert "cannot work" not in out and "only measures ports with no forward" in out + assert "or a VPN" not in out, "some VPNs forward UDP ports" + + +def test_the_guide_stops_the_node_from_cashpilot_for_the_decisive_test(): + """A plain docker stop is not a stop the worker knows about; it can start the node mid-test.""" + guide = (Path(__file__).resolve().parents[1] / "docs" / "guides" / "mysterium.md").read_text() + section = guide[guide.index("**Confirm it.**") : guide.index("**Fix.**")] + assert "docker stop cashpilot" not in section and "docker start cashpilot" not in section + assert "**Stop**" in section and "**Start**" in section + assert "port-check-servers" not in guide and "Tried without success" in guide From d37259041c54982712b9dbadcdf82a245fbe5de9 Mon Sep 17 00:00:00 2001 From: GeiserX <9169332+GeiserX@users.noreply.github.com> Date: Mon, 9 Nov 2026 20:04:10 +0100 Subject: [PATCH 9/9] fix(mysterium): give a slot back when Docker is down, move past a stalled listing, and judge sessions only after a full sort A batch that could not make its Docker client kept the pool slot it had taken, so a few such batches left the probe unable to read anything. The client is now made on the pool in that slot. A listing that always stalls no longer keeps the services behind it from their turn. A sweep that could not reach the database or fold the probe rows kept the last probe hints with no check of the catalog's definition or of the one-day limit; both now apply on that path too. The sessions marker printed even when awk or sort failed, so an empty output read as a healthy node. It now needs the whole pipeline to work, while an empty session list still counts as read. The STUN script keeps a rewrite it already measured when the machine runs out of sockets. --- app/health_probe.py | 20 ++- app/main.py | 40 ++++- .../casaos/CashPilot/docker-compose.yml | 6 +- .../runtipi/cashpilot/docker-compose.yml | 6 +- docker-compose.build.yml | 6 +- docker-compose.fleet.yml | 6 +- docker-compose.worker.yml | 6 +- docker-compose.yml | 6 +- scripts/stun_port_pair.py | 23 ++- services/bandwidth/mysterium.yml | 13 +- tests/test_mysterium_health_probe.py | 151 +++++++++++++++++- 11 files changed, 237 insertions(+), 46 deletions(-) diff --git a/app/health_probe.py b/app/health_probe.py index 4b825095..56ad5f61 100644 --- a/app/health_probe.py +++ b/app/health_probe.py @@ -308,21 +308,29 @@ def _unreached(slug: str) -> None: if _resume_service is None: _resume_service = slug - for slug, spec in declared: + def _list(slug: str) -> Any: + """Make the client if there is none yet, then list ``slug``'s copies.""" + nonlocal client + if client is None: + client = _client() + return orchestrator.service_instances(slug, client=client) + + for n, (slug, spec) in enumerate(declared): left = min(READ_TIMEOUT, deadline - time.monotonic()) if left <= 0 or not _slots.acquire(blocking=False): # Not listed: the UI keeps these copies' last verdicts. _unreached(slug) break try: - if client is None: - client = _client() - # On the pool and this module's client, so a stalled listing ends + # Making the client and listing both run on the pool in the slot + # just taken, so a failure gives the slot back and a stall ends # within the batch's remaining time. - copies = _run_in_pool(functools.partial(orchestrator.service_instances, slug, client=client), left) + copies = _run_in_pool(functools.partial(_list, slug), left) except TimeoutError: logger.warning("Listing %s containers for the health probe ran out of time", slug) - _unreached(slug) + # The next call starts after this service, so one that always + # stalls cannot keep the ones behind it from ever being read. + _unreached(declared[(n + 1) % len(declared)][0]) break except Exception as exc: # noqa: BLE001 - one service never fails the rest logger.warning("Could not list %s containers for the health probe: %s", slug, exc) diff --git a/app/main.py b/app/main.py index d5e828b1..fe220b99 100644 --- a/app/main.py +++ b/app/main.py @@ -2071,6 +2071,26 @@ def _indexes(values: Any) -> set[int]: return state, held, f"{reason}, for {int((now - min(stale)) // 3600)} hours" +def _kept_probe( + key: tuple[str, int, int], spec: dict[str, Any] | None, now: float +) -> tuple[tuple[str, dict[int, tuple[bool, float]]] | None, list[str]]: + """A copy's last probe state and hints, for a sweep that could not redo them. + + Nothing when the catalog's probe changed since: the old indexes may point + at other checks. The state stays while its timestamps age; its hints are + dropped once a check they show has gone PROBE_STALE_SECONDS unread, so a + failing sweep cannot keep showing a verdict longer than a working one. + """ + if spec is None: + return None, [] + definition, state = _probe_state.get(key, (None, {})) + if definition != health_probe.fingerprint(spec) or not state: + return None, [] + if any(hit and now - since >= PROBE_STALE_SECONDS for hit, since in state.values()): + return (definition, state), [] + return (definition, state), _probe_hints.get(key, []) + + async def _sweep_windowed_signals() -> None: """Re-read every running copy's windowed log signals and health probe. @@ -2103,11 +2123,15 @@ async def _sweep_windowed_signals() -> None: instance = int(c.get("instance") or 1) key = (slug, wid, instance) - def _keep(k: tuple[str, int, int] = key) -> None: - """Carry this copy's last verdicts over unchanged.""" - for new, old in ((signal_hints, _signal_hints), (probe_hints, _probe_hints), (probe_state, _probe_state)): - if k in old: - new[k] = old[k] + def _keep(k: tuple[str, int, int] = key, probe_spec: dict[str, Any] | None = spec) -> None: + """Carry this copy's last log verdicts over, and its probe verdicts while they still apply.""" + if k in _signal_hints: + signal_hints[k] = _signal_hints[k] + kept_probe, kept_hints = _kept_probe(k, probe_spec, time.time()) + if kept_probe is not None: + probe_state[k] = kept_probe + if kept_hints: + probe_hints[k] = kept_hints try: if wid not in workers: @@ -2173,9 +2197,9 @@ def _keep(k: tuple[str, int, int] = key) -> None: probe_state[key] = (definition, state) except Exception as exc: logger.warning("Health probe check failed for %s on worker %s: %s", slug, wid, exc) - if kept_state: - probed = _probe_hints.get(key, []) - probe_state[key] = (definition, kept_state) + kept_probe, probed = _kept_probe(key, spec, time.time()) + if kept_probe is not None: + probe_state[key] = kept_probe if probed: probe_hints[key] = probed if logged or probed: diff --git a/contrib/app-stores/casaos/CashPilot/docker-compose.yml b/contrib/app-stores/casaos/CashPilot/docker-compose.yml index 7d4fadca..85dc7f7e 100644 --- a/contrib/app-stores/casaos/CashPilot/docker-compose.yml +++ b/contrib/app-stores/casaos/CashPilot/docker-compose.yml @@ -125,7 +125,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -170,7 +170,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 # The folders the proxy allows, so the worker can say what to set before # the proxy refuses a host-folder bind. Empty means none. - CASHPILOT_COMPOSE_DIR= @@ -302,7 +302,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$$$m\"\nfi\nif s=$$$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$$$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$$$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$$$0, /\"duration\":[0-9]+/)) d = substr($$$$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$$$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$$$m\"\nfi\nset -o pipefail\nif s=$$$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\") &&\n sorted=$$$$(echo \"$$$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$$$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$$$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$$$0, /\"duration\":[0-9]+/)) d = substr($$$$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$$$0\n }' | sort -rn); then\n [ -z \"$$$$sorted\" ] || echo \"$$$$sorted\" | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$$$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$$$T iptables-legacy -t nat -S MYST 2>/dev/null; $$$$T iptables -t nat -S MYST 2>/dev/null; else case \"$$$$($$$$T iptables -V 2>/dev/null)\" in *nf_tables*) $$$$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/contrib/app-stores/runtipi/cashpilot/docker-compose.yml b/contrib/app-stores/runtipi/cashpilot/docker-compose.yml index 81d6a17c..fd6aeb7f 100644 --- a/contrib/app-stores/runtipi/cashpilot/docker-compose.yml +++ b/contrib/app-stores/runtipi/cashpilot/docker-compose.yml @@ -90,7 +90,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -121,7 +121,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 # The values the proxy gets, so the worker can say what to set before the # proxy refuses a host-folder bind. - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -226,7 +226,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nset -o pipefail\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\") &&\n sorted=$$(echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn); then\n [ -z \"$$sorted\" ] || echo \"$$sorted\" | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.build.yml b/docker-compose.build.yml index 0161bf7b..894e4550 100644 --- a/docker-compose.build.yml +++ b/docker-compose.build.yml @@ -134,7 +134,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -168,7 +168,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -287,7 +287,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nset -o pipefail\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\") &&\n sorted=$$(echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn); then\n [ -z \"$$sorted\" ] || echo \"$$sorted\" | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.fleet.yml b/docker-compose.fleet.yml index 6df25a5b..463c4a94 100644 --- a/docker-compose.fleet.yml +++ b/docker-compose.fleet.yml @@ -141,7 +141,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -225,7 +225,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -352,7 +352,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nset -o pipefail\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\") &&\n sorted=$$(echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn); then\n [ -z \"$$sorted\" ] || echo \"$$sorted\" | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.worker.yml b/docker-compose.worker.yml index 12b9993c..04e04694 100644 --- a/docker-compose.worker.yml +++ b/docker-compose.worker.yml @@ -93,7 +93,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -129,7 +129,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -245,7 +245,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nset -o pipefail\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\") &&\n sorted=$$(echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn); then\n [ -z \"$$sorted\" ] || echo \"$$sorted\" | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/docker-compose.yml b/docker-compose.yml index 7d8f9c1c..e8d8e563 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -156,7 +156,7 @@ services: # The policy's fingerprint. Compose does not recreate a container when # only its config's content changes, so this line is what makes # `docker compose up -d` restart the proxy on a new policy. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 configs: - source: cashpilot_socket_policy target: /etc/sockguard/sockguard.yaml @@ -233,7 +233,7 @@ services: - DOCKER_HOST=unix:///run/cashpilot-docker/docker.sock # The proxy policy's fingerprint (scripts/socket_proxy_policy.py), so the # worker can say when its image needs a newer policy than this file has. - - CASHPILOT_PROXY_POLICY=54821ddd893d3689 + - CASHPILOT_PROXY_POLICY=16092b75e37d2917 # The same two values the proxy gets, so the worker can say what to set # before the proxy refuses (the in-app update, a host-folder bind). - CASHPILOT_COMPOSE_DIR=${CASHPILOT_COMPOSE_DIR:-} @@ -356,7 +356,7 @@ configs: - ["cat", "/run/ready"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id\" && { echo; wget -qO- -T 5 \"http://127.0.0.1:4050/transactor/settle/history?page_size=1000\" || true; }"] - ["sh", "-c", "id=$$(wget -qO- -T 5 http://127.0.0.1:4050/identities | grep -o '0x[0-9a-fA-F]\\{40\\}' | head -1) && wget -qO- -T 5 \"http://127.0.0.1:4050/identities/$$id/beneficiary\""] - - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\"); then\n echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn | head -5\n echo \"sessions read: all\"\nfi"] + - ["timeout", "12", "sh", "-c", "if m=$$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then\n echo \"monitoring read: $$m\"\nfi\nset -o pipefail\nif s=$$(wget -qO- -Y off -T 5 \"http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100\") &&\n sorted=$$(echo \"$$s\" | sed 's/},{/}\\n{/g' | awk '\n match($$0, /\"created_at\":\"[^\"]+\"/) {\n t = substr($$0, RSTART + 14, 19); gsub(/[-T:]/, \" \", t)\n d = 0; if (match($$0, /\"duration\":[0-9]+/)) d = substr($$0, RSTART + 11, RLENGTH - 11)\n print mktime(t) + d, $$0\n }' | sort -rn); then\n [ -z \"$$sorted\" ] || echo \"$$sorted\" | head -5\n echo \"sessions read: all\"\nfi"] - ["sh", "-c", "T=\"\"; command -v timeout >/dev/null 2>&1 && T=\"timeout 5\"; $$T iptables-nft -t nat -S MYST 2>/dev/null; if grep -qx nat /proc/net/ip_tables_names 2>/dev/null; then $$T iptables-legacy -t nat -S MYST 2>/dev/null; $$T iptables -t nat -S MYST 2>/dev/null; else case \"$$($$T iptables -V 2>/dev/null)\" in *nf_tables*) $$T iptables -t nat -S MYST 2>/dev/null;; esac; fi"] - ["cat", "/etc/anon/anonrc"] image_pull: diff --git a/scripts/stun_port_pair.py b/scripts/stun_port_pair.py index 77df1085..8eac84cc 100644 --- a/scripts/stun_port_pair.py +++ b/scripts/stun_port_pair.py @@ -29,7 +29,8 @@ rewritten but some pair could not be tested in full (a port that did not bind or got no answer), so the pairing was not checked: run it again with another --start, 4 when --start and --pairs do not give real ports (1 to 65535), and 5 -when the machine would not open a socket, so nothing was tested. A +when the machine would not open a socket before any rewrite was seen (one +seen first still gives 1). A rewritten port is reported as a pairing router when some ports kept their number, and as a NAT that rewrites every port when none did. Read-only: it sends a few UDP packets to a public STUN @@ -108,7 +109,14 @@ def _servers() -> list[tuple[str, int]]: class NoSocket(Exception): - """This machine would not give the test a socket (out of file descriptors, or no permission).""" + """This machine would not give the test a socket (out of file descriptors, or no permission). + + ``measured`` holds what run had counted before that, as run returns it. + """ + + def __init__(self, reason: str, measured: tuple[int, int, int]) -> None: + super().__init__(reason) + self.measured = measured def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int]: @@ -130,7 +138,7 @@ def run(server: tuple[str, int], start: int, pairs: int) -> tuple[int, int, int] try: sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) except OSError as exc: - raise NoSocket(exc.strerror or str(exc)) from exc + raise NoSocket(exc.strerror or str(exc), (answered, rewritten, complete)) from exc socks.append(sock) try: # A client socket on a chosen source port, so the test knows @@ -183,8 +191,13 @@ def main() -> int: try: answered, rewritten, complete = run(server, args.start, args.pairs) except NoSocket as exc: - print(f"Could not open a UDP socket ({exc}): nothing was tested.") - return 5 + answered, rewritten, complete = exc.measured + if not rewritten: + print(f"Could not open a UDP socket ({exc}): the test did not finish.") + return 5 + # A rewrite already seen is the verdict, whatever was left untested. + print(f"Could not open a UDP socket ({exc}): the test stopped early.") + break if answered: break print(f"No answer from {server[0]}:{server[1]}.") diff --git a/services/bandwidth/mysterium.yml b/services/bandwidth/mysterium.yml index 64fa45c6..60d5c604 100644 --- a/services/bandwidth/mysterium.yml +++ b/services/bandwidth/mysterium.yml @@ -182,7 +182,10 @@ docker: # (the node asks Mysterium's quality oracle for it) never costs the sessions # verdict, and a failed sessions read never costs the monitoring one; a check # whose read failed keeps its last verdict. Each marker comes after its - # data, so a run that timeout cuts short never passes for a full read. -Y off keeps an inherited + # data, so a run that timeout cuts short never passes for a full read, and + # the sessions marker needs the whole sort to have worked (pipefail; head + # runs after it, so it cannot fail the sort by closing early), while an + # empty list is still a full read. -Y off keeps an inherited # http_proxy away from the loopback reads. timeout 12 bounds the whole run # inside the 15 s the worker waits. Seen live # (Nov 2026) on two nodes behind routers that rewrite the UDP source port of @@ -201,13 +204,15 @@ docker: if m=$(wget -qO- -Y off -T 5 http://127.0.0.1:4050/node/monitoring-status); then echo "monitoring read: $m" fi - if s=$(wget -qO- -Y off -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100"); then - echo "$s" | sed 's/},{/}\n{/g' | awk ' + set -o pipefail + if s=$(wget -qO- -Y off -T 5 "http://127.0.0.1:4050/sessions?direction=Provided&status=Completed&page_size=100") && + sorted=$(echo "$s" | sed 's/},{/}\n{/g' | awk ' match($0, /"created_at":"[^"]+"/) { t = substr($0, RSTART + 14, 19); gsub(/[-T:]/, " ", t) d = 0; if (match($0, /"duration":[0-9]+/)) d = substr($0, RSTART + 11, RLENGTH - 11) print mktime(t) + d, $0 - }' | sort -rn | head -5 + }' | sort -rn); then + [ -z "$sorted" ] || echo "$sorted" | head -5 echo "sessions read: all" fi checks: diff --git a/tests/test_mysterium_health_probe.py b/tests/test_mysterium_health_probe.py index 2f5be0d4..a97f3f57 100644 --- a/tests/test_mysterium_health_probe.py +++ b/tests/test_mysterium_health_probe.py @@ -199,7 +199,7 @@ def test_the_session_read_has_no_date_window_and_does_not_hang_on_the_status_rea script = _spec()["command"][-1] assert "date_from" not in script and "date " not in script status, sessions = script.split("\nfi\n", 1) - assert "monitoring-status" in status and status.startswith("if ") and sessions.startswith("if ") + assert "monitoring-status" in status and status.startswith("if ") and sessions.startswith("set -o pipefail\nif ") assert sessions.rstrip().endswith('echo "sessions read: all"\nfi'), "the marker comes after the data" assert [c.get("answered") for c in _spec()["checks"]] == ["monitoring read: ", "sessions read: all"] @@ -224,7 +224,7 @@ def test_the_sessions_judged_are_the_five_that_ended_last(): but ended after a run of short ones must still be among those judged.""" script = _spec()["command"][-1] assert "page_size=100" in script - assert "mktime(t) + d" in script and "sort -rn | head -5" in script + assert "mktime(t) + d" in script and "| sort -rn)" in script and '"$sorted" | head -5' in script def _awk_has_mktime() -> bool: @@ -237,7 +237,8 @@ def _awk_has_mktime() -> bool: def test_a_long_session_that_ended_last_is_judged_though_it_started_first(): """Runs the catalog's own sessions pipeline on a page in the API's order.""" script = _spec()["command"][-1] - pipeline = script[script.index('echo "$s" | ') + len('echo "$s" | ') : script.index("| head -5") + len("| head -5")] + start = script.index('echo "$s" | ') + len('echo "$s" | ') + pipeline = script[start : script.index("| sort -rn") + len("| sort -rn")] + " | head -5" dead = [_session(i, 61, 0, 0) | {"created_at": f"2026-11-08T1{i // 6}:{i % 6}0:00Z"} for i in range(30)] long_good = _session(99, 40 * 3600, 900_000, 400_000) | {"created_at": "2026-11-07T00:00:00Z"} page = {"items": [*reversed(dead), long_good], "page": 1, "page_size": 100, "total_items": 31, "total_pages": 1} @@ -251,6 +252,38 @@ def test_a_long_session_that_ended_last_is_judged_though_it_started_first(): assert health_probe.judge(out.stdout + "sessions read: all", _spec()) == [1] +def _run_sessions_branch(tmp_path, page: str, *, broken_awk: bool = False) -> str: + """Run the catalog command under bash with a stub wget answering ``page`` + (monitoring fails); ``broken_awk`` makes awk exit with an error.""" + stubs = tmp_path / "bin" + stubs.mkdir() + (stubs / "wget").write_text('#!/bin/sh\ncase "$*" in *monitoring*) exit 1;; esac\nprintf "%s" "$PAGE"\n') + if broken_awk: + (stubs / "awk").write_text("#!/bin/sh\ncat >/dev/null\nexit 2\n") + for stub in stubs.iterdir(): + stub.chmod(0o755) + env = {**os.environ, "PATH": f"{stubs}:{os.environ['PATH']}", "PAGE": page} + script = _spec()["command"][-1] + return subprocess.run(["bash", "-c", script], capture_output=True, text=True, env=env).stdout + + +def test_a_failed_sessions_pipeline_is_no_full_read(tmp_path): + """awk or sort failing after a good fetch must leave the sessions check unread, + not judged healthy on empty output.""" + page = json.dumps({"items": [_session(i, 61, 0, 0) for i in range(6)]}, separators=(",", ":")) + out = _run_sessions_branch(tmp_path, page, broken_awk=True) + assert "sessions read: all" not in out + assert health_probe.unanswered(out, _spec()) == [0, 1] + + +@pytest.mark.skipif(not _awk_has_mktime(), reason="this awk has no mktime") +def test_an_empty_session_list_is_still_a_full_read(tmp_path): + """A node with no completed sessions yet was read in full and holds no bad run.""" + out = _run_sessions_branch(tmp_path, '{"items":[],"page":1,"page_size":100,"total_items":0}') + assert out.splitlines() == ["sessions read: all"] + assert health_probe.unanswered(out, _spec()) == [0] and health_probe.judge(out, _spec()) == [] + + def test_the_monitoring_finding_sends_to_the_tun_check_first(): """The monitoring finding points at the tun and SETUID check first.""" means = _spec()["checks"][0]["means"] @@ -633,6 +666,49 @@ def _list(slug, client=None): assert took < 2 and [r["slug"] for r in rows] == ["aaa"] and rows[0]["hits"] == [0, 1] +def test_a_client_that_cannot_be_made_gives_its_slot_back(): + """Docker down at the start of a batch must not use up the pool's slots for good.""" + api = _Api({"fast": (0, FAILING.encode())}) + with ( + patch("app.orchestrator.service_instances", return_value=_containers("fast")), + patch("app.orchestrator._instance_of", return_value=1), + ): + for _ in range(health_probe._POOL_SIZE + 1): + with patch("app.health_probe._client", side_effect=OSError("no docker")): + assert health_probe.read_all(_two_services()) == [] + with patch("app.health_probe._client", return_value=MagicMock(api=api)): + rows = health_probe.read_all(_two_services()) + assert [r.get("hits") for r in rows] == [[0, 1], [0, 1]] + + +def test_a_listing_that_always_stalls_lets_the_next_service_go_first(monkeypatch): + """The cursor moves past a stalled listing, or the services behind it are never read.""" + release = threading.Event() + api = _Api({"fast": (0, FAILING.encode())}) + listed = [] + + def _list(slug, client=None): + """aaa's listing always hangs; bbb lists at once.""" + listed.append(slug) + if slug == "aaa": + release.wait(10) + return [] + return _containers("fast") + + monkeypatch.setattr(health_probe, "BATCH_BUDGET", 0.3) + try: + with ( + patch("app.orchestrator.service_instances", side_effect=_list), + patch("app.orchestrator._instance_of", return_value=1), + patch("app.health_probe._client", return_value=MagicMock(api=api)), + ): + assert health_probe.read_all(_two_services()) == [] + second = health_probe.read_all(_two_services()) + finally: + release.set() + assert listed[1] == "bbb" and second[0]["slug"] == "bbb" and second[0]["hits"] == [0, 1] + + def test_the_worker_endpoint_serves_the_rows(): """The worker endpoint returns what read_all reads.""" client = TestClient(worker_api.app) @@ -661,7 +737,7 @@ def _row(hits=None, *, error=None, unread=(), definition=None): return row -def _sweep(probes=None, *, probe_error=None, logs="", log_error=None): +def _sweep(probes=None, *, probe_error=None, logs="", log_error=None, worker_error=None): """Run one sweep against fake worker answers; returns the copy's hints and the paths called.""" calls = [] @@ -678,7 +754,12 @@ async def _proxy(wid, method, path, params=None, **kw): with ( patch("app.main._get_all_worker_containers", new_callable=AsyncMock, return_value=[RUNNING]), - patch("app.main.database.get_worker", new_callable=AsyncMock, return_value=WORKER), + patch( + "app.main.database.get_worker", + new_callable=AsyncMock, + return_value=WORKER, + side_effect=worker_error, + ), patch( "app.main.database.get_deployment_spec", new_callable=AsyncMock, @@ -694,8 +775,10 @@ async def _proxy(wid, method, path, params=None, **kw): def _no_carried_turn(): """Each test starts read_all with the first copy.""" health_probe._resume.clear() + health_probe._resume_service = None yield health_probe._resume.clear() + health_probe._resume_service = None @pytest.fixture(autouse=True) @@ -816,6 +899,30 @@ def test_a_verdict_kept_from_another_definition_is_dropped(): assert hints == [], "the session verdict must not come back as the monitoring one" +def test_a_worker_lookup_failure_keeps_log_verdicts_but_not_another_definitions_probe(): + """When the worker row cannot be read, the log verdict stays, and a probe + verdict read against another definition must not come back.""" + _sweep([_row([1])], logs=FAILED_LOG) + changed = copy.deepcopy(catalog.get_service("mysterium")) + changed["docker"]["health_probe"]["checks"].reverse() + with patch("app.main.catalog.get_service", return_value=changed): + hints, _ = _sweep(worker_error=RuntimeError("database is locked")) + assert len(hints) == 1 and "forward the UDP port range" in hints[0] + assert ("mysterium", 7, 1) not in main._probe_state + + +def test_a_failing_sweep_does_not_keep_a_verdict_past_a_day(): + """The kept probe hints obey the same one-day limit as a working sweep.""" + _sweep([_row([1])]) + later = main.time.time() + main.PROBE_STALE_SECONDS + 3600 + with patch("app.main.time.time", return_value=later): + with patch("app.main._probe_step", side_effect=RuntimeError("boom")): + hints, _ = _sweep([_row([1])]) + assert hints == [], "a day-old verdict must not survive a failing probe step" + hints, _ = _sweep(worker_error=RuntimeError("database is locked")) + assert hints == [], "nor a failing worker lookup" + + def test_a_check_unread_for_a_day_says_so(): """A check unread for a day is reported as unreadable.""" _sweep([_row([0, 1])]) @@ -977,6 +1084,40 @@ def close(self): assert peak == 2 and open_now == 0 +def test_a_rewrite_seen_before_the_sockets_ran_out_still_counts(monkeypatch): + """Running out of sockets after a rewrite was measured keeps that verdict, exit 1.""" + stun = _stun() + opened = 0 + + class _Few: + """UDP sockets until the third, then out of file descriptors.""" + + def __init__(self, *a, **k): + """Open one, or refuse past two.""" + nonlocal opened + opened += 1 + if opened > 2: + raise OSError(24, "Too many open files") + self.port = 0 + + def settimeout(self, value): + """Accept the timeout.""" + + def bind(self, address): + """Remember the port.""" + self.port = address[1] + + def close(self): + """Close it.""" + + monkeypatch.setattr(stun, "_servers", lambda: [("192.0.2.1", 3478)]) + monkeypatch.setattr("sys.argv", ["stun_port_pair.py"]) + monkeypatch.setattr(stun.socket, "socket", _Few) + # The odd port goes out first and comes back rewritten; its partner keeps its number. + monkeypatch.setattr(stun, "probe", lambda sock, server: sock.port + 100 if sock.port % 2 else sock.port) + assert stun.main() == 1 + + def test_every_port_rewritten_makes_no_claim_about_a_forward(monkeypatch, capsys): """The test measures ports with no forward, so it says nothing about one.""" stun = _stun()