Very regular cyclical high CPU usage

[dhirwinjr]

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

[clebert.suconic]

Can you try an updated SVN checkout?

[dhirwinjr]

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

[clebert.suconic]

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.

[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!

[clebert.suconic]

Thanks for Justin Bertram who pointed us out

[dhirwinjr]

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

[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

[clebert.suconic]

If it happens again, we may need a client and server thread dumps to analyze it.

[dhirwinjr]

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

[clebert.suconic]

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?