Skip to content

Commit 3375435

Browse files
authored
Fix SctpDataSender lost-wakeup race: move _senderMre.Reset() to top of DoSend loop (#1560)
Root cause: _senderMre.Reset() was called AFTER the send work and BEFORE _senderMre.Wait(burstPeriod). If a SACK arrived between the last chunk sent and the Reset, its _senderMre.Set() signal was wiped by the Reset() and the sender thread then blocked for the full BURST_PERIOD_MILLISECONDS (50 ms default) before noticing more cwnd was available. On localhost loopback where SACKs round-trip in microseconds the race window was hit almost every burst, capping actual throughput at the theoretical MAX_BURST * MTU / BURST_PERIOD steady-state (~104 KB/s for MTU=1300 + 50 ms period) rather than the much higher rate the link could sustain. Fix: Reset at the START of each iteration so any Set() fired during the send work is preserved through to the next Wait(). Wait returns promptly on the SACK signal, and throughput becomes bounded by MRE wake latency (sub-millisecond) rather than the 50 ms burst period. RFC 4960 §7.2.2 defaults (MAX_BURST, BURST_PERIOD_MILLISECONDS) unchanged. Includes a regression test, SctpDataSenderUnitTest.Throughput_FastSack Wake_ExceedsBurstCeiling: sends 360 x 1400-byte chunks (504 KB total) with synchronous SACK delivery on the same thread, asserts completion in under 2 seconds. Pre-fix measurement: 5613 ms / 89.8 KB/s. Post-fix on the same machine: 94 ms / 5.4 MB/s (60x speedup). Pre-fix test fails at the 2000 ms threshold; post-fix passes with ~20x headroom. No regressions on the existing SctpData* tests (53/55 pass, 2 pre- existing CI skips unrelated to this change). Diagnostic credit to Geordi (a crew AI agent on the LostBeard team) who traced the throughput ceiling to SctpDataSender.cs line by line before filing the handoff that prompted this investigation. Fix authored by LostBeard with AI-assisted code review from Riker (another crew AI agent) and a Rule-4b verify-before-you-speak step where the test was run against an intentionally-reverted version of the fix to prove the failure mode matches the measured ceiling before re-applying.
1 parent f3f32f9 commit 3375435

2 files changed

Lines changed: 84 additions & 2 deletions

File tree

src/SIPSorcery/net/SCTP/SctpDataSender.cs

Lines changed: 13 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -526,6 +526,19 @@ private void DoSend(object state)
526526

527527
while (!_isClosed)
528528
{
529+
// Reset the sender wake event at the START of each iteration. Resetting
530+
// AFTER the send work introduces a lost-wakeup race with SACK arrival:
531+
// a SACK that fires _senderMre.Set() between the last chunk sent and
532+
// the Reset() gets its signal wiped by Reset(), and the thread then
533+
// blocks in _senderMre.Wait() for the full BURST_PERIOD_MILLISECONDS
534+
// even though more work is ready to go. On loopback where SACKs
535+
// round-trip in microseconds this window is hit almost every burst,
536+
// capping throughput at the RFC4960 §7.2.2 steady-state of roughly
537+
// MAX_BURST * MTU / BURST_PERIOD (~104 KB/s for MTU=1300, period=50ms).
538+
// Resetting first preserves any Set() that happens during send work so
539+
// Wait() returns immediately on the next iteration.
540+
_senderMre.Reset();
541+
529542
var outstandingBytes = _outstandingBytes;
530543
// DateTime.Now calls have been a tiny bit expensive in the past so get a small saving by only
531544
// calling once per loop.
@@ -615,8 +628,6 @@ private void DoSend(object state)
615628
}
616629
}
617630

618-
_senderMre.Reset();
619-
620631
int wait = GetSendWaitMilliseconds();
621632
//logger.LogTrace($"SCTP sender wait period {wait}ms, arwnd {_receiverWindow}, cwnd {_congestionWindow} " +
622633
// $"outstanding bytes {_outstandingBytes}, send queue {_sendQueue.Count}, missing {_missingChunks.Count} "

test/unit/net/SCTP/SctpDataSenderUnitTest.cs

Lines changed: 71 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,9 @@
1515

