[2.9.0]NPE on invoke IgniteCache.destroy()

classic Classic list List threaded Threaded
6 messages Options
38797715 38797715
Reply | Threaded
Open this post in threaded view
|

[2.9.0]NPE on invoke IgniteCache.destroy()

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 Ilya Kazakov
Reply | Threaded
Open this post in threaded view
|

Re: [2.9.0]NPE on invoke IgniteCache.destroy()

Hello! Can you provide some details, or show some short reproducer?

-----------------
Ilya Kazakov

пн, 7 дек. 2020 г. в 21:31, 38797715 <[hidden email]>:

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.]]
38797715 38797715
Reply | Threaded
Open this post in threaded view
|

Re: [2.9.0]NPE on invoke IgniteCache.destroy()

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 写道:
Hello! Can you provide some details, or show some short reproducer?

-----------------
Ilya Kazakov

пн, 7 дек. 2020 г. в 21:31, 38797715 <[hidden email]>:

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.]]
Zhenya Stanilovsky Zhenya Stanilovsky
Reply | Threaded
Open this post in threaded view
|

Re[2]: [2.9.0]NPE on invoke IgniteCache.destroy()

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]>:
 

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 写道:
Hello! Can you provide some details, or show some short reproducer?
 
-----------------
Ilya Kazakov
 
пн, 7 дек. 2020 г. в 21:31, 38797715 <38797715@...>:

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.kasnacheev ilya.kasnacheev
Reply | Threaded
Open this post in threaded view
|

Re: Re[2]: [2.9.0]NPE on invoke IgniteCache.destroy()

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]>:
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]>:
 

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 写道:
Hello! Can you provide some details, or show some short reproducer?
 
-----------------
Ilya Kazakov
 
пн, 7 дек. 2020 г. в 21:31, 38797715 <38797715@...>:

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.]]
 
 
 
 
slava.koptilin slava.koptilin
Reply | Threaded
Open this post in threaded view
|

Re: [2.9.0]NPE on invoke IgniteCache.destroy()

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/