Spark to Ignite Data load, Ignite node crashashing

classic Classic list List threaded Threaded
3 messages Options
ApacheUser ApacheUser
Reply | Threaded
Open this post in threaded view
|

Spark to Ignite Data load, Ignite node crashashing

Hello Ignite team,

I a writing data from Spark Dataframe to Ignite, frequently one node goes
down, I dont see any error in log file below is the trace. If i restart it
doesn't join Cluster unless I stop the Spark job which is writing data to
Ignite Cluster.

I have 4 nodes with 4CPU/16GB RAM 200GB disc space, persistenc eis enabled,
What could be the reason?

[00:44:33]    __________  ________________
[00:44:33]   /  _/ ___/ |/ /  _/_  __/ __/
[00:44:33]  _/ // (7 7    // /  / / / _/
[00:44:33] /___/\___/_/|_/___/ /_/ /___/
[00:44:33]
[00:44:33] ver. 2.6.0#20180710-sha1:669feacc
[00:44:33] 2018 Copyright(C) Apache Software Foundation
[00:44:33]
[00:44:33] Ignite documentation: http://ignite.apache.org
[00:44:33]
[00:44:33] Quiet mode.
[00:44:33]   ^-- Logging to file
'/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/log/ignite-d90d68c6.0.log'
[00:44:33]   ^-- Logging by 'JavaLogger [quiet=true, config=null]'
[00:44:33]   ^-- To see **FULL** console log here add -DIGNITE_QUIET=false
or "-v" to ignite.{sh|bat}
[00:44:33]
[00:44:33] OS: Linux 3.10.0-862.3.2.el7.x86_64 amd64
[00:44:33] VM information: Java(TM) SE Runtime Environment 1.8.0_171-b11
Oracle Corporation Java HotSpot(TM) 64-Bit Server VM 25.171-b11
[00:44:33] Configured plugins:
[00:44:33]   ^-- None
[00:44:33]
[00:44:33] Configured failure handler: [hnd=StopNodeOrHaltFailureHandler
[tryStop=false, timeout=0]]
[00:44:33] 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.
[00:44:33] Security status [authentication=off, tls/ssl=off]
[00:44:35] Nodes started on local machine require more than 20% of physical
RAM what can lead to significant slowdown due to swapping (please decrease
JVM heap size, data region size or checkpoint buffer size)
[required=13412MB, available=15885MB]
[00:44:35] Performance suggestions for grid  (fix if possible)
[00:44:35] To disable, set -DIGNITE_PERFORMANCE_SUGGESTIONS_DISABLED=true
[00:44:35]   ^-- Set max direct memory size if getting 'OOME: Direct buffer
memory' (add '-XX:MaxDirectMemorySize=<size>[g|G|m|M|k|K]' to JVM options)
[00:44:35]   ^-- Disable processing of calls to System.gc() (add
'-XX:+DisableExplicitGC' to JVM options)
[00:44:35]   ^-- Speed up flushing of dirty pages by OS (alter
vm.dirty_expire_centisecs parameter by setting to 500)
[00:44:35]   ^-- Reduce pages swapping ratio (set vm.swappiness=10)
[00:44:35] Refer to this page for more performance suggestions:
https://apacheignite.readme.io/docs/jvm-and-system-tuning
[00:44:35]
[00:44:35] To start Console Management & Monitoring run
ignitevisorcmd.{sh|bat}
[00:44:35]
[00:44:35] Ignite node started OK (id=d90d68c6)
[00:44:35] >>> Ignite cluster is not active (limited functionality
available). Use control.(sh|bat) script or IgniteCluster interface to
activate.
[00:44:35] Topology snapshot [ver=4, servers=4, clients=0, CPUs=16,
offheap=40.0GB, heap=4.0GB]
[00:44:35]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=INACTIVE]
[00:44:35]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:44:35]   ^-- 1 nodes left for auto-activation
[a99529d8-e483-44b3-96eb-a5a773e380e3]
[00:44:35] Data Regions Configured:
[00:44:35]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
[00:48:20] Topology snapshot [ver=5, servers=4, clients=1, CPUs=16,
offheap=50.0GB, heap=8.4GB]
[00:48:20]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=ACTIVE]
[00:48:20]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:48:20] Data Regions Configured:
[00:48:20]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
[00:48:37] Topology snapshot [ver=6, servers=4, clients=2, CPUs=16,
offheap=60.0GB, heap=12.0GB]
[00:48:37]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=ACTIVE]
[00:48:37]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:48:37] Data Regions Configured:
[00:48:37]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
[00:48:37] Topology snapshot [ver=7, servers=4, clients=3, CPUs=16,
offheap=70.0GB, heap=16.0GB]
[00:48:37]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=ACTIVE]
[00:48:37]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:48:37] Data Regions Configured:
[00:48:37]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
[00:48:38] Topology snapshot [ver=8, servers=4, clients=4, CPUs=16,
offheap=80.0GB, heap=19.0GB]
[00:48:38]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=ACTIVE]
[00:48:38]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:48:38] Data Regions Configured:
[00:48:38]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
[00:48:40] Topology snapshot [ver=9, servers=4, clients=5, CPUs=16,
offheap=90.0GB, heap=23.0GB]
[00:48:40]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=ACTIVE]
[00:48:40]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:48:40] Data Regions Configured:
[00:48:40]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
[00:48:40] Topology snapshot [ver=10, servers=4, clients=6, CPUs=16,
offheap=100.0GB, heap=26.0GB]
[00:48:40]   ^-- Node [id=D90D68C6-C725-43F8-BC32-71363FE3E86F,
clusterState=ACTIVE]
[00:48:40]   ^-- Baseline [id=0, size=4, online=3, offline=1]
[00:48:40] Data Regions Configured:
[00:48:40]   ^-- default [initSize=256.0 MiB, maxSize=10.0 GiB,
persistenceEnabled=true]
bin/ignite.sh: line 183:  6035 Killed                  "$JAVA" ${JVM_OPTS}
${QUIET} "${RESTART_SUCCESS_OPT}" ${JMX_MON} -DIGNITE_HOME="${IGNITE_HOME}"
-DIGNITE_PROG_NAME="$0" ${JVM_XOPTS} -cp "${CP}" ${MAIN_CLASS} "${CONFIG}"
#

Thanks



--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/
ApacheUser ApacheUser
Reply | Threaded
Open this post in threaded view
|

Re: Spark to Ignite Data load, Ignite node crashashing

attaching log of the tow nodes crashing everytime, I have 4 nodes but the
other two nodes ver rarely crashed. All nodes(VM) are 4CPU/16GB RAm/200GB
HDD(Shared Storage)

node 3:
[16:35:21,938][INFO][main][IgniteKernal]

>>>    __________  ________________  
>>>   /  _/ ___/ |/ /  _/_  __/ __/  
>>>  _/ // (7 7    // /  / / / _/    
>>> /___/\___/_/|_/___/ /_/ /___/  
>>>
>>> ver. 2.6.0#20180710-sha1:669feacc
>>> 2018 Copyright(C) Apache Software Foundation
>>>
>>> Ignite documentation: http://ignite.apache.org

