[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15854424#comment-15854424
]
Christopher L. Shannon commented on AMQ-5618:
-
The thread is here
http://activemq.2283324.n4.nabble.com/DISCUSS-LevelDB-deprecation-tp4719227.html
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876 | INFO | Promoted to master |
> org.apache.activemq.leveldb.replicated.MasterElector | main-EventThread
> 2015-02-25 21:38:43,894 | INFO | Using the pure java LevelDB implementation.
> | org.apache.activemq.leveldb.LevelDBClient | ActiveMQ
> BrokerService[localhost] Task-5
> 2015-02-25 21:38:45,954 | WARN | Invalid log position: 44 |
> org.apache.
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15854412#comment-15854412
]
Pablo Lozano commented on AMQ-5618:
---
Hey [~cshannon] could you do me a favor and point me to a place where I can
find the discussion in which LevelDB was decided to be deprecated? Mailing List
archive or something similar would be great.
Thanks
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876 | INFO | Promoted to master |
> org.apache.activemq.leveldb.replicated.MasterElector | main-EventThread
> 2015-02-25 21:38:43,894 | INFO | Using the pure java LevelDB implementation.
> | org.apache.activemq.leveldb.LevelDBClient | ActiveMQ
> BrokerService[localh
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15663702#comment-15663702
]
Xiang Zhao commented on AMQ-5618:
-
We're using version 5.13.4, and have the same issues. We have a three node
cluster using replicatedLevelDB persistence, and sometimes we shutdown one of
the nodes to do failover testing, and from time to time, we got the error "
WARN | No reader available for position: 0" on the master, and then we had to
delete all the LevelDB folders on the three nodes to make it work again.
I think it's a critical bug, hopefully someone can look further into it.
Thanks in advance.
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15514423#comment-15514423
]
Pablo Lozano commented on AMQ-5618:
---
I have done some digging around.. and it seems that it will sooner or later
will stop the loop.. eventually at least.
I dont have the setup of Replicated LevelDB at hand right now but from I can
see is that is basically lost track about the last position on the records of
LevelDB.
>From the logs in my case it would try to iterate from 0 to the last position
>it knows exists. So in my case it would iterate until 32610993430.
The fix from AMQ-5300 seems not to be executed as this replay of the logs of
LevelDB is being triggered by a call which bypasses its fix. The fix basically
is not to start replaying from 0 but from the last record registered.
{noformat}
2015-01-29 19:42:55,740 -0600 WARN 56426 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] LevelDBClient - Could not load message
seq: 162542 from DataLocator(11e952fc, 1754)
2015-01-29 19:42:55,740 -0600 WARN 56426 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] RecordLog - No reader available for
position: 11e999ce, log_infos:
{32610993430=LogInfo(/m2/tomcat7.0/work/navigator-mail-mq/6009/work/repDB/000797c44516.log,32610993430,0)}
2015-01-29 19:42:55,740 -0600 WARN 56426 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] LevelDBClient - Could not load message
seq: 162552 from DataLocator(11e999ce, 1754)
2015-01-29 19:42:55,740 -0600 WARN 56426 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] RecordLog - No reader available for
position: 11e9a7f8, log_infos:
{32610993430=LogInfo(/m2/tomcat7.0/work/navigator-mail-mq/6009/work/repDB/000797c44516.log,32610993430,0)}
2015-01-29 19:42:55,740 -0600 WARN 56426 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] LevelDBClient - Could not load message
seq: 162554 from DataLocator(11e9a7f8, 1754)
2015-01-29 19:42:55,740 -0600 WARN 56426 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] RecordLog - No reader available for
position: 11e9b622, log_infos:
{32610993430=LogInfo(/m2/tomcat7.0/work/navigator-mail-mq/6009/work/repDB/000797c44516.log,32610993430,0)}
2015-01-29 19:42:55,741 -0600 WARN 56427 [ActiveMQ
BrokerService[mailsystemBroker] Task-2] LevelDBClient - Could not load message
seq: 162556 from DataLocator(11e9b622, 1754)
{noformat}
I lost most of my log files from this issue but if someone can attach then if
possible at Trace level and if possible with a LevelDB included I may be able
to take a look deeper. My Scala is not the best but I think I can help track
the root of the issue
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15513740#comment-15513740
]
William Brendel commented on AMQ-5618:
--
Another data point: My team also encountered this issue recently, in June 2016,
while evaluating replicated LevelDB storage for our application. We were using
AMQ 5.13.3 and ZK 3.4.8 with 3 instances. Like Jonathan G, our database seemed
to be corrupted beyond repair, causing us to eliminate replicated LevelDB as an
option.
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876 | INFO | Promoted to master |
> org.apache.activemq.leveldb.replicated.MasterElector | main-EventThread
> 2015-02-25 21:38:43,894 | INFO |
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15513715#comment-15513715
]
Jonathan G commented on AMQ-5618:
-
Hello Pablo,
Yes, we have amq 5.14 and zook 3.4.8. 3 - 3 instances of each with master/slave.
We found the very same repl. leveldb corruption that the ticket reporter had.
Our db was corrupted beyond repair.
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876 | INFO | Promoted to master |
> org.apache.activemq.leveldb.replicated.MasterElector | main-EventThread
> 2015-02-25 21:38:43,894 | INFO | Using the pure java LevelDB implementation.
> | org.apache.activemq.leveldb.LevelDBClient | ActiveMQ
> BrokerService[localhost]
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15508175#comment-15508175
]
Pablo Lozano commented on AMQ-5618:
---
Actually no, and my team discarded the usage of Replicated Level DB
But on a certain hope, another team from my company started using Replicated
Level DB and until now they haven't seen this issue occur.
They are running 5.13.3 and Java version of LevelDB. I think they have
stumbled with other issues related to Zookeeper but not this one.
Important question, is this issue still occurring to you?
Thanks,
Pablo
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876 | INFO | Promoted to master |
> org.apache.activemq.level
[jira] [Commented] (AMQ-5618) Infinite loop in log replay with Replicated LevelDB
[
https://issues.apache.org/jira/browse/AMQ-5618?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15490395#comment-15490395
]
Jonathan G commented on AMQ-5618:
-
Hello Pablo,
Have you had to chance to come up with a work around?
Thx!
> Infinite loop in log replay with Replicated LevelDB
> ---
>
> Key: AMQ-5618
> URL: https://issues.apache.org/jira/browse/AMQ-5618
> Project: ActiveMQ
> Issue Type: Bug
>Affects Versions: 5.11.0, 5.11.1
> Environment: Linux, Google Compute Engine
>Reporter: Artem Karpenko
>Priority: Critical
>
> This is very similar to AMQ-5300 except that I use replicatedLevelDB
> persistence adapter and in order to reproduce I don't have to delete any
> index files.
> Setup: 1 ZK instance, 3 AMQ nodes.
> One of the AMQ configs:
> {code}
> replicas="3"
> bind="tcp://0.0.0.0:61619"
> zkAddress="instance-6:2181"
> zkPath="/activemq/leveldb-stores"
> hostname="instance-7" />
> {code}
> Difference between nodes is only in hostname attribute.
> The way to reproduce is almost the same as in AMQ-5300:
> # Produce lots of messages to generate several log files in leveldb data
> directory.
> # Consume _some_ messages until you see "Deleting log" in activemq.log.
> # Restart master. Wait for system to rebalance itself. Everything's fine at
> this point.
> # Restart the second master.
> # Observe the massive (infinite?) logging on slave and relatively calm but
> still possibly infinite logging on master.
> This is what the first master logs after it's restarted:
> {code}
> 2015-02-25 21:37:08,338 | DEBUG | Download session connected... |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:08,582 | INFO | Slave skipping download of:
> log/190be289.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,099 | INFO | Slave skipping download of:
> log/0642f848.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,411 | INFO | Slave skipping download of:
> log/0c85f06d.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,838 | INFO | Slave skipping download of:
> log/12c8e921.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,842 | INFO | Slave requested:
> 1c9373b4.index/CURRENT |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,846 | INFO | Slave requested:
> 1c9373b4.index/MANIFEST-02 |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,850 | INFO | Slave requested:
> 1c9373b4.index/03.log |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,857 | INFO | Attaching... Downloaded 0.02/95.65 kb and
> 1/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,859 | INFO | Attaching... Downloaded 0.06/95.65 kb and
> 2/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,861 | INFO | Attaching... Downloaded 95.65/95.65 kb and
> 3/3 files | org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,862 | INFO | Attached |
> org.apache.activemq.leveldb.replicated.SlaveLevelDBStore |
> hawtdispatch-DEFAULT-1
> 2015-02-25 21:37:09,878 | DEBUG | Taking a snapshot of the current index:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/1c9373b4.index
> | org.apache.activemq.leveldb.LevelDBClient | Thread-2
> 2015-02-25 21:37:10,352 | DEBUG | Recovering from last index snapshot at:
> /usr/local/apache-activemq-5.11.1/data/replicatedLevelDB/dirty.index |
> org.apache.activemq.leveldb.LevelDBClient | Thread-2
> {code}
> Right after that everything seems fine. But as soon as I stop the new master,
> the another new master (that would be the third one) logs
> {code}
> 2015-02-25 21:38:43,876 | INFO | Promoted to master |
> org.apache.activemq.leveldb.replicated.MasterElector | main-EventThread
> 2015-02-25 21:38:43,894 | INFO | Using the pure java LevelDB implementation.
> | org.apache.activemq.leveldb.LevelDBClient | ActiveMQ
> BrokerService[localhost] Task-5
> 2015-02-25 21:38:45,954 | WARN | Invalid log position: 44 |
> org.apache.activemq.leveldb.LevelDBClient | ActiveMQ BrokerSer
