[jira] [Created] (IGNITE-11217) After cluster kill and restart with new jvm option - one of node fail with failure type - Failed to read WAL record at position

[Anton Vinogradov (Jira)]

ARomantsov created IGNITE-11217:
-----------------------------------

             Summary: After cluster kill and restart with new jvm option - one of node fail with failure type - Failed to read WAL record at position
                 Key: IGNITE-11217
                 URL: https://issues.apache.org/jira/browse/IGNITE-11217
             Project: Ignite
          Issue Type: Bug
          Components: data structures
    Affects Versions: 2.7
            Reporter: ARomantsov
             Fix For: 2.8


Test scenario:

- Start two server load
- execute operations (put/put-all/streamer/remove)
- execute client that collect checksum
- kill nodes
- add JVM options to server - DIGNITE_WAL_LOG_TX_RECORDS=true, DIGNITE_RECOVERY_VERBOSE_LOGGING
- start nodes
- activate them
Found that one node fail


{code:java}
[23:16:06,230][INFO][main][GridCacheProcessor] Finished restoring partition state for local groups [groupsProcessed=45, partitionsProcessed=764, time=557ms]
[23:16:06,280][INFO][main][FileWriteAheadLogManager] Stopping WAL iteration due to an exception: Failed to read WAL record at position: 27700852 size: 67108864, ptr=FileWALPointer [idx=0, fileOff=27700852, len=0]
[23:16:06,298][SEVERE][main][IgniteKernal] Exception during start processors, node will be stopped and close connections
class org.apache.ignite.IgniteCheckedException: Failed to read WAL record at position: 27700852 size: 67108864
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.handleRecordException(AbstractWalRecordsIterator.java:305)
        at org.apache.ignite.internal.processors.cache.persistence.wal.FileWriteAheadLogManager$RecordsIterator.handleRecordException(FileWriteAheadLogManager.java:2691)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.advanceRecord(AbstractWalRecordsIterator.java:269)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.advance(AbstractWalRecordsIterator.java:158)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.onNext(AbstractWalRecordsIterator.java:127)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.onNext(AbstractWalRecordsIterator.java:53)
        at org.apache.ignite.internal.util.GridCloseableIteratorAdapter.nextX(GridCloseableIteratorAdapter.java:41)
        at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.tailPointer(GridCacheDatabaseSharedManager.java:1984)
        at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.startMemoryRestore(GridCacheDatabaseSharedManager.java:1958)
        at org.apache.ignite.internal.IgniteKernal.start(IgniteKernal.java:1050)
        at org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance.start0(IgnitionEx.java:2040)
        at org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance.start(IgnitionEx.java:1732)
        at org.apache.ignite.internal.IgnitionEx.start0(IgnitionEx.java:1158)
        at org.apache.ignite.internal.IgnitionEx.startConfigurations(IgnitionEx.java:1076)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:962)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:861)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:731)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:700)
        at org.apache.ignite.Ignition.start(Ignition.java:348)
        at org.apache.ignite.startup.cmdline.CommandLineStartup.main(CommandLineStartup.java:301)
Caused by: class org.apache.ignite.IgniteCheckedException: Failed to read WAL record at position: 27700852 size: 67108864
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV1Serializer.readWithCrc(RecordV1Serializer.java:395)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV2Serializer.readRecord(RecordV2Serializer.java:236)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.advanceRecord(AbstractWalRecordsIterator.java:254)
        ... 17 more
Caused by: java.io.IOException: class org.apache.ignite.IgniteCheckedException: Unsupported protocol version: 34
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV1Serializer.readVersion(RecordDataV1Serializer.java:2010)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV2Serializer.readMvccDataEntry(RecordDataV2Serializer.java:328)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV2Serializer.readPlainRecord(RecordDataV2Serializer.java:162)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV1Serializer.readRecord(RecordDataV1Serializer.java:208)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV2Serializer$2.readWithHeaders(RecordV2Serializer.java:163)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV1Serializer.readWithCrc(RecordV1Serializer.java:374)
        ... 19 more
        Suppressed: class org.apache.ignite.internal.processors.cache.persistence.wal.crc.IgniteDataIntegrityViolationException: val: 1816937838 writtenCrc: 1387698722
                at org.apache.ignite.internal.processors.cache.persistence.wal.io.FileInput$Crc32CheckingFileInput.close(FileInput.java:106)
                at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV1Serializer.readWithCrc(RecordV1Serializer.java:381)
                ... 19 more
Caused by: class org.apache.ignite.IgniteCheckedException: Unsupported protocol version: 34
        at org.apache.ignite.internal.processors.cache.persistence.tree.io.CacheVersionIO.checkProtocolVersion(CacheVersionIO.java:143)
        at org.apache.ignite.internal.processors.cache.persistence.tree.io.CacheVersionIO.readSize(CacheVersionIO.java:156)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV1Serializer.readVersion(RecordDataV1Serializer.java:2003)
        ... 24 more
