IBM WebSphere Application Server Performance Cookbook

OpenJDK JCL and Tools

java.util.logging (JUL)

Log to System.err
  1. Create logging.properties and set all the trace levels at the end: 
    handlers=java.util.logging.ConsoleHandler 
java.util.logging.ConsoleHandler.level=ALL
java.util.logging.SimpleFormatter.format=[%1$tc] %4$s: %5$s %6$s%n

# Trace:
#.level=INFO
.level=ALL
#com.example.MyClass.level=ALL
  2. Set -Djava.util.logging.config.file=/$PATH/logging.properties
Log to a file
  1. Create logging.properties and set all the trace levels at the end: 
    handlers=java.util.logging.FileHandler
java.util.logging.FileHandler.pattern=/$PATH/jul.log   
java.util.logging.FileHandler.limit=100000
java.util.logging.FileHandler.count=2
java.util.logging.FileHandler.formatter=java.util.logging.SimpleFormatter
java.util.logging.SimpleFormatter.format=[%1$tc] %4$s: %5$s %6$s%n

# Trace:
.level=INFO
com.example.MyClass.level=ALL
  2. Set -Djava.util.logging.config.file=/$PATH/logging.properties
SimpleFormatter patterns

Available fields:

  1. date
  2. source: caller, if available; otherwise, the logger's name.
  3. logger
  4. level
  5. message
  6. thrown: throwable if any

The format is specified with format string syntax:

  • [%1$tc] %4$s: %5$s%n 
    [Fri Sep 25 12:13:14 PDT 2020] SEVERE: message
  • %1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS.%1$tL %4$-6s %3$s %5$s%6$s%n 
    2020-01-01 01:02:03.456 SEVERE com.example.MyClass message

Java >= 7 supports specifying SimpleFormatter.format with -Djava.util.logging.SimpleFormatter.format=$FORMAT

Reflection Inflation

For a discussion of reflection and inflation, see the general Java chapter. On the HotSpot JVM, the option -Dsun.reflect.inflationThreshold=0 creates an inflated Java bytecode accessor which is used on the second and every subsequent method invocation.

JSSE Debug

JSSE supports debug output to System.out with -Djavax.net.debug (example output); most commonly, -Djavax.net.debug=all

All the options are described in sun/security/ssl/Debug.java.

The value -Djavax.net.debug= is equivalent to disabling debug.

HTTP(S) Client (HttpURLConnection)

The OpenJDK JCL includes an HTTP client implemented using the abstract classes java/net/HttpURLConnection and javax/net/ssl/HttpsURLConnection and concrete classes sun/net/www/protocol/http/HttpURLConnection and sun/net/www/protocol/https/HttpsURLConnectionImpl. A client is created using the java/net/URL.openConnection method.

Timeouts
Keep-Alive

For HTTP/1.1 connections, the specification (RFC 2616) states that if the server does not respond with a Connection: close response header, then the connection should be treated as a keep-alive connection. The maximum duration may be specified wih the Keep-Alive: timeout=X (seconds) response header.

However, OpenJDK also requires that the server responds with a Connection: keep-alive header. It appears this logic is not required by the specification but it seems to be there for legacy reasons and is unlikely to be changed, particularly with the replacement HTTP client available since Java 11.

Therefore, if the server responds with Connection: keep-alive, then the connection is cached into an in-memory KeepAliveCache. This may be disabled with -Dhttp.keepAlive=false although this may impact performance (the main purpose of keep-alive connections is to avoid the TCP and TLS handshakes, which are relatively expensive). The maximum number of cached keep-alive connections per destination host is controlled with -Dhttp.maxConnections=X (default 5).

If the server responds with a Keep-Alive: timeout=X response header, then the KeepAliveCache will purge and close the connection after approximately X seconds of idleness. If the server does not respond with such a header, the default is 5 seconds. The timeout mechanism is implemented on a thread with the name Keep-Alive-Timer. The thread ends gracefully if there are no connections in the pool, and the thread is re-created when needed.

In summary, if the HttpURLConnection client is used, and the protocol is HTTP/1.1, and the server responds with a Connection: keep-alive header, and the server does not respond with a Keep-Alive: timeout=X header, then the client JDK will time-out the connection from its KeepAliveCache after 5 seconds of inactivity. In newer versions of Java (e.g. 8u361, IBM Java 8.0.8.0, etc.), this 5 second default is tunable with -Dhttp.keepAlive.time.server.

