惊人的 3,200% CPU 利用率问题排查

3,200% CPU Utilization

Source | HN Comments

文章讲述了作者遇到的一个因多线程并发访问未加锁的 `TreeMap` 导致的 CPU 3200% 利用率的严重问题。通过线程转储和代码分析，作者发现 `TreeMap` 内部的红黑树结构在并发修改下可能形成循环，导致无限循环和高 CPU 占用。作者通过实验验证了该问题，并发现 C++ 和 Go 语言也存在类似问题。文章最后提出了使用 `Collections.synchronizedMap` 或 `ConcurrentHashMap` 的简单修复方案，以及一种有争议的、通过跟踪访问节点来检测循环的修复方案。

Joseph Mate

3,200% CPU Utilization

发布于 2025 年 2 月 26 日

不久前，我的机器出了大问题，几乎无法通过 SSH 连接上去。CPU 利用率高达 3,200% —— 主机上的所有 32 个核心都被完全占用！与我上次只占用 1 个核心，100% 利用率的 bug 相比

幸运的是，它使用的是 Java 17 运行时，可以生成包含 CPU 时间的线程转储！按 CPU 时间排序后，我找到了一堆看起来与以下类似的线程：

"Thread-0" #22 [14700] prio=5 os_prio=0 cpu=10359.38ms elapsed=11.49s tid=0x000001cdc35aaf60 nid=14700 runnable [0x00000047cfffe000]
  java.lang.Thread.State: RUNNABLE
	at java.util.TreeMap.put(java.base@17.0.1/TreeMap.java:826)
	at java.util.TreeMap.put(java.base@17.0.1/TreeMap.java:534)
	at BusinessLogic.someFunction(BusinessLogic.java:29)
  ...

我对此做出了快速判断，并根据堆栈跟踪查看了 BusinessLogic:29，它看起来像这样：

public void someFunction(SomeType relatedObject, List<SomeOtherType> unrelatedObjects) {
 ...
 for (SomeOtherType unrelatedObject : unrelatedObjects) {
  treeMap.put(relatedObject.a(), relatedObject.b()); // line 29
 }
 ...
}

这段代码很奇怪。注意，我们正在迭代 unrelatedObject，但循环体只使用了 relatedObject。这段代码可以简化为：

public void someFunction(SomeType relatedObject, List<SomeOtherType> unrelatedObjects) {
 ...
 treeMap.put(relatedObject.a(), relatedObject.b());
 ...
 // unrelatedObjects 在函数的后面部分被使用，所以不能移除这个参数
}

这里肯定进行了一些重构，unrelatedObject 不再被使用了。我准备了单元测试，并在修复前后运行了测试。我尝试了具有 1,000,000 个条目的 treeMap 和 unrelatedObjects，远远超过了应用程序实际遇到的情况，但无法重现这个问题。假设 unrelatedObjects 的大小为 N，treeMap 的大小为 M，则复杂度为 O(N lg(M))。所以无法重现这个问题也是有道理的。直到达到 1 亿到 10 亿个条目，你才会真正看到一分钟的执行时间。

一定是其他原因。我确信 treeMap 和 unrelatedObjects 永远不会超过 1,000 个条目。甚至还远不足以导致 O(N lg(M)) 算法出现问题。

我对这个类不是很熟悉，所以我开始四处查看，专注于 treeMap 和 unrelatedObjects，以确认我关于它们永远不会超过 1,000 个条目的假设是否成立。它们有可能达到数百万甚至数十亿吗？

然后我注意到了 TreeMap 的定义：

// 实际上这个字段并不是命名为 treeMap。
private final Map<K,V> treeMap = new TreeMap<>();

这太可怕了。有多个线程访问 TreeMap，而且没有进行任何保护。在这一点上，我灵光一现。一个没有保护的 TreeMap 会导致 3,200% 的利用率吗？

实验

