Random Disconnect and Long Reconnects

Jason_Morton · July 30, 2008, 6:16pm

Platform: Mac Mini

Openfire Version: 3.5.2

Active Directory Authentacation

java version "1.5.0_13"
Java™ 2 Runtime Environment, Standard Edition (build 1.5.0_13-b05-241)
Java HotSpot™ Server VM (build 1.5.0_13-121, mixed mode)

We are seeing many errors in the error log file.

EXAMPLE #1:

2008.07.30 09:05:38 [org.jivesoftware.openfire.handler.IQvCardHandler.handleIQ(IQvCardHandler.java: 92)]
java.lang.UnsupportedOperationException: LdapVCardProvider: Invalid vcard changes.
at org.jivesoftware.openfire.ldap.LdapVCardProvider.updateVCard(LdapVCardProvider. java:324)
at org.jivesoftware.openfire.vcard.VCardManager.setVCard(VCardManager.java:133)
at org.jivesoftware.openfire.handler.IQvCardHandler.handleIQ(IQvCardHandler.java:8 3)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:49)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:349)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:101)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:68)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:311)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler .java:79)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:276)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:175)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:133)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:58)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:185)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :239)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.java:283)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:613)

EXAMPLE #2:

2008.07.30 00:01:33 [org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSes sion(LocalOutgoingServerSession.java:259)] Error trying to connect to remote server: tbeck(DNS
lookup: tbeck:5269)
java.net.UnknownHostException: tbeck
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:177)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:430)
at java.net.Socket.connect(Socket.java:520)
at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSess ion(LocalOutgoingServerSession.java:254)
at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain (LocalOutgoingServerSession.java:144)
at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.sendPa cket(OutgoingSessionPromise.java:215)
at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(Ou tgoingSessionPromise.java:194)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:613)
2008.07.30 00:02:15 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:110)]
java.lang.ArrayIndexOutOfBoundsException
2008.07.30 00:02:18 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:110)]
java.lang.ArrayIndexOutOfBoundsException
2008.07.30 00:03:06 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:110)]
java.lang.ArrayIndexOutOfBoundsException
2008.07.30 00:03:07 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:110)]
java.lang.ArrayIndexOutOfBoundsException
2008.07.30 00:03:09 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:110)]
java.lang.ArrayIndexOutOfBoundsException
2008.07.30 00:03:15 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:110)]
java.lang.ArrayIndexOutOfBoundsException

EXAMPLE #3:

[org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:69)] Internal server error
java.lang.IllegalArgumentException: IQ must be of type ‘set’ or ‘get’. Original IQ:
at org.xmpp.packet.IQ.createResultIQ(IQ.java:355)
at org.jivesoftware.openfire.disco.IQDiscoInfoHandler.handleIQ(IQDiscoInfoHandler. java:99)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:49)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:349)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:101)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:68)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:311)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler .java:79)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:276)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:175)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:133)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:58)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:185)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :239)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.java:283)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:613)

In addition, I am using Adium, when I try to connect to the server it hangs at “Reading Data 50%”. This server has been up for 2 weeks without any issues and these problems just started a couple days ago.

Jason_Morton · July 30, 2008, 8:42pm

In Addition I am seeing this error:

2008.07.30 15:41:13 002078 (01/05/00) - #3 registered a statement as closed which wasn’t known to be open. This could happen if you close a statement twice.
2008.07.30 15:41:13 002079 (01/05/00) - #4 registered a statement as closed which wasn’t known to be open. This could happen if you close a statement twice.
2008.07.30 15:41:13 002080 (01/05/00) - #5 registered a statement as closed which wasn’t known to be open. This could happen if you close a statement twice.
2008.07.30 15:41:13 002081 (01/05/00) - #1 registered a statement as closed which wasn’t known to be open. This could happen if you close a statement twice.

Daniel_Henninger · July 31, 2008, 8:20pm

Howdy, the IQ related error is a known bug that was fixed in trunk I believe. (will be in next release, 3.5.3 and/or 3.6.0)

The vcard errors are generally becuase the client was trying to set something that’s invalid, typically ignorable.

The DB statements are ignorable, annoying, but ignorable.

The connection error is due to an attempt to connect to a host that the server can’t resolve. Mostly ignorable.

Overall I don’t see anything in particular that should be causing problems here ---- Though the IQ error -is- known to sometimes cause problems. Do these disconnects seem to happen at any particular time?

– by that i mean do they happen for a lot of people all at a certain time?

Armando_Keniti_Kusan · September 24, 2008, 5:37pm

I’ having exactly the same error.

Some Information:

Openfire 3.6.0a/OracleXE
RedHat Enterprise 5.2
Spark 2.5.8 on Windows XP SP3
40 simultaneous users on server, that is located in a DataCenter (all users under Internet connection).
Only some clients are having this problem.
I didn’t find any pattern that is causing this problem.