[16:35:21,946][INFO][main][IgniteKernal] Config URL:
file:/data/ignitedata/apache-ignite-fabric-2.6.0-bin/config/default-config.xml
[16:35:21,954][INFO][main][IgniteKernal] IgniteConfiguration
[igniteInstanceName=null, pubPoolSize=8, svcPoolSize=8, callbackPoolSize=8,
stripedPoolSize=8, sysPoolSize=8, mgmtPoolSize=4, igfsPoolSize=4,
dataStreamerPoolSize=8, utilityCachePoolSize=8,
utilityCacheKeepAliveTime=60000, p2pPoolSize=2, qryPoolSize=8,
igniteHome=/data/ignitedata/apache-ignite-fabric-2.6.0-bin,
igniteWorkDir=/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work,
mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@6f94fa3e,
nodeId=df202ccb-356f-426a-8131-e2cc0b9bf98f,
marsh=org.apache.ignite.internal.binary.BinaryMarshaller@3023df74,
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, internalLsnr=null],
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@6302bbb1,
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=1000, 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@31304f14[Count = 1],
stopping=false,
metricsLsnr=org.apache.ignite.spi.communication.tcp.TcpCommunicationMetricsListener@34a3d150],
evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@2a4fb17b,
colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [lsnr=null],
indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@7cc0cdad,
addrRslvr=null, clientMode=false, rebalanceThreadPoolSize=1,
txCfg=org.apache.ignite.configuration.TransactionConfiguration@7c7b252e,
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@4d5d943d,
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=10737418240, initSize=268435456, swapPath=null,
pageEvictionMode=DISABLED, evictionThreshold=0.9, emptyPagesPoolSize=100,
metricsEnabled=true, metricsSubIntervalCount=5,
metricsRateTimeInterval=60000, persistenceEnabled=true,
checkpointPageBufSize=0], storagePath=/data/ignitedata/data,
checkpointFreq=180000, lockWaitTime=10000, checkpointThreads=4,
checkpointWriteOrder=SEQUENTIAL, walHistSize=20, walSegments=10,
walSegmentSize=67108864, walPath=/root/ignite/wal,
walArchivePath=db/wal/archive, metricsEnabled=true, 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@4c583ecf,
metricsSubIntervalCnt=5, metricsRateTimeInterval=60000,
walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false,
walCompactionEnabled=false], activeOnStart=true, autoActivation=true,
longQryWarnTimeout=500, 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, sslEnabled=false,
useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null],
authEnabled=true, failureHnd=null, commFailureRslvr=null]
[16:35:21,954][INFO][main][IgniteKernal] Daemon mode: off
[16:35:21,954][INFO][main][IgniteKernal] OS: Linux 3.10.0-862.3.2.el7.x86_64
amd64
[16:35:21,955][INFO][main][IgniteKernal] OS user: root
[16:35:21,955][INFO][main][IgniteKernal] PID: 9038
[16:35:21,955][INFO][main][IgniteKernal] Language runtime: Java Platform API
Specification ver. 1.8
[16:35:21,955][INFO][main][IgniteKernal] VM information: Java(TM) SE Runtime
Environment 1.8.0_171-b11 Oracle Corporation Java HotSpot(TM) 64-Bit Server
VM 25.171-b11
[16:35:21,957][INFO][main][IgniteKernal] VM total memory: 1.0GB
[16:35:21,957][INFO][main][IgniteKernal] Remote Management [restart: on,
REST: on, JMX (remote: on, port: 49163, auth: off, ssl: off)]
[16:35:21,957][INFO][main][IgniteKernal] Logger: JavaLogger [quiet=true,
config=null]
[16:35:21,957][INFO][main][IgniteKernal]
IGNITE_HOME=/data/ignitedata/apache-ignite-fabric-2.6.0-bin
[16:35:21,957][INFO][main][IgniteKernal] VM arguments: [-Xms1g, -Xmx1g,
-XX:+AggressiveOpts, -XX:MaxMetaspaceSize=256m, -XX:+UseG1GC,
-DIGNITE_QUIET=true,
-DIGNITE_SUCCESS_FILE=/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/ignite_success_41e927d2-f522-4b8e-aec5-dbe288f53bae,
-Dcom.sun.management.jmxremote, -Dcom.sun.management.jmxremote.port=49163,
-Dcom.sun.management.jmxremote.authenticate=false,
-Dcom.sun.management.jmxremote.ssl=false,
-DIGNITE_HOME=/data/ignitedata/apache-ignite-fabric-2.6.0-bin,
-DIGNITE_PROG_NAME=bin/ignite.sh]
[16:35:21,958][INFO][main][IgniteKernal] System cache's DataRegion size is
configured to 40 MB. Use DataStorageConfiguration.systemCacheMemorySize
property to change the setting.
[16:35:21,967][INFO][main][IgniteKernal] Configured caches [in 'sysMemPlc'
dataRegion: ['ignite-sys-cache']]
[16:35:21,970][INFO][main][IgniteKernal] 3-rd party licenses can be found
at: /data/ignitedata/apache-ignite-fabric-2.6.0-bin/libs/licenses
[16:35:22,023][INFO][main][IgnitePluginProcessor] Configured plugins:
[16:35:22,023][INFO][main][IgnitePluginProcessor]   ^-- None
[16:35:22,023][INFO][main][IgnitePluginProcessor]
[16:35:22,024][INFO][main][FailureProcessor] Configured failure handler:
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0]]
[16:35:22,094][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]
[16:35:22,127][WARNING][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.
[16:35:22,145][WARNING][main][NoopCheckpointSpi] Checkpoints are disabled
(to enable configure any GridCheckpointSpi implementation)
[16:35:22,171][WARNING][main][GridCollisionManager] Collision resolution is
disabled (all jobs will be activated upon arrival).
[16:35:22,172][INFO][main][IgniteKernal] Security status
[authentication=off, tls/ssl=off]
[16:35:22,223][INFO][main][TcpDiscoverySpi] Successfully bound to TCP port
[port=47500, localHost=0.0.0.0/0.0.0.0,
locNodeId=df202ccb-356f-426a-8131-e2cc0b9bf98f]
[16:35:22,390][INFO][main][PdsFoldersResolver] Successfully created new
persistent storage folder
[/data/ignitedata/data/node00-84153e73-2d96-49b3-b593-bef18c8218f9]
[16:35:22,391][INFO][main][PdsFoldersResolver] Consistent ID used for local
node is [84153e73-2d96-49b3-b593-bef18c8218f9] according to persistence data
storage folders
[16:35:22,397][INFO][main][CacheObjectBinaryProcessorImpl] Resolved
directory for serialized binary metadata:
/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/binary_meta/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:22,596][INFO][main][FilePageStoreManager] Resolved page store work
directory: /data/ignitedata/data/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:22,598][INFO][main][FileWriteAheadLogManager] Resolved write ahead
log work directory:
/root/ignite/wal/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:22,655][INFO][main][FileWriteAheadLogManager] Resolved write ahead
log archive directory:
/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/db/wal/archive/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:22,673][INFO][main][FileWriteAheadLogManager] Started write-ahead log
manager [mode=LOG_ONLY]
[16:35:22,714][INFO][main][GridCacheDatabaseSharedManager] Read checkpoint
status [startMarker=null, endMarker=null]
[16:35:22,739][INFO][main][PageMemoryImpl] Started page memory
[memoryAllocated=100.0 MiB, pages=24812, tableSize=1.9 MiB,
checkpointBuffer=100.0 MiB]
[16:35:22,740][INFO][main][GridCacheDatabaseSharedManager] Checking memory
state [lastValidPos=FileWALPointer [idx=0, fileOff=0, len=0],
lastMarked=FileWALPointer [idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:22,755][INFO][main][GridCacheDatabaseSharedManager] Applying lost
cache updates since last checkpoint record [lastMarked=FileWALPointer
[idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:22,756][INFO][main][GridCacheDatabaseSharedManager] Finished applying
WAL changes [updatesApplied=0, time=0ms]
[16:35:22,838][INFO][main][ClientListenerProcessor] Client connector
processor has started on TCP port 10800
[16:35:22,883][INFO][main][GridTcpRestProtocol] Command protocol
successfully started [name=TCP binary, host=0.0.0.0/0.0.0.0, port=11211]
[16:35:22,932][INFO][main][IgniteKernal] Non-loopback local IPs:
64.101.22.98, fe80:0:0:0:f816:3eff:fe3c:aad6%eth0
[16:35:22,932][INFO][main][IgniteKernal] Enabled local MACs: FA163E3CAAD6
[16:35:24,227][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
accepted incoming connection [rmtAddr=/64.101.22.96, rmtPort=39781]
[16:35:24,237][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
spawning a new thread for connection [rmtAddr=/64.101.22.96, rmtPort=39781]
[16:35:24,238][INFO][tcp-disco-sock-reader-#5][TcpDiscoverySpi] Started
serving remote node connection [rmtAddr=/64.101.22.96:39781, rmtPort=39781]
[16:35:24,327][WARNING][main][IgniteKernal] Nodes started on local machine
require more than 20% of physical RAM what can lead to significant slowdown
due to swapping (please decrease JVM heap size, data region size or
checkpoint buffer size) [required=13412MB, available=15885MB]
[16:35:24,391][INFO][main][IgniteKernal] Performance suggestions for grid
(fix if possible)
[16:35:24,392][INFO][main][IgniteKernal] To disable, set
-DIGNITE_PERFORMANCE_SUGGESTIONS_DISABLED=true
[16:35:24,392][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)
[16:35:24,392][INFO][main][IgniteKernal]   ^-- Disable processing of calls
to System.gc() (add '-XX:+DisableExplicitGC' to JVM options)
[16:35:24,392][INFO][main][IgniteKernal]   ^-- Speed up flushing of dirty
pages by OS (alter vm.dirty_expire_centisecs parameter by setting to 500)
[16:35:24,392][INFO][main][IgniteKernal]   ^-- Reduce pages swapping ratio
(set vm.swappiness=10)
[16:35:24,392][INFO][main][IgniteKernal] Refer to this page for more
performance suggestions:
https://apacheignite.readme.io/docs/jvm-and-system-tuning
[16:35:24,393][INFO][main][IgniteKernal]
[16:35:24,393][INFO][main][IgniteKernal] To start Console Management &
Monitoring run ignitevisorcmd.{sh|bat}
[16:35:24,393][INFO][main][IgniteKernal]
[16:35:24,394][INFO][main][IgniteKernal]

>>> +----------------------------------------------------------------------+
>>> Ignite ver. 2.6.0#20180710-sha1:669feacc5d3a4e60efcdd300dc8de99780f38eed
>>> +----------------------------------------------------------------------+
>>> OS name: Linux 3.10.0-862.3.2.el7.x86_64 amd64
>>> CPU(s): 4
>>> Heap: 1.0GB
>>> VM name: 9038@ccrc_spark_analytic_4
>>> Local node [ID=DF202CCB-356F-426A-8131-E2CC0B9BF98F, order=3,
>>> clientMode=false]
>>> Local node addresses: [64.101.22.98/0:0:0:0:0:0:0:1%lo, /127.0.0.1,
>>> /64.101.22.98]
>>> Local ports: TCP:10800 TCP:11211 TCP:47100 UDP:47400 TCP:47500

[16:35:24,394][INFO][main][IgniteKernal] >>> Ignite cluster is not active
(limited functionality available). Use control.(sh|bat) script or
IgniteCluster interface to activate.
[16:35:24,396][INFO][main][GridDiscoveryManager] Topology snapshot [ver=3,
servers=3, clients=0, CPUs=12, offheap=30.0GB, heap=3.0GB]
[16:35:24,396][INFO][main][GridDiscoveryManager]   ^-- Node
[id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=INACTIVE]
[16:35:24,396][INFO][main][GridDiscoveryManager] Data Regions Configured:
[16:35:24,396][INFO][main][GridDiscoveryManager]   ^-- default
[initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:35:25,812][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=3e90fa61-10ae-4f29-bc07-1a5ee34870a2,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.97],
sockAddrs=[/64.101.22.97:47500, /0:0:0:0:0:0:0:1%lo:47500,
/127.0.0.1:47500], discPort=47500, order=4, intOrder=4,
lastExchangeTime=1533832525697, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false]
[16:35:25,814][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=4, servers=4, clients=0, CPUs=16, offheap=40.0GB, heap=4.0GB]
[16:35:25,814][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=INACTIVE]
[16:35:25,814][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:35:25,814][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:35:34,340][INFO][ignite-update-notifier-timer][GridUpdateNotifier] Your
version is up to date.
[16:35:40,648][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Received activate request with BaselineTopology[id=0]
[16:35:40,652][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Started state transition: true
[16:35:40,667][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], crd=false,
evt=DISCOVERY_CUSTOM_EVT, evtNode=9eb5b437-977b-4a27-874d-2f554f11b3b1,
customEvt=ChangeGlobalStateMessage
[id=a48da8f1561-17023b74-7b2a-4808-acff-c836ff2bfc3b,
reqId=393b2bd6-1a39-41a3-b889-6bcb348c0b7f,
initiatingNodeId=9eb5b437-977b-4a27-874d-2f554f11b3b1, activate=true,
baselineTopology=BaselineTopology [id=0, branchingHash=-3794941467,
branchingType='New BaselineTopology',
baselineNodes=[ed7c9512-9c83-4c0f-a13c-0ee2016f31a3,
5ddaed11-e882-450d-bc91-f14704edfffc, 66183021-00d7-4afa-bef4-dca67652cd67,
84153e73-2d96-49b3-b593-bef18c8218f9]], forceChangeBaselineTopology=false,
timestamp=1533832540592], allowMerge=false]
[16:35:40,668][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Start activation process [nodeId=df202ccb-356f-426a-8131-e2cc0b9bf98f,
client=false, topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:40,668][INFO][exchange-worker-#43][FilePageStoreManager] Resolved
page store work directory:
/data/ignitedata/data/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:40,669][INFO][exchange-worker-#43][FileWriteAheadLogManager] Resolved
write ahead log work directory:
/root/ignite/wal/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:40,669][INFO][exchange-worker-#43][FileWriteAheadLogManager] Resolved
write ahead log archive directory:
/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/db/wal/archive/node00-84153e73-2d96-49b3-b593-bef18c8218f9
[16:35:40,669][INFO][exchange-worker-#43][FileWriteAheadLogManager] Started
write-ahead log manager [mode=LOG_ONLY]
[16:35:40,679][INFO][exchange-worker-#43][PageMemoryImpl] Started page
memory [memoryAllocated=100.0 MiB, pages=24812, tableSize=1.9 MiB,
checkpointBuffer=100.0 MiB]
[16:35:40,733][INFO][exchange-worker-#43][PageMemoryImpl] Started page
memory [memoryAllocated=10.0 GiB, pages=2541052, tableSize=197.7 MiB,
checkpointBuffer=2.0 GiB]
[16:35:40,735][INFO][exchange-worker-#43][PageMemoryImpl] Started page
memory [memoryAllocated=100.0 MiB, pages=24812, tableSize=1.9 MiB,
checkpointBuffer=100.0 MiB]
[16:35:40,782][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Read checkpoint status [startMarker=null, endMarker=null]
[16:35:40,783][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Checking memory state [lastValidPos=FileWALPointer [idx=0, fileOff=0,
len=0], lastMarked=FileWALPointer [idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:40,784][INFO][exchange-worker-#43][FileWriteAheadLogManager] Resuming
logging to WAL segment
[file=/root/ignite/wal/node00-84153e73-2d96-49b3-b593-bef18c8218f9/0000000000000000.wal,
offset=0, ver=2]
[16:35:40,865][INFO][exchange-worker-#43][GridClusterStateProcessor] Writing
BaselineTopology[id=0]
[16:35:41,193][INFO][exchange-worker-#43][GridCacheProcessor] Started cache
[name=ignite-sys-cache, id=-2100569601, memoryPolicyName=sysMemPlc,
mode=REPLICATED, atomicity=TRANSACTIONAL, backups=2147483647]
[16:35:41,199][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Successfully activated caches [nodeId=df202ccb-356f-426a-8131-e2cc0b9bf98f,
client=false, topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:41,211][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:35:41,231][INFO][grid-nio-worker-tcp-comm-0-#25][TcpCommunicationSpi]
Established outgoing communication connection [locAddr=/64.101.22.98:35468,
rmtAddr=/64.101.22.95:47100]
[16:35:41,324][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832524246, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]]
[16:35:41,324][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:35:41,325][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Read checkpoint status [startMarker=null, endMarker=null]
[16:35:41,325][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Applying lost cache updates since last checkpoint record
[lastMarked=FileWALPointer [idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:41,406][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Finished applying WAL changes [updatesApplied=0, time=81ms]
[16:35:41,489][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=09382c71-988c-40e1-a1a9-896559b1fc5a,
startPtr=FileWALPointer [idx=0, fileOff=261363, len=47],
checkpointLockWait=0ms, checkpointLockHoldTime=2ms,
walCpRecordFsyncDuration=65ms, pages=27, reason='node started']
[16:35:41,491][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], crd=false]
[16:35:41,650][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Received state change finish message: true
[16:35:41,656][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Received full
message, will finish exchange [node=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:41,659][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], err=null]
[16:35:41,682][INFO][grid-nio-worker-tcp-comm-1-#26][TcpCommunicationSpi]
Established outgoing communication connection [locAddr=/64.101.22.98:58728,
rmtAddr=ccrc_spark_analytic_2.cisco.com/64.101.22.96:47100]
[16:35:41,687][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=4, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
node=9eb5b437-977b-4a27-874d-2f554f11b3b1]
[16:35:41,690][INFO][sys-#53][GridClusterStateProcessor] Successfully
performed final activation steps
[nodeId=df202ccb-356f-426a-8131-e2cc0b9bf98f, client=false,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:41,703][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=09382c71-988c-40e1-a1a9-896559b1fc5a, pages=27,
markPos=FileWALPointer [idx=0, fileOff=261363, len=47],
walSegmentsCleared=0, markDuration=83ms, pagesWrite=11ms, fsync=200ms,
total=295ms]
[16:36:16,567][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
accepted incoming connection [rmtAddr=/64.101.22.98, rmtPort=48566]
[16:36:16,567][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
spawning a new thread for connection [rmtAddr=/64.101.22.98, rmtPort=48566]
[16:36:16,567][INFO][tcp-disco-sock-reader-#7][TcpDiscoverySpi] Started
serving remote node connection [rmtAddr=/64.101.22.98:48566, rmtPort=48566]
[16:36:16,669][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=855d5f8d-57d0-49f0-830e-da51908019d2,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.98],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0, /64.101.22.98:0],
discPort=0, order=5, intOrder=5, lastExchangeTime=1533832576626, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:16,670][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=5, servers=4, clients=1, CPUs=16, offheap=50.0GB, heap=8.4GB]
[16:36:16,671][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:36:16,671][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:16,671][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:16,671][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:16,673][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=855d5f8d-57d0-49f0-830e-da51908019d2,
customEvt=null, allowMerge=true]
[16:36:16,674][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=5,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=5, minorTopVer=0],
err=null]
[16:36:16,674][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], crd=false]
[16:36:16,675][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=5, minorTopVer=0], evt=NODE_JOINED,
node=855d5f8d-57d0-49f0-830e-da51908019d2]
[16:36:17,445][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], crd=false,
evt=DISCOVERY_CUSTOM_EVT, evtNode=855d5f8d-57d0-49f0-830e-da51908019d2,
customEvt=DynamicCacheChangeBatch
[id=612bb8f1561-de578bea-fbc7-4fe6-8d49-95906395021b,
reqs=[DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_QHDR, hasCfg=true,
nodeId=855d5f8d-57d0-49f0-830e-da51908019d2, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStartfalse]],
exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_QHDR],
stopCaches=null, startGrps=[SQL_PUBLIC_QHDR], stopGrps=[], resetParts=null,
stateChangeRequest=null], startCaches=false], allowMerge=false]
[16:36:17,603][INFO][exchange-worker-#43][GridCacheProcessor] Started cache
[name=SQL_PUBLIC_QHDR, id=-2066276374, memoryPolicyName=default,
mode=PARTITIONED, atomicity=ATOMIC, backups=1]
[16:36:17,615][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:36:17,625][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832524246, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1]]]
[16:36:17,626][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:36:17,693][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], crd=false]
[16:36:17,724][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Received full
message, will finish exchange [node=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
resVer=AffinityTopologyVersion [topVer=5, minorTopVer=1]]
[16:36:17,728][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=5, minorTopVer=1],
resVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], err=null]
[16:36:17,744][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=5, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
node=855d5f8d-57d0-49f0-830e-da51908019d2]
[16:36:17,765][INFO][pub-#59][GridCacheDatabaseSharedManager] Finished
indexes rebuilding for cache [name=SQL_PUBLIC_QHDR, grpName=null]
[16:36:24,394][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:01:00.001]
    ^-- H/N/C [hosts=4, nodes=5, CPUs=16]
    ^-- CPU [cur=0.27%, avg=1.78%, GC=0%]
    ^-- PageMemory [pages=37]
    ^-- Heap [used=64MB, free=93.72%, comm=1024MB]
    ^-- Non heap [used=51MB, free=93.11%, comm=52MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=1, qSize=0]
    ^-- System thread pool [active=0, idle=8, qSize=0]
[16:36:32,304][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=6036816f-cbb9-43b3-94ff-ec55f233155d,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.96],
sockAddrs=[ccrc_spark_analytic_2.cisco.com/64.101.22.96:0,
/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0], discPort=0, order=6, intOrder=6,
lastExchangeTime=1533832592256, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=true]
[16:36:32,305][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=6, servers=4, clients=2, CPUs=16, offheap=60.0GB, heap=12.0GB]
[16:36:32,305][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:36:32,306][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:32,306][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:32,306][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:32,307][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=6, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=6036816f-cbb9-43b3-94ff-ec55f233155d,
customEvt=null, allowMerge=true]
[16:36:32,307][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=6,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=6, minorTopVer=0],
err=null]
[16:36:32,307][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=6, minorTopVer=0], crd=false]
[16:36:32,311][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=6, minorTopVer=0], evt=NODE_JOINED,
node=6036816f-cbb9-43b3-94ff-ec55f233155d]
[16:36:32,321][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=4cd15597-95eb-4870-b683-e23f4bea674b,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.98],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0, /64.101.22.98:0],
discPort=0, order=7, intOrder=7, lastExchangeTime=1533832592267, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:32,322][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=7, servers=4, clients=3, CPUs=16, offheap=70.0GB, heap=16.0GB]
[16:36:32,322][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:36:32,322][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:32,322][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:32,323][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:32,323][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=7, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=4cd15597-95eb-4870-b683-e23f4bea674b,
customEvt=null, allowMerge=true]
[16:36:32,324][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=7,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=7, minorTopVer=0],
err=null]
[16:36:32,324][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=7, minorTopVer=0], crd=false]
[16:36:32,328][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=7, minorTopVer=0], evt=NODE_JOINED,
node=4cd15597-95eb-4870-b683-e23f4bea674b]
[16:36:32,482][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=2ba16c0b-e88d-4fb1-b0ff-f3ac43dc8b58,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0, /64.101.22.95:0],
discPort=0, order=8, intOrder=8, lastExchangeTime=1533832592439, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:32,483][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=8, servers=4, clients=4, CPUs=16, offheap=80.0GB, heap=19.0GB]
[16:36:32,483][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:36:32,483][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:32,483][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:32,484][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:32,487][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=8, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=2ba16c0b-e88d-4fb1-b0ff-f3ac43dc8b58,
customEvt=null, allowMerge=true]
[16:36:32,488][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=8,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=0],
err=null]
[16:36:32,488][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=8, minorTopVer=0], crd=false]
[16:36:32,494][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=8, minorTopVer=0], evt=NODE_JOINED,
node=2ba16c0b-e88d-4fb1-b0ff-f3ac43dc8b58]
[16:36:32,914][INFO][grid-nio-worker-tcp-comm-2-#27][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.98:47100,
rmtAddr=/64.101.22.96:45300]
[16:36:33,131][INFO][grid-nio-worker-tcp-comm-3-#28][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/127.0.0.1:47100,
rmtAddr=/127.0.0.1:60546]
[16:36:33,455][INFO][grid-nio-worker-tcp-comm-0-#25][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.98:47100,
rmtAddr=/64.101.22.95:36782]
[16:36:35,872][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
accepted incoming connection [rmtAddr=/64.101.22.97, rmtPort=41060]
[16:36:35,872][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
spawning a new thread for connection [rmtAddr=/64.101.22.97, rmtPort=41060]
[16:36:35,873][INFO][tcp-disco-sock-reader-#9][TcpDiscoverySpi] Started
serving remote node connection [rmtAddr=/64.101.22.97:41060, rmtPort=41060]
[16:36:36,085][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=e55be418-9131-4abd-8f9c-d3616a0cb508,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.97],
sockAddrs=[/64.101.22.97:0, /0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0],
discPort=0, order=9, intOrder=9, lastExchangeTime=1533832595986, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:36,086][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=9, servers=4, clients=5, CPUs=16, offheap=90.0GB, heap=23.0GB]
[16:36:36,086][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:36:36,086][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:36,086][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:36,086][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:36,091][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=9, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=e55be418-9131-4abd-8f9c-d3616a0cb508,
customEvt=null, allowMerge=true]
[16:36:36,092][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=9,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=9, minorTopVer=0],
err=null]
[16:36:36,092][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=9, minorTopVer=0], crd=false]
[16:36:36,095][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=9, minorTopVer=0], evt=NODE_JOINED,
node=e55be418-9131-4abd-8f9c-d3616a0cb508]
[16:36:36,105][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=e780e47b-9117-4382-8b4d-d4de92c69b46,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.97],
sockAddrs=[/64.101.22.97:0, /0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0],
discPort=0, order=10, intOrder=10, lastExchangeTime=1533832596025,
loc=false, ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:36,106][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=10, servers=4, clients=6, CPUs=16, offheap=100.0GB,
heap=26.0GB]
[16:36:36,106][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:36:36,106][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:36,106][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:36,106][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:36,110][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=e780e47b-9117-4382-8b4d-d4de92c69b46,
customEvt=null, allowMerge=true]
[16:36:36,110][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=10,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=10, minorTopVer=0],
err=null]
[16:36:36,111][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=0], crd=false]
[16:36:36,114][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=10, minorTopVer=0], evt=NODE_JOINED,
node=e780e47b-9117-4382-8b4d-d4de92c69b46]
[16:36:37,018][INFO][grid-nio-worker-tcp-comm-1-#26][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.98:47100,
rmtAddr=/64.101.22.97:50666]
[16:36:37,145][INFO][grid-nio-worker-tcp-comm-2-#27][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.98:47100,
rmtAddr=/64.101.22.97:50668]
[16:37:24,392][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:02:00.004]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=36.1%, avg=14.65%, GC=0.33%]
    ^-- PageMemory [pages=251780]
    ^-- Heap [used=453MB, free=55.75%, comm=1024MB]
    ^-- Non heap [used=60MB, free=91.92%, comm=64MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:38:24,399][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:03:00.008]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=5.17%, avg=19.52%, GC=0%]
    ^-- PageMemory [pages=501357]
    ^-- Heap [used=121MB, free=88.1%, comm=1024MB]
    ^-- Non heap [used=61MB, free=91.69%, comm=65MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:38:43,106][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=539d8365-1bcd-4816-95ed-003980a879dc,
startPtr=FileWALPointer [idx=54, fileOff=52068068, len=11795],
checkpointLockWait=1ms, checkpointLockHoldTime=43ms,
walCpRecordFsyncDuration=453ms, pages=566123, reason='timeout']
[16:39:19,141][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=539d8365-1bcd-4816-95ed-003980a879dc,
pages=566123, markPos=FileWALPointer [idx=54, fileOff=52068068, len=11795],
walSegmentsCleared=0, markDuration=1696ms, pagesWrite=22171ms,
fsync=13864ms, total=37732ms]
[16:39:24,402][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:04:00.017]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=15.5%, avg=24.94%, GC=0.2%]
    ^-- PageMemory [pages=688740]
    ^-- Heap [used=507MB, free=50.4%, comm=1024MB]
    ^-- Non heap [used=64MB, free=91.36%, comm=65MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:40:24,411][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:05:00.020]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=25.57%, avg=24.47%, GC=0.43%]
    ^-- PageMemory [pages=887105]
    ^-- Heap [used=400MB, free=60.93%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.51%, comm=65MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:40:32,570][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], crd=false,
