diff --git a/.github/workflows/e2e.yml b/.github/workflows/e2e.yml index 1f0d86dd2..d8b613c71 100644 --- a/.github/workflows/e2e.yml +++ b/.github/workflows/e2e.yml @@ -125,6 +125,14 @@ jobs: for service in $(compose config --services); do compose logs --no-color --timestamps "$service" \ > "stack-logs/$service.log" 2>&1 || true + # …and a bounded tail of each into the job log, inside a collapsed group. A container + # that died takes its "why" with it, and the artifact is not always reachable from the + # environment triaging the run (#522) — the last 200 lines carry the stack trace, the + # failed migration or the shutdown reason, so the common cases stay diagnosable from + # the run page alone. + echo "::group::$service (last 200 log lines)" + tail -n 200 "stack-logs/$service.log" || true + echo "::endgroup::" done # Restart counts, exit codes, OOMKilled — the "did it crash or hang?" evidence. compose ps -aq | xargs -r docker inspect \ diff --git a/CHANGELOG.md b/CHANGELOG.md index 728121964..3878b7b5c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -259,6 +259,15 @@ follow [Semantic Versioning](https://semver.org). Ongoing work is collected unde ### Fixed +- **One failing background job no longer takes the whole API down.** Proxytrace runs a couple of + dozen background loops — trace ingestion, scheduled test runs, cleanups, search indexing, the + license check. On .NET's default, an unexpected error in *any one* of them shut down the entire + API process, and it shut down reporting success: the container exited cleanly, so a restart policy + saw nothing to restart and the deployment simply stayed dark until someone noticed. A failing loop + now stops on its own while the API and every other loop keep running, and the failure is recorded + in the error log where it can be seen and acted on. Work that genuinely must succeed before the + API serves anything — above all database migrations — still stops startup exactly as before. + - **The Costs page opens for everyone on the team again.** Reading spend has always been free for every project member, but the page also asked for the provider list behind it — something only an administrator may see. The refusal was treated as a page-wide failure, so anyone who is not an diff --git a/Proxytrace.Api/Program.cs b/Proxytrace.Api/Program.cs index 4a1e02223..624dada92 100644 --- a/Proxytrace.Api/Program.cs +++ b/Proxytrace.Api/Program.cs @@ -12,6 +12,7 @@ using Proxytrace.Api.Auth.Mcp; using Proxytrace.Api.Kiosk; using Proxytrace.Api.Middleware; +using Proxytrace.Common.Hosting; using Proxytrace.Domain.Kiosk; using Module = Proxytrace.Api.Module; @@ -32,6 +33,10 @@ builder.Services.AddHttpContextAccessor(); +// A throwing BackgroundService must not take the API down (see the extension's remarks and #522): +// .NET's default stops the host and exits 0, which no restart policy treats as a failure. +builder.Services.AddResilientBackgroundServices(); + // Throttle the anonymous auth endpoints (login/signup, password reset, MFA verify) per client IP. // In-memory is fine — each deployment runs a single API instance. Applied via // [EnableRateLimiting(...)] on the endpoints. NOTE: the partition key is the *connection* remote diff --git a/Proxytrace.Common.Tests/Hosting/HostingServiceCollectionExtensionsTests.cs b/Proxytrace.Common.Tests/Hosting/HostingServiceCollectionExtensionsTests.cs new file mode 100644 index 000000000..91e2939c6 --- /dev/null +++ b/Proxytrace.Common.Tests/Hosting/HostingServiceCollectionExtensionsTests.cs @@ -0,0 +1,100 @@ +using AwesomeAssertions; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Options; +using Proxytrace.Common.Hosting; + +namespace Proxytrace.Common.Tests.Hosting; + +/// +/// Covers the host-level guard from #522: an unhandled exception in a background loop must not +/// stop the process. These build a real rather than the shared test container, +/// because the behaviour under test *is* the host's own fault handling. +/// +[TestClass] +public sealed class HostingServiceCollectionExtensionsTests +{ + [TestMethod] + public void AddResilientBackgroundServices_ConfiguresIgnoreBehavior() + { + var services = new ServiceCollection(); + + services.AddResilientBackgroundServices(); + + HostOptions options = services.BuildServiceProvider().GetRequiredService>().Value; + options.BackgroundServiceExceptionBehavior.Should().Be(BackgroundServiceExceptionBehavior.Ignore); + } + + [TestMethod] + public async Task FaultedBackgroundService_WithResilientHosting_LeavesTheHostRunning() + { + using IHost host = BuildHost(configure: builder => builder.AddResilientBackgroundServices()); + + await host.StartAsync(CancellationToken.None); + await WaitForFaultAsync(host); + + // Still up: the faulted loop is gone, the process (and with it the HTTP surface) is not. + HostRunning(host).Should().BeTrue(); + + await host.StopAsync(CancellationToken.None); + } + + /// + /// The regression this guards against: on the framework default the same fault stops the host, + /// which is what produced the silent exit-0 API container in #522. + /// + [TestMethod] + public async Task FaultedBackgroundService_OnTheFrameworkDefault_StopsTheHost() + { + using IHost host = BuildHost(configure: _ => { }); + + await host.StartAsync(CancellationToken.None); + await WaitForFaultAsync(host); + + HostRunning(host).Should().BeFalse(); + } + + private static IHost BuildHost(Action configure) => + new HostBuilder() + .ConfigureServices(services => + { + configure(services); + services.AddSingleton(); + services.AddHostedService(sp => sp.GetRequiredService()); + }) + .Build(); + + /// + /// Waits until the background service has actually thrown, then gives the host a moment to act + /// on it — the stop is asynchronous, so asserting immediately would race the shutdown. + /// + private static async Task WaitForFaultAsync(IHost host) + { + await host.Services.GetRequiredService().Faulted; + await Task.Delay(TimeSpan.FromMilliseconds(200)); + } + + /// + /// The host's own view of whether it is still up: StopHost triggers the application + /// lifetime's stopping token, Ignore leaves it untouched. + /// + private static bool HostRunning(IHost host) => + !host.Services.GetRequiredService().ApplicationStopping.IsCancellationRequested; + + private sealed class ThrowingBackgroundService : BackgroundService + { + private readonly TaskCompletionSource faulted = + new(TaskCreationOptions.RunContinuationsAsynchronously); + + public Task Faulted => faulted.Task; + + protected override async Task ExecuteAsync(CancellationToken stoppingToken) + { + // Yield first: a synchronous throw completes inside StartAsync and would surface as a + // startup failure instead of the mid-run fault this covers. + await Task.Yield(); + faulted.SetResult(); + throw new InvalidOperationException("background loop failed"); + } + } +} diff --git a/Proxytrace.Common.Tests/Proxytrace.Common.Tests.csproj b/Proxytrace.Common.Tests/Proxytrace.Common.Tests.csproj index 64af353da..da6f9eb99 100644 --- a/Proxytrace.Common.Tests/Proxytrace.Common.Tests.csproj +++ b/Proxytrace.Common.Tests/Proxytrace.Common.Tests.csproj @@ -14,6 +14,9 @@ all + + diff --git a/Proxytrace.Common/Hosting/HostingServiceCollectionExtensions.cs b/Proxytrace.Common/Hosting/HostingServiceCollectionExtensions.cs new file mode 100644 index 000000000..c8acfdd2d --- /dev/null +++ b/Proxytrace.Common/Hosting/HostingServiceCollectionExtensions.cs @@ -0,0 +1,42 @@ +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; + +namespace Proxytrace.Common.Hosting; + +/// +/// Host-level wiring shared by every Proxytrace process host (the app API and the standalone +/// ingestion proxy). +/// +public static class HostingServiceCollectionExtensions +{ + /// + /// Makes an unhandled exception in a non-fatal to the host. + /// + /// .NET's default is : one throwing + /// background loop stops the whole host and the process exits with code 0 — a clean + /// shutdown, indistinguishable from an intentional stop. Nothing restarts on a zero exit + /// (`restart: on-failure`, most orchestrator defaults), the container simply stays down, and + /// the log line explaining why is a single Critical entry the process is already too far gone + /// to persist. That is how a licensed e2e `api` container went from healthy to gone in ~35s + /// with no diagnosable trace ([#522](https://github.com/NordsteinSoftware/Proxytrace/issues/522)). + /// + /// + /// The trade is deliberate: with the + /// faulted service stops but every other one — and the HTTP surface — keeps serving, and the + /// framework logs the fault at Error level. That level is exactly what + /// ErrorLogChannelLoggerProvider captures, so the crash lands in the in-product error + /// log instead of dying with the process. Losing one background loop is a degraded feature; + /// losing the host is a total outage. + /// + /// + /// This only covers faults. The startup-critical + /// work — schema initialization/migrations (DatabaseInitializationService), the secret + /// and preview backfills, the seeders — is implemented as plain + /// with the work in StartAsync, which still aborts startup when it throws. Keep it that + /// way: an API that came up against an unmigrated database must not serve traffic. + /// + /// + public static IServiceCollection AddResilientBackgroundServices(this IServiceCollection services) => + services.Configure(options => + options.BackgroundServiceExceptionBehavior = BackgroundServiceExceptionBehavior.Ignore); +} diff --git a/Proxytrace.Common/Proxytrace.Common.csproj b/Proxytrace.Common/Proxytrace.Common.csproj index b75d67b11..66db2d6ac 100644 --- a/Proxytrace.Common/Proxytrace.Common.csproj +++ b/Proxytrace.Common/Proxytrace.Common.csproj @@ -15,6 +15,9 @@ + + diff --git a/Proxytrace.Proxy.Api/Program.cs b/Proxytrace.Proxy.Api/Program.cs index 0b755a633..7f18ac867 100644 --- a/Proxytrace.Proxy.Api/Program.cs +++ b/Proxytrace.Proxy.Api/Program.cs @@ -2,6 +2,7 @@ using System.Text.Json.Serialization; using Autofac; using Autofac.Extensions.DependencyInjection; +using Proxytrace.Common.Hosting; using Proxytrace.Proxy.Controllers; var builder = WebApplication.CreateBuilder(args); @@ -17,6 +18,10 @@ builder.Host.ConfigureContainer(containerBuilder => containerBuilder.RegisterModule()); +// Same reasoning as the app API: a faulted BackgroundService (here the stored-license watcher) +// must degrade that loop, not stop the forwarding host with a clean exit 0. See #522. +builder.Services.AddResilientBackgroundServices(); + builder.Services.AddControllers() .AddJsonOptions(options => { diff --git a/docs/architecture.md b/docs/architecture.md index 6feb94985..714b0f34b 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -76,6 +76,36 @@ DI is wired with Autofac. Each project ships a `Module : Autofac.Module` (`Proxy **The `registerApplicationServices` flag.** When `true` — the API/app host and the test/perf harnesses (`Storage.Tests`, `Domain.Tests`, `Application.Tests`, the perf harness) — `Storage.Module` registers Storage's own startup/initialization hosted services: the DB-initializer (`IDatabaseInitializer`) plus the secret/preview backfill services. The standalone **proxy host** (`Proxytrace.Proxy.Api`) passes `false`: it attaches to an already-migrated database read-only and runs no schema init or backfills. Since [#270](https://github.com/NordsteinSoftware/Proxytrace/issues/270), `Storage.Module` no longer references or registers `Application.Module` (the flag's name is historical) — each composition root that needs the Application graph (the API host plus the four `Storage.Tests` / `Domain.Tests` / `Application.Tests` / perf harnesses) registers `Application.Module` **and** the at-rest secret seam (`Infrastructure.Security.SecretProtectionModule`) explicitly. The API root's registrations are idempotent (the `IfNotRegistered`/`builder.Properties` guards make any double registration a no-op). +## Hosted services: what may kill the host + +Both process hosts (`Proxytrace.Api`, `Proxytrace.Proxy.Api`) call +`AddResilientBackgroundServices()` from +[`Proxytrace.Common/Hosting/HostingServiceCollectionExtensions.cs`](../Proxytrace.Common/Hosting/HostingServiceCollectionExtensions.cs), +which sets `HostOptions.BackgroundServiceExceptionBehavior` to `Ignore`. .NET's default is +`StopHost`: **one** throwing `BackgroundService` stops the whole host and the process exits with +code **0** — a clean shutdown no restart policy treats as a failure, so the container just stays +down, and the Critical log line explaining it never gets persisted because the process is already +going away. That is how a healthy e2e `api` container vanished mid-run in +[#522](https://github.com/NordsteinSoftware/Proxytrace/issues/522). + +With `Ignore` the faulted loop stops and everything else — including the HTTP surface — keeps +serving, and the framework logs the fault at `Error`, which is exactly what +`ErrorLogChannelLoggerProvider` captures into the in-product error log. + +**This splits hosted services into two kinds, and the split is load-bearing:** + +| Kind | Base | On throw | +|---|---|---| +| Long-running loop (ingestion worker, schedulers, cleanups, license check, indexers, writers) | `BackgroundService` (work in `ExecuteAsync`) | Loop stops, logged at `Error`, host keeps running | +| Startup-critical work (`DatabaseInitializationService`, the secret/preview/tool backfills, the seeders) | `IHostedService` (work in `StartAsync`) | **Startup aborts** — unaffected by the option | + +So: put anything the API must not serve traffic without (schema migrations above all) in +`StartAsync` on a plain `IHostedService`; put anything whose failure should degrade one feature +rather than take the deployment down in `ExecuteAsync` on a `BackgroundService`. A background loop +that wants to survive its own transient failures still has to catch them itself (see +`ErrorLogWriter` and `LicenseCheckService.SafeRunCheckAsync` for the shape) — `Ignore` keeps the +*host* alive, it does not restart the loop. + ## Multi-tenant list scoping (`IProjectAccessGuard`) Every resource belongs to an `IProject`; users belong to projects via `Project.Members`, and the diff --git a/docs/testing.md b/docs/testing.md index 35c108e8b..1a4878e33 100644 --- a/docs/testing.md +++ b/docs/testing.md @@ -118,7 +118,10 @@ unavailable, skip the e2e suite and say so rather than attempting to run it. See In CI (`.github/workflows/e2e.yml`) a failing run uploads two artifacts: `playwright-report` (always) and `e2e-stack-logs` (on failure only) — per-service Docker Compose logs, container states, and `docker inspect` output, captured *before* teardown so stack-side failures stay -triageable. +triageable. The same step also echoes `compose ps -a` plus the **last 200 lines of every service** +into the job log (one collapsed group per service), so a container that crashed or exited can be +diagnosed from the run page without downloading the artifact — which is not always reachable from +wherever the triage happens ([#522](https://github.com/NordsteinSoftware/Proxytrace/issues/522)). ## Prompt behavior (prompt-lab) diff --git a/manual/admin/error-log.md b/manual/admin/error-log.md index ee1f4c21b..08cc08920 100644 --- a/manual/admin/error-log.md +++ b/manual/admin/error-log.md @@ -35,6 +35,19 @@ Errors are persisted to the database, so they survive restarts and are shared ac Entries from Entity Framework Core and the error-log pipeline itself are deliberately excluded to avoid feedback loops. +::: warning A failed background service is recorded here — and stays down until a restart +Proxytrace runs a number of background loops: trace ingestion, scheduled test runs, retention +cleanups, search indexing, the license check. If one of them fails unexpectedly it stops **on its +own** — the API and every other loop keep running, so the deployment stays up — and the failure is +recorded on this page with `BackgroundService failed` and the loop's stacktrace. + +That is deliberate: losing one feature beats losing the whole API. But the loop does **not** come +back by itself, so whatever it was doing (say, consuming captured traces) stays stopped until the +API container is restarted. An entry like this is worth acting on rather than filing away: restart +the API, then check that what the loop feeds — new traces arriving, scheduled runs firing — has +resumed. +::: + ::: tip API responses are sanitized — the Error Log is not Outside development, an unexpected server error returns only a generic message to the client (database conflicts surface as a friendly 409). The full exception message and stacktrace are