Tips and tools to analyse JVM

Publié le 5 juillet 2017 par davidhxxx

How to know the memory allocated to the JVM by default (XMS and XMX) ?

It depends on the Java version.
On JVM 8 :
Xms = 1/64 of the physical memory on the machine.
Xmx = 1/4 of the physical memory on the machine.

To check these info whatever the version :
java -XX:+PrintFlagsFinal -version | grep -i 'HeapSize'

Which GC used?

Since Java 8, G1 is recommended.

Select the GC

Use CMS GC :
-XX:+UseConcMarkSweepGC
Use G1 GC :
-XX:+UseG1GC

How to work the Heap Memory

Role : storing objects.
2 areas :
– Young Generation Space
– Old/Tenured Space

Young Generation

2 areas :
– Eden Space
– Survivor Space

Eden Space: When we create an object, the memory will be allocated from the Eden Space.
Survivor Space: This contains the objects that have survived from the Young garbage collection or Minor garbage collection. Two spaces insides : S0 and S1.

Tenured or Old Generation Space

Objects which reach to max tenured threshold during the minor GC or young GC, will be moved to Tenured or Old Generation Space.

Common issues with heap

Old generation highly used: means that objects are retained during a very long time.
Young generation highly used: means that one or several current processing consume much memory.

Understand GC info from jcmd GC.heap_info

With CMS GC

The output shows the young space info and the old space info.
To know the real heap used, we need to sum them.
Example : 

28276:
 par new generation   total 105152K, used 63076K [0x00000006ab400000, 0x00000006b2610000, 0x00000006ca730000)
  eden space 93504K,  55% used [0x00000006ab400000, 0x00000006ae639340, 0x00000006b0f50000)
  from space 11648K, 100% used [0x00000006b1ab0000, 0x00000006b2610000, 0x00000006b2610000)
  to   space 11648K,   0% used [0x00000006b0f50000, 0x00000006b0f50000, 0x00000006b1ab0000)
 concurrent mark-sweep generation total 338368K, used 192322K [0x00000006ca730000, 0x00000006df1a0000, 0x0000000800000000)
 Metaspace       used 54027K, capacity 55838K, committed 56080K, reserved 1097728K
  class space    used 6873K, capacity 7583K, committed 7676K, reserved 1048576K

Explanations :
par new generation total 105152K, used 63076K :
total : the size allocated to the new generation
used : the size really used by the app.

concurrent mark-sweep generation total 338368K, used 192322K :
total : the size allocated to the old generation
used : the size really used by the app.

With G1

The output shows the young space info and the all gen heap info but we don’t have details about old space info used.
While we could still deem the old space used by substracting the all gen heap used to the young heap used.
Example : 

20090:
 garbage-first heap   total 122880K, used 35830K [0x00000006ab400000, 0x0000000800000000)
  region size 1024K, 2 young (2048K), 0 survivors (0K)
 Metaspace       used 53646K, capacity 55508K, committed 55808K, reserved 1097728K
  class space    used 6876K, capacity 7583K, committed 7680K, reserved 1048576K

Explanations :
garbage-first heap total 122880K, used 35830K :
total : the size allocated to the heap
used : the size really used by the app.

region size 1024K, 2 young (2048K), 0 survivors (0K) :
young : the size used by the young generation
survivors : todo

JVM Flags to capture heap, GC and threads information

JVM flags to enable the GC logs

– The minimal argument :

-verbose:gc

It produces very minimalist output.

GC type – Memory used before GC -> Memory used after GC (heap size), duration of the collect

[GC (Allocation Failure)  524800K->38559K(2010112K), 0.1192019 secs]
[GC (Allocation Failure)  563359K->73184K(2534912K), 0.1574194 secs]
[GC (Allocation Failure)  1122784K->150192K(2534912K), 0.5188990 secs]
[GC (Allocation Failure)  1199792K->228186K(2708992K), 0.2588466 secs]
[GC (Allocation Failure)  1451866K->320412K(2708992K), 0.3597946 secs]
[GC (Allocation Failure)  1544092K->413344K(2376192K), 0.3852612 secs]

– To get more details, dates and specify a log file :

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:D:\my-gc.log  

