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

Monday, February 22, 2016

Default HotSpot Maximum Direct Memory Size

In my previous blog post Improved Documentation of HotSpot Options in Java 8, I wrote about the misunderstandings surrounding the HotSpot JVM's default setting for non-standard option -XX:MaxDirectMemorySize. In this post, I look at a simple way to determine the "default" maximum direct memory size in the HotSpot JVM.

The Java 8 documentation for the Java launcher states the following regarding -XX:MaxDirectMemorySize (I added the emphasis):

Sets the maximum total size (in bytes) of the New I/O (the java.nio package) direct-buffer allocations. Append the letter k or K to indicate kilobytes, m or M to indicate megabytes, g or G to indicate gigabytes. By default, the size is set to 0, meaning that the JVM chooses the size for NIO direct-buffer allocations automatically.

The above explains that 0 is the default for maximum direct memory size in HotSpot when no size is explicitly specified via the -XX:MaxDirectMemorySize option. Using options such as -XX:+PrintFlagsInitial and -XX:+PrintFlagsFinal doesn't help in this case because the values these would display is also zero when not explicitly specified. For example, running java -XX:+PrintFlagsFinal -version displays:

     size_t MaxDirectMemorySize                       = 0

As far as I know, there is no "standard" way to access the maximum direct memory size. The class java.lang.Runtime provides information on approximate free memory in the JVM, total memory in the JVM, and maximum memory the JVM will attempt to use. Although java.lang.management.MemoryMXBean offers non-heap memory usage in addition to heap memory usage, this non-heap usage refers to the "method area" and possibly an implementation's "internal processing or optimization" rather than to direct memory.

There are some non-standard approaches to determining one's HotSpot JVM default maximum memory size. In the StackOverflow thread Is there a way to measure direct memory usage in Java?, whiskeyspider writes about sun.misc.SharedSecrets.getJavaNioAccess().getDirectBufferPool().getMemoryUsed()‌​ and sun.misc.VM.maxDirectMemory(). These HotSpot-specific classes respectively indicate the amount of direct memory being used and the maximum amount of direct memory that can be used.

The sun.misc.SharedSecrets class provides information on direct memory use via method calls getJavaNioAccess().getDirectBufferPool() to access an instance of sun.misc.JavaNioAccess.BufferPool. The BufferPool interface defines three methods providing direct memory related details: getCount(), getTotalCapacity(), and getMemoryUsed(). Although these methods provide interesting details about direct memory use, they don't tell us what the maximum direct memory is.

The sun.misc.VM.maxDirectMemory() method in the HotSpot JVM supplies us with the maximum direct memory whether it was explicitly specified with -XX:MaxDirectMemorySize= or whether it was implicitly set such that -XX:MaxDirectMemorySize=0 (default) and the VM selects the maximum size of direct memory.

To help demonstrate using these methods to determine maximum direct memory and direct memory used, I first introduce a utility I'll be using in my examples. This enum is named MemoryUnit and is adapted for this post from dustin.utilities.memory.MemoryUnit.java. I could have used Apache Commons's FileUtils.byteCountToDisplaySize(long) or Brice McIver's more elaborate adaptation of it, but decided to use this simple TimeUnit-inspired enum as shown next.

MemoryUnit.java
package dustin.examples.maxdirectmemory;

/**
 * Representation of basic memory units.
 */
public enum MemoryUnit
{
   /** Smallest memory unit. */
   BYTES,
   /** "One thousand" (1024) bytes. */
   KILOBYTES,
   /** "One million" (1024x1024) bytes. */
   MEGABYTES,
   /** "One billion" (1024x1024x1024) bytes. */
   GIGABYTES;

   /** Number of bytes in a kilobyte. */
   private final double BYTES_PER_KILOBYTE = 1024.0;
   /** Number of kilobytes in a megabyte. */
   private final double KILOBYTES_PER_MEGABYTE = 1024.0;
   /** Number of megabytes per gigabyte. */
   private final double MEGABYTES_PER_GIGABYTE = 1024.0;

