Merge pull request #9408 from umbraco/v8/bugfix/task-scheduler-maindo…

…m-logging

Ensure that TaskScheduler.Default is used anywhere that ContinueWith is used, adds more debug logging to MainDom operations

(cherry picked from commit 9a1b456)

# Conflicts:
#	src/Umbraco.Core/Runtime/SqlMainDomLock.cs

src/Umbraco.Core/Logging/LoggingTaskExtension.cs

@@ -1,4 +1,5 @@
 using System;
+using System.Threading;
 using System.Threading.Tasks;
 
 namespace Umbraco.Core.Logging
@@ -14,7 +15,12 @@ internal static class LoggingTaskExtension
         /// </summary>
         public static Task LogErrors(this Task task, Action<string, Exception> logMethod)
         {
-            return task.ContinueWith(t => LogErrorsInner(t, logMethod), TaskContinuationOptions.OnlyOnFaulted);
+            return task.ContinueWith(
+                t => LogErrorsInner(t, logMethod),
+                CancellationToken.None,
+                TaskContinuationOptions.OnlyOnFaulted,
+                // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                TaskScheduler.Default);
         }
 
         /// <summary>
@@ -26,7 +32,10 @@ public static Task LogErrors(this Task task, Action<string, Exception> logMethod
         /// </summary>
         public static Task LogErrorsWaitable(this Task task, Action<string, Exception> logMethod)
         {
-            return task.ContinueWith(t => LogErrorsInner(t, logMethod));
+            return task.ContinueWith(
+                t => LogErrorsInner(t, logMethod),
+                // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                TaskScheduler.Default);
         }
 
         private static void LogErrorsInner(Task task, Action<string, Exception> logAction)

src/Umbraco.Core/Runtime/MainDom.cs

@@ -3,6 +3,7 @@
 using System.Linq;
 using System.Security.Cryptography;
 using System.Threading;
+using System.Threading.Tasks;
 using System.Web.Hosting;
 using Umbraco.Core;
 using Umbraco.Core.Logging;
@@ -38,6 +39,9 @@ internal class MainDom : IMainDom, IRegisteredObject, IDisposable
 
         private const int LockTimeoutMilliseconds = 40000; // 40 seconds
 
+        private Task _listenTask;
+        private Task _listenCompleteTask;
+
         #endregion
 
         #region Ctor
@@ -172,7 +176,13 @@ private bool Acquire()
             try
             {
                 // Listen for the signal from another AppDomain coming online to release the lock
-                _mainDomLock.ListenAsync().ContinueWith(_ => OnSignal("signal"));
+                _listenTask = _mainDomLock.ListenAsync();
+                _listenCompleteTask = _listenTask.ContinueWith(t =>
+                {
+                    _logger.Debug<MainDom>("Listening task completed with {TaskStatus}", _listenTask.Status);
+
+                    OnSignal("signal");
+                }, TaskScheduler.Default); // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
             }
             catch (OperationCanceledException ex)
             {

src/Umbraco.Core/Runtime/SqlMainDomLock.cs

@@ -124,7 +124,12 @@ public Task ListenAsync()
 
             // Create a long running task (dedicated thread)
             // to poll to check if we are still the MainDom registered in the DB
-            return Task.Factory.StartNew(ListeningLoop, _cancellationTokenSource.Token, TaskCreationOptions.LongRunning, TaskScheduler.Default);
+            return Task.Factory.StartNew(
+                ListeningLoop,
+                _cancellationTokenSource.Token,
+                TaskCreationOptions.LongRunning,
+                // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                TaskScheduler.Default); 
 
         }
 
@@ -159,7 +164,11 @@ private void ListeningLoop()
                     // the other MainDom is taking to startup. In this case the db row will just be deleted and the
                     // new MainDom will just take over.
                     if (_cancellationTokenSource.IsCancellationRequested)
+                    {
+                        _logger.Debug<SqlMainDomLock>("Task canceled, exiting loop");
                         return;
+                    }
+
                     IUmbracoDatabase db = null;
                     try
                     {
@@ -183,8 +192,10 @@ private void ListeningLoop()
                         // We need to keep on listening unless we've been notified by our own AppDomain to shutdown since
                         // we don't want to shutdown resources controlled by MainDom inadvertently. We'll just keep listening otherwise.
                         if (_cancellationTokenSource.IsCancellationRequested)
+                        {
+                            _logger.Debug<SqlMainDomLock>("Task canceled, exiting loop");
                             return;
-
+                        }
                     }
                     finally
                     {
@@ -389,6 +400,8 @@ protected virtual void Dispose(bool disposing)
                 {
                     lock (_locker)
                     {
+                        _logger.Debug<SqlMainDomLock>($"{nameof(SqlMainDomLock)} Disposing...");
+
                         // immediately cancel all sub-tasks, we don't want them to keep querying
                         _cancellationTokenSource.Cancel();
                         _cancellationTokenSource.Dispose();

src/Umbraco.Web/PublishedCache/NuCache/ContentStore.cs

@@ -1335,7 +1335,11 @@ private Task CollectAsyncLocked()
                 {
                     _collectTask = null;
                 }
-            }, TaskContinuationOptions.ExecuteSynchronously);
+            },
+            CancellationToken.None,
+            TaskContinuationOptions.ExecuteSynchronously,
+            // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+            TaskScheduler.Default);
             // ReSharper restore InconsistentlySynchronizedField
 
             return task;

src/Umbraco.Web/PublishedCache/NuCache/SnapDictionary.cs

@@ -380,7 +380,11 @@ private Task CollectAsyncLocked()
                 {
                     _collectTask = null;
                 }
-            }, TaskContinuationOptions.ExecuteSynchronously);
+            },
+            CancellationToken.None,
+            TaskContinuationOptions.ExecuteSynchronously,
+            // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+            TaskScheduler.Default);
             // ReSharper restore InconsistentlySynchronizedField
 
             return task;

src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs

@@ -756,9 +756,17 @@ private void StopInitial()
                 lock (_locker)
                 {
                     if (_runningTask != null)
-                        _runningTask.ContinueWith(_ => StopImmediate());
+                    {
+                        _runningTask.ContinueWith(
+                            _ => StopImmediate(),
+                            // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                            TaskScheduler.Default);
+                    }   
                     else
+                    {
                         StopImmediate();
+                    }
+
                 }
             }
 

src/Umbraco.Web/Scheduling/TaskAndFactoryExtensions.cs

@@ -8,6 +8,7 @@ internal static class TaskAndFactoryExtensions
     {
         #region Task Extensions
 
+        // TODO: Not used, is this used in Deploy or something?
         static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completionSource, Task task)
         {
             if (task.IsFaulted)
@@ -16,6 +17,7 @@ static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completio
                 completionSource.SetResult(default(TResult));
         }
 
+        // TODO: Not used, is this used in Deploy or something?
         static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completionSource, Task<TResult> task)
         {
             if (task.IsFaulted)
@@ -24,17 +26,33 @@ static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completio
                 completionSource.SetResult(task.Result);
         }
 
