You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Ignite TC Bot (Jira)" <ji...@apache.org> on 2020/04/23 15:48:00 UTC
[jira] [Commented] (IGNITE-12712) NPE in checkpoint thread
[ https://issues.apache.org/jira/browse/IGNITE-12712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17090708#comment-17090708 ]
Ignite TC Bot commented on IGNITE-12712:
----------------------------------------
{panel:title=Branch: [pull/7463/head] Base: [master] : No blockers found!|borderStyle=dashed|borderColor=#ccc|titleBGColor=#D6F7C1}{panel}
[TeamCity *--> Run :: All* Results|https://ci.ignite.apache.org/viewLog.html?buildId=5249118&buildTypeId=IgniteTests24Java8_RunAll]
> NPE in checkpoint thread
> ------------------------
>
> Key: IGNITE-12712
> URL: https://issues.apache.org/jira/browse/IGNITE-12712
> Project: Ignite
> Issue Type: Bug
> Reporter: Anton Kalashnikov
> Assignee: Anton Kalashnikov
> Priority: Major
> Time Spent: 10m
> Remaining Estimate: 0h
>
> NPE occured in checkpoint thread (rare reproducing):
> {noformat}
> [2019-11-04 20:54:58,018][INFO ][sys-#50][GridDhtPartitionsExchangeFuture] Received full message, will finish exchange [node=1784645d-3bef-44fe-8288-e0c16202f5e3, resVer=AffinityTopologyVersion [topVer=4, minorTopVer=9]]
> [2019-11-04 20:54:58,023][INFO ][sys-#50][GridDhtPartitionsExchangeFuture] Finish exchange future [startVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], err=null]
> [2019-11-04 20:54:58,029][INFO ][sys-#50][GridCacheProcessor] Finish proxy initialization, cacheName=SQL_PUBLIC_T8, localNodeId=5b153e14-70f2-4408-a125-584752532ebd
> [2019-11-04 20:54:58,030][INFO ][sys-#50][GridDhtPartitionsExchangeFuture] Completed partition exchange [localNode=5b153e14-70f2-4408-a125-584752532ebd, exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode [id=1784645d-3bef-44fe-8288-e0c16202f5e3, consistentId=1, addrs=ArrayList [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1572890071469, loc=false, ver=8.7.8#20191101-sha1:e344ed04, isClient=false], done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=4, minorTopVer=9]]
> [2019-11-04 20:54:58,030][INFO ][sys-#50][GridDhtPartitionsExchangeFuture] Exchange timings [startVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters initialization" (0 ms), stage="Update caches registry" (0 ms), stage="Start caches" (52 ms), stage="Affinity initialization on cache group start" (1 ms), stage="Determine exchange type" (0 ms), stage="Preloading notification" (0 ms), stage="WAL history reservation" (0 ms), stage="Wait partitions release" (1 ms), stage="Wait partitions release latch" (5 ms), stage="Wait partitions release" (0 ms), stage="Restore partition states" (7 ms), stage="After states restored callback" (10 ms), stage="Waiting for Full message" (59 ms), stage="Affinity recalculation" (0 ms), stage="Full map updating" (4 ms), stage="Exchange done" (7 ms), stage="Total time" (146 ms)]
> [2019-11-04 20:54:58,030][INFO ][sys-#50][GridDhtPartitionsExchangeFuture] Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=9], stage="Affinity initialization on cache group start [grp=SQL_PUBLIC_T8]" (1 ms) (parent=Affinity initialization on cache group start), stage="Restore partition states [grp=SQL_PUBLIC_T8]" (6 ms) (parent=Restore partition states), stage="Restore partition states [grp=ignite-sys-cache]" (3 ms) (parent=Restore partition states), stage="Restore partition states [grp=cache_group_3]" (0 ms) (parent=Restore partition states)]
> [2019-11-04 20:54:58,037][INFO ][exchange-worker-#45][GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=4, minorTopVer=9], force=false, evt=DISCOVERY_CUSTOM_EVT, node=1784645d-3bef-44fe-8288-e0c16202f5e3]
> [2019-11-04 20:54:58,713][INFO ][db-checkpoint-thread-#53][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=82969270-b1a5-4480-9513-3af65bab0e17, startPtr=FileWALPointer [idx=0, fileOff=3550077, len=12350], checkpointBeforeLockTime=8ms, checkpointLockWait=4ms, checkpointListenersExecuteTime=56ms, checkpointLockHoldTime=61ms, walCpRecordFsyncDuration=4ms, writeCheckpointEntryDuration=8ms, splitAndSortCpPagesDuration=1ms, pages=178, reason='timeout']
> [2019-11-04 20:54:58,914][INFO ][exchange-worker-#45][time] Started exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=10], crd=false, evt=DISCOVERY_CUSTOM_EVT, evtNode=1784645d-3bef-44fe-8288-e0c16202f5e3, customEvt=DynamicCacheChangeBatch [id=8b06d873e61-af9e27a6-8fe9-4da1-bc0a-d19cd0eabd36, reqs=ArrayList [DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_T9, hasCfg=true, nodeId=1784645d-3bef-44fe-8288-e0c16202f5e3, clientStartOnly=false, stop=false, destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_T9], stopCaches=null, startGrps=[cache_group_4], stopGrps=[], resetParts=null, stateChangeRequest=null], startCaches=false], allowMerge=false]
> [2019-11-04 20:54:58,930][INFO ][exchange-worker-#45][PageMemoryImpl] Started page memory [memoryAllocated=200.0 MiB, pages=49630, tableSize=3.9 MiB, checkpointBuffer=200.0 MiB]
> [2019-11-04 20:54:58,933][ERROR][db-checkpoint-thread-#53][root] 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=SYSTEM_WORKER_TERMINATION, err=java.lang.NullPointerException]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.persistence.pagemem.PageMemoryImpl.finishCheckpoint(PageMemoryImpl.java:1194)
> at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$Checkpointer.markCheckpointEnd(GridCacheDatabaseSharedManager.java:4686)
> at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$Checkpointer.doCheckpoint(GridCacheDatabaseSharedManager.java:4026)
> at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager$Checkpointer.body(GridCacheDatabaseSharedManager.java:3782)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:119)
> at java.base/java.lang.Thread.run(Thread.java:835)
> [2019-11-04 20:54:58,938][WARN ][exchange-worker-#45][MvccProcessorImpl] Attempting to start active vacuum.
> [2019-11-04 20:54:58,938][INFO ][exchange-worker-#45][MvccProcessorImpl] Mvcc processor started.
> [2019-11-04 20:54:58,939][WARN ][db-checkpoint-thread-#53][FailureProcessor] No deadlocked threads detected.
> [2019-11-04 20:54:59,041][INFO ][exchange-worker-#45][GridCacheProcessor] Started cache [name=SQL_PUBLIC_T9, id=-1691533654, group=cache_group_4, dataRegionName=dataRegion4, mode=PARTITIONED, atomicity=TRANSACTIONAL_SNAPSHOT, backups=2, mvcc=true]
> [2019-11-04 20:54:59,044][INFO ][exchange-worker-#45][GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=10], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
> [2019-11-04 20:54:59,047][INFO ][exchange-worker-#45][GridDhtPartitionsExchangeFuture] Finished waiting for partitions release latch: ClientLatch [coordinator=TcpDiscoveryNode [id=1784645d-3bef-44fe-8288-e0c16202f5e3, consistentId=1, addrs=ArrayList [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1572890071469, loc=false, ver=8.7.8#20191101-sha1:e344ed04, isClient=false], ackSent=true, super=CompletableLatch [id=CompletableLatchUid [id=exchange, topVer=AffinityTopologyVersion [topVer=4, minorTopVer=10]]]]
> [2019-11-04 20:54:59,047][INFO ][exchange-worker-#45][GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=10], waitTime=0ms, futInfo=NA, mode=LOCAL]
> [2019-11-04 20:54:59,051][WARN ][db-checkpoint-thread-#53][FailureProcessor] Thread dump at 2019/11/04 20:54:59 MSK
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)