From 3f78331145fee09e763e409b42e307ee542cab6e Mon Sep 17 00:00:00 2001 From: Shannon Date: Thu, 5 Dec 2019 23:26:49 +1100 Subject: [PATCH] Adds lots of notes, fixes tests to ensure we catch OperationCanceledException where necessary, adds logging to tests, fixes a boolean op --- .../Scheduling/BackgroundTaskRunnerTests.cs | 63 ++++++++++++------- .../Scheduling/BackgroundTaskRunner.cs | 33 +++++++--- 2 files changed, 64 insertions(+), 32 deletions(-) diff --git a/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs b/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs index 4d264c830e..ea42cd2ea9 100644 --- a/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs +++ b/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs @@ -7,6 +7,7 @@ using System.Threading.Tasks; using NUnit.Framework; using Umbraco.Core; using Umbraco.Core.Logging; +using Umbraco.Tests.TestHelpers; using Umbraco.Web.Scheduling; namespace Umbraco.Tests.Scheduling @@ -21,7 +22,7 @@ namespace Umbraco.Tests.Scheduling [OneTimeSetUp] public void InitializeFixture() { - _logger = new DebugDiagnosticsLogger(); + _logger = new ConsoleLogger(); } [Test] @@ -102,12 +103,12 @@ namespace Umbraco.Tests.Scheduling { using (var runner = new BackgroundTaskRunner(new BackgroundTaskRunnerOptions(), _logger)) { - MyTask t; + MyTask t1, t2, t3; Assert.IsFalse(runner.IsRunning); // because AutoStart is false - runner.Add(new MyTask(5000)); - runner.Add(new MyTask()); - runner.Add(t = new MyTask()); + runner.Add(t1 = new MyTask(5000)); + runner.Add(t2 = new MyTask()); + runner.Add(t3 = new MyTask()); Assert.IsTrue(runner.IsRunning); // is running tasks // shutdown -force => run all queued tasks @@ -115,7 +116,7 @@ namespace Umbraco.Tests.Scheduling Assert.IsTrue(runner.IsRunning); // is running tasks await runner.StoppedAwaitable; // runner stops, within test's timeout - Assert.AreNotEqual(DateTime.MinValue, t.Ended); // t has run + Assert.AreNotEqual(DateTime.MinValue, t3.Ended); // t3 has run } } @@ -124,20 +125,25 @@ namespace Umbraco.Tests.Scheduling { using (var runner = new BackgroundTaskRunner(new BackgroundTaskRunnerOptions(), _logger)) { - MyTask t; + MyTask t1, t2, t3; Assert.IsFalse(runner.IsRunning); // because AutoStart is false - runner.Add(new MyTask(5000)); - runner.Add(new MyTask()); - runner.Add(t = new MyTask()); + runner.Add(t1 = new MyTask(5000)); + runner.Add(t2 = new MyTask()); + runner.Add(t3 = new MyTask()); Assert.IsTrue(runner.IsRunning); // is running tasks + Thread.Sleep(1000); // since we are forcing shutdown, we need to give it a chance to start, else it will be canceled before the queue is started + // shutdown +force => tries to cancel the current task, ignores queued tasks runner.Shutdown(true, false); // +force -wait Assert.IsTrue(runner.IsRunning); // is running that long task it cannot cancel - await runner.StoppedAwaitable; // runner stops, within test's timeout - Assert.AreEqual(DateTime.MinValue, t.Ended); // t has *not* run + await runner.StoppedAwaitable; // runner stops, within test's timeout (no cancelation token used, no need to catch OperationCanceledException) + + Assert.AreNotEqual(DateTime.MinValue, t1.Ended); // t1 *has* run + Assert.AreEqual(DateTime.MinValue, t2.Ended); // t2 has *not* run + Assert.AreEqual(DateTime.MinValue, t3.Ended); // t3 has *not* run } } @@ -163,7 +169,15 @@ namespace Umbraco.Tests.Scheduling // shutdown +force => tries to cancel the current task, ignores queued tasks runner.Shutdown(true, false); // +force -wait - await runner.StoppedAwaitable; // runner stops, within test's timeout + try + { + await runner.StoppedAwaitable; // runner stops, within test's timeout ... maybe + } + catch (OperationCanceledException) + { + // catch exception, this can occur because we are +force shutting down which will + // cancel a pending task if the queue hasn't completed in time + } } } @@ -188,7 +202,8 @@ namespace Umbraco.Tests.Scheduling runner.Add(t = new MyTask()); // sleeps 500 ms ... total = 1500 ms until it's done Assert.IsTrue(runner.IsRunning); // is running the task - await runner.StopInternal(false); // -immediate = -force, -wait (max 2000 ms delay before +immediate) + runner.Stop(false); // -immediate = -force, -wait (max 2000 ms delay before +immediate) + await runner.TerminatedAwaitable; Assert.IsTrue(stopped); // raised that one Assert.IsTrue(terminating); // has raised that event @@ -221,7 +236,8 @@ namespace Umbraco.Tests.Scheduling runner.Add(t = new MyTask()); // sleeps 500 ms ... total = 1500 ms until it's done Assert.IsTrue(runner.IsRunning); // is running the task - await runner.StopInternal(true); // +immediate = +force, +wait (no delay) + runner.Stop(true); // +immediate = +force, +wait (no delay) + await runner.TerminatedAwaitable; Assert.IsTrue(stopped); // raised that one Assert.IsTrue(terminating); // has raised that event @@ -255,8 +271,7 @@ namespace Umbraco.Tests.Scheduling }, _logger)) { Assert.IsTrue(runner.IsRunning); // because AutoStart is true - runner.Stop(false); // keepalive = must be stopped - await runner.StoppedAwaitable; // runner stops, within test's timeout + await runner.StopInternal(false); // keepalive = must be stopped } } @@ -282,13 +297,9 @@ namespace Umbraco.Tests.Scheduling // dispose will stop it } - await runner.StoppedAwaitable; // runner stops, within test's timeout - //await runner.TerminatedAwaitable; // NO! see note below + await runner.StoppedAwaitable; Assert.Throws(() => runner.Add(new MyTask())); - // but do NOT await on TerminatedAwaitable - disposing just shuts the runner down - // so that we don't have a runaway task in tests, etc - but it does NOT terminate - // the runner - it really is NOT a nice way to end a runner - it's there for tests } [Test] @@ -575,7 +586,7 @@ namespace Umbraco.Tests.Scheduling Thread.Sleep(5000); Assert.IsTrue(runner.IsRunning); // still waiting for the task to release Assert.IsFalse(task.HasRun); - runner.Shutdown(false, false); + runner.Shutdown(false, false); // -force, -wait await runner.StoppedAwaitable; // wait for the entire runner operation to complete Assert.IsTrue(task.HasRun); } @@ -871,7 +882,9 @@ namespace Umbraco.Tests.Scheduling public override void PerformRun() { + Console.WriteLine($"Sleeping {_milliseconds}..."); Thread.Sleep(_milliseconds); + Console.WriteLine("Wake up!"); } } @@ -988,7 +1001,9 @@ namespace Umbraco.Tests.Scheduling public DateTime Ended { get; set; } public virtual void Dispose() - { } + { + + } } } } diff --git a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs b/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs index ebb9162f29..c0475b1f79 100644 --- a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs +++ b/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs @@ -199,7 +199,7 @@ namespace Umbraco.Web.Scheduling { lock (_locker) { - var task = _runningTask ?? Task.FromResult(0); + var task = _runningTask ?? Task.CompletedTask; return new ThreadingTaskImmutable(task); } } @@ -211,8 +211,9 @@ namespace Umbraco.Web.Scheduling /// An awaitable object. /// /// Used to wait until the runner has terminated. - /// This is for unit tests and should not be used otherwise. In most cases when the runner - /// has terminated, the application domain is going down and it is not the right time to do things. + /// + /// The only time the runner will be terminated is by the Hosting Environment when the application is being shutdown. + /// /// internal ThreadingTaskImmutable TerminatedAwaitable { @@ -347,14 +348,18 @@ namespace Umbraco.Web.Scheduling // will stop waiting on the queue or on a latch _tasks.Complete(); - if (!hasTasks || force) + if (force) { // we must bring everything down, now lock (_locker) { // was Complete() enough? - if (_isRunning == false) return; + // if _tasks.Complete() ended up triggering code to stop the runner and reset + // the _isRunning flag, then there's no need to initiate a cancel on the cancelation token. + if (_isRunning == false) + return; } + // try to cancel running async tasks (cannot do much about sync tasks) // break latched tasks // stop processing the queue @@ -586,17 +591,18 @@ namespace Umbraco.Web.Scheduling // triggers when the hosting environment requests that the runner terminates internal event TypedEventHandler, EventArgs> Terminating; - // triggers when the runner has terminated (no task can be added, no task is running) + // triggers when the hosting environment has terminated (no task can be added, no task is running) internal event TypedEventHandler, EventArgs> Terminated; private void OnEvent(TypedEventHandler, EventArgs> handler, string name) { - if (handler == null) return; OnEvent(handler, name, EventArgs.Empty); } private void OnEvent(TypedEventHandler, TArgs> handler, string name, TArgs e) { + _logger.Debug("{LogPrefix} OnEvent {EventName}", _logPrefix, name); + if (handler == null) return; try @@ -672,6 +678,15 @@ namespace Umbraco.Web.Scheduling #endregion + #region IRegisteredObject.Stop + + /// + /// Used by IRegisteredObject.Stop and shutdown on threadpool threads to not block shutdown times. + /// + /// + /// + /// An awaitable Task that is used to handle the shutdown. + /// internal Task StopInternal(bool immediate) { // the first time the hosting environment requests that the runner terminates, @@ -701,7 +716,7 @@ namespace Umbraco.Web.Scheduling { lock (_locker) { - if (_terminated) return Task.FromResult(0); + if (_terminated) return Task.CompletedTask; return Task.Run(StopImmediate, CancellationToken.None); } } @@ -810,5 +825,7 @@ namespace Umbraco.Web.Scheduling terminatedSource.TrySetResult(0); } + + #endregion } }