2.5 配套代码：分配速率、GC 日志与 Humongous 对象
对应小节：2.5 内存与 GC 三件事：① 亲眼看到「分配速率决定 GC 频率」② 读懂 GC 日志 ③ 复现 Humongous 对象的陷阱。
一、实验：分配速率与 GC 频率的关系
// src/main/kotlin/lesson02/AllocationRate.kt
package lesson02
import java.lang.management.ManagementFactory
import kotlin.random.Random
private val threadBean = ManagementFactory.getThreadMXBean() as com.sun.management.ThreadMXBean
fun allocatedMb(): Double =
threadBean.getThreadAllocatedBytes(Thread.currentThread().threadId()) / 1024.0 / 1024.0
fun gcCount(): Long =
ManagementFactory.getGarbageCollectorMXBeans().sumOf { it.collectionCount }
fun gcTimeMs(): Long =
ManagementFactory.getGarbageCollectorMXBeans().sumOf { it.collectionTime }
/**
* 分配指定大小的"垃圾"，观察 GC 频率。
* @param bytesPerIteration 每次迭代分配的字节数
*/
fun allocateGarbage(bytesPerIteration: Int, iterations: Int) {
val rnd = Random(42)
for (i in 0 until iterations) {
val arr = ByteArray(bytesPerIteration)
arr[0] = rnd.nextInt().toByte() // 防止整个分配被消除
if (arr[0] == Byte.MAX_VALUE) println("never") // 让 arr 有逃逸可能
}
}
fun measureScenario(label: String, bytesPerIteration: Int, iterations: Int) {
val gcBefore = gcCount()
val gcTimeBefore = gcTimeMs()
val allocBefore = allocatedMb()
val t0 = System.nanoTime()
allocateGarbage(bytesPerIteration, iterations)
val elapsedMs = (System.nanoTime() - t0) / 1_000_000.0
val allocMb = allocatedMb() - allocBefore
val gcDelta = gcCount() - gcBefore
val gcTimeDelta = gcTimeMs() - gcTimeBefore
println("%-26s %10.1f MB 分配速率 %8.1f MB/s GC次数 %3d GC总停顿 %5d ms"
.format(label, allocMb, allocMb / (elapsedMs / 1000), gcDelta, gcTimeDelta))
}
fun main() {
println("=== 分配速率 → GC 频率 的关系 ===")
println("（堆默认大小；如果想看得更明显，用 -Xmx256m 运行）\n")
println("%-26s %13s %21s %14s %18s".format("场景", "总分配量", "分配速率", "GC次数", "GC停顿"))
// 同样的总分配量，但速率不同
measureScenario("小对象慢速分配", 1_024, 200_000) // 200 MB，分 20 万次
measureScenario("小对象快速分配", 1_024, 2_000_000) // 2 GB
measureScenario("大对象分配", 1_048_576, 2_000) // 2 GB，每次 1 MB
println()
println("预期观察：")
println(" 1. 分配速率越高，GC 次数越多（这就是「分配速率决定 GC 频率」）")
println(" 2. 大对象场景的 GC 行为不同——1MB 的数组在 G1 下可能触发 Humongous 分配")
println()
println("⚠️ 这个实验会占用较多内存和 CPU，建议用 -Xmx256m 限制堆，并在空闲机器上跑。")
}
运行建议：
# 堆限制小一点，GC 现象更明显
java -Xmx256m -Xlog:gc*:file=gc-alloc.log:time,uptime,level,tags \
-cp build/classes/kotlin/main lesson02.AllocationRateKt
二、预期输出形态
场景 总分配量 分配速率 GC次数 GC停顿
小对象慢速分配 200.0 MB 850.3 MB/s 12 45 ms
小对象快速分配 2000.0 MB 3200.7 MB/s 118 620 ms
大对象分配 2000.0 MB 2800.1 MB/s 203 1890 ms
三个值得注意的点：
| 观察 | 含义 |
|---|---|
| 分配速率 ×3.8，GC 次数 ×9.8 | GC 频率对分配速率是非线性敏感的 |
| 大对象的 GC 次数更多、停顿更长 | Humongous 分配会提前触发 GC |
| 总分配量相同，但 GC 行为完全不同 | 「分配了多少」不如「多快分配」重要 |
三、读 GC 日志
# 打开 GC 日志（生产环境必开）
java -Xlog:gc*:file=gc.log:time,uptime,level,tags:filecount=5,filesize=20m -jar app.jar
# 只看关键行
grep -E "Pause Young|Pause Full|Humongous" gc.log | head -30
# 看 Humongous 分配（G1 特有）
java -Xlog:gc+humongous=info -jar app.jar
日志行解读：
[2025-01-15T10:23:45.123+0800][12.456s][info][gc] GC(42) Pause Young (Normal) (G1 Evacuation Pause) 128M->32M(256M) 4.231ms
│ │ │ │ │ │ │ │
时间戳 运行时长 GC序号 类型 子类型 回收前→后 堆容量 停顿
| 看什么 | 判断 |
|---|---|
Pause Young 的频率 |
几秒一次 → 分配速率太高 |
Pause Full 出现 |
⚠️ 配置不当或内存泄漏，必须查明 |
| 停顿时间（末尾 ms） | 与延迟分布的尖刺时间对齐吗？ |
回收前->后 |
如果回收后仍居高不下 → 对象在晋升或有泄漏 |
Humongous |
大对象，检查是否有大数组/大字符串 |
关键动作：把 GC 停顿和 P99 尖刺对齐
# 把 GC 停顿时间戳提取出来
grep "Pause Young" gc.log | awk '{print $1, $NF}' > gc-pauses.txt
# 然后和你的延迟监控（Prometheus 的 P99 尖刺时间点）对照
# 对齐 → GC 是根因；不对齐 → 排除 GC，别在这里浪费时间
这是第 6 章「排除假设」的标准动作。先把 GC 排除掉，再看别的地方，能省下大量时间。
四、复现 Humongous 对象陷阱
// src/main/kotlin/lesson02/HumongousDemo.kt
package lesson02
import kotlin.random.Random
private var sink = 0
/**
* 在 G1 中，超过 region 大小一半的对象是 Humongous 对象，会：
* - 直接在老年代分配
* - 可能连续占用多个 region
* - 可能【提前触发 GC】
*/
fun main() {
val rnd = Random(42)
println("region 大小 = %.1f MB（用 -XX:+PrintFlagsFinal | grep G1HeapRegionSize 查看）"
.format(1.0))
// 场景 A：小对象（远小于 region 的一半）
println("\n场景 A：每次分配 256 KB（非 Humongous）")
repeat(10_000) {
val a = ByteArray(256 * 1024)
a[0] = rnd.nextInt().toByte()
sink += a[0]
}
println(" 完成，观察 GC 日志里的 Humongous 计数")
// 场景 B：大对象（超过 region 的一半 → Humongous）
println("\n场景 B：每次分配 4 MB（Humongous！）")
repeat(2_000) {
val a = ByteArray(4 * 1024 * 1024)
a[0] = rnd.nextInt().toByte()
sink += a[0]
}
println(" 完成，对比 GC 日志")
println("\nsink = $sink")
println("\n对比方法：分别运行两次，比较 GC 日志里：")
println(" - GC 总次数")
println(" - 是否有 'Humongous' 相关日志")
println(" - 停顿时间总和")
}
# 场景 A
java -Xmx512m -Xlog:gc+humongous=info:file=gc-small.log -cp build/classes/kotlin/main lesson02.HumongousDemoKt
# 场景 B（把 repeat 里的 256KB 改成 4MB 再跑一次）
# 或者直接用 -XX:G1HeapRegionSize 调整 region 大小来观察阈值变化
修法（对真实项目）：
| 问题 | 修法 |
|---|---|
| 大数组一次性读入 | 改成流式处理 / 分块读取 |
| 大字符串（拼接出的 JSON） | 用流式序列化，避免构造完整字符串 |
| 大缓存的序列化结果 | 改成增量处理或复用缓冲区（这是少数对象池确实有效的场景） |
五、找分配热点
# 分配火焰图（async-profiler）
asprof -d 60 -e alloc -f alloc.html <pid>
# 或者用 JFR
jcmd <pid> JFR.start name=alloc settings=profile duration=60s filename=alloc.jfr
# 用 JDK Mission Control 打开，看 jdk.ObjectAllocationSample
# 或者看 Micrometer 指标（分配速率的趋势）
curl -s localhost:8080/metrics | grep jvm_gc_memory_allocated_bytes_total
Kotlin 常见分配热点（在第 5 节正文里有完整清单）：
// 1. data class copy()
val updated = order.copy(status = "PAID") // 热路径上频繁调用 → 大量分配
// 2. 装箱
val list: List<Int> = ... // 每个 Int 装箱
val array: IntArray = ... // 无装箱
// 3. 字符串拼接（循环内）
repeat(1000) { result += "$i," } // 每次分配新 String
// ✅ 改成 StringBuilder
// 4. Regex 重复编译
Regex("""\d{3}""").findAll(text) // ❌ 每次编译
private val RE = Regex("""\d{3}""") // ✅ 提到顶层
六、动手改造
| 改动 | 观察什么 |
|---|---|
用 -Xmx64m 跑分配实验 |
GC 频率大幅上升、可能 OOM——这就是堆太小的表现 |
用 -Xmx2g 跑同样的实验 |
GC 频率下降，但单次停顿变长——「堆越大停顿越长」的验证 |
用 -XX:+UseZGC 再跑一次 |
停顿变成亚毫秒级，但总吞吐可能下降（用总耗时对比） |
把 ByteArray(4MB) 换成 ByteArray(1MB) 并调小 region |
观察 Humongous 阈值随 region 大小变化 |
在实验里加上 -prof gc（如果用 JMH） |
直接得到 gc.alloc.rate，比手工计算更规范 |
七、这段代码的局限
ThreadMXBean.getThreadAllocatedBytes是 JDK 内部 API，且只统计当前线程（不含其他线程）。用于对比可以，精确测量请用 JMH 的-prof gc或 async-profiler。- GC 行为强烈依赖 JDK 版本、GC 选型、堆大小、region 大小，你的数字会和示例不同。看趋势，不看绝对值。
- 这个实验会真实消耗内存与 CPU，不要在重要环境跑。
- 不要用这个实验的结果去调你的生产 JVM 参数——生产调优必须用真实负载（第 7 章）。