kahadb recovery

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

kahadb recovery

Steve Hill
Hi!

Can anyone provide guidance on why restarting ActiveMQ can take hours?  
We were seeing lots of message not found in sequence and it is currently
at 5.9M entries recovered.  Is there a way to know how many entries
there are so we have an idea when it might finish?

There are currently about 1600 files in the kahadb data directory and
the total size is 30GB of what about 700mb is the db.data file.


2017-04-22 16:28:21,079 | DEBUG | message not found in sequence id
index: ID:atas01p.x.com-57366-1491745186855-3:1:20207097:1:1 |
org.apache.activemq.store.kahadb.MessageDatabase | main
2017-04-22 16:28:21,082 | DEBUG | message not found in sequence id
index: ID:atas01p.x.com-57366-1491745186855-3:1:20207096:1:1 |
org.apache.activemq.store.kahadb.MessageDatabase | main
2017-04-22 16:28:21,187 | DEBUG | message not found in sequence id
index: ID:atas01p.x.com-57366-1491745186855-3:1:20462448:1:1 |
org.apache.activemq.store.kahadb.MessageDatabase | main
2017-04-22 16:30:56,681 | INFO  | @97201:5488429, 5600000 entries
recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
2017-04-22 16:36:17,337 | INFO  | @97210:5155402, 5700000 entries
recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
2017-04-22 16:41:45,794 | INFO  | @97217:11700458, 5800000 entries
recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
2017-04-22 16:47:19,324 | INFO  | @97226:18610005, 5900000 entries
recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main

Any guidance would be much appreciated.

Thanks!

Steve.

Reply | Threaded
Open this post in threaded view
|

Re: kahadb recovery

Steve Hill
We now realize that the number after the @ is the file number being
processed and after the colon is the offset in the file.  Eg,
97226:18610005 means db-97226.log is being processed.  Based on this at
least we now know how far we are through the startup.  It looks like it
will take a further 2 hours to start, with a total startup time of 8
hours - this feels somewhat excessive!

On 4/22/17 4:53 PM, Steve Hill wrote:

> Hi!
>
> Can anyone provide guidance on why restarting ActiveMQ can take
> hours?  We were seeing lots of message not found in sequence and it is
> currently at 5.9M entries recovered.  Is there a way to know how many
> entries there are so we have an idea when it might finish?
>
> There are currently about 1600 files in the kahadb data directory and
> the total size is 30GB of what about 700mb is the db.data file.
>
>
> 2017-04-22 16:28:21,079 | DEBUG | message not found in sequence id
> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207097:1:1 |
> org.apache.activemq.store.kahadb.MessageDatabase | main
> 2017-04-22 16:28:21,082 | DEBUG | message not found in sequence id
> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207096:1:1 |
> org.apache.activemq.store.kahadb.MessageDatabase | main
> 2017-04-22 16:28:21,187 | DEBUG | message not found in sequence id
> index: ID:atas01p.x.com-57366-1491745186855-3:1:20462448:1:1 |
> org.apache.activemq.store.kahadb.MessageDatabase | main
> 2017-04-22 16:30:56,681 | INFO  | @97201:5488429, 5600000 entries
> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
> 2017-04-22 16:36:17,337 | INFO  | @97210:5155402, 5700000 entries
> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
> 2017-04-22 16:41:45,794 | INFO  | @97217:11700458, 5800000 entries
> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
> 2017-04-22 16:47:19,324 | INFO  | @97226:18610005, 5900000 entries
> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>
> Any guidance would be much appreciated.
>
> Thanks!
>
> Steve.
>

Reply | Threaded
Open this post in threaded view
|

Re: kahadb recovery

tabish121@gmail.com
On 04/22/2017 05:56 PM, Steve Hill wrote:
> We now realize that the number after the @ is the file number being
> processed and after the colon is the offset in the file.  Eg,
> 97226:18610005 means db-97226.log is being processed. Based on this at
> least we now know how far we are through the startup.  It looks like
> it will take a further 2 hours to start, with a total startup time of
> 8 hours - this feels somewhat excessive!

