ignite-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Andrey Kornev <andrewkor...@hotmail.com>
Subject Re: Long activation times with Ignite persistence enabled
Date Mon, 22 Jan 2018 19:36:07 GMT
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.goncharuk@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 <andrewkornev@hotmail.com<mailto:andrewkornev@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



Mime
View raw message