[
https://issues.apache.org/jira/browse/IGNITE-23693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Pavel Pereslegin updated IGNITE-23693:
--------------------------------------
Description:
This case is flaky.
Sometimes after canceling a long-running DML query, the implicit tx is not
rolled back.
Reproducer (put it into ItSqlSynchronousApiTest for example):
{code:java}
@Test
public void cancelLongRunningDml() throws InterruptedException {
sql("CREATE TABLE test (id INT PRIMARY KEY)");
IgniteSql sql = igniteSql();
// Long running DML query uses implicit RW transaction.
String query = "INSERT INTO test SELECT x FROM system_range(0,
10000000000);";
for (int i = 1; i <= 100; i++) {
log.info("iteration #" + i);
CancelHandle cancelHandle = CancelHandle.create();
CancellationToken token = cancelHandle.token();
// Run long DML query.
CompletableFuture<ResultSet<SqlRow>> f =
IgniteTestUtils.runAsync(() -> sql.execute(null, token,
query));
// Wait until the query starts executing.
Awaitility.await().untilAsserted(() ->
assertThat(queryProcessor().runningQueries(), greaterThan(0)));
// Wait a bit more to improve failure rate.
Thread.sleep(500);
// Wait for query cancel.
cancelHandle.cancel();
// Query was actually cancelled.
assertThat(queryProcessor().runningQueries(), is(0));
assertThrowsSqlException(
Sql.EXECUTION_CANCELLED_ERR,
"The query was cancelled while executing.",
() -> await(f)
);
// BUT the transaction may still be in progress (FAILING HERE).
Awaitility.await().untilAsserted(() ->
assertThat(txManager().pending(), is(0)));
// Clean-up after iteration.
sql("DELETE FROM test");
}
}
{code}
Error output
{noformat}
org.awaitility.core.ConditionTimeoutException: Assertion condition defined as a
lambda expression in org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest
Expected: is <0>
but: was <1> within 10 seconds.
Expected :is <0>
Actual :<1> within 10 seconds.
<Click to see difference>
at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
at
org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
at
org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
at
org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1006)
at
org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:790)
at
org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest.cancelStatement(ItSqlSynchronousApiTest.java:114)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
Caused by: java.lang.AssertionError:
Expected: is <0>
but: was <1>
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
at
org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest.lambda$cancelStatement$5(ItSqlSynchronousApiTest.java:114)
at
org.awaitility.core.AssertionCondition.lambda$new$0(AssertionCondition.java:53)
at
org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:248)
at
org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:235)
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:834)
{noformat}
was:
This case is flaky.
Sometimes after canceling a long-running DML query, the implicit tx is not
rolled back.
Reproducer (put it into ItSqlSynchronousApiTest for example):
{code:java}
@Test
public void cancelLongRunningDml() throws InterruptedException {
sql("CREATE TABLE test (id INT PRIMARY KEY)");
IgniteSql sql = igniteSql();
// Long running DML query uses implicit RW transaction.
String query = "INSERT INTO test SELECT x FROM system_range(0,
10000000000);";
for (int i = 1; i <= 100; i++) {
log.info("iteration #" + i);
CancelHandle cancelHandle = CancelHandle.create();
CancellationToken token = cancelHandle.token();
// Run long DML query.
CompletableFuture<ResultSet<SqlRow>> f =
IgniteTestUtils.runAsync(() -> sql.execute(null, token,
query));
// Wait until the query starts executing.
Awaitility.await().untilAsserted(() ->
assertThat(queryProcessor().runningQueries(), greaterThan(0)));
// Wait a bit more to improve failure rate.
Thread.sleep(500);
// Wait for query cancel.
cancelHandle.cancel();
// Query was actually cancelled.
assertThat(queryProcessor().runningQueries(), is(0));
assertThrowsSqlException(
Sql.EXECUTION_CANCELLED_ERR,
"The query was cancelled while executing.",
() -> await(f)
);
// BUT the transaction may still be in progress (FAILING HERE).
Awaitility.await().untilAsserted(() ->
assertThat(txManager().pending(), is(0)));
// Clean-up after iteration.
sql("DELETE FROM test");
}
}
{code}
Error output
{noformat}
org.awaitility.core.ConditionTimeoutException: Assertion condition defined as a
lambda expression in org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest
Expected: is <0>
but: was <1> within 10 seconds.
Expected :is <0>
Actual :<1> within 10 seconds.
<Click to see difference>
at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
at
org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
at
org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
at
org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1006)
at
org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:790)
at
org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest.cancelStatement(ItSqlSynchronousApiTest.java:114)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
Caused by: java.lang.AssertionError:
Expected: is <0>
but: was <1>
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
at
org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest.lambda$cancelStatement$5(ItSqlSynchronousApiTest.java:114)
at
org.awaitility.core.AssertionCondition.lambda$new$0(AssertionCondition.java:53)
at
org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:248)
at
org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:235)
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:834)
{noformat}
> Sql. After canceling a long-running DML query, the implicit tx is not rolled
> back.
> ----------------------------------------------------------------------------------
>
> Key: IGNITE-23693
> URL: https://issues.apache.org/jira/browse/IGNITE-23693
> Project: Ignite
> Issue Type: Bug
> Components: sql
> Reporter: Pavel Pereslegin
> Priority: Major
> Labels: ignite-3
>
> This case is flaky.
> Sometimes after canceling a long-running DML query, the implicit tx is not
> rolled back.
> Reproducer (put it into ItSqlSynchronousApiTest for example):
> {code:java}
> @Test
> public void cancelLongRunningDml() throws InterruptedException {
> sql("CREATE TABLE test (id INT PRIMARY KEY)");
> IgniteSql sql = igniteSql();
> // Long running DML query uses implicit RW transaction.
> String query = "INSERT INTO test SELECT x FROM system_range(0,
> 10000000000);";
> for (int i = 1; i <= 100; i++) {
> log.info("iteration #" + i);
> CancelHandle cancelHandle = CancelHandle.create();
> CancellationToken token = cancelHandle.token();
> // Run long DML query.
> CompletableFuture<ResultSet<SqlRow>> f =
> IgniteTestUtils.runAsync(() -> sql.execute(null, token,
> query));
> // Wait until the query starts executing.
> Awaitility.await().untilAsserted(() ->
> assertThat(queryProcessor().runningQueries(), greaterThan(0)));
> // Wait a bit more to improve failure rate.
> Thread.sleep(500);
> // Wait for query cancel.
> cancelHandle.cancel();
> // Query was actually cancelled.
> assertThat(queryProcessor().runningQueries(), is(0));
> assertThrowsSqlException(
> Sql.EXECUTION_CANCELLED_ERR,
> "The query was cancelled while executing.",
> () -> await(f)
> );
> // BUT the transaction may still be in progress (FAILING HERE).
> Awaitility.await().untilAsserted(() ->
> assertThat(txManager().pending(), is(0)));
> // Clean-up after iteration.
> sql("DELETE FROM test");
> }
> }
> {code}
> Error output
> {noformat}
> org.awaitility.core.ConditionTimeoutException: Assertion condition defined as
> a lambda expression in
> org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest
> Expected: is <0>
> but: was <1> within 10 seconds.
> Expected :is <0>
> Actual :<1> within 10 seconds.
> <Click to see difference>
> at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
> at
> org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
> at
> org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
> at
> org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1006)
> at
> org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:790)
> at
> org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest.cancelStatement(ItSqlSynchronousApiTest.java:114)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
> at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
> Caused by: java.lang.AssertionError:
> Expected: is <0>
> but: was <1>
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
> at
> org.apache.ignite.internal.sql.api.ItSqlSynchronousApiTest.lambda$cancelStatement$5(ItSqlSynchronousApiTest.java:114)
> at
> org.awaitility.core.AssertionCondition.lambda$new$0(AssertionCondition.java:53)
> at
> org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:248)
> at
> org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:235)
> 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:834)
> {noformat}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