Always good to include a version when asking for help.

>
> On 4/22/17 4:53 PM, Steve Hill wrote:
>> Hi!
>>
>> Can anyone provide guidance on why restarting ActiveMQ can take
>> hours?  We were seeing lots of message not found in sequence and it
>> is currently at 5.9M entries recovered.  Is there a way to know how
>> many entries there are so we have an idea when it might finish?
>>
>> There are currently about 1600 files in the kahadb data directory and
>> the total size is 30GB of what about 700mb is the db.data file.
>>
>>
>> 2017-04-22 16:28:21,079 | DEBUG | message not found in sequence id
>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207097:1:1 |
>> org.apache.activemq.store.kahadb.MessageDatabase | main
>> 2017-04-22 16:28:21,082 | DEBUG | message not found in sequence id
>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207096:1:1 |
>> org.apache.activemq.store.kahadb.MessageDatabase | main
>> 2017-04-22 16:28:21,187 | DEBUG | message not found in sequence id
>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20462448:1:1 |
>> org.apache.activemq.store.kahadb.MessageDatabase | main
>> 2017-04-22 16:30:56,681 | INFO  | @97201:5488429, 5600000 entries
>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>> 2017-04-22 16:36:17,337 | INFO  | @97210:5155402, 5700000 entries
>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>> 2017-04-22 16:41:45,794 | INFO  | @97217:11700458, 5800000 entries
>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>> 2017-04-22 16:47:19,324 | INFO  | @97226:18610005, 5900000 entries
>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>
>> Any guidance would be much appreciated.
>>
>> Thanks!
>>
>> Steve.
>>
>
>


--
Tim Bish
twitter: @tabish121
blog: http://timbish.blogspot.com/

Reply | Threaded
Open this post in threaded view
|

Re: kahadb recovery

Steve Hill
The version is 5.14.3

On 4/22/17 6:55 PM, Timothy Bish wrote:

> On 04/22/2017 05:56 PM, Steve Hill wrote:
>> We now realize that the number after the @ is the file number being
>> processed and after the colon is the offset in the file.  Eg,
>> 97226:18610005 means db-97226.log is being processed. Based on this
>> at least we now know how far we are through the startup.  It looks
>> like it will take a further 2 hours to start, with a total startup
>> time of 8 hours - this feels somewhat excessive!
>
> Always good to include a version when asking for help.
>
>>
>> On 4/22/17 4:53 PM, Steve Hill wrote:
>>> Hi!
>>>
>>> Can anyone provide guidance on why restarting ActiveMQ can take
>>> hours?  We were seeing lots of message not found in sequence and it
>>> is currently at 5.9M entries recovered.  Is there a way to know how
>>> many entries there are so we have an idea when it might finish?
>>>
>>> There are currently about 1600 files in the kahadb data directory
>>> and the total size is 30GB of what about 700mb is the db.data file.
>>>
>>>
>>> 2017-04-22 16:28:21,079 | DEBUG | message not found in sequence id
>>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207097:1:1 |
>>> org.apache.activemq.store.kahadb.MessageDatabase | main
>>> 2017-04-22 16:28:21,082 | DEBUG | message not found in sequence id
>>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207096:1:1 |
>>> org.apache.activemq.store.kahadb.MessageDatabase | main
>>> 2017-04-22 16:28:21,187 | DEBUG | message not found in sequence id
>>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20462448:1:1 |
>>> org.apache.activemq.store.kahadb.MessageDatabase | main
>>> 2017-04-22 16:30:56,681 | INFO  | @97201:5488429, 5600000 entries
>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>> 2017-04-22 16:36:17,337 | INFO  | @97210:5155402, 5700000 entries
>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>> 2017-04-22 16:41:45,794 | INFO  | @97217:11700458, 5800000 entries
>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>> 2017-04-22 16:47:19,324 | INFO  | @97226:18610005, 5900000 entries
>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>>
>>> Any guidance would be much appreciated.
>>>
>>> Thanks!
>>>
>>> Steve.
>>>
>>
>>
>
>

