Akka-http Logging: Logging the Response Time of the Rest API

Reading Time: 2 minutes

Sometimes while developing REST API’s we want to log the response time of our REST APi for the sake of better tuning. We are going to discuss the same case here and will see how to do that in Akka-http .

So sometime before while I was working on akka-http while developing a spark-akka-http-couchbase Lightbend activator template , a weird use case came in-front of me. I wanted to log each and every request that is made to my server along with the response time that my server took to execute it. I searched for it and found that others are also searching for the same thing. I thought that akka must have provided something for implementing this (which they probably don’t) , but I didn’t found anything in the documentation , and hence I have to come up with my own custom solution( just a little hack ! 😉 )

So let’s start with first things first :

WHY..??

I wanted this just to tune my REST APi , which is quite an important task and one can do so many things to tune it on its Local machine but the real thing happens on the production-server , where Logs are our best friend and the enemies too :P. Hence I developed this so that when we deploy our application on Staging Server(replica of production) , we can tune it in the best way by analyzing as to which routes are taking the maximum time, and then as the routine : check the code use Futures etc wherever possible and do the things in the right way.

How to do this in akka-http.?

So here is the code which can be used to log the response time of each and every request.


import akka.actor.ActorSystem
import akka.event.{LoggingAdapter, Logging}
import akka.event.Logging.LogLevel
import akka.http.scaladsl.Http
import akka.http.scaladsl.model.HttpRequest
import akka.http.scaladsl.server.Route
import akka.http.scaladsl.server.RouteResult.Complete
import akka.stream.{Materializer, ActorMaterializer}
import com.knoldus.logging.routes.KnoldusRoutingService
import akka.http.scaladsl.server.directives.{LoggingMagnet, LogEntry, DebuggingDirectives}
import pl.project13.scala.rainbow.Rainbow
import scala.concurrent.ExecutionContext.Implicits.global
import Rainbow._

import scala.concurrent.ExecutionContext

class KnoldusRoutingServer(implicit val system: ActorSystem,
implicit val materializer: ActorMaterializer) extends KnoldusRoutingService {
def startServer(address: String, port: Int) = {
val loggedRoute = requestMethodAndResponseStatusAsInfo(Logging.InfoLevel, routes)
Http().bindAndHandle(loggedRoute, address, port)
}

def requestMethodAndResponseStatusAsInfo(level: LogLevel, route: Route)
(implicit m: Materializer, ex: ExecutionContext) = {

def akkaResponseTimeLoggingFunction(loggingAdapter: LoggingAdapter, requestTimestamp: Long)(req: HttpRequest)(res: Any): Unit = {
val entry = res match {
case Complete(resp) =>
val responseTimestamp: Long = System.currentTimeMillis()
val elapsedTime: Long = responseTimestamp - requestTimestamp
val loggingString = "Logged Request:" + req.method + ":" + req.uri + ":" + resp.status + ":" + elapsedTime
val coloredLoggingString = if (elapsedTime > StartApp.thresholdValue) {
loggingString.red
} else {
loggingString.green
}
LogEntry(coloredLoggingString, level)
case anythingElse =>
LogEntry(s"$anythingElse", level)
}
entry.logTo(loggingAdapter)
}
DebuggingDirectives.logRequestResult(LoggingMagnet(log => {
val requestTimestamp = System.currentTimeMillis()
akkaResponseTimeLoggingFunction(log, requestTimestamp)
}))(route)

}
}

Here we are using the Debugging directives of akka for logging and also scala-rainbow by Konard Malawski for the colors . This will log the request that are coming to your server on to your console in a colored fashion. If the request takes more than 3 sec(as a standard) it will be RED or else GREEN.

You can find the whole code here.

I hope now you can log your Response time as well ! 🙂
Happy hakking ! 😀

References: