A connection manager with more than one connection to the openfire server doesn't seem to work

With server connections set to 2 in manager.xml, all attempts to login look like this:

jabber: Recv (ssl)(413): <?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="[http://etherx.jabber.org/streams](http://etherx.jabber.org/streams)" xmlns="jabber:client" from="domain" id="connection_manager" xml:lang="en" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>JIVE-SHAREDSECRET</mechanism><mechanism>PLAIN</mechanism></mechanisms><auth xmlns="[http://jabber.org/features/iq-auth](http://jabber.org/features/iq-auth)"/></stream:features>
sasl: Mechs found: JIVE-SHAREDSECRET PLAIN
jabber: Sending (ssl) (JID@domain/): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='PLAIN'>password removed</auth>
jabber: Recv (ssl)(101): <error code="404" type="cancel"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error>
jabber: Unknown packet: error

I added some more verbose debugging to the connection manager source and ended up with this:

forwarding to server: <route to='domain-server' from='connection_manager/Connection Worker - 8' streamid='connectionstreamid'><auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='PLAIN'/></route>
received from server: <route streamid="connectionstreamid" from="domain-server" to="connection_manager/Connection Worker - 8" type="error"><error code="404" type="cancel"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></route>
forwarding to client: <error code="404" type="cancel"><item-not-found xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error>

and in the openfire debug logs we get stuff like:

ConnectionHandler:
java.io.IOException: An existing connection was forcibly closed by the remote host
at sun.nio.ch.SocketDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(Unknown Source)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
at sun.nio.ch.IOUtil.read(Unknown Source)
at sun.nio.ch.SocketChannelImpl.read(Unknown Source)
at org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.j ava:218)
at org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcesso r.java:198)
at org.apache.mina.transport.socket.nio.SocketIoProcessor.access$400(SocketIoProce ssor.java:45)
at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProce ssor.java:485)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)

The timestamps do not line up on the “existing connection was forcibly closed” and the "received from server: " entries, but I can’t put much stock in that because one of the logging services thinks the time is at least 30 minutes later than it actually is so for all I know those two events are happening at the exact same time.

When I switched the connection manager to only maintain 1 connection to the server, users were able to log in without problems. Any thoughts on what’s going on?

Anybody?

Tracked the problem into the MultiplexerPacketHandler.java,

and found that the handler’s route() method can be called

while other thread is in the middle of

ConnectionMultiplexerManager.createClientSession() method.

Made a patch, to make the packets over multiple multiplexer

connection manager threads synchronized on the session

object if they are belong to the same streamID.

Seems ok so far. Need more

diff -ub -r openfire_src.orig/src/java/org/jivesoftware/openfire/multiplex/MultiplexerPacke tHandler.java openfire_src/src/java/org/jivesoftware/openfire/multiplex/MultiplexerPacketHand ler.java

— openfire_src.orig/src/java/org/jivesoftware/openfire/multiplex/MultiplexerPacke tHandler.java 2011-06-21 23:22:26.000000000 +0900

+++ openfire_src/src/java/org/jivesoftware/openfire/multiplex/MultiplexerPacketHand ler.java 2011-06-22 16:13:08.000000000 +0900

@@ -182,6 +182,9 @@

}

SessionPacketRouter router = new SessionPacketRouter(session);

  •   synchronized(session){//XXX letmesee --shr //keep packet order
    

// Connection Manager already validate JIDs so just skip this expensive operation

router.setSkipJIDValidation(true);

try {

@@ -197,6 +200,9 @@

Log.error("Error processing wrapped packet: " + route.getChildElement().asXML(), e);

sendErrorPacket(route, PacketError.Condition.internal_server_error, null);

}

  •    } //synchronized(session){//XXX letmesee --shr //keep packet order
    

}

/**