Signup for new content

deadline-stopwatch-640-285

Unit-Level Performance tuning in Java

How to simply improve performance of your java applications. Everything purely in IDE, without even starting the whole app.

When it comes to performance testing, I hear a lot about having a dedicated environment, funky tools like JMeter or Apica, and complicated scenarios. These take a lot of effort to set up and maintain. Therefore, I like to first make sure that the most critical units are well-optimized without any of these tools. One way to make this is through unit-level performance test apps. What’s great about these apps is that there is no need for any special tool, they can be ready to go within a minutes and they are proven to save a lot of time, money, and calls from angry customers.

In this article, I am going to share an example of such a test app. You can do the same in your projects.

Technology stack:

  • Netbeans IDE
  • Java
  • Maven

Testable Unit

In order to be able to run performance tests for a single unit, there is a need to have well-defined and testable units. Let’s work with an example (I have cooked this one, but you will get the idea).

This is a module for message broadcasting. Core method accepts pipe delimited String as an input, extracts parameters, finds the appropriate username, and broadcasts the messages. Following the implementation.

package com.enterprisemath.articles.unitperformance;

/**
 * Provider for user related data.
 * 
 * @author radek.hecl
 */
public interface UserProvider {

 /**
  * Returns user name.
  * 
  * @param userId user id
  * @return user name
  */
 public String getUserName(String userId);

}

// -----------------------------------------------------

package com.enterprisemath.articles.unitperformance;

import java.util.Date;

/**
 * Service for message broadcast.
 * 
 * @author radek.hecl
 */
public interface BroadcastService {

 /**
  * Broadcasts message.
  * 
  * @param userName user name
  * @param timestamp timestamp
  * @param message message
  */
 public void broadcastMessage(String userName, Date timestamp, String message);

}

// -----------------------------------------------------

package com.enterprisemath.articles.unitperformance;

import com.enterprisemath.utils.Dates;
import com.enterprisemath.utils.ValidationUtils;
import java.util.Date;
import org.apache.commons.lang3.builder.ToStringBuilder;

/**
 * Module for message broadcasting.
 *
 * @author radek.hecl
 */
public class MessageBroadcastModule {

 /**
  * Provider for user data.
  */
 private UserProvider userProvider;

 /**
  * Service for broadcast.
  */
 private BroadcastService broadcastService;

 /**
  * Creates new instance.
  */
 private MessageBroadcastModule() {}

 /**
  * Guards this object to be consistent. Throws exception if this is not the case.
  */
 private void guardInvariants() {
  ValidationUtils.guardNotNull(userProvider, "userProvider cannot be null");
  ValidationUtils.guardNotNull(broadcastService, "broadcastService cannot be null");
 }

 /**
  * Processes message.
  *
  * @param message message
  */
 public void processMessage(String message) {
  String[] parts = message.split("\\|");
  String userName = null;
  String txt = null;
  Date now = null;
  for (String part: parts) {
   String[] subs = part.split("=", 2);
   if (subs[0].equals("userId")) {
    userName = userProvider.getUserName(subs[1]);
   }
   else if (subs[0].equals("timestamp")) {
    now = Dates.parse(subs[1], "yyyy/MM/dd HH:mm:ss");
   }
   else if (subs[0].equals("message")) {
    txt = subs[1];
   }
  }

  ValidationUtils.guardNotNull(userName, "wrong input message, user is missing");
  ValidationUtils.guardNotNull(txt, "wrong input message, text is missing");
  ValidationUtils.guardNotNull(now, "wrong input message, timestamp is missing");
  broadcastService.broadcastMessage(userName, now, txt);

 }

 @Override
 public String toString() {
  return ToStringBuilder.reflectionToString(this);
 }

 /**
  * Creates new instance.
  *
  * @param userProvider provider for user data
  * @param broadcastService broadcast service
  * @return created object
  */
 public static MessageBroadcastModule create(UserProvider userProvider, BroadcastService broadcastService) {
  MessageBroadcastModule res = new MessageBroadcastModule();
  res.userProvider = userProvider;
  res.broadcastService = broadcastService;
  res.guardInvariants();
  return res;
 }

}

If you want to compile this, here is a POM file with dependencies:

