[jira] [Commented] (AMQ-6415) LevelDB IOException

2016-09-19 Thread John Leach (JIRA)

[ 
https://issues.apache.org/jira/browse/AMQ-6415?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15503697#comment-15503697
 ] 

John Leach commented on AMQ-6415:
-

My problem now is that I'm finding old messages in queues that have been 
expired and deleted on the other side of my bridge. They are automatically 
expired when I try to inspect the queue in the web admin, but once in a while 
activemq crashes when I'm inspecting them. I'm presuming it's related to the 
same problem.

{code}
Sep 19 14:39:48 srv-2uv19 activemq:  WARN | Found a negative log reference for 
log: 536872052
Sep 19 14:39:52 srv-2uv19 activemq:  INFO | Stopping 
BrokerService[a.staging_queue.example.com] due to exception, java.io.IOException
Sep 19 14:39:52 srv-2uv19 activemq: java.io.IOException
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.LevelDBClient.might_fail(LevelDBClient.scala:552)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.LevelDBClient.might_fail_using_index(LevelDBClient.scala:1044)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.LevelDBClient.store(LevelDBClient.scala:1390)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.DBManager$$anonfun$drainFlushes$1.apply$mcV$sp(DBManager.scala:627)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.fusesource.hawtdispatch.package$$anon$4.run(hawtdispatch.scala:330)[hawtdispatch-scala-2.11-1.22.jar:1.22]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_111]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_111]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
java.lang.Thread.run(Thread.java:745)[:1.7.0_111]
Sep 19 14:39:52 srv-2uv19 activemq:  INFO | Apache ActiveMQ 5.14.0 
(a.staging_queue.example.com, ID:srv-2uv19-56209-1473679866792-1:1) is shutting 
down
Sep 19 14:39:52 srv-2uv19 activemq:  WARN | Transport Connection to: 
tcp://x:58657 failed: java.io.IOException: Broker 
BrokerService[a.staging_queue.gb1.brightbox.com] is being stopped
Sep 19 14:39:52 srv-2uv19 activemq: ERROR | Failed to remove expired Message 
from the store 
Sep 19 14:39:52 srv-2uv19 activemq: java.io.IOException: 
org.apache.activemq.broker.SuppressReplyException: ShutdownBrokerInitiated
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.LevelDBStore$.toIOException(LevelDBStore.scala:65)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.LevelDBStore$.waitOn(LevelDBStore.scala:74)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.leveldb.LevelDBStore$LevelDBMessageStore.removeAsyncMessage(LevelDBStore.scala:811)[activemq-leveldb-store-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:922)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1737)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1729)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1799)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1790)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1943)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:2160)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.broker.region.Queue.iterate(Queue.java:1601)[activemq-broker-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)[activemq-client-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 activemq: #011at 
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)[activemq-client-5.14.0.jar:5.14.0]
Sep 19 14:39:52 srv-2uv19 ac

[jira] [Commented] (AMQ-6415) LevelDB IOException

2016-09-08 Thread John Leach (JIRA)

[ 
https://issues.apache.org/jira/browse/AMQ-6415?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15474305#comment-15474305
 ] 

John Leach commented on AMQ-6415:
-

Looks like adding expireMessagesPeriod="0" as suggested has worked - no crashes 
since.