+        // TODO: Not used, is this used in Deploy or something?
         public static Task ContinueWithTask(this Task task, Func<Task, Task> continuation)
         {
             var completionSource = new TaskCompletionSource<object>();
-            task.ContinueWith(atask => continuation(atask).ContinueWith(atask2 => SetCompletionSource(completionSource, atask2)));
+            task.ContinueWith(atask => continuation(atask).ContinueWith(
+                    atask2 => SetCompletionSource(completionSource, atask2),
+                    // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                    TaskScheduler.Default),
+                // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                TaskScheduler.Default);
             return completionSource.Task;
         }
 
+        // TODO: Not used, is this used in Deploy or something?
         public static Task ContinueWithTask(this Task task, Func<Task, Task> continuation, CancellationToken token)
         {
             var completionSource = new TaskCompletionSource<object>();
-            task.ContinueWith(atask => continuation(atask).ContinueWith(atask2 => SetCompletionSource(completionSource, atask2), token), token);
+            task.ContinueWith(atask => continuation(atask).ContinueWith(
+                    atask2 => SetCompletionSource(completionSource, atask2),
+                    token,
+                    TaskContinuationOptions.None,
+                    // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                    TaskScheduler.Default),
+                token,
+                TaskContinuationOptions.None,
+                // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                TaskScheduler.Default);
             return completionSource.Task;
         }
 

src/Umbraco.Web/WebApi/HttpActionContextExtensions.cs

@@ -89,7 +89,9 @@ public static MultipartFormDataStreamProvider ReadAsMultipart(this HttpActionCon
                         throw x.Exception;
                     }
                     result = x.ConfigureAwait(false).GetAwaiter().GetResult();
-                });
+                },
+                // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
+                TaskScheduler.Default);
             task.Wait();
 
             if (result == null)