3

I have a Java program that at some point turns into 100% CPU usage and sleep state at the same time. The program is not multithreaded.

Looking around, I think the most likely cause for that is a bug or some mismatch in the way I run the java interpreter with respect to garbage collection. I can only think that the 100% CPU usage is because of GC. I am allocating enough memory for the program to run using Xmx, and the program does not run even near the amount I allocate. The amount I allocate is also much less than the total memory available on the machine.

I found this:

http://code.google.com/p/spymemcached/issues/detail?id=279

There were also some mentions of that on stackoverflow.com such as here:

CMS garbage collector - when does it run?

Still, I couldn't find a solution. Is this a bug in the JVM, and if so, how would I fix it?

EDIT: I added a paste of the jstack output here: http://pastebin.com/Au0V9FCN

Community
  • 1
  • 1
kloop
  • 4,537
  • 13
  • 42
  • 66
  • Get a stack dump with `jstack` to see what is going on there. Does the 100% usage go down after a while? – Thilo Sep 20 '13 at 06:28
  • Then do get the jstack output. – Thilo Sep 20 '13 at 06:29
  • 2
    Can you reproduce the issue with a simple program that you could show in your post? Do you monitor GC (with verbose:gc)? – assylias Sep 20 '13 at 06:31
  • if you stop your program execution does it cpu goes down at normal performance? – Ankur Loriya Sep 20 '13 at 06:32
  • @Thilo, waiting for it to get stuck again, and then will run it. – kloop Sep 20 '13 at 06:35
  • @assylias I didn't know about monitor the gc, but I added a stack there from jstack in my edit. I am not sure how to reproduce this issue with a small example, this is really esoteric for me... – kloop Sep 20 '13 at 06:45
  • @AnkurLoriya yes, it does go down to normal performance. – kloop Sep 20 '13 at 06:45
  • @Thilo not sure how to interpret the jstack output (appears in the edit). There are some threads in waiting state, and the main thread seems to sleep in a println, which is strange to me... – kloop Sep 20 '13 at 06:47
  • Forgot to say, better take two jstacks a few seconds apart to see which threads are still moving along. From the one you posted the program seems to be busy with "corejava.Format.expFormat" whatever that is (or somewhere up the stack with your application code). – Thilo Sep 20 '13 at 06:56
  • @Thilo, I will run jstack again, but I aborted the program, so I have to wait for it to reach the same problem again. May take a bit. Thanks for your patience. – kloop Sep 20 '13 at 07:06
  • Have you added the verbose GC flag when running your program to see if that is the issue? – assylias Sep 20 '13 at 07:22
  • @Thilo I did jstack with 10 seconds intervals, they all get stuck in the same place, diff does not show any differences between the outputs other than time / date. – kloop Sep 20 '13 at 08:41
  • @assylias I am running it again with verbose:gc, will update. – kloop Sep 20 '13 at 08:42
  • 1
    then it looks like you have some problem in your code there. That is an application thread that is not moving along anymore, right? – Thilo Sep 20 '13 at 08:43
  • mmm... that's an internal toString command that it hangs on... how could it be a problem with my code? there is a single thread, and yes, it hangs there – kloop Sep 20 '13 at 08:48
  • If you are calling toString() a lot e.g. in a debug message you are not actually displaying, this can cause one thread to consume 100% of CPU. – Peter Lawrey Sep 23 '13 at 19:29
  • Could it be just a big 3D-matrix problem resulting into many String concatenations and/or throttling output? – Andrey Chaschev Sep 23 '13 at 21:12

1 Answers1

3

Reproduce your issue, and when you see CPU is saturated perform JSTACK dumps on your Java process and use an OS utility to capture Process CPU and its threads CPU break down (ps -L in linux). You should actually setup a script that does this about 10 or 20 times 1 sec spaced samplings.

After this, if you are running on linux, you can cross reference the LWPid's with JSTACK output, just convert LWPID from ps -L to hex and you should be good to go on JSTACK's output.

At this point you will get a clear idea on what is consuming CPU on your app.

If GC is the problem then you will see the GC Threads hogging the CPU, at this point JConsole will be helpful in identifying further root cause. Otherwise you will notice clearly who is responsible for CPU consumption and you can act accordingly.

P.S. My examples are on linux, if you are not running linux you can google up ways to get process CPU break down dumps.

Do let me know what you find out.

bubooal
  • 621
  • 3
  • 8