   /**
    * Returns the number of bytes corresponding to the
    * provided input for a particular unit of memory.
    *
    * @param input Number of units of memory.
    * @return Number of bytes corresponding to the provided
    *    number of particular memory units.
    */
   public double toBytes(final long input)
   {
      double bytes;
      switch (this)
      {
         case BYTES:
            bytes = input;
            break;
         case KILOBYTES:
            bytes = input * BYTES_PER_KILOBYTE;
            break;
         case MEGABYTES:
            bytes = input * BYTES_PER_KILOBYTE * KILOBYTES_PER_MEGABYTE;
            break;
         case GIGABYTES:
            bytes = input * BYTES_PER_KILOBYTE * KILOBYTES_PER_MEGABYTE * MEGABYTES_PER_GIGABYTE;
            break;
         default :
            throw new RuntimeException("No value '" + this + "' recognized for enum MemoryUnit.");
      }
      return bytes;
   }

   /**
    * Returns the number of kilobytes corresponding to the
    * provided input for a particular unit of memory.
    *
    * @param input Number of units of memory.
    * @return Number of kilobytes corresponding to the provided
    *    number of particular memory units.
    */
   public double toKiloBytes(final long input)
   {
      double kilobytes;
      switch (this)
      {
         case BYTES:
            kilobytes = input / BYTES_PER_KILOBYTE;
            break;
         case KILOBYTES:
            kilobytes = input;
            break;
         case MEGABYTES:
            kilobytes = input * KILOBYTES_PER_MEGABYTE;
            break;
         case GIGABYTES:
            kilobytes = input * KILOBYTES_PER_MEGABYTE * MEGABYTES_PER_GIGABYTE;
            break;
         default:
            throw new RuntimeException("No value '" + this + "' recognized for enum MemoryUnit.");
      }
      return kilobytes;
   }

   /**
    * Returns the number of megabytes corresponding to the
    * provided input for a particular unit of memory.
    *
    * @param input Number of units of memory.
    * @return Number of megabytes corresponding to the provided
    *    number of particular memory units.
    */
   public double toMegaBytes(final long input)
   {
      double megabytes;
      switch (this)
      {
         case BYTES:
            megabytes = input / BYTES_PER_KILOBYTE / KILOBYTES_PER_MEGABYTE;
            break;
         case KILOBYTES:
            megabytes = input / KILOBYTES_PER_MEGABYTE;
            break;
         case MEGABYTES:
            megabytes = input;
            break;
         case GIGABYTES:
            megabytes = input * MEGABYTES_PER_GIGABYTE;
            break;
         default:
            throw new RuntimeException("No value '" + this + "' recognized for enum MemoryUnit.");
      }
      return megabytes;
   }

   /**
    * Returns the number of gigabytes corresponding to the
    * provided input for a particular unit of memory.
    *
    * @param input Number of units of memory.
    * @return Number of gigabytes corresponding to the provided
    *    number of particular memory units.
    */
   public double toGigaBytes(final long input)
   {
      double gigabytes;
      switch (this)
      {
         case BYTES:
            gigabytes = input / BYTES_PER_KILOBYTE / KILOBYTES_PER_MEGABYTE / MEGABYTES_PER_GIGABYTE;
            break;
         case KILOBYTES:
            gigabytes = input / KILOBYTES_PER_MEGABYTE / MEGABYTES_PER_GIGABYTE;
            break;
         case MEGABYTES:
            gigabytes = input / MEGABYTES_PER_GIGABYTE;
            break;
         case GIGABYTES:
            gigabytes = input;
            break;
         default:
            throw new RuntimeException("No value '" + this + "' recognized for enum MemoryUnit.");
      }
      return gigabytes;
   }
}

With MemoryUnit available as a helper utility, the next code example demonstrates using the methods on the JavaNioAccess.BufferPool provided by SharedSecrets. These values aren't the maximum possible direct memory, but are instead estimates of the direct memory already being used.

