【发布时间】：2020-07-06 23:02:56
【问题描述】：
我正在使用 spring-integration（和引导）来设置会话事务处理 JMS 侦听器。但是我观察到一个问题，消息似乎被确认并迟到了一秒钟（即使它们被 spring-integration 应用程序处理得更快。
设置：
#Properties
spring.activemq.broker-url=nio://localhost:61616
spring.activemq.pool.enabled=true
spring.activemq.pool.max-connections=15
spring.activemq.pool.block-if-full=false
#ConnectionFactory
@Bean
public ActiveMQConnectionFactoryCustomizer activeMQConnectionFactoryCustomizer() {
return factory -> {
factory.setClientIDPrefix(amqClientId);
};
}
#Inbound Gateway
@Bean
public IntegrationFlow jmsInFlow(ConnectionFactory connectionFactory, JmsMessageConverter messageConverter) {
TracingMessageListenerContainer tracingMessageListenerContainer = new TracingMessageListenerContainer();
tracingMessageListenerContainer.setConnectionFactory(connectionFactory);
ActiveMQQueue destination = new ActiveMQQueue(jmsIn);
tracingMessageListenerContainer.setDestination(destination);
tracingMessageListenerContainer.setSessionTransacted(true);
tracingMessageListenerContainer.setSessionAcknowledgeMode(CLIENT_ACKNOWLEDGE);
tracingMessageListenerContainer.setConcurrency("100-200");
tracingMessageListenerContainer.setCacheLevel(CACHE_CONSUMER);
return IntegrationFlows.from(Jms.inboundGateway(tracingMessageListenerContainer)
.jmsMessageConverter(messageConverter)
.explicitQosEnabledForReplies(true)
.replyDeliveryPersistent(false)
.errorChannel("integrationError"))
.log(INFO, "InboundMessage")
.headerFilter("jms_type") //FIXME Needed as header is copied from source message to response, should replace with headerFilter on jms gateway
.channel(INFRA_IN)
.get();
}
#Outbound Adapter
@Bean
public IntegrationFlow jmsOutFlow(ConnectionFactory connectionFactory, JmsMessageConverter messageConverter) {
return IntegrationFlows.from(INFRA_OUT)
.log(INFO, "OutboundMessage")
.handle(Jms.outboundAdapter(connectionFactory)
.configureJmsTemplate(jmsTemplateSpec -> {
jmsTemplateSpec.jmsMessageConverter(messageConverter);
jmsTemplateSpec.sessionTransacted(true);
jmsTemplateSpec.sessionAcknowledgeMode(CLIENT_ACKNOWLEDGE);
jmsTemplateSpec.explicitQosEnabled(true);
})
.deliveryModeFunction((Function<org.springframework.messaging.Message<JsonMessage>, Integer>)
message -> Optional.ofNullable(message.getHeaders().get(SEND_PERSISTED_HEADER, Boolean.class))
.map(value -> value ? PERSISTENT : NON_PERSISTENT)
.orElse(NON_PERSISTENT)
)
.destination(jmsOut))
.get();
}
这些是来自代理的日志，您可以看到最终确认和提交正好晚了 1 秒（从应用程序的日志中我可以看到它也更早完成了处理）：
2020-03-24 14:39:24,372 | INFO | Sending message: ActiveMQTextMessage {commandId = 154, responseRequired = true, messageId = ID:s-p.n-39946-1584976128611-12:1:100:1:7, originalDestination = queue://connectionproxy.out, originalTransactionId = null, producerId = testBrokers-p->testBrokers-reg-39946-1584976128611-20:2:1:1, destination = queue://testengine.in, transactionId = null, expiration = 0, timestamp = 1585060764371, arrival = 0, brokerInTime = 1585060764371, brokerOutTime = 1585060764371, correlationId = 8d216a4c-d9d4-4607-be60-f5aaa7159603, replyTo = null, persistent = false, type = DoPlayerAction, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@5f1e98fd, marshalledProperties = org.apache.activemq.util.ByteSequence@58037850, dataStructure = null, redeliveryCounter = 0, size = 1565, properties = {CometdClientId=mg1tq4fa2hfpp6ceztgm0e33q3f, lag=65, deviceSessionId=9999, breadcrumbId=ID-s-reg-novalocal-43151-1584976153021-0-4170, audit_channel=/service/hand/action, ventureId=1, CamelJmsDeliveryMode=1, partnerId=1300, authenticator=c.t.c.i.a.v.TestVentureAuthenticator, memberId=123, RouteLogging=true}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = {"tableId":8,"player":{"id":123,"ve...sequence":8}} | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,372 | INFO | Adding destination: Queue:testengine.in | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,372 | INFO | preProcessDispatch: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = queue://testengine.in, message = ActiveMQTextMessage {} | LBP | ActiveMQ BrokerService[testBrokers-reg] Task-258
2020-03-24 14:39:24,372 | INFO | postProcessDispatch: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = queue://testengine.in, message = ActiveMQTextMessage {} | LBP | ActiveMQ BrokerService[testBrokers-reg] Task-258
2020-03-24 14:39:24,373 | INFO | Beginning transaction: TX:ID:s-r.n-39302-1585056153756-1:1:42 | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,389 | INFO | Adding Producer: ProducerInfo {commandId = 411, responseRequired = true, producerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = null, brokerPath = null, dispatchAsync = false, windowSize = 0, sentCount = 0} | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,390 | INFO | Sending message: ActiveMQTextMessage {commandId = 412, responseRequired = false, messageId = ID:s-r.n-39302-1585056153756-1:1:39:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = queue://testengine.out, transactionId = TX:ID:s-r.n-39302-1585056153756-1:1:42, expiration = 0, timestamp = 1585060764390, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = 8d216a4c-d9d4-4607-be60-f5aaa7159603, replyTo = null, persistent = false, type = HandUpdatedEvent, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@1ab48393, marshalledProperties = org.apache.activemq.util.ByteSequence@5105a072, dataStructure = null, redeliveryCounter = 0, size = 3372, properties = {CometdClientId=mg1tq4fa2hfpp6ceztgm0e33q3f, ventureId=1, CamelJmsDeliveryMode=1, SendPersisted=false, API_VERSION=2.0, RouteLogging=true, lag=65, deviceSessionId=9999, breadcrumbId=ID-s-reg-novalocal-43151-1584976153021-0-4170, SERIALISATION_VERSION=2.0, audit_channel=/service/hand/action, tableId=8, partnerId=1300, authenticator=c.t.c.i.a.v.TestVentureAuthenticator, memberId=123, timestamp=1585060764389}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = {"timestamp":1585060764388,"correlationId":"8...quence":8}}}} | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,391 | INFO | Adding destination: Queue:testengine.out | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,391 | INFO | Sending message: ActiveMQTextMessage {commandId = 413, responseRequired = false, messageId = ID:s-r.n-39302-1585056153756-1:1:39:1:2, originalDestination = null, originalTransactionId = null, producerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = queue://testengine.out, transactionId = TX:ID:s-r.n-39302-1585056153756-1:1:42, expiration = 0, timestamp = 1585060764391, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = 8d216a4c-d9d4-4607-be60-f5aaa7159603, replyTo = null, persistent = false, type = PlayerUpdated, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@7af713df, marshalledProperties = org.apache.activemq.util.ByteSequence@39f53529, dataStructure = null, redeliveryCounter = 0, size = 1733, properties = {tableId=8, SendPersisted=false, API_VERSION=2.0, SERIALISATION_VERSION=2.0, playerId=1_123, timestamp=1585060764391}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = {"timestamp":1585060764390,"correlationId":"8...handId":1}]}} | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,391 | INFO | Adding destination: Queue:testengine.out | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,393 | INFO | Sending message: ActiveMQTextMessage {commandId = 414, responseRequired = false, messageId = ID:s-r.n-39302-1585056153756-1:1:39:1:3, originalDestination = null, originalTransactionId = null, producerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = queue://testengine.out, transactionId = TX:ID:s-r.n-39302-1585056153756-1:1:42, expiration = 0, timestamp = 1585060764392, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = 8d216a4c-d9d4-4607-be60-f5aaa7159603, replyTo = null, persistent = false, type = PlayerUpdated, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@763819f, marshalledProperties = org.apache.activemq.util.ByteSequence@7b99b731, dataStructure = null, redeliveryCounter = 0, size = 1735, properties = {tableId=8, SendPersisted=false, API_VERSION=2.0, SERIALISATION_VERSION=2.0, playerId=1_1585060648037, timestamp=1585060764391}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = {"timestamp":1585060764390,"correlationId":"8...handId":1}]}} | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,393 | INFO | Adding destination: Queue:testengine.out | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,394 | INFO | Sending message: ActiveMQTextMessage {commandId = 415, responseRequired = false, messageId = ID:s-r.n-39302-1585056153756-1:1:39:1:4, originalDestination = null, originalTransactionId = null, producerId = ID:s-r.n-39302-1585056153756-1:1:39:1, destination = queue://testengine.out, transactionId = TX:ID:s-r.n-39302-1585056153756-1:1:42, expiration = 0, timestamp = 1585060764393, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = 8d216a4c-d9d4-4607-be60-f5aaa7159603, replyTo = null, persistent = false, type = TableSequenceUpdatedEvent, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@39b22a76, marshalledProperties = org.apache.activemq.util.ByteSequence@297e1c14, dataStructure = null, redeliveryCounter = 0, size = 2414, properties = {CometdClientId=mg1tq4fa2hfpp6ceztgm0e33q3f, ventureId=1, CamelJmsDeliveryMode=1, SendPersisted=false, API_VERSION=2.0, RouteLogging=true, lag=65, deviceSessionId=9999, breadcrumbId=ID-s-reg-novalocal-43151-1584976153021-0-4170, SERIALISATION_VERSION=2.0, audit_channel=/service/hand/action, tableId=8, partnerId=1300, authenticator=c.t.c.i.a.v.TestVentureAuthenticator, memberId=123, timestamp=1585060764393}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = {"timestamp":1585060764392,"correlationId":"8...675519:0"}]}} | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:24,394 | INFO | Adding destination: Queue:testengine.out | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:25,394 | INFO | Acknowledging message for client ID: thisIsMyClientAppId-39302-1585056153756-0:1, ID:s-p.n-39946-1584976128611-12:1:100:1:7 | LBP | ActiveMQ NIO Worker 42
2020-03-24 14:39:25,394 | INFO | Committing transaction: TX:ID:s-r.n-39302-1585056153756-1:1:42 | LBP | ActiveMQ NIO Worker 42
有人知道我的设置有什么问题导致了这个延迟问题吗？
更新： 这些是来自实际应用程序的日志（与上面的代理日志相反）。不是针对相同的时间戳，而是针对消息集，因此它应该具有可比性。此处似乎不存在延迟。
2020-03-27 10:12:29.556 DEBUG 21528 --- [nerContainer-87] org.apache.activemq.TransactionContext : Begin:TX:ID:s-r.n-39350-1585303832228-1:1:7
2020-03-27 10:12:29.557 DEBUG 21528 --- [nerContainer-87] onConfig$TracingMessageListenerContainer : Received message of type [class org.apache.activemq.command.ActiveMQTextMessage] from consumer [JmsPoolMessageConsumer { ActiveMQMessageConsumer { value=ID:s-r.n-39350-1585303832228-1:1:40:1, started=true } }] of session [JmsPoolSession { ActiveMQSession {id=ID:s-r.n-39350-1585303832228-1:1:40,started=true} java.lang.Object@5a3a13ad }]
2020-03-27 10:12:29.558 DEBUG 21528 --- [nerContainer-87] .i.j.ChannelPublishingJmsMessageListener : converted JMS Message [ActiveMQTextMessage {commandId = 41, responseRequired = true, messageId = ID:s-p.n-39946-1584976128611-12:11:29:1:1, originalDestination = queue://connectionproxy.out, originalTransactionId = null, producerId = gameBrokers-p->gameBrokers-r-39946-1584976128611-125:2:1:1, destination = queue://gameengine.in, transactionId = null, expiration = 0, timestamp = 1585303949554, arrival = 0, brokerInTime = 1585303949555, brokerOutTime = 1585303949556, correlationId = 800da7b4-717b-43a0-b146-428a789dc960, replyTo = null, persistent = false, type = DoPlayerAction, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = org.apache.activemq.util.ByteSequence@5562cdea, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, readOnlyProperties = true, readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer = false, text = {"tableId":14,"player":{"id":123,"v...sequence":3}}] to integration Message payload [DoPlayerActionMessage{action=ACTION3, player=MessageGamePlayerTokenInfo{name='test-console4', instanceId='null', gameSessionId='null'}, tableId=14, amount=MessageCashAmountInfo [amount=5, currencyId=7, currencyIso=TCH], seatNumber=null, sequence=3} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}]
2020-03-27 10:12:29.558 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : preSend on channel 'bean 'jmsInFlow.channel#0'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method jmsInFlow'', message: GenericMessage [payload={} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}, headers={CometdClientId=abc, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_destination=queue://gameengine.in, ventureId=1, CamelJmsDeliveryMode=1, priority=4, jms_timestamp=1585303949554, RouteLogging=true, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_redelivered=false, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, jms_correlationId=800da7b4-717b-43a0-b146-428a789dc960, jms_type=DoPlayerAction, partnerId=1300, id=3037b982-083d-b7df-27d3-1a2eff1ee67e, authenticator=c.g.c.i.a.TestVentureAuthenticator, jms_messageId=ID:s-p.n-39946-1584976128611-12:11:29:1:1, memberId=123, timestamp=1585303949558}]
...
2020-03-27 10:12:29.598 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : preSend on channel 'bean 'jmsOutFlow.channel#1'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method jmsOutFlow'', message: GenericMessage [payload={}, headers={SendPersisted=false, id=acd19c61-0cec-78e8-34ec-7e2f6531a6be, timestamp=1585303949597}]
2020-03-27 10:12:29.598 DEBUG 21528 --- [nerContainer-87] o.s.i.jms.JmsSendingMessageRoundler : bean 'jmsOutFlow.jms:outbound-channel-adapter#0' for component 'jmsOutFlow.org.springframework.integration.config.ConsumerEndpointFactoryBean#1'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method jmsOutFlow' received message: GenericMessage [payload={}, headers={SendPersisted=false, id=acd19c61-0cec-78e8-34ec-7e2f6531a6be, timestamp=1585303949597}]
2020-03-27 10:12:29.598 DEBUG 21528 --- [nerContainer-87] o.s.integration.jms.DynamicJmsTemplate : Executing callback on JMS Session: JmsPoolSession { ActiveMQSession {id=ID:s-r.n-39350-1585303832228-1:1:40,started=true} java.lang.Object@5a3a13ad }
2020-03-27 10:12:29.600 DEBUG 21528 --- [nerContainer-87] o.s.integration.jms.DynamicJmsTemplate : Sending created message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = null, originalDestination = null, originalTransactionId = null, producerId = null, destination = null, transactionId = null, expiration = 0, timestamp = 0, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = 800da7b4-717b-43a0-b146-428a789dc960, replyTo = null, persistent = false, type = RoundUpdatedEvent, priority = 0, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {CometdClientId=abc, ventureId=1, CamelJmsDeliveryMode=1, SendPersisted=false, API_VERSION=2.0, RouteLogging=true, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, SERIALISATION_VERSION=2.0, audit_channel=/service/round/action, tableId=14, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, timestamp=1585303949597}, readOnlyProperties = false, readOnlyBody = false, droppable = false, jmsXGroupFirstForConsumer = false, text = {"timestamp":1585303949596,"correlationId":"8...quence":3}}}}
2020-03-27 10:12:29.601 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'jmsOutFlow.channel#1'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method jmsOutFlow'', message: GenericMessage [payload={}, headers={SendPersisted=false, id=acd19c61-0cec-78e8-34ec-7e2f6531a6be, timestamp=1585303949597}]
2020-03-27 10:12:29.601 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'infraOut'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method appOutFlow'', message: GenericMessage [payload={}, headers={SendPersisted=false, id=acd19c61-0cec-78e8-34ec-7e2f6531a6be, timestamp=1585303949597}]
2020-03-27 10:12:29.601 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'appOut'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method appOutManyFlow'', message: GenericMessage [payload={}, headers={SendPersisted=false, id=c0d9e1f5-9f00-b60d-b991-ef6b11e8b436, timestamp=1585303949597}]
2020-03-27 10:12:29.602 DEBUG 21528 --- [nerContainer-87] o.s.i.roundler.ServiceActivatingRoundler : roundler 'ServiceActivator for [org.springframework.integration.roundler.MethodInvokingMessageProcessor@675fdd0] (appInFlow.org.springframework.integration.config.ConsumerEndpointFactoryBean#0)' produced no reply for request Message: GenericMessage [payload={} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}, headers={CometdClientId=abc, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_destination=queue://gameengine.in, ventureId=1, CamelJmsDeliveryMode=1, priority=4, jms_timestamp=1585303949554, RouteLogging=true, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_redelivered=false, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, jms_correlationId=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, id=6728c2b8-869b-4df5-a0e4-316a6a95d087, authenticator=c.g.c.i.a.TestVentureAuthenticator, jms_messageId=ID:s-p.n-39946-1584976128611-12:11:29:1:1, memberId=123, timestamp=1585303949559}]
2020-03-27 10:12:29.602 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'appIn'; defined in: 'class path resource [companynew/game/gs/config/application/ApplicationConfig.class]'; from source: 'bean method appInFlow'', message: GenericMessage [payload={} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}, headers={CometdClientId=abc, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_destination=queue://gameengine.in, ventureId=1, CamelJmsDeliveryMode=1, priority=4, jms_timestamp=1585303949554, RouteLogging=true, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_redelivered=false, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, jms_correlationId=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, id=6728c2b8-869b-4df5-a0e4-316a6a95d087, authenticator=c.g.c.i.a.TestVentureAuthenticator, jms_messageId=ID:s-p.n-39946-1584976128611-12:11:29:1:1, memberId=123, timestamp=1585303949559}]
2020-03-27 10:12:29.602 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'appInUnAuthenticated'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method infraInFlow'', message: GenericMessage [payload={} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}, headers={CometdClientId=abc, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_destination=queue://gameengine.in, ventureId=1, CamelJmsDeliveryMode=1, priority=4, jms_timestamp=1585303949554, RouteLogging=true, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_redelivered=false, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, jms_correlationId=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, id=6728c2b8-869b-4df5-a0e4-316a6a95d087, authenticator=c.g.c.i.a.TestVentureAuthenticator, jms_messageId=ID:s-p.n-39946-1584976128611-12:11:29:1:1, memberId=123, timestamp=1585303949559}]
2020-03-27 10:12:29.602 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'infraIn'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method jmsInFlow'', message: GenericMessage [payload={} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}, headers={CometdClientId=abc, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_destination=queue://gameengine.in, ventureId=1, CamelJmsDeliveryMode=1, priority=4, jms_timestamp=1585303949554, RouteLogging=true, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_redelivered=false, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, jms_correlationId=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, id=6728c2b8-869b-4df5-a0e4-316a6a95d087, authenticator=c.g.c.i.a.TestVentureAuthenticator, jms_messageId=ID:s-p.n-39946-1584976128611-12:11:29:1:1, memberId=123, timestamp=1585303949559}]
2020-03-27 10:12:29.602 DEBUG 21528 --- [nerContainer-87] o.s.integration.channel.DirectChannel : postSend (sent=true) on channel 'bean 'jmsInFlow.channel#0'; defined in: 'class path resource [c/g/g/c/i/j/JmsIntegrationConfig.class]'; from source: 'bean method jmsInFlow'', message: GenericMessage [payload={} JsonMessage{timestamp=Fri Mar 27 10:12:29 UTC 2020, correlationId='800da7b4-717b-43a0-b146-428a789dc960', venture='null', ventureId=null, headers={CometdClientId=abc, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, ventureId=1, CamelJmsDeliveryMode=1, JMSCorrelationID=800da7b4-717b-43a0-b146-428a789dc960, partnerId=1300, authenticator=c.g.c.i.a.TestVentureAuthenticator, memberId=123, RouteLogging=true}, loggingMessage=true}, headers={CometdClientId=abc, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_destination=queue://gameengine.in, ventureId=1, CamelJmsDeliveryMode=1, priority=4, jms_timestamp=1585303949554, RouteLogging=true, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@77054e87, jms_redelivered=false, lag=49, deviceSessionId=9999, breadcrumbId=ID-s-r-novalocal-43151-1584976153021-0-9607, audit_channel=/service/round/action, jms_correlationId=800da7b4-717b-43a0-b146-428a789dc960, jms_type=DoPlayerAction, partnerId=1300, id=3037b982-083d-b7df-27d3-1a2eff1ee67e, authenticator=c.g.c.i.a.TestVentureAuthenticator, jms_messageId=ID:s-p.n-39946-1584976128611-12:11:29:1:1, memberId=123, timestamp=1585303949558}]
2020-03-27 10:12:30.602 DEBUG 21528 --- [nerContainer-87] .i.j.ChannelPublishingJmsMessageListener : expected a reply but none was received
2020-03-27 10:12:30.603 DEBUG 21528 --- [nerContainer-87] org.apache.activemq.ActiveMQSession : ID:s-r.n-39350-1585303832228-1:1:40 Transaction Commit :TX:ID:s-r.n-39350-1585303832228-1:1:7
2020-03-27 10:12:30.603 DEBUG 21528 --- [nerContainer-87] org.apache.activemq.TransactionContext : Commit: TX:ID:s-r.n-39350-1585303832228-1:1:7 syncCount: 1
2020-03-27 10:12:32.355 DEBUG 21528 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10001ms elapsed since last write check.
【问题讨论】：
-
如果没有看到其余的流程和调试日志，很难说。为
org.springframework.integration开启 DEBUG 日志记录并检查通过应用程序的消息流的日志时间戳。 -
我认为
TracingMessageListenerContainer必须是一个bean。我相信它是对现有容器的一些扩展，因此必须在afterPropertiesSet()中完成一些初始化逻辑。 -
另外，很高兴看到调用该确认的代码以及在该 ack 调用之前您的流程看起来如何。
-
@GaryRussell 我已将应用程序端日志的示例添加到问题中
-
@GaryRussell 我现在明白了一半，注意到日志
expected a reply but none was received。事实证明，在我的 spring-integration 流程中，我有一个返回null/void的服务激活器。阅读文档我理解这有效地终止了流程。入站 JMS 消息不期望响应，并且由于某种原因，流提前终止会导致此延迟（而不是立即确认 JMS 消息）。也许您知道原因或可以提出解决方法？如何实现一个可以在同一个队列上处理request-reply和non request-reply的JMS网关？
标签： spring-boot jms spring-integration activemq spring-jms