<project
    xmlns="http://maven.apache.org/POM/4.0.0"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/maven-v4_0_0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>com.enterprisemath.articles</groupId>
    <artifactId>unitperformance</artifactId>
    <packaging>jar</packaging>
    <version>1.0-SNAPSHOT</version>
    <name>unitperformance</name>
    <url>http://maven.apache.org</url>
    <dependencies>
        <dependency>
            <groupId>com.enterprisemath</groupId>
            <artifactId>em-utils</artifactId>
            <version>2.4.0</version>
        </dependency>
        <dependency>
            <groupId>junit</groupId>
            <artifactId>junit</artifactId>
            <version>4.10</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.mockito</groupId>
            <artifactId>mockito-core</artifactId>
            <version>1.9.5</version>
            <scope>test</scope>
        </dependency>
    </dependencies>
</project>

The core method is called processMessage. In more detail, this method does following:

  1. Splits input into parts.
  2. Maps relevant parameters and finds the username.
  3. Validates that all mandatory parameters for this module are presented.
  4. Broadcasts the message.

If you want to properly test this method, then test case has to cover following:

  1. Positive case, when message is broadcasted
  2. Negative cases, when validation failed
  3. Make sure that no harmful side effect is caused

And here is the example impementation.

package com.enterprisemath.articles.unitperformance;
import com.enterprisemath.utils.Dates;
import com.enterprisemath.utils.Month;
import org.apache.commons.lang3.builder.ToStringBuilder;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.fail;
import org.junit.Before;
import org.junit.Test;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyNoMoreInteractions;
import static org.mockito.Mockito.when;

/**
 * Test case for message broadcast module.
 *
 * @author radek.hecl
 */
public class MessageBroadcastModuleTest {

 /**
  * Provider for user data.
  */
 private UserProvider userProvider;

 /**
  * Service for broadcast.
  */
 private BroadcastService broadcastService;

 /**
  * Tested module.
  */
 private MessageBroadcastModule module;

 /**
  * Creates new instance.
  */
 public MessageBroadcastModuleTest() {}

 /**
  * Sets up test environment.
  */
 @Before
 public void setUp() {
  userProvider = mock(UserProvider.class);
  broadcastService = mock(BroadcastService.class);
  module = MessageBroadcastModule.create(userProvider, broadcastService);
 }

 /**
  * Tests message processing.
  */
 @Test
 public void testProcessMessage() {

  when(userProvider.getUserName("1")).thenReturn("John Seaman");
  module.processMessage("userId=1|message=Hello world|timestamp=2017/01/01 12:00:00|ip=127.0.0.1|city=Brno|age=12|occupation=student");

  try {
   module.processMessage("message=Hello world|timestamp=2017/01/01 12:00:00|ip=127.0.0.1|city=Brno|age=12|occupation=student");
   fail("exception expected");
  } catch (RuntimeException e) {
   assertTrue(e.getMessage(), e.getMessage().contains("wrong input message, user is missing"));
  }

  try {
   module.processMessage("userId=1|message=Hello world0|ip=127.0.0.1|city=Brno|age=12|occupation=student");
   fail("exception expected");
  } catch (RuntimeException e) {
   assertTrue(e.getMessage(), e.getMessage().contains("wrong input message, timestamp is missing"));
  }

  try {
   module.processMessage("userId=1|timestamp=2017/01/01 12:00:00|ip=127.0.0.1|city=Brno|age=12|occupation=student");
   fail("exception expected");
  } catch (RuntimeException e) {
   assertTrue(e.getMessage(), e.getMessage().contains("wrong input message, text is missing"));
  }

  verify(broadcastService).broadcastMessage("John Seaman", Dates.createTime(2017, Month.JANUARY, 1, 12, 0, 0), "Hello world");

  verifyNoMoreInteractions(broadcastService);
 }

 @Override
 public String toString() {
  return ToStringBuilder.reflectionToString(this);
 }
}

In the unit test you can see one happy case and 3 cases where validation failed. In addition you can see there invocation of verifyNoMoreInteractions to check that broadcastService doesn’t broadcasted any unwanted messages. That would be a harmful side effect. On the other hand userProvider doesn’t need to have this protection, because it performs read only operation (assuming it is truly read only and multiple readings are not causing anything harm). Regardless your coding style it is important to make similar work and make sure code is logically correct before starting with any optimization.

Test Application and Profiler

Now, when you have a code separated to the isolated unit and well defined unit tests, you are ready to start optimizing the performance. Before writing anything, ask yourself a question: Is this a critical part of the application? If answer is not, then it’s better not to optimize. Examples of critical parts are:

  • Methods called hundreds of millions of times.
  • Methods that process a lot of records.
  • Methods aggregating data from third parties in (near) real-time.

