[ZOOKEEPER-3480] Flaky test CommitProcessorMetricsTest.testConcurrentRequestProcessingInCommitProcessor

• Type: Test
• Status: Resolved
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: 3.6.0
• Fix Version/s: 3.6.0
• Component/s: tests
• Labels: pull-request-available
• Assignee: Fangmin Lv
• Reporter: Fangmin Lv
• Created: 31/Jul/19 06:46
• Updated: 06/Aug/19 09:25
• Resolved: 05/Aug/19 23:49

Description

Found this flaky test on Jenkins, here is the log:

Error Message

expected:<3> but was:<2>

Stacktrace

java.lang.AssertionError: expected:<3> but was:<2> at org.apache.zookeeper.server.quorum.CommitProcessorMetricsTest.testConcurrentRequestProcessingInCommitProcessor(CommitProcessorMetricsTest.java:391)

Standard Output

2019-07-31 03:15:17,408 [myid:] - INFO [main:ZKTestCase$1@60] - STARTING testConcurrentRequestProcessingInCommitProcessor 2019-07-31 03:15:17,408 [myid:] - INFO [main:CommitProcessorMetricsTest@52] - setup 2019-07-31 03:15:17,409 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - RUNNING TEST METHOD testConcurrentRequestProcessingInCommitProcessor 2019-07-31 03:15:17,411 [myid:] - INFO [main:CommitProcessor@496] - Configuring CommitProcessor with readBatchSize -1 commitBatchSize 1 2019-07-31 03:15:17,411 [myid:] - INFO [main:CommitProcessor@454] - Configuring CommitProcessor with 24 worker threads. 2019-07-31 03:15:17,461 [myid:] - INFO [main:CommitProcessorMetricsTest$TestCommitProcessor@109] - numWorkerThreads in Test is 3 2019-07-31 03:15:19,466 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@99] - TEST METHOD FAILED testConcurrentRequestProcessingInCommitProcessor java.lang.AssertionError: expected:<3> but was:<2> at org.junit.Assert.fail(Assert.java:88) at org.junit.Assert.failNotEquals(Assert.java:834) at org.junit.Assert.assertEquals(Assert.java:118) at org.junit.Assert.assertEquals(Assert.java:144) at org.apache.zookeeper.server.quorum.CommitProcessorMetricsTest.testConcurrentRequestProcessingInCommitProcessor(CommitProcessorMetricsTest.java:391) 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.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:80) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) at org.junit.rules.RunRules.evaluate(RunRules.java:20) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) 2019-07-31 03:15:19,472 [myid:] - INFO [main:CommitProcessorMetricsTest@68] - tearDown starting 2019-07-31 03:15:19,473 [myid:] - INFO [main:CommitProcessor@646] - Shutting down 2019-07-31 03:15:20,464 [myid:] - INFO [CommitProcessor:1:CommitProcessor@419] - CommitProcessor exited loop! 2019-07-31 03:15:20,465 [myid:] - INFO [main:ZKTestCase$1@75] - FAILED testConcurrentRequestProcessingInCommitProcessor java.lang.AssertionError: expected:<3> but was:<2> at org.junit.Assert.fail(Assert.java:88) at org.junit.Assert.failNotEquals(Assert.java:834) at org.junit.Assert.assertEquals(Assert.java:118) at org.junit.Assert.assertEquals(Assert.java:144) at org.apache.zookeeper.server.quorum.CommitProcessorMetricsTest.testConcurrentRequestProcessingInCommitProcessor(CommitProcessorMetricsTest.java:391) 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.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:80) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) at org.junit.rules.RunRules.evaluate(RunRules.java:20) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) 2019-07-31 03:15:20,467 [myid:] - INFO [main:ZKTestCase$1@65] - FINISHED testConcurrentRequestProcessingInCommitProcessor

 

Issue Links

• is duplicated by: ZOOKEEPER-3477 Flaky test:CommitProcessorMetricsTest.testConcurrentRequestProcessingInCommitProcessor
• is duplicated by: ZOOKEEPER-3493 Deflake testConcurrentRequestProcessingInCommitProcessor in CommitProcessorMetricsTest
• links to: GitHub Pull Request #1035