我设计了一个简单的实验来尝试重现这个问题。我创建了一堆线程，随机更新一个共享的 TreeMap。

for (int i = 0; i < numThreads; i++) {
  threads.add(new Thread(() -> {
    Random random = new Random();
    for(int j = 0; j < numUpdates; j++) {
      try {
        treeMap.put(random.nextInt(1000), random.nextInt(1000));
      } catch (NullPointerException e) {
        // 让它继续运行，以便我们可以重现这个问题。
      }
    }
  }));
}

这个 try catch 非常关键。如果没有 try catch，我无法重现这个问题。一些线程会崩溃并输出以下内容：

Exception in thread "Thread-0" java.lang.NullPointerException: Cannot read field "right" because "l" is null
    at java.base/java.util.TreeMap.rotateRight(TreeMap.java:2562)
    at java.base/java.util.TreeMap.fixAfterInsertion(TreeMap.java:2594)
    at java.base/java.util.TreeMap.addEntry(TreeMap.java:770)
    at java.base/java.util.TreeMap.put(TreeMap.java:828)
    at java.base/java.util.TreeMap.put(TreeMap.java:534)
    at SimpleRepro.lambda$main$0(SimpleRepro.java:28)
    at java.base/java.lang.Thread.run(Thread.java:833)

但程序仍然会停止。

可能只有允许你捕获 NPE 的语言才会遇到这个问题。其他语言只会崩溃。运行几次后，我看到了 500% 的 CPU 利用率。太疯狂了！我一直认为竞态条件会导致数据损坏或死锁。我从未想过它会导致性能问题。但这是有道理的，你可能会以某种方式破坏数据，从而创建一个无限循环。

你可以在我的 GitHub 项目 java-by-experiments 仓库中查看这个 Java 实验：SimpleRepro.java

为了更加确定，我创建了另一个实验，使用反射来转储 TreeMap 的节点及其颜色。（在 Java 中，TreeMap 使用红黑树实现。）TreeMap 中的循环以蓝色突出显示。 TreeMap 实验生成的循环示例

所以，如果你正在搜索或放入一些尚未在映射中的内容，它可能会陷入那个无限循环中。

要重现上面的图表，你需要使用反射来访问 TreeMap.Entry 的根、左侧和右侧字段。你从根开始递归遍历 TreeMap.Entry，记录你访问过的 Entry。如果你访问了一个已经访问过的条目，你就知道你遇到了一个循环。打印所有来自已访问节点的节点来显示这个循环。

private final TreeMap<Integer,Integer> treeMap;
private static final Field treeMapRootField;
private static final Field treeMapEntryLeft;
private static final Field treeMapEntryRight;
private static final Field treeMapEntryKey;
private static final Field treeMapEntryColor;
...
public void print() throws Exception {
  print(treeMapRootField.get(treeMap), "", new IdentityHashMap<>());
}
private void print(
  Object treeMapEntry, String tabs, IdentityHashMap<Object, Object> visited
) throws Exception {
  if (treeMapEntry != null && !visited.containsKey(treeMapEntry)) {
    // in order traversal
    visited.put(treeMapEntry, treeMapEntry);
    print(treeMapEntryLeft.get(treeMapEntry), tabs + " ", visited);
    System.out.println(tabs + treeMapEntryKey.get(treeMapEntry) + ":"
      + (treeMapEntryColor.getBoolean(treeMapEntry) ? "BLACK" : "RED"));
    print(treeMapEntryRight.get(treeMapEntry), tabs + " ", visited);
  } else if (treeMapEntry != null && visited.containsKey(treeMapEntry)) {
    System.out.println(tabs + treeMapEntryKey.get(treeMapEntry) + ":"
      + (treeMapEntryColor.getBoolean(treeMapEntry) ? "BLACK" : "RED")
      + " CYCLE"
    );
  }
}