In general, for LAN connections that are expected to be persistent between a JCL HTTP(S) client and backend, set -Dhttp.maxConnections less than or equal to the maximum number of concurrent connections supported by the backend divided by the number of clients, ensure the backend is sending the Connection: keep-alive header, configure the Keep Alive Timeout relatively high (this may be limited by resource constraints or intermediate network device timeouts), and, if possible, configure the backend to send a Keep-Alive: timeout=X value that is slightly less than the timeout that it uses itself to time out connections (to avoid a race condition wherein the client re-uses a pooled connection which has already timed out on the backend).

For examples:

  • If WebSphere Liberty is acting as a server: 
    <httpEndpoint id="defaultHttpEndpoint"
              httpPort="9081"
              httpsPort="9444"
              headersRef="addResponseHeaders" />

<headers id="addResponseHeaders">
  <add>Connection: keep-alive</add>
  <add>Keep-Alive: timeout=30</add>
</headers>

<httpOptions persistTimeout="575h" />
  • If IHS is acting as a server, starting with IHS 9 or 8.5.5.19, when setting KeepAliveTimeout to a millisecond value, for example, KeepAliveTimeout 30999ms, then IHS will use this for its timeout but it will send back a Keep-Alive timeout response header rounded down to 30 seconds (in this example).
Expect: 100-Continue

This client has a limitation that if the request contains the header "Expect: 100-Continue", this will only automatically be processed by the JDK if streaming mode is enabled. Streaming mode is not enabled by default and it may be enabled by calling HttpURLConnection setChunkedStreamingMode or setFixedLengthStreamingMode.

HTTP(S) Client (HTTP Client)

Java 11 introduced the Java HTTP Client. This is a more modern alternative to HttpURLConnection, including support for HTTP/2 and it does not have limitations such as the Expect 100-Continue non-streaming mode limitation.

Starting with Java 20, the default idle connection timeout was reduced from 1200 to 30 seconds and jdk.httpclient.keepalive.timeout was enhanced to also apply to HTTP/2 connections.

Lightweight Directory Access Protocol (LDAP) Client

  • -Dcom.sun.jndi.ldap.connect.timeout=X: connection timeout in milliseconds
  • -Dcom.sun.jndi.ldap.read.timeout=X: read timeout in milliseconds for LDAP operations

https://docs.oracle.com/javase/8/docs/technotes/guides/jndi/jndi-ldap.html

ServerCommunicatorAdmin

The following warning message:

The server has decided to close this client connection.

is emitted by a subclass of com/sun/jmx/remote/internal/ServerCommunicatorAdmin.

This is within JMX because of a terminate call (probably from the timeout thread). Example output:

[5/15/20 19:20:49:708 EEST] 0000022b misc          W ServerCommunicatorAdmin reqIncoming The server has decided to close this client connection.

On J9-based JVMs, you may investigate who is creating and destroying these objects with:

-Xtrace:print=mt,methods={com/sun/jmx/remote/internal/ServerCommunicatorAdmin.<init>*},trigger=method{com/sun/jmx/remote/internal/ServerCommunicatorAdmin.<init>*,jstacktrace}

String.substring Performance

HotSpot V7 update 6 introduced a significant change to the implementation of java/lang/String, where calls to substring no longer return a "view" into the String, but instead return a copy (of the substring portion):

If profiling shows significant activity in substring or in array copy, then this may be why. In general, the change is believed to be positive because with the old behavior, the original, potentially very large, String cannot be garbage collected unitl all substrings are garbage collected. However, if applications use substring heavily, then they may need to be re-coded.

DNS Cache

The JVM has a DNS cache called the InetAddress cache. The cache timeout is first read from networkaddress.cache.ttl in the java.security file. Next, it is read from the system property -Dsun.net.inetaddr.ttl although this is deprecated. If neither property is set, and a SecurityManager is enabled (Java 2 Security on WebSphere), then successful lookups are cached forever; otherwise, successful lookups are cached for 30 seconds. Unsuccessful lookups are cached for 10 seconds (networkaddress.cache.negative.ttl or -Dsun.net.inetaddr.negative.ttl).

The result of evaluating localhost is not cached by default.

If the operating system supports both IPv4 and IPv6, then lookups will first be done over IPv6. If IPv6 is not the primary source, to instead do IPv4 first and avoid potential IPv6 timeouts, use -Djava.net.preferIPv4Stack=true.