You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ignite.apache.org by Marco Bernagozzi <ma...@gmail.com> on 2019/09/24 12:00:55 UTC
Failed to read magic header (too few bytes received)
Hi.
I get this error sometimes, it seems to be quite random. Any idea what this
might be caused by?
Since every time it's thrown a hundred times or so, I had to temporarily
suppress all the errors from that class. Is there a way to fix this or at
least to make it be thrown just once?
My settings:
AwsConfiguration awsConfiguration = AwsConfigurationSingleton.getInstance();
BasicAWSCredentials creds = new BasicAWSCredentials(
awsConfiguration.getAwsAccessKey(),
awsConfiguration.getAwsSecretKey()
);
TcpDiscoveryS3IpFinder ipFinder = new TcpDiscoveryS3IpFinder();
ipFinder.setAwsCredentials(creds);
ipFinder.setBucketEndpoint("s3.eu-west-1.amazonaws.com");
ipFinder.setBucketName(awsConfiguration.getIgniteBucket());
TcpDiscoverySpi spi = new TcpDiscoverySpi();
spi.setIpFinder(ipFinder);
IgniteConfiguration cfg = new IgniteConfiguration();
DataStorageConfiguration storageCfg = new DataStorageConfiguration();
storageCfg.getDefaultDataRegionConfiguration().setPersistenceEnabled(false);
cfg.setDataStorageConfiguration(storageCfg);
IgniteLogger log = new Slf4jLogger();
cfg.setGridLogger(log);
TcpCommunicationSpi commSpi = new TcpCommunicationSpi();
commSpi.setMessageQueueLimit(10000);
cfg.setCommunicationSpi(commSpi);
cfg.setDiscoverySpi(spi);
cfg.setBinaryConfiguration(new BinaryConfiguration());
cfg.getBinaryConfiguration().setCompactFooter(false);
cfg.setFailureDetectionTimeout(60 * 1000);
The log:
INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
>>> __________ ________________
>>> / _/ ___/ |/ / _/_ __/ __/
>>> _/ // (7 7 // / / / / _/
>>> /___/\___/_/|_/___/ /_/ /___/
>>>
>>> ver. 2.7.5#20190603-sha1:be4f2a15
>>> 2018 Copyright(C) Apache Software Foundation
>>>
>>> Ignite documentation: http://ignite.apache.org
INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
Config URL: n/a
INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
IgniteConfiguration [igniteInstanceName=null, pubPoolSize=36,
svcPoolSize=36, callbackPoolSize=36, stripedPoolSize=36, sysPoolSize=36,
mgmtPoolSize=4, igfsPoolSize=36, dataStreamerPoolSize=36,
utilityCachePoolSize=36, utilityCacheKeepAliveTime=60000, p2pPoolSize=2,
qryPoolSize=36, igniteHome=/opt/ignite/apache-ignite-2.7.5-bin,
igniteWorkDir=/opt/ignite/apache-ignite-2.7.5-bin/work,
mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@47c81abf,
nodeId=09156c05-f869-4826-814e-1f47fcefeeb4, marsh=BinaryMarshaller [],
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=org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$FirstConnectionPolicy@104d9de4,
enableForcibleNodeKill=false, enableTroubleshootingLog=false, 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=10000, slowClientQueueLimit=0,
nioSrvr=null, shmemSrv=null, usePairedConnections=false,
connectionsPerNode=1, tcpNoDelay=true, filterReachableAddresses=false,
ackSndThreshold=32, unackedMsgsBufSize=0, sockWriteTimeout=2000,
boundTcpPort=-1, boundTcpShmemPort=-1, selectorsCnt=18, selectorSpins=0,
addrRslvr=null, ctxInitLatch=java.util.concurrent.CountDownLatch@2b43b6cc[Count
= 1], stopping=false],
evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@3221402f,
colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [],
indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@415fad70,
addrRslvr=null,
encryptionSpi=org.apache.ignite.spi.encryption.noop.NoopEncryptionSpi@7947ad4c,
clientMode=false, rebalanceThreadPoolSize=1, txCfg=TransactionConfiguration
[txSerEnabled=false, dfltIsolation=REPEATABLE_READ,
dfltConcurrency=PESSIMISTIC, dfltTxTimeout=0,
txTimeoutOnPartitionMapExchange=0, pessimisticTxLogSize=0,
pessimisticTxLogLinger=10000, tmLookupClsName=null, txManagerFactory=null,
useJtaSync=false], cacheSanityCheckEnabled=true, discoStartupDelay=60000,
deployMode=SHARED, p2pMissedCacheSize=100, locHost=null,
timeSrvPortBase=31100, timeSrvPortRange=100, failureDetectionTimeout=60000,
sysWorkerBlockedTimeout=null, clientFailureDetectionTimeout=30000,
metricsLogFreq=60000, hadoopCfg=null, connectorCfg=ConnectorConfiguration
[jettyPath=null, host=null, port=11211, noDelay=true, directBuf=false,
sndBufSize=32768, rcvBufSize=32768, idleQryCurTimeout=600000,
idleQryCurCheckFreq=60000, sndQueueLimit=0, selectorCnt=4,
idleTimeout=7000, sslEnabled=false, sslClientAuth=false,
sslCtxFactory=null, sslFactory=null, portRange=100, threadPoolSize=36,
msgInterceptor=null], odbcCfg=null, warmupClos=null,
atomicCfg=AtomicConfiguration [seqReserveSize=1000, cacheMode=PARTITIONED,
backups=1, aff=null, grpName=null], classLdr=null, sslCtxFactory=null,
platformCfg=null, binaryCfg=BinaryConfiguration [idMapper=null,
nameMapper=null, serializer=null, compactFooter=false], memCfg=null,
pstCfg=null, dsCfg=DataStorageConfiguration [sysRegionInitSize=41943040,
sysRegionMaxSize=104857600, pageSize=0, concLvl=0,
dfltDataRegConf=DataRegionConfiguration [name=default, maxSize=14753283276,
initSize=268435456, swapPath=null, pageEvictionMode=DISABLED,
evictionThreshold=0.9, emptyPagesPoolSize=100, metricsEnabled=false,
metricsSubIntervalCount=5, metricsRateTimeInterval=60000,
persistenceEnabled=false, checkpointPageBufSize=0], dataRegions=null,
storagePath=null, checkpointFreq=180000, lockWaitTime=10000,
checkpointThreads=4, checkpointWriteOrder=SEQUENTIAL, walHistSize=20,
maxWalArchiveSize=1073741824, walSegments=10, walSegmentSize=67108864,
walPath=db/wal, walArchivePath=db/wal/archive, metricsEnabled=false,
walMode=LOG_ONLY, walTlbSize=131072, walBuffSize=0, walFlushFreq=2000,
walFsyncDelay=1000, walRecordIterBuffSize=67108864,
alwaysWriteFullPages=false,
fileIOFactory=org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIOFactory@349479c0,
metricsSubIntervalCnt=5, metricsRateTimeInterval=60000,
walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false,
walCompactionEnabled=false, walCompactionLevel=1,
checkpointReadLockTimeout=null], activeOnStart=true, autoActivation=true,
longQryWarnTimeout=3000, sqlConnCfg=null,
cliConnCfg=ClientConnectorConfiguration [host=null, port=10800,
portRange=100, sockSndBufSize=0, sockRcvBufSize=0, tcpNoDelay=true,
maxOpenCursorsPerConn=128, threadPoolSize=36, idleTimeout=0,
jdbcEnabled=true, odbcEnabled=true, thinCliEnabled=true, sslEnabled=false,
useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null],
mvccVacuumThreadCnt=2, mvccVacuumFreq=5000, authEnabled=false,
failureHnd=null, commFailureRslvr=null]
INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
Daemon mode: off
INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: OS:
Linux 4.4.0-1020-aws amd64
INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: OS
user: root
INFO [2019-09-24 10:04:21,415] org.apache.ignite.internal.IgniteKernal:
PID: 1
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
Language runtime: Java Platform API Specification ver. 11
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM
information: OpenJDK Runtime Environment 11.0.3+1-Debian-1bpo91 Oracle
Corporation OpenJDK 64-Bit Server VM 11.0.3+1-Debian-1bpo91
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM
total memory: 17.0GB
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
Remote Management [restart: off, REST: on, JMX (remote: off)]
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
Logger: Slf4jLogger [impl=Logger[org.apache.ignite.internal.IgniteKernal],
quiet=false]
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
IGNITE_HOME=/opt/ignite/apache-ignite-2.7.5-bin
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM
arguments: [-XX:+AlwaysPreTouch, -XX:+UseG1GC, -XX:+DisableExplicitGC,
-XX:+ScavengeBeforeFullGC,
--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED,
--add-exports=java.base/sun.nio.ch=ALL-UNNAMED,
--add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED,
--add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED,
--add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED,
--illegal-access=permit, -Djdk.tls.client.protocols=TLSv1.2,
-Djava.net.preferIPv4Stack=true, -DIGNITE_QUIET=false]
INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
System cache's DataRegion size is configured to 40 MB. Use
DataStorageConfiguration.systemRegionInitialSize property to change the
setting.
INFO [2019-09-24 10:04:21,420] org.apache.ignite.internal.IgniteKernal:
Configured caches [in 'sysMemPlc' dataRegion: ['ignite-sys-cache']]
INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal:
3-rd party licenses can be found at:
/opt/ignite/apache-ignite-2.7.5-bin/libs/licenses
INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal:
Local node user attribute [algotworker=true]
INFO [2019-09-24 10:04:21,460]
org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
Configured plugins:
INFO [2019-09-24 10:04:21,460]
org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor: ^-- None
INFO [2019-09-24 10:04:21,460]
org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
INFO [2019-09-24 10:04:21,460]
org.apache.ignite.internal.processors.failure.FailureProcessor: Configured
failure handler: [hnd=StopNodeOrHaltFailureHandler [tryStop=false,
timeout=0, super=AbstractFailureHandler
[ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED,
SYSTEM_CRITICAL_OPERATION_TIMEOUT]]]]
INFO [2019-09-24 10:04:21,495]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi: Successfully
bound communication NIO server to TCP port [port=47100, locHost=
0.0.0.0/0.0.0.0, selectorsCnt=18, selectorSpins=0, pairedConn=false]
WARN [2019-09-24 10:04:21,519]
org.apache.ignite.spi.checkpoint.noop.NoopCheckpointSpi: Checkpoints are
disabled (to enable configure any GridCheckpointSpi implementation)
WARN [2019-09-24 10:04:21,533]
org.apache.ignite.internal.managers.collision.GridCollisionManager:
Collision resolution is disabled (all jobs will be activated upon arrival).
INFO [2019-09-24 10:04:21,536] org.apache.ignite.internal.IgniteKernal:
Security status [authentication=off, tls/ssl=off]
WARN [2019-09-24 10:04:21,656]
org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager:
DataRegionConfiguration.maxWalArchiveSize instead
DataRegionConfiguration.walHistorySize would be used for removing old
archive wal files
INFO [2019-09-24 10:04:21,666]
org.apache.ignite.internal.processors.cache.distributed.dht.topology.PartitionsEvictManager:
Evict partition permits=9
INFO [2019-09-24 10:04:21,785]
org.apache.ignite.internal.processors.odbc.ClientListenerProcessor: Client
connector processor has started on TCP port 10800
INFO [2019-09-24 10:04:21,811]
org.apache.ignite.internal.processors.rest.protocols.tcp.GridTcpRestProtocol:
Command protocol successfully started [name=TCP binary, host=0.0.0.0/0.0.0.0,
port=11211]
INFO [2019-09-24 10:04:21,817] org.eclipse.jetty.server.Server:
jetty-9.0.z-SNAPSHOT
INFO [2019-09-24 10:04:21,819] org.eclipse.jetty.server.ServerConnector:
Started ServerConnector@47eb8e95{HTTP/1.1}{0.0.0.0:8080}
INFO [2019-09-24 10:04:21,819]
org.apache.ignite.internal.processors.rest.protocols.http.jetty.GridJettyRestProtocol:
Command protocol successfully started [name=Jetty REST, host=/0.0.0.0,
port=8080]
INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal:
Non-loopback local IPs: 10.0.31.159, 169.254.1.1, 172.17.0.1, 172.18.0.1
INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal:
Enabled local MACs: 024254D57DDE, 0242BC90FC25, 0632865AE178, 8AB58EDB020C
INFO [2019-09-24 10:04:21,863]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Connection check
threshold is calculated: 60000
INFO [2019-09-24 10:04:21,867]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Successfully bound to
TCP port [port=47500, localHost=0.0.0.0/0.0.0.0,
locNodeId=09156c05-f869-4826-814e-1f47fcefeeb4]
WARN [2019-09-24 10:04:21,869]
org.apache.ignite.spi.discovery.tcp.ipfinder.s3.TcpDiscoveryS3IpFinder:
Amazon client configuration is not set (will use default).
INFO [2019-09-24 10:04:22,520]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
incoming connection [rmtAddr=/10.0.11.210, rmtPort=57994]
INFO [2019-09-24 10:04:22,524]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57994]
INFO [2019-09-24 10:04:22,524]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote
node connection [rmtAddr=/10.0.11.210:57994, rmtPort=57994]
WARN [2019-09-24 10:04:22,525]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic
header (too few bytes received) [rmtAddr=/10.0.11.210:57994, locAddr=/
10.0.31.159:47500]
INFO [2019-09-24 10:04:22,525]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving
remote node connection [rmtAddr=/10.0.11.210:57994, rmtPort=57994
INFO [2019-09-24 10:04:22,722]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
incoming connection [rmtAddr=/10.0.11.210, rmtPort=57996]
INFO [2019-09-24 10:04:22,722]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57996]
INFO [2019-09-24 10:04:22,722]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote
node connection [rmtAddr=/10.0.11.210:57996, rmtPort=57996]
WARN [2019-09-24 10:04:22,722]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic
header (too few bytes received) [rmtAddr=/10.0.11.210:57996, locAddr=/
10.0.31.159:47500]
INFO [2019-09-24 10:04:22,722]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving
remote node connection [rmtAddr=/10.0.11.210:57996, rmtPort=57996
INFO [2019-09-24 10:04:22,923]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
incoming connection [rmtAddr=/10.0.11.210, rmtPort=57998]
INFO [2019-09-24 10:04:22,924]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57998]
Re: Failed to read magic header (too few bytes received)
Posted by Marco Bernagozzi <ma...@gmail.com>.
Update 2:
Digging more in the logging, the issue seems to be:
[tcp-disco-ip-finder-cleaner-#5] ERROR
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - Failed to clean IP
finder up.
class org.apache.ignite.spi.IgniteSpiException: Failed to list objects in
the bucket: ignite-configurations-production
at
org.apache.ignite.spi.discovery.tcp.ipfinder.s3.TcpDiscoveryS3IpFinder.getRegisteredAddresses(TcpDiscoveryS3IpFinder.java:192)
at
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi.registeredAddresses(TcpDiscoverySpi.java:1900)
at
org.apache.ignite.spi.discovery.tcp.ServerImpl$IpFinderCleaner.cleanIpFinder(ServerImpl.java:1998)
at
org.apache.ignite.spi.discovery.tcp.ServerImpl$IpFinderCleaner.body(ServerImpl.java:1973)
at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
Caused by: com.amazonaws.SdkClientException: Failed to sanitize XML
document destined for handler class
com.amazonaws.services.s3.model.transform.XmlResponsesSaxParser$ListBucketHandler
at
com.amazonaws.services.s3.model.transform.XmlResponsesSaxParser.sanitizeXmlDocument(XmlResponsesSaxParser.java:214)
at
com.amazonaws.services.s3.model.transform.XmlResponsesSaxParser.parseListBucketObjectsResponse(XmlResponsesSaxParser.java:298)
at
com.amazonaws.services.s3.model.transform.Unmarshallers$ListObjectsUnmarshaller.unmarshall(Unmarshallers.java:70)
at
com.amazonaws.services.s3.model.transform.Unmarshallers$ListObjectsUnmarshaller.unmarshall(Unmarshallers.java:59)
at
com.amazonaws.services.s3.internal.S3XmlResponseHandler.handle(S3XmlResponseHandler.java:62)
at
com.amazonaws.services.s3.internal.S3XmlResponseHandler.handle(S3XmlResponseHandler.java:31)
at
com.amazonaws.http.response.AwsResponseHandlerAdapter.handle(AwsResponseHandlerAdapter.java:70)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleResponse(AmazonHttpClient.java:1554)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1272)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1056)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:743)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:717)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:699)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:667)
at
com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:649)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:513)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4137)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4079)
at
com.amazonaws.services.s3.AmazonS3Client.listObjects(AmazonS3Client.java:819)
at
com.amazonaws.services.s3.AmazonS3Client.listObjects(AmazonS3Client.java:791)
at
org.apache.ignite.spi.discovery.tcp.ipfinder.s3.TcpDiscoveryS3IpFinder.getRegisteredAddresses(TcpDiscoveryS3IpFinder.java:146)
... 4 more
Caused by: com.amazonaws.AbortedException:
at
com.amazonaws.internal.SdkFilterInputStream.abortIfNeeded(SdkFilterInputStream.java:53)
at
com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:81)
at
com.amazonaws.event.ProgressInputStream.read(ProgressInputStream.java:180)
at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
at java.base/java.io.InputStreamReader.read(InputStreamReader.java:185)
at java.base/java.io.BufferedReader.read1(BufferedReader.java:210)
at java.base/java.io.BufferedReader.read(BufferedReader.java:287)
at java.base/java.io.Reader.read(Reader.java:229)
at
com.amazonaws.services.s3.model.transform.XmlResponsesSaxParser.sanitizeXmlDocument(XmlResponsesSaxParser.java:186)
... 24 more
[tcp-disco-msg-worker-#2] INFO
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node
[newNext=TcpDiscoveryNode [id=bc657c40-27dd-4190-af04-e53068176937,
addrs=[10.0.11.210, 127.0.0.1, 172.17.0.1, 172.18.0.1],
sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/172.18.0.1:47500],
discPort=47500, order=8, intOrder=7, lastExchangeTime=1569318655381,
loc=false, ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
On Tue, 24 Sep 2019 at 15:59, Marco Bernagozzi <ma...@gmail.com>
wrote:
> It was on aws, and I don't have the IP log of all the instances I had up.
> My best guess it's that it was just one of the slave instances.
> I have two sets of machines, masters and slaves. They are all servers. The
> masters create caches and distribute caches to a set of slaves using a node
> filter.
> Here are the options I'm using to run it
>
> CMD ["java", "-jar", "-XX:+AlwaysPreTouch", "-XX:+UseG1GC",
> "-XX:+DisableExplicitGC", "-XX:+ScavengeBeforeFullGC",
> "--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED",
> "--add-exports=java.base/sun.nio.ch=ALL-UNNAMED",
> "--add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED",
> "--add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED",
> "--add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED","--illegal-access=permit",
> "-Djdk.tls.client.protocols=TLSv1.2", "-Djava.net.preferIPv4Stack=true",
> "-DIGNITE_QUIET=false", "algotworker.jar", "server", "config.yml"]
>
> In my logs, "10.0.11.210" appears first in the slave nodes:
> [main] INFO org.apache.ignite.internal.IgniteKernal - Non-loopback local
> IPs: 10.0.11.210, 169.254.1.1, 172.17.0.1, 172.18.0.1
> [tcp-disco-msg-worker-#2] INFO
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node
> [newNext=TcpDiscoveryNode [id=bc657c40-27dd-4190-af04-e53068176937,
> addrs=[10.0.11.210, 127.0.0.1, 172.17.0.1, 172.18.0.1],
> sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
> 127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
> 10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/
> 172.18.0.1:47500], discPort=47500, order=8, intOrder=7,
> lastExchangeTime=1569318655381, loc=false,
> ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
> [tcp-disco-msg-worker-#2] WARN
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node has
> connection to it's previous, trying previous again. [next=TcpDiscoveryNode
> [id=bc657c40-27dd-4190-af04-e53068176937, addrs=[10.0.11.210, 127.0.0.1,
> 172.17.0.1, 172.18.0.1],
> sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
> 127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
> 10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/
> 172.18.0.1:47500], discPort=47500, order=8, intOrder=7,
> lastExchangeTime=1569318655381, loc=false,
> ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
> [tcp-disco-msg-worker-#2] INFO
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node
> [newNext=TcpDiscoveryNode [id=bc657c40-27dd-4190-af04-e53068176937,
> addrs=[10.0.11.210, 127.0.0.1, 172.17.0.1, 172.18.0.1],
> sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
> 127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
> 10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/
> 172.18.0.1:47500], discPort=47500, order=8, intOrder=7,
> lastExchangeTime=1569318655381, loc=false,
> ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
> [tcp-disco-msg-worker-#2] WARN
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node has
> connection to it's previous, trying previous again. [next=TcpDiscoveryNode
> [id=bc657c40-27dd-4190-af04-e53068176937, addrs=[10.0.11.210, 127.0.0.1,
> 172.17.0.1, 172.18.0.1],
> sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
> 127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
> 10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/
> 172.18.0.1:47500], discPort=47500, order=8, intOrder=7,
> lastExchangeTime=1569318655381, loc=false,
> ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
>
> I didn't see this before. What does this mean? I guess this is the issue,
> right?
>
>
> On Tue, 24 Sep 2019 at 15:16, Stephen Darlington <
> stephen.darlington@gridgain.com> wrote:
>
>> What’s on IP address 10.0.11.210? It’s sending Ignite something that it
>> doesn’t understand. Maybe it’s not another copy of Ignite? Could it be a
>> firewall setting truncating the message? Or perhaps the remote node has a
>> different configuration, for example mixing up communication and discovery
>> ports?
>>
>> Regards,
>> Stephen
>>
>> On 24 Sep 2019, at 13:00, Marco Bernagozzi <ma...@gmail.com>
>> wrote:
>>
>> Hi.
>> I get this error sometimes, it seems to be quite random. Any idea what
>> this might be caused by?
>> Since every time it's thrown a hundred times or so, I had to temporarily
>> suppress all the errors from that class. Is there a way to fix this or at
>> least to make it be thrown just once?
>>
>> My settings:
>>
>> AwsConfiguration awsConfiguration =
>> AwsConfigurationSingleton.getInstance();
>> BasicAWSCredentials creds = new BasicAWSCredentials(
>> awsConfiguration.getAwsAccessKey(),
>> awsConfiguration.getAwsSecretKey()
>> );
>> TcpDiscoveryS3IpFinder ipFinder = new TcpDiscoveryS3IpFinder();
>> ipFinder.setAwsCredentials(creds);
>> ipFinder.setBucketEndpoint("s3.eu-west-1.amazonaws.com");
>> ipFinder.setBucketName(awsConfiguration.getIgniteBucket());
>>
>> TcpDiscoverySpi spi = new TcpDiscoverySpi();
>> spi.setIpFinder(ipFinder);
>> IgniteConfiguration cfg = new IgniteConfiguration();
>> DataStorageConfiguration storageCfg = new DataStorageConfiguration();
>>
>> storageCfg.getDefaultDataRegionConfiguration().setPersistenceEnabled(false);
>> cfg.setDataStorageConfiguration(storageCfg);
>> IgniteLogger log = new Slf4jLogger();
>> cfg.setGridLogger(log);
>> TcpCommunicationSpi commSpi = new TcpCommunicationSpi();
>> commSpi.setMessageQueueLimit(10000);
>> cfg.setCommunicationSpi(commSpi);
>> cfg.setDiscoverySpi(spi);
>> cfg.setBinaryConfiguration(new BinaryConfiguration());
>> cfg.getBinaryConfiguration().setCompactFooter(false);
>> cfg.setFailureDetectionTimeout(60 * 1000);
>>
>> The log:
>>
>> INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
>> >>> __________ ________________
>> >>> / _/ ___/ |/ / _/_ __/ __/
>> >>> _/ // (7 7 // / / / / _/
>> >>> /___/\___/_/|_/___/ /_/ /___/
>> >>>
>> >>> ver. 2.7.5#20190603-sha1:be4f2a15
>> >>> 2018 Copyright(C) Apache Software Foundation
>> >>>
>> >>> Ignite documentation: http://ignite.apache.org
>> INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
>> Config URL: n/a
>> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
>> IgniteConfiguration [igniteInstanceName=null, pubPoolSize=36,
>> svcPoolSize=36, callbackPoolSize=36, stripedPoolSize=36, sysPoolSize=36,
>> mgmtPoolSize=4, igfsPoolSize=36, dataStreamerPoolSize=36,
>> utilityCachePoolSize=36, utilityCacheKeepAliveTime=60000, p2pPoolSize=2,
>> qryPoolSize=36, igniteHome=/opt/ignite/apache-ignite-2.7.5-bin,
>> igniteWorkDir=/opt/ignite/apache-ignite-2.7.5-bin/work,
>> mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@47c81abf,
>> nodeId=09156c05-f869-4826-814e-1f47fcefeeb4, marsh=BinaryMarshaller [],
>> 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=org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$FirstConnectionPolicy@104d9de4,
>> enableForcibleNodeKill=false, enableTroubleshootingLog=false, 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=10000, slowClientQueueLimit=0,
>> nioSrvr=null, shmemSrv=null, usePairedConnections=false,
>> connectionsPerNode=1, tcpNoDelay=true, filterReachableAddresses=false,
>> ackSndThreshold=32, unackedMsgsBufSize=0, sockWriteTimeout=2000,
>> boundTcpPort=-1, boundTcpShmemPort=-1, selectorsCnt=18, selectorSpins=0,
>> addrRslvr=null, ctxInitLatch=java.util.concurrent.CountDownLatch@2b43b6cc[Count
>> = 1], stopping=false],
>> evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@3221402f,
>> colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [],
>> indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@415fad70,
>> addrRslvr=null,
>> encryptionSpi=org.apache.ignite.spi.encryption.noop.NoopEncryptionSpi@7947ad4c,
>> clientMode=false, rebalanceThreadPoolSize=1, txCfg=TransactionConfiguration
>> [txSerEnabled=false, dfltIsolation=REPEATABLE_READ,
>> dfltConcurrency=PESSIMISTIC, dfltTxTimeout=0,
>> txTimeoutOnPartitionMapExchange=0, pessimisticTxLogSize=0,
>> pessimisticTxLogLinger=10000, tmLookupClsName=null, txManagerFactory=null,
>> useJtaSync=false], cacheSanityCheckEnabled=true, discoStartupDelay=60000,
>> deployMode=SHARED, p2pMissedCacheSize=100, locHost=null,
>> timeSrvPortBase=31100, timeSrvPortRange=100, failureDetectionTimeout=60000,
>> sysWorkerBlockedTimeout=null, clientFailureDetectionTimeout=30000,
>> metricsLogFreq=60000, hadoopCfg=null, connectorCfg=ConnectorConfiguration
>> [jettyPath=null, host=null, port=11211, noDelay=true, directBuf=false,
>> sndBufSize=32768, rcvBufSize=32768, idleQryCurTimeout=600000,
>> idleQryCurCheckFreq=60000, sndQueueLimit=0, selectorCnt=4,
>> idleTimeout=7000, sslEnabled=false, sslClientAuth=false,
>> sslCtxFactory=null, sslFactory=null, portRange=100, threadPoolSize=36,
>> msgInterceptor=null], odbcCfg=null, warmupClos=null,
>> atomicCfg=AtomicConfiguration [seqReserveSize=1000, cacheMode=PARTITIONED,
>> backups=1, aff=null, grpName=null], classLdr=null, sslCtxFactory=null,
>> platformCfg=null, binaryCfg=BinaryConfiguration [idMapper=null,
>> nameMapper=null, serializer=null, compactFooter=false], memCfg=null,
>> pstCfg=null, dsCfg=DataStorageConfiguration [sysRegionInitSize=41943040,
>> sysRegionMaxSize=104857600, pageSize=0, concLvl=0,
>> dfltDataRegConf=DataRegionConfiguration [name=default, maxSize=14753283276,
>> initSize=268435456, swapPath=null, pageEvictionMode=DISABLED,
>> evictionThreshold=0.9, emptyPagesPoolSize=100, metricsEnabled=false,
>> metricsSubIntervalCount=5, metricsRateTimeInterval=60000,
>> persistenceEnabled=false, checkpointPageBufSize=0], dataRegions=null,
>> storagePath=null, checkpointFreq=180000, lockWaitTime=10000,
>> checkpointThreads=4, checkpointWriteOrder=SEQUENTIAL, walHistSize=20,
>> maxWalArchiveSize=1073741824, walSegments=10, walSegmentSize=67108864,
>> walPath=db/wal, walArchivePath=db/wal/archive, metricsEnabled=false,
>> walMode=LOG_ONLY, walTlbSize=131072, walBuffSize=0, walFlushFreq=2000,
>> walFsyncDelay=1000, walRecordIterBuffSize=67108864,
>> alwaysWriteFullPages=false,
>> fileIOFactory=org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIOFactory@349479c0,
>> metricsSubIntervalCnt=5, metricsRateTimeInterval=60000,
>> walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false,
>> walCompactionEnabled=false, walCompactionLevel=1,
>> checkpointReadLockTimeout=null], activeOnStart=true, autoActivation=true,
>> longQryWarnTimeout=3000, sqlConnCfg=null,
>> cliConnCfg=ClientConnectorConfiguration [host=null, port=10800,
>> portRange=100, sockSndBufSize=0, sockRcvBufSize=0, tcpNoDelay=true,
>> maxOpenCursorsPerConn=128, threadPoolSize=36, idleTimeout=0,
>> jdbcEnabled=true, odbcEnabled=true, thinCliEnabled=true, sslEnabled=false,
>> useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null],
>> mvccVacuumThreadCnt=2, mvccVacuumFreq=5000, authEnabled=false,
>> failureHnd=null, commFailureRslvr=null]
>> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
>> Daemon mode: off
>> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
>> OS: Linux 4.4.0-1020-aws amd64
>> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
>> OS user: root
>> INFO [2019-09-24 10:04:21,415] org.apache.ignite.internal.IgniteKernal:
>> PID: 1
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> Language runtime: Java Platform API Specification ver. 11
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> VM information: OpenJDK Runtime Environment 11.0.3+1-Debian-1bpo91 Oracle
>> Corporation OpenJDK 64-Bit Server VM 11.0.3+1-Debian-1bpo91
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> VM total memory: 17.0GB
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> Remote Management [restart: off, REST: on, JMX (remote: off)]
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> Logger: Slf4jLogger [impl=Logger[org.apache.ignite.internal.IgniteKernal],
>> quiet=false]
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> IGNITE_HOME=/opt/ignite/apache-ignite-2.7.5-bin
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> VM arguments: [-XX:+AlwaysPreTouch, -XX:+UseG1GC, -XX:+DisableExplicitGC,
>> -XX:+ScavengeBeforeFullGC,
>> --add-exports=java.base/jdk.internal.misc=ALL-UNNAMED,
>> --add-exports=java.base/sun.nio.ch=ALL-UNNAMED,
>> --add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED,
>> --add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED,
>> --add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED,
>> --illegal-access=permit, -Djdk.tls.client.protocols=TLSv1.2,
>> -Djava.net.preferIPv4Stack=true, -DIGNITE_QUIET=false]
>> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
>> System cache's DataRegion size is configured to 40 MB. Use
>> DataStorageConfiguration.systemRegionInitialSize property to change the
>> setting.
>> INFO [2019-09-24 10:04:21,420] org.apache.ignite.internal.IgniteKernal:
>> Configured caches [in 'sysMemPlc' dataRegion: ['ignite-sys-cache']]
>> INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal:
>> 3-rd party licenses can be found at:
>> /opt/ignite/apache-ignite-2.7.5-bin/libs/licenses
>> INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal:
>> Local node user attribute [algotworker=true]
>> INFO [2019-09-24 10:04:21,460]
>> org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
>> Configured plugins:
>> INFO [2019-09-24 10:04:21,460]
>> org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor: ^-- None
>> INFO [2019-09-24 10:04:21,460]
>> org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
>> INFO [2019-09-24 10:04:21,460]
>> org.apache.ignite.internal.processors.failure.FailureProcessor: Configured
>> failure handler: [hnd=StopNodeOrHaltFailureHandler [tryStop=false,
>> timeout=0, super=AbstractFailureHandler
>> [ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED,
>> SYSTEM_CRITICAL_OPERATION_TIMEOUT]]]]
>> INFO [2019-09-24 10:04:21,495]
>> org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi: Successfully
>> bound communication NIO server to TCP port [port=47100, locHost=
>> 0.0.0.0/0.0.0.0, selectorsCnt=18, selectorSpins=0, pairedConn=false]
>> WARN [2019-09-24 10:04:21,519]
>> org.apache.ignite.spi.checkpoint.noop.NoopCheckpointSpi: Checkpoints are
>> disabled (to enable configure any GridCheckpointSpi implementation)
>> WARN [2019-09-24 10:04:21,533]
>> org.apache.ignite.internal.managers.collision.GridCollisionManager:
>> Collision resolution is disabled (all jobs will be activated upon arrival).
>> INFO [2019-09-24 10:04:21,536] org.apache.ignite.internal.IgniteKernal:
>> Security status [authentication=off, tls/ssl=off]
>> WARN [2019-09-24 10:04:21,656]
>> org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager:
>> DataRegionConfiguration.maxWalArchiveSize instead
>> DataRegionConfiguration.walHistorySize would be used for removing old
>> archive wal files
>> INFO [2019-09-24 10:04:21,666]
>> org.apache.ignite.internal.processors.cache.distributed.dht.topology.PartitionsEvictManager:
>> Evict partition permits=9
>> INFO [2019-09-24 10:04:21,785]
>> org.apache.ignite.internal.processors.odbc.ClientListenerProcessor: Client
>> connector processor has started on TCP port 10800
>> INFO [2019-09-24 10:04:21,811]
>> org.apache.ignite.internal.processors.rest.protocols.tcp.GridTcpRestProtocol:
>> Command protocol successfully started [name=TCP binary, host=
>> 0.0.0.0/0.0.0.0, port=11211]
>> INFO [2019-09-24 10:04:21,817] org.eclipse.jetty.server.Server:
>> jetty-9.0.z-SNAPSHOT
>> INFO [2019-09-24 10:04:21,819] org.eclipse.jetty.server.ServerConnector:
>> Started ServerConnector@47eb8e95{HTTP/1.1}{0.0.0.0:8080}
>> INFO [2019-09-24 10:04:21,819]
>> org.apache.ignite.internal.processors.rest.protocols.http.jetty.GridJettyRestProtocol:
>> Command protocol successfully started [name=Jetty REST, host=/0.0.0.0,
>> port=8080]
>> INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal:
>> Non-loopback local IPs: 10.0.31.159, 169.254.1.1, 172.17.0.1, 172.18.0.1
>> INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal:
>> Enabled local MACs: 024254D57DDE, 0242BC90FC25, 0632865AE178, 8AB58EDB020C
>> INFO [2019-09-24 10:04:21,863]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Connection check
>> threshold is calculated: 60000
>> INFO [2019-09-24 10:04:21,867]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Successfully bound to
>> TCP port [port=47500, localHost=0.0.0.0/0.0.0.0,
>> locNodeId=09156c05-f869-4826-814e-1f47fcefeeb4]
>> WARN [2019-09-24 10:04:21,869]
>> org.apache.ignite.spi.discovery.tcp.ipfinder.s3.TcpDiscoveryS3IpFinder:
>> Amazon client configuration is not set (will use default).
>> INFO [2019-09-24 10:04:22,520]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
>> incoming connection [rmtAddr=/10.0.11.210, rmtPort=57994]
>> INFO [2019-09-24 10:04:22,524]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
>> a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57994]
>> INFO [2019-09-24 10:04:22,524]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote
>> node connection [rmtAddr=/10.0.11.210:57994, rmtPort=57994]
>> WARN [2019-09-24 10:04:22,525]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic
>> header (too few bytes received) [rmtAddr=/10.0.11.210:57994, locAddr=/
>> 10.0.31.159:47500]
>> INFO [2019-09-24 10:04:22,525]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving
>> remote node connection [rmtAddr=/10.0.11.210:57994, rmtPort=57994
>> INFO [2019-09-24 10:04:22,722]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
>> incoming connection [rmtAddr=/10.0.11.210, rmtPort=57996]
>> INFO [2019-09-24 10:04:22,722]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
>> a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57996]
>> INFO [2019-09-24 10:04:22,722]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote
>> node connection [rmtAddr=/10.0.11.210:57996, rmtPort=57996]
>> WARN [2019-09-24 10:04:22,722]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic
>> header (too few bytes received) [rmtAddr=/10.0.11.210:57996, locAddr=/
>> 10.0.31.159:47500]
>> INFO [2019-09-24 10:04:22,722]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving
>> remote node connection [rmtAddr=/10.0.11.210:57996, rmtPort=57996
>> INFO [2019-09-24 10:04:22,923]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
>> incoming connection [rmtAddr=/10.0.11.210, rmtPort=57998]
>> INFO [2019-09-24 10:04:22,924]
>> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
>> a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57998]
>>
>>
>>
>>
Re: Failed to read magic header (too few bytes received)
Posted by Marco Bernagozzi <ma...@gmail.com>.
It was on aws, and I don't have the IP log of all the instances I had up.
My best guess it's that it was just one of the slave instances.
I have two sets of machines, masters and slaves. They are all servers. The
masters create caches and distribute caches to a set of slaves using a node
filter.
Here are the options I'm using to run it
CMD ["java", "-jar", "-XX:+AlwaysPreTouch", "-XX:+UseG1GC",
"-XX:+DisableExplicitGC", "-XX:+ScavengeBeforeFullGC",
"--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED",
"--add-exports=java.base/sun.nio.ch=ALL-UNNAMED",
"--add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED",
"--add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED",
"--add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED","--illegal-access=permit",
"-Djdk.tls.client.protocols=TLSv1.2", "-Djava.net.preferIPv4Stack=true",
"-DIGNITE_QUIET=false", "algotworker.jar", "server", "config.yml"]
In my logs, "10.0.11.210" appears first in the slave nodes:
[main] INFO org.apache.ignite.internal.IgniteKernal - Non-loopback local
IPs: 10.0.11.210, 169.254.1.1, 172.17.0.1, 172.18.0.1
[tcp-disco-msg-worker-#2] INFO
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node
[newNext=TcpDiscoveryNode [id=bc657c40-27dd-4190-af04-e53068176937,
addrs=[10.0.11.210, 127.0.0.1, 172.17.0.1, 172.18.0.1],
sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/172.18.0.1:47500],
discPort=47500, order=8, intOrder=7, lastExchangeTime=1569318655381,
loc=false, ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
[tcp-disco-msg-worker-#2] WARN
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node has
connection to it's previous, trying previous again. [next=TcpDiscoveryNode
[id=bc657c40-27dd-4190-af04-e53068176937, addrs=[10.0.11.210, 127.0.0.1,
172.17.0.1, 172.18.0.1],
sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/172.18.0.1:47500],
discPort=47500, order=8, intOrder=7, lastExchangeTime=1569318655381,
loc=false, ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
[tcp-disco-msg-worker-#2] INFO
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node
[newNext=TcpDiscoveryNode [id=bc657c40-27dd-4190-af04-e53068176937,
addrs=[10.0.11.210, 127.0.0.1, 172.17.0.1, 172.18.0.1],
sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/172.18.0.1:47500],
discPort=47500, order=8, intOrder=7, lastExchangeTime=1569318655381,
loc=false, ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
[tcp-disco-msg-worker-#2] WARN
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - New next node has
connection to it's previous, trying previous again. [next=TcpDiscoveryNode
[id=bc657c40-27dd-4190-af04-e53068176937, addrs=[10.0.11.210, 127.0.0.1,
172.17.0.1, 172.18.0.1],
sockAddrs=[ip-172-17-0-1.eu-west-1.compute.internal/172.17.0.1:47500, /
127.0.0.1:47500, production-algo-spot-instance-ASG/10.0.31.153:47500, /
10.0.11.210:47500, ip-172-18-0-1.eu-west-1.compute.internal/172.18.0.1:47500],
discPort=47500, order=8, intOrder=7, lastExchangeTime=1569318655381,
loc=false, ver=2.7.5#20190603-sha1:be4f2a15, isClient=false]]
I didn't see this before. What does this mean? I guess this is the issue,
right?
On Tue, 24 Sep 2019 at 15:16, Stephen Darlington <
stephen.darlington@gridgain.com> wrote:
> What’s on IP address 10.0.11.210? It’s sending Ignite something that it
> doesn’t understand. Maybe it’s not another copy of Ignite? Could it be a
> firewall setting truncating the message? Or perhaps the remote node has a
> different configuration, for example mixing up communication and discovery
> ports?
>
> Regards,
> Stephen
>
> On 24 Sep 2019, at 13:00, Marco Bernagozzi <ma...@gmail.com>
> wrote:
>
> Hi.
> I get this error sometimes, it seems to be quite random. Any idea what
> this might be caused by?
> Since every time it's thrown a hundred times or so, I had to temporarily
> suppress all the errors from that class. Is there a way to fix this or at
> least to make it be thrown just once?
>
> My settings:
>
> AwsConfiguration awsConfiguration =
> AwsConfigurationSingleton.getInstance();
> BasicAWSCredentials creds = new BasicAWSCredentials(
> awsConfiguration.getAwsAccessKey(),
> awsConfiguration.getAwsSecretKey()
> );
> TcpDiscoveryS3IpFinder ipFinder = new TcpDiscoveryS3IpFinder();
> ipFinder.setAwsCredentials(creds);
> ipFinder.setBucketEndpoint("s3.eu-west-1.amazonaws.com");
> ipFinder.setBucketName(awsConfiguration.getIgniteBucket());
>
> TcpDiscoverySpi spi = new TcpDiscoverySpi();
> spi.setIpFinder(ipFinder);
> IgniteConfiguration cfg = new IgniteConfiguration();
> DataStorageConfiguration storageCfg = new DataStorageConfiguration();
>
> storageCfg.getDefaultDataRegionConfiguration().setPersistenceEnabled(false);
> cfg.setDataStorageConfiguration(storageCfg);
> IgniteLogger log = new Slf4jLogger();
> cfg.setGridLogger(log);
> TcpCommunicationSpi commSpi = new TcpCommunicationSpi();
> commSpi.setMessageQueueLimit(10000);
> cfg.setCommunicationSpi(commSpi);
> cfg.setDiscoverySpi(spi);
> cfg.setBinaryConfiguration(new BinaryConfiguration());
> cfg.getBinaryConfiguration().setCompactFooter(false);
> cfg.setFailureDetectionTimeout(60 * 1000);
>
> The log:
>
> INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
> >>> __________ ________________
> >>> / _/ ___/ |/ / _/_ __/ __/
> >>> _/ // (7 7 // / / / / _/
> >>> /___/\___/_/|_/___/ /_/ /___/
> >>>
> >>> ver. 2.7.5#20190603-sha1:be4f2a15
> >>> 2018 Copyright(C) Apache Software Foundation
> >>>
> >>> Ignite documentation: http://ignite.apache.org
> INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
> Config URL: n/a
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
> IgniteConfiguration [igniteInstanceName=null, pubPoolSize=36,
> svcPoolSize=36, callbackPoolSize=36, stripedPoolSize=36, sysPoolSize=36,
> mgmtPoolSize=4, igfsPoolSize=36, dataStreamerPoolSize=36,
> utilityCachePoolSize=36, utilityCacheKeepAliveTime=60000, p2pPoolSize=2,
> qryPoolSize=36, igniteHome=/opt/ignite/apache-ignite-2.7.5-bin,
> igniteWorkDir=/opt/ignite/apache-ignite-2.7.5-bin/work,
> mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@47c81abf,
> nodeId=09156c05-f869-4826-814e-1f47fcefeeb4, marsh=BinaryMarshaller [],
> 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=org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$FirstConnectionPolicy@104d9de4,
> enableForcibleNodeKill=false, enableTroubleshootingLog=false, 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=10000, slowClientQueueLimit=0,
> nioSrvr=null, shmemSrv=null, usePairedConnections=false,
> connectionsPerNode=1, tcpNoDelay=true, filterReachableAddresses=false,
> ackSndThreshold=32, unackedMsgsBufSize=0, sockWriteTimeout=2000,
> boundTcpPort=-1, boundTcpShmemPort=-1, selectorsCnt=18, selectorSpins=0,
> addrRslvr=null, ctxInitLatch=java.util.concurrent.CountDownLatch@2b43b6cc[Count
> = 1], stopping=false],
> evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@3221402f,
> colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [],
> indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@415fad70,
> addrRslvr=null,
> encryptionSpi=org.apache.ignite.spi.encryption.noop.NoopEncryptionSpi@7947ad4c,
> clientMode=false, rebalanceThreadPoolSize=1, txCfg=TransactionConfiguration
> [txSerEnabled=false, dfltIsolation=REPEATABLE_READ,
> dfltConcurrency=PESSIMISTIC, dfltTxTimeout=0,
> txTimeoutOnPartitionMapExchange=0, pessimisticTxLogSize=0,
> pessimisticTxLogLinger=10000, tmLookupClsName=null, txManagerFactory=null,
> useJtaSync=false], cacheSanityCheckEnabled=true, discoStartupDelay=60000,
> deployMode=SHARED, p2pMissedCacheSize=100, locHost=null,
> timeSrvPortBase=31100, timeSrvPortRange=100, failureDetectionTimeout=60000,
> sysWorkerBlockedTimeout=null, clientFailureDetectionTimeout=30000,
> metricsLogFreq=60000, hadoopCfg=null, connectorCfg=ConnectorConfiguration
> [jettyPath=null, host=null, port=11211, noDelay=true, directBuf=false,
> sndBufSize=32768, rcvBufSize=32768, idleQryCurTimeout=600000,
> idleQryCurCheckFreq=60000, sndQueueLimit=0, selectorCnt=4,
> idleTimeout=7000, sslEnabled=false, sslClientAuth=false,
> sslCtxFactory=null, sslFactory=null, portRange=100, threadPoolSize=36,
> msgInterceptor=null], odbcCfg=null, warmupClos=null,
> atomicCfg=AtomicConfiguration [seqReserveSize=1000, cacheMode=PARTITIONED,
> backups=1, aff=null, grpName=null], classLdr=null, sslCtxFactory=null,
> platformCfg=null, binaryCfg=BinaryConfiguration [idMapper=null,
> nameMapper=null, serializer=null, compactFooter=false], memCfg=null,
> pstCfg=null, dsCfg=DataStorageConfiguration [sysRegionInitSize=41943040,
> sysRegionMaxSize=104857600, pageSize=0, concLvl=0,
> dfltDataRegConf=DataRegionConfiguration [name=default, maxSize=14753283276,
> initSize=268435456, swapPath=null, pageEvictionMode=DISABLED,
> evictionThreshold=0.9, emptyPagesPoolSize=100, metricsEnabled=false,
> metricsSubIntervalCount=5, metricsRateTimeInterval=60000,
> persistenceEnabled=false, checkpointPageBufSize=0], dataRegions=null,
> storagePath=null, checkpointFreq=180000, lockWaitTime=10000,
> checkpointThreads=4, checkpointWriteOrder=SEQUENTIAL, walHistSize=20,
> maxWalArchiveSize=1073741824, walSegments=10, walSegmentSize=67108864,
> walPath=db/wal, walArchivePath=db/wal/archive, metricsEnabled=false,
> walMode=LOG_ONLY, walTlbSize=131072, walBuffSize=0, walFlushFreq=2000,
> walFsyncDelay=1000, walRecordIterBuffSize=67108864,
> alwaysWriteFullPages=false,
> fileIOFactory=org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIOFactory@349479c0,
> metricsSubIntervalCnt=5, metricsRateTimeInterval=60000,
> walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false,
> walCompactionEnabled=false, walCompactionLevel=1,
> checkpointReadLockTimeout=null], activeOnStart=true, autoActivation=true,
> longQryWarnTimeout=3000, sqlConnCfg=null,
> cliConnCfg=ClientConnectorConfiguration [host=null, port=10800,
> portRange=100, sockSndBufSize=0, sockRcvBufSize=0, tcpNoDelay=true,
> maxOpenCursorsPerConn=128, threadPoolSize=36, idleTimeout=0,
> jdbcEnabled=true, odbcEnabled=true, thinCliEnabled=true, sslEnabled=false,
> useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null],
> mvccVacuumThreadCnt=2, mvccVacuumFreq=5000, authEnabled=false,
> failureHnd=null, commFailureRslvr=null]
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
> Daemon mode: off
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal:
> OS: Linux 4.4.0-1020-aws amd64
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: OS
> user: root
> INFO [2019-09-24 10:04:21,415] org.apache.ignite.internal.IgniteKernal:
> PID: 1
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
> Language runtime: Java Platform API Specification ver. 11
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM
> information: OpenJDK Runtime Environment 11.0.3+1-Debian-1bpo91 Oracle
> Corporation OpenJDK 64-Bit Server VM 11.0.3+1-Debian-1bpo91
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM
> total memory: 17.0GB
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
> Remote Management [restart: off, REST: on, JMX (remote: off)]
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
> Logger: Slf4jLogger [impl=Logger[org.apache.ignite.internal.IgniteKernal],
> quiet=false]
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
> IGNITE_HOME=/opt/ignite/apache-ignite-2.7.5-bin
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM
> arguments: [-XX:+AlwaysPreTouch, -XX:+UseG1GC, -XX:+DisableExplicitGC,
> -XX:+ScavengeBeforeFullGC,
> --add-exports=java.base/jdk.internal.misc=ALL-UNNAMED,
> --add-exports=java.base/sun.nio.ch=ALL-UNNAMED,
> --add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED,
> --add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED,
> --add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED,
> --illegal-access=permit, -Djdk.tls.client.protocols=TLSv1.2,
> -Djava.net.preferIPv4Stack=true, -DIGNITE_QUIET=false]
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal:
> System cache's DataRegion size is configured to 40 MB. Use
> DataStorageConfiguration.systemRegionInitialSize property to change the
> setting.
> INFO [2019-09-24 10:04:21,420] org.apache.ignite.internal.IgniteKernal:
> Configured caches [in 'sysMemPlc' dataRegion: ['ignite-sys-cache']]
> INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal:
> 3-rd party licenses can be found at:
> /opt/ignite/apache-ignite-2.7.5-bin/libs/licenses
> INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal:
> Local node user attribute [algotworker=true]
> INFO [2019-09-24 10:04:21,460]
> org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
> Configured plugins:
> INFO [2019-09-24 10:04:21,460]
> org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor: ^-- None
> INFO [2019-09-24 10:04:21,460]
> org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
> INFO [2019-09-24 10:04:21,460]
> org.apache.ignite.internal.processors.failure.FailureProcessor: Configured
> failure handler: [hnd=StopNodeOrHaltFailureHandler [tryStop=false,
> timeout=0, super=AbstractFailureHandler
> [ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED,
> SYSTEM_CRITICAL_OPERATION_TIMEOUT]]]]
> INFO [2019-09-24 10:04:21,495]
> org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi: Successfully
> bound communication NIO server to TCP port [port=47100, locHost=
> 0.0.0.0/0.0.0.0, selectorsCnt=18, selectorSpins=0, pairedConn=false]
> WARN [2019-09-24 10:04:21,519]
> org.apache.ignite.spi.checkpoint.noop.NoopCheckpointSpi: Checkpoints are
> disabled (to enable configure any GridCheckpointSpi implementation)
> WARN [2019-09-24 10:04:21,533]
> org.apache.ignite.internal.managers.collision.GridCollisionManager:
> Collision resolution is disabled (all jobs will be activated upon arrival).
> INFO [2019-09-24 10:04:21,536] org.apache.ignite.internal.IgniteKernal:
> Security status [authentication=off, tls/ssl=off]
> WARN [2019-09-24 10:04:21,656]
> org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager:
> DataRegionConfiguration.maxWalArchiveSize instead
> DataRegionConfiguration.walHistorySize would be used for removing old
> archive wal files
> INFO [2019-09-24 10:04:21,666]
> org.apache.ignite.internal.processors.cache.distributed.dht.topology.PartitionsEvictManager:
> Evict partition permits=9
> INFO [2019-09-24 10:04:21,785]
> org.apache.ignite.internal.processors.odbc.ClientListenerProcessor: Client
> connector processor has started on TCP port 10800
> INFO [2019-09-24 10:04:21,811]
> org.apache.ignite.internal.processors.rest.protocols.tcp.GridTcpRestProtocol:
> Command protocol successfully started [name=TCP binary, host=
> 0.0.0.0/0.0.0.0, port=11211]
> INFO [2019-09-24 10:04:21,817] org.eclipse.jetty.server.Server:
> jetty-9.0.z-SNAPSHOT
> INFO [2019-09-24 10:04:21,819] org.eclipse.jetty.server.ServerConnector:
> Started ServerConnector@47eb8e95{HTTP/1.1}{0.0.0.0:8080}
> INFO [2019-09-24 10:04:21,819]
> org.apache.ignite.internal.processors.rest.protocols.http.jetty.GridJettyRestProtocol:
> Command protocol successfully started [name=Jetty REST, host=/0.0.0.0,
> port=8080]
> INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal:
> Non-loopback local IPs: 10.0.31.159, 169.254.1.1, 172.17.0.1, 172.18.0.1
> INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal:
> Enabled local MACs: 024254D57DDE, 0242BC90FC25, 0632865AE178, 8AB58EDB020C
> INFO [2019-09-24 10:04:21,863]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Connection check
> threshold is calculated: 60000
> INFO [2019-09-24 10:04:21,867]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Successfully bound to
> TCP port [port=47500, localHost=0.0.0.0/0.0.0.0,
> locNodeId=09156c05-f869-4826-814e-1f47fcefeeb4]
> WARN [2019-09-24 10:04:21,869]
> org.apache.ignite.spi.discovery.tcp.ipfinder.s3.TcpDiscoveryS3IpFinder:
> Amazon client configuration is not set (will use default).
> INFO [2019-09-24 10:04:22,520]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
> incoming connection [rmtAddr=/10.0.11.210, rmtPort=57994]
> INFO [2019-09-24 10:04:22,524]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
> a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57994]
> INFO [2019-09-24 10:04:22,524]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote
> node connection [rmtAddr=/10.0.11.210:57994, rmtPort=57994]
> WARN [2019-09-24 10:04:22,525]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic
> header (too few bytes received) [rmtAddr=/10.0.11.210:57994, locAddr=/
> 10.0.31.159:47500]
> INFO [2019-09-24 10:04:22,525]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving
> remote node connection [rmtAddr=/10.0.11.210:57994, rmtPort=57994
> INFO [2019-09-24 10:04:22,722]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
> incoming connection [rmtAddr=/10.0.11.210, rmtPort=57996]
> INFO [2019-09-24 10:04:22,722]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
> a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57996]
> INFO [2019-09-24 10:04:22,722]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote
> node connection [rmtAddr=/10.0.11.210:57996, rmtPort=57996]
> WARN [2019-09-24 10:04:22,722]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic
> header (too few bytes received) [rmtAddr=/10.0.11.210:57996, locAddr=/
> 10.0.31.159:47500]
> INFO [2019-09-24 10:04:22,722]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving
> remote node connection [rmtAddr=/10.0.11.210:57996, rmtPort=57996
> INFO [2019-09-24 10:04:22,923]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted
> incoming connection [rmtAddr=/10.0.11.210, rmtPort=57998]
> INFO [2019-09-24 10:04:22,924]
> org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning
> a new thread for connection [rmtAddr=/10.0.11.210, rmtPort=57998]
>
>
>
>
Re: Failed to read magic header (too few bytes received)
Posted by Stephen Darlington <st...@gridgain.com>.
What’s on IP address 10.0.11.210? It’s sending Ignite something that it doesn’t understand. Maybe it’s not another copy of Ignite? Could it be a firewall setting truncating the message? Or perhaps the remote node has a different configuration, for example mixing up communication and discovery ports?
Regards,
Stephen
> On 24 Sep 2019, at 13:00, Marco Bernagozzi <ma...@gmail.com> wrote:
>
> Hi.
> I get this error sometimes, it seems to be quite random. Any idea what this might be caused by?
> Since every time it's thrown a hundred times or so, I had to temporarily suppress all the errors from that class. Is there a way to fix this or at least to make it be thrown just once?
>
> My settings:
>
> AwsConfiguration awsConfiguration = AwsConfigurationSingleton.getInstance();
> BasicAWSCredentials creds = new BasicAWSCredentials(
> awsConfiguration.getAwsAccessKey(),
> awsConfiguration.getAwsSecretKey()
> );
> TcpDiscoveryS3IpFinder ipFinder = new TcpDiscoveryS3IpFinder();
> ipFinder.setAwsCredentials(creds);
> ipFinder.setBucketEndpoint("s3.eu-west-1.amazonaws.com <http://s3.eu-west-1.amazonaws.com/>");
> ipFinder.setBucketName(awsConfiguration.getIgniteBucket());
>
> TcpDiscoverySpi spi = new TcpDiscoverySpi();
> spi.setIpFinder(ipFinder);
> IgniteConfiguration cfg = new IgniteConfiguration();
> DataStorageConfiguration storageCfg = new DataStorageConfiguration();
> storageCfg.getDefaultDataRegionConfiguration().setPersistenceEnabled(false);
> cfg.setDataStorageConfiguration(storageCfg);
> IgniteLogger log = new Slf4jLogger();
> cfg.setGridLogger(log);
> TcpCommunicationSpi commSpi = new TcpCommunicationSpi();
> commSpi.setMessageQueueLimit(10000);
> cfg.setCommunicationSpi(commSpi);
> cfg.setDiscoverySpi(spi);
> cfg.setBinaryConfiguration(new BinaryConfiguration());
> cfg.getBinaryConfiguration().setCompactFooter(false);
> cfg.setFailureDetectionTimeout(60 * 1000);
>
> The log:
>
> INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal:
> >>> __________ ________________
> >>> / _/ ___/ |/ / _/_ __/ __/
> >>> _/ // (7 7 // / / / / _/
> >>> /___/\___/_/|_/___/ /_/ /___/
> >>>
> >>> ver. 2.7.5#20190603-sha1:be4f2a15
> >>> 2018 Copyright(C) Apache Software Foundation
> >>>
> >>> Ignite documentation: http://ignite.apache.org <http://ignite.apache.org/>
> INFO [2019-09-24 10:04:21,402] org.apache.ignite.internal.IgniteKernal: Config URL: n/a
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: IgniteConfiguration [igniteInstanceName=null, pubPoolSize=36, svcPoolSize=36, callbackPoolSize=36, stripedPoolSize=36, sysPoolSize=36, mgmtPoolSize=4, igfsPoolSize=36, dataStreamerPoolSize=36, utilityCachePoolSize=36, utilityCacheKeepAliveTime=60000, p2pPoolSize=2, qryPoolSize=36, igniteHome=/opt/ignite/apache-ignite-2.7.5-bin, igniteWorkDir=/opt/ignite/apache-ignite-2.7.5-bin/work, mbeanSrv=com.sun.jmx.mbeanserver.JmxMBeanServer@47c81abf, nodeId=09156c05-f869-4826-814e-1f47fcefeeb4, marsh=BinaryMarshaller [], 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=org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$FirstConnectionPolicy@104d9de4, enableForcibleNodeKill=false, enableTroubleshootingLog=false, 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=10000, slowClientQueueLimit=0, nioSrvr=null, shmemSrv=null, usePairedConnections=false, connectionsPerNode=1, tcpNoDelay=true, filterReachableAddresses=false, ackSndThreshold=32, unackedMsgsBufSize=0, sockWriteTimeout=2000, boundTcpPort=-1, boundTcpShmemPort=-1, selectorsCnt=18, selectorSpins=0, addrRslvr=null, ctxInitLatch=java.util.concurrent.CountDownLatch@2b43b6cc[Count = 1], stopping=false], evtSpi=org.apache.ignite.spi.eventstorage.NoopEventStorageSpi@3221402f, colSpi=NoopCollisionSpi [], deploySpi=LocalDeploymentSpi [], indexingSpi=org.apache.ignite.spi.indexing.noop.NoopIndexingSpi@415fad70, addrRslvr=null, encryptionSpi=org.apache.ignite.spi.encryption.noop.NoopEncryptionSpi@7947ad4c, clientMode=false, rebalanceThreadPoolSize=1, txCfg=TransactionConfiguration [txSerEnabled=false, dfltIsolation=REPEATABLE_READ, dfltConcurrency=PESSIMISTIC, dfltTxTimeout=0, txTimeoutOnPartitionMapExchange=0, pessimisticTxLogSize=0, pessimisticTxLogLinger=10000, tmLookupClsName=null, txManagerFactory=null, useJtaSync=false], cacheSanityCheckEnabled=true, discoStartupDelay=60000, deployMode=SHARED, p2pMissedCacheSize=100, locHost=null, timeSrvPortBase=31100, timeSrvPortRange=100, failureDetectionTimeout=60000, sysWorkerBlockedTimeout=null, clientFailureDetectionTimeout=30000, metricsLogFreq=60000, hadoopCfg=null, connectorCfg=ConnectorConfiguration [jettyPath=null, host=null, port=11211, noDelay=true, directBuf=false, sndBufSize=32768, rcvBufSize=32768, idleQryCurTimeout=600000, idleQryCurCheckFreq=60000, sndQueueLimit=0, selectorCnt=4, idleTimeout=7000, sslEnabled=false, sslClientAuth=false, sslCtxFactory=null, sslFactory=null, portRange=100, threadPoolSize=36, msgInterceptor=null], odbcCfg=null, warmupClos=null, atomicCfg=AtomicConfiguration [seqReserveSize=1000, cacheMode=PARTITIONED, backups=1, aff=null, grpName=null], classLdr=null, sslCtxFactory=null, platformCfg=null, binaryCfg=BinaryConfiguration [idMapper=null, nameMapper=null, serializer=null, compactFooter=false], memCfg=null, pstCfg=null, dsCfg=DataStorageConfiguration [sysRegionInitSize=41943040, sysRegionMaxSize=104857600, pageSize=0, concLvl=0, dfltDataRegConf=DataRegionConfiguration [name=default, maxSize=14753283276, initSize=268435456, swapPath=null, pageEvictionMode=DISABLED, evictionThreshold=0.9, emptyPagesPoolSize=100, metricsEnabled=false, metricsSubIntervalCount=5, metricsRateTimeInterval=60000, persistenceEnabled=false, checkpointPageBufSize=0], dataRegions=null, storagePath=null, checkpointFreq=180000, lockWaitTime=10000, checkpointThreads=4, checkpointWriteOrder=SEQUENTIAL, walHistSize=20, maxWalArchiveSize=1073741824, walSegments=10, walSegmentSize=67108864, walPath=db/wal, walArchivePath=db/wal/archive, metricsEnabled=false, walMode=LOG_ONLY, walTlbSize=131072, walBuffSize=0, walFlushFreq=2000, walFsyncDelay=1000, walRecordIterBuffSize=67108864, alwaysWriteFullPages=false, fileIOFactory=org.apache.ignite.internal.processors.cache.persistence.file.AsyncFileIOFactory@349479c0, metricsSubIntervalCnt=5, metricsRateTimeInterval=60000, walAutoArchiveAfterInactivity=-1, writeThrottlingEnabled=false, walCompactionEnabled=false, walCompactionLevel=1, checkpointReadLockTimeout=null], activeOnStart=true, autoActivation=true, longQryWarnTimeout=3000, sqlConnCfg=null, cliConnCfg=ClientConnectorConfiguration [host=null, port=10800, portRange=100, sockSndBufSize=0, sockRcvBufSize=0, tcpNoDelay=true, maxOpenCursorsPerConn=128, threadPoolSize=36, idleTimeout=0, jdbcEnabled=true, odbcEnabled=true, thinCliEnabled=true, sslEnabled=false, useIgniteSslCtxFactory=true, sslClientAuth=false, sslCtxFactory=null], mvccVacuumThreadCnt=2, mvccVacuumFreq=5000, authEnabled=false, failureHnd=null, commFailureRslvr=null]
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: Daemon mode: off
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: OS: Linux 4.4.0-1020-aws amd64
> INFO [2019-09-24 10:04:21,413] org.apache.ignite.internal.IgniteKernal: OS user: root
> INFO [2019-09-24 10:04:21,415] org.apache.ignite.internal.IgniteKernal: PID: 1
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: Language runtime: Java Platform API Specification ver. 11
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM information: OpenJDK Runtime Environment 11.0.3+1-Debian-1bpo91 Oracle Corporation OpenJDK 64-Bit Server VM 11.0.3+1-Debian-1bpo91
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM total memory: 17.0GB
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: Remote Management [restart: off, REST: on, JMX (remote: off)]
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: Logger: Slf4jLogger [impl=Logger[org.apache.ignite.internal.IgniteKernal], quiet=false]
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: IGNITE_HOME=/opt/ignite/apache-ignite-2.7.5-bin
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: VM arguments: [-XX:+AlwaysPreTouch, -XX:+UseG1GC, -XX:+DisableExplicitGC, -XX:+ScavengeBeforeFullGC, --add-exports=java.base/jdk.internal.misc=ALL-UNNAMED, --add-exports=java.base/sun.nio.ch <http://sun.nio.ch/>=ALL-UNNAMED, --add-exports=java.management/com.sun.jmx.mbeanserver=ALL-UNNAMED, --add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED, --add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED, --illegal-access=permit, -Djdk.tls.client.protocols=TLSv1.2, -Djava.net.preferIPv4Stack=true, -DIGNITE_QUIET=false]
> INFO [2019-09-24 10:04:21,416] org.apache.ignite.internal.IgniteKernal: System cache's DataRegion size is configured to 40 MB. Use DataStorageConfiguration.systemRegionInitialSize property to change the setting.
> INFO [2019-09-24 10:04:21,420] org.apache.ignite.internal.IgniteKernal: Configured caches [in 'sysMemPlc' dataRegion: ['ignite-sys-cache']]
> INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal: 3-rd party licenses can be found at: /opt/ignite/apache-ignite-2.7.5-bin/libs/licenses
> INFO [2019-09-24 10:04:21,422] org.apache.ignite.internal.IgniteKernal: Local node user attribute [algotworker=true]
> INFO [2019-09-24 10:04:21,460] org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor: Configured plugins:
> INFO [2019-09-24 10:04:21,460] org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor: ^-- None
> INFO [2019-09-24 10:04:21,460] org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor:
> INFO [2019-09-24 10:04:21,460] org.apache.ignite.internal.processors.failure.FailureProcessor: Configured failure handler: [hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0, super=AbstractFailureHandler [ignoredFailureTypes=[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]]]
> INFO [2019-09-24 10:04:21,495] org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi: Successfully bound communication NIO server to TCP port [port=47100, locHost=0.0.0.0/0.0.0.0 <http://0.0.0.0/0.0.0.0>, selectorsCnt=18, selectorSpins=0, pairedConn=false]
> WARN [2019-09-24 10:04:21,519] org.apache.ignite.spi.checkpoint.noop.NoopCheckpointSpi: Checkpoints are disabled (to enable configure any GridCheckpointSpi implementation)
> WARN [2019-09-24 10:04:21,533] org.apache.ignite.internal.managers.collision.GridCollisionManager: Collision resolution is disabled (all jobs will be activated upon arrival).
> INFO [2019-09-24 10:04:21,536] org.apache.ignite.internal.IgniteKernal: Security status [authentication=off, tls/ssl=off]
> WARN [2019-09-24 10:04:21,656] org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager: DataRegionConfiguration.maxWalArchiveSize instead DataRegionConfiguration.walHistorySize would be used for removing old archive wal files
> INFO [2019-09-24 10:04:21,666] org.apache.ignite.internal.processors.cache.distributed.dht.topology.PartitionsEvictManager: Evict partition permits=9
> INFO [2019-09-24 10:04:21,785] org.apache.ignite.internal.processors.odbc.ClientListenerProcessor: Client connector processor has started on TCP port 10800
> INFO [2019-09-24 10:04:21,811] org.apache.ignite.internal.processors.rest.protocols.tcp.GridTcpRestProtocol: Command protocol successfully started [name=TCP binary, host=0.0.0.0/0.0.0.0 <http://0.0.0.0/0.0.0.0>, port=11211]
> INFO [2019-09-24 10:04:21,817] org.eclipse.jetty.server.Server: jetty-9.0.z-SNAPSHOT
> INFO [2019-09-24 10:04:21,819] org.eclipse.jetty.server.ServerConnector: Started ServerConnector@47eb8e95{HTTP/1.1}{0.0.0.0:8080 <http://0.0.0.0:8080/>}
> INFO [2019-09-24 10:04:21,819] org.apache.ignite.internal.processors.rest.protocols.http.jetty.GridJettyRestProtocol: Command protocol successfully started [name=Jetty REST, host=/0.0.0.0 <http://0.0.0.0/>, port=8080]
> INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal: Non-loopback local IPs: 10.0.31.159, 169.254.1.1, 172.17.0.1, 172.18.0.1
> INFO [2019-09-24 10:04:21,843] org.apache.ignite.internal.IgniteKernal: Enabled local MACs: 024254D57DDE, 0242BC90FC25, 0632865AE178, 8AB58EDB020C
> INFO [2019-09-24 10:04:21,863] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Connection check threshold is calculated: 60000
> INFO [2019-09-24 10:04:21,867] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Successfully bound to TCP port [port=47500, localHost=0.0.0.0/0.0.0.0 <http://0.0.0.0/0.0.0.0>, locNodeId=09156c05-f869-4826-814e-1f47fcefeeb4]
> WARN [2019-09-24 10:04:21,869] org.apache.ignite.spi.discovery.tcp.ipfinder.s3.TcpDiscoveryS3IpFinder: Amazon client configuration is not set (will use default).
> INFO [2019-09-24 10:04:22,520] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted incoming connection [rmtAddr=/10.0.11.210 <http://10.0.11.210/>, rmtPort=57994]
> INFO [2019-09-24 10:04:22,524] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning a new thread for connection [rmtAddr=/10.0.11.210 <http://10.0.11.210/>, rmtPort=57994]
> INFO [2019-09-24 10:04:22,524] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote node connection [rmtAddr=/10.0.11.210:57994 <http://10.0.11.210:57994/>, rmtPort=57994]
> WARN [2019-09-24 10:04:22,525] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic header (too few bytes received) [rmtAddr=/10.0.11.210:57994 <http://10.0.11.210:57994/>, locAddr=/10.0.31.159:47500 <http://10.0.31.159:47500/>]
> INFO [2019-09-24 10:04:22,525] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving remote node connection [rmtAddr=/10.0.11.210:57994 <http://10.0.11.210:57994/>, rmtPort=57994
> INFO [2019-09-24 10:04:22,722] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted incoming connection [rmtAddr=/10.0.11.210 <http://10.0.11.210/>, rmtPort=57996]
> INFO [2019-09-24 10:04:22,722] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning a new thread for connection [rmtAddr=/10.0.11.210 <http://10.0.11.210/>, rmtPort=57996]
> INFO [2019-09-24 10:04:22,722] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Started serving remote node connection [rmtAddr=/10.0.11.210:57996 <http://10.0.11.210:57996/>, rmtPort=57996]
> WARN [2019-09-24 10:04:22,722] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Failed to read magic header (too few bytes received) [rmtAddr=/10.0.11.210:57996 <http://10.0.11.210:57996/>, locAddr=/10.0.31.159:47500 <http://10.0.31.159:47500/>]
> INFO [2019-09-24 10:04:22,722] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: Finished serving remote node connection [rmtAddr=/10.0.11.210:57996 <http://10.0.11.210:57996/>, rmtPort=57996
> INFO [2019-09-24 10:04:22,923] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery accepted incoming connection [rmtAddr=/10.0.11.210 <http://10.0.11.210/>, rmtPort=57998]
> INFO [2019-09-24 10:04:22,924] org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi: TCP discovery spawning a new thread for connection [rmtAddr=/10.0.11.210 <http://10.0.11.210/>, rmtPort=57998]