From 9d9e672a09f59d25334c5b9a0431c565a6c9a8f5 Mon Sep 17 00:00:00 2001 From: Robert Dickey Date: Sat, 19 Sep 2026 11:59:00 -0500 Subject: [PATCH] fix(ai): make debug-message cooldown comparisons wraparound-safe (#2659) When an AI debug-message cooldown crosses the signed tick-counter boundary, DebugInterpolatedStringHandler can emit before the deadline or suppress a message after it. Both constructors compare absolute tick values. Use subtraction-based deadline comparisons in both constructors, following dev-docs/tick-counts.md. This is a two-line production change; message formatting, cooldown duration, and gameplay behavior are unchanged. Adds 35 regression cases exercising the actual handler and DebugSayFormatted: - Both constructor overloads, with debugging enabled and disabled. - Before/at/after deadlines on positive and negative clocks. - Future and expired deadlines across signed wraparound. - Cooldown rearming across wraparound and buffer clearing. - A compiler-generated interpolated call through the public extension method. Validation on Linux / .NET 10, based on clean upstream 35e3a31b4: - Release build: 0 warnings, 0 errors. - New tests against unchanged production code: 28 passed, 7 failed. - With the fix: 35 passed, including without client map data (no skips). - Selected AI/pet suites: 134 passed / 7 failed before; 141 passed / 0 failed after. Tests use synthetic entities; no running shard or world saves. The faulty comparisons were reverified on upstream main before submission. Windows execution remains unverified. The tests exercise explicitly assigned deadlines; deadline initialization is outside this patch. Addresses only the DebugInterpolatedStringHandler comparison item in #2627; it does not close the other audit items. --- .../Mobiles/AI/DebugMessageTimingTests.cs | 145 ++++++++++++++++++ .../BaseAI/DebugInterpolatedStringHandler.cs | 4 +- 2 files changed, 147 insertions(+), 2 deletions(-) create mode 100644 Projects/UOContent.Tests/Tests/Mobiles/AI/DebugMessageTimingTests.cs diff --git a/Projects/UOContent.Tests/Tests/Mobiles/AI/DebugMessageTimingTests.cs b/Projects/UOContent.Tests/Tests/Mobiles/AI/DebugMessageTimingTests.cs new file mode 100644 index 000000000..042628b79 --- /dev/null +++ b/Projects/UOContent.Tests/Tests/Mobiles/AI/DebugMessageTimingTests.cs @@ -0,0 +1,145 @@ +using System.Collections.Generic; +using System.Globalization; +using Server; +using Server.Mobiles; +using Server.Mobiles.AI.BaseAI; +using Xunit; + +namespace UOContent.Tests.Mobiles.AI; + +[Collection("Sequential UOContent Tests")] +public class DebugMessageTimingTests +{ + public static IEnumerable DeadlineCases() + { + (long Now, long Deadline, bool Due)[] clocks = + [ + (99, 100, false), (100, 100, true), (101, 100, true), + (-101, -100, false), (-100, -100, true), (-99, -100, true), + (long.MaxValue - 10, long.MinValue + 10, false), + (long.MinValue + 10, long.MaxValue - 10, true) + ]; + + foreach (var (now, deadline, due) in clocks) + { + foreach (var withProvider in new[] { false, true }) + { + foreach (var debug in new[] { false, true }) + { + yield return [now, deadline, due, withProvider, debug]; + } + } + } + } + + [Theory] + [MemberData(nameof(DeadlineCases))] + public void Handler_EmitsOnlyWhenDebugEnabledAndDue( + long now, long deadline, bool due, bool withProvider, bool debug) + { + var previousTick = Core.TickCount; + var pet = new PetTestStub(); + var ai = pet.AIObject; + pet.Debug = debug; + ai.NextDebugMessage = deadline; + Core._tickCount = now; + var handler = withProvider + ? new DebugInterpolatedStringHandler(6, 1, CultureInfo.InvariantCulture, ai) + : new DebugInterpolatedStringHandler(6, 1, ai); + + try + { + handler.AppendLiteral("value "); + handler.AppendFormatted(42); + Assert.Equal(debug && due ? "value 42" : "", handler.Text.ToString()); + + ai.DebugSayFormatted(ref handler, 50); + Assert.Equal(debug && due ? unchecked(now + 50) : deadline, ai.NextDebugMessage); + Assert.True(handler.Text.IsEmpty); + } + finally + { + handler.Clear(); + Core._tickCount = previousTick; + pet.Delete(); + } + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public void Handler_RearmedCooldown_WaitsAcrossWrap(bool withProvider) + { + var previousTick = Core.TickCount; + var pet = new PetTestStub { Debug = true }; + var ai = pet.AIObject; + + try + { + Core._tickCount = long.MaxValue - 10; + ai.NextDebugMessage = Core.TickCount; + Emit(ai, withProvider); + var deadline = ai.NextDebugMessage; + Assert.Equal(long.MinValue + 39, deadline); + + Core._tickCount = long.MaxValue - 9; + Emit(ai, withProvider); + Assert.Equal(deadline, ai.NextDebugMessage); + + Core._tickCount = deadline - 1; + Emit(ai, withProvider); + Assert.Equal(deadline, ai.NextDebugMessage); + + Core._tickCount = deadline; + Emit(ai, withProvider); + Assert.Equal(deadline + 50, ai.NextDebugMessage); + } + finally + { + Core._tickCount = previousTick; + pet.Delete(); + } + } + + [Fact] + public void InterpolatedCall_UsesHandlerAcrossWrap() + { + var previousTick = Core.TickCount; + var pet = new PetTestStub { Debug = true }; + var ai = pet.AIObject; + + try + { + Core._tickCount = long.MaxValue - 10; + ai.NextDebugMessage = long.MinValue + 10; + var value = 42; + ai.DebugSayFormatted($"value {value}", 50); + Assert.Equal(long.MinValue + 10, ai.NextDebugMessage); + + Core._tickCount = long.MinValue + 10; + ai.DebugSayFormatted($"value {value}", 50); + Assert.Equal(long.MinValue + 60, ai.NextDebugMessage); + } + finally + { + Core._tickCount = previousTick; + pet.Delete(); + } + } + + private static void Emit(BaseAI ai, bool withProvider) + { + var handler = withProvider + ? new DebugInterpolatedStringHandler(5, 0, CultureInfo.InvariantCulture, ai) + : new DebugInterpolatedStringHandler(5, 0, ai); + try + { + handler.AppendLiteral("debug"); + ai.DebugSayFormatted(ref handler, 50); + } + finally + { + handler.Clear(); + } + } +} diff --git a/Projects/UOContent/Mobiles/AI/BaseAI/DebugInterpolatedStringHandler.cs b/Projects/UOContent/Mobiles/AI/BaseAI/DebugInterpolatedStringHandler.cs index 05630d2f8..03c0f1a1e 100644 --- a/Projects/UOContent/Mobiles/AI/BaseAI/DebugInterpolatedStringHandler.cs +++ b/Projects/UOContent/Mobiles/AI/BaseAI/DebugInterpolatedStringHandler.cs @@ -56,7 +56,7 @@ public ref struct DebugInterpolatedStringHandler /// This is intended to be called only by compiler-generated code. Arguments are not validated as they'd otherwise be for members intended to be used directly. public DebugInterpolatedStringHandler(int literalLength, int formattedCount, Mobiles.BaseAI ai) { - _debugActive = ai.Mobile?.Debug == true && Core.TickCount >= ai.NextDebugMessage; + _debugActive = ai.Mobile?.Debug == true && Core.TickCount - ai.NextDebugMessage >= 0; if (_debugActive) { @@ -79,7 +79,7 @@ public ref struct DebugInterpolatedStringHandler /// This is intended to be called only by compiler-generated code. Arguments are not validated as they'd otherwise be for members intended to be used directly. public DebugInterpolatedStringHandler(int literalLength, int formattedCount, IFormatProvider? provider, Mobiles.BaseAI ai) { - _debugActive = ai.Mobile?.Debug == true && Core.TickCount >= ai.NextDebugMessage; + _debugActive = ai.Mobile?.Debug == true && Core.TickCount - ai.NextDebugMessage >= 0; if (_debugActive) {