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 it 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.