Uploaded image for project: 'Ignite'
  1. Ignite
  2. IGNITE-19591

Possible bottleneck with RocksDB on multiple table creation, with RocksDB as table storage

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • None
    • 3.0
    • None

    Description

      Scenario:

      • 1 node cluster
      • rocksdb table storage ( created via SQL query create zone test_zone engine rocksdb with partitions=25 )
      • sequential tables creation using this zone (queries like CREATE TABLE table_0(id INT PRIMARY KEY, column_1 VARCHAR, column_2 VARCHAR, column_3 VARCHAR, column_4 VARCHAR) with primary_zone='TEST_ZONE'  ). Number of talbes: 1000, pause between query executions: 30 ms.

      After creating a couple of hundreds of tables, queries start failing with timeout.

      Threads are busy with RocksDB write operations:

        

      "%sqllogic0%JRaft-FSMCaller-Disruptor-_stripe_0-0" #28 daemon prio=5 os_prio=0 cpu=203.13ms elapsed=58.63s tid=0x000001e4966a0800 nid=0x37e0 runnable  [0x0000002e032ff000]
        java.lang.Thread.State: RUNNABLE
        at org.rocksdb.RocksDB.write1(Native Method)
        at org.rocksdb.RocksDB.write(RocksDB.java:1722)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.lambda$runConsistently$1(RocksDbMvPartitionStorage.java:236)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage$$Lambda$2003/0x00000008014ecc40.get(Unknown Source)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.busy(RocksDbMvPartitionStorage.java:1415)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.runConsistently(RocksDbMvPartitionStorage.java:222)
        at org.apache.ignite.internal.table.distributed.raft.snapshot.outgoing.SnapshotAwarePartitionDataStorage.runConsistently(SnapshotAwarePartitionDataStorage.java:66)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.handleBuildIndexCommand(PartitionListener.java:471)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.lambda$onWrite$2(PartitionListener.java:187)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener$$Lambda$2187/0x0000000801536040.accept(Unknown Source)
        at java.util.Iterator.forEachRemaining(java.base@13.0.1/Iterator.java:133)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.onWrite(PartitionListener.java:149)
        at org.apache.ignite.internal.raft.server.impl.JraftServerImpl$DelegatingStateMachine.onApply(JraftServerImpl.java:592)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.doApplyTasks(FSMCallerImpl.java:561)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.doCommitted(FSMCallerImpl.java:529)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.runApplyTask(FSMCallerImpl.java:448)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:136)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:130)
        at org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:217)
        at org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:181)
        at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:137)
        at java.lang.Thread.run(java.base@13.0.1/Thread.java:830)

"%sqllogic0%vault-1" #92 prio=5 os_prio=0 cpu=2687.50ms elapsed=58.52s tid=0x000001e49bdfc000 nid=0x6f24 runnable  [0x0000002e079fd000]
        java.lang.Thread.State: RUNNABLE
        at org.rocksdb.RocksDB.open(Native Method)
        at org.rocksdb.RocksDB.open(RocksDB.java:307)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbTableStorage.lambda$start$1(RocksDbTableStorage.java:251)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbTableStorage$$Lambda$1786/0x000000080148a040.run(Unknown Source)
        at org.apache.ignite.internal.util.IgniteUtils.inBusyLock(IgniteUtils.java:889)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbTableStorage.start(RocksDbTableStorage.java:223)
        at org.apache.ignite.internal.table.distributed.TableManager.createTableStorage(TableManager.java:1159)
        at org.apache.ignite.internal.table.distributed.TableManager.createTableLocally(TableManager.java:1103)
        at org.apache.ignite.internal.table.distributed.TableManager.onTableCreate(TableManager.java:547)
        at org.apache.ignite.internal.table.distributed.TableManager$1.onCreate(TableManager.java:460)
        at org.apache.ignite.internal.configuration.notifications.ConfigurationNotifier$1$$Lambda$1711/0x0000000801460440.apply(Unknown Source)
        at org.apache.ignite.internal.configuration.notifications.ConfigurationNotifier.notifyPublicListeners(ConfigurationNotifier.java:488)
        at org.apache.ignite.internal.configuration.notifications.ConfigurationNotifier$1.visitNamedListNode(ConfigurationNotifier.java:206)
        at org.apache.ignite.internal.configuration.notifications.ConfigurationNotifier$1.visitNamedListNode(ConfigurationNotifier.java:129)
        at org.apache.ignite.internal.schema.configuration.TablesNode.traverseChildren(Unknown Source)
        at org.apache.ignite.internal.configuration.notifications.ConfigurationNotifier.notifyListeners(ConfigurationNotifier.java:129)
        at org.apache.ignite.internal.configuration.notifications.ConfigurationNotifier.notifyListeners(ConfigurationNotifier.java:91)
        at org.apache.ignite.internal.configuration.ConfigurationRegistry$3$1.visitInnerNode(ConfigurationRegistry.java:271)
        at org.apache.ignite.internal.configuration.ConfigurationRegistry$3$1.visitInnerNode(ConfigurationRegistry.java:254)
        at org.apache.ignite.internal.configuration.SuperRoot.traverseChildren(SuperRoot.java:105)
        at org.apache.ignite.internal.configuration.ConfigurationRegistry$3.onConfigurationUpdated(ConfigurationRegistry.java:254)
        at org.apache.ignite.internal.configuration.ConfigurationChanger$3.lambda$onEntriesChanged$1(ConfigurationChanger.java:658)
        at org.apache.ignite.internal.configuration.ConfigurationChanger$3$$Lambda$1702/0x000000080145d440.apply(Unknown Source)
        at java.util.concurrent.CompletableFuture$UniCompose.tryFire(java.base@13.0.1/CompletableFuture.java:1146)
        at java.util.concurrent.CompletableFuture.postComplete(java.base@13.0.1/CompletableFuture.java:506)
        at java.util.concurrent.CompletableFuture$AsyncRun.run(java.base@13.0.1/CompletableFuture.java:1813)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@13.0.1/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@13.0.1/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@13.0.1/Thread.java:830)

