Saturday, April 30, 2016

Programmatic jcmd Access

Questions posed online demonstrate the occasional desire of developers to access via their Java applications the types of information normally gained from running JConsole, VisualVM, or JDK command-line tools externally against the application. Here are some examples of those types of questions:

I recently blogged on the usefulness of jcmd. This "Swiss-army knife" of command-line JDK tools provides much information about running Java processes and many of the types of information developers might want to acquire programatically are available via jcmd.

The Tools Enhancements in JDK 8 page states, "JDK 8 provides remote access to diagnostic commands which were previously accessible only locally via the jcmd tool. Remote access is provided using the Java Management Extensions (JMX), so diagnostic commands are exposed to a platform MBean registered to the platform MBean server. The MBean is the com.sun.management.DiagnosticCommandMBean interface." In the post Looking at DiagnosticCommandMBean in JConsole and VisualVM, I looked at using JMX and DiagnosticCommandMBean via JConsole and VisualVM to access jcmd type information on a running JVM process.

In this post I look at how to use com.sun.management.DiagnosticCommandMBean to programmatically access information provided by jcmd.

The DiagnosticCommandMBean is accessed via JMX using the ObjectName "com.sun.management:type=DiagnosticCommand". Most of the operations require no arguments and return a String. With this in mind, a general approach to accessing these operations that have String[] signatures, a String return type, and don't actually require a parameter is shown in the following code snippet.

Setting Up DiagnosticCommandMBean and General Method for Accessing Operations of Same Signature
   /** Object Name of DiagnosticCommandMBean. */
   public final static String DIAGNOSTIC_COMMAND_MBEAN_NAME =
      "com.sun.management:type=DiagnosticCommand";

   /** My MBean Server. */
   private final MBeanServer server = ManagementFactory.getPlatformMBeanServer();

   /** Platform MBean Server. */
   private final ObjectName objectName;

   //  . . .

   /**
    * Invoke operation on the DiagnosticCommandMBean that accepts
    *    String array argument but does not require any String
    *    argument and returns a String.
    *
    * @param operationName Name of operation on DiagnosticCommandMBean.
    * @param operationDescription Description of operation being invoked
    *    on the DiagnosticCommandMBean.
    * @return String returned by DiagnosticCommandMBean operation.
    */
   private String invokeNoStringArgumentsCommand(
      final String operationName, final String operationDescription)
   {
      String result;
      try
      {
         result = (String) server.invoke(objectName, operationName, new Object[] {null}, new String[]{String[].class.getName()});
      }
      catch (InstanceNotFoundException | ReflectionException | MBeanException exception)
      {
         result = "ERROR: Unable to access '" + operationDescription + "' - " + exception;
      }
      return result;
   }

With the code above in place, the method invokeNoStringArgumentsCommand(String, String) can be used to access several of the operations that DiagnosticCommandMBean provides. The help sub-command is useful when used with jcmd because it lists the available sub-commands associated with a specified Java process. Likewise, the "help" operation provided by the DiagnosticCommandMBean is similarly helpful in providing a list of commands that the MBean supports. This is easy to access with the code shown next that uses the code just shown.

/**
 * Provide list of supported operations (help).
 *
 * @return Single string containing names of supported operations.
 */
public String getAvailableOperations()
{
   return invokeNoStringArgumentsCommand("help", "Help (List Commands)");
}

Running this from a simple Java application leads to output similar to that shown next:

The following commands are available:
JFR.stop
JFR.start
JFR.dump
JFR.check
VM.native_memory
VM.check_commercial_features
VM.unlock_commercial_features
GC.rotate_log
Thread.print
GC.class_stats
GC.class_histogram
GC.run_finalization
GC.run
VM.uptime
VM.flags
VM.system_properties
VM.command_line
VM.version
help

For more information about a specific command use 'help '.

In my blog post Determining the Active HotSpot Garbage Collector, I wrote that jcmd can be used to identify the VM flags of a running Java process and that, from those flags, one can glean which garbage collector is in use. Because the DiagnosticCommandMBean supports the VM.flags operation as shown above, this operation can be used to view the VM flags and, from those flags, determine which collector is in use. The next code listing shows two example methods with the first accessing the VM flags of the process and the second method providing a simplistic example of how to use the first method to identify the garbage collector in use.

Obtain Virtual Machine Flags and Identify Active Garbage Collector
/**
 * Provide a String representing the Virtual Machine flags.
 *
 * @return String containing the virtual machine flags.
 */
public String getVirtualMachineFlags()
{
   return invokeNoStringArgumentsCommand("vmFlags", "Determine VM flags");
}

/**
 * Provide String representing active/current garbage collector.
 *
 * @return String representation of current garbage collector
 *    ("Parallel/Throughput", "Concurrent Mark Sweep (CMS)",
 *    "Garbage First", or "UNDETERMINED").
 */
public String determineGarbageCollector()
{
   String garbageCollector;
   final String vmFlags = getVirtualMachineFlags();
   if (vmFlags.contains("+UseParallelGC") || vmFlags.contains("+UseParallelOldGC"))
   {
      garbageCollector = "Parallel/Throughput";
   }
   else if (vmFlags.contains("+UseConcMarkSweepGC"))
   {
      garbageCollector = "Concurrent Mark Sweep (CMS)";
   }
   else if (vmFlags.contains("+UseG1GC"))
   {
      garbageCollector = "Garbage First";
   }
   else
   {
      garbageCollector = "UNDETERMINED";
   }
   return garbageCollector;
}

The String with the VM flags and the output of the identified garbage collector are shown next:

-XX:CICompilerCount=3 -XX:InitialHeapSize=134217728 -XX:MaxHeapSize=2128609280 -XX:MaxNewSize=709361664 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=44564480 -XX:OldSize=89653248 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
Parallel/Throughput

The examples already shown (accessing help and VM flags) are demonstrative of the same general approach that can be used to programmatically access other operations on DiagnosticCommandMBean with the same signature. A series of code listings and corresponding output are shown next to illustrate some of these.

Accessing Virtual Machine Uptime
/**
 * Provide virtual machine uptime as single String.
 *
 * @return Single string containing virtual machine uptime.
 */
public String getVirtualMachineUptime()
{
   return invokeNoStringArgumentsCommand("vmUptime", "Virtual Machine Uptime");
}
0.272 s
Accessing Thread Dump
/**
 * Provide thread dump as single String.
 *
 * @return Single string containing formatted thread dump.
 */
public String getThreadDump()
{
   return invokeNoStringArgumentsCommand("threadPrint", "Thread Dump");
}
2016-04-30 20:21:22
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.25-b02 mixed mode):

"Monitor Ctrl-Break" #10 daemon prio=5 os_prio=0 tid=0x00000000189ea800 nid=0x1590 runnable [0x000000001903e000]
   java.lang.Thread.State: RUNNABLE
 at java.net.DualStackPlainSocketImpl.accept0(Native Method)
 at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketImpl.java:131)
 at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
 at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:199)
 - locked <0x0000000081208810> (a java.net.SocksSocketImpl)
 at java.net.ServerSocket.implAccept(ServerSocket.java:545)
 at java.net.ServerSocket.accept(ServerSocket.java:513)
 at com.intellij.rt.execution.application.AppMain$1.run(AppMain.java:90)
 at java.lang.Thread.run(Thread.java:745)

"Service Thread" #9 daemon prio=9 os_prio=0 tid=0x0000000018915800 nid=0x2468 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x0000000017087000 nid=0x17a0 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x0000000017080000 nid=0x1560 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001707d000 nid=0x2004 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001707b000 nid=0x2160 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001707a000 nid=0x458 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x00000000024f7000 nid=0x1964 in Object.wait() [0x00000000183ef000]
   java.lang.Thread.State: WAITING (on object monitor)
 at java.lang.Object.wait(Native Method)
 - waiting on <0x0000000081201570> (a java.lang.ref.ReferenceQueue$Lock)
 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)
 - locked <0x0000000081201570> (a java.lang.ref.ReferenceQueue$Lock)
 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)
 at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x00000000024ee000 nid=0x270c in Object.wait() [0x00000000182ef000]
   java.lang.Thread.State: WAITING (on object monitor)
 at java.lang.Object.wait(Native Method)
 - waiting on <0x0000000081208c28> (a java.lang.ref.Reference$Lock)
 at java.lang.Object.wait(Object.java:502)
 at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
 - locked <0x0000000081208c28> (a java.lang.ref.Reference$Lock)

