fix(cms-upload): scope InfiniteTimeSpan to upload client; add response-wait budget after body completes

This commit is contained in:
daniel-c-harvey
2026-06-17 11:14:15 -04:00
parent c9c6286571
commit 803bc7840a
3 changed files with 177 additions and 25 deletions
+14 -5
View File
@@ -44,17 +44,26 @@ builder.Services.AddHttpClient("DeepDrft.Content", client =>
client.BaseAddress = new Uri(contentApiUrl); client.BaseAddress = new Uri(contentApiUrl);
}); });
// Named HttpClient for ApiKey-protected Content API calls (CmsTrackService's vault delete). // Named HttpClient for ApiKey-protected Content API calls (CmsTrackService's non-upload operations:
// API key baked into the default request headers so callers need not add it manually. // delete, paged list, metadata read/write, waveform jobs, releases, genres).
// Timeout left at the default 100s — these are short request/response pairs and an infinite timeout
// would hang an InteractiveServer circuit forever on a dead connection.
var contentApiKey = builder.Configuration["Api:ContentApiKey"] var contentApiKey = builder.Configuration["Api:ContentApiKey"]
?? throw new InvalidOperationException("Api:ContentApiKey is required"); ?? throw new InvalidOperationException("Api:ContentApiKey is required");
builder.Services.AddHttpClient("DeepDrft.Content.Cms", client => builder.Services.AddHttpClient("DeepDrft.Content.Cms", client =>
{ {
client.BaseAddress = new Uri(contentApiUrl); client.BaseAddress = new Uri(contentApiUrl);
client.DefaultRequestHeaders.Add("ApiKey", contentApiKey); client.DefaultRequestHeaders.Add("ApiKey", contentApiKey);
// Large mix uploads (several hundred MB) outrun the 100s default whole-request timeout. The send });
// path enforces an idle/heartbeat deadline instead (CmsTrackService), which can only express
// "no bytes for N seconds" if the client itself does not impose a total cap — hence Infinite here. // Dedicated upload client — inherits the API key but removes the whole-request timeout.
// Large WAV uploads (several hundred MB) outrun the 100s default. The upload path enforces an
// idle/heartbeat deadline instead (body-streaming phase via ProgressStreamContent) plus a separate
// response-wait budget (CmsTrackService), so the client itself must not impose a total cap.
builder.Services.AddHttpClient("DeepDrft.Content.Cms.Upload", client =>
{
client.BaseAddress = new Uri(contentApiUrl);
client.DefaultRequestHeaders.Add("ApiKey", contentApiKey);
client.Timeout = Timeout.InfiniteTimeSpan; client.Timeout = Timeout.InfiniteTimeSpan;
}); });
+65 -13
View File
@@ -18,16 +18,26 @@ namespace DeepDrftManager.Services;
public class CmsTrackService : ICmsTrackService public class CmsTrackService : ICmsTrackService
{ {
private const string ContentCmsClientName = "DeepDrft.Content.Cms"; private const string ContentCmsClientName = "DeepDrft.Content.Cms";
private const string UploadClientName = "DeepDrft.Content.Cms.Upload";
private const string UploadPath = "api/track/upload"; private const string UploadPath = "api/track/upload";
// Idle/heartbeat window: abort an upload only after this long with zero bytes written to the wire. // Idle/heartbeat window: abort an upload only after this long with zero bytes written to the wire.
// The window resets on every progress tick, so a slow-but-moving half-gig upload never trips it; // The window resets on every progress tick, so a slow-but-moving half-gig upload never trips it;
// a genuinely stalled socket does. Operator-tunable via Upload:IdleTimeoutSeconds. // a genuinely stalled socket does. Governs the BODY-STREAMING phase only.
// Operator-tunable via Upload:IdleTimeoutSeconds.
private const int DefaultIdleTimeoutSeconds = 90; private const int DefaultIdleTimeoutSeconds = 90;
// Response-wait budget: once the request body is fully on the wire the server runs AudioProcessor
// decode → vault write → SQL persist. For a several-hundred-MB WAV this can take many minutes.
// The idle heartbeat goes silent after the last byte, so a separate, larger deadline governs the
// response-wait phase so a fully-uploaded file is never killed mid-persist.
// Operator-tunable via Upload:ResponseTimeoutSeconds.
private const int DefaultResponseTimeoutSeconds = 600; // 10 minutes
private readonly IHttpClientFactory _httpClientFactory; private readonly IHttpClientFactory _httpClientFactory;
private readonly ILogger<CmsTrackService> _logger; private readonly ILogger<CmsTrackService> _logger;
private readonly TimeSpan _uploadIdleTimeout; private readonly TimeSpan _uploadIdleTimeout;
private readonly TimeSpan _uploadResponseTimeout;
public CmsTrackService( public CmsTrackService(
IHttpClientFactory httpClientFactory, IHttpClientFactory httpClientFactory,
@@ -36,8 +46,10 @@ public class CmsTrackService : ICmsTrackService
{ {
_httpClientFactory = httpClientFactory; _httpClientFactory = httpClientFactory;
_logger = logger; _logger = logger;
var seconds = configuration.GetValue<int?>("Upload:IdleTimeoutSeconds") ?? DefaultIdleTimeoutSeconds; var idleSeconds = configuration.GetValue<int?>("Upload:IdleTimeoutSeconds") ?? DefaultIdleTimeoutSeconds;
_uploadIdleTimeout = TimeSpan.FromSeconds(seconds > 0 ? seconds : DefaultIdleTimeoutSeconds); _uploadIdleTimeout = TimeSpan.FromSeconds(idleSeconds > 0 ? idleSeconds : DefaultIdleTimeoutSeconds);
var responseSeconds = configuration.GetValue<int?>("Upload:ResponseTimeoutSeconds") ?? DefaultResponseTimeoutSeconds;
_uploadResponseTimeout = TimeSpan.FromSeconds(responseSeconds > 0 ? responseSeconds : DefaultResponseTimeoutSeconds);
} }
public async Task<ResultContainer<TrackDto>> UploadTrackAsync( public async Task<ResultContainer<TrackDto>> UploadTrackAsync(
@@ -59,21 +71,51 @@ public class CmsTrackService : ICmsTrackService
IProgress<long>? progress = null, IProgress<long>? progress = null,
CancellationToken ct = default) CancellationToken ct = default)
{ {
// Idle/heartbeat cancellation: HttpClient.Timeout is a whole-request cap and cannot express // Two-phase cancellation for the upload send:
// "no bytes for N seconds", so the named client runs with InfiniteTimeSpan and the deadline //
// lives here. Each ProgressStreamContent tick resets CancelAfter(idle); a stalled socket lets // BODY-STREAMING phase (while bytes are on the wire):
// the window elapse and cancels the send. Linked to the caller's ct so a page cancel still wins. // idleCts fires if no progress tick arrives within the idle window. Each
// ProgressStreamContent chunk resets CancelAfter(idle), so a slow-but-moving
// upload never trips it; a genuinely stalled socket does.
//
// RESPONSE-WAIT phase (after the last byte, while the server persists):
// The idle heartbeat goes silent once the body is fully sent. responseCts is
// armed at that moment with a larger budget so a fully-uploaded file is never
// killed mid-persist. idleCts is simultaneously disarmed (CancelAfter(Infinite))
// so it cannot misfire during the response-wait.
//
// sendCts links both so either deadline — plus the caller's ct — cancels the send.
using var idleCts = CancellationTokenSource.CreateLinkedTokenSource(ct); using var idleCts = CancellationTokenSource.CreateLinkedTokenSource(ct);
idleCts.CancelAfter(_uploadIdleTimeout); idleCts.CancelAfter(_uploadIdleTimeout);
// responseCts starts disarmed; the body-complete callback below arms it.
using var responseCts = CancellationTokenSource.CreateLinkedTokenSource(ct);
// Umbrella token passed to SendAsync — either phase token (or the caller) can cancel.
using var sendCts = CancellationTokenSource.CreateLinkedTokenSource(idleCts.Token, responseCts.Token);
// Rebuild the multipart container so the boundary is owned by HttpClient and the // Rebuild the multipart container so the boundary is owned by HttpClient and the
// caller-supplied stream (already buffered by the SignalR upload) is the source. // caller-supplied stream (already buffered by the SignalR upload) is the source.
using var multipart = new MultipartFormDataContent(); using var multipart = new MultipartFormDataContent();
var wavContent = new ProgressStreamContent(wavStream, contentLength, written => var wavContent = new ProgressStreamContent(
wavStream,
contentLength,
written =>
{ {
// One mechanism, two consumers: advance the UI meter and reset the idle heartbeat. // One mechanism, three consumers: advance the UI meter, reset the idle heartbeat,
// and on body-complete transition to the response-wait budget.
progress?.Report(written); progress?.Report(written);
if (written < contentLength)
{
// Body still in flight — keep the idle heartbeat alive.
idleCts.CancelAfter(_uploadIdleTimeout); idleCts.CancelAfter(_uploadIdleTimeout);
}
else
{
// Last byte on the wire. Disarm the idle timer and start the response budget.
idleCts.CancelAfter(Timeout.InfiniteTimeSpan);
responseCts.CancelAfter(_uploadResponseTimeout);
}
}); });
wavContent.Headers.ContentType = new MediaTypeHeaderValue( wavContent.Headers.ContentType = new MediaTypeHeaderValue(
string.IsNullOrWhiteSpace(contentType) ? "audio/wav" : contentType); string.IsNullOrWhiteSpace(contentType) ? "audio/wav" : contentType);
@@ -93,22 +135,32 @@ public class CmsTrackService : ICmsTrackService
// for an unrecognised value). Authoritative only when this upload creates the release. // for an unrecognised value). Authoritative only when this upload creates the release.
multipart.Add(new StringContent(medium.ToString()), "medium"); multipart.Add(new StringContent(medium.ToString()), "medium");
var client = _httpClientFactory.CreateClient(ContentCmsClientName); // Use the dedicated upload client (InfiniteTimeSpan) so the two-phase CTS logic above is the
// sole timeout authority. Non-upload operations use the bounded "DeepDrft.Content.Cms" client.
var client = _httpClientFactory.CreateClient(UploadClientName);
using var request = new HttpRequestMessage(HttpMethod.Post, UploadPath) { Content = multipart }; using var request = new HttpRequestMessage(HttpMethod.Post, UploadPath) { Content = multipart };
HttpResponseMessage response; HttpResponseMessage response;
try try
{ {
response = await client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead, idleCts.Token); response = await client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead, sendCts.Token);
} }
catch (OperationCanceledException) when (idleCts.IsCancellationRequested && !ct.IsCancellationRequested) catch (OperationCanceledException) when (!ct.IsCancellationRequested)
{
// Either idle window (body-streaming stall) or response-wait budget (server persist too slow).
if (idleCts.IsCancellationRequested)
{ {
// Idle window elapsed with no bytes moving — a stalled connection, not a caller cancel.
_logger.LogWarning("Upload of {TrackName} stalled — no progress for {IdleSeconds}s; aborting.", _logger.LogWarning("Upload of {TrackName} stalled — no progress for {IdleSeconds}s; aborting.",
trackName, _uploadIdleTimeout.TotalSeconds); trackName, _uploadIdleTimeout.TotalSeconds);
return ResultContainer<TrackDto>.CreateFailResult( return ResultContainer<TrackDto>.CreateFailResult(
$"Upload stalled — no data transferred for {_uploadIdleTimeout.TotalSeconds:0}s. Please retry."); $"Upload stalled — no data transferred for {_uploadIdleTimeout.TotalSeconds:0}s. Please retry.");
} }
// responseCts fired: body reached the server but persist timed out.
_logger.LogWarning("Upload of {TrackName} timed out waiting for server response after {ResponseSeconds}s.",
trackName, _uploadResponseTimeout.TotalSeconds);
return ResultContainer<TrackDto>.CreateFailResult(
$"Upload timed out waiting for the server to respond after {_uploadResponseTimeout.TotalSeconds:0}s. Please retry.");
}
catch (Exception ex) catch (Exception ex)
{ {
_logger.LogError(ex, "Content API call failed for upload of {TrackName}", trackName); _logger.LogError(ex, "Content API call failed for upload of {TrackName}", trackName);
@@ -90,6 +90,97 @@ public class ProgressStreamContentTests
Assert.That(idleCts.IsCancellationRequested, Is.True); Assert.That(idleCts.IsCancellationRequested, Is.True);
} }
// --- Two-phase deadline switching (Finding 1 regression test) ---
// After the last body byte is reported the idle timer must be disarmed and the response-wait
// budget must be armed. This test simulates the exact scenario that triggered Finding 1:
// the body streams quickly, then a long server-side lag (standing in for AudioProcessor +
// vault write + SQL persist) follows. The idle window is short; the response budget is long.
// With the fix the operation must complete; without it idleCts would fire during the lag.
[Test]
public async Task PostBodyLag_DoesNotTriggerIdleTimeout_WhenResponseBudgetIsLarger()
{
var idle = TimeSpan.FromMilliseconds(150);
var responseBudget = TimeSpan.FromMilliseconds(600);
using var idleCts = new CancellationTokenSource();
idleCts.CancelAfter(idle);
using var responseCts = new CancellationTokenSource();
// responseCts starts disarmed — same as in CmsTrackService.
using var sendCts = CancellationTokenSource.CreateLinkedTokenSource(idleCts.Token, responseCts.Token);
const long contentLength = 4096;
var source = new PacedStream(chunkCount: 1, chunkSize: (int)contentLength, delayPerChunk: TimeSpan.FromMilliseconds(10));
var content = new ProgressStreamContent(source, contentLength, written =>
{
if (written < contentLength)
{
idleCts.CancelAfter(idle);
}
else
{
// Body complete — disarm idle, arm response budget (mirrors CmsTrackService).
idleCts.CancelAfter(Timeout.InfiniteTimeSpan);
responseCts.CancelAfter(responseBudget);
}
});
using var sink = new MemoryStream();
await content.CopyToAsync(sink, sendCts.Token);
// Body is done. Simulate a slow server (longer than idle window, shorter than response budget).
var serverLag = TimeSpan.FromMilliseconds(300); // > idle (150 ms), < response budget (600 ms)
await Task.Delay(serverLag, sendCts.Token);
Assert.That(sendCts.IsCancellationRequested, Is.False,
"A post-body server lag within the response budget must not cancel the send token.");
Assert.That(idleCts.IsCancellationRequested, Is.False,
"The idle CTS must be disarmed after body completes.");
Assert.That(responseCts.IsCancellationRequested, Is.False,
"The response CTS must not have fired — server lag was within the response budget.");
}
[Test]
public async Task PostBodyLag_CancelsViaResponseCts_WhenResponseBudgetExceeded()
{
var idle = TimeSpan.FromMilliseconds(200);
var responseBudget = TimeSpan.FromMilliseconds(150);
using var idleCts = new CancellationTokenSource();
idleCts.CancelAfter(idle);
using var responseCts = new CancellationTokenSource();
using var sendCts = CancellationTokenSource.CreateLinkedTokenSource(idleCts.Token, responseCts.Token);
const long contentLength = 4096;
var source = new PacedStream(chunkCount: 1, chunkSize: (int)contentLength, delayPerChunk: TimeSpan.FromMilliseconds(10));
var content = new ProgressStreamContent(source, contentLength, written =>
{
if (written < contentLength)
{
idleCts.CancelAfter(idle);
}
else
{
idleCts.CancelAfter(Timeout.InfiniteTimeSpan);
responseCts.CancelAfter(responseBudget);
}
});
using var sink = new MemoryStream();
await content.CopyToAsync(sink, sendCts.Token);
// Simulate a slow server that exceeds the response budget.
var serverLag = TimeSpan.FromMilliseconds(400); // > response budget (150 ms)
Assert.That(
async () => await Task.Delay(serverLag, sendCts.Token),
Throws.InstanceOf<OperationCanceledException>(),
"A post-body lag exceeding the response budget must cancel via sendCts.");
Assert.That(responseCts.IsCancellationRequested, Is.True,
"responseCts must be the source of the cancellation, not idleCts.");
Assert.That(idleCts.IsCancellationRequested, Is.False,
"idleCts must remain disarmed — the response budget fired, not the idle window.");
}
/// <summary> /// <summary>
/// A read-only stream that yields a fixed number of equal chunks, pausing between reads to emulate /// A read-only stream that yields a fixed number of equal chunks, pausing between reads to emulate
/// network pacing. Optionally inserts a longer stall before a given chunk to emulate a stalled link. /// network pacing. Optionally inserts a longer stall before a given chunk to emulate a stalled link.