10 Replies Latest reply on Feb 23, 2012 7:38 PM by clebert.suconic

Very regular cyclical high CPU usage

dhirwinjr Feb 21, 2012 11:48 AM

All,

I've had some issues with HornetQ 2.2.5 in a Linux RHEL environment that I eventually resolved through some configuration changes. Now HornetQ has been running for over a week but I'm now seeing something unusual that I haven't seen before. In particular every 5 minutes the CPU usage for the HornetQ process spikes to 100% for about 30 seconds (it shows ~12% below but it's an 8-core machine so it's hitting 100% on one of the CPUs). During this spike I sometimes see "javax.jms.JMSException: Timed out waiting for respons when sending packet 71" which makes sense; the server is under a heavy load. So the exception isn't really the issue, it's rather why is HornetQ running at 100% for 30 seconds every 5 minutes? And it's extremely cyclical; here's a screen shot from VisualVM:

I'm going to try and profile this to see whether I can determine what class/method is under load but is there anything obvious that I should look at? Is there some reaper thread or other internal HornetQ process that runs once every 5 minutes that might be causing this?

I'm attaching the two relevant configs as reference.

Thanks,

Dave

hornetq-jms.xml 11.8 KB
hornetq-configuration.xml 2.4 KB

1. Re: Very regular cyclical high CPU usage

clebert.suconic Feb 21, 2012 1:26 PM (in response to dhirwinjr)

Can you try an updated SVN checkout?
Actions
2. Re: Very regular cyclical high CPU usage

dhirwinjr Feb 21, 2012 1:36 PM (in response to clebert.suconic)

Thanks Clebert for your response. I recently checked out version 2.2.8_EAP_GA from SVN. Is that the most appropriate version to run? Or 2.2.9_AS7_Final? FYI, we're just running HornetQ as a standalone application; it's not bundled with JBoss.

BTW, I see that 2.2.5 is the last release that is downloadable from the JBoss download site yet there are several later HornetQ tags. Any reason these later tags aren't built into a downloadable binaries?

Thanks,
Dave
Actions
3. Re: Very regular cyclical high CPU usage

clebert.suconic Feb 21, 2012 2:44 PM (in response to dhirwinjr)

2.2.9.AS7_Final is the most appropriate.

We have made this available as part of AS7, but not as part of a downloadable as we need to make a few adjustments on AS5 integration. But this would be fine for a standalone version as you're using.

I have bumped into a distributed dead lock a few months ago, that was peculiar to paging and having multiple sessions on the same connection (with producer and consumer through the same connection).

That was the only case I could think of. The user reported the timeout you described. So, I would say it's worth giving a try on the tag.
Actions
4. Re: Very regular cyclical high CPU usage

clebert.suconic Feb 21, 2012 2:49 PM (in response to clebert.suconic)

Duh... actually,

This is the most appropriate....

https://anonsvn.jboss.org/repos/hornetq/tags/HornetQ_2_2_11_AS7_Final/

It's out of the order as it uses alphabetical order. it also caught me... sorry!
Actions
5. Re: Very regular cyclical high CPU usage

clebert.suconic Feb 21, 2012 2:49 PM (in response to clebert.suconic)

Thanks for Justin Bertram who pointed us out
Actions
6. Re: Very regular cyclical high CPU usage

dhirwinjr Feb 21, 2012 3:06 PM (in response to clebert.suconic)

Clebert Suconic wrote:

Duh... actually,

This is the most appropriate....

https://anonsvn.jboss.org/repos/hornetq/tags/HornetQ_2_2_11_AS7_Final/

It's out of the order as it uses alphabetical order. it also caught me... sorry!

Thanks...I'll give that a try in our development environment and see if that helps.

Dave
Actions
7. Re: Very regular cyclical high CPU usage

dhirwinjr Feb 22, 2012 5:56 PM (in response to dhirwinjr)

So I upgraded to versioni 2.2.11 and at least after running for a couple of hours I don't see this issue any more. I will continue to monitor it over the next few days and see if the problem comes back.

Thanks,
Dave
Actions
8. Re: Very regular cyclical high CPU usage

clebert.suconic Feb 23, 2012 11:25 AM (in response to dhirwinjr)

If it happens again, we may need a client and server thread dumps to analyze it.
Actions
9. Re: Very regular cyclical high CPU usage

dhirwinjr Feb 23, 2012 6:17 PM (in response to clebert.suconic)

Hmm, now I'm seeing a different error after the system has run for < 24 hours. In particular here's the exception:

ERROR [2012-02-23 09:20:56,742] [pool-11-thread-1] [server.services.alarm.faces.jms.AlarmJmsFace] -- Error while publishing alarm callback: Unable to create producing session; nested exception is:
          javax.jms.JMSException: Failed to create session
java.rmi.RemoteException: Unable to create producing session; nested exception is:
          javax.jms.JMSException: Failed to create session
          at protocol.jms.lib.ATMSContext.getProducingSession(ATMSContext.java:911)
          at protocol.jms.lib.ATMSContext.publishMessage(ATMSContext.java:976)
          at server.services.alarm.faces.jms.AlarmJmsFace.update(AlarmJmsFace.java:102)
          at com.delcan.commons.services.PublisherImpl$1.run(PublisherImpl.java:140)
          at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
          at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
          at java.util.concurrent.FutureTask.run(Unknown Source)
          at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
          at java.lang.Thread.run(Unknown Source)
Caused by: javax.jms.JMSException: Failed to create session
          at org.hornetq.core.client.impl.ClientSessionFactoryImpl.createSessionInternal(ClientSessionFactoryImpl.java:864)
          at org.hornetq.core.client.impl.ClientSessionFactoryImpl.createSession(ClientSessionFactoryImpl.java:279)
          at org.hornetq.jms.client.HornetQConnection.createSessionInternal(HornetQConnection.java:513)
          at org.hornetq.jms.client.HornetQConnection.createSession(HornetQConnection.java:161)
          at protocol.jms.lib.ATMSContext.getProducingSession(ATMSContext.java:909)
          ... 9 more
Caused by: HornetQException[errorCode=0 message=Failed to create session]
          ... 14 more
Caused by: java.lang.IllegalStateException: Connection is null
          at org.hornetq.core.client.impl.ClientSessionFactoryImpl.createSessionInternal(ClientSessionFactoryImpl.java:745)
          ... 13 more
DEBUG [2012-02-23 09:20:56,742] [pool-11-thread-1] [server.services.alarm.faces.email.AlarmEmailFace] -- Received a publisher update [type=device update]

This happens every time a message producer tries to publish a message to a JMS topic. It's going to be hard to say that this is due to network connectivity issues becaues another process running on the exact same machine hasn't experienced the same issue.Any suggestions on things I should look at?

Thanks,
Dave
Actions
10. Re: Very regular cyclical high CPU usage

clebert.suconic Feb 23, 2012 7:38 PM (in response to dhirwinjr)

Are you creating new session on every send?

Maybe the Connecton got closed by some other error?

Why don't you enable logging at your client?
Actions

Go to original post