![]() |
Hi community, Call IgniteCache.destroy Method, NPE appears,logs are as follows: 2020-12-07 17:32:18.870 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.e.time - Started exchange init [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=279], crd=true, evt=DISCOVERY_CUSTOM_EVT, evtNode=320935f6-3516-4b0b-9e5f-e80768696522, customEvt=DynamicCacheChangeBatch [id=1f2a90e2671-562b8f51-fa6a-4094-928c-6976ce87614a, reqs=ArrayList [DynamicCacheChangeRequest [cacheName=PksQuota, hasCfg=false, nodeId=320935f6-3516-4b0b-9e5f-e80768696522, clientStartOnly=false, stop=true, destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions [startCaches=null, stopCaches=[PksQuota], startGrps=[], stopGrps=[PksQuota, destroy=true], resetParts=null, stateChangeRequest=null], startCaches=false], allowMerge=false, exchangeFreeSwitch=false] 2020-12-07 17:32:18.873 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture - Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=279], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED] 2020-12-07 17:32:18.873 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture - Finished waiting for partitions release latch: ServerLatch [permits=0, pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid [id=exchange, topVer=AffinityTopologyVersion [topVer=1, minorTopVer=279]]]] 2020-12-07 17:32:18.873 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture - Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=279], waitTime=0ms, futInfo=NA, mode=LOCAL] 2020-12-07 17:32:19.037 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture - finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=279], resVer=AffinityTopologyVersion [topVer=1, minorTopVer=279]] 2020-12-07 17:32:19.438 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture - Finish exchange future [startVer=AffinityTopologyVersion [topVer=1, minorTopVer=279], resVer=AffinityTopologyVersion [topVer=1, minorTopVer=279], err=null, rebalanced=true, wasRebalanced=true] 2020-12-07 17:32:20.870 [] [db-checkpoint-thread-#75%tradecore%] INFO o.a.i.i.p.c.p.GridCacheDatabaseSharedManager - Checkpoint started [checkpointId=f001018a-100e-4154-98c9-547dabf5015f, startPtr=FileWALPointer [idx=16, fileOff=1059360696, len=4770137], checkpointBeforeLockTime=549ms, checkpointLockWait=0ms, checkpointListenersExecuteTime=529ms, checkpointLockHoldTime=853ms, walCpRecordFsyncDuration=17ms, writeCheckpointEntryDuration=7ms, splitAndSortCpPagesDuration=4ms, pages=10775, reason='caches stop'] 2020-12-07 17:32:21.255 [] [checkpoint-runner-#79%tradecore%] WARN o.a.i.i.p.c.p.GridCacheDatabaseSharedManager - 1 checkpoint pages were not written yet due to unsuccessful page write lock acquisition and will be retried 2020-12-07 17:32:21.261 [] [exchange-worker-#54%tradecore%] ERROR o.a.i.i.p.c.GridCacheProcessor - Failed to wait for checkpoint finish during cache stop. org.apache.ignite.IgniteCheckedException: Compound exception for CountDownFuture. at org.apache.ignite.internal.util.future.CountDownFuture.addError(CountDownFuture.java:72) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.util.future.CountDownFuture.onDone(CountDownFuture.java:46) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.util.future.CountDownFuture.onDone(CountDownFuture.java:28) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:478) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$WriteCheckpointPages.run(GridCacheDatabaseSharedManager.java:4546) ~[ignite-core-2.9.0.jar!/:2.9.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_272] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_272] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_272] Suppressed: java.lang.NullPointerException at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$WriteCheckpointPages.writePages(GridCacheDatabaseSharedManager.java:4584) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$WriteCheckpointPages.run(GridCacheDatabaseSharedManager.java:4540) ~[ignite-core-2.9.0.jar!/:2.9.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_272] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_272] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_272] 2020-12-07 17:32:21.265 [] [exchange-worker-#54%tradecore%] INFO o.a.i.i.p.c.GridCacheProcessor - Stopped cache [cacheName=PksQuota] 2020-12-07 17:32:21.268 [] [db-checkpoint-thread-#75%tradecore%] ERROR c.j.i.i.c.IgniteConfig - Critical system error detected. Will be handled accordingly to configured handler [hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0, super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext [type=CRITICAL_ERROR, err=class o.a.i.IgniteCheckedException: Compound exception for CountDownFuture.]] org.apache.ignite.IgniteCheckedException: Compound exception for CountDownFuture. at org.apache.ignite.internal.util.future.CountDownFuture.addError(CountDownFuture.java:72) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.util.future.CountDownFuture.onDone(CountDownFuture.java:46) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.util.future.CountDownFuture.onDone(CountDownFuture.java:28) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:478) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$WriteCheckpointPages.run(GridCacheDatabaseSharedManager.java:4546) ~[ignite-core-2.9.0.jar!/:2.9.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_272] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_272] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_272] Suppressed: java.lang.NullPointerException at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$WriteCheckpointPages.writePages(GridCacheDatabaseSharedManager.java:4584) ~[ignite-core-2.9.0.jar!/:2.9.0] at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$WriteCheckpointPages.run(GridCacheDatabaseSharedManager.java:4540) ~[ignite-core-2.9.0.jar!/:2.9.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_272] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_272] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_272] 2020-12-07 17:32:21.558 [] [db-checkpoint-thread-#75%tradecore%] WARN o.a.i.i.p.c.CacheDiagnosticManager - Page locks dump:
Thread=[name=Ims-PublishThread-sync0, id=122], state=WAITING Locked pages = [] Locked pages log: name=Ims-PublishThread-sync0 time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=MessageBus-1, id=22], state=WAITING Locked pages = [] Locked pages log: name=MessageBus-1 time=(1607333541276, 2020-12-07 17:32:21.276)
Thread=[name=MessageBus-2, id=23], state=WAITING Locked pages = [] Locked pages log: name=MessageBus-2 time=(1607333541276, 2020-12-07 17:32:21.276)
Thread=[name=MessageBus-3, id=24], state=WAITING Locked pages = [] Locked pages log: name=MessageBus-3 time=(1607333541276, 2020-12-07 17:32:21.276)
Thread=[name=MessageBus-4, id=25], state=WAITING Locked pages = [] Locked pages log: name=MessageBus-4 time=(1607333541276, 2020-12-07 17:32:21.276)
Thread=[name=checkpoint-runner-#76%tradecore%, id=114], state=WAITING Locked pages = [] Locked pages log: name=checkpoint-runner-#76%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=checkpoint-runner-#77%tradecore%, id=115], state=WAITING Locked pages = [] Locked pages log: name=checkpoint-runner-#77%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=checkpoint-runner-#78%tradecore%, id=116], state=WAITING Locked pages = [] Locked pages log: name=checkpoint-runner-#78%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=checkpoint-runner-#79%tradecore%, id=117], state=WAITING Locked pages = [] Locked pages log: name=checkpoint-runner-#79%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-0-#9%tradecore%, id=34], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-0-#9%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-1-#10%tradecore%, id=35], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-1-#10%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-2-#11%tradecore%, id=36], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-2-#11%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-3-#12%tradecore%, id=37], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-3-#12%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-4-#13%tradecore%, id=38], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-4-#13%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-5-#14%tradecore%, id=39], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-5-#14%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-6-#15%tradecore%, id=40], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-6-#15%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=data-streamer-stripe-7-#16%tradecore%, id=41], state=WAITING Locked pages = [] Locked pages log: name=data-streamer-stripe-7-#16%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=db-checkpoint-thread-#75%tradecore%, id=113], state=RUNNABLE Locked pages = [] Locked pages log: name=db-checkpoint-thread-#75%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=dms-writer-thread-#58%tradecore%, id=95], state=WAITING Locked pages = [] Locked pages log: name=dms-writer-thread-#58%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=exchange-worker-#54%tradecore%, id=91], state=WAITING Locked pages = [] Locked pages log: name=exchange-worker-#54%tradecore% time=(1607333541276, 2020-12-07 17:32:21.276)
Thread=[name=jdbc-request-handler-worker-#29357%tradecore%, id=39238], state=WAITING Locked pages = [] Locked pages log: name=jdbc-request-handler-worker-#29357%tradecore% time=(1607333541274, 2020-12-07 17:32:21.274)
Thread=[name=vacuum-cleaner-#67%tradecore%, id=105], state=RUNNABLE Locked pages = [] Locked pages log: name=vacuum-cleaner-#67%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#68%tradecore%, id=106], state=RUNNABLE Locked pages = [] Locked pages log: name=vacuum-cleaner-#68%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#69%tradecore%, id=107], state=WAITING Locked pages = [] Locked pages log: name=vacuum-cleaner-#69%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#70%tradecore%, id=108], state=RUNNABLE Locked pages = [] Locked pages log: name=vacuum-cleaner-#70%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#71%tradecore%, id=109], state=RUNNABLE Locked pages = [] Locked pages log: name=vacuum-cleaner-#71%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#72%tradecore%, id=110], state=RUNNABLE Locked pages = [] Locked pages log: name=vacuum-cleaner-#72%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#73%tradecore%, id=111], state=WAITING Locked pages = [] Locked pages log: name=vacuum-cleaner-#73%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
Thread=[name=vacuum-cleaner-#74%tradecore%, id=112], state=WAITING Locked pages = [] Locked pages log: name=vacuum-cleaner-#74%tradecore% time=(1607333541277, 2020-12-07 17:32:21.277)
2020-12-07 17:32:21.558 [] [db-checkpoint-thread-#75%tradecore%] ERROR c.j.i.i.c.IgniteConfig - JVM will be halted immediately due to the failure: [failureCtx=FailureContext [type=CRITICAL_ERROR, err=class o.a.i.IgniteCheckedException: Compound exception for CountDownFuture.]]
|
![]() ![]() |
Ilya Kazakov |
![]() |
Hello! Can you provide some details, or show some short reproducer? ----------------- Ilya Kazakov пн, 7 дек. 2020 г. в 21:31, 38797715 <[hidden email]>:
|
![]() |
Hi Ilya, This issue is not easy to reproduce. However, judging from the exception stack, the issue may be
related to the checkpoint process during the destruction of the
cache. 在 2020/12/9 上午9:33, Ilya Kazakov 写道:
|
![]() ![]() |
Zhenya Stanilovsky |
![]() |
looks like we deactivate pageMem concurrently with cp pageWrite, plz someone fill the ticket with appropriate logs.
Среда, 9 декабря 2020, 4:52 +03:00 от 38797715 <[hidden email]>: |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! Why don't you do it yourself if you have the understanding of the issue? It seems you're the only one ATM. Regards, -- Ilya Kasnacheev ср, 9 дек. 2020 г. в 09:27, Zhenya Stanilovsky <[hidden email]>:
|
![]() ![]() |
slava.koptilin |
![]() |
This post was updated on .
In reply to this post by 38797715
Hello,
This is definitely a bug. The good news is that it looks like https://issues.apache.org/jira/browse/IGNITE-13207 & https://issues.apache.org/jira/browse/IGNITE-13151 & https://issues.apache.org/jira/browse/IGNITE-13681 are fixing this issue. All of them are included in AI-2.10 Thanks, S. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
Free forum by Nabble | Edit this page |