evt=DISCOVERY_CUSTOM_EVT, evtNode=855d5f8d-57d0-49f0-830e-da51908019d2,
customEvt=DynamicCacheChangeBatch
[id=de7bb8f1561-de578bea-fbc7-4fe6-8d49-95906395021b,
reqs=[DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_QMAJOR, hasCfg=true,
nodeId=855d5f8d-57d0-49f0-830e-da51908019d2, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStartfalse]],
exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_QMAJOR],
stopCaches=null, startGrps=[SQL_PUBLIC_QMAJOR], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
allowMerge=false]
[16:40:32,686][INFO][exchange-worker-#43][GridCacheProcessor] Started cache
[name=SQL_PUBLIC_QMAJOR, id=-1412181587, memoryPolicyName=default,
mode=PARTITIONED, atomicity=ATOMIC, backups=1]
[16:40:32,690][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:40:32,697][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832524246, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1]]]
[16:40:32,698][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:40:32,754][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], crd=false]
[16:40:32,785][INFO][sys-#89][GridDhtPartitionsExchangeFuture] Received full
message, will finish exchange [node=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
resVer=AffinityTopologyVersion [topVer=10, minorTopVer=1]]
[16:40:32,788][INFO][sys-#89][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=10,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=10, minorTopVer=1],
err=null]
[16:40:32,830][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=10, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
node=855d5f8d-57d0-49f0-830e-da51908019d2]
[16:40:32,836][INFO][pub-#90][GridCacheDatabaseSharedManager] Finished
indexes rebuilding for cache [name=SQL_PUBLIC_QMAJOR, grpName=null]
[16:41:24,410][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:06:00.020]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=28.1%, avg=24.96%, GC=1.07%]
    ^-- PageMemory [pages=1085678]
    ^-- Heap [used=694MB, free=32.16%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.41%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=1, qSize=0]
    ^-- System thread pool [active=0, idle=8, qSize=0]
[16:41:43,675][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=14b0b9a5-620b-4da5-8e16-7294526d9e41,
startPtr=FileWALPointer [idx=123, fileOff=54166553, len=21643],
checkpointLockWait=0ms, checkpointLockHoldTime=97ms,
walCpRecordFsyncDuration=959ms, pages=693814, reason='timeout']
[16:42:24,415][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:07:00.029]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=4.43%, avg=27.47%, GC=0%]
    ^-- PageMemory [pages=1294400]
    ^-- Heap [used=546MB, free=46.62%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.41%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:43:24,423][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:08:00.031]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=4.23%, avg=24.6%, GC=0%]
    ^-- PageMemory [pages=1324326]
    ^-- Heap [used=731MB, free=28.55%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.44%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:44:24,425][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:09:00.038]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=38.27%, avg=22.81%, GC=0.97%]
    ^-- PageMemory [pages=1390283]
    ^-- Heap [used=850MB, free=16.93%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.43%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:44:26,331][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=14b0b9a5-620b-4da5-8e16-7294526d9e41,
pages=693814, markPos=FileWALPointer [idx=123, fileOff=54166553, len=21643],
walSegmentsCleared=0, markDuration=2270ms, pagesWrite=135670ms,
fsync=26986ms, total=164926ms]
[16:44:41,707][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=63315d75-2838-47af-8b24-8316c1cc0152,
startPtr=FileWALPointer [idx=150, fileOff=32790119, len=21643],
checkpointLockWait=0ms, checkpointLockHoldTime=25ms,
walCpRecordFsyncDuration=141ms, pages=268343, reason='timeout']
[16:45:12,994][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=63315d75-2838-47af-8b24-8316c1cc0152,
pages=268343, markPos=FileWALPointer [idx=150, fileOff=32790119, len=21643],
walSegmentsCleared=0, markDuration=297ms, pagesWrite=5199ms, fsync=26088ms,
total=31585ms]
[16:45:24,432][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:10:00.045]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=13.33%, avg=22.66%, GC=0.37%]
    ^-- PageMemory [pages=1480461]
    ^-- Heap [used=588MB, free=42.51%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.43%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:46:24,440][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:11:00.048]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=36.83%, avg=23.93%, GC=1.13%]
    ^-- PageMemory [pages=1718609]
    ^-- Heap [used=552MB, free=46.03%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.47%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:47:24,435][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:12:00.050]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=52.5%, avg=24.93%, GC=1.6%]
    ^-- PageMemory [pages=1961029]
    ^-- Heap [used=369MB, free=63.94%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.49%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:47:44,338][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=fe7fefc1-550a-4847-980e-2afbbc185e89,
startPtr=FileWALPointer [idx=223, fileOff=47554540, len=21643],
checkpointLockWait=1ms, checkpointLockHoldTime=32ms,
walCpRecordFsyncDuration=1833ms, pages=699616, reason='timeout']
[16:48:24,436][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:13:00.050]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=59.33%, avg=26.26%, GC=1.13%]
    ^-- PageMemory [pages=2120598]
    ^-- Heap [used=448MB, free=56.23%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.48%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:48:46,011][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=fe7fefc1-550a-4847-980e-2afbbc185e89,
pages=699616, markPos=FileWALPointer [idx=223, fileOff=47554540, len=21643],
walSegmentsCleared=0, markDuration=2912ms, pagesWrite=40636ms,
fsync=21037ms, total=64586ms]
[16:49:24,443][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:14:00.056]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=0.27%, avg=25.34%, GC=0%]
    ^-- PageMemory [pages=2207591]
    ^-- Heap [used=884MB, free=13.57%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.48%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:50:24,450][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:15:00.065]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=1.33%, avg=23.76%, GC=0%]
    ^-- PageMemory [pages=2229194]
    ^-- Heap [used=572MB, free=44.09%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.48%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:50:42,853][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=e6af1260-5082-473a-b7c7-d90c846e5d28,
startPtr=FileWALPointer [idx=256, fileOff=4285480, len=21643],
checkpointLockWait=392ms, checkpointLockHoldTime=29ms,
walCpRecordFsyncDuration=108ms, pages=317292, reason='timeout']
[16:51:24,460][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:16:00.074]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=0.33%, avg=23.37%, GC=0%]
    ^-- PageMemory [pages=2296945]
    ^-- Heap [used=363MB, free=64.49%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.49%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:52:13,369][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=e6af1260-5082-473a-b7c7-d90c846e5d28,
pages=317292, markPos=FileWALPointer [idx=256, fileOff=4285480, len=21643],
walSegmentsCleared=0, markDuration=1039ms, pagesWrite=49074ms,
fsync=41442ms, total=91947ms]
[16:52:24,473][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:17:00.087]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=0.73%, avg=22.73%, GC=0%]
    ^-- PageMemory [pages=2377713]
    ^-- Heap [used=705MB, free=31.08%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.48%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:53:16,106][WARNING][jvm-pause-detector-worker][] Possible too long JVM
