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

Improve Failing GICS Request Logs #612

Open
stolzA opened this issue Feb 20, 2025 · 2 comments · May be fixed by #624
Open

Improve Failing GICS Request Logs #612

stolzA opened this issue Feb 20, 2025 · 2 comments · May be fixed by #624
Assignees
Labels
aspect/Observability Monitoring, logging, and metrics related to system health kind/Enhancement Improving existing functionality
Milestone

Comments

@stolzA
Copy link

stolzA commented Feb 20, 2025

Log level is set to DEBUG.
In our example the error originates in gICS. The tc-agent log shows:

ERROR 1 --- [onPool-worker-1] c.s.f.t.c.FhirConsentedPatientsProvider  : Unable to fetch consent from gICS
org.springframework.web.reactive.function.client.WebClientResponseException$BadRequest: 400 Bad Request from POST http://gics-test:8080/gics/ttp-fhir/fhir/gics/$allConsentsForDomain
	at org.springframework.web.reactive.function.client.WebClientResponseException.create(WebClientResponseException.java:321) ~[spring-webflux-6.2.2.jar!/:6.2.2]
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
	*__checkpoint ⇢ 400 BAD_REQUEST from POST http://gics-test:8080/gics/ttp-fhir/fhir/gics/$allConsentsForDomain [DefaultWebClient]
Original Stack Trace:
		at org.springframework.web.reactive.function.client.WebClientResponseException.create(WebClientResponseException.java:321) ~[spring-webflux-6.2.2.jar!/:6.2.2]
		at org.springframework.web.reactive.function.client.DefaultClientResponse.lambda$createException$1(DefaultClientResponse.java:214) ~[spring-webflux-6.2.2.jar!/:6.2.2]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:106) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxOnErrorReturn$ReturnSubscriber.onNext(FluxOnErrorReturn.java:162) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxDefaultIfEmpty$DefaultIfEmptySubscriber.onNext(FluxDefaultIfEmpty.java:122) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:299) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxFilterFuseable$FilterFuseableConditionalSubscriber.onNext(FluxFilterFuseable.java:337) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.Operators$BaseFluxToMonoOperator.completePossiblyEmpty(Operators.java:2097) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoCollect$CollectSubscriber.onComplete(MonoCollect.java:145) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPublish$PublishSubscriber.checkTerminated(FluxPublish.java:634) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPublish$PublishSubscriber.drain(FluxPublish.java:494) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPublish$PublishSubscriber.onComplete(FluxPublish.java:355) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onComplete(FluxContextWrite.java:126) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onComplete(FluxMapFuseable.java:350) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxFlattenIterable$FlattenIterableSubscriber.drainAsync(FluxFlattenIterable.java:371) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxFlattenIterable$FlattenIterableSubscriber.drain(FluxFlattenIterable.java:724) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxFlattenIterable$FlattenIterableSubscriber.onComplete(FluxFlattenIterable.java:273) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.adapter.JdkFlowAdapter$SubscriberToRS.onComplete(JdkFlowAdapter.java:160) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at java.net.http/jdk.internal.net.http.ResponseSubscribers$PublishingBodySubscriber.complete(Unknown Source) ~[java.net.http:na]
		at java.net.http/jdk.internal.net.http.ResponseSubscribers$PublishingBodySubscriber.lambda$new$1(Unknown Source) ~[java.net.http:na]
		at java.base/java.util.concurrent.CompletableFuture$UniAccept.tryFire(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture.postComplete(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture.complete(Unknown Source) ~[na:na]
		at java.net.http/jdk.internal.net.http.ResponseSubscribers$PublishingBodySubscriber.lambda$subscribe$3(Unknown Source) ~[java.net.http:na]
		at java.base/java.util.concurrent.CompletableFuture.uniAcceptNow(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture.uniAcceptStage(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture.thenAccept(Unknown Source) ~[na:na]
		at java.net.http/jdk.internal.net.http.ResponseSubscribers$PublishingBodySubscriber.subscribe(Unknown Source) ~[java.net.http:na]
		at reactor.adapter.JdkFlowAdapter$FlowPublisherAsFlux.subscribe(JdkFlowAdapter.java:68) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:68) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPublish.connect(FluxPublish.java:106) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxAutoConnect.subscribe(FluxAutoConnect.java:62) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.Flux.subscribe(Flux.java:8891) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at org.springframework.http.client.reactive.AbstractClientHttpResponse$SingleSubscriberPublisher.subscribe(AbstractClientHttpResponse.java:112) ~[spring-web-6.2.2.jar!/:6.2.2]
		at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:165) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onNext(FluxDoFinally.java:113) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onNext(MonoPeekTerminal.java:180) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.onNext(FluxPeekFuseable.java:854) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.SerializedSubscriber.onNext(SerializedSubscriber.java:99) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.onNext(FluxTimeout.java:181) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPeek$PeekSubscriber.onNext(FluxPeek.java:200) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPeek$PeekSubscriber.onNext(FluxPeek.java:200) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxPeek$PeekSubscriber.onNext(FluxPeek.java:200) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.complete(MonoIgnoreThen.java:294) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onNext(MonoIgnoreThen.java:188) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.apply(MonoCompletionStage.java:121) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.apply(MonoCompletionStage.java:67) ~[reactor-core-3.7.2.jar!/:3.7.2]
		at java.base/java.util.concurrent.CompletableFuture.uniHandle(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture.postComplete(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture.postFire(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.CompletableFuture$Completion.exec(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.ForkJoinTask.doExec(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.ForkJoinPool.scan(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.ForkJoinPool.runWorker(Unknown Source) ~[na:na]
		at java.base/java.util.concurrent.ForkJoinWorkerThread.run(Unknown Source) ~[na:na]
@knoppiks knoppiks added kind/Enhancement Improving existing functionality aspect/Observability Monitoring, logging, and metrics related to system health labels Feb 20, 2025
@knoppiks knoppiks changed the title Logs are not helpful enough when POST request fails. Improve Failing GICS Request Logs Feb 20, 2025
@trobanga trobanga self-assigned this Feb 21, 2025
@trobanga
Copy link
Contributor

We should handle all error codes specified in IG TTP-FHIR Gateway

400: Fehlende oder fehlerhafte Parameter.
401: Fehlende Authentifizierung oder Autorisierung.
404: Parameter mit unbekanntem Inhalt.
422: Fehlende oder falsche Patienten-Attribute.

It seems that at the moment we only handle 404.

@trobanga
Copy link
Contributor

I suggest that if there is an OperationOutcome from gICS, we log and forward it as an error.

@trobanga trobanga linked a pull request Feb 24, 2025 that will close this issue
@trobanga trobanga added this to the 5.2 milestone Feb 24, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
aspect/Observability Monitoring, logging, and metrics related to system health kind/Enhancement Improving existing functionality
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants