Alexey, Thanks a lot for looking into this!
My configuration is very basic: 3 caches all using standard 1024 partitions, sharing a 1GB persistent memory region. Please find below the stack trace of the exchange worker thread captured while the node's activation is in progress (2.4 Ignite branch). Hope it helps! Thanks! Andrey "exchange-worker-#42%ignite-2%" #82 prio=5 os_prio=31 tid=0x00007ffe8bf1c000 nid=0xc403 waiting on condition [0x000070000ed43000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:304) at org.apache.ignite.internal.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:177) at org.apache.ignite.internal.util.future.GridFutureAdapter.getUninterruptibly(GridFutureAdapter.java:145) at org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIO.read(AsyncFileIO.java:95) at org.apache.ignite.internal.processors.cache.persistence.file.FilePageStore.read(FilePageStore.java:324) at org.apache.ignite.internal.processors.cache.persistence.file.FilePageStoreManager.read(FilePageStoreManager.java:306) at org.apache.ignite.internal.processors.cache.persistence.file.FilePageStoreManager.read(FilePageStoreManager.java:291) at org.apache.ignite.internal.processors.cache.persistence.pagemem.PageMemoryImpl.acquirePage(PageMemoryImpl.java:656) at org.apache.ignite.internal.processors.cache.persistence.pagemem.PageMemoryImpl.acquirePage(PageMemoryImpl.java:576) at org.apache.ignite.internal.processors.cache.persistence.DataStructure.acquirePage(DataStructure.java:130) at org.apache.ignite.internal.processors.cache.persistence.freelist.PagesList.init(PagesList.java:212) at org.apache.ignite.internal.processors.cache.persistence.freelist.AbstractFreeList.<init>(AbstractFreeList.java:367) at org.apache.ignite.internal.processors.cache.persistence.freelist.CacheFreeListImpl.<init>(CacheFreeListImpl.java:47) at org.apache.ignite.internal.processors.cache.persistence.GridCacheOffheapManager$GridCacheDataStore$1.<init>(GridCacheOffheapManager.java:1041) at org.apache.ignite.internal.processors.cache.persistence.GridCacheOffheapManager$GridCacheDataStore.init0(GridCacheOffheapManager.java:1041) at org.apache.ignite.internal.processors.cache.persistence.GridCacheOffheapManager$GridCacheDataStore.updateCounter(GridCacheOffheapManager.java:1247) at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLocalPartition.updateCounter(GridDhtLocalPartition.java:835) at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLocalPartition.casState(GridDhtLocalPartition.java:523) - locked <0x000000077a3d1120> (a org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLocalPartition) at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLocalPartition.<init>(GridDhtLocalPartition.java:218) at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.forceCreatePartition(GridDhtPartitionTopologyImpl.java:804) at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.restorePartitionState(GridCacheDatabaseSharedManager.java:2196) at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.applyLastUpdates(GridCacheDatabaseSharedManager.java:2155) at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.restoreState(GridCacheDatabaseSharedManager.java:1322) at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.beforeExchange(GridCacheDatabaseSharedManager.java:1113) at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.distributedExchange(GridDhtPartitionsExchangeFuture.java:1063) at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:661) at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:2329) at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110) at java.lang.Thread.run(Thread.java:748) 2018-01-22 11:30:01,049 INFO [exchange-worker-#42%ContentStore-2%] GridCacheDatabaseSharedManager - Finished applying WAL changes [updatesApplied=0, time=68435ms] 2018-01-22 11:30:01,789 INFO [main] GridDiscoveryManager - Topology snapshot [ver=4, servers=2, clients=0, CPUs=8, offheap=26.0GB, heap=4.0GB] 2018-01-22 11:30:01,789 INFO [main] GridDiscoveryManager - Data Regions Configured: 2018-01-22 11:30:01,789 INFO [main] GridDiscoveryManager - ^-- default [initSize=256.0 MiB, maxSize=12.0 GiB, persistenceEnabled=false] 2018-01-22 11:30:01,789 INFO [main] GridDiscoveryManager - ^-- durable [initSize=256.0 MiB, maxSize=1.0 GiB, persistenceEnabled=true] ________________________________ From: Alexey Goncharuk <alexey.goncha...@gmail.com> Sent: Monday, January 22, 2018 12:30 AM To: user@ignite.apache.org Subject: Re: Long activation times with Ignite persistence enabled Andrey, Can you please describe in greater detail the configuration of your nodes (specifically, number of caches and number of partitions). Ignite would not load all the partitions into memory on startup simply because there is no such logic. What it does, however, is loading meta pages for each partition in each cache group to determine the correct cluster state and schedule rebalancing, if needed. If the number of caches x number of partitions is high, this may take a while. If this is the case, you can either reduce the number of partitions or group logical caches with the same affinity into physical cache group, so that those caches will share the same partition file. See CacheConfiguration#setGroupName(String) for more detail. Last but not least, it looks very suspicious that with 0 pending updates it took almost 90 seconds to read WAL. From the code, I see that this again may be related to partition state recovery, I will need to re-check this and get back to you later. Thanks, AG 2018-01-19 2:51 GMT+03:00 Andrey Kornev <andrewkor...@hotmail.com<mailto:andrewkor...@hotmail.com>>: Hello, I'm wondering if there is a way to improve the startup time of Ignite node when the persistence is enabled? It seems the time is proportional to the size (and number) of the partition files. This is somewhat surprising as I expected the startup time be the same (plus-minus some constant factor) regardless of the amount of data persisted. The delay looks to be due to Ignite loading *all* partition files for *all* persistence-enabled caches as part of a node's join. Here's an example of the startup log output: 2018-01-18 14:00:40,230 INFO [exchange-worker-#42%ignite-1%] GridCacheDatabaseSharedManager - Read checkpoint status [startMarker=/tmp/storage/data/1/cp/1516311778910-d56f8ceb-2205-4bef-9ed3-a7446e34aa06-START.bin, endMarker=/tmp/storage/data/1/cp/1516311778910-d56f8ceb-2205-4bef-9ed3-a7446e34aa06-END.bin] 2018-01-18 14:00:40,230 INFO [exchange-worker-#42%ignite-1%] GridCacheDatabaseSharedManager - Applying lost cache updates since last checkpoint record [lastMarked=FileWALPointer [idx=1693, fileOff=7970054, len=60339], lastCheckpointId=d56f8ceb-2205-4bef-9ed3-a7446e34aa06] 2018-01-18 14:00:57,114 WARN [exchange-worker-#42%ignite-1%] PageMemoryImpl - Page evictions started, this will affect storage performance (consider increasing DataRegionConfiguration#setMaxSize). 2018-01-18 14:02:05,469 INFO [exchange-worker-#42%ignite-1%] GridCacheDatabaseSharedManager - Finished applying WAL changes [updatesApplied=0, time=85234ms] It took ≈1.5 minute to activate a node. To add insult to injury, the eviction kicked in and most of the loaded pages got evicted (in this test, I had the caches sharing a 1GB memory region loading about 10GB of data and index). In general, I think it's not unreasonable to expect 1-to-10 ratio of the data region size to the total persisted data size. Why load all that data in the first place? It seems like a huge waste of time. Can the data partitions be loaded lazily on demand while the index partition can still be loaded during node startup? Thanks Andrey