可以在我的 java-by-experiments GitHub 项目中找到可运行的代码：ExploringTreeMap.java 和 TreeMapExplorer.java

这段代码不切实际

有些人可能会声称我的实验代码不切实际。谁会忽略 NPE？有两种实际的方法：Executor 中的未捕获异常和由线程池支持的服务。

`Executor` 中的未捕获异常

我们可以结合另一个常见的错误（它会抑制未捕获的异常）来重现这个问题。

以下代码也可以重现这个问题，但使用了线程池。

final ExecutorService pool = Executors.newFixedThreadPool(numThreads);
final TreeMap<Integer,Integer> treeMap = new TreeMap<>();
Random random = new Random();
for (int i = 0; i < numThreads*numUpdatesPerThread; i++) {
  pool.submit( () -> {
    treeMap.put(random.nextInt(10000), random.nextInt(10000));
  });
}
pool.shutdown();
pool.awaitTermination(1, TimeUnit.DAYS);

来自 ExecutorUncaughtRepro.java 的代码片段。

当你运行它时，你会看到它挂起。进行线程转储，你会看到相同的症状：

"pool-1-thread-1" #22 [15356] prio=5 os_prio=0 cpu=17734.38ms elapsed=21.39s tid=0x0000023c45dd3e90 nid=15356 runnable [0x000000780b4fe000]
  java.lang.Thread.State: RUNNABLE
	at java.util.TreeMap.put(java.base@19.0.1/TreeMap.java:826)
	at java.util.TreeMap.put(java.base@19.0.1/TreeMap.java:534)
	at ExecutorUncaughtRepro.lambda$main$0(ExecutorUncaughtRepro.java:33)
	at ExecutorUncaughtRepro$$Lambda$14/0x00000008010031f0.run(Unknown Source)
	at java.util.concurrent.Executors$RunnableAdapter.call(java.base@19.0.1/Executors.java:577)
	at java.util.concurrent.FutureTask.run(java.base@19.0.1/FutureTask.java:317)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@19.0.1/ThreadPoolExecutor.java:1144)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@19.0.1/ThreadPoolExecutor.java:642)
	at java.lang.Thread.run(java.base@19.0.1/Thread.java:1589)

它卡在 TreeMap 上，并且 CPU 利用率非常高。

然而，在标准输出中没有任何东西！线程池吞噬了所有 NPE，没有给出任何问题指示。不幸的是，这就是我的情况。

当你管理自己的线程池时，你需要确保：

通过线程工厂在线程上注册一个未捕获的异常处理程序
操作它返回的 future。如果你执行 future.get()，你将会得到一个包装了 NPE 的 ExectionException!

再次使用 gRPC

另一种方法是拥有某种由线程池支持的服务，比如一个 gRPC 服务。在这里，我用 gRPC 重现了一个现实的场景，它可以重现这个问题。该服务由一个没有保护的 TreeMap 提供支持。

@Override
public void addReceipt(
  ReceiptProcessorServiceOuterClass.AddReceiptRequest req,
  StreamObserver<ReceiptProcessorServiceOuterClass.AddReceiptResponse> responseObserver
) {
  int timestamp = req.getTimestamp();
  int totalPrice = req.getTotalPrice();
  receipts.put(timestamp, totalPrice);
  ReceiptProcessorServiceOuterClass.AddReceiptResponse response = ReceiptProcessorServiceOuterClass.AddReceiptResponse.newBuilder().build();
  responseObserver.onNext(response);
  responseObserver.onCompleted();
}

来自 GrpcRepro.java 的代码片段。

转储线程会给我们：

