When the world sees a 500... but the server promises it is a 200

Submitted by Robert MacLean on Sat, 11/16/2019 - 13:04

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 lets talk about the world the problem can be found in.

The world

It is a µservice (that is 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 a ingress controller and a load balancer.

 +---------------+
 |               |
 |   Internet    |
 |               |
 +---------------+
         |
         |
         |
 +---------------+
 |               |
 | Load Balancer |
 |               |
 +---------------+
         |
         |
         |
 +---------------+
 |               |
 |    Ingress    |
 |               |
 +---------------+
         |
         |
         |
 +---------------+
 |               |
 |    Traefik    |
 |               |
 +---------------+
         |
         |
         |
 +---------------+
 |               |
 | Microservice  |
 |               |
 +---------------+

The microservice acts a BFF (backend for front end), so it does some auth fun and makes calls to an internal API and manipulates 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 we have an integration environment which are setup 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 is just the microservice... no traefik etc...

The Problem

When we run our load test from outside everything works except 1 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 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 to the load tests it gets a 500

+---------------+   500 Here
|               |
|   Internet    |
|               |
+-------+-------+
        |
        |
        /
        |
        |
+-------+-------+   200 Here
|               |
| Microservice  |
|               |
+---------------+

Further pulling of logs show 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 on 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 that the microservice logs still show it is returning a 200 - like what the actual?! Could there be an network issue or magic?

Interesting the 500 came with an error saying "insufficient content written"

Insufficient content written

This led me to looking at the content and looking at what we are sending and I see 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 the incorrect amount of body, so the client goes, well the server is wrong and raises a 500. I've always thought 500 errors were server error and thus could only be raised on the server.

The fix

The fix is simple, in our server we were using the Response.fromResponse to map internal API to the public API and so it was copying the Content-Length from the internal API and we were sending that along.

This meant the fix was to delete the Content-Length header before we call fromResponse to ensure it would rebuild the header and be correct.

The reason why it didn't fail else where, the version of the mock API we use added Content-Length but newer versions and the real APIs used chunked encoding which never set the header so there is 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.

VSCode + Catalina

Submitted by Robert MacLean on Thu, 10/10/2019 - 21:56

For the most part, the initial upgrade to macOS Catalina was uneventful; I was caught unaware by the wave of permission requests that greeted me but it was 2 minutes of clicking accept or deny and continuing on with my day (though, how normal users will cope is beyond me... it feels very un-apple).

The two issues I did run into, were the need to reconfigure Google Drive (again, a minor 2-minute activity) and trying to get VSCode to work properly. This was a lot more annoying. The initial issue was that git, could not be found... this broke all of source control in VSCode. The fix was to run the following from the terminal: xcode-select --install and restarting VSCode.

Once that was fixed, the next issue was that I could no longer sign commits with GPG, this gave a similar issue as the initial Git not being found.

The correct fix for VSCode is to add it to the list of Developer Tools which you can find under Security & Privacy. Once a restart of VSCode everything just worked. I added Terminal to the list too which also stopped autocomplete from Fish Shell from constantly prompting too.

important reminder that diversity is important

Submitted by Robert MacLean on Mon, 09/16/2019 - 22:01

(I tweeted this story today, and some wanted to be able to share it so here it is)

Everyone gets along well at work, except Jim

He never comes to after-work drinks. He doesn't go get Friday burger lunch with the team. He doesn't chip in for Sarah's farewell gift. When he gets unicorned (i.e. he left his machine unlocked & someone emailed everyone), he doesn't buy the punishment cake. This annoys everyone. Why doesn't he just play along? It is harmless fun.

Jim sucks... Right? He just isn't trying to be part of the team... Right?

Well, Jim can't afford the transport from after-hours drinks or the expensive burgers or the cake.

He would like to.

Financial diversity is a hard one to spot in a team, but it is a real thing. Are you excluding people because they are not privileged like you?

Learning Kotlin: The notnull delegate and lateinit

Submitted by Robert MacLean on Mon, 09/03/2018 - 09:00

More Information

A lot of introductions to Kotlin start with how null is opt-in because that makes it safer, we even looked at this way back in post 8. The problem though is that sometimes we do not know what we want the value to be when we initialise the value and we know that when we use it we don't want to worry about nulls. The ability to change from null to never null might seem to be impossible but Kotlin has two ways to do the impossible.

Before we look at the two solutions, let us look at a non-working example. Here we have a class to represent a physical building and we want to store the number of floors which we get from calling an API (not shown). The problem here is there is no good default value. A house with just a ground floor is 0, a multistory office building could have 10 floors, and an underground bunker could have -30 floors.

  1. class Building() {
  2.     var numberOfFloors : Int
  3.  
  4.     fun getBuildingInfo(erfNumber : String){
  5.         // call municpality web service to get details
  6.         numberOfFloors = 0; // 0 cause 0 = G like in elevators
  7.     }
  8. }
  9.  
  10. fun main(args:Array<String>) {
  11.     val house = Building()
  12.     house.getBuildingInfo("123")
  13.     println("My house, up the road, has ${house.numberOfFloors}")
  14. }

This will not compile as it states Property must be initialized or be abstract for the number of floors.

notnull

Following on from our previous delegates we have the notnull delegate we can use to allow the property to not be set initially and then

  1. import kotlin.properties.Delegates
  2.  
  3. class Building() {
  4.     var numberOfFloors : Int by Delegates.notNull()
  5.  
  6.     fun getBuildingInfo(erfNumber : String){
  7.         // call municpality web service to get details
  8.         this.numberOfFloors = 10;
  9.     }
  10. }
  11.  
  12. fun main(args:Array<String>) {
  13.     val house = Building()
  14.     house.getBuildingInfo("123")
  15.     println("My house, down the street, has ${house.numberOfFloors}")
  16. }

This example will print out that we have 10 floors. If we were to comment out line 14, we would get the following exception: Exception in thread "main" java.lang.IllegalStateException: Property numberOfFloors should be initialized before get. - so not exactly a null exception but close enough it makes no difference.

lateinit

Another option is lateinit which we can add before the var keyword, but we cannot use it with Int, or other primative types so we need to change that as well to a class. This is a really nice and simple solution.

  1. data class Floors(val aboveGround: Int, val belowGround: Int)
  2.  
  3. class Building() {
  4.     lateinit var numberOfFloors : Floors
  5.  
  6.     fun getBuildingInfo(erfNumber : String){
  7.         // call municpality web service to get details
  8.         this.numberOfFloors = Floors(2, 40);
  9.     }
  10. }
  11.  
  12. fun main(args:Array<String>) {
  13.     val house = Building()
  14.     house.getBuildingInfo("123")
  15.     println("My house, in the middle of the avenue, has ${house.numberOfFloors}")
  16. }

Once again, if we comment out line 14 we get an exception as expected 'Exception in thread "main" kotlin.UninitializedPropertyAccessException: lateinit property numberOfFloors has not been initialized'.

lateinit vs. notnull

As we can see in our simple examples both achieve the goal but they both have their own limitations and advantages too:

  • notnull being a delegate needs an extra object instance for each property, so there is a small additional memory/performance load.
  • The notnull delegate hides the getting and setting in a separate instance which means anything that works with the field, for example Java DI tools, will not work with it.
  • lateinit doesn't work with primitive types (Int, Char, Boolean etc...) as we saw above.
  • lateinit only works with var and not val.
  • when using lateinit you gain access to the.isInitialized method which you can use to check if it was initialized.

Learning Kotlin: The vetoable delegate

Submitted by Robert MacLean on Fri, 08/31/2018 - 09:00

More Information

The vetoable delegate is usable with variables only (i.e. you need to be able to change the value) and it takes a lambda which returns a boolean. If the return value is true, the value is set; otherwise, the value is not set.

As an example, we will have a User and ensure the age can never be lowered (since time only goes forward)

  1. import kotlin.properties.Delegates
  2.  
  3. class User() {
  4.     var age : Int by Delegates.vetoable(0)  { property, oldValue, newValue ->
  5.         newValue > oldValue
  6.     }
  7. }
  8.  
  9. fun main(args:Array<String>) {
  10.     val user = User()
  11.     user.age = 10;
  12.     println(user.age)
  13.  
  14.     user.age = 15
  15.     println(user.age)
  16.  
  17.     user.age = 10
  18.     println(user.age)
  19. }

This produces:

10
15
15

Learning Kotlin: The map delegate

Submitted by Robert MacLean on Thu, 08/30/2018 - 09:00

More Information

The next delegate is actually built into something we have looked at before, map and if you use by to refer to one, when you get the value it goes to the map values to look it up.

As a way to illustrate this, we will take some JSON data and parse it with the kotlinx.serialization code. We then loop over each item and convert it into a map which we use to create an instance of User.

  1. import kotlinx.serialization.json.*
  2.  
  3. class User(userValues:Map<String, Any?>) {
  4.     val name: String by userValues
  5.     val eyeColour: String by userValues
  6.     val age : String by userValues
  7. }
  8.  
  9. fun main(args:Array<String>) {
  10.     val json = """[{
  11.        "name":"Robert",
  12.        "eyeColour":"Green",
  13.        "age":36
  14.    },{
  15.        "name":"Frank",
  16.        "eyeColour":"Blue"
  17.    }]""";
  18.  
  19.     (JsonTreeParser(json).read() as JsonArray)
  20.         .map{  
  21.             val person = it as JsonObject
  22.             person.keys.associateBy({it}, {person.getPrimitive(it).content})
  23.         }.map {
  24.             User(it)
  25.         }.forEach { println("${it.name} with ${it.eyeColour} eyes") }
  26.        
  27. }

This code outputs:

Robert with Green eyes
Frank with Blue eyes

However, if we change line 25 to include the age we get a better view of what is happening.

  1. }.forEach { println("${it.name} with ${it.eyeColour} eyes and is ${it.age} years old") }

