[IGNITE-22331] Storage aimem throws "Failed to commit the transaction." on creation of 1000 tables

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 3.0.0-beta2
• Component/s: general, persistence
• Labels: ignite-3
• Ignite Flags: Docs Required, Release Notes Required
• Assignee: Unassigned
• Reporter: Igor
• Created: 26/May/24 23:04
• Updated: 26/May/24 23:05

Description

Steps to reproduce:

1. Start cluster with 1 node with JVM options: "-Xms4096m -Xmx4096m"

2. Create 1000 tables with 200 varchar columns each  and insert 1 row into each. One by one.

Expected result:
Tables are created.

Actual result:

On table ~850 the exception is thrown:

java.sql.SQLException: Failed to commit the transaction.
          at org.apache.ignite.internal.jdbc.proto.IgniteQueryErrorCode.createJdbcSqlException(IgniteQueryErrorCode.java:57)
          at org.apache.ignite.internal.jdbc.JdbcStatement.execute0(JdbcStatement.java:154)
          at org.apache.ignite.internal.jdbc.JdbcPreparedStatement.executeWithArguments(JdbcPreparedStatement.java:765)
          at org.apache.ignite.internal.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:173)
          at org.gridgain.ai3tests.tests.amountcapacity.TablesAmountCapacityBaseTest.lambda$insertRowAndAssertTimeout$2(TablesAmountCapacityBaseTest.java:92)
          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)

In server logs there are reapeating exceptions:

2024-05-22 19:17:55:328 +0000 [WARNING][CompletableFutureDelayScheduler][RaftGroupServiceImpl] Recoverable error during the request occurred (will be retried on the randomly selected node) [request=WriteActionRequestImpl [command=[0, 9, 42, -106, -126, -44, -28, -50, -73, -24, -57, 1], deserializedCommand=PrimaryReplicaChangeCommandImpl [leaseStartTime=112486348502663445], groupId=3014_part_22], peer=Peer [consistentId=TablesAmountCapacityTest_cluster_0, idx=0], newPeer=Peer [consistentId=TablesAmountCapacityTest_cluster_0, idx=0]].
java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException
    at java.base/java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:367)
    at java.base/java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:376)
    at java.base/java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:1019)
    at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
    at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
    at java.base/java.util.concurrent.CompletableFuture$Timeout.run(CompletableFuture.java:2792)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
    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)
Caused by: java.util.concurrent.TimeoutException
    ... 7 more
2024-05-22 19:17:55:328 +0000 [WARNING][CompletableFutureDelayScheduler][RaftGroupServiceImpl] Recoverable error during the request occurred (will be retried on the randomly selected node) [request=WriteActionRequestImpl [command=[0, 9, 42, -103, -126, -44, -28, -50, -73, -24, -57, 1], deserializedCommand=PrimaryReplicaChangeCommandImpl [leaseStartTime=112486348502663448], groupId=3026_part_2], peer=Peer [consistentId=TablesAmountCapacityTest_cluster_0, idx=0], newPeer=Peer [consistentId=TablesAmountCapacityTest_cluster_0, idx=0]].
java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException
    at java.base/java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:367)
    at java.base/java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:376)
    at java.base/java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:1019)
    at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
    at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
    at java.base/java.util.concurrent.CompletableFuture$Timeout.run(CompletableFuture.java:2792)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
    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)
Caused by: java.util.concurrent.TimeoutException
    ... 7 more
2024-05-22 19:17:55:360 +0000 [WARNING][%TablesAmountCapacityTest_cluster_0%metastorage-watch-executor-1][WatchProcessor] Watch event processing has been too long [duration=356, keys=[placementdriver.leases]]