"main" #1 prio=5 os_prio=0 tid=0x0000000000c4e000 nid=0x24f8 waiting on condition [0x0000000000dee000]
   java.lang.Thread.State: RUNNABLE
 at sun.management.DiagnosticCommandImpl.executeDiagnosticCommand(Native Method)
 at sun.management.DiagnosticCommandImpl.access$000(DiagnosticCommandImpl.java:40)
 at sun.management.DiagnosticCommandImpl$Wrapper.execute(DiagnosticCommandImpl.java:128)
 at sun.management.DiagnosticCommandImpl.invoke(DiagnosticCommandImpl.java:230)
 at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819)
 at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801)
 at dustin.examples.diagnostics.VirtualMachineDiagnostics.invokeNoStringArgumentsCommand(VirtualMachineDiagnostics.java:167)
 at dustin.examples.diagnostics.VirtualMachineDiagnostics.getThreadDump(VirtualMachineDiagnostics.java:88)
 at dustin.examples.diagnostics.VirtualMachineDiagnostics.main(VirtualMachineDiagnostics.java:187)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:483)
 at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)

"VM Thread" os_prio=2 tid=0x0000000017046000 nid=0x22b0 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002417800 nid=0x1580 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002419000 nid=0x16d8 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x000000000241a800 nid=0x177c runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x000000000241c800 nid=0x1974 runnable 

"VM Periodic Task Thread" os_prio=2 tid=0x0000000018918000 nid=0x10dc waiting on condition 

JNI global references: 15
Getting Class Histogram
/**
 * Provide class histogram as single String.
 *
 * @return Single string containing formatted class histogram.
 */
public String getHistogram()
{
   return invokeNoStringArgumentsCommand("gcClassHistogram", "GC Class Histogram");
}
 num     #instances         #bytes  class name