/**
 * Write amount of direct memory used to standard output
 * using SharedSecrets, JavaNetAccess, the direct Buffer Pool,
 * and methods getMemoryUsed() and getTotalCapacity().
 */
public static void writeUsedDirectMemoryToStdOut()
{
   final double sharedSecretsMemoryUsed =
      MemoryUnit.BYTES.toMegaBytes(
         SharedSecrets.getJavaNioAccess().getDirectBufferPool().getMemoryUsed());
   out.println(
      "sun.misc.SharedSecrets.getJavaNioAccess().getDirectBufferPool().getMemoryUsed(): "
         + sharedSecretsMemoryUsed + " MB");
   final double sharedSecretsTotalCapacity =
      MemoryUnit.BYTES.toMegaBytes(SharedSecrets.getJavaNioAccess().getDirectBufferPool().getTotalCapacity());
   out.println("sun.misc.SharedSecrets.getJavaNioAccess().getDirectBufferPool().getTotalCapacity(): "
      + sharedSecretsTotalCapacity + " MB");
}

The above code can be executed after placing something in direct memory with a line similar to the following:

final ByteBuffer bytes = ByteBuffer.allocateDirect(1_000_000);

When direct memory is used as shown above and the code above that is executed, the output looks like this:

sun.misc.SharedSecrets.getJavaNioAccess().getDirectBufferPool().getMemoryUsed(): 0.95367431640625 MB
sun.misc.SharedSecrets.getJavaNioAccess().getDirectBufferPool().getTotalCapacity(): 0.95367431640625 MB

The methods just demonstrated provide estimates of the amount of direct memory being used, but still do not show the maximum available direct memory. This can be determined with VM.maxDirectMemory as shown in the next code listing.

/**
 * Write maximum direct memory size set (explicitly or
 * implicitly) for this VM instance using VM's
 * method maxDirectMemory().
 */
public static void writeMaximumDirectMemorySizeToStdOut()
{
   final double vmSize =
      MemoryUnit.BYTES.toMegaBytes(VM.maxDirectMemory());
   out.println(
       "sun.misc.VM.maxDirectMemory(): " + vmSize + " MB");
}

When the above code is executed on my laptop with JDK 8 and no explicitly specified -XX:MaxDirectMemorySize, the result looks like this:

sun.misc.VM.maxDirectMemory(): 1804.5 MB

From this, I can see that the JVM running on my machine has a default maximum direct memory size of approximately 1.8 GB. I know this is the default because I haven't explicitly specified -XX:MaxDirectMemorySize on the command-line and because running the sample Java application with -XX:+PrintFlagsFinal shows zero (default) for it.

To assure myself that this approach is showing the correct maximum direct memory, I can explicitly specify the maximum direct memory on the command line and see what the code shown above writes out. In this case, I'm providing -XX:MaxDirectMemorySize=3G on the command-line. Here's the output when I run the above code with that explicit setting:

sun.misc.VM.maxDirectMemory(): 3072.0 MB

Most of the code listings shown in this post can be found on GitHub.

Conclusion

When one needs to know the maximum direct memory available for a particular application running on the HotSpot JVM, the method VM.maxDirectMemory() is what is probably the easiest way to get this information if -XX:MaxDirectMemorySize is not explicitly specified. Knowing the maximum allowed direct memory can be useful when working directly with Java NIO or even when working with Java NIO indirectly while working with products that use Java NIO such as Terracotta and Hazelcast "offheap" options.

Monday, February 8, 2016

Simplicity and Value of HotSpot's -XshowSettings Flag

A handy HotSpot JVM flag (option for the Java launcher java) is the -XshowSettings option. This option is described in the Oracle Java launcher description page as follows:

-XshowSettings:category

Shows settings and continues. Possible category arguments for this option include the following:

all

Shows all categories of settings. This is the default value.

locale

