Slow JMS destination lookup

[mohitanchlia]

When we increase our number of sessions we see that queue destination lookup slows down from 70ms to 10000ms (10sec). I am trying to look at network and things like that but I don't think network is the problem because we are in same subnet and have 1gigbit port. Is there a clean way to isolate the problem?

[peterj]

Have you observed the garbage collection activity on the server? Having a couple of major collections performed during the course of a lookup could cause such a response time increase.

[mohitanchlia]

response times are slow consistently after we increase the load. And only lookup that slows down is looking up queue destination

[peterj]

That was too vague and confusing.

What do you mean by "response times are slow consistently after we increase the load" That is exactly what I would suspect would happen - the higher the load the slower the response times. And response times for what - the JNDI lookup only or for sending the messages?

It is especially confusing when you then say "And only lookup that slows down is looking up queue destination". Are you saying that the response time for sending a message, or the whole processing of a message, is acceptable? Are you saying that only one particular queue has this issue? Are you saying that looking up a topic destination does not have this issue? Are you saying that the response time for looking up the connection factory is acceptable but the response time for looking up the queue is not?

Please be very specific and supply numbers, including information about the load.

And it still could be GC.

[mohitanchlia]

Sorry for the confusion. I meant to say that response time for JNDI look up for queue destination increases from 50ms to 10000 (10sec) as we apply more load. I am not sure why the JNDI lookup would slow down that much. I see slow lookup time for all the queues. We don't use topic.

Because the response time for JNDI lookup is excruciatingly slow overall user experience results in slow response time. So connection lookup is not a proble, creating message/producer is not a problem, send message is not a problem. Only queue lookup (all queues) is slow.

[anilit99]

With the provided information, I can only take some guesses.
I believe when you say load - you mean number of messages on the queue ? Or overall application/user load ?

Anyways just to skim on the surface :
1. Did u try caching the initial context ? Building IC everytime, can cause some delay issues.
2. Sanity checks (closing the resources )
Please try to post the lookup code.

[peterj]

How do you determine how long the lookup requires? Is there timing code around the lookup? In which case I would like to see the lookup code also. I'm not sure why a queue would take longer to lookup than the connection. Though it does seem to imply that the server is doing a lot of work when a queue is being looked up...

[mohitanchlia]

Below is the code. I have timing around the code and only piece that's slow is when there is a ctx.lookup involved.

 private Object lookupJndi(String jndiName) {
 Object result = null;

 try {
 result = ctx.lookup(jndiName);
 } catch (NamingException e) {
 throw new ServiceLocatorException("JNDI lookup error while looking up resource: '" + jndiName + "'", e);
 }
 return result;
 }

cache = Collections.synchronizedMap(new WeakHashMap<String, Object>());

 public Object lookup(String jndiName, boolean useCache) {
 Object result = null;
 long t1=System.currentTimeMillis();
 if (useCache) {
 if (cache.containsKey(jndiName)) {
 result = cache.get(jndiName);
 }

 // WeakHashMap can return null
 if (result == null) {
 result = lookupJndi(jndiName);
 logger.info(jndiName + " Lookup took " + (System.currentTimeMillis() - t1));
 t1=System.currentTimeMillis();
 // we need to make copy of the key
 // as the original one can be a literal from the
 // String pool which prevents it from being garbage collected
 // and our WeakHashMap working
 cache.put(new String(jndiName), result);
 logger.info(jndiName + " Lookup insert in cache took " + (System.currentTimeMillis() - t1));
 t1=System.currentTimeMillis();
 }else{
 logger.info(jndiName + " Lookup from cache took " + (System.currentTimeMillis() - t1));
 t1=System.currentTimeMillis();
 }
 } else {
 result = lookupJndi(jndiName);
 logger.info(jndiName + " Lookup took " + (System.currentTimeMillis() - t1));
 t1=System.currentTimeMillis();
 }
 return result;
 }