3

This one is baffling. All of a sudden we've started experiencing a situation where all threads in a Java process reach a BLOCKED state and the process is completely frozen. There's no jvm.log or hs*.log file to point to what's going on.

A jstack dump lists many threads, all in BLOCKED state, some of them as baffling as this:

Thread 14766: (state = BLOCKED)
- java.lang.String.substring(int, int) @bci=62, line=1939 (Compiled frame)
- java.util.Formatter.parse(java.lang.String) @bci=73, line=2469 (Compiled frame)
- java.util.Formatter.format(java.util.Locale, java.lang.String, java.lang.Object[]) @bci=213, line=2438 (Compiled frame)
- java.util.Formatter.format(java.lang.String, java.lang.Object[]) @bci=7, line=2367 (Compiled frame)
- java.lang.String.format(java.lang.String, java.lang.Object[]) @bci=9, line=2769 (Compiled frame)

(cropped the rest)

Or this:

Thread 14794: (state = BLOCKED)
- java.lang.Throwable.toString() @bci=17, line=344 (Interpreted frame)
- java.lang.String.valueOf(java.lang.Object) @bci=10, line=2826 (Compiled frame)
- java.io.PrintWriter.println(java.lang.Object) @bci=1, line=710 (Interpreted frame)
- java.lang.Throwable.printStackTrace(java.io.PrintWriter) @bci=6, line=509 (Compiled frame)
- org.apache.log4j.DefaultThrowableRenderer.render(java.lang.Throwable) @bci=19, line=60 (Compiled frame)
- org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep() @bci=50, line=87 (Interpreted frame)
- org.apache.log4j.spi.LoggingEvent.getThrowableStrRep() @bci=13, line=413 (Compiled frame)
- org.apache.log4j.WriterAppender.subAppend(org.apache.log4j.spi.LoggingEvent) @bci=26, line=313 (Compiled frame)
- org.apache.log4j.RollingFileAppender.subAppend(org.apache.log4j.spi.LoggingEvent) @bci=2, line=276 (Interpreted frame)
- org.apache.log4j.WriterAppender.append(org.apache.log4j.spi.LoggingEvent) @bci=10, line=162 (Compiled frame)
- org.apache.log4j.AppenderSkeleton.doAppend(org.apache.log4j.spi.LoggingEvent) @bci=106, line=251 (Compiled frame)
- org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(org.apache.log4j.spi.LoggingEvent) @bci=41, line=66 (Compiled frame)
- org.apache.log4j.Category.callAppenders(org.apache.log4j.spi.LoggingEvent) @bci=26, line=206 (Compiled frame)
- org.apache.log4j.Category.forcedLog(java.lang.String, org.apache.log4j.Priority, java.lang.Object, java.lang.Throwable) @bci=14, line=391 (Interpreted frame)
- org.apache.log4j.Category.error(java.lang.Object, java.lang.Throwable) @bci=37, line=322 (Interpreted frame)

(cropped the rest)

I must admit that while I've tried to search for a cause online, I don't know where to begin looking for it.

This is happening under jdk1.6.0_31

Gabe
  • 84,912
  • 12
  • 139
  • 238
Yon
  • 1,023
  • 4
  • 13
  • 23
  • 3
    Welcome to the wonderful world of multithreaded programming: https://en.wikipedia.org/wiki/Deadlock – ebo Apr 03 '12 at 11:46
  • check it for deadlock in an IDE, wherein you can view each thread's execution. How many threads are running? got enough memory? – Ashok Raj Apr 03 '12 at 11:48
  • Similar situation in this log it seems: http://issues.hudson-ci.org/secure/attachment/19564/trace.log – aioobe Apr 03 '12 at 11:53
  • Why would there be a deadlock in Throwable.toString() and String.substring(int,int) – Yon Apr 03 '12 at 12:12
  • @aioobe Yes that looks similar, any idea what's going on? – Yon Apr 03 '12 at 12:16

4 Answers4

3

Are they all blocked in string operations? Have you run out of heap perm gen space maybe (do a 'jstat -gc' on the hung process)

vladimir e.
  • 723
  • 3
  • 7
  • Result of jstat: S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT 40000.0 36928.0 9345.7 0.0 557952.0 518204.3 1271808.0 339799.0 145408.0 144225.6 1254 68.950 403 1281.828 1350.778 Looks like there may be an issue of perm space indeed. – Yon Apr 03 '12 at 13:08
  • However, max perm size is set to "-XX:MaxPermSize=192m". So why is only 140mb or so available? – Yon Apr 03 '12 at 13:10
  • Well it may be trying to grow it and hitting some other limit. As I understand it -Xmx (max heap size) is the max for combined young and old generations and perm gen space is in addition to that, so that should not be limiting factor. But then JVM has always seemed to behave bit strangely when perm gen fills up, so maybe try setting a fixed, larger size (-XX:PermSize=192m). Could also try turning on perm gen collecting using CMS collector. – vladimir e. Apr 03 '12 at 13:43
  • -XX:+UseConcMarkSweepGC -XX:+CMSPermGenSweepingEnabled -XX:+CMSClassUnloadingEnabled – vladimir e. Apr 03 '12 at 13:45
  • are you running on 32bit OS? could be the 3GB process VM limit – vladimir e. Apr 03 '12 at 14:02
  • It's a 64-bit OS. Why would there be a need to set the PermSize if the MaxSize is already set to 192? – Yon Apr 03 '12 at 14:11
  • I don't know - but I have seen strange behaviour with perm gen when it fills up so I think it might be worth a go – vladimir e. Apr 03 '12 at 14:13
  • You can see this here: PGCMN PGCMX PGC PC YGC FGC FGCT GCT 22528.0 196608.0 131072.0 131072.0 426 263 741.838 754.752 – Yon Apr 03 '12 at 14:24
  • This is what we're getting from with the gcutil option, looks like it's a garbage collection (Eden space) that's locking it all down: S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 0.00 100.00 96.82 99.98 426 12.914 297 877.414 890.328 – Yon Apr 03 '12 at 14:29
  • Apparently the issue was that Eden was filling up quickly and the GC kept running endlessly because of a loop that was generating Strings like crazy. – Yon Apr 03 '12 at 17:17
0

This part of exception:

org.apache.log4j.Category.callAppenders(org.apache.log4j.spi.LoggingEvent) @bci=26, line=206 (Compiled frame)
org.apache.log4j.Category.forcedLog(java.lang.String, org.apache.log4j.Priority, java.lang.Object, java.lang.Throwable) @bci=14, line=391 (Interpreted frame)
org.apache.log4j.Category.error(java.lang.Object, java.lang.Throwable) @bci=37, line=322 (Interpreted frame)

Probably, it is related to a bug in log4j. Have a look at the following webpage:

https://issues.apache.org/bugzilla/show_bug.cgi?id=41214

Marcelo
  • 1,471
  • 3
  • 19
  • 22
Bug Bug
  • 1
0

What is the OS? Multithreading issues are many times OS dependent since their implementation is OS specific. Java threads are just an abstraction of OS threading.

/Koya

randominstanceOfLivingThing
  • 16,873
  • 13
  • 49
  • 72
0

I would run the program with -verbosegc. It appears to be blocked waiting for some free space.

Peter Lawrey
  • 525,659
  • 79
  • 751
  • 1,130