We are running an openfire server with hazelcast plugin for clustering. Sometimes the client IP shows as null or Invalid session/connection in the XMPP Console, as shown in the image and when this is shown the clients get disconnected, and are never able to reconnect
The warn.log file shows:
2016.10.05 23:45:36 org.jivesoftware.openfire.nio.ConnectionHandler - Closing connection due to exception in session: (0x0002298E: nio socket, server, null => 0.0.0.0/0.0.0.0:5222) org.apache.mina.filter.codec.ProtocolDecoderException: org.jivesoftware.openfire.nio.XMLNotWellFormedException: Character is invalid in: ^V (Hexdump: 16 03 03 00 96 10 00 00 92 91 04 01 AC EF A4 1F 6D 28 E6 B0 99 33 B2 D6 87 2C 1B B1 DF 77 1E 1D D7 FB E5 47 7D 04 8A 5E B8 77 59 FA 31 80 68 BA C0 8C C8 A9 7E A0 7D 74 2D 68 EF E0 B1 35 32 05 1D EA 97 2B 27 CB A9 D8 38 6F C0 59 0C B4 AB AC 33 90 09 05 38 18 97 EC 6F 97 1E 7B 09 56 FD A8 CC B3 2B 15 CA 22 9B 8E 02 84 25 9F E7 90 72 2A 7D 84 12 10 4C 58 21 10 E6 C3 77 03 79 F0 4D 7C 7C 15 4C BD AD 24 72 7D B7 CD AD 53 4B 2F BF 3F AD E7 F0 D5 A4 2C 55 36 84 D0 74 14 03 03 00 01 01 16 03 03 00 40 95 06 24 78 2F 4A 9C 0D 92 22 EB 32 2A 03 13 35 4A 5A E6 44 2B 31 D7 48 99 4A BC AF 32 BE F5 D3 22 09 92 E2 1C 9E 14 EA 3D 76 93 31 D8 45 A1 D8 FB 46 E2 BD C6 42 59 E4 5B C2 24 73 77 01 DA 95) at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:242) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(D efaultIoFilterChain.java:417) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilt erChain.java:47) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceiv ed(DefaultIoFilterChain.java:765) at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:74) at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(Ordere dThreadPoolExecutor.java:769) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Order edThreadPoolExecutor.java:761) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThr eadPoolExecutor.java:703) at java.lang.Thread.run(Thread.java:745) Caused by: org.jivesoftware.openfire.nio.XMLNotWellFormedException: Character is invalid in: ^V at org.jivesoftware.openfire.nio.XMLLightweightParser.read(XMLLightweightParser.ja va:223) at org.jivesoftware.openfire.nio.XMPPDecoder.doDecode(XMPPDecoder.java:41) at org.apache.mina.filter.codec.CumulativeProtocolDecoder.decode(CumulativeProtoco lDecoder.java:176) at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:232) … 9 more
2016.10.05 23:46:51 com.hazelcast.nio.tcp.ReadHandler - [172.31.29.146]:5701 [openfire] [3.5.1] hz.openfire.IO.thread-in-0 Closing socket to endpoint Address[172.31.20.168]:5701, Cause:java.io.EOFException: Remote socket closed! 2016.10.05 23:46:52 com.hazelcast.nio.tcp.TcpIpConnectionMonitor - [172.31.29.146]:5701 [openfire] [3.5.1] Removing connection to endpoint Address[172.31.20.168]:5701 Cause => java.net.SocketException {Connection refused to address /172.31.20.168:5701}, Error-Count: 5 2016.10.05 23:46:57 com.hazelcast.nio.tcp.ReadHandler - [172.31.29.146]:5701 [openfire] [3.5.1] hz.openfire.IO.thread-in-1 Closing socket to endpoint Address[172.31.29.47]:5701, Cause:java.io.EOFException: Remote socket closed! 2016.10.05 23:46:58 com.hazelcast.nio.tcp.TcpIpConnectionMonitor - [172.31.29.146]:5701 [openfire] [3.5.1] Removing connection to endpoint Address[172.31.29.47]:5701 Cause => java.net.SocketException {Connection refused to address /172.31.29.47:5701}, Error-Count: 5 2016.10.05 23:46:59 com.hazelcast.map.impl.BasicMapContextQuerySupport - [172.31.29.146]:5701 [openfire] [3.5.1] Could not get results java.util.concurrent.ExecutionException: com.hazelcast.spi.exception.TargetNotMemberException: Not Member! target:Address[172.31.29.47]:5701, partitionId: -1, operation: com.hazelcast.map.impl.operation.QueryOperation, service: hz:impl:mapService at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolveApplicatio nResponseOrThrowException(InvocationFuture.java:357) at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.get(InvocationFut ure.java:225) at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.get(InvocationFut ure.java:204) at com.hazelcast.map.impl.BasicMapContextQuerySupport.addResultsOfPredicate(BasicM apContextQuerySupport.java:350) at com.hazelcast.map.impl.BasicMapContextQuerySupport.query(BasicMapContextQuerySu pport.java:249) at com.hazelcast.map.impl.proxy.MapProxySupport.query(MapProxySupport.java:1136) at com.hazelcast.map.impl.proxy.MapProxyImpl.entrySet(MapProxyImpl.java:575) at com.hazelcast.map.impl.proxy.MapProxyImpl.entrySet(MapProxyImpl.java:560) at org.jivesoftware.openfire.plugin.util.cache.ClusteredCache.entrySet(ClusteredCa che.java:117) at org.jivesoftware.util.cache.CacheWrapper.entrySet(CacheWrapper.java:130) at org.jivesoftware.openfire.spi.RoutingTableImpl.leftCluster(RoutingTableImpl.jav a:1065) at org.jivesoftware.openfire.cluster.ClusterManager$2.run(ClusterManager.java:118) Caused by: com.hazelcast.spi.exception.TargetNotMemberException: Not Member! target:Address[172.31.29.47]:5701, partitionId: -1, operation: com.hazelcast.map.impl.operation.QueryOperation, service: hz:impl:mapService at com.hazelcast.spi.impl.operationservice.impl.Invocation.initInvocationTarget(In vocation.java:298) at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.jav a:222) at com.hazelcast.spi.impl.operationservice.impl.Invocation.run(Invocation.java:262 ) at com.hazelcast.spi.impl.operationservice.impl.TargetInvocation.run(TargetInvocat ion.java:29) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedT hread.java:76) at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.j ava:92) at ------ End remote and begin local stack-trace ------.(Unknown Source) at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolveApplicatio nResponse(InvocationFuture.java:384) at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolveApplicatio nResponseOrThrowException(InvocationFuture.java:334) … 11 more
2016.10.05 23:47:01 com.hazelcast.spi.EventService - [172.31.29.146]:5701 [openfire] [3.5.1] Error while logging processing event java.lang.NullPointerException at org.jivesoftware.util.StringUtils.getBytes(StringUtils.java:1098) at org.jivesoftware.openfire.plugin.util.cache.CacheListener.handleEntryEvent(Cach eListener.java:68) at org.jivesoftware.openfire.plugin.util.cache.CacheListener.entryRemoved(CacheLis tener.java:60) at com.hazelcast.map.impl.MapListenerAdaptors$2$1.onEvent(MapListenerAdaptors.java :83) at com.hazelcast.map.impl.InternalMapListenerAdapter.onEvent(InternalMapListenerAd apter.java:51) at com.hazelcast.map.impl.MapEventPublishingService.callListener(MapEventPublishin gService.java:90) at com.hazelcast.map.impl.MapEventPublishingService.dispatchEntryEventData(MapEven tPublishingService.java:102) at com.hazelcast.map.impl.MapEventPublishingService.dispatchEvent(MapEventPublishi ngService.java:46) at com.hazelcast.map.impl.MapEventPublishingService.dispatchEvent(MapEventPublishi ngService.java:33) at com.hazelcast.map.impl.MapService.dispatchEvent(MapService.java:91) at com.hazelcast.map.impl.MapService.dispatchEvent(MapService.java:61) at com.hazelcast.spi.impl.eventservice.impl.EventPacketProcessor.process(EventPack etProcessor.java:53) at com.hazelcast.spi.impl.eventservice.impl.RemoteEventPacketProcessor.run(RemoteE ventPacketProcessor.java:38) at com.hazelcast.util.executor.StripedExecutor$Worker.process(StripedExecutor.java :190) at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:174 )
The error.log shows
2016.10.05 23:47:13 org.jivesoftware.openfire.SessionManager - Could not close socket com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active! at com.hazelcast.spi.AbstractDistributedObject.getService(AbstractDistributedObjec t.java:93) at com.hazelcast.map.impl.proxy.MapProxySupport.toData(MapProxySupport.java:1122) at com.hazelcast.map.impl.proxy.MapProxyImpl.remove(MapProxyImpl.java:178) at org.jivesoftware.openfire.plugin.util.cache.ClusteredCache.remove(ClusteredCach e.java:96) at org.jivesoftware.util.cache.CacheWrapper.remove(CacheWrapper.java:145) at org.jivesoftware.openfire.spi.RoutingTableImpl.removeClientRoute(RoutingTableIm pl.java:903) at org.jivesoftware.openfire.SessionManager.removeSession(SessionManager.java:1234 ) at org.jivesoftware.openfire.SessionManager.removeSession(SessionManager.java:1206 ) at org.jivesoftware.openfire.SessionManager$ClientSessionListener.onConnectionClos e(SessionManager.java:1409) at org.jivesoftware.openfire.nio.NIOConnection.notifyCloseListeners(NIOConnection. java:260) at org.jivesoftware.openfire.nio.NIOConnection.close(NIOConnection.java:242) at org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHandl er.java:161) at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.exceptionCaugh t(DefaultIoFilterChain.java:672) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextExceptionCaught(D efaultIoFilterChain.java:461) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1100(DefaultIoFilt erChain.java:47) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.exceptionCaug ht(DefaultIoFilterChain.java:760) at org.apache.mina.core.filterchain.IoFilterAdapter.exceptionCaught(IoFilterAdapte r.java:102) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextExceptionCaught(D efaultIoFilterChain.java:461) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1100(DefaultIoFilt erChain.java:47) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.exceptionCaug ht(DefaultIoFilterChain.java:760) at org.apache.mina.core.filterchain.IoFilterAdapter.exceptionCaught(IoFilterAdapte r.java:102) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextExceptionCaught(D efaultIoFilterChain.java:461) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1100(DefaultIoFilt erChain.java:47) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.exceptionCaug ht(DefaultIoFilterChain.java:760) at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:93) at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(Ordere dThreadPoolExecutor.java:769) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Order edThreadPoolExecutor.java:761) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThr eadPoolExecutor.java:703) at java.lang.Thread.run(Thread.java:745) 2016.10.05 23:47:13 org.jivesoftware.openfire.nio.ConnectionHandler - Closing connection due to error while processing message: dXNlcm5hbWU9Ijk2NjUwNDgxMTkxOCIscmVhbG09InhtcHAuc2F5ZmVhcHAuY29tIixjbm9uY2U9ImY 2MmM2OWMxOGU4ZWEzM2Y5NmRhY2I0ODU4YzhiNTQwNWU0ZDRiMzVmM2U4NWNmNjk0OGJmNWE5M2Q0MDA zNmIiLG5jPTAwMDAwMDAxLHFvcD1hdXRoLGRpZ2VzdC11cmk9InhtcHAveG1wcC5zYXlmZWFwcC5jb20 iLHJlc3BvbnNlPTY3ODQ0MDM0ZjA5ZDc4YzQyODFmN2E1YzhmMGMyNDFhLGNoYXJzZXQ9dXRmLTgsbm9 uY2U9IlpCME1CUVBwNFZsT2RxTWhIZTQwcWIxTHh4b1NoNkZwRDhRaXZKUm4i com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active! at com.hazelcast.spi.AbstractDistributedObject.getService(AbstractDistributedObjec t.java:93) at com.hazelcast.map.impl.proxy.MapProxySupport.toData(MapProxySupport.java:1122) at com.hazelcast.map.impl.proxy.MapProxyImpl.get(MapProxyImpl.java:81) at org.jivesoftware.openfire.plugin.util.cache.ClusteredCache.get(ClusteredCache.j ava:92) at org.jivesoftware.util.cache.CacheWrapper.get(CacheWrapper.java:140) at org.jivesoftware.openfire.lockout.LockOutManager.getUserLockOut(LockOutManager. java:244) at org.jivesoftware.openfire.lockout.LockOutManager.getDisabledStatus(LockOutManag er.java:152) at org.jivesoftware.openfire.lockout.LockOutManager.isAccountDisabled(LockOutManag er.java:163) at org.jivesoftware.openfire.net.SASLAuthentication.authenticationSuccessful(SASLA uthentication.java:682) at org.jivesoftware.openfire.net.SASLAuthentication.handle(SASLAuthentication.java :357) at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:191) at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:180) at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceive d(DefaultIoFilterChain.java:690) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(D efaultIoFilterChain.java:417) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilt erChain.java:47) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceiv ed(DefaultIoFilterChain.java:765) at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapte r.java:109)
Kindly help me with this. Thanks!
Regards,
Iqbal