jms:inbound-gateway invoking ws:outbound-gateway problem

[marcin.kasinski]

Hello
I made simple JMS test scenarios with JMS.

Scenario 1.

Read jms queue with soap message -> send request to service-activator -> generate JMS reply

<int-jms:inbound-gateway id="jmshelloin"

default-reply-queue-name="replies"
request-destination-name="requests"
connection-factory="connectionFactory"
request-channel="jmsChannelIn" />


		<int:service-activator id="jms_processRequest" input-channel="jmsChannelIn" method="processHelloFromString">
		<bean class="mk.ProcessHello"  />
				<int:poller fixed-delay="200"></int:poller>
		</int:service-activator>

	public Message<?> processHelloFromString(String inxml, @Headers MessageHeaders headers) {
...

		String returnedXMLString="<soap:Envelope xmlns:soap=\"http://schemas.xmlsoap.org/soap/envelope/\">   <soap:Body>      <ns2:helloResponse xmlns:ns2=\"http://mkpackage/\">         <return>Hello ZAAAZ</return>      </ns2:helloResponse>   </soap:Body></soap:Envelope>";
		


				Message<?> retmessage = MessageBuilder.withPayload(returnedXMLString)
						.setHeader("inputHeadersfromJMS", headers)
						.copyHeaders(headers)
						 .setReplyChannel((MessageChannel)
										  headers.getReplyChannel()) .build();



						return retmessage;

	}

It works OK.
Gateway sends reply and I can read it from reply queue.



Scenario 2.

Read jms queue with soap message -> send request to service-activator -> send soap to remote HTTP WebService -> send HTTP response to service-activator -> generate JMS reply

<int-jms:inbound-gateway id="jmshelloinadvanced"

default-reply-queue-name="replies2"
request-destination-name="requests2"
connection-factory="connectionFactory"
request-channel="jmsChannelIn2"

/>

		<int:service-activator id="jms_processRequest2" input-channel="jmsChannelIn2" method="processHelloFromString2" 
		output-channel="channelbeforechain"
		 >


			<int:chain id="mqadvanced" input-channel="channelbeforechain"  >
				<int:poller fixed-delay="200"></int:poller>

			<int-ws:outbound-gateway id="HelloGateway" fault-message-resolver="SimpleFaultMessageResolver"
		uri="http://localhost:9091/HelloImplWeb/services/HelloMgrImplPort" />

			<int:service-activator method="processHelloReplyFromString" >
		<bean class="mk.ProcessHelloReply"/>
	</int:service-activator>

	</int:chain>

In ProcessHelloReply I generate reply XML after processing HTTP Web Service reply.

			
	public Message<?>  processHelloReplyFromString(String in,@Headers MessageHeaders headers) {
...
Message<?> retmessage = MessageBuilder.withPayload(retString)

					.copyHeaders(headers)

					 .setReplyChannel((MessageChannel)
									  headers.getReplyChannel()) .build();
	
			printHeaders(headers);
	
			System.out.println("sending reply :"+retString);
					return retmessage;

}

In service output I can see returned XML and headers

