[jboss-jira] [JBoss JIRA] (WFLY-7352) XNIO bridge for Artemis doesn't work with newer versions of Netty and Artemis.
Jeff Mesnil (JIRA)
issues at jboss.org
Tue Feb 21 04:28:00 EST 2017
[ https://issues.jboss.org/browse/WFLY-7352?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jeff Mesnil resolved WFLY-7352.
-------------------------------
Fix Version/s: 11.0.0.Alpha1
Resolution: Done
netty-xnio-transport has been upgrade to 0.1.2.Final and Netty to 4.1.5.Final
> XNIO bridge for Artemis doesn't work with newer versions of Netty and Artemis.
> ------------------------------------------------------------------------------
>
> Key: WFLY-7352
> URL: https://issues.jboss.org/browse/WFLY-7352
> Project: WildFly
> Issue Type: Bug
> Components: JMS
> Reporter: Jeff Mesnil
> Assignee: Jeff Mesnil
> Priority: Blocker
> Fix For: 11.0.0.Alpha1
>
>
> Test scenario:
> 1. Start server EAP 7.1.0.DR6 (with Artemis 1.4.0) with queue InQueue and OutQueue. Configure non-exclusive divert from InQueue to OutQueue.
> 2. Send large message to InQueue with scheduled delivery 10 seconds
> 3. Start consumer on OutQueue with receive timeout 1000ms and check that NO message was received
> 4. Start consumer on InQueue with receive timeout 1000ms and check that NO message was received
> 5. Start consumer on InQueue with receive timeout 11000ms and check that message is received
> 6. Start consumer on OutQueue with receive timeout 11000ms and check that message is received
> Result:
> Sometimes happens that consumer in step 3. receives a message. By checking trace logs, consumer in step 3. was receiving message 9664ms instead of ~1000ms.
> In attachment is trace log from client and server and test log with client thread dump during ~10s receive.
> Investigation:
> In the moment when client tries to receive a message there is send SessionForceConsumerDelivery packet by client:
> {code}
> 15:07:07,589 Thread-11 INFO [org.jboss.qa.artemis.test.messages.JmsMessagesTestCase$ReceiveThread:474] Start message comsumption from original queue with receive timeout 1000ms
> 15:07:07,590 Thread-11 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl:386] org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl at 332729ad{consumerContext=ActiveMQConsumerContext{id=0}, queueName=jms.queue.OutQueue}:: receive(1000)
> 15:07:07,590 Thread-11 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl:191] org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl at 332729ad{consumerContext=ActiveMQConsumerContext{id=0}, queueName=jms.queue.OutQueue}::receive(1000, false)
> 15:07:08,591 Thread-11 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl:370] org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl at 332729ad{consumerContext=ActiveMQConsumerContext{id=0}, queueName=jms.queue.OutQueue}::Returning null
> 15:07:08,591 Thread-11 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl:392] org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl at 332729ad{consumerContext=ActiveMQConsumerContext{id=0}, queueName=jms.queue.OutQueue}:: receive(1000) -> null, trying again with receive(0)
> 15:07:08,591 Thread-11 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl:191] org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl at 332729ad{consumerContext=ActiveMQConsumerContext{id=0}, queueName=jms.queue.OutQueue}::receive(0, true)
> 15:07:08,592 Thread-11 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl:301] org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl at 332729ad{consumerContext=ActiveMQConsumerContext{id=0}, queueName=jms.queue.OutQueue}::Forcing delivery
> 15:07:08,593 Thread-11 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl:248] Sending packet nonblocking PACKET(SessionForceConsumerDelivery)[type=78, channelID=11, packetObject=SessionForceConsumerDelivery, consumerID=0, sequence=0] on channeID=11
> 15:07:08,604 Thread-11 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl:286] Writing buffer for channelID=11
> {code}
> Response from server comes ~10s later - it's packet SessionReceiveMessage:
> {code}
> 15:07:17,250 Thread-0 (ActiveMQ-client-netty-threads-1138697171) TRACE [org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl:354] handling packet PACKET(SessionReceiveMessage)[type=75, chan
> nelID=11, packetObject=SessionReceiveMessage, message=ClientMessageImpl[messageID=44, durable=false, address=jms.queue.OutQueue,userID=null,properties=TypedProperties[_hornetq.forced.delivery.seq=0]], consumerID
> =0, deliveryCount=0]
> {code}
> in the mean time client is waiting on - ---org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.receive(ClientConsumerImpl.java:261):
> {noformat}
> wait(Long.MAX_VALUE);
> {noformat}
> and is waiting for notify. From server log I can see that SessionReceiveMessage was send at:
> {code}
> 15:07:08,621 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-18 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$2 at 39cb2b3a-1512482465)) Sending packet nonblocking PACKET(SessionReceiveMessage)[type=75, channelID=11, packetObject=SessionReceiveMessage, message=ServerMessage[messageID=44,durable=false,userID=null,priority=0, bodySize=50, timestamp=0,expiration=0, durable=false, address=jms.queue.OutQueue,properties=TypedProperties[_hornetq.forced.delivery.seq=0]]@1525441837, consumerID=0, deliveryCount=0] on channeID=11
> 15:07:08,633 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-18 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$2 at 39cb2b3a-1512482465)) Writing buffer for channelID=11
> {code}
> but it wasn't flushed and for some reason is actually send ~10s later with the large message:
> {code}
> 15:07:17,236 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-27 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$2 at 39cb2b3a-1512482465)) Sending pa
> cket nonblocking PACKET(SessionReceiveLargeMessage)[type=76, channelID=11, packetObject=SessionReceiveLargeMessage, consumerID=0, deliveryCount=1, largeMessageSize=409605, message=LargeServerMessage[messageID=40
> ,durable=true,userID=1befe4c2-920f-11e6-9ae8-3ca9f4349bfc,priority=4, timestamp=Fri Oct 14 15:07:07 CEST 2016,expiration=0, durable=true, address=jms.queue.OutQueue,properties=TypedProperties[__AMQ_CID=1bdc35af-
> 920f-11e6-9ae8-3ca9f4349bfc,_AMQ_SCHED_DELIVERY=1476450437224,_AMQ_ORIG_ADDRESS=jms.queue.InQueue,_AMQ_ORIG_MESSAGE_ID=36,counter=0,_AMQ_DUPL_ID=16c2be09-573a-4e02-a369-6a36c2f32fbd,_AMQ_LARGE_SIZE=409605]]@1994
> 218683] on channeID=11
> 15:07:17,246 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-27 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$2 at 39cb2b3a-1512482465)) Writing bu
> ffer for channelID=11
> 15:07:17,247 TRACE [org.xnio.nio.selector] (default I/O-1) Selected on sun.nio.ch.EPollSelectorImpl at 61ea580a
> 15:07:17,247 TRACE [org.xnio.nio] (default I/O-1) Running task io.netty.channel.AbstractChannelHandlerContext$WriteAndFlushTask at 5c93c5d7
> {code}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
More information about the jboss-jira
mailing list