zgc log 中的 mmu 线是什么意思？

What does the mmu line mean in zgc log?

提问人：Garrus 提问时间：12/27/2022 最后编辑：Garrus 更新时间：12/28/2022 访问量：252

问：

在典型的详细 zgc 日志中，这些数字在这条 mmu 行中的含义是什么？

[gc,mmu ] GC(18939) MMU: 2ms/0.0%, 5ms/0.0%, 10ms/0.0%, 20ms/0.0%, 50ms/36.2%, 100ms/68.0%

我已经搜索并阅读了几页，但仍然没有在那一行上表达，所以我在这里寻找答案。

zgc 循环的完整输出示例：（jdk 版本：17）

[2022-12-26T20:09:49.485+0800][824756][gc,start    ] GC(18939) Garbage Collection (Allocation Rate)
[2022-12-26T20:09:49.485+0800][824756][gc,task     ] GC(18939) Using 8 workers
[2022-12-26T20:09:49.486+0800][824899][gc,phases   ] GC(18939) Pause Mark Start 0.048ms
[2022-12-26T20:09:51.200+0800][824756][gc,phases   ] GC(18939) Concurrent Mark 1713.889ms
[2022-12-26T20:09:51.200+0800][824899][gc,phases   ] GC(18939) Pause Mark End 0.064ms
[2022-12-26T20:09:51.200+0800][824756][gc,phases   ] GC(18939) Concurrent Mark Free 0.002ms
[2022-12-26T20:09:51.220+0800][824756][gc,phases   ] GC(18939) Concurrent Process Non-Strong References 20.398ms
[2022-12-26T20:09:51.221+0800][824756][gc,phases   ] GC(18939) Concurrent Reset Relocation Set 0.297ms
[2022-12-26T20:09:51.237+0800][824756][gc,phases   ] GC(18939) Concurrent Select Relocation Set 16.689ms
[2022-12-26T20:09:51.238+0800][824899][gc,phases   ] GC(18939) Pause Relocate Start 0.012ms
[2022-12-26T20:09:51.248+0800][824756][gc,phases   ] GC(18939) Concurrent Relocate 9.731ms
[2022-12-26T20:09:51.248+0800][824756][gc,load     ] GC(18939) Load: 17.62/16.95/16.43
[2022-12-26T20:09:51.248+0800][824756][gc,mmu      ] GC(18939) MMU: 2ms/0.0%, 5ms/0.0%, 10ms/0.0%, 20ms/0.0%, 50ms/36.2%, 100ms/68.0%
[2022-12-26T20:09:51.248+0800][824756][gc,marking  ] GC(18939) Mark: 8 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
[2022-12-26T20:09:51.248+0800][824756][gc,marking  ] GC(18939) Mark Stack Usage: 32M
[2022-12-26T20:09:51.248+0800][824756][gc,nmethod  ] GC(18939) NMethods: 33902 registered, 10715 unregistered
[2022-12-26T20:09:51.248+0800][824756][gc,metaspace] GC(18939) Metaspace: 189M used, 191M committed, 1200M reserved
[2022-12-26T20:09:51.248+0800][824756][gc,ref      ] GC(18939) Soft: 2612 encountered, 78 discovered, 0 enqueued
[2022-12-26T20:09:51.248+0800][824756][gc,ref      ] GC(18939) Weak: 59639 encountered, 21677 discovered, 142 enqueued
[2022-12-26T20:09:51.248+0800][824756][gc,ref      ] GC(18939) Final: 11628 encountered, 1203 discovered, 2 enqueued
[2022-12-26T20:09:51.248+0800][824756][gc,ref      ] GC(18939) Phantom: 2517 encountered, 1758 discovered, 1 enqueued
[2022-12-26T20:09:51.248+0800][824756][gc,reloc    ] GC(18939) Small Pages: 16920 / 33840M, Empty: 23428M, Relocated: 13M, In-Place: 0
[2022-12-26T20:09:51.248+0800][824756][gc,reloc    ] GC(18939) Medium Pages: 9 / 288M, Empty: 192M, Relocated: 0M, In-Place: 0
[2022-12-26T20:09:51.248+0800][824756][gc,reloc    ] GC(18939) Large Pages: 13 / 146M, Empty: 0M, Relocated: 0M, In-Place: 0
[2022-12-26T20:09:51.248+0800][824756][gc,reloc    ] GC(18939) Forwarding Usage: 5M
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939) Min Capacity: 45056M(100%)
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939) Max Capacity: 45056M(100%)
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939) Soft Max Capacity: 45056M(100%)
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939)                Mark Start          Mark End        Relocate Start      Relocate End           High               Low
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939)  Capacity:    45056M (100%)      45056M (100%)      45056M (100%)      45056M (100%)      45056M (100%)      45056M (100%)
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939)      Free:    10782M (24%)        5440M (12%)       28954M (64%)       36920M (82%)       36922M (82%)        5376M (12%)
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939)      Used:    34274M (76%)       39616M (88%)       16102M (36%)        8136M (18%)       39680M (88%)        8134M (18%)
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939)      Live:         -              2504M (6%)         2504M (6%)         2504M (6%)             -                  -
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939) Allocated:         -              5342M (12%)        5448M (12%)        5487M (12%)            -                  -
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939)   Garbage:         -             31769M (71%)        8149M (18%)         143M (0%)             -                  -
[2022-12-26T20:09:51.248+0800][824756][gc,heap     ] GC(18939) Reclaimed:         -                  -             23620M (52%)       31625M (70%)            -                  -
[2022-12-26T20:09:51.248+0800][824756][gc          ] GC(18939) Garbage Collection (Allocation Rate) 34274M(76%)->8136M(18%)
垃圾回收 JVM-热点 zgc

评论

答：

0赞 apangin 12/28/2022 #1

术语 MMU（Minimum Mutator Utilization）是在 Perry Cheng 和 Guy E. Blelloch 的论文“A Parallel， Real-Time Garbage Collector”中引入的。

MMU 不仅允许人们查看最大暂停时间，还允许查看 处理器可供赋值器使用的时间分数 （应用程序）用于指定大小的任何时间窗口（最坏情况 在整个执行过程中）。这是一个更有用的衡量标准 实时功能不仅仅是最长暂停时间。

更正式地说，在 HotSpot JVM 中

MMU(t) = (t - time_paused) / t

其中 是应用程序线程在以上次 GC 暂停结束的最后一个毫秒时间片内暂停的总时间。time_pausedt

例如 表示在过去 100 毫秒内，应用程序线程运行的总持续时间为 68 毫秒。MMU 100ms/68.0%

评论

0赞 Garrus 12/28/2022
非常感谢您的解释。（该死的，我错过了论文）我还意识到 mmu 线总是显示自第一个 gc 以来的最坏情况。这让我困惑了一段时间，因为它显示在每个周期的输出中，但统计数据除外。

上一个：不安全库如何帮助原子变量实现线程安全？

下一个：为什么 java-11 version 命令显示 java 18.x 作为输出？