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.

Sign up for GitHub

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

Jump to bottom

Missing MHS header wait-for-response on outbound messages #88

Closed
no-man-is-an-island opened this issue Feb 16, 2021 · 2 comments · Fixed by #91
Closed

Missing MHS header wait-for-response on outbound messages #88

no-man-is-an-island opened this issue Feb 16, 2021 · 2 comments · Fixed by #91

Comments

@no-man-is-an-island
Copy link

Gp2Gp adapter version: 0.0.1
MHS outbound adapter version: 1.0.2

Steps to reproduce:

When running the e2e tests, with the gp2gp adapter pointing at a real instance of the MHS adapter (as opposed to the mock). No spine/opentest connectivity needed, as the outbound request does not get past the initial request validation in the MHS outbound service.

Description of error:

The outbound MHS request sent by the Gp2Gp adapter gets requested with the following error:

gp2gp_1             | 2021-02-15 23:09:49.955 Level=INFO  Logger=u.n.a.g.e.SendEhrExtractCoreTaskExecutor ConversationId=1234 TaskId=1cdd25e3-c0b0-4919-a484-65f1d4b8bc8b Thread="DefaultMessageListenerContainer-1" Message="SendEhrExtractCore task was created, Sending EHR extract to Spine"
gp2gp_1             | 2021-02-15 23:09:50.017 Level=INFO  Logger=uk.nhs.adaptors.gp2gp.mhs.MhsClient ConversationId=1234 TaskId=1cdd25e3-c0b0-4919-a484-65f1d4b8bc8b Thread="DefaultMessageListenerContainer-1" Message="Mhs Outbound Request, Mhs Outbound Endpoint: http://outbound"
outbound_1          | [2021-02-15T23:09:50.040431Z] | INFO | 9 |  | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 |  |  | outbound.outbound.request.synchronous.handler | Didn't receive message id in incoming request from supplier, so have generated a new one.
outbound_1          | [2021-02-15T23:09:50.040605Z] | INFO | 9 |  | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 | BD9A3537-BD60-4ED1-955E-250F65B108BE |  | outbound.outbound.request.synchronous.handler | Didn't receive correlation id in incoming request from supplier, so have generated a new one.
outbound_1          | [2021-02-15T23:09:50.040670Z] | INFO | 9 | RCMR_IN030000UK06 | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 | BD9A3537-BD60-4ED1-955E-250F65B108BE |  | outbound.outbound.request.synchronous.handler | Found Interaction-Id in message headers
outbound_1          | [2021-02-15T23:09:50.040769Z] | ERROR | 9 | RCMR_IN030000UK06 | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 | BD9A3537-BD60-4ED1-955E-250F65B108BE |  | outbound.outbound.request.synchronous.handler | Failed to parse wait-for-response header from message
outbound_1          | [2021-02-15T23:09:50.040958Z] | INFO | 9 | RCMR_IN030000UK06 | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 | BD9A3537-BD60-4ED1-955E-250F65B108BE |  | outbound.utilities.timing | FuncName=post from Handler=SynchronousHandler took Duration=0.001 seconds
outbound_1          | [2021-02-15T23:09:50.041058Z] | WARNING | 9 | RCMR_IN030000UK06 | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 | BD9A3537-BD60-4ED1-955E-250F65B108BE |  | outbound.tornado.general | 400 POST / (192.168.112.7): wait-for-response header missing
outbound_1          | [2021-02-15T23:09:50.041601Z] | WARNING | 9 | RCMR_IN030000UK06 | 0715A0DF-DFB9-4A4C-BB57-234C00F40381 | BD9A3537-BD60-4ED1-955E-250F65B108BE |  | outbound.tornado.access | 400 POST / (192.168.112.7) 2.03ms
gp2gp_1             | 2021-02-15 23:09:50.060 Level=ERROR Logger=u.n.a.gp2gp.common.task.TaskConsumer ConversationId=1234 TaskId=1cdd25e3-c0b0-4919-a484-65f1d4b8bc8b Thread="DefaultMessageListenerContainer-1" Message="Error while processing task queue message ID:782c2eb9-fdb8-4121-b132-6bdc8a8ecb35:2:1:2-1"
gp2gp_1             | uk.nhs.adaptors.gp2gp.mhs.InvalidOutboundMessageException: The following error occurred during Mhs Outbound Request: 400: wait-for-response header missing
gp2gp_1             | 	at uk.nhs.adaptors.gp2gp.common.service.WebClientFilterService.lambda$getResponseError$4(WebClientFilterService.java:52)
gp2gp_1             | 	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
gp2gp_1             | Error has been observed at the following site(s):
gp2gp_1             | 	|_ checkpoint ⇢ Request to POST http://outbound [DefaultWebClient]
gp2gp_1             | Stack trace:
gp2gp_1             | 		at uk.nhs.adaptors.gp2gp.common.service.WebClientFilterService.lambda$getResponseError$4(WebClientFilterService.java:52)
gp2gp_1             | 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:125)
gp2gp_1             | 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:127)
gp2gp_1             | 		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107)
gp2gp_1             | 		at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:295)
gp2gp_1             | 		at reactor.core.publisher.FluxFilterFuseable$FilterFuseableConditionalSubscriber.onNext(FluxFilterFuseable.java:337)
gp2gp_1             | 		at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1789)
gp2gp_1             | 		at reactor.core.publisher.MonoCollect$CollectSubscriber.onComplete(MonoCollect.java:159)
gp2gp_1             | 		at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:142)
gp2gp_1             | 		at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:259)
gp2gp_1             | 		at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:142)
gp2gp_1             | 		at reactor.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:389)
gp2gp_1             | 		at reactor.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:396)
gp2gp_1             | 		at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:452)
gp2gp_1             | 		at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:664)
gp2gp_1             | 		at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:94)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
gp2gp_1             | 		at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
gp2gp_1             | 		at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
gp2gp_1             | 		at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
gp2gp_1             | 		at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
gp2gp_1             | 		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
gp2gp_1             | 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
gp2gp_1             | 		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
gp2gp_1             | 		at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:795)
gp2gp_1             | 		at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:480)
gp2gp_1             | 		at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378)
gp2gp_1             | 		at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
gp2gp_1             | 		at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
gp2gp_1             | 		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
gp2gp_1             | 		at java.base/java.lang.Thread.run(Unknown Source)
gp2gp_1             | 	Suppressed: java.lang.Exception: #block terminated with an error
gp2gp_1             | 		at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:99)
gp2gp_1             | 		at reactor.core.publisher.Mono.block(Mono.java:1703)
gp2gp_1             | 		at uk.nhs.adaptors.gp2gp.mhs.MhsClient.sendEhrExtractCore(MhsClient.java:23)
gp2gp_1             | 		at uk.nhs.adaptors.gp2gp.ehr.SendEhrExtractCoreTaskExecutor.execute(SendEhrExtractCoreTaskExecutor.java:50)
gp2gp_1             | 		at uk.nhs.adaptors.gp2gp.ehr.SendEhrExtractCoreTaskExecutor.execute(SendEhrExtractCoreTaskExecutor.java:21)
gp2gp_1             | 		at uk.nhs.adaptors.gp2gp.common.task.TaskHandler.handle(TaskHandler.java:44)
gp2gp_1             | 		at uk.nhs.adaptors.gp2gp.common.task.TaskConsumer.receive(TaskConsumer.java:28)
gp2gp_1             | 		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
gp2gp_1             | 		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
gp2gp_1             | 		at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
gp2gp_1             | 		at java.base/java.lang.reflect.Method.invoke(Unknown Source)
gp2gp_1             | 		at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:171)
gp2gp_1             | 		at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:120)
gp2gp_1             | 		at org.springframework.jms.listener.adapter.MessagingMessageListenerAdapter.invokeHandler(MessagingMessageListenerAdapter.java:114)
gp2gp_1             | 		at org.springframework.jms.listener.adapter.MessagingMessageListenerAdapter.onMessage(MessagingMessageListenerAdapter.java:77)
gp2gp_1             | 		at org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:736)
gp2gp_1             | 		at org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:696)
gp2gp_1             | 		at org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:674)
gp2gp_1             | 		at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:318)
gp2gp_1             | 		at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:257)
gp2gp_1             | 		at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1189)
gp2gp_1             | 		at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1179)
gp2gp_1             | 		at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:1076)
gp2gp_1             | 		at java.base/java.lang.Thread.run(Unknown Source)
@mattd-kainos
Copy link
Contributor

This issue has been fixed in main by e8e91cd but not yet included in a release. As a workaround you could build an image from main. We'll get a new release out to include this fix.

@mattd-kainos mattd-kainos linked a pull request Feb 17, 2021 that will close this issue
NIAD-1089 Release 0.0.2 #91
Merged
@mattd-kainos
Copy link
Contributor

Should be fixed with 0.0.2 release, please reopen if there are any issues

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

NIAD-1089 Release 0.0.2 NHSDigital/integration-adaptor-gp2gp-sending
2 participants
@no-man-is-an-island @mattd-kainos