1616
using System;
1717
using System.Collections.Concurrent;
18+
using System.Diagnostics;
1819
using System.Linq;
20+
using System.Threading;
1921
using System.Threading.Tasks;
2022
using Microsoft.Extensions.Logging;
2123
using SIPSorcery.Sys;
@@ -90,6 +92,75 @@ public async Task FillCongestionWindow()
9092
Assert.True(sender._congestionWindow < sender._outstandingBytes);
9193
}
9294

95+
/// <summary>
96+
/// Regression test for the DoSend Reset-race (producer-consumer lost-wakeup).
97+
/// Before the fix, <c>_senderMre.Reset()</c> ran AFTER the send work, so any
98+
/// <c>Set()</c> fired by an incoming SACK in the window between the last chunk
99+
/// sent and the Reset was wiped, and the thread blocked for the full
100+
/// <see cref="SctpDataSender.BURST_PERIOD_MILLISECONDS"/> (50 ms) before noticing
101+
/// more cwnd was available. This capped throughput at
102+
/// <c>MAX_BURST * MTU / BURST_PERIOD = 4 * 1300 / 50 ms = 104 KB/s</c> even on
103+
/// localhost loopback where SACKs round-trip in microseconds.
104+
///
105+
/// With the fix (Reset moved to the TOP of the loop, preserving Set-during-send
106+
/// for the next Wait), 500 KB ships in well under 500 ms on any reasonable
107+
/// machine - the bottleneck becomes the ManualResetEventSlim wake latency
108+
/// (sub-millisecond), not the 50 ms burst period.
109+
///
110+
/// Pre-fix expected: 500 KB / 104 KB/s = ~4800 ms + slow-start ramp = ~5+ seconds.
111+
/// Post-fix expected: under 500 ms.
112+
/// Threshold set at 2000 ms to leave slack for CI jitter while still proving
113+
/// we're not on the broken 100-KB/s ceiling.
114+
/// </summary>
115+
[Fact]
116+
public async Task Throughput_FastSackWake_ExceedsBurstCeiling()
117+
{
118+
uint arwnd = SctpAssociation.DEFAULT_ADVERTISED_RECEIVE_WINDOW;
119+
ushort mtu = 1400;
120+
uint initialTSN = 0;
121+
122+
SctpDataReceiver receiver = new SctpDataReceiver(arwnd, mtu, initialTSN);
123+
SctpDataSender sender = new SctpDataSender("throughput-probe", null, mtu, initialTSN, arwnd);
124+
125+
// Deliver data + SACK synchronously on the sender's own DoSend thread - the
126+
// worst case for the Reset race, because the SACK's Set() fires BEFORE the
127+
// Reset that wiped it pre-fix.
128+
Action<SctpDataChunk> doSend = (chunk) =>
129+
{
130+
receiver.OnDataChunk(chunk);
131+
sender.GotSack(receiver.GetSackChunk());
132+
};
133+
sender._sendDataChunk = doSend;
134+
sender.StartSending();
135+
136+
// 360 chunks of 1400 bytes = 504 KB. Large enough to exit slow-start and
137+
// enter the steady-state where the race would dominate, small enough that
138+
// a fast machine finishes in milliseconds.
139+
const int chunksToSend = 360;
140+
var buffer = new byte[mtu];
141+
142+
var sw = Stopwatch.StartNew();
143+
for (int i = 0; i < chunksToSend; i++)
144+
{
145+
sender.SendData(0, 0, buffer);
146+
}
147+
148+
// Wait for all chunks to be acknowledged by the receiver.
149+
uint expectedAckTSN = (uint)(chunksToSend - 1);
150+
while (receiver.CumulativeAckTSN != expectedAckTSN && sw.ElapsedMilliseconds < 10000)
151+
{
152+
await Task.Delay(5);
153+
}
154+
sw.Stop();
155+
156+
Assert.Equal(expectedAckTSN, receiver.CumulativeAckTSN);
157+
Assert.True(sw.ElapsedMilliseconds < 2000,
158+
$"Throughput regression: {chunksToSend * mtu} bytes took {sw.ElapsedMilliseconds} ms " +
159+
$"(effective {(double)(chunksToSend * mtu) / sw.ElapsedMilliseconds:F1} KB/s). " +
160+
$"Expected under 2000 ms with SACK-wake race fix. Pre-fix throughput is " +
161+
$"capped at ~104 KB/s by the Reset race, giving ~{chunksToSend * mtu / 104} ms.");
162+
}
163+
93164
/// <summary>
94165
/// Tests that the congestion window increases in slow start mode.
95166
/// </summary>

0 commit comments

Comments
 (0)