Defect clusters and their impact

Not long ago I spent a day hunting a bug that manifested in a puzzling way. To sign out of GoodData, an HTTP DELETE request goes to the resource representing the user session. In Internet Explorer 10, the browser would hang for exactly a minute waiting for a response, then always receive an internal server error.

The first step is usually to check the logs. At a glance, they showed that the front-end server waited a minute for the back end. When no response came, the front end returned an internal server error to the client. Yet the logs also showed that at roughly the same time, the back end did ultimately process the request correctly. Nothing was blocked in the request processing itself. My first thought was a deadlock on the front end that cleared after a minute. I cranked up the logging for key front-end components through the JMX console. The detailed logs showed the request was held up nowhere on the front end. On the back end, detailed logging showed the minute wasn’t being spent in any of the usual suspects, such as the database. Next came carefully placed traces to show the processing state. After an hour of experimenting, we isolated the wait to the line that reads the HTTP body inside the back-end server’s REST framework.

A colleague thought a malformed HTTP request might be the culprit. Out came the black magic of a TCP dump on the back-end port. The first, second, and even third time I looked, everything seemed fine. We finally spotted that the request included a Content-length header saying nine bytes, but no body. The back end was waiting for a request body that never came. We still had to work out where the request was being mangled.

We first suspected the browser. With Internet Explorer, caution is always warranted, but it was sending the request with its body. Next came the load balancer and so on. Eventually it looked as if the front-end server was dropping the body, or rather the HTTP client inside it that forwarded the request. Naturally I wanted to know why. It only happened with one particular request in one particular version of one browser. I ended up at the code that copied the HTTP request. It all looked fine apart from one little detail.

//Vytvoreni HTTP metody
HttpMethodBase method;
if ("GET".equals(request.getMethod())) {
    method = new GetMethod(uri);
} else if ("POST".equals(request.getMethod())) {
    method = new PostMethod(uri);
    setRequestBody((PostMethod) method, request);
} else if ("PUT".equals(request.getMethod())) {
    method = new PutMethod(uri);
    setRequestBody((PutMethod) method, request);
} else if ("DELETE".equals(request.getMethod())) {
    method = new DeleteMethod(uri);
} else if ("HEAD".equals(request.getMethod())) {
    method = new HeadMethod(uri);
} else {
    ...
}

//Kopirovani HTTP hlavicek
for (Enumeration headerNames = request.getHeaderNames(); headerNames.hasMoreElements();) {
    method.setRequestHeader(headerName, request.getHeader(headerName));
}

The code that copied the HTTP request from the servlet abstraction to the Apache Jakarta Commons HTTP Client abstraction copied every HTTP header, including Content-length, but copied the request body only for the POST method. Then it was clear. The DELETE abstraction has no way to set the request body. The fix was straightforward. Ignore the original Content-length header. After that, everything worked.

Defect clusters

The story illustrates something about defects. They tend to show up only when several occur together, often in a particular order. A single defect seldom causes a collapse on its own. It generally takes a cluster. The person who yanks your server’s power cord rarely has any business doing anything in the server room to begin with. It’s much the same in the real world, as you may have seen in documentaries about air disasters or heard in accounts of the Chernobyl disaster. A cluster of faults was behind those events.

Back to our example. Looking at it closely, we find that leaving out any one defect would have broken the chain that produced the one-minute wait. Each fault in isolation would have had a far less serious effect. Conversely, only a particular cluster of faults leads to a particular failure. Here’s what came together in this case.

Vague specification
The HTTP specification doesn’t explicitly say that DELETE can’t or mustn’t send a request body. It’s up to the HTTP client how to deal with it. Internet Explorer takes a permissive view of the specification. I didn’t check other browsers. The HTTP client we used interprets it very differently.
A bug on the client side
A closer look showed that the HTTP request body sent by the browser was simply the string undefined. That points to a bug in the application’s JavaScript that shows up only in Internet Explorer.
A bug on the server side
If the code above had copied the headers correctly, the problem still wouldn’t have occurred. The bad copy shows up only if the previous bug occurs and the server also honors the Content-length header for DELETE.

Bugs that surface only in a cluster are very hard to find. In testing you need very good integration coverage. Unit tests are based on assumptions about what the surroundings of the thing under test will do, both at the input and at the output. The chance that a cluster will arise there is very small. The danger lies in the cluster and in how unusual it is.