JFR và profiling — Flight Recorder, JMC, async-profiler

TL;DR: CLI tool (bài 07) cho snapshot tại một thời điểm; khi cần timeline — hệ thống lag 30 phút trước vì gì — bạn cần profiler ghi liên tục. JFR (Java Flight Recorder) là profiler built-in JVM, capture event (GC, JIT, lock, I/O, allocation, exception) với overhead dưới 1% — bật always-on trong production với rotation theo maxage/maxsize, dump snapshot khi có incident. Phân tích bằng JDK Mission Control (JMC). Cần flame graph chi tiết hơn (kể cả native stack)? async-profiler — sampling qua AsyncGetCallTrace + perf_events, không chờ safepoint. Setup chuẩn production: JFR always-on (safety net) + async-profiler on-demand (deep dive).

Bài 07 dừng ở các tool snapshot: jstack chụp 1 khoảnh khắc, jstat đọc số hiện tại. Nhưng câu hỏi on-call thường gặp là về quá khứ: "30 phút trước hệ thống lag — lúc đó GC thế nào, thread nào contention, allocation từ đâu?" Snapshot sau sự kiện không trả lời được. Cần một "hộp đen máy bay" ghi liên tục.

Bài này đi qua: JFR (Java Flight Recorder — production profiler), JMC (Mission Control — đọc recording), async-profiler (flame graph CPU/alloc/lock), và workflow profiling điển hình: từ GC pressure đến hot allocation site.

1. JFR — Java Flight Recorder

JFR là production-grade profiler built-in JVM. Capture event (GC, JIT, lock, IO, allocation, exception) với overhead dưới 1% — bật được trong production.

Lịch sử

JFR được Oracle ship trong JRockit (commercial JVM mua lại từ BEA), sau merge vào HotSpot. Open-source từ Java 11 (JEP 328).

Trước Java 11: cần Oracle JDK + license. Java 11+: free, mainline OpenJDK.

Khởi động JFR

Pre-recorded (continuous)

java -XX:StartFlightRecording=duration=60s,filename=profile.jfr MyApp

Record 60s từ khi JVM start, dump file.

On-demand qua jcmd

# Start recording
jcmd 12345 JFR.start name=mysession duration=120s filename=/tmp/profile.jfr

# Check status
jcmd 12345 JFR.check

# Stop early
jcmd 12345 JFR.stop name=mysession

Always-on profile

java -XX:StartFlightRecording=settings=profile,maxsize=200m,maxage=1h,disk=true MyApp

JFR ghi liên tục, giữ 1 giờ gần nhất hoặc 200MB. On-demand JFR.dump lấy snapshot — debug post-incident: "30 phút trước hệ thống lag, có pattern gì?".

jcmd <PID> JFR.dump filename=/tmp/incident-$(date +%s).jfr

Profile preset: default (low overhead), profile (more events, ~2% overhead). Custom preset qua .jfc file XML.

Event quan trọng

• jdk.GarbageCollection: mỗi GC cycle với cause + duration.
• jdk.AllocationOutsideTLAB: object alloc đặc biệt (large object) — tracking allocation hot.
• jdk.JavaMonitorWait / jdk.JavaMonitorEnter: thread đợi lock — contention analysis.
• jdk.Compilation / jdk.Deoptimization: JIT activity.
• jdk.SocketRead / jdk.SocketWrite / jdk.FileRead: I/O latency.
• jdk.ExceptionThrown: mỗi exception throw — debug "exception storm".

2. JMC — phân tích JFR file

JDK Mission Control (JMC) — desktop tool free, mở .jfr file:

• Garbage Collections: list cycle, pause time, cause.
• Method Profiling: flame graph CPU usage.
• Memory Allocation: top allocation site (class, thread, method).
• Thread: pause, contention, lock wait.
• JVM Internal: compilation event, deoptimization.
• I/O: file read, network read latency.

JMC interactive — drill down từ summary đến exact stack trace + line number.

CLI alternative:

jfr print --events GarbageCollection,MetaspaceOOM profile.jfr

3. async-profiler — flame graph chi tiết

JFR overhead thấp, sample-based — đủ cho overview. Cần detail hot method? async-profiler (https://github.com/async-profiler/async-profiler) — open-source, không phải Oracle, profiling theo CPU sampling và allocation tracking.

# Profile 30s, output flame graph
asprof -d 30 -f /tmp/flame.html 12345

# CPU profile
asprof -e cpu -d 30 -f cpu.html 12345

# Allocation profile (where alloc happens)
asprof -e alloc -d 30 -f alloc.html 12345

# Lock profile (contention)
asprof -e lock -d 30 -f lock.html 12345

Flame graph HTML: stack visualization. Trục X = % time CPU, trục Y = stack depth. Method "wide" = ăn nhiều CPU. Click để zoom.

Pattern đọc:

• Plateau wide ở top: hot method dùng CPU thực sự.
• Tower cao: deep call chain — có thể inline opportunity.
• Multiple wide top: nhiều hot path — phân bổ optimize.

async-profiler ưu điểm vs JFR:

• Native stack: thấy JNI / native call (JFR chỉ Java frame).
• Flame graph beautiful: intuitive hơn JMC table.
• Allocation profiling chi tiết hơn: thấy chính xác alloc per method.

Dùng song song JFR (continuous, low overhead) + async-profiler (deep dive khi đã identify suspicious).

4. Workflow — GC chạy liên tục, throughput thấp

# 1. jstat realtime (bai 07) - confirm pattern
jstat -gcutil <PID> 1000

# Pattern xau:
# - YGC tang nhanh (vai giay 1 lan)
# - O% leo cao (~95%) lien tuc
# - FGC tang -> co full GC
# - GCT chiem dang ke uptime (vuot 5%)

# 2. JFR capture allocation hot
jcmd <PID> JFR.start name=alloc duration=60s filename=alloc.jfr

# 3. Mo JMC, Memory Allocation tab
# - Top allocation method
# - Allocation rate

# 4. Refactor code: cat alloc thua (string concat trong loop,
#    intermediate stream object, vong loop tao throw-away object)

Xác nhận lại bằng async-profiler allocation flame graph nếu cần đến mức per-method:

asprof -e alloc -d 30 -f alloc.html <PID>

5. Pitfall tổng hợp

❌ Nhầm 1: Bỏ qua JFR vì nghĩ "tốn performance".

JFR overhead <1% production-grade. Bat always-on co loi hon overhead.

✅ Always-on JFR với rotation 1 giờ là standard production setup.

❌ Nhầm 2: CPU flame graph cho vấn đề memory.

App cham vi GC pressure -> CPU profile chi thay GC thread.
Phai profile allocation (-e alloc / JFR Memory tab).

✅ Chọn event type theo symptom: cpu / alloc / lock.

❌ Nhầm 3: Profile trên dev machine rồi kết luận cho production.

Dev: data nho, JIT chua warm, khong contention.
Production: data lon, 50 thread, cache miss khac han.

✅ Profile trên production (JFR overhead thấp cho phép) hoặc môi trường tải tương đương.

6. 📚 Deep Dive Oracle

7. Tóm tắt

• JFR (Java Flight Recorder): production profiler built-in, overhead dưới 1%. Open-source từ Java 11 (JEP 328).
• 3 mode: record từ start (-XX:StartFlightRecording), on-demand (jcmd JFR.start/stop), always-on với maxsize/maxage rotation.
• Always-on + JFR.dump khi incident = debug được quá khứ — pattern "hộp đen máy bay".
• JMC (Mission Control): GUI phân tích .jfr — GC, allocation, lock contention, exception, I/O.
• async-profiler: flame graph CPU + allocation + lock. Native stack support. Sampling qua AsyncGetCallTrace, không chờ safepoint.
• Flame graph: trục X = % time, plateau rộng trên đỉnh = hot method; tower cao = call chain sâu.
• Chọn event theo symptom: CPU cao → -e cpu; GC pressure → JFR Memory tab / -e alloc; chậm vì lock → -e lock.
• Workflow GC liên tục: jstat confirm → JFR allocation profile → JMC top allocation site → refactor cắt alloc.
• Setup chuẩn production: JFR always-on (safety net) + async-profiler on-demand (deep dive). Không phải either/or.

8. Tự kiểm tra

Bài tiếp theo: Object header và field layout — vì sao object nhỏ vẫn tốn 16 byte