Hi, Thanks for looking at my issue.
There are tags for 1.8.1, 1.8.2 and 1.8.3 at https://github.com/gridgain/apache-ignite so I have been trying using jars built from those tags, including 1.9 I'm still getting the issues. What concerns me the most is that it is very easy to lockup the whole grid. I have tried various short (2s) .. long (40s) FailureDetectionTimeout and I still get a lockup. I've tried the prefer ip4 as you suggested but it didn't make any difference. I've included my jvm args, an excerpt from the jvm gc logs, and some more recent ignite logs. Cheers Cameron *[jvm args]* -Xms2G -Xmx2G -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -Xloggc:target/gc-log-devA.txt -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+UseTLAB -XX:NewSize=128m -XX:MaxNewSize=128m -XX:MaxTenuringThreshold=0 -XX:SurvivorRatio=1024 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=40 -XX:MaxGCPauseMillis=1000 -XX:InitiatingHeapOccupancyPercent=50 -XX:+UseCompressedOops -XX:ParallelGCThreads=6 -XX:ConcGCThreads=6 *[GC logs]* 2017-02-17T02:43:31.345+1100: 1997.387: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:43:32.099+1100: 1998.141: [GC (Allocation Failure) 2017-02-17T02:43:32.100+1100: 1998.141: [ParNew: 130485K->0K(131008K), 0.0332423 secs] 773911K->655291K(2097088K), 0.0336493 secs] [Times: user=0.10 sys=0.00, real=0.04 secs] 2017-02-17T02:43:32.498+1100: 1998.539: [GC (Allocation Failure) 2017-02-17T02:43:32.498+1100: 1998.539: [ParNew: 130944K->0K(131008K), 0.0489761 secs] 786235K->683673K(2097088K), 0.0492079 secs] [Times: user=0.13 sys=0.01, real=0.05 secs] 2017-02-17T02:43:33.578+1100: 1999.620: [GC (Allocation Failure) 2017-02-17T02:43:33.578+1100: 1999.620: [ParNew: 130944K->0K(131008K), 0.0589320 secs] 814617K->710468K(2097088K), 0.0594862 secs] [Times: user=0.19 sys=0.01, real=0.06 secs] 2017-02-17T02:43:33.997+1100: 2000.038: [GC (Allocation Failure) 2017-02-17T02:43:33.997+1100: 2000.038: [ParNew: 130944K->0K(131008K), 0.0382098 secs] 841412K->723510K(2097088K), 0.0386616 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 2017-02-17T02:43:34.724+1100: 2000.765: [GC (Allocation Failure) 2017-02-17T02:43:34.724+1100: 2000.765: [ParNew: 130944K->0K(131008K), 0.0061646 secs] 854454K->725669K(2097088K), 0.0064497 secs] [Times: user=0.03 sys=0.01, real=0.01 secs] 2017-02-17T02:43:35.303+1100: 2001.344: [GC (Allocation Failure) 2017-02-17T02:43:35.303+1100: 2001.345: [ParNew: 130944K->0K(131008K), 0.0102684 secs] 856613K->727224K(2097088K), 0.0105370 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:43:35.582+1100: 2001.623: [GC (Allocation Failure) 2017-02-17T02:43:35.582+1100: 2001.623: [ParNew: 130944K->0K(131008K), 0.0201246 secs] 858168K->735764K(2097088K), 0.0204913 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2017-02-17T02:43:35.856+1100: 2001.898: [GC (Allocation Failure) 2017-02-17T02:43:35.856+1100: 2001.898: [ParNew: 130944K->0K(131008K), 0.0176264 secs] 866708K->745151K(2097088K), 0.0178741 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:43:36.554+1100: 2002.595: [GC (Allocation Failure) 2017-02-17T02:43:36.554+1100: 2002.596: [ParNew: 130944K->0K(131008K), 0.0480600 secs] 876095K->752482K(2097088K), 0.0483472 secs] [Times: user=0.08 sys=0.00, real=0.05 secs] 2017-02-17T02:43:38.991+1100: 2005.033: [GC (Allocation Failure) 2017-02-17T02:43:38.991+1100: 2005.033: [ParNew: 130930K->0K(131008K), 0.0188153 secs] 883413K->764137K(2097088K), 0.0191396 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:43:40.428+1100: 2006.470: [GC (Allocation Failure) 2017-02-17T02:43:40.428+1100: 2006.470: [ParNew: 130941K->0K(131008K), 0.0272629 secs] 895079K->775860K(2097088K), 0.0274685 secs] [Times: user=0.07 sys=0.01, real=0.02 secs] 2017-02-17T02:43:41.195+1100: 2007.237: [GC (Allocation Failure) 2017-02-17T02:43:41.195+1100: 2007.237: [ParNew: 130944K->0K(131008K), 0.0117222 secs] 906804K->778960K(2097088K), 0.0120822 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 2017-02-17T02:43:41.919+1100: 2007.960: [GC (Allocation Failure) 2017-02-17T02:43:41.919+1100: 2007.961: [ParNew: 130944K->0K(131008K), 0.0181342 secs] 909904K->782162K(2097088K), 0.0183815 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 2017-02-17T02:43:42.337+1100: 2008.378: [GC (Allocation Failure) 2017-02-17T02:43:42.337+1100: 2008.378: [ParNew: 130944K->0K(131008K), 0.0182636 secs] 913106K->790713K(2097088K), 0.0187463 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:43:42.358+1100: 2008.399: [GC (CMS Initial Mark) [1 CMS-initial-mark: 790713K(1966080K)] 791332K(2097088K), 0.0103648 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 2017-02-17T02:43:42.368+1100: 2008.410: [CMS-concurrent-mark-start] 2017-02-17T02:43:42.668+1100: 2008.709: [CMS-concurrent-mark: 0.299/0.299 secs] [Times: user=1.76 sys=0.00, real=0.29 secs] 2017-02-17T02:43:42.668+1100: 2008.709: [CMS-concurrent-preclean-start] 2017-02-17T02:43:42.674+1100: 2008.716: [CMS-concurrent-preclean: 0.006/0.006 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:43:42.674+1100: 2008.716: [CMS-concurrent-abortable-preclean-start] 2017-02-17T02:43:43.450+1100: 2009.491: [GC (Allocation Failure) 2017-02-17T02:43:43.450+1100: 2009.491: [ParNew: 130944K->0K(131008K), 0.0551432 secs] 921657K->801859K(2097088K), 0.0556674 secs] [Times: user=0.14 sys=0.00, real=0.05 secs] 2017-02-17T02:43:45.723+1100: 2011.764: [CMS-concurrent-abortable-preclean: 0.322/3.048 secs] [Times: user=1.42 sys=0.04, real=3.05 secs] 2017-02-17T02:43:45.724+1100: 2011.766: [GC (CMS Final Remark) [YG occupancy: 115048 K (131008 K)]2017-02-17T02:43:45.724+1100: 2011.766: [Rescan (parallel) , 0.0249292 secs]2017-02-17T02:43:45.749+1100: 2011.791: [weak refs processing, 0.0221092 secs]2017-02-17T02:43:45.772+1100: 2011.813: [class unloading, 0.0755943 secs]2017-02-17T02:43:45.847+1100: 2011.889: [scrub symbol table, 0.0482050 secs]2017-02-17T02:43:45.895+1100: 2011.937: [scrub string table, 0.0079892 secs][1 CMS-remark: 801859K(1966080K)] 916908K(2097088K), 0.1793458 secs] [Times: user=0.28 sys=0.00, real=0.18 secs] 2017-02-17T02:43:45.905+1100: 2011.946: [CMS-concurrent-sweep-start] 2017-02-17T02:43:45.921+1100: 2011.962: [GC (Allocation Failure) 2017-02-17T02:43:45.921+1100: 2011.962: [ParNew: 130944K->0K(131008K), 0.0357489 secs] 930403K->813145K(2097088K), 0.0360470 secs] [Times: user=0.14 sys=0.00, real=0.03 secs] 2017-02-17T02:43:46.320+1100: 2012.362: [CMS-concurrent-sweep: 0.375/0.415 secs] [Times: user=1.13 sys=0.00, real=0.42 secs] 2017-02-17T02:43:46.320+1100: 2012.362: [CMS-concurrent-reset-start] 2017-02-17T02:43:46.322+1100: 2012.363: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-02-17T02:43:50.055+1100: 2016.097: [GC (Allocation Failure) 2017-02-17T02:43:50.056+1100: 2016.097: [ParNew: 130944K->0K(131008K), 0.0349198 secs] 749766K->633040K(2097088K), 0.0353595 secs] [Times: user=0.12 sys=0.00, real=0.04 secs] 2017-02-17T02:43:50.371+1100: 2016.413: [GC (Allocation Failure) 2017-02-17T02:43:50.371+1100: 2016.413: [ParNew: 130944K->0K(131008K), 0.0282887 secs] 763984K->644930K(2097088K), 0.0285394 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2017-02-17T02:43:51.940+1100: 2017.981: [GC (Allocation Failure) 2017-02-17T02:43:51.940+1100: 2017.981: [ParNew: 130944K->0K(131008K), 0.0328645 secs] 775874K->656750K(2097088K), 0.0332418 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 2017-02-17T02:43:53.526+1100: 2019.567: [GC (Allocation Failure) 2017-02-17T02:43:53.526+1100: 2019.567: [ParNew: 130944K->0K(131008K), 0.0335550 secs] 787694K->669230K(2097088K), 0.0339693 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 2017-02-17T02:43:56.384+1100: 2022.425: [GC (Allocation Failure) 2017-02-17T02:43:56.384+1100: 2022.425: [ParNew: 130944K->0K(131008K), 0.0216725 secs] 800174K->683670K(2097088K), 0.0218995 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:43:56.723+1100: 2022.764: [GC (Allocation Failure) 2017-02-17T02:43:56.723+1100: 2022.765: [ParNew: 130944K->0K(131008K), 0.0282867 secs] 814614K->696494K(2097088K), 0.0285313 secs] [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-02-17T02:43:59.368+1100: 2025.410: [GC (Allocation Failure) 2017-02-17T02:43:59.368+1100: 2025.410: [ParNew: 130944K->0K(131008K), 0.0202311 secs] 827438K->708728K(2097088K), 0.0204566 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2017-02-17T02:44:00.094+1100: 2026.135: [GC (Allocation Failure) 2017-02-17T02:44:00.094+1100: 2026.135: [ParNew: 130944K->0K(131008K), 0.0543868 secs] 839672K->722031K(2097088K), 0.0547452 secs] [Times: user=0.16 sys=0.00, real=0.06 secs] 2017-02-17T02:44:00.740+1100: 2026.782: [GC (Allocation Failure) 2017-02-17T02:44:00.740+1100: 2026.782: [ParNew: 130944K->0K(131008K), 0.0965223 secs] 852975K->753244K(2097088K), 0.0969327 secs] [Times: user=0.24 sys=0.00, real=0.09 secs] 2017-02-17T02:44:03.694+1100: 2029.736: [GC (Allocation Failure) 2017-02-17T02:44:03.694+1100: 2029.736: [ParNew: 130944K->0K(131008K), 0.0083419 secs] 884188K->758851K(2097088K), 0.0085863 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:44:03.944+1100: 2029.986: [GC (Allocation Failure) 2017-02-17T02:44:03.945+1100: 2029.986: [ParNew: 130944K->0K(131008K), 0.0322574 secs] 889795K->771415K(2097088K), 0.0324985 secs] [Times: user=0.12 sys=0.01, real=0.03 secs] 2017-02-17T02:44:04.315+1100: 2030.356: [GC (Allocation Failure) 2017-02-17T02:44:04.315+1100: 2030.356: [ParNew: 130944K->0K(131008K), 0.0184334 secs] 902359K->776472K(2097088K), 0.0186736 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 2017-02-17T02:44:04.672+1100: 2030.713: [GC (Allocation Failure) 2017-02-17T02:44:04.672+1100: 2030.714: [ParNew: 130944K->0K(131008K), 0.0104419 secs] 907416K->779222K(2097088K), 0.0107390 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:44:06.929+1100: 2032.971: [GC (Allocation Failure) 2017-02-17T02:44:06.929+1100: 2032.971: [ParNew: 130944K->0K(131008K), 0.0306160 secs] 910166K->788721K(2097088K), 0.0309050 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 2017-02-17T02:44:06.962+1100: 2033.004: [GC (CMS Initial Mark) [1 CMS-initial-mark: 788721K(1966080K)] 789037K(2097088K), 0.0104127 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-02-17T02:44:06.973+1100: 2033.015: [CMS-concurrent-mark-start] 2017-02-17T02:44:07.222+1100: 2033.264: [CMS-concurrent-mark: 0.249/0.249 secs] [Times: user=1.55 sys=0.01, real=0.25 secs] 2017-02-17T02:44:07.222+1100: 2033.264: [CMS-concurrent-preclean-start] 2017-02-17T02:44:07.232+1100: 2033.273: [CMS-concurrent-preclean: 0.009/0.009 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 2017-02-17T02:44:07.232+1100: 2033.273: [CMS-concurrent-abortable-preclean-start] 2017-02-17T02:44:07.303+1100: 2033.344: [GC (Allocation Failure) 2017-02-17T02:44:07.303+1100: 2033.344: [ParNew: 130944K->0K(131008K), 0.0210551 secs] 919665K->798886K(2097088K), 0.0212904 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:44:10.241+1100: 2036.283: [CMS-concurrent-abortable-preclean: 0.254/3.009 secs] [Times: user=0.95 sys=0.03, real=3.01 secs] 2017-02-17T02:44:10.243+1100: 2036.284: [GC (CMS Final Remark) [YG occupancy: 129195 K (131008 K)]2017-02-17T02:44:10.243+1100: 2036.285: [Rescan (parallel) , 0.0237959 secs]2017-02-17T02:44:10.267+1100: 2036.308: [weak refs processing, 0.0135225 secs]2017-02-17T02:44:10.280+1100: 2036.322: [class unloading, 0.0650329 secs]2017-02-17T02:44:10.345+1100: 2036.387: [scrub symbol table, 0.0456804 secs]2017-02-17T02:44:10.391+1100: 2036.433: [scrub string table, 0.0033289 secs][1 CMS-remark: 798886K(1966080K)] 928081K(2097088K), 0.1516345 secs] [Times: user=0.26 sys=0.00, real=0.15 secs] 2017-02-17T02:44:10.395+1100: 2036.437: [CMS-concurrent-sweep-start] 2017-02-17T02:44:10.400+1100: 2036.442: [GC (Allocation Failure) 2017-02-17T02:44:10.400+1100: 2036.442: [ParNew: 130944K->0K(131008K), 0.0445364 secs] 929185K->811108K(2097088K), 0.0450258 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 2017-02-17T02:44:10.842+1100: 2036.883: [CMS-concurrent-sweep: 0.396/0.447 secs] [Times: user=1.12 sys=0.01, real=0.45 secs] 2017-02-17T02:44:10.842+1100: 2036.883: [CMS-concurrent-reset-start] 2017-02-17T02:44:10.845+1100: 2036.887: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:44:11.903+1100: 2037.944: [GC (Allocation Failure) 2017-02-17T02:44:11.903+1100: 2037.944: [ParNew: 130944K->0K(131008K), 0.0221250 secs] 744770K->626298K(2097088K), 0.0224061 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2017-02-17T02:44:15.166+1100: 2041.208: [GC (Allocation Failure) 2017-02-17T02:44:15.166+1100: 2041.208: [ParNew: 130944K->0K(131008K), 0.0177362 secs] 757242K->637567K(2097088K), 0.0179457 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:44:15.504+1100: 2041.545: [GC (Allocation Failure) 2017-02-17T02:44:15.504+1100: 2041.546: [ParNew: 130944K->0K(131008K), 0.0277922 secs] 768511K->650176K(2097088K), 0.0280503 secs] [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-02-17T02:44:18.209+1100: 2044.251: [GC (Allocation Failure) 2017-02-17T02:44:18.210+1100: 2044.251: [ParNew: 130944K->0K(131008K), 0.0233300 secs] 781120K->664952K(2097088K), 0.0237955 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 2017-02-17T02:44:20.464+1100: 2046.506: [GC (Allocation Failure) 2017-02-17T02:44:20.464+1100: 2046.506: [ParNew: 130944K->0K(131008K), 0.0273960 secs] 795896K->676992K(2097088K), 0.0278519 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 2017-02-17T02:44:21.484+1100: 2047.525: [GC (Allocation Failure) 2017-02-17T02:44:21.484+1100: 2047.525: [ParNew: 130944K->0K(131008K), 0.0449985 secs] 807936K->690259K(2097088K), 0.0453177 secs] [Times: user=0.12 sys=0.00, real=0.05 secs] 2017-02-17T02:44:21.945+1100: 2047.987: [GC (Allocation Failure) 2017-02-17T02:44:21.946+1100: 2047.987: [ParNew: 130944K->0K(131008K), 0.0251679 secs] 821203K->699483K(2097088K), 0.0262224 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 2017-02-17T02:44:24.626+1100: 2050.667: [GC (Allocation Failure) 2017-02-17T02:44:24.626+1100: 2050.667: [ParNew: 130944K->0K(131008K), 0.0251576 secs] 830427K->713888K(2097088K), 0.0254822 secs] [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-02-17T02:44:26.128+1100: 2052.170: [GC (Allocation Failure) 2017-02-17T02:44:26.128+1100: 2052.170: [ParNew: 130944K->0K(131008K), 0.0426065 secs] 844832K->726675K(2097088K), 0.0428679 secs] [Times: user=0.14 sys=0.00, real=0.05 secs] 2017-02-17T02:44:27.678+1100: 2053.719: [GC (Allocation Failure) 2017-02-17T02:44:27.678+1100: 2053.719: [ParNew: 130944K->0K(131008K), 0.0323946 secs] 857619K->740490K(2097088K), 0.0327861 secs] [Times: user=0.14 sys=0.00, real=0.04 secs] 2017-02-17T02:44:30.840+1100: 2056.882: [GC (Allocation Failure) 2017-02-17T02:44:30.840+1100: 2056.882: [ParNew: 130944K->0K(131008K), 0.0477350 secs] 871434K->753192K(2097088K), 0.0483545 secs] [Times: user=0.11 sys=0.00, real=0.05 secs] 2017-02-17T02:44:31.322+1100: 2057.363: [GC (Allocation Failure) 2017-02-17T02:44:31.322+1100: 2057.363: [ParNew: 130944K->0K(131008K), 0.0307054 secs] 884136K->763364K(2097088K), 0.0309678 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] 2017-02-17T02:44:34.620+1100: 2060.661: [GC (Allocation Failure) 2017-02-17T02:44:34.620+1100: 2060.661: [ParNew: 130944K->0K(131008K), 0.0201055 secs] 894308K->770865K(2097088K), 0.0203720 secs] [Times: user=0.06 sys=0.02, real=0.03 secs] 2017-02-17T02:44:34.971+1100: 2061.012: [GC (Allocation Failure) 2017-02-17T02:44:34.971+1100: 2061.012: [ParNew: 130944K->0K(131008K), 0.0315070 secs] 901809K->782181K(2097088K), 0.0317446 secs] [Times: user=0.14 sys=0.00, real=0.03 secs] 2017-02-17T02:44:38.021+1100: 2064.063: [GC (Allocation Failure) 2017-02-17T02:44:38.021+1100: 2064.063: [ParNew: 130944K->0K(131008K), 0.0275684 secs] 913125K->797709K(2097088K), 0.0279734 secs] [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-02-17T02:44:38.052+1100: 2064.094: [GC (CMS Initial Mark) [1 CMS-initial-mark: 797709K(1966080K)] 798588K(2097088K), 0.0051309 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:44:38.058+1100: 2064.099: [CMS-concurrent-mark-start] 2017-02-17T02:44:38.288+1100: 2064.330: [CMS-concurrent-mark: 0.230/0.230 secs] [Times: user=1.45 sys=0.01, real=0.24 secs] 2017-02-17T02:44:38.288+1100: 2064.330: [CMS-concurrent-preclean-start] 2017-02-17T02:44:38.294+1100: 2064.335: [CMS-concurrent-preclean: 0.005/0.005 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 2017-02-17T02:44:38.294+1100: 2064.335: [CMS-concurrent-abortable-preclean-start] 2017-02-17T02:44:38.387+1100: 2064.428: [GC (Allocation Failure) 2017-02-17T02:44:38.387+1100: 2064.428: [ParNew: 130944K->0K(131008K), 0.0140969 secs] 928653K->805184K(2097088K), 0.0143336 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 2017-02-17T02:44:41.231+1100: 2067.272: [CMS-concurrent-abortable-preclean: 0.254/2.937 secs] [Times: user=1.09 sys=0.07, real=2.94 secs] 2017-02-17T02:44:41.232+1100: 2067.273: [GC (CMS Final Remark) [YG occupancy: 75740 K (131008 K)]2017-02-17T02:44:41.232+1100: 2067.273: [Rescan (parallel) , 0.0185411 secs]2017-02-17T02:44:41.251+1100: 2067.292: [weak refs processing, 0.0161160 secs]2017-02-17T02:44:41.267+1100: 2067.308: [class unloading, 0.0620000 secs]2017-02-17T02:44:41.329+1100: 2067.370: [scrub symbol table, 0.0471891 secs]2017-02-17T02:44:41.376+1100: 2067.417: [scrub string table, 0.0029885 secs][1 CMS-remark: 805184K(1966080K)] 880925K(2097088K), 0.1471620 secs] [Times: user=0.21 sys=0.01, real=0.14 secs] 2017-02-17T02:44:41.379+1100: 2067.421: [CMS-concurrent-sweep-start] 2017-02-17T02:44:41.521+1100: 2067.562: [GC (Allocation Failure) 2017-02-17T02:44:41.521+1100: 2067.562: [ParNew: 130944K->0K(131008K), 0.0275124 secs] 879741K->762742K(2097088K), 0.0277784 secs] [Times: user=0.12 sys=0.00, real=0.03 secs] 2017-02-17T02:44:41.893+1100: 2067.934: [CMS-concurrent-sweep: 0.479/0.513 secs] [Times: user=1.67 sys=0.04, real=0.52 secs] 2017-02-17T02:44:41.893+1100: 2067.934: [CMS-concurrent-reset-start] 2017-02-17T02:44:41.896+1100: 2067.938: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:44:41.933+1100: 2067.975: [GC (Allocation Failure) 2017-02-17T02:44:41.934+1100: 2067.975: [ParNew: 130944K->0K(131008K), 0.0225040 secs] 753799K->632471K(2097088K), 0.0231169 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2017-02-17T02:44:46.357+1100: 2072.399: [GC (Allocation Failure) 2017-02-17T02:44:46.358+1100: 2072.399: [ParNew: 130944K->0K(131008K), 0.0233062 secs] 763415K->648794K(2097088K), 0.0235657 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] 2017-02-17T02:44:46.693+1100: 2072.734: [GC (Allocation Failure) 2017-02-17T02:44:46.693+1100: 2072.734: [ParNew: 130944K->0K(131008K), 0.0204649 secs] 779738K->658469K(2097088K), 0.0207512 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 2017-02-17T02:44:49.622+1100: 2075.664: [GC (Allocation Failure) 2017-02-17T02:44:49.623+1100: 2075.664: [ParNew: 130944K->0K(131008K), 0.0261480 secs] 789413K->669895K(2097088K), 0.0264612 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 2017-02-17T02:44:50.683+1100: 2076.724: [GC (Allocation Failure) 2017-02-17T02:44:50.683+1100: 2076.725: [ParNew: 130944K->0K(131008K), 0.0304973 secs] 800839K->682648K(2097088K), 0.0308284 secs] [Times: user=0.11 sys=0.01, real=0.03 secs] 2017-02-17T02:44:52.917+1100: 2078.958: [GC (Allocation Failure) 2017-02-17T02:44:52.917+1100: 2078.958: [ParNew: 130944K->0K(131008K), 0.0199548 secs] 813592K->691321K(2097088K), 0.0202226 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 2017-02-17T02:44:53.254+1100: 2079.296: [GC (Allocation Failure) 2017-02-17T02:44:53.254+1100: 2079.296: [ParNew: 130944K->0K(131008K), 0.0288800 secs] 822265K->702344K(2097088K), 0.0292182 secs] [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-02-17T02:44:56.103+1100: 2082.145: [GC (Allocation Failure) 2017-02-17T02:44:56.103+1100: 2082.145: [ParNew: 130944K->0K(131008K), 0.0306146 secs] 833288K->714654K(2097088K), 0.0310109 secs] [Times: user=0.12 sys=0.00, real=0.03 secs] 2017-02-17T02:44:57.011+1100: 2083.052: [GC (Allocation Failure) 2017-02-17T02:44:57.011+1100: 2083.053: [ParNew: 130944K->0K(131008K), 0.0438056 secs] 845598K->729259K(2097088K), 0.0443198 secs] [Times: user=0.15 sys=0.00, real=0.04 secs] 2017-02-17T02:44:58.467+1100: 2084.509: [GC (Allocation Failure) 2017-02-17T02:44:58.467+1100: 2084.509: [ParNew: 130944K->0K(131008K), 0.0106478 secs] 860203K->731810K(2097088K), 0.0109459 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-02-17T02:44:59.134+1100: 2085.176: [GC (Allocation Failure) 2017-02-17T02:44:59.134+1100: 2085.176: [ParNew: 130915K->0K(131008K), 0.0057411 secs] 862725K->732521K(2097088K), 0.0059370 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-02-17T02:44:59.657+1100: 2085.698: [GC (Allocation Failure) 2017-02-17T02:44:59.657+1100: 2085.698: [ParNew: 130944K->0K(131008K), 0.0262399 secs] 863465K->743741K(2097088K), 0.0265018 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] 2017-02-17T02:45:00.112+1100: 2086.153: [GC (Allocation Failure) 2017-02-17T02:45:00.112+1100: 2086.153: [ParNew: 130944K->0K(131008K), 0.1237185 secs] 874685K->779466K(2097088K), 0.1242109 secs] [Times: user=0.29 sys=0.00, real=0.12 secs] 2017-02-17T02:45:04.750+1100: 2090.791: [GC (Allocation Failure) 2017-02-17T02:45:04.750+1100: 2090.791: [ParNew: 130944K->0K(131008K), 0.0165329 secs] 910410K->787929K(2097088K), 0.0168275 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 2017-02-17T02:45:04.768+1100: 2090.809: [GC (CMS Initial Mark) [1 CMS-initial-mark: 787929K(1966080K)] 788776K(2097088K), 0.0040991 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 2017-02-17T02:45:04.772+1100: 2090.814: [CMS-concurrent-mark-start] 2017-02-17T02:45:04.990+1100: 2091.032: [CMS-concurrent-mark: 0.218/0.218 secs] [Times: user=1.40 sys=0.00, real=0.22 secs] 2017-02-17T02:45:04.991+1100: 2091.032: [CMS-concurrent-preclean-start] 2017-02-17T02:45:04.996+1100: 2091.038: [CMS-concurrent-preclean: 0.006/0.006 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:45:04.996+1100: 2091.038: [CMS-concurrent-abortable-preclean-start] 2017-02-17T02:45:05.109+1100: 2091.151: [CMS-concurrent-abortable-preclean: 0.013/0.113 secs] [Times: user=0.25 sys=0.01, real=0.12 secs] 2017-02-17T02:45:05.111+1100: 2091.153: [GC (CMS Final Remark) [YG occupancy: 81420 K (131008 K)]2017-02-17T02:45:05.112+1100: 2091.153: [Rescan (parallel) , 0.0170368 secs]2017-02-17T02:45:05.129+1100: 2091.170: [weak refs processing, 0.0160407 secs]2017-02-17T02:45:05.145+1100: 2091.186: [class unloading, 0.0761075 secs]2017-02-17T02:45:05.221+1100: 2091.262: [scrub symbol table, 0.0461117 secs]2017-02-17T02:45:05.267+1100: 2091.308: [scrub string table, 0.0027865 secs][1 CMS-remark: 787929K(1966080K)] 869350K(2097088K), 0.1584396 secs] [Times: user=0.23 sys=0.00, real=0.16 secs] 2017-02-17T02:45:05.270+1100: 2091.312: [CMS-concurrent-sweep-start] 2017-02-17T02:45:05.309+1100: 2091.350: [GC (Allocation Failure) 2017-02-17T02:45:05.309+1100: 2091.350: [ParNew: 130944K->0K(131008K), 0.0256950 secs] 909451K->791427K(2097088K), 0.0259124 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 2017-02-17T02:45:05.664+1100: 2091.705: [CMS-concurrent-sweep: 0.363/0.394 secs] [Times: user=1.26 sys=0.00, real=0.39 secs] 2017-02-17T02:45:05.664+1100: 2091.706: [CMS-concurrent-reset-start] 2017-02-17T02:45:05.670+1100: 2091.711: [CMS-concurrent-reset: 0.005/0.005 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-02-17T02:45:09.948+1100: 2095.990: [GC (Allocation Failure) 2017-02-17T02:45:09.948+1100: 2095.990: [ParNew: 130944K->0K(131008K), 0.0347194 secs] 728922K->612136K(2097088K), 0.0350136 secs] [Times: user=0.12 sys=0.01, real=0.03 secs] 2017-02-17T02:45:10.346+1100: 2096.388: [GC (Allocation Failure) 2017-02-17T02:45:10.347+1100: 2096.388: [ParNew: 130944K->0K(131008K), 0.0421117 secs] 743080K->623894K(2097088K), 0.0427087 secs] [Times: user=0.11 sys=0.00, real=0.05 secs] 2017-02-17T02:45:14.076+1100: 2100.118: [GC (Allocation Failure) 2017-02-17T02:45:14.076+1100: 2100.118: [ParNew: 130944K->0K(131008K), 0.0383561 secs] 754838K->633484K(2097088K), 0.0386263 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 2017-02-17T02:45:14.516+1100: 2100.557: [GC (Allocation Failure) 2017-02-17T02:45:14.516+1100: 2100.557: [ParNew: 130944K->0K(131008K), 0.0469385 secs] 764428K->645002K(2097088K), 0.0472950 secs] [Times: user=0.11 sys=0.00, real=0.05 secs] 2017-02-17T02:45:18.610+1100: 2104.651: [GC (Allocation Failure) 2017-02-17T02:45:18.610+1100: 2104.651: [ParNew: 130944K->0K(131008K), 0.0438649 secs] 775946K->659657K(2097088K), 0.0444299 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 2017-02-17T02:45:19.016+1100: 2105.058: [GC (Allocation Failure) 2017-02-17T02:45:19.016+1100: 2105.058: [ParNew: 130944K->0K(131008K), 0.0507684 secs] 790601K->671909K(2097088K), 0.0511395 secs] [Times: user=0.12 sys=0.01, real=0.05 secs] 2017-02-17T02:45:22.558+1100: 2108.600: [GC (Allocation Failure) 2017-02-17T02:45:22.558+1100: 2108.600: [ParNew: 130944K->0K(131008K), 0.0372261 secs] 802853K->680749K(2097088K), 0.0376654 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 2017-02-17T02:45:23.046+1100: 2109.087: [GC (Allocation Failure) 2017-02-17T02:45:23.046+1100: 2109.087: [ParNew: 130944K->0K(131008K), 0.0351447 secs] 811693K->691789K(2097088K), 0.0354445 secs] [Times: user=0.09 sys=0.00, real=0.04 secs] 2017-02-17T02:45:26.053+1100: 2112.095: [GC (Allocation Failure) 2017-02-17T02:45:26.053+1100: 2112.095: [ParNew: 130944K->0K(131008K), 0.0656059 secs] 822733K->708014K(2097088K), 0.0659827 secs] [Times: user=0.14 sys=0.00, real=0.06 secs] 2017-02-17T02:45:41.925+1100: 2127.967: [GC (Allocation Failure) 2017-02-17T02:45:41.925+1100: 2127.967: [ParNew: 130944K->0K(131008K), 0.0155199 secs] 838958K->711744K(2097088K), 0.0158258 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 2017-02-17T02:46:00.038+1100: 2146.079: [GC (Allocation Failure) 2017-02-17T02:46:00.038+1100: 2146.079: [ParNew: 130944K->0K(131008K), 0.0400212 secs] 842688K->728169K(2097088K), 0.0402518 secs] [Times: user=0.10 sys=0.00, real=0.04 secs] 2017-02-17T02:46:11.916+1100: 2157.958: [GC (Allocation Failure) 2017-02-17T02:46:11.917+1100: 2157.958: [ParNew: 130944K->0K(131008K), 0.0289077 secs] 859113K->744463K(2097088K), 0.0291609 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 2017-02-17T02:46:31.907+1100: 2177.949: [GC (Allocation Failure) 2017-02-17T02:46:31.908+1100: 2177.949: [ParNew: 130944K->0K(131008K), 0.0112924 secs] 875407K->747899K(2097088K), 0.0115952 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 2017-02-17T02:46:51.900+1100: 2197.941: [GC (Allocation Failure) 2017-02-17T02:46:51.900+1100: 2197.942: [ParNew: 130944K->0K(131008K), 0.0045572 secs] 878843K->750985K(2097088K), 0.0048081 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-02-17T02:47:01.930+1100: 2207.971: [GC (Allocation Failure) 2017-02-17T02:47:01.930+1100: 2207.971: [ParNew: 130944K->0K(131008K), 0.0086248 secs] 881929K->755528K(2097088K), 0.0088485 secs] [Times: user=0.04 sys=0.00, real=0.00 secs] 2017-02-17T02:47:21.928+1100: 2227.970: [GC (Allocation Failure) 2017-02-17T02:47:21.929+1100: 2227.970: [ParNew: 130944K->0K(131008K), 0.0077591 secs] 886472K->758584K(2097088K), 0.0082467 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 2017-02-17T02:47:41.948+1100: 2247.989: [GC (Allocation Failure) 2017-02-17T02:47:41.948+1100: 2247.990: [ParNew: 130126K->0K(131008K), 0.0102145 secs] 888711K->760882K(2097088K), 0.0108365 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:48:01.923+1100: 2267.964: [GC (Allocation Failure) 2017-02-17T02:48:01.923+1100: 2267.965: [ParNew: 130944K->0K(131008K), 0.0107592 secs] 891826K->764669K(2097088K), 0.0110117 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:48:21.917+1100: 2287.958: [GC (Allocation Failure) 2017-02-17T02:48:21.917+1100: 2287.958: [ParNew: 130944K->0K(131008K), 0.0090583 secs] 895613K->768273K(2097088K), 0.0092679 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-02-17T02:48:41.904+1100: 2307.945: [GC (Allocation Failure) 2017-02-17T02:48:41.904+1100: 2307.945: [ParNew: 130944K->0K(131008K), 0.0078590 secs] 899217K->773317K(2097088K), 0.0081014 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] 2017-02-17T02:49:00.029+1100: 2326.070: [GC (Allocation Failure) 2017-02-17T02:49:00.029+1100: 2326.070: [ParNew: 130944K->0K(131008K), 0.0087433 secs] 904261K->777092K(2097088K), 0.0090668 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 2017-02-17T02:49:11.929+1100: 2337.970: [GC (Allocation Failure) 2017-02-17T02:49:11.929+1100: 2337.970: [ParNew: 130944K->0K(131008K), 0.0084035 secs] 908036K->780961K(2097088K), 0.0086772 secs] [Times: user=0.04 sys=0.00, real=0.00 secs] 2017-02-17T02:49:31.924+1100: 2357.965: [GC (Allocation Failure) 2017-02-17T02:49:31.924+1100: 2357.965: [ParNew: 130944K->0K(131008K), 0.0067438 secs] 911905K->786009K(2097088K), 0.0069780 secs] [Times: user=0.02 sys=0.01, real=0.01 secs] 2017-02-17T02:49:51.920+1100: 2377.961: [GC (Allocation Failure) 2017-02-17T02:49:51.920+1100: 2377.962: [ParNew: 130944K->0K(131008K), 0.0077132 secs] 916953K->790678K(2097088K), 0.0079584 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] 2017-02-17T02:49:51.929+1100: 2377.971: [GC (CMS Initial Mark) [1 CMS-initial-mark: 790678K(1966080K)] 791582K(2097088K), 0.0041258 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:49:51.934+1100: 2377.975: [CMS-concurrent-mark-start] 2017-02-17T02:49:52.152+1100: 2378.193: [CMS-concurrent-mark: 0.218/0.218 secs] [Times: user=1.40 sys=0.00, real=0.22 secs] 2017-02-17T02:49:52.152+1100: 2378.193: [CMS-concurrent-preclean-start] 2017-02-17T02:49:52.158+1100: 2378.200: [CMS-concurrent-preclean: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:49:52.159+1100: 2378.200: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 2017-02-17T02:49:57.255+1100: 2383.297: [CMS-concurrent-abortable-preclean: 0.251/5.097 secs] [Times: user=5.46 sys=0.01, real=5.10 secs] 2017-02-17T02:49:57.257+1100: 2383.299: [GC (CMS Final Remark) [YG occupancy: 32717 K (131008 K)]2017-02-17T02:49:57.258+1100: 2383.299: [Rescan (parallel) , 0.0059087 secs]2017-02-17T02:49:57.263+1100: 2383.305: [weak refs processing, 0.0087868 secs]2017-02-17T02:49:57.272+1100: 2383.314: [class unloading, 0.0610022 secs]2017-02-17T02:49:57.333+1100: 2383.375: [scrub symbol table, 0.0349937 secs]2017-02-17T02:49:57.368+1100: 2383.410: [scrub string table, 0.0020473 secs][1 CMS-remark: 790678K(1966080K)] 823395K(2097088K), 0.1130339 secs] [Times: user=0.14 sys=0.00, real=0.12 secs] 2017-02-17T02:49:57.371+1100: 2383.412: [CMS-concurrent-sweep-start] 2017-02-17T02:49:57.643+1100: 2383.685: [CMS-concurrent-sweep: 0.272/0.272 secs] [Times: user=0.81 sys=0.01, real=0.27 secs] 2017-02-17T02:49:57.643+1100: 2383.685: [CMS-concurrent-reset-start] 2017-02-17T02:49:57.647+1100: 2383.688: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-02-17T02:50:11.909+1100: 2397.950: [GC (Allocation Failure) 2017-02-17T02:50:11.909+1100: 2397.950: [ParNew: 130944K->0K(131008K), 0.0080014 secs] 750096K->624619K(2097088K), 0.0083174 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 2017-02-17T02:50:31.913+1100: 2417.955: [GC (Allocation Failure) 2017-02-17T02:50:31.913+1100: 2417.955: [ParNew: 130944K->0K(131008K), 0.0055607 secs] 755563K->628586K(2097088K), 0.0058577 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 2017-02-17T02:50:51.903+1100: 2437.944: [GC (Allocation Failure) 2017-02-17T02:50:51.903+1100: 2437.945: [ParNew: 130944K->0K(131008K), 0.0069750 secs] 759530K->632225K(2097088K), 0.0074119 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-02-17T02:51:01.931+1100: 2447.972: [GC (Allocation Failure) 2017-02-17T02:51:01.931+1100: 2447.972: [ParNew: 130944K->0K(131008K), 0.0052841 secs] 763169K->637260K(2097088K), 0.0054611 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 2017-02-17T02:51:21.928+1100: 2467.969: [GC (Allocation Failure) 2017-02-17T02:51:21.928+1100: 2467.969: [ParNew: 130944K->0K(131008K), 0.0091373 secs] 768204K->640807K(2097088K), 0.0093986 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:51:41.936+1100: 2487.977: [GC (Allocation Failure) 2017-02-17T02:51:41.936+1100: 2487.977: [ParNew: 130152K->0K(131008K), 0.0099106 secs] 770959K->645792K(2097088K), 0.0101119 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-02-17T02:52:01.928+1100: 2507.970: [GC (Allocation Failure) 2017-02-17T02:52:01.928+1100: 2507.970: [ParNew: 130944K->0K(131008K), 0.0096195 secs] 776736K->650814K(2097088K), 0.0102844 secs] [Times: user=0.04 sys=0.00, real=0.00 secs] 2017-02-17T02:52:21.913+1100: 2527.955: [GC (Allocation Failure) 2017-02-17T02:52:21.913+1100: 2527.955: [ParNew: 130944K->0K(131008K), 0.0176493 secs] 781758K->656556K(2097088K), 0.0179549 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 2017-02-17T02:52:41.904+1100: 2547.945: [GC (Allocation Failure) 2017-02-17T02:52:41.904+1100: 2547.945: [ParNew: 130944K->0K(131008K), 0.0072279 secs] 787500K->660929K(2097088K), 0.0075509 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-02-17T02:52:52.300+1100: 2558.341: [GC (Allocation Failure) 2017-02-17T02:52:52.300+1100: 2558.341: [ParNew: 130944K->0K(131008K), 0.0064136 secs] 791873K->664124K(2097088K), 0.0065792 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] *[ignite logs]* 30064 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Failed to wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0], node=54047017-02fb-4885-8586-25799b9c382e]. Dumping pending objects that might be the cause: 30064 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Ready affinity version: AffinityTopologyVersion [topVer=-1, minorTopVer=0] 30071 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=3, nodeId8=54047017, msg=null, type=NODE_JOINED, tstamp=1487259925888], crd=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED], added=false, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1487259928142, endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true, topSnapshot=null, lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false, initTs=1487259928142, centralizedAff=false, evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b, 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52], sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2, intOrder=2, lastExchangeTime=1487259925667, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], super=GridFutureAdapter [resFlag=0, res=null, startTime=1487259928142, endTime=0, ignoreInterrupts=false, state=INIT]] 30071 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending exchange futures: 30072 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Last 10 exchange futures (total: 1): 30073 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=3, nodeId8=54047017, msg=null, type=NODE_JOINED, tstamp=1487259925888], crd=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED], added=false, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1487259928142, endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true, topSnapshot=null, lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false, initTs=1487259928142, centralizedAff=false, evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b, 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52], sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2, intOrder=2, lastExchangeTime=1487259925667, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], super=GridFutureAdapter [resFlag=0, res=null, startTime=1487259928142, endTime=0, ignoreInterrupts=false, state=INIT]] 30073 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending transactions: 30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending explicit locks: 30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending cache futures: 30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending atomic cache futures: 30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending data streamer futures: 30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending transaction deadlock detection futures: 30084 W o.a.i.s.c.tcp.TcpCommunicationSpi [exchange-worker-#24%webapp%] Communication SPI recovery descriptors: [key=ClientKey [nodeId=f931e110-ac37-43ba-b54a-faa79c9ac34b, order=1], msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272, lastAcked=272, reserveCnt=1, descIdHash=703751156] Communication SPI clients: [node=f931e110-ac37-43ba-b54a-faa79c9ac34b, client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl [selectorIdx=0, queueSize=0, writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], recovery=GridNioRecoveryDescriptor [acked=272, resendCnt=0, rcvCnt=272, sentCnt=272, reserved=true, lastAck=272, nodeLeft=false, node=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], connected=true, connectCnt=0, queueLimit=5120, reserveCnt=1], super=GridNioSessionImpl [locAddr=/192.168.0.53:47100, rmtAddr=/192.168.0.53:33596, createTime=1487259926038, closeTime=0, bytesSent=13367, bytesRcvd=1172506, sndSchedTime=1487259928672, lastSndTime=1487259928672, lastRcvTime=1487259928682, readsPaused=false, filterChain=FilterChain[filters=[GridNioCodecFilter [parser=o.a.i.i.util.nio.GridDirectParser@375e6c31, directMode=true], GridConnectionBytesVerifyFilter], accepted=true]], super=GridAbstractCommunicationClient [lastUsed=1487259926138, reserves=0]]] 30086 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-1-#10%webapp%] >> Selector info [idx=1, keysCnt=0] 30086 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-0-#9%webapp%] >> Selector info [idx=0, keysCnt=1] Connection info [rmtAddr=/192.168.0.53:33596, locAddr=/ 192.168.0.53:47100, msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272, descIdHash=703751156, bytesRcvd=1172506, bytesSent=13367, opQueueSize=0, msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0, stack=[StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], null, null, null, null, null, null]]], msgReader=DirectMessageReader [state=DirectMessageState [pos=0, stack=[StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527761936, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527761936, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527761936, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null, null, null, null, null, null, null]], lastRead=true]] 30086 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-2-#11%webapp%] >> Selector info [idx=2, keysCnt=0] 30086 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-3-#12%webapp%] >> Selector info [idx=3, keysCnt=0] 40086 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Failed to wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0], node=54047017-02fb-4885-8586-25799b9c382e]. Dumping pending objects that might be the cause: 40087 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Ready affinity version: AffinityTopologyVersion [topVer=-1, minorTopVer=0] 40088 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=3, nodeId8=54047017, msg=null, type=NODE_JOINED, tstamp=1487259925888], crd=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED], added=false, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1487259928142, endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true, topSnapshot=null, lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false, initTs=1487259928142, centralizedAff=false, evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b, 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52], sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2, intOrder=2, lastExchangeTime=1487259925667, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], super=GridFutureAdapter [resFlag=0, res=null, startTime=1487259928142, endTime=0, ignoreInterrupts=false, state=INIT]] 40088 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending exchange futures: 40088 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Last 10 exchange futures (total: 1): 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=3, nodeId8=54047017, msg=null, type=NODE_JOINED, tstamp=1487259925888], crd=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED], added=false, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1487259928142, endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true, topSnapshot=null, lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false, initTs=1487259928142, centralizedAff=false, evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b, 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52], sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2, intOrder=2, lastExchangeTime=1487259925667, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3, intOrder=3, lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], super=GridFutureAdapter [resFlag=0, res=null, startTime=1487259928142, endTime=0, ignoreInterrupts=false, state=INIT]] 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending transactions: 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending explicit locks: 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending cache futures: 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending atomic cache futures: 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending data streamer futures: 40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager [exchange-worker-#24%webapp%] Pending transaction deadlock detection futures: 40090 W o.a.i.s.c.tcp.TcpCommunicationSpi [exchange-worker-#24%webapp%] Communication SPI recovery descriptors: [key=ClientKey [nodeId=f931e110-ac37-43ba-b54a-faa79c9ac34b, order=1], msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272, lastAcked=272, reserveCnt=1, descIdHash=703751156] Communication SPI clients: [node=f931e110-ac37-43ba-b54a-faa79c9ac34b, client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl [selectorIdx=0, queueSize=0, writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], recovery=GridNioRecoveryDescriptor [acked=272, resendCnt=0, rcvCnt=272, sentCnt=272, reserved=true, lastAck=272, nodeLeft=false, node=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false, ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], connected=true, connectCnt=0, queueLimit=5120, reserveCnt=1], super=GridNioSessionImpl [locAddr=/192.168.0.53:47100, rmtAddr=/192.168.0.53:33596, createTime=1487259926038, closeTime=0, bytesSent=13367, bytesRcvd=1172506, sndSchedTime=1487259928672, lastSndTime=1487259928672, lastRcvTime=1487259928682, readsPaused=false, filterChain=FilterChain[filters=[GridNioCodecFilter [parser=o.a.i.i.util.nio.GridDirectParser@375e6c31, directMode=true], GridConnectionBytesVerifyFilter], accepted=true]], super=GridAbstractCommunicationClient [lastUsed=1487259926138, reserves=0]]] 40090 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-2-#11%webapp%] >> Selector info [idx=2, keysCnt=0] 40091 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-0-#9%webapp%] >> Selector info [idx=0, keysCnt=1] Connection info [rmtAddr=/192.168.0.53:33596, locAddr=/ 192.168.0.53:47100, msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272, descIdHash=703751156, bytesRcvd=1172506, bytesSent=13367, opQueueSize=0, msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0, stack=[StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527729152, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false], null, null, null, null, null, null]]], msgReader=DirectMessageReader [state=DirectMessageState [pos=0, stack=[StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527761936, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527761936, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem [stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], baseOff=140318527761936, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null, null, null, null, null, null, null]], lastRead=true]] 40091 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-1-#10%webapp%] >> Selector info [idx=1, keysCnt=0] 40091 W o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-3-#12%webapp%] >> Selector info [idx=3, keysCnt=0] On Thu, 16 Feb 2017 at 22:05 Andrey Mashenkov <andrey.mashen...@gmail.com> wrote: Hi Cameron, Ignite does not have 1.8.x versions. It look like you use IPv6 on some of you nodes. At first, check if either -Djava.net.preferIPv6Addresses=true or -Djava.net.preferIPv4Addresses=true java option is set for all of your nodes and communication port is set properly. On Thu, Feb 16, 2017 at 1:29 AM, Cameron Braid <came...@braid.com.au> wrote: > Hi, > > I am getting the following error in Ignite version 1.8.1 : > > "Failed to wait for partition release future" > > The related logs lines are at the bottom. > > I was curious if it could be related to > https://issues.apache.org/jira/browse/IGNITE-3212 which has fix for > version > 1.9. Could this be the case ? > > Otherwise, is this likely to be a bug in ignite, or something specific to > my environment? > > Cheers > > Cameron > > > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287661 WARN > o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture > [exchange-worker-#26%webapp%] Failed to wait for partition release > future > [topVer=AffinityTopologyVersion [topVer=21, minorTopVer=2], > node=79d74dfa-9903-42e3-af94-524ab08c1f97]. Dumping pending objects > that > might be the cause: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287661 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Ready affinity version: > AffinityTopologyVersion [topVer=21, minorTopVer=1] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287667 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Last exchange future: > GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, > reassign=false, discoEvt=DiscoveryCustomEvent > [customMsg=DynamicCacheChangeBatch [reqs=[DynamicCacheChangeRequest > [deploymentId=3f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9, > startCfg=CacheConfiguration [name=userTable.cmsDataVehicles.query, > storeConcurrentLoadAllThreshold=5, rebalancePoolSize=2, > rebalanceTimeout=10000, evictPlc=null, evictSync=false, > evictKeyBufSize=1024, evictSyncConcurrencyLvl=4, evictSyncTimeout=10000, > evictFilter=null, evictMaxOverflowRatio=10.0, eagerTtl=true, > dfltLockTimeout=0, startSize=1500000, nearCfg=null, > writeSync=PRIMARY_SYNC, > storeFactory=null, storeKeepBinary=false, loadPrevVal=false, > aff=o.a.i.cache.affinity.rendezvous.RendezvousAffinityFunction@7e1c4f4, > cacheMode=REPLICATED, atomicityMode=ATOMIC, > atomicWriteOrderMode=PRIMARY, > backups=2147483647 <(214)%20748-3647>, invalidate=false, tmLookupClsName=null, > rebalanceMode=ASYNC, rebalanceOrder=0, rebalanceBatchSize=524288, > rebalanceBatchesPrefetchCount=2, offHeapMaxMem=-1, swapEnabled=false, > maxConcurrentAsyncOps=500, writeBehindEnabled=false, > writeBehindFlushSize=10240, writeBehindFlushFreq=5000, > writeBehindFlushThreadCnt=1, writeBehindBatchSize=512, > maxQryIterCnt=1024, > memMode=ONHEAP_TIERED, > affMapper=o.a.i.i.processors.cache.CacheDefaultBinaryAffinityKeyM > apper@6ca896dd, > rebalanceDelay=0, rebalanceThrottle=0, interceptor=null, > longQryWarnTimeout=3000, qryDetailMetricsSz=0, readFromBackup=true, > nodeFilter=o.a.i.configuration.CacheConfiguration$ > IgniteAllNodesPredicate@db2015b, > sqlSchema=null, sqlEscapeAll=false, sqlOnheapRowCacheSize=10240, > snapshotableIdx=false, cpOnRead=true, topValidator=null], > cacheType=USER, > initiatingNodeId=79d74dfa-9903-42e3-af94-524ab08c1f97, > nearCacheCfg=null, > clientStartOnly=false, stop=false, close=false, failIfExists=true, > template=false, rcvdFrom=null, exchangeNeeded=true, cacheFutTopVer=null, > cacheName=userTable.cmsDataVehicles.query]], clientNodes=null, > id=4f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9, > clientReconnect=false], affTopVer=AffinityTopologyVersion [topVer=21, > minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode > [id=79d74dfa-9903-42e3-af94-524ab08c1f97, addrs=[0:0:0:0:0:0:0:1%lo, > 10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=21, > intOrder=12, lastExchangeTime=1487193806549, loc=true, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=21, > nodeId8=79d74dfa, msg=null, type=DISCOVERY_CUSTOM_EVT, > tstamp=1487193798024]], crd=TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion > [topVer=21, minorTopVer=2], nodeId=79d74dfa, evt=DISCOVERY_CUSTOM_EVT], > added=true, initFut=GridFutureAdapter [resFlag=0, res=null, > startTime=1487193798024, endTime=0, ignoreInterrupts=false, state=INIT], > init=false, topSnapshot=null, lastVer=null, > partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=3, > done=false, cancelled=false, err=null, futs=[true, true, false, true]], > affChangeMsg=null, skipPreload=false, clientOnlyExchange=false, > initTs=1487193798024, centralizedAff=false, evtLatch=0, > remaining=[0940d968-a901-4c78-8354-8171628d41aa, > 659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=0940d968-a901-4c78-8354-8171628d41aa, addrs=[0:0:0:0:0:0:0:1%lo, > 10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=20, > intOrder=11, lastExchangeTime=1487178534516, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=79d74dfa-9903-42e3-af94-524ab08c1f97, addrs=[0:0:0:0:0:0:0:1%lo, > 10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=21, > intOrder=12, lastExchangeTime=1487193806549, loc=true, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], > super=GridFutureAdapter > [resFlag=0, res=null, startTime=1487193798024, endTime=0, > ignoreInterrupts=false, state=INIT]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287667 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending exchange futures: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287668 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Last 10 exchange futures (total: 3): > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287668 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] >>> GridDhtPartitionsExchangeFuture > [dummy=false, forcePreload=false, reassign=false, > discoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch > [reqs=[DynamicCacheChangeRequest > [deploymentId=3f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9, > startCfg=CacheConfiguration [name=userTable.cmsDataVehicles.query, > storeConcurrentLoadAllThreshold=5, rebalancePoolSize=2, > rebalanceTimeout=10000, evictPlc=null, evictSync=false, > evictKeyBufSize=1024, evictSyncConcurrencyLvl=4, evictSyncTimeout=10000, > evictFilter=null, evictMaxOverflowRatio=10.0, eagerTtl=true, > dfltLockTimeout=0, startSize=1500000, nearCfg=null, > writeSync=PRIMARY_SYNC, > storeFactory=null, storeKeepBinary=false, loadPrevVal=false, > aff=o.a.i.cache.affinity.rendezvous.RendezvousAffinityFunction@7e1c4f4, > cacheMode=REPLICATED, atomicityMode=ATOMIC, > atomicWriteOrderMode=PRIMARY, > backups=2147483647 <(214)%20748-3647>, invalidate=false, tmLookupClsName=null, > rebalanceMode=ASYNC, rebalanceOrder=0, rebalanceBatchSize=524288, > rebalanceBatchesPrefetchCount=2, offHeapMaxMem=-1, swapEnabled=false, > maxConcurrentAsyncOps=500, writeBehindEnabled=false, > writeBehindFlushSize=10240, writeBehindFlushFreq=5000, > writeBehindFlushThreadCnt=1, writeBehindBatchSize=512, > maxQryIterCnt=1024, > memMode=ONHEAP_TIERED, > affMapper=o.a.i.i.processors.cache.CacheDefaultBinaryAffinityKeyM > apper@6ca896dd, > rebalanceDelay=0, rebalanceThrottle=0, interceptor=null, > longQryWarnTimeout=3000, qryDetailMetricsSz=0, readFromBackup=true, > nodeFilter=o.a.i.configuration.CacheConfiguration$ > IgniteAllNodesPredicate@db2015b, > sqlSchema=null, sqlEscapeAll=false, sqlOnheapRowCacheSize=10240, > snapshotableIdx=false, cpOnRead=true, topValidator=null], > cacheType=USER, > initiatingNodeId=79d74dfa-9903-42e3-af94-524ab08c1f97, > nearCacheCfg=null, > clientStartOnly=false, stop=false, close=false, failIfExists=true, > template=false, rcvdFrom=null, exchangeNeeded=true, cacheFutTopVer=null, > cacheName=userTable.cmsDataVehicles.query]], clientNodes=null, > id=4f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9, > clientReconnect=false], affTopVer=AffinityTopologyVersion [topVer=21, > minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode > [id=79d74dfa-9903-42e3-af94-524ab08c1f97, addrs=[0:0:0:0:0:0:0:1%lo, > 10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=21, > intOrder=12, lastExchangeTime=1487193806549, loc=true, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=21, > nodeId8=79d74dfa, msg=null, type=DISCOVERY_CUSTOM_EVT, > tstamp=1487193798024]], crd=TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion > [topVer=21, minorTopVer=2], nodeId=79d74dfa, evt=DISCOVERY_CUSTOM_EVT], > added=true, initFut=GridFutureAdapter [resFlag=0, res=null, > startTime=1487193798024, endTime=0, ignoreInterrupts=false, state=INIT], > init=false, topSnapshot=null, lastVer=null, > partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=3, > done=false, cancelled=false, err=null, futs=[true, true, false, true]], > affChangeMsg=null, skipPreload=false, clientOnlyExchange=false, > initTs=1487193798024, centralizedAff=false, evtLatch=0, > remaining=[0940d968-a901-4c78-8354-8171628d41aa, > 659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=0940d968-a901-4c78-8354-8171628d41aa, addrs=[0:0:0:0:0:0:0:1%lo, > 10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=20, > intOrder=11, lastExchangeTime=1487178534516, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=79d74dfa-9903-42e3-af94-524ab08c1f97, addrs=[0:0:0:0:0:0:0:1%lo, > 10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=21, > intOrder=12, lastExchangeTime=1487193806549, loc=true, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], > super=GridFutureAdapter > [resFlag=0, res=null, startTime=1487193798024, endTime=0, > ignoreInterrupts=false, state=INIT]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287669 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] >>> GridDhtPartitionsExchangeFuture > [dummy=false, forcePreload=false, reassign=false, > discoEvt=DiscoveryCustomEvent [customMsg=null, > affTopVer=AffinityTopologyVersion [topVer=21, minorTopVer=1], > super=DiscoveryEvent [evtNode=TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=21, > nodeId8=79d74dfa, msg=null, type=DISCOVERY_CUSTOM_EVT, > tstamp=1487178539604]], crd=TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion > [topVer=21, minorTopVer=1], nodeId=659ea029, evt=DISCOVERY_CUSTOM_EVT], > added=true, initFut=GridFutureAdapter [resFlag=2, res=true, > startTime=1487178539604, endTime=1487178539762, ignoreInterrupts=false, > state=DONE], init=true, topSnapshot=null, lastVer=null, > partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=4, > done=true, cancelled=false, err=null, futs=[true, true, true, true]], > affChangeMsg=CacheAffinityChangeMessage > [id=426bdb24a51-0943897a-92a2-454f-8ce0-2cfc43f893df, > topVer=AffinityTopologyVersion [topVer=21, minorTopVer=0], exchId=null, > partsMsg=null, exchangeNeeded=true], skipPreload=false, > clientOnlyExchange=false, initTs=1487178539604, centralizedAff=false, > evtLatch=0, remaining=[0940d968-a901-4c78-8354-8171628d41aa, > 659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=0940d968-a901-4c78-8354-8171628d41aa, addrs=[0:0:0:0:0:0:0:1%lo, > 10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=20, > intOrder=11, lastExchangeTime=1487178534516, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=79d74dfa-9903-42e3-af94-524ab08c1f97, addrs=[0:0:0:0:0:0:0:1%lo, > 10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=21, > intOrder=12, lastExchangeTime=1487193806549, loc=true, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], > super=GridFutureAdapter > [resFlag=2, res=AffinityTopologyVersion [topVer=21, minorTopVer=1], > startTime=1487178539604, endTime=1487178540040, ignoreInterrupts=false, > state=DONE]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287670 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] >>> GridDhtPartitionsExchangeFuture > [dummy=false, forcePreload=false, reassign=false, > discoEvt=DiscoveryEvent > [evtNode=TcpDiscoveryNode [id=79d74dfa-9903-42e3-af94-524ab08c1f97, > addrs=[0:0:0:0:0:0:0:1%lo, 10.130.1.43, 127.0.0.1], > sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, > /127.0.0.1:47500], discPort=47500, order=21, intOrder=12, > lastExchangeTime=1487193806549, loc=true, ver=1.8.1#20161208-sha1: > a8fcb7b2, > isClient=false], topVer=21, nodeId8=79d74dfa, msg=null, > type=NODE_JOINED, > tstamp=1487178534607], crd=TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion > [topVer=21, minorTopVer=0], nodeId=79d74dfa, evt=NODE_JOINED], > added=false, > initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1487178535485, > endTime=1487178535753, ignoreInterrupts=false, state=DONE], init=true, > topSnapshot=null, lastVer=null, partReleaseFut=GridCompoundFuture > [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, > err=null, > futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false, > clientOnlyExchange=false, initTs=1487178535485, centralizedAff=false, > evtLatch=0, remaining=[0940d968-a901-4c78-8354-8171628d41aa, > 659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=0940d968-a901-4c78-8354-8171628d41aa, addrs=[0:0:0:0:0:0:0:1%lo, > 10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=20, > intOrder=11, lastExchangeTime=1487178534516, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode > [id=79d74dfa-9903-42e3-af94-524ab08c1f97, addrs=[0:0:0:0:0:0:0:1%lo, > 10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/10.130.1.43:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=21, > intOrder=12, lastExchangeTime=1487193806549, loc=true, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]], > super=GridFutureAdapter > [resFlag=2, res=AffinityTopologyVersion [topVer=21, minorTopVer=0], > startTime=1487178535485, endTime=1487178536184, ignoreInterrupts=false, > state=DONE]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287670 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending transactions: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287670 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending explicit locks: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287670 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending cache futures: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287670 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending atomic cache futures: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287671 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] >>> GridDhtAtomicSingleUpdateFuture > [key=KeyCacheObjectImpl [val=97B561DF-9EE8-6605-171B-B2404DDABCDA, > hasValBytes=true], nearReaderEntry=null] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287671 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] >>> GridDhtAtomicSingleUpdateFuture > [key=KeyCacheObjectImpl [val=97B561DF-9EE8-6605-171B-B2404DDABCDA, > hasValBytes=true], nearReaderEntry=null] > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287671 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending data streamer futures: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287671 WARN > o.a.i.i.p.c.GridCachePartitionExchangeManager > [exchange-worker-#26%webapp%] Pending transaction deadlock detection > futures: > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287675 WARN > o.a.i.s.c.tcp.TcpCommunicationSpi [exchange-worker-#26%webapp%] > Communication SPI recovery descriptors: > - Feb 16 08:23:28 webapp-92-50ik3 webapp [key=ClientKey > [nodeId=0940d968-a901-4c78-8354-8171628d41aa, order=20], > msgsSent=308295, > msgsAckedByRmt=308288, msgsRcvd=286268, lastAcked=286267, reserveCnt=1, > descIdHash=791992180] > - Feb 16 08:23:28 webapp-92-50ik3 webapp [key=ClientKey > [nodeId=659ea029-ca80-4413-af47-67b446ffd3e7, order=18], > msgsSent=329991, > msgsAckedByRmt=329984, msgsRcvd=346386, lastAcked=346385, reserveCnt=1, > descIdHash=2140218415] > - Feb 16 08:23:28 webapp-92-50ik3 webapp Communication SPI clients: > - Feb 16 08:23:28 webapp-92-50ik3 webapp > [node=659ea029-ca80-4413-af47-67b446ffd3e7, > client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl > [selectorIdx=0, queueSize=0, writeBuf=java.nio.DirectByteBuffer[pos=0 > lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 > cap=32768], recovery=GridNioRecoveryDescriptor [acked=329984, > resendCnt=0, > rcvCnt=346386, sentCnt=329991, reserved=true, lastAck=346385, > nodeLeft=false, node=TcpDiscoveryNode > [id=659ea029-ca80-4413-af47-67b446ffd3e7, addrs=[0:0:0:0:0:0:0:1%lo, > 10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, / > 127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18, > intOrder=10, lastExchangeTime=1487178534506, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], connected=true, > connectCnt=0, queueLimit=5120, reserveCnt=1], super=GridNioSessionImpl > [locAddr=/10.130.1.43:47100, rmtAddr=/10.128.1.11:51314, > createTime=1487178534627, closeTime=0, bytesSent=344557012, > bytesRcvd=620151134, sndSchedTime=1487193802122, > lastSndTime=1487193803605, > lastRcvTime=1487193806891, readsPaused=false, > filterChain=FilterChain[filters=[GridNioCodecFilter > [parser=o.a.i.i.util.nio.GridDirectParser@69c438c, directMode=true], > GridConnectionBytesVerifyFilter], accepted=true]], > super=GridAbstractCommunicationClient [lastUsed=1487178534637, > reserves=0]]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp > [node=0940d968-a901-4c78-8354-8171628d41aa, > client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl > [selectorIdx=1, queueSize=0, writeBuf=java.nio.DirectByteBuffer[pos=0 > lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 > cap=32768], recovery=GridNioRecoveryDescriptor [acked=308288, > resendCnt=0, > rcvCnt=286268, sentCnt=308295, reserved=true, lastAck=286267, > nodeLeft=false, node=TcpDiscoveryNode > [id=0940d968-a901-4c78-8354-8171628d41aa, addrs=[0:0:0:0:0:0:0:1%lo, > 10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500, > /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=20, > intOrder=11, lastExchangeTime=1487178534516, loc=false, > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], connected=true, > connectCnt=0, queueLimit=5120, reserveCnt=1], super=GridNioSessionImpl > [locAddr=/10.130.1.43:47100, rmtAddr=/10.129.1.129:53754, > createTime=1487178536131, closeTime=0, bytesSent=325615325, > bytesRcvd=362872151, sndSchedTime=1487193805754, > lastSndTime=1487193805754, > lastRcvTime=1487193807968, readsPaused=false, > filterChain=FilterChain[filters=[GridNioCodecFilter > [parser=o.a.i.i.util.nio.GridDirectParser@69c438c, directMode=true], > GridConnectionBytesVerifyFilter], accepted=true]], > super=GridAbstractCommunicationClient [lastUsed=1487178536131, > reserves=0]]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287676 WARN > o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-2-#12%webapp%] > - Feb 16 08:23:28 webapp-92-50ik3 webapp >> Selector info [idx=2, > keysCnt=0] > - Feb 16 08:23:28 webapp-92-50ik3 webapp > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287676 WARN > o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-3-#13%webapp%] > - Feb 16 08:23:28 webapp-92-50ik3 webapp >> Selector info [idx=3, > keysCnt=0] > - Feb 16 08:23:28 webapp-92-50ik3 webapp > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287678 WARN > o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-0-#10%webapp%] > - Feb 16 08:23:28 webapp-92-50ik3 webapp >> Selector info [idx=0, > keysCnt=1] > - Feb 16 08:23:28 webapp-92-50ik3 webapp Connection info [rmtAddr=/ > 10.128.1.11:51314, locAddr=/10.130.1.43:47100, msgsSent=329991, > msgsAckedByRmt=329984, msgsRcvd=346386, descIdHash=2140218415, > bytesRcvd=620151134, bytesSent=344557012, opQueueSize=0, > msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0, > stack=[StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396325296, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396325296, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396325296, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396325296, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396325296, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396325296, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > null, null, null, null]]], msgReader=DirectMessageReader > [state=DirectMessageState [pos=0, stack=[StateItem > [stream=DirectByteBufferStreamImplV2 [buf=java.nio. > DirectByteBuffer[pos=0 > lim=32768 cap=32768], baseOff=140713396358080, arrOff=-1, tmpArrOff=0, > tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, > arrPos=-1, > keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, > uuidState=0, > uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396358080, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem > [stream=DirectByteBufferStreamImplV2 [buf=java.nio. > DirectByteBuffer[pos=0 > lim=32768 cap=32768], baseOff=140713396358080, arrOff=-1, tmpArrOff=0, > tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, > arrPos=-1, > keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, > uuidState=0, > uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713396358080, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem > [stream=DirectByteBufferStreamImplV2 [buf=java.nio. > DirectByteBuffer[pos=0 > lim=32768 cap=32768], baseOff=140713396358080, arrOff=-1, tmpArrOff=0, > tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, > arrPos=-1, > keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, > uuidState=0, > uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], > null, > null, null, null, null]], lastRead=true]] > - Feb 16 08:23:28 webapp-92-50ik3 webapp > - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287678 WARN > o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-1-#11%webapp%] > - Feb 16 08:23:28 webapp-92-50ik3 webapp >> Selector info [idx=1, > keysCnt=1] > - Feb 16 08:23:28 webapp-92-50ik3 webapp Connection info [rmtAddr=/ > 10.129.1.129:53754, locAddr=/10.130.1.43:47100, msgsSent=308295, > msgsAckedByRmt=308288, msgsRcvd=286268, descIdHash=791992180, > bytesRcvd=362872151, bytesSent=325615325, opQueueSize=0, > msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0, > stack=[StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463385408, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463385408, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463385408, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463385408, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463385408, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463385408, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, > hdrWritten=false], > null, null, null, null]]], msgReader=DirectMessageReader > [state=DirectMessageState [pos=0, stack=[StateItem > [stream=DirectByteBufferStreamImplV2 [buf=java.nio. > DirectByteBuffer[pos=0 > lim=32768 cap=32768], baseOff=140713463418192, arrOff=-1, tmpArrOff=0, > tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, > arrPos=-1, > keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, > uuidState=0, > uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463418192, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem > [stream=DirectByteBufferStreamImplV2 [buf=java.nio. > DirectByteBuffer[pos=0 > lim=32768 cap=32768], baseOff=140713463418192, arrOff=-1, tmpArrOff=0, > tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, > arrPos=-1, > keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, > uuidState=0, > uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], > StateItem [stream=DirectByteBufferStreamImplV2 > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], > baseOff=140713463418192, arrOff=-1, tmpArrOff=0, tmpArrBytes=0, > msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, > keyDone=false, > readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0, > uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem > [stream=DirectByteBufferStreamImplV2 [buf=java.nio. > DirectByteBuffer[pos=0 > lim=32768 cap=32768], baseOff=140713463418192, arrOff=-1, tmpArrOff=0, > tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, > arrPos=-1, > keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, > uuidState=0, > uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], > null, > null, null, null, null]], lastRead=true]] > -- Best regards, Andrey V. Mashenkov
