[logback-dev] TimeBasedFileNamingAndTriggeringPolicyBaseTest fails

Ralph Goers rgoers at apache.org
Tue Mar 6 00:22:06 CET 2012 

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)
        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)
        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.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53)
        at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123)
        at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104)
        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.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164)
        at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110)
        at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:175)
        at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:107)
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:68)

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)
>>         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.runners.ParentRunner.run(ParentRunner.java:300)
>>         at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53)
>>         at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123)
>>         at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104)
>>         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.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164)
>>         at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110)
>>         at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:175)
>>         at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:107)
>>         at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:68)
>> indirectPerfTest(ch.qos.logback.classic.turbo.ReconfigureOnChangeTest)  Time elapsed: 0.034 sec
>> 
>> Ralph
>> 
>> 
>> On Mar 5, 2012, at 12:07 PM, ceki wrote:
>> 
>>> 
>>> Hi Joern, Hi Ralph,
>>> 
>>> This issue should be fixed now.
>>> See also  https://github.com/ceki/logback/commit/45879248ca1dad7b0d589
>>> 
>>> Cheers,
>>> --
>>> Ceki
>>> http://twitter.com/#!/ceki
>>> 
>>> On 27.02.2012 15:11, Joern Huxhorn wrote:
>>>> Same here, for quite some time.
>>>> 
>>>> On 27.02.2012, at 02:39, Ralph Goers wrote:
>>>> 
>>>>> I just got a new Mac at work and at home. The Logback build is failing on both. I have no idea if the error is due to the upgrade or not.
>>>>> 
>>>>> -------------------------------------------------------------------------------
>>>>> Test set: ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest
>>>>> -------------------------------------------------------------------------------
>>>>> Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 1,133,311.978 sec<<<   FAILURE!
>>>>> singleDate(ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest)  Time elapsed: 0 secmultiDate(ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest)  Time elapsed: 0.002 sec<<<   FAILURE!
>>>>> java.lang.AssertionError: expected:<foo-2011-12/59.log>   but was:<null>
>>>>>        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:147)
>>>>>        at ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest.multiDate(TimeBasedFileNamingAndTriggeringPolicyBaseTest.java:65)
>>>>>        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)
>>>>>        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.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:441)
>>>>>        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>>>>>        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>>>>>        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:680)
>>> 
>>> 
>>> _______________________________________________
>>> 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
> 
> 
> -- 
> Ceki
> http://twitter.com/#!/ceki
> _______________________________________________
> 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