Which JDK are you running? Which exact CPU? On 16.04.2013 23:07, Broc Seib wrote:
Hi Carl and Ceki,
I grabbed 3727d7ff0fd33a9584a9ba0ef0369506fa8f562e right after Carl committed it.
$ git log -1 commit 3727d7ff0fd33a9584a9ba0ef0369506fa8f562e Author: Carl Harris <ceharris@vt.edu <mailto:ceharris@vt.edu>> Date: Tue Apr 16 14:43:35 2013 -0400
removed an unused import to silence a build warning in eclipse
I believe Carl's patch addressed the previous problem I was seeing. But I still have some mixed results getting a clean build. When I first ran 'mvn clean; mvn install' I got an error in Logback Core Module, in ch.qos.logback.core.appender.FileAppenderTest. But when I did 'mvn clean; mvn install' again, FileAppenderTest worked fine. (Failed surefire-report included below.)
After Logback Core built, Logback Access Module build fails. See the test set for ch.qos.logback.access.db.DBAppenderHSQLTest below.
------------------------------------------------------------------------------- Test set: ch.qos.logback.core.appender.FileAppenderTest ------------------------------------------------------------------------------- Tests run: 6, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.079 sec <<< FAILURE! testCreateParentFolders(ch.qos.logback.core.appender.FileAppenderTest) Time elapsed: 0.001 sec <<< FAILURE! java.lang.AssertionError: failed to delete C:\gitrepo\logback\logback-core\target\test-output\fat992837029 at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at ch.qos.logback.core.appender.FileAppenderTest.testCreateParentFolders(FileAppenderTest.java:93) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:24) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)
smoke(ch.qos.logback.core.appender.FileAppenderTest) Time elapsed: 0.049 sec testPrudentModeLogicalImplications(ch.qos.logback.core.appender.FileAppenderTest) Time elapsed: 0.02 sec testNewAppender(ch.qos.logback.core.appender.FileAppenderTest) Time elapsed: 0 sec testConfiguredAppender(ch.qos.logback.core.appender.FileAppenderTest) Time elapsed: 0.002 sec testNoStart(ch.qos.logback.core.appender.FileAppenderTest) Time elapsed: 0.001 sec
------------------------------------------------------------------------------- Test set: ch.qos.logback.access.db.DBAppenderHSQLTest ------------------------------------------------------------------------------- Tests run: 4, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.207 sec <<< FAILURE! testAppendAccessEvent(ch.qos.logback.access.db.DBAppenderHSQLTest) Time elapsed: 0.026 sec testAppendHeaders(ch.qos.logback.access.db.DBAppenderHSQLTest) Time elapsed: 0.006 sec testAppendMultipleEvents(ch.qos.logback.access.db.DBAppenderHSQLTest) Time elapsed: 0.022 sec testCheckNoHeadersAreInserted(ch.qos.logback.access.db.DBAppenderHSQLTest) Time elapsed: 0.009 sec <<< FAILURE! java.lang.AssertionError at org.junit.Assert.fail(Assert.java:92) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertFalse(Assert.java:68) at org.junit.Assert.assertFalse(Assert.java:79) at ch.qos.logback.access.db.DBAppenderHSQLTest.testCheckNoHeadersAreInserted(DBAppenderHSQLTest.java:148) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) 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:30) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:30) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189) at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165) at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
On Tue, Apr 16, 2013 at 2:48 PM, Harris, Carl <ceharris@vt.edu <mailto:ceharris@vt.edu>> wrote:
Last couple of commits should help reduce timing sensitivity in the SocketConnectorBaseTest and SocketAppenderTest. Anxious to hear if this improves matters for you Broc.
carl
On Apr 16, 2013, at 2:00 PM, Broc Seib wrote:
Here it is:
------------------------------------------------------------------------------- Test set: ch.qos.logback.core.net.SocketConnectorBaseTest ------------------------------------------------------------------------------- Tests run: 3, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 5.596 sec <<< FAILURE! testConnect(ch.qos.logback.core.net.SocketConnectorBaseTest) Time elapsed: 0.081 sec testConnectEventually(ch.qos.logback.core.net.SocketConnectorBaseTest) Time elapsed: 2.514 sec testConnectionFails(ch.qos.logback.core.net.SocketConnectorBaseTest) Time elapsed: 0.001 sec <<< FAILURE! java.lang.AssertionError at org.junit.Assert.fail(Assert.java:92) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertFalse(Assert.java:68) at org.junit.Assert.assertFalse(Assert.java:79) at ch.qos.logback.core.net.SocketConnectorBaseTest.testConnectionFails(SocketConnectorBaseTest.java:89) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) 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:30) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:24) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)
On Tue, Apr 16, 2013 at 1:56 PM, Harris, Carl <ceharris@vt.edu <mailto:ceharris@vt.edu><mailto:ceharris@vt.edu <mailto:ceharris@vt.edu>>> wrote: Broc,
Would you please send the surefire-report for the test ch.qos.logback.core.net.SocketConnectorBaseTest, so I can take a look to see where/why it is failing?
logback-core/target/surefire-reports/ch.qos.logback.core.net.SocketConnectorBaseTest.txt
Thanks,
carl
On Apr 16, 2013, at 1:02 PM, Broc Seib wrote:
Hi Ceki,
I just updated to the latest code you just committed, 56e8ab2192697bc27a8cfbd8441db62aff53e87c but I think there is a different problem now.
bseib@BSEIB-WIN7 /c/gitrepo $ rm -rf logback
bseib@BSEIB-WIN7 /c/gitrepo $ git clone https://github.com/qos-ch/logback.git Cloning into 'logback'... remote: Counting objects: 52855, done. remote: Compressing objects: 100% (13701/13701), done. remote: Total 52855 (delta 26607), reused 52138 (delta 26038) Receiving objects: 100% (52855/52855), 20.13 MiB | 1.17 MiB/s, done. Resolving deltas: 100% (26607/26607), done.
bseib@BSEIB-WIN7 /c/gitrepo $ cd logback/
bseib@BSEIB-WIN7 /c/gitrepo/logback (master) $ git log -1 commit 56e8ab2192697bc27a8cfbd8441db62aff53e87c Merge: 2ff61c7 513e380 Author: Ceki Gulcu <ceki@qos.ch <mailto:ceki@qos.ch><mailto:ceki@qos.ch <mailto:ceki@qos.ch>><mailto:ceki@qos.ch <mailto:ceki@qos.ch><mailto:ceki@qos.ch <mailto:ceki@qos.ch>>>> Date: Tue Apr 16 18:09:23 2013 +0200
Merge branch 'master' of github.com:qos-ch/logback
And then 'mvn clean; mvn install':
[...] Running ch.qos.logback.core.joran.conditional.IfThenElseAndIncludeCompositionTest Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.635 sec includeNestedWithinIf(ch.qos.logback.core.joran.conditional.IfThenElseAndIncludeCompositionTest) Time elapsed: 0.635 sec
Results :
Failed tests: testConnectionFails(ch.qos.logback.core.net.SocketConnectorBaseTest)
lossyAppenderShouldOnlyLooseCertainEvents(ch.qos.logback.core.AsyncAppenderBaseTest): expected:<8> but was:<10>
Tests run: 424, Failures: 2, Errors: 0, Skipped: 6
[INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary: [INFO] [INFO] Logback-Parent .................................... SUCCESS [0.244s] [INFO] Logback Core Module ............................... FAILURE [27.251s] [INFO] Logback Classic Module ............................ SKIPPED [INFO] Logback Access Module ............................. SKIPPED [INFO] Logback Site ...................................... SKIPPED [INFO] Logback Examples Module ........................... SKIPPED [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 28.014s [INFO] Finished at: Tue Apr 16 12:51:50 EDT 2013 [INFO] Final Memory: 28M/308M [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on project logback-core: There are test failures.
On Tue, Apr 16, 2013 at 12:42 PM, ceki <ceki@qos.ch <mailto:ceki@qos.ch><mailto:ceki@qos.ch <mailto:ceki@qos.ch>><mailto:ceki@qos.ch <mailto:ceki@qos.ch><mailto:ceki@qos.ch <mailto:ceki@qos.ch>>>> wrote:
I am hoping that commit [1] should make the test failures in logback-core/src/test/java/ch/qos/logback/core/rolling disappear.
[1] https://github.com/qos-ch/logback/commit/2ff61c7c1cb0562
On 16.04.2013 06:05, Broc Seib wrote: Yes, I've done "mvn clean; mvn install" but still get a failure. I'm also on a 3.4GHz Win7 box with a SSD. Is there any possibility of a timing sensitivity for being "too fast"?
Tests run: 7, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.557 sec <<< FA ILURE! withZipCompression_FileSet_NoRestart_7(ch.qos.logback.core.rolling.SizeAndTimeBa sedFNATP_Test) Time elapsed: 0.201 sec withGZCompression_FileBlank_NoRestart_6(ch.qos.logback.core.rolling.SizeAndTimeB asedFNATP_Test) Time elapsed: 0.006 sec <<< ERROR! java.io.FileNotFoundException: target\test-output\910764289\test6-2013-04-15_23_ 47_35-1.txt (The system cannot find the file specified) at java.io.FileInputStream.open(Native Method) at java.io.FileInputStream.<init>(FileInputStream.java:138) at ch.qos.logback.core.testUtil.FileToBufferUtil.regularReadIntoList(Fil eToBufferUtil.java:60) at ch.qos.logback.core.testUtil.FileToBufferUtil.readIntoList(FileToBuff erUtil.java:38) at ch.qos.logback.core.rolling.ScaffoldingForRollingTests.fileContentChe ck(ScaffoldingForRollingTests.java:84) at ch.qos.logback.core.rolling.ScaffoldingForRollingTests.sortedContentC heck(ScaffoldingForRollingTests.java:99) at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP_Test.generic(SizeAn dTimeBasedFNATP_Test.java:130) at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP_Test.withGZCompress ion_FileBlank_NoRestart_6(SizeAndTimeBasedFNATP_Test.java:189) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framework Method.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCal lable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMe thod.java:42) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMet hod.java:20) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores. java:28) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRun ner.java:68) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRun ner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:24) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:47 1) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor. java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor .java:603) at java.lang.Thread.run(Thread.java:722)
withGZCompression_FileSet_NoRestart_5(ch.qos.logback.core.rolling.SizeAndTimeBas edFNATP_Test) Time elapsed: 0.067 sec noCompression_FileSet_WithStopStart_4(ch.qos.logback.core.rolling.SizeAndTimeBas edFNATP_Test) Time elapsed: 0.102 sec noCompression_FileBlank_WithStopStart_3(ch.qos.logback.core.rolling.SizeAndTimeB asedFNATP_Test) Time elapsed: 0.061 sec noCompression_FileBlank_NoRestart_2(ch.qos.logback.core.rolling.SizeAndTimeBased FNATP_Test) Time elapsed: 0.036 sec noCompression_FileSet_NoRestart_1(ch.qos.logback.core.rolling.SizeAndTimeBasedFN ATP_Test) Time elapsed: 0.039 sec Running ch.qos.logback.core.recovery.ResilientOutputStreamTest Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.288 sec verifyRecuperationAfterFailure(ch.qos.logback.core.recovery.ResilientOutputStrea mTest) Time elapsed: 0.288 sec Running ch.qos.logback.core.rolling.helper.CompressTest Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.253 sec test2(ch.qos.logback.core.rolling.helper.CompressTest) Time elapsed: 0.223 sec test1(ch.qos.logback.core.rolling.helper.CompressTest) Time elapsed: 0.018 sec test3(ch.qos.logback.core.rolling.helper.CompressTest) Time elapsed: 0.012 sec
Results :
Tests in error:
withGZCompression_FileBlank_NoRestart_6(ch.qos.logback.core.rolling.SizeAndTim eBasedFNATP_Test): target\test-output\910764289\test6-2013-04-15_23_47_35-1.txt (The system cannot find the file specified)
Tests run: 424, Failures: 0, Errors: 1, Skipped: 6
[INFO] ------------------------------------------------------------------------ [INFO] Reactor Summary: [INFO] [INFO] Logback-Parent .................................... SUCCESS [0.338s] [INFO] Logback Core Module ............................... FAILURE [28.279s] [INFO] Logback Classic Module ............................ SKIPPED [INFO] Logback Access Module ............................. SKIPPED [INFO] Logback Site ...................................... SKIPPED [INFO] Logback Examples Module ........................... SKIPPED [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 29.140s [INFO] Finished at: Mon Apr 15 23:47:54 EDT 2013 [INFO] Final Memory: 28M/241M [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2. 12.4:test (default-test) on project logback-core: There are test failures.
-- Ceki 65% of statistics are made up on the spot