[Bug][Backend][Profile] GET /api/Profile/images/6a5d78cacf3094d34c21faba 500s: stored image larger than advertised Content-Length; GlobalExceptionHandlerMiddleware then crashes writing after response start #758

Closed
opened 2026-07-21 02:54:57 +00:00 by spikerj · 3 comments
Owner

New error signature found in 2026-07-21 swarm recon — first seen 07-20 23:44:37Z, zero occurrences in the prior 24h; recurred 4x through 02:34:17Z (all the same request), survived the 01:42Z backend redeploy. Not attributable to a specific deploy — looks data-triggered.

Primary failure

GET /api/Profile/images/6a5d78cacf3094d34c21faba (anonymous, hit by HeadlessChrome UA — prerender/monitoring) throws:

System.InvalidOperationException: Response Content-Length mismatch: too many bytes written (737280 of 658063).

via ResponseCompressionBody.WriteAsync → Kestrel HttpProtocol.WritePipeAsync. The stored bytes for that image are 737,280 but the size the endpoint advertises is 658,063 — stale/incorrect size metadata for this one asset. Smells like the filesystem↔MinIO mirror-divergence class from #696 (one store updated, the size recorded from the other), but that needs confirming: compare the blob length in Mongo metadata vs filesystem vs MinIO photos/profile bucket for id 6a5d78cacf3094d34c21faba.

Secondary bug (code, fix regardless)

When the primary throws mid-stream, GlobalExceptionHandlerMiddleware.HandleExceptionAsync (SpikerSoft.Api/Middleware/GlobalExceptionHandlerMiddleware.cs:114) tries to set Response.ContentType and throws:

System.InvalidOperationException: Headers are read-only, response has already started.

The middleware must check context.Response.HasStarted and abort/log instead of attempting to write an error body — right now every mid-stream failure produces a second unhandled exception and a garbage half-response.

Repro/observe

curl -s -o /dev/null -w '%{http_code}' https://learn.spikersoft.com/api/Profile/images/6a5d78cacf3094d34c21faba (or Seq: filter @Exception like '%Content-Length mismatch%').

New error signature found in 2026-07-21 swarm recon — first seen **07-20 23:44:37Z**, zero occurrences in the prior 24h; recurred 4x through 02:34:17Z (all the same request), survived the 01:42Z backend redeploy. Not attributable to a specific deploy — looks data-triggered. ## Primary failure `GET /api/Profile/images/6a5d78cacf3094d34c21faba` (anonymous, hit by HeadlessChrome UA — prerender/monitoring) throws: ``` System.InvalidOperationException: Response Content-Length mismatch: too many bytes written (737280 of 658063). ``` via `ResponseCompressionBody.WriteAsync` → Kestrel `HttpProtocol.WritePipeAsync`. The stored bytes for that image are 737,280 but the size the endpoint advertises is 658,063 — stale/incorrect size metadata for this one asset. Smells like the filesystem↔MinIO mirror-divergence class from #696 (one store updated, the size recorded from the other), but that needs confirming: compare the blob length in Mongo metadata vs filesystem vs MinIO `photos`/profile bucket for id `6a5d78cacf3094d34c21faba`. ## Secondary bug (code, fix regardless) When the primary throws mid-stream, `GlobalExceptionHandlerMiddleware.HandleExceptionAsync` (`SpikerSoft.Api/Middleware/GlobalExceptionHandlerMiddleware.cs:114`) tries to set `Response.ContentType` and throws: ``` System.InvalidOperationException: Headers are read-only, response has already started. ``` The middleware must check `context.Response.HasStarted` and abort/log instead of attempting to write an error body — right now every mid-stream failure produces a second unhandled exception and a garbage half-response. ## Repro/observe `curl -s -o /dev/null -w '%{http_code}' https://learn.spikersoft.com/api/Profile/images/6a5d78cacf3094d34c21faba` (or Seq: filter `@Exception like '%Content-Length mismatch%'`).
Author
Owner

Verification at 02:56Z: https://api.spikersoft.com/api/Profile/images/6a5d78cacf3094d34c21faba currently returns 200 with exactly 658,063 bytes (image/png, both plain and gzip) — i.e. the advertised Content-Length is being honored right now.

So the failure is intermittent: 4 occurrences 23:44Z–02:34Z where the write path produced 737,280 bytes (= exactly 720 KiB) against the same 658,063 advertised length. That looks less like permanently-stale metadata and more like a racy read from a second store/variant — sometimes the handler streams a different (larger, possibly newer or padded) blob than the one whose length it advertised. Worth checking whether this endpoint reads via the filesystem↔MinIO dual-store path and whether id 6a5d78cacf3094d34c21faba has two copies of different sizes.

Verification at 02:56Z: `https://api.spikersoft.com/api/Profile/images/6a5d78cacf3094d34c21faba` currently returns **200 with exactly 658,063 bytes** (image/png, both plain and gzip) — i.e. the advertised Content-Length is being honored right now. So the failure is **intermittent**: 4 occurrences 23:44Z–02:34Z where the write path produced 737,280 bytes (= exactly 720 KiB) against the same 658,063 advertised length. That looks less like permanently-stale metadata and more like a **racy read from a second store/variant** — sometimes the handler streams a different (larger, possibly newer or padded) blob than the one whose length it advertised. Worth checking whether this endpoint reads via the filesystem↔MinIO dual-store path and whether id `6a5d78cacf3094d34c21faba` has two copies of different sizes.
Author
Owner

Resolved by spikersoft-backend PR #442 (merged + deployed): profile images now serve from MinIO via S3ImageStorageService — the GridFS advertised-length/actual-bytes mismatch path no longer exists. Verified live: GET api/Profile/images/6a5d78cacf3094d34c21faba → 200, 658063 bytes (exact migrated size; it was hash-verified during the #771 migration). GridFS profile-images.* since dropped. Closing.

Resolved by spikersoft-backend PR #442 (merged + deployed): profile images now serve from MinIO via S3ImageStorageService — the GridFS advertised-length/actual-bytes mismatch path no longer exists. Verified live: GET api/Profile/images/6a5d78cacf3094d34c21faba → 200, 658063 bytes (exact migrated size; it was hash-verified during the #771 migration). GridFS profile-images.* since dropped. Closing.
Author
Owner

Record correction (2026-07-22): the Content-Length-mismatch signature RECURRED once on the MinIO path (03:23Z, same image id), so my closure note attributing the fix to the storage cutover was wrong about root cause — the defect is in the serving path, storage-agnostic. Continued tracking with full evidence in the new ticket filed today; leaving this closed since the symptom that motivated it (repeating failures on GridFS) is gone.

Record correction (2026-07-22): the Content-Length-mismatch signature RECURRED once on the MinIO path (03:23Z, same image id), so my closure note attributing the fix to the storage cutover was wrong about root cause — the defect is in the serving path, storage-agnostic. Continued tracking with full evidence in the new ticket filed today; leaving this closed since the symptom that motivated it (repeating failures on GridFS) is gone.
Sign in to join this conversation.