Openfire 3.5.1 - Very Strange S2S Behavior

For the last month or so, things have been acting up. It appears that the two openfire servers I run are having s2s issues. I have been unable to add users from one server to the other, and vice versa. This has always worked, so I’m not sure whats going on.

S2S security is set to optional on both servers

Only local subscription requests are being intercepted by the server

This doesn’t matter which server I start out on, but if I try to add user1@server1.jabber.org to user2@server2.jabber.org, user1 just sits there as pending. The same thing happens if I reverse things. Now, sometimes messages get through, but the majority of the time the messages are not even making it through.

Below are an assortment of log files captured:

Error Logs:

jabber.uww.edu:

2008.06.09 21:57:05 org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSessi on(LocalOutgoingServerSession.java:259) Error trying to connect to remote server: modevia.com(DNS lookup: modevia.com:5269)

java.net.SocketTimeoutException: connect timed out

at java.net.PlainSocketImpl.socketConnect(Native Method)

at java.net.PlainSocketImpl.doConnect(Unknown Source)

at java.net.PlainSocketImpl.connectToAddress(Unknown Source)

at java.net.PlainSocketImpl.connect(Unknown Source)

at java.net.SocksSocketImpl.connect(Unknown Source)

at java.net.Socket.connect(Unknown Source)

at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSess ion(LocalOutgoingServerSession.java:254)

at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain (LocalOutgoingServerSession.java:185)

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(Unknown Source)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

at java.lang.Thread.run(Unknown Source)

2008.06.09 21:57:05 org.jivesoftware.openfire.server.ServerDialback.createIncomingSession(ServerDial back.java:387) An error occured while creating a server session

java.net.SocketException: Connection reset

at java.net.SocketInputStream.read(Unknown Source)

at org.jivesoftware.openfire.net.ServerTrafficCounter$InputStreamWrapper.read(Serv erTrafficCounter.java:210)

at sun.nio.cs.StreamDecoder.readBytes(Unknown Source)

at sun.nio.cs.StreamDecoder.implRead(Unknown Source)

at sun.nio.cs.StreamDecoder.read(Unknown Source)

at java.io.InputStreamReader.read(Unknown Source)

at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)

at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)

at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:76)

at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)

at org.dom4j.io.XMPPPacketReader.parseDocument(XMPPPacketReader.java:317)

at org.jivesoftware.openfire.server.ServerDialback.createIncomingSession(ServerDia lback.java:347)

at org.jivesoftware.openfire.session.LocalIncomingServerSession.createSession(Loca lIncomingServerSession.java:102)

at org.jivesoftware.openfire.net.ServerSocketReader.createSession(ServerSocketRead er.java:212)

at org.jivesoftware.openfire.net.SocketReader.createSession(SocketReader.java:398)

at org.jivesoftware.openfire.net.BlockingReadingMode.run(BlockingReadingMode.java: 54)

at org.jivesoftware.openfire.net.SocketReader.run(SocketReader.java:120)

at java.lang.Thread.run(Unknown Source)

jabber.modevia.com:

at org.jivesoftware.openfire.net.TLSStreamHandler.doHandshake(TLSStreamHandler.jav a:212)

at org.jivesoftware.openfire.net.TLSStreamHandler.start(TLSStreamHandler.java:158)

at org.jivesoftware.openfire.net.SocketConnection.startTLS(SocketConnection.java:1 66)

at org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode. java:74)

at org.jivesoftware.openfire.net.BlockingReadingMode.readStream(BlockingReadingMod e.java:127)

at org.jivesoftware.openfire.net.BlockingReadingMode.run(BlockingReadingMode.java: 63)

at org.jivesoftware.openfire.net.SocketReader.run(SocketReader.java:120)

at java.lang.Thread.run(Thread.java:619)

2008.06.10 01:26:32 org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode.j ava:77) Error while negotiating TLS: org.jivesoftware.openfire.net.SocketConnection@c5b819 socket: Socket[http://addr=/140.146.80.242,port=55322,localport=5269|http://addr=/140.146.80.24 2,port=55322,localport=5269] session: org.jivesoftware.openfire.session.LocalIncomingServerSession@db7e08 status: 1 address: jabber.modevia.com/f6c20ac8 id: f6c20ac8

javax.net.ssl.SSLException: Unsupported record version Unknown-47.115

at com.sun.net.ssl.internal.ssl.EngineInputRecord.bytesInCompletePacket(EngineInpu tRecord.java:97)

at com.sun.net.ssl.internal.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:754 )

