While testing my changes to logback I ran into a bit of a problem with
one of the unit tests.
ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest hangs every
time i run it. I even downloaded from your repository and tried it
with the same results. This is on my MacBook Pro.
Output from jstack.
2009-09-06 23:16:23
Full thread dump Java HotSpot(TM) 64-Bit Server VM (14.1-b02-90 mixed
mode):
"Attach Listener" daemon prio=9 tid=0x000000010217e800 nid=0x1148d2000
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"SocketAcceptorIoProcessor-2.0" prio=5 tid=0x0000000102c3e800
nid=0x114cda000 runnable [0x0000000114cd9000]
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 <0x0000000106cbd098> (a sun.nio.ch.Util$1)
- locked <0x0000000106cbd080> (a java.util.Collections$UnmodifiableSet)
- locked <0x0000000106cbcd20> (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=0x0000000102ad9800 nid=0x1146d6000
runnable [0x00000001146d5000]
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 <0x000000010897a298> (a sun.nio.ch.Util$1)
- locked <0x000000010897a2b0> (a java.util.Collections$UnmodifiableSet)
- locked <0x00000001082b1cc0> (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 @3d015a9e" daemon prio=5 tid=0x0000000102be0000
nid=0x114bd7000 in Object.wait() [0x0000000114bd6000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000001077ffd18> (a org.hsqldb.lib.HsqlTimer)
at org.hsqldb.lib.HsqlTimer.nextTask(Unknown Source)
- locked <0x00000001077ffd18> (a org.hsqldb.lib.HsqlTimer)
at org.hsqldb.lib.HsqlTimer$TaskRunner.run(Unknown Source)
at java.lang.Thread.run(Thread.java:637)
"Low Memory Detector" daemon prio=5 tid=0x0000000102025800
nid=0x114290000 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"CompilerThread1" daemon prio=9 tid=0x000000010288f000 nid=0x11418d000
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"CompilerThread0" daemon prio=9 tid=0x0000000102025000 nid=0x11408a000
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=9 tid=0x0000000102024000
nid=0x113f87000 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Surrogate Locker Thread (CMS)" daemon prio=5 tid=0x0000000102023800
nid=0x113e84000 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=8 tid=0x0000000102885800 nid=0x113b03000 in
Object.wait() [0x0000000113b02000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000001076f0848> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x00000001076f0848> (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=0x0000000102016800
nid=0x113a00000 in Object.wait() [0x00000001139ff000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000001076f7f50> (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 <0x00000001076f7f50> (a java.lang.ref.Reference$Lock)
"main" prio=5 tid=0x0000000102800800 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 <0x0000000106c839c0> (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 <0x0000000106c800c0> (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:279)
at ch.qos.logback.core.net.SMTPAppenderBase.append
(SMTPAppenderBase.java:150)
at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:87)
- locked <0x0000000107a67dc0> (a
ch.qos.logback.classic.net.SMTPAppender)
at
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders
(AppenderAttachableImpl.java:60)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:271)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:258)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend
(Logger.java:440)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:
394)
at ch.qos.logback.classic.Logger.error(Logger.java:557)
at ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest.htmlLong
(SMTPAppender_SubethaSMTPTest.java:182)
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=0x0000000102884000 nid=0x1138fd000 runnable
"Gang worker#0 (Parallel GC Threads)" prio=9 tid=0x0000000102802000
nid=0x106102000 runnable
"Gang worker#1 (Parallel GC Threads)" prio=9 tid=0x0000000102802800
nid=0x106205000 runnable
"Concurrent Mark-Sweep GC Thread" prio=9 tid=0x0000000102842000
nid=0x11359f000 runnable
"VM Periodic Task Thread" prio=10 tid=0x0000000102026800
nid=0x114393000 waiting on condition
"Exception Catcher Thread" prio=10 tid=0x0000000102801800
nid=0x101701000 runnable
JNI global references: 701
Console output:
Running ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest
TEST 23:53:02.564 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: AUTH
TEST 23:53:02.564 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: DATA
TEST 23:53:02.564 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: EHLO
TEST 23:53:02.564 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: HELO
TEST 23:53:02.564 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: HELP
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: MAIL
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: NOOP
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: QUIT
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: RCPT
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: RSET
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: STARTTLS
TEST 23:53:02.565 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: VRFY
TEST 23:53:02.659 [SocketAcceptorIoProcessor-0.0] DEBUG
o.s.smtp.server.ConnectionHandler - Active connections = 1
TEST 23:53:02.661 [SocketAcceptorIoProcessor-0.0] DEBUG
o.s.smtp.server.ConnectionHandler - SMTP connection count: 1
TEST 23:53:02.663 [SocketAcceptorIoProcessor-0.0] DEBUG
o.s.smtp.server.ConnectionHandler - S: 220 192.168.10.130 ESMTP
SubEthaSMTP
TEST 23:53:02.672 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.673 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.675 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.676 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.679 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.679 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: EHLO rgoerss-macbook-pro.local
TEST 23:53:02.680 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250-192.168.10.130
250-8BITMIME
250-STARTTLS
250 Ok
TEST 23:53:02.680 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.680 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.680 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.681 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.681 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: MAIL FROM:<[email protected]>
TEST 23:53:02.681 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:02.681 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.681 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.682 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.682 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.682 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: RCPT TO:<[email protected]>
TEST 23:53:02.683 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:02.683 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.683 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.684 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.684 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.684 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: DATA
TEST 23:53:02.684 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 354 End data with
<CR><LF>.<CR><LF>
TEST 23:53:02.684 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.684 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.685 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.690 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.692 [SubEthaSMTP Thread 1] DEBUG
org.subethamail.wiser.Wiser - Delivering new message ...
TEST 23:53:02.704 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:02.705 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.705 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.705 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.706 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.706 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: QUIT
TEST 23:53:02.706 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 221 Bye
TEST 23:53:02.707 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
TEST 23:53:02.710 [SocketAcceptorIoProcessor-0.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61067
TEST 23:53:02.714 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - Active connections = 0
TEST 23:53:02.715 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61067
[HEADER
190 [main] DEBUG test
ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest - hello
191 [main] ERROR test
ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest - en error
java.lang.Exception: an exception
at ch.qos.logback.classic.net.SMTPAppender_SubethaSMTPTest.smoke
(SMTPAppender_SubethaSMTPTest.java:122) [test-classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [na:
1.6.0_15]
at sun.reflect.NativeMethodAccessorImpl.invoke
(NativeMethodAccessorImpl.java:39) [na:1.6.0_15]
at sun.reflect.DelegatingMethodAccessorImpl.invoke
(DelegatingMethodAccessorImpl.java:25) [na:1.6.0_15]
at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_15]
at org.junit.internal.runners.TestMethod.invoke(TestMethod.java:59)
[junit-4.4.jar:na]
at org.junit.internal.runners.MethodRoadie.runTestMethod
(MethodRoadie.java:98) [junit-4.4.jar:na]
at org.junit.internal.runners.MethodRoadie$2.run(MethodRoadie.java:
79) [junit-4.4.jar:na]
at
org.junit.internal.runners.MethodRoadie.runBeforesThenTestThenAfters
(MethodRoadie.java:87) [junit-4.4.jar:na]
at org.junit.internal.runners.MethodRoadie.runTest(MethodRoadie.java:
77) [junit-4.4.jar:na]
at org.junit.internal.runners.MethodRoadie.run(MethodRoadie.java:42)
[junit-4.4.jar:na]
at org.junit.internal.runners.JUnit4ClassRunner.invokeTestMethod
(JUnit4ClassRunner.java:88) [junit-4.4.jar:na]
at org.junit.internal.runners.JUnit4ClassRunner.runMethods
(JUnit4ClassRunner.java:51) [junit-4.4.jar:na]
at org.junit.internal.runners.JUnit4ClassRunner$1.run
(JUnit4ClassRunner.java:44) [junit-4.4.jar:na]
at org.junit.internal.runners.ClassRoadie.runUnprotected
(ClassRoadie.java:27) [junit-4.4.jar:na]
at org.junit.internal.runners.ClassRoadie.runProtected
(ClassRoadie.java:37) [junit-4.4.jar:na]
at org.junit.internal.runners.JUnit4ClassRunner.run
(JUnit4ClassRunner.java:42) [junit-4.4.jar:na]
at org.apache.maven.surefire.junit4.JUnit4TestSet.execute
(JUnit4TestSet.java:62) [surefire-junit4-2.4.2.jar:2.4.2]
at
org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet
(AbstractDirectoryTestSuite.java:140) [surefire-api-2.4.2.jar:2.1]
at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute
(AbstractDirectoryTestSuite.java:127) [surefire-api-2.4.2.jar:2.1]
at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
[surefire-api-2.4.2.jar:2.1]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [na:
1.6.0_15]
at sun.reflect.NativeMethodAccessorImpl.invoke
(NativeMethodAccessorImpl.java:39) [na:1.6.0_15]
at sun.reflect.DelegatingMethodAccessorImpl.invoke
(DelegatingMethodAccessorImpl.java:25) [na:1.6.0_15]
at java.lang.reflect.Method.invoke(Method.java:597) [na:1.6.0_15]
at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess
(SurefireBooter.java:338) [surefire-booter-2.4.2.jar:na]
at org.apache.maven.surefire.booter.SurefireBooter.main
(SurefireBooter.java:997) [surefire-booter-2.4.2.jar:na]
FOOTER
TEST 23:53:02.726 [main] INFO o.subethamail.smtp.server.SMTPServer -
SMTP Server socket shut down.
TEST 23:53:02.743 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: AUTH
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: DATA
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: EHLO
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: HELO
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: HELP
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: MAIL
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: NOOP
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: QUIT
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: RCPT
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: RSET
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: STARTTLS
TEST 23:53:02.745 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: VRFY
TEST 23:53:02.763 [SocketAcceptorIoProcessor-1.0] DEBUG
o.s.smtp.server.ConnectionHandler - Active connections = 1
TEST 23:53:02.763 [SocketAcceptorIoProcessor-1.0] DEBUG
o.s.smtp.server.ConnectionHandler - SMTP connection count: 1
TEST 23:53:02.763 [SocketAcceptorIoProcessor-1.0] DEBUG
o.s.smtp.server.ConnectionHandler - S: 220 192.168.10.130 ESMTP
SubEthaSMTP
TEST 23:53:02.774 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.778 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: EHLO rgoerss-macbook-pro.local
TEST 23:53:02.778 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250-192.168.10.130
250-8BITMIME
250-STARTTLS
250 Ok
TEST 23:53:02.778 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.779 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.779 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.779 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.780 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: MAIL FROM:<[email protected]>
TEST 23:53:02.780 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:02.780 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.780 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.780 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.780 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.783 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: RCPT TO:<[email protected]>
TEST 23:53:02.784 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:02.784 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.784 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.784 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.784 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.784 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: DATA
TEST 23:53:02.784 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 354 End data with
<CR><LF>.<CR><LF>
TEST 23:53:02.785 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.785 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.785 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.796 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.796 [SubEthaSMTP Thread 1] DEBUG
org.subethamail.wiser.Wiser - Delivering new message ...
TEST 23:53:02.796 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:02.796 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.798 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.806 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.807 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.807 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: QUIT
TEST 23:53:02.807 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 221 Bye
TEST 23:53:02.808 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.808 [SocketAcceptorIoProcessor-1.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61068
TEST 23:53:02.809 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - Active connections = 0
TEST 23:53:02.810 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61068
TEST 23:53:02.918 [main] INFO o.subethamail.smtp.server.SMTPServer -
SMTP Server socket shut down.
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: AUTH
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: DATA
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: EHLO
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: HELO
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: HELP
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: MAIL
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: NOOP
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: QUIT
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: RCPT
TEST 23:53:02.923 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: RSET
TEST 23:53:02.924 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: STARTTLS
TEST 23:53:02.924 [main] DEBUG o.s.smtp.server.CommandHandler - Added
command: VRFY
TEST 23:53:03.073 [SocketAcceptorIoProcessor-2.0] DEBUG
o.s.smtp.server.ConnectionHandler - Active connections = 1
TEST 23:53:03.073 [SocketAcceptorIoProcessor-2.0] DEBUG
o.s.smtp.server.ConnectionHandler - SMTP connection count: 1
TEST 23:53:03.074 [SocketAcceptorIoProcessor-2.0] DEBUG
o.s.smtp.server.ConnectionHandler - S: 220 192.168.10.130 ESMTP
SubEthaSMTP
TEST 23:53:03.074 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.074 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.074 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.075 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.075 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.076 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: EHLO rgoerss-macbook-pro.local
TEST 23:53:03.076 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250-192.168.10.130
250-8BITMIME
250-STARTTLS
250 Ok
TEST 23:53:03.076 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.077 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.077 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.077 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.077 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: MAIL FROM:<[email protected]>
TEST 23:53:03.077 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:03.077 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.078 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.078 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.078 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.078 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: RCPT TO:<[email protected]>
TEST 23:53:03.078 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 250 Ok
TEST 23:53:03.078 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.079 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.079 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - C: DATA
TEST 23:53:03.079 [SubEthaSMTP Thread 1] DEBUG
o.s.smtp.server.ConnectionHandler - S: 354 End data with
<CR><LF>.<CR><LF>
TEST 23:53:03.080 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
TEST 23:53:03.080 [SocketAcceptorIoProcessor-2.0] DEBUG
o.a.m.filter.executor.ExecutorFilter - Launching thread for /
127.0.0.1:61069
TEST 23:53:03.080 [SubEthaSMTP Thread 1] DEBUG
o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty
for /127.0.0.1:61069
^CDestroying 1 processes
Destroying process..
Destroyed 1 processes
_______________________________________________
logback-dev mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-dev
