Flaky-test: FilterEntryTest.testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription

example failure

  Error:  Tests run: 10, Failures: 3, Errors: 0, Skipped: 7, Time elapsed: 129.61 s <<< FAILURE! - in org.apache.pulsar.broker.service.plugin.FilterEntryTest
  Error:  testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription(org.apache.pulsar.broker.service.plugin.FilterEntryTest)  Time elapsed: 60.758 s  <<< FAILURE!
  java.util.concurrent.TimeoutException
  	at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
  	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
  	at org.apache.pulsar.broker.service.plugin.FilterEntryTest.testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription(FilterEntryTest.java:356)
  	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.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
  	at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:45)
  	at org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:73)
  	at org.testng.internal.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)

Failed again https://github.com/apache/pulsar/runs/7717528894?check_suite_focus=true

Look like the RESCHEDULE message always choose the same consumer.

metadata {matchValueAccept=FOR-1, matchValueReschedule=FOR-2} key FOR-2 outcome RESCHEDULE
RESCHEDULE: 4:181 - consumer1
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:182 - consumer2
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:184 - consumer2
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:186 - consumer2
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:188 - consumer2
filterEntry for {matchValueAccept=FOR-1, matchValueReschedule=FOR-2}
metadata {matchValueAccept=FOR-1, matchValueReschedule=FOR-2} key FOR-2 outcome RESCHEDULE
RESCHEDULE: 4:181 - consumer1
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:182 - consumer2
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:184 - consumer2
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:186 - consumer2
filterEntry for {matchValueAccept=FOR-2, matchValueReschedule=FOR-1}
metadata {matchValueAccept=FOR-2, matchValueReschedule=FOR-1} key FOR-1 outcome RESCHEDULE
RESCHEDULE: 4:188 - consumer2
filterEntry for {matchValueAccept=FOR-1, matchValueReschedule=FOR-2}
metadata {matchValueAccept=FOR-1, matchValueReschedule=FOR-2} key FOR-2 outcome RESCHEDULE
RESCHEDULE: 4:181 - consumer1
....

@Demogorgon314 Great finds, are you working on this issue?

Yes, I will try to fix it.

Another one https://github.com/apache/pulsar/runs/8037496227?check_suite_focus=true

The issue had no activity for 30 days, mark with Stale label.

@Demogorgon314 Yet another one, https://github.com/apache/pulsar/actions/runs/3541194507/jobs/5946967295#step:10:1050

  Error:  Tests run: 27, Failures: 1, Errors: 0, Skipped: 26, Time elapsed: 133.901 s <<< FAILURE! - in org.apache.pulsar.broker.service.plugin.FilterEntryTest
  Error:  testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription(org.apache.pulsar.broker.service.plugin.FilterEntryTest)  Time elapsed: 60.88 s  <<< FAILURE!
  java.util.concurrent.TimeoutException
  	at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
  	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
  	at org.apache.pulsar.broker.service.plugin.FilterEntryTest.testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription(FilterEntryTest.java:441)
  	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)

The issue had no activity for 30 days, mark with Stale label.

Another one https://github.com/apache/pulsar/actions/runs/3927573395/jobs/6714418502#step:11:1062

Error:  Tests run: 17, Failures: 1, Errors: 0, Skipped: 16, Time elapsed: 129.697 s <<< FAILURE! - in org.apache.pulsar.broker.service.plugin.FilterEntryTest
  Error:  testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription(org.apache.pulsar.broker.service.plugin.FilterEntryTest)  Time elapsed: 60.835 s  <<< FAILURE!
  java.util.concurrent.TimeoutException
  	at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
  	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
  	at org.apache.pulsar.broker.service.plugin.FilterEntryTest.testEntryFilterRescheduleMessageDependingOnConsumerSharedSubscription(FilterEntryTest.java:441)
  	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)

The issue had no activity for 30 days, mark with Stale label.