pause: 886 milliseconds.
[16:53:17,343][INFO][grid-nio-worker-tcp-comm-3-#28][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/127.0.0.1:47100,
rmtAddr=/127.0.0.1:60678]
[16:53:17,410][WARNING][tcp-disco-msg-worker-#3][TcpDiscoverySpi] Failed to
send message to next node [msg=TcpDiscoveryMetricsUpdateMessage
[super=TcpDiscoveryAbstractMessage
[sndNodeId=9eb5b437-977b-4a27-874d-2f554f11b3b1,
id=9b5e98f1561-6aba33d0-311a-4bbb-bc09-0959a62eddd6,
verifierNodeId=6aba33d0-311a-4bbb-bc09-0959a62eddd6, topVer=0, pendingIdx=0,
failedNodes=null, isClient=false]], next=TcpDiscoveryNode
[id=3e90fa61-10ae-4f29-bc07-1a5ee34870a2, addrs=[0:0:0:0:0:0:0:1%lo,
127.0.0.1, 64.101.22.97], sockAddrs=[/64.101.22.97:47500,
/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=4,
intOrder=4, lastExchangeTime=1533832525697, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=false], errMsg=Failed to send
message to next node [msg=TcpDiscoveryMetricsUpdateMessage
[super=TcpDiscoveryAbstractMessage
[sndNodeId=9eb5b437-977b-4a27-874d-2f554f11b3b1,
id=9b5e98f1561-6aba33d0-311a-4bbb-bc09-0959a62eddd6,
verifierNodeId=6aba33d0-311a-4bbb-bc09-0959a62eddd6, topVer=0, pendingIdx=0,
failedNodes=null, isClient=false]], next=ClusterNode
[id=3e90fa61-10ae-4f29-bc07-1a5ee34870a2, order=4, addr=[0:0:0:0:0:0:0:1%lo,
127.0.0.1, 64.101.22.97], daemon=false]]]
[16:53:17,433][WARNING][tcp-disco-msg-worker-#3][TcpDiscoverySpi] Local node
has detected failed nodes and started cluster-wide procedure. To speed up
failure detection please see 'Failure Detection' section under javadoc for
'TcpDiscoverySpi'
[16:53:17,546][INFO][grid-nio-worker-tcp-comm-0-#25][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/127.0.0.1:47100,
rmtAddr=/127.0.0.1:60680]
[16:53:17,555][WARNING][disco-event-worker-#41][GridDiscoveryManager] Node
FAILED: TcpDiscoveryNode [id=3e90fa61-10ae-4f29-bc07-1a5ee34870a2,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.97],
sockAddrs=[/64.101.22.97:47500, /0:0:0:0:0:0:0:1%lo:47500,
/127.0.0.1:47500], discPort=47500, order=4, intOrder=4,
lastExchangeTime=1533832525697, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false]
[16:53:17,556][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=11, servers=3, clients=6, CPUs=16, offheap=90.0GB,
heap=25.0GB]
[16:53:17,556][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=DF202CCB-356F-426A-8131-E2CC0B9BF98F, clusterState=ACTIVE]
[16:53:17,556][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=3, offline=1]
[16:53:17,556][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:53:17,557][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:53:17,580][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=11, minorTopVer=0], crd=false,
evt=NODE_FAILED, evtNode=3e90fa61-10ae-4f29-bc07-1a5ee34870a2,
customEvt=null, allowMerge=true]
[16:53:19,049][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=11, minorTopVer=0], waitTime=1472ms,
futInfo=NA]
[16:53:19,051][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832524246, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=11, minorTopVer=0]]]
[16:53:19,052][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=11, minorTopVer=0], waitTime=0ms,
futInfo=NA]
[16:53:19,062][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=11, minorTopVer=0], crd=false]
[16:53:19,117][INFO][sys-#161][GridDhtPartitionsExchangeFuture] Received
full message, will finish exchange
[node=6aba33d0-311a-4bbb-bc09-0959a62eddd6, resVer=AffinityTopologyVersion
[topVer=11, minorTopVer=0]]
[16:53:19,155][INFO][sys-#161][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=11,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=11, minorTopVer=0],
err=null]
[16:53:19,197][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=11, minorTopVer=0], evt=NODE_FAILED,
node=3e90fa61-10ae-4f29-bc07-1a5ee34870a2]
[16:53:24,482][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:18:00.096]
    ^-- H/N/C [hosts=4, nodes=9, CPUs=16]
    ^-- CPU [cur=37.67%, avg=22.41%, GC=1.1%]
    ^-- PageMemory [pages=2488681]
    ^-- Heap [used=743MB, free=27.42%, comm=1024MB]
    ^-- Non heap [used=64MB, free=91.36%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=2, qSize=0]
    ^-- System thread pool [active=0, idle=8, qSize=0]
