Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Log4j is hanging my application what am I doing wrong?

Tags:

First some background on the application. I have an application processing many independent tasks in parallel via a thread pool. The thread pool is now hanging.

The following is an snippet from my thread dumps, all my Threads in pool-2 are BLOCKED by "pool-2-thread-78". It seems to be locked trying to write to the console which I find extremely odd. Can anyone shed any light on the situation for me?

EDIT: Platform details java version "1.6.0_07" Java(TM) SE Runtime Environment (build 1.6.0_07-b06) Java HotSpot(TM) Client VM (build 10.0-b23, mixed mode, sharing)

Ubuntu Linux server dual quad core machine.

It seems to lock when writing to the printstream, I have considered just removing the console appender however I would rather know why it is blocking and remove it based on this knowledge. In the past the remove and see if it works has come back to bite me :)

relevant section from my log4j

log4j.rootLogger=DEBUG, STDOUT log4j.logger.com.blah=INFO, LOG log4j.appender.STDOUT=org.apache.log4j.ConsoleAppender log4j.appender.LOG=org.apache.log4j.FileAppender

Thread dump extract

"pool-2-thread-79" Id=149 BLOCKED on org.apache.log4j.spi.RootLogger@6c3ba437 owned by "pool-2-thread-78" Id=148 at org.apache.log4j.Category.callAppenders(Category.java:201) at org.apache.log4j.Category.forcedLog(Category.java:388) at org.apache.log4j.Category.error(Category.java:302) at com.blah.MessageProcessTask.run(MessageProcessTask.java:103) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask/java:268) at java.util.concurrent.FutureTask.run(FutureTask/java:54) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619)

"pool-2-thread-78" Id=148 RUNNABLE at java.io.FileOutputStream.writeBytes(Native Method) at java.io.FileOutputStream.write(FileOutputStream.java:260) at java.io.BufferedOutputStream.write(BufferedOutputStream.java:105) - locked <0x6f314ba4> (a java.io.BufferedOutputStream) at java.io.PrintStream.write(PrintStream.java:430) - locked <0xd5d3504> (a java.io.PrintStream) at org.apache.log4j.ConsoleAppender$SystemOutStream.write(ConsoleAppender.java:173) at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202) at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272) at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:276) at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:122) - locked <0x6243a076> (a java.io.OutputStreamWriter) at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:212) at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:57) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:315) at org.apache.log4j.WriterAppender.append(WriterAppender.java:159) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:230) - locked <0x45dbd560> (a org.apache.log4j.ConsoleAppender) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:65) at org.apache.log4j.Category.callAppenders(Category.java:203) - locked <0x6c3ba437> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:388) at org.apache.log4j.Category.error(Category.java:302) at com.blah.MessageProcessTask.run(MessageProcessTask.java:103) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask/java:268) at java.util.concurrent.FutureTask.run(FutureTask/java:54) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619)