activemq-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Andrius Dagys (JIRA)" <j...@apache.org>
Subject [jira] [Created] (ARTEMIS-1217) Race condition during session reconnection
Date Thu, 08 Jun 2017 10:47:18 GMT
Andrius Dagys created ARTEMIS-1217:
--------------------------------------

             Summary: 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.3.15#6346)

Mime
View raw message