Hi,
I'm testing v2.5 vs v2.4 for persisted dataregion with *walModel
= NONE* and while performance seems better I failed to restart
the cluster after what I think is a proper shutdown (using top
-deactivate then kill -k from visor).
When I try to reactivate the cluster (using top -activate from
visor) I get the following exception on each nodes :
[09:21:37,592][INFO][grid-nio-worker-tcp-comm-0-#33][TcpCommunicationSpi]
Accepted incoming communication connection
[locAddr=/192.168.1.1:47100 <http://192.168.1.1:47100>,
rmtAddr=/192.168.1.102:44646 <http://192.168.1.102:44646>]
[09:21:37,656][INFO][pub-#92][GridClusterStateProcessor] Sending
activate request with BaselineTopology null
[09:21:37,659][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Received activate request with BaselineTopology: null
[09:21:37,661][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Started state transition: true
[09:21:37,687][INFO][exchange-worker-#52][time] Started exchange
init [topVer=AffinityTopologyVersion [topVer=69, minorTopVer=1],
crd=true, evt=DISCOVERY_CUSTOM_EVT,
evtNode=0f5d38b7-b748-4861-91ef-204ed9343e60,
customEvt=ChangeGlobalStateMessage
[id=c0eeccec361-85ace6cb-d27e-4a0e-9106-ca39e6fcbfdd,
reqId=5a1cf16e-f610-4b4b-b1eb-76078be38d6c,
initiatingNodeId=0f5d38b7-b748-4861-91ef-204ed9343e60,
activate=true, baselineTopology=null,
forceChangeBaselineTopology=false, timestamp=1528183297656],
allowMerge=false]
[09:21:37,688][INFO][exchange-worker-#52][GridDhtPartitionsExchangeFuture]
Start activation process
[nodeId=0f5d38b7-b748-4861-91ef-204ed9343e60, client=false,
topVer=AffinityTopologyVersion [topVer=69, minorTopVer=1]]
[09:21:37,688][INFO][exchange-worker-#52][FilePageStoreManager]
Resolved page store work directory:
/usr/share/apache-ignite-fabric-2.5.0-bin/work/db/node00-bcfb4de5-5fc6-41e9-9ebd-90b873711c19
[09:21:37,689][INFO][exchange-worker-#52][FileWriteAheadLogManager]
Resolved write ahead log work directory:
/usr/share/apache-ignite-fabric-2.5.0-bin/work/db/wal/node00-bcfb4de5-5fc6-41e9-9ebd-90b873711c19
[09:21:37,689][INFO][exchange-worker-#52][FileWriteAheadLogManager]
Resolved write ahead log archive directory:
/usr/share/apache-ignite-fabric-2.5.0-bin/work/db/wal/archive/node00-bcfb4de5-5fc6-41e9-9ebd-90b873711c19
[09:21:37,690][WARNING][exchange-worker-#52][FileWriteAheadLogManager]
Started write-ahead log manager in NONE mode, persisted data may
be lost in a case of unexpected node failure. Make sure to
deactivate the cluster before shutdown.
[09:21:37,701][INFO][exchange-worker-#52][PageMemoryImpl] Started
page memory [memoryAllocated=100.0 MiB, pages=24804,
tableSize=1.9 MiB, checkpointBuffer=100.0 MiB]
[09:21:37,798][INFO][exchange-worker-#52][PageMemoryImpl] Started
page memory [memoryAllocated=8.0 GiB, pages=2032836,
tableSize=158.1 MiB, checkpointBuffer=2.0 GiB]
[09:21:37,800][INFO][exchange-worker-#52][PageMemoryImpl] Started
page memory [memoryAllocated=100.0 MiB, pages=24804,
tableSize=1.9 MiB, checkpointBuffer=100.0 MiB]
[09:21:38,168][INFO][exchange-worker-#52][GridCacheDatabaseSharedManager]
Read checkpoint status
[startMarker=/usr/share/apache-ignite-fabric-2.5.0-bin/work/db/node00-bcfb4de5-5fc6-41e9-9ebd-90b873711c19/cp/1528182048551-ea54267c-22c4-4b64-b328-87cc09d3d460-START.bin,
endMarker=/usr/share/apache-ignite-fabric-2.5.0-bin/work/db/node00-bcfb4de5-5fc6-41e9-9ebd-90b873711c19/cp/1528182048551-ea54267c-22c4-4b64-b328-87cc09d3d460-END.bin]
[09:21:38,169][INFO][exchange-worker-#52][GridCacheDatabaseSharedManager]
Checking memory state [lastValidPos=FileWALPointer [idx=0,
fileOff=0, len=0], lastMarked=FileWALPointer [idx=0, fileOff=0,
len=0], lastCheckpointId=ea54267c-22c4-4b64-b328-87cc09d3d460]
*[09:21:38,228][SEVERE][exchange-worker-#52][] Critical system
error detected. Will be handled accordingly to configured handler
[hnd=class o.a.i.failure.StopNodeOrHaltFailureHandler,
failureCtx=FailureContext [type=CRITICAL_ERROR, err=class
o.a.i.i.pagemem.wal.StorageException: Restore wal pointer = null,
while status.endPtr = FileWALPointer [idx=0, fileOff=0, len=0].
Can't restore memory - critical part of WAL archive is missing.]]**
**class org.apache.ignite.internal.pagemem.wal.StorageException:
Restore wal pointer = null, while status.endPtr = FileWALPointer
[idx=0, fileOff=0, len=0]. Can't restore memory - critical part
of WAL archive is missing.**
** at
org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.readCheckpointAndRestoreMemory(GridCacheDatabaseSharedManager.java:759)**
** at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onClusterStateChangeRequest(GridDhtPartitionsExchangeFuture.java:894)**
** at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:641)**
** at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:2419)**
** at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:2299)**
** at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)**
** at java.lang.Thread.run(Thread.java:748)**
**[09:21:38,229][SEVERE][exchange-worker-#52][] JVM will be
halted immediately due to the failure: [failureCtx=FailureContext
[type=CRITICAL_ERROR, err=class
o.a.i.i.pagemem.wal.StorageException: Restore wal pointer = null,
while status.endPtr = FileWALPointer [idx=0, fileOff=0, len=0].
Can't restore memory - critical part of WAL archive is missing.]]*
This operation ended successfully with version 2.4.
The exception was introduced by IGNITE-8393
<https://github.com/apache/ignite/commit/5ec1796408d45296cbb26bb93353e23e18b039c8>
but the problem may lie deeper, like in the checkpoint process
which store a status.endPtr = FileWALPointer even when walMode =
NONE.
Any idea ?
Regards,
---
Emmanuel.
