diff --git a/tests/DodoSSH.Client.Ssh.Tests/SshServerFixture.cs b/tests/DodoSSH.Client.Ssh.Tests/SshServerFixture.cs index 22ebd31..a06acfc 100644 --- a/tests/DodoSSH.Client.Ssh.Tests/SshServerFixture.cs +++ b/tests/DodoSSH.Client.Ssh.Tests/SshServerFixture.cs @@ -1,4 +1,6 @@ +using System.Net.Sockets; using System.Security.Cryptography; +using System.Text; using DotNet.Testcontainers.Builders; using DotNet.Testcontainers.Containers; using Xunit; @@ -40,6 +42,21 @@ public sealed class SshServerFixture : IAsyncLifetime private const int SshPort = 2222; + /// + /// How many connections in a row the server has to answer before this fixture calls it ready. + /// + /// + /// Twenty-five, and the number is measured rather than picked. Probing a fresh container 200 times with + /// penalties left at the image's default, the first Not allowed at this time came back at probe + /// 18 and 183 of the 200 were refused; with PerSourcePenalties no applied, none of 200 were. Ten + /// was tried first and is useless — it sits below the threshold, so the guard passed happily against a + /// server that was still penalising. See . + /// + private const int RequiredStreak = 25; + + /// How long to keep trying before giving up on the server entirely. + private static readonly TimeSpan ReadyTimeout = TimeSpan.FromSeconds(60); + private readonly SemaphoreSlim sftpGate = new(1, 1); private IContainer? container; @@ -80,101 +97,94 @@ public sealed class SshServerFixture : IAsyncLifetime .Build(); await container.StartAsync(); - await AllowTcpForwardingAsync(); + await ReconfigureAsync(); + await WaitUntilServingAsync(); } /// - /// Lets this server open the direct-tcpip channels a forward is made of. + /// Turns off the hardening this suite trips over, and makes the running server re-read its config. /// /// /// - /// ◆ The image ships AllowTcpForwarding no, and nothing says so at the point it bites. A - /// dynamic forward starts perfectly happily — it is a local listener, and opening it asks the server - /// nothing — and then every connection through it is refused when the channel is opened. SSH.NET - /// reports that as SOCKS5: General failure from the proxy, which names neither the server nor - /// the setting, and is what the first run of LoopbackProxyTests collected. + /// ◆ PerSourcePenalties no is the fix for the flake this suite had for months, and the other + /// two settings here are not. OpenSSH 9.8 added per-source penalties and 10.x has them on by + /// default; this image runs 10.3. A source address that keeps disconnecting without authenticating is + /// penalised, and while the penalty holds every connection from it is answered with the clear-text line + /// Not allowed at this time and then closed. /// /// - /// Patched after start rather than baked in, because the image's entrypoint writes its configuration - /// itself on every boot — a mounted file would be overwritten before sshd read it. sshd re-reads on - /// SIGHUP and applies the result to connections made after that, and the readiness wait has - /// already run, so nothing here races the boot. + /// This suite generates exactly that traffic, by design. This client's first contact with an + /// unknown host is a connection deliberately refused at the host key — which is a disconnect with no + /// authentication attempt — and several tests do nothing else: + /// RefusingTheHostKey_AbortsTheConnection, AnUntrustedHost_IsRefusedExactlyAsAShellWouldBe, + /// and every helper that learns a host key by being turned away first. Enough of them close together and + /// sshd stops talking to the test host altogether, for a while, and then starts again. + /// + /// + /// From the client that is SshConnectionException: The connection was closed by the remote host + /// within milliseconds — no banner, nothing to say which of the many reasons it was. It hits whichever + /// class is running when the penalty lands and spares the rest, which is why it read as random and why + /// the class it hit lost every connection it made rather than a random few. The one test in that + /// class that expects a refusal passed throughout, for the wrong reason. + /// + /// + /// ◆ Two earlier diagnoses were wrong, and are recorded here so they are not tried again. + /// MaxStartups was blamed on the reasoning that xUnit runs test classes in parallel, so ten + /// unauthenticated connections would be in flight at once — but every class that touches this server + /// shares , and xUnit's unit of parallelism is the collection, so they run one + /// after another and never have more than a connection or two open. The reload window was blamed next, + /// and a wait for the banner to answer was written and removed as unproven; it was unproven because the + /// banner does answer, right up until the penalty lands. + /// + /// + /// The line is appended rather than replaced in place, unlike the two below it, because the image's + /// config does not mention the keyword at all — there is no line to replace, and sshd takes the first + /// value it finds for a keyword that appears more than once. + /// + /// + /// ◆ AllowTcpForwarding is what a dynamic forward needs, and the image ships it off as + /// hardening. Without it a forward opens perfectly happily — a local listener asks the server nothing — + /// and then every connection through it is refused when the channel is opened. SSH.NET reports that as + /// SOCKS5: General failure, which names neither the server nor the setting, and is what the first + /// run of LoopbackProxyTests collected. That suite is also the alarm if this method ever silently + /// stops working. + /// + /// + /// MaxStartups is raised for the reason it should have been in the first place rather than as a + /// fix for anything: the compiled-in default refuses connections at random past ten unauthenticated ones + /// in flight, and a throttle is hardening a test server has no business reproducing. It is kept, not + /// because it was ever shown to matter here, but because removing it would be a second change riding + /// along with this one. + /// + /// + /// Both are replaced in place rather than appended, because sshd_config takes the first value + /// it finds for a keyword: an appended line would be dead the day the image ships an uncommented one of + /// its own. /// /// /// ◆ /config/sshd/sshd_config, and there are two. The image also carries - /// /etc/ssh/sshd_config, which looks like the file to patch, reads identically, and is not the - /// one the running server was started with — patching it changes the text and nothing else, which is a - /// fix that appears to work and leaves the failure exactly where it was. Measured with find - /// rather than assumed, after the first version of this method did precisely that. + /// /etc/ssh/sshd_config, which looks like the file to patch, reads identically, and is not the one + /// the running server was started with — patching it changes the text and nothing else, which is a fix + /// that appears to work and leaves the failure exactly where it was. /// /// - /// It is on for the whole assembly rather than for the one test that needs it. Forwarding is off in - /// this image as hardening, not as a behaviour worth reproducing: nothing else here opens a channel of - /// any kind, so allowing it changes what exactly one suite can do and what none of the others see. - /// - /// - /// ◆ MaxStartups is raised here too, against a flake this suite has and that this change is - /// a mitigation for rather than a proven cure. The distinction is stated because the evidence - /// stops short of the claim, and a later reader deserves to know which. - /// - /// - /// What is established: sshd's compiled-in default is 10:30:100 — past ten - /// unauthenticated connections in flight it refuses new ones at random, thirty percent of the - /// time, rising to always at a hundred — and the image ships the line commented out, so that default - /// was what ran. xUnit runs test classes in parallel and most classes here open a connection, so ten - /// in flight is reachable in the opening seconds. A refused connection presents to the client as - /// SshConnectionException: The connection was closed by the remote host within tens of - /// milliseconds, on whichever test connects at the wrong moment — which is exactly the observed - /// failure, seen in CI and reproduced locally. - /// - /// - /// What is not established is that this limit is the only cause, because the flake rate could - /// not be measured reliably. On the development machine the identical unmodified suite ran 85/85 clean - /// and, an hour later, failed 13 runs out of 15 — Docker throughput on that host swings far enough to - /// swamp the effect being measured. Any before/after comparison taken there is noise, and two were, - /// before that was noticed. - /// - /// - /// It is committed anyway, on the narrower argument that it is right regardless: a connection throttle - /// is hardening this suite has no interest in reproducing. It exists to test an SSH client, not to - /// survive a rate limit, and a test server that drops connections at random is a bad test server - /// whether or not it is the cause of this particular flake. - /// - /// - /// Not fixed by serialising the suite, which would have hidden it and cost the parallelism, and - /// not by retrying the connect, which would have made the client's own reconnect behaviour untestable - /// by burying it in the fixture. The limit is a property of a hardened server that this suite has no - /// interest in reproducing — it exists to test an SSH client, not to survive a throttle. - /// - /// - /// Replaced in place rather than appended, because sshd_config takes the first value it finds - /// for a keyword: an appended line would be dead the day the image ships an uncommented one of its own. - /// - /// - /// ◆ The reload window is the other candidate, and it is deliberately not guarded against. - /// SIGHUP makes sshd close its listeners and re-execute itself, and pkill returns when - /// the signal is delivered rather than when that has finished — so in principle a connection made - /// immediately afterwards is refused, producing this same exception. A wait that opened connections - /// until the server answered with its banner three times running was written, and then removed: it - /// could not be shown to change anything either, and a fixture carrying two unproven fixes for one - /// symptom is worse than one, because the next person has to disprove both. - /// - /// - /// If this flake returns, that is the next thing to try. Two things to know before trying it: the two - /// causes are indistinguishable from the client, so a fix can only be judged by a repeat run and never - /// by whether the next run passes — and the repeat run has to happen somewhere with stable Docker - /// throughput, which the development machine is not. Better still, make sshd say why: raise its - /// LogLevel here, disable Ryuk so the container outlives the run, and read - /// docker logs. A MaxStartups refusal names itself there; a reload does not. + /// ◆ Patched after boot and reloaded, rather than injected before it — which was tried and does not + /// work. This image family runs /custom-cont-init.d scripts, which look like the right hook + /// and are not: the container's own log puts sshd is listening on port 2222 before + /// [custom-init] Files found, executing, so a script there edits a file the running server has + /// already read. It leaves a config that greps correctly and a server behaving as though it had never + /// been touched — the same trap as the wrong file, one layer up. Measured from the log, after a version + /// of this fixture did exactly that and failed twenty-eight tests. /// /// - private async Task AllowTcpForwardingAsync() + private async Task ReconfigureAsync() { var result = await container!.ExecAsync([ "sh", "-c", "sed -i 's/^AllowTcpForwarding no/AllowTcpForwarding yes/' /config/sshd/sshd_config" + " && sed -i 's/^#*MaxStartups .*/MaxStartups 200/' /config/sshd/sshd_config" + + " && printf '\\nPerSourcePenalties no\\n' >> /config/sshd/sshd_config" + " && pkill -HUP sshd", ]); @@ -183,7 +193,107 @@ public sealed class SshServerFixture : IAsyncLifetime throw new InvalidOperationException( $"Could not reconfigure the test server: {result.Stderr}"); } + } + /// + /// Blocks until the server answers connections in a row with its banner. + /// + /// + /// + /// ◆ This is a guard rather than a wait, and what it guards against is + /// PerSourcePenalties coming back. Reconfiguring above turns it off; this proves it is off, + /// immediately and by name, instead of letting the suite discover it later as an unrelated-looking + /// failure in whichever class happened to be running. + /// + /// + /// Consecutive, and deliberately with no pause between them. Each probe opens a connection, reads + /// the identification string and disconnects without authenticating — which is exactly the shape of + /// connection PerSourcePenalties punishes, and exactly what this suite does all day: a first + /// contact with an unknown host is a connection this client deliberately refuses at the host key. + /// back to back is therefore not a soak test, it is the specific + /// provocation, sized above the measured threshold on purpose, and it costs well under a second when the + /// setting is off. + /// + /// + /// It is also the one check that can tell a listening socket from a running server. The container's own + /// readiness — a log line and netstat showing :2222 — passes on a container whose sshd has + /// gone: the socket is published by a host-side proxy that accepts before it has anything to forward to, + /// so a dead server presents as a connection accepted and closed rather than as one refused. + /// + /// + /// Probed from the host rather than with docker exec, deliberately: that is the path the tests + /// take, proxy included, and penalties are counted per source address — from inside the container the + /// source would be the loopback rather than the address every test connects from. + /// + /// + private async Task WaitUntilServingAsync() + { + // TimeProvider.System rather than DateTimeOffset.UtcNow, which this repository bans so that time can + // be faked — and rather than a fake, because what is being waited on is a real container starting. + var deadline = TimeProvider.System.GetUtcNow() + ReadyTimeout; + var streak = 0; + var last = "no probe ran"; + + while (streak < RequiredStreak) + { + if (TimeProvider.System.GetUtcNow() >= deadline) + { + throw new InvalidOperationException( + $"The test server did not answer {RequiredStreak} connections in a row within " + + $"{ReadyTimeout}. The last probe said: {last}. If it says \"Not allowed at this " + + "time\", sshd is penalising this source address and PerSourcePenalties is no longer " + + "being turned off — see ReconfigureAsync."); + } + + var (answered, what) = await ProbeAsync(); + last = what; + + if (answered) + { + streak++; + continue; + } + + // Only pause when it is not working. Back-to-back probes are the point while they succeed; + // hammering a server that has not finished starting is just noise. + streak = 0; + await Task.Delay(TimeSpan.FromMilliseconds(200)); + } + } + + /// Opens a socket and reads far enough to see OpenSSH's identification string. + /// + /// The description comes back with the answer because the interesting failures are not exceptions. A + /// penalised source is told Not allowed at this time in clear text before the socket closes, and + /// a suite that only knew "no banner" would have to go and find that out again — which is what happened + /// the first time, at some length. + /// + private async Task<(bool Answered, string What)> ProbeAsync() + { + try + { + using var probe = new TcpClient(); + using var timeout = new CancellationTokenSource(TimeSpan.FromSeconds(5)); + + await probe.ConnectAsync(Host, Port, timeout.Token); + + var buffer = new byte[64]; + var read = await probe.GetStream().ReadAtLeastAsync( + buffer, 4, throwOnEndOfStream: false, timeout.Token); + + var answered = read >= 4 && "SSH-"u8.SequenceEqual(buffer.AsSpan(0, 4)); + + return ( + answered, + answered + ? "SSH-" + : $"{read} bytes: " + + Encoding.ASCII.GetString(buffer, 0, Math.Max(read, 0)).ReplaceLineEndings(" ")); + } + catch (Exception exception) when (exception is SocketException or OperationCanceledException or IOException) + { + return (false, $"{exception.GetType().Name}: {exception.Message}"); + } } /// @@ -225,12 +335,17 @@ public sealed class SshServerFixture : IAsyncLifetime /// /// /// - /// Shared rather than opened per test, and that is a limit of the server rather than an optimisation. - /// sshd's MaxStartups drops connections at random once enough are part-way through a handshake, - /// and this client's first contact with an unknown host is a connection deliberately refused at - /// the host key — so a suite that opened its own session per test made two handshakes per test and - /// pushed the whole assembly over the threshold. What that looks like is unrelated tests failing with - /// "the connection was closed by the remote host", a different few each run. + /// Shared rather than opened per test. This was once explained as a way of staying under the server's + /// MaxStartups throttle, on the belief that the suite ran its classes in parallel and made two + /// handshakes per test — this client's first contact with an unknown host is a connection deliberately + /// refused at the host key, so every session costs two. The parallelism was not real: every + /// class here shares one collection and xUnit runs collections, not classes, in parallel. See + /// , which is where that mistake was found and what the failure it + /// was blamed for turned out to be. + /// + /// + /// It stays shared regardless, on the plainer argument: one session is enough, and a handshake per test + /// would be seconds of the suite's runtime spent proving nothing this file has not already proved. /// /// /// Safe to share because an SFTP session holds no per-test state: every test here works in a directory