"grpc-default-executor-23" #54 [8796] daemon prio=5 os_prio=0 cpu=18671.88ms elapsed=175.50s tid=0x00000168b6c707c0 nid=8796 runnable [0x000000059fbfe000]
  java.lang.Thread.State: RUNNABLE
	at java.util.TreeMap.put(java.base@19.0.1/TreeMap.java:826)
	at java.util.TreeMap.put(java.base@19.0.1/TreeMap.java:534)
	at ReceiptProcessorServiceImpl.addReceipt(GrpcRepro.java:59)
	at ReceiptProcessorServiceGrpc$MethodHandlers.invoke(ReceiptProcessorServiceGrpc.java:185)
	at io.grpc.stub.ServerCalls$UnaryServerCallHandler$UnaryServerCallListener.onHalfClose(ServerCalls.java:182)
	at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:346)
	at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:860)
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@19.0.1/ThreadPoolExecutor.java:1144)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@19.0.1/ThreadPoolExecutor.java:642)
	at java.lang.Thread.run(java.base@19.0.1/Thread.java:1589)

表明 TreeMap.put() 卡在了一个无限循环中。

它是如何发生的？旋转

我怀疑两个线程独立地沿相反的方向旋转树，从而导致循环。或者，也许两个重叠的旋转以产生循环的方式交错写入。但是，我没有线程间交错以证明这一点的证据。

我还怀疑 NPE 是必要的。如果没有遇到 NPE，这个问题就无法重现，就像我在 Java 实验中看到的那样。

其他语言

我通过尝试在之前编程过的尽可能多的语言中重现这个问题来探索只有具有 NPE 的语言才能表现出这个想法。如果这个说法是真的，我希望它只会在 Java、Kotlin、C#、Ruby、Typescript 和 Python 中重现。我希望无法在 Go、C++、Rust 和 Elixir 中重现这个问题。

| 语言 | 受影响 | 解释 | 代码链接 | | -------- | ---- | --------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | Java | 是 | 这篇文章就是基于这个 | source | | C# | 是 | SortedDictionary 使用红黑树 | source | | Ruby | 否 | 使用了来自 kanwei/algorithms 的红黑树，但无法重现这个问题。我认为由于全局解释器锁 (GIL) 及其限制线程何时可以上下文切换，从而阻止导致无限循环的线程交错，所以可能无法重现该问题。 | source | | C++ | 是 | 使用红黑树。我预计它总是首先出现段错误，从而阻止它遇到这个问题。 | source | | Go | 是 | 有流行的数据结构库。与 C++ 类似，我预计它只会出现段错误，而不会重现无限循环。我错了。 | source | | Rust | 否 | 编译器阻止了我。我不了解足够的关于编写不安全代码的知识来重现这个问题 | source | | Kotlin | 是 | 使用 Java 的 TreeMap，预期相同的问题 | | | PHP | 否 | 不在标准库中，也没有找到任何使用红黑树的流行库 | | | JavaScript | 否 | 多线程模型无法共享引用 | | | Typescript | 否 | 与 JavaScript 相同的论点 | | | Python | 否 | 标准库中没有红黑树，像 Sorted Containers 这样的流行库也没有使用红黑树。尽管没有红黑树，如果我运行了实验，我希望由于与 Ruby 相同的原因而无法重现：GIL。 | | | Elixir | 否 | 尽管在 Elixir（和 Erlang）中红黑树有许多第三方实现，但编程模型使其不可能：数据结构是不可变的，线程之间的交互仅限于消息传递。 | |

从这张表中，最有趣的是 C++，因为我由于上一节中的假设而没有期望能够重现这个问题。因此，我在这里包含了实验的细节。同样，Go 出乎意料，但为了精简文章，我省略了它。你可以在这里看到 Go。

这段代码本质上与 Java 的代码相同，只是使用了 C++ 标准库。我还添加了额外的打印，因为我很震惊这个问题能够重现，我只是想更加确定。

