65.9K
CodeProject 正在变化。 阅读更多。
Home

实时调试多线程代码！

Peter Huber SG
starIconstarIconstarIconstarIcon
emptyStarIcon
starIcon

4.97/5 (34投票s)

2014年7月3日

公共领域

6分钟阅读

viewsIcon

46296

downloadIcon

741

非阻塞、多线程安全追踪，仅有微秒延迟

引言

编写多线程应用程序比单线程程序要困难得多。更糟糕的是，需要实时调试才能找到这些 bug，这几乎是不可能的。但不要担心，这篇文章将解释如何轻松做到这一点！

挑战

我们都喜欢 Visual Studio，使用它的断点和单步执行代码来找出程序行为异常的原因。可惜的是，设置断点或单步执行会完全改变多线程应用程序的行为，因为在这种情况下，哪个线程以何种顺序执行哪个指令至关重要，精确到微秒甚至更短。在多线程系统中停止或延迟任何操作都会使其行为完全不同。

所以很明显，我们在调试时不能停止单个线程。这意味着我们应该使用追踪，看起来像这样

Console.WriteLine("Thread A requests someLock");
lock (someLock) {
  Console.WriteLine("Thread A got someLock");
  //do some work
  Console.WriteLine("Thread A releases someLock");
}
Console.WriteLine("Thread A released someLock");

在您猜测错误可能发生的地方执行此操作，您将在输出窗口中看到是哪个线程导致了它。唯一的问题是您不能使用 Console.WriteLine()，因为

  • 它太慢了，在我电脑上需要大约 500 微秒。追踪后的程序行为会与未追踪的程序有很大不同。
  • Console.WriteLine 会锁定线程，如果多个线程同时尝试写入，这是实时多线程调试中的大忌。

解决方案

不要使用控制台进行追踪，而是将您的追踪写入内存。一旦问题发生，在内存中检查发生了什么。写入内存时应尽可能减少开销，就像这样

public const int MaxMessages = 0x100;
string[] messages = new string[MaxMessages];
int messagesIndex = -1;

public void Trace(string message) {
  int thisIndex = Interlocked.Increment(ref messagesIndex);
  messages[thisIndex] = message;
}

基本上，Trace() 将消息写入一个 string 数组。请注意，Interlocked.Increment() 是多线程安全的且非阻塞的，这与 .NET Framework 中许多阻塞式的线程安全方法不同。这种最低限度的方法需要大约 2 微秒，这个延迟应该是可以接受的。毕竟，即使完全相同的代码执行两次，也会存在一些时间变化，取决于微处理器还在做什么，代码和数据是否在处理器缓存中，等等。

当然，上面的代码也有一个问题，当数组满了时我们会收到一个异常，我们可以像这样轻松地解决它

const int indexMask = MaxMessages-1;

public void Trace(string message) {
  int thisIndex = Interlocked.Increment(ref messagesIndex) & indexMask;
  messages[thisIndex] = message;
}

一旦达到 messages 数组的末尾，这将强制索引回到 0。缓冲区可以存储 0x100 条消息，即十进制的 256 条。如果您需要更多历史记录，请增加 MaxMessages。但要小心，0x1000000 % MaxMessages 必须等于 0。这意味着您可以使用 0x100、0x200、0x400、0x800、0x1000 等数字，但不能使用 0x300。

当 messagesIndex 达到 int.Max（0x7FFFFFFF 或 2,147,483,647）时会发生什么？基本上，整数会溢出到 int.Min（0x8000000 或 -2,147,483,648，但幸运的是不会抛出异常）。按位“And”运算符 & 会截断开头的 1，并且非常小的负数也会映射到 0 - 0x100 的范围内。

追踪更多信息

如果能知道是哪个线程在什么时候写入了消息，那就太好了。我们可以这样实现

static string[] threadNames = new string[MaxMessages];
static long[] ticks = new long[MaxMessages];
static Stopwatch stopWatch;

static RealTimeTracer() {
  stopWatch = new Stopwatch();
  stopWatch.Start();
}

public static void Trace(string message) {
  int thisIndex = Interlocked.Increment(ref messagesIndex) & indexMask;
  ticks[thisIndex] = stopWatch.ElapsedTicks;
  messages[thisIndex] = message;
  threadNames[thisIndex] = Thread.CurrentThread.Name;
}

这将增加 Trace() 所需的时间到大约 3 微秒。当然，您可以添加任何其他您想要的信息，但尽量减少创建新对象，因为内存管理可能会带来一些不必要的延迟。 

