Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log full stack trace on validator exceptions #172

Merged
merged 1 commit into from
May 8, 2024

Conversation

dehall
Copy link
Contributor

@dehall dehall commented Apr 9, 2024

It can be difficult to debug the root cause of exceptions in the validator wrapper because only the exception message is returned and logged, not the whole stack trace. This PR just adds the caught exception to the logger statement so that the stack trace is logged. No changes to the response.
Addresses the most important part of #170 (and the previous PR #168 also made uncaught Errors get logged, so that's no longer a big concern either)

I haven't been able to consistently reproduce Exceptions (the ones we've seen have been one-off or environment related), so the easiest way to test this is probably to change the method ValidationControllerImpl.validateRequest to just throw an exception, eg:

throw org.hl7.fhir.exceptions.FHIRException("test")

Before this PR change, this would log:

2024-04-09 11:57:11.033 [ktor-jetty-8082-2] INFO  ktor.application - Received Validation Request. FHIR Version: 4.0.1 IGs: [] Memory (free/max): 543476728/9663676416
2024-04-09 11:57:11.039 [ktor-jetty-8082-2] ERROR ktor.application - test
2024-04-09 11:57:11.300 [ktor-jetty-8082-4] INFO  ktor.application - 500 Internal Server Error: POST - /validate

With the PR change:

2024-04-09 11:53:14.321 [ktor-jetty-8082-2] INFO  ktor.application - Received Validation Request. FHIR Version: 4.0.1 IGs: [] Memory (free/max): 544638504/9663676416
2024-04-09 11:53:14.327 [ktor-jetty-8082-2] ERROR ktor.application - test
org.hl7.fhir.exceptions.FHIRException: test
	at controller.validation.ValidationControllerImpl.validateRequest(ValidationControllerImpl.kt:18)
	at controller.validation.ValidationModuleKt$validationModule$1.invokeSuspend(ValidationModule.kt:43)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at io.ktor.util.pipeline.SuspendFunctionGun.resumeRootWith(SuspendFunctionGun.kt:138)
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:112)
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(SuspendFunctionGun.kt:14)
	at io.ktor.util.pipeline.SuspendFunctionGun$continuation$1.resumeWith(SuspendFunctionGun.kt:62)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
2024-04-09 11:53:14.587 [ktor-jetty-8082-4] INFO  ktor.application - 500 Internal Server Error: POST - /validate

@dotasek dotasek self-requested a review May 8, 2024 22:18
Copy link
Collaborator

@dotasek dotasek left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good improvement. Tested with your instructions locally, and now get a full stack trace.

@dotasek dotasek merged commit 6ef15b2 into hapifhir:master May 8, 2024
3 of 5 checks passed
@dehall dehall deleted the log_validator_stack_trace branch May 9, 2024 11:05
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants