Mini-challenge: Debug memory leak với heap dump và JFR

Mini-challenge khép lại module JVM Internals. Bạn nhận được codebase một service đang leak memory trong production. Symptom: heap leo từ 200MB lúc start lên 3GB sau 1 giờ, 80% time GC, p99 latency tăng từ 50ms lên 2s.

Bạn sẽ:

1. Reproduce leak local với load generator tích hợp.
2. Capture diagnostic (jstat, JFR, heap dump).
3. Phân tích heap dump với MAT-style approach.
4. Identify root cause.
5. Fix với data structure phù hợp.
6. Verify fix với heap dump diff.

Đây là task điển hình senior Java engineer trong on-call: từ alert đến fix trong 1-2 giờ.

🎯 Đề bài

Setup

Service EventTracker ghi nhận event user clicks vào button trên website. Mỗi event có ID, timestamp, userId, button name. Service expose 2 endpoint:

• POST /track — nhận event, lưu vào memory + DB.
• GET /stats/{userId} — trả về số click 24h gần nhất của user.

Code dùng "in-memory cache" để tránh hit DB cho mọi /stats call. Cache sử dụng HashMap<String, List<Event>> mapping userId → danh sách event.

Production thật nhận khoảng 100 click/user/giờ. Để reproduce leak trong vài phút thay vì cả ngày, starter code có load generator chạy ngay trong cùng JVM: 1000 user, mỗi user bắn 10 event/giây → tổng 10.000 event/giây. Với heap 512MB, leak lộ rõ sau 2-3 phút.

Vì sao load generator nằm cùng JVM với app? Leak nằm trong chính process bạn monitor — jstat/jcmd/heap dump trỏ vào đúng PID đó là thấy. Production thực tế load đến từ HTTP client bên ngoài, nhưng cấu trúc leak (cache giữ event mãi) giống hệt.

Yêu cầu

1. Reproduce: chạy EventTrackerApp.main với heap nhỏ (-Xmx512m -XX:+HeapDumpOnOutOfMemoryError -Xlog:gc*=info:file=gc.log) khoảng 5 phút. Quan sát heap qua dòng log monitor in mỗi 5 giây.

2. Diagnose: dùng tools (trỏ vào PID của chính EventTrackerApp):

   • jstat -gcutil <pid> 1000 — confirm Old growing.
   • jcmd <pid> JFR.start name=leak duration=120s filename=/tmp/leak.jfr — capture allocation profile.
   • jcmd <pid> GC.heap_dump /tmp/leak.hprof — heap dump.
   • jcmd <pid> GC.class_histogram | head -20 — top class theo size.

3. Analyze: từ histogram + heap dump, identify:

   • Class nào chiếm nhiều heap nhất.
   • Tại sao instance không bị GC (giữ bởi reference nào).
   • Pattern leak (cache không bound? listener leak? thread local leak?).

4. Fix: refactor EventCache với:

   • TTL (event quá 24h tự evict — đúng business semantic "click 24h gần nhất").
   • Thread-safe (concurrent access từ 50 worker thread).
   • Bound được size khi cần.

5. Verify: rerun load test, capture heap dump sau 5 phút và sau 30 phút, diff. Heap stable, no growth.

📦 Concept dùng trong bài

▶️ Starter code

EventTrackerApp.java (1 file duy nhất — app + load generator cùng JVM):

import java.time.Instant;
import java.util.*;
import java.util.concurrent.atomic.AtomicLong;

public class EventTrackerApp {

    public record Event(String id, String userId, String button, Instant timestamp) { }

    // BUG: leak here
    public static class EventCache {
        private final Map<String, List<Event>> cache = new HashMap<>();

        public void add(Event e) {
            cache.computeIfAbsent(e.userId(), k -> new ArrayList<>()).add(e);
        }

        public List<Event> getEventsLast24h(String userId) {
            List<Event> all = cache.getOrDefault(userId, List.of());
            Instant cutoff = Instant.now().minusSeconds(86400);
            return all.stream()
                .filter(e -> e.timestamp().isAfter(cutoff))
                .toList();
        }

        public int size() {
            return cache.values().stream().mapToInt(List::size).sum();
        }
    }

    public static class EventTracker {
        private final EventCache cache = new EventCache();
        private final AtomicLong idGen = new AtomicLong();

        public void track(String userId, String button) {
            Event e = new Event(
                String.valueOf(idGen.incrementAndGet()),
                userId, button, Instant.now());
            cache.add(e);
            // Imagine DB persist here
        }