检索追踪信息

您需要编写一些代码来实时检测问题何时发生。届时，只需调用 RealTimeTracer.GetTrace()，它将所有消息以一个 string 的形式返回。GetTrace() 将在短时间内停止所有追踪，以返回一组一致的消息。您也可以在 Visual Studio 中设置一个断点，当错误发生时，在“快速监视”窗口中显示 RealTimeTracer.GetTrace()。最后，您可以使用 RealTimeTracer.IsStopped 属性来控制是否执行追踪。

另一种方法是让追踪运行一段时间，然后停止所有操作并检查追踪信息是否有错误。

对测量时间的解释

我通过以下方式测量了 Tracer 所需的时间

string[] testResults = new string[maxTestCycles];
string testString = "abcdefgh";
for (int testIndex = 0; testIndex < maxTestCycles; testIndex++) {
  Stopwatch stopWatch = new Stopwatch();
  stopWatch.Start();
  for (int i = 0; i < RealTimeTracer.MaxMessages/10; i++) {
    RealTimeTracer.Trace(testString);
  }
  stopWatch.Stop();
  Console.WriteLine("Test " + testIndex + ": " + 
                    stopWatch.Elapsed.TotalMilliseconds/RealTimeTracer.MaxMessages*1000 + 
                    " microseconds.");
}

当我运行最精简的 Tracer 版本时，我得到了以下测量结果

Test 0: 1.52734375 microseconds.
Test 1: 0.005859375 microseconds
Test 2: 0.00390625 microseconds.
Test 3: 0.00390625 microseconds.
Test 4: 0.00390625 microseconds.

为什么第一次测试花费的时间这么长？可能是因为 .NET 需要准备一些东西，但可以肯定的是，处理器在执行前需要将所有内容加载到缓存中。在下一个周期，所有东西都已经在缓存中了，因此执行速度更快。

您应该使用哪个时间？有人可能会争辩说加载缓存是正常的，这在现实中也是如此。然而，如果您试图让代码运行得更快并想比较不同版本，我建议只取最快的时间。原因在于结果是可重复的，也就是说，如果您重复测试，您将得到相同的数字。 

小心这样的建议

引用

作为一般规则，在测试极快的算法时，建议将循环运行 10,000 到 100,000 次，以提高测量精度。

这实际上不是真的！因为您让代码运行的时间越长，发生操作系统随机事件的可能性就越高。想象一下，如果在一次测试中，您突然运行了垃圾回收。那个时间与您的代码无关。因此，为了测量代码的执行时间，请保持时间短并消除所有缓慢的结果。如果您的测试运行 10 次，每次 100 微秒，但有一次需要 10 毫秒，那么问题不在于您的代码，而是有些不受您控制的东西让微处理器很忙。

多线程程序的测试方法

即使 RealTimeTracer 只有几行代码，也必须对其进行彻底测试。我建议首先顺序测试，只使用 1 个线程。一旦逻辑对于 1 个线程运行正常，然后使用多个线程运行另一个测试。

解决方案来自控制台项目 TestConsole. Program.Main() 可以运行 2 个测试

  1. testSingleThread() 使用 1 个线程将一个运行的数字写入追踪。然后测试验证每个数字是否正确且按顺序写入追踪。
  2. testMultiThread() 在多个线程上启动写入器，写入运行的数字。一段时间后，主线程停止写入器线程，并在追踪中验证每个线程是否按顺序写入了其数字，并且没有遗漏任何数字。 

我的 PC 有 8 个处理器核心，所以我使用 1 个主线程、6 个测试线程，并为操作系统保留 1 个核心。只是为了好玩，我也尝试了 100 个线程，但由于所有线程切换，测试运行得慢得多。 

Using the Code

RealTimeTracer 是我 TracerLib.dll 中的一个类。我将 RealTimeTracer 设置为 static，这样您就可以从代码的第一行开始追踪，而无需进行任何设置。

RealTimeTracer.Trace("Some Trace Message");

如果您需要更多历史记录，请更改常量 RealTimeTracer.MaxMessages。

调用 RealTimeTracer.GetTrace() 将追踪作为 string 返回。这在 Visual Studio 中查看追踪时非常方便。它确保在构建追踪时不会追踪新信息。

使用 RealTimeTracer.IsStopped，您可以控制是否进行追踪。

如果您对任何 .NET 技术的通用追踪感兴趣，请阅读我的文章

历史

  • 初始版本
© . All rights reserved.