> LevelDB IOException
> ---
>
> Key: AMQ-6415
> URL: https://issues.apache.org/jira/browse/AMQ-6415
> Project: ActiveMQ
>  Issue Type: Bug
>  Components: Message Store
>Affects Versions: 5.14.0
> Environment: Ubuntu 14.04, 32bit, OpenJDK 7u111
>Reporter: John Leach
>  Labels: leveldb
>
> two brokers bridged together, producers and consumers spread across the two.
> After about 8 hours or so processing ~30 messages/second, amq logs a 
> java.io.IOException, shuts down, and is restarted where it seems to continue 
> on its way:
> {quote}
> 2016-09-04 19:19:01,315 | INFO  | Stopping 
> BrokerService[a.staging_queue.example.com] due to exception, 
> java.io.IOException | org.apache.activemq.util.DefaultIOExceptionHandler | 
> LevelDB IOException handler.
> java.io.IOException
> at 
> org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.might_fail(LevelDBClient.scala:552)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.might_fail_using_index(LevelDBClient.scala:1044)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.store(LevelDBClient.scala:1390)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.DBManager$$anonfun$drainFlushes$1.apply$mcV$sp(DBManager.scala:627)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.fusesource.hawtdispatch.package$$anon$4.run(hawtdispatch.scala:330)[hawtdispatch-scala-2.11-1.22.jar:1.22]
> at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_111]
> at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_111]
> at java.lang.Thread.run(Thread.java:745)[:1.7.0_111]
> 2016-09-04 19:19:01,321 | INFO  | Apache ActiveMQ 5.14.0 
> (a.staging_queue.example.com,, ID:srv-2uv19-35903-1472985997586-1:1) is 
> shutting down | org.apache.activemq.broker.BrokerService | 
> IOExceptionHandler: stopping BrokerService[a.staging_queue.example.com]
> ...
> 2016-09-04 19:19:01,414 | ERROR | Failed to remove expired Message from the 
> store  | org.apache.activemq.broker.region.Queue | ActiveMQ 
> Broker[a.staging_queue.example.com] Scheduler
> java.io.IOException: org.apache.activemq.broker.SuppressReplyException: 
> ShutdownBrokerInitiated
> at 
> org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$.toIOException(LevelDBStore.scala:65)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$.waitOn(LevelDBStore.scala:74)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$LevelDBMessageStore.removeAsyncMessage(LevelDBStore.scala:811)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:922)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1737)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1729)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1799)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1790)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.doBrowseList(Queue.java:1153)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.doBrowse(Queue.java:1131)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.expireMessages(Queue.java:908)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.access$100(Queue.java:103)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue$2.run(Queue.java:146)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)[activemq-client-5.14.0.jar:5.14.0]
> at java.util.TimerThread.mainLoop(Timer.java:555)[:1.7.0_111]
> at java.util.TimerThread.run(Timer.java:505)[:1.7.0_111]
> 2016-09-04 19:19:01,465 | INFO  | Stopped LevelDB[/path/to/data/level

[jira] [Commented] (AMQ-6415) LevelDB IOException

2016-09-06 Thread John Leach (JIRA)

[ 
https://issues.apache.org/jira/browse/AMQ-6415?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15467053#comment-15467053
 ] 

John Leach commented on AMQ-6415:
-

Thanks Gary. I've tested it with the native leveldb library but have the same 
problem. I'm now running a test with maxExpireMesssagePeriod=0. I already had 
gcInactiveDestinations enabled, if it matters. Here's my destinationPolicy 
section now:

{code:xml}
  

  




  


{code}

We switched to leveldb a couple of years ago after having some pretty bad 
performance problems with kahadb, but I see there has been some work on kahadb 
in the mean time which might help so I'll give that a go later (though I'm 
happy to continue debugging this leveldb problem)