[16:53:39,729][WARNING][data-streamer-stripe-4-#13][PageMemoryImpl] Page
replacements started, pages will be rotated with disk, this will affect
storage performance (consider increasing
DataRegionConfiguration#setMaxSize).
[16:53:45,331][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=e5ee9e24-e543-4bf0-a115-b84cc1fa24a2,
startPtr=FileWALPointer [idx=287, fileOff=4295697, len=21643],
checkpointLockWait=1860ms, checkpointLockHoldTime=211ms,
walCpRecordFsyncDuration=414ms, pages=319384, reason='timeout']
[16:54:00,663][WARNING][jvm-pause-detector-worker][] Possible too long JVM
pause: 821 milliseconds.
[16:54:03,167][WARNING][jvm-pause-detector-worker][] Possible too long JVM
pause: 1448 milliseconds.
[16:54:26,496][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=df202ccb, uptime=00:19:01.762]
    ^-- H/N/C [hosts=4, nodes=9, CPUs=16]
    ^-- CPU [cur=2.83%, avg=22.34%, GC=0%]
    ^-- PageMemory [pages=2532127]
    ^-- Heap [used=388MB, free=62.04%, comm=1024MB]
    ^-- Non heap [used=65MB, free=91.24%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=5, qSize=0]
[16:54:45,250][WARNING][jvm-pause-detector-worker][] Possible too long JVM
pause: 1359 milliseconds.
[16:54:57,741][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=e5ee9e24-e543-4bf0-a115-b84cc1fa24a2,
pages=319384, markPos=FileWALPointer [idx=287, fileOff=4295697, len=21643],
walSegmentsCleared=0, markDuration=1656ms, pagesWrite=71182ms, fsync=1211ms,
total=75909ms]

Node 4:

[16:35:23,395][INFO][main][IgniteKernal]

>>>    __________  ________________  
>>>   /  _/ ___/ |/ /  _/_  __/ __/  
>>>  _/ // (7 7    // /  / / / _/    
>>> /___/\___/_/|_/___/ /_/ /___/  
>>>
>>> ver. 2.6.0#20180710-sha1:669feacc
>>> 2018 Copyright(C) Apache Software Foundation
>>>
>>> Ignite documentation: http://ignite.apache.org

[16:35:23,404][INFO][main][IgniteKernal] Config URL:
file:/data/ignitedata/apache-ignite-fabric-2.6.0-bin/config/default-config.xml
[16:35:23,413][INFO][main][IgniteKernal] IgniteConfiguration
[igniteInstanceName=null, pubPoolSize=8, svcPoolSize=8, callbackPoolSize=8,
stripedPoolSize=8, sysPoolSize=8, mgmtPoolSize=4, igfsPoolSize=4,
dataStreamerPoolSize=8, utilityCachePoolSize=8,
utilityCacheKeepAliveTime=60000, p2pPoolSize=2, qryPoolSize=8,
igniteHome=/data/ignitedata/apache-ignite-fabric-2.6.0-bin,
igniteWorkDir=/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work,
mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@6f94fa3e,
nodeId=3e90fa61-10ae-4f29-bc07-1a5ee34870a2,
marsh=org.apache.ignite.internal.binary.BinaryMarshaller@3023df74,
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, internalLsnr=null],
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@6302bbb1,
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=1000, 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@31304f14[Count = 1],
stopping=false,
metricsLsnr=org.apache.ignite.spi.communication.tcp.TcpCommunicationMetricsListener@34a3d150],
evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@2a4fb17b,
colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [lsnr=null],
indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@7cc0cdad,
addrRslvr=null, clientMode=false, rebalanceThreadPoolSize=1,
txCfg=org.apache.ignite.configuration.TransactionConfiguration@7c7b252e,
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@4d5d943d,
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=10737418240, initSize=268435456, swapPath=null,
pageEvictionMode=DISABLED, evictionThreshold=0.9, emptyPagesPoolSize=100,
metricsEnabled=true, metricsSubIntervalCount=5,
metricsRateTimeInterval=60000, persistenceEnabled=true,
checkpointPageBufSize=0], storagePath=/data/ignitedata/data,
checkpointFreq=180000, lockWaitTime=10000, checkpointThreads=4,
checkpointWriteOrder=SEQUENTIAL, walHistSize=20, walSegments=10,
walSegmentSize=67108864, walPath=/root/ignite/wal,
walArchivePath=db/wal/archive, metricsEnabled=true, 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@4c583ecf,
metricsSubIntervalCnt=5, metricsRateTimeInterval=60000,
walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false,
walCompactionEnabled=false], activeOnStart=true, autoActivation=true,
longQryWarnTimeout=500, 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, sslEnabled=false,
useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null],
authEnabled=true, failureHnd=null, commFailureRslvr=null]
[16:35:23,413][INFO][main][IgniteKernal] Daemon mode: off
[16:35:23,414][INFO][main][IgniteKernal] OS: Linux 3.10.0-862.3.2.el7.x86_64
amd64
[16:35:23,414][INFO][main][IgniteKernal] OS user: root
[16:35:23,414][INFO][main][IgniteKernal] PID: 19878
[16:35:23,414][INFO][main][IgniteKernal] Language runtime: Java Platform API
Specification ver. 1.8
[16:35:23,415][INFO][main][IgniteKernal] VM information: Java(TM) SE Runtime
Environment 1.8.0_171-b11 Oracle Corporation Java HotSpot(TM) 64-Bit Server
VM 25.171-b11
[16:35:23,416][INFO][main][IgniteKernal] VM total memory: 1.0GB
[16:35:23,416][INFO][main][IgniteKernal] Remote Management [restart: on,
REST: on, JMX (remote: on, port: 49165, auth: off, ssl: off)]
[16:35:23,416][INFO][main][IgniteKernal] Logger: JavaLogger [quiet=true,
config=null]
[16:35:23,416][INFO][main][IgniteKernal]
IGNITE_HOME=/data/ignitedata/apache-ignite-fabric-2.6.0-bin
[16:35:23,416][INFO][main][IgniteKernal] VM arguments: [-Xms1g, -Xmx1g,
-XX:+AggressiveOpts, -XX:MaxMetaspaceSize=256m, -XX:+UseG1GC,
-DIGNITE_QUIET=true,
-DIGNITE_SUCCESS_FILE=/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/ignite_success_6072bc65-662b-4157-8748-518151f0fdb4,
-Dcom.sun.management.jmxremote, -Dcom.sun.management.jmxremote.port=49165,
-Dcom.sun.management.jmxremote.authenticate=false,
-Dcom.sun.management.jmxremote.ssl=false,
-DIGNITE_HOME=/data/ignitedata/apache-ignite-fabric-2.6.0-bin,
-DIGNITE_PROG_NAME=bin/ignite.sh]
[16:35:23,416][INFO][main][IgniteKernal] System cache's DataRegion size is
configured to 40 MB. Use DataStorageConfiguration.systemCacheMemorySize
property to change the setting.
[16:35:23,424][INFO][main][IgniteKernal] Configured caches [in 'sysMemPlc'
dataRegion: ['ignite-sys-cache']]
[16:35:23,428][INFO][main][IgniteKernal] 3-rd party licenses can be found
at: /data/ignitedata/apache-ignite-fabric-2.6.0-bin/libs/licenses
[16:35:23,483][INFO][main][IgnitePluginProcessor] Configured plugins:
[16:35:23,483][INFO][main][IgnitePluginProcessor]   ^-- None
[16:35:23,484][INFO][main][IgnitePluginProcessor]
[16:35:23,485][INFO][main][FailureProcessor] Configured failure handler:
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0]]
[16:35:23,532][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]
[16:35:23,566][WARNING][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.
[16:35:23,587][WARNING][main][NoopCheckpointSpi] Checkpoints are disabled
(to enable configure any GridCheckpointSpi implementation)
[16:35:23,616][WARNING][main][GridCollisionManager] Collision resolution is
disabled (all jobs will be activated upon arrival).
[16:35:23,618][INFO][main][IgniteKernal] Security status
[authentication=off, tls/ssl=off]
[16:35:23,660][INFO][main][TcpDiscoverySpi] Successfully bound to TCP port
[port=47500, localHost=0.0.0.0/0.0.0.0,
locNodeId=3e90fa61-10ae-4f29-bc07-1a5ee34870a2]
[16:35:23,874][INFO][main][PdsFoldersResolver] Successfully created new
persistent storage folder
[/data/ignitedata/data/node00-66183021-00d7-4afa-bef4-dca67652cd67]
[16:35:23,876][INFO][main][PdsFoldersResolver] Consistent ID used for local
node is [66183021-00d7-4afa-bef4-dca67652cd67] according to persistence data
storage folders
[16:35:23,881][INFO][main][CacheObjectBinaryProcessorImpl] Resolved
directory for serialized binary metadata:
/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/binary_meta/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:24,087][INFO][main][FilePageStoreManager] Resolved page store work
directory: /data/ignitedata/data/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:24,099][INFO][main][FileWriteAheadLogManager] Resolved write ahead
log work directory:
/root/ignite/wal/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:24,120][INFO][main][FileWriteAheadLogManager] Resolved write ahead
log archive directory:
/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/db/wal/archive/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:24,138][INFO][main][FileWriteAheadLogManager] Started write-ahead log
manager [mode=LOG_ONLY]
[16:35:24,163][INFO][main][GridCacheDatabaseSharedManager] Read checkpoint
status [startMarker=null, endMarker=null]
[16:35:24,201][INFO][main][PageMemoryImpl] Started page memory
[memoryAllocated=100.0 MiB, pages=24812, tableSize=1.9 MiB,
checkpointBuffer=100.0 MiB]
[16:35:24,202][INFO][main][GridCacheDatabaseSharedManager] Checking memory
state [lastValidPos=FileWALPointer [idx=0, fileOff=0, len=0],
lastMarked=FileWALPointer [idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:24,215][INFO][main][GridCacheDatabaseSharedManager] Applying lost
cache updates since last checkpoint record [lastMarked=FileWALPointer
[idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:24,216][INFO][main][GridCacheDatabaseSharedManager] Finished applying
WAL changes [updatesApplied=0, time=0ms]
[16:35:24,304][INFO][main][ClientListenerProcessor] Client connector
processor has started on TCP port 10800
[16:35:24,351][INFO][main][GridTcpRestProtocol] Command protocol
successfully started [name=TCP binary, host=0.0.0.0/0.0.0.0, port=11211]
[16:35:24,396][INFO][main][IgniteKernal] Non-loopback local IPs:
64.101.22.97, fe80:0:0:0:f816:3eff:feb0:851%eth0
[16:35:24,397][INFO][main][IgniteKernal] Enabled local MACs: FA163EB00851
[16:35:25,712][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
accepted incoming connection [rmtAddr=/64.101.22.98, rmtPort=41636]
[16:35:25,724][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
spawning a new thread for connection [rmtAddr=/64.101.22.98, rmtPort=41636]
[16:35:25,724][INFO][tcp-disco-sock-reader-#5][TcpDiscoverySpi] Started
serving remote node connection [rmtAddr=/64.101.22.98:41636, rmtPort=41636]
[16:35:25,819][WARNING][main][IgniteKernal] Nodes started on local machine
require more than 20% of physical RAM what can lead to significant slowdown
due to swapping (please decrease JVM heap size, data region size or
checkpoint buffer size) [required=13412MB, available=15885MB]
[16:35:25,902][INFO][main][IgniteKernal] Performance suggestions for grid
(fix if possible)
[16:35:25,903][INFO][main][IgniteKernal] To disable, set
-DIGNITE_PERFORMANCE_SUGGESTIONS_DISABLED=true
[16:35:25,903][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)
[16:35:25,903][INFO][main][IgniteKernal]   ^-- Disable processing of calls
to System.gc() (add '-XX:+DisableExplicitGC' to JVM options)
[16:35:25,904][INFO][main][IgniteKernal]   ^-- Speed up flushing of dirty
pages by OS (alter vm.dirty_expire_centisecs parameter by setting to 500)
[16:35:25,904][INFO][main][IgniteKernal]   ^-- Reduce pages swapping ratio
(set vm.swappiness=10)
[16:35:25,904][INFO][main][IgniteKernal] Refer to this page for more
performance suggestions:
https://apacheignite.readme.io/docs/jvm-and-system-tuning
[16:35:25,904][INFO][main][IgniteKernal]
[16:35:25,905][INFO][main][IgniteKernal] To start Console Management &
Monitoring run ignitevisorcmd.{sh|bat}
[16:35:25,905][INFO][main][IgniteKernal]
[16:35:25,906][INFO][main][IgniteKernal]

>>> +----------------------------------------------------------------------+
>>> Ignite ver. 2.6.0#20180710-sha1:669feacc5d3a4e60efcdd300dc8de99780f38eed
>>> +----------------------------------------------------------------------+
>>> OS name: Linux 3.10.0-862.3.2.el7.x86_64 amd64
>>> CPU(s): 4
>>> Heap: 1.0GB
>>> VM name: 19878@ccrc_spark_analytic_3
>>> Local node [ID=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, order=4,
>>> clientMode=false]
>>> Local node addresses: [64.101.22.97/0:0:0:0:0:0:0:1%lo, /127.0.0.1,
>>> /64.101.22.97]
>>> Local ports: TCP:10800 TCP:11211 TCP:47100 UDP:47400 TCP:47500

[16:35:25,906][INFO][main][IgniteKernal] >>> Ignite cluster is not active
(limited functionality available). Use control.(sh|bat) script or
IgniteCluster interface to activate.
[16:35:25,910][INFO][main][GridDiscoveryManager] Topology snapshot [ver=4,
servers=4, clients=0, CPUs=16, offheap=40.0GB, heap=4.0GB]
[16:35:25,910][INFO][main][GridDiscoveryManager]   ^-- Node
[id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=INACTIVE]
[16:35:25,910][INFO][main][GridDiscoveryManager] Data Regions Configured:
[16:35:25,910][INFO][main][GridDiscoveryManager]   ^-- default
[initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:35:35,846][INFO][ignite-update-notifier-timer][GridUpdateNotifier] Your
version is up to date.
[16:35:40,665][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Received activate request with BaselineTopology[id=0]
[16:35:40,668][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Started state transition: true
[16:35:40,688][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], crd=false,
evt=DISCOVERY_CUSTOM_EVT, evtNode=9eb5b437-977b-4a27-874d-2f554f11b3b1,
customEvt=ChangeGlobalStateMessage
[id=a48da8f1561-17023b74-7b2a-4808-acff-c836ff2bfc3b,
reqId=393b2bd6-1a39-41a3-b889-6bcb348c0b7f,
initiatingNodeId=9eb5b437-977b-4a27-874d-2f554f11b3b1, activate=true,
baselineTopology=BaselineTopology [id=0, branchingHash=-3794941467,
branchingType='New BaselineTopology',
baselineNodes=[ed7c9512-9c83-4c0f-a13c-0ee2016f31a3,
5ddaed11-e882-450d-bc91-f14704edfffc, 66183021-00d7-4afa-bef4-dca67652cd67,
84153e73-2d96-49b3-b593-bef18c8218f9]], forceChangeBaselineTopology=false,
timestamp=1533832540592], allowMerge=false]
[16:35:40,689][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Start activation process [nodeId=3e90fa61-10ae-4f29-bc07-1a5ee34870a2,
client=false, topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:40,689][INFO][exchange-worker-#43][FilePageStoreManager] Resolved
page store work directory:
/data/ignitedata/data/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:40,689][INFO][exchange-worker-#43][FileWriteAheadLogManager] Resolved
write ahead log work directory:
/root/ignite/wal/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:40,690][INFO][exchange-worker-#43][FileWriteAheadLogManager] Resolved
write ahead log archive directory:
/data/ignitedata/apache-ignite-fabric-2.6.0-bin/work/db/wal/archive/node00-66183021-00d7-4afa-bef4-dca67652cd67
[16:35:40,690][INFO][exchange-worker-#43][FileWriteAheadLogManager] Started
write-ahead log manager [mode=LOG_ONLY]
[16:35:40,702][INFO][exchange-worker-#43][PageMemoryImpl] Started page
memory [memoryAllocated=100.0 MiB, pages=24812, tableSize=1.9 MiB,
checkpointBuffer=100.0 MiB]
[16:35:40,758][INFO][exchange-worker-#43][PageMemoryImpl] Started page
memory [memoryAllocated=10.0 GiB, pages=2541052, tableSize=197.7 MiB,
checkpointBuffer=2.0 GiB]
[16:35:40,761][INFO][exchange-worker-#43][PageMemoryImpl] Started page
memory [memoryAllocated=100.0 MiB, pages=24812, tableSize=1.9 MiB,
checkpointBuffer=100.0 MiB]
[16:35:40,782][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Read checkpoint status [startMarker=null, endMarker=null]
[16:35:40,783][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Checking memory state [lastValidPos=FileWALPointer [idx=0, fileOff=0,
len=0], lastMarked=FileWALPointer [idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:40,784][INFO][exchange-worker-#43][FileWriteAheadLogManager] Resuming
logging to WAL segment
[file=/root/ignite/wal/node00-66183021-00d7-4afa-bef4-dca67652cd67/0000000000000000.wal,
offset=0, ver=2]
[16:35:40,825][INFO][exchange-worker-#43][GridClusterStateProcessor] Writing
BaselineTopology[id=0]
[16:35:41,123][INFO][exchange-worker-#43][GridCacheProcessor] Started cache
[name=ignite-sys-cache, id=-2100569601, memoryPolicyName=sysMemPlc,
mode=REPLICATED, atomicity=TRANSACTIONAL, backups=2147483647]
[16:35:41,129][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Successfully activated caches [nodeId=3e90fa61-10ae-4f29-bc07-1a5ee34870a2,
client=false, topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:41,143][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:35:41,171][INFO][grid-nio-worker-tcp-comm-0-#25][TcpCommunicationSpi]
Established outgoing communication connection [locAddr=/64.101.22.97:53872,
rmtAddr=/64.101.22.95:47100]
[16:35:41,323][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832525728, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]]
[16:35:41,324][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:35:41,324][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Read checkpoint status [startMarker=null, endMarker=null]
[16:35:41,324][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Applying lost cache updates since last checkpoint record
[lastMarked=FileWALPointer [idx=0, fileOff=0, len=0],
lastCheckpointId=00000000-0000-0000-0000-000000000000]
[16:35:41,405][INFO][exchange-worker-#43][GridCacheDatabaseSharedManager]
Finished applying WAL changes [updatesApplied=0, time=81ms]
[16:35:41,440][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], crd=false]
[16:35:41,462][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=d00e7fdc-dffb-4d11-9bd5-55592dd328af,
startPtr=FileWALPointer [idx=0, fileOff=261363, len=47],
checkpointLockWait=0ms, checkpointLockHoldTime=3ms,
walCpRecordFsyncDuration=37ms, pages=27, reason='node started']
[16:35:41,508][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=d00e7fdc-dffb-4d11-9bd5-55592dd328af, pages=27,
markPos=FileWALPointer [idx=0, fileOff=261363, len=47],
walSegmentsCleared=0, markDuration=56ms, pagesWrite=8ms, fsync=36ms,
total=100ms]
[16:35:41,653][INFO][tcp-disco-msg-worker-#3][GridClusterStateProcessor]
Received state change finish message: true
[16:35:41,659][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Received full
message, will finish exchange [node=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:35:41,662][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], err=null]
[16:35:41,687][INFO][grid-nio-worker-tcp-comm-1-#26][TcpCommunicationSpi]
Established outgoing communication connection [locAddr=/64.101.22.97:39700,
rmtAddr=ccrc_spark_analytic_2.cisco.com/64.101.22.96:47100]
[16:35:41,695][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=4, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
node=9eb5b437-977b-4a27-874d-2f554f11b3b1]
[16:35:41,706][INFO][sys-#53][GridClusterStateProcessor] Successfully
performed final activation steps
[nodeId=3e90fa61-10ae-4f29-bc07-1a5ee34870a2, client=false,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[16:36:16,673][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=855d5f8d-57d0-49f0-830e-da51908019d2,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.98],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0, /64.101.22.98:0],
discPort=0, order=5, intOrder=5, lastExchangeTime=1533832576646, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:16,675][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=5, servers=4, clients=1, CPUs=16, offheap=50.0GB, heap=8.4GB]
[16:36:16,675][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=ACTIVE]
[16:36:16,676][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:16,676][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:16,676][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:16,678][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=855d5f8d-57d0-49f0-830e-da51908019d2,
customEvt=null, allowMerge=true]
[16:36:16,679][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=5,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=5, minorTopVer=0],
err=null]
[16:36:16,679][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], crd=false]
[16:36:16,681][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=5, minorTopVer=0], evt=NODE_JOINED,
node=855d5f8d-57d0-49f0-830e-da51908019d2]
[16:36:17,457][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], crd=false,
evt=DISCOVERY_CUSTOM_EVT, evtNode=855d5f8d-57d0-49f0-830e-da51908019d2,
customEvt=DynamicCacheChangeBatch
[id=612bb8f1561-de578bea-fbc7-4fe6-8d49-95906395021b,
reqs=[DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_QHDR, hasCfg=true,
nodeId=855d5f8d-57d0-49f0-830e-da51908019d2, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStartfalse]],
exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_QHDR],
stopCaches=null, startGrps=[SQL_PUBLIC_QHDR], stopGrps=[], resetParts=null,
stateChangeRequest=null], startCaches=false], allowMerge=false]
[16:36:17,595][INFO][exchange-worker-#43][GridCacheProcessor] Started cache
[name=SQL_PUBLIC_QHDR, id=-2066276374, memoryPolicyName=default,
mode=PARTITIONED, atomicity=ATOMIC, backups=1]
[16:36:17,605][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:36:17,626][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832525728, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1]]]
[16:36:17,626][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:36:17,686][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], crd=false]
[16:36:17,727][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Received full
message, will finish exchange [node=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
resVer=AffinityTopologyVersion [topVer=5, minorTopVer=1]]
[16:36:17,733][INFO][sys-#51][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=5, minorTopVer=1],
resVer=AffinityTopologyVersion [topVer=5, minorTopVer=1], err=null]
[16:36:17,738][INFO][pub-#59][GridCacheDatabaseSharedManager] Finished
indexes rebuilding for cache [name=SQL_PUBLIC_QHDR, grpName=null]
[16:36:17,741][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=5, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
node=855d5f8d-57d0-49f0-830e-da51908019d2]
[16:36:25,909][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:01:00.006]
    ^-- H/N/C [hosts=4, nodes=5, CPUs=16]
    ^-- CPU [cur=0.5%, avg=1.44%, GC=0%]
    ^-- PageMemory [pages=37]
    ^-- Heap [used=60MB, free=94.14%, comm=1024MB]
    ^-- Non heap [used=50MB, free=93.15%, comm=51MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=1, qSize=0]
    ^-- System thread pool [active=0, idle=8, qSize=0]
[16:36:32,315][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=6036816f-cbb9-43b3-94ff-ec55f233155d,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.96],
sockAddrs=[ccrc_spark_analytic_2.cisco.com/64.101.22.96:0,
/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0], discPort=0, order=6, intOrder=6,
lastExchangeTime=1533832592274, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=true]
[16:36:32,317][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=6, servers=4, clients=2, CPUs=16, offheap=60.0GB, heap=12.0GB]
[16:36:32,317][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=ACTIVE]
[16:36:32,317][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:32,317][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:32,317][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:32,318][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=6, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=6036816f-cbb9-43b3-94ff-ec55f233155d,
customEvt=null, allowMerge=true]
[16:36:32,318][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=6,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=6, minorTopVer=0],
err=null]
[16:36:32,319][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=6, minorTopVer=0], crd=false]
[16:36:32,322][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=6, minorTopVer=0], evt=NODE_JOINED,
node=6036816f-cbb9-43b3-94ff-ec55f233155d]
[16:36:32,335][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
accepted incoming connection [rmtAddr=/64.101.22.95, rmtPort=39396]
[16:36:32,335][INFO][tcp-disco-srvr-#2][TcpDiscoverySpi] TCP discovery
spawning a new thread for connection [rmtAddr=/64.101.22.95, rmtPort=39396]
[16:36:32,343][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=4cd15597-95eb-4870-b683-e23f4bea674b,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.98],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0, /64.101.22.98:0],
discPort=0, order=7, intOrder=7, lastExchangeTime=1533832592291, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:32,344][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=7, servers=4, clients=3, CPUs=16, offheap=70.0GB, heap=16.0GB]
[16:36:32,345][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=ACTIVE]
[16:36:32,345][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:32,345][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:32,345][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:32,346][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=7, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=4cd15597-95eb-4870-b683-e23f4bea674b,
customEvt=null, allowMerge=true]
[16:36:32,356][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=7,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=7, minorTopVer=0],
err=null]
[16:36:32,357][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=7, minorTopVer=0], crd=false]
[16:36:32,360][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=7, minorTopVer=0], evt=NODE_JOINED,
node=4cd15597-95eb-4870-b683-e23f4bea674b]
[16:36:32,362][INFO][tcp-disco-sock-reader-#7][TcpDiscoverySpi] Started
serving remote node connection [rmtAddr=/64.101.22.95:39396, rmtPort=39396]
[16:36:32,515][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=2ba16c0b-e88d-4fb1-b0ff-f3ac43dc8b58,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0, /64.101.22.95:0],
discPort=0, order=8, intOrder=8, lastExchangeTime=1533832592447, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:32,516][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=8, servers=4, clients=4, CPUs=16, offheap=80.0GB, heap=19.0GB]
[16:36:32,516][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=ACTIVE]
[16:36:32,516][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:32,517][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:32,517][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:32,517][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=8, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=2ba16c0b-e88d-4fb1-b0ff-f3ac43dc8b58,
customEvt=null, allowMerge=true]
[16:36:32,518][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=8,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=0],
err=null]
[16:36:32,518][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=8, minorTopVer=0], crd=false]
[16:36:32,521][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=8, minorTopVer=0], evt=NODE_JOINED,
node=2ba16c0b-e88d-4fb1-b0ff-f3ac43dc8b58]
[16:36:33,312][INFO][grid-nio-worker-tcp-comm-2-#27][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.97:47100,
rmtAddr=/64.101.22.95:36338]
[16:36:36,095][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=e55be418-9131-4abd-8f9c-d3616a0cb508,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.97],
sockAddrs=[/64.101.22.97:0, /0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0],
discPort=0, order=9, intOrder=9, lastExchangeTime=1533832595997, loc=false,
ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:36,096][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=9, servers=4, clients=5, CPUs=16, offheap=90.0GB, heap=23.0GB]
[16:36:36,096][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=ACTIVE]
[16:36:36,096][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:36,096][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:36,096][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:36,097][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=9, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=e55be418-9131-4abd-8f9c-d3616a0cb508,
customEvt=null, allowMerge=true]
[16:36:36,097][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=9,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=9, minorTopVer=0],
err=null]
[16:36:36,097][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=9, minorTopVer=0], crd=false]
[16:36:36,100][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=9, minorTopVer=0], evt=NODE_JOINED,
node=e55be418-9131-4abd-8f9c-d3616a0cb508]
[16:36:36,120][INFO][disco-event-worker-#41][GridDiscoveryManager] Added new
node to topology: TcpDiscoveryNode [id=e780e47b-9117-4382-8b4d-d4de92c69b46,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.97],
sockAddrs=[/64.101.22.97:0, /0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0],
discPort=0, order=10, intOrder=10, lastExchangeTime=1533832596044,
loc=false, ver=2.6.0#20180710-sha1:669feacc, isClient=true]
[16:36:36,122][INFO][disco-event-worker-#41][GridDiscoveryManager] Topology
snapshot [ver=10, servers=4, clients=6, CPUs=16, offheap=100.0GB,
heap=26.0GB]
[16:36:36,122][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Node [id=3E90FA61-10AE-4F29-BC07-1A5EE34870A2, clusterState=ACTIVE]
[16:36:36,122][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]
[16:36:36,122][INFO][disco-event-worker-#41][GridDiscoveryManager] Data
Regions Configured:
[16:36:36,122][INFO][disco-event-worker-#41][GridDiscoveryManager]   ^--
default [initSize=256.0 MiB, maxSize=10.0 GiB, persistenceEnabled=true]
[16:36:36,123][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=0], crd=false,
evt=NODE_JOINED, evtNode=e780e47b-9117-4382-8b4d-d4de92c69b46,
customEvt=null, allowMerge=true]
[16:36:36,124][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=10,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=10, minorTopVer=0],
err=null]
[16:36:36,124][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=0], crd=false]
[16:36:36,127][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=10, minorTopVer=0], evt=NODE_JOINED,
node=e780e47b-9117-4382-8b4d-d4de92c69b46]
[16:36:37,144][INFO][grid-nio-worker-tcp-comm-3-#28][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.97:47100,
rmtAddr=/64.101.22.96:47328]
[16:36:37,965][INFO][grid-nio-worker-tcp-comm-0-#25][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/64.101.22.97:47100,
rmtAddr=/64.101.22.98:41826]
[16:36:47,125][INFO][grid-nio-worker-tcp-comm-1-#26][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/127.0.0.1:47100,
rmtAddr=/127.0.0.1:50908]
[16:36:49,915][INFO][grid-nio-worker-tcp-comm-2-#27][TcpCommunicationSpi]
Accepted incoming communication connection [locAddr=/127.0.0.1:47100,
rmtAddr=/127.0.0.1:50910]
[16:37:25,911][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:02:00.014]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=25.5%, avg=11.21%, GC=0.6%]
    ^-- PageMemory [pages=240343]
    ^-- Heap [used=325MB, free=68.26%, comm=1024MB]
    ^-- Non heap [used=61MB, free=91.74%, comm=62MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:38:25,920][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:03:00.022]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=13.4%, avg=16.22%, GC=0%]
    ^-- PageMemory [pages=483399]
    ^-- Heap [used=507MB, free=50.47%, comm=1024MB]
    ^-- Non heap [used=60MB, free=91.85%, comm=63MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:38:43,496][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=a4e541e7-5fc7-4b7d-945f-56e75917278e,
startPtr=FileWALPointer [idx=51, fileOff=62100019, len=11282],
checkpointLockWait=0ms, checkpointLockHoldTime=76ms,
walCpRecordFsyncDuration=290ms, pages=536455, reason='timeout']
[16:39:11,926][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=a4e541e7-5fc7-4b7d-945f-56e75917278e,
pages=536455, markPos=FileWALPointer [idx=51, fileOff=62100019, len=11282],
walSegmentsCleared=0, markDuration=2090ms, pagesWrite=22345ms, fsync=6084ms,
total=30519ms]
[16:39:25,924][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:04:00.022]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=19.67%, avg=21.51%, GC=0.6%]
    ^-- PageMemory [pages=659362]
    ^-- Heap [used=580MB, free=43.36%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.51%, comm=64MB]
    ^-- Outbound messages queue [size=1]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:40:25,924][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:05:00.028]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=21.07%, avg=21.58%, GC=0.33%]
    ^-- PageMemory [pages=846121]
    ^-- Heap [used=627MB, free=38.72%, comm=1024MB]
    ^-- Non heap [used=61MB, free=91.68%, comm=64MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:40:32,565][INFO][exchange-worker-#43][time] Started exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], crd=false,
evt=DISCOVERY_CUSTOM_EVT, evtNode=855d5f8d-57d0-49f0-830e-da51908019d2,
customEvt=DynamicCacheChangeBatch
[id=de7bb8f1561-de578bea-fbc7-4fe6-8d49-95906395021b,
reqs=[DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_QMAJOR, hasCfg=true,
nodeId=855d5f8d-57d0-49f0-830e-da51908019d2, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStartfalse]],
exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_QMAJOR],
stopCaches=null, startGrps=[SQL_PUBLIC_QMAJOR], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
allowMerge=false]
[16:40:32,638][INFO][exchange-worker-#43][GridCacheProcessor] Started cache
[name=SQL_PUBLIC_QMAJOR, id=-1412181587, memoryPolicyName=default,
mode=PARTITIONED, atomicity=ATOMIC, backups=1]
[16:40:32,644][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:40:32,693][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
addrs=[0:0:0:0:0:0:0:1%lo, 127.0.0.1, 64.101.22.95],
sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
/64.101.22.95:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1533832525728, loc=false, ver=2.6.0#20180710-sha1:669feacc,
isClient=false], ackSent=true, super=CompletableLatch [id=exchange,
topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1]]]
[16:40:32,694][INFO][exchange-worker-#43][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], waitTime=0ms,
futInfo=NA]
[16:40:32,749][INFO][exchange-worker-#43][time] Finished exchange init
[topVer=AffinityTopologyVersion [topVer=10, minorTopVer=1], crd=false]
[16:40:32,785][INFO][sys-#84][GridDhtPartitionsExchangeFuture] Received full
message, will finish exchange [node=6aba33d0-311a-4bbb-bc09-0959a62eddd6,
resVer=AffinityTopologyVersion [topVer=10, minorTopVer=1]]
[16:40:32,789][INFO][sys-#84][GridDhtPartitionsExchangeFuture] Finish
exchange future [startVer=AffinityTopologyVersion [topVer=10,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=10, minorTopVer=1],
err=null]
[16:40:32,799][INFO][exchange-worker-#43][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=10, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
node=855d5f8d-57d0-49f0-830e-da51908019d2]
[16:40:32,800][INFO][pub-#85][GridCacheDatabaseSharedManager] Finished
indexes rebuilding for cache [name=SQL_PUBLIC_QMAJOR, grpName=null]
[16:41:25,933][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:06:00.037]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=23.43%, avg=22.47%, GC=0.7%]
    ^-- PageMemory [pages=1045037]
    ^-- Heap [used=599MB, free=41.5%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.41%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=1, qSize=0]
    ^-- System thread pool [active=0, idle=8, qSize=0]
[16:41:42,871][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=49a7ce4f-ea12-40d9-9311-4bf97bded048,
startPtr=FileWALPointer [idx=118, fileOff=9710039, len=20617],
checkpointLockWait=0ms, checkpointLockHoldTime=52ms,
walCpRecordFsyncDuration=198ms, pages=661927, reason='timeout']
[16:42:25,940][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:07:00.042]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=15.67%, avg=24.3%, GC=0.17%]
    ^-- PageMemory [pages=1221710]
    ^-- Heap [used=387MB, free=62.19%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.49%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:43:25,947][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:08:00.049]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=4.5%, avg=21.68%, GC=0%]
    ^-- PageMemory [pages=1225810]
    ^-- Heap [used=636MB, free=37.85%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.46%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:44:23,844][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=49a7ce4f-ea12-40d9-9311-4bf97bded048,
pages=661927, markPos=FileWALPointer [idx=118, fileOff=9710039, len=20617],
walSegmentsCleared=0, markDuration=1456ms, pagesWrite=139159ms,
fsync=21813ms, total=162428ms]
[16:44:25,956][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:09:00.055]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=6.4%, avg=20.37%, GC=0.2%]
    ^-- PageMemory [pages=1266931]
    ^-- Heap [used=426MB, free=58.33%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.45%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:44:41,874][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=17ee184e-e37f-4b1e-b1a6-950597585b86,
startPtr=FileWALPointer [idx=138, fileOff=11618977, len=20617],
checkpointLockWait=0ms, checkpointLockHoldTime=23ms,
walCpRecordFsyncDuration=189ms, pages=208080, reason='timeout']
[16:45:07,153][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=17ee184e-e37f-4b1e-b1a6-950597585b86,
pages=208080, markPos=FileWALPointer [idx=138, fileOff=11618977, len=20617],
walSegmentsCleared=0, markDuration=456ms, pagesWrite=4310ms, fsync=20968ms,
total=25734ms]
[16:45:25,990][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:10:00.092]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=34.4%, avg=21.33%, GC=0.83%]
    ^-- PageMemory [pages=1422412]
    ^-- Heap [used=377MB, free=63.09%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.48%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:46:25,998][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:11:00.098]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=38.17%, avg=22.63%, GC=2.47%]
    ^-- PageMemory [pages=1661176]
    ^-- Heap [used=637MB, free=37.74%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.51%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:47:26,002][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:12:00.105]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=28.4%, avg=23.82%, GC=1.5%]
    ^-- PageMemory [pages=1895385]
    ^-- Heap [used=288MB, free=71.85%, comm=1024MB]
    ^-- Non heap [used=62MB, free=91.56%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:47:42,690][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=f4dbe4f2-8510-4428-b8d9-40dd2fbf9bea,
startPtr=FileWALPointer [idx=212, fileOff=52611399, len=20617],
checkpointLockWait=1ms, checkpointLockHoldTime=28ms,
walCpRecordFsyncDuration=338ms, pages=725316, reason='timeout']
[16:48:26,010][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:13:00.106]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=64.9%, avg=24.71%, GC=1%]
    ^-- PageMemory [pages=2045788]
    ^-- Heap [used=589MB, free=42.4%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.53%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:48:44,775][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=f4dbe4f2-8510-4428-b8d9-40dd2fbf9bea,
pages=725316, markPos=FileWALPointer [idx=212, fileOff=52611399, len=20617],
walSegmentsCleared=0, markDuration=1273ms, pagesWrite=57165ms, fsync=4920ms,
total=63359ms]
[16:49:26,003][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:14:00.106]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=0.17%, avg=24.09%, GC=0%]
    ^-- PageMemory [pages=2113002]
    ^-- Heap [used=835MB, free=18.45%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.52%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:50:26,012][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:15:00.115]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=44%, avg=22.73%, GC=1.7%]
    ^-- PageMemory [pages=2164851]
    ^-- Heap [used=729MB, free=28.74%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.52%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:50:41,879][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint started [checkpointId=da3d20a5-c2ce-4bfb-b446-3d7b9cbdf7fa,
startPtr=FileWALPointer [idx=243, fileOff=54767645, len=20617],
checkpointLockWait=0ms, checkpointLockHoldTime=26ms,
walCpRecordFsyncDuration=256ms, pages=309780, reason='timeout']
[16:51:26,017][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:16:00.119]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=0.57%, avg=22.42%, GC=0%]
    ^-- PageMemory [pages=2220223]
    ^-- Heap [used=415MB, free=59.44%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.51%, comm=66MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]
