You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "clebert suconic (JIRA)" <ji...@apache.org> on 2017/08/31 19:12:26 UTC
[jira] [Closed] (ARTEMIS-1217) Race condition during session
reconnection
[ 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)