> LevelDB IOException
> ---
>
> Key: AMQ-6415
> URL: https://issues.apache.org/jira/browse/AMQ-6415
> Project: ActiveMQ
>  Issue Type: Bug
>  Components: Message Store
>Affects Versions: 5.14.0
> Environment: Ubuntu 14.04, 32bit, OpenJDK 7u111
>Reporter: John Leach
>  Labels: leveldb
>
> two brokers bridged together, producers and consumers spread across the two.
> After about 8 hours or so processing ~30 messages/second, amq logs a 
> java.io.IOException, shuts down, and is restarted where it seems to continue 
> on its way:
> {quote}
> 2016-09-04 19:19:01,315 | INFO  | Stopping 
> BrokerService[a.staging_queue.example.com] due to exception, 
> java.io.IOException | org.apache.activemq.util.DefaultIOExceptionHandler | 
> LevelDB IOException handler.
> java.io.IOException
> at 
> org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.might_fail(LevelDBClient.scala:552)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.might_fail_using_index(LevelDBClient.scala:1044)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.store(LevelDBClient.scala:1390)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.DBManager$$anonfun$drainFlushes$1.apply$mcV$sp(DBManager.scala:627)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.fusesource.hawtdispatch.package$$anon$4.run(hawtdispatch.scala:330)[hawtdispatch-scala-2.11-1.22.jar:1.22]
> at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_111]
> at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_111]
> at java.lang.Thread.run(Thread.java:745)[:1.7.0_111]
> 2016-09-04 19:19:01,321 | INFO  | Apache ActiveMQ 5.14.0 
> (a.staging_queue.example.com,, ID:srv-2uv19-35903-1472985997586-1:1) is 
> shutting down | org.apache.activemq.broker.BrokerService | 
> IOExceptionHandler: stopping BrokerService[a.staging_queue.example.com]
> ...
> 2016-09-04 19:19:01,414 | ERROR | Failed to remove expired Message from the 
> store  | org.apache.activemq.broker.region.Queue | ActiveMQ 
> Broker[a.staging_queue.example.com] Scheduler
> java.io.IOException: org.apache.activemq.broker.SuppressReplyException: 
> ShutdownBrokerInitiated
> at 
> org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$.toIOException(LevelDBStore.scala:65)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$.waitOn(LevelDBStore.scala:74)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$LevelDBMessageStore.removeAsyncMessage(LevelDBStore.scala:811)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:922)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1737)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1729)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1799)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1790)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.doBrowseList(Queue.java:1153)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.doBrowse(Queue.java:1131)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.expireMessages(Queue.java:908)[acti

[jira] [Commented] (AMQ-6415) LevelDB IOException

2016-09-05 Thread Gary Tully (JIRA)

[ 
https://issues.apache.org/jira/browse/AMQ-6415?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15464624#comment-15464624
 ] 

Gary Tully commented on AMQ-6415:
-

maybe the trigger is some concurrent access via message expiry. try disabling 
periodic message expiry via a policy entry. maxExpireMessagePeriod=0.

it may also be worth reverting to kahadb. Is there some leveldb store attribute 
that you depend on?

> LevelDB IOException
> ---
>
> Key: AMQ-6415
> URL: https://issues.apache.org/jira/browse/AMQ-6415
> Project: ActiveMQ
>  Issue Type: Bug
>  Components: Message Store
>Affects Versions: 5.14.0
> Environment: Ubuntu 14.04, 32bit, OpenJDK 7u111
>Reporter: John Leach
>  Labels: leveldb
>
> two brokers bridged together, producers and consumers spread across the two.
> After about 8 hours or so processing ~30 messages/second, amq logs a 
> java.io.IOException, shuts down, and is restarted where it seems to continue 
> on its way:
> {quote}
> 2016-09-04 19:19:01,315 | INFO  | Stopping 
> BrokerService[a.staging_queue.example.com] due to exception, 
> java.io.IOException | org.apache.activemq.util.DefaultIOExceptionHandler | 
> LevelDB IOException handler.
> java.io.IOException
> at 
> org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.might_fail(LevelDBClient.scala:552)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.might_fail_using_index(LevelDBClient.scala:1044)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBClient.store(LevelDBClient.scala:1390)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.DBManager$$anonfun$drainFlushes$1.apply$mcV$sp(DBManager.scala:627)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.fusesource.hawtdispatch.package$$anon$4.run(hawtdispatch.scala:330)[hawtdispatch-scala-2.11-1.22.jar:1.22]
> at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_111]
> at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_111]
> at java.lang.Thread.run(Thread.java:745)[:1.7.0_111]
> 2016-09-04 19:19:01,321 | INFO  | Apache ActiveMQ 5.14.0 
> (a.staging_queue.example.com,, ID:srv-2uv19-35903-1472985997586-1:1) is 
> shutting down | org.apache.activemq.broker.BrokerService | 
> IOExceptionHandler: stopping BrokerService[a.staging_queue.example.com]
> ...
> 2016-09-04 19:19:01,414 | ERROR | Failed to remove expired Message from the 
> store  | org.apache.activemq.broker.region.Queue | ActiveMQ 
> Broker[a.staging_queue.example.com] Scheduler
> java.io.IOException: org.apache.activemq.broker.SuppressReplyException: 
> ShutdownBrokerInitiated
> at 
> org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:40)[activemq-client-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$.toIOException(LevelDBStore.scala:65)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$.waitOn(LevelDBStore.scala:74)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.leveldb.LevelDBStore$LevelDBMessageStore.removeAsyncMessage(LevelDBStore.scala:811)[activemq-leveldb-store-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:922)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1737)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1729)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1799)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1790)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.doBrowseList(Queue.java:1153)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.doBrowse(Queue.java:1131)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.expireMessages(Queue.java:908)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue.access$100(Queue.java:103)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.broker.region.Queue$2.run(Queue.java:146)[activemq-broker-5.14.0.jar:5.14.0]
> at 
> org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)[activemq-client-5.14.0.jar:5.14.0]
> at java.util.TimerThread.mainLoop(Tim