// C++ 中 TreeMap 的等价物是 std::map
// 使用相同的红黑树数据结构
std::map<int, int> sortedMap;
for (int i = 0; i < numThreads; i++) {
  threads.emplace_back([&]() {
    // 复制，这样我们就不会使用 i (5) 的最新值
    int threadId = threadIdGenerator.fetch_add(1);
    std::random_device rd;
    std::mt19937 gen(rd());
    std::uniform_int_distribution<> dis(0, 999);
          
    int progressThreshold = numUpdates / progressRatio;
    std::cout << "Thread " << threadId << " started.";
    for (int j = 0; j < numUpdates; j++) {
      try {
        int key = dis(gen);
        int value = dis(gen);
        sortedMap[key] = value;
      } catch (const std::exception& e) {
        std::cerr << "Caught exception on thread " << threadId << ":" << e.what() << std::endl;
      }
      if ((j + 1) % progressThreshold == 0) {
          std::cout << "Thread " << threadId << ": " 
              << ((j + 1) * 100 / numUpdates) << "% complete (" 
              << (j + 1) << "/" << numUpdates << " updates)\n";
      }
    }
    std::cout << "Thread " << threadId << " completed.";
  });
}

偶尔，程序会像以前一样出现段错误并崩溃。这就是我期望的最坏情况。

./SimpleRepro
zsh: segmentation fault ./SimpleRepro

然而，很少情况下，输出会像下面这样，表明线程卡住了。等待 10 分钟后，线程从未完成。我没有预料到会发生这种情况，因为我认为这需要一个抛出并吞噬的异常。这里没有发生这种情况。

./SimpleRepro
Thread 0 started.Thread Thread 0: 10% complete (Thread 10/10012Thread started.3
started.Thread 4 started.Thread 4: 10% complete (10/100 updates)
 updates)
Thread 0: 20% complete (20/100 updates)
Thread 0: 30% complete (30/100 updates)
Thread 0: 40% complete (40/100 updates)
Thread 1: 10% complete (10/100 updates)
 started.Thread 2: 10% complete (10/100 updates)
Thread 1: 20% complete (20/100 updates)
<5 分钟没有输出>

从工具 top 中我们可以看到，由于 CPU 利用率很高，所以问题重现了。

top
PID  COMMAND   %CPU TIME   ...
59815 SimpleRepro 170.8 08:49.61 ...

这表明我的说法是错误的。我能够在 Go 和 C++ 中重现这个问题。尽管它们有时会出现段错误，但有时它们会陷入无限循环。在像 C++ 这样的语言中，当你引用空指针时，它总是会出现段错误，因此肯定存在一个线程交错，它不会遇到空指针！我不知道为什么。我预计它们会崩溃，因为我经常在 Java 实验中看到 NPE。

有了这些知识，我回到了我的 SimpeRepro java 实验，并没有再捕获 NPE。重新运行 12 次后，我仍然能够重现这个问题，尽管没有捕获 NPE：

"Thread-4" #17 prio=5 os_prio=31 cpu=18597.02ms elapsed=23.79s tid=0x00007f81051ac200 nid=0x6a03 runnable [0x000070000bcb5000]
  java.lang.Thread.State: RUNNABLE
    at java.util.TreeMap.put(java.base@17.0.3/TreeMap.java:826)
    at java.util.TreeMap.put(java.base@17.0.3/TreeMap.java:534)
    at SimpleRepro.lambda$main$0(SimpleRepro.java:28)
    at SimpleRepro$$Lambda$1/0x0000000800c00a08.run(Unknown Source)
    at java.lang.Thread.run(java.base@17.0.3/Thread.java:833)

另一件让我惊讶的事情是，像 Ruby 这样的语言，尽管允许你捕获 NPE，但并没有让你重现这个问题。全局解释器锁 (GIL) 以某种方式阻止了所有会重现这个问题的执行交错。

简单的修复：防止并发修改

解决这个问题最简单的方法是用 Collections.synchronizedMap 包装 TreeMap，或者切换到 ConcurrentHashMap 并按需排序。然而，这些修复很无聊，并没有阻止我们犯这个错误并关闭我们的主机。

