Java Performance Analysis – Section Four – JVM Monitoring on Linux

Monitoring and Performance Analysis

Monitoring

Monitoring typically refers to a proactive or preventive activity in production, quality assessment, or development environments. When the application owner receives performance issues without sufficient clues to locate the problem, they will first check performance monitoring, followed by performance analysis.

Performance Analysis

Performance analysis is an intrusive activity that collects runtime performance data, which can affect the application’s throughput or response time. Performance analysis is a response after monitoring alerts, focusing on more concentrated monitoring.

JVM Monitoring

1. JVM Memory Monitoring on Linux

Common JVM memory commands on Linux can be found in Section Three of Java Performance Analysis – Memory Monitoring on Linux.

2. Code Implementation for Printing JVM Monitoring

/**
     * Format bytes
     */
private static String formatBytes(long bytes) {
    if (bytes < 0) return "N/A";
    if (bytes < 1024) return bytes + " B";
    if (bytes < 1024 * 1024) return String.format("%.2f KB", bytes / 1024.0);
    if (bytes < 1024 * 1024 * 1024) return String.format("%.2f MB", bytes / (1024.0 * 1024));
    return String.format("%.2f GB", bytes / (1024.0 * 1024 * 1024));
}

/**
     * Print memory information
     */
public static void printMemoryInfo() {
    MemoryMXBean memoryMXBean = ManagementFactory.getMemoryMXBean();

    // Heap memory
    MemoryUsage heapMemory = memoryMXBean.getHeapMemoryUsage();
    System.out.println("=== Heap Memory Information ===");
    System.out.println("Initial Size: " + formatBytes(heapMemory.getInit()));
    System.out.println("Used: " + formatBytes(heapMemory.getUsed()));
    System.out.println("Committed: " + formatBytes(heapMemory.getCommitted()));
    System.out.println("Max: " + formatBytes(heapMemory.getMax()));
    System.out.println("Usage Rate: " + String.format("%.2f%%", (double) heapMemory.getUsed() / heapMemory.getMax() * 100));

    // Non-heap memory
    MemoryUsage nonHeapMemory = memoryMXBean.getNonHeapMemoryUsage();
    System.out.println("\n=== Non-Heap Memory Information ===");
    System.out.println("Used: " + formatBytes(nonHeapMemory.getUsed()));
    System.out.println("Committed: " + formatBytes(nonHeapMemory.getCommitted()));

    // Detailed information of each memory pool
    System.out.println("\n=== Detailed Memory Pool Information ===");
    List<MemoryPoolMXBean> memoryPools = ManagementFactory.getMemoryPoolMXBeans();
    for (MemoryPoolMXBean pool : memoryPools) {
        MemoryUsage usage = pool.getUsage();
        System.out.println("\nMemory Pool: " + pool.getName());
        System.out.println("  Type: " + pool.getType());
        System.out.println("  Used: " + formatBytes(usage.getUsed()));
        System.out.println("  Max: " + formatBytes(usage.getMax()));
        if (usage.getMax() > 0) {
            System.out.println("  Usage Rate: " + String.format("%.2f%%", (double) usage.getUsed() / usage.getMax() * 100));
        }
    }
}

/**
     * Print GC information
     */
public static void printGCInfo() {
    System.out.println("\n=== GC Information ===");
    List<GarbageCollectorMXBean> gcBeans = ManagementFactory.getGarbageCollectorMXBeans();

    for (GarbageCollectorMXBean gc : gcBeans) {
        System.out.println("\nGC Name: " + gc.getName());
        System.out.println("  Collection Count: " + gc.getCollectionCount());
        System.out.println("  Collection Time: " + gc.getCollectionTime() + " ms");
        System.out.println("  Memory Pool: " + String.join(", ", gc.getMemoryPoolNames()));

        // Average time per GC
        if (gc.getCollectionCount() > 0) {
            System.out.println("  Average Time per Collection: " + String.format("%.2f ms", (double) gc.getCollectionTime() / gc.getCollectionCount()));
        }
    }
}

3. Remote Monitoring via JMX

To enable JMX remote monitoring, add the following configuration to the JVM startup parameters:

