Hi! I’ve seen a memory leak when we migrated from ...

# ktor

[gotoOla]

Hi! I’ve seen a memory leak when we migrated from kotlin 1.2 with 0.x-coroutines and 0.9.5-ktor to kotlin 1.3, 1.0 coroutines and 1.0.1 ktor. I’ve been running a lot of memory profiling and narrowed
it down ot our HttpClient. The memory leakage seems to be a lot of char[] .

We have a class which acts as a http client. This class is called from another class with GlobalScope.launch {} (this was previously just launch) and is sending about 600 requests per second (but sometimes peaks at 1400 rps).
With ktor 0.9.5 we had this working for a few months. I’m now looking for help since it’s not much code left that is in our control but maybe we have used it wrong. Anybody see something fishy in the code below
or know about any known issue with the HttpClient?


This is our httpClient which leaks memory.

import our.company.toJsonString
import our.company.ApplicationMetrics
import io.ktor.client.HttpClient
import io.ktor.client.engine.apache.Apache
import io.ktor.client.engine.config
import <http://io.ktor.client.request.post|io.ktor.client.request.post>
import io.ktor.client.response.HttpResponse
import org.slf4j.LoggerFactory

class UpdateClient(
    baseUrl: String
) {
    private val logger = LoggerFactory.getLogger(UpdateClient::class.java)
    private val client = HttpClient(Apache.config {
        socketTimeout = 30_000
        connectTimeout = 30_000
    })
    private val updateUrl = "$baseUrl/shared"

    suspend fun postUpdates(updates: List<Update>) {
        try {
            val payload = updates.toJsonString()
            <http://client.post|client.post><HttpResponse>(updateUrl) {
                body = payload
            }
            ApplicationMetrics.updatesSent.labels("true").inc(updates.size.toDouble())
        } catch (e: Exception) {
            logger.error("Could not post updates", e)
            ApplicationMetrics.updatesSent.labels("false").inc(updates.size.toDouble())
        }
    }
}

The service that calls this looks something like this

fun businessLogic(urls: List<Url>) {
        runBlocking {
            val urlsInDynamo = urls.map { url ->
                GlobalScope.async {
                    try {
                        val result = dynamoClient.increaseSharesAsync(url)
                        Update(result.attributes()["aString"]?.s()!!, result.attributes()["aValue"]?.n()!!.toLong())
                    } catch (e: Exception) {
                        logger.warn("Unable to write get result from the update to dynamo", e)
                        null
                    }
                }
            }.awaitAll().filterNotNull()

            if (urlsInDynamo.isEmpty()) {
                throw RuntimeException("Non of the urls were updated in Dynamo")
            }

            // Fire and forget
            GlobalScope.launch {
                val updates = urlsInDynamo
                    .groupBy { it.aString }
                    .map {
                        it.value.maxBy {
                            it.value
                        }!!
                    }
                    .toList()
                // This is where we call the update client at about 600 rps
                updateClient.postUpdates(updates)
            }
        }
    }

And the data class and extension we use

fun Any.toJsonString(pretty: Boolean = false): String {
    return DefaultObjectMapper
        .let { if (pretty) it.writer(SerializationFeature.INDENT_OUTPUT) else it.writer() }
        .writeValueAsString(this)
}

data class Update(val aString: String, val aValue: Long)

[gotoOla]

This is how the profiling looks when I ran it with xmx 128

[gotoOla]

Screenshot 2018-12-21 at 13.11.59.png

[gotoOla]

Now that I rubber ducked a bit I will try to evaluate the .toJsonString-extension that we use but that worked good with the previous versions. Next step will be to change the ktor client for something else and see if we still have the same issue

[e5l]

Hi @gotoOla, could you try to close the HttpResponse here :`client.post<HttpResponse>(updateUrl)`

[gotoOla]

@e5l]

[gotoOla]

oops, fat fingers, do you mean just

<http://client.post|client.post><HttpResponse>(updateUrl) {
                    body = payload
                }.close()

?

[e5l]

Yep

[gotoOla]

will do

[gotoOla]

deploying now, usually takes 5-10 minutes before it has gone full garbage-collector cycle

[gotoOla]

thanks for looking at this 🙂

[e5l]

No problem. Let's check and fix it if there is a problem

[gotoOla]

seems to haver done the trick, one of the “bigger” garbage collectors just hit and freed up memory in a good way

[gotoOla]

may I ask how I should reason about this? Is it because the responseBody is returned as a stream? I looked at https://ktor.io/clients/http-client.html where the client is closed but didn’t find examples on the request itself

[e5l]

There are 2 reasons: Apache requires to release response explicitly(for the internal stuff like buffers and pools), and for a stream-body

[e5l]

The response.body is stream type: ByteReadChannel

[gotoOla]

ah ok makes sense, so I guess we kept references to the urls and payloads themselves…a traditional leak ;D

[gotoOla]

not sure why we never saw this with ktor 0.9.3-0.9.5 though…will think a bit more about this. But thank you soo much for the help! Have been running profiling and tried to narrow down this issue for a few days so I’m very happy and grateful for your help! 🙂

[Alexander Weickmann]

We ran into the exact same issue. This is still nowhere documented. Many examples also show usage of HttpClient and do not close their HttpResponses.

[e5l]

In ktor 1.3.2 the HttpResponse is not closeable anymore, and you shouldn't close it

[Alexander Weickmann]

Yes, actually it is now a HttpStatement, which is closed by the framework 👍