From ae129282c87af4428d26bf84bd90185cd41441f3 Mon Sep 17 00:00:00 2001 From: "Jeremy D. Miller" Date: Sun, 2 Aug 2026 13:10:31 -0500 Subject: [PATCH] Wait for the ASB emulator's MANAGEMENT api, and pin the image (GH-3781 follow-up) CIAzureServiceBus has been reporting green while burning 22 of its 25-retry budget on every single run -- 85% of all retries in the repository -- and all 22 were one class, InlineSendingAndReceivingCompliance, failing identically four consecutive main runs in a row. Nothing about that is flaky. With retries forced off in CI, the real failure surfaced: Azure.Messaging.ServiceBus.ServiceBusException : Service is warming up. Please try after some time. Status: 503 (Service Unavailable) SystemTracker: localhost:$Resources/topics The emulator binds its AMQP listener on 5673 as soon as Kestrel starts, but its MANAGEMENT api on 5300 -- the one ServiceBusAdministrationClient uses to create queues and topics -- answers 503 for another ~26 seconds. The readiness gate was a bare TCP connect to 5673, so it announced "up and ready!" in under a second while every provisioning call still failed. InlineComplianceFixture threw out of InitializeAsync, which fails all 22 tests in the class at once, and the retry policy reran each of them alone in a fresh process -- warm by then -- so the job went green and nobody saw it. Nothing in Wolverine caused this. servicebus-emulator:latest moved 2.0.0 -> 2.0.1, and 2.0.1 warms more slowly. CI pulls :latest fresh every run and got the new image; a developer machine keeps whatever it pulled months ago, which is why this was never reproducible locally and why it appeared to land in a tidy three-commit window with no plausible commit in it. Reverting the only candidate in that window (GH-3774) changed nothing -- verified with a two-arm CI probe. So, both halves: - The gate now polls the management endpoint until it stops answering 503, and THROWS instead of logging a warning and carrying on. The old behaviour meant an emulator that never started at all still fed the whole suite into a broker that could not serve it, and the failures read as flaky tests rather than as infrastructure that never came up. Budget raised 60s -> 3 minutes; the measured warm-up is ~26s on a fast machine and a 4-vCPU runner is slower. - Both images pinned. The emulator to 2.0.1, which is what :latest resolves to today. azure-sql-edge publishes no concrete tag matching its :latest manifest, so it is pinned by digest -- byte-for-byte what CI has already been running, so it changes nothing except that it can no longer move underneath us. Verified locally against the exact CI image (pulled 2.0.1, removed the containers for a genuine cold start): the gate waits 26s and gets a 200 where it previously returned instantly on the TCP connect. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_0116vfBcKwcjWn8msM4ZjkuA --- build/CITargets.cs | 62 ++++++++++++++++++++++++++++++++++++++-------- docker-compose.yml | 15 ++++++++--- 2 files changed, 63 insertions(+), 14 deletions(-) diff --git a/build/CITargets.cs b/build/CITargets.cs index 8370ea4e7..20d3f7e95 100644 --- a/build/CITargets.cs +++ b/build/CITargets.cs @@ -227,28 +227,70 @@ void WaitForLocalStackToBeReady() Log.Warning("LocalStack did not become ready after 60 seconds"); } + /// + /// Waits for the Azure Service Bus emulator to be ready for provisioning, not merely accepting + /// sockets. + /// + /// The emulator binds its AMQP listener on 5673 as soon as Kestrel starts, but its MANAGEMENT api + /// on 5300 — the one ServiceBusAdministrationClient uses to create queues and topics — answers + /// 503 "Service is warming up. Please try after some time." for a good while after that. This + /// gate used to be a bare TCP connect to 5673, so it announced "up and ready!" while every provisioning + /// call still failed. The first test class to provision anything (InlineComplianceFixture) threw + /// out of InitializeAsync, which fails every test in its class — all 22 of them — and the + /// standing retry policy then reran each one alone in a fresh process, by which time the emulator was + /// warm. So the job reported GREEN while burning 22 of its 25-retry budget on every single run, and + /// those 22 were 85% of all retries in the entire repository. + /// + /// It went unnoticed for so long partly because it does not reproduce locally: docker-compose + /// pinned these images to :latest, and servicebus-emulator:latest moved from 2.0.0 to + /// 2.0.1, which warms up more slowly. CI pulls fresh every run and gets 2.0.1; a developer machine + /// keeps whatever it pulled months ago. The images are pinned now for exactly that reason. + /// void WaitForAzureServiceBusEmulatorToBeReady() { - var attempt = 0; - while (attempt < 30) + using var http = new System.Net.Http.HttpClient { Timeout = TimeSpan.FromSeconds(10) }; + + // Any management request will do. While warming, the emulator answers 503 to all of them; once warm + // it answers something else (200/400/401 depending on auth and api-version), so readiness does not + // 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) { try { - using var tcpClient = new System.Net.Sockets.TcpClient(); - tcpClient.Connect("localhost", 5673); - Log.Information("Azure Service Bus emulator is up and ready!"); - return; + 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) + catch (Exception e) { - // ignore connection errors + lastReason = e.Message; } Thread.Sleep(2000); - attempt++; } - Log.Warning("Azure Service Bus emulator did not become ready after 60 seconds"); + // 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}"); } /// diff --git a/docker-compose.yml b/docker-compose.yml index f8aa3d0ef..085e26bc4 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -146,8 +146,15 @@ services: volumes: - ./docker/oracle:/container-entrypoint-initdb.d + # These two were on :latest, which is how CI changed behaviour with no commit behind it: + # servicebus-emulator:latest moved 2.0.0 -> 2.0.1, 2.0.1 takes longer to warm its management api, and + # CIAzureServiceBus started failing a whole test class on every run (retried green, so nobody saw it). + # It was also unreproducible locally, because a developer machine keeps whatever it pulled months ago + # while CI pulls fresh every run. Pinned so the version moves only when someone moves it. + # azure-sql-edge publishes no concrete tag matching its :latest manifest, hence the digest -- it is + # byte-for-byte what CI has been running. asb-sql: - image: "mcr.microsoft.com/azure-sql-edge:latest" + image: "mcr.microsoft.com/azure-sql-edge@sha256:902628a8be89e35dfb7895ca31d602974c7bafde4d583a0d0873844feb1c42cf" environment: - "ACCEPT_EULA=Y" - "MSSQL_SA_PASSWORD=Strong_Passw0rd#2025" @@ -155,7 +162,7 @@ services: sb-emulator: asb-emulator: - image: "mcr.microsoft.com/azure-messaging/servicebus-emulator:latest" + image: "mcr.microsoft.com/azure-messaging/servicebus-emulator:2.0.1" volumes: - ./docker/asb/Config.json:/ServiceBus_Emulator/ConfigFiles/Config.json ports: @@ -172,7 +179,7 @@ services: sb-emulator: asb-sql-2: - image: "mcr.microsoft.com/azure-sql-edge:latest" + image: "mcr.microsoft.com/azure-sql-edge@sha256:902628a8be89e35dfb7895ca31d602974c7bafde4d583a0d0873844feb1c42cf" environment: - "ACCEPT_EULA=Y" - "MSSQL_SA_PASSWORD=Strong_Passw0rd#2025" @@ -180,7 +187,7 @@ services: sb-emulator-2: asb-emulator-2: - image: "mcr.microsoft.com/azure-messaging/servicebus-emulator:latest" + image: "mcr.microsoft.com/azure-messaging/servicebus-emulator:2.0.1" volumes: - ./docker/asb/Config.json:/ServiceBus_Emulator/ConfigFiles/Config.json ports: