[logback-dev] TimeBasedFileNamingAndTriggeringPolicyBaseTest fails

Joern Huxhorn jhuxhorn at googlemail.com
Wed Mar 7 00:46:53 CET 2012 

Latest build had two failing tests on our Jenkins running on OS X 10.7.3 with Java6U29:

java.lang.AssertionError: expected:<4> but was:<3>
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemoval_STest.check(TimeBasedRollingWithArchiveRemoval_STest.scala:294)
	at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemoval_STest.generateDailyRollover(TimeBasedRollingWithArchiveRemoval_STest.scala:86)
	at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemoval_STest.dailyRolloverWithInactivity10(TimeBasedRollingWithArchiveRemoval_STest.scala:105)

java.io.FileNotFoundException: target/test-output/67017605/toto.log1331074567926532000.tmp (No such file or directory)
	at java.io.FileInputStream.open(Native Method)
	at java.io.FileInputStream.<init>(FileInputStream.java:120)
	at ch.qos.logback.core.testUtil.FileToBufferUtil.regularReadIntoList(FileToBufferUtil.java:60)
	at ch.qos.logback.core.testUtil.FileToBufferUtil.readIntoList(FileToBufferUtil.java:38)
	at ch.qos.logback.core.rolling.RollingScaffolding$$anonfun$fileContentCheck$2.apply(RollingScaffolding.scala:147)
	at ch.qos.logback.core.rolling.RollingScaffolding$$anonfun$fileContentCheck$2.apply(RollingScaffolding.scala:146)
	at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:34)
	at scala.collection.mutable.ArrayOps.foreach(ArrayOps.scala:38)
	at ch.qos.logback.core.rolling.RollingScaffolding$class.fileContentCheck(RollingScaffolding.scala:146)
	at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP_STest.fileContentCheck(SizeAndTimeBasedFNATP_STest.scala:28)
	at ch.qos.logback.core.rolling.RollingScaffolding$class.sortedContentCheck(RollingScaffolding.scala:134)
	at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP_STest.sortedContentCheck(SizeAndTimeBasedFNATP_STest.scala:28)
	at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP_STest.generic(SizeAndTimeBasedFNATP_STest.scala:122)
	at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP_STest.withGZCompression_FileSet_NoRestart_5(SizeAndTimeBasedFNATP_STest.scala:174)

Before that, the builds were fine for two days, 8 builds in total.
So yes, this seems to be pretty random, especially since the failing build  was caused by this commit: https://github.com/ceki/logback/commit/b0876ea252337f55c9f0b7b6d613d7b38ed1503f

On 06.03.2012, at 23:30, Ralph Goers wrote:

> Yes, the SMTPAppender test now passes. ReconfigureOnChangeTest fails sometimes and sometimes the build now completes successfully.
> 
> Thanks,
> Ralph
> 
> On Mar 6, 2012, at 12:11 PM, ceki wrote:
> 
>> 
>> Fixing LBCLASSIC-221 fixes SMTPAppender_GreenTest. Failures of ReconfigureOnChangeTest are probably related to MacOS. (It's a pretty lame excuse but that's the best I've got at the moment.)
>> 
>> --
>> Ceki
>> http://twitter.com/#!/ceki
>> 
>> 
>> On 06.03.2012 00:22, Ralph Goers wrote:
>>> My machine wasn't busy.  As said in a prior email I just purchased a new MacBook Pro with a 2.5 GHz Intel Core i7.  I ran the build again against logback-class (twice) and this time got a different error. I then ran the full build and also got this new error.
>>> 
>>> -------------------------------------------------------------------------------
>>> Test set: ch.qos.logback.classic.net.SMTPAppender_GreenTest
>>> -------------------------------------------------------------------------------
>>> Tests run: 8, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 1.421 sec<<<  FAILURE!
>>> smoke(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.309 secLBCLASSIC_104(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.115 sechtml(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.15 sechtmlLong(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.381 sectestCustomEvaluator(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.116 sectestCustomBufferSize(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.115 sectestMultipleTo(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.113 secbufferShouldBeResetBetweenMessages(ch.qos.logback.classic.net.SMTPAppender_GreenTest)  Time elapsed: 0.121 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.classic.net.SMTPAppender_GreenTest.bufferShouldBeResetBetweenMessages(SMTPAppender_GreenTest.java:297)
>>> 
>>> On Mar 5, 2012, at 2:07 PM, ceki wrote:
>>> 
>>>> 
>>>> "current duration 6.76 exceeded expected 2.18862" indicates that either your machine is busy or the test fails for your OS. The performance tests have revealed themselves to be very fragile.
>>>> 
>>>> On 05.03.2012 19:42, Ralph Goers wrote:
>>>>> Yes, that error seems to be fixed. Now logback-classic is failing with
>>>>> 
>>>>> -------------------------------------------------------------------------------
>>>>> Test set: ch.qos.logback.classic.turbo.ReconfigureOnChangeTest
>>>>> -------------------------------------------------------------------------------
>>>>> Tests run: 10, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 10.493 sec<<<   FAILURE!
>>>>> scan1(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 1.23 secscanWithFileInclusion(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 0.931 secscanWithResourceInclusion(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 1.034 secincludeScanViaInputStreamSuppliedConfigFile(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 1.013 secfallbackToSafe(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 2.031 secfallbackToSafeWithIncludedFile(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 1.935 secgscan1(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 1.047 secscan_lbclassic154(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 1.016 secdirectPerfTest(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 0.219 sec<<<   FAILURE!
>>>>> junit.framework.AssertionFailedError: current duration 6.76 exceeded expected 2.18862 (adjusted reference), 18 (raw reference)
>>>>>        at org.slf4j.helpers.BogoPerf.assertDuration(BogoPerf.java:121)
>>>>>        at ch.qos.logback.classic.turbo.ReconfigureOnChangeTest.directPerfTest(ReconfigureOnChangeTest.java:301)
>>>>>        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:45)
>>>>>        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
>> _______________________________________________
>> logback-dev mailing list
>> logback-dev at qos.ch
>> http://mailman.qos.ch/mailman/listinfo/logback-dev
> 
> _______________________________________________
> logback-dev mailing list
> logback-dev at qos.ch
> http://mailman.qos.ch/mailman/listinfo/logback-dev

More information about the logback-dev mailing list