[16:51:47,120][INFO][db-checkpoint-thread-#46][GridCacheDatabaseSharedManager]
Checkpoint finished [cpId=da3d20a5-c2ce-4bfb-b446-3d7b9cbdf7fa,
pages=309780, markPos=FileWALPointer [idx=243, fileOff=54767645, len=20617],
walSegmentsCleared=0, markDuration=454ms, pagesWrite=47535ms, fsync=17706ms,
total=65695ms]
[16:52:26,024][INFO][grid-timeout-worker-#23][IgniteKernal]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=3e90fa61, uptime=00:17:00.122]
    ^-- H/N/C [hosts=4, nodes=10, CPUs=16]
    ^-- CPU [cur=6.83%, avg=22.13%, GC=0.4%]
    ^-- PageMemory [pages=2342159]
    ^-- Heap [used=790MB, free=22.77%, comm=1024MB]
    ^-- Non heap [used=63MB, free=91.51%, comm=67MB]
    ^-- Outbound messages queue [size=0]
    ^-- Public thread pool [active=0, idle=0, qSize=0]
    ^-- System thread pool [active=0, idle=6, qSize=0]

Thanks




--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/
dkarachentsev dkarachentsev
Reply | Threaded
Open this post in threaded view
|

Re: Spark to Ignite Data load, Ignite node crashashing

Hi,

Looks like it was killed by kernel. Check logs for OOM Killer:
grep -i 'killed process' /var/log/messages

If process was killed by Linux, correct your config, you might be set too
much memory for Ignite paged memory, set to lower values [1]

If not, try to find in logs by PID, maybe it was killed due to other reason.

[1] https://apacheignite.readme.io/docs/memory-configuration

Thanks!
-Dmitry



--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/