Created attachment 28882 [details]
Test Plan

I configured a very simple Test plan with a JMS Point-to-Point where Request queue and Receive Queue are the same.
If I run 3 samples, randomly I can get one response time equal to Timeout while receive was in fact immediate.

I added logs around wait in FixedQueueExecutor and notify in MessageAdmin.


Here is the result:
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: wait for reply Milamber-1338839705293 started on 1338839705298 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: GU Point-à-Point 1-1 will wait on : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705287} 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: RPL_ID [Milamber-1338839705293] for holder request=ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705287}, reply=null 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GU Point-à-Point 1-1-JMS-Receiver notifying : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705287} 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GU Point-à-Point 1-1-JMS-Receiver notified : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705287} 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: done waiting for Milamber-1338839705293 on ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705287} ended on 1338839705320 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GET_ID [Milamber-1338839705293] for request=ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705287}, reply=ActiveMQTextMessage {commandId = 5, responseRequired = true, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705294, arrival = 0, brokerInTime = 1338839705294, brokerOutTime = 1338839705295, correlationId = Milamber-1338839705293, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = Message de test
ID TEMPS = 1338839705287} 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: REQ_ID [Milamber-1338839705328] 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: RPL_ID [Milamber-1338839705328] for holder request=ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705328}, reply=null 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GU Point-à-Point 1-1-JMS-Receiver notifying : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705328} 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GU Point-à-Point 1-1-JMS-Receiver notified : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705328} 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: wait for reply Milamber-1338839705328 started on 1338839705353 
2012/06/04 21:55:05 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: GU Point-à-Point 1-1 will wait on : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705328} 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: done waiting for Milamber-1338839705328 on ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705328} ended on 1338839725353 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GET_ID [Milamber-1338839705328] for request=ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839705328}, reply=ActiveMQTextMessage {commandId = 6, responseRequired = true, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:2, originalDestination = null, originalTransactionId = null, producerId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839705328, arrival = 0, brokerInTime = 1338839705329, brokerOutTime = 1338839705329, correlationId = Milamber-1338839705328, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = Message de test
ID TEMPS = 1338839705328} 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.Utils: Adding property [JMSCorrelationId=Milamber-1338839725355] 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: REQ_ID [Milamber-1338839725355] 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: RPL_ID [Milamber-1338839725355] for holder request=ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839725355}, reply=null 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GU Point-à-Point 1-1-JMS-Receiver notifying : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839725355} 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: wait for reply Milamber-1338839725355 started on 1338839725358 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GU Point-à-Point 1-1-JMS-Receiver notified : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839725355} 
2012/06/04 21:55:25 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: GU Point-à-Point 1-1 will wait on : ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839725355} 
2012/06/04 21:55:45 DEBUG - jmeter.protocol.jms.sampler.FixedQueueExecutor: done waiting for Milamber-1338839725355 on ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839725355} ended on 1338839745358 
2012/06/04 21:55:45 DEBUG - jmeter.protocol.jms.sampler.MessageAdmin: GET_ID [Milamber-1338839725355] for request=ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = null, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false, text = Message de test
ID TEMPS = 1338839725355}, reply=ActiveMQTextMessage {commandId = 7, responseRequired = true, messageId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1:3, originalDestination = null, originalTransactionId = null, producerId = ID:macbook-pro-de-philippe-mouawad.local-64635-1338839705124-0:2:1:1, destination = queue://example.A, transactionId = null, expiration = 0, timestamp = 1338839725356, arrival = 0, brokerInTime = 1338839725356, brokerOutTime = 1338839725357, correlationId = Milamber-1338839725355, replyTo = queue://example.A, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = Message de test
ID TEMPS = 1338839725355} 
2012/06/04 21:55:45 INFO  - jmeter.threads.JMeterThread: Thread finished: GU Point-à-Point 1-1