Flaky-test: PerformanceTransactionTest.testConsumeTxnMessage #14109

lhotari · 2022-02-03T13:30:54Z

Flaky-test: org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage
Number of failures: 5

org.apache.pulsar.testclient.PerformanceTransactionTest is flaky. The testConsumeTxnMessage test method fails sporadically.

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@9317087]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2022-02-02T16:48:35.3692126Z

Full exception stacktrace

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@9317087]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	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:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@7858aa00]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2022-01-29T05:03:33.6909916Z

Full exception stacktrace

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@7858aa00]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	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:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@360348b7]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2022-01-28T12:46:12.5203828Z

Full exception stacktrace

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@360348b7]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	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:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@2ac4931c]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2022-02-02T13:38:31.6649715Z

Full exception stacktrace

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@2ac4931c]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	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:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@54f7543]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)

Usage tip: To enable automatic navigation to failure message, open the following links with CTRL/CMD-click.
example failure 2022-01-29T05:24:40.1685311Z

Full exception stacktrace

java.lang.AssertionError: expected [null] but found [org.apache.pulsar.client.impl.MessageImpl@54f7543]
	at org.testng.Assert.fail(Assert.java:99)
	at org.testng.Assert.failNotSame(Assert.java:1033)
	at org.testng.Assert.assertNull(Assert.java:965)
	at org.testng.Assert.assertNull(Assert.java:953)
	at org.apache.pulsar.testclient.PerformanceTransactionTest.testConsumeTxnMessage(PerformanceTransactionTest.java:235)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	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:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

The text was updated successfully, but these errors were encountered:

lhotari · 2022-02-03T13:33:09Z

The test is flaky that was introduced by the changes in #11933. @liangyepianzhou would you mind taking a look at #14109 ? Thank you

liangyepianzhou · 2022-02-03T13:45:41Z

This is an unstable test caused by message retransmissions. I think it should be possible to fix this test by reducing the accuracy. I'll give a PR with the fix later.

lhotari · 2022-02-03T13:49:09Z

This is an unstable test caused by message retransmissions. I think it should be possible to fix this test by reducing the accuracy. I'll give a PR with the fix later.

Thanks @liangyepianzhou , that would be great.

github-actions · 2022-03-06T01:53:34Z

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

github-actions · 2022-05-28T02:11:34Z

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

codelipenghui · 2022-08-08T02:33:10Z

@liangyepianzhou Do you want to push a PR to fix the issue?

* [Fix][Flaky-test] Fix testConsumeTxnMessage Master #14109 ## Motivation The transaction commit is async, so the consumer can still receive message when the consumer rebuilds. ## Modification Add Awaitility.await() for check-ing whether the ongoingTxns = 0.

* [Fix][Flaky-test] Fix testConsumeTxnMessage Master apache#14109 ## Motivation The transaction commit is async, so the consumer can still receive message when the consumer rebuilds. ## Modification Add Awaitility.await() for check-ing whether the ongoingTxns = 0.

codelipenghui · 2022-08-18T23:52:54Z

The flaky test still happens on the master branch https://github.com/apache/pulsar/runs/7899134537?check_suite_focus=true, reopen the ticket. @liangyepianzhou Could you please help check again?

* [Fix][Flaky-test] Fix testConsumeTxnMessage Master #14109 ## Motivation The transaction commit is async, so the consumer can still receive message when the consumer rebuilds. ## Modification Add Awaitility.await() for check-ing whether the ongoingTxns = 0. (cherry picked from commit c29503e)

* [Fix][Flaky-test] Fix testConsumeTxnMessage Master apache#14109 ## Motivation The transaction commit is async, so the consumer can still receive message when the consumer rebuilds. ## Modification Add Awaitility.await() for check-ing whether the ongoingTxns = 0. (cherry picked from commit c29503e) (cherry picked from commit 6db6679)

poorbarcode · 2022-09-16T03:22:47Z

another one: https://github.com/apache/pulsar/actions/runs/3062091034/jobs/4943495494

…7837) Fixes: #14109 ### Motivation The expected execution flow for this test is: 1. send 505 messages 2. commit 10 transactions, every transaction ack 50 messages 3. receive the last 5 messages in the last transaction, wait for transaction timeout 4. confirm that the last 5 messages can be consumed by new consumer <strong>(High light)</strong> The default value for transaction TTL is 10 seconds, and the default value for `Awaitility.await` is also 10 seconds, so this test is not stable. Note: This is a guess cause, the problem is not reproduced locally. But after transaction TTL is set to 11s, the probability of the problem occurring is 100%. ### Modifications Fix flaky test - set transaction TTL to 5s Other changes - define a name for the task thread - acknowledge the last 5 messages ### Matching PR in forked repository PR in forked repository: - poorbarcode#13

lhotari added the type/flaky-tests label Feb 3, 2022

lhotari mentioned this issue Feb 3, 2022

[Transaction] Add transaction perf #11933

Merged

3 tasks

sijie mentioned this issue Feb 3, 2022

ISSUE-14109: Flaky-test: PerformanceTransactionTest.testConsumeTxnMessage streamnative/pulsar-archived#3688

Open

liangyepianzhou mentioned this issue Feb 3, 2022

[Flaky-test] Fix PerformanceTransactionTest.testConsumeTxnMessage #14111

Closed

4 tasks

github-actions bot added the lifecycle/stale label Mar 6, 2022

liangyepianzhou mentioned this issue Aug 8, 2022

[Fix][Flaky-test] Fix testConsumeTxnMessage #16981

Merged

5 tasks

codelipenghui assigned liangyepianzhou Aug 8, 2022

liangyepianzhou closed this as completed in #16981 Aug 9, 2022

codelipenghui reopened this Aug 18, 2022

poorbarcode mentioned this issue Sep 26, 2022

[fix][flaky-test]PerformanceTransactionTest.testConsumeTxnMessage #17837

Merged

4 tasks

congbobo184 closed this as completed in #17837 Sep 29, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Flaky-test: PerformanceTransactionTest.testConsumeTxnMessage #14109

Flaky-test: PerformanceTransactionTest.testConsumeTxnMessage #14109

lhotari commented Feb 3, 2022

lhotari commented Feb 3, 2022

liangyepianzhou commented Feb 3, 2022

lhotari commented Feb 3, 2022

github-actions bot commented Mar 6, 2022

github-actions bot commented May 28, 2022

codelipenghui commented Aug 8, 2022

codelipenghui commented Aug 18, 2022

poorbarcode commented Sep 16, 2022

Flaky-test: PerformanceTransactionTest.testConsumeTxnMessage #14109

Flaky-test: PerformanceTransactionTest.testConsumeTxnMessage #14109

Comments

lhotari commented Feb 3, 2022

lhotari commented Feb 3, 2022

liangyepianzhou commented Feb 3, 2022

lhotari commented Feb 3, 2022

github-actions bot commented Mar 6, 2022

github-actions bot commented May 28, 2022

codelipenghui commented Aug 8, 2022

codelipenghui commented Aug 18, 2022

poorbarcode commented Sep 16, 2022