Ignite could not consumption the WAL log and release the OS buffer when persisten on
I have one ignite server with 128G memory, and with persistent enabled to keep my data safe.
As I got from the official document, my understanding: When Persitent enabled, Ignite will first save data changes to OS buffer(I check this as buff/cache in linux command free -mh), and then write to WAL log, and via checkpoint process periodically to analyze the WAL log and free the parsed WAL log disk space and release the used OS buffer, correct me if I am wrong.
But in my testing, When Ignite start to handling traffic, I found the OS buffer increase quickly and check the WAL log directory, there are lots wal log generated in order, nearly same as the size with buff/cache.
[root@Redis1 apache-ignite]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 109G 995M 1.7G 109G
Swap: 127G 0B 127G
127G
Only a few minutes, the free column reduced quickly vs. buff/cache increasing
[root@Redis1 apache-ignite]# free -mh
total used free shared buff/cache available
Mem: 125G 15G 85G 995M 25G 108G
Swap: 127G 0B 127G
and the WAL log size and segement numbers keep increasing also, still nearly same as the size with buff/cache.
I have check the ignite log, the checkpoint process audit each 3minutes:
[05:30:05,818][INFO][db-checkpoint-thread-#107][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=9428aebc-f2b0-4d33-bed6-fb9a1ad49848, startPtr=FileWALPointer [idx=341, fileOff=50223036, len=420491], checkpointLockWait=0ms, checkpointLockHoldTime=860ms, walCpRecordFsyncDuration=245ms, pages=89627, reason='timeout']
[05:30:22,429][INFO][db-checkpoint-thread-#107][GridCacheDatabaseSharedManager] Checkpoint finished [cpId=9428aebc-f2b0-4d33-bed6-fb9a1ad49848, pages=89627, markPos=FileWALPointer [idx=341, fileOff=50223036, len=420491], walSegmentsCleared=0, markDuration=1288ms, pagesWrite=844ms, fsync=15767ms, total=17899ms]
But for the output of "free -mh" command, "free" column could not be released, still increasing with traffic going on, even when I stopped traffic, it also doesn't get reduced, If i keep send traffic, the available memory keep reducing, and finally the avail memory reduced to around hundread MegaBytes,
[root@Redis1 apache-ignite]# free -mh
total used free shared buff/cache available
Mem: 125G 16G 370M 971M 108G 107G
Swap: 127G 0B 127G
When this happens(free memory exhausting?), all my service based on ignite stop to handle my new request anymore, for ignite, it hangs.
I also notice the Checkpoint log with reason='timeout', i don't know if this stand for that ignite could not properly parse the WAL log and free OS cache buffer? Is there anyway to let checkpoint work normally to free the memroy?
My question is how could I do something to prevent ignite exhausting the available memory, and keeping my service available with persistent on, I found if i turn persistent off, ignite handle very quickly, and cache usage less then 1G with same traffic, but when persistent flag enabled, The OS cache memroy increasing vert quickly and exhaust all the available memroy, then ignite could not resume from this conditon and hang.
I have tried many parameters, use WALMODE, LOG_ONLY or BACKGROUND, set -DIGNITE_WAL_MMAP=false in JVM, set checkpointPageBufferSize, but none of them could save my ignite service, it still eat the OS cache and exhaust it.
https://apacheignite.readme.io/docs/write-ahead-log https://apacheignite.readme.io/docs/durable-memory-tuning#section-checkpointing-buffer-size
<property name="dataStorageConfiguration">
<bean class="org.apache.ignite.configuration.DataStorageConfiguration">
<property name="defaultDataRegionConfiguration">
<bean class="org.apache.ignite.configuration.DataRegionConfiguration">
<!-- 10 GB initial size. -->
<property name="initialSize" value="#{10L * 1024 * 1024 * 1024}"/>
<!-- 50 GB maximum size. -->
<property name="maxSize" value="#{50L * 1024 * 1024 * 1024}"/>
<property name="persistenceEnabled" value="true"/>
<property name="checkpointPageBufferSize" value="#{1024L * 1024 * 1024}"/>
</bean>
</property>
<property name="writeThrottlingEnabled" value="true"/>
<property name="walMode" value="LOG_ONLY"/>
<property name="walPath" value="/wal/ebc"/>
<property name="walArchivePath" value="/wal/ebc"/>
</bean>
</property>
Bellow is my cache configuration:
public void createLvOneTxCache() {
CacheConfiguration<String, OrderInfo> cacheCfg =
new CacheConfiguration<>("LvOneTxCache");
cacheCfg.setCacheMode(CacheMode.REPLICATED);
//cacheCfg.setStoreKeepBinary(true);
cacheCfg.setAtomicityMode(ATOMIC);
ebcLvOneTxCache = ignite.getOrCreateCache(cacheCfg);
}
I have try to modify the parameters, but the OS cache still increasing:
<!-- Enabling Apache Ignite native persistence. -->
<property name="dataStorageConfiguration">
<bean class="org.apache.ignite.configuration.DataStorageConfiguration">
<property name="defaultDataRegionConfiguration">
<bean class="org.apache.ignite.configuration.DataRegionConfiguration">
<!-- 10 GB initial size. -->
<property name="initialSize" value="#{4L * 1024 * 1024 * 1024}"/>
<!-- 50 GB maximum size. -->
<property name="maxSize" value="#{4L * 1024 * 1024 * 1024}"/>
<property name="persistenceEnabled" value="true"/>
<property name="checkpointPageBufferSize" value="#{4L * 1024 * 1024 * 1024}"/>
</bean>
</property>
<property name="checkpointFrequency" value="6000"/>
<property name="checkpointThreads" value="32"/>
<property name="writeThrottlingEnabled" value="true"/>
<property name="walMode" value="LOG_ONLY"/>
<property name="walPath" value="/wal/ebc"/>
<property name="walArchivePath" value="/wal/ebc"/>
</bean>
</property>
And ignite log show audit quickly but the cache doesn't get released also.
[07:51:20,165][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=fd0c7e68-564a-4b40-9516-bb2a451869e7, startPtr=FileWALPointer [idx=23, fileOff=47849256, len=420491], checkpointLockWait=0ms, checkpointLockHoldTime=77ms, walCpRecordFsyncDuration=233ms, pages=7744, reason='timeout']
[07:51:20,219][INFO][sys-stripe-0-#1][PageMemoryImpl] Throttling is applied to page modifications [percentOfPartTime=0.36, markDirty=16378 pages/sec, checkpointWrite=3322 pages/sec, estIdealMarkDirty=673642 pages/sec, curDirty=0.00, maxDirty=0.40, avgParkTime=21501 ns, pages: (total=7744, evicted=0, written=7744, synced=229, cpBufUsed=0, cpBufTotal=1036430)]
[07:51:22,303][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint finished [cpId=fd0c7e68-564a-4b40-9516-bb2a451869e7, pages=7744, markPos=FileWALPointer [idx=23, fileOff=47849256, len=420491], walSegmentsCleared=0, markDuration=317ms, pagesWrite=24ms, fsync=2114ms, total=2456ms]
[07:51:26,117][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=d64991bc-3d2f-4f2c-8175-d7e92f46f0bf, startPtr=FileWALPointer [idx=25, fileOff=35951286, len=420491], checkpointLockWait=0ms, checkpointLockHoldTime=49ms, walCpRecordFsyncDuration=200ms, pages=7605, reason='timeout']
[07:51:28,612][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint finished [cpId=d64991bc-3d2f-4f2c-8175-d7e92f46f0bf, pages=7605, markPos=FileWALPointer [idx=25, fileOff=35951286, len=420491], walSegmentsCleared=0, markDuration=266ms, pagesWrite=23ms, fsync=2472ms, total=2761ms]
[07:51:32,118][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=07246861-57ae-4ef5-8419-cb7710d2f72d, startPtr=FileWALPointer [idx=27, fileOff=38042090, len=420491], checkpointLockWait=6ms, checkpointLockHoldTime=60ms, walCpRecordFsyncDuration=185ms, pages=7186, reason='timeout']
[07:51:32,121][INFO][service-#232][PageMemoryImpl] Throttling is applied to page modifications [percentOfPartTime=0.24, markDirty=10738 pages/sec, checkpointWrite=2757 pages/sec, estIdealMarkDirty=310976 pages/sec, curDirty=0.00, maxDirty=0.07, avgParkTime=358945 ns, pages: (total=7186, evicted=0, written=896, synced=0, cpBufUsed=565, cpBufTotal=1036430)]
[07:51:34,534][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint finished [cpId=07246861-57ae-4ef5-8419-cb7710d2f72d, pages=7186, markPos=FileWALPointer [idx=27, fileOff=38042090, len=420491], walSegmentsCleared=0, markDuration=257ms, pagesWrite=29ms, fsync=2387ms, total=2679ms]
[07:51:38,169][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=44e6870a-e370-4bd3-8ad9-8252abb0acd3, startPtr=FileWALPointer [idx=29, fileOff=44462293, len=420491], checkpointLockWait=0ms, checkpointLockHoldTime=76ms, walCpRecordFsyncDuration=210ms, pages=7529, reason='timeout']
[07:51:40,668][INFO][db-checkpoint-thread-#108][GridCacheDatabaseSharedManager] Checkpoint finished [cpId=44e6870a-e370-4bd3-8ad9-8252abb0acd3, pages=7529, markPos=FileWALPointer [idx=29, fileOff=44462293, len=420491], walSegmentsCleared=0, markDuration=303ms, pagesWrite=24ms, fsync=2475ms, total=2802ms]
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 107G 995M 3.5G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 107G 995M 3.5G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 107G 995M 3.5G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 105G 995M 5.6G 109G
Swap: 127G 0B 127G
When I stop the traffic to update the cache, and i find the OS cache get back, but very very slow, it takes very long time to be released, with quick checkpointFrequency 6s. How could this could be handled quickly?
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 104G 995M 6.5G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 104G 995M 6.3G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 104G 995M 6.3G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 106G 995M 4.6G 109G
Swap: 127G 0B 127G
[root@Redis1 node00-296a5110-74ad-45e0-bf9c-5c075a4f5fdf]# free -mh
total used free shared buff/cache available
Mem: 125G 14G 106G 995M 4.4G 109G
It's totally fine that OS caches disk data, it's very good explained here linux ate my ram. If your kernel supports, you always may set amount of free memory, that could reduce pauses when Ignite allocates new memory blocks