My JIRA ID: pavel.sapezhko As I mentioned above, first we will have only archiver thread crashed and absolute wal started from 0, but we will have alive ignite instance. Logs can be found in attach.
On Fri, Apr 6, 2018 at 5:42 PM Dmitry Pavlov <dpavlov....@gmail.com> wrote: > Hi Pavel, > > Thank you. Could you please attach logs/stacktraces. Now it is not quite > clear where Ignite has failed? > > Could you please share your JIRA ID? > > Hi PMCs, > > could you please add Pavel to contributor list so > https://issues.apache.org/jira/browse/IGNITE-8167 issue can be assigned? > > Sincerely, > Dmitriy Pavlov > > > пт, 6 апр. 2018 г. в 17:38, Pavel Sapezhko <pavel.sapez...@synesis.ru>: > > > Working on it. > > -- > > > > С уважением, > > Cапежко Павел Александрович > > Инженер-программист ООО "Synesis" > > Skype: p.sapezhko > > > -- С уважением, Cапежко Павел Александрович Инженер-программист ООО "Synesis" Skype: p.sapezhko
WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by org.apache.ignite.internal.util.GridUnsafe$2 (file:/home/pavel.sapezhko/src/ignite/modules/core/target/classes/) to field java.nio.Buffer.address WARNING: Please consider reporting this to the maintainers of org.apache.ignite.internal.util.GridUnsafe$2 WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release [06-04-2018 18:08:17][INFO ][main][IgniteKernal] >>> __________ ________________ >>> / _/ ___/ |/ / _/_ __/ __/ >>> _/ // (7 7 // / / / / _/ >>> /___/\___/_/|_/___/ /_/ /___/ >>> >>> ver. 2.4.0#20180305-sha1:aa342270 >>> 2018 Copyright(C) Apache Software Foundation >>> >>> Ignite documentation: http://ignite.apache.org [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Config URL: file:/home/pavel.sapezhko/src/ignite/examples/config/persistentstore/example-persistent-store.xml [06-04-2018 18:08:17][INFO ][main][IgniteKernal] IgniteConfiguration [igniteInstanceName=null, pubPoolSize=8, svcPoolSize=8, callbackPoolSize=8, stripedPoolSize=8, sysPoolSize=8, mgmtPoolSize=4, igfsPoolSize=8, dataStreamerPoolSize=8, utilityCachePoolSize=8, utilityCacheKeepAliveTime=60000, p2pPoolSize=2, qryPoolSize=8, igniteHome=/home/pavel.sapezhko/src/ignite, igniteWorkDir=/home/pavel.sapezhko/src/ignite/work, mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@66d1af89, nodeId=e8d21e4a-5725-446e-b310-5f682079639c, marsh=org.apache.ignite.internal.binary.BinaryMarshaller@3e34ace1, marshLocJobs=false, daemon=false, p2pEnabled=false, netTimeout=5000, sndRetryDelay=1000, sndRetryCnt=3, metricsHistSize=10000, metricsUpdateFreq=2000, metricsExpTime=9223372036854775807, discoSpi=TcpDiscoverySpi [addrRslvr=null, sockTimeout=0, ackTimeout=0, marsh=null, reconCnt=10, reconDelay=2000, maxAckTimeout=600000, forceSrvMode=false, clientReconnectDisabled=false], segPlc=STOP, segResolveAttempts=2, waitForSegOnStart=true, allResolversPassReq=true, segChkFreq=10000, commSpi=TcpCommunicationSpi [connectGate=null, connPlc=null, enableForcibleNodeKill=false, enableTroubleshootingLog=false, srvLsnr=org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2@6cbcf243, locAddr=null, locHost=null, locPort=47100, locPortRange=100, shmemPort=-1, directBuf=true, directSndBuf=false, idleConnTimeout=600000, connTimeout=5000, maxConnTimeout=600000, reconCnt=10, sockSndBuf=32768, sockRcvBuf=32768, msgQueueLimit=0, slowClientQueueLimit=0, nioSrvr=null, shmemSrv=null, usePairedConnections=false, connectionsPerNode=1, tcpNoDelay=true, filterReachableAddresses=false, ackSndThreshold=32, unackedMsgsBufSize=0, sockWriteTimeout=2000, lsnr=null, boundTcpPort=-1, boundTcpShmemPort=-1, selectorsCnt=4, selectorSpins=0, addrRslvr=null, ctxInitLatch=java.util.concurrent.CountDownLatch@29e6eb25[Count = 1], stopping=false, metricsLsnr=org.apache.ignite.spi.communication.tcp.TcpCommunicationMetricsListener@339bf286], evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@38be305c, colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [lsnr=null], indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@269f4bad, addrRslvr=null, clientMode=false, rebalanceThreadPoolSize=1, txCfg=org.apache.ignite.configuration.TransactionConfiguration@5ed731d0, cacheSanityCheckEnabled=true, discoStartupDelay=60000, deployMode=SHARED, p2pMissedCacheSize=100, locHost=null, timeSrvPortBase=31100, timeSrvPortRange=100, failureDetectionTimeout=10000, clientFailureDetectionTimeout=30000, metricsLogFreq=60000, hadoopCfg=null, connectorCfg=org.apache.ignite.configuration.ConnectorConfiguration@3234f74e, odbcCfg=null, warmupClos=null, atomicCfg=AtomicConfiguration [seqReserveSize=1000, cacheMode=PARTITIONED, backups=1, aff=null, grpName=null], classLdr=null, sslCtxFactory=null, platformCfg=null, binaryCfg=null, memCfg=null, pstCfg=null, dsCfg=DataStorageConfiguration [sysRegionInitSize=41943040, sysCacheMaxSize=104857600, pageSize=0, concLvl=0, dfltDataRegConf=DataRegionConfiguration [name=default, maxSize=6668739379, initSize=268435456, swapPath=null, pageEvictionMode=DISABLED, evictionThreshold=0.9, emptyPagesPoolSize=100, metricsEnabled=false, metricsSubIntervalCount=5, metricsRateTimeInterval=60000, persistenceEnabled=true, checkpointPageBufSize=0], storagePath=null, checkpointFreq=180000, lockWaitTime=10000, checkpointThreads=4, checkpointWriteOrder=SEQUENTIAL, walHistSize=20, walSegments=10, walSegmentSize=67108864, walPath=db/wal, walArchivePath=db/wal/archive, metricsEnabled=false, walMode=LOG_ONLY, walTlbSize=131072, walBuffSize=0, walFlushFreq=2000, walFsyncDelay=1000, walRecordIterBuffSize=67108864, alwaysWriteFullPages=false, fileIOFactory=org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIOFactory@40e10ff8, metricsSubIntervalCnt=5, metricsRateTimeInterval=60000, walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false, walCompactionEnabled=false], activeOnStart=true, autoActivation=true, longQryWarnTimeout=3000, sqlConnCfg=null, cliConnCfg=ClientConnectorConfiguration [host=null, port=10800, portRange=100, sockSndBufSize=0, sockRcvBufSize=0, tcpNoDelay=true, maxOpenCursorsPerConn=128, threadPoolSize=8, idleTimeout=0, jdbcEnabled=true, odbcEnabled=true, thinCliEnabled=true]] [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Daemon mode: off [06-04-2018 18:08:17][INFO ][main][IgniteKernal] OS: Linux 4.4.0-119-generic amd64 [06-04-2018 18:08:17][INFO ][main][IgniteKernal] OS user: pavel.sapezhko [06-04-2018 18:08:17][INFO ][main][IgniteKernal] PID: 18070 [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Language runtime: Java Platform API Specification ver. 9 [06-04-2018 18:08:17][INFO ][main][IgniteKernal] VM information: Java(TM) SE Runtime Environment 9.0.4+11 Oracle Corporation Java HotSpot(TM) 64-Bit Server VM 9.0.4+11 [06-04-2018 18:08:17][INFO ][main][IgniteKernal] VM total memory: 7.8GB [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Remote Management [restart: on, REST: on, JMX (remote: on, port: 49152, auth: off, ssl: off)] [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Logger: Log4JLogger [quiet=false, config=null] [06-04-2018 18:08:17][INFO ][main][IgniteKernal] IGNITE_HOME=/home/pavel.sapezhko/src/ignite [06-04-2018 18:08:17][INFO ][main][IgniteKernal] VM arguments: [--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED, --add-exports=java.base/sun.nio.ch=ALL-UNNAMED, --add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED, --add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED, --add-modules=java.xml.bind, -DIGNITE_WAL_MMAP=false,-DIGNITE_USE_ASYNC_FILE_IO_FACTORY=false, -ea, -DIGNITE_QUIET=true, -DIGNITE_SUCCESS_FILE=/home/pavel.sapezhko/src/ignite/work/ignite_success_b95c42e2-9cfd-45c2-9323-144eaeff8e1c, -Dcom.sun.management.jmxremote, -Dcom.sun.management.jmxremote.port=49152, -Dcom.sun.management.jmxremote.authenticate=false, -Dcom.sun.management.jmxremote.ssl=false, -DIGNITE_UPDATE_NOTIFIER=false, -DIGNITE_HOME=/home/pavel.sapezhko/src/ignite, -DIGNITE_PROG_NAME=./bin/ignite.sh] [06-04-2018 18:08:17][INFO ][main][IgniteKernal] System cache's DataRegion size is configured to 40 MB. Use DataStorageConfiguration.systemCacheMemorySize property to change the setting. [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Configured caches [in 'sysMemPlc' dataRegion: ['ignite-sys-cache', 'ignite-hadoop-mr-sys-cache']] [06-Apr-2018 18:08:17][WARN ][pub-#22][GridDiagnostic] Initial heap size is 498MB (should be no less than 512MB, use -Xms512m -Xmx512m). [06-04-2018 18:08:17][INFO ][main][IgniteKernal] 3-rd party licenses can be found at: /home/pavel.sapezhko/src/ignite/libs/licenses [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] Configured plugins: [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] ^-- TestReconnectPlugin 1.0 [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] ^-- [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] ^-- StanByClusterTestProvider 1.0 [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] ^-- null [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] ^-- Ignite Native I/O Plugin [Direct I/O] [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] ^-- Copyright(C) Apache Software Foundation [06-04-2018 18:08:17][INFO ][main][IgnitePluginProcessor] [06-04-2018 18:08:17][INFO ][main][TcpCommunicationSpi] Successfully bound communication NIO server to TCP port [port=47100, locHost=0.0.0.0/0.0.0.0, selectorsCnt=4, selectorSpins=0, pairedConn=false] [06-Apr-2018 18:08:17][WARN ][main][TcpCommunicationSpi] Message queue limit is set to 0 which may lead to potential OOMEs when running cache operations in FULL_ASYNC or PRIMARY_SYNC modes due to message queues growth on sender and receiver sides. [06-Apr-2018 18:08:17][WARN ][main][NoopCheckpointSpi] Checkpoints are disabled (to enable configure any GridCheckpointSpi implementation) [06-Apr-2018 18:08:17][WARN ][main][GridCollisionManager] Collision resolution is disabled (all jobs will be activated upon arrival). [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Security status [authentication=off, tls/ssl=off] [06-04-2018 18:08:17][INFO ][main][TcpDiscoverySpi] Successfully bound to TCP port [port=47500, localHost=0.0.0.0/0.0.0.0, locNodeId=e8d21e4a-5725-446e-b310-5f682079639c] [06-04-2018 18:08:17][INFO ][main][PdsFoldersResolver] Successfully locked persistence storage folder [/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6] [06-04-2018 18:08:17][INFO ][main][PdsFoldersResolver] Consistent ID used for local node is [b437b563-60ad-4fb0-8ea8-14c8d4ab26d6] according to persistence data storage folders [06-04-2018 18:08:17][INFO ][main][CacheObjectBinaryProcessorImpl] Resolved directory for serialized binary metadata: /home/pavel.sapezhko/src/ignite/work/binary_meta/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:17][INFO ][main][FilePageStoreManager] Resolved page store work directory: /home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:17][INFO ][main][FileWriteAheadLogManager] Resolved write ahead log work directory: /home/pavel.sapezhko/src/ignite/work/db/wal/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:17][INFO ][main][FileWriteAheadLogManager] Resolved write ahead log archive directory: /home/pavel.sapezhko/src/ignite/work/db/wal/archive/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:17][INFO ][main][FileWriteAheadLogManager] Started write-ahead log manager [mode=LOG_ONLY] [06-04-2018 18:08:17][INFO ][main][GridCacheDatabaseSharedManager] Read checkpoint status [startMarker=/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/cp/1522940944126-c3ee1c23-6011-4c1f-a195-0cdf7d8328eb-START.bin, endMarker=/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/cp/1522940944126-c3ee1c23-6011-4c1f-a195-0cdf7d8328eb-END.bin] [06-04-2018 18:08:17][INFO ][main][PageMemoryImpl] Started page memory [memoryAllocated=100.0 MiB, pages=24936, tableSize=1.4 MiB, checkpointBuffer=100.0 MiB] [06-04-2018 18:08:17][INFO ][main][GridCacheDatabaseSharedManager] Checking memory state [lastValidPos=FileWALPointer [idx=62, fileOff=11196957, len=31143], lastMarked=FileWALPointer [idx=62, fileOff=11196957, len=31143], lastCheckpointId=c3ee1c23-6011-4c1f-a195-0cdf7d8328eb] [06-04-2018 18:08:17][INFO ][main][FileWriteAheadLogManager] Stopping WAL iteration due to an exception: EOF at position [11227641] expected to read [8] bytes, ptr=FileWALPointer [idx=62, fileOff=11196957, len=0] [06-04-2018 18:08:17][INFO ][main][GridCacheDatabaseSharedManager] Applying lost cache updates since last checkpoint record [lastMarked=FileWALPointer [idx=62, fileOff=11196957, len=31143], lastCheckpointId=c3ee1c23-6011-4c1f-a195-0cdf7d8328eb] [06-04-2018 18:08:17][INFO ][main][FileWriteAheadLogManager] Stopping WAL iteration due to an exception: EOF at position [11227641] expected to read [8] bytes, ptr=FileWALPointer [idx=62, fileOff=11196957, len=0] [06-04-2018 18:08:17][INFO ][main][GridCacheDatabaseSharedManager] Finished applying WAL changes [updatesApplied=0, time=0ms] [06-04-2018 18:08:17][INFO ][main][GridClusterStateProcessor] Restoring history for BaselineTopology[id=0] [06-04-2018 18:08:17][INFO ][main][ClientListenerProcessor] Client connector processor has started on TCP port 10800 [06-04-2018 18:08:17][INFO ][main][GridTcpRestProtocol] Command protocol successfully started [name=TCP binary, host=0.0.0.0/0.0.0.0, port=11211] SLF4J: Class path contains multiple SLF4J bindings. SLF4J: Found binding in [jar:file:/home/pavel.sapezhko/src/ignite/modules/rest-http/target/libs/slf4j-log4j12-1.7.7.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: Found binding in [jar:file:/home/pavel.sapezhko/src/ignite/modules/visor-plugins/target/libs/slf4j-log4j12-1.7.7.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: Found binding in [jar:file:/home/pavel.sapezhko/src/ignite/modules/zookeeper/target/libs/slf4j-log4j12-1.7.7.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory] [06-04-2018 18:08:17][INFO ][main][GridJettyRestProtocol] Command protocol successfully started [name=Jetty REST, host=/0.0.0.0, port=8080] [06-Apr-2018 18:08:17][WARN ][main][IgniteKernal] Hadoop module will not start due to exception: Java version 9 and above is not supported. [06-04-2018 18:08:17][INFO ][main][root] Page size configuration for storage path [/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6]: 4096; Linux memory page size: 4096; Selected FS block size : 4096. [06-04-2018 18:08:17][INFO ][main][root] Selected FS block size : 4096 [06-04-2018 18:08:17][INFO ][main][root] Direct IO is enabled for block IO operations on aligned memory structures. [block size = 4096, durable memory page size = 4096] [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Non-loopback local IPs: 10.0.3.1, 172.17.0.1, 172.20.9.164, 192.168.100.1, 192.168.122.1, fe80:0:0:0:1879:23ad:4142:c5f6%enp0s31f6 [06-04-2018 18:08:17][INFO ][main][IgniteKernal] Enabled local MACs: 00163E000000, 024250E4A9A1, 1C1B0D059123 [06-04-2018 18:08:19][INFO ][main][GridClusterStateProcessor] Sending activate request with BaselineTopology BaselineTopology [id=0, branchingHash=-1902524211, branchingType='New BaselineTopology', baselineNodes=[b437b563-60ad-4fb0-8ea8-14c8d4ab26d6]] [06-04-2018 18:08:19][INFO ][tcp-disco-msg-worker-#3][GridClusterStateProcessor] Received activate request with BaselineTopology[id=0] [06-04-2018 18:08:19][INFO ][tcp-disco-msg-worker-#3][GridClusterStateProcessor] Started state transition: true [06-04-2018 18:08:19][INFO ][exchange-worker-#42][time] Started exchange init [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1], crd=true, evt=DISCOVERY_CUSTOM_EVT, evtNode=e8d21e4a-5725-446e-b310-5f682079639c, customEvt=ChangeGlobalStateMessage [id=2c0408b9261-4e4b7148-cad0-4cec-b86b-a60d0865ff4e, reqId=8094e1ef-23c2-49e8-9a40-98ca119886df, initiatingNodeId=e8d21e4a-5725-446e-b310-5f682079639c, activate=true, baselineTopology=BaselineTopology [id=0, branchingHash=-1902524211, branchingType='New BaselineTopology', baselineNodes=[b437b563-60ad-4fb0-8ea8-14c8d4ab26d6]], forceChangeBaselineTopology=false, timestamp=1523027299204], allowMerge=false] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridDhtPartitionsExchangeFuture] Start activation process [nodeId=e8d21e4a-5725-446e-b310-5f682079639c, client=false, topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][FilePageStoreManager] Resolved page store work directory: /home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:19][INFO ][exchange-worker-#42][FileWriteAheadLogManager] Resolved write ahead log work directory: /home/pavel.sapezhko/src/ignite/work/db/wal/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:19][INFO ][exchange-worker-#42][FileWriteAheadLogManager] Resolved write ahead log archive directory: /home/pavel.sapezhko/src/ignite/work/db/wal/archive/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6 [06-04-2018 18:08:19][INFO ][exchange-worker-#42][FileWriteAheadLogManager] Started write-ahead log manager [mode=LOG_ONLY] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][PageMemoryImpl] Started page memory [memoryAllocated=100.0 MiB, pages=24936, tableSize=1.4 MiB, checkpointBuffer=100.0 MiB] [06-04-2018 18:08:19][INFO ][main][IgniteKernal] Performance suggestions for grid (fix if possible) [06-04-2018 18:08:19][INFO ][main][IgniteKernal] To disable, set -DIGNITE_PERFORMANCE_SUGGESTIONS_DISABLED=true [06-04-2018 18:08:19][INFO ][main][IgniteKernal] ^-- Switch to the most recent 1.8 JVM version [06-04-2018 18:08:19][INFO ][main][IgniteKernal] ^-- Specify JVM heap max size (add '-Xmx<size>[g|G|m|M|k|K]' to JVM options) [06-04-2018 18:08:19][INFO ][main][IgniteKernal] ^-- Set max direct memory size if getting 'OOME: Direct buffer memory' (add '-XX:MaxDirectMemorySize=<size>[g|G|m|M|k|K]' to JVM options) [06-04-2018 18:08:19][INFO ][main][IgniteKernal] ^-- Disable processing of calls to System.gc() (add '-XX:+DisableExplicitGC' to JVM options) [06-04-2018 18:08:19][INFO ][main][IgniteKernal] ^-- Disable assertions (remove '-ea' from JVM options) [06-04-2018 18:08:19][INFO ][main][IgniteKernal] Refer to this page for more performance suggestions: https://apacheignite.readme.io/docs/jvm-and-system-tuning [06-04-2018 18:08:19][INFO ][main][IgniteKernal] [06-04-2018 18:08:19][INFO ][main][IgniteKernal] To start Console Management & Monitoring run ignitevisorcmd.{sh|bat} [06-04-2018 18:08:19][INFO ][main][IgniteKernal] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][PageMemoryImpl] Started page memory [memoryAllocated=6.2 GiB, pages=1585944, tableSize=92.1 MiB, checkpointBuffer=1.6 GiB] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][PageMemoryImpl] Started page memory [memoryAllocated=100.0 MiB, pages=24936, tableSize=1.4 MiB, checkpointBuffer=100.0 MiB] [06-04-2018 18:08:19][INFO ][main][IgniteKernal] >>> +----------------------------------------------------------------------+ >>> Ignite ver. 2.4.0#20180305-sha1:aa342270b13cc1f4713382a8eb23b2eb7edaa3a5 >>> +----------------------------------------------------------------------+ >>> OS name: Linux 4.4.0-119-generic amd64 >>> CPU(s): 8 >>> Heap: 7.8GB >>> VM name: 18070@SapezhkoP >>> Local node [ID=E8D21E4A-5725-446E-B310-5F682079639C, order=1, clientMode=false] >>> Local node addresses: [172.17.0.1/0:0:0:0:0:0:0:1%lo, 10.0.3.1/10.0.3.1, 192.168.122.1/127.0.0.1, 192.168.100.1/172.17.0.1, 172.20.9.164/172.20.9.164, /192.168.100.1, /192.168.122.1] >>> Local ports: TCP:8080 TCP:10800 TCP:11211 TCP:47100 UDP:47400 TCP:47500 [06-04-2018 18:08:19][INFO ][main][GridDiscoveryManager] Topology snapshot [ver=1, servers=1, clients=0, CPUs=8, offheap=6.2GB, heap=7.8GB] [06-04-2018 18:08:19][INFO ][main][GridDiscoveryManager] Data Regions Configured: [06-04-2018 18:08:19][INFO ][main][GridDiscoveryManager] ^-- default [initSize=256.0 MiB, maxSize=6.2 GiB, persistenceEnabled=true] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheDatabaseSharedManager] Read checkpoint status [startMarker=/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/cp/1522940944126-c3ee1c23-6011-4c1f-a195-0cdf7d8328eb-START.bin, endMarker=/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/cp/1522940944126-c3ee1c23-6011-4c1f-a195-0cdf7d8328eb-END.bin] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheDatabaseSharedManager] Checking memory state [lastValidPos=FileWALPointer [idx=62, fileOff=11196957, len=31143], lastMarked=FileWALPointer [idx=62, fileOff=11196957, len=31143], lastCheckpointId=c3ee1c23-6011-4c1f-a195-0cdf7d8328eb] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][FileWriteAheadLogManager] Stopping WAL iteration due to an exception: EOF at position [11227641] expected to read [8] bytes, ptr=FileWALPointer [idx=62, fileOff=11196957, len=0] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][FileWriteAheadLogManager] Resuming logging to WAL segment [file=/home/pavel.sapezhko/src/ignite/work/db/wal/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/0000000000000000.wal, offset=0, ver=2] Exception in thread "wal-file-archiver%null" java.lang.AssertionError: lastArchived=61, current=0 at org.apache.ignite.internal.processors.cache.persistence.wal.FileWriteAheadLogManager$FileArchiver.run(FileWriteAheadLogManager.java:1522) [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridClusterStateProcessor] Writing BaselineTopology[id=0] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheProcessor] Started cache [name=ignite-sys-cache, id=-2100569601, memoryPolicyName=sysMemPlc, mode=REPLICATED, atomicity=TRANSACTIONAL, backups=2147483647] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheProcessor] Started cache [name=ignite-hadoop-mr-sys-cache, id=-1448311745, memoryPolicyName=sysMemPlc, mode=REPLICATED, atomicity=TRANSACTIONAL, backups=2147483647] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheProcessor] Started cache [name=testCache, id=-1206548976, memoryPolicyName=default, mode=PARTITIONED, atomicity=ATOMIC, backups=0] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridDhtPartitionsExchangeFuture] Successfully activated caches [nodeId=e8d21e4a-5725-446e-b310-5f682079639c, client=false, topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1], waitTime=0ms, futInfo=NA] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheDatabaseSharedManager] Read checkpoint status [startMarker=/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/cp/1522940944126-c3ee1c23-6011-4c1f-a195-0cdf7d8328eb-START.bin, endMarker=/home/pavel.sapezhko/src/ignite/work/db/node00-b437b563-60ad-4fb0-8ea8-14c8d4ab26d6/cp/1522940944126-c3ee1c23-6011-4c1f-a195-0cdf7d8328eb-END.bin] [06-04-2018 18:08:19][INFO ][exchange-worker-#42][GridCacheDatabaseSharedManager] Applying lost cache updates since last checkpoint record [lastMarked=FileWALPointer [idx=62, fileOff=11196957, len=31143], lastCheckpointId=c3ee1c23-6011-4c1f-a195-0cdf7d8328eb] [06-04-2018 18:08:41][INFO ][exchange-worker-#42][GridCacheDatabaseSharedManager] Finished applying WAL changes [updatesApplied=0, time=21837ms] [06-04-2018 18:08:41][INFO ][exchange-worker-#42][GridDhtPartitionsExchangeFuture] finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1], resVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]] [06-04-2018 18:08:41][INFO ][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager] Checkpoint started [checkpointId=e3bfe3b7-e295-4553-953e-1eaea5c46128, startPtr=FileWALPointer [idx=0, fileOff=4443427, len=19515], checkpointLockWait=0ms, checkpointLockHoldTime=44ms, pages=1041, reason='node started'] [06-04-2018 18:08:41][INFO ][tcp-disco-msg-worker-#3][GridClusterStateProcessor] Received state change finish message: true [06-04-2018 18:08:41][INFO ][exchange-worker-#42][GridDhtPartitionsExchangeFuture] Finish exchange future [startVer=AffinityTopologyVersion [topVer=1, minorTopVer=1], resVer=AffinityTopologyVersion [topVer=1, minorTopVer=1], err=null] [06-04-2018 18:08:41][INFO ][exchange-worker-#42][time] Finished exchange init [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1], crd=true] [06-04-2018 18:08:41][INFO ][sys-#51][GridClusterStateProcessor] Successfully performed final activation steps [nodeId=e8d21e4a-5725-446e-b310-5f682079639c, client=false, topVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]] [06-04-2018 18:08:41][INFO ][exchange-worker-#42][GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=1, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, node=e8d21e4a-5725-446e-b310-5f682079639c] [06-04-2018 18:08:42][INFO ][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager] Checkpoint finished [cpId=e3bfe3b7-e295-4553-953e-1eaea5c46128, pages=1041, markPos=FileWALPointer [idx=0, fileOff=4443427, len=19515], walSegmentsCleared=0, markDuration=90ms, pagesWrite=33ms, fsync=1174ms, total=1297ms]