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

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Duplicate
• Affects Version/s: 3.0
• Component/s: general, persistence
• Labels: ignite-3
• Ignite Flags: Docs Required, Release Notes Required
• Assignee: Roman Puchkovskiy
• Reporter: Igor
• Created: 26/May/24 23:04
• Updated: 04/Sep/24 16:22
• Resolved: 17/Jul/24 10:54

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]]

Issue Links

• duplicates: IGNITE-21725 The exception "Primary replica has expired" on creation of 1000 tables
• relates to: IGNITE-22757 Excessive memory usage in schema-related code in SQL
• relates to: IGNITE-22760 JVM can crash due to access to spill-related RocksDB after closing it
• relates to: IGNITE-22758 In-memory Raft stores logs on heap for too long
• relates to: IGNITE-22759 Do not do partition SafeTime sync if previous attempt is not finished
• relates to: IGNITE-22761 Disable WAL in RocksDB used to spill volatile Raft logs on disk