[
https://issues.apache.org/jira/browse/AMQ-5259?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ding Jinqiang updated AMQ-5259:
-------------------------------
Description:
When use the leveldb persistenceAdapter, I found that the producer will stall
for about 10-20s, which I think is quite strange...
And then I open the debug log and see something below:
2014-07-03 10:54:40,961 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:696 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:41,452 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:697 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:41,944 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:698 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:42,433 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:699 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:42,914 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:700 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:43,314 | DEBUG | Taking a snapshot of the current index:
/home/work/local/activemq/apache-activemq-5.10.0/data/leveldb/0000001391db4436.index
| org.apache.activemq.leveldb.LevelDBClient | Thread-2
2014-07-03 10:55:12,253 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:701 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:55:12,742 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:702 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:55:13,235 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:703 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:55:13,724 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:704 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
Another piece:
2014-07-03 10:53:42,605 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:637 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:53:43,116 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:638 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:53:43,133 | DEBUG | Taking a snapshot of the current index:
/home/work/local/activemq/apache-activemq-5.10.0/data/leveldb/000000138b966b69.index
| org.apache.activemq.leveldb.LevelDBClient | Thread-2
2014-07-03 10:53:43,649 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:639 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:11,969 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:640 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
It happened all the time during my performance test stage, which certainly
reduce the throughput greatly...
I think the problem lays on the snapshot thread, but in your description about
leveldb is "Fast index snapshots using hard links", so is that normal?
was:
When use the leveldb persistenceAdapter, I found that the producer will stall
for about 10-20s, which I think is quite strange...
And then I open the debug log and see something below:
{{
2014-07-03 10:54:40,961 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:696 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:41,452 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:697 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:41,944 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:698 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:42,433 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:699 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:42,914 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:700 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:43,314 | DEBUG | Taking a snapshot of the current index:
/home/work/local/activemq/apache-activemq-5.10.0/data/leveldb/0000001391db4436.index
| org.apache.activemq.leveldb.LevelDBClient | Thread-2
2014-07-03 10:55:12,253 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:701 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:55:12,742 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:702 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:55:13,235 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:703 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:55:13,724 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:704 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
}}
Another piece:
{{
2014-07-03 10:53:42,605 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:637 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:53:43,116 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:638 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:53:43,133 | DEBUG | Taking a snapshot of the current index:
/home/work/local/activemq/apache-activemq-5.10.0/data/leveldb/000000138b966b69.index
| org.apache.activemq.leveldb.LevelDBClient | Thread-2
2014-07-03 10:53:43,649 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:639 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
2014-07-03 10:54:11,969 | DEBUG | commit:
TX:ID:10.81.200.187-44084-1404353539471-1:1:640 syncCount: 1000 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
}}
I think the problem lays on the snapshot thread, but in your description about
leveldb is "Fast index snapshots using hard links", so is that normal?
> LevelDB spent much time on "Taking a snapshot of the current index" and stall
> producers
> ---------------------------------------------------------------------------------------
>
> Key: AMQ-5259
> URL: https://issues.apache.org/jira/browse/AMQ-5259
> Project: ActiveMQ
> Issue Type: Bug
> Components: activemq-leveldb-store
> Affects Versions: 5.10.0
> Environment: CentOS 6.3
> Reporter: Ding Jinqiang
>
> When use the leveldb persistenceAdapter, I found that the producer will stall
> for about 10-20s, which I think is quite strange...
> And then I open the debug log and see something below:
> 2014-07-03 10:54:40,961 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:696 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:54:41,452 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:697 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:54:41,944 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:698 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:54:42,433 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:699 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:54:42,914 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:700 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:54:43,314 | DEBUG | Taking a snapshot of the current index:
> /home/work/local/activemq/apache-activemq-5.10.0/data/leveldb/0000001391db4436.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2014-07-03 10:55:12,253 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:701 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:55:12,742 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:702 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:55:13,235 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:703 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:55:13,724 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:704 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> Another piece:
> 2014-07-03 10:53:42,605 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:637 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:53:43,116 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:638 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:53:43,133 | DEBUG | Taking a snapshot of the current index:
> /home/work/local/activemq/apache-activemq-5.10.0/data/leveldb/000000138b966b69.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2014-07-03 10:53:43,649 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:639 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> 2014-07-03 10:54:11,969 | DEBUG | commit:
> TX:ID:10.81.200.187-44084-1404353539471-1:1:640 syncCount: 1000 |
> org.apache.activemq.transaction.LocalTransaction | ActiveMQ NIO Worker 453
> It happened all the time during my performance test stage, which certainly
> reduce the throughput greatly...
> I think the problem lays on the snapshot thread, but in your description
> about leveldb is "Fast index snapshots using hard links", so is that normal?
--
This message was sent by Atlassian JIRA
(v6.2#6252)