This simple adjustment changes the output to be:

Robert with Green eyes and is 36 years oldException in thread "main"
java.util.NoSuchElementException: Key age is missing in the map.
        at kotlin.collections.MapsKt__MapWithDefaultKt.getOrImplicitDefaultNullable(MapWithDefault.kt:24)
        at sadev.User.getAge(blog.kt)
        at sadev.BlogKt.main(blog.kt:27)

As you can see, the map is not initialising the values ahead of time. Rather it is merely being used to look up what value in the map when the properties getter is called.

Learning Kotlin: The Observable Delegate (with a slight detour on reference functions)

Submitted by Robert MacLean on Wed, 08/29/2018 - 09:00

More Information

  • This is the 27th post in a multipart series.
    If you want to read more, see our series index
  • Koans used in here are 34 and 35

Following on from our introduction to the by operator and delegates, this post looks at the second of the five built-in delegates, observable.

The next built-in delegate is observable - this allows intercept all attempts to set the value. You can do this with a setter, but remember you would need to duplicate that setter code every time. With the observable, you can build the logic once and reuse it over and over again.

Once again let us start with the way we would do this without the delegated property:

  1. class User() {
  2.     var name: String = "<NO VALUE>"
  3.         set(value) {
  4.             DataChanged("name", name, value)
  5.         }
  6.  
  7.     var eyeColour: String = "<NO VALUE>"
  8.         set(value) {
  9.             DataChanged("eyeColour", name, value)
  10.         }
  11.  
  12.     fun DataChanged(propertyName: String, oldValue: String, newValue: String) {
  13.         println("$propertyName changed! $oldValue -> $newValue")
  14.     }
  15. }
  16.  
  17. fun main(args:Array<String>) {
  18.     val user = User()
  19.     user.name = "Robert"
  20.     user.eyeColour = "Green"
  21. }

