From da3db09a9f7153eb82cf89fafd89cdab6bf71d36 Mon Sep 17 00:00:00 2001 From: calebtt Date: Fri, 25 Sep 2026 22:22:42 -0500 Subject: [PATCH] Refuse to schedule a reconnect while an attempt is in flight The health check reads the registration state without the lock. When it read TemporaryFailure just before a scheduled attempt started, its ScheduleReconnection() call ran with that attempt already in flight and scheduled another one: an attempt no failure asked for, and in extended mode the in-flight agent was stopped before it could report its result. CI on master caught it as more reconnect attempts than failures. ScheduleReconnection() now also refuses while RegistrationState is Registering, checked under the lock. New deterministic test: calling it during an in-flight attempt starts nothing and the attempt still reports its failure (without the fix: 1 attempt, expected 0). The registration timing tests also failed on a starved runner (reproduced by pinning the tests to one CPU): SIPSorcery blocks thread-pool threads during each attempt, and with test classes running in parallel the pool grew by about one thread a second, so timers fired ~1 s late. The test assembly now raises the thread-pool minimum when it loads. Closes #22 Co-Authored-By: Claude Opus 5.5 --- Network/SipClient.cs | 9 ++++-- .../RegistrationTemporaryFailureTests.cs | 28 +++++++++++++++++++ .../RegistrationTestHarness.cs | 2 ++ tests/SipBotLib.Tests/TestSetup.cs | 19 +++++++++++++ 4 files changed, 56 insertions(+), 2 deletions(-) create mode 100644 tests/SipBotLib.Tests/TestSetup.cs diff --git a/Network/SipClient.cs b/Network/SipClient.cs index bae845a..b2d99c7 100644 --- a/Network/SipClient.cs +++ b/Network/SipClient.cs @@ -1101,11 +1101,16 @@ private void PerformHealthCheck(object? state) /// Extended retry: the agent is stopped (the client owns the retries) and attempts continue /// forever, the delay doubling from the initial delay up to the cap. /// - private void ScheduleReconnection() + internal void ScheduleReconnection() { lock (_lockObject) { - if (_isShutdown || _reconnectPending || _registrationState == RegistrationState.HardFailure) + // Checked under the lock: the health check reads the state without it, so by the time + // it gets here an attempt it did not know about may already be in flight. Scheduling + // then would start an attempt no failure asked for and, in extended mode, stop the + // in-flight agent before it can report its result. + if (_isShutdown || _reconnectPending + || _registrationState is RegistrationState.HardFailure or RegistrationState.Registering) return; long delay; diff --git a/tests/SipBotLib.Tests/RegistrationTemporaryFailureTests.cs b/tests/SipBotLib.Tests/RegistrationTemporaryFailureTests.cs index f4c9575..b395454 100644 --- a/tests/SipBotLib.Tests/RegistrationTemporaryFailureTests.cs +++ b/tests/SipBotLib.Tests/RegistrationTemporaryFailureTests.cs @@ -179,6 +179,34 @@ public async Task Health_check_does_not_interrupt_an_attempt_in_flight(bool exte } } +/// +/// The health check reads the registration state without the lock. If it read TemporaryFailure +/// just before a scheduled attempt started, its ScheduleReconnection() call arrives while that +/// attempt is in flight. Seen on the CI runner as more reconnect attempts than failures. The +/// request must be refused, and the in-flight attempt must still report its own failure. +/// +public class RegistrationScheduleRaceTests +{ + [Theory] + [InlineData(true)] + [InlineData(false)] + public async Task A_late_schedule_request_leaves_the_attempt_in_flight_alone(bool extended) + { + using var h = new RegistrationTestHarness(extended: extended); + h.Registrar.Script = Reply.Drop; + h.Client.StartRegistration(); + Assert.Equal(RegistrationState.Registering, h.Client.RegistrationState); + + h.Client.ScheduleReconnection(); + await Task.Delay(600); + + Assert.Equal(0, h.Metric("reconnection_attempts")); + Assert.Equal(1, h.Registrar.Count); + Assert.True(await h.WaitForState(RegistrationState.TemporaryFailure, TimeSpan.FromSeconds(5)), + $"the in-flight attempt never reported its failure; state is {h.Client.RegistrationState}"); + } +} + /// /// After a success the extended backoff starts over: the first retry of the next outage comes /// after the initial delay again. Waits for a real refresh (25 s), so it is its own class. diff --git a/tests/SipBotLib.Tests/RegistrationTestHarness.cs b/tests/SipBotLib.Tests/RegistrationTestHarness.cs index 413e0af..df063aa 100644 --- a/tests/SipBotLib.Tests/RegistrationTestHarness.cs +++ b/tests/SipBotLib.Tests/RegistrationTestHarness.cs @@ -49,6 +49,8 @@ public RegistrationTestHarness( public bool SawAlreadyRunning => Errors.Any(e => e.Message.Contains("already running")); + public long Metric(string name) => Client.Metrics.TryGetValue(name, out var value) ? value : 0; + public static async Task WaitUntil(Func condition, TimeSpan timeout) { var deadline = DateTime.UtcNow + timeout; diff --git a/tests/SipBotLib.Tests/TestSetup.cs b/tests/SipBotLib.Tests/TestSetup.cs new file mode 100644 index 0000000..ffdd92a --- /dev/null +++ b/tests/SipBotLib.Tests/TestSetup.cs @@ -0,0 +1,19 @@ +using System.Runtime.CompilerServices; + +namespace SipBotLib.Tests; + +internal static class TestSetup +{ + /// + /// SIPSorcery blocks thread-pool threads (each registration attempt waits synchronously for + /// its response). With many test classes running in parallel on a small CI runner, the pool + /// runs dry and grows by about one thread a second, so timers fire up to ~1 s late and the + /// registration timing tests fail. A higher minimum keeps timers on time. + /// + [ModuleInitializer] + internal static void RaiseThreadPoolMinimum() + { + ThreadPool.GetMinThreads(out int workers, out int io); + ThreadPool.SetMinThreads(Math.Max(workers, 64), Math.Max(io, 64)); + } +}