有争议的修复：跟踪访问过的节点

如果可以安全地犯这个错误，但不会产生循环呢？

我修改了红黑树来记录它已经访问过的节点。这只需要额外的 O(lg(n)) 内存，因为它受到树的高度限制。红黑树的高度保证为 O(lg(n))。如果我们遇到一个已经访问过的节点，我们将抛出一个 ConcurrentModificationException。这不会阻止数据损坏，但如果将来有人再次犯这个错误，它将阻止来自无限循环的 100% CPU 利用率。但这需要标准库采用这种技术，我不认为这种情况会发生，因为需要额外的内存。

diff --git a/tree_map_corruption/java/src/main/java/ProtectedTreeMap.java b/tree_map_corruption/java/src/main/java/ProtectedTreeMap.java
index 53c15bb..2713d5a 100644
--- a/tree_map_corruption/java/src/main/java/ProtectedTreeMap.java
+++ b/tree_map_corruption/java/src/main/java/ProtectedTreeMap.java
@@ -345,7 +345,9 @@ public class ProtectedTreeMap<K,V>
     @SuppressWarnings("unchecked")
       Comparable<? super K> k = (Comparable<? super K>) key;
     Entry<K,V> p = root;
+    IdentityHashMap<Entry<?,?>, Boolean> visited = new IdentityHashMap<>();
     while (p != null) {
+      visited.put(p, true);
       int cmp = k.compareTo(p.key);
       if (cmp < 0)
         p = p.left;
@@ -353,6 +355,10 @@ public class ProtectedTreeMap<K,V>
         p = p.right;
       else
         return p;
+
+      if (visited.containsKey(p)) {
+        throw new ConcurrentModificationException("TreeMap corrupted. Loop detected");
+      }
     }
     return null;
   }
@@ -779,6 +785,7 @@ public class ProtectedTreeMap<K,V>
   }
 
   private V put(K key, V value, boolean replaceOld) {
+    IdentityHashMap<Entry<?,?>, Boolean> visited = new IdentityHashMap<>();
     Entry<K,V> t = root;
     if (t == null) {
       addEntryToEmptyMap(key, value);
@@ -790,6 +797,7 @@ public class ProtectedTreeMap<K,V>
     Comparator<? super K> cpr = comparator;
     if (cpr != null) {
       do {
+        visited.put(t, true);
         parent = t;
         cmp = cpr.compare(key, t.key);
         if (cmp < 0)
@@ -803,12 +811,17 @@ public class ProtectedTreeMap<K,V>
           }
           return oldValue;
         }
+
+        if (visited.containsKey(t)) {
+          throw new ConcurrentModificationException("TreeMap corrupted. Loop detected");
+        }
       } while (t != null);
     } else {
       Objects.requireNonNull(key);
       @SuppressWarnings("unchecked")
       Comparable<? super K> k = (Comparable<? super K>) key;
       do {
+                                visited.put(t, true);
         parent = t;
         cmp = k.compareTo(t.key);
         if (cmp < 0)
@@ -822,6 +835,10 @@ public class ProtectedTreeMap<K,V>
           }
           return oldValue;
         }
+
+        if (visited.containsKey(t)) {
+          throw new ConcurrentModificationException("TreeMap corrupted. Loop detected");
+        }
       } while (t != null);
     }
     addEntry(key, value, parent, cmp < 0);

来自我的 [ProtectedTreeMap.java](https://josephmate.github.io/2025-02-26-3200p-cpu-util/<https:/github.com/josephmate/java-by-experiments/blob/main/tree_map_corrupti

惊人的 3,200% CPU 利用率问题排查

3,200% CPU Utilization

实验

相关工作

这段代码不切实际

Executor 中的未捕获异常

再次使用 gRPC

它是如何发生的？旋转

其他语言

简单的修复：防止并发修改

有争议的修复：跟踪访问过的节点

`Executor` 中的未捕获异常