From f36f7ef35ccb5596a7993bf3817edd1a2c163663 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Victor=20Peter=20Rouven=20M=C3=BCller?= Date: Tue, 8 Feb 2022 17:34:48 +0100 Subject: [PATCH] Fix logging of internal server errors for the json api changelog_begin - [HTTP-JSON] Internal server errors are now properly logged again changelog_end --- .../com/digitalasset/http/Endpoints.scala | 22 +++++++++++++------ .../http/EndpointsCompanion.scala | 22 +++++++++++++------ .../digitalasset/http/WebSocketService.scala | 10 ++++++--- 3 files changed, 37 insertions(+), 17 deletions(-) diff --git a/ledger-service/http-json/src/main/scala/com/digitalasset/http/Endpoints.scala b/ledger-service/http-json/src/main/scala/com/digitalasset/http/Endpoints.scala index 014fec8b3a0b..5c0bb524efe1 100644 --- a/ledger-service/http-json/src/main/scala/com/digitalasset/http/Endpoints.scala +++ b/ledger-service/http-json/src/main/scala/com/digitalasset/http/Endpoints.scala @@ -89,7 +89,9 @@ class Endpoints( import util.ErrorOps._ private def responseToRoute(res: Future[HttpResponse]): Route = _ => res map Complete - private def toRoute[T: MkHttpResponse](res: => T): Route = + private def toRoute[T: MkHttpResponse](res: => T)(implicit + lc: LoggingContextOf[InstanceUUID with RequestID] + ): Route = responseToRoute(httpResponse(res)) private def mkRequestLogMsg(request: HttpRequest, remoteAddress: RemoteAddress) = @@ -383,19 +385,24 @@ class Endpoints( .fromFunction((_: E \/ A).leftMap(E.run)) .recover(logException("Source") andThen Error.fromThrowable andThen (-\/(_))) - private def httpResponse[T](output: T)(implicit T: MkHttpResponse[T]): Future[HttpResponse] = + private def httpResponse[T](output: T)(implicit + T: MkHttpResponse[T], + lc: LoggingContextOf[InstanceUUID with RequestID], + ): Future[HttpResponse] = T.run(output) .recover(Error.fromThrowable andThen (httpResponseError(_))) - private implicit def sourceStreamSearchResults[A: JsonWriter] - : MkHttpResponse[ET[domain.SyncResponse[Source[Error \/ A, NotUsed]]]] = + private implicit def sourceStreamSearchResults[A: JsonWriter](implicit + lc: LoggingContextOf[InstanceUUID with RequestID] + ): MkHttpResponse[ET[domain.SyncResponse[Source[Error \/ A, NotUsed]]]] = MkHttpResponse { output => implicitly[MkHttpResponse[Future[Error \/ SearchResult[Error \/ JsValue]]]] .run(output.map(_ map (_ map (_ map ((_: A).toJson)))).run) } - private implicit def searchResults - : MkHttpResponse[Future[Error \/ SearchResult[Error \/ JsValue]]] = + private implicit def searchResults(implicit + lc: LoggingContextOf[InstanceUUID with RequestID] + ): MkHttpResponse[Future[Error \/ SearchResult[Error \/ JsValue]]] = MkHttpResponse { output => output.map(_.fold(httpResponseError, searchHttpResponse)) } @@ -426,7 +433,8 @@ class Endpoints( } private implicit def fullySync[A: JsonWriter](implicit - metrics: Metrics + metrics: Metrics, + lc: LoggingContextOf[InstanceUUID with RequestID], ): MkHttpResponse[ET[domain.SyncResponse[A]]] = MkHttpResponse { result => Timed.future( metrics.daml.HttpJsonApi.responseCreationTimer, diff --git a/ledger-service/http-json/src/main/scala/com/digitalasset/http/EndpointsCompanion.scala b/ledger-service/http-json/src/main/scala/com/digitalasset/http/EndpointsCompanion.scala index f86dd25b7b2c..7735cba3003f 100644 --- a/ledger-service/http-json/src/main/scala/com/digitalasset/http/EndpointsCompanion.scala +++ b/ledger-service/http-json/src/main/scala/com/digitalasset/http/EndpointsCompanion.scala @@ -9,7 +9,7 @@ import akka.http.scaladsl.server.{RequestContext, Route} import akka.util.ByteString import com.daml.http.domain.{JwtPayload, JwtPayloadLedgerIdOnly, JwtWritePayload} import com.daml.http.json.SprayJson -import com.daml.http.util.Logging.{InstanceUUID, RequestID} +import com.daml.http.util.Logging.{InstanceUUID, RequestID, extendWithRequestIdLogCtx} import util.GrpcHttpErrorCodes._ import com.daml.jwt.domain.{DecodedJwt, Jwt} import com.daml.ledger.api.auth.{AuthServiceJWTCodec, CustomDamlJWTPayload, StandardJWTPayload} @@ -290,27 +290,35 @@ object EndpointsCompanion { } } - lazy val notFound: Route = (ctx: RequestContext) => + def notFound(implicit lc: LoggingContextOf[InstanceUUID]): Route = (ctx: RequestContext) => ctx.request match { case HttpRequest(method, uri, _, _, _) => - Future.successful( - Complete(httpResponseError(NotFound(s"${method: HttpMethod}, uri: ${uri: Uri}"))) + extendWithRequestIdLogCtx(implicit lc => + Future.successful( + Complete(httpResponseError(NotFound(s"${method: HttpMethod}, uri: ${uri: Uri}"))) + ) ) } - private[http] def httpResponseError(error: Error): HttpResponse = { + private[http] def httpResponseError( + error: Error + )(implicit lc: LoggingContextOf[InstanceUUID with RequestID]): HttpResponse = { import com.daml.http.json.JsonProtocol._ val resp = errorResponse(error) httpResponse(resp.status, SprayJson.encodeUnsafe(resp)) } private[this] val logger = ContextualizedLogger.get(getClass) - private[http] def errorResponse(error: Error): domain.ErrorResponse = { + private[http] def errorResponse( + error: Error + )(implicit lc: LoggingContextOf[InstanceUUID with RequestID]): domain.ErrorResponse = { val (status, errorMsg): (StatusCode, String) = error match { case InvalidUserInput(e) => StatusCodes.BadRequest -> e case ParticipantServerError(grpcStatus, d) => grpcStatus.asAkkaHttpForJsonApi -> s"$grpcStatus${d.cata((": " + _), "")}" - case ServerError(_) => StatusCodes.InternalServerError -> "HTTP JSON API Server Error" + case ServerError(reason) => + logger.error(s"Internal server error occured: $reason") + StatusCodes.InternalServerError -> "HTTP JSON API Server Error" case Unauthorized(e) => StatusCodes.Unauthorized -> e case NotFound(e) => StatusCodes.NotFound -> e } diff --git a/ledger-service/http-json/src/main/scala/com/digitalasset/http/WebSocketService.scala b/ledger-service/http-json/src/main/scala/com/digitalasset/http/WebSocketService.scala index a7443e2eea6c..a89ae47343c2 100644 --- a/ledger-service/http-json/src/main/scala/com/digitalasset/http/WebSocketService.scala +++ b/ledger-service/http-json/src/main/scala/com/digitalasset/http/WebSocketService.scala @@ -42,7 +42,7 @@ import Liskov.<~< import com.daml.http.domain.TemplateId.toLedgerApiValue import com.daml.http.domain.TemplateId.{OptionalPkg, RequiredPkg} import com.daml.http.util.FlowUtil.allowOnlyFirstInput -import com.daml.http.util.Logging.InstanceUUID +import com.daml.http.util.Logging.{InstanceUUID, RequestID, extendWithRequestIdLogCtx} import com.daml.lf.crypto.Hash import com.daml.logging.{ContextualizedLogger, LoggingContextOf} import com.daml.metrics.Metrics @@ -697,7 +697,9 @@ class WebSocketService( }.valueOr(e => Source.single(-\/(e))): Source[Error \/ Message, NotUsed], ) .takeWhile(_.isRight, inclusive = true) // stop after emitting 1st error - .map(_.fold(e => wsErrorMessage(e), identity): Message) + .map( + _.fold(e => extendWithRequestIdLogCtx(implicit lc1 => wsErrorMessage(e)), identity): Message + ) } private def parseJson(x: Message): Future[InvalidUserInput \/ JsValue] = x match { @@ -931,7 +933,9 @@ class WebSocketService( .collect { case (_, Some(x)) => x } } - private[http] def wsErrorMessage(error: Error): TextMessage.Strict = + private[http] def wsErrorMessage(error: Error)(implicit + lc: LoggingContextOf[InstanceUUID with RequestID] + ): TextMessage.Strict = wsMessage(SprayJson.encodeUnsafe(errorResponse(error))) private[http] def wsMessage(jsVal: JsValue): TextMessage.Strict =