errorChannel: org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@1115887b org.springframework.integration.core.MessagingTemplate.TemporaryReplyChannel org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel
JMS_IBM_Format: MQSTR    java.lang.String java.lang.String
SOAPJMS_bindingVersion: 1.0 java.lang.String java.lang.String
jms_timestamp: 1348256417457 java.lang.Long java.lang.Long
replyChannel: org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@1115887b org.springframework.integration.core.MessagingTemplate.TemporaryReplyChannel org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel
SOAPJMS_soapAction: "urn:Hello" java.lang.String java.lang.String
JMSXUserID: MUSR_MQADMIN java.lang.String java.lang.String
jms_replyTo: queue://QM_WBRK/MQSI.APPCXFQM3.QIN com.ibm.mq.jms.MQQueue com.ibm.mq.jms.MQQueue
JMS_IBM_MsgType: 1 java.lang.Integer java.lang.Integer
JMS_IBM_PutApplType: 28 java.lang.Integer java.lang.Integer
JMS_IBM_PutDate: 20120921 java.lang.String java.lang.String
jms_messageId: ID:414d5120514d5f5742524b2020202020f3aa5c5020018e03 java.lang.String java.lang.String
JMS_IBM_PutTime: 19401747 java.lang.String java.lang.String
timestamp: 1348256420516 java.lang.Long java.lang.Long
id: eb81c578-80e8-425d-a025-679ab8744574 java.util.UUID java.util.UUID
JMS_IBM_Character_Set: UTF-8 java.lang.String java.lang.String
history: jmshelloinadvanced,jmsChannelIn2,jms_processRequest2,channelbeforechain,mqadvanced org.springframework.integration.history.MessageHistory org.springframework.integration.history.MessageHistory
JMSXDeliveryCount: 1 java.lang.Integer java.lang.Integer
jms_redelivered: false java.lang.Boolean java.lang.Boolean
inputHeadersfromJMS: {errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@1115887b, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348256417457, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@1115887b, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120921, jms_messageId=ID:414d5120514d5f5742524b2020202020f3aa5c5020018e03, JMS_IBM_PutTime=19401747, timestamp=1348256417677, id=396a4711-f7c9-4bb6-b034-5c57fb3597c4, JMS_IBM_Character_Set=UTF-8, history=jmshelloinadvanced,jmsChannelIn2,jms_processRequest2, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java} org.springframework.integration.MessageHeaders org.springframework.integration.MessageHeaders
SOAPJMS_contentType: text/xml; charset=UTF-8 java.lang.String java.lang.String
JMS_IBM_Encoding: 273 java.lang.Integer java.lang.Integer
SOAPJMS_isFault: false java.lang.Boolean java.lang.Boolean
JMSXAppID: WebSphere MQ Client for Java java.lang.String java.lang.String

sending reply :<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">   <soap:Body>      <ns2:helloResponse xmlns:ns2="http://mkpackage/">         <return>Hello AAAKKKKKKKAZZZZZZZZZKKKKKKK</return>      </ns2:helloResponse>   </soap:Body></soap:Envelope>

Problem is that in this scenarion that generated JMS reply messageis not put into my JMS reply queue.

Any idea what I do wrong here ?

[Gary Russell]

I suggest you run with DEBUG level logging, the framework will log the messages as they flow through the system. It should become clear what's happening.

[marcin.kasinski]

Thanks Gary for reply.

Here is my log4j .

log4j.rootCategory=trace, stdout

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d %p [%c] - <%m>%n

log4j.category.org.apache.activemq=trace
log4j.category.org.springframework.batch=trace
log4j.category.org.springframework.transaction=trace
log4j.category.org.springframework.integration.jms=trace
log4j.category.org.springframework=trace
log4j.category.org.springframework.jms=trace


log4j.category.org.hibernate.SQL=trace
# for traceging datasource initialization
# log4j.category.test.jdbc=trace

With scenario 1 I got :

