[ http://jira.qos.ch/browse/LBCLASSIC-207?page=com.atlassian.jira.plugin.syste... ] Joern Huxhorn updated LBCLASSIC-207: ------------------------------------ Attachment: LoggingEventVOSerializationTest.java I have written a small test that will currently fail but shouldn't. Expected :[Three, Four, Five] Actual :[Ljava.lang.String;@377653ae I still have serious problems building Logback, though. SMTPAppender_SubethaSMTPTest still hangs (ThreadDump below) and TimeBasedRollingWithArchiveRemovalTest failed once with a Timeout, too. TEST 14:48:28.537 [SubEthaSMTP Thread 1] DEBUG o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty for /127.0.0.1:56367 TEST 14:48:28.537 [SocketAcceptorIoProcessor-2.0] DEBUG o.a.m.filter.executor.ExecutorFilter - Launching thread for /127.0.0.1:56367 TEST 14:48:28.537 [SubEthaSMTP Thread 1] DEBUG o.a.m.filter.executor.ExecutorFilter - Exiting since queue is empty for /127.0.0.1:56367 Full thread dump Java HotSpot(TM) 64-Bit Server VM (14.3-b01-101 mixed mode): "SocketAcceptorIoProcessor-2.0" prio=5 tid=0x000000010674f000 nid=0x114e5d000 runnable [0x0000000114e5c000] 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 <0x00000001069822b0> (a sun.nio.ch.Util$1) - locked <0x0000000106982298> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000106981f38> (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=0x0000000102578800 nid=0x114b54000 runnable [0x0000000114b53000] 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 <0x00000001077a0150> (a sun.nio.ch.Util$1) - locked <0x00000001077a0168> (a java.util.Collections$UnmodifiableSet) - locked <0x00000001077a00d8> (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) "Low Memory Detector" daemon prio=5 tid=0x0000000102021000 nid=0x114290000 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "CompilerThread1" daemon prio=9 tid=0x0000000106093000 nid=0x11418d000 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "CompilerThread0" daemon prio=9 tid=0x0000000106092800 nid=0x11408a000 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=9 tid=0x0000000106091800 nid=0x113f87000 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Surrogate Locker Thread (CMS)" daemon prio=5 tid=0x0000000106091000 nid=0x113e84000 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=8 tid=0x000000010607b000 nid=0x113bf8000 in Object.wait() [0x0000000113bf7000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000107cc4b50> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) - locked <0x0000000107cc4b50> (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=0x000000010607a800 nid=0x113af5000 in Object.wait() [0x0000000113af4000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000107cc0018> (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 <0x0000000107cc0018> (a java.lang.ref.Reference$Lock) "main" prio=5 tid=0x0000000102000800 nid=0x100501000 runnable [0x00000001004fe000] 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 <0x000000010690fd18> (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 <0x000000010690c418> (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:292) at ch.qos.logback.core.net.SMTPAppenderBase.append(SMTPAppenderBase.java:159) at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:85) - locked <0x00000001077a04c0> (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:283) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:270) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:471) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:425) at ch.qos.logback.classic.Logger.error(Logger.java:588) 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.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) 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:345) at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:1009) "VM Thread" prio=9 tid=0x0000000102020800 nid=0x105f5c000 runnable "Gang worker#0 (Parallel GC Threads)" prio=9 tid=0x0000000106000000 nid=0x105a05000 runnable "Gang worker#1 (Parallel GC Threads)" prio=9 tid=0x0000000106001000 nid=0x105b08000 runnable "Concurrent Mark-Sweep GC Thread" prio=9 tid=0x0000000106040000 nid=0x105e59000 runnable "VM Periodic Task Thread" prio=10 tid=0x0000000102022000 nid=0x114393000 waiting on condition "Exception Catcher Thread" prio=10 tid=0x0000000102001800 nid=0x102901000 runnable JNI global references: 938 Heap par new generation total 18624K, used 3939K [0x0000000106800000, 0x0000000107cc0000, 0x0000000107cc0000) eden space 16000K, 17% used [0x0000000106800000, 0x0000000106ab73e0, 0x00000001077a0000) from space 2624K, 44% used [0x00000001077a0000, 0x00000001078c1938, 0x0000000107a30000) to space 2624K, 0% used [0x0000000107a30000, 0x0000000107a30000, 0x0000000107cc0000) concurrent mark-sweep generation total 62656K, used 4194K [0x0000000107cc0000, 0x000000010b9f0000, 0x000000010bc00000) concurrent-mark-sweep perm gen total 35236K, used 21273K [0x000000010bc00000, 0x000000010de69000, 0x0000000111000000)
LoggingEventVO is using a simply toString during serialization, fumbling with arrays. -------------------------------------------------------------------------------------
Key: LBCLASSIC-207 URL: http://jira.qos.ch/browse/LBCLASSIC-207 Project: logback-classic Issue Type: Bug Components: appender Affects Versions: 0.9.20 Reporter: Joern Huxhorn Assignee: Logback dev list Attachments: LoggingEventVOSerializationTest.java
Any array used as parameter shows up unreadable. It should instead use the same toString logic used by MessageFormatter. I'd have submitted a patch/branch for this issue but - unfortunately - SLF4J MessageFormatter does not have a method that's performing just the String conversion. Please see http://github.com/huxi/lilith/blob/master/lilith-data/logging/src/main/java/... especially the method String deepToString(Object o) Because of this, a fix (providing and using said method) would span over both SLF4J and Logback.
-- 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