Merge wt/step-logs-t9: Task 9
This commit is contained in:
@@ -280,6 +280,16 @@ public static class EndpointExtensions
|
|||||||
// production call so Replay of a real integration call is complete.
|
// production call so Replay of a real integration call is complete.
|
||||||
trace: method.TraceAllCalls);
|
trace: method.TraceAllCalls);
|
||||||
|
|
||||||
|
// Flow Debugger step logs (design 2026-09-09 D3): the executor sanitises the
|
||||||
|
// caller-facing message, so this stash is the ONLY place a method script's real
|
||||||
|
// exception survives for the inbound audit row. AuditWriteMiddleware consumes the
|
||||||
|
// slot once when it builds that row; the HTTP body below still carries only the
|
||||||
|
// safe ErrorMessage.
|
||||||
|
if (scriptResult.ErrorDetail is { } scriptErrorDetail)
|
||||||
|
{
|
||||||
|
httpContext.Items[AuditWriteMiddleware.ErrorDetailItemKey] = scriptErrorDetail;
|
||||||
|
}
|
||||||
|
|
||||||
if (!scriptResult.Success)
|
if (!scriptResult.Success)
|
||||||
{
|
{
|
||||||
// A client-aborted request is not a script failure.
|
// A client-aborted request is not a script failure.
|
||||||
|
|||||||
@@ -599,8 +599,12 @@ public class InboundScriptExecutor
|
|||||||
catch (Exception ex)
|
catch (Exception ex)
|
||||||
{
|
{
|
||||||
_logger.LogError(ex, "Script execution failed for method {Method}", method.Name);
|
_logger.LogError(ex, "Script execution failed for method {Method}", method.Name);
|
||||||
// Safe error message, no internal details
|
// Safe error message, no internal details — the caller only ever sees this.
|
||||||
return new InboundScriptResult(false, null, "Internal script error", "SCRIPT_ERROR");
|
// Flow Debugger step logs (design 2026-09-09 D3): the exception itself rides the
|
||||||
|
// additive ErrorDetail so the endpoint can put it on the inbound AUDIT row, where
|
||||||
|
// the Flow Debugger's inbound node reads it. It must never reach the HTTP body.
|
||||||
|
return new InboundScriptResult(
|
||||||
|
false, null, "Internal script error", "SCRIPT_ERROR", ErrorDetail: ex.ToString());
|
||||||
}
|
}
|
||||||
finally
|
finally
|
||||||
{
|
{
|
||||||
@@ -743,8 +747,18 @@ public class InboundScriptContext
|
|||||||
/// <c>SCRIPT_COMPILE_FAILED</c>, <c>SCRIPT_ERROR</c>). Null when the executor does not
|
/// <c>SCRIPT_COMPILE_FAILED</c>, <c>SCRIPT_ERROR</c>). Null when the executor does not
|
||||||
/// classify the failure; the endpoint then falls back to <c>SCRIPT_ERROR</c>.
|
/// classify the failure; the endpoint then falls back to <c>SCRIPT_ERROR</c>.
|
||||||
/// </param>
|
/// </param>
|
||||||
|
/// <param name="ErrorDetail">
|
||||||
|
/// Flow Debugger step logs (design 2026-09-09 D3): verbose, operator-only failure detail —
|
||||||
|
/// the method script's exception <c>ToString()</c>. <b>Audit-row only.</b> The endpoint stashes
|
||||||
|
/// it on <c>HttpContext.Items[AuditWriteMiddleware.ErrorDetailItemKey]</c> so it lands on the
|
||||||
|
/// inbound audit row (and therefore on the Flow Debugger's inbound node); it is NEVER written
|
||||||
|
/// to the HTTP response, which keeps carrying the sanitised <see cref="ErrorMessage"/>. Null
|
||||||
|
/// for failures whose message already says everything (timeouts, client aborts, site-scope
|
||||||
|
/// denials, compile failures).
|
||||||
|
/// </param>
|
||||||
public record InboundScriptResult(
|
public record InboundScriptResult(
|
||||||
bool Success,
|
bool Success,
|
||||||
string? ResultJson,
|
string? ResultJson,
|
||||||
string? ErrorMessage,
|
string? ErrorMessage,
|
||||||
string? ErrorCode = null);
|
string? ErrorCode = null,
|
||||||
|
string? ErrorDetail = null);
|
||||||
|
|||||||
@@ -79,6 +79,16 @@ public sealed class AuditWriteMiddleware
|
|||||||
/// </summary>
|
/// </summary>
|
||||||
public const string AuditActorItemKey = "ZB.MOM.WW.ScadaBridge.InboundAPI.AuditActor";
|
public const string AuditActorItemKey = "ZB.MOM.WW.ScadaBridge.InboundAPI.AuditActor";
|
||||||
|
|
||||||
|
/// <summary>
|
||||||
|
/// <see cref="HttpContext.Items"/> key used by the endpoint handler to publish the
|
||||||
|
/// method script's exception detail when the script threw (Flow Debugger step logs,
|
||||||
|
/// design 2026-09-09 D3). The executor deliberately sanitises the caller-facing
|
||||||
|
/// message, so this slot is the only place the real cause survives; it is consumed
|
||||||
|
/// once here, onto the inbound audit row's <c>ErrorDetail</c>, and never written to
|
||||||
|
/// the HTTP response. An exception that ESCAPED the pipeline takes precedence.
|
||||||
|
/// </summary>
|
||||||
|
public const string ErrorDetailItemKey = "ScadaBridge.Audit.ErrorDetail";
|
||||||
|
|
||||||
/// <summary>
|
/// <summary>
|
||||||
/// ParentExecutionId: <see cref="HttpContext.Items"/> key under
|
/// ParentExecutionId: <see cref="HttpContext.Items"/> key under
|
||||||
/// which this middleware stashes the inbound request's per-request
|
/// which this middleware stashes the inbound request's per-request
|
||||||
@@ -318,6 +328,17 @@ public sealed class AuditWriteMiddleware
|
|||||||
headerDict[header.Key] = value;
|
headerDict[header.Key] = value;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// Flow Debugger step logs (design 2026-09-09 D3): an exception that ESCAPED the
|
||||||
|
// pipeline is the authoritative failure, so it wins; otherwise the endpoint may
|
||||||
|
// have stashed the method script's exception (which the executor keeps out of the
|
||||||
|
// HTTP body). Absent both, the row carries no detail.
|
||||||
|
var errorDetail = thrown?.ToString();
|
||||||
|
if (errorDetail is null
|
||||||
|
&& ctx.Items.TryGetValue(ErrorDetailItemKey, out var stashedErrorDetail))
|
||||||
|
{
|
||||||
|
errorDetail = stashedErrorDetail as string;
|
||||||
|
}
|
||||||
|
|
||||||
var extra = JsonSerializer.Serialize(new
|
var extra = JsonSerializer.Serialize(new
|
||||||
{
|
{
|
||||||
remoteIp = ctx.Connection.RemoteIpAddress?.ToString(),
|
remoteIp = ctx.Connection.RemoteIpAddress?.ToString(),
|
||||||
@@ -347,6 +368,7 @@ public sealed class AuditWriteMiddleware
|
|||||||
httpStatus: statusCode,
|
httpStatus: statusCode,
|
||||||
durationMs: (int)Math.Min(durationMs, int.MaxValue),
|
durationMs: (int)Math.Min(durationMs, int.MaxValue),
|
||||||
errorMessage: thrown?.Message,
|
errorMessage: thrown?.Message,
|
||||||
|
errorDetail: errorDetail,
|
||||||
requestSummary: requestBody,
|
requestSummary: requestBody,
|
||||||
responseSummary: responseBody,
|
responseSummary: responseBody,
|
||||||
payloadTruncated: payloadTruncated,
|
payloadTruncated: payloadTruncated,
|
||||||
|
|||||||
@@ -432,7 +432,23 @@ public sealed class EndpointExtensionsTests : IDisposable
|
|||||||
var method = SeedMethod(1, "boom",
|
var method = SeedMethod(1, "boom",
|
||||||
"""throw new System.InvalidOperationException("boom-msg");""");
|
"""throw new System.InvalidOperationException("boom-msg");""");
|
||||||
|
|
||||||
using var host = await BuildHostAsync(method);
|
// Flow Debugger step logs (design 2026-09-09 D3): the detail the body must NOT carry
|
||||||
|
// is nonetheless stashed for AuditWriteMiddleware, so the inbound audit row (and the
|
||||||
|
// Flow Debugger's inbound node) can say why the run failed. A capture middleware reads
|
||||||
|
// the slot once the endpoint has finished, proving both halves in one request.
|
||||||
|
string? capturedDetail = null;
|
||||||
|
using var host = await BuildHostAsync(method, customize: builder =>
|
||||||
|
{
|
||||||
|
builder.Use(async (ctx, next) =>
|
||||||
|
{
|
||||||
|
await next();
|
||||||
|
if (ctx.Items.TryGetValue(
|
||||||
|
AuditWriteMiddleware.ErrorDetailItemKey, out var stashed))
|
||||||
|
{
|
||||||
|
capturedDetail = stashed as string;
|
||||||
|
}
|
||||||
|
});
|
||||||
|
});
|
||||||
var token = await SeedKeyAsync(host, "key1", "caller", new[] { "boom" });
|
var token = await SeedKeyAsync(host, "key1", "caller", new[] { "boom" });
|
||||||
var client = host.GetTestClient();
|
var client = host.GetTestClient();
|
||||||
|
|
||||||
@@ -445,6 +461,10 @@ public sealed class EndpointExtensionsTests : IDisposable
|
|||||||
// message is not leaked (the executor sanitises before this point).
|
// message is not leaked (the executor sanitises before this point).
|
||||||
Assert.Contains("error", body);
|
Assert.Contains("error", body);
|
||||||
Assert.DoesNotContain("boom-msg", body);
|
Assert.DoesNotContain("boom-msg", body);
|
||||||
|
|
||||||
|
// …while the audit-only slot carries the real cause.
|
||||||
|
Assert.NotNull(capturedDetail);
|
||||||
|
Assert.Contains("boom-msg", capturedDetail);
|
||||||
}
|
}
|
||||||
|
|
||||||
[Fact]
|
[Fact]
|
||||||
|
|||||||
@@ -202,6 +202,56 @@ public class InboundScriptExecutorTests
|
|||||||
Assert.Equal("Internal script error", result.ErrorMessage);
|
Assert.Equal("Internal script error", result.ErrorMessage);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
[Fact]
|
||||||
|
public async Task HandlerThrows_ErrorDetailCarriesTheException_WhileTheMessageStaysSafe()
|
||||||
|
{
|
||||||
|
// Flow Debugger step logs (design 2026-09-09 D3): the generic SCRIPT_ERROR catch keeps
|
||||||
|
// the caller-facing message sanitised, but the exception itself must survive on the
|
||||||
|
// additive ErrorDetail so the endpoint can put it on the inbound audit row (and the
|
||||||
|
// Flow Debugger's inbound node can show why the run failed).
|
||||||
|
var method = new ApiMethod("failing-detail", "throw new InvalidOperationException(\"real reason\");")
|
||||||
|
{ Id = 1, TimeoutSeconds = 10 };
|
||||||
|
_executor.RegisterHandler("failing-detail", _ => throw new InvalidOperationException("real reason"));
|
||||||
|
|
||||||
|
var result = await _executor.ExecuteAsync(
|
||||||
|
method,
|
||||||
|
new Dictionary<string, object?>(),
|
||||||
|
_route,
|
||||||
|
TimeSpan.FromSeconds(10));
|
||||||
|
|
||||||
|
Assert.False(result.Success);
|
||||||
|
Assert.Equal("Internal script error", result.ErrorMessage);
|
||||||
|
Assert.Equal("SCRIPT_ERROR", result.ErrorCode);
|
||||||
|
Assert.NotNull(result.ErrorDetail);
|
||||||
|
Assert.Contains("InvalidOperationException", result.ErrorDetail);
|
||||||
|
Assert.Contains("real reason", result.ErrorDetail);
|
||||||
|
// The caller-safe fields must never carry it.
|
||||||
|
Assert.DoesNotContain("real reason", result.ErrorMessage!);
|
||||||
|
}
|
||||||
|
|
||||||
|
[Fact]
|
||||||
|
public async Task HandlerTimesOut_CarriesNoErrorDetail()
|
||||||
|
{
|
||||||
|
// A timeout is fully described by its message + TIMEOUT code — the
|
||||||
|
// OperationCanceledException adds nothing, so the row stays detail-less.
|
||||||
|
var method = new ApiMethod("slow-detail", "Thread.Sleep(60000);") { Id = 1, TimeoutSeconds = 1 };
|
||||||
|
_executor.RegisterHandler("slow-detail", async ctx =>
|
||||||
|
{
|
||||||
|
await Task.Delay(TimeSpan.FromSeconds(60), ctx.CancellationToken);
|
||||||
|
return "never";
|
||||||
|
});
|
||||||
|
|
||||||
|
var result = await _executor.ExecuteAsync(
|
||||||
|
method,
|
||||||
|
new Dictionary<string, object?>(),
|
||||||
|
_route,
|
||||||
|
TimeSpan.FromMilliseconds(100));
|
||||||
|
|
||||||
|
Assert.False(result.Success);
|
||||||
|
Assert.Equal("TIMEOUT", result.ErrorCode);
|
||||||
|
Assert.Null(result.ErrorDetail);
|
||||||
|
}
|
||||||
|
|
||||||
[Fact]
|
[Fact]
|
||||||
public async Task RoutedAskTimeout_Returns500WithSiteUnreachableCode()
|
public async Task RoutedAskTimeout_Returns500WithSiteUnreachableCode()
|
||||||
{
|
{
|
||||||
|
|||||||
@@ -265,6 +265,74 @@ public class AuditWriteMiddlewareTests
|
|||||||
Assert.Equal("kaboom", evt.ErrorMessage);
|
Assert.Equal("kaboom", evt.ErrorMessage);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// ---------------------------------------------------------------------
|
||||||
|
// 4b. Error detail — the endpoint stashes a method script's exception on
|
||||||
|
// HttpContext.Items (the HTTP body only ever carries the sanitised
|
||||||
|
// message), and the middleware lifts it onto the row.
|
||||||
|
// ---------------------------------------------------------------------
|
||||||
|
|
||||||
|
[Fact]
|
||||||
|
public async Task ScriptErrorDetail_StashedOnItems_LandsOnTheRow()
|
||||||
|
{
|
||||||
|
var writer = new RecordingAuditWriter();
|
||||||
|
var ctx = BuildContext();
|
||||||
|
const string detail = "System.InvalidOperationException: real reason\n at Script.<Main>";
|
||||||
|
var mw = CreateMiddleware(hc =>
|
||||||
|
{
|
||||||
|
hc.Items[AuditWriteMiddleware.ErrorDetailItemKey] = detail;
|
||||||
|
hc.Response.StatusCode = 500;
|
||||||
|
return Task.CompletedTask;
|
||||||
|
}, writer);
|
||||||
|
|
||||||
|
await mw.InvokeAsync(ctx);
|
||||||
|
|
||||||
|
var evt = Assert.Single(writer.Events);
|
||||||
|
Assert.Equal(AuditStatus.Failed, evt.Status);
|
||||||
|
Assert.Equal(detail, evt.ErrorDetail);
|
||||||
|
}
|
||||||
|
|
||||||
|
[Fact]
|
||||||
|
public async Task NoErrorDetailStashed_LeavesErrorDetailNull()
|
||||||
|
{
|
||||||
|
var writer = new RecordingAuditWriter();
|
||||||
|
var ctx = BuildContext();
|
||||||
|
var mw = CreateMiddleware(hc =>
|
||||||
|
{
|
||||||
|
hc.Response.StatusCode = 200;
|
||||||
|
return Task.CompletedTask;
|
||||||
|
}, writer);
|
||||||
|
|
||||||
|
await mw.InvokeAsync(ctx);
|
||||||
|
|
||||||
|
var evt = Assert.Single(writer.Events);
|
||||||
|
Assert.Null(evt.ErrorDetail);
|
||||||
|
}
|
||||||
|
|
||||||
|
[Fact]
|
||||||
|
public async Task ThrownException_ErrorDetail_WinsOverTheStashedItem()
|
||||||
|
{
|
||||||
|
// An exception that ESCAPED the pipeline is the richer, more authoritative
|
||||||
|
// source: it describes the failure the framework error path is about to report.
|
||||||
|
var writer = new RecordingAuditWriter();
|
||||||
|
var ctx = BuildContext();
|
||||||
|
var boom = new InvalidOperationException("kaboom");
|
||||||
|
var mw = CreateMiddleware(hc =>
|
||||||
|
{
|
||||||
|
hc.Items[AuditWriteMiddleware.ErrorDetailItemKey] = "stashed detail";
|
||||||
|
throw boom;
|
||||||
|
}, writer);
|
||||||
|
|
||||||
|
await Assert.ThrowsAsync<InvalidOperationException>(() => mw.InvokeAsync(ctx));
|
||||||
|
|
||||||
|
var evt = Assert.Single(writer.Events);
|
||||||
|
// Compared by content, not by an exact ToString(): the re-throw keeps appending
|
||||||
|
// stack frames after the row was built, so the captured text is a prefix of what
|
||||||
|
// the exception reads as by the time the assertion runs.
|
||||||
|
Assert.NotNull(evt.ErrorDetail);
|
||||||
|
Assert.StartsWith(boom.GetType().FullName + ": kaboom", evt.ErrorDetail);
|
||||||
|
Assert.DoesNotContain("stashed detail", evt.ErrorDetail);
|
||||||
|
}
|
||||||
|
|
||||||
// ---------------------------------------------------------------------
|
// ---------------------------------------------------------------------
|
||||||
// 5. Actor resolution — the endpoint handler stashes the API key name
|
// 5. Actor resolution — the endpoint handler stashes the API key name
|
||||||
// AFTER successful auth so the middleware can pick it up from
|
// AFTER successful auth so the middleware can pick it up from
|
||||||
|
|||||||
Reference in New Issue
Block a user