From ea1564fba7892301ea94dbb119c6133c008f8e41 Mon Sep 17 00:00:00 2001 From: atlas Date: Wed, 11 Nov 2026 05:23:56 +0100 Subject: [PATCH] hive-squid test: wait for the agent, retry no-answer connects, print evidence on failure --- nix/vm-tests/hive-squid.nix | 91 +++++++++++++++++++++++++------------ 1 file changed, 62 insertions(+), 29 deletions(-) diff --git a/nix/vm-tests/hive-squid.nix b/nix/vm-tests/hive-squid.nix index aa5051df1..5c23725a8 100644 --- a/nix/vm-tests/hive-squid.nix +++ b/nix/vm-tests/hive-squid.nix @@ -235,6 +235,7 @@ pkgs.testers.runNixOSTest { import secrets import shlex import time + from contextlib import contextmanager # Drawn fresh each run. The users file holds only their hashes, as # hive-c0re renders it. `atlas` is a restricted agent and `uma` an @@ -262,16 +263,48 @@ pkgs.testers.runNixOSTest { proxy.wait_for_unit("nginx.service") web.wait_for_unit("nginx.service") proxy.wait_for_open_port(3128, "${bridgeIp}") + # `start_all` boots the agent beside the proxy; its network is up only once + # it has reached multi-user.target and can open the proxy's port. + agent.wait_for_unit("multi-user.target") + agent.wait_until_succeeds("timeout 3 bash -c 'echo > /dev/tcp/${bridgeIp}/3128'") PRIVATE = ["priv10.t.local", "priv172.t.local", "priv192.t.local", "cgnat.t.local", "ula.t.local", "any6.t.local"] + SEEN = [] + def connect(host, cred=None): - # The status squid answered the CONNECT with; 000 when none came back. + # The status squid answered the CONNECT with. 000 means no answer, which + # no assertion expects: squid closes its listener while a reload re-reads + # its configuration, so 000 is retried. auth = f"-U '{cred}' " if cred else "" - return agent.succeed( - "curl -sS -m 15 -p -x http://${bridgeIp}:3128 " + auth + "-o /dev/null " - f"-w '%{{http_connect}}' https://{host}/ 2>/dev/null || true" - ).strip() + got = "000" + for _ in range(15): + got = agent.succeed( + "curl -sS -m 15 -p -x http://${bridgeIp}:3128 " + auth + "-o /dev/null " + f"-w '%{{http_connect}}' https://{host}/ 2>/dev/null || true" + ).strip() + if got != "000": + break + time.sleep(1) + SEEN.append(f"{host} as {cred.split(':')[0] if cred else '-'}: {got}") + return got + + @contextmanager + def checked(name): + # A subtest that prints what the proxy and the agent were doing when it fails. + with subtest(name): + try: + yield + except BaseException: + print("recent connects:\n" + "\n".join(SEEN[-12:])) + for vm, cmd in ( + (proxy, "systemctl status squid.service squid-unrestricted-reload.service squid-selfcheck.service --no-pager -n 0"), + (proxy, "journalctl -u squid.service -o cat --no-pager | tail -n 40"), + (proxy, "ss -ltn"), + (agent, "ip -brief address; ip route; systemctl is-system-running"), + ): + print(f"--- {vm.name}: {cmd}\n" + vm.execute(cmd)[1]) + raise def write_users(*creds): # What hive-c0re does: hashes only, written aside and renamed into @@ -323,12 +356,12 @@ pkgs.testers.runNixOSTest { time.sleep(1) raise AssertionError(f"{host} as {cred.split(':')[0]}: wanted {want}, last got {got}") - with subtest("the private listeners answer the proxy itself, so a refusal below is squid's"): + with checked("the private listeners answer the proxy itself, so a refusal below is squid's"): for addr in ["10.99.0.2", "172.16.99.2", "192.168.99.2", "100.64.99.2", "fd00:99::2"]: proxy.wait_until_succeeds(f"timeout 3 bash -c 'echo > /dev/tcp/{addr}/443'") assert connect("forge.t.local", None) == "407", "control: the public name is challenged, not refused" - with subtest("squid starts on the empty users file and list and refuses every login"): + with checked("squid starts on the empty users file and list and refuses every login"): assert proxy.succeed(f"stat -c '%U:%G %a' {USERS}").strip() == "hive-core:squid 640" assert proxy.succeed(f"stat -c '%U:%G %a' {LIST}").strip() == "hive-core:squid 640" assert proxy.succeed("stat -c %a /var/lib/hive-squid").strip() == "2750" @@ -344,7 +377,7 @@ pkgs.testers.runNixOSTest { assert connect("forge.t.local", ATLAS) == "407", "no such user" assert connect("other.t.local", UMA) == "407", "no such user, unlisted name" - with subtest("the users file holds hashes, never a password"): + with checked("the users file holds hashes, never a password"): write_users(ATLAS, UMA, SELFCHECK, SELFCHECK_U) users = proxy.succeed(f"cat {USERS}") rows = [l.split(":", 1) for l in users.splitlines()] @@ -354,7 +387,7 @@ pkgs.testers.runNixOSTest { assert all(re.fullmatch(r"\$6\$\S+", r[1]) for r in rows), users assert not any(p in users for p in PW.values()), users - with subtest("an allowed name is tunnelled with a credential and challenged without one"): + with checked("an allowed name is tunnelled with a credential and challenged without one"): assert connect("forge.t.local", ATLAS) == "200", "allow canary" assert connect("cache.t.local", ATLAS) == "200", "the self-check canary, allowed on top of the list" assert connect("forge.t.local") == "407", "no credential" @@ -363,19 +396,19 @@ pkgs.testers.runNixOSTest { # DES would accept the first eight characters; the hash must not. assert connect("forge.t.local", "atlas:" + PW["atlas"][:8]) == "407", "a prefix of the password" - with subtest("a base-list name is open to a restricted user, with a credential, and nothing else is"): + with checked("a base-list name is open to a restricted user, with a credential, and nothing else is"): assert connect("api.t.local", ATLAS) == "200", "restricted user, base name" assert connect("api.t.local") == "407", "no credential" assert connect("api.t.local", "atlas:" + secrets.token_urlsafe(24)) == "407", "wrong password" assert connect("other.t.local", ATLAS) == "403", "control: an unlisted name is still refused" assert connect("basebridge.t.local", ATLAS) == "403", "a base name that resolves to the bridge" - with subtest("with an empty list every user is restricted"): + with checked("with an empty list every user is restricted"): assert connect("other.t.local", UMA) == "403", "uma, not listed yet" assert connect("other.t.local", ATLAS) == "403" assert connect("forge.t.local", UMA) == "200", "control: uma still reaches a listed name" - with subtest("a listed user reaches an unlisted name and the others are refused"): + with checked("a listed user reaches an unlisted name and the others are refused"): write_list(*UNRESTRICTED) wait_status("other.t.local", UMA, "200") assert connect("other.t.local", ATLAS) == "403", "restricted" @@ -385,7 +418,7 @@ pkgs.testers.runNixOSTest { assert connect("other.t.local", "uma:" + secrets.token_urlsafe(24)) == "407", "wrong password" assert connect("deny-canary.invalid", ATLAS) == "403", "restricted, an unlisted name" - with subtest("neither kind of user reaches a host-local or private destination, or another port"): + with checked("neither kind of user reaches a host-local or private destination, or another port"): for cred in (ATLAS, UMA): who = cred.split(":")[0] assert connect("loop.t.local", cred) == "403", f"{who}: loopback" @@ -398,7 +431,7 @@ pkgs.testers.runNixOSTest { assert connect("other.t.local:22", cred) == "403", f"{who}: port 22" assert connect("other.t.local:80", cred) == "403", f"{who}: CONNECT to port 80" - with subtest("an agent cannot read cachemgr"): + with checked("an agent cannot read cachemgr"): agent.succeed( "test $(curl -s -m 15 -o /dev/null -w '%{http_code}' " "http://${bridgeIp}:3128/squid-internal-mgr/counters) = 403" @@ -423,7 +456,7 @@ pkgs.testers.runNixOSTest { def squid_saw(pattern): return re.search(pattern, proxy.succeed("journalctl -u squid.service -o cat")) - with subtest("an agent with the proxy variables reaches an allowed name through squid and a swarm-internal name directly"): + with checked("an agent with the proxy variables reaches an allowed name through squid and a swarm-internal name directly"): NO_PROXY = "localhost,127.0.0.1,::1,bridge.t.local,${bridgeIp}" # Plain HTTP to the listeners' port 443, so the answer carries a status. assert agent_get(ATLAS, NO_PROXY, "http://forge.t.local:443/") not in ("000", "403", "407") @@ -438,12 +471,12 @@ pkgs.testers.runNixOSTest { f"env {agent_env(ATLAS, NO_PROXY)} curl -sS -m 15 -o /dev/null -w '%{{http_connect}}' https://forge.t.local/ 2>/dev/null || true" ).strip() == "200" - with subtest("an agent without the proxy variables goes direct"): + with checked("an agent without the proxy variables goes direct"): assert agent.succeed( "curl -sS -m 15 -o /dev/null -w '%{http_code}' http://bridge.t.local:443/ 2>/dev/null || true" ).strip() not in ("000", "403", "407") - with subtest("the self-check passes with its credential"): + with checked("the self-check passes with its credential"): proxy.succeed("install -d -m 0700 /run/credstore") proxy.succeed(f"printf '%s\\n' {PW['selfcheck.squid']} > /run/credstore/hive-squid.selfcheck") proxy.succeed("chmod 400 /run/credstore/hive-squid.selfcheck") @@ -456,7 +489,7 @@ pkgs.testers.runNixOSTest { "unrestricted_canary=other.t.local unrestricted_status=200'" ) - with subtest("the self-check fails, and says why, when the unrestricted user is not listed"): + with checked("the self-check fails, and says why, when the unrestricted user is not listed"): write_list() wait_status("other.t.local", UMA, "403") proxy.fail("systemctl start squid-selfcheck.service") @@ -470,7 +503,7 @@ pkgs.testers.runNixOSTest { write_list(*UNRESTRICTED) wait_status("other.t.local", UMA, "200") - with subtest("the self-check fails, and says why, without a credential or with the wrong one"): + with checked("the self-check fails, and says why, without a credential or with the wrong one"): proxy.succeed("mv /run/credstore/hive-squid.selfcheck /run/credstore/kept") proxy.fail("systemctl start squid-selfcheck.service") proxy.succeed( @@ -490,7 +523,7 @@ pkgs.testers.runNixOSTest { ) proxy.succeed("mv -f /run/credstore/kept /run/credstore/hive-squid.selfcheck") - with subtest("squid's access log reaches the journal under squid.service, with the user"): + with checked("squid's access log reaches the journal under squid.service, with the user"): journal = proxy.succeed("journalctl -u squid.service -o cat") assert re.search(r"192\.168\.1\.3 TCP_TUNNEL/200 .* CONNECT forge\.t\.local:443 atlas ", journal), journal assert re.search(r"192\.168\.1\.3 TCP_TUNNEL/200 .* CONNECT other\.t\.local:443 uma ", journal), journal @@ -500,7 +533,7 @@ pkgs.testers.runNixOSTest { # Exporter scrapes are cachemgr requests and stay out of the log. assert "squid-internal-mgr" not in journal, journal - with subtest("the exporter serves squid's counters on loopback"): + with checked("the exporter serves squid's counters on loopback"): metrics = proxy.succeed("curl -sf http://127.0.0.1:9301/metrics") print("\n".join(l for l in metrics.splitlines() if l.startswith(("squid_up", "squid_client_http")))) assert 'squid_up{host="${bridgeIp}"} 1' in metrics @@ -510,20 +543,20 @@ pkgs.testers.runNixOSTest { assert m and float(m.group(1)) >= 1, metrics proxy.fail("curl -sf -m 5 http://${bridgeIp}:9301/metrics") - with subtest("squid survives a reload and keeps the list"): + with checked("squid survives a reload and keeps the list"): proxy.succeed("systemctl reload squid.service") proxy.wait_for_unit("squid.service") assert connect("forge.t.local", ATLAS) == "200" assert connect("other.t.local", UMA) == "200" assert connect("other.t.local", ATLAS) == "403" - with subtest("a user added while squid runs can log in, with no reload, and is restricted"): + with checked("a user added while squid runs can log in, with no reload, and is restricted"): write_users(ATLAS, UMA, SELFCHECK, SELFCHECK_U, RUTH) assert connect("forge.t.local", RUTH) == "200" assert connect("forge.t.local", ATLAS) == "200" assert connect("other.t.local", RUTH) == "403" - with subtest("a user the list gains is unrestricted after the reload and loses it again"): + with checked("a user the list gains is unrestricted after the reload and loses it again"): write_list(*UNRESTRICTED, "ruth") wait_status("other.t.local", RUTH, "200") assert connect("loop.t.local", RUTH) == "403", "still no loopback" @@ -531,7 +564,7 @@ pkgs.testers.runNixOSTest { wait_status("other.t.local", RUTH, "403") assert connect("other.t.local", UMA) == "200", "control: uma is still listed" - with subtest("the swarm's allow-list adds to the hive's names, opens one to every restricted user, and a per-agent rule opens one to that agent alone"): + with checked("the swarm's allow-list adds to the hive's names, opens one to every restricted user, and a per-agent rule opens one to that agent alone"): seeded = proxy.succeed(f"cat {ALLOWED}") assert connect("swarm.t.local", RUTH) == "403", "control: not allowed yet" assert connect("agentonly.t.local", ATLAS) == "403", "control: not allowed yet" @@ -556,7 +589,7 @@ pkgs.testers.runNixOSTest { wait_status("agentonly.t.local", ATLAS, "403") assert connect("forge.t.local", RUTH) == "200", "the hive's own name after the swarm list is gone" - with subtest("a log-mode agent reaches an unlisted name and is logged as would_deny, and nothing else changes"): + with checked("a log-mode agent reaches an unlisted name and is logged as would_deny, and nothing else changes"): # What hive-c0re renders for `ruth` in log mode, after the agent rules. write_allow( seeded, @@ -584,7 +617,7 @@ pkgs.testers.runNixOSTest { write_allow(seeded, "") wait_status("other.t.local", RUTH, "403") - with subtest("the swarm's deny list is refused before any allow, in every mode, with or without a credential, and logged as egress_denied"): + with checked("the swarm's deny list is refused before any allow, in every mode, with or without a credential, and logged as egress_denied"): # What hive-c0re renders: `forge.t.local` and `other.t.local` for every # agent, `api.t.local` (a base-list name) for atlas alone. `ruth` is in # log mode, so her rule follows. The names are allowed or reachable @@ -631,7 +664,7 @@ pkgs.testers.runNixOSTest { assert connect("api.t.local", ATLAS) == "200", "the list emptied" assert connect("other.t.local", UMA) == "200", "the list emptied, unrestricted" - with subtest("squid starts on a missing list, treats every user as restricted, and recovers when it appears"): + with checked("squid starts on a missing list, treats every user as restricted, and recovers when it appears"): proxy.succeed(f"rm {LIST}") proxy.succeed("systemctl restart squid.service") proxy.wait_for_unit("squid.service") @@ -641,7 +674,7 @@ pkgs.testers.runNixOSTest { write_list(*UNRESTRICTED) wait_status("other.t.local", UMA, "200") - with subtest("squid starts on a missing users file, refuses logins, and recovers when it appears"): + with checked("squid starts on a missing users file, refuses logins, and recovers when it appears"): proxy.succeed(f"rm {USERS}") proxy.succeed("systemctl restart squid.service") proxy.wait_for_unit("squid.service")