From 20cfe15fcf2cec03ecf040e26b26a1283c86c0a4 Mon Sep 17 00:00:00 2001
From: Fabian Engelniederhammer <fabian.engelniederhammer@tngtech.com>
Date: Wed, 3 Apr 2024 14:34:35 +0200
Subject: [PATCH] feat: log whether request was cached #717

and reduce logging noise from data version checker
---
 .../genspectrum/lapis/LapisSpringConfig.kt    |  1 -
 .../lapis/logging/RequestContext.kt           |  1 +
 .../org/genspectrum/lapis/silo/SiloClient.kt  | 20 ++++++++++++++++---
 3 files changed, 18 insertions(+), 4 deletions(-)

diff --git a/lapis2/src/main/kotlin/org/genspectrum/lapis/LapisSpringConfig.kt b/lapis2/src/main/kotlin/org/genspectrum/lapis/LapisSpringConfig.kt
index 0b928ba16..11e6c8a21 100644
--- a/lapis2/src/main/kotlin/org/genspectrum/lapis/LapisSpringConfig.kt
+++ b/lapis2/src/main/kotlin/org/genspectrum/lapis/LapisSpringConfig.kt
@@ -75,7 +75,6 @@ class LapisSpringConfig {
         filter.setIncludePayload(true)
         filter.setMaxPayloadLength(10000)
         filter.setIncludeHeaders(false)
-        filter.setAfterMessagePrefix("REQUEST DATA: ")
         return filter
     }
 
diff --git a/lapis2/src/main/kotlin/org/genspectrum/lapis/logging/RequestContext.kt b/lapis2/src/main/kotlin/org/genspectrum/lapis/logging/RequestContext.kt
index 87b7d2a66..8dfdd390a 100644
--- a/lapis2/src/main/kotlin/org/genspectrum/lapis/logging/RequestContext.kt
+++ b/lapis2/src/main/kotlin/org/genspectrum/lapis/logging/RequestContext.kt
@@ -20,6 +20,7 @@ class RequestContext {
     var endpoint: String? = null
     var filter: CommonSequenceFilters? = null
     var responseCode: Int? = null
+    var cached: Boolean? = null
 }
 
 private val log = KotlinLogging.logger {}
diff --git a/lapis2/src/main/kotlin/org/genspectrum/lapis/silo/SiloClient.kt b/lapis2/src/main/kotlin/org/genspectrum/lapis/silo/SiloClient.kt
index 59ef4f22b..c012a09d3 100644
--- a/lapis2/src/main/kotlin/org/genspectrum/lapis/silo/SiloClient.kt
+++ b/lapis2/src/main/kotlin/org/genspectrum/lapis/silo/SiloClient.kt
@@ -4,6 +4,7 @@ import com.fasterxml.jackson.databind.ObjectMapper
 import com.fasterxml.jackson.module.kotlin.readValue
 import mu.KotlinLogging
 import org.genspectrum.lapis.controller.LapisHeaders.REQUEST_ID
+import org.genspectrum.lapis.logging.RequestContext
 import org.genspectrum.lapis.logging.RequestIdContext
 import org.genspectrum.lapis.response.InfoData
 import org.springframework.beans.factory.annotation.Value
@@ -27,14 +28,22 @@ const val SILO_RESPONSE_MAX_LOG_LENGTH = 10_000
 class SiloClient(
     private val cachedSiloClient: CachedSiloClient,
     private val dataVersion: DataVersion,
+    private val requestContext: RequestContext,
 ) {
     fun <ResponseType> sendQuery(query: SiloQuery<ResponseType>): ResponseType {
         val result = cachedSiloClient.sendQuery(query)
         dataVersion.dataVersion = result.dataVersion
+
+        if (RequestContextHolder.getRequestAttributes() != null && requestContext.cached == null) {
+            requestContext.cached = true
+        }
+
         return result.queryResult
     }
 
     fun callInfo(): InfoData {
+        log.info { "Calling SILO info" }
+
         val info = cachedSiloClient.callInfo()
         dataVersion.dataVersion = info.dataVersion
         return info
@@ -48,11 +57,16 @@ class CachedSiloClient(
     @Value("\${silo.url}") private val siloUrl: String,
     private val objectMapper: ObjectMapper,
     private val requestIdContext: RequestIdContext,
+    private val requestContext: RequestContext,
 ) {
     private val httpClient = HttpClient.newHttpClient()
 
     @Cacheable(SILO_QUERY_CACHE_NAME, condition = "#query.action.cacheable && !#query.action.randomize")
     fun <ResponseType> sendQuery(query: SiloQuery<ResponseType>): WithDataVersion<ResponseType> {
+        if (RequestContextHolder.getRequestAttributes() != null) {
+            requestContext.cached = false
+        }
+
         val queryJson = objectMapper.writeValueAsString(query)
 
         log.info { "Calling SILO: $queryJson" }
@@ -74,8 +88,6 @@ class CachedSiloClient(
     }
 
     fun callInfo(): InfoData {
-        log.info { "Calling SILO info" }
-
         val response = send(URI("$siloUrl/info")) { it.GET() }
 
         return InfoData(getDataVersion(response))
@@ -101,7 +113,9 @@ class CachedSiloClient(
             throw RuntimeException(message, exception)
         }
 
-        log.info { "Response from SILO: ${response.statusCode()}" }
+        if (!uri.toString().endsWith("info")) {
+            log.info { "Response from SILO: ${response.statusCode()}" }
+        }
         log.debug {
             val body = response.body()
             val truncationPostfix = when {