[logback-dev] TimeBasedFileNamingAndTriggeringPolicyBaseTest fails

ceki ceki at qos.ch
Mon Mar 5 20:07:03 CET 2012


"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


More information about the logback-dev mailing list