Mark Gregory Turansky

We spent too long hunting down a bug in a database method call that consistently returned “null” in our integration environment, but returned the correct value in a development unit test.

Do you see the problem here? Compare these two screenshots. Both screenshots show a look into two different jars on our classpath. The title of this article is a big hint.

Two points goes to the first person to explain the problem. (-2 points for any of my teammates that answer first!)

The moral of the story is that namespaces are one heck of a good idea and that we should always be very careful when relying on classpath-based resources.  I’ll write more about the problem after giving others a chance to solve the puzzle.

Joe Coder runs through his feature in the UI. It works. The doodad renders beautifully on the screen, and when he clicks the button, all the right things happen on the server. He checks his code in, writes a quick comment in Jira, changes the issue status to “Completed & Checked-in”, and goes to his next task. Lo and behold, his To Do list is empty! Joe’s done coding!

Or is he?

Configuration Management cuts a branch off the trunk code. Joe’s code goes through QA.

Some QA departments try to break developers’ code, others just test the “go path” to insure their test scripts work. In Joe’s case, the QA department has a test script that is a step-by-step use case for how the feature should work. QA signs off on his feature. The doodad worked exactly as specified, which is to say, the select/combo box was correctly filled with test data from the database.

Joe’s code goes to production … and takes down an entire server.

How can this be? It went through QA! Testers verified that his code did what it was supposed to do!

Most software organizations use the term robust wrongly. I generally hear it used in a context that implies the software has more features. Robustness has nothing to do with features or capabilities! Software products are robust because they are healthy, strong, and don’t fall over when the table that populates a select/combo box has a million rows in it.

Joe Coder never tested his feature with a large result set. Michael Nygard — in his excellent book Release It! from the Pragmatic Press — calls this problem an unbounded result set. It’s a common problem and an easy trap to fall into.

Writing code for a small result set enables rapid feedback for a developer. This is important, because the developer’s first task is to write his program correctly. It seems, though, that this first step is oftentimes the only step in the process! Without testing the program against a large result set, the new feature is a performance problem waiting to happen. The most common consequences are memory errors (have you ever tried filling a combo/select box with a million rows from the database?) or unscalable algorithms (see Schlemiel the Painter’s Algorithm).

In our case, testing with big numbers revealed concurrency issues that we did not and could not find when developing with simple, smaller tests. Our multi-threaded, multi-node messaging system would routinely deadlock whenever we slammed it with lots and lots of messages. It didn’t do this when we posted simple messages to the endpoint during development. Similarly, we noticed that we held on to objects for too long during big batch runs. They all got garbage collected when the batch completed, so it wasn’t exactly a memory leak, but there was no need to hold on to the references. After we fixed that, we noticed that our servers would stay within a tight and predictable memory band, as opposed to GC’ing all at once at the end of a batch. Terracotta server expertly pages large heaps to disk, so we were never at risk of running out of memory. Still, it’s nice to see our JVMs running lean and mean.

We’re still stress testing our system today. This past weekend, we pumped over one million real-world messages through our message bus. Our concurrency issues are gone, memory usage is predictable, and we stopped our test only to let our QA department have at our servers. There are zero technical reasons why our test couldn’t have processed another million messages. Terracotta Server held up strong throughout.

But we’re still not done testing yet. We still have to see what happens if we pull the plug (literally) on our message bus. We still have to throw poorly written messages/jobs at our bus to see how they’re handled. We need to validate that we’ve got enough business visibility into our messaging system so that operations folks have enough info at runtime to do their jobs. We need canaries in the coal mine to inform us when things are going wrong, and for that we need better metrics and reporting built into our system that shows performance over time.

We’re code complete, but we’re not done yet.

Imagine two pieces of software. One has “robust error handling” while the other prints a stacktrace and dies. Which one do you prefer?

I like the one that dies. Loudly. Depending on the type of application you’re building, the dead program might serve you better, too. Why? Because it’s obvious when something goes horrifically wrong. The message won’t be buried in a snowcrash of logging output.

What is “robust error handling” anyway? My team is currently building a sophisticated message bus and we’ve run into a few subtle concurrency issues. These are the hardest things to find when writing a distributed application with many threads on different physical nodes. Our error handling consisted of trapping the exception, logging it to Log4J at ERROR level, setting the correct state on our class (or so we thought), and going back to what the code was doing. It seemed like a good first pass, except that it didn’t work. We didn’t or couldn’t predicate every possible state in our system, so we made our best guesses, but naturally some corner cases bit us with an unexpected deadlock. Everything stopped and we didn’t know why.

Our logs, naturally, were huge with debugging turned on. Application logging is largely useless, anyway, without a plan to use it. And without a debug statement prefixing every line of code, you’re going to have a hard time finding deadlock situations across JVMs on the network.

So how’d we find our gremlin? We killed the process. Our “robust error handling” now looks like this:

try {
     // attempt the work
} catch(Exception e){
     e.printStackTrace();
     System.exit(-1);
}

Once we made that change and deployed our software to all the nodes, we found our deadlock.

Our problem was an unsychronized getter (you think gets are reads and therefore thread safe? Ha!). It turns out that somewhere in the callstack, this getter called toArray() on an ArrayList, which internally uses an iterator to build the array. If you’ve done any multi-threaded programming, you probably know what happens when another thread tries to modify your collection/list concurrently while using an iterator.

Our problem arose in a parent message (those that divide work among many child messages for parallel execution) which would leave orphaned children in certain error scenarios. We didn’t discover this cornercase in the logs, but we found it quickly when we crashed the program and exited.

I understand that exiting a running program isn’t the correct solution for all problems, but it was for our’s and it was dramatically more revealing than looking through tons of debug gibberish in log files. So, if you have the kind of program that can safely exit, then I say…

Fail loudly and proudly.