        public int statsLast24h(String userId) {
            return cache.getEventsLast24h(userId).size();
        }

        public int totalEvents() {
            return cache.size();
        }
    }

    // Load generator NOI BO: 50 worker thread, moi worker phu trach 20 user.
    // Moi vong: ban 1 event cho tung user roi ngu 100ms
    // -> moi user 10 event/s -> tong 1000 user x 10 = 10k event/s.
    static void startLoadGenerator(EventTracker tracker) {
        int workers = 50;
        int usersPerWorker = 20;   // 50 x 20 = 1000 distinct user
        for (int w = 0; w < workers; w++) {
            final int base = w * usersPerWorker;
            Thread t = new Thread(() -> {
                while (true) {
                    for (int i = 0; i < usersPerWorker; i++) {
                        int userId = base + i;
                        tracker.track("user-" + userId, "button-" + (userId % 5));
                    }
                    try { Thread.sleep(100); } catch (InterruptedException e) { return; }
                }
            }, "load-worker-" + w);
            t.setDaemon(true);
            t.start();
        }
    }

    public static void main(String[] args) throws InterruptedException {
        EventTracker tracker = new EventTracker();

        // Print heap + cache size every 5s
        Thread monitor = new Thread(() -> {
            while (true) {
                try { Thread.sleep(5000); } catch (InterruptedException e) { return; }
                Runtime r = Runtime.getRuntime();
                long used = (r.totalMemory() - r.freeMemory()) / 1024 / 1024;
                long max = r.maxMemory() / 1024 / 1024;
                System.out.printf("Heap %d/%d MB - cache total events: %d%n",
                    used, max, tracker.totalEvents());
            }
        });
        monitor.setDaemon(true);
        monitor.start();

        startLoadGenerator(tracker);
        System.out.println("EventTracker started. PID: " + ProcessHandle.current().pid());

        // Block - keep JVM alive
        Thread.currentThread().join();
    }
}

Compile và chạy:

javac EventTrackerApp.java

# Terminal 1: chay app (load generator tu chay ben trong)
java -Xms256m -Xmx512m \
     -XX:+HeapDumpOnOutOfMemoryError \
     -XX:HeapDumpPath=/tmp/heap.hprof \
     -Xlog:gc*=info:file=/tmp/gc.log \
     EventTrackerApp

# Terminal 2: monitor chinh JVM do
jps -l                                  # tim PID EventTrackerApp
jstat -gcutil <PID> 1000                # realtime GC
jcmd <PID> GC.heap_info                 # heap stats
jcmd <PID> GC.class_histogram | head -20

Dành 30-40 phút làm.

💡 Gợi ý — workflow diagnose

S0     S1     E      O      M      YGC    YGCT    FGC    FGCT
0.00  88.31  35.12  20.20  93.92      5    0.123     0    0.000
0.00  90.50  60.85  35.20  93.92     12    0.234     0    0.000
0.00  92.50  72.12  55.85  93.92     20    0.456     0    0.000
0.00  94.50  85.12  75.20  93.92     30    0.678     1    0.234
0.00  96.50  90.85  90.85  93.92     40    1.123     2    0.789

jcmd <PID> GC.class_histogram | head -20

 num     #instances         #bytes  class name (module)
-------------------------------------------------------
   1:        500000      40000000  EventTrackerApp$Event
   2:        500000      32000000  java.lang.String
   3:          1000       8000000  java.util.ArrayList
   4:          1000        128000  java.util.HashMap$Node
   ...

jcmd <PID> GC.heap_dump /tmp/leak.hprof

// EventCache
private final Map<String, List<Event>> cache = new HashMap<>();

public void add(Event e) {
    cache.computeIfAbsent(e.userId(), k -> new ArrayList<>()).add(e);
    // BUG: never remove old event
}

public List<Event> getEventsLast24h(String userId) {
    List<Event> all = cache.getOrDefault(userId, List.of());
    Instant cutoff = Instant.now().minusSeconds(86400);
    return all.stream()
        .filter(e -> e.timestamp().isAfter(cutoff))
        .toList();
    // BUG: filter chi tao List moi return, KHONG xoa event cu khoi cache
}

public void add(Event e) {
    Instant cutoff = Instant.now().minusSeconds(86400);
    List<Event> userEvents = cache.computeIfAbsent(e.userId(), k -> new ArrayList<>());
    userEvents.removeIf(ev -> ev.timestamp().isBefore(cutoff));
    userEvents.add(e);
}