at com.sun.net.ssl.internal.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:669)

at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:607)

at org.jivesoftware.openfire.net.TLSStreamHandler.doHandshake(TLSStreamHandler.jav a:212)

at org.jivesoftware.openfire.net.TLSStreamHandler.start(TLSStreamHandler.java:158)

at org.jivesoftware.openfire.net.SocketConnection.startTLS(SocketConnection.java:1 66)

at org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode. java:74)

at org.jivesoftware.openfire.net.BlockingReadingMode.readStream(BlockingReadingMod e.java:127)

at org.jivesoftware.openfire.net.BlockingReadingMode.run(BlockingReadingMode.java: 63)

at org.jivesoftware.openfire.net.SocketReader.run(SocketReader.java:120)

at java.lang.Thread.run(Thread.java:619)

2008.06.10 01:26:53 org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode.j ava:77) Error while negotiating TLS: org.jivesoftware.openfire.net.SocketConnection@b5423f socket: Socket[http://addr=/140.146.80.242,port=55325,localport=5269|http://addr=/140.146.80.24 2,port=55325,localport=5269] session: org.jivesoftware.openfire.session.LocalIncomingServerSession@4c19ae status: 1 address: jabber.modevia.com/7fdd993c id: 7fdd993c

javax.net.ssl.SSLException: Unsupported record version Unknown-47.115

at com.sun.net.ssl.internal.ssl.EngineInputRecord.bytesInCompletePacket(EngineInpu tRecord.java:97)

at com.sun.net.ssl.internal.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:754 )

at com.sun.net.ssl.internal.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:669)

at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:607)

at org.jivesoftware.openfire.net.TLSStreamHandler.doHandshake(TLSStreamHandler.jav a:212)

at org.jivesoftware.openfire.net.TLSStreamHandler.start(TLSStreamHandler.java:158)

at org.jivesoftware.openfire.net.SocketConnection.startTLS(SocketConnection.java:1 66)

at org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode. java:74)

at org.jivesoftware.openfire.net.BlockingReadingMode.readStream(BlockingReadingMod e.java:127)

at org.jivesoftware.openfire.net.BlockingReadingMode.run(BlockingReadingMode.java: 63)

at org.jivesoftware.openfire.net.SocketReader.run(SocketReader.java:120)

at java.lang.Thread.run(Thread.java:619)

2008.06.10 01:27:14 org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode.j ava:77) Error while negotiating TLS: org.jivesoftware.openfire.net.SocketConnection@9d7837 socket: Socket[http://addr=/140.146.80.242,port=55329,localport=5269|http://addr=/140.146.80.24 2,port=55329,localport=5269] session: org.jivesoftware.openfire.session.LocalIncomingServerSession@1cfd020 status: 1 address: jabber.modevia.com/5f235469 id: 5f235469

javax.net.ssl.SSLException: Unsupported record version Unknown-47.115

at com.sun.net.ssl.internal.ssl.EngineInputRecord.bytesInCompletePacket(EngineInpu tRecord.java:97)

at com.sun.net.ssl.internal.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:754 )

at com.sun.net.ssl.internal.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:669)

at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:607)

at org.jivesoftware.openfire.net.TLSStreamHandler.doHandshake(TLSStreamHandler.jav a:212)

at org.jivesoftware.openfire.net.TLSStreamHandler.start(TLSStreamHandler.java:158)

at org.jivesoftware.openfire.net.SocketConnection.startTLS(SocketConnection.java:1 66)

at org.jivesoftware.openfire.net.SocketReadingMode.negotiateTLS(SocketReadingMode. java:74)

at org.jivesoftware.openfire.net.BlockingReadingMode.readStream(BlockingReadingMod e.java:127)

at org.jivesoftware.openfire.net.BlockingReadingMode.run(BlockingReadingMode.java: 63)

at org.jivesoftware.openfire.net.SocketReader.run(SocketReader.java:120)

at java.lang.Thread.run(Thread.java:619)

From the debug log:

jabber.uww.edu:

