diff --git a/build/NuSpecs/UmbracoCms.Core.nuspec b/build/NuSpecs/UmbracoCms.Core.nuspec index 450aec09b6..cb7092fe80 100644 --- a/build/NuSpecs/UmbracoCms.Core.nuspec +++ b/build/NuSpecs/UmbracoCms.Core.nuspec @@ -38,7 +38,8 @@ - + + diff --git a/src/Umbraco.Tests/Logging/ConsoleLogger.cs b/src/Umbraco.Tests/Logging/ConsoleLogger.cs new file mode 100644 index 0000000000..ba3981841d --- /dev/null +++ b/src/Umbraco.Tests/Logging/ConsoleLogger.cs @@ -0,0 +1,48 @@ +using System; +using System.Linq; +using Umbraco.Core.Logging; + +namespace Umbraco.Tests.Logging +{ + // FIXME how come some C# 6 features are working here ?! + + public class ConsoleLogger : ILogger + { + public void Error(Type callingType, string message, Exception exception) + { + Console.WriteLine("INFO {0} - {1}", callingType.Name, message); + Console.WriteLine(exception); + } + + public void Warn(Type callingType, string message, params Func[] formatItems) + { + Console.WriteLine("WARN {0} - {1}", callingType.Name, string.Format(message, formatItems.Select(x => x()).ToArray())); + } + + public void WarnWithException(Type callingType, string message, Exception e, params Func[] formatItems) + { + Console.WriteLine("WARN {0} - {1}", callingType.Name, string.Format(message, formatItems.Select(x => x()).ToArray())); + Console.WriteLine(e); + } + + public void Info(Type callingType, Func generateMessage) + { + Console.WriteLine("INFO {0} - {1}", callingType.Name, generateMessage()); + } + + public void Info(Type type, string generateMessageFormat, params Func[] formatItems) + { + Console.WriteLine("INFO {0} - {1}", type.Name, string.Format(generateMessageFormat, formatItems.Select(x => x()).ToArray())); + } + + public void Debug(Type callingType, Func generateMessage) + { + Console.WriteLine("DEBUG {0} - {1}", callingType.Name, generateMessage()); + } + + public void Debug(Type type, string generateMessageFormat, params Func[] formatItems) + { + Console.WriteLine("DEBUG {0} - {1}", type.Name, string.Format(generateMessageFormat, formatItems.Select(x => x()).ToArray())); + } + } +} diff --git a/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs b/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs index db060ddc79..aacb056346 100644 --- a/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs +++ b/src/Umbraco.Tests/Scheduling/BackgroundTaskRunnerTests.cs @@ -783,25 +783,25 @@ namespace Umbraco.Tests.Scheduling private class MyLatchedTask : ILatchedBackgroundTask { private readonly int _runMilliseconds; - private readonly ManualResetEventSlim _latch; + private readonly TaskCompletionSource _latch; public bool HasRun { get; private set; } public MyLatchedTask(int runMilliseconds, bool runsOnShutdown) { _runMilliseconds = runMilliseconds; - _latch = new ManualResetEventSlim(false); + _latch = new TaskCompletionSource(); RunsOnShutdown = runsOnShutdown; } - public WaitHandle Latch + public Task Latch { - get { return _latch.WaitHandle; } + get { return _latch.Task; } } public bool IsLatched { - get { return _latch.IsSet == false; } + get { return _latch.Task.IsCompleted == false; } } public bool RunsOnShutdown { get; private set; } @@ -814,7 +814,7 @@ namespace Umbraco.Tests.Scheduling public void Release() { - _latch.Set(); + _latch.SetResult(true); } public Task RunAsync(CancellationToken token) @@ -909,6 +909,56 @@ namespace Umbraco.Tests.Scheduling } } + [Test] + public void SourceTaskTest() + { + var runner = new BackgroundTaskRunner(new BackgroundTaskRunnerOptions { KeepAlive = true, LongRunning = true }, _logger); + + var task = new SourceTask(); + runner.Add(task); + Assert.IsTrue(runner.IsRunning); + Console.WriteLine("completing"); + task.Complete(); // in Deploy this does not return ffs - no point until I cannot repro + Console.WriteLine("completed"); + Console.WriteLine("done"); + } + + private class SourceTask : IBackgroundTask + { + private readonly SemaphoreSlim _timeout = new SemaphoreSlim(0, 1); + private readonly TaskCompletionSource _source = new TaskCompletionSource(); + + public void Complete() + { + _source.SetResult(null); + } + + public void Dispose() + { } + + public void Run() + { + throw new NotImplementedException(); + } + + private int i; + + public async Task RunAsync(CancellationToken token) + { + Console.WriteLine("boom"); + var timeout = _timeout.WaitAsync(token); + var task = WorkItemRunAsync(); + var anyTask = await Task.WhenAny(task, timeout).ConfigureAwait(false); + } + + private async Task WorkItemRunAsync() + { + await _source.Task.ConfigureAwait(false); + } + + public bool IsAsync { get { return true; } } + } + public abstract class BaseTask : IBackgroundTask { public bool WasCancelled { get; set; } diff --git a/src/Umbraco.Tests/Scheduling/DeployTest.cs b/src/Umbraco.Tests/Scheduling/DeployTest.cs new file mode 100644 index 0000000000..60322ce7b7 --- /dev/null +++ b/src/Umbraco.Tests/Scheduling/DeployTest.cs @@ -0,0 +1,73 @@ +using System; +using System.Threading; +using System.Threading.Tasks; +using NUnit.Framework; +using Umbraco.Tests.Logging; +using Umbraco.Web.Scheduling; + +namespace Umbraco.Tests.Scheduling +{ + // THIS REPRODUCES THE DEPLOY ISSUE IN CORE + // + // the exact same thing also reproduces in playground + // so it's not a framework version issue - but something we're doing here + + [TestFixture] + [Timeout(4000)] + public class Repro + { + [Test] + public async Task ReproduceDeployIssue() + { + var logger = new ConsoleLogger(); + var runner = new BackgroundTaskRunner(new BackgroundTaskRunnerOptions { KeepAlive = true, LongRunning = true }, logger); + var work = new SimpleWorkItem(); + runner.Add(work); + + Console.WriteLine("running"); + await Task.Delay(1000); // don't complete too soon + + Console.WriteLine("completing"); + + // this never returns, never reached "completed" because the same thread + // resumes executing the waiting on queue operation in the runner + work.Complete(); + Console.WriteLine("completed"); + + Console.WriteLine("done"); + } + + public class SimpleWorkItem : IBackgroundTask + { + private TaskCompletionSource _completionSource; + + public async Task RunAsync(CancellationToken token) + { + _completionSource = new TaskCompletionSource(); + token.Register(() => _completionSource.TrySetCanceled()); // propagate + Console.WriteLine("item running..."); + await _completionSource.Task.ConfigureAwait(false); + Console.WriteLine("item returning"); + } + + public bool Complete(bool success = true) + { + Console.WriteLine("item completing"); + // this never returns, see test + _completionSource.SetResult(0); + Console.WriteLine("item returning from completing"); + return true; + } + + public void Run() + { + throw new NotImplementedException(); + } + + public bool IsAsync { get { return true; } } + + public void Dispose() + {} + } + } +} \ No newline at end of file diff --git a/src/Umbraco.Tests/Umbraco.Tests.csproj b/src/Umbraco.Tests/Umbraco.Tests.csproj index 041a11836c..2395a03fd0 100644 --- a/src/Umbraco.Tests/Umbraco.Tests.csproj +++ b/src/Umbraco.Tests/Umbraco.Tests.csproj @@ -40,6 +40,7 @@ prompt 4 false + 5 pdbonly @@ -177,10 +178,12 @@ + + diff --git a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs b/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs index fa878c3f79..acbbdbf710 100644 --- a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs +++ b/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs @@ -1,9 +1,7 @@ using System; -using System.Collections.Concurrent; -using System.Collections.Generic; -using System.Runtime.CompilerServices; using System.Threading; using System.Threading.Tasks; +using System.Threading.Tasks.Dataflow; using System.Web.Hosting; using Umbraco.Core; using Umbraco.Core.Events; @@ -27,18 +25,21 @@ namespace Umbraco.Web.Scheduling public class BackgroundTaskRunner : BackgroundTaskRunner, IBackgroundTaskRunner where T : class, IBackgroundTask { + // do not remove this comment! + // + // if you plan to do anything on this class, first go and read + // http://blog.stephencleary.com/2012/12/dont-block-in-asynchronous-code.html + // http://stackoverflow.com/questions/19481964/calling-taskcompletionsource-setresult-in-a-non-blocking-manner + // http://stackoverflow.com/questions/21225361/is-there-anything-like-asynchronous-blockingcollectiont + // and more, and more, and more + // and remember: async is hard + private readonly string _logPrefix; private readonly BackgroundTaskRunnerOptions _options; private readonly ILogger _logger; private readonly object _locker = new object(); - private readonly BlockingCollection _tasks = new BlockingCollection(); - private IEnumerator _enumerator; - - // that event is used to stop the pump when it is alive and waiting - // on a latched task - so it waits on the latch, the cancellation token, - // and the completed event - private readonly ManualResetEventSlim _completedEvent = new ManualResetEventSlim(false); + private readonly BufferBlock _tasks = new BufferBlock(new DataflowBlockOptions { }); // in various places we are testing these vars outside a lock, so make them volatile private volatile bool _isRunning; // is running @@ -60,7 +61,7 @@ namespace Umbraco.Web.Scheduling /// An optional action to execute when the main domain status is aquired. /// An optional action to execute when the main domain status is released. public BackgroundTaskRunner(ILogger logger, Action mainDomInstall = null, Action mainDomRelease = null) - : this(typeof (T).FullName, new BackgroundTaskRunnerOptions(), logger, mainDomInstall, mainDomRelease) + : this(typeof(T).FullName, new BackgroundTaskRunnerOptions(), logger, mainDomInstall, mainDomRelease) { } /// @@ -82,7 +83,7 @@ namespace Umbraco.Web.Scheduling /// An optional action to execute when the main domain status is aquired. /// An optional action to execute when the main domain status is released. public BackgroundTaskRunner(BackgroundTaskRunnerOptions options, ILogger logger, Action mainDomInstall = null, Action mainDomRelease = null) - : this(typeof (T).FullName, options, logger, mainDomInstall, mainDomRelease) + : this(typeof(T).FullName, options, logger, mainDomInstall, mainDomRelease) { } /// @@ -173,7 +174,7 @@ namespace Umbraco.Web.Scheduling /// An awaitable instance. /// Used to wait until the runner is no longer running (IsRunning == false), /// though the runner could be started again afterwards by adding tasks to it. - internal ThreadingTaskImmutable StoppedAwaitable + public ThreadingTaskImmutable StoppedAwaitable { get { @@ -222,8 +223,8 @@ namespace Umbraco.Web.Scheduling throw new InvalidOperationException("The task runner has completed."); // add task - _logger.Debug(_logPrefix + "Task added {0}", task.GetType); - _tasks.Add(task); + _logger.Debug(_logPrefix + "Task added {0}", () => task.GetType().FullName); + _tasks.Post(task); // start StartUpLocked(); @@ -242,13 +243,13 @@ namespace Umbraco.Web.Scheduling { if (_completed) { - _logger.Debug(_logPrefix + "Task cannot be added {0}, the task runner has already shutdown", task.GetType); + _logger.Debug(_logPrefix + "Task cannot be added {0}, the task runner has already shutdown", () => task.GetType().FullName); return false; } // add task - _logger.Debug(_logPrefix + "Task added {0}", task.GetType); - _tasks.Add(task); + _logger.Debug(_logPrefix + "Task added {0}", () => task.GetType().FullName); + _tasks.Post(task); // start StartUpLocked(); @@ -303,9 +304,7 @@ namespace Umbraco.Web.Scheduling // create a new token source since this is a new process _shutdownTokenSource = new CancellationTokenSource(); _shutdownToken = _shutdownTokenSource.Token; - - _enumerator = _options.KeepAlive ? _tasks.GetConsumingEnumerable(_shutdownToken).GetEnumerator() : null; - _runningTask = Task.Run(async () => await Pump(), _shutdownToken); + _runningTask = Task.Run(async () => await Pump().ConfigureAwait(false), _shutdownToken); _logger.Debug(_logPrefix + "Starting"); } @@ -325,23 +324,22 @@ namespace Umbraco.Web.Scheduling if (_isRunning == false) return; // done already } - // try to be nice - // assuming multiple threads can do these without problems - _completedEvent.Set(); - _tasks.CompleteAdding(); + // complete the queue + // will stop waiting on the queue or on a latch + _tasks.Complete(); if (force) { // we must bring everything down, now - Thread.Sleep(100); // give time to CompleteAdding() + Thread.Sleep(100); // give time to Complete() lock (_locker) { - // was CompleteAdding() enough? + // was Complete() enough? if (_isRunning == false) return; } // try to cancel running async tasks (cannot do much about sync tasks) - // break delayed tasks delay - // truncate running queues + // break latched tasks + // stop processing the queue _shutdownTokenSource.Cancel(false); // false is the default } @@ -356,66 +354,64 @@ namespace Umbraco.Web.Scheduling { while (true) { - var bgTask = GetNextBackgroundTask(); - if (bgTask == null) - return; + // get the next task + // if it returns null the runner is going down, stop + var bgTask = await GetNextBackgroundTask(_shutdownToken); + if (bgTask == null) return; + // set a cancellation source so that the current task can be cancelled + // link from _shutdownToken so that we can use _cancelTokenSource for both lock (_locker) { - // set another one - for the next task _cancelTokenSource = CancellationTokenSource.CreateLinkedTokenSource(_shutdownToken); } - bgTask = WaitForLatch(bgTask, _cancelTokenSource.Token); - if (bgTask == null) return; + // wait for latch should return the task + // if it returns null it's either that the task has been cancelled + // or the whole runner is going down - in both cases, continue, + // and GetNextBackgroundTask will take care of shutdowns + bgTask = await WaitForLatch(bgTask, _cancelTokenSource.Token); + if (bgTask == null) continue; + // executes & be safe - RunAsync should NOT throw but only raise an event, + // but... just make sure we never ever take everything down try { await RunAsync(bgTask, _cancelTokenSource.Token).ConfigureAwait(false); } catch (Exception e) { - // RunAsync should NOT throw exception - just raise an event - // this is here for safety and to ensure we don't kill everything, ever _logger.Error(_logPrefix + "Task runner exception.", e); } - _cancelTokenSource = null; + // done + lock (_locker) + { + _cancelTokenSource = null; + } } } - private T GetNextBackgroundTask() + // gets the next background task from the buffer + private async Task GetNextBackgroundTask(CancellationToken token) { while (true) { - // exit if cancelling - if (_shutdownToken.IsCancellationRequested == false) - { - // try to get a task - // the blocking MoveNext will end if token is cancelled or collection is completed - T bgTask; - var hasBgTask = _options.KeepAlive - ? (bgTask = _enumerator.MoveNext() ? _enumerator.Current : null) != null // blocking - : _tasks.TryTake(out bgTask); // non-blocking - - // exit if cancelling - if (_shutdownToken.IsCancellationRequested == false && hasBgTask) - return bgTask; - } + var task = await GetNextBackgroundTask2(token); + if (task != null) return task; lock (_locker) { + // deal with race condition if (_shutdownToken.IsCancellationRequested == false && _tasks.Count > 0) continue; + // if we really have nothing to do, stop _logger.Debug(_logPrefix + "Stopping"); if (_options.PreserveRunningTask == false) _runningTask = null; - _isRunning = false; - _shutdownToken = CancellationToken.None; - _enumerator = null; } OnEvent(Stopped, "Stopped"); @@ -423,32 +419,82 @@ namespace Umbraco.Web.Scheduling } } - private T WaitForLatch(T bgTask, CancellationToken token) + private async Task GetNextBackgroundTask2(CancellationToken shutdownToken) + { + // exit if cancelling + if (shutdownToken.IsCancellationRequested) + return null; + + // if keepalive is false then don't block, exit if there is + // no task in the buffer - yes, there is a race cond, which + // we'll take care of + if (_options.KeepAlive == false && _tasks.Count == 0) + return null; + + try + { + // A Task that informs of whether and when more output is available. If, when the + // task completes, its Result is true, more output is available in the source (though another + // consumer of the source may retrieve the data). If it returns false, more output is not + // and will never be available, due to the source completing prior to output being available. + + var output = await _tasks.OutputAvailableAsync(shutdownToken); // block until output or cancelled + if (output == false) return null; + } + catch (TaskCanceledException) + { + return null; + } + + try + { + // A task that represents the asynchronous receive operation. When an item value is successfully + // received from the source, the returned task is completed and its Result returns the received + // value. If an item value cannot be retrieved because the source is empty and completed, an + // InvalidOperationException exception is thrown in the returned task. + + // the source cannot be empty *and* completed here - we know we have output + return await _tasks.ReceiveAsync(shutdownToken); + } + catch (TaskCanceledException) + { + return null; + } + } + + // if bgTask is not a latched background task, or if it is not latched, returns immediately + // else waits for the latch, taking care of completion and shutdown and whatnot + private async Task WaitForLatch(T bgTask, CancellationToken token) { var latched = bgTask as ILatchedBackgroundTask; if (latched == null || latched.IsLatched == false) return bgTask; - // returns the array index of the object that satisfied the wait - var i = WaitHandle.WaitAny(new[] { latched.Latch, token.WaitHandle, _completedEvent.WaitHandle }); + // support cancelling awaiting + // read https://github.com/dotnet/corefx/issues/2704 + // read http://stackoverflow.com/questions/27238232/how-can-i-cancel-task-whenall + var tokenTaskSource = new TaskCompletionSource(); + token.Register(s => ((TaskCompletionSource)s).SetResult(true), tokenTaskSource); - switch (i) - { - case 0: - // ok to run now - return bgTask; - case 1: - // cancellation - return null; - case 2: - // termination - if (latched.RunsOnShutdown) return bgTask; - latched.Dispose(); - return null; - default: - throw new Exception("panic."); - } + // returns the task that completed + // - latched.Latch completes when the latch releases + // - _tasks.Completion completes when the runner completes + // - tokenTaskSource.Task completes when this task, or the whole runner, is cancelled + var task = await Task.WhenAny(latched.Latch, _tasks.Completion, tokenTaskSource.Task); + + // ok to run now + if (task == latched.Latch) + return bgTask; + + // if shutting down, return the task only if it runs on shutdown + if (_shutdownToken.IsCancellationRequested == false && latched.RunsOnShutdown) return bgTask; + + // else, either it does not run on shutdown or it's been cancelled, dispose + latched.Dispose(); + return null; } + // runs the background task, taking care of shutdown (as far as possible - cannot abort + // a non-async Run for example, so we'll do our best) private async Task RunAsync(T bgTask, CancellationToken token) { try @@ -483,7 +529,7 @@ namespace Umbraco.Web.Scheduling catch (Exception ex) { _logger.Error(_logPrefix + "Task has failed", ex); - } + } } #region Events @@ -548,7 +594,7 @@ namespace Umbraco.Web.Scheduling { OnEvent(TaskCancelled, "TaskCancelled", e); - //dispose it + // dispose it e.Task.Dispose(); } diff --git a/src/Umbraco.Web/Scheduling/ILatchedBackgroundTask.cs b/src/Umbraco.Web/Scheduling/ILatchedBackgroundTask.cs index 79379cb966..c761e5f4de 100644 --- a/src/Umbraco.Web/Scheduling/ILatchedBackgroundTask.cs +++ b/src/Umbraco.Web/Scheduling/ILatchedBackgroundTask.cs @@ -1,5 +1,6 @@ using System; using System.Threading; +using System.Threading.Tasks; namespace Umbraco.Web.Scheduling { @@ -13,10 +14,10 @@ namespace Umbraco.Web.Scheduling internal interface ILatchedBackgroundTask : IBackgroundTask { /// - /// Gets a wait handle on the task condition. + /// Gets a task on latch. /// /// The task is not latched. - WaitHandle Latch { get; } + Task Latch { get; } /// /// Gets a value indicating whether the task is latched. diff --git a/src/Umbraco.Web/Scheduling/LatchedBackgroundTaskBase.cs b/src/Umbraco.Web/Scheduling/LatchedBackgroundTaskBase.cs index 3315fa7c34..cde9986483 100644 --- a/src/Umbraco.Web/Scheduling/LatchedBackgroundTaskBase.cs +++ b/src/Umbraco.Web/Scheduling/LatchedBackgroundTaskBase.cs @@ -7,11 +7,11 @@ namespace Umbraco.Web.Scheduling { internal abstract class LatchedBackgroundTaskBase : DisposableObject, ILatchedBackgroundTask { - private readonly ManualResetEventSlim _latch; + private TaskCompletionSource _latch; protected LatchedBackgroundTaskBase() { - _latch = new ManualResetEventSlim(false); + _latch = new TaskCompletionSource(); } /// @@ -29,24 +29,24 @@ namespace Umbraco.Web.Scheduling /// public abstract bool IsAsync { get; } - public WaitHandle Latch + public Task Latch { - get { return _latch.WaitHandle; } + get { return _latch.Task; } } public bool IsLatched { - get { return _latch.IsSet == false; } + get { return _latch.Task.IsCompleted == false; } } protected void Release() { - _latch.Set(); + _latch.SetResult(true); } protected void Reset() { - _latch.Reset(); + _latch = new TaskCompletionSource(); } public abstract bool RunsOnShutdown { get; } @@ -56,8 +56,6 @@ namespace Umbraco.Web.Scheduling // remain active protected override void DisposeResources() - { - _latch.Dispose(); - } + { } } } diff --git a/src/Umbraco.Web/Umbraco.Web.csproj b/src/Umbraco.Web/Umbraco.Web.csproj index c89e60a399..9eb0b0ef4f 100644 --- a/src/Umbraco.Web/Umbraco.Web.csproj +++ b/src/Umbraco.Web/Umbraco.Web.csproj @@ -213,6 +213,10 @@ + + ..\packages\System.Threading.Tasks.Dataflow.4.6.0\lib\netstandard1.1\System.Threading.Tasks.Dataflow.dll + True + 3.5 diff --git a/src/Umbraco.Web/packages.config b/src/Umbraco.Web/packages.config index 9106e59fe0..8c743ba07c 100644 --- a/src/Umbraco.Web/packages.config +++ b/src/Umbraco.Web/packages.config @@ -28,6 +28,7 @@ + \ No newline at end of file diff --git a/src/umbraco.sln.DotSettings b/src/umbraco.sln.DotSettings index 19aedb76e3..dd168f105b 100644 --- a/src/umbraco.sln.DotSettings +++ b/src/umbraco.sln.DotSettings @@ -1,4 +1,4 @@ - + <data><IncludeFilters /><ExcludeFilters /></data> <data /> True @@ -16,14 +16,5 @@ Disposable construction HINT False - - - - - - - - - - - \ No newline at end of file + CSharp50 + \ No newline at end of file