Fixes and Updates for DB Scope and Ambient Context leaks (#9953)

* Adds some scope tests (ported back from netcore) and provides a much better error message, ensure execution context is not flowed to child tasks that shouldn't leak any current ambient context

* updates comment

* Ensure SqlMainDomLock suppresses execution context too

* Since we're awaiting a task in a library method, ConfigureAwait(false)

* missing null check

Co-authored-by: Elitsa Marinovska <elm@umbraco.dk>
This commit is contained in:
Shannon Deminick
2021-03-15 22:56:38 +11:00
committed by GitHub
parent ef60a98fe1
commit d0f047e729
7 changed files with 207 additions and 52 deletions

View File

@@ -126,7 +126,7 @@ namespace Umbraco.Core.Runtime
}
return await WaitForExistingAsync(tempId, millisecondsTimeout);
return await WaitForExistingAsync(tempId, millisecondsTimeout).ConfigureAwait(false);
}
public Task ListenAsync()
@@ -139,13 +139,15 @@ namespace Umbraco.Core.Runtime
// 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,
// Must explicitly specify this, see https://blog.stephencleary.com/2013/10/continuewith-is-dangerous-too.html
TaskScheduler.Default);
using (ExecutionContext.SuppressFlow())
{
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);
}
}
/// <summary>
@@ -226,10 +228,10 @@ namespace Umbraco.Core.Runtime
}
}
finally
{
db?.CompleteTransaction();
db?.Dispose();
}
{
db?.CompleteTransaction();
db?.Dispose();
}
}
}
@@ -245,37 +247,40 @@ namespace Umbraco.Core.Runtime
{
var updatedTempId = tempId + UpdatedSuffix;
return Task.Run(() =>
using (ExecutionContext.SuppressFlow())
{
try
return Task.Run(() =>
{
using var db = _dbFactory.CreateDatabase();
var watch = new Stopwatch();
watch.Start();
while (true)
try
{
// poll very often, we need to take over as fast as we can
// local testing shows the actual query to be executed from client/server is approx 300ms but would change depending on environment/IO
Thread.Sleep(1000);
using var db = _dbFactory.CreateDatabase();
var acquired = TryAcquire(db, tempId, updatedTempId);
if (acquired.HasValue)
return acquired.Value;
if (watch.ElapsedMilliseconds >= millisecondsTimeout)
var watch = new Stopwatch();
watch.Start();
while (true)
{
return AcquireWhenMaxWaitTimeElapsed(db);
// poll very often, we need to take over as fast as we can
// local testing shows the actual query to be executed from client/server is approx 300ms but would change depending on environment/IO
Thread.Sleep(1000);
var acquired = TryAcquire(db, tempId, updatedTempId);
if (acquired.HasValue)
return acquired.Value;
if (watch.ElapsedMilliseconds >= millisecondsTimeout)
{
return AcquireWhenMaxWaitTimeElapsed(db);
}
}
}
}
catch (Exception ex)
{
_logger.Error<SqlMainDomLock>(ex, "An error occurred trying to acquire and waiting for existing SqlMainDomLock to shutdown");
return false;
}
catch (Exception ex)
{
_logger.Error<SqlMainDomLock>(ex, "An error occurred trying to acquire and waiting for existing SqlMainDomLock to shutdown");
return false;
}
}, _cancellationTokenSource.Token);
}, _cancellationTokenSource.Token);
}
}
private bool? TryAcquire(IUmbracoDatabase db, string tempId, string updatedTempId)

View File

@@ -345,6 +345,8 @@ namespace Umbraco.Core.Scoping
if (this != _scopeProvider.AmbientScope)
{
var failedMessage = $"The {nameof(Scope)} {this.InstanceId} being disposed is not the Ambient {nameof(Scope)} {(_scopeProvider.AmbientScope?.InstanceId.ToString() ?? "NULL")}. This typically indicates that a child {nameof(Scope)} was not disposed, or flowed to a child thread that was not awaited, or concurrent threads are accessing the same {nameof(Scope)} (Ambient context) which is not supported. If using Task.Run (or similar) as a fire and forget tasks or to run threads in parallel you must suppress execution context flow with ExecutionContext.SuppressFlow() and ExecutionContext.RestoreFlow().";
#if DEBUG_SCOPES
var ambient = _scopeProvider.AmbientScope;
_logger.Debug<Scope>("Dispose error (" + (ambient == null ? "no" : "other") + " ambient)");
@@ -356,7 +358,7 @@ namespace Umbraco.Core.Scoping
+ "- ambient ctor ->\r\n" + ambientInfos.CtorStack + "\r\n"
+ "- dispose ctor ->\r\n" + disposeInfos.CtorStack + "\r\n");
#else
throw new InvalidOperationException("Not the ambient scope.");
throw new InvalidOperationException(failedMessage);
#endif
}