[23:16:06,299][SEVERE][main][IgniteKernal] Got exception while starting (will rollback startup routine).
class org.apache.ignite.IgniteCheckedException: Failed to read WAL record at position: 27700852 size: 67108864
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.handleRecordException(AbstractWalRecordsIterator.java:305)
        at org.apache.ignite.internal.processors.cache.persistence.wal.FileWriteAheadLogManager$RecordsIterator.handleRecordException(FileWriteAheadLogManager.java:2691)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.advanceRecord(AbstractWalRecordsIterator.java:269)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.advance(AbstractWalRecordsIterator.java:158)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.onNext(AbstractWalRecordsIterator.java:127)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.onNext(AbstractWalRecordsIterator.java:53)
        at org.apache.ignite.internal.util.GridCloseableIteratorAdapter.nextX(GridCloseableIteratorAdapter.java:41)
        at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.tailPointer(GridCacheDatabaseSharedManager.java:1984)
        at org.apache.ignite.internal.processors.cache.persistence.GridCacheDatabaseSharedManager.startMemoryRestore(GridCacheDatabaseSharedManager.java:1958)
        at org.apache.ignite.internal.IgniteKernal.start(IgniteKernal.java:1050)
        at org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance.start0(IgnitionEx.java:2040)
        at org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance.start(IgnitionEx.java:1732)
        at org.apache.ignite.internal.IgnitionEx.start0(IgnitionEx.java:1158)
        at org.apache.ignite.internal.IgnitionEx.startConfigurations(IgnitionEx.java:1076)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:962)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:861)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:731)
        at org.apache.ignite.internal.IgnitionEx.start(IgnitionEx.java:700)
        at org.apache.ignite.Ignition.start(Ignition.java:348)
        at org.apache.ignite.startup.cmdline.CommandLineStartup.main(CommandLineStartup.java:301)
Caused by: class org.apache.ignite.IgniteCheckedException: Failed to read WAL record at position: 27700852 size: 67108864
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV1Serializer.readWithCrc(RecordV1Serializer.java:395)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV2Serializer.readRecord(RecordV2Serializer.java:236)
        at org.apache.ignite.internal.processors.cache.persistence.wal.AbstractWalRecordsIterator.advanceRecord(AbstractWalRecordsIterator.java:254)
        ... 17 more
Caused by: java.io.IOException: class org.apache.ignite.IgniteCheckedException: Unsupported protocol version: 34
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV1Serializer.readVersion(RecordDataV1Serializer.java:2010)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV2Serializer.readMvccDataEntry(RecordDataV2Serializer.java:328)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV2Serializer.readPlainRecord(RecordDataV2Serializer.java:162)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV1Serializer.readRecord(RecordDataV1Serializer.java:208)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV2Serializer$2.readWithHeaders(RecordV2Serializer.java:163)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV1Serializer.readWithCrc(RecordV1Serializer.java:374)
        ... 19 more
        Suppressed: class org.apache.ignite.internal.processors.cache.persistence.wal.crc.IgniteDataIntegrityViolationException: val: 1816937838 writtenCrc: 1387698722
                at org.apache.ignite.internal.processors.cache.persistence.wal.io.FileInput$Crc32CheckingFileInput.close(FileInput.java:106)
                at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordV1Serializer.readWithCrc(RecordV1Serializer.java:381)
                ... 19 more
Caused by: class org.apache.ignite.IgniteCheckedException: Unsupported protocol version: 34
        at org.apache.ignite.internal.processors.cache.persistence.tree.io.CacheVersionIO.checkProtocolVersion(CacheVersionIO.java:143)
        at org.apache.ignite.internal.processors.cache.persistence.tree.io.CacheVersionIO.readSize(CacheVersionIO.java:156)
        at org.apache.ignite.internal.processors.cache.persistence.wal.serializer.RecordDataV1Serializer.readVersion(RecordDataV1Serializer.java:2003)
        ... 24 more
[23:16:06,302][WARNING][main][IgniteKernal] Attempt to stop starting grid. This operation cannot be guaranteed to be successful.
[23:16:06,313][INFO][main][GridTcpRestProtocol] Command protocol successfully stopped: TCP binary
[23:16:06,347][SEVERE][ttl-cleanup-worker-#45][] Critical system error detected. Will be handled accordingly to configured handler [hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0, super=AbstractFailureHandler [ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext [type=SYSTEM_WORKER_TERMINATION, err=class o.a.i.IgniteException: Got interrupted while waiting for future to complete.]]
class org.apache.ignite.IgniteException: Got interrupted while waiting for future to complete.
        at org.apache.ignite.internal.managers.discovery.GridDiscoveryManager.localJoin(GridDiscoveryManager.java:2208)
        at org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:136)
        at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
        at java.lang.Thread.run(Thread.java:748)
Caused by: class org.apache.ignite.internal.IgniteInterruptedCheckedException: Got interrupted while waiting for future to complete.
        at org.apache.ignite.internal.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:186)
        at org.apache.ignite.internal.util.future.GridFutureAdapter.get(GridFutureAdapter.java:141)
        at org.apache.ignite.internal.managers.discovery.GridDiscoveryManager.localJoin(GridDiscoveryManager.java:2205)
        ... 3 more
[23:16:06,347][WARNING][ttl-cleanup-worker-#45][FailureProcessor] No deadlocked threads detected.
{code}




--
This message was sent by Atlassian JIRA
(v7.6.3#76005)