From 30967f6dfbfc5afb9d0b1999e1806c766aa3ceb6 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Tue, 9 Oct 2018 18:04:01 -0400 Subject: [PATCH 1/3] Add more Timer tests Exercise scenarios involving lots of timers. --- .../tests/TimerFiringTests.cs | 87 +++++++++++++++++++ 1 file changed, 87 insertions(+) diff --git a/src/System.Threading.Timer/tests/TimerFiringTests.cs b/src/System.Threading.Timer/tests/TimerFiringTests.cs index b5a73f662164..37a5f98af5a9 100644 --- a/src/System.Threading.Timer/tests/TimerFiringTests.cs +++ b/src/System.Threading.Timer/tests/TimerFiringTests.cs @@ -3,8 +3,10 @@ // See the LICENSE file in the project root for more information. using System; +using System.Diagnostics; using System.Linq; using System.Threading; +using System.Threading.Tasks; using Xunit; public partial class TimerFiringTests @@ -209,4 +211,89 @@ public void Timer_Dispose_WaitHandle() Assert.Equal(0, tickCount); Assert.Throws(() => t.Change(0, 0)); } + + [OuterLoop("Takes several seconds")] + [Fact] + public async Task Timer_ManyDifferentSingleDueTimes_AllFireSuccessfully() + { + await Task.WhenAll(from p in Enumerable.Range(0, Environment.ProcessorCount) + select Task.Run(async () => + { + await Task.WhenAll(from i in Enumerable.Range(1, 1_000) select DueTimeAsync(i)); + await Task.WhenAll(from i in Enumerable.Range(1, 1_000) select DueTimeAsync(1_001 - i)); + })); + } + + [OuterLoop("Takes several seconds")] + [Fact] + public async Task Timer_ManyDifferentPeriodicTimes_AllFireSuccessfully() + { + await Task.WhenAll(from p in Enumerable.Range(0, Environment.ProcessorCount) + select Task.Run(async () => + { + await Task.WhenAll(from i in Enumerable.Range(1, 400) select PeriodAsync(period: i, iterations: 3)); + await Task.WhenAll(from i in Enumerable.Range(1, 400) select PeriodAsync(period: 401 - i, iterations: 3)); + })); + } + + [OuterLoop("Takes several seconds")] + [Theory] // selection based on 333ms threshold used by implementation + [InlineData(new int[] { 15 })] + [InlineData(new int[] { 333 })] + [InlineData(new int[] { 332, 333, 334 })] + [InlineData(new int[] { 200, 300, 400 })] + [InlineData(new int[] { 200, 250, 300 })] + [InlineData(new int[] { 400, 450, 500 })] + [InlineData(new int[] { 1000 })] + public async Task Timer_ManyDifferentSerialSingleDueTimes_AllFireWithinAllowedRange(int[] dueTimes) + { + const int MillisecondsPadding = 50; // for each timer, out of range == Math.Abs(actualTime - dueTime) > MillisecondsPadding + const int MaxAllowedOutOfRangePercentage = 10; // max % allowed out of range to pass test + + long totalTimers = 0, outOfRange = 0; + await Task.WhenAll(from p in Enumerable.Range(0, Environment.ProcessorCount) + select Task.Run(async () => + { + await Task.WhenAll(from dueTimeTemplate in dueTimes + from dueTime in Enumerable.Repeat(dueTimeTemplate, 10) + select Task.Run(async () => + { + var sw = new Stopwatch(); + for (int i = 1; i <= 1_000 / dueTime; i++) + { + sw.Restart(); + await DueTimeAsync(dueTime); + sw.Stop(); + + Interlocked.Increment(ref totalTimers); + if (Math.Abs(sw.ElapsedMilliseconds - dueTime) > MillisecondsPadding) + { + Interlocked.Increment(ref outOfRange); + } + } + })); + })); + + Assert.InRange((double)outOfRange / totalTimers * 100, 0, MaxAllowedOutOfRangePercentage); + } + + private static Task DueTimeAsync(int dueTime) + { + // We could just use Task.Delay, but it only uses Timer as an implementation detail. + // Since these are Timer tests, we use an implementation that explicitly uses Timer. + var tcs = new TaskCompletionSource(); + var t = new Timer(_ => tcs.SetResult(true)); // rely on Timer(TimerCallback) rooting itself + t.Change(dueTime, -1); + return tcs.Task; + } + + private static async Task PeriodAsync(int period, int iterations) + { + var tcs = new TaskCompletionSource(); + using (var t = new Timer(_ => { if (Interlocked.Decrement(ref iterations) == 0) tcs.SetResult(true); })) // rely on Timer(TimerCallback) rooting itself + { + t.Change(period, period); + await tcs.Task.ConfigureAwait(false); + } + } } From bc6156d5648ebeaaabddee61088806f844e92476 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 10 Oct 2018 17:09:38 -0400 Subject: [PATCH 2/3] Add debugging details to new test The test is failing with very high percentages (e.g. 100%) on macOS in CI. Add more data to find out why. --- .../tests/TimerFiringTests.cs | 30 +++++++++++++++++-- 1 file changed, 27 insertions(+), 3 deletions(-) diff --git a/src/System.Threading.Timer/tests/TimerFiringTests.cs b/src/System.Threading.Timer/tests/TimerFiringTests.cs index 37a5f98af5a9..9448dc7a4f4e 100644 --- a/src/System.Threading.Timer/tests/TimerFiringTests.cs +++ b/src/System.Threading.Timer/tests/TimerFiringTests.cs @@ -3,8 +3,11 @@ // See the LICENSE file in the project root for more information. using System; +using System.Collections.Concurrent; +using System.Collections.Generic; using System.Diagnostics; using System.Linq; +using System.Text; using System.Threading; using System.Threading.Tasks; using Xunit; @@ -250,7 +253,9 @@ public async Task Timer_ManyDifferentSerialSingleDueTimes_AllFireWithinAllowedRa const int MillisecondsPadding = 50; // for each timer, out of range == Math.Abs(actualTime - dueTime) > MillisecondsPadding const int MaxAllowedOutOfRangePercentage = 10; // max % allowed out of range to pass test - long totalTimers = 0, outOfRange = 0; + var outOfRange = new ConcurrentQueue>(); + + long totalTimers = 0; await Task.WhenAll(from p in Enumerable.Range(0, Environment.ProcessorCount) select Task.Run(async () => { @@ -268,13 +273,32 @@ select Task.Run(async () => Interlocked.Increment(ref totalTimers); if (Math.Abs(sw.ElapsedMilliseconds - dueTime) > MillisecondsPadding) { - Interlocked.Increment(ref outOfRange); + outOfRange.Enqueue(new KeyValuePair(dueTime, sw.ElapsedMilliseconds)); } } })); })); - Assert.InRange((double)outOfRange / totalTimers * 100, 0, MaxAllowedOutOfRangePercentage); + double percOutOfRange = (double)outOfRange.Count / totalTimers * 100; + if (percOutOfRange > MaxAllowedOutOfRangePercentage) + { + IOrderedEnumerable>> results = + from sample in outOfRange + group sample by sample.Key into groupedByDueTime + orderby groupedByDueTime.Key + select groupedByDueTime; + + var sb = new StringBuilder(); + sb.AppendFormat("{0}% out of {1} timer firings were off by more than {2}ms", + percOutOfRange, totalTimers, MillisecondsPadding); + foreach (IGrouping> result in results) + { + sb.AppendLine(); + sb.AppendFormat("Expected: {0}, Actuals: {1}", result.Key, string.Join(", ", result.Select(k => k.Value))); + } + + Assert.True(false, sb.ToString()); + } } private static Task DueTimeAsync(int dueTime) From 3bc14f801ea1372af58dcfe70c5995e0bd973f52 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 10 Oct 2018 21:57:08 -0400 Subject: [PATCH 3/3] Disable test on macOS, and make test a little more forgiving, too --- src/System.Threading.Timer/tests/TimerFiringTests.cs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/System.Threading.Timer/tests/TimerFiringTests.cs b/src/System.Threading.Timer/tests/TimerFiringTests.cs index 9448dc7a4f4e..b3b98a8a9096 100644 --- a/src/System.Threading.Timer/tests/TimerFiringTests.cs +++ b/src/System.Threading.Timer/tests/TimerFiringTests.cs @@ -239,6 +239,7 @@ select Task.Run(async () => })); } + [PlatformSpecific(~TestPlatforms.OSX)] // macOS in CI appears to have a lot more variation [OuterLoop("Takes several seconds")] [Theory] // selection based on 333ms threshold used by implementation [InlineData(new int[] { 15 })] @@ -250,8 +251,8 @@ select Task.Run(async () => [InlineData(new int[] { 1000 })] public async Task Timer_ManyDifferentSerialSingleDueTimes_AllFireWithinAllowedRange(int[] dueTimes) { - const int MillisecondsPadding = 50; // for each timer, out of range == Math.Abs(actualTime - dueTime) > MillisecondsPadding - const int MaxAllowedOutOfRangePercentage = 10; // max % allowed out of range to pass test + const int MillisecondsPadding = 100; // for each timer, out of range == Math.Abs(actualTime - dueTime) > MillisecondsPadding + const int MaxAllowedOutOfRangePercentage = 20; // max % allowed out of range to pass test var outOfRange = new ConcurrentQueue>();