When the world sees a 500... but the server promises it is a 200
Here is the story of all the work I did this week, and it is so odd I feel it needs to be shared... but let’s talk about the world the problem can be found in. # The world It is a µservice (that’s the ohh, look how smart I am to use a symbol for micro) written with Dropwizard and deployed in a Docker container, with Traefik in front of that. To hit it, you go through an ingress controller and a load balancer.
+---------------+
| |
| Internet |
| |
+---------------+
|
+---------------+
| |
| Load Balancer |
| |
+---------------+
|
+---------------+
| |
| Ingress |
| |
+---------------+
|
+---------------+
| |
| Traefik |
| |
+---------------+
|
+---------------+
| |
| Microservice |
| |
+---------------+
The microservice acts as a BFF (backend for frontend), so it does some auth fun and makes calls to an internal API, manipulating them (e.g., changes the data structure). We have a number of different REST-style calls across GET, POST, PUT, and DELETE.
In terms of environments, we obviously have a production environment and an integration environment, which are set up the same way. We have a stubs environment where we fake out the internal API. Lastly, we can run the microservice on our laptops—but there’s just the microservice, no Traefik, etc. # The Problem
When we run our load test from outside, everything works except one call, which fails 98% of the time with a HTTP 500. Other calls (even the same method) all work. Load tests run against the stubs environment, and the same call works perfectly on our laptops, in integration, and in production. We can even run the fake internal API on the laptops with the load tests, and it works fine there. Basically, one call fails most of the time in one environment... 🤔
Grabbing logs
When we pull the logs for the microservice in stubs, things get weirder—it is returning an HTTP 200 😐. This is the same experience we get everywhere else; it works... except in stubs, where the load tests get a 500.
+---------------+
| 500 |
| |
| Internet |
| |
+-------+-------+
/
+-------+-------+
| 200 |
| |
| Microservice |
| |
+---------------+
Further log pulling shows 500s in the load balancer and the ingress, so somewhere between the microservice and Traefik, the HTTP 200 becomes a HTTP 500... but we don’t have logs for Traefik we can pull, which makes this a bit harder to determine. # Logging onto Traefik
Next, we logged onto Traefik and decided to curl the microservice directly—and lo and behold... we get a 500 🤯. And to make it more interesting, the microservice logs still show it is returning a 200—like what the actual?!. Could there be a network issue or magic?
Interestingly, the 500 came with an error saying: "insufficient content written."
Insufficient content written
This led me to looking at the content and what we’re sending. I noticed we are sending Content-Length and the body, and guess what... the length of the body does not equal the Content-Length... oh 💩. This is a client-side HTTP error, where the server sends an incorrect amount of body, so the client goes: "Well, the server must be wrong" and raises a 500.
I’ve always thought 500 errors were server errors and thus could only be raised on the server.
The fix
The fix was simple: in our server, we were using Response.fromResponse to map the internal API to the public API. It was copying the Content-Length from the internal API and sending it along. The fix was to delete the Content-Length header before calling fromResponse, ensuring it would rebuild the header and be correct.
The reason why it didn’t fail elsewhere: the version of the mock API we used added Content-Length, but newer versions and the real APIs used chunked encoding, which never set the header, so there’s no issue there.
This was a long road to understand the issue, and one line to fix it—and totally a new experience in learning that server errors can occur client-side too.