You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by dhonorez <dy...@gmail.com> on 2013/10/01 14:10:16 UTC

Slow acknowledgement

Hi, we're experiencing difficulties with ActiveMQ 5.8.0 where it takes the
broker 5 seconds to acknowledge a message in case a consumer is connected.
This results in a very slow producer. 

Logs:
2013-10-01 13:38:22,838  [ActiveMQ Transport:
tcp:///10.9.145.10:51104@63616] INFO  LoggingBrokerPlugin       - *Sending
message* : ActiveMQTextMessage {commandId = 771056, responseRequired = true,
messageId = ID:dev-processing01-47717-1380548500282-1:1:1:1:378787,
originalDestination = null, originalTransactionId = null, producerId =
ID:dev-processing01-47717-1380548500282-1:1:1:1, destination =
queue://response.queue, transactionId = null, expiration = 0, timestamp =
1380627502838, arrival = 0, brokerInTime = 0, brokerOutTime = 0,
correlationId = null, replyTo = null, 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 = <?xml version="1.0" encoding="UTF-8" standalo...usinessInfo>}
2013-10-01 13:38:22,839  [ActiveMQ BrokerService[amq1.dev-processing01]
Task-10748] INFO  LoggingBrokerPlugin       - *preProcessDispatch*
:MessageDispatch {commandId = 0, responseRequired = false, consumerId =
ID:dev-processing01-49925-1380555217837-0:2:4:1, destination =
queue://graydon.data.response.queue, message = ActiveMQTextMessage
{commandId = 771056, responseRequired = true, messageId =
ID:dev-processing01-47717-1380548500282-1:1:1:1:378787, originalDestination
= null, originalTransactionId = null, producerId =
ID:dev-processing01-47717-1380548500282-1:1:1:1, destination =
queue://response.queue, transactionId = null, expiration = 0, timestamp =
1380627502838, arrival = 0, brokerInTime = 1380627502838, brokerOutTime = 0,
correlationId = null, replyTo = null, 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 = 1737, properties =
{BrokerPath=amq1.dev-processing01.*}, readOnlyProperties = false,
readOnlyBody = false, droppable = false, text = <?xml version="1.0"
encoding="UTF-8" standalo...usinessInfo>}, redeliveryCounter = 0}
2013-10-01 13:38:22,839  [ActiveMQ BrokerService[amq1.dev-processing01]
Task-10748] INFO  LoggingBrokerPlugin       - *postProcessDispatch*
:MessageDispatch {commandId = 0, responseRequired = false, consumerId =
ID:dev-processing01-49925-1380555217837-0:2:4:1, destination =
queue://graydon.data.response.queue, message = ActiveMQTextMessage
{commandId = 771056, responseRequired = true, messageId =
ID:dev-processing01-47717-1380548500282-1:1:1:1:378787, originalDestination
= null, originalTransactionId = null, producerId =
ID:dev-processing01-47717-1380548500282-1:1:1:1, destination =
queue://response.queue, transactionId = null, expiration = 0, timestamp =
1380627502838, arrival = 0, brokerInTime = 1380627502838, brokerOutTime =
1380627502839, correlationId = null, replyTo = null, persistent = true, type
= null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId =
null, compressed = false, userID = null, content =
org.apache.activemq.util.ByteSequence@3871e6ee, marshalledProperties =
org.apache.activemq.util.ByteSequence@3df03035, dataStructure = null,
redeliveryCounter = 0, size = 1737, properties =
{BrokerPath=amq1.dev-processing01}, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = <?xml version="1.0" encoding="UTF-8"
standalo...usinessInfo>}, redeliveryCounter = 0}
2013-10-01 13:38:27,839  [ActiveMQ Transport:
tcp:///10.9.145.10:54886@63616] INFO  LoggingBrokerPlugin       -
*Acknowledging message* for client ID : client,
ID:dev-processing01-47717-1380548500282-1:1:1:1:378787

We are clueless why this is going so slow. Any help would be greatly
appreciated.



--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Slow acknowledgement

Posted by kal123 <kp...@gmail.com>.
was this resolved? can you let us know how, i think we might be hitting
similar issue



--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4673266.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Slow acknowledgement

Posted by dhonorez <dy...@gmail.com>.
Ok, thanks for the suggestions.

My todo-list for now consists of:
- dropping leveldb storage, and re-run batch to see if corruption has
anything to do with it
- replace leveldb with kahadb
- get a few thread dumps while producing messages



--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4672153.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Slow acknowledgement

Posted by Gary Tully <ga...@gmail.com>.
not really. with jdbc the number of connections can be a limitation.
maybe try verify with kahadb to contrast.

getting a few broker thread dumps in quick succession would help
identify where the broker is spending its time.

On 2 October 2013 14:27, dhonorez <dy...@gmail.com> wrote:
> We're using LevelDB. I'll post the config as soon as I get the chance.
>
> Are you, by any chance, thinking of this issue with LevelDB:
>
>> We've been using the levelDB store a month of two now in production on NFS
>> (with standard file lock failover configured). We've had a corrupt store
>> several times now in the last few weeks, with no errors in the logs...
>> just queues piling up, and very low throughput. The only thing we could do
>> to resolve this, is throw away the store, and start over.
>
>
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4672143.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



-- 
http://redhat.com
http://blog.garytully.com

Re: Slow acknowledgement

Posted by dhonorez <dy...@gmail.com>.
<levelDB directory="${activemq.base}/data-shared/activemq-nm/store/leveldb" >
  <locker>
    <shared-file-locker lockAcquireSleepInterval="10000"/>
  </locker>
</levelDB>




--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4672147.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Slow acknowledgement

Posted by dhonorez <dy...@gmail.com>.
We're using LevelDB. I'll post the config as soon as I get the chance. 

Are you, by any chance, thinking of this issue with LevelDB:

> We've been using the levelDB store a month of two now in production on NFS
> (with standard file lock failover configured). We've had a corrupt store
> several times now in the last few weeks, with no errors in the logs...
> just queues piling up, and very low throughput. The only thing we could do
> to resolve this, is throw away the store, and start over.





--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4672143.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Slow acknowledgement

Posted by Gary Tully <ga...@gmail.com>.
what store? Maybe post your xml config

On 2 October 2013 07:51, dhonorez <dy...@gmail.com> wrote:
> More info:
>
> This works fine when no consumers are connected to the queue. As soon as a
> client connects, we're experiencing the slowdown.
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4672085.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



-- 
http://redhat.com
http://blog.garytully.com

Re: Slow acknowledgement

Posted by dhonorez <dy...@gmail.com>.
More info:

This works fine when no consumers are connected to the queue. As soon as a
client connects, we're experiencing the slowdown.



--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-acknowledgement-tp4672049p4672085.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.