[
https://issues.apache.org/jira/browse/ARTEMIS-1217?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
clebert suconic closed ARTEMIS-1217.
------------------------------------
> Race condition during session reconnection
> ------------------------------------------
>
> Key: ARTEMIS-1217
> URL: https://issues.apache.org/jira/browse/ARTEMIS-1217
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Affects Versions: 2.1.0
> Reporter: Andrius Dagys
> Priority: Minor
>
> We have the following scenario:
> There's a client and a server. The server runs a broker and creates a session
> with a producer/consumer to monitor the server queue and respond to client
> requests.
> The client establishes a session with the server broker, creates a client
> queue and a producer/consumer to send requests to the server and receive
> responses.
> In one of our tests we check that the client can correctly reconnect when the
> server (and the broker) restarts. The problem is that occasionally after
> reconnecting the client is able to send a request message to the server
> queue, but the server fails to send a response message due to the client
> queue bindings not being set yet.
> It also seems to be caused by the fact that the client uses different
> sessions for consumer & producer. However, this issue started occurring only
> after we updated from 1.5.3 to 2.1.0.
> Here's an excerpt from the logs:
> {code}
> 16:32:14 [Thread-5 (activemq-netty-threads)]
> impl.RemotingConnectionImpl.bufferReceived - handling packet
> PACKET(SessionSendMessage)[type=71, channelID=10,
> packetObject=SessionSendMessage, message=ServerMessage[messageID=0],
> requiresResponse=false]
> 16:32:14 [Thread-5 (activemq-netty-threads)]
> core.ServerSessionPacketHandler.handlePacket -
> ServerSessionPacketHandler::handlePacket,PACKET(SessionSendMessage)[type=71,
> channelID=10, packetObject=SessionSendMessage,
> message=ServerMessage[messageID=0], requiresResponse=false]
> 16:32:14 [Thread-5 (activemq-netty-threads)] impl.ServerSessionImpl.send -
> send(message=CoreMessage[messageID=26,durable=false,userID=null,priority=4,
> timestamp=Mon Jun 05 16:32:14 BST 2017,expiration=0, durable=false,
> address=rpc.client.user1.5976801431518807802,properties=TypedProperties[tag=0,rpc-id=8487092758120613782,_AMQ_VALIDATED_USER=user1]]@572371329,
> direct=true) being called
> 16:32:14 [Thread-5 (activemq-netty-threads)] impl.SecurityStoreImpl.check -
> checking access permissions to rpc.client.user1.5976801431518807802
> 16:32:14 [Thread-5 (activemq-netty-threads)] impl.PostOfficeImpl.route -
> Couldn't find any bindings for address=rpc.client.user1.5976801431518807802
> on message=CoreMessage[messageID=26,durable=false,userID=null,priority=4,
> timestamp=Mon Jun 05 16:32:14 BST 2017,expiration=0, durable=false,
> address=rpc.client.user1.5976801431518807802,properties=TypedProperties[tag=0,rpc-id=8487092758120613782,_AMQ_VALIDATED_USER=user1]]@572371329
> 16:32:14 [Thread-5 (activemq-netty-threads)] impl.PostOfficeImpl.route -
> Message after
> routed=CoreMessage[messageID=26,durable=false,userID=null,priority=4,
> timestamp=Mon Jun 05 16:32:14 BST 2017,expiration=0, durable=false,
> address=rpc.client.user1.5976801431518807802,properties=TypedProperties[tag=0,rpc-id=8487092758120613782,_AMQ_VALIDATED_USER=user1]]@572371329
> 16:32:14 [Thread-5 (activemq-netty-threads)] impl.PostOfficeImpl.route -
> Message CoreMessage[messageID=26,durable=false,userID=null,priority=4,
> timestamp=Mon Jun 05 16:32:14 BST 2017,expiration=0, durable=false,
> address=rpc.client.user1.5976801431518807802,properties=TypedProperties[tag=0,rpc-id=8487092758120613782,_AMQ_VALIDATED_USER=user1]]@572371329
> is not going anywhere as it didn't have a binding on
> address:rpc.client.user1.5976801431518807802
> 16:32:14 [Thread-5 (activemq-netty-threads)]
> core.ServerSessionPacketHandler.sendResponse -
> ServerSessionPacketHandler::scheduling response::null
> 16:32:14 [Thread-5 (activemq-netty-threads)]
> core.ServerSessionPacketHandler.done - ServerSessionPacketHandler::regular
> response sent::null
> 16:32:14 [Thread-0
> (ActiveMQ-IO-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$4@2bcc0ea8)]
> impl.JournalTransaction.commit - no compact commit 22
> 16:32:14 [Thread-4 (activemq-netty-threads)]
> impl.PageCursorProviderImpl.createSubscription -
> rpc.client.user1.5976801431518807802 creating subscription 20 with filter null
> java.lang.Exception: trace
> at
> org.apache.activemq.artemis.core.paging.cursor.impl.PageCursorProviderImpl.createSubscription(PageCursorProviderImpl.java:96)
> [artemis-server-2.1.0.jar:2.1.0]
> ...
> 16:32:14 [Thread-4 (activemq-netty-threads)]
> impl.SimpleAddressManager.addBinding - Adding binding LocalQueueBinding
> [address=rpc.client.user1.5976801431518807802,
> queue=QueueImpl[name=rpc.client.user1.5976801431518807802,
> postOffice=PostOfficeImpl
> [server=ActiveMQServerImpl::serverUUID=239659ff-4a04-11e7-bb1a-2663463a67ed],
> temp=true]@1a83a5b5, filter=null, name=rpc.client.user1.5976801431518807802,
> clusterName=rpc.client.user1.5976801431518807802239659ff-4a04-11e7-bb1a-2663463a67ed]
> with address = rpc.client.user1.5976801431518807802
> java.lang.Exception: trace
> at
> org.apache.activemq.artemis.core.postoffice.impl.SimpleAddressManager.addBinding(SimpleAddressManager.java:81)
> [artemis-server-2.1.0.jar:2.1.0]
> ...
> 16:32:14 [Thread-4 (activemq-netty-threads)] impl.BindingsImpl.addBinding -
> addBinding(LocalQueueBinding [address=rpc.client.user1.5976801431518807802,
> queue=QueueImpl[name=rpc.client.user1.5976801431518807802,
> postOffice=PostOfficeImpl
> [server=ActiveMQServerImpl::serverUUID=239659ff-4a04-11e7-bb1a-2663463a67ed],
> temp=true]@1a83a5b5, filter=null, name=rpc.client.user1.5976801431518807802,
> clusterName=rpc.client.user1.5976801431518807802239659ff-4a04-11e7-bb1a-2663463a67ed])
> being called
> 16:32:14 [Thread-4 (activemq-netty-threads)] impl.BindingsImpl.addBinding -
> Adding binding LocalQueueBinding
> [address=rpc.client.user1.5976801431518807802,
> queue=QueueImpl[name=rpc.client.user1.5976801431518807802,
> postOffice=PostOfficeImpl
> [server=ActiveMQServerImpl::serverUUID=239659ff-4a04-11e7-bb1a-2663463a67ed],
> temp=true]@1a83a5b5, filter=null, name=rpc.client.user1.5976801431518807802,
> clusterName=rpc.client.user1.5976801431518807802239659ff-4a04-11e7-bb1a-2663463a67ed]
> into BindingsImpl [name=rpc.client.user1.5976801431518807802] bindingTable:
> **************************************************
> routingNameBindingMap:
> key=rpc.client.user1.5976801431518807802, value(s):
> LocalQueueBinding
> [address=rpc.client.user1.5976801431518807802,
> queue=QueueImpl[name=rpc.client.user1.5976801431518807802,
> postOffice=PostOfficeImpl
> [server=ActiveMQServerImpl::serverUUID=239659ff-4a04-11e7-bb1a-2663463a67ed],
> temp=true]@1a83a5b5, filter=null, name=rpc.client.user1.5976801431518807802,
> clusterName=rpc.client.user1.5976801431518807802239659ff-4a04-11e7-bb1a-2663463a67ed]
> routingNamePositions:
> EMPTY!
> bindingsMap:
> key=20, value=LocalQueueBinding
> [address=rpc.client.user1.5976801431518807802,
> queue=QueueImpl[name=rpc.client.user1.5976801431518807802,
> postOffice=PostOfficeImpl
> [server=ActiveMQServerImpl::serverUUID=239659ff-4a04-11e7-bb1a-2663463a67ed],
> temp=true]@1a83a5b5, filter=null, name=rpc.client.user1.5976801431518807802,
> clusterName=rpc.client.user1.5976801431518807802239659ff-4a04-11e7-bb1a-2663463a67ed]
> exclusiveBindings:
> EMPTY!
> ####################################################
> {code}
> I also created a minimal repro test:
> https://github.com/corda/activemq-artemis/blob/reconnect-bug/tests/integration-tests/src/test/java/org/apache/activemq/artemis/tests/integration/RaceConditionTest.java
> it hangs once in every 10-20 runs.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