2008.06.09 18:33:12 LocalOutgoingServerSession: OS - Trying to connect to modevia.com:5269(DNS lookup: modevia.com:5269)

2008.06.09 18:33:12 ServerDialback: OS - Unexpected answer in validation from: jabber.modevia.com id: 37ca1b6f for domain: jabber.uww.edu answer:<stream:error xmlns:stream=“http://etherx.jabber.org/streams”><remote-connection-failed xmlns=“urn:ietf:params:xml:ns:xmpp-streams”/></stream:error>

Socket[http://addr=/209.213.104.21,port=45386,localport=5269|http://addr=/209.213.104.2 1,port=45386,localport=5269]

2008.06.09 18:33:12 Connection closed before session established

2008.06.09 18:33:12 Connect Socket[http://addr=/209.213.104.21,port=45386,localport=5269|http://addr=/209.213.104.2 1,port=45386,localport=5269]

2008.06.09 18:33:12 ServerDialback: OS - Sent dialback key to host: jabber.modevia.com id: 37ca1b6f from domain: jabber.uww.edu

2008.06.09 18:33:12 ServerDialback: OS - Connection to jabber.modevia.com:5269 successful

2008.06.09 18:33:12 ServerDialback: OS - Trying to connect to jabber.modevia.com:5269(DNS lookup: jabber.modevia.com:5269)

2008.06.09 18:33:12 LocalOutgoingServerSession: OS - Going to try connecting using server dialback with: jabber.modevia.com

… 18 more

at org.jivesoftware.openfire.net.ServerTrustManager.checkServerTrusted(ServerTrust Manager.java:135)

Caused by: java.security.cert.CertificateException: root certificate not trusted of http://*.jabber.modevia.com

… 10 more

jabber.modevia.com

2008.06.09 23:58:07 Connection closed before session established

2008.06.09 23:58:07 ServerDialback: RS - Closing connection to Authoritative Server: jabber.uww.edu

2008.06.09 23:58:07 ServerDialback: RS - Asking AS to verify dialback key for id5245c0be

2008.06.09 23:58:07 ServerDialback: RS - Connection to AS: jabber.uww.edu:5269 successful

2008.06.09 23:58:07 ServerDialback: RS - Trying to connect to Authoritative Server: jabber.uww.edu:5269(DNS lookup: jabber.uww.edu:5269)

2008.06.09 23:58:07 ServerDialback: RS - Received dialback key from host: jabber.uww.edu to: jabber.modevia.com

2008.06.09 23:58:07 Connect Socket[http://addr=/140.146.80.242,port=49278,localport=5269|http://addr=/140.146.80.24 2,port=49278,localport=5269]

Socket[http://addr=/140.146.80.242,port=49277,localport=5269|http://addr=/140.146.80.24 2,port=49277,localport=5269]

Hey there,

I noticed one line in particular: “root certificate not trusted of”, which would mean your certificate validation chain seems to be broken or you don’t have the proper root certificates installed for the certificates you are using (in openfire’s truststore). Next to that I also noticed some timeouts so it may be a combined problem with poor connectivity and not having the full validation chain available.

You can try setting:

xmpp.server.certificate.verify = false

on both servers, and see if you still get the s2s errors. If not, you should have a look at making sure your certificates are complete, correct, and that the truststore on your servers have the appropriate root certificates and intermediate certificates (if any) installed.

Also, if one or both of the servers are using self-signed certificates, you can try to use:

xmpp.server.certificate.accept-selfsigned = true

to make sure self-signed certificates are considered valid.

Hope this helps,

Mark.

I’ll give those settings a shot later tonight.

The question i still have though is why would this just randmoly start happening? Nothing has changed on either servers, so i’m just confused why it all of the sudden stopped working

The question i still have though is why would this just randmoly start

happening? Nothing has changed on either servers, so i’m just confused why it

all of the sudden stopped working

I’m afraid I don’t have an answer to that one. Obviously -something- has

changed, you don’t suddenly lose trust, unless one of your certificates

expired.

On 3.5.2, this is again all mucked up:

java.lang.Exception: Failed to create connection to remote serverat org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.sendPa cket(OutgoingSessionPromise.java:228)at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(Ou tgoingSessionPromise.java:194)

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)

I am running self signed certs - is there a serious problem if they aren’t signed?