[logback-dev] [JIRA] Created: (LBGENERAL-33) SMTPAppender_SubethaSMTPTest hang

Ralph Goers (JIRA) noreply-jira at qos.ch
Wed Oct 14 22:37:44 CEST 2009 

SMTPAppender_SubethaSMTPTest hang
---------------------------------

                 Key: LBGENERAL-33
                 URL: http://jira.qos.ch/browse/LBGENERAL-33
             Project: logback-general
          Issue Type: Sub-task
    Affects Versions: 0.9.17
         Environment: Mac OSX
            Reporter: Ralph Goers
            Assignee: Logback dev list


This test frequently waits forever waiting for a response. The jstack output follows:
2009-10-13 09:59:33
Full thread dump Java HotSpot(TM) 64-Bit Server VM (14.1-b02-90 mixed mode):

"Attach Listener" daemon prio=9 tid=0x00000001022f4800 nid=0x1150c6000 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"SocketAcceptorIoProcessor-2.0" prio=5 tid=0x000000011316f000 nid=0x115487000 runnable [0x0000000115486000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
	at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:136)
	at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:69)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
	- locked <0x00000001064d86b8> (a sun.nio.ch.Util$1)
	- locked <0x00000001064d86a0> (a java.util.Collections$UnmodifiableSet)
	- locked <0x00000001064d8340> (a sun.nio.ch.KQueueSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
	at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:480)
	at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:637)

"SocketAcceptor-2" prio=5 tid=0x0000000102196800 nid=0x114e4e000 runnable [0x0000000114e4d000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
	at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:136)
	at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:69)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
	- locked <0x0000000107ad72c0> (a sun.nio.ch.Util$1)
	- locked <0x0000000107ad72d8> (a java.util.Collections$UnmodifiableSet)
	- locked <0x0000000107aee2b8> (a sun.nio.ch.KQueueSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84)
	at org.apache.mina.transport.socket.nio.SocketAcceptor$Worker.run(SocketAcceptor.java:220)
	at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:637)

"HSQLDB Timer @e8ae59a" daemon prio=5 tid=0x0000000113421800 nid=0x114fc3000 in Object.wait() [0x0000000114fc2000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000001072e8c08> (a org.hsqldb.lib.HsqlTimer)
	at org.hsqldb.lib.HsqlTimer.nextTask(Unknown Source)
	- locked <0x00000001072e8c08> (a org.hsqldb.lib.HsqlTimer)
	at org.hsqldb.lib.HsqlTimer$TaskRunner.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:637)

"Thread-5" prio=5 tid=0x00000001023ac800 nid=0x114b1b000 runnable [0x0000000114b1a000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainDatagramSocketImpl.receive0(Native Method)
	- locked <0x00000001071a3c58> (a java.net.PlainDatagramSocketImpl)
	at java.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:136)
	- locked <0x00000001071a3c58> (a java.net.PlainDatagramSocketImpl)
	at java.net.DatagramSocket.receive(DatagramSocket.java:712)
	- locked <0x00000001071c6cd8> (a java.net.DatagramPacket)
	- locked <0x0000000107195e18> (a java.net.DatagramSocket)
	at ch.qos.logback.classic.net.mock.MockSyslogServer.run(MockSyslogServer.java:50)

"Thread-4" prio=5 tid=0x000000011321f800 nid=0x114a18000 runnable [0x0000000114a17000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainDatagramSocketImpl.receive0(Native Method)
	- locked <0x00000001071a3cb0> (a java.net.PlainDatagramSocketImpl)
	at java.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:136)
	- locked <0x00000001071a3cb0> (a java.net.PlainDatagramSocketImpl)
	at java.net.DatagramSocket.receive(DatagramSocket.java:712)
	- locked <0x00000001071c6d08> (a java.net.DatagramPacket)
	- locked <0x0000000107195e50> (a java.net.DatagramSocket)
	at ch.qos.logback.classic.net.mock.MockSyslogServer.run(MockSyslogServer.java:50)

"Thread-3" prio=5 tid=0x000000010241d800 nid=0x114915000 runnable [0x0000000114914000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainDatagramSocketImpl.receive0(Native Method)
	- locked <0x0000000107104030> (a java.net.PlainDatagramSocketImpl)
	at java.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:136)
	- locked <0x0000000107104030> (a java.net.PlainDatagramSocketImpl)
	at java.net.DatagramSocket.receive(DatagramSocket.java:712)
	- locked <0x0000000107125850> (a java.net.DatagramPacket)
	- locked <0x00000001071243f8> (a java.net.DatagramSocket)
	at ch.qos.logback.classic.net.mock.MockSyslogServer.run(MockSyslogServer.java:50)

"Thread-1" prio=5 tid=0x000000011316c000 nid=0x114703000 runnable [0x0000000114702000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainDatagramSocketImpl.receive0(Native Method)
	- locked <0x0000000107077898> (a java.net.PlainDatagramSocketImpl)
	at java.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:136)
	- locked <0x0000000107077898> (a java.net.PlainDatagramSocketImpl)
	at java.net.DatagramSocket.receive(DatagramSocket.java:712)
	- locked <0x00000001070e9668> (a java.net.DatagramPacket)
	- locked <0x00000001070f1b20> (a java.net.DatagramSocket)
	at ch.qos.logback.classic.net.mock.MockSyslogServer.run(MockSyslogServer.java:50)

