From 88978d91edca16f9c6a4177b5ed997bc12486b29 Mon Sep 17 00:00:00 2001 From: vlad Date: Wed, 26 Oct 2016 20:06:38 -0400 Subject: Request tracing and audit logging --- src/main/scala/xyz/driver/core/app.scala | 80 ++++++++++++++------------- src/main/scala/xyz/driver/core/auth.scala | 11 +++- src/main/scala/xyz/driver/core/rest.scala | 3 +- src/test/scala/xyz/driver/core/AuthTest.scala | 4 +- 4 files changed, 54 insertions(+), 44 deletions(-) diff --git a/src/main/scala/xyz/driver/core/app.scala b/src/main/scala/xyz/driver/core/app.scala index e080e1b..8f892e8 100644 --- a/src/main/scala/xyz/driver/core/app.scala +++ b/src/main/scala/xyz/driver/core/app.scala @@ -7,12 +7,13 @@ import akka.http.scaladsl.model.StatusCodes._ import akka.http.scaladsl.model.{HttpResponse, StatusCodes} import akka.http.scaladsl.server.Directives._ import akka.http.scaladsl.server.RouteResult._ -import akka.http.scaladsl.server.{ExceptionHandler, Route, RouteConcatenation} +import akka.http.scaladsl.server.{ExceptionHandler, RequestContext, Route, RouteConcatenation} import akka.stream.ActorMaterializer import com.typesafe.config.Config import org.slf4j.LoggerFactory import spray.json.DefaultJsonProtocol import xyz.driver.core +import xyz.driver.core.auth.AuthService import xyz.driver.core.logging.{Logger, TypesafeScalaLogger} import xyz.driver.core.rest.Swagger import xyz.driver.core.stats.SystemStats @@ -63,48 +64,51 @@ object app { val swaggerRoutes = swaggerService.routes ~ swaggerService.swaggerUI val versionRt = versionRoute(version, gitHash, time.currentTime()) - val generalExceptionHandler = ExceptionHandler { - - case is: IllegalStateException => - extractUri { uri => - // TODO: extract `requestUuid` from request or thread, provided by linkerd/zipkin - def requestUuid = java.util.UUID.randomUUID.toString - - log.debug(s"Request is not allowed to $uri ($requestUuid)", is) - complete( - HttpResponse(BadRequest, - entity = s"""{ "requestUuid": "$requestUuid", "message": "${is.getMessage}" }""")) - } - - case cm: ConcurrentModificationException => - extractUri { uri => - // TODO: extract `requestUuid` from request or thread, provided by linkerd/zipkin - def requestUuid = java.util.UUID.randomUUID.toString - - log.debug(s"Concurrent modification of the resource $uri ($requestUuid)", cm) - complete( - HttpResponse(Conflict, entity = s"""{ "requestUuid": "$requestUuid", "message": "${cm.getMessage}" }""")) - } - - case t: Throwable => - extractUri { uri => - // TODO: extract `requestUuid` from request or thread, provided by linkerd/zipkin - def requestUuid = java.util.UUID.randomUUID.toString - - log.error(s"Request to $uri could not be handled normally ($requestUuid)", t) - complete( - HttpResponse(InternalServerError, - entity = s"""{ "requestUuid": "$requestUuid", "message": "${t.getMessage}" }""")) - } - } - val _ = Future { - http.bindAndHandle(route2HandlerFlow(handleExceptions(generalExceptionHandler) { - logRequestResult("log")(modules.map(_.route).foldLeft(versionRt ~ healthRoute ~ swaggerRoutes)(_ ~ _)) + http.bindAndHandle(route2HandlerFlow(handleExceptions(exceptionHandler) { ctx => + log.audit(s"Received request ${ctx.request}") + modules.map(_.route).foldLeft(versionRt ~ healthRoute ~ swaggerRoutes)(_ ~ _)(ctx) }), interface, port)(materializer) } } + protected def extractTrackingId(ctx: RequestContext) = { + ctx.request.headers + .find(_.name == AuthService.TrackingIdHeader) + .map(_.value()) + .getOrElse(java.util.UUID.randomUUID.toString) + // TODO: In the case when absent, should be taken the same generated id, as in `authorize` + } + + protected def exceptionHandler = ExceptionHandler { + + case is: IllegalStateException => + ctx => + val trackingId = extractTrackingId(ctx) + log.debug(s"Request is not allowed to ${ctx.request.uri} ($trackingId)", is) + complete( + HttpResponse(BadRequest, entity = s"""{ "trackingId": "$trackingId", "message": "${is.getMessage}" }"""))( + ctx) + + case cm: ConcurrentModificationException => + ctx => + val trackingId = extractTrackingId(ctx) + val concurrentModificationMessage = "Resource was changed concurrently, try requesting a newer version" + log.audit(s"Concurrent modification of the resource ${ctx.request.uri} ($trackingId)", cm) + complete( + HttpResponse( + Conflict, + entity = s"""{ "trackingId": "$trackingId", "message": "$concurrentModificationMessage" }"""))(ctx) + + case t: Throwable => + ctx => + val trackingId = extractTrackingId(ctx) + log.error(s"Request to ${ctx.request.uri} could not be handled normally ($trackingId)", t) + complete( + HttpResponse(InternalServerError, + entity = s"""{ "trackingId": "$trackingId", "message": "${t.getMessage}" }"""))(ctx) + } + protected def versionRoute(version: String, gitHash: String, startupTime: Time): Route = { import DefaultJsonProtocol._ import SprayJsonSupport._ diff --git a/src/main/scala/xyz/driver/core/auth.scala b/src/main/scala/xyz/driver/core/auth.scala index 874f1e1..17f89c0 100644 --- a/src/main/scala/xyz/driver/core/auth.scala +++ b/src/main/scala/xyz/driver/core/auth.scala @@ -72,12 +72,13 @@ object auth { final case class Base64[T](value: String) - final case class AuthToken(value: Base64[Macaroon]) + final case class AuthToken(value: Base64[Macaroon], trackingId: String) final case class PasswordHash(value: String) object AuthService { val AuthenticationTokenHeader = "WWW-Authenticate" + val TrackingIdHeader = "l5d-ctx-trace" // https://linkerd.io/doc/0.7.4/linkerd/protocol-http/ } trait AuthService[U <: User] { @@ -90,16 +91,20 @@ object auth { def authorize(permissions: Permission*): Directive1[(AuthToken, U)] = { parameters('authToken.?).flatMap { parameterTokenValue => optionalHeaderValueByName(AuthService.AuthenticationTokenHeader).flatMap { headerTokenValue => - verifyAuthToken(headerTokenValue.orElse(parameterTokenValue), permissions.toSet) + optionalHeaderValueByName(AuthService.TrackingIdHeader).flatMap { trackingIdValue => + verifyAuthToken(headerTokenValue.orElse(parameterTokenValue), trackingIdValue, permissions.toSet) + } } } } private def verifyAuthToken(tokenOption: Option[String], + trackingIdValue: Option[String], permissions: Set[Permission]): Directive1[(AuthToken, U)] = tokenOption match { case Some(tokenValue) => - val token = AuthToken(Base64[Macaroon](tokenValue)) + val trackingId = trackingIdValue.getOrElse(java.util.UUID.randomUUID.toString) + val token = AuthToken(Base64[Macaroon](tokenValue), trackingId) onComplete(authStatus(token).run).flatMap { tokenUserResult => checkPermissions(tokenUserResult, permissions, token) diff --git a/src/main/scala/xyz/driver/core/rest.scala b/src/main/scala/xyz/driver/core/rest.scala index bfb4ddd..eaf97db 100644 --- a/src/main/scala/xyz/driver/core/rest.scala +++ b/src/main/scala/xyz/driver/core/rest.scala @@ -54,7 +54,8 @@ object rest { val request = (if(requestStub.entity.isKnownEmpty()) requestStub else { requestStub.withEntity(requestStub.entity.transformDataBytes(encryptionFlow)) - }).withHeaders(RawHeader(AuthService.AuthenticationTokenHeader, authToken.value.value)) + }).withHeaders(RawHeader(AuthService.AuthenticationTokenHeader, authToken.value.value), + RawHeader(AuthService.TrackingIdHeader, authToken.trackingId)) log.audit(s"Sending to ${request.uri} request $request") diff --git a/src/test/scala/xyz/driver/core/AuthTest.scala b/src/test/scala/xyz/driver/core/AuthTest.scala index fef3eda..97279de 100644 --- a/src/test/scala/xyz/driver/core/AuthTest.scala +++ b/src/test/scala/xyz/driver/core/AuthTest.scala @@ -40,7 +40,7 @@ class AuthTest extends FlatSpec with Matchers with MockitoSugar with ScalatestRo it should "throw error is authorized user is not having the requested permission" in { - val referenceAuthToken = AuthToken(Base64("I am a pathologist's token")) + val referenceAuthToken = AuthToken(Base64("I am a pathologist's token"), "BC131CD") Post("/administration/attempt").addHeader( RawHeader(AuthService.AuthenticationTokenHeader, referenceAuthToken.value.value) @@ -60,7 +60,7 @@ class AuthTest extends FlatSpec with Matchers with MockitoSugar with ScalatestRo it should "pass and retrieve the token to client code, if token is in request and user has permission" in { - val referenceAuthToken = AuthToken(Base64("I am token")) + val referenceAuthToken = AuthToken(Base64("I am token"), "AAADDDFFF") Get("/valid/attempt/?a=2&b=5").addHeader( RawHeader(AuthService.AuthenticationTokenHeader, referenceAuthToken.value.value) -- cgit v1.2.3