You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Chandra Bose Renganathan (JIRA)" <ji...@apache.org> on 2017/05/19 17:24:04 UTC

[jira] [Updated] (IGNITE-5247) TcpCommunicationSpi calls GridNioRecoveryDescriptor with looks unusually large rcvCnt and fail with null.

     [ https://issues.apache.org/jira/browse/IGNITE-5247?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Chandra Bose Renganathan updated IGNITE-5247:
---------------------------------------------
    Description: 
TcpCommunicationSpi calls GridNioRecoveryDescriptor with looks unusually large rcvCnt and fail with null. 

This happens when new node try to join existing grid of size 2 or 3, 

Environment Machine 1: 
SunOS betapm 5.10 Generic_150400-48 sun4v sparc sun4v

Environment Machine 2: 
Linux sbpmwsv1 2.6.32-642.13.1.el6.x86_64 #1 SMP Wed Nov 23 16:03:01 EST 2016 x86_64 x86_64 x86_64 GNU/Linux

rcvCnt=216172782113783808 ???

The configuration following. MyTcpDiscoveryIpFinderAdapter returns 3 InetSocketAddress including self.

        IgniteConfiguration cfg = new IgniteConfiguration();
        TcpDiscoverySpi spi = new TcpDiscoverySpi();
        JdkMarshaller marshaller = new JdkMarshaller();
        cfg.setMarshaller(marshaller);
        spi.setLocalPort(8087);
        spi.setSocketTimeout(80000L);
        spi.setAckTimeout(80000L);
       
        spi.setLocalPortRange(1);
        spi.setIpFinder(new MyTcpDiscoveryIpFinderAdapter());
        cfg.setDiscoverySpi(spi);
        cfg.setGridName("demo-cluster");
        cfg.setClientMode(false);

        Ignite ignite = Ignition.start(cfg);
        IgniteCache<String, String> cache = ignite.getOrCreateCache("bose");
        System.out.println(cache.get("key1"));


May 19, 2017 10:09:13 AM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Closing NIO session because of unhandled exception.
class org.apache.ignite.internal.util.nio.GridNioException: null
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2043)
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.bodyInternal(GridNioServer.java:1868)
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.body(GridNioServer.java:1573)
        at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
        at org.apache.ignite.internal.util.nio.GridNioRecoveryDescriptor.ackReceived(GridNioRecoveryDescriptor.java:211)
        at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:647)
        at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:342)
        at org.apache.ignite.internal.util.nio.GridNioFilterChain$TailFilter.onMessageReceived(GridNioFilterChain.java:279)
        at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
        at org.apache.ignite.internal.util.nio.GridNioCodecFilter.onMessageReceived(GridNioCodecFilter.java:117)
        at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
        at org.apache.ignite.internal.util.nio.GridConnectionBytesVerifyFilter.onMessageReceived(GridConnectionBytesVerifyFilter.java:88)
        at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
        at org.apache.ignite.internal.util.nio.GridNioServer$HeadFilter.onMessageReceived(GridNioServer.java:3062)
        at org.apache.ignite.internal.util.nio.GridNioFilterChain.onMessageReceived(GridNioFilterChain.java:175)
        at org.apache.ignite.internal.util.nio.GridNioServer$DirectNioClientWorker.processRead(GridNioServer.java:1121)
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2031)
        ... 4 more

May 19, 2017 10:09:14 AM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Closing NIO session because of unhandled exception.
class org.apache.ignite.internal.util.nio.GridNioException: null
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2043)
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.bodyInternal(GridNioServer.java:1868)
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.body(GridNioServer.java:1573)
        at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
        at org.apache.ignite.internal.util.nio.GridNioRecoveryDescriptor.ackReceived(GridNioRecoveryDescriptor.java:211)
        at org.apache.ignite.internal.util.nio.GridNioRecoveryDescriptor.onHandshake(GridNioRecoveryDescriptor.java:294)
        at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.connected(TcpCommunicationSpi.java:716)
        at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onFirstMessage(TcpCommunicationSpi.java:577)
        at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:626)
        at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:342)
        at org.apache.ignite.internal.util.nio.GridNioFilterChain$TailFilter.onMessageReceived(GridNioFilterChain.java:279)
        at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
        at org.apache.ignite.internal.util.nio.GridNioCodecFilter.onMessageReceived(GridNioCodecFilter.java:117)
        at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
        at org.apache.ignite.internal.util.nio.GridConnectionBytesVerifyFilter.onMessageReceived(GridConnectionBytesVerifyFilter.java:123)
        at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
        at org.apache.ignite.internal.util.nio.GridNioServer$HeadFilter.onMessageReceived(GridNioServer.java:3062)
        at org.apache.ignite.internal.util.nio.GridNioFilterChain.onMessageReceived(GridNioFilterChain.java:175)
        at org.apache.ignite.internal.util.nio.GridNioServer$DirectNioClientWorker.processRead(GridNioServer.java:1121)
        at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2031)
        ... 4 more


  was:
TcpCommunicationSpi calls GridNioRecoveryDescriptor with looks unusually large rcvCnt and fail with null. 

This happens when new node try to join existing grid of size 2 or 3, 

Environment linux.

rcvCnt=216172782113783808 ???
The configuration following. PopcornJGroupsTcpDiscoveryIpFinder returns 3 InetSocketAddress including self.

          IgniteConfiguration cfg = new IgniteConfiguration();
          cfg.setGridLogger(new Slf4jLogger(LOG));
          TcpDiscoverySpi spi = new TcpDiscoverySpi();
          spi.setLocalPort(cachePort);
          spi.setSocketTimeout(popcornCfg.getLongProperty("popcorn.cache.socketTimeout", 10000L));
          spi.setLocalPortRange(popcornCfg.getIntProperty("popcorn.cache.portRange", 2));
          spi.setIpFinder(new PopcornJGroupsTcpDiscoveryIpFinder(this));
		  Ignition.start(cfg);



08:15:00.838-07:00 [grid-nio-worker-tcp-comm-1-#522%demo-cluster.service%] ERROR o.a.i.s.c.t.TcpCommunicationSpi -  - Caught unhandled exception in NIO worker thread (restart the node)., "exception":"java.lang.AssertionError: Missed message [rcvCnt=216172782113783808, acked=3, desc=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=3, sentCnt=3, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode [id=acf668c2-188b-4488-bc02-f4a4eca46ab3, addrs=[127.0.0.1, 144.77.76.153], sockAddrs=[/127.0.0.1:20103, tttt.com/144.77.76.153:20103], discPort=20103, order=2, intOrder=2, lastExchangeTime=1495034080652, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], connected=true, connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false]]", "stack":[
	"o.a.i.i.u.n.GridNioRecoveryDescriptor.ackReceived(GridNioRecoveryDescriptor.java:207) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.s.c.t.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:647) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.s.c.t.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:342) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioFilterChain$TailFilter.onMessageReceived(GridNioFilterChain.java:279) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioCodecFilter.onMessageReceived(GridNioCodecFilter.java:117) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridConnectionBytesVerifyFilter.onMessageReceived(GridConnectionBytesVerifyFilter.java:88) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioServer$HeadFilter.onMessageReceived(GridNioServer.java:3062) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioFilterChain.onMessageReceived(GridNioFilterChain.java:175) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioServer$DirectNioClientWorker.processRead(GridNioServer.java:1121) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2031) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioServer$AbstractNioClientWorker.bodyInternal(GridNioServer.java:1868) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.n.GridNioServer$AbstractNioClientWorker.body(GridNioServer.java:1573) ~[ignite-core-2.0.0.jar:2.0.0]",
	"o.a.i.i.u.w.GridWorker.run(GridWorker.java:110) [ignite-core-2.0.0.jar:2.0.0]",
	"java.lang.Thread.run(Thread.java:745) [na:1.8.0_112]"]}



