Igor created IGNITE-22331:
-----------------------------
Summary: Storage aimem throws "Failed to commit the transaction."
on creation of 1000 tables
Key: IGNITE-22331
URL: https://issues.apache.org/jira/browse/IGNITE-22331
Project: Ignite
Issue Type: Bug
Components: general, persistence
Affects Versions: 3.0.0-beta2
Reporter: Igor
*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:
{code:java}
java.sql.SQLException: The primary replica has changed
[expectedLeaseholderName=TablesAmountCapacityTest_cluster_0,
currentLeaseholderName=null,
expectedLeaseholderId=bf69f842-d6c8-4f7a-b7e4-96458a4d92cb,
currentLeaseholderId=null,
expectedEnlistmentConsistencyToken=112491691050598880,
currentEnlistmentConsistencyToken=null] 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){code}
In server logs there is an exception:
{code:java}
2024-05-23 17:57:19:570 +0000
[WARNING][CompletableFutureDelayScheduler][RaftGroupServiceImpl] Recoverable
error during the request occurred (will be retried on the randomly selected
node) [request=WriteActionRequestImpl [command=[0, 9, 41, -58, -128, -112, -21,
-103, -45, -23, -57, 1], deserializedCommand=SafeTimeSyncCommandImpl
[safeTimeLong=112491694408335429], groupId=3402_part_7], 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-23 17:57:19:570 +0000
[WARNING][CompletableFutureDelayScheduler][RaftGroupServiceImpl] Recoverable
error during the request occurred (will be retried on the randomly selected
node) [request=WriteActionRequestImpl [command=[0, 9, 41, -106, -128, -108,
-21, -103, -45, -23, -57, 1], deserializedCommand=SafeTimeSyncCommandImpl
[safeTimeLong=112491694408400917], groupId=3402_part_21], 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-23 17:57:19:588 +0000
[WARNING][CompletableFutureDelayScheduler][RaftGroupServiceImpl] Recoverable
error during the request occurred (will be retried on the randomly selected
node) [request=WriteActionRequestImpl [command=[112, 71, 2, -126, -128, -80,
-11, -103, -45, -23, -57, 1, 1], deserializedCommand=SyncTimeCommandImpl
[initiatorTerm=1, initiatorTimeLong=112491694429831169,
safeTimeLong=112491694429831171], groupId=metastorage_group], 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-23 17:57:19:809 +0000
[INFO][%TablesAmountCapacityTest_cluster_0%sql-execution-pool-3][JdbcQueryEventHandlerImpl]
Exception while executing query [query=insert into test_table_804(id,
column_1, column_2, column_3, column_4, column_5, column_6, column_7, column_8,
column_9, column_10, column_11, column_12, column_13, column_14, column_15,
column_16, column_17, column_18, column_19, column_20, column_21, column_22,
column_23, column_24, column_25, column_26, column_27, column_28, column_29,
column_30, column_31, column_32, column_33, column_34, column_35, column_36,
column_37, column_38, column_39, column_40, column_41, column_42, column_43,
column_44, column_45, column_46, column_47, column_48, column_49, column_50,
column_51, column_52, column_53, column_54, column_55, column_56, column_57,
column_58, column_59, column_60, column_61, column_62, column_63, column_64,
column_65, column_66, column_67, column_68, column_69, column_70, column_71,
column_72, column_73, column_74, column_75, column_76, column_77, column_78,
column_79, column_80, column_81, column_82, column_83, column_84, column_85,
column_86, column_87, column_88, column_89, column_90, column_91, column_92,
column_93, column_94, column_95, column_96, column_97, column_98, column_99,
column_100, column_101, column_102, column_103, column_104, column_105,
column_106, column_107, column_108, column_109, column_110, column_111,
column_112, column_113, column_114, column_115, column_116, column_117,
column_118, column_119, column_120, column_121, column_122, column_123,
column_124, column_125, column_126, column_127, column_128, column_129,
column_130, column_131, column_132, column_133, column_134, column_135,
column_136, column_137, column_138, column_139, column_140, column_141,
column_142, column_143, column_144, column_145, column_146, column_147,
column_148, column_149, column_150, column_151, column_152, column_153,
column_154, column_155, column_156, column_157, column_158, column_159,
column_160, column_161, column_162, column_163, column_164, column_165,
column_166, column_167, column_168, column_169, column_170, column_171,
column_172, column_173, column_174, column_175, column_176, column_177,
column_178, column_179, column_180, column_181, column_182, column_183,
column_184, column_185, column_186, column_187, column_188, column_189,
column_190, column_191, column_192, column_193, column_194, column_195,
column_196, column_197, column_198, column_199) values (?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
org.apache.ignite.sql.SqlException: IGN-CMN-65535
TraceId:deb29fc0-b0b6-4cb6-a727-2f326cfbecea The primary replica has changed
[expectedLeaseholderName=TablesAmountCapacityTest_cluster_0,
currentLeaseholderName=null,
expectedLeaseholderId=bf69f842-d6c8-4f7a-b7e4-96458a4d92cb,
currentLeaseholderId=null,
expectedEnlistmentConsistencyToken=112491691050598880,
currentEnlistmentConsistencyToken=null]
at
org.apache.ignite.internal.lang.SqlExceptionMapperUtil.mapToPublicSqlException(SqlExceptionMapperUtil.java:61)
at
org.apache.ignite.internal.sql.engine.SqlQueryProcessor$PrefetchCallback.onPrefetchComplete(SqlQueryProcessor.java:1123)
at
org.apache.ignite.internal.sql.engine.prepare.KeyValueModifyPlan.lambda$execute$3(KeyValueModifyPlan.java:141)
at
java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
at
java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
at
java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionContext.lambda$execute$0(ExecutionContext.java:329)
at
org.apache.ignite.internal.sql.engine.exec.QueryTaskExecutorImpl.lambda$execute$0(QueryTaskExecutorImpl.java:83)
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: org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:deb29fc0-b0b6-4cb6-a727-2f326cfbecea The primary replica has changed
[expectedLeaseholderName=TablesAmountCapacityTest_cluster_0,
currentLeaseholderName=null,
expectedLeaseholderId=bf69f842-d6c8-4f7a-b7e4-96458a4d92cb,
currentLeaseholderId=null,
expectedEnlistmentConsistencyToken=112491691050598880,
currentEnlistmentConsistencyToken=null]
at
org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:118)
at
org.apache.ignite.internal.lang.SqlExceptionMapperUtil.mapToPublicSqlException(SqlExceptionMapperUtil.java:51)
... 10 more
Caused by:
org.apache.ignite.internal.replicator.exception.PrimaryReplicaMissException:
IGN-REP-6 TraceId:deb29fc0-b0b6-4cb6-a727-2f326cfbecea The primary replica has
changed [expectedLeaseholderName=TablesAmountCapacityTest_cluster_0,
currentLeaseholderName=null,
expectedLeaseholderId=bf69f842-d6c8-4f7a-b7e4-96458a4d92cb,
currentLeaseholderId=null,
expectedEnlistmentConsistencyToken=112491691050598880,
currentEnlistmentConsistencyToken=null]
at
org.apache.ignite.internal.table.distributed.replicator.PartitionReplicaListener.lambda$ensureReplicaIsPrimary$215(PartitionReplicaListener.java:3782)
at
java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072)
at
java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at
java.base/java.util.concurrent.CompletableFuture.postFire(CompletableFuture.java:610)
at
java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:649)
at
java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)
... 3 more
2024-05-23 17:57:19:819 +0000
[INFO][TablesAmountCapacityTest_cluster_0-srv-worker-1][ClientInboundMessageHandler]
Partition primary replica changed, notifying client [connectionId=1,
remoteAddress=/127.0.0.1:49190]{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