Note, that we need to do the setter manually twice and in each one we will need to change a value, which you know you will get missed when you copy & paste the code.

In the next example, we change to use the observable delegate which allows us to easily call the same function.

While I don't recommend this for production, I did in the example call it in two different ways. For age, as the second parameter is a lambda I just create that and pass the parameters to my function. This is how all the demos normally show the usage of this. For name though, since my function has the same signature as the lambda I can pass it directly to the observable which seems MUCH nicer to me. Though since we need to pass a reference to our function we need to prefix it with ::.

  1. package sadev
  2.  
  3. import kotlin.properties.Delegates
  4. import kotlin.reflect.KProperty
  5.  
  6. class User() {
  7.     var name: String by Delegates.observable("<NO VALUE>", ::DataChanged)
  8.  
  9.     var eyeColour: String by Delegates.observable("<NO VALUE>") { property, old, new ->
  10.             DataChanged(property, old, new)
  11.         }
  12.  
  13.     fun DataChanged(property: KProperty<*>, oldValue: String, newValue: String) {
  14.         println("${property.name} changed! $oldValue -> $newValue")
  15.     }
  16. }
  17.  
  18. fun main(args:Array<String>) {
  19.     val user = User()
  20.     user.name = "Robert"
  21.     user.eyeColour = "Green"
  22. }

Learning Kotlin: The Lazy Delegate

Submitted by Robert MacLean on Tue, 08/28/2018 - 09:00

More Information

  • This is the 26th post in a multipart series.
    If you want to read more, see our series index
  • Koans used in here are 34 and 35

