Ktor Log Call Duration

Question

I'm trying to log calls with response time. So far no solution..

install(CallLogging) {
    level = Level.INFO
    disableDefaultColors()
    format { call ->
        val status = call.response.status()
        val httpMethod = call.request.httpMethod.value
        val path = call.request.path()
        // How to access duration
        val duration = ???
        "$status $httpMethod $path $duration"
    }
}

I can probably ObserveResponse but, i will have seperate log entries for one call..

Any ideas?

Answer 1

I found solution. But it is cumbersome..

...
import io.ktor.server.plugins.callloging.*
import java.time.LocalDateTime
import java.time.temporal.ChronoUnit
...

    val CALL_START_TIME = AttributeKey<LocalDateTime>("CallStartTime")

    intercept(ApplicationCallPipeline.Setup) {
        // intercept before calling routing and mark start of call
        call.attributes.put(CALL_START_TIME, LocalDateTime.now())
    }

    install(CallLogging) {
        level = Level.INFO
        disableDefaultColors()
        format { call ->
            val status = call.response.status()
            val httpMethod = call.request.httpMethod.value
            val path = call.request.path()
            val duration = when (val startTime = call.attributes.getOrNull(CALL_START_TIME)) {
                null -> "?ms" // just in case
                else -> "${startTime.until(LocalDateTime.now(), ChronoUnit.MILLIS)}ms"
            }

            "$status $httpMethod $path $duration"
        }
    }
...

Hope that KTOR will make more elegant solution in future...

Original answer Sergey Mashkov