java -Dcom.sun.management.jmxremote \
     -Dcom.sun.management.jmxremote.port=9999 \
     -Dcom.sun.management.jmxremote.authenticate=false \
     -Dcom.sun.management.jmxremote.ssl=false \
     -jar your-app.jar

Code Implementation

/**
     * Connect to remote JVM
     */
public static MBeanServerConnection connectToRemoteJVM(String host, int port) throws Exception {
    String url = "service:jmx:rmi:///jndi/rmi://" + host + ":" + port + "/jmxrmi";
    JMXServiceURL serviceURL = new JMXServiceURL(url);
    JMXConnector connector = JMXConnectorFactory.connect(serviceURL);
    return connector.getMBeanServerConnection();
}

/**
     * Get memory information from remote JVM
     */
public static void getRemoteMemoryInfo(MBeanServerConnection mbsc) throws Exception {
    ObjectName memoryBean = ObjectName.getInstance("java.lang:type=Memory");

    // Get heap memory
    CompositeData heapMemory = (CompositeData) mbsc.getAttribute(memoryBean, "HeapMemoryUsage");
    long used = (Long) heapMemory.get("used");
    long max = (Long) heapMemory.get("max");

    System.out.println("Remote JVM Heap Memory:");
    System.out.println("  Used: " + formatBytes(used));
    System.out.println("  Max: " + formatBytes(max));
    System.out.println("  Usage Rate: " + String.format("%.2f%%", (double) used / max * 100));
}

/**
     * Get GC information from remote JVM
     */
public static void getRemoteGCInfo(MBeanServerConnection mbsc) throws Exception {
    ObjectName gcQuery = ObjectName.getInstance("java.lang:type=GarbageCollector,*");
    Set<ObjectName> gcNames = mbsc.queryNames(gcQuery, null);

    System.out.println("\nRemote JVM GC Information:");
    for (ObjectName gcName : gcNames) {
        String name = (String) mbsc.getAttribute(gcName, "Name");
        Long count = (Long) mbsc.getAttribute(gcName, "CollectionCount");
        Long time = (Long) mbsc.getAttribute(gcName, "CollectionTime");

        System.out.printf("  %s: Count=%d, Time=%dms%n", name, count, time);
    }
}

4. -XX:+PrintGCDetails

<span>java -XX:+PrintGCDetails -jar your-application.jar </span>, note that this should be used cautiously in production environments

[44.881s][info   ][gc,start    ] GC(3) Pause Young (Prepare Mixed) (G1 Evacuation Pause)
[44.881s][info   ][gc,task     ] GC(3) Using 9 workers of 9 for evacuation
[44.886s][info   ][gc,phases   ] GC(3)   Pre Evacuate Collection Set: 0.2ms
[44.886s][info   ][gc,phases   ] GC(3)   Merge Heap Roots: 0.1ms
[44.886s][info   ][gc,phases   ] GC(3)   Evacuate Collection Set: 3.9ms
[44.886s][info   ][gc,phases   ] GC(3)   Post Evacuate Collection Set: 0.6ms
[44.886s][info   ][gc,phases   ] GC(3)   Other: 0.1ms
[44.886s][info   ][gc,heap     ] GC(3) Eden regions: 510->0(549)
[44.886s][info   ][gc,heap     ] GC(3) Survivor regions: 5->10(65)
[44.886s][info   ][gc,heap     ] GC(3) Old regions: 8->8
[44.886s][info   ][gc,heap     ] GC(3) Humongous regions: 0->0
[44.886s][info   ][gc,metaspace] GC(3) Metaspace: 33276K(33920K)->33276K(33920K) NonClass: 28938K(29312K)->28938K(29312K) Class: 4338K(4608K)->4338K(4608K)
[44.886s][info   ][gc          ] GC(3) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 521M->16M(1024M) 5.087ms
[44.886s][info   ][gc,cpu      ] GC(3) User=0.02s Sys=0.01s Real=0.01s

Basic Information

Field Value Explanation Interpretation
Trigger Reason G1 Evacuation Pause G1 evacuation pause Normal object copying/evacuation process

Parallel Worker Threads

Field Value Explanation Interpretation
Using X workers of Y 9 / 9 Used 9 threads out of 9 available 🟢 Thread utilization 100%, maximized parallelism

GC Phase Duration Details

