Broken build
I haven’t run a build in a while and looking at the recent commits I am not sure what is causing this, but some change since 2.19.0 is now causing the following build failures in log4j-core. Ralph [ERROR] Failures: [ERROR] LoggerTest.basicFlow:90 expected: <2> but was: <4> [ERROR] LoggerTest.builder:77 Incorrect message 1 Expected: " DEBUG org.apache.logging.log4j.LoggerTest.builder(LoggerTest.java:73) Hello" but: was "ENTER[ FLOW ] TRACE Enter doFoo(a=1, b=2)" [ERROR] LoggerTest.debug:209 expected: <1> but was: <0> [ERROR] LoggerTest.debugWithParmsAndThrowable:230 expected: <1> but was: <2> [ERROR] LoggerTest.flowTracingMessage:104 Incorrect Entry Expected: a string starting with "ENTER[ FLOW ] TRACE Enter" but: was "THROWING[ EXCEPTION ] ERROR Throwing java.lang.IllegalArgumentException: Test Exception at org.apache.logging.log4j.LoggerTest.throwing(LoggerTest.java:596) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) at java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189) at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056) at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692) at java.util.concurrent.ForkJoinWorkerThr
Re: Broken build
Is this a consistent failure or random? > On Nov 16, 2022, at 3:42 PM, Ralph Goers wrote: > > I haven’t run a build in a while and looking at the recent commits I am not > sure what is causing this, but some change since 2.19.0 is now causing the > following build failures in log4j-core. > > Ralph > > [ERROR] Failures: > [ERROR] LoggerTest.basicFlow:90 expected: <2> but was: <4> > [ERROR] LoggerTest.builder:77 Incorrect message 1 > Expected: " DEBUG > org.apache.logging.log4j.LoggerTest.builder(LoggerTest.java:73) Hello" > but: was "ENTER[ FLOW ] TRACE Enter doFoo(a=1, b=2)" > [ERROR] LoggerTest.debug:209 expected: <1> but was: <0> > [ERROR] LoggerTest.debugWithParmsAndThrowable:230 expected: <1> but was: <2> > [ERROR] LoggerTest.flowTracingMessage:104 Incorrect Entry > Expected: a string starting with "ENTER[ FLOW ] TRACE Enter" > but: was "THROWING[ EXCEPTION ] ERROR Throwing > java.lang.IllegalArgumentException: Test Exception > at org.apache.logging.log4j.LoggerTest.throwing(LoggerTest.java:596) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:498) > at > org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) > at > org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) > at > org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) > at > org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) > at > org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) > at > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) > at > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) > at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) > at > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) > at > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) > at java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189) > at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) > at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056) > at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692) > at > java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157) >
Re: Broken build
The stack bottom shows java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157) I hope we are not running tests in parallel or else how can we be reliable and reproducible? And compare builds between developers? Gary On Wed, Nov 16, 2022, 19:23 Matt Sicker wrote: > Is this a consistent failure or random? > > > On Nov 16, 2022, at 3:42 PM, Ralph Goers > wrote: > > > > I haven’t run a build in a while and looking at the recent commits I am > not sure what is causing this, but some change since 2.19.0 is now causing > the following build failures in log4j-core. > > > > Ralph > > > > [ERROR] Failures: > > [ERROR] LoggerTest.basicFlow:90 expected: <2> but was: <4> > > [ERROR] LoggerTest.builder:77 Incorrect message 1 > > Expected: " DEBUG > org.apache.logging.log4j.LoggerTest.builder(LoggerTest.java:73) Hello" > > but: was "ENTER[ FLOW ] TRACE Enter doFoo(a=1, b=2)" > > [ERROR] LoggerTest.debug:209 expected: <1> but was: <0> > > [ERROR] LoggerTest.debugWithParmsAndThrowable:230 expected: <1> but > was: <2> > > [ERROR] LoggerTest.flowTracingMessage:104 Incorrect Entry > > Expected: a string starting with "ENTER[ FLOW ] TRACE Enter" > > but: was "THROWING[ EXCEPTION ] ERROR Throwing > java.lang.IllegalArgumentException: Test Exception > > at org.apache.logging.log4j.LoggerTest.throwing(LoggerTest.java:596) > > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > > at java.lang.reflect.Method.invoke(Method.java:498) > > at > org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) > > at > org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) > > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) > > at > org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) > > at > org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) > > at > org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) > > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) > > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) > > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) > > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) > > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) > > at > org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) > > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) > > at > org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) > > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) > > at > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) > > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) > > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) > > at > org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) > > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) > > at > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) > > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) > > at > org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) > > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) > > at > org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) > > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) > > at > org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) > > at > org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) > > at java.util.concur
Re: Broken build
Consistent Ralph > On Nov 16, 2022, at 5:23 PM, Matt Sicker wrote: > > Is this a consistent failure or random? > >> On Nov 16, 2022, at 3:42 PM, Ralph Goers wrote: >> >> I haven’t run a build in a while and looking at the recent commits I am not >> sure what is causing this, but some change since 2.19.0 is now causing the >> following build failures in log4j-core. >> >> Ralph >> >> [ERROR] Failures: >> [ERROR] LoggerTest.basicFlow:90 expected: <2> but was: <4> >> [ERROR] LoggerTest.builder:77 Incorrect message 1 >> Expected: " DEBUG >> org.apache.logging.log4j.LoggerTest.builder(LoggerTest.java:73) Hello" >>but: was "ENTER[ FLOW ] TRACE Enter doFoo(a=1, b=2)" >> [ERROR] LoggerTest.debug:209 expected: <1> but was: <0> >> [ERROR] LoggerTest.debugWithParmsAndThrowable:230 expected: <1> but was: >> <2> >> [ERROR] LoggerTest.flowTracingMessage:104 Incorrect Entry >> Expected: a string starting with "ENTER[ FLOW ] TRACE Enter" >>but: was "THROWING[ EXCEPTION ] ERROR Throwing >> java.lang.IllegalArgumentException: Test Exception >> at org.apache.logging.log4j.LoggerTest.throwing(LoggerTest.java:596) >> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >> at >> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) >> at >> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) >> at java.lang.reflect.Method.invoke(Method.java:498) >> at >> org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) >> at >> org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) >> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) >> at >> org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) >> at >> org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) >> at >> org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) >> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) >> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) >> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) >> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) >> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) >> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) >> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) >> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) >> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) >> at >> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) >> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) >> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) >> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) >> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) >> at >> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) >> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) >> at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) >> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) >> at >> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) >> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) >> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) >> at >> org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) >> at java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189) >> at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) >> at >> java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.ja
Re: Broken build
On Windows, I get: [INFO] Running org.apache.logging.log4j.status.StatusConsoleListenerTest [ERROR] Tests run: 41, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.042 s <<< FAILURE! - in org.apache.logging.log4j.spi.MutableThreadContextStackTest [ERROR] org.apache.logging.log4j.LoggerTest.flowTracingMessage Time elapsed: 0.48 s <<< FAILURE! org.opentest4j.AssertionFailedError: expected: <2> but was: <3> at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:151) at org.junit.jupiter.api.AssertionFailureBuilder.buildAndThrow(AssertionFailureBuilder.java:132) at org.junit.jupiter.api.AssertEquals.failNotEqual(AssertEquals.java:197) at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:150) at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:145) at org.junit.jupiter.api.Assertions.assertEquals(Assertions.java:528) at org.apache.logging.log4j.LoggerTest.flowTracingMessage(LoggerTest.java:103) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) at java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189) at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) at java.util.concurrent.ForkJoinTask.doJoin(ForkJoinTask.java:389) at java.util.concur
Re: Broken build
Hi Gary, On Thu, 17 Nov 2022 at 12:24, Gary Gregory wrote: > I hope we are not running tests in parallel or else how can we be reliable > and reproducible? And compare builds between developers? Yes, `log4j-api-test` is configured to run in parallel (at least in `master`). This setting has been switched on and off in the past year. In June I switched it on: https://github.com/apache/logging-log4j2/commit/0e68a1ab3c94d7a86a8e85483c2c36d4ff9143b7 Build errors in `log4j-api-test` have been rare these last months, but probably we need a profile to switch parallelism off (or a profile to switch it on). Piotr
Re: Broken build
I haven’t tried master recently. The failures I am seeing are in release-2.x. Ralph > On Nov 17, 2022, at 10:23 AM, Piotr P. Karwasz > wrote: > > Hi Gary, > > On Thu, 17 Nov 2022 at 12:24, Gary Gregory wrote: >> I hope we are not running tests in parallel or else how can we be reliable >> and reproducible? And compare builds between developers? > > Yes, `log4j-api-test` is configured to run in parallel (at least in > `master`). This setting has been switched on and off in the past year. > In June I switched it on: > > https://github.com/apache/logging-log4j2/commit/0e68a1ab3c94d7a86a8e85483c2c36d4ff9143b7 > > Build errors in `log4j-api-test` have been rare these last months, but > probably we need a profile to switch parallelism off (or a profile to > switch it on). > > Piotr
Re: Broken build
There’s a random seed value output for each run as the test order is randomized. You can use the seed to replay a particular test ordering, though if it’s a bug, it’ll still likely only show up randomly. > On Nov 17, 2022, at 5:23 AM, Gary Gregory wrote: > > The stack bottom shows > > java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157) > > I hope we are not running tests in parallel or else how can we be reliable > and reproducible? And compare builds between developers? > > Gary > > On Wed, Nov 16, 2022, 19:23 Matt Sicker wrote: > >> Is this a consistent failure or random? >> >>> On Nov 16, 2022, at 3:42 PM, Ralph Goers >> wrote: >>> >>> I haven’t run a build in a while and looking at the recent commits I am >> not sure what is causing this, but some change since 2.19.0 is now causing >> the following build failures in log4j-core. >>> >>> Ralph >>> >>> [ERROR] Failures: >>> [ERROR] LoggerTest.basicFlow:90 expected: <2> but was: <4> >>> [ERROR] LoggerTest.builder:77 Incorrect message 1 >>> Expected: " DEBUG >> org.apache.logging.log4j.LoggerTest.builder(LoggerTest.java:73) Hello" >>>but: was "ENTER[ FLOW ] TRACE Enter doFoo(a=1, b=2)" >>> [ERROR] LoggerTest.debug:209 expected: <1> but was: <0> >>> [ERROR] LoggerTest.debugWithParmsAndThrowable:230 expected: <1> but >> was: <2> >>> [ERROR] LoggerTest.flowTracingMessage:104 Incorrect Entry >>> Expected: a string starting with "ENTER[ FLOW ] TRACE Enter" >>>but: was "THROWING[ EXCEPTION ] ERROR Throwing >> java.lang.IllegalArgumentException: Test Exception >>> at org.apache.logging.log4j.LoggerTest.throwing(LoggerTest.java:596) >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>> at >> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) >>> at >> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) >>> at java.lang.reflect.Method.invoke(Method.java:498) >>> at >> org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) >>> at >> org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) >>> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) >>> at >> org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) >>> at >> org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) >>> at >> org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) >>> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) >>> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) >>> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) >>> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) >>> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) >>> at >> org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) >>> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) >>> at >> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) >>> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) >>> at >> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) >>> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) >>> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) >>> at >> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) >>> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) >>> at >> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) >>> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) >>> at >> org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) >>> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) >>> at >> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) >>> at >> org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively
Re: Broken build
I ran mvn test -Dtest=LoggerTest and it still fails. Ralph > On Nov 17, 2022, at 12:27 PM, Matt Sicker wrote: > > There’s a random seed value output for each run as the test order is > randomized. You can use the seed to replay a particular test ordering, though > if it’s a bug, it’ll still likely only show up randomly. > >> On Nov 17, 2022, at 5:23 AM, Gary Gregory wrote: >> >> The stack bottom shows >> >> java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157) >> >> I hope we are not running tests in parallel or else how can we be reliable >> and reproducible? And compare builds between developers? >> >> Gary >> >> On Wed, Nov 16, 2022, 19:23 Matt Sicker wrote: >> >>> Is this a consistent failure or random? >>> On Nov 16, 2022, at 3:42 PM, Ralph Goers >>> wrote: I haven’t run a build in a while and looking at the recent commits I am >>> not sure what is causing this, but some change since 2.19.0 is now causing >>> the following build failures in log4j-core. Ralph [ERROR] Failures: [ERROR] LoggerTest.basicFlow:90 expected: <2> but was: <4> [ERROR] LoggerTest.builder:77 Incorrect message 1 Expected: " DEBUG >>> org.apache.logging.log4j.LoggerTest.builder(LoggerTest.java:73) Hello" but: was "ENTER[ FLOW ] TRACE Enter doFoo(a=1, b=2)" [ERROR] LoggerTest.debug:209 expected: <1> but was: <0> [ERROR] LoggerTest.debugWithParmsAndThrowable:230 expected: <1> but >>> was: <2> [ERROR] LoggerTest.flowTracingMessage:104 Incorrect Entry Expected: a string starting with "ENTER[ FLOW ] TRACE Enter" but: was "THROWING[ EXCEPTION ] ERROR Throwing >>> java.lang.IllegalArgumentException: Test Exception at org.apache.logging.log4j.LoggerTest.throwing(LoggerTest.java:596) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at >>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at >>> org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727) at >>> org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) at >>> org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) at >>> org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156) at >>> org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147) at >>> org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86) at >>> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103) at >>> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93) at >>> org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) at >>> org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) at >>> org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) at >>> org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) at >>> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92) at >>> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86) at >>> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217) at >>> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at >>> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213) at >>> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138) at >>> org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68) at >>> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) at >>> org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at >>> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) at >>> org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) at >>> org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestT
Re: Broken build
On Thu, 17 Nov 2022 at 23:23, Ralph Goers wrote: > > I ran mvn test -Dtest=LoggerTest and it still fails. In `release-2.x` JUnit 5 is configured with: junit.jupiter.execution.parallel.mode.default = concurrent In `master` we have: junit.jupiter.execution.parallel.mode.default = same_thread junit.jupiter.execution.parallel.mode.classes.default = concurrent and it seems much more stable. Running all the test methods of a class concurrently is something we are not ready for. Piotr
Re: Broken build
I made that change to log4j-api-test and that fixed the problem. Ralph > On Nov 17, 2022, at 3:29 PM, Piotr P. Karwasz wrote: > > On Thu, 17 Nov 2022 at 23:23, Ralph Goers wrote: >> >> I ran mvn test -Dtest=LoggerTest and it still fails. > > In `release-2.x` JUnit 5 is configured with: > > junit.jupiter.execution.parallel.mode.default = concurrent > > In `master` we have: > > junit.jupiter.execution.parallel.mode.default = same_thread > junit.jupiter.execution.parallel.mode.classes.default = concurrent > > and it seems much more stable. Running all the test methods of a class > concurrently is something we are not ready for. > > Piotr
