LogicalOperationStack 与 .Net 4.5 中的异步不兼容吗

Trace.CorrelationManager.LogicalOperationStack允许具有嵌套逻辑操作标识符，其中最常见的情况是日志记录 (NDC)。它是否仍然可以使用async-await?

这是一个简单的例子，使用LogicalFlow这是我的简单包装LogicalOperationStack:

private static void Main() => OuterOperationAsync().GetAwaiter().GetResult();

private static async Task OuterOperationAsync()
{
    Console.WriteLine(LogicalFlow.CurrentOperationId);
    using (LogicalFlow.StartScope())
    {
        Console.WriteLine("\t" + LogicalFlow.CurrentOperationId);
        await InnerOperationAsync();
        Console.WriteLine("\t" + LogicalFlow.CurrentOperationId);
        await InnerOperationAsync();
        Console.WriteLine("\t" + LogicalFlow.CurrentOperationId);
    }
    Console.WriteLine(LogicalFlow.CurrentOperationId);
}

private static async Task InnerOperationAsync()
{
    using (LogicalFlow.StartScope())
    {
        await Task.Delay(100);
    }
}

LogicalFlow:

public static class LogicalFlow
{
    public static Guid CurrentOperationId =>
        Trace.CorrelationManager.LogicalOperationStack.Count > 0
            ? (Guid) Trace.CorrelationManager.LogicalOperationStack.Peek()
            : Guid.Empty;

    public static IDisposable StartScope()
    {
        Trace.CorrelationManager.StartLogicalOperation();
        return new Stopper();
    }

    private static void StopScope() => 
        Trace.CorrelationManager.StopLogicalOperation();

    private class Stopper : IDisposable
    {
        private bool _isDisposed;
        public void Dispose()
        {
            if (!_isDisposed)
            {
                StopScope();
                _isDisposed = true;
            }
        }
    }
}

Output:

00000000-0000-0000-0000-000000000000
    49985135-1e39-404c-834a-9f12026d9b65
    54674452-e1c5-4b1b-91ed-6bd6ea725b98
    c6ec00fd-bff8-4bde-bf70-e073b6714ae5
54674452-e1c5-4b1b-91ed-6bd6ea725b98

具体值并不重要，但据我了解，外线都应该显示Guid.Empty (i.e. 00000000-0000-0000-0000-000000000000）和内线应该显示相同Guid value.

你可能会说LogicalOperationStack正在使用Stack这不是线程安全的，这就是输出错误的原因。但虽然这在一般情况下是正确的，但在这种情况下永远不会有超过一个线程访问LogicalOperationStack同时 (every async调用时等待操作并且不使用组合器，例如Task.WhenAll)

问题是LogicalOperationStack存储在CallContext它具有写时复制行为。这意味着只要您没有在CallContext（当您使用以下命令添加到现有堆栈时，您不会这样做StartLogicalOperation）您正在使用父上下文而不是您自己的上下文。

这可以通过简单的设置来显示anything进入CallContext在添加到现有堆栈之前。例如如果我们改变了StartScope对此：

public static IDisposable StartScope()
{
    CallContext.LogicalSetData("Bar", "Arnon");
    Trace.CorrelationManager.StartLogicalOperation();
    return new Stopper();
}

输出是：

00000000-0000-0000-0000-000000000000
    fdc22318-53ef-4ae5-83ff-6c3e3864e37a
    fdc22318-53ef-4ae5-83ff-6c3e3864e37a
    fdc22318-53ef-4ae5-83ff-6c3e3864e37a
00000000-0000-0000-0000-000000000000

Note: 我并不是建议任何人真正这样做。真正实用的解决方案是使用ImmutableStack而不是LogicalOperationStack因为它既是线程安全的，又因为当你调用时它是不可变的Pop你会得到一个新的ImmutableStack然后你需要设置回CallContext。完整的实现可以作为这个问题的答案：跟踪 C#/.NET 任务流 https://stackoverflow.com/q/24468894/885318

所以，应该LogicalOperationStack与...一起工作async这只是一个错误？是LogicalOperationStack只是不适合async世界？或者我错过了什么？

Update: Using Task.Delay它使用时显然令人困惑System.Threading.Timer which 捕捉到ExecutionContext内部 http://referencesource.microsoft.com/#mscorlib/system/threading/timer.cs,544. Using await Task.Yield();代替await Task.Delay(100);使示例更容易理解。

Yes, LogicalOperationStack should与...一起工作async-await and it is一个错误，它没有。

我联系了微软的相关开发人员，他的回复是这样的：

"我没有意识到这一点，但它看起来确实坏了。写时复制逻辑的行为应该与我们真正创建的副本完全相同ExecutionContext进入该方法时。然而，复制ExecutionContext会创建一个深层副本CorrelationManager上下文，因为它的特殊情况CallContext.Clone()。我们在写时复制逻辑中没有考虑到这一点。”

此外，他建议使用新的System.Threading.AsyncLocal<T> https://msdn.microsoft.com/en-us/library/dn906268%28v=vs.110%29.aspx相反，.Net 4.6 中添加的类应该正确处理该问题。

所以，我继续实施LogicalFlow在一个顶部AsyncLocal而不是LogicalOperationStack使用VS2015 RC和.Net 4.6：

public static class LogicalFlow
{
    private static AsyncLocal<Stack> _asyncLogicalOperationStack = new AsyncLocal<Stack>();

    private static Stack AsyncLogicalOperationStack
    {
        get
        {
            if (_asyncLogicalOperationStack.Value == null)
            {
                _asyncLogicalOperationStack.Value = new Stack();
            }

            return _asyncLogicalOperationStack.Value;
        }
    }

    public static Guid CurrentOperationId =>
        AsyncLogicalOperationStack.Count > 0
            ? (Guid)AsyncLogicalOperationStack.Peek()
            : Guid.Empty;

    public static IDisposable StartScope()
    {
        AsyncLogicalOperationStack.Push(Guid.NewGuid());
        return new Stopper();
    }

    private static void StopScope() =>
        AsyncLogicalOperationStack.Pop();
}

相同测试的输出确实应该是这样：

00000000-0000-0000-0000-000000000000
    ae90c3e3-c801-4bc8-bc34-9bccfc2b692a
    ae90c3e3-c801-4bc8-bc34-9bccfc2b692a
    ae90c3e3-c801-4bc8-bc34-9bccfc2b692a
00000000-0000-0000-0000-000000000000