Merge pull request #9408 from umbraco/v8/bugfix/task-scheduler-maindom-logging

bergmania · nul800sebastiaan · commit cd1120e062dc · 2020-12-15T14:14:30.000+01:00
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
diff --git a/src/Umbraco.Core/Logging/LoggingTaskExtension.cs b/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)
diff --git a/src/Umbraco.Core/Runtime/MainDom.cs b/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)
             {
diff --git a/src/Umbraco.Core/Runtime/SqlMainDomLock.cs b/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();
diff --git a/src/Umbraco.Web/PublishedCache/NuCache/ContentStore.cs b/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;
diff --git a/src/Umbraco.Web/PublishedCache/NuCache/SnapDictionary.cs b/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;
diff --git a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs b/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();
+                    }
+                        
                 }
             }
 
diff --git a/src/Umbraco.Web/Scheduling/TaskAndFactoryExtensions.cs b/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;
         }
 
diff --git a/src/Umbraco.Web/WebApi/HttpActionContextExtensions.cs b/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)

Original file line number	Diff line number	Diff line change
`@@ -1335,7 +1335,11 @@ private Task CollectAsyncLocked()`
`1335`	`1335`	`{`
`1336`	`1336`	`_collectTask = null;`
`1337`	`1337`	`}`
`1338`		`- }, TaskContinuationOptions.ExecuteSynchronously);`
	`1338`	`+ },`
	`1339`	`+ CancellationToken.None,`
	`1340`	`+ TaskContinuationOptions.ExecuteSynchronously,`
	`1341`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`1342`	`+ TaskScheduler.Default);`
`1339`	`1343`	`// ReSharper restore InconsistentlySynchronizedField`
`1340`	`1344`
`1341`	`1345`	`return task;`
Original file line number	Diff line number	Diff line change
`@@ -380,7 +380,11 @@ private Task CollectAsyncLocked()`
`380`	`380`	`{`
`381`	`381`	`_collectTask = null;`
`382`	`382`	`}`
`383`		`- }, TaskContinuationOptions.ExecuteSynchronously);`
	`383`	`+ },`
	`384`	`+ CancellationToken.None,`
	`385`	`+ TaskContinuationOptions.ExecuteSynchronously,`
	`386`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`387`	`+ TaskScheduler.Default);`
`384`	`388`	`// ReSharper restore InconsistentlySynchronizedField`
`385`	`389`
`386`	`390`	`return task;`
Original file line number	Diff line number	Diff line change
`@@ -756,9 +756,17 @@ private void StopInitial()`
`756`	`756`	`lock (_locker)`
`757`	`757`	`{`
`758`	`758`	`if (_runningTask != null)`
`759`		`- _runningTask.ContinueWith(_ => StopImmediate());`
	`759`	`+ {`
	`760`	`+ _runningTask.ContinueWith(`
	`761`	`+ _ => StopImmediate(),`
	`762`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`763`	`+ TaskScheduler.Default);`
	`764`	`+ }`
`760`	`765`	`else`
	`766`	`+ {`
`761`	`767`	`StopImmediate();`
	`768`	`+ }`
	`769`	`+`
`762`	`770`	`}`
`763`	`771`	`}`
`764`	`772`
Original file line number	Diff line number	Diff line change
`@@ -8,6 +8,7 @@ internal static class TaskAndFactoryExtensions`
`8`	`8`	`{`
`9`	`9`	`#region Task Extensions`
`10`	`10`
	`11`	`+ // TODO: Not used, is this used in Deploy or something?`
`11`	`12`	`static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completionSource, Task task)`
`12`	`13`	`{`
`13`	`14`	`if (task.IsFaulted)`
`@@ -16,6 +17,7 @@ static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completio`
`16`	`17`	`completionSource.SetResult(default(TResult));`
`17`	`18`	`}`
`18`	`19`
	`20`	`+ // TODO: Not used, is this used in Deploy or something?`
`19`	`21`	`static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completionSource, Task<TResult> task)`
`20`	`22`	`{`
`21`	`23`	`if (task.IsFaulted)`
`@@ -24,17 +26,33 @@ static void SetCompletionSource<TResult>(TaskCompletionSource<TResult> completio`
`24`	`26`	`completionSource.SetResult(task.Result);`
`25`	`27`	`}`
`26`	`28`
	`29`	`+ // TODO: Not used, is this used in Deploy or something?`
`27`	`30`	`public static Task ContinueWithTask(this Task task, Func<Task, Task> continuation)`
`28`	`31`	`{`
`29`	`32`	`var completionSource = new TaskCompletionSource<object>();`
`30`		`- task.ContinueWith(atask => continuation(atask).ContinueWith(atask2 => SetCompletionSource(completionSource, atask2)));`
	`33`	`+ task.ContinueWith(atask => continuation(atask).ContinueWith(`
	`34`	`+ atask2 => SetCompletionSource(completionSource, atask2),`
	`35`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`36`	`+ TaskScheduler.Default),`
	`37`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`38`	`+ TaskScheduler.Default);`
`31`	`39`	`return completionSource.Task;`
`32`	`40`	`}`
`33`	`41`
	`42`	`+ // TODO: Not used, is this used in Deploy or something?`
`34`	`43`	`public static Task ContinueWithTask(this Task task, Func<Task, Task> continuation, CancellationToken token)`
`35`	`44`	`{`
`36`	`45`	`var completionSource = new TaskCompletionSource<object>();`
`37`		`- task.ContinueWith(atask => continuation(atask).ContinueWith(atask2 => SetCompletionSource(completionSource, atask2), token), token);`
	`46`	`+ task.ContinueWith(atask => continuation(atask).ContinueWith(`
	`47`	`+ atask2 => SetCompletionSource(completionSource, atask2),`
	`48`	`+ token,`
	`49`	`+ TaskContinuationOptions.None,`
	`50`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`51`	`+ TaskScheduler.Default),`
	`52`	`+ token,`
	`53`	`+ TaskContinuationOptions.None,`
	`54`	`+ // Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html`
	`55`	`+ TaskScheduler.Default);`
`38`	`56`	`return completionSource.Task;`
`39`	`57`	`}`
`40`	`58`