> TcpCommunicationSpi calls GridNioRecoveryDescriptor with looks unusually large rcvCnt and fail with null. 
> ----------------------------------------------------------------------------------------------------------
>
>                 Key: IGNITE-5247
>                 URL: https://issues.apache.org/jira/browse/IGNITE-5247
>             Project: Ignite
>          Issue Type: Bug
>          Components: cache
>    Affects Versions: 2.0
>            Reporter: Chandra Bose Renganathan
>            Priority: Critical
>
> TcpCommunicationSpi calls GridNioRecoveryDescriptor with looks unusually large rcvCnt and fail with null. 
> This happens when new node try to join existing grid of size 2 or 3, 
> Environment Machine 1: 
> SunOS betapm 5.10 Generic_150400-48 sun4v sparc sun4v
> Environment Machine 2: 
> Linux sbpmwsv1 2.6.32-642.13.1.el6.x86_64 #1 SMP Wed Nov 23 16:03:01 EST 2016 x86_64 x86_64 x86_64 GNU/Linux
> rcvCnt=216172782113783808 ???
> The configuration following. MyTcpDiscoveryIpFinderAdapter returns 3 InetSocketAddress including self.
>         IgniteConfiguration cfg = new IgniteConfiguration();
>         TcpDiscoverySpi spi = new TcpDiscoverySpi();
>         JdkMarshaller marshaller = new JdkMarshaller();
>         cfg.setMarshaller(marshaller);
>         spi.setLocalPort(8087);
>         spi.setSocketTimeout(80000L);
>         spi.setAckTimeout(80000L);
>        
>         spi.setLocalPortRange(1);
>         spi.setIpFinder(new MyTcpDiscoveryIpFinderAdapter());
>         cfg.setDiscoverySpi(spi);
>         cfg.setGridName("demo-cluster");
>         cfg.setClientMode(false);
>         Ignite ignite = Ignition.start(cfg);
>         IgniteCache<String, String> cache = ignite.getOrCreateCache("bose");
>         System.out.println(cache.get("key1"));
> May 19, 2017 10:09:13 AM org.apache.ignite.logger.java.JavaLogger error
> SEVERE: Closing NIO session because of unhandled exception.
> class org.apache.ignite.internal.util.nio.GridNioException: null
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2043)
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.bodyInternal(GridNioServer.java:1868)
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.body(GridNioServer.java:1573)
>         at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.NullPointerException
>         at org.apache.ignite.internal.util.nio.GridNioRecoveryDescriptor.ackReceived(GridNioRecoveryDescriptor.java:211)
>         at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:647)
>         at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:342)
>         at org.apache.ignite.internal.util.nio.GridNioFilterChain$TailFilter.onMessageReceived(GridNioFilterChain.java:279)
>         at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
>         at org.apache.ignite.internal.util.nio.GridNioCodecFilter.onMessageReceived(GridNioCodecFilter.java:117)
>         at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
>         at org.apache.ignite.internal.util.nio.GridConnectionBytesVerifyFilter.onMessageReceived(GridConnectionBytesVerifyFilter.java:88)
>         at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
>         at org.apache.ignite.internal.util.nio.GridNioServer$HeadFilter.onMessageReceived(GridNioServer.java:3062)
>         at org.apache.ignite.internal.util.nio.GridNioFilterChain.onMessageReceived(GridNioFilterChain.java:175)
>         at org.apache.ignite.internal.util.nio.GridNioServer$DirectNioClientWorker.processRead(GridNioServer.java:1121)
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2031)
>         ... 4 more
> May 19, 2017 10:09:14 AM org.apache.ignite.logger.java.JavaLogger error
> SEVERE: Closing NIO session because of unhandled exception.
> class org.apache.ignite.internal.util.nio.GridNioException: null
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2043)
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.bodyInternal(GridNioServer.java:1868)
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.body(GridNioServer.java:1573)
>         at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.NullPointerException
>         at org.apache.ignite.internal.util.nio.GridNioRecoveryDescriptor.ackReceived(GridNioRecoveryDescriptor.java:211)
>         at org.apache.ignite.internal.util.nio.GridNioRecoveryDescriptor.onHandshake(GridNioRecoveryDescriptor.java:294)
>         at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.connected(TcpCommunicationSpi.java:716)
>         at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onFirstMessage(TcpCommunicationSpi.java:577)
>         at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:626)
>         at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$2.onMessage(TcpCommunicationSpi.java:342)
>         at org.apache.ignite.internal.util.nio.GridNioFilterChain$TailFilter.onMessageReceived(GridNioFilterChain.java:279)
>         at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
>         at org.apache.ignite.internal.util.nio.GridNioCodecFilter.onMessageReceived(GridNioCodecFilter.java:117)
>         at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
>         at org.apache.ignite.internal.util.nio.GridConnectionBytesVerifyFilter.onMessageReceived(GridConnectionBytesVerifyFilter.java:123)
>         at org.apache.ignite.internal.util.nio.GridNioFilterAdapter.proceedMessageReceived(GridNioFilterAdapter.java:109)
>         at org.apache.ignite.internal.util.nio.GridNioServer$HeadFilter.onMessageReceived(GridNioServer.java:3062)
>         at org.apache.ignite.internal.util.nio.GridNioFilterChain.onMessageReceived(GridNioFilterChain.java:175)
>         at org.apache.ignite.internal.util.nio.GridNioServer$DirectNioClientWorker.processRead(GridNioServer.java:1121)
>         at org.apache.ignite.internal.util.nio.GridNioServer$AbstractNioClientWorker.processSelectedKeysOptimized(GridNioServer.java:2031)
>         ... 4 more



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)