Thursday, January 3, 2013

JConsole and Memory Usage

JConsole is a GUI provided by Java. It's shipped with the JDK. It can report on memory usage of a remote java application. In order to use it successfully, you must define some java system properties. For example, if you want to monitor a Tomcat application, you might make the following changes.

vi /opt/apache-tomcat-7.0.25/bin/catalina.sh

# after this
elif [ "$1" = "start" ] ; then

# add this
JAVA_OPTS="$JAVA_OPTS -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9999 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=$(hostname)"

Restart tomcat to pickup the changes.

com.sun.management.jmxremote -- Required. Enables JMX.

com.sun.management.jmxremote.port -- Required. This can be any unused port. You will specify it when connecting to this box with JConsole.

com.sun.management.jmxremote.authenticate -- If false then no authentication is required. Anyone who can see your jmxremote.port will be able to connect with JConsole. If you open that port only to your Windows-Box-IP, that's probably okay. If true you may need to specify the passwords file. See below.

com.sun.management.jmxremote.ssl -- If not false, extra config is required.

java.rmi.server.hostname -- Required. This must resolve to the IP by which your JConsole will address this box. If you have an EC2 instance in a VPC with a private IP and an EIP, specify the EIP here. If your DNS is setup correctly the $(hostname) variable already defined in catalina.sh should work fine.

You may additionally specify these, although the above config where they are not defined worked okay for me.

java.security.policy -- Never used this. More info here.

com.sun.management.jmxremote.local.only -- Never used this. More info here.

com.sun.management.jmxremote.password.file -- May be required when jmxremote.authenticate=true. More info here.

java.rmi.server.useLocalHostname -- Some examples advise setting this to false, but in my tests it had no effect.

Not only is java.rmi.server.hostname required, but even if you specify it as an IP you may get the following error.

Error: Exception thrown by the agent : java.net.MalformedURLException: Local host name unknown: java.net.UnknownHostException: ip-10-0-0-138: ip-10-0-0-138: Name or service not known

That error was on an amazon linux image in a VPC and my DNS wasn't working. hostname did report "ip-10-0-0-138" but pinging that didn't resolve to an IP. For whatever reason, that is fatal to the above RMI config, even if you specify java.rmi.server.hostname as the IP. To work around this, manually map the DNS in your hosts file.

hostname
 ip-10-0-0-138

ping ip-10-0-0-138
 ping: unknown host ip-10-0-0-138

vi /etc/hosts
 IP_FROM_RMI_SERVER_HOSTNAME_ABOVE ip-10-0-0-138
 127.0.0.1   localhost localhost.localdomain

