diff --git a/build/CITargets.cs b/build/CITargets.cs index 7ed84c154..c1c094dcf 100644 --- a/build/CITargets.cs +++ b/build/CITargets.cs @@ -133,154 +133,162 @@ void AwaitDockerServices(params string[] services) WaitForPubsubEmulatorToBeReady(); } - void WaitForPubsubEmulatorToBeReady() + /// + /// Polls until a service reports itself ready, and throws when the budget runs out. + /// + /// Every gate in this file used to log a warning and carry on. That is how + /// CIAzureServiceBus spent 22 of its 25-retry budget on four consecutive green main + /// runs: the gate declared the emulator ready in under a second, provisioning ran against an api + /// still answering 503, a class fixture threw, and 22 tests failed together — as flaky tests, not + /// as infrastructure that never came up. It was found by accident. GH-3783 made that one gate + /// fatal; this makes the rest of them fatal through a single shared path, so a gate added later + /// cannot quietly reintroduce the warn-and-continue shape. + /// + /// A container that never starts should fail its job in seconds with a message naming the + /// service, not hand the whole suite to a broker that cannot serve it. + /// + /// + /// Returns null when the service is ready, or a short reason why it is not. Exceptions are + /// treated as "not ready" and their message becomes the reason, so the final error carries the + /// last real failure rather than a generic timeout. + /// + void awaitService(string name, TimeSpan budget, Func probe) { - var attempt = 0; - while (attempt < 30) + var deadline = DateTime.UtcNow.Add(budget); + var lastReason = "no attempt completed"; + var attempts = 0; + + while (true) { + attempts++; + try { - using var tcpClient = new System.Net.Sockets.TcpClient(); - tcpClient.Connect("localhost", 8085); - Log.Information("GCP Pub/Sub emulator is up and ready!"); - return; + var reason = probe(); + if (reason is null) + { + Log.Information("{Service} is up and ready (attempt {Attempts})", name, attempts); + return; + } + + lastReason = reason; } - catch (Exception) + catch (Exception e) { - // ignore connection errors + lastReason = e.Message; } + if (DateTime.UtcNow >= deadline) break; + Thread.Sleep(2000); - attempt++; } - Log.Warning("GCP Pub/Sub emulator did not become ready after 60 seconds"); + throw new InvalidOperationException( + $"{name} was not ready after {budget.TotalSeconds:n0}s ({attempts} attempts). " + + $"Last attempt: {lastReason}"); } - void WaitForKafkaToBeReady() + /// + /// Opens a TCP connection, returning null when it succeeds. The weakest probe shape available — + /// a listening socket is not the same claim as a broker that will serve a request — so prefer a + /// real protocol call wherever the client library is already referenced here. + /// + static string tcpProbe(string host, int port) + { + using var tcpClient = new System.Net.Sockets.TcpClient(); + tcpClient.Connect(host, port); + return null; + } + + void WaitForPubsubEmulatorToBeReady() { - var attempt = 0; - while (attempt < 30) + // The emulator answers HTTP on its main port, so this asks it a question rather than only + // checking that something is listening — the distinction the ASB gate was built on. + using var http = new System.Net.Http.HttpClient { Timeout = TimeSpan.FromSeconds(5) }; + + awaitService("GCP Pub/Sub emulator", TimeSpan.FromSeconds(60), () => { - try - { - using var tcpClient = new System.Net.Sockets.TcpClient(); - tcpClient.Connect("localhost", 9092); - Log.Information("Kafka is up and ready!"); - return; - } - catch (Exception) - { - // ignore connection errors - } + var response = http.GetAsync("http://localhost:8085/").GetAwaiter().GetResult(); - Thread.Sleep(2000); - attempt++; - } + // Any HTTP answer means the emulator is serving. Deliberately not asserting 200: the + // lesson from GH-3783 is that pinning a gate to one status code is how it hangs when the + // service legitimately answers a different one. + return response is null ? "no response" : null; + }); + } - Log.Warning("Kafka did not become ready after 60 seconds"); + void WaitForKafkaToBeReady() + { + // Still TCP-only, and knowingly the weakest gate here: a Kafka broker accepts connections + // before it will serve metadata or allow topic creation, so this can pass while the broker + // is not yet usable. Fixing it properly means a metadata request through an AdminClient, and + // Confluent.Kafka is not referenced by this build project (nor centrally versioned), so that + // is a change with its own risk rather than a line here. Tracked separately; making the gate + // fatal is the part that matters today. + awaitService("Kafka", TimeSpan.FromSeconds(60), () => tcpProbe("localhost", 9092)); } void WaitForSqlServerToBeReady() { - var attempt = 0; - while (attempt < 30) - { - try - { - using var conn = new Microsoft.Data.SqlClient.SqlConnection("Server=localhost,1434;User Id=sa;Password=P@55w0rd;Timeout=5;Encrypt=False"); - conn.Open(); - var cmd = conn.CreateCommand(); - cmd.CommandText = "SELECT 1"; - cmd.ExecuteNonQuery(); - Log.Information("SQL Server is up and ready!"); - return; - } - catch (Exception) - { - Thread.Sleep(2000); - attempt++; - } - } - - Log.Warning("SQL Server did not become ready after 60 seconds"); + // Budget is now wall-clock rather than an attempt count. The old "60 seconds" in the warning + // was never true: each failed attempt could burn the connection's own 5s timeout before the + // 2s sleep, so 30 attempts was anywhere from 60s to 210s depending on how the failure came + // back. A deadline says what it means. + awaitService("SQL Server", TimeSpan.FromMinutes(2), () => + { + using var conn = new Microsoft.Data.SqlClient.SqlConnection( + "Server=localhost,1434;User Id=sa;Password=P@55w0rd;Timeout=5;Encrypt=False"); + conn.Open(); + var cmd = conn.CreateCommand(); + cmd.CommandText = "SELECT 1"; + cmd.ExecuteNonQuery(); + return null; + }); } void WaitForMySqlToBeReady() { - var attempt = 0; - while (attempt < 30) - { - try - { - using var conn = new MySqlConnector.MySqlConnection("Server=localhost;Port=3306;Database=wolverine;User=root;Password=P@55w0rd;"); - conn.Open(); - var cmd = conn.CreateCommand(); - cmd.CommandText = "SELECT 1"; - cmd.ExecuteNonQuery(); - Log.Information("MySQL is up and ready!"); - return; - } - catch (Exception) - { - Thread.Sleep(2000); - attempt++; - } - } - - Log.Warning("MySQL did not become ready after 60 seconds"); + awaitService("MySQL", TimeSpan.FromMinutes(2), () => + { + using var conn = new MySqlConnector.MySqlConnection( + "Server=localhost;Port=3306;Database=wolverine;User=root;Password=P@55w0rd;"); + conn.Open(); + var cmd = conn.CreateCommand(); + cmd.CommandText = "SELECT 1"; + cmd.ExecuteNonQuery(); + return null; + }); } void WaitForOracleToBeReady() { - var attempt = 0; - while (attempt < 60) - { - try - { - using var conn = new Oracle.ManagedDataAccess.Client.OracleConnection("User Id=wolverine;Password=wolverine;Data Source=localhost:1521/FREEPDB1"); - conn.Open(); - var cmd = conn.CreateCommand(); - cmd.CommandText = "SELECT 1 FROM DUAL"; - cmd.ExecuteNonQuery(); - Log.Information("Oracle is up and ready!"); - return; - } - catch (Exception) - { - Thread.Sleep(2000); - attempt++; - } - } - - Log.Warning("Oracle did not become ready after 120 seconds"); + // Oracle is the slowest image in the compose file to reach a usable state, hence the roomiest + // budget. Connecting as the application user against FREEPDB1 (rather than pinging the + // listener) is deliberate: the listener answers well before the pluggable database will + // accept an application login. + awaitService("Oracle", TimeSpan.FromMinutes(3), () => + { + using var conn = new Oracle.ManagedDataAccess.Client.OracleConnection( + "User Id=wolverine;Password=wolverine;Data Source=localhost:1521/FREEPDB1"); + conn.Open(); + var cmd = conn.CreateCommand(); + cmd.CommandText = "SELECT 1 FROM DUAL"; + cmd.ExecuteNonQuery(); + return null; + }); } void WaitForLocalStackToBeReady() { - var attempt = 0; using var httpClient = new System.Net.Http.HttpClient { Timeout = TimeSpan.FromSeconds(5) }; - while (attempt < 30) - { - try - { - var response = httpClient.GetAsync("http://localhost:4566/_localstack/health").GetAwaiter().GetResult(); - if (response.IsSuccessStatusCode) - { - Log.Information("LocalStack is up and ready!"); - return; - } - } - catch (Exception) - { - // ignore connection errors - } - Thread.Sleep(2000); - attempt++; - } + awaitService("LocalStack", TimeSpan.FromMinutes(2), () => + { + var response = httpClient.GetAsync("http://localhost:4566/_localstack/health") + .GetAwaiter().GetResult(); - Log.Warning("LocalStack did not become ready after 60 seconds"); + return response.IsSuccessStatusCode ? null : $"health endpoint answered {(int)response.StatusCode}"; + }); } /// @@ -311,42 +319,26 @@ void WaitForAzureServiceBusEmulatorToBeReady() // depend on getting the ATOM api-version right here. const string managementProbe = "http://localhost:5300/$Resources/topics"; - var deadline = DateTime.UtcNow.AddMinutes(3); - var lastReason = "no attempt completed"; - - while (DateTime.UtcNow < deadline) + // Deliberately fatal, via the same shared path as every other gate. This used to log a warning + // and carry on, so an emulator that never came up at all still fed the entire suite into a + // broker that could not serve it — and the resulting failures read as flaky tests rather than + // as infrastructure that never started. + awaitService("Azure Service Bus emulator", TimeSpan.FromMinutes(3), () => { - try - { - using (var tcpClient = new System.Net.Sockets.TcpClient()) - { - tcpClient.Connect("localhost", 5673); - } - - var response = http.GetAsync(managementProbe).GetAwaiter().GetResult(); - if (response.StatusCode != System.Net.HttpStatusCode.ServiceUnavailable) - { - Log.Information( - "Azure Service Bus emulator is up and ready for provisioning (management api answered {StatusCode})", - (int)response.StatusCode); - return; - } - - lastReason = "the management api on 5300 is still warming up (503)"; - } - catch (Exception e) + using (var tcpClient = new System.Net.Sockets.TcpClient()) { - lastReason = e.Message; + tcpClient.Connect("localhost", 5673); } - Thread.Sleep(2000); - } + var response = http.GetAsync(managementProbe).GetAwaiter().GetResult(); - // Deliberately fatal. This used to log a warning and carry on, so an emulator that never came up at - // all still fed the entire suite into a broker that could not serve it — and the resulting failures - // read as flaky tests rather than as infrastructure that never started. - throw new InvalidOperationException( - $"The Azure Service Bus emulator was not ready for provisioning after 3 minutes. Last attempt: {lastReason}"); + // Keyed on "not 503", NOT on "== 200". CI answers 400 here and a developer machine + // answers 200; asserting 200 would hang for the whole budget and then fail the job. This + // distinction cost a day to find — do not tighten it. + return response.StatusCode == System.Net.HttpStatusCode.ServiceUnavailable + ? "the management api on 5300 is still warming up (503)" + : null; + }); } /// diff --git a/build/build.cs b/build/build.cs index 01973afe7..460e6c46a 100644 --- a/build/build.cs +++ b/build/build.cs @@ -405,30 +405,29 @@ bool IsDotNetToolInstalled(string toolName) return output.Any(line => line.Contains(toolName, StringComparison.OrdinalIgnoreCase)); } + /// + /// Postgres readiness. This was the thinnest gate in the build by a wide margin: ten attempts + /// separated by 250ms is a 2.5 second budget for a container start, after which it logged + /// an error and let the suite run anyway. + /// + /// It was already running out of room in production. In CIMQTT5 on main run 30847233633 it + /// spent four of its ten attempts before Postgres answered — roughly 1.1s of a 2.5s allowance — + /// so a slower runner would have sailed past the end and started the tests against a database + /// that was not up. Every failure after that would have looked like a test problem. + /// private void WaitForDatabaseToBeReady() { - var attempt = 0; - while (attempt < 10) - try - { - using var conn = new Npgsql.NpgsqlConnection(PostgresConnectionString + ";Pooling=false"); - conn.Open(); - - var cmd = conn.CreateCommand(); - cmd.CommandText = "select 1"; - cmd.ExecuteNonQuery(); + awaitService("PostgreSQL", TimeSpan.FromMinutes(2), () => + { + using var conn = new Npgsql.NpgsqlConnection(PostgresConnectionString + ";Pooling=false"); + conn.Open(); - Log.Information("Postgresql is up and ready!"); - return; - } - catch (Exception ex) - { - Log.Information("Database is not ready ({Error})", ex.Message); - Thread.Sleep(250); - attempt++; - } + var cmd = conn.CreateCommand(); + cmd.CommandText = "select 1"; + cmd.ExecuteNonQuery(); - Log.Error("Database is not ready after all attempts."); + return null; + }); } private Dictionary ReferencedProjects = new() diff --git a/docker-compose.yml b/docker-compose.yml index 085e26bc4..384bed92e 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -56,7 +56,9 @@ services: # GCS emulator used by the WolverineFx.ClaimCheck.GoogleCloudStorage backend tests. # Serves plain HTTP on 4443; tests point the client at it via STORAGE_EMULATOR_HOST. fake-gcs-server: - image: "fsouza/fake-gcs-server:latest" + # Pinned: :latest resolved to exactly this tag when it was pinned, so this is byte-for-byte what + # CI had been running. See the note on asb-emulator below for why a rolling tag is a trap here. + image: "fsouza/fake-gcs-server:1.55.1" ports: - "4443:4443" command: ["-scheme", "http", "-host", "0.0.0.0", "-port", "4443", "-public-host", "localhost:4443"] @@ -73,7 +75,17 @@ services: # If you're working locally on ARM and don't need Polecat tests, you can override this service # using `docker-compose -f docker-compose.yml -f docker-compose.azure-sql-edge.yml up -d` sqlserver: - image: mcr.microsoft.com/mssql/server:2025-latest + # 2025-latest is a rolling tag: it moves on every cumulative update, CI pulls it fresh every run, + # and a developer machine keeps whatever it pulled months ago. Pinned by digest rather than tag + # because no concrete 2025-CU* tag matches the 2025-latest manifest -- the same reason + # azure-sql-edge below is pinned by digest. This is byte-for-byte what CI was already running. + # + # Resolve this digest with `docker buildx imagetools inspect :`, never with a curl of + # the registry's manifest endpoint. A HEAD with an Accept for a manifest LIST returns MCR a + # digest for a representation that does not exist as a pullable manifest here -- this tag is a + # single-platform manifest -- and the resulting pin fails every job that needs SQL Server with + # "manifest unknown". Ask the tool that will do the pulling. + image: mcr.microsoft.com/mssql/server@sha256:86cc6144ef39bb0fbed2329e1ad79b13ee82e7b2e4739213a0db0800e668a74a ports: - "1434:1433" environment: @@ -83,7 +95,9 @@ services: - "MSSQL_PID=Developer" pulsar: - image: "apachepulsar/pulsar:4.0.3" + # Kept in step with PulsarContainerFixture, which is what CI actually runs against (Testcontainers). + # This said 4.0.3 while the fixture said :latest -- two different Pulsars for the same test suite. + image: "apachepulsar/pulsar:4.2.4" ports: - "6650:6650" - "8080:8080" @@ -121,7 +135,9 @@ services: - "6379:6379" nats: - image: "nats:2" + # Kept in step with NatsContainerFixture.NatsImage, which is what the NATS tests actually run + # against (Testcontainers). "nats:2" is a floating minor; it happens to equal 2.14.4 today. + image: "nats:2.14.4" ports: - "4222:4222" - "8222:8222" diff --git a/src/Transports/NATS/Wolverine.Nats.Tests/NatsContainerFixture.cs b/src/Transports/NATS/Wolverine.Nats.Tests/NatsContainerFixture.cs index 685e3a38e..295500a5f 100644 --- a/src/Transports/NATS/Wolverine.Nats.Tests/NatsContainerFixture.cs +++ b/src/Transports/NATS/Wolverine.Nats.Tests/NatsContainerFixture.cs @@ -5,6 +5,17 @@ namespace Wolverine.Nats.Tests; public class NatsContainerFixture : IAsyncLifetime { + /// + /// GH-3799. Pinned, and shared by every NATS container in this project so the version lives in + /// one place instead of three string literals that can drift apart. + /// + /// 2.14.4 is exactly what nats:latest resolved to when this was pinned, so nothing + /// about what CI runs changes — it just stops changing on its own. A rolling tag is pulled fresh + /// on every CI run and never on a developer machine, which is how a moving + /// servicebus-emulator spent four runs looking like a code regression (GH-3783). + /// + public const string NatsImage = "nats:2.14.4"; + private static NatsContainer? _container; private static string? _connectionString; private static int _referenceCount; @@ -21,7 +32,7 @@ public async ValueTask InitializeAsync() if (_container != null) return; _container = new NatsBuilder() - .WithImage("nats:latest") + .WithImage(NatsImage) .Build(); await _container.StartAsync(); diff --git a/src/Transports/NATS/Wolverine.Nats.Tests/NatsNamedBrokerTests.cs b/src/Transports/NATS/Wolverine.Nats.Tests/NatsNamedBrokerTests.cs index d527e9d67..040bc30ff 100644 --- a/src/Transports/NATS/Wolverine.Nats.Tests/NatsNamedBrokerTests.cs +++ b/src/Transports/NATS/Wolverine.Nats.Tests/NatsNamedBrokerTests.cs @@ -102,7 +102,7 @@ public async ValueTask InitializeAsync() return; } - _serverB = new NatsBuilder().WithImage("nats:latest").Build(); + _serverB = new NatsBuilder().WithImage(NatsContainerFixture.NatsImage).Build(); await _serverB.StartAsync(); _serverBUrl = _serverB.GetConnectionString(); diff --git a/src/Transports/NATS/Wolverine.Nats.Tests/NatsPerTenantConnectionTests.cs b/src/Transports/NATS/Wolverine.Nats.Tests/NatsPerTenantConnectionTests.cs index 7b52059bb..826ea34c1 100644 --- a/src/Transports/NATS/Wolverine.Nats.Tests/NatsPerTenantConnectionTests.cs +++ b/src/Transports/NATS/Wolverine.Nats.Tests/NatsPerTenantConnectionTests.cs @@ -54,7 +54,7 @@ public async ValueTask InitializeAsync() // Server B is a second, independent broker so "used the tenant's own connection" is provable: the // message can only appear on B if the dedicated connection carried it there. - _serverB = new NatsBuilder().WithImage("nats:latest").Build(); + _serverB = new NatsBuilder().WithImage(NatsContainerFixture.NatsImage).Build(); await _serverB.StartAsync(); _serverBUrl = _serverB.GetConnectionString(); diff --git a/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarContainerFixture.cs b/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarContainerFixture.cs index 39e9e9936..bd62332a0 100644 --- a/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarContainerFixture.cs +++ b/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarContainerFixture.cs @@ -6,6 +6,17 @@ namespace Wolverine.Pulsar.Tests; public static class PulsarContainerFixture { + /// + /// GH-3799. Pinned, and shared by every Pulsar container in this project. + /// + /// 4.2.4 is exactly what apachepulsar/pulsar:latest resolved to when this was + /// pinned — and :latest had moved to it that same day, so CI's Pulsar was changing under + /// the suite with nothing in the repository recording it. docker-compose.yml is set to the same + /// version; it previously said 4.0.3, which meant a developer and CI were running different + /// brokers for the same tests. + /// + public const string PulsarImage = "apachepulsar/pulsar:4.2.4"; + private static PulsarContainer? _container; public static Uri ServiceUrl { get; private set; } = new("pulsar://localhost:6650"); @@ -35,7 +46,7 @@ internal static void Initialize() // Console.Out. The banner lands in the raw protocol channel and the whole assembly dies // with "Test process did not return valid JSON", running no tests at all. _container = new PulsarBuilder() - .WithImage("apachepulsar/pulsar:latest") + .WithImage(PulsarImage) .WithLogger(NullLogger.Instance) .Build(); diff --git a/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarPerTenantConnectionTests.cs b/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarPerTenantConnectionTests.cs index ca24878b4..3c519494e 100644 --- a/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarPerTenantConnectionTests.cs +++ b/src/Transports/Pulsar/Wolverine.Pulsar.Tests/PulsarPerTenantConnectionTests.cs @@ -44,7 +44,7 @@ public async ValueTask InitializeAsync() try { - _clusterB = new PulsarBuilder().WithImage("apachepulsar/pulsar:latest").Build(); + _clusterB = new PulsarBuilder().WithImage(PulsarContainerFixture.PulsarImage).Build(); await _clusterB.StartAsync(); _clusterBServiceUrl = new Uri(_clusterB.GetBrokerAddress());