Reply | Threaded
Open this post in threaded view
|

Re: kahadb recovery

Tim Bain
When a system is slow, there's always something (or several somethings,
rotating between them) that is the limiting resource. I'd start by trying
to determine what that resource is, using standard OS monitoring tools (top
and the like). If you can tell that CPU is a primary bottleneck, use a
profiler or sampler like JVisualVM to determine where the time is being
spent, and share what you find here (maybe there's a bug we need to fix).
If it's disk IO, turn off Log4J logging (or at least turn it up to WARN),
and if it's still the bottleneck, consider options to upgrade your storage
hardware to something more performant. If the JVM is spending a lot of time
garbage collecting (JVisualVM and JConsole will tell you that), increase
the broker's heap size. If your OS is heavily into swap, buy more RAM. And
the list goes on, but the starting point is you characterizing what's
actually slow, and we can help you figure out why it's slow.

Tim

On Apr 22, 2017 10:29 PM, "Steve Hill" <[hidden email]> wrote:

> The version is 5.14.3
>
> On 4/22/17 6:55 PM, Timothy Bish wrote:
>
>> On 04/22/2017 05:56 PM, Steve Hill wrote:
>>
>>> We now realize that the number after the @ is the file number being
>>> processed and after the colon is the offset in the file.  Eg,
>>> 97226:18610005 means db-97226.log is being processed. Based on this at
>>> least we now know how far we are through the startup.  It looks like it
>>> will take a further 2 hours to start, with a total startup time of 8 hours
>>> - this feels somewhat excessive!
>>>
>>
>> Always good to include a version when asking for help.
>>
>>
>>> On 4/22/17 4:53 PM, Steve Hill wrote:
>>>
>>>> Hi!
>>>>
>>>> Can anyone provide guidance on why restarting ActiveMQ can take hours?
>>>> We were seeing lots of message not found in sequence and it is currently at
>>>> 5.9M entries recovered.  Is there a way to know how many entries there are
>>>> so we have an idea when it might finish?
>>>>
>>>> There are currently about 1600 files in the kahadb data directory and
>>>> the total size is 30GB of what about 700mb is the db.data file.
>>>>
>>>>
>>>> 2017-04-22 16:28:21,079 | DEBUG | message not found in sequence id
>>>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207097:1:1 |
>>>> org.apache.activemq.store.kahadb.MessageDatabase | main
>>>> 2017-04-22 16:28:21,082 | DEBUG | message not found in sequence id
>>>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20207096:1:1 |
>>>> org.apache.activemq.store.kahadb.MessageDatabase | main
>>>> 2017-04-22 16:28:21,187 | DEBUG | message not found in sequence id
>>>> index: ID:atas01p.x.com-57366-1491745186855-3:1:20462448:1:1 |
>>>> org.apache.activemq.store.kahadb.MessageDatabase | main
>>>> 2017-04-22 16:30:56,681 | INFO  | @97201:5488429, 5600000 entries
>>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>>> 2017-04-22 16:36:17,337 | INFO  | @97210:5155402, 5700000 entries
>>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>>> 2017-04-22 16:41:45,794 | INFO  | @97217:11700458, 5800000 entries
>>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>>> 2017-04-22 16:47:19,324 | INFO  | @97226:18610005, 5900000 entries
>>>> recovered .. | org.apache.activemq.store.kahadb.MessageDatabase | main
>>>>
>>>> Any guidance would be much appreciated.
>>>>
>>>> Thanks!
>>>>
>>>> Steve.
>>>>
>>>>
>>>
>>>
>>
>>
>