Wednesday, September 5, 2018

Mysterious Latency

The project was underway and we've started looking into performance tuning. The eG system monitoring tool flagged out webservice transactions lasting more than a few seconds. The application was apparently choking for more than 4 seconds on Java code. But it was not just any chunk of logic. The method being flagged was org.apache.cxf.transport.servlet.AbstractHTTPServlet; which was part of the CXF library. This was not even part of our custom codes.

I'd fired up the Java VisualVM to inspect the thread stack on my local machine. We had a couple of guys help take a look at the latency as well, diving into the log files. We'd pretty much stumbled upon the same issue from different angles.

The framework we're using adopts CXF, which in turn is able to output SOAP requests and responses to the log files. By setting the loggingInInterceptor and/or loggingOutInterceptor, we were debugging the XML content in the staging environment. The "limit" property was set to "-1" for both, in order to log entire payloads. This, of course, did not sit well with the other environment looking at the performance aspects of the system. This logging activity was costing an additional 5 seconds at times, according to the log (ironic, I know). We'd then recommended for the property to be set to "0" instead, so that zero bytes of the payloads will be logged.

Connecting Java VisualVM to WebSphere 8
Referring to this post, I'd added the following JVM arguments into my WebSphere
-Djavax.management.builder.initial= -Dcom.sun.management.jmxremote  -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.port=1099 -Djava.rmi.server.hostname=MYHOSTNAME

Subsequently following this article that's a bit clearer, I'd then connect via VisualVM to the localhost:1099, which was then able to sample the method calls with indications of self execution times.

Configuring CXF logging
The XML configuration of the CXF interceptors look something like this:
<bean id="loggingInInterceptor" class="org.apache.cxf.interceptor.LoggingInInterceptor" parent="abstractLoggingInterceptor">
    <property name="limit" value="-1"/>
</bean>
<bean id="loggingOutInterceptor" class="org.apache.cxf.interceptor.LoggingOutInterceptor" parent="abstractLoggingInterceptor">
    <property name="limit" value="-1"/>
</bean>

Which goes without saying, that the limits should be set to a value other than "-1" if you don't want/need the SOAP for debugging, especially outside of a development environment.

This is extra important if your XML includes one or more image binaries encoded as Base64 strings.

Wednesday, June 6, 2018

Maven Install does not Package


This episode started with our use of Jenkins. But ultimately it had to do with how Maven was behaving with regards to the various lifecycle phases. Our original command was "mvn clean install". 

This would be the norm for most of our projects, except for one module which was generating stub files from the WSDL of another. One particular object - let's just call it com.blogger.quirksofit.vehicles.QuirkyParentType - is being extended by numerous others in a com.blogger.quirksofit.vehicles.cars subpackage. Class QuirkyParentType will always be generated into com.blogger.quirksofit.vehicles, but depending on how the project JAR was being built, QuirkyParentType may or may not be generated into com.blogger.quirksofit.vehicles.cars where the subclasses reside.

This problem doesn't surface until our tests where the first module calls the other. The backend replies with an ambiguous XML tag for QuirkyParentType which the front determines to be part of the com.blogger.quirksofit.vehicles.cars subpackage. And if the Maven build was not done correctly, this will all break.

We noticed that "mvn clean install package" helped, to a certain extent. The source file for QuirkyParentType was generated, but it was still not propagated into the Maven repository. What did manage to do the trick, was when we tried to call "mvn clean package install" out of exasperation. We'd previously assumed that the Install phase should call Package first. This did not happen for some reason. And by putting package after install, the repository was updated before the source was generated.

Finally, we put all of this into Jenkins to complete the build and left for home, and our late night dinners.

Quartz Scheduler needs synchronised clocks in clustered environment

We had batch jobs that we refusing to work and were misbehaving with erratic schedules that were rarely successful. The tasks were making use of Quartz which were sitting in a cluster of servers. We didn't think much of it that one of the servers were misconfigured with a different timezone previously as this was in a development setup. This errant server was 8 hours behind, using UTC as its timezone.

A few attempts later, I managed to convince the machine to adopt our timezone instead. But the application server still refuses to follow suit. Fortunately, I found out how to change its timezone as well, after a few false starts.

The jobs then came back to life after they snapped out of their jetlag. The difference in timezone was causing a lot of misfirings to occur as each cluster node checked in on each other via the database.

Tuesday, May 15, 2018

ConcurrentHashMap bug compiling on Java 8 for Java 7

It's been a long couple of months, but I'm back with another quirky discovery.

TL;DR - we changed all declarations of ConcurrentHashMap to Map.

The current project has a number of components. Some are to be deployed on a Java 7 runtime, others make use of newer capabilities on a Java 8 runtime. While trying to streamline the build process using Jenkins, this issue came up while I was switching over from Java 7 to 8. We'd normally assume that it'd suffice for Maven to build with the specific major version in mind using maven.compiler.source and maven.compiler.target configured either in the POM or over the command line. Despite these additions, the runtime would still complain of the following error somewhere in our codes:

java.lang.NoSuchMethodError: java.util.concurrent.ConcurrentHashMap.keySet()Ljava/util/concurrent/ConcurrentHashMap$KeySetView;

A bit of searching turned up this post that explained

Notably the Java 1.7 ConcurrentHashMap#keySet() returns a Set<K> while the 1.8 ConcurrentHashMap#keySet() returns a ConcurrentHashMap.KeySetView<K,V>.

The OP then proceeded to suggested to simply edit the declaration of the ConcurrentHashMap to Map as a workaround.

Other solutions I found mentioned
  1. configuring the -bootclasspath of the Maven build path to point to the rt.jar of the older JDK;
  2. setting up a separate Jenkins/Maven for both halves of the project targetting different Java versions;
Both solutions are not feasible essentially because besides the fact that I'm unwilling to break up the Jenkins for the components using Java 7 and 8 respectively, such a differentiation would eventually get lost in translation, and anybody on the team that tries building similarly on their own (using any combination of JDK/Maven/IDE) may still encounter the same problem unwittingly, thereby costing even more man-hours to investigate and fix.

Editing the declaration would still seem less painful in the long run.

Digging further turned up a bug report which was closed as "Not an issue". The workaround suggested was not exactly helpful, compared to the first article I'd located, but apparently it was related to JSR166.