You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Shobhana <sh...@quickride.in> on 2016/03/28 13:10:50 UTC
ActiveMQ with KahaDB as persistent store becomes very slow (almost
unresponsive) after creating large no (25000+) of Topics
Hi,
Is there any limit to the number of Topics that can be created on a single
broker? As per my understanding, there is no such limit and it depends on
the system in which the broker is running.
Problem observed which raised the above question :
I tried to simulate an issue which occurs in our production environment when
the no of topics created are very high (25000+). The subscriber test client
does the following :
a) Creates 5 threads each of which will establish a connection with the AMQ
broker using Eclipse Paho's MqttClient V3 lib (so 5 connections are
established)
b) Each thread further creates 5 more threads and these 5 threads use the
same connection to subscribe to different topics in a loop. (so overall
there are 25 threads using 5 connections to subscribe to different topics).
On another machine, I ran another publisher test client which does similar
to subscriber test client, except that it publishes messages in a loop
instead of subscribing to the topics.
When I run these test clients, it runs fine for a few minutes (15-30 mins)
and then starts failing with "Subscribe operation timed out exception" from
MqttClient. I have seen MqttClient code and observed that this exception is
thrown if the client does not receive ACK for subscribe operation within 30
secs. So why is AMQ not able to send ACK within 30 secs? There are no
exceptions in AMQ logs when this happens. After the subscriber test client
failed, publisher test client also fails with "Publish operation timed out".
When the exceptions started, I killed the test clients abruptly and after
sometime saw a bunch of following exceptions in AMQ logs :
2016-03-28 10:36:48,612 | WARN | Failed to send frame MQTTFrame { type:
PUBCOMP, qos: AT_MOST_ONCE, dup:false } |
org.apache.activemq.transport.mqtt.MQTTProtocolConverter | ActiveMQ NIO
Worker 1255
java.io.IOException: Broken pipe
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)[:1.7.0_95]
at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)[:1.7.0_95]
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)[:1.7.0_95]
at sun.nio.ch.IOUtil.write(IOUtil.java:65)[:1.7.0_95]
at
sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:492)[:1.7.0_95]
at
org.apache.activemq.transport.nio.NIOOutputStream.write(NIOOutputStream.java:206)[activemq-client-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.nio.NIOOutputStream.flush(NIOOutputStream.java:132)[activemq-client-5.13.1.jar:5.13.1]
at java.io.DataOutputStream.flush(DataOutputStream.java:123)[:1.7.0_95]
at
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:194)[activemq-client-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTTransportFilter.sendToMQTT(MQTTTransportFilter.java:120)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTProtocolConverter.sendToMQTT(MQTTProtocolConverter.java:183)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTProtocolConverter.onMQTTPubRel(MQTTProtocolConverter.java:489)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTProtocolConverter.onMQTTCommand(MQTTProtocolConverter.java:224)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTTransportFilter.onCommand(MQTTTransportFilter.java:94)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[activemq-client-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$1.onFrame(MQTTCodec.java:65)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec.processCommand(MQTTCodec.java:90)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec.access$400(MQTTCodec.java:26)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$4.parse(MQTTCodec.java:213)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$3.parse(MQTTCodec.java:179)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$2.parse(MQTTCodec.java:138)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$4.parse(MQTTCodec.java:217)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$3.parse(MQTTCodec.java:179)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec$2.parse(MQTTCodec.java:138)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTCodec.parse(MQTTCodec.java:76)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTNIOTransport.processBuffer(MQTTNIOTransport.java:132)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTNIOTransport.serviceRead(MQTTNIOTransport.java:120)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTNIOTransport.access$000(MQTTNIOTransport.java:43)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.mqtt.MQTTNIOTransport$1.onSelect(MQTTNIOTransport.java:72)[activemq-mqtt-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:98)[activemq-client-5.13.1.jar:5.13.1]
at
org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:118)[activemq-client-5.13.1.jar:5.13.1]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_95]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_95]
at java.lang.Thread.run(Thread.java:745)[:1.7.0_95]
These exceptions make sense because I had killed the test client abruptly.
But after this, AMQ becomes virtually unusable! Further attempts to connect
to the broker and/or subscribe/unsubscribe to/from topics will always
timeout.
I took thread dumps of AMQ process and made following observations :
a) Most of the threads are waiting to acquire read lock on
org.apache.activemq.broker.region.AbstractRegion's destinationsLock
b) The method
org.apache.activemq.broker.region.AbstractRegion.addDestination which had
acquired the write lock did not finish even after 5 minutes! (Check
"ActiveMQ NIO Worker 1323" in ThreadDump1.log and ThreadDump2.log)
c) The method org.apache.activemq.broker.region.TopicRegion.addConsumer
which internally calls the addDestination method mentioned above did not
complete even after 30 minutes!! (Check same thread in ThreadDump2.log and
ThreadDump3.log)
ThreadDump1.log
<http://activemq.2283324.n4.nabble.com/file/n4709985/ThreadDump1.log>
ThreadDump2.log
<http://activemq.2283324.n4.nabble.com/file/n4709985/ThreadDump2.log>
ThreadDump3.log
<http://activemq.2283324.n4.nabble.com/file/n4709985/ThreadDump3.log>
PS :
a) We have disabled dedicated task runner by setting
-Dorg.apache.activemq.UseDedicatedTaskRunner=false
b) We use KahaDB as persistent store and all messages are set to QOS 1.
I feel I am not using the right AMQ configurations, but I am not able to
figure out which config is missing/wrong.
Any help / pointers would be greatly appreciated!
Thanks,
Shobhana
--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Tim Bain <tb...@alumni.duke.edu>.
Sounds good. A profiler (as opposed to a sampler) should be able to tell
you how many times a given method is called, so if you see that that's 1,
then you'd be able to make the claim that a single call to updateIndex() is
taking 3.5 minutes. But looking only at thread dumps, all you can say is
that you're calling updateIndex() again 3.5 minutes later, but not 1)
whether it's the same call as the first one, and 2) whether you've spent a
substantial amount of the intervening time calling updateIndex() (either
once or many times, whichever) or whether you actually spent most of your
time doing something else but just happened to take thread dumps at times
when you were calling updateIndex().
BTW, I suspect that you're right that calls to updateIndex() are where
you're spending your time, but that it's many repeated calls rather than
one single 3.5-minute call and rather than just happening to hit
updateIndex() twice when you ran your thread dumps. But without something
to prove how many calls were made and how long was spent on them, you
really can't make any claims about what's happening.
Tim
On Mon, Apr 11, 2016 at 6:44 AM, Shobhana <sh...@quickride.in> wrote:
> I looked at only the thread dumps. I will profile with some profiler first
> and see where is the broker spending more time.
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710583.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Shobhana <sh...@quickride.in>.
I looked at only the thread dumps. I will profile with some profiler first
and see where is the broker spending more time.
--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710583.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Tim Bain <tb...@alumni.duke.edu>.
How are you able to tell that a single call to updateIndex() is taking 3.5
minutes? It's not possible to determine that from thread dumps alone, so
what other tool are you using to prove that assertion?
A profiler such as JVisualVM would help you determine where precisely the
broker is spending its time, though of course it may not tell you exactly
why. Stepping through the code with a debugger may help you figure out the
why if it's not obvious from the profiler output. Luckily this is an open
source project and you can download the source to make that possible.
Tim
On Apr 8, 2016 11:58 AM, "Shobhana" <sh...@quickride.in> wrote:
> Hi Tim,
>
> I said indexing was the point of contention after seeing that Thread
> "ActiveMQ NIO Worker 169" was still working on
> org.apache.activemq.store.kahadb.MessageDatabase.updateIndex even after >
> 3.5 minutes.
>
> These are full thread dumps. I guess the lock (read lock) is held by
> threads
> "ActiveMQ NIO Worker 169" and "ActiveMQ NIO Worker 171". Since the read
> lock
> is already held by other threads, the thread "ActiveMQ Broker[localhost]
> Scheduler" is waiting to acquire write lock. Since there is already a
> thread
> waiting to acquire write lock, other threads which are waiting to acquire
> read lock are still waiting.
>
> What could be the reason for updateIndex not completing even after 3.5
> minutes?
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710533.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Shobhana <sh...@quickride.in>.
Hi Tim,
I said indexing was the point of contention after seeing that Thread
"ActiveMQ NIO Worker 169" was still working on
org.apache.activemq.store.kahadb.MessageDatabase.updateIndex even after >
3.5 minutes.
These are full thread dumps. I guess the lock (read lock) is held by threads
"ActiveMQ NIO Worker 169" and "ActiveMQ NIO Worker 171". Since the read lock
is already held by other threads, the thread "ActiveMQ Broker[localhost]
Scheduler" is waiting to acquire write lock. Since there is already a thread
waiting to acquire write lock, other threads which are waiting to acquire
read lock are still waiting.
What could be the reason for updateIndex not completing even after 3.5
minutes?
--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710533.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Tim Bain <tb...@alumni.duke.edu>.
Kevin Burton has already identified that GCing destinations is horribly
inefficient when the number of destinations is large; search the archives
for posts from him for more details. He has proposed some fixes (in Git,
but against an earlier version), but so far as I know no one from the
community has spent the time to rebase his changes into the current
baseline. I don't think it would take that long to do, but no one (myself
included) has spent the time on it, as far as I know.
In your new thread dumps, the thread doing the indexing is holding locks
that no one else is waiting for, so I don't see why you claim that indexing
is now the point of contention.
Four threads are waiting on 0x0000000780169de0 and one thread is waiting on
0x00000007812b3bd0, but I don't see any threads holding those locks. Is
this a full thread dump, or just a partial?
On Thu, Mar 31, 2016 at 5:43 AM, Christopher Shannon <
christopher.l.shannon@gmail.com> wrote:
> The CountStatisticImpl class is basically just a wrapper for an atomic
> long. It's used all over the place (destinations, subscriptions, inside
> kahadb, etc) to keep track of various metrics in a non-blocking way.
> There's a DestinationStatistics object for each destination and that has
> several of those counters in it, There's an option to disable metrics
> tracking but that will only prevent the counters from actually
> incrementing, not stop the allocations. Some of the metrics are required
> for parts of the broker and won't honor that flag to disable them (such as
> needing message counts in kahadb) but I plan on going back and double
> checking all of those metrics at some point soon to make sure everything
> that can honor that flag does. Since you have a lot of destinations you
> are seeing a lot of those counters.
>
> If you disable disk syncs then you need to be aware that you are risking
> message loss. Since you are no longer waiting to make sure data is
> persisted to the disk before sending the ack to the producer there's a
> chance of losing messages if something happens (like a power outage)
>
> On Wed, Mar 30, 2016 at 2:41 PM, Shobhana <sh...@quickride.in> wrote:
>
> > Hi Tim & Christopher,
> >
> > I tried with 5.13.2 version but as you suspected, it did not solve my
> > problem.
> >
> > We don't have any wildcard subscriptions. Most of the Topics have a
> maximum
> > of 8 subscriptions (Ranges between 2 and 8) and a few topics (~25-30 so
> > far)
> > have more than 8 (this is not fixed, it depends on no of users interested
> > in
> > these specific topics; the max I have seen is 40).
> >
> > Btw, I just realized that I have set a very low value for destination
> > inactivity (30 secs) and hence many destinations are getting removed very
> > early. Later when there is any message published to the same destination,
> > it
> > would result in destination getting created again. I will correct this by
> > increasing this time out to appropriate values based on each destination
> > (varies from 1 hour to 1 day)
> >
> > Today after upgrading to 5.13.2 version in my test env, I tried with
> > different configurations to see if there is any improvement. In
> particular,
> > I disabled journal disk sync (since many threads were waiting at KahaDB
> > level operations) and also disabled metadata update. With these changes,
> > the
> > contention moved to a different level (KahaDB update index .. see
> attached
> > thread dumps)
> >
> > ThreadDump1.txt
> > <http://activemq.2283324.n4.nabble.com/file/n4710055/ThreadDump1.txt>
> > ThreadDump2.txt
> > <http://activemq.2283324.n4.nabble.com/file/n4710055/ThreadDump2.txt>
> >
> > I will test again by increasing the index cache size (current value is
> set
> > to the default of 10000) to 100000 and see if it makes any improvement.
> >
> > Also histo reports showed a huge number (1393177) of
> > org.apache.activemq.management.CountStatisticImpl instances and 1951637
> > instances of java.util.concurrent.locks.ReentrantLock$NonfairSync. See
> > attached histo for complete report.
> >
> > histo.txt <http://activemq.2283324.n4.nabble.com/file/n4710055/histo.txt
> >
> >
> > What are these org.apache.activemq.management.CountStatisticImpl
> instances?
> > Is there any way to avoid them?
> >
> > Thanks,
> > Shobhana
> >
> >
> >
> >
> >
> >
> > --
> > View this message in context:
> >
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710055.html
> > Sent from the ActiveMQ - User mailing list archive at Nabble.com.
> >
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Christopher Shannon <ch...@gmail.com>.
The CountStatisticImpl class is basically just a wrapper for an atomic
long. It's used all over the place (destinations, subscriptions, inside
kahadb, etc) to keep track of various metrics in a non-blocking way.
There's a DestinationStatistics object for each destination and that has
several of those counters in it, There's an option to disable metrics
tracking but that will only prevent the counters from actually
incrementing, not stop the allocations. Some of the metrics are required
for parts of the broker and won't honor that flag to disable them (such as
needing message counts in kahadb) but I plan on going back and double
checking all of those metrics at some point soon to make sure everything
that can honor that flag does. Since you have a lot of destinations you
are seeing a lot of those counters.
If you disable disk syncs then you need to be aware that you are risking
message loss. Since you are no longer waiting to make sure data is
persisted to the disk before sending the ack to the producer there's a
chance of losing messages if something happens (like a power outage)
On Wed, Mar 30, 2016 at 2:41 PM, Shobhana <sh...@quickride.in> wrote:
> Hi Tim & Christopher,
>
> I tried with 5.13.2 version but as you suspected, it did not solve my
> problem.
>
> We don't have any wildcard subscriptions. Most of the Topics have a maximum
> of 8 subscriptions (Ranges between 2 and 8) and a few topics (~25-30 so
> far)
> have more than 8 (this is not fixed, it depends on no of users interested
> in
> these specific topics; the max I have seen is 40).
>
> Btw, I just realized that I have set a very low value for destination
> inactivity (30 secs) and hence many destinations are getting removed very
> early. Later when there is any message published to the same destination,
> it
> would result in destination getting created again. I will correct this by
> increasing this time out to appropriate values based on each destination
> (varies from 1 hour to 1 day)
>
> Today after upgrading to 5.13.2 version in my test env, I tried with
> different configurations to see if there is any improvement. In particular,
> I disabled journal disk sync (since many threads were waiting at KahaDB
> level operations) and also disabled metadata update. With these changes,
> the
> contention moved to a different level (KahaDB update index .. see attached
> thread dumps)
>
> ThreadDump1.txt
> <http://activemq.2283324.n4.nabble.com/file/n4710055/ThreadDump1.txt>
> ThreadDump2.txt
> <http://activemq.2283324.n4.nabble.com/file/n4710055/ThreadDump2.txt>
>
> I will test again by increasing the index cache size (current value is set
> to the default of 10000) to 100000 and see if it makes any improvement.
>
> Also histo reports showed a huge number (1393177) of
> org.apache.activemq.management.CountStatisticImpl instances and 1951637
> instances of java.util.concurrent.locks.ReentrantLock$NonfairSync. See
> attached histo for complete report.
>
> histo.txt <http://activemq.2283324.n4.nabble.com/file/n4710055/histo.txt>
>
> What are these org.apache.activemq.management.CountStatisticImpl instances?
> Is there any way to avoid them?
>
> Thanks,
> Shobhana
>
>
>
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710055.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Shobhana <sh...@quickride.in>.
Hi Tim & Christopher,
I tried with 5.13.2 version but as you suspected, it did not solve my
problem.
We don't have any wildcard subscriptions. Most of the Topics have a maximum
of 8 subscriptions (Ranges between 2 and 8) and a few topics (~25-30 so far)
have more than 8 (this is not fixed, it depends on no of users interested in
these specific topics; the max I have seen is 40).
Btw, I just realized that I have set a very low value for destination
inactivity (30 secs) and hence many destinations are getting removed very
early. Later when there is any message published to the same destination, it
would result in destination getting created again. I will correct this by
increasing this time out to appropriate values based on each destination
(varies from 1 hour to 1 day)
Today after upgrading to 5.13.2 version in my test env, I tried with
different configurations to see if there is any improvement. In particular,
I disabled journal disk sync (since many threads were waiting at KahaDB
level operations) and also disabled metadata update. With these changes, the
contention moved to a different level (KahaDB update index .. see attached
thread dumps)
ThreadDump1.txt
<http://activemq.2283324.n4.nabble.com/file/n4710055/ThreadDump1.txt>
ThreadDump2.txt
<http://activemq.2283324.n4.nabble.com/file/n4710055/ThreadDump2.txt>
I will test again by increasing the index cache size (current value is set
to the default of 10000) to 100000 and see if it makes any improvement.
Also histo reports showed a huge number (1393177) of
org.apache.activemq.management.CountStatisticImpl instances and 1951637
instances of java.util.concurrent.locks.ReentrantLock$NonfairSync. See
attached histo for complete report.
histo.txt <http://activemq.2283324.n4.nabble.com/file/n4710055/histo.txt>
What are these org.apache.activemq.management.CountStatisticImpl instances?
Is there any way to avoid them?
Thanks,
Shobhana
--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710055.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Tim Bain <tb...@alumni.duke.edu>.
AbstractRegion.lookup()
<http://grepcode.com/file/repo1.maven.org/maven2/org.apache.activemq/activemq-broker/5.11.1/org/apache/activemq/broker/region/AbstractRegion.java#AbstractRegion.lookup%28org.apache.activemq.broker.ConnectionContext%2Corg.apache.activemq.command.ActiveMQDestination%2Cboolean%29>
has two copies of the following code:
455 destinationsLock.readLock().lock();
456 try {
457 dest = destinations.get(destination);
458 } finally {
459 destinationsLock.readLock().unlock();
460 }
destinations is a ConcurrentHashMap. Why are we using a single external
lock around a ConcurrentHashMap??? We've got lots of similar code
elsewhere in AbstractRegion. I suspect that the primary goal is to make
sure that addDestination() and receiveDestination() don't create or remove
the same destination twice, but there are other ways to do that (for
example, having the map be ConcurrentHashMap<ActiveMQDestination,
AtomicReference<Destination>> and putting the AtomicReference into the map
immediately and then later populating the reference once the object is
constructed).
I've submitted https://issues.apache.org/jira/browse/AMQ-6226 to capture
that proposed improvement.
BTW, although I'm sure that the bug Chris referenced can't hurt, it doesn't
appear to be related to the apparent root cause of your issue, so I'd
expect you'll see little or no improvement in 5.13.2. But it's definitely
worth testing to be sure.
Tim
On Mar 30, 2016 5:17 AM, "Christopher Shannon" <
christopher.l.shannon@gmail.com> wrote:
> Also, the bug fix should at least help the performance on start up but may
> not help with the producer timing out problem. The main issue is that the
> message has to be dispatched to all subscriptions before the ACK can be
> sent back to the producer, so if you have a lot of subscriptions (such as a
> wildcard subscription on a lot of topics) this could cause ACKs to be slow.
>
> On Tue, Mar 29, 2016 at 8:53 PM, Shobhana <sh...@quickride.in> wrote:
>
> > Thank you Christopher for your suggestion. I'll check this with 5.13.2
> >
> >
> >
> > --
> > View this message in context:
> >
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710043.html
> > Sent from the ActiveMQ - User mailing list archive at Nabble.com.
> >
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Christopher Shannon <ch...@gmail.com>.
Also, the bug fix should at least help the performance on start up but may
not help with the producer timing out problem. The main issue is that the
message has to be dispatched to all subscriptions before the ACK can be
sent back to the producer, so if you have a lot of subscriptions (such as a
wildcard subscription on a lot of topics) this could cause ACKs to be slow.
On Tue, Mar 29, 2016 at 8:53 PM, Shobhana <sh...@quickride.in> wrote:
> Thank you Christopher for your suggestion. I'll check this with 5.13.2
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710043.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Shobhana <sh...@quickride.in>.
Thank you Christopher for your suggestion. I'll check this with 5.13.2
--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710043.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Christopher Shannon <ch...@gmail.com>.
Can you try version 5.13.2 and see if that helps? There was a performance
bug related to durables (AMQ-6158) in KahaDB that was fixed which might
help here.
On Tue, Mar 29, 2016 at 12:17 AM, Shobhana <sh...@quickride.in> wrote:
> I enabled debug logs to see what was happening when AMQ could not send ACK
> within 30 secs. I started the AMQ broker on 28-Mar around 17:40 and to my
> surprise, I find that the server startup is still going on even now at
> 29-Mar 09:30 (~16 hours!!). I see a lot of following messages in the logs :
>
> 2016-03-28 18:36:25,340 | DEBUG | PrimaryBroker adding destination:
> topic://33ConcurrentTopicCreator410 |
> org.apache.activemq.broker.region.AbstractRegion | main
> 2016-03-28 18:36:25,347 | DEBUG | Restoring durable subscription:
> SubscriptionInfo {subscribedDestination =
> topic://33ConcurrentTopicCreator410, destination =
> topic://33ConcurrentTopicCreator410, clientId = 3ConcurrentTopicCreator,
> subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator410, selector =
> null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
> main
> 2016-03-28 18:36:25,350 | DEBUG | PrimaryBroker adding destination:
> topic://33ConcurrentTopicCreator409 |
> org.apache.activemq.broker.region.AbstractRegion | main
> 2016-03-28 18:36:25,357 | DEBUG | Restoring durable subscription:
> SubscriptionInfo {subscribedDestination =
> topic://33ConcurrentTopicCreator409, destination =
> topic://33ConcurrentTopicCreator409, clientId = 3ConcurrentTopicCreator,
> subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator409, selector =
> null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
> main
> 2016-03-28 18:36:25,360 | DEBUG | PrimaryBroker adding destination:
> topic://33ConcurrentTopicCreator408 |
> org.apache.activemq.broker.region.AbstractRegion | main
> 2016-03-28 18:36:25,367 | DEBUG | Restoring durable subscription:
> SubscriptionInfo {subscribedDestination =
> topic://33ConcurrentTopicCreator408, destination =
> topic://33ConcurrentTopicCreator408, clientId = 3ConcurrentTopicCreator,
> subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator408, selector =
> null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
> main
> 2016-03-28 18:36:25,370 | DEBUG | PrimaryBroker adding destination:
> topic://33ConcurrentTopicCreator403 |
> org.apache.activemq.broker.region.AbstractRegion | main
> 2016-03-28 18:36:25,377 | DEBUG | Restoring durable subscription:
> SubscriptionInfo {subscribedDestination =
> topic://33ConcurrentTopicCreator403, destination =
> topic://33ConcurrentTopicCreator403, clientId = 3ConcurrentTopicCreator,
> subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator403, selector =
> null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
> main
> 2016-03-28 18:36:25,380 | DEBUG | PrimaryBroker adding destination:
> topic://33ConcurrentTopicCreator402 |
> org.apache.activemq.broker.region.AbstractRegion | main
> 2016-03-28 18:36:25,387 | DEBUG | Restoring durable subscription:
> SubscriptionInfo {subscribedDestination =
> topic://33ConcurrentTopicCreator402, destination =
> topic://33ConcurrentTopicCreator402, clientId = 3ConcurrentTopicCreator,
> subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator402, selector =
> null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
> main
>
> There are 89000+ instances of "PrimaryBroker adding destination:" and
> "Restoring durable subscription:"
>
> If I enable only INFO log level, broker starts up within a few minutes, but
> if DEBUG is enabled, why does it take so long? Will writing debug message
> to
> the log take so much more time?
>
>
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710008.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Re: ActiveMQ with KahaDB as persistent store becomes very slow
(almost unresponsive) after creating large no (25000+) of Topics
Posted by Shobhana <sh...@quickride.in>.
I enabled debug logs to see what was happening when AMQ could not send ACK
within 30 secs. I started the AMQ broker on 28-Mar around 17:40 and to my
surprise, I find that the server startup is still going on even now at
29-Mar 09:30 (~16 hours!!). I see a lot of following messages in the logs :
2016-03-28 18:36:25,340 | DEBUG | PrimaryBroker adding destination:
topic://33ConcurrentTopicCreator410 |
org.apache.activemq.broker.region.AbstractRegion | main
2016-03-28 18:36:25,347 | DEBUG | Restoring durable subscription:
SubscriptionInfo {subscribedDestination =
topic://33ConcurrentTopicCreator410, destination =
topic://33ConcurrentTopicCreator410, clientId = 3ConcurrentTopicCreator,
subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator410, selector =
null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
main
2016-03-28 18:36:25,350 | DEBUG | PrimaryBroker adding destination:
topic://33ConcurrentTopicCreator409 |
org.apache.activemq.broker.region.AbstractRegion | main
2016-03-28 18:36:25,357 | DEBUG | Restoring durable subscription:
SubscriptionInfo {subscribedDestination =
topic://33ConcurrentTopicCreator409, destination =
topic://33ConcurrentTopicCreator409, clientId = 3ConcurrentTopicCreator,
subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator409, selector =
null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
main
2016-03-28 18:36:25,360 | DEBUG | PrimaryBroker adding destination:
topic://33ConcurrentTopicCreator408 |
org.apache.activemq.broker.region.AbstractRegion | main
2016-03-28 18:36:25,367 | DEBUG | Restoring durable subscription:
SubscriptionInfo {subscribedDestination =
topic://33ConcurrentTopicCreator408, destination =
topic://33ConcurrentTopicCreator408, clientId = 3ConcurrentTopicCreator,
subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator408, selector =
null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
main
2016-03-28 18:36:25,370 | DEBUG | PrimaryBroker adding destination:
topic://33ConcurrentTopicCreator403 |
org.apache.activemq.broker.region.AbstractRegion | main
2016-03-28 18:36:25,377 | DEBUG | Restoring durable subscription:
SubscriptionInfo {subscribedDestination =
topic://33ConcurrentTopicCreator403, destination =
topic://33ConcurrentTopicCreator403, clientId = 3ConcurrentTopicCreator,
subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator403, selector =
null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
main
2016-03-28 18:36:25,380 | DEBUG | PrimaryBroker adding destination:
topic://33ConcurrentTopicCreator402 |
org.apache.activemq.broker.region.AbstractRegion | main
2016-03-28 18:36:25,387 | DEBUG | Restoring durable subscription:
SubscriptionInfo {subscribedDestination =
topic://33ConcurrentTopicCreator402, destination =
topic://33ConcurrentTopicCreator402, clientId = 3ConcurrentTopicCreator,
subscriptionName = AT_LEAST_ONCE:33ConcurrentTopicCreator402, selector =
null, noLocal = false} | org.apache.activemq.broker.region.TopicRegion |
main
There are 89000+ instances of "PrimaryBroker adding destination:" and
"Restoring durable subscription:"
If I enable only INFO log level, broker starts up within a few minutes, but
if DEBUG is enabled, why does it take so long? Will writing debug message to
the log take so much more time?
--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-with-KahaDB-as-persistent-store-becomes-very-slow-almost-unresponsive-after-creating-large-s-tp4709985p4710008.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.