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
Re: [logging-log4j2] branch master updated: Add Lazy::pure for pure reified values
Oops, “reified” should say “memoized”. You get the idea.
—
Matt Sicker
> On Nov 17, 2022, at 22:12, mattsic...@apache.org wrote:
>
> This is an automated email from the ASF dual-hosted git repository.
>
> mattsicker pushed a commit to branch master
> in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
>
>
> The following commit(s) were added to refs/heads/master by this push:
> new 2986332a90 Add Lazy::pure for pure reified values
> 2986332a90 is described below
>
> commit 2986332a90e10d14547faf8729e19ec7ff01c622
> Author: Matt Sicker
> AuthorDate: Thu Nov 17 22:10:29 2022 -0600
>
>Add Lazy::pure for pure reified values
>
>This adds a Lazy variant where the supplier function is a pure function.
> Given a pure function, memory reordering semantics are mostly irrelevant, so
> this can both safely recompute the value and publish more than one resulting
> computed reference as the results should all be the same value.
>
>This updates JSON encoding cache tables to use Lazy::pure.
>
>Signed-off-by: Matt Sicker
> ---
> .../java/org/apache/logging/log4j/util/Lazy.java | 13 ++
> .../org/apache/logging/log4j/util/LazyUtil.java| 29 ++
> .../apache/logging/log4j/core/util/JsonUtils.java | 2 +-
> .../layout/template/json/util/JsonWriter.java | 2 +-
> 4 files changed, 44 insertions(+), 2 deletions(-)
>
> diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/util/Lazy.java
> b/log4j-api/src/main/java/org/apache/logging/log4j/util/Lazy.java
> index ec3edb5b61..1c08f6d8d8 100644
> --- a/log4j-api/src/main/java/org/apache/logging/log4j/util/Lazy.java
> +++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/Lazy.java
> @@ -16,6 +16,7 @@
> */
> package org.apache.logging.log4j.util;
>
> +import java.util.Objects;
> import java.util.function.Function;
> import java.util.function.Supplier;
>
> @@ -44,6 +45,7 @@ public interface Lazy extends Supplier {
> * Creates a lazy value using the provided Supplier for initialization
> guarded by a Lock.
> */
> static Lazy lazy(final Supplier supplier) {
> +Objects.requireNonNull(supplier);
> return new LazyUtil.SafeLazy<>(supplier);
> }
>
> @@ -59,6 +61,17 @@ public interface Lazy extends Supplier {
> * in order to set the initialized value.
> */
> static Lazy relaxed(final Supplier supplier) {
> +Objects.requireNonNull(supplier);
> return new LazyUtil.ReleaseAcquireLazy<>(supplier);
> }
> +
> +/**
> + * Creates a pure lazy value using the provided Supplier to initialize
> the value. The supplier may be invoked more
> + * than once, and the return value should be a purely computed value as
> the result may be a different instance
> + * each time. This is useful for building cache tables and other pure
> computations.
> + */
> +static Lazy pure(final Supplier supplier) {
> +Objects.requireNonNull(supplier);
> +return new LazyUtil.PureLazy<>(supplier);
> +}
> }
> diff --git
> a/log4j-api/src/main/java/org/apache/logging/log4j/util/LazyUtil.java
> b/log4j-api/src/main/java/org/apache/logging/log4j/util/LazyUtil.java
> index a75935ea8c..0150aaf289 100644
> --- a/log4j-api/src/main/java/org/apache/logging/log4j/util/LazyUtil.java
> +++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/LazyUtil.java
> @@ -162,4 +162,33 @@ final class LazyUtil {
> return isInitialized() ? String.valueOf(VALUE.getOpaque(value)) :
> "Lazy value not initialized";
> }
> }
> +
> +static class PureLazy implements Lazy {
> +private final Supplier supplier;
> +private Object value;
> +
> +public PureLazy(final Supplier supplier) {
> +this.supplier = supplier;
> +}
> +
> +@Override
> +public T value() {
> +Object value = this.value;
> +if (value == null) {
> +value = supplier.get();
> +this.value = wrapNull(value);
> +}
> +return unwrapNull(value);
> +}
> +
> +@Override
> +public boolean isInitialized() {
> +return value != null;
> +}
> +
> +@Override
> +public void set(final T newValue) {
> +value = newValue;
> +}
> +}
> }
> diff --git
> a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/JsonUtils.java
> b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/JsonUtils.java
> index 3815967aeb..fede436bb2 100644
> ---
> a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/JsonUtils.java
> +++
> b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/JsonUtils.java
> @@ -31,7 +31,7 @@ public final class JsonUtils {
> * to use after backslash; and negative values that generic (backslash -
> u)
> * escaping is to be used.
> */
> -private static final Lazy ESC_CODES = Lazy.relaxed(() ->