Finally you must open up your firewall (and/or Security Group if you're in Amazon EC2). It is not sufficient to open your jmxremote.port as JMX seems to open other connections on random ports. This can probably be imporved, but in order to get it working I opened all ports inbound and outbound for the IP from which I would connect with JConsole.

Allow Inbound
 0 - 65535   YOUR_JCONSOLE_BOX_IP/32
Allow Outbound
 0 - 65535   YOUR_JCONSOLE_BOX_IP/32

Having configured and successfully restarted Tomcat on the target Linux box, and having opened all ports for connection to/from the machine on which you will run JConsole, you can now launch JConsole.

C:\Program Files\Java\jdk1.7.0_03\bin\jconsole.exe

In the "New Connection" dialog, select "Remote Process" and provide <hostname>:<port> such as example.com:9999 or 1.2.3.4:9999. If you set jmxremote.authenticate=false above (as I did) then you can leave the username/password fields blank. Click connect.

The overview tab shows your heap memory usage, classes loaded, and live threads. You're probably also interested in PermGen from the Chart dropdown on the Memory tab. You'll note an increse in these at Tomcat startup and another increase when you hit each web-app for the first time. Heap memory grows steadily until garbage collection kicks in, so it becoms a sawtooth between min and max values. On the memory tab, there is a "Perform GC" button that will force garbage collection, which should drop it to the minimum heap required by your running applicaiton.

  • Heap Memory Usage: 125 Mb (max val that triggers garbage collection)
  • Heap Memory Usage: 56 Mb (min val after garbage collection)
  • Live Threads: 121
  • Classes Loaded: 10,379
  • Memory Pool "Perm Gen" Used: 46 Mb

The following JAVA_OPTS allow you to specify the memory available to your Java process (Tomcat) and thus the resource shared amongst your web-apps.

  • -Xms256M (Heap Memory Committed) (min heap)
  • -Xmx512M (Heap Memory Max) (disk caching may occur after this)
  • -XX:MaxPermSize=128M (Max available for the "Perm Gen" memory pool. If this runs out, you'll see errors like: "java.lang.OutOfMemoryError: PermGen space")

Memory

You can look at memory in a variety of ways.

cat /proc/meminfo | grep Mem
 MemTotal:         615664 kB
 MemFree:            7848 kB

free -m
              total       used       free     shared    buffers     cached
 Mem:           601        593          7          0          1        153
 -/+ buffers/cache:        438        162
 Swap:            0          0          0

vmstat -s
       615664  total memory
       607816  used memory
       532804  active memory
        59680  inactive memory
         7848  free memory

These values disagree with the %mem counts available from ps. stackoverflow helps describe why ps is wrong.

A good description of meminfo is provided on redhat.com. Basically MemFree isn't accurate either. It looks like MemTotal is roughly equal to MemFree + Active + Inactive, and that Inactive can be claimed by other processes. So if you run a process that uses a big chunk of memory then you terminate that process, MemFree may still appear near zero but actually there is a bunch of inactive memory available.

ps -e --format=%mem,cmd | sort -nrk 1 | head -10
 65.7 /opt/...tomcat...
 5.3 /usr/libexec/mysqld...
 0.4 sshd: local [priv]
 0.2 sshd: local@pts/1
 0.2 sendmail: Queue runner@01:00:00 for /var/spool/clientmqueue
 0.2 sendmail: accepting connections
 0.2 ntpd -u ntp:ntp -p /var/run/ntpd.pid -g
 0.2 /bin/sh /usr/bin/mysqld_safe...
 0.2 -bash
 0.1 /usr/sbin/sshd

ps -e --no-headers --format=%mem | awk '{ SUM += $1} END { print SUM }'
 73.4

The VM Summary tab in JConsole agrees with the meminfo count.

Current heap size:        130,127 kbytes
Maximum heap size:        506,816 kbytes
Committed memory:         266,168 kbytes
Total physical memory:    615,664 kbytes
Free physical memory:       6,932 kbytes
Committed virtual memory: 813,460 kbytes

VM arguments: -Xms256M -Xmx512M -XX:MaxPermSize=128M

In JConsole, on the Memory tab, after clicking the "Perform GC" button, I have the following values. Note that heap memory is composed of eden-space, survior-space and tenured-gen, while non-heap memory is composed of code-cache and perm-gen.

Heap Memory Usage             Used:       64,832 kbytes
Heap Memory Usage             Committed: 266,168 kbytes
Heap Memory Usage             Max:       506,816 kbytes

 Memory Pool "Eden Space"     Used:        1,328 kbytes
 Memory Pool "Eden Space"     Committed:  73,472 kbytes
 Memory Pool "Eden Space"     Max:       139,776 kbytes

 Memory Pool "Survivor Space" Used:            0 kbytes
 Memory Pool "Survivor Space" Committed:   9,152 kbytes
 Memory Pool "Survivor Space" Max:        17,472 kbytes

 Memory Pool "Tenured Gen"    Used:       62,662 kbytes
 Memory Pool "Tenured Gen"    Committed: 183,544 kbytes
 Memory Pool "Tenured Gen"    Max:       349,568 kbytes

Non-Heap Memory Usage         Used:       53,784 kbytes
Non-Heap Memory Usage         Committed:  54,016 kbytes
Non-Heap Memory Usage         Max:       180,224 kbytes

 Memory Pool "Code Cache"     Used:        3,953 kbytes
 Memory Pool "Code Cache"     Committed:   4,096 kbytes
 Memory Pool "Code Cache"     Max:        49,152 kbytes

 Memory Pool "Perm Gen"       Used:       49,815 kbytes
 Memory Pool "Perm Gen"       Committed:  49,920 kbytes
 Memory Pool "Perm Gen"       Max:       131,072 kbytes

In this example JConsole reports that Tomcat has committed a total of 266 + 54 = 320 and that it is using 64 + 53 = 117.

# while tomcat is running
cat /proc/meminfo | grep Mem
 MemTotal:         615664 kB
 MemFree:            7080 kB

# after tomcat is shutdown
cat /proc/meminfo | grep Mem
 MemTotal:         615664 kB
 MemFree:          405124 kB

The difference is 398,044 kB which is close to the expected 320M committed above.

# clean micro after reboot
cat /proc/meminfo | grep Mem
 MemTotal:         615664 kB
 MemFree:          539164 kB

This indicates that my tomcat eats 398m and other software (probably mysql in my case) eats 134m, and the OS requires 76m.

{ "loggedin": false, "owner": false, "avatar": "", "render": "nothing", "trackingID": "UA-36983794-1", "description": "Details on JConsole for JMX monitoring of heap and memory usage of Tomcat on a remote Linux or Unix box. This helps you configure Tomcat to launch with enough memory for your applications.", "page": { "blogIds": [ 4 ] }, "domain": "holtstrom.com", "base": "\/michael", "url": "https:\/\/holtstrom.com\/michael\/", "frameworkFiles": "https:\/\/holtstrom.com\/michael\/_framework\/_files.4\/", "commonFiles": "https:\/\/holtstrom.com\/michael\/_common\/_files.3\/", "mediaFiles": "https:\/\/holtstrom.com\/michael\/media\/_files.3\/", "tmdbUrl": "http:\/\/www.themoviedb.org\/", "tmdbPoster": "http:\/\/image.tmdb.org\/t\/p\/w342" }