java - 使用 GC 中报告的实时时间验证单个内核上的 cpu 争用？

Question

我有一台配备 ARMv7 Cortex-A8(1 核，13 流水线深度) 和 512M 的设备 运行超过 250 个线程；但是，顶级命令的平均负载似乎低于 1 或略高于 1.5 [1]。

在使用 vmstat[2] 时，我可以看到与设备 [2] 上可用的内核相比，procs(r) 似乎经常非常高，在这种情况下它只是一个单核 cpu。

在分析设备上运行的进程之一的 GC 收集时，我得到以下结果[3]:有趣的是，实时时间明显高于(用户+系统)时间；因此，例如，据报道 GC 花费了 226 毫秒，而实时花费了 230 毫秒。

鉴于以下情况: 假设正确吗，设备正在遭受 cpu 争用 如果，那么 CPU 争用会反射(reflect)在使用 top 的平均负载上吗？ 顶部的平均负载是否是线程引起的 CPU 争用的良好指标？ 还有什么会导致 vmstat 的 procs -r 计数值过高？

[3]
2019-01-21T10:18:55.607+0000: 78.012: [GC (Allocation Failure) 2019-01-21T10:18:55.608+0000: 78.013: [DefNew: 5632K->576K(5632K), 0.2220500 secs] 13789K->9541K(17928K), 0.2260043 secs] [Times: user=0.06 sys=0.00, real=0.23 secs]

2019-01-21T10:26:18.394+0000: 520.799: [GC (Allocation Failure) 2019-01-21T10:26:18.396+0000: 520.801: [DefNew: 9423K->601K(9792K), 0.1988650 secs] 30450K->21806K(31360K), 0.2060742 secs] [Times: user=0.07 sys=0.00, real=0.21 secs]

2019-01-21T10:19:51.661+0000: 134.066: [GC (Allocation Failure) 2019-01-21T10:19:51.663+0000: 134.068: [DefNew: 9560K->766K(9792K), 0.3196409 secs] 22499K->13926K(31360K), 0.3309429 secs] [Times: user=0.04 sys=0.02, real=0.33 secs] 


[1]
//Top
top - 10:40:04 up  1:58,  8 users,  load average: 1.66, 1.23, 1.64
Threads: 251 total,   3 running, 248 sleeping,   0 stopped,   0 zombie

[2]
Vmsatat 
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 5  0      0  16136  22012 232432    0    0     0     0 1614 3670 40 35 26  0  0
 3  0      0  21740  22012 232444    0    0     0     0 2576 5744 61 39  0  0  0
 0  0      0  21628  22012 232448    0    0     0     0 2006 4809 52 22 26  0  0
 0  0      0  21740  22012 232448    0    0     0     0  595  843  5  8 87  0  0
 3  0      0  21740  22012 232448    0    0     0     0  140  309  2  4 94  0  0
 0  0      0  21740  22036 232448    0    0     0   116  220  349  8  3 89  0  0
 2  0      0  21740  22036 232448    0    0     0     0  125  282  2  3 95  0  0
 0  0      0  21740  22036 232448    0    0     0     0  129  280  2  4 94  0  0
 1  0      0  21740  22036 232448    0    0     0     0  127  266  3  3 94  0  0
 0  0      0  21740  22036 232448    0    0     0     4  145  315  3  3 94  0  0
 2  0      0  18988  22036 232448    0    0     0     0 1619 3888 43 38 19  0  0
 2  0      0  24592  22040 232444    0    0     0    36 2315 5472 64 36  0  0  0
 0  0      0  24480  22040 232444    0    0     0     0 1766 4273 51 23 26  0  0
 0  0      0  24512  22040 232444    0    0     0     0  658 1033  6  7 87  0  0
 0  0      0  24544  22040 232444    0    0     0     0  163  353  1  4 95  0  0
 0  0      0  24544  22040 232444    0    0     0     0  122  242  3  3 94  0  0
 1  0      0  24544  22040 232444    0    0     0     0  142  304  1  4 95  0  0
 0  0      0  24544  22040 232444    0    0     0     0  137  294  2  4 94  0  0
 0  0      0  24544  22040 232444    0    0     0     0  137  276  3  4 93  0  0
 0  0      0  24544  22040 232444    0    0     0     0  134  308  3  2 95  0  0
 9  0      0  19080  22040 232448    0    0     0     0 1952 4268 42 37 20  0  0
 1  0      0  24460  22040 232456    0    0     0     0 2058 4523 65 35  0  0  0
 2  0      0  24560  22040 232452    0    0     0     0 3057 7385 58 42  0  0  0

Answer 1

Linux 平均负载代表(粗略地说)R、D 或(历史上)W 中操作系统进程队列上的进程或线程数 状态。

• https://unix.stackexchange.com/questions/9465/understanding-top-and-load-average

---

Is average load on top a good indicator on CPU contention caused by threads?

不一定。

1. 它可能是由进程而不是线程引起的。
2. D 状态表示进程正在等待“不可中断的”I/O:通常是文件系统操作。因此，如果您正在访问一个慢速文件系统(例如负载很重的网络文件服务器)，则可能会推高平均负载。

What else can cause high values for vmstat's procs -r count?

根据vmstat 手册条目，r 列实际上是处于R 状态的进程(或线程)数。 d 列是处于 D 状态的进程数。请注意，这些是瞬时测量值，而不是平均值。

所以，答案是流程。

---

另一件需要注意的事情是，JVM 可能会在运行 GC 时挂起所有应用程序线程(针对进程)。根据 GC 的实现，此暂停可能会在 GC 运行期间或仅在某些阶段发生。

所以你观察到GC CPU时间和时钟时间几乎相同并不意味着没有CPU争用。

相反，GC CPU 时间和时钟时间之间的主要差异并不一定意味着存在 CPU 争用(与应用程序线程或其他进程)。另一种可能性是争用(实际)内存页；即虚拟内存抖动。