import com.github.benmanes.caffeine.cache.*;

private final Cache<String, List<Event>> cache = Caffeine.newBuilder()
    .maximumSize(10_000)                           // Max 10k user
    .expireAfterWrite(Duration.ofHours(24))        // Auto evict 24h
    .build();

# Heap dump 1: 5 phut sau start
jcmd <PID> GC.heap_dump /tmp/dump1.hprof
jcmd <PID> GC.class_histogram | head -10

# Heap dump 2: 30 phut sau start
jcmd <PID> GC.heap_dump /tmp/dump2.hprof
jcmd <PID> GC.class_histogram | head -10
# So sanh: Event count khong tang tuyen tinh nua -> fix dung

jcmd <PID> JFR.start name=alloc duration=60s filename=/tmp/alloc.jfr
# ... wait 60s ...
# Open JMC, Memory Allocation tab

✅ Lời giải

import java.time.Instant;
import java.util.*;
import java.util.concurrent.*;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicLong;

public class EventTrackerApp {

    public record Event(String id, String userId, String button, Instant timestamp) { }

    public static class EventCache implements AutoCloseable {
        private final Map<String, List<Event>> cache = new ConcurrentHashMap<>();
        private final ScheduledExecutorService cleaner;
        private final long ttlSeconds;

        public EventCache(long ttlSeconds) {
            this.ttlSeconds = ttlSeconds;
            this.cleaner = Executors.newSingleThreadScheduledExecutor(r -> {
                Thread t = new Thread(r, "EventCache-Cleaner");
                t.setDaemon(true);
                return t;
            });
            cleaner.scheduleAtFixedRate(this::cleanup, 1, 1, TimeUnit.MINUTES);
        }

        public void add(Event e) {
            cache.compute(e.userId(), (k, existing) -> {
                List<Event> list = existing != null ? existing : new ArrayList<>();
                synchronized (list) {
                    list.add(e);
                }
                return list;
            });
        }

        public List<Event> getEventsLast24h(String userId) {
            List<Event> userEvents = cache.get(userId);
            if (userEvents == null) return List.of();
            Instant cutoff = Instant.now().minusSeconds(ttlSeconds);
            synchronized (userEvents) {
                return userEvents.stream()
                    .filter(e -> e.timestamp().isAfter(cutoff))
                    .toList();
            }
        }

        private void cleanup() {
            Instant cutoff = Instant.now().minusSeconds(ttlSeconds);
            AtomicInteger removed = new AtomicInteger();
            for (String userId : cache.keySet()) {
                // compute atomic per key: serialize voi add() tren cung user,
                // khong the go entry trong luc add dang chen event
                cache.compute(userId, (k, list) -> {
                    if (list == null) return null;
                    synchronized (list) {
                        int before = list.size();
                        list.removeIf(e -> e.timestamp().isBefore(cutoff));
                        removed.addAndGet(before - list.size());
                        return list.isEmpty() ? null : list;
                    }
                });
            }
            System.err.println("[Cleanup] Removed " + removed.get()
                + " stale events. Cache size: " + size());
        }

        public int size() {
            int total = 0;
            for (List<Event> list : cache.values()) {
                synchronized (list) {
                    total += list.size();
                }
            }
            return total;
        }

        public int userCount() {
            return cache.size();
        }

        @Override
        public void close() {
            cleaner.shutdown();
        }
    }

    public static class EventTracker {
        private final EventCache cache = new EventCache(86400);
        private final AtomicLong idGen = new AtomicLong();

        public void track(String userId, String button) {
            Event e = new Event(
                String.valueOf(idGen.incrementAndGet()),
                userId, button, Instant.now());
            cache.add(e);
        }

        public int statsLast24h(String userId) {
            return cache.getEventsLast24h(userId).size();
        }

        public int totalEvents() { return cache.size(); }
        public int activeUsers() { return cache.userCount(); }
    }

    // main + startLoadGenerator giu nguyen nhu starter code
}

private final EventCache cache = new EventCache(60);   // TTL 60s for test

Heap 180/512 MB | events: 600000 | users: 1000
[Cleanup] Removed 0 stale events. Cache size: 600000
Heap 320/512 MB | events: 1200000 | users: 1000
[Cleanup] Removed 600000 stale events. Cache size: 600000
Heap 310/512 MB | events: 1150000 | users: 1000
[Cleanup] Removed 590000 stale events. Cache size: 610000

# Truoc fix - 2 phut
jcmd <PID> GC.class_histogram | head -3
# 1: 1200000 EventTrackerApp$Event ~96 MB

