search

apache / pulsar

Apache Pulsar - distributed pub-sub messaging system
https://pulsar.apache.org/
Apache License 2.0
14.14k stars 3.57k forks source link

Flaky-test: LeaderElectionTest.revalidateLeaderWithinSameSession #21535

Open lhotari opened 10 months ago

lhotari commented 10 months ago

Search before asking

Example failures

Exception stacktrace

java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
    at org.testng.internal.invokers.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:47)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:76)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)

Are you willing to submit a PR?

lhotari commented 10 months ago

Recent failures:

Flaky-test: org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession Number of failures: 2

org.apache.pulsar.metadata.LeaderElectionTest is flaky. The revalidateLeaderWithinSameSession test method fails sporadically.

java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2023-11-18T12:21:56.1868635Z

Full exception stacktrace 
java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
    at org.testng.internal.invokers.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:47)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:76)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:840)

example failure 2023-11-15T06:20:40.2995786Z

Full exception stacktrace 
java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
    at org.testng.internal.invokers.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:47)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:76)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1583)
lhotari commented 9 months ago

again: https://github.com/apache/pulsar/actions/runs/7152492116/job/19477989177?pr=21681#step:11:255

Error:  org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession[RocksDB, org.apache.pulsar.metadata.BaseMetadataStoreTest$$Lambda$890/0x00007fc2286e23c8@4ac2b4c6](8)  Time elapsed: 0.014 s  <<< FAILURE!
  java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
    at org.testng.internal.invokers.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:47)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:76)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:[264](https://github.com/apache/pulsar/actions/runs/7152492116/job/19477989177?pr=21681#step:11:265))
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:840)
lhotari commented 9 months ago

Flaky-test: org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession Number of failures: 1

org.apache.pulsar.metadata.LeaderElectionTest is flaky. The revalidateLeaderWithinSameSession test method fails sporadically.

java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2023-12-12T12:28:11.5333133Z

Full exception stacktrace 
java.lang.AssertionError: expected [Optional[test-2]] but found [Optional.empty]
    at org.testng.Assert.fail(Assert.java:110)
    at org.testng.Assert.failNotEquals(Assert.java:1577)
    at org.testng.Assert.assertEqualsImpl(Assert.java:149)
    at org.testng.Assert.assertEquals(Assert.java:131)
    at org.testng.Assert.assertEquals(Assert.java:643)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.lambda$assertEqualsAndRetry$6(BaseMetadataStoreTest.java:133)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.retryStrategically(BaseMetadataStoreTest.java:141)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:129)
    at org.apache.pulsar.metadata.BaseMetadataStoreTest.assertEqualsAndRetry(BaseMetadataStoreTest.java:121)
    at org.apache.pulsar.metadata.LeaderElectionTest.revalidateLeaderWithinSameSession(LeaderElectionTest.java:212)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
    at org.testng.internal.invokers.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:47)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:76)
    at org.testng.internal.invokers.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:840)
nikam14 commented 6 months ago

In the Test revalidateLeaderWithinSameSession() it is calling assertEqualsAndRetry() method in which it is using Lambda Expression. There it is calling the actual.get() method two times. First at line no. - 130 if (actual.get().equals(expectedAndRetry)) { Second at line no. - 133 assertEquals(actual.get(), expected); Here we are calling the Object twice. Calling actual.get() method twice which may return different object at both times. Instead we can call it once store it and check both the conditions . In this way at both conditions we are checking the same Object.

We can change this to 1 this 2

nikam14 commented 5 months ago

@lhotari what do you think about mentioned solution in above comment.

lhotari commented 5 months ago

@lhotari what do you think about mentioned solution in above comment.

@nikam14 subscribe to the developer mailing list and start a discussion thread about this change. Instructions for joining: https://pulsar.apache.org/contact/. I personally don't think that a PIP is needed for such a small change, but it doesn't hurt and the benefit is that the change gets noticed.