chore: log request and user ID as log annotations (DEV-1233) (#2466)

dasch-swiss · Feb 23, 2023 · bec6fe6 · bec6fe6
1 parent 6de3c5d
commit bec6fe6
Show file tree

Hide file tree

Showing 4 changed files with 17 additions and 3 deletions.
diff --git a/project/Dependencies.scala b/project/Dependencies.scala
@@ -38,7 +38,7 @@ object Dependencies {
   val zioHttp              = "dev.zio" %% "zio-http"               % ZioHttpVersion
   val zioJson              = "dev.zio" %% "zio-json"               % ZioJsonVersion
   val zioLogging           = "dev.zio" %% "zio-logging"            % ZioLoggingVersion
-  val zioLoggingSlf4j      = "dev.zio" %% "zio-logging-slf4j"      % ZioLoggingVersion
+  val zioLoggingSlf4j      = "dev.zio" %% "zio-logging-slf4j2"     % ZioLoggingVersion
   val zioMacros            = "dev.zio" %% "zio-macros"             % ZioVersion
   val zioMetricsConnectors = "dev.zio" %% "zio-metrics-connectors" % ZioMetricsConnectorsVersion
   val zioPrelude           = "dev.zio" %% "zio-prelude"            % ZioPreludeVersion

diff --git a/webapi/src/main/resources/logback.xml b/webapi/src/main/resources/logback.xml
@@ -7,7 +7,7 @@
 
     <appender name="STDOUT" class="ConsoleAppender">
         <encoder class="PatternLayoutEncoder">
-            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
+            <pattern>%d{HH:mm:ss.SSS} [%thread] [%kvp] %-5level %logger{36} - %msg%n</pattern>
         </encoder>
     </appender>
 

diff --git a/webapi/src/main/scala/org/knora/webapi/core/HttpServerZ.scala b/webapi/src/main/scala/org/knora/webapi/core/HttpServerZ.scala
@@ -9,7 +9,9 @@ import zio._
 import zio.http._
 import zio.http.middleware.Cors
 import zio.http.model.Method
+import zio.logging.LogAnnotation.TraceId
 
+import java.util.UUID
 import scala.annotation.tailrec
 
 import org.knora.webapi.config.AppConfig
@@ -32,6 +34,17 @@ object HttpServerZ {
         )
     } yield Middleware.cors(corsConfig)
 
+  private val loggingMiddleware = Middleware.requestLogging()
+
+  private val tracingMiddleware = new Middleware[Any, Nothing, Request, Response, Request, Response] {
+    override def apply[R1, E1](http: Http[R1, E1, Request, Response])(implicit
+      trace: Trace
+    ): Http[R1, E1, Request, Response] =
+      Http.collectZIO[Request] { case request =>
+        http(request).mapError(_.get) @@ TraceId(UUID.randomUUID())
+      }
+  }
+
   private def metricsMiddleware() = {
     // in order to avoid extensive amounts of labels, we should replace path segment slugs
     // see docs/03-endpoints/instrumentation/metrics.md
@@ -66,7 +79,7 @@ object HttpServerZ {
       routes              <- apiRoutes
       cors                <- corsMiddleware
       metrics              = metricsMiddleware()
-      routesWithMiddleware = routes @@ cors @@ metrics
+      routesWithMiddleware = routes @@ cors @@ metrics @@ loggingMiddleware @@ tracingMiddleware
       serverConfig         = ZLayer.succeed(ServerConfig.default.port(port))
       _                   <- Server.serve(routesWithMiddleware).provide(Server.live, serverConfig).forkDaemon
       _                   <- ZIO.logInfo(">>> Acquire ZIO HTTP Server <<<")

diff --git a/webapi/src/main/scala/org/knora/webapi/http/middleware/AuthenticationMiddleware.scala b/webapi/src/main/scala/org/knora/webapi/http/middleware/AuthenticationMiddleware.scala
@@ -42,6 +42,7 @@ final case class AuthenticationMiddleware(authenticatorService: AuthenticatorSer
             authenticatorService
               .getUser(request)
               .orElseSucceed(KnoraSystemInstances.Users.AnonymousUser)
+              .tap(u => ZIO.logInfo(s"Authenticated as User: ${u.id} (${u.username})"))
         } yield (request, requestingUser),
       out => ZIO.succeed(out)
     )