Following on from our introduction to the by operator and delegates, this post looks at the first of the five built-in delegates, lazy. Lazy property evaluation allows you to set the initial value of a property the first time you try to get it. This is really useful for scenarios where there is a high cost of getting the data. For example, if you want to set the value of a username which requires a call to a microservice but since you don't always need the username you can use this to initial it when you try and retrieve it the first time.

Setting up the context for the example, let us look at two ways you may do this now. The first way is you call the service in the constructor, so you take the hit immediately regardless if you ever need it. It is nice and clean though.

  1. class User {
  2.     val name: String
  3.  
  4.     constructor(id:Int){
  5.         // load service ... super expensive
  6.         Thread.sleep(1000)
  7.         name = "Robert"
  8.     }
  9. }
  10.  
  11. fun main(args:Array<String>) {
  12.     val user = User(1)
  13.     println(user.name)
  14. }

The second solution is to add a load function so we need to call that to load the data. This gets rid of the performance hit but is less clean and if you forget to call load your code is broken. You may think, that will never happen to me... I just did that right now while writing the sample code. It took me less than 2 min to forget I needed it. 🙈

Another pain is I need to make my name property variable since it will be assigned at a later point.

  1. class User(val id: Int) {
  2.     var name: String = ""
  3.  
  4.     fun load() {
  5.         // load service ... super expensive
  6.         Thread.sleep(1000)
  7.         name = "Robert"
  8.     }
  9. }
  10.  
  11. fun main(args:Array<String>) {
  12.     val user = User(1)
  13.     user.load()
  14.     println(user.name)
  15. }

The solution to this is obviously lazy - this gives us the best of all of the above (clean code, no performance hit unless I need it, can use val, no forgetting things) and none of the downsides.

  1. class User(val id: Int) {
  2.     val name: String by lazy {
  3.         // load service ... super expensive
  4.         Thread.sleep(1000)
  5.         "Robert"
  6.     }
  7. }
  8.  
  9. fun main(args:Array<String>) {
  10.     val user = User(1)
  11.     println(user.name)
  12. }

Learning Kotlin: by

Submitted by Robert MacLean on Mon, 08/27/2018 - 09:00

More Information

  • This is the 25th post in a multipart series.
    If you want to read more, see our series index
  • Koans used in here are 34 and 35

The fourth set of Koans looks at properties and the first two look at getters and setters. If you coming from another programming language then these should work the way you expect they should. This post will look at the amazing by keyword in the third and fourth examples. The by keyword enables us to delegate the getter/setter to be handled by a separate class which means that common patterns can be extracted and reused.

Out of the box, there are five built-in options which I will expand into in their own posts, but for now, let us build our own delegate class. In this example, we can assign any value but the result we get is always HAHAHA. We could store the result in the instance and return the value assigned but we do not have to. The key take away is that we have ensured the logic for our properties in one reusable place, rather than scattered across multiple getters and setters.

  1. import kotlin.reflect.KProperty
  2.  
  3. class User {
  4.     var name : String by Delegate()
  5.     var eyeColour : String by Delegate();
  6. }
  7.  
  8. class Delegate {
  9.     operator fun getValue(thisRef: Any?, property: KProperty<*>): String {
  10.         println("$thisRef, thank you for delegating '${property.name}' to me!")
  11.         return "HAHAHA"
  12.     }
  13.  
  14.     operator fun setValue(thisRef: Any?, property: KProperty<*>, value: String) {
  15.         println("$value has been assigned to '${property.name}' in $thisRef.")
  16.     }
  17. }
  18.  
  19. fun main(args: Array<String>) {
  20.     val user = User()
  21.     user.name = "Robert"
  22.     user.eyeColour = "Green"
  23.     println("My word ${user.name} but your eyes are ${user.eyeColour}")
  24. }

Learning Kotlin: todo

Submitted by Robert MacLean on Fri, 08/24/2018 - 09:00

More Information

  • This is the 24th post in a multipart series.
    If you want to read more, see our series index

This post will be a shorter than normal one, as we are looking at a small feature that is easy to explain but can have major impacts to your code base and that is the todo function.

To use it, you simply call it and optionally pass in a string which gives a reason why that code is not done. For example:

  1. fun main(args:Array<String>) {
  2.   todo("Haven't started")
  3. }

This will throw a NotImplementedError when it is encountered. What I really like about this is that we are being explicit about the intent. In addition it makes it really easy to find in your IDE of choice.