At Attivio we strive to create software of the highest quality. One technique we've adopted heavily inside our organization is the concept of 'unit' testing. I put unit in quotes because a unit test here might mean validating that MyClass.add2plus2() == 4 however it might also mean starting up an instance of our full application, feeding a few test documents through a workflow and validating via search that the entire system works end to end. Further, while we try to design code in order to be easily testable we try to avoid modifying production code specifically for a given test case.

As you can imagine, the full integration tests are often times very difficult to write and verify. We have a highly parallel system that runs multiple processes, with multiple threads and a message based architecture to perform the business logic in a workflow. We wanted to share some of the testing challenges we've encountered and the strategies we've come up with to solve those issues.

Testing log output

The Problem

We need to verify that a certain block of code is being executed or that a certain log message is being sent to the user.

Our Solution

First a little background. We use logging heavily throughout our system to convey information, error messages and trace level debugging. Our logging system is based on Slf4j with a Log4j backing implementation. All of our normal unit tests run with our default log4j configuration file. In order to address the logging problem we've created a CapturingLog4jAppender class to unsurprisingly, capture log output. It does this by dynamically inserting a new Appender into the log4j system. It works in a test as follows:

// first we need to install the logger and tell it to listen on a given class / package / etc
CapturingLog4jAppender log = CapturingLog4jAppender.install(MyClassBeingTested.class);

// perform test that exercises MyClassBeingTested

// check to see if there were any unexpected warnings
Assert.assertEquals(0, log.getWarningCount());

// we can also check for the existence of certain log messages
// the last flag determines if it is an exact match or a regex match.  both of these samples use regex
Assert.assertEquals(1, captured.count(".*Some log message I expect to see.*", false));
Assert.assertEquals(0, captured.count(".*Some log message I didn't expect to see.*", false));

// uninstall the log
log.uninstall();

The nice thing about this approach is that we can effectively monitor any number of classes for very intricate behaviors assuming we have the logging in place. For example, we can make sure that certain error cases were handled correctly if their side effects are hard to evaluate. We've also found that the log messages we add for testing are almost always useful in the field for debugging problems with customer configurations.

Checking for exceptions in other threads

The Problem

Since we have such a highly parallel system we often times encounter exceptions in other threads that are unhandled. While this is usually not a problem in production, it does come up while doing development of new features.*

Our Solution

We use Java's built-in uncaught exception handler to trap these exceptions.

public class TestExceptionHandler {
  
  private static ConcurrentLinkedQueue<Throwable> exceptions = new ConcurrentLinkedQueue<Throwable>();

  public static final init() {
    Thread.setDefaultUncaughtExceptionHandler(new Thread.UncaughtExceptionHandler() {
      @Override
      public void uncaughtException(Thread thread, Throwable throwable) {
        exceptions.add(throwable);
      }
    }
  });

  public static Collection<Throwable> getExceptions() {
    return exceptions;
  }

  public static void clear() {
    exceptions.clear();
  }
}

Then in your test you can check for exceptions with the following logic:// initialize at the beginning of your test.

// initialize at the beginning of your test
TestExceptionHandler.init();

// run a test that may have lots of exceptions in many threads

// check to make sure there were no exceptions thrown
Assert.assertEquals(0, TestExceptionHandler.getExceptions().size()); 

// clear it out for the next test
TestExceptionHandler.clear();

Detecting state in an asynchronous workflow engine

The Problem

We need to know when something is done and/or cause work to be paused in the middle of our asynchronous workflow processing engine.

Our Solution

One of the big improvements made in Java 5 and 6 was the inclusion of the concurrent package. We use these classes heavily in our code however we've also found use for some of these in our tests as well, specifically the CountDownLatch. The Javadoc for the CountDownlatch has very good examples of how to use it however we've used the class as a test control mechanism in addition to the normal multi-threaded production code management. If you're only doing simple yes/no type operations you can use a single volatile boolean variable.

CountDownLatch latch = new CountDownLatch(5);

startSomeAsyncProcess();
// wait for my mock async processor to run 5 times.
latch.await();
// check some other affected by the asynchronous processing since we know it's "done"

public static final class MockAsyncProcessor() {
  public void run() {
    // do 'stuff'
    // each time this processor is called the counter decreases by 1.
    latch.countDown();
  }
}

Each of these mechanisms helps us ensure that our code does what we say it's going to do and more importantly, it enables us to add new functionality at any level of the product and be sure that we're not going to break some small intricate behavior of some other part of the system.

AIE can be used as a comprehensive information application development platform. When it's used this way customers can develop arbitrarily complex applications that can have a variety of performance and memory runtime profiles. So whether we are testing an upcoming feature or helping a customer in the field debug a production application, we often turn to the YourKit Java profiler. Aside from the IDE I use every day (Eclipse), YourKit is hands down the most useful developer's tool I use.

Why YourKit is Awesome

BSD license/API

The YourKit license allows unrestricted shipment and embedding of the server agent. This enables us to ship the agent with our core product. Since the API supports runtime activation and deactivation of profiling, we can include the profiling capability in all executing instances of AIE. Often performance and memory utilization issues can only be observed in the field while running real applications against real data. This capability allows us to have this support ready to turn on, while having minimal impact on runtime performance or stability. Captured profiling snapshots can then be sent back to the office for analysis.

Customer Service

Whenever we have had an issue with using YourKit, they have responded exceptionally quickly with fixes and updates. They also have a great forum with quick turn around on questions from the development staff. Even if some of the fancier features (which I love but could live without) were not present, this kind of customer service is what makes us feel that we are working with a company we can depend on. This is the type of partnership focus that makes a software company great to work with, and what we always strive to achieve at Attivio. Examples of issues YourKit has addressed for us:

• They quickly added support for the runtime specification of the agent listener port. AIE uses several ports, each located at standard offset from a user-specified baseport. This feature allows the profiler port to play nicely with our standard configurations.
• They added the -disableall option to allow easily disabling all instrumentation and default profiling activities. AIE runs with this option by default. This new feature allows us to be future-proofed against new instrumentation options.
• In large memory environments, dumping the entire JVM heap can take a long time. They added a new option -disableoomedumper in less than 5 business days. See http://forums.yourkit.com/viewtopic.php?f=2&t=3266.

UI/Analysis

YourKit has all the standard profiler capabilities and some great UI to go along with it. The list below is not at all comprehensive, but includes some of my favorites. It is clear that YourKit has put a lot of thought and effort into providing a tool that helps you work with the snapshot you've got, which is critical for diagnosing production issues.

Threads Visualization

Sometimes in a multi-threaded application it can be difficult to understand what is going on at a specific time in the application. The YourKit profiler has a threads visualization that helps with this. Its color-coded view shows the state of threads over time and allows you to view the stack traces of all threads at a particular point in time.

CPU Telemetry

When it comes to solving CPU performance issues, the CPU telemetry view is our standard first stop. The Hot Spots link usually directs us to the culprit very quickly. When the problem is more complex than that, the Merged Callees tab allows us to find all the places a particular method is called and allows easy navigation up and down the call stack. The image below shows the ability to select a subset of time in order to further fine tune this analysis:

Monitor Tracking

Sometimes a performance problem is not due to an inefficient algorithm, but due to multiple threads competing for a shared resource. The monitor view helps to track down these types of issues. For each thread, the time it has spent waiting or blocked is displayed along with the stack traces of the various cases.

There's a lot more I don't have time to address. But YourKit is continually innovating and preparing for the future. Probes are an exciting new feature we plan on using that will allow customization and fine-tuning of profiling. There is JRockit and Java 7 support as well.