Skip to content

Commit b507724

Browse files
committed
Added some logging to find out what takes time (in context of Prometheus).
1 parent 6f44aa1 commit b507724

File tree

2 files changed

+43
-10
lines changed

2 files changed

+43
-10
lines changed

src/main/kotlin/no/nav/klage/search/config/FunksjonelleGaugesConfiguration.kt

+2-2
Original file line numberDiff line numberDiff line change
@@ -26,8 +26,8 @@ class FunksjonelleGaugesConfiguration {
2626
fun registerFunctionalStats(elasticsearchService: ElasticsearchService): MeterBinder {
2727
return try {
2828
MeterBinder { registry: MeterRegistry ->
29-
Ytelse.values().forEach { ytelse ->
30-
Type.values().forEach { type ->
29+
Ytelse.entries.forEach { ytelse ->
30+
Type.entries.forEach { type ->
3131
Gauge.builder("funksjonell.ikketildelt") { elasticsearchService.countIkkeTildelt(ytelse, type) }
3232
.tag("ytelse", ytelse.navn)
3333
.tag("type", type.navn)

src/main/kotlin/no/nav/klage/search/service/ElasticsearchService.kt

+41-8
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@ import org.opensearch.search.sort.SortBuilders
2222
import org.opensearch.search.sort.SortOrder
2323
import org.springframework.context.ApplicationListener
2424
import org.springframework.context.event.ContextRefreshedEvent
25+
import java.lang.System.currentTimeMillis
2526
import java.time.LocalDate
2627
import java.util.*
2728
import java.util.concurrent.TimeUnit
@@ -277,31 +278,55 @@ open class ElasticsearchService(private val esBehandlingRepository: EsBehandling
277278
}
278279

279280
open fun countIkkeTildelt(ytelse: Ytelse, type: Type): Long {
280-
return countByStatusYtelseAndType(IKKE_TILDELT, ytelse, type)
281+
return runWithTiming(method = ::countIkkeTildelt.name) {
282+
countByStatusYtelseAndType(IKKE_TILDELT, ytelse, type)
283+
}
281284
}
282285

283286
open fun countTildelt(ytelse: Ytelse, type: Type): Long {
284-
return countByStatusYtelseAndType(TILDELT, ytelse, type)
287+
return runWithTiming(method = ::countTildelt.name) {
288+
countByStatusYtelseAndType(TILDELT, ytelse, type)
289+
}
285290
}
286291

287292
open fun countSendtTilMedunderskriver(ytelse: Ytelse, type: Type): Long {
288-
return countByStatusYtelseAndType(SENDT_TIL_MEDUNDERSKRIVER, ytelse, type)
293+
return runWithTiming(method = ::countSendtTilMedunderskriver.name) {
294+
countByStatusYtelseAndType(SENDT_TIL_MEDUNDERSKRIVER, ytelse, type)
295+
}
289296
}
290297

291298
open fun countMedunderskriverValgt(ytelse: Ytelse, type: Type): Long {
292-
return countByStatusYtelseAndType(MEDUNDERSKRIVER_VALGT, ytelse, type)
299+
return runWithTiming(method = ::countMedunderskriverValgt.name) {
300+
countByStatusYtelseAndType(MEDUNDERSKRIVER_VALGT, ytelse, type)
301+
}
293302
}
294303

295304
open fun countReturnertTilSaksbehandler(ytelse: Ytelse, type: Type): Long {
296-
return countByStatusYtelseAndType(RETURNERT_TIL_SAKSBEHANDLER, ytelse, type)
305+
return runWithTiming(method = ::countReturnertTilSaksbehandler.name) {
306+
countByStatusYtelseAndType(RETURNERT_TIL_SAKSBEHANDLER, ytelse, type)
307+
}
297308
}
298309

299310
open fun countAvsluttet(ytelse: Ytelse, type: Type): Long {
300-
return countByStatusYtelseAndType(FULLFOERT, ytelse, type)
311+
return runWithTiming(method = ::countAvsluttet.name) {
312+
countByStatusYtelseAndType(FULLFOERT, ytelse, type)
313+
}
301314
}
302315

303316
open fun countSattPaaVent(ytelse: Ytelse, type: Type): Long {
304-
return countByStatusYtelseAndType(SATT_PAA_VENT, ytelse, type)
317+
return runWithTiming(method = ::countSattPaaVent.name) {
318+
countByStatusYtelseAndType(SATT_PAA_VENT, ytelse, type)
319+
}
320+
}
321+
322+
private fun <T> runWithTiming(method: String, block: () -> T): T {
323+
val start = currentTimeMillis()
324+
try {
325+
return block.invoke()
326+
} finally {
327+
val end = currentTimeMillis()
328+
logger.debug("Time it took to call $method: ${end - start} millis")
329+
}
305330
}
306331

307332
private fun countByStatusYtelseAndType(status: EsStatus, ytelse: Ytelse, type: Type): Long {
@@ -313,6 +338,7 @@ open class ElasticsearchService(private val esBehandlingRepository: EsBehandling
313338
}
314339

315340
open fun countAntallSaksdokumenterIAvsluttedeBehandlingerMedian(ytelse: Ytelse, type: Type): Double {
341+
val start = currentTimeMillis()
316342
val baseQuery: BoolQueryBuilder = QueryBuilders.boolQuery()
317343
baseQuery.must(QueryBuilders.termQuery(EsBehandling::status.name, FULLFOERT))
318344
baseQuery.must(QueryBuilders.termQuery(EsBehandling::ytelseId.name, ytelse.id))
@@ -324,7 +350,14 @@ open class ElasticsearchService(private val esBehandlingRepository: EsBehandling
324350
}
325351
.toList()
326352

327-
return getMedian(saksdokumenterPerAvsluttetBehandling)
353+
val medianStart = currentTimeMillis()
354+
val median = getMedian(saksdokumenterPerAvsluttetBehandling)
355+
val medianEnd = currentTimeMillis()
356+
logger.debug("Time it took to calculate median for list with ${saksdokumenterPerAvsluttetBehandling.size} elements: ${medianEnd - medianStart} millis")
357+
358+
val end = currentTimeMillis()
359+
logger.debug("Time it took to call ${::countAntallSaksdokumenterIAvsluttedeBehandlingerMedian.name}: ${end - start} millis")
360+
return median
328361
}
329362

330363
open fun countLedigeOppgaverMedUtgaattFristByCriteria(criteria: CountLedigeOppgaverMedUtgaattFristSearchCriteria): Int {

0 commit comments

Comments
 (0)