So, one of your colleagues complained that a Java application is using an “abnormally high” system CPU as opposed to user CPU. Where do you start to look? Once you find the root cause, how do you resolve the issue?

Well, this is exactly one issue I had to work on. In my case, the system CPU usage was consistently between 50% and 60% of the CPU. The Java application is a software product that runs on AIX which provides a lot of performance troubleshooting facilities. The first step, I thought, would be to run a performance trace that would identify which AIX routine the system (kernel) was using most. The performance trace revealed that the AIX kernel was executing the statx routine a lot more than any other routine. The performance trace also revealed that the AIX kernel was looking for certain files repeatedly, many times… some files were being repeatedly looked for thousands of times while other files were being repeatedly looked for hundreds of times. This was a huge number of lookups considering that the trace contained only a few seconds worth of data. Once the names of the files have been identified, that gave me a clue as most of these files looked like they are classes. I immediately suspected that this is something related to the Java class loader. I was not necessarily blaming the Java class loader, but this was where my focus should be. Before looking into the Java class loader, I wanted to do a check on those files that were found as reported by the AIX trace. We had collected thread dumps while running the AIX performance trace. So, considering the fact that the thread dumps show loaded classes and we had the names of the classes that were found as reported by the AIX trace, I was able to find references to these classes in the thread dumps.

To confirm further that some classes were not being found, one of the IBM Java class loader trace options was specified so we could collect one aspect of class loader execution. The option was: –Dibm.cl.verbose=*. This option is specified as a JVM startup parameter. The class loader trace confirmed that there were a number of classes that were never found. This confirmed the results of the AIX performance trace. The class loader trace also revealed that there were fully qualified filenames specified on the class path that do not exist. Since the product was functionally working as expected, we cleaned up the class path so that it did not specify those files that did not exist. Listing 1 shows an example class loader trace:

ExtClassLoader attempting to find classname

.

.

.

The class loader trace is quite verbose. I only included what is relevant. If you know the Java class loading delegation model, then you know that the parent class loader attempts to load a class before the child class loader. So, the bootstrap (root) class loader, which is implemented in a platform dependent language such as C, attempts to load a class first. If the class is not found, then the ExtClassLoader attempts to load the class. If the class is not found, then the AppClassLoader attempts to load the class. If the class is never found, this class lookup/load activity repeats again as the class is referenced by the code. Interestingly, the class loader trace that we collected did not have any reference to the bootstrap (root) class loader.

The first question I had after confirming that some classes were not found was: why didn’t the product fail? Why didn’t the product report that some classes were not found? The product architect confirmed that the logs did not have any ClassNotFoundException references. So, at this point, we knew why the system CPU usage was high, we knew it was something related to the Java class loader, but we had no clue what was triggering this problem. I suspected that some code is trying to use a class that was never loaded. This engaged the class loader to try to find the class by walking through the class path and trying to find that class.

In the next blog, I will provide the next steps I followed to get to the actual code that was triggering the class loader to search for classes that were never found.