Phase Duration Explanation Interpretation
Pre Evacuate Collection Set 0.2ms Preparation before evacuation: selecting areas to reclaim Selection work is quick, with low overhead
Merge Heap Roots 0.1ms Merging heap root references: consolidating GC root objects Few root objects, processing is fast
Evacuate Collection Set 3.9ms Evacuation collection: copying live objects to new areas 🔴 Main duration (76%), many live objects
Post Evacuate Collection Set 0.6ms Post-evacuation processing: updating references, cleanup work Subsequent processing overhead is reasonable
Other 0.1ms Other miscellaneous time Other overhead is negligible

Heap Memory Region Changes

Region Change (Before→After) Capacity Explanation Interpretation
Eden regions 510 → 0 (549) New object allocation area, cleared after GC 🟢 Reclaimed 510 regions, recovery rate 100%
Survivor regions 5 → 10 (65) Temporary storage area for live objects 🟡 Live objects doubled, indicating many objects promoted
Old regions 8 → 8 Old generation area 🟢 Old generation has not increased, pressure is low
Humongous regions 0 → 0 Large object area (objects larger than 50% of region size) 🟢 No large objects, low risk of memory fragmentation

Region Count Explanation:

  • Each region’s default size is usually 1-32MB (depending on heap size)
  • Numbers in parentheses (549), (65) indicate the maximum capacity of that region type

Metaspace (Class Metadata)

Region Change Capacity Explanation Interpretation
Total Metaspace 33276K → 33276K (33920K) Total space for class metadata 🟢 No change, loaded classes stable (usage rate 98%)
NonClass 28938K → 28938K (29312K) Non-class metadata (constant pools, etc.) Usage rate 99%, close to full
Class 4338K → 4338K (4608K) Class metadata Usage rate 94%, within normal range

⚠️ Note: High Metaspace usage (98%), continuous growth may lead to Full GC

Overall GC Effect Summary

Metric Value Explanation Interpretation
Heap Memory Change 521M → 16M Heap usage before and after GC 🟢 Reclaimed 505M (97%), excellent effect
Total Heap Capacity (1024M) Maximum available heap memory Current usage rate only 1.6%, ample space
Total Pause Duration 5.087ms Actual time the application was paused 🟢 < 10ms, imperceptible to users

CPU Resource Usage

CPU Metric Value Explanation Interpretation
User Time 0.02s User mode CPU time (GC thread execution time) 9 threads consumed a total of 0.02s CPU
System Time 0.01s Kernel mode CPU time (system calls) Low overhead for system calls
Real Time 0.01s Actual wall clock time Actual pause 0.01s = 10ms

CPU Utilization Calculation:

CPU Utilization = (User + System) / Real = (0.02 + 0.01) / 0.01 = 300%

Interpretation: Good multithreading parallel effect, 9 threads achieve 300% CPU utilization (3 cores fully loaded)

5. OutOfMemoryError: Metaspace

Metaspace memory overflow is generally caused by cyclic generation of proxy classes or frequent loading of a large number of third-party libraries.

public String testMetapace() {
    System.out.println("Starting Metaspace overflow test...");
    System.out.println("Current MaxMetaspaceSize: " + Runtime.getRuntime().maxMemory() / 1024 / 1024 + "MB");

    List<Object> proxyList = new ArrayList<>();
    int count = 0;
    try {
        while (true) {
            // Create a new ClassLoader, creating a new class each time
            ClassLoader classLoader = Demo1Application.class.getClassLoader();

            // Create dynamic proxy
            Object proxy = createDynamicProxy(classLoader);
            proxyList.add(proxy);

            count++;
            if (count % 1000 == 0) {
                System.out.println("Number of proxy classes created: " + count);
                printMemoryInfo();
            }
        }
    } catch (Exception e) {
        System.err.println("\n=== OutOfMemoryError Occurred ===");
        System.err.println("Error Message: " + e.getMessage());
        System.err.println("Total created proxy classes: " + count);
        printMemoryInfo();
        e.printStackTrace();
    }
    return "Metaspace overflow test completed";
}

/**
 * Create dynamic proxy object
 */
private static Object createDynamicProxy(ClassLoader classLoader) {
    return Proxy.newProxyInstance(
        classLoader,
        new Class<?>[]{TestInterface.class},
        new TestInvocationHandler()
    );
}

Leave a Comment