"%sqllogic0%JRaft-FSMCaller-Disruptor-_stripe_1-0" #29 daemon prio=5 os_prio=0 cpu=140.63ms elapsed=58.63s tid=0x000001e49669c800 nid=0x2214 runnable  [0x0000002e033fe000]
        java.lang.Thread.State: RUNNABLE
        at org.rocksdb.RocksDB.write1(Native Method)
        at org.rocksdb.RocksDB.write(RocksDB.java:1722)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.lambda$runConsistently$1(RocksDbMvPartitionStorage.java:236)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage$$Lambda$2003/0x00000008014ecc40.get(Unknown Source)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.busy(RocksDbMvPartitionStorage.java:1415)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.runConsistently(RocksDbMvPartitionStorage.java:222)
        at org.apache.ignite.internal.table.distributed.raft.snapshot.outgoing.SnapshotAwarePartitionDataStorage.runConsistently(SnapshotAwarePartitionDataStorage.java:66)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.handleSafeTimeSyncCommand(PartitionListener.java:378)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.lambda$onWrite$2(PartitionListener.java:185)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener$$Lambda$2187/0x0000000801536040.accept(Unknown Source)
        at java.util.Iterator.forEachRemaining(java.base@13.0.1/Iterator.java:133)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.onWrite(PartitionListener.java:149)
        at org.apache.ignite.internal.raft.server.impl.JraftServerImpl$DelegatingStateMachine.onApply(JraftServerImpl.java:592)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.doApplyTasks(FSMCallerImpl.java:561)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.doCommitted(FSMCallerImpl.java:529)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.runApplyTask(FSMCallerImpl.java:448)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:136)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:130)
        at org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:217)
        at org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:181)
        at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:137)
        at java.lang.Thread.run(java.base@13.0.1/Thread.java:830)


"%sqllogic0%JRaft-FSMCaller-Disruptor-_stripe_2-0" #30 daemon prio=5 os_prio=0 cpu=140.63ms elapsed=58.63s tid=0x000001e49669d000 nid=0x7770 runnable  [0x0000002e034fe000]
        java.lang.Thread.State: RUNNABLE
        at org.rocksdb.RocksDB.write1(Native Method)
        at org.rocksdb.RocksDB.write(RocksDB.java:1722)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.lambda$runConsistently$1(RocksDbMvPartitionStorage.java:236)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage$$Lambda$2003/0x00000008014ecc40.get(Unknown Source)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.busy(RocksDbMvPartitionStorage.java:1415)
        at org.apache.ignite.internal.storage.rocksdb.RocksDbMvPartitionStorage.runConsistently(RocksDbMvPartitionStorage.java:222)
        at org.apache.ignite.internal.table.distributed.raft.snapshot.outgoing.SnapshotAwarePartitionDataStorage.runConsistently(SnapshotAwarePartitionDataStorage.java:66)
        at org.apache.ignite.internal.table.distributed.raft.PartitionListener.onConfigurationCommitted(PartitionListener.java:398)
        at org.apache.ignite.internal.raft.server.impl.JraftServerImpl$DelegatingStateMachine.onRawConfigurationCommitted(JraftServerImpl.java:669)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.doCommitted(FSMCallerImpl.java:511)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl.runApplyTask(FSMCallerImpl.java:448)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:136)
        at org.apache.ignite.raft.jraft.core.FSMCallerImpl$ApplyTaskHandler.onEvent(FSMCallerImpl.java:130)
        at org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:217)
        at org.apache.ignite.raft.jraft.disruptor.StripedDisruptor$StripeEntryHandler.onEvent(StripedDisruptor.java:181)
        at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:137)
        at java.lang.Thread.run(java.base@13.0.1/Thread.java:830)

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. IGNITE-19275 Creation of big amount of tables throws exception

          • Critical - Crashes, loss of data, severe memory leak.
          • Resolved
          links to

          Web Link GitHub Pull Request #2200

          Activity

            People

              ibessonov Ivan Bessonov
              Denis Chudov Denis Chudov
              Kirill Tkalenko Kirill Tkalenko
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 2h 10m
                  2h 10m