From 7be22d2ac269babdae562e1d16f56b8f351211a9 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Thu, 22 Oct 2026 09:52:17 -0400 Subject: [PATCH] fix(auditlog): truncate over-width SiteCalls.LastError on the cached-telemetry dual-write and the reconciliation pull (review 2026-10-21 follow-up) --- docs/requirements/Component-AuditLog.md | 6 ++- .../Central/AuditLogIngestActor.cs | 4 +- .../Central/GrpcPullSiteCallsClient.cs | 4 +- .../Central/SiteCallColumnBounds.cs | 41 +++++++++++++++++++ ...ditLogIngestActorCombinedTelemetryTests.cs | 31 ++++++++++++++ .../Central/GrpcPullSiteCallsClientTests.cs | 39 ++++++++++++++++++ 6 files changed, 121 insertions(+), 4 deletions(-) create mode 100644 src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/SiteCallColumnBounds.cs diff --git a/docs/requirements/Component-AuditLog.md b/docs/requirements/Component-AuditLog.md index eea019aa..db32bac3 100644 --- a/docs/requirements/Component-AuditLog.md +++ b/docs/requirements/Component-AuditLog.md @@ -353,7 +353,11 @@ collapse first-write-wins before the statement is built, duplicates *across* packets are eliminated by the anti-semi-join, and any failure falls back to the per-row / per-entry path — so the documented invariant that one bad row cannot sink the rest of the batch still holds, it is simply no longer paid for on the -healthy path. +healthy path. A site `LastError` longer than the central `SiteCalls.LastError` column (1024 +characters) is truncated to the column width on both the dual-write and the +reconciliation pull (`SiteCallColumnBounds`) — an over-width message used to fail the +whole dual-write with SQL 8152, so the audit row came back Rejected and the +`SiteCalls` row was never written by either path (review 2026-10-21 follow-up). The set-based path binds its string parameters at the VALUE's own length, never at the column width. Declaring the width makes the client TRUNCATE an over-long diff --git a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/AuditLogIngestActor.cs b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/AuditLogIngestActor.cs index 55e1404a..8e91e3e7 100644 --- a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/AuditLogIngestActor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/AuditLogIngestActor.cs @@ -435,7 +435,7 @@ public class AuditLogIngestActor : ReceiveActor var safeRedactor = redactor ?? SafeDefaultAuditRedactor.Instance; var filteredAudit = safeRedactor.Apply(entry.Audit); var auditStamped = AuditRowProjection.WithIngestedAtUtc(filteredAudit, ingestedAt); - var siteCallStamped = entry.SiteCall with { IngestedAtUtc = ingestedAt }; + var siteCallStamped = SiteCallColumnBounds.Clamp(entry.SiteCall) with { IngestedAtUtc = ingestedAt }; await auditRepo.InsertIfNotExistsAsync(auditStamped, fallbackBudget.Token) .ConfigureAwait(false); @@ -539,7 +539,7 @@ public class AuditLogIngestActor : ReceiveActor foreach (var entry in cmd.Entries) { await siteCallRepo - .UpsertAsync(entry.SiteCall with { IngestedAtUtc = ingestedAt }, ct) + .UpsertAsync(SiteCallColumnBounds.Clamp(entry.SiteCall) with { IngestedAtUtc = ingestedAt }, ct) .ConfigureAwait(false); } diff --git a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/GrpcPullSiteCallsClient.cs b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/GrpcPullSiteCallsClient.cs index faae334e..8aabe554 100644 --- a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/GrpcPullSiteCallsClient.cs +++ b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/GrpcPullSiteCallsClient.cs @@ -141,7 +141,9 @@ public sealed class GrpcPullSiteCallsClient : IPullSiteCallsClient { try { - var sc = SiteCallDtoMapper.FromDto(dto) with { SourceSite = siteId }; + // Fit LastError to the central column so the reconciliation upsert cannot fail + // with SQL 8152 (review 2026-10-21 follow-up — see SiteCallColumnBounds). + var sc = SiteCallColumnBounds.Clamp(SiteCallDtoMapper.FromDto(dto)) with { SourceSite = siteId }; siteCalls.Add(sc); } catch (Exception ex) diff --git a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/SiteCallColumnBounds.cs b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/SiteCallColumnBounds.cs new file mode 100644 index 00000000..069599c2 --- /dev/null +++ b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Central/SiteCallColumnBounds.cs @@ -0,0 +1,41 @@ +using ZB.MOM.WW.ScadaBridge.Commons.Entities.Audit; + +namespace ZB.MOM.WW.ScadaBridge.AuditLog.Central; + +/// +/// Fits a site-supplied to the central SiteCalls column widths before +/// it is written (review 2026-10-21 follow-up). The site's tracking store does not bound +/// , while the central column is nvarchar(1024) +/// (SiteCallEntityTypeConfiguration): an over-width error used to fail the +/// cached-telemetry dual-write with SQL 8152 — the audit row was reported Rejected to the site +/// and the reconciliation pull's upsert failed the same way, so the SiteCalls row was never +/// written at all. Truncating a diagnostic message is the right trade; dropping the row is not. +/// +internal static class SiteCallColumnBounds +{ + /// Width of SiteCalls.LastError; must match SiteCallEntityTypeConfiguration. + public const int LastErrorMaxLength = 1024; + + /// + /// Returns unchanged when it already fits, otherwise a copy whose + /// is truncated to characters + /// (never splitting a UTF-16 surrogate pair). + /// + /// The row about to be written centrally. + /// A row that fits the central columns. + public static SiteCall Clamp(SiteCall siteCall) + { + if (siteCall.LastError is not { Length: > LastErrorMaxLength } error) + { + return siteCall; + } + + var cut = LastErrorMaxLength; + if (char.IsHighSurrogate(error[cut - 1])) + { + cut--; + } + + return siteCall with { LastError = error[..cut] }; + } +} diff --git a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/AuditLogIngestActorCombinedTelemetryTests.cs b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/AuditLogIngestActorCombinedTelemetryTests.cs index 92c02d93..afda9389 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/AuditLogIngestActorCombinedTelemetryTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/AuditLogIngestActorCombinedTelemetryTests.cs @@ -160,6 +160,37 @@ public class AuditLogIngestActorCombinedTelemetryTests : TestKit, IClassFixture< Assert.Equal(siteCall.Status, siteCallRow!.Status); } + /// + /// Review 2026-10-21 follow-up: a site LastError longer than the central + /// SiteCalls.LastError column (nvarchar(1024)) used to fail the dual-write with SQL + /// 8152 — the audit row was reported Rejected and the SiteCalls row was never upserted. The + /// ingest now truncates it to the column width, so both rows land. + /// + /// A task that represents the asynchronous operation. + [SkippableFact] + public async Task Receive_OverWidthLastError_IsTruncated_BothRowsLand() + { + Skip.IfNot(_fixture.Available, _fixture.SkipReason); + + var siteId = NewSiteId(); + var (audit, siteCall) = NewEntry(siteId); + siteCall = siteCall with { LastError = new string('x', 5000) }; + + var actor = CreateActor(BuildServiceProvider()); + actor.Tell( + new IngestCachedTelemetryCommand(new[] { new CachedTelemetryEntry(audit, siteCall) }), + TestActor); + + var reply = ExpectMsg(TimeSpan.FromSeconds(15)); + Assert.Equal(new[] { audit.EventId }, reply.AcceptedEventIds); + Assert.Empty(reply.RejectedEventIds); + + await using var read = CreateReadContext(); + var siteCallRow = await read.Set() + .SingleAsync(s => s.TrackedOperationId == siteCall.TrackedOperationId); + Assert.Equal(SiteCallColumnBounds.LastErrorMaxLength, siteCallRow.LastError!.Length); + } + /// Verifies that a duplicate event id with an unchanged status is a no-op that leaves the row counts unchanged and still acknowledges the id. /// A task that represents the asynchronous operation. [SkippableFact] diff --git a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/GrpcPullSiteCallsClientTests.cs b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/GrpcPullSiteCallsClientTests.cs index df3b7d18..f41cb4e4 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/GrpcPullSiteCallsClientTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Central/GrpcPullSiteCallsClientTests.cs @@ -274,6 +274,45 @@ public class GrpcPullSiteCallsClientTests Assert.False(result.MoreAvailable); } + /// + /// Review 2026-10-21 follow-up: a pulled LastError longer than the central SiteCalls column + /// is truncated to the column width, so the reconciliation upsert cannot fail with SQL 8152. + /// + /// A task that represents the asynchronous operation. + [Fact] + public async Task PullAsync_truncates_over_width_last_error_to_the_column_width() + { + var proto = new ProtoPullResponse(); + var dto = Dto(Guid.NewGuid(), BaseTime); + dto.LastError = new string('e', 5000); + proto.Operationals.Add(dto); + + var sut = new GrpcPullSiteCallsClient( + new StaticEnumerator(new SiteEntry("site-a", "http://site-a:8083")), + FakeInvoker.Returning(proto), + NullLogger.Instance); + + var result = await sut.PullAsync("site-a", BaseTime, afterId: null, batchSize: 256, CancellationToken.None); + + Assert.Equal(SiteCallColumnBounds.LastErrorMaxLength, Assert.Single(result.SiteCalls).LastError!.Length); + } + + /// A surrogate pair straddling the cut is never split; short values pass through untouched. + [Fact] + public void SiteCallColumnBounds_Clamp_KeepsSurrogatePairsWhole_AndLeavesShortValuesAlone() + { + static ZB.MOM.WW.ScadaBridge.Commons.Entities.Audit.SiteCall Call(string lastError) => + SiteCallDtoMapper.FromDto(Dto(Guid.NewGuid(), BaseTime)) with { LastError = lastError }; + + var shortCall = Call("boom"); + Assert.Same(shortCall, SiteCallColumnBounds.Clamp(shortCall)); + + var straddle = new string('a', SiteCallColumnBounds.LastErrorMaxLength - 2) + "\U0001F600" + "tail"; + var clamped = SiteCallColumnBounds.Clamp(Call(straddle)).LastError!; + Assert.True(clamped.Length <= SiteCallColumnBounds.LastErrorMaxLength); + Assert.False(char.IsHighSurrogate(clamped[^1])); + } + /// Verifies that PullAsync with a MinValue unspecified-kind cursor does not throw and still dials the site. /// A task that represents the asynchronous operation. [Fact]