If you evaluated your method as a critical part of the application, then it is time to write the test application. Typically, you can place the test application right next to the unit tests. Here is the example.

package com.enterprisemath.articles.unitperformance;

import com.enterprisemath.utils.Dates;
import com.enterprisemath.utils.Month;
import java.util.ArrayList;
import java.util.Date;
import java.util.List;
import org.apache.commons.lang3.time.DateUtils;
import static org.mockito.Matchers.any;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.when;
import org.mockito.invocation.InvocationOnMock;
import org.mockito.stubbing.Answer;

/**
 * Performance test application for message broadcast module.
 *
 * @author radek.hecl
 */
public class MessageBroadcastModulePerformanceTestApp {

 /**
  * Prevents construction.
  */
 private MessageBroadcastModulePerformanceTestApp() {}

 /**
  * Main method.
  *
  * @param args arguments
  */
 public static void main(String args[]) {

  //
  // set up
  System.out.println("Setting up and generating test data");

  UserProvider userProvider = mock(UserProvider.class);

  BroadcastService broadcastService = new BroadcastService() {
   public void broadcastMessage(String userName, Date timestamp, String message) {}
  };

  MessageBroadcastModule module = MessageBroadcastModule.create(userProvider, broadcastService);

  System.out.println("Generating test data");

  when(userProvider.getUserName(any(String.class))).thenAnswer(new Answer < String > () {
   public String answer(InvocationOnMock invocation) throws Throwable {
    //Thread.sleep(10);
    String id = (String) invocation.getArguments()[0];
    return "user " + id;
   }
  });

  Date ts = Dates.createDate(2017, Month.JANUARY, 1);
  List < String > messages = new ArrayList < String > (1000000);
  for (int i = 0; i < 1000000; ++i) {
   int usid = i % 50;
   ts = DateUtils.addMilliseconds(ts, 1);
   messages.add("userId=" + usid + "|message=Hello world|timestamp=" + Dates.format(ts, "yyyy/MM/dd HH:mm:ss") +
    "|ip=127.0.0.1|city=Brno|age=12|occupation=student");
  }

  System.out.println("Set up completed and data generated");

  //
  // wait to give user chance to connect profiler
  System.out.println("Timeout to allow attach profiler");

  try {
   for (int i = 0; i < 20; ++i) {
    Thread.sleep(1000);
    System.out.print(".");
   }
   System.out.println("");
  } catch (InterruptedException e) {
   throw new RuntimeException(e);
  }
  System.out.println("Finished waiting for profiler");

  //
  // test
  System.out.println("Started performance test");

  long startTime = System.currentTimeMillis();
  for (String msg: messages) {
   module.processMessage(msg);
  }
  long endTime = System.currentTimeMillis();

  System.out.println("Performance test finished");

  //
  // dump the result
  long duration = endTime - startTime;
  System.out.println("Num messages = " + messages.size());
  System.out.println("Duration = " + duration + "; referenceDuration = 14882");
  System.out.println("Duration / message = " + ((double) duration / messages.size()));
  System.out.println("JOB DONE!!!");
 }

}

Usually, this is just small application containing four parts:

  1. Environment setup and data generation (it is desired to exclude this from measurement).
  2. A waiting period to allow user connect profiler.
  3. Test execution.
  4. Result presentation.

As you can see I have used mockito to mock userProvider. And broadcastService is implemented inline. Both ways allow you to create a unit performance test without even having the real implementation of dependent services. For this purpose, the difference in them is that the mock version carries additional overhead. The right choice depends on the particular use case. That’s all about setup.

Starting Profiler

When you have your application ready, you can run it and attach the profiler during the prepared waiting period (to get good results, you should attach the profiler during that time). In NetBeans, it is pretty easy. Application can be run by the right click and then Run File option. Profiler is attached from top menu bar as Profile > Attach Profiler, then choose CPU and click Attach. Finally, choose your application and click OK. For illustration, please see the images below.

Analyzing Results

If everything is done everything correctly, then the console should look familiar to the following dump after the application finishes. See the profile attachment inside the waiting period (in the middle of the dots):

