Slow Jolokia response with cassandra

[ajorgensen]

I am seeing some very slow jolokia request times on my Cassandra 3.0 cluster. Specifically when running the following:

curl 127.0.0.1:8778/jolokia/list

on a slightly loaded cluster I am seeing request times around 30-40 seconds and on a more heavily loaded cluster I am seeing request times in the 2 minute mark. We are currently using jolokia 1.3.2 and v4 of the diamond collector. I also have a Cassandra 1.1 cluster that has the same load and number of nodes and running the same curl command comes back in about 1 second however it is using jolokia 1.2.3 which has a known issue where the keys are truncated at 1000 so my hunch is that is actually what is causing the faster response times.

Is there anything I can do to help diagnose this issue to see what is causing the slowdown or has anyone else experience this?

I have a bug open on the cassandra side as well as i'm not sure which is the culprit here, any advice on how to debug would be greatly appreciated. https://issues.apache.org/jira/browse/CASSANDRA-11677

[rhuss]

Which version do you use ? There was an issue with reverse DNS lookups which might be the reason. You can switch this off with a configuration option allowDnsReverseLookup.

On the other hand you can use 1.2.3. This 1000 element limit is only a default value (which was set to unlimited in a later version). Setting set the configuration option maxCollectionSize to 0 should do the trick.

[ajorgensen]

We are using version 1.3.2 at the moment, I also tried 1.3.3 with the same effect. Those are good suggestions, one other thing I was thinking of trying was only specifying the beans that we need. Currently diamond defaults to collecting all of the metrics which potentially there could be a lot of. I am going to try to pare the list down and see if the query times get better.

One other anecdote was that I was able to use jmxterm (https://github.com/jiaqi/jmxterm) to query jmx in cassandra directly and it seemed pretty fast to come back, I likely wasnt doing quite as an extensive of a query as jolokia is but perhaps that add some merit to the dns lookup suggestion you made.

Thanks so much for the suggestions and I will give them a try and report back if i find anything.

regarding the dns issue, the diamond collector i believe is talking directly to 127.0.0.1 so no dns lookup should be required unless jolokia is doing something under the covers.

Another interesting annecdote is that jolokia took almost 2 minutes to come back and say my request was invalid for the following:

$ time curl "http://127.0.0.1:8778/jolokia/list&maxDepth=1"
{"stacktrace":"java.lang.IllegalArgumentException: No type with name 'list&maxDepth=1' exists\n\tat org.jolokia.util.RequestType.getTypeByName(RequestType.java:69)\n\tat org.jolokia.request.JmxRequestFactory.createGetRequest(JmxRequestFactory.java:94)\n\tat org.jolokia.http.HttpRequestHandler.handleGetRequest(HttpRequestHandler.java:78)\n\tat org.jolokia.jvmagent.handler.JolokiaHttpHandler.executeGetRequest(JolokiaHttpHandler.java:269)\n\tat org.jolokia.jvmagent.handler.JolokiaHttpHandler.doHandle(JolokiaHttpHandler.java:220)\n\tat org.jolokia.jvmagent.handler.JolokiaHttpHandler.handle(JolokiaHttpHandler.java:169)\n\tat com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79)\n\tat sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:83)\n\tat com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:82)\n\tat sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:675)\n\tat com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79)\n\tat sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:647)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)\n\tat java.lang.Thread.run(Thread.java:745)\n","error_type":"java.lang.IllegalArgumentException","error":"java.lang.IllegalArgumentException : No type with name 'list&maxDepth=1' exists","status":400}
real    1m42.283s
user    0m0.011s
sys     0m0.000s

Also even with maxDepth=1 it still took almost 2 minutes to come back but with less data

time curl "http://127.0.0.1:8778/jolokia/list?maxDepth=1"
{"request":{"type":"list"},"value":{"org.apache.cassandra.service":"1","java.util.logging":"1","org.apache.cassandra.db":"1","org.apache.cassandra.metrics":"1","java.nio":"1","org.apache.cassandra.hints":"1","JMImplementation":"1","java.lang":"1","com.sun.management":"1","ch.qos.logback.classic":"1","org.apache.cassandra.internal":"1","jmx4perl":"1","org.apache.cassandra.request":"1","org.apache.cassandra.net":"1","org.apache.cassandra.auth":"1","org.apache.cassandra.RPC-THREAD-POOL":"1","com.thinkaurelius.thrift.server":"1","jolokia":"1"},"timestamp":1461850682,"status":200}
real    1m50.179s
user    0m0.005s
sys     0m0.007s

[tlasica]

I am using jolokia 1.3.5 with C* 3.10 and everything works perfectly fast:

automaton@ip-10-200-181-242:~$ time curl "http://node0:8778/jolokia/list&maxDepth=1"
{"stacktrace":"java.lang.IllegalArgumentException: No type with name 'list&maxDepth=1' exists\n\tat 
....
lang.IllegalArgumentException : No type with name 'list&maxDepth=1' exists","status":400}
real	0m0.021s
user	0m0.009s
sys	0m0.004s```