2017-07-05T11:52:17.021+0200: 2.228: [GC (Allocation Failure) [PSYoungGen: 65536K->8369K(76288K)] 65536K->8377K(251392K), 0.0139402 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2017-07-05T11:52:17.231+0200: 2.439: [GC (Allocation Failure) [PSYoungGen: 73905K->9760K(76288K)] 73913K->9768K(251392K), 0.0232961 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
2017-07-05T11:52:17.450+0200: 2.657: [GC (Allocation Failure) [PSYoungGen: 75296K->10736K(76288K)] 75304K->14287K(251392K), 0.0378601 secs] [Times: user=0.11 sys=0.02, real=0.04 secs] 
2017-07-05T11:52:17.680+0200: 2.887: [GC (Allocation Failure) [PSYoungGen: 76272K->10720K(141824K)] 79823K->18992K(316928K), 0.0205512 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
2017-07-05T11:52:18.120+0200: 3.328: [GC (Allocation Failure) [PSYoungGen: 141792K->10720K(141824K)] 150064K->28456K(316928K), 0.0483284 secs] [Times: user=0.11 sys=0.02, real=0.05 secs] 
2017-07-05T11:52:18.499+0200: 3.706: [GC (Allocation Failure) [PSYoungGen: 141792K->20262K(282624K)] 159528K->37998K(457728K), 0.0309031 secs] [Times: user=0.11 sys=0.00, real=0.03 secs]

JVM flags to generate a heap dump on outOfMemoryError

By default the dump is generated in the directory where the process was launched but we can instead of specify the dump location or the folder to use :
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\my-heap-dump.log

JVM flags to generate a thread dump

-XX:OnOutOfMemoryError= »kill -3 pid %p »

How the JVM monitoring works

To enable tools as JCMD or JStack to monitor/interact with a JVM, a feature is required.
That is enabled via a flag enabled by default : -XX:-UsePerfData

Enables the perfdata feature. This option is enabled by default to allow JVM monitoring and performance testing. Disabling it suppresses the creation of the hsperfdata_userid directories. To disable the perfdata feature, specify -XX:-UsePerfData.

The perfdata is a binary(or socket maybe) with as filename the pid of the JVM that it monitors.
Location : /tmp/hsperfdata_fooUserId where fooUserId is the user that launched the JVM.

Metaspaces

When -XX:+UseCompressedClassPointers option is ON (default for heaps < 32G), classes are moved from Metaspace to the separate area called Compressed Class Space. This is to allow addressing VM class structures with 32-bit values instead of 64-bit.
So, Compressed Class Space contains internal representation of Java classes, while Metaspace holds all the rest metadata: methods, constant pools, annotations, etc.

The size of Compressed Class Space is limited by
-XX:CompressedClassSpaceSize which is 1G by default.
By example to limit that to 300MB : -XX:CompressedClassSpaceSize=300m

Tools to list Java processes

jps
Syntax : jps [ options ] [ hostid ]

* hostid
Syntax : [protocol:][[//]hostname][:port][/servername]

* Helpful options:
-q : print only process ids
-m : Displays arguments passed to the main method. May be null for embedded JVMs.
-l : Displays the full package name for the application’s main class or the full path name to the application’s JAR file.
-v : Displays the arguments passed to the JVM.

Tools to Manage Java processes

Complete UI tools : visualvm and jconsole
These are free and complete tools to analyse JVM

Specialized UI tools
– Eclipse memory analyzer : Java heap analyzer that helps you find memory leaks and reduce memory consumption.

JMX protocol
That has to be enabled in the running JVM.
It is quite low level protocol to query (select and update) the JVM state.
Most of high tools rely on that to capture/interact with a JVM process.

jcmd
Utility to send diagnostic command requests to the JVM allowing to perform Java Flight Recordings and diagnose JVM.

jstack
Utility to generate thread dump.

JCMD Details

Requirements
– used on the same machine where the JVM is running

Common errors

Symptom : the JVM process is not displayed in the list or executing any jmcd command on it fails.
Possible causes :
– execute jcmd with the same user and group identifiers that were used to launch the JVM.
– check that the socket created to allow the remote connection was not deleted. You can find it in /tmp/.java_pid1234

General commands

Execute a command on the specified jvm :
jcmd JAVA_PID JCMD_COMMAND :

Print the list of running JVMs : pid along the main class and command-line arguments that were used to launch the process :
jcmd

List available commands :
jcmd JAVA_PID help

Documentation for a specific command :
jcmd JAVA_PID help JCMD_COMMAND

Helpful commands

GC.heap_info
Provide generic Java heap information.
Impact: Medium

Thread.print
Print all threads with stacktraces
Impact: Medium: Depends on the number of threads.

GC.class_histogram
Print a table with the num of instances and of occupied bytes for each class
Impact: High: Depends on Java heap size and content.

GC.heap_dump ABSOLUTE-FILE
Generate a HPROF format dump of the Java heap store it into the ABSOLUTE-FILE param
Impact: High: Depends on Java heap size and content. Request a full GC unless the ‘-all’ option is specified.

GC.run
Call java.lang.System.gc().
Impact: Medium: Depends on Java heap size and content.

VM.uptime
Print VM uptime.
Impact: Low

VM.dynlibs
Print loaded dynamic libraries.
Impact: Low

VM.flags
Print VM flag options and their current values.
Impact: Low

VM.system_properties
Print system properties.
Impact: Low

VM.command_line
Print the command line used to start this VM instance.
Impact: Low

VM.version
Print JVM version information.
Impact: Low

GC.rotate_log : rotate gc logs
Force the GC log file to be rotated.
Impact: Low

GC.run_finalization
Call java.lang.System.runFinalization().
Impact: Medium: Depends on Java content.

Jstack Details

* create a thread dump of a java process : jstack -l PID
* force the creation of the thread dump of a java process : jstack -F PID

*Running a process with sh -c such as : sh -c « cd /foo && java -jar my.jar » & create two processes : the sh process and the java process

Tools to analyze logs/dump

GC logs :
– Eclipse plugin : IBM Monitoring and Diagnostic Tools – Garbage Collection and Memory Visualizer (GCMV)
– …

Heap dump in HPROF format:
– Eclipse memory analyzer (standalone version exists)
– VisualVM

Scripting

Script to perform thread dumps if a memory amount is reached

With JCMD and shell
To run that in background :
nohup ./track-memory.sh log.txt & 

#!/bin/bash
To complete

Simple code to perform thread dumps every seconds for a specific JVM

i=0; while true; do jcmd 7777 Thread.print > details-$i.txt; sleep 1s; i=$(( $i+1 )); done

Ce contenu a été publié dans Non classé. Vous pouvez le mettre en favoris avec ce permalien.

Laisser un commentaire

Votre adresse de messagerie ne sera pas publiée. Les champs obligatoires sont indiqués avec *