cd C:\projects\enterprisemath.com\articles\unitperformance; "JAVA_HOME=C:\\Program Files\\Java\\jdk1.8.0_25" cmd /c "\"\"C:\\Program Files\\NetBeans 8.0.1\\java\\maven\\bin\\mvn.bat\" -Dexec.args=\"-classpath %classpath com.enterprisemath.articles.unitperformance.MessageBroadcastModulePerformanceTestApp\" -Dexec.executable=\"C:\\Program Files\\Java\\jdk1.8.0_25\\bin\\java.exe\" -Dexec.classpathScope=test -Dmaven.ext.class.path=C:\\Users\\radek.hecl\\AppData\\Roaming\\NetBeans\\8.0.1\\maven-nblib\\netbeans-eventspy.jar org.codehaus.mojo:exec-maven-plugin:1.2.1:exec\""
Running NetBeans Compile On Save execution. Phase execution is skipped and output directories of dependency projects (with Compile on Save turned on) will be used instead of their jar artifacts.
Scanning for projects...

------------------------------------------------------------------------
Building unitperformance 1.0-SNAPSHOT
------------------------------------------------------------------------

--- exec-maven-plugin:1.2.1:exec (default-cli) @ unitperformance ---
Setting up and generating test data
Generating test data
Set up completed and data generated
Timeout to allow attach profiler
..............Profiler Agent: Waiting for connection on port 5140 (Protocol version: 15)
.Profiler Agent: Established connection with the tool
Profiler Agent: Local accelerated session
.....
Finished waiting for profiler
Started performance test
Performance test finished
Num messages = 1000000
Duration = 15530; referenceDuration = 14882
Duration / message = 0.01553
JOB DONE!!!
Profiler Agent: Connection with agent closed
Profiler Agent: Connection with agent closed
Profiler Agent: JNI OnLoad Initializing...
Profiler Agent: JNI OnLoad Initialized successfully
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
------------------------------------------------------------------------
BUILD SUCCESS
------------------------------------------------------------------------
Total time: 42.375s
Finished at: Wed May 10 00:32:11 JST 2017
Final Memory: 5M/123M
------------------------------------------------------------------------

From the console output you can read that test took roughly 15 seconds. In addition to the console output, there is a profiler result which looks similar to the following.

It is possible to drill down within the profiler result and see how much time program spend in each method. The point of this test is to see details of the processMessage method. It is very clear that majority of time is taken by the getUserName method. In this case, it is caused by calling to the mock class. For simplicity, let’s assume that it would look similar if underline implementation makes a call to the database (in such a case, SQL would need to be sent to the database and the database would need to parse it, pull data, and return the result over some protocol, which would definitely take some time). So as the resolution, let’s consider the method getUserName as a bottleneck to deal with.

Bottleneck Optimization

As you probably know, the typical way to avoid expensive queries is some form of caching. Let’s try the most primitive one: using HashMap. Here’s how the optimized processMessage method looks:

...

/**
 * Cache for users.
 */
private Map < String, String > usersCache = new HashMap < String, String > ();

...

public void processMessage(String message) {
 String[] parts = message.split("\\|");
 String userName = null;
 String txt = null;
 Date now = null;
 for (String part: parts) {
  String[] subs = part.split("=", 2);
  if (subs[0].equals("userId")) {
   if (usersCache.containsKey(subs[1])) {
    userName = usersCache.get(subs[1]);
   }
   else {
    userName = userProvider.getUserName(subs[1]);
    usersCache.put(subs[1], userName);
   }
  }
   else if (subs[0].equals("timestamp")) {
   now = Dates.parse(subs[1], "yyyy/MM/dd HH:mm:ss");
  }
   else if (subs[0].equals("message")) {
   txt = subs[1];
  }
 }
 ValidationUtils.guardNotNull(userName, "wrong input message, user is missing");
 ValidationUtils.guardNotNull(txt, "wrong input message, text is missing");
 ValidationUtils.guardNotNull(now, "wrong input message, timestamp is missing");
 broadcastService.broadcastMessage(userName, now, txt);
}

When you run the performance test program with this adjustment, then the whole run takes around 4.4 seconds instead of the original 15 seconds (on the same machine). The profiler result looks like the following:

Now the bottleneck becomes the function for parsing dates from the string. This would be the next step for optimization, if required. Before closing, let me add a few notes.

  • Using hash maps for caching is probably not what you want in most of real cases.
  • Optimization introduced new branch of code which is not covered by current unit test. Good practice is to revisit unit test and get this case properly covered.
  • Optimization generally makes code more complex and less readable. Therefore focus first only on the parts of your application which are critical, use profiler to find the real bottleneck within the units and stop optimizing when performance is good enough for your case.

Summary

This article shows one way of performance tuning at the unit level. This type of optimization has an advantage in that that anyone can do it with only a laptop and a few basic tools and everything can be setup within a minutes. Therefore, this is the great first layer of the performance tuning, which will save you a lot of time and money during the later stages.