2012-09-22 13:36:36,288 DEBUG [org.springframework.integration.handler.ServiceActivatingHandler] - <handler 'ServiceActivator for [org.springframework.integration.handler.MethodInvokingMessageProcessor@47cf39e]' sending reply Message: [Payload=<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">   <soap:Body>      <ns2:helloResponse xmlns:ns2="http://mkpackage/">         <return>Hello ZAAAZ</return>      </ns2:helloResponse>   </soap:Body></soap:Envelope>][Headers={errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@3b5657af, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348313796148, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@3b5657af, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120922, JMS_IBM_PutTime=11363617, jms_messageId=ID:414d5120514d5f5742524b202020202034a05d5020006403, timestamp=1348313796288, id=f358e1a0-5ba4-47fc-b38c-80c1dff2861c, history=jmshelloin,jmsChannelIn,jms_processRequest, JMS_IBM_Character_Set=UTF-8, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, inputHeadersfromJMS={errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@3b5657af, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348313796148, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@3b5657af, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120922, jms_messageId=ID:414d5120514d5f5742524b202020202034a05d5020006403, JMS_IBM_PutTime=11363617, timestamp=1348313796248, id=2a6eab01-9296-4fb7-a39f-110c66a7fc40, JMS_IBM_Character_Set=UTF-8, history=jmshelloin,jmsChannelIn,jms_processRequest, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java}, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java}]>

With scenario 2 I got :

2012-09-22 13:37:51,385 DEBUG [org.springframework.integration.handler.ServiceActivatingHandler] - <handler 'ServiceActivator for [org.springframework.integration.handler.MethodInvokingMessageProcessor@3077df72]' sending reply Message: [Payload=<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">   <soap:Body>      <ns2:helloResponse xmlns:ns2="http://mkpackage/">         <return>Hello AAAKKKKKKKAZZZZZZZZZKKKKKKK</return>      </ns2:helloResponse>   </soap:Body></soap:Envelope>][Headers={errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@4fcd8366, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348313868802, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@4fcd8366, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120922, JMS_IBM_PutTime=11374882, jms_messageId=ID:414d5120514d5f5742524b202020202034a05d5020007703, timestamp=1348313871385, id=1da139d6-1c80-4879-b514-6c9a6f00e068, history=jmshelloinadvanced,jmsChannelIn2,jms_processRequest2,channelbeforechain,mqadvanced, JMS_IBM_Character_Set=UTF-8, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, inputHeadersfromJMS={errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@4fcd8366, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348313868802, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@4fcd8366, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120922, jms_messageId=ID:414d5120514d5f5742524b202020202034a05d5020007703, JMS_IBM_PutTime=11374882, timestamp=1348313868882, id=ffbf4362-c03d-407b-95ad-cb9cc2d21947, JMS_IBM_Character_Set=UTF-8, history=jmshelloinadvanced,jmsChannelIn2,jms_processRequest2, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java}, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java}]>

In both scenarios debud says that message is sent.
I dont know what it is.

[marcin.kasinski]

Hello.

I've done Spring Integration code debugging.

The source of my problem was ws outbound gateway timeout .
Service invoked by my gateway executes requests very slow and I need increase reply timeout.

Nw my question is:

How can I set reply timeout on my ws outbound gateway ?

[Gary Russell]

I am confused by your statement; in both logs above you show the service activator sending a reply, so how can it be a timeout problem on the ws gateway?

By default the ws outbound gateway has infinite timeout; it can be adjusted by providing a customized message sender with a receiveTimeout.

The inbound JMS gateway has a timeout, but that only applies if you use any async handoffs downstream. When using direct channels it's ignored.

We need to see the whole log to help further - pulling out individual log records is not much help.

Also, it is always a good idea to use the thread name (%t) in the log pattern when debugging Spring Integration apps.

[marcin.kasinski]

Sorry Gary it is my fault.

It is not clear timeout.

I'll try to explain it with detailed information after little Spring integration code research.

Lets focus on my "Scenario 2".

Read jms queue with soap message -> send request to service-activator -> send soap to remote HTTP WebService -> send HTTP response to service-activator -> generate JMS reply


With this scenario everything works fine with short reply . When invoked service sends reply in very short time (let say less then second) I can see and then process reply message in JMS queue.

If invoked service sends reply after let say 10 seconds there is no reply message in JMS queue.

Below logs .

...

11:49:04.770 DEBUG [task-scheduler-3][org.springframework.integration.ws.DefaultSoapHeaderMapper] headerName=[JMSXAppID] WILL NOT be mapped
11:49:04.770 DEBUG [task-scheduler-3][org.springframework.ws.client.MessageTracing.sent] Sent request [SaajSoapMessage {http://mkpackage/}hello]
wrz 24, 2012 11:49:04 AM org.apache.cxf.services.HelloMgrImplService.HelloMgrImplPort.HelloMgrInterface
INFO: Inbound Message

Here invoked service receive request
----------------------------
ID: 1
Address: http://localhost:9090/HelloImplWeb/services/HelloMgrImplPort
Encoding: UTF-8
Http-Method: POST
Content-Type: text/xml; charset=utf-8
Headers: {Accept=[text/xml, text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2], accept-encoding=[gzip], cache-control=[no-cache], connection=[keep-alive], Content-Length=[218], content-type=[text/xml; charset=utf-8], host=[localhost:9090], pragma=[no-cache], SOAPAction=[""], user-agent=[Java/1.7.0_04]}
Payload: <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body><ns2:hello xmlns:ns2="http://mkpackage/"><arg0>AAAAA</arg0></ns2:hello></SOAP-ENV:Body></SOAP-ENV:Envelope>
--------------------------------------


11:49:05.164 DEBUG [org.springframework.jms.listener.DefaultMessageListenerContainer#0-1][org.springframework.integration.jms.ChannelPublishingJmsMessageListener] expected a reply but none was received
11:49:05.644 DEBUG [task-scheduler-8][org.springframework.integration.endpoint.PollingConsumer] Poll resulted in Message: null
11:49:05.644 DEBUG [task-scheduler-8][org.springframework.integration.endpoint.PollingConsumer] Received no Message during the poll, returning 'false'
...

wrz 24, 2012 11:49:15 AM org.apache.cxf.services.HelloMgrImplService.HelloMgrImplPort.HelloMgrInterface
INFO: Outbound Message
---------------------------
Here invoked service sends reply

ID: 1
Encoding: UTF-8
Content-Type: text/xml
Headers: {}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><ns2:helloResponse xmlns:ns2="http://mkpackage/"><return>Hello AAAAA</return></ns2:helloResponse></soap:Body></soap:Envelope>
--------------------------------------
11:49:15.174 DEBUG [task-scheduler-3][org.springframework.ws.client.MessageTracing.received] Received response [SaajSoapMessage {http://mkpackage/}helloResponse] for request [SaajSoapMessage {http://mkpackage/}hello]
...
11:49:15.174 DEBUG [task-scheduler-3][org.springframework.integration.handler.ServiceActivatingHandler] handler 'ServiceActivator for [org.springframework.integration.handler.MethodInvokingMessageProcessor@190f3ef6]' sending reply Message: [Payload=<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">   <soap:Body>      <ns2:helloResponse xmlns:ns2="http://mkpackage/">         <return>Hello AAAKKKKKKKAZZZZZZZZZKKKKKKK</return>      </ns2:helloResponse>   </soap:Body></soap:Envelope>][Headers={errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@381486a1, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348480143992, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@381486a1, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120924, JMS_IBM_PutTime=09490404, jms_messageId=ID:414d5120514d5f5742524b2020202020070360502002ce03, timestamp=1348480155174, id=e6926a6c-a77d-4032-87e1-0c5645a5ba31, JMS_IBM_Character_Set=UTF-8, history=jmshelloinadvanced,jmsChannelIn2,jms_processRequest2,channelbeforechain,mqadvanced, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, inputHeadersfromJMS={errorChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@381486a1, JMS_IBM_Format=MQSTR   , SOAPJMS_bindingVersion=1.0, jms_timestamp=1348480143992, replyChannel=org.springframework.integration.core.MessagingTemplate$TemporaryReplyChannel@381486a1, SOAPJMS_soapAction="urn:Hello", JMSXUserID=MUSR_MQADMIN, jms_replyTo=queue://QM_WBRK/MQSI.APPCXFQM3.QIN, JMS_IBM_MsgType=1, JMS_IBM_PutApplType=28, JMS_IBM_PutDate=20120924, jms_messageId=ID:414d5120514d5f5742524b2020202020070360502002ce03, JMS_IBM_PutTime=09490404, timestamp=1348480144642, id=3c4b1cfd-5773-4806-af0b-fab4f16eddbe, history=jmshelloinadvanced,jmsChannelIn2,jms_processRequest2, JMS_IBM_Character_Set=UTF-8, JMSXDeliveryCount=1, jms_redelivered=false, SOAPJMS_contentType=text/xml; charset=UTF-8, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java}, JMS_IBM_Encoding=273, SOAPJMS_isFault=false, JMSXAppID=WebSphere MQ Client for Java}]
11:49:15.768 DEBUG [task-scheduler-1][org.springframework.integration.endpoint.PollingConsumer] Poll resulted in Message: null
11:49:15.768 DEBUG [task-scheduler-1][org.springframework.integration.endpoint.PollingConsumer] Received no Message during the poll, returning 'false'

As you can see SI checks reply just after sending request to webService (expected a reply but none was received log message ).
SI because thinks reply is null dosn't send reply.

My question is : Why SI try to send reply before my entire flow ends ?
Did I miss something ?

When service sends reply in very short time there is no "expected a reply but none was received" message in logs.


I hope now it is clear.