Skip to content

Commit

Permalink
chore: full trace logging in message handler
Browse files Browse the repository at this point in the history
  • Loading branch information
@karl-run
karl-run committed Apr 30, 2024
1 parent 9b459c1 commit fc00608
Showing 1 changed file with 43 additions and 3 deletions.
46 changes: 43 additions & 3 deletions src/main/kotlin/no/nav/syfo/application/BlockingApplicationRunner.kt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -110,9 +110,9 @@ class BlockingApplicationRunner(
wrapExceptions {
loop@ while (applicationState.ready) {
val randomUuid = UUID.randomUUID().toString()
logger.info("Polling for message, trace id: $randomUuid")
logger.info("TRACE_DEBUG: Polling for message, trace id: $randomUuid")
val message = inputconsumer.receive(1000)
logger.info("Received message, trace id: $randomUuid")
logger.info("TRACE_DEBUG: Received message, trace id: $randomUuid")

var loggingMeta: LoggingMeta? = null
if (message == null) {
Expand All @@ -133,17 +133,19 @@ class BlockingApplicationRunner(
val requestLatency = REQUEST_TIME.startTimer()
val fellesformat = safeUnmarshal(inputMessageText)

logger.info("TRACE_DEBUG: Before vedlegg, trace id: $randomUuid")
val vedlegg = getVedlegg(fellesformat)
if (vedlegg.isNotEmpty()) {
SYKMELDING_VEDLEGG_COUNTER.inc()
removeVedleggFromFellesformat(fellesformat)
}
logger.info("TRACE_DEBUG: After vedlegg, trace id: $randomUuid")
val fellesformatText =
when (vedlegg.isNotEmpty()) {
true -> fellesformatMarshaller.toString(fellesformat)
false -> inputMessageText
}

logger.info("TRACE_DEBUG: AFter fellesformat, trace id: $randomUuid")
val receiverBlock = fellesformat.get<XMLMottakenhetBlokk>()
val msgHead = fellesformat.get<XMLMsgHead>()
val legekontorOrgNr =
Expand All @@ -157,13 +159,16 @@ class BlockingApplicationRunner(
orgNr = legekontorOrgNr,
msgId = msgHead.msgInfo.msgId,
)
logger.info("TRACE_DEBUG: Received message, trace id: $randomUuid")
logger.info("Received message, {}", StructuredArguments.fields(loggingMeta))

val healthInformation = extractHelseOpplysningerArbeidsuforhet(fellesformat)
val ediLoggId = receiverBlock.ediLoggId
val sha256String = sha256hashstring(healthInformation)
val msgId = msgHead.msgInfo.msgId

logger.info("TRACE_DEBUG: After health information, trace id: $randomUuid")

val legekontorHerId = extractOrganisationHerNumberFromSender(fellesformat)?.id
val legekontorReshId = extractOrganisationRashNumberFromSender(fellesformat)?.id
val legekontorOrgName =
Expand All @@ -172,6 +177,8 @@ class BlockingApplicationRunner(
""
)

logger.info("TRACE_DEBUG: After legekontorstuff, trace id: $randomUuid")

val partnerReferanse = receiverBlock.partnerReferanse

val originaltPasientFnr = healthInformation.pasient.fodselsnummer.id
Expand All @@ -186,6 +193,7 @@ class BlockingApplicationRunner(

val avsenderSystem = healthInformation.avsenderSystem.toAvsenderSystem()

logger.info("TRACE_DEBUG: Before sykmelding stuff, trace id: $randomUuid")
val sykmeldingId = UUID.randomUUID().toString()

val rulesetVersion = healthInformation.regelSettVersjon
Expand All @@ -203,6 +211,7 @@ class BlockingApplicationRunner(
rulesetVersion,
)

logger.info("TRACE_DEBUG: Before extract, trace id: $randomUuid")
logger.info(
"Extracted data, ready to make sync calls to get more data, {}",
StructuredArguments.fields(loggingMeta),
Expand All @@ -221,6 +230,7 @@ class BlockingApplicationRunner(
)
}

logger.info("TRACE_DEBUG: Before signatur, trace id: $randomUuid")
val signaturFnr =
if (erVirksomhetSykmelding) {
logger.info(
Expand Down Expand Up @@ -269,20 +279,27 @@ class BlockingApplicationRunner(
} else {
receiverBlock.avsenderFnrFraDigSignatur
}
logger.info("TRACE_DEBUG: After signatur, trace id: $randomUuid")

logger.info("TRACE_DEBUG: before PDL, trace id: $randomUuid")
val identer =
pdlPersonService.getIdenter(
listOf(signaturFnr, originaltPasientFnr),
loggingMeta,
)
logger.info("TRACE_DEBUG: After PDL, trace id: $randomUuid")

logger.info("TRACE_DEBUG: Before TSSID, trace id: $randomUuid")
val tssIdEmottak =
smtssClient.findBestTssIdEmottak(
signaturFnr,
legekontorOrgName,
loggingMeta,
sykmeldingId,
)
logger.info("TRACE_DEBUG: After TSSID, trace id: $randomUuid")

logger.info("TRACE_DEBUG: Before TSSID INFOTOAST, trace id: $randomUuid")
val tssIdInfotrygd =
if (!tssIdEmottak.isNullOrEmpty()) {
tssIdEmottak
Expand All @@ -294,6 +311,7 @@ class BlockingApplicationRunner(
sykmeldingId,
)
}
logger.info("TRACE_DEBUG: After TTSID INFOTOAST, trace id: $randomUuid")

logger.info(
"tssIdEmottak is $tssIdEmottak {}",
Expand All @@ -304,6 +322,7 @@ class BlockingApplicationRunner(
StructuredArguments.fields(loggingMeta),
)

logger.info("TRACE_DEBUG: Before emottak sub, trace id: $randomUuid")
handleEmottakSubscription(
tssIdEmottak,
emottakSubscriptionClient,
Expand All @@ -312,11 +331,16 @@ class BlockingApplicationRunner(
partnerReferanse,
loggingMeta,
)
logger.info("TRACE_DEBUG: After emottak sub, trace id: $randomUuid")


logger.info("TRACE_DEBUG: Before dup check, trace id: $randomUuid")
val duplicationCheckSha256String =
duplicationService.getDuplicationCheck(sha256String, ediLoggId)
logger.info("TRACE_DEBUG: After dup check, trace id: $randomUuid")

if (duplicationCheckSha256String != null) {
logger.info("TRACE_DEBUG: Inside dup check not null, trace id: $randomUuid")
val duplicate =
Duplicate(
sykmeldingId,
Expand All @@ -341,8 +365,10 @@ class BlockingApplicationRunner(
duplicationService,
duplicate,
)
logger.info("TRACE_DEBUG: After dup check not null, trace id: $randomUuid")
continue@loop
} else {
logger.info("TRACE_DEBUG: Inside dup check IS! null, trace id: $randomUuid")
val pasient = identer[originaltPasientFnr]
val behandler = identer[signaturFnr]

Expand All @@ -363,14 +389,17 @@ class BlockingApplicationRunner(
duplicateCheck,
)
) {
logger.info("TRACE_DEBUG: Inside dup check skipping??, trace id: $randomUuid")
continue@loop
}

logger.info("TRACE_DEBUG: Inside dup check before behandler, trace id: $randomUuid")
val signerendeBehandler =
norskHelsenettClient.getByFnr(
fnr = signaturFnr,
loggingMeta = loggingMeta,
)
logger.info("TRACE_DEBUG: Inside dup check after behandler, trace id: $randomUuid")

val behandlenedeBehandler =
if (
Expand All @@ -388,6 +417,7 @@ class BlockingApplicationRunner(
null
}

logger.info("TRACE_DEBUG: Inside dup check before behandlene behandler, trace id: $randomUuid")
val behandlenedeBehandlerFnr =
extractFnrDnrFraBehandler(healthInformation)
?: getBehandlerFnr(
Expand All @@ -396,7 +426,9 @@ class BlockingApplicationRunner(
behandlenedeBehandler = behandlenedeBehandler,
)
?: signaturFnr
logger.info("TRACE_DEBUG: Inside dup check after behandlene behandler, trace id: $randomUuid")

logger.info("TRACE_DEBUG: Inside dup check before behandlene behandler (HPR), trace id: $randomUuid")
val behandlenedeBehandlerhprNummer =
padHpr(extractHpr(fellesformat)?.id?.trim())
?: getBehandlerHprNr(
Expand All @@ -405,6 +437,7 @@ class BlockingApplicationRunner(
avsenderHpr = padHpr(extractHpr(fellesformat)?.id?.trim()),
behandlenedeBehandler = behandlenedeBehandler,
)
logger.info("TRACE_DEBUG: Inside dup check after behandlene behandler (HPR), trace id: $randomUuid")

val sykmelding =
healthInformation.toSykmelding(
Expand All @@ -430,6 +463,7 @@ class BlockingApplicationRunner(
)
}

logger.info("TRACE_DEBUG: Inside dup check before vedlegg, trace id: $randomUuid")
if (vedlegg.isNotEmpty()) {
val vedleggOver300MegaByte =
vedlegg.filter {
Expand Down Expand Up @@ -468,6 +502,8 @@ class BlockingApplicationRunner(
continue@loop
}
}
logger.info("TRACE_DEBUG: Inside dup check after vedlegg, trace id: $randomUuid")


if (sykmelding.signaturDato.isAfter(LocalDateTime.now())) {
handleSignaturDatoInTheFuture(
Expand All @@ -484,6 +520,7 @@ class BlockingApplicationRunner(
continue@loop
}

logger.info("TRACE_DEBUG: Inside dup check before vedlegg LISTE, trace id: $randomUuid")
val vedleggListe: List<String> =
if (vedlegg.isNotEmpty()) {
bucketUploadService.lastOppVedlegg(
Expand All @@ -503,7 +540,9 @@ class BlockingApplicationRunner(
} else {
emptyList()
}
logger.info("TRACE_DEBUG: Inside dup check after vedlegg LISTE, trace id: $randomUuid")

// ASSUMED OK HER
val receivedSykmelding =
ReceivedSykmelding(
sykmelding = sykmelding,
Expand Down Expand Up @@ -553,6 +592,7 @@ class BlockingApplicationRunner(
loggingMeta,
)

logger.info("TRACE_DEBUG: Inside dup check before WHEN, trace id: $randomUuid")
when (validationResult.status) {
Status.OK ->
handleStatusOK(
Expand Down

0 comments on commit fc00608

Please sign in to comment.