# Truoc fix - 4 phut
# 1: 2400000 EventTrackerApp$Event ~192 MB
# Tang tuyen tinh theo thoi gian -> leak, sap OOM voi -Xmx512m

# Sau fix (TTL test 60s) - 5 phut
# 1: ~900000 EventTrackerApp$Event ~72 MB

# Sau fix - 30 phut
# 1: ~900000 EventTrackerApp$Event ~72 MB
# Dao dong quanh steady state -> no leak

🎓 Mở rộng

Mức 1 — Caffeine library:

<!-- pom.xml -->
<dependency>
    <groupId>com.github.ben-manes.caffeine</groupId>
    <artifactId>caffeine</artifactId>
    <version>3.1.8</version>
</dependency>

import com.github.benmanes.caffeine.cache.*;

private final Cache<String, List<Event>> cache = Caffeine.newBuilder()
    .maximumSize(10_000)                           // Bound user count
    .expireAfterWrite(Duration.ofHours(24))        // Auto evict
    .recordStats()                                  // Metric for monitoring
    .build();

Ngắn hơn 50 dòng code, thread-safe built-in, eviction policy tunable (LFU, LRU, custom). Production standard.

Mức 2 — Off-heap cache với Chronicle Map:

Nếu cache lớn (10GB+), in-heap GC pressure cao. Chronicle Map alloc off-heap:

ChronicleMap<String, List<Event>> cache = ChronicleMap
    .of(String.class, List.class)
    .averageKey("user-12345")
    .averageValueSize(1024)
    .entries(1_000_000)
    .createPersistedTo(new File("/tmp/event-cache.dat"));

Survive JVM restart, không impact GC. Trade-off: serialization overhead mỗi access.

Mức 3 — Time-series database thay cache:

Cache Event trong app process là anti-pattern cho production scale. Production dùng:

• InfluxDB / Prometheus cho metric / event count.
• Redis cho session-like data với TTL.
• App service stateless, query DB cho /stats.

Trade-off: latency từ in-memory ~1μs lên DB ~1ms. Acceptable cho stats endpoint không hit mỗi request.

Mức 4 — Continuous JFR monitoring trong production:

Set -XX:StartFlightRecording=settings=profile,maxsize=200m,maxage=1h,disk=true trong JVM args (bài 08). JFR ghi liên tục 1 giờ gần nhất. Khi alert fire, dump snapshot:

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

Capture state lúc incident, phân tích offline với JMC.

✨ Điều bạn vừa làm được

Hoàn thành mini-challenge này, bạn đã:

• Reproduce production issue trong môi trường local — skill đầu tiên cho debug.
• Đọc jstat realtime để confirm pattern leak (Old growing).
• Capture heap dump với jcmd, không restart JVM.
• Phân tích heap dump với class histogram + Path to GC Roots.
• Identify root cause: cache không bound, không TTL.
• Fix với data structure phù hợp: ConcurrentHashMap + background cleanup hoặc Caffeine bounded cache.
• Verify fix với heap dump diff trước/sau.
• Áp dụng production debug workflow end-to-end — kỹ năng phân biệt junior/senior.

Chúc mừng — bạn đã hoàn thành module JVM Internals!

Bạn giờ hiểu JVM ở mọi tầng:

• Class loader — class load qua loader nào, pattern isolation Tomcat / Spring Boot.
• Bytecode — đọc javap, hiểu invokedynamic, lambda compile thế nào.
• JIT — interpreter → C1 → C2, inlining, escape analysis, deoptimization.
• Memory layout — heap young/old, metaspace, native memory, object header + compressed OOP.
• GC — chọn collector phù hợp (Parallel / G1 / ZGC) theo SLA; safepoint và STW pause thực sự.
• Tools — jcmd/jstat/JFR/async-profiler, workflow debug từ symptom đến root cause.

Đây cũng là module cuối của khoá Java Internals — chặng thứ ba và là chặng cuối của Java track (Foundations → OO & Functional → Internals). Bạn đã đi từ dòng cú pháp đầu tiên đến tầng máy ảo bên dưới. Bước tiếp theo tự nhiên: khoá Spring — áp nền tảng internals này vào framework backend phổ biến nhất của Java, nơi hiểu proxy, classloader và GC giúp bạn debug những vấn đề mà đọc docs không giải được.

Java production-grade engineering không phải về việc viết được nhiều code — mà về việc debug code khi nó đi sai trên production. Bạn vừa thực hành đúng kỹ năng đó.