----------------------------------------------
   1:          3485         243064  [C
   2:           467         124976  [B
   3:           992         104200  java.lang.Class
   4:          3452          82848  java.lang.String
   5:          1006          46744  [Ljava.lang.Object;
   6:           525          46200  java.lang.reflect.Method
   7:           309          22248  java.lang.reflect.Field
   8:           519          16608  java.util.HashMap$Node
   9:           326          11760  [Ljava.lang.String;
  10:           211           8968  [I
  11:           434           8312  [Ljava.lang.Class;
  12:            77           7416  [Ljava.util.HashMap$Node;
  13:           179           7160  java.lang.ref.SoftReference
  14:           101           5656  java.lang.Class$ReflectionData
  15:            73           4672  java.net.URL
  16:            97           4656  java.util.HashMap
  17:            89           4560  [Ljava.lang.reflect.Method;
  18:           189           4536  javax.management.ImmutableDescriptor
  19:           279           4464  java.lang.Integer
  20:           139           4448  java.util.Hashtable$Entry
  21:           105           4200  java.util.WeakHashMap$Entry
  22:           129           4128  java.util.concurrent.ConcurrentHashMap$Node
  23:           128           4096  com.sun.jmx.mbeanserver.ConvertingMethod
  24:            90           3600  java.util.TreeMap$Entry
  25:            34           3360  [Ljava.util.WeakHashMap$Entry;
  26:             8           3008  java.lang.Thread
  27:            45           2880  javax.management.openmbean.OpenMBeanAttributeInfoSupport
  28:            87           2784  java.lang.ref.WeakReference
  29:           160           2560  java.lang.Object
  30:            49           2544  [Ljavax.management.MBeanAttributeInfo;
  31:           135           2536  [Lcom.sun.jmx.mbeanserver.MXBeanMapping;
  32:            30           2400  java.lang.reflect.Constructor
  33:            48           2304  javax.management.MBeanInfo
  34:            49           1960  java.io.ObjectStreamField
  35:            60           1920  javax.management.MBeanAttributeInfo
  36:            46           1840  java.util.LinkedHashMap$Entry
  37:            38           1824  sun.util.locale.LocaleObjectCache$CacheEntry
  38:            44           1760  java.lang.ref.Finalizer
  39:            30           1752  [Ljava.lang.reflect.Field;
  40:            36           1728  sun.misc.URLClassPath$JarLoader
  41:             1           1712  [[B
  42:            40           1600  sun.management.DiagnosticCommandArgumentInfo
  43:            31           1488  java.util.WeakHashMap
  44:            60           1440  java.util.ArrayList
  45:            11           1392  [Ljava.util.Hashtable$Entry;
  46:            42           1344  java.lang.ref.ReferenceQueue
  47:             2           1320  [J
  48:            10           1312  [Ljava.util.concurrent.ConcurrentHashMap$Node;
  49:            26           1248  java.util.logging.LogManager$LoggerWeakRef
  50:            47           1120  [Ljavax.management.ObjectName$Property;
  51:             1           1040  [Ljava.lang.Integer;
  52:            39           1008  [Ljavax.management.MBeanOperationInfo;
  53:            24            960  javax.management.ObjectName
  54:            38            912  java.io.ExpiringCache$Entry
  55:            19            912  sun.management.DiagnosticCommandInfo
  56:            18            864  java.util.TreeMap
  57:            12            864  java.util.logging.Logger
  58:            35            840  javax.management.ObjectName$Property
  59:            15            840  javax.management.openmbean.ArrayType
  60:            20            800  com.sun.jmx.mbeanserver.MXBeanSupport
  61:            20            800  javax.management.MBeanOperationInfo
  62:            14            784  sun.nio.cs.UTF_8$Encoder
  63:            32            768  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$IdentityMapping
  64:            12            768  java.util.jar.JarFile
  65:            19            760  sun.util.locale.BaseLocale$Key
  66:            15            720  java.lang.management.PlatformComponent
  67:            44            704  java.lang.ref.ReferenceQueue$Lock
  68:            11            704  java.util.concurrent.ConcurrentHashMap
  69:            21            672  com.sun.jmx.mbeanserver.WeakIdentityHashMap$IdentityWeakReference
  70:             7            672  java.util.jar.JarFile$JarFileEntry
  71:            12            672  java.util.zip.ZipFile$ZipFileInputStream
  72:            19            608  java.util.Locale
  73:            19            608  sun.management.DiagnosticCommandImpl$Wrapper
  74:            19            608  sun.util.locale.BaseLocale
  75:            18            576  javax.management.MBeanParameterInfo
  76:            10            560  java.util.LinkedHashMap
  77:            14            560  javax.management.openmbean.SimpleType
  78:            23            552  com.sun.jmx.mbeanserver.PerInterface$MethodAndSig
  79:            26            536  [Ljava.lang.reflect.Constructor;
  80:            22            528  com.sun.jmx.mbeanserver.NamedObject
  81:            22            528  sun.reflect.generics.tree.SimpleClassTypeSignature
  82:            13            520  java.security.AccessControlContext
  83:            16            512  java.util.logging.LogManager$LogNode
  84:            17            504  [Ljava.io.ObjectStreamField;
  85:             9            504  javax.management.openmbean.CompositeType
  86:            19            488  [Lsun.management.DiagnosticCommandArgumentInfo;
  87:            12            480  com.sun.jmx.mbeanserver.PerInterface
  88:            20            480  java.lang.Class$AnnotationData
  89:            20            480  java.util.Arrays$ArrayList
  90:            20            480  java.util.jar.Attributes$Name
  91:            19            456  [Ljavax.management.MBeanParameterInfo;
  92:            19            456  java.util.Locale$LocaleKey
  93:            14            448  java.util.concurrent.locks.ReentrantLock$NonfairSync
  94:             8            448  javax.management.openmbean.OpenMBeanParameterInfoSupport
  95:            20            440  [Ljavax.management.MBeanNotificationInfo;
  96:            13            416  java.io.File
  97:            22            408  [Lsun.reflect.generics.tree.TypeArgument;
  98:            10            400  java.io.FileDescriptor
  99:            10            400  sun.reflect.UnsafeQualifiedStaticObjectFieldAccessorImpl
 100:             1            384  java.lang.ref.Finalizer$FinalizerThread
 101:             6            384  java.nio.DirectByteBuffer
 102:             8            384  java.util.Hashtable
 103:             1            384  java.util.logging.LogManager$Cleaner
 104:            12            384  java.util.zip.ZipCoder
 105:             1            376  java.lang.ref.Reference$ReferenceHandler
 106:            15            360  javax.management.StandardMBean
 107:            22            352  sun.reflect.generics.tree.ClassTypeSignature
 108:             4            336  [D
 109:             7            336  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$CompositeMapping
 110:             6            336  java.nio.DirectLongBufferU
 111:            14            336  java.util.concurrent.CopyOnWriteArrayList
 112:             6            336  sun.management.MemoryPoolImpl
 113:            14            336  sun.reflect.NativeConstructorAccessorImpl
 114:            16            328  [Ljava.lang.management.PlatformComponent;
 115:             4            320  [S
 116:            13            312  java.lang.management.ManagementPermission
 117:             9            288  java.lang.OutOfMemoryError
 118:            12            288  java.util.ArrayDeque
 119:            12            288  java.util.Collections$SingletonList
 120:             9            288  java.util.logging.Level
 121:            12            288  sun.misc.MetaIndex
 122:             5            280  sun.util.calendar.ZoneInfo
 123:             8            256  sun.misc.ProxyGenerator$PrimitiveTypeInfo
 124:             2            240  java.net.SocksSocketImpl
 125:             6            240  sun.management.MemoryPoolImpl$CollectionSensor
 126:             6            240  sun.management.MemoryPoolImpl$PoolSensor
 127:             6            240  sun.reflect.generics.repository.MethodRepository
 128:            14            224  java.util.concurrent.locks.ReentrantLock
 129:            14            224  sun.reflect.DelegatingConstructorAccessorImpl
 130:            13            216  [Ljavax.management.MBeanConstructorInfo;
 131:             9            216  java.util.logging.Level$KnownLevel
 132:             9            216  sun.util.logging.PlatformLogger$Level
 133:            10            208  [Ljava.lang.reflect.Type;
 134:             5            200  java.lang.ClassLoader$NativeLibrary
 135:             6            192  java.util.Vector
 136:             8            192  sun.reflect.generics.factory.CoreReflectionFactory
 137:             6            192  sun.reflect.generics.tree.MethodTypeSignature
 138:             2            176  java.net.DualStackPlainSocketImpl
 139:             9            168  [Lsun.reflect.generics.tree.FieldTypeSignature;
 140:             3            168  javax.management.openmbean.OpenMBeanOperationInfoSupport
 141:             9            160  [Lsun.reflect.generics.tree.FormalTypeParameter;
 142:             5            160  java.io.FileInputStream
 143:             4            160  java.security.ProtectionDomain
 144:             5            160  javax.management.MBeanNotificationInfo
 145:             5            160  javax.management.StandardEmitterMBean
 146:             6            144  java.util.LinkedList$Node
 147:             3            144  java.util.Properties
 148:             6            144  sun.misc.PerfCounter
 149:             6            144  sun.reflect.generics.reflectiveObjects.ParameterizedTypeImpl
 150:             6            144  sun.reflect.generics.scope.MethodScope
 151:             4            128  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$ArrayMapping
 152:             2            128  java.io.ExpiringCache$1
 153:             4            128  java.security.CodeSource
 154:             8            128  java.util.HashSet
 155:             4            128  java.util.LinkedList
 156:             1            120  [[Ljava.lang.String;
 157:             5            120  sun.misc.FloatingDecimal$PreparedASCIIToBinaryBuffer
 158:             2            112  java.lang.Package
 159:             2            112  java.util.zip.ZipFile$ZipFileInflaterInputStream
 160:             1             96  [Ljava.lang.invoke.MethodType;
 161:             6             96  [Lsun.reflect.generics.tree.TypeSignature;
 162:             3             96  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$EnumMapping
 163:             4             96  java.lang.RuntimePermission
 164:             2             96  java.lang.ThreadGroup
 165:             6             96  java.lang.ThreadLocal
 166:             2             96  java.nio.HeapByteBuffer
 167:             4             96  java.util.Collections$UnmodifiableRandomAccessList
 168:             3             96  java.util.Stack
 169:             2             96  java.util.zip.Inflater
 170:             2             96  javax.management.openmbean.TabularType
 171:             2             96  sun.management.GarbageCollectorImpl
 172:             2             96  sun.nio.cs.StreamEncoder
 173:             4             96  sun.reflect.annotation.AnnotationInvocationHandler
 174:             3             96  sun.reflect.generics.reflectiveObjects.TypeVariableImpl
 175:             3             96  sun.reflect.generics.repository.ClassRepository
 176:             1             88  sun.misc.Launcher$AppClassLoader
 177:             1             88  sun.misc.Launcher$ExtClassLoader
 178:             1             80  [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
 179:             1             80  [Ljava.lang.invoke.LambdaForm;
 180:             2             80  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$TabularMapping
 181:             2             80  java.io.BufferedWriter
 182:             2             80  java.io.ExpiringCache
 183:             2             80  java.lang.invoke.MethodType
 184:             2             80  java.util.IdentityHashMap
 185:             2             80  sun.management.MemoryManagerImpl
 186:             2             80  sun.misc.FloatingDecimal$BinaryToASCIIBuffer
 187:             2             80  sun.misc.URLClassPath
 188:             1             72  [Ljavax.management.openmbean.SimpleType;
 189:             3             72  java.lang.annotation.RetentionPolicy
 190:             1             72  java.lang.invoke.MethodTypeForm
 191:             3             72  java.net.InetAddress$InetAddressHolder
 192:             3             72  java.util.Collections$SynchronizedSet
 193:             1             72  java.util.logging.LogManager$RootLogger
 194:             3             72  sun.misc.FloatingDecimal$ExceptionalBinaryToASCIIBuffer
 195:             3             72  sun.reflect.NativeMethodAccessorImpl
 196:             3             72  sun.reflect.generics.tree.ClassSignature
 197:             3             72  sun.reflect.generics.tree.FormalTypeParameter
 198:             1             64  [F
 199:             2             64  [Ljava.lang.Thread;
 200:             2             64  [Ljava.lang.annotation.RetentionPolicy;
 201:             4             64  [Ljava.security.Principal;
 202:             2             64  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$CollectionMapping
 203:             4             64  com.sun.proxy.$Proxy1
 204:             2             64  java.io.FileOutputStream
 205:             2             64  java.io.FilePermission
 206:             2             64  java.io.PrintStream
 207:             2             64  java.lang.ThreadLocal$ThreadLocalMap$Entry
 208:             2             64  java.lang.VirtualMachineError
 209:             2             64  java.lang.invoke.MethodType$ConcurrentWeakInternSet$WeakEntry
 210:             2             64  java.lang.ref.ReferenceQueue$Null
 211:             2             64  java.lang.reflect.Proxy$Key1
 212:             2             64  java.lang.reflect.WeakCache$CacheValue
 213:             2             64  java.security.BasicPermissionCollection
 214:             2             64  java.security.Permissions
 215:             4             64  java.security.ProtectionDomain$Key
 216:             4             64  java.util.LinkedHashMap$LinkedValues
 217:             2             64  java.util.PropertyPermission
 218:             2             64  sun.reflect.annotation.AnnotationType
 219:             1             56  [Ljava.lang.Runnable;
 220:             3             56  [Lsun.reflect.generics.tree.ClassTypeSignature;
 221:             1             56  [Lsun.util.logging.PlatformLogger$Level;
 222:             1             56  java.lang.invoke.MemberName
 223:             1             56  java.util.logging.LogManager
 224:             3             48  [Ljava.lang.annotation.Annotation;
 225:             2             48  [Ljava.lang.reflect.TypeVariable;
 226:             1             48  [[Ljava.lang.Object;
 227:             2             48  com.sun.jmx.mbeanserver.ClassLoaderRepositorySupport$LoaderEntry
 228:             1             48  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory$Mappings
 229:             1             48  com.sun.jmx.mbeanserver.MBeanIntrospector$MBeanInfoMap
 230:             1             48  com.sun.jmx.mbeanserver.MBeanIntrospector$PerInterfaceMap
 231:             2             48  com.sun.jmx.mbeanserver.WeakIdentityHashMap
 232:             2             48  java.io.BufferedOutputStream
 233:             2             48  java.io.File$PathStatus
 234:             2             48  java.io.FilePermissionCollection
 235:             2             48  java.io.OutputStreamWriter
 236:             2             48  java.lang.StringBuilder
 237:             2             48  java.net.InetAddress
 238:             2             48  java.net.InetAddress$Cache
 239:             2             48  java.net.InetAddress$Cache$Type
 240:             2             48  java.nio.charset.CoderResult
 241:             3             48  java.nio.charset.CodingErrorAction
 242:             1             48  java.util.concurrent.locks.ReentrantReadWriteLock$FairSync
 243:             2             48  java.util.logging.Logger$LoggerBundle
 244:             2             48  java.util.zip.ZStreamRef
 245:             2             48  sun.management.ManagementFactoryHelper$1
 246:             2             48  sun.misc.NativeSignalHandler
 247:             2             48  sun.misc.Signal
 248:             1             48  sun.nio.cs.SingleByte$Decoder
 249:             3             48  sun.reflect.DelegatingMethodAccessorImpl
 250:             2             48  sun.reflect.generics.scope.ClassScope
 251:             2             40  [Lcom.sun.jmx.mbeanserver.ClassLoaderRepositorySupport$LoaderEntry;
 252:             1             40  [Ljava.lang.management.MemoryPoolMXBean;
 253:             1             40  com.sun.jmx.interceptor.DefaultMBeanServerInterceptor
 254:             1             40  com.sun.jmx.mbeanserver.JmxMBeanServer
 255:             1             40  com.sun.jmx.mbeanserver.MBeanServerDelegateImpl
 256:             1             40  java.io.BufferedInputStream
 257:             1             40  sun.management.DiagnosticCommandImpl
 258:             1             40  sun.nio.cs.StandardCharsets$Aliases
 259:             1             40  sun.nio.cs.StandardCharsets$Cache
 260:             1             40  sun.nio.cs.StandardCharsets$Classes
 261:             1             40  sun.nio.cs.UTF_8$Decoder
 262:             1             32  [Ljava.lang.OutOfMemoryError;
 263:             2             32  [Ljava.lang.StackTraceElement;
 264:             1             32  [Ljava.lang.ThreadGroup;
 265:             1             32  [Ljava.lang.management.MemoryManagerMXBean;
 266:             1             32  com.sun.jmx.mbeanserver.Repository
 267:             1             32  java.io.WinNTFileSystem
 268:             1             32  java.lang.ArithmeticException
 269:             2             32  java.lang.Boolean
 270:             1             32  java.lang.NullPointerException
 271:             2             32  java.lang.Shutdown$Lock
 272:             1             32  java.lang.StringCoding$StringDecoder
 273:             1             32  java.lang.reflect.WeakCache
 274:             1             32  java.net.Socket
 275:             2             32  java.nio.ByteOrder
 276:             1             32  java.util.Collections$UnmodifiableMap
 277:             2             32  java.util.HashMap$EntrySet
 278:             1             32  java.util.concurrent.atomic.AtomicReferenceFieldUpdater$AtomicReferenceFieldUpdaterImpl
 279:             1             32  java.util.logging.LogManager$SystemLoggerContext
 280:             1             32  javax.management.MBeanConstructorInfo
 281:             1             32  sun.management.MemoryImpl
 282:             2             32  sun.net.www.protocol.jar.Handler
 283:             1             32  sun.nio.cs.StandardCharsets
 284:             1             24  [Ljava.io.File$PathStatus;
 285:             1             24  [Ljava.lang.invoke.MethodHandle;
 286:             1             24  [Ljava.net.InetAddress$Cache$Type;
 287:             1             24  [Ljava.net.InetSocketAddress;
 288:             1             24  [Ljava.security.ProtectionDomain;
 289:             1             24  [Lsun.launcher.LauncherHelper;
 290:             1             24  com.sun.jmx.mbeanserver.ClassLoaderRepositorySupport
 291:             1             24  com.sun.jmx.mbeanserver.MXBeanLookup
 292:             1             24  com.sun.jmx.remote.util.ClassLogger
 293:             1             24  dustin.examples.diagnostics.VirtualMachineDiagnostics
 294:             1             24  java.lang.ThreadLocal$ThreadLocalMap
 295:             1             24  java.lang.invoke.LambdaForm$NamedFunction
 296:             1             24  java.lang.invoke.MethodType$ConcurrentWeakInternSet
 297:             1             24  java.lang.reflect.ReflectPermission
 298:             1             24  java.net.Inet4Address
 299:             1             24  java.net.Inet6AddressImpl
 300:             1             24  java.net.ServerSocket
 301:             1             24  java.util.BitSet
 302:             1             24  java.util.Collections$EmptyMap
 303:             1             24  java.util.Collections$SetFromMap
 304:             1             24  java.util.Locale$Cache
 305:             1             24  java.util.concurrent.atomic.AtomicLong
 306:             1             24  java.util.concurrent.locks.ReentrantReadWriteLock
 307:             1             24  java.util.jar.Manifest
 308:             1             24  java.util.logging.LogManager$LoggerContext
 309:             1             24  java.util.logging.LoggingPermission
 310:             1             24  javax.management.NotificationBroadcasterSupport
 311:             1             24  sun.launcher.LauncherHelper
 312:             1             24  sun.management.CompilationImpl
 313:             1             24  sun.management.OperatingSystemImpl
 314:             1             24  sun.management.RuntimeImpl
 315:             1             24  sun.management.ThreadImpl
 316:             1             24  sun.management.VMManagementImpl
 317:             1             24  sun.misc.JarIndex
 318:             1             24  sun.misc.URLClassPath$FileLoader
 319:             1             24  sun.nio.cs.ISO_8859_1
 320:             1             24  sun.nio.cs.MS1252
 321:             1             24  sun.nio.cs.ThreadLocalCoders$1
 322:             1             24  sun.nio.cs.ThreadLocalCoders$2
 323:             1             24  sun.nio.cs.US_ASCII
 324:             1             24  sun.nio.cs.UTF_16
 325:             1             24  sun.nio.cs.UTF_16BE
 326:             1             24  sun.nio.cs.UTF_16LE
 327:             1             24  sun.nio.cs.UTF_8
 328:             1             24  sun.util.locale.BaseLocale$Cache
 329:             1             16  [Ljava.lang.Throwable;
 330:             1             16  [Ljava.nio.file.attribute.FileAttribute;
 331:             1             16  [Ljava.security.cert.Certificate;
 332:             1             16  [Ljava.util.logging.Handler;
 333:             1             16  com.intellij.rt.execution.application.AppMain$1
 334:             1             16  com.sun.jmx.interceptor.DefaultMBeanServerInterceptor$ResourceContext$1
 335:             1             16  com.sun.jmx.mbeanserver.DefaultMXBeanMappingFactory
 336:             1             16  com.sun.jmx.mbeanserver.DescriptorCache
 337:             1             16  com.sun.jmx.mbeanserver.MBeanAnalyzer$MethodOrder
 338:             1             16  com.sun.jmx.mbeanserver.MBeanInstantiator
 339:             1             16  com.sun.jmx.mbeanserver.MXBeanIntrospector
 340:             1             16  com.sun.jmx.mbeanserver.SecureClassLoaderRepository
 341:             1             16  java.io.FileDescriptor$1
 342:             1             16  java.lang.ApplicationShutdownHooks$1
 343:             1             16  java.lang.CharacterDataLatin1
 344:             1             16  java.lang.Runtime
 345:             1             16  java.lang.String$CaseInsensitiveComparator
 346:             1             16  java.lang.System$2
 347:             1             16  java.lang.Terminator$1
 348:             1             16  java.lang.invoke.MemberName$Factory
 349:             1             16  java.lang.management.PlatformComponent$1
 350:             1             16  java.lang.management.PlatformComponent$10
 351:             1             16  java.lang.management.PlatformComponent$11
 352:             1             16  java.lang.management.PlatformComponent$12
 353:             1             16  java.lang.management.PlatformComponent$13
 354:             1             16  java.lang.management.PlatformComponent$14
 355:             1             16  java.lang.management.PlatformComponent$15
 356:             1             16  java.lang.management.PlatformComponent$2
 357:             1             16  java.lang.management.PlatformComponent$3
 358:             1             16  java.lang.management.PlatformComponent$4
 359:             1             16  java.lang.management.PlatformComponent$5
 360:             1             16  java.lang.management.PlatformComponent$6
 361:             1             16  java.lang.management.PlatformComponent$7
 362:             1             16  java.lang.management.PlatformComponent$8
 363:             1             16  java.lang.management.PlatformComponent$9
 364:             1             16  java.lang.ref.Reference$Lock
 365:             1             16  java.lang.reflect.Proxy$KeyFactory
 366:             1             16  java.lang.reflect.Proxy$ProxyClassFactory
 367:             1             16  java.lang.reflect.ReflectAccess
 368:             1             16  java.net.InetAddress$2
 369:             1             16  java.net.URLClassLoader$7
 370:             1             16  java.nio.Bits$1
 371:             1             16  java.nio.Bits$1$1
 372:             1             16  java.nio.charset.CoderResult$1
 373:             1             16  java.nio.charset.CoderResult$2
 374:             1             16  java.security.ProtectionDomain$1
 375:             1             16  java.security.ProtectionDomain$3
 376:             1             16  java.util.Collections$EmptyIterator
 377:             1             16  java.util.Collections$EmptyList
 378:             1             16  java.util.Collections$EmptySet
 379:             1             16  java.util.Collections$SingletonSet
 380:             1             16  java.util.HashMap$Values
 381:             1             16  java.util.Hashtable$EntrySet
 382:             1             16  java.util.WeakHashMap$KeySet
 383:             1             16  java.util.concurrent.atomic.AtomicInteger
 384:             1             16  java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock
 385:             1             16  java.util.concurrent.locks.ReentrantReadWriteLock$Sync$ThreadLocalHoldCounter
 386:             1             16  java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock
 387:             1             16  java.util.jar.Attributes
 388:             1             16  java.util.jar.JavaUtilJarAccessImpl
 389:             1             16  java.util.logging.LoggingProxyImpl
 390:             1             16  java.util.zip.ZipFile$1
 391:             1             16  javax.management.JMX
 392:             1             16  javax.management.MBeanServerBuilder
 393:             1             16  javax.management.NotificationBroadcasterSupport$1
 394:             1             16  sun.management.ClassLoadingImpl
 395:             1             16  sun.management.HotSpotDiagnostic
 396:             1             16  sun.management.ManagementFactoryHelper$PlatformLoggingImpl
 397:             1             16  sun.misc.ASCIICaseInsensitiveComparator
 398:             1             16  sun.misc.FloatingDecimal$1
 399:             1             16  sun.misc.Launcher
 400:             1             16  sun.misc.Launcher$Factory
 401:             1             16  sun.misc.Perf
 402:             1             16  sun.misc.Unsafe
 403:             1             16  sun.net.www.protocol.file.Handler
 404:             1             16  sun.nio.ch.FileChannelImpl$1
 405:             1             16  sun.reflect.ReflectionFactory
 406:             1             16  sun.reflect.generics.tree.TypeVariableSignature
 407:             1             16  sun.util.calendar.Gregorian
Total         16267         885480

Some of the sub-commands available with jcmd are only available when diagnostic operations are unlocked with -XX:+UnlockDiagnosticVMOptions (specified when running the Java process). This is true of the DiagnosticCommandMBean counterparts as demonstrated in the next code listing and output listing.

Accessing Class Statistics
/**
 * Provide class statistics as single String.
 *
 * This is only supported when {@code -XX:+UnlockDiagnosticVMOptions} is enabled.
 *
 * @return Single string containing formatted class statistics.
 */
public String getClassStatistics()
{
   return invokeNoStringArgumentsCommand("gcClassStats", "GC Class Statistics");
}
GC.class_stats command requires -XX:+UnlockDiagnosticVMOptions

One jcmd subcommand I have not seen exposed as an operation on DiagnosticCommandMBean is that for generating a heap dump (jcmd's GC.heap_dump). There is no equivalent operation exposed by DiagnosticCommandMBean as far as I can tell from looking at the exposed operations in VisualVM and JConsole and from looking at the available commands listed by the "help" operation as demonstrated above. Although DiagnosticCommandMBean does not appear to provide an operation for invoking a heap dump, another MBean (com.sun.management.HotSpotDiagnostic with ObjectName of "com.sun.management:type=HotSpotDiagnostic") does with operation "dumpHeap" and this is demonstrated in A. Sundararajan's's blog post "Programmatically dumping heap from Java applications."

Conclusion

The DiagnosticCommandMBean provides most of jcmd's functionality and is therefore makes jcmd functionality available to Java applications to run that functionality against themselves.

The code listings shown in this post are available in the class VirtualMachineDiagnostics, which is available on GitHub. I may add or modify this class in the future, but the original version has the same code as shown in this post.

Thursday, April 14, 2016

Determining the Active HotSpot Garbage Collector

The StackOverflow questions find which type of garbage collector is running, Default Garbage collector for a jvm, How can I see what garbage collector is running by looking at gc logs?, and How to know the current GC strategy of the HotSpot jvm?, and the blog post How to programmatically obtain GC information demonstrate the desire at times to know which Java garbage collector is used by a Java application. In this post, I look at some of the easiest and most common approaches to determining the garbage collector associated with a Java application running in the Oracle HotSpot VM.

For demonstration purposes, I'll be running a simple Java application. The code for this application is not significant for demonstrating how to determine the applicable garbage collector. The simple Java application can be run with the command java -cp stringInstantiationsDemo.jar dustin.examples.demo.IndefiniteRun. Notice that there is no specification of a JVM flag for the garbage collector to be used. This means that the JVM will use an ergonomically selected garbage collector.

One easy approach to determining the selected garbage collector is via use of the -XX:+PrintCommandLineFlags flag (which I wrote about in the blog post JavaOne 2011: The Definitive Set of HotSpot Performance Command-line Options). This flag can be used in the command java -XX:+PrintCommandLineFlags -cp stringInstantiationsDemo.jar dustin.examples.demo.IndefiniteRun as demonstrated in the following screen snapshot:

As the last screen snapshot indicates, use of the -XX:+PrintCommandLineFlags demonstrates the existence of the -XX:+UseParallelGC flag, which indicates that the collector being used automatically in this case is the parallel collector (also known as throughput collector).

Use of the -XX:+PrintCommandLineFlags allows us to see the ergonomically selected garbage collector works well when starting a new Java application. When we want to see the garbage collector used by an already-running Java process, jcmd comes in handy (I wrote about this useful tool in the post jcmd: One JDK Command-Line Tool to Rule Them All). This is illustrated in the next screen snapshot that demonstrates use of jcmd to see the JVM command-line flags of an already-running Java application.

From the previous image, we see that we can use jcmd <pid> VM.flags to identify virtual machine flags that will indicate the garbage collector being used. In this case, we again see the presence of -XX:+UseParallelGC, indicating use of the parallel/throughput garbage collector.

I just demonstrated using jcmd to see the implicit JVM arguments that tell us which garbage collector was automatically chosen for a particular application's VM when the garbage collector was not explicitly specified. The next two images show that JConsole and VisualVM do NOT show implicit JVM arguments and so do NOT show the garbage collector being used automatically when one is not specified.

Although neither JConsole nor VisualVM shows implicit Java Virtual Machine arguments such as the implicitly chosen garbage collector, both tools can still be used to determine the garbage collector in use via JMX and the GarbageCollectorMXBean with object type java.lang:type=GarbageCollector. In the case of the simple application used so far in this post, this will be java.lang:type=GarbageCollector,name=PS MarkSweep because this is the parallel or throughput collector. This is demonstrated in JConsole and VisualVM (via the MBeans plugin) in the next two screen snapshots.

The above examples have demonstrated three basic approaches to determining which garbage collector is applicable. These are summarized in the following table for the parallel/throughput collector previously demonstrated as well as for the other two main Oracle HotSpot JVM collectors (CMS and G1). The table shows what to look for when ascertaining which collector (parallel, CMS, or G1) is in use with one of the approaches described above (explicitly specified on command-line, jcmd, or JMX MXBean).

Garbage Collector Explicit Command-line jcmd VM.flags java.lang:type=GarbageCollector,name=
Parallel / Throughput -XX:+UseParallelOldGC
-XX:+UseParallelGC
PS MarkSweep
PS Scavenge
Concurrent Mark Sweep (CMS) -XX:+UseConcMarkSweepGC ConcurrentMarkSweep
Garbage First (G1) -XX:+UseG1GC G1 Old Generation
G1 Young Generation

Although not shown here, another way to determine which collector is in use from VisualVM or JConsole is to use the DiagnosticCommandMBean to look up VM.flags in the same manner that jcmd provides VM flags as discussed above. I have blogged on using DiagnosticCommandMBean to accomplish jcmd behaviors in the post Looking at DiagnosticCommandMBean in JConsole and VisualVM.

The JVM generally prevents two different garbage collectors' flags from being provided. When two exist on the same attempt to launch a Java application, a message like "Conflicting collector combinations in option list" will appear and the Java process won't start. Therefore, one simply needs to identify a flag for a specific collector associated with a running Java application to know which collector is in use. This post has demonstrated multiple simple approaches that can be used to identify which HotSpot garbage collector is being applied in a given application's JVM.

Saturday, April 2, 2016

Java 8 Deferred Invocation with Java Util Logging

In the blog post Better Performing Non-Logging Logger Calls in Log4j2, I looked at approaches one can use in Log4j 2 to reduce or avoid invocation of methods in log statements that, based on the specified log level, are not actually logged at all. As part of this discussion, I covered Log4j 2's support for Java 8-based deferred execution using lambda expressions. In this post, I demonstrate using the built-in java.util.logging (JUL) support for deferred execution of methods in log statements using lambda expressions in a similar way to that supported by Log4j 2.

The java.util.logging.Logger class-level Javadoc documentation describes JUL's support for deferred execution:

A set of methods alternatively take a "msgSupplier" instead of a "msg" argument. These methods take a Supplier function which is invoked to construct the desired log message only when the message actually is to be logged based on the effective log level thus eliminating unnecessary message construction.

Browsing the public API for java.util.logging.Logger provides a quick overview of the methods referenced in that comment that use a supplier to allow for deferral of method invocation until it is actually known that the log needs to be made. The code.util.logging.Logger methods that accept an instance of the built-in functional interface java.util.function.Supplier as an argument. For example, the next screen snapshot captures a small portion of the HTML rendered Javadoc with some of the methods that accept a Supplier.

I like to use javap to easily view a Java class's public API. This can be done in this case by executing the command javap -classpath rt.jar java.util.logging.Logger from the $JAVA_HOME/jre/lib directory (assuming you've configured the JAVA_HOME environment variable). The next screen snapshot depicts the execution of this command and the first portion of the results. That screen snapshot is followed by text version of the output with the uses of Supplier emphasized.

Compiled from "Logger.java"
public class java.util.logging.Logger {
  static final java.lang.String SYSTEM_LOGGER_RB_NAME;
  public static final java.lang.String GLOBAL_LOGGER_NAME;
  public static final java.util.logging.Logger global;
  static final boolean $assertionsDisabled;
  public static final java.util.logging.Logger getGlobal();
  protected java.util.logging.Logger(java.lang.String, java.lang.String);
  java.util.logging.Logger(java.lang.String, java.lang.String, java.lang.Class<?>, java.util.logging.LogManager, boolean);
  void setLogManager(java.util.logging.LogManager);
  public static java.util.logging.Logger getLogger(java.lang.String);
  public static java.util.logging.Logger getLogger(java.lang.String, java.lang.String);
  static java.util.logging.Logger getPlatformLogger(java.lang.String);
  public static java.util.logging.Logger getAnonymousLogger();
  public static java.util.logging.Logger getAnonymousLogger(java.lang.String);
  public java.util.ResourceBundle getResourceBundle();
  public java.lang.String getResourceBundleName();
  public void setFilter(java.util.logging.Filter) throws java.lang.SecurityException;
  public java.util.logging.Filter getFilter();
  public void log(java.util.logging.LogRecord);
  public void log(java.util.logging.Level, java.lang.String);
  public void log(java.util.logging.Level, java.util.function.Supplier<java.lang.String>);
  public void log(java.util.logging.Level, java.lang.String, java.lang.Object);
  public void log(java.util.logging.Level, java.lang.String, java.lang.Object[]);
  public void log(java.util.logging.Level, java.lang.String, java.lang.Throwable);
  public void log(java.util.logging.Level, java.lang.Throwable, java.util.function.Supplier<java.lang.String>);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.util.function.Supplier<java.lang.String>);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Object);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Object[]);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Throwable);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.Throwable, java.util.function.Supplier<java.lang.String>);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Object);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Object[]);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.util.ResourceBundle, java.lang.String, java.lang.Object...);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Throwable);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.util.ResourceBundle, java.lang.String, java.lang.Throwable);
  public void entering(java.lang.String, java.lang.String);
  public void entering(java.lang.String, java.lang.String, java.lang.Object);
  public void entering(java.lang.String, java.lang.String, java.lang.Object[]);
  public void exiting(java.lang.String, java.lang.String);
  public void exiting(java.lang.String, java.lang.String, java.lang.Object);
  public void throwing(java.lang.String, java.lang.String, java.lang.Throwable);
  public void severe(java.lang.String);
  public void warning(java.lang.String);
  public void info(java.lang.String);
  public void config(java.lang.String);
  public void fine(java.lang.String);
  public void finer(java.lang.String);
  public void finest(java.lang.String);
  public void severe(java.util.function.Supplier<java.lang.String>);
  public void warning(java.util.function.Supplier<java.lang.String>);
  public void info(java.util.function.Supplier<java.lang.String>);
  public void config(java.util.function.Supplier<java.lang.String>);
  public void fine(java.util.function.Supplier<java.lang.String>);
  public void finer(java.util.function.Supplier<java.lang.String>);
  public void finest(java.util.function.Supplier<java.lang.String>);
  public void setLevel(java.util.logging.Level) throws java.lang.SecurityException;
  final boolean isLevelInitialized();
  public java.util.logging.Level getLevel();
  public boolean isLoggable(java.util.logging.Level);
  public java.lang.String getName();
  public void addHandler(java.util.logging.Handler) throws java.lang.SecurityException;
  public void removeHandler(java.util.logging.Handler) throws java.lang.SecurityException;
  public java.util.logging.Handler[] getHandlers();
  java.util.logging.Handler[] accessCheckedHandlers();
  public void setUseParentHandlers(boolean);
  public boolean getUseParentHandlers();
  public void setResourceBundle(java.util.ResourceBundle);
  public java.util.logging.Logger getParent();
  public void setParent(java.util.logging.Logger);
  final void removeChildLogger(java.util.logging.LogManager$LoggerWeakRef);
  static java.util.logging.Logger$LoggerBundle access$000();
  static java.util.logging.Logger$LoggerBundle access$100();
  static {};
}

We can see from the public API for java.util.logging.Logger that there are overloaded methods for "precise logging" (logp methods that accept two Strings for explicitly specified class and method names) and for "regular logging" that accept instances of Supplier. These methods allow for the supplier to only be processed if the logging level is set to a level specific enough for the log statement to be written.

Here is a list of the current java.util.logging.Logger methods accepting a Supplier instance:

  • Regular, Specific-Level Logging Methods
    • public void severe(java.util.function.Supplier<java.lang.String>);
    • public void warning(java.util.function.Supplier<java.lang.String>);
    • public void info(java.util.function.Supplier<java.lang.String>);
    • public void config(java.util.function.Supplier<java.lang.String>);
    • public void fine(java.util.function.Supplier<java.lang.String>);
    • public void finer(java.util.function.Supplier<java.lang.String>);
    • public void finest(java.util.function.Supplier<java.lang.String>);
  • Regular, General Logging Methods Requiring Specification of Log Level
    • public void log(java.util.logging.Level, java.util.function.Supplier<java.lang.String>);
    • public void log(java.util.logging.Level, java.lang.Throwable, java.util.function.Supplier<java.lang.String>);
  • "Precise" Logging Method
    • public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.util.function.Supplier<java.lang.String>);

Keeping in mind that the precise logging method (with name logp) accepts its String arguments for class and method names, one of the most significant differences between JUL's deferred invocation logging API from Log4j 2's implementation can be observed: the JUL implementation does not allow for a "message" string to be provided as a separate (additional) parameter to its logging methods.

In my previous blog post, I demonstrated use of Log4j 2's org.apache.logging.log4j.Logger.debug(String message, Supplier<?>... paramSuppliers) method that accepts a message String in addition to the deferred execution of a provided Supplier. There are similar methods provided in Log4j 2's org.apache.logging.log4j.Logger for other specific log levels (error, fatal, info, trace, and warn) and for the general logging with explicit specification of log level. The additional flexibility to easily provide context via a separate String from the Supplier is a nice one to have. It's also worth noting that Log4j 2's Logger also supports various log methods that accept only a Supplier (without any context message String) similar to the methods java.util.logging.Logger provides.

In the blog post Top Five Reasons to Try Java 8, John Shepard writes that "now that Functions can be passed into (and returned) from methods, log.isLogLevelEnabled and similar methods no longer needs to be spattered across the code base." He then provides a simple code listing that demonstrates how to provide String context via this API when an individual String argument for message context is not part of the method's signature. My example at the end of this post will be similar.

As I discussed in my post Better Performing Non-Logging Logger Calls in Log4j2, deferred execution powered by Java lambda expressions allows developers to remove logging guards from their code by deferring both implicit and explicit method calls on passed-in objects until the lambda expression is resolved. This is never done if the logging level the software is running at is less specific than the specific log level of the message. In other words, code can be converted from the next shown code listing to be like the smaller code listing that follows it.

if (logger.isLoggable(Level.FINE))
{
   logger.fine("GUARDED: " + slow);
}
if (logger.isLoggable(Level.FINE))
{
   logger.fine(expensiveOperation());
}
logger.fine(() -> "LAMBDA: " + slow);
logger.fine(this::expensiveOperation);

Although many things in software development are really matters of taste and opinion, it's difficult to imagine many arguments in favor of the earlier, more verbose code. Despite what some assert, less code is NOT always more readable to everyone. However, in this case, I believe that there are very few developers who would argue that the more verbose code is in anyway better than the Java 8 version.

Monday, March 21, 2016

Looking at DiagnosticCommandMBean in JConsole and VisualVM

I've used JConsole for many years as a suitable generic JMX client. This tool is generally available with the Oracle JDK and is easy to use. In terms of JMX interaction, the most significant advantage of JConsole over VisualVM is that JConsole comes with a built-in MBeans tab while a plugin must be applied for this same functionality in VisualVM. However, as I explained in the blog post From JConsole to VisualVM, this plug-in is easy to install. In this post, I look at an area where VisualVM with the MBeans plugin is superior to JConsole with its built-in MBeans support: DiagnosticCommandMBean. I am using the versions of JConsole and VisualVM that are provided with the Oracle JDK (Java 8).

The next three screen snapshots demonstrate accessing operations of DiagnosticCommandMBean via JConsole. The first image displays about details regarding the DiagnosticCommandMBean such as its ObjectName (com.sun.management:type=DiagnosticCommand). The second image demonstrates that JConsole allows one to see the VM's system properties by clicking on the operation's "vmSystemProperties" button. The third image demonstrates that some operations of the DiagnosticCommandMBean ("help" in this case) cannot be invoked from JConsole.

As the last image shown demonstrates, some MBean operations are disabled. The reason for this is that, as described on StackOverflow, "they are enabled only for operations which take in simple types." Andreas Veithen has elaborated on this: "JConsole [only] allows to invoke methods that only have parameters with simple types. That includes primitive types, wrapper classes for primitive types and strings. Methods that have parameters with other types cannot be invoked because JConsole doesn't know how to construct instances of these types."

Fortunately, the MBeans plugin for VisualVM does provide support for operations against DiagnosticCommandMBean that deal with more complex data types. This support was explicitly added via VISUALVM-574 ("Add support for DiagnosticCommandMBean in MBeans plugin"). The next screen snapshot depicts basic background information regarding this plugin and is available in VisualVM by clicking on Tools -> Plugins -> Available Plugins -> VisualVM-MBeans.

After downloading and installing the VisualVM-MBeans plugin, VisualVM makes all operations on DiagnosticCommandMBean available as demonstrated in the next three screen snapshots. The first image shows that none of the operations are "grayed out." The second and third images show that both the "system properties" and the "help operations" are supported.

In the example of invoking "help" above, I did not pass it any arguments, so it behaved exactly as jcmd would behave when "help" is invoked without any other arguments and returns a list of jcmd command options available for the given Java process. The next screen snapshot depicts how this works similarly to jcmd when I provide one of those command names to the "help" operation as an argument (getting help on VM.uptime in this case).

The Tool Enhancements in JDK 8 page explains that DiagnosticCommandMBean makes jcmd functions available programatically and remotely: "JDK 8 provides remote access to diagnostic commands which were previously accessible only locally via the jcmd tool. Remote access is provided using the Java Management Extensions (JMX), so diagnostic commands are exposed to a platform MBean registered to the platform MBean server. The MBean is the com.sun.management.DiagnosticCommandMBean interface." The VisualVM plugin for JConsole/MBeans support makes use of the graphical VisualVM tool behave similarly to using jcmd from the command-line.

This post has demonstrated that DiagnosticCommandMBean provides access to the same data that jcmd provides for remote and programmatic access and that VisualVM provides a useful graphical interface for taking advantage of DiagnosticCommandMBean via the VisualVM-MBeans plugin.

Friday, March 4, 2016

SQL: Counting Groups of Rows Sharing Common Column Values

In this post, I focus on using simple SQL SELECT statements to count the number of rows in a table meeting a particular condition with the results grouped by a certain column of the table. These are all basic SQL concepts, but mixing them allows for different and useful representations of data stored in a relational database. The specific aspects of a SQL query covered in this post and illustrated with simple examples are the aggregate function count(), WHERE, GROUP BY, and HAVING. These will be used to build together a simple single SQL query that indicates the number of rows in a table that match different values for a given column in that table.

I'll need some simple SQL data to demonstrate. The following SQL code demonstrates creation of a table called ALBUMS in a PostgreSQL database followed by use of INSERT statements to populate that table.

createAndPopulateAlbums.sql
CREATE TABLE albums
(
   title text,
   artist text,
   year integer
);

INSERT INTO albums (title, artist, year)
   VALUES ('Back in Black', 'AC/DC', 1980);
INSERT INTO albums (title, artist, year)
   VALUES ('Slippery When Wet', 'Bon Jovi', 1986);
INSERT INTO albums (title, artist, year)
   VALUES ('Third Stage', 'Boston', 1986);
INSERT INTO albums (title, artist, year)
   VALUES ('Hysteria', 'Def Leppard', 1987);
INSERT INTO albums (title, artist, year)
   VALUES ('Some Great Reward', 'Depeche Mode', 1984);
INSERT INTO albums (title, artist, year)
   VALUES ('Violator', 'Depeche Mode', 1990);
INSERT INTO albums (title, artist, year)
   VALUES ('Brothers in Arms', 'Dire Straits', 1985);
INSERT INTO albums (title, artist, year)
   VALUES ('Rio', 'Duran Duran', 1982);
INSERT INTO albums (title, artist, year)
   VALUES ('Hotel California', 'Eagles', 1976);
INSERT INTO albums (title, artist, year)
   VALUES ('Rumours', 'Fleetwood Mac', 1977);
INSERT INTO albums (title, artist, year)
   VALUES ('Kick', 'INXS', 1987);
INSERT INTO albums (title, artist, year)
   VALUES ('Appetite for Destruction', 'Guns N'' Roses', 1987);
INSERT INTO albums (title, artist, year)
   VALUES ('Thriller', 'Michael Jackson', 1982);
INSERT INTO albums (title, artist, year)
   VALUES ('Welcome to the Real World', 'Mr. Mister', 1985);
INSERT INTO albums (title, artist, year)
   VALUES ('Never Mind', 'Nirvana', 1991);
INSERT INTO albums (title, artist, year)
   VALUES ('Please', 'Pet Shop Boys', 1986);
INSERT INTO albums (title, artist, year)
   VALUES ('The Dark Side of the Moon', 'Pink Floyd', 1973);
INSERT INTO albums (title, artist, year)
   VALUES ('Look Sharp!', 'Roxette', 1988);
INSERT INTO albums (title, artist, year)
   VALUES ('Songs from the Big Chair', 'Tears for Fears', 1985);
INSERT INTO albums (title, artist, year)
   VALUES ('Synchronicity', 'The Police', 1983);
INSERT INTO albums (title, artist, year)
   VALUES ('Into the Gap', 'Thompson Twins', 1984);
INSERT INTO albums (title, artist, year)
   VALUES ('The Joshua Tree', 'U2', 1987);
INSERT INTO albums (title, artist, year)
   VALUES ('1984', 'Van Halen', 1984);

The next two screen snapshots show the results of running this script in psql:

At this point, if I want to see how many albums were released in each year, I could use several individual SQL query statements like these:

SELECT count(1) FROM albums where year = 1985;
SELECT count(1) FROM albums where year = 1987;

It might be desirable to see how many albums were released in each year without needing an individual query for each year. This is where using an aggregate function like count() with a GROUP BY clause comes in handy. The next query is simple, but takes advantage of GROUP BY to display the count of each "group" of rows grouped by the albums' release years.

SELECT year, count(1)
  FROM albums
 GROUP BY year;

The WHERE clause can be used as normal to narrow the number of returned rows by specifying a narrowing condition. For example, the following query returns the albums that were released in a year after 1988.

SELECT year, count(1)
  FROM albums
 WHERE year > 1988
 GROUP BY year;

We might want to only return the years for which multiple albums (more than one) are in our table. A first naive approach might be as shown next (doesn't work as shown in the screen snapshot that follows):

-- Bad Code!: Don't do this.
SELECT year, count(1)
  FROM albums
 WHERE count(1) > 1
 GROUP BY year;

The last screen snapshot demonstrates that "aggregate functions are not allowed in WHERE." In other words, we cannot use the count() in the WHERE clause. This is where the HAVING clause is useful because HAVING narrows results in a similar manner as WHERE does, but is used with aggregate functions and GROUP BY.

The next SQL listing demonstrates using the HAVING clause to accomplish the earlier attempted task (listing years for which multiple album rows exist in the table):

SELECT year, count(1)
  FROM albums
 GROUP BY year
HAVING count(1) > 1;

Finally, I may want to order the results so that they are listed in increasing (later) years. Two of the SQL queries demonstrated earlier are shown here with ORDER BY added.

SELECT year, count(1)
  FROM albums
 GROUP BY year
 ORDER BY year;
SELECT year, count(1)
  FROM albums
 GROUP BY year
HAVING count(1) > 1
 ORDER BY year;

SQL has become a much richer language than when I first began working with it, but the basic SQL that has been available for numerous years remains effective and useful. Although the examples in this post have been demonstrated using PostgreSQL, these examples should work on most relational databases that implement ANSI SQL.

Monday, February 29, 2016

jcmd: One JDK Command-Line Tool to Rule Them All

I have referenced the handy JDK tool jcmd in several posts in the past, but focus exclusively on its usefulness here like I have previously done for jps. The jcmd tool was introduced with Oracle's Java 7 and is particularly useful in troubleshooting issues with JVM applications by using it to identify Java processes' IDs (akin to jps), acquiring heap dumps (akin to jmap), acquiring thread dumps (akin to jstack), viewing virtual machine characteristics such as system properties and command-line flags (akin to jinfo), and acquiring garbage collection statistics (akin to jstat). The jcmd tool has been called "a swiss-army knife for investigating and resolving issues with your JVM application" and a "hidden gem."

When using most JDK command-line tools (including jcmd), it's often important to identify the process ID (pid) of the Java process for which we want to use the command-line tool. This is easily accomplished with jcmd by simply running the command without any arguments as shown in the next screen snapshot.

Running jcmd without arguments in the example above shows two Java processes running (jcmd itself with a pid of 324 and another Java process with a pid of 7268). Note that although jcmd works very much like jps when it comes to listing Java processes, jcmd lists more information than jps does without arguments -lm.

Running jcmd -h shows help and usage information for jcmd as demonstrated in the next screen snapshot.

The help explains, as was just shown, that jcmd "lists Java processes" when "no options are given." The help also states that this is behavior similar to running jcmd -p, but I think it means to say running jcmd without options is equivalent to running jcmd -l, which is shown in the next screen snapshot.

As when jcmd was run without any options, jcmd -l lists Java processes and their respective pids. The pids are different in this example because it's a different execution of jcmd and I have a different Java process running this time.

Running jcmd -h showed relatively few options. To see help on the many capabilities that jcmd supports, one needs to ask jcmd which capabilities are supported for a particular Java process. The next screen snapshot illustrates this. I first run jcmd without options to discover the pid of the Java process of interest (6320 in this case). Then, I am able to run jcmd 6320 help to see which commands jcmd supports.

The previous screen snapshot demonstrates the commands jcmd supports for the particular Java VM identified by the pid. Specifically, it states, "The following commands are available:" and then lists them:

  • JFR.stop
  • JFR.start
  • JFR.dump
  • JFR.check
  • VM.native_memory
  • VM.check_commercial_features
  • VM.unlock_commercial_features
  • ManagementAgent.stop
  • ManagementAgent.start_local
  • ManagementAgent.start
  • GC.rotate_log
  • GC.class_stats
  • GC.class_histogram
  • GC.heap_dump
  • GC.run_finalization
  • GC.run
  • Thread.print
  • VM.uptime
  • VM.flags
  • VM.system_properties
  • VM.command_line
  • VM.version
  • help

When jcmd <pid> help is run against a pid for a different Java VM process, it's possible to get a different list of available commands. This is illustrated in the next screen snapshot when jcmd 1216 help is executed against that process with pid of 1216.

By comparing the last two screen snapshots, it becomes clear that jcmd supports different commands for different Java VM instances. This is why the supported commands for a particular VM are listed by specifying the pid in the help command. Some of the commands available against the second VM (pid 1216 in this case) that were not listed for the originally checked VM include the following:

  • VM.log
  • ManagementAgent.status
  • Compiler.directives_clear
  • Compiler.directives_remove
  • Compiler.directives_add
  • Compiler.directives_print
  • VM.print_touched_methods
  • Compiler.codecache
  • Compiler.codelist
  • Compiler.queue
  • VM.classloader_stats
  • JVMTI.data_dump
  • VM.stringtable
  • VM.symboltable
  • VM.class_hierarchy
  • GC.finalizer_info
  • GC.heap_info
  • VM.info
  • VM.dynlibs
  • VM.set_flag

This "help" also advises, "For more information about a specific command use 'help <command>'." Doing this is illustrated in the next screen snapshot specifically for jcmd's Thread.print

While on the subject of jcmd Thread.print command, it's a good time to illustrate using this to see thread stacks of Java processes. The next screen snapshot shows the beginning of the much lengthier results seen when jcmd <pid> Thread.print is executed (in this case for the Java process with pid 6320).

There are several VM.* commands supported by jcmd: VM.version, VM.uptime, VM.command_line, VM.flags, VM.system_properties, VM.native_memory, and VM.classloader_stats. The next screen snapshot illustrates use of jcmd <pid> VM.version and jcmd <pid> VM.uptime for the Java process with pid 6320.

The next screen snapshot demonstrates execution of jcmd <pid> VM.command_line against process with pid 6320.

From this screen snapshot which shows the top portion of the output from running jcmd 6320 VM.command_line, we can see from the JVM command-line arguments that were provided to this process that it's a NetBeans-related process. Running the command jcmd <pid> VM.flags against Java process with pid 6320 shows the HotSpot options passed to that process.

The system properties used by a Java process can be listed using jcmd <pid> VM.system_properties and this is illustrated in the next screen snapshot.

When one attempts to run jcmd <pid> VM.native_memory against a Java process that hasn't had Native Memory Tracking (NMT) enabled, the error message "Native Memory Tracking is not enabled" is printed as shown in the next screen snapshot.

To use the command jcmd <pid> VM.native_memory, the JVM (java process) to be measured should be started with either the -XX:NativeMemoryTracking=summary or -XX:NativeMemoryTracking=detail options. Once the VM has been started with either of those options, the commands jcmd <pid> VM.native_memory baseline and then jcmd <pid> VM.native_memory detail.diff can be executed against that JVM process.

The command jcmd <pid> VM.classloader_stats provides insight into the classloader. This is shown in the next screen snapshot against Java process with pid 1216:

jcmd <pid> VM.class_hierarchy is an interesting command that prints the hierarchy of the classes loaded in the targeted Java VM process.

jcmd <pid> VM.dynlibs can be used to view dynamic libraries information. This is demonstrated in the next screen snapshot when executed against Java process with pid 1216.

The jcmd <pid> VM.info lists a lot of information regarding the targeted Java VM process including a VM summary and information about the process, garbage collection events, dynamic libraries, arguments provided to the VM, and some of the characteristics of the host machine. Just a small part of the beginning of the output of this is demonstrated in the next screen snapshot for jcmd 1216 VM.info:

The next screen snapshot demonstrates use of jcmd <pid> VM.stringtable and jcmd <pid> VM.symboltable:

Use of jcmd <pid> Compiler.directives_print is demonstrated in the next screen snapshot.

Several commands supported by jcmd support managing and monitoring garbage collection. Two of these are jcmd <pid> GC.run [similar to System.gc()] and jcmd <pid> GC.run_finalization [similar to System.runFinalization()]. The two of these are demonstrated in the next screen snapshot.

The command jcmd <pid> GC.class_histogram provides a handy way to view an object histogram as shown in the next screen snapshot.

jcmd can be used to generate a heap dump against a running Java VM with jcmd <pid> GC.heap_dump <filename> and this is demonstrated in the next screen snapshot.

The jhat command can now be used to process the heap dump generated by jcmd as shown in the next two screen snapshots.

There are some jcmd commands that only work against Java VMs that were started using the -XX:+UnlockDiagnosticVMOptions JVM flag. The next screen snapshot demonstrates what happens when I try to run jcmd <pid> GC.class_stats against a Java VM that wasn't started with the flag -XX:+UnlockDiagnosticVMOptions.

When the targeted VM is started with -XX:+UnlockDiagnosticVMOptions, jcmd <pid> GC.class_stats displays "statistics about Java class metadata."

This post has covered several of the commands provided by jcmd, but has not covered the functionality related to Java Flight Recorder [JFR] (commands with names starting with JFR.*), related to checking and enabling commercial features (jcmd <pid> VM.check_commercial_features and jcmd <pid> VM.unlock_commercial_features), and related to JMX-based management (ManagementAgent.start, ManagementAgent.start_local, ManagementAgent.stop, and ManagementAgent.status).

Relationship of jcmd to Other Command-line JDK Tools

FunctionalityjcmdSimilar Tool
Listing Java Processes jcmd jps -lm
Heap Dumps jcmd <pid> GC.heap_dump jmap -dump <pid>
Heap Usage Histogram jcmd <pid> GC.class_histogram jmap -histo <pid>
Thread Dump jcmd <pid> Thread.print jstack <pid>
List System Properties jcmd <pid> VM.system_properties jinfo -sysprops <pid>
List VM Flags jcmd <pid> VM.flags jinfo -flags <pid>

Conclusion

In one command-line tool, jcmd brings together the functionality of several command-line JDK tools. This post has demonstrated several of the functions provided by jcmd.

My Other Blog Posts Referencing jcmd