busy threads?

Submitted by Guest on Wed, 27/11/2013 - 08:26

Implementation discussion

Hi, we've been experiencing this problem for some time now, and it's definitely not specific to version 1.7-beta, since I've seen it w/ 1.6 and 1.5 as well. Basically, the system gets ever slower throughout the day. I have a cron job to restart tomcat (running 7) every night to help avert the issue. I took to having a look at it today to see what I could find, but got a bit stuck.

Here's what top looks like w/ thread view turned on:

op - 16:31:04 up 27 days, 6:47, 3 users, load average: 0.18, 0.21, 0.22

Tasks: 356 total, 1 running, 355 sleeping, 0 stopped, 0 zombie

Cpu(s): 5.2%us, 0.2%sy, 0.0%ni, 94.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st

Mem: 1952356k total, 1758892k used, 193464k free, 21092k buffers

Swap: 4191228k total, 243776k used, 3947452k free, 291844k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

2287 tomcat7 20 0 1868m 667m 7664 S 9 35.0 9:48.01 java

1474 root 20 0 1880m 208m 2516 S 0 11.0 26:38.08 java

1926 root 20 0 1880m 208m 2516 S 0 11.0 119:37.02 java

2296 tomcat7 20 0 1868m 667m 7664 S 0 35.0 0:36.23 java

11314 tomcat7 20 0 1868m 667m 7664 S 0 35.0 0:03.05 java

11545 tomcat7 20 0 1868m 667m 7664 S 0 35.0 0:01.22 java

12691 tomcat7 20 0 1868m 667m 7664 S 0 35.0 0:00.01 java

11708 paul 20 0 92304 1704 800 S 0 0.1 0:00.16 sshd

1 root 20 0 24448 1980 1096 S 0 0.1 0:02.11 init

2 root 20 0 0 0 0 S 0 0.0 0:00.00 kthreadd

3 root 20 0 0 0 0 S 0 0.0 0:55.32 ksoftirqd/0

5 root 20 0 0 0 0 S 0 0.0 0:00.18 kworker/u:0

6 root RT 0 0 0 0 S 0 0.0 0:00.60 migration/0

7 root RT 0 0 0 0 S 0 0.0 24:10.46 watchdog/0

8 root RT 0 0 0 0 S 0 0.0 0:00.76 migration/1

9 root 20 0 0 0 0 S 0 0.0 0:00.00 kworker/1:0

10 root 20 0 0 0 0 S 0 0.0 0:50.36 ksoftirqd/1

For this one it shows Java at 9% usage, but it's pegged there, and only goes up... sometimes to 30%. It gets works as the day goes on. I've taken some thread dumps (kill -3 2287 in the example above). The attached catalina.out file has three (3) dumps (consecutive within a few minutes) in it.

Problem is that I don't know what all the threads are doing in there... was hoping someone more versed than me might be able to look at this and let me know if there's a problem on my end, or if there's something going on in the app that should be looked at.

Cheers,

Paul

Re: busy threads?

Submitted by tanderson on Wed, 27/11/2013 - 10:41.

I don't think the problem is related to threads. Its more likely to be related to garbage collection (GC), but its not clear from the logs what is going on.

You can get more information using the jvisualvm tool, included in the Java Development Kit (JDK) distribution in the bin directory. If you have installed the Java Runtime Environment (JRE) instead of the JRE, you can also download jvisualvm from http://visualvm.java.net/download.html

You can get a synopsis here: http://docs.oracle.com/javase/7/docs/technotes/tools/share/jvisualvm.html

Basically, you run it, and attach it to a running JVM. On the Monitor tab, you can see CPU usage vs GC and used heap over time.

To get a clearer indication of what GC is doing, install the Visual GC plugin from Tools -> Plugins -> Available Plugins. When you connect to the JVM, a Visual GC tab will be displayed that shows a breakdown of heap utilisation. An explanation can be found here: http://www.oracle.com/technetwork/java/visualgc-136680.html

Re: busy threads?

Submitted by pstadler (not verified) on Wed, 27/11/2013 - 14:09.

Installed visualvm to take a look... haven't been able to spend a lot of time with it, and ran into some issues installing the GC tool (apparently some problems w/ 1.3.2 on ubuntu 12.04). I did notice that the heap grows very quickly however. Is this expected behavior? It eventually ends up in some heap thrashing (or so it looks from the graph). This is on openjdk-6...

Cheers, Paul

Attachment	Size
Screenshot from 2013-11-26 21:29:40.png	39.38 KB
Screenshot from 2013-11-26 22:11:12.png	25.04 KB

Re: busy threads?

Submitted by tanderson on Wed, 27/11/2013 - 15:38.

125MB is pretty small heap-wise. You're reaching that limit, so its could be shedding caches to avoid OutOfMemory errors, only to have to repopulate them soon after.

Try increasing the heap size to 512MB and see if performance improves. If it quickly reaches 512MB and exhibits signs of slowdown, increase to 768MB.

You should be able to do this by creating a setenv.sh script in the tomcat bin/ directory with the following:

 export JAVA_OPTS=-Xmx512m

This script will get sourced by catalina.sh.

Note that 1.7-beta-2 will require openjdk-7.

-Tim

Re: busy threads?

Submitted by pstadler (not verified) on Wed, 27/11/2013 - 23:26.

Interesting. So it appears that the override of JAVA_OPTS in /etc/init.d/tomcat7 doesn't work. It was using the defaults even though it was set in there. The defaults are set in /etc/defaults/tomcat7, so I've just made the change there.

I had been running OpenJDK-7, but for some reason Ubuntu 12.04 LTS thinks it needs OpenJDK-6 for VisualVM... not sure why, must be a requirement for version 1.3.2 which is in the ubuntu repo for 12.04. VisualVM 1.3.3 installs w/ OpenJDK-7 for Ubuntu 13.10 which is on my test box.

Now that I've (actually) got the heap size set right I'll let it run like this for a while and see if I run into the same problem. There's a strong possibility what I was seeing was just the GC going berserk as a result of insufficient heap... so I'll just let it run like this for a while on OpenJDK-7 before I go back and inspect.

Thanks for your help!

Cheers, Paul

Tomcat heap space is critical

Submitted by tgething (not verified) on Wed, 08/01/2014 - 17:58.

This is just to add a note to this discussion to emphasise how important the Tomcat heap size is. We are a reasonably busy practice with 13 workstations. Today is day 3 of running OpenVPMS live (switching from RxWorks.) Days 1 & 2 were not good - poor response times and Tomcat running 30-40% of the CPU.

Last night Tim A pointed me at this post and suggested I look at the heap space set for Tomcat. We run a Win2003 server and I just installed Tomcat and did not worry about heap space.

In <TOMCAT_HOME>\bin there is tomcat6w.exe - I fired this and on its Java tab you can see & set the heap space. It was blank - indicating the default which I suspect is 128MB. I pushed both min and max to 1024MB and restarted Tomcat.

Wonderful - today we are zinging along.

I have no idea what we could get away with - I have not played with the jvisualvm tool. However, we are not short on memory, so I will leave it at 1024.

Moral: give Tomcat lots of memory if you are running more than a couple of workstations.

Regards, Tim G