AnsweredAssumed Answered

Invalid session/connection in Openfire

Question asked by Iqbal on Oct 6, 2016

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

 

Screen Shot 2016-10-06 at 12.54.11 PM.png

 

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

Outcomes