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;
}
}
}
}
输出:
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
(即00000000-0000-0000-0000-000000000000
),内部代码行应该显示相同的Guid
值。
您可能会说LogicalOperationStack
使用的Stack
不是线程安全的,这就是输出错误的原因。但是,虽然这通常是正确的,但在这种情况下,不会有超过一个线程同时访问 LogicalOperationStack
(每个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
注意:我并不是建议任何人真的这样做。真正实用的解决方案是使用ImmutableStack
而不是LogicalOperationStack
,因为它是线程安全的,而且由于它在调用Pop
时是不可变的,所以您会得到一个新的ImmutableStack
,然后需要将其设置回CallContext
__中。一个完整的实现可以作为这个问题的答案:
那么,LogicalOperationStack
应该与async
一起工作,而它只是一个bug吗?是不是async
世界不适合使用LogicalOperationStack
?还是我错过了什么?
更新:使用Task.Delay
显然令人困惑,因为它使用的System.Threading.Timer
是captures the ExecutionContext
internally。使用await Task.Yield();
而不是await Task.Delay(100);
可以使示例更容易理解。
发布于 2015-05-09 02:36:08
是的,LogicalOperationStack
应该可以和async-await
一起工作,但是它不能。
我已经联系了微软的相关开发人员,他的回复是:
“我没有意识到这一点,但它确实看起来像是坏了的。写入时复制逻辑的行为应该与我们在进入方法时真正创建了
ExecutionContext
的副本一样。但是,复制ExecutionContext
将创建CorrelationManager
上下文的深层副本,因为它在CallContext.Clone()
中是特殊情况。我们在写入时复制逻辑中没有考虑到这一点。”
此外,他建议使用.Net 4.6中添加的新System.Threading.AsyncLocal
类,该类应该可以正确处理该问题。
因此,我继续使用VS2015 RC和.Net 4.6在AsyncLocal
而不是LogicalOperationStack
上实现了LogicalFlow
:
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
发布于 2018-10-24 15:20:08
这里和web上提到的解决方案之一是在上下文中调用LogicalSetData:
CallContext.LogicalSetData("one", null);
Trace.CorrelationManager.StartLogicalOperation();
但实际上,只要读取当前的执行上下文就足够了:
var context = Thread.CurrentThread.ExecutionContext;
Trace.CorrelationManager.StartLogicalOperation();
https://stackoverflow.com/questions/28769483
复制相似问题