View File

@@ -1,6 +1,7 @@
using System;
using System.Collections;
using System.Collections.Generic;
using System.ComponentModel;
using System.Data;
using System.Runtime.Remoting.Messaging;
using System.Web;
@@ -240,6 +241,9 @@ namespace Umbraco.Core.Scoping
var value = GetHttpContextObject<ScopeContext>(ContextItemKey, false);
return value ?? GetCallContextObject<ScopeContext>(ContextItemKey);
}
[Obsolete("This setter is not used and will be removed in future versions")]
[EditorBrowsable(EditorBrowsableState.Never)]
set
{
// clear both

View File

@@ -24,8 +24,8 @@ namespace Umbraco.Examine
// note
// wrapping all operations that end up calling base.SafelyProcessQueueItems in a safe call
// context because they will fork a thread/task/whatever which should *not* capture our
// call context (and the database it can contain)! ideally we should be able to override
// SafelyProcessQueueItems but that's not possible in the current version of Examine.
// call context (and the database it can contain)!
// TODO: FIX Examine to not flow the ExecutionContext so callers don't need to worry about this!
/// <summary>
/// Used to store the path of a content object
@@ -99,6 +99,9 @@ namespace Umbraco.Examine
{
if (CanInitialize())
{
// Use SafeCallContext to prevent the current CallContext flow to child
// tasks executed in the base class so we don't leak Scopes.
// TODO: See notes at the top of this class
using (new SafeCallContext())
{
base.PerformDeleteFromIndex(itemIds, onComplete);
@@ -106,6 +109,20 @@ namespace Umbraco.Examine
}
}
protected override void PerformIndexItems(IEnumerable<ValueSet> values, Action<IndexOperationEventArgs> onComplete)
{
if (CanInitialize())
{
// Use SafeCallContext to prevent the current CallContext flow to child
// tasks executed in the base class so we don't leak Scopes.
// TODO: See notes at the top of this class
using (new SafeCallContext())
{
base.PerformIndexItems(values, onComplete);
}
}
}
/// <summary>
/// Returns true if the Umbraco application is in a state that we can initialize the examine indexes
/// </summary>

View File

@@ -2,6 +2,7 @@
using System.Collections;
using System.Runtime.Remoting.Messaging;
using System.Threading;
using System.Threading.Tasks;
using NUnit.Framework;
using Umbraco.Core;
using Umbraco.Core.Persistence;
@@ -24,6 +25,119 @@ namespace Umbraco.Tests.Scoping
Assert.IsNull(ScopeProvider.AmbientScope); // gone
}
[Test]
public void GivenUncompletedScopeOnChildThread_WhenTheParentCompletes_TheTransactionIsRolledBack()
{
ScopeProvider scopeProvider = ScopeProvider;
Assert.IsNull(ScopeProvider.AmbientScope);
IScope mainScope = scopeProvider.CreateScope();
var t = Task.Run(() =>
{
IScope nested = scopeProvider.CreateScope();
Thread.Sleep(2000);
nested.Dispose();
});
Thread.Sleep(1000); // mimic some long running operation that is shorter than the other thread
mainScope.Complete();
Assert.Throws<InvalidOperationException>(() => mainScope.Dispose());
Task.WaitAll(t);
}
[Test]
public void GivenNonDisposedChildScope_WhenTheParentDisposes_ThenInvalidOperationExceptionThrows()
{
// this all runs in the same execution context so the AmbientScope reference isn't a copy
ScopeProvider scopeProvider = ScopeProvider;
Assert.IsNull(ScopeProvider.AmbientScope);
IScope mainScope = scopeProvider.CreateScope();
IScope nested = scopeProvider.CreateScope(); // not disposing
InvalidOperationException ex = Assert.Throws<InvalidOperationException>(() => mainScope.Dispose());
Console.WriteLine(ex);
}
[Test]
public void GivenChildThread_WhenParentDisposedBeforeChild_ParentScopeThrows()
{
// The ambient context is NOT thread safe, even though it has locks, etc...
// This all just goes to show that concurrent threads with scopes is a no-go.
var childWait = new ManualResetEventSlim(false);
var parentWait = new ManualResetEventSlim(false);
ScopeProvider scopeProvider = ScopeProvider;
Assert.IsNull(ScopeProvider.AmbientScope);
IScope mainScope = scopeProvider.CreateScope();
var t = Task.Run(() =>
{
Console.WriteLine("Child Task start: " + scopeProvider.AmbientScope.InstanceId);
// This will evict the parent from the ScopeProvider.StaticCallContextObjects
// and replace it with the child
IScope nested = scopeProvider.CreateScope();
childWait.Set();
Console.WriteLine("Child Task scope created: " + scopeProvider.AmbientScope.InstanceId);
parentWait.Wait(); // wait for the parent thread
Console.WriteLine("Child Task before dispose: " + scopeProvider.AmbientScope.InstanceId);
// This will evict the child from the ScopeProvider.StaticCallContextObjects
// and replace it with the parent
nested.Dispose();
Console.WriteLine("Child Task after dispose: " + scopeProvider.AmbientScope.InstanceId);
});
childWait.Wait(); // wait for the child to start and create the scope
// This is a confusing thing (this is not the case in netcore), this is NULL because the
// parent thread's scope ID was evicted from the ScopeProvider.StaticCallContextObjects
// so now the ambient context is null because the GUID in the CallContext doesn't match
// the GUID in the ScopeProvider.StaticCallContextObjects.
Assert.IsNull(scopeProvider.AmbientScope);
// now dispose the main without waiting for the child thread to join
// This will throw because at this stage a child scope has been created which means
// it is the Ambient (top) scope but here we're trying to dispose the non top scope.
Assert.Throws<InvalidOperationException>(() => mainScope.Dispose());
parentWait.Set(); // tell child thread to proceed
Task.WaitAll(t); // wait for the child to dispose
mainScope.Dispose(); // now it's ok
Console.WriteLine("Parent Task disposed: " + scopeProvider.AmbientScope?.InstanceId);
}
[Test]
public void GivenChildThread_WhenChildDisposedBeforeParent_OK()
{
ScopeProvider scopeProvider = ScopeProvider;
Assert.IsNull(ScopeProvider.AmbientScope);
IScope mainScope = scopeProvider.CreateScope();
// Task.Run will flow the execution context unless ExecutionContext.SuppressFlow() is explicitly called.
// This is what occurs in normal async behavior since it is expected to await (and join) the main thread,
// but if Task.Run is used as a fire and forget thread without being done correctly then the Scope will
// flow to that thread.
var t = Task.Run(() =>
{
Console.WriteLine("Child Task start: " + scopeProvider.AmbientScope.InstanceId);
IScope nested = scopeProvider.CreateScope();
Console.WriteLine("Child Task before dispose: " + scopeProvider.AmbientScope.InstanceId);
nested.Dispose();
Console.WriteLine("Child Task after disposed: " + scopeProvider.AmbientScope.InstanceId);
});
Console.WriteLine("Parent Task waiting: " + scopeProvider.AmbientScope?.InstanceId);
Task.WaitAll(t);
Console.WriteLine("Parent Task disposing: " + scopeProvider.AmbientScope.InstanceId);
mainScope.Dispose();
Console.WriteLine("Parent Task disposed: " + scopeProvider.AmbientScope?.InstanceId);
Assert.Pass();
}
[Test]
public void SimpleCreateScope()
{

View File

@@ -104,7 +104,7 @@ namespace Umbraco.Tests.Services
var threads = new List<Thread>();
var exceptions = new List<Exception>();
Debug.WriteLine("Starting...");
Console.WriteLine("Starting...");
var done = TraceLocks();
@@ -114,12 +114,12 @@ namespace Umbraco.Tests.Services
{
try
{
Debug.WriteLine("[{0}] Running...", Thread.CurrentThread.ManagedThreadId);
Console.WriteLine("[{0}] Running...", Thread.CurrentThread.ManagedThreadId);
var name1 = "test-" + Guid.NewGuid();
var content1 = contentService.Create(name1, -1, "umbTextpage");
Debug.WriteLine("[{0}] Saving content #1.", Thread.CurrentThread.ManagedThreadId);
Console.WriteLine("[{0}] Saving content #1.", Thread.CurrentThread.ManagedThreadId);
Save(contentService, content1);
Thread.Sleep(100); //quick pause for maximum overlap!
@@ -127,7 +127,7 @@ namespace Umbraco.Tests.Services
var name2 = "test-" + Guid.NewGuid();
var content2 = contentService.Create(name2, -1, "umbTextpage");
Debug.WriteLine("[{0}] Saving content #2.", Thread.CurrentThread.ManagedThreadId);
Console.WriteLine("[{0}] Saving content #2.", Thread.CurrentThread.ManagedThreadId);
Save(contentService, content2);
}
catch (Exception e)
@@ -139,16 +139,16 @@ namespace Umbraco.Tests.Services
}
// start all threads
Debug.WriteLine("Starting threads");
Console.WriteLine("Starting threads");
threads.ForEach(x => x.Start());
// wait for all to complete
Debug.WriteLine("Joining threads");
Console.WriteLine("Joining threads");
threads.ForEach(x => x.Join());
done.Set();
Debug.WriteLine("Checking exceptions");
Console.WriteLine("Checking exceptions");
if (exceptions.Count == 0)
{
//now look up all items, there should be 40!
@@ -172,7 +172,7 @@ namespace Umbraco.Tests.Services
var threads = new List<Thread>();
var exceptions = new List<Exception>();
Debug.WriteLine("Starting...");
Console.WriteLine("Starting...");
var done = TraceLocks();
@@ -182,18 +182,18 @@ namespace Umbraco.Tests.Services
{
try
{
Debug.WriteLine("[{0}] Running...", Thread.CurrentThread.ManagedThreadId);
Console.WriteLine("[{0}] Running...", Thread.CurrentThread.ManagedThreadId);
var name1 = "test-" + Guid.NewGuid();
var media1 = mediaService.CreateMedia(name1, -1, Constants.Conventions.MediaTypes.Folder);
Debug.WriteLine("[{0}] Saving media #1.", Thread.CurrentThread.ManagedThreadId);
Console.WriteLine("[{0}] Saving media #1.", Thread.CurrentThread.ManagedThreadId);
Save(mediaService, media1);
Thread.Sleep(100); //quick pause for maximum overlap!
var name2 = "test-" + Guid.NewGuid();
var media2 = mediaService.CreateMedia(name2, -1, Constants.Conventions.MediaTypes.Folder);
Debug.WriteLine("[{0}] Saving media #2.", Thread.CurrentThread.ManagedThreadId);
Console.WriteLine("[{0}] Saving media #2.", Thread.CurrentThread.ManagedThreadId);
Save(mediaService, media2);
}
catch (Exception e)

View File

@@ -319,7 +319,10 @@ namespace Umbraco.Web.Scheduling
// create a new token source since this is a new process
_shutdownTokenSource = new CancellationTokenSource();
_shutdownToken = _shutdownTokenSource.Token;
_runningTask = Task.Run(async () => await Pump().ConfigureAwait(false), _shutdownToken);
using (ExecutionContext.SuppressFlow())
{
_runningTask = Task.Run(async () => await Pump().ConfigureAwait(false), _shutdownToken);
}
_logger.Debug<BackgroundTaskRunner>("{LogPrefix} Starting", _logPrefix);
}
@@ -544,10 +547,14 @@ namespace Umbraco.Web.Scheduling
try
{
if (bgTask.IsAsync)
{
// configure await = false since we don't care about the context, we're on a background thread.
await bgTask.RunAsync(token).ConfigureAwait(false);
}
else
{
bgTask.Run();
}
}
finally // ensure we disposed - unless latched again ie wants to re-run
{
@@ -710,14 +717,20 @@ namespace Umbraco.Web.Scheduling
// with a single aspnet thread during shutdown and we don't want to delay other calls to IRegisteredObject.Stop.
if (!immediate)
{
return Task.Run(StopInitial, CancellationToken.None);
using (ExecutionContext.SuppressFlow())
{
return Task.Run(StopInitial, CancellationToken.None);
}
}
else
{
lock (_locker)
{
if (_terminated) return Task.CompletedTask;
return Task.Run(StopImmediate, CancellationToken.None);
using (ExecutionContext.SuppressFlow())
{
return Task.Run(StopImmediate, CancellationToken.None);
}
}
}
}