"Thread-0" prio=5 tid=0x0000000113113000 nid=0x1145ed000 runnable [0x00000001145ec000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainDatagramSocketImpl.receive0(Native Method)
	- locked <0x00000001070778f0> (a java.net.PlainDatagramSocketImpl)
	at java.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:136)
	- locked <0x00000001070778f0> (a java.net.PlainDatagramSocketImpl)
	at java.net.DatagramSocket.receive(DatagramSocket.java:712)
	- locked <0x00000001070e9698> (a java.net.DatagramPacket)
	- locked <0x00000001070f1b58> (a java.net.DatagramSocket)
	at ch.qos.logback.classic.net.mock.MockSyslogServer.run(MockSyslogServer.java:50)

"Low Memory Detector" daemon prio=5 tid=0x000000010208e000 nid=0x114290000 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=9 tid=0x000000010208d800 nid=0x11418d000 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=9 tid=0x000000010208c800 nid=0x11408a000 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=9 tid=0x000000010208c000 nid=0x113f87000 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Surrogate Locker Thread (CMS)" daemon prio=5 tid=0x000000010208b000 nid=0x113e84000 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x0000000102075800 nid=0x113b07000 in Object.wait() [0x0000000113b06000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x0000000106ef0848> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
	- locked <0x0000000106ef0848> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x0000000113026000 nid=0x113a04000 in Object.wait() [0x0000000113a03000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x0000000106ef0860> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:485)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
	- locked <0x0000000106ef0860> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=0x0000000102000800 nid=0x101301000 runnable [0x00000001012fe000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at com.sun.mail.util.TraceInputStream.read(TraceInputStream.java:97)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
	- locked <0x0000000106458610> (a java.io.BufferedInputStream)
	at com.sun.mail.util.LineInputStream.readLine(LineInputStream.java:75)
	at com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1440)
	at com.sun.mail.smtp.SMTPTransport.issueSendCommand(SMTPTransport.java:1376)
	at com.sun.mail.smtp.SMTPTransport.finishData(SMTPTransport.java:1215)
	at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:586)
	- locked <0x0000000106454d10> (a com.sun.mail.smtp.SMTPTransport)
	at javax.mail.Transport.send0(Transport.java:169)
	at javax.mail.Transport.send(Transport.java:98)
	at ch.qos.logback.core.net.SMTPAppenderBase.sendBuffer(SMTPAppenderBase.java:282)
	at ch.qos.logback.core.net.SMTPAppenderBase.append(SMTPAppenderBase.java:153)
	at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:91)
	- locked <0x000000010710e350> (a ch.qos.logback.classic.net.SMTPAppender)
	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:64)
	at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:276)
	at ch.qos.logback.classic.Logger.callAppenders(Logger.java:263)
	at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:445)
	at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:399)
	at ch.qos.logback.classic.Logger.error(Logger.java:562)
	at ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest.htmlLong(SMTPAppender_SubethaSMTPTest.java:195)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.junit.internal.runners.TestMethod.invoke(TestMethod.java:59)
	at org.junit.internal.runners.MethodRoadie.runTestMethod(MethodRoadie.java:98)
	at org.junit.internal.runners.MethodRoadie$2.run(MethodRoadie.java:79)
	at org.junit.internal.runners.MethodRoadie.runBeforesThenTestThenAfters(MethodRoadie.java:87)
	at org.junit.internal.runners.MethodRoadie.runTest(MethodRoadie.java:77)
	at org.junit.internal.runners.MethodRoadie.run(MethodRoadie.java:42)
	at org.junit.internal.runners.JUnit4ClassRunner.invokeTestMethod(JUnit4ClassRunner.java:88)
	at org.junit.internal.runners.JUnit4ClassRunner.runMethods(JUnit4ClassRunner.java:51)
	at org.junit.internal.runners.JUnit4ClassRunner$1.run(JUnit4ClassRunner.java:44)
	at org.junit.internal.runners.ClassRoadie.runUnprotected(ClassRoadie.java:27)
	at org.junit.internal.runners.ClassRoadie.runProtected(ClassRoadie.java:37)
	at org.junit.internal.runners.JUnit4ClassRunner.run(JUnit4ClassRunner.java:42)
	at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:62)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
	at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338)
	at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997)

"VM Thread" prio=9 tid=0x0000000102070000 nid=0x113901000 runnable 

"Gang worker#0 (Parallel GC Threads)" prio=9 tid=0x0000000102002000 nid=0x105902000 runnable 

"Gang worker#1 (Parallel GC Threads)" prio=9 tid=0x0000000102002800 nid=0x105a05000 runnable 

"Concurrent Mark-Sweep GC Thread" prio=9 tid=0x0000000102042000 nid=0x112d9f000 runnable 
"VM Periodic Task Thread" prio=10 tid=0x000000010208f000 nid=0x114393000 waiting on condition 

"Exception Catcher Thread" prio=10 tid=0x0000000102001800 nid=0x101701000 runnable 
JNI global references: 939


-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

More information about the logback-dev mailing list