Shows settings related to locale.

properties

Shows settings related to system properties.

vm

Shows the settings of the JVM.

This flag can be easily used with the Java launcher using syntax such as java -XshowSettings. In this case, it's as if the all category was provided and locale information, system properties information, and virtual machine settings will be displayed. However, when executed list that, the help/usage information for running the Java launcher will also be displayed and, because that usage information is displayed after the locale, properties, and VM information, it can make it a bit less convenient to see those details. A common approach used to avoid the displaying of the verbose usage information for java when using flags such as -XshowSettings, -XX:+PrintFlagsInitial, and -XX:+PrintFlagsFinal is to also supply the -version argument. This allows the results of the other flag to be seen more clearly with only the JVM version details added (which are more succinct than the usage information).

The next several screen snapshots demonstrate using this option to get useful details regarding one's HotSpot JVM.

java -XshowSettings:locales -version

java -XshowSettings:properties -version (not all shown)

java -XshowSettings:vm -version

Running java -XshowSettings:all (or simply its default equivalent java -XshowSettings) will show locales, properties, and virtual machine details. Note that although the -X in the flag tells us this is a non-standard flag, OpenJDK has had support for this flag since late 2010.

The -XshowSettings Java launcher option is another example of the growing number of simple tools and options added in later versions of Java that make things that seem like they should be simple even simpler to accomplish. Besides displaying locales details, system properties, and virtual machine information, I'd love to see a future version of this option include a category for timezones available on a given JVM. There are ways to get timezones now that aren't too complicated, but the approach -XshowSettings provides for listing locales seems like a natural fit for listing supported timezones.

Saturday, February 6, 2016

Improved Documentation of HotSpot Options in Java 8

One of the small but welcome features introduced with Oracle's HotSpot implementation of Java 8 is the addition of many common HotSpot Java launcher (java) options/flags to the launcher's documentation. In the past, a developer interested in even some fairly common HotSpot JVM options has had to potentially look in multiple different sources to find "official" documentation on these flags. These sources included the aforementioned Java launcher documentation as we all other resources such as Troubleshooting Guide for Java SE 6 with HotSpot VM, Troubleshooting Guide for HotSpot VM (7), and Java 8 Troubleshooting Guide. There have also been numerous "unofficial" sources documenting these options such as in books and The most complete list of -XX options for Java JVM.

One of the risks to be aware of when reading about HotSpot JVM options from disparate sources is that it is easy to start reading about a certain JVM option not realizing that the documentation is explicitly for JVMs other than HotSpot such as JRockit or IBM's JVM. JRockit's documentation can be particularly misleading if the developer is not paying close attention because it is available with an Oracle URL and with Oracle logos.

An example of JRockit JVM option documentation being confused as HotSpot JVM option documentation is a feedback comment on the blog post How to Fix java.lang.OufOfMemoryError: Direct Buffer Memory that "corrects" the author's statement about the default JVM maximum direct buffer limit by referencing JRockit documentation (but JRockit's default of 0 leads to very different behavior than HotSpot's default also of 0). In a different but related example, a poster on the StackOverflow thread Default for XX:MaxDirectMemorySize makes the same mistake and also references the JRockit documentation despite the question being, "What is the default value for XX:MaxDirectMemorySize for SUN JVM 1.6?" Having common HotSpot options documented in the main Java launcher documentation should help reduce these frequent causes of confusion about HotSpot VM options' behavior.

Two examples of HotSpot JVM options now documented directly in the Java launcher (the executable java to which the options apply) documentation are -XX:+HeapDumpOnOutOfMemory and -XX:MaxDirectMemorySize. The documentation for the Oracle HotSpot 8 Java launcher describes these two example options as shown next:

These and several other HotSpot JVM options that were available before Java 8 are not described in prior versions of the Java launcher documentation such as for Java 7 and Java 6. This is a small but nonetheless welcome addition that is just one small part of a long list of reasons for moving to Java 8 from older versions.