S2S Connections failing with nothing useful in debug log

Dylan_G · October 15, 2024, 6:34am

Hello, I’m trying to initiate a server to server connection with Openfire but it’s failing. Debug logs do not tell me anything useful.

Openfire version: 4.7.5
OS: Redhat Linux 8.10
1st XMPP Domain Name: chat.my.first.server
1st Server Host Name (FQDN): chat.my.first.server
2nd XMPP Domain Name: chat.my.second.server
2nd Server Host Name (FQDN): chat.my.second.server

Previously it worked when both clients were on Redhat 8.6. Is it possible support was lost with the move to 8.10?

Log:

Sending server to server ping request to chat.my.second.server
Routing to remote domain: 
<iq type="get" id="579-6" from="chat.my.first.server" to="chat.my.second.server">
  <ping xmlns="urn:xmpp:ping"/>
</iq>
A new outgoing session for {chat.my.first.server -> chat.my.second.server} is needed. Instantiating a new queue stanza for delivery when that's done.
Created new PacketProcessor for {chat.my.first.server -> chat.my.second.server}
Queuing stanza to intended recipient 'chat.my.second.server' in the outgoing session promise to domain '{chat.my.first.server -> chat.my.second.server}': <iq type="get" id="579-6" from="chat.my.first.server" to="chat.my.second.server"><ping xmlns="urn:xmpp:ping"/></iq>
Start for {chat.my.first.server -> chat.my.second.server}
Start establishing a connection for {chat.my.first.server -> chat.my.second.server}
Start domain authentication ...
Searching for pre-existing outgoing sessions to the remote domain (if one exists, it will be re-used) ...
There are no pre-existing outgoing sessions to the remote domain itself. Searching for pre-existing outgoing sessions to super- or subdomains of the remote domain (if one exists, it might be re-usable) ...
There are no pre-existing session to other domains hosted on the remote domain.
Unable to re-use an existing session. Creating a new session ...
Creating new session...
Creating plain socket connection to a host that belongs to the remote XMPP domain.
Creating a socket connection to XMPP domain 'chat.my.second.server' ...
Use DNS to resolve remote hosts for the provided XMPP domain 'chat.my.second.server' (default port: 5269) ...
DNS SRV Lookup for service 'xmpp-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpp-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:660) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:578) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:426) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:211) ~[?:1.8.0_402]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:1.8.0_402]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:1.8.0_402]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:224) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:117) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:47) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:258) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:212) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:298) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:254) [xmppserver-4.7.5.jar:4.7.5]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_402]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_402]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_402]
DNS SRV Lookup for service 'xmpps-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpps-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:660) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:578) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:426) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:211) ~[?:1.8.0_402]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:1.8.0_402]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:1.8.0_402]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:224) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:121) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:47) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:258) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:212) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:298) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:254) [xmppserver-4.7.5.jar:4.7.5]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_402]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_402]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_402]
DNS SRV Lookup for service 'jabber', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_jabber._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:660) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:578) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:426) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:211) ~[?:1.8.0_402]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[?:1.8.0_402]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:1.8.0_402]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:1.8.0_402]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:1.8.0_402]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:224) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:129) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:47) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:258) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:212) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:298) [xmppserver-4.7.5.jar:4.7.5]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:254) [xmppserver-4.7.5.jar:4.7.5]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_402]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_402]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_402]
Found 1 host(s) for XMPP domain 'chat.my.second.server'.
- chat.my.second.server:5269 (no direct TLS)
Trying to create socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269 (blocks up to 120000 ms) ...
Successfully created socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269!
Opening a new connection to chat.my.second.server/ww.xx.yy.zz:5269 that is initially not encrypted.
Send the stream header and wait for response...
Got a response (stream ID: 6l6vk8uyoq, version: 1.0). Check if the remote server is XMPP 1.0 compliant...
The remote server is XMPP 1.0 compliant (or at least reports to be).
Processing stream features of the remote domain...
Check if both us as well as the remote server have enabled STARTTLS and/or dialback ...
Both us and the remote server support the STARTTLS feature. Secure and authenticate the connection with TLS & SASL...
Securing and authenticating connection ...
Indicating we want TLS and wait for response.
Received 'proceed' from remote server. Negotiating TLS...
Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
Constructed trust manager. Number of trusted issuers: 150, accepts self-signed: false, checks validity: false
Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
Attempting to verify a chain of 4 certificates.
Attempting to ignore any validity (expiry) issues, as instructed by configuration.
Validating chain with 4 certificates, using 150 trust anchors.
TLS negotiation was successful. Connection secured. Proceeding with authentication...
CertificateManager: Subject Alternative Name Mapping returned [*.my.second.server, *.chat.my.second.server, chat.my.second.server, mychatserver, mychatserver.my.second.server]
TLS negotiation was successful so initiate a new stream.
Remote server is offering dialback: false, EXTERNAL SASL: false
Trying to authenticate with dialback.
Trying to connecting using dialback over TLS.
Authenticating domain ...
Sending dialback key and wait for the validation response...
Connect Socket[addr=/ww.xx.yy.zz,port=38486,localport=5269]
Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
Constructed trust manager. Number of trusted issuers: 150, accepts self-signed: false, checks validity: false
Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
Flushing pending nodes (count: 0)
Failed to establish server to server session.

.

zoidberg · October 15, 2024, 7:50am

On Openfire 4.7.5 TLSv1.3 have issues. try disabling TLSv1.3 on both servers, or upgrade to the latest Openfire version 4.9 which is working perfectly.
Besides that your Logs are clearly also complaning about no SRV records, IIRC it will still work if you are using the default port for S2S 5269/5270, otherwise it will not work. Maybe consider creating said SRV records.
https://wiki.xmpp.org/web/SRV_Records

guus · October 15, 2024, 8:23am

The operating system used by the clients has no effect on the success rate of s2s connectivity between two servers. Even the operating system of the servers themselves has very little effect (assuming that the basic configuration is OK, of course).

Apart from the very last log line, do you have any indication that s2s is not being established? From what I read, the connection attempt was successful. I seem to recall that Openfire’s s2s tester sometimes prints that a connection attempt is not successful, while it in reality was successful.

One way of checking this is to see if there is an S2S session in the admin console, shortly after the test was done.

Dylan_G · October 15, 2024, 10:04am

TLS 1.3 is disabled. I am using the default ports, so ignoring SRV messages.

Dylan_G · October 15, 2024, 10:08am

Sorry, I meant both Openfire servers are on Redhat 8.10. Performing a S2S Test takes 2+ minutes and there is no connection displayed in Active Server Sessions in the admin console when it completes.

I’m testing using the S2S Connection Test page on the admin console, as well as Spark on Windows 10 clients. The two Openfire servers are on different DNS sites.

guus · October 15, 2024, 10:11am

That’s weird.

The log data that you copy/pasted, did that come from the admin console, or from the log files?They should be equal, but I’ve seen instances where the log files would contain more data. Maybe it’s worth investigating that?

Dylan_G · October 15, 2024, 11:02am

It comes from the S2S Connection Test results. XMPP/Certs/Logs. Nothing in Certs, C/P from Logs textbox. Server logs don’t tell me anything

2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.net.SocketUtil - Found 1 host(s) for XMPP domain 'chat.my.second.server'.
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.net.SocketUtil - - chat.my.second.server:5269 (no direct TLS)
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.net.SocketUtil - Trying to create socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269 (blocks up to 120000 ms) ...
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.net.SocketUtil - Successfully created socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269!
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.server.ServerDialback[Acting as Originating Server: Create Outgoing Session from: chat.my.first.server to a RS in the domain of: chat.my.second.server (port: 5269)] - Send the stream header and wait for response...
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.server.ServerDialback[Acting as Originating Server: Create Outgoing Session from: chat.my.first.server to a RS in the domain of: chat.my.second.server (port: 5269)] - Got a response. Check if the remote server supports dialback...
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.server.ServerDialback[Acting as Originating Server: Create Outgoing Session from: chat.my.first.server to a RS in the domain of: chat.my.second.server (port: 5269)] - Dialback seems to be supported by the remote server.
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.server.ServerDialback[Acting as Originating Server: Authenticate domain: chat.my.first.server with a RS in the domain of: chat.my.second.server (id: 6rcykeg6ea)] - Authenticating domain ...
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [S2SOutgoingPromise-5]: org.jivesoftware.openfire.server.ServerDialback[Acting as Originating Server: Authenticate domain: chat.my.first.server with a RS in the domain of: chat.my.second.server (id: 6rcykeg6ea)] - Sending dialback key and wait for the validation response...
2024.10.15 10:57:23 ^[[36mDEBUG^[[m [Socket Listener at port 5269]: org.jivesoftware.openfire.net.BlockingAcceptingMode - Connect Socket[addr=/10.52.13.40,port=44686,localport=5269]
2024.10.15 10:57:24 ^[[36mDEBUG^[[m [Server SR - 539767101]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
2024.10.15 10:57:24 ^[[36mDEBUG^[[m [Server SR - 539767101]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
2024.10.15 10:57:24 ^[[36mDEBUG^[[m [Server SR - 539767101]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Constructed trust manager. Number of trusted issuers: 151, accepts self-signed: true, checks validity: false
2024.10.15 10:57:24 ^[[36mDEBUG^[[m [Server SR - 539767101]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.

But then nothing happens.

The behavior was pretty much plug and play when connecting between two Redhat 8.6 servers. I can’t find anything different than trying 8.6 ↔ 8.6, but now it’s failing 8.6 ↔ 8.10 and 8.10 ↔ 8.10. Is it possible there is some routing issue with the physical routers/gateways that is manifesting in some weird way? Both servers can ping each other and all ports are open (5222, 5223, 5269, 5270) on each server

guus · October 15, 2024, 11:45am

I can’t quite explain it, and I’m not keen in digging into such an issue in a version of Openfire that is older, since the server-to-server code got a major update in later versions of Openfire. Perhaps trying the most recent version resolves the problem, or would give more actionable logged messages.

Dylan_G · October 16, 2024, 6:04am

New logs with a fresh Openfire 4.9.0 instance, still failing

Sending server to server ping request to chat.my.second.server
isAnonymousRoute() invoked with a JID that's not a full JID: chat.my.first.server
Routing to remote domain: 
<iq type="get" id="375-32" from="chat.my.first.server" to="chat.my.second.server">
  <ping xmlns="urn:xmpp:ping"/>
</iq>
A new outgoing session for {chat.my.first.server -> chat.my.second.server} is needed. Instantiating a new queue stanza for delivery when that's done.
Created new PacketProcessor for {chat.my.first.server -> chat.my.second.server}
Queuing stanza to intended recipient 'chat.my.second.server' in the outgoing session promise to domain '{chat.my.first.server -> chat.my.second.server}': <iq type="get" id="375-32" from="chat.my.first.server" to="chat.my.second.server"><ping xmlns="urn:xmpp:ping"/></iq>
Start for {chat.my.first.server -> chat.my.second.server}
Start establishing a connection for {chat.my.first.server -> chat.my.second.server}
Start domain authentication ...
Searching for pre-existing outgoing sessions to the remote domain (if one exists, it will be re-used) ...
There are no pre-existing outgoing sessions to the remote domain itself. Searching for pre-existing outgoing sessions to super- or subdomains of the remote domain (if one exists, it might be re-usable) ...
There are no pre-existing session to other domains hosted on the remote domain.
Unable to re-use an existing session. Creating a new session ...
Creating new session...
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@6304ae9e
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@6dc34c8e
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@69fcc5ee
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@2cfe46b5
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@6a486dea
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@1d98eb11
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@12c49ef9
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@4cd1b9fa
Creating plain socket connection to a host that belongs to the remote XMPP domain.
Creating a socket connection to XMPP domain 'chat.my.second.server' ...
Use DNS to resolve remote hosts for the provided XMPP domain 'chat.my.second.server' (default port: 5269) ...
DNS SRV Lookup for service 'xmpp-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpp-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:120) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
DNS SRV Lookup for service 'xmpps-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpps-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:133) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
DNS SRV Lookup for service 'jabber', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_jabber._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:141) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Found 1 host(s) for XMPP domain 'chat.my.second.server'.
- chat.my.second.server:5269 (no direct TLS)
Trying to create socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269 (blocks up to 120000 ms) ...
Successfully created socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269!
Opening a new connection to chat.my.second.server/10.52.13.40:5269 that is initially not encrypted.
Adding NettyOutboundConnectionHandler
Netty XMPP handler added: null
Send the stream header and wait for response...
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
Handler on /10.54.5.40:58922--chat.my.second.server/10.52.13.40:5269 received: <?xml version="1.0" encoding="UTF-8"?>
Handler on /10.54.5.40:58922--chat.my.second.server/10.52.13.40:5269 received: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" id="7bvwze6ke7" version="1.0">
Handler on /10.54.5.40:58922--chat.my.second.server/10.52.13.40:5269 received: <stream:features><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
Both us and the remote server support the STARTTLS feature. Encrypt and authenticate the connection with TLS & SASL...
Indicating we want TLS and wait for response.
Sending: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
Handler on /10.54.5.40:58922--chat.my.second.server/10.52.13.40:5269 received: <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
Received 'proceed' from remote server. Negotiating TLS...
Encrypting and authenticating connection ...
Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
Constructed trust manager. Number of trusted issuers: 144, accepts self-signed: false, checks validity: true
Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
Attempting to verify a chain of 4 certificates.
Validating chain with 4 certificates, using 143 trust anchors.
[id: 0x956db619, L:/10.54.5.40:58922 - R:chat.my.second.server/10.52.13.40:5269] HANDSHAKEN: protocol:TLSv1.3 cipher suite:TLS_AES_256_GCM_SHA384
CertificateManager: Subject Alternative Name Mapping returned [chat.my.second.server, *.chat.my.second.server]
TLS negotiation with 'chat.my.second.server' was successful. Connection encrypted. Proceeding with authentication.
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
An exception occurred while creating a session. Closing connection.
java.util.concurrent.TimeoutException: null
	at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1892) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2027) ~[?:?]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Closing NettyConnection{peer: chat.my.second.server/10.52.13.40:5269, state: CLOSED, session: null, Netty channel handler context name: NettyOutboundConnectionHandler#0} with optional error: null
Flushed any final bytes, closing connection.
Notifying close listeners.
Finished closing connection.
Netty XMPP handler removed: /10.54.5.40:58922--chat.my.second.server/10.52.13.40:5269
Unable to authenticate: Fail to create new session.
An exception occurred while trying to establish a connection for {chat.my.first.server -> chat.my.second.server}
java.lang.Exception: Failed to create connection to remote server
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:301) ~[xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Purging queue for {chat.my.first.server -> chat.my.second.server}
Bouncing queued stanza: 
<iq type="get" id="375-32" from="chat.my.first.server" to="chat.my.second.server">
  <ping xmlns="urn:xmpp:ping"/>
</iq>
Finished processing {chat.my.first.server -> chat.my.second.server}
Erroneous server to server response received.
Failed to establish server to server session.

Dylan_G · October 16, 2024, 6:55am

Increased xmpp.server.initialise-timeout system property, timeout is removed from logs, but connection fails with no output

Sending server to server ping request to chat.my.second.server
isAnonymousRoute() invoked with a JID that's not a full JID: chat.my.first.server
Routing to remote domain: 
<iq type="get" id="364-6" from="chat.my.first.server" to="chat.my.second.server">
  <ping xmlns="urn:xmpp:ping"/>
</iq>
A new outgoing session for {chat.my.first.server -> chat.my.second.server} is needed. Instantiating a new queue stanza for delivery when that's done.
Created new PacketProcessor for {chat.my.first.server -> chat.my.second.server}
Queuing stanza to intended recipient 'chat.my.second.server' in the outgoing session promise to domain '{chat.my.first.server -> chat.my.second.server}': <iq type="get" id="364-6" from="chat.my.first.server" to="chat.my.second.server"><ping xmlns="urn:xmpp:ping"/></iq>
Start for {chat.my.first.server -> chat.my.second.server}
Start establishing a connection for {chat.my.first.server -> chat.my.second.server}
Start domain authentication ...
Searching for pre-existing outgoing sessions to the remote domain (if one exists, it will be re-used) ...
There are no pre-existing outgoing sessions to the remote domain itself. Searching for pre-existing outgoing sessions to super- or subdomains of the remote domain (if one exists, it might be re-usable) ...
There are no pre-existing session to other domains hosted on the remote domain.
Unable to re-use an existing session. Creating a new session ...
Creating new session...
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@28fa9825
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@611952e5
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@6dd3194d
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@2a4d463b
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@560ac8e7
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@7d2f36b9
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@8c34120
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@48ffa29d
Creating plain socket connection to a host that belongs to the remote XMPP domain.
Creating a socket connection to XMPP domain 'chat.my.second.server' ...
Use DNS to resolve remote hosts for the provided XMPP domain 'chat.my.second.server' (default port: 5269) ...
DNS SRV Lookup for service 'xmpp-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpp-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:120) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
DNS SRV Lookup for service 'xmpps-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpps-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:133) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
DNS SRV Lookup for service 'jabber', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_jabber._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:141) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Found 1 host(s) for XMPP domain 'chat.my.second.server'.
- chat.my.second.server:5269 (no direct TLS)
Trying to create socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269 (blocks up to 120000 ms) ...
Successfully created socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269!
Opening a new connection to chat.my.second.server/10.52.13.40:5269 that is initially not encrypted.
Adding NettyOutboundConnectionHandler
Netty XMPP handler added: null
Send the stream header and wait for response...
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
Handler on /10.54.5.40:60868--chat.my.second.server/10.52.13.40:5269 received: <?xml version="1.0" encoding="UTF-8"?>
Handler on /10.54.5.40:60868--chat.my.second.server/10.52.13.40:5269 received: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" id="4gmzbnfj9i" version="1.0">
Handler on /10.54.5.40:60868--chat.my.second.server/10.52.13.40:5269 received: <stream:features><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
Both us and the remote server support the STARTTLS feature. Encrypt and authenticate the connection with TLS & SASL...
Indicating we want TLS and wait for response.
Sending: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
Handler on /10.54.5.40:60868--chat.my.second.server/10.52.13.40:5269 received: <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
Received 'proceed' from remote server. Negotiating TLS...
Encrypting and authenticating connection ...
Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
Constructed trust manager. Number of trusted issuers: 144, accepts self-signed: false, checks validity: true
Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
Attempting to verify a chain of 4 certificates.
Validating chain with 4 certificates, using 143 trust anchors.
[id: 0x8968d63c, L:/10.54.5.40:60868 - R:chat.my.second.server/10.52.13.40:5269] HANDSHAKEN: protocol:TLSv1.3 cipher suite:TLS_AES_256_GCM_SHA384
CertificateManager: Subject Alternative Name Mapping returned [chat.my.second.server, *.chat.my.second.server]
TLS negotiation with 'chat.my.second.server' was successful. Connection encrypted. Proceeding with authentication.
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
Closing NettyConnection{peer: chat.my.second.server/10.52.13.40:5269, state: CLOSED, session: null, Netty channel handler context name: NettyOutboundConnectionHandler#0} with optional error: null
Flushed any final bytes, closing connection.
Notifying close listeners.
Finished closing connection.
Netty XMPP handler removed: /10.54.5.40:60868--chat.my.second.server/10.52.13.40:5269
Freed 16 thread-local buffer(s) from thread: nioEventLoopGroup-11-1
Flushing pending nodes (count: 0)
Failed to establish server to server session.

guus · October 16, 2024, 7:37am

TLS negotiation with 'chat.my.second.server' was successful. Connection encrypted. Proceeding with authentication.
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
Closing NettyConnection{peer: chat.my.second.server/10.52.13.40:5269, state: CLOSED, session: null, Netty channel handler context name: NettyOutboundConnectionHandler#0} with optional error: null

This suggests that encryption has successfully been negotiated, but the connection gets closed during or directly after authentication. It’s puzzling to me that this does not log any error.

Have you looked at the log files of the other server at the same time? Maybe that contains a clue.

I expect authentication to first use SASL EXTERNAL, which basically verifies that the certificate of the peer correctly identifies the XMPP domain name of that server. Can you verify that both certificates are issued to the correct domain? The XMPP domain name needs to be the CN or a SAN - either is fine.

If SASL EXTERNAL fails because of a invalid certificate, newer versions of Openfire do not automatically attempt the weaker Dialback method of authentication. You can toggle that behavior by enabling a checkbox named “If attempting to validate a certificate fails, the connection is closed and not attempted via dialback authentication” in the server-to-server settings on the admin panel. This may be a workaround for a faulty certificate.

Dylan_G · October 16, 2024, 9:05am

The setting did not help. This is the log from the second server

2024.10.16 09:03:25.254 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyServerConnectionHandler - Adding NettyServerConnectionHandler
2024.10.16 09:03:25.254 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Netty XMPP handler added: /10.52.13.40:5269--/10.54.5.40:34216
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyConnection - Closing NettyConnection{peer: /10.54.5.40:34216, state: CLOSED, session: null, Netty channel handler context name: NettyServerConnectionHandler#0} with optional error: null
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyConnection - Flushed any final bytes, closing connection.
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyConnection - Notifying close listeners.
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyConnection - Finished closing connection.
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-4]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Netty XMPP handler removed: /10.52.13.40:5269--/10.54.5.40:34216
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyServerConnectionHandler - Adding NettyServerConnectionHandler
2024.10.16 09:03:25.257 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Netty XMPP handler added: /10.52.13.40:5269--/10.54.5.40:34218
2024.10.16 09:03:25.259 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /10.52.13.40:5269--/10.54.5.40:34218 received: <?xml version="1.0" encoding="UTF-8"?>
2024.10.16 09:03:25.259 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /10.52.13.40:5269--/10.54.5.40:34218 received: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
2024.10.16 09:03:25.259 DEBUG [socket_s2s-thread-5]: org.jivesoftware.openfire.session.LocalIncomingServerSession - Creating new session with stream ID 'aig6ixhz1u' for local 'chat.my.second.server' to peer 'chat.my.first.server'.
2024.10.16 09:03:25.259 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.session.LocalIncomingServerSession - Remote server is XMPP 1.0 compliant so offer TLS and SASL to establish the connection (and server dialback)
2024.10.16 09:03:25.260 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.session.LocalIncomingServerSession - Outbound stream & feature advertisement: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" id="aig6ixhz1u" version="1.0"><stream:features><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
2024.10.16 09:03:25.260 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" id="aig6ixhz1u" version="1.0"><stream:features><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
2024.10.16 09:03:25.260 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.session.LocalIncomingServerSession - Set the domain or subdomain of the local server targeted by the remote server: chat.my.second.server
2024.10.16 09:03:25.470 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /10.52.13.40:5269--/10.54.5.40:34218 received: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
2024.10.16 09:03:25.471 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.net.StanzaHandler - Connection '[10, 54, 5, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback"
2024.10.16 09:03:25.471 DEBUG [socket_s2s-thread-5]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
2024.10.16 09:03:25.471 DEBUG [socket_s2s-thread-5]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
2024.10.16 09:03:25.472 DEBUG [socket_s2s-thread-5]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Constructed trust manager. Number of trusted issuers: 144, accepts self-signed: false, checks validity: true
2024.10.16 09:03:25.472 DEBUG [socket_s2s-thread-5]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
2024.10.16 09:03:25.472 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Sending: <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
2024.10.16 09:03:35.485 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Closing NettyConnection{peer: /10.54.5.40:34218, state: CLOSED, session: LocalIncomingServerSession{address=chat.my.second.server/b3ba82b5-4329-49df-b964-833fe1199455, streamID=aig6ixhz1u, status=CONNECTED, isEncrypted=false, isDetached=false, authenticationMethod=null, localDomain=chat.my.second.server, defaultIdentity=chat.my.first.server, validatedDomains={}}, Netty channel handler context name: NettyServerConnectionHandler#0} with optional error: null
2024.10.16 09:03:35.485 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Flushed any final bytes, closing connection.
2024.10.16 09:03:35.485 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Notifying close listeners.
2024.10.16 09:03:35.486 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Finished closing connection.
2024.10.16 09:03:35.486 ERROR [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnection - Problem during connection close or cleanup
io.netty.handler.ssl.SslHandshakeTimeoutException: handshake timed out after 10000ms
        at io.netty.handler.ssl.SslHandler$7.run(SslHandler.java:2217) ~[netty-handler-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) ~[netty-common-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:153) ~[netty-common-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) [netty-common-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) [netty-common-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) [netty-common-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569) [netty-transport-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) [netty-common-4.1.108.Final.jar:4.1.108.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.108.Final.jar:4.1.108.Final]
        at java.lang.Thread.run(Thread.java:829) [?:?]
2024.10.16 09:03:35.486 TRACE [socket_s2s-thread-5]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Netty XMPP handler removed: /10.52.13.40:5269--/10.54.5.40:34218

chat.my.first.server has a CA Signed RSA certificate with CN = chat.my.first.server, SAN *.chat.my.first.server

chat.my.second.server has a CA Signed RSA certificate with CN = chat.my.second.server, SAN *.chat.my.second.server

guus · October 16, 2024, 10:53am

This is puzzling. Combining a few of the log files (which were probably taken in different tries, but I expect the tries to be similar enough for them to be compared):

Second server, near the end, signals that TLS negotiation can start and tells the first server to continue:

Sending: <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

I believe that the first server receives this (there are no timestamps in that log though), and successfully negotiates TLS, because it logs:

TLS negotiation with 'chat.my.second.server' was successful. Connection encrypted. Proceeding with authentication.

The first server continues with setting up a new stream (on the same socket) to do authentication:

Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">

The second server doesn’t seem to receive this (or at least, it isn’t logged). The connection eventually times out after 10 seconds of perceived inactivity.

I’m currently at a loss why this happens.

Is there anything being logged to std-err/std-out/nohup.out?

What happens if you disable STARTTLS and Mutual Authentication altogether, thus forcing dialback authentication? I’m not suggesting to do that in production, but I’m interested in seeing if that generates logs that points at a possible cause for this issue.

Dylan_G · October 16, 2024, 11:04am

Setting the STARTLS policy to Disabled on both servers allows S2S connections to go through

Sending server to server ping request to chat.my.second.server
isAnonymousRoute() invoked with a JID that's not a full JID: chat.my.first.server
Routing to remote domain: 
<iq type="get" id="522-35" from="chat.my.first.server" to="chat.my.second.server">
  <ping xmlns="urn:xmpp:ping"/>
</iq>
A new outgoing session for {chat.my.first.server -> chat.my.second.server} is needed. Instantiating a new queue stanza for delivery when that's done.
Created new PacketProcessor for {chat.my.first.server -> chat.my.second.server}
Queuing stanza to intended recipient 'chat.my.second.server' in the outgoing session promise to domain '{chat.my.first.server -> chat.my.second.server}': <iq type="get" id="522-35" from="chat.my.first.server" to="chat.my.second.server"><ping xmlns="urn:xmpp:ping"/></iq>
Start for {chat.my.first.server -> chat.my.second.server}
Start establishing a connection for {chat.my.first.server -> chat.my.second.server}
Start domain authentication ...
Searching for pre-existing outgoing sessions to the remote domain (if one exists, it will be re-used) ...
There are no pre-existing outgoing sessions to the remote domain itself. Searching for pre-existing outgoing sessions to super- or subdomains of the remote domain (if one exists, it might be re-usable) ...
There are no pre-existing session to other domains hosted on the remote domain.
Unable to re-use an existing session. Creating a new session ...
Creating new session...
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@4d32d2bb
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@43f5256d
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@47cab9cb
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@2c82f56
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@59b492be
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@33000aa8
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@2196e9e2
instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@62e7d019
Creating plain socket connection to a host that belongs to the remote XMPP domain.
Creating a socket connection to XMPP domain 'chat.my.second.server' ...
Use DNS to resolve remote hosts for the provided XMPP domain 'chat.my.second.server' (default port: 5269) ...
DNS SRV Lookup for service 'xmpp-server', protocol 'tcp' and name 'chat.my.second.server'
Flushing pending nodes (count: 0)
No SRV record found for '_xmpp-server._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:120) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
DNS SRV Lookup for service 'jabber', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_jabber._tcp.chat.my.second.server.'
javax.naming.NameNotFoundException: DNS name not found [response code 3]
	at com.sun.jndi.dns.DnsClient.checkResponseCode(DnsClient.java:661) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.isMatchResponse(DnsClient.java:579) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:427) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsClient.query(DnsClient.java:212) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.Resolver.query(Resolver.java:81) ~[jdk.naming.dns:?]
	at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434) ~[jdk.naming.dns:?]
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) ~[?:?]
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) ~[?:?]
	at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) ~[?:?]
	at org.jivesoftware.openfire.net.DNSUtil.srvLookup(DNSUtil.java:236) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.DNSUtil.resolveXMPPDomain(DNSUtil.java:141) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.net.SocketUtil.createSocketToXmppDomain(SocketUtil.java:62) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.nio.NettySessionInitializer.init(NettySessionInitializer.java:100) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.createOutgoingSession(LocalOutgoingServerSession.java:262) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.session.LocalOutgoingServerSession.authenticateDomain(LocalOutgoingServerSession.java:209) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.establishConnection(OutgoingSessionPromise.java:288) [xmppserver-4.9.0.jar:4.9.0]
	at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:244) [xmppserver-4.9.0.jar:4.9.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Found 1 host(s) for XMPP domain 'chat.my.second.server'.
- chat.my.second.server:5269 (no direct TLS)
Trying to create socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269 (blocks up to 120000 ms) ...
Successfully created socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269!
Opening a new connection to chat.my.second.server/10.52.13.40:5269 that is initially not encrypted.
Adding NettyOutboundConnectionHandler
Netty XMPP handler added: null
Send the stream header and wait for response...
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" version="1.0">
Handler on /10.54.5.40:55578--chat.my.second.server/10.52.13.40:5269 received: <?xml version="1.0" encoding="UTF-8"?>
Handler on /10.54.5.40:55578--chat.my.second.server/10.52.13.40:5269 received: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" id="1ee0687o00" version="1.0">
Handler on /10.54.5.40:55578--chat.my.second.server/10.52.13.40:5269 received: <stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
Check if both us as well as the remote server have enabled STARTTLS and/or dialback ...
Remote server is offering dialback: true, EXTERNAL SASL: false
Trying to authenticate using dialback.
[Acting as Originating Server: Authenticate domain: chat.my.first.server with a RS in the domain of: chat.my.second.server (id: 1ee0687o00)]
Sending: <db:result from="chat.my.first.server" to="chat.my.second.server">488e2dc3b9f9503a5d1f7bb3e51a58c57051d958</db:result>
Adding NettyServerConnectionHandler
Netty XMPP handler added: /10.54.5.40:5269--/10.52.13.40:45920
Handler on /10.54.5.40:5269--/10.52.13.40:45920 received: <?xml version="1.0" encoding="UTF-8"?>
Handler on /10.54.5.40:5269--/10.52.13.40:45920 received: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" to="chat.my.first.server" from="chat.my.second.server" version="1.0">
Creating new session with stream ID '5n8i001tht' for local 'chat.my.first.server' to peer 'chat.my.second.server'.
Remote server is XMPP 1.0 compliant so offer TLS and SASL to establish the connection (and server dialback)
Outbound stream & feature advertisement: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" id="5n8i001tht" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" id="5n8i001tht" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Set the domain or subdomain of the local server targeted by the remote server: chat.my.first.server
Handler on /10.54.5.40:5269--/10.52.13.40:45920 received: <db:verify xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" id="1ee0687o00">488e2dc3b9f9503a5d1f7bb3e51a58c57051d958</db:verify>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback"
Verifying key... 
Sending: <db:verify from="chat.my.first.server" to="chat.my.second.server" type="valid" id="1ee0687o00"/>
Verification successful! Key was: VALID
Handler on /10.54.5.40:5269--/10.52.13.40:45920 received: </stream:stream>
Closing session as an end-of-stream was received: LocalIncomingServerSession{address=chat.my.first.server/a296bf6e-f265-4067-91fb-b9626d65aac5, streamID=5n8i001tht, status=CONNECTED, isEncrypted=false, isDetached=false, authenticationMethod=null, localDomain=chat.my.first.server, defaultIdentity=chat.my.second.server, validatedDomains={}}
Closing NettyConnection{peer: /10.52.13.40:45920, state: CLOSED, session: LocalIncomingServerSession{address=chat.my.first.server/a296bf6e-f265-4067-91fb-b9626d65aac5, streamID=5n8i001tht, status=CONNECTED, isEncrypted=false, isDetached=false, authenticationMethod=null, localDomain=chat.my.first.server, defaultIdentity=chat.my.second.server, validatedDomains={}}, Netty channel handler context name: NettyServerConnectionHandler#0} with optional error: null
Flushed any final bytes, closing connection.
Notifying close listeners.
Finished closing connection.
Netty XMPP handler removed: /10.54.5.40:5269--/10.52.13.40:45920
Handler on /10.54.5.40:55578--chat.my.second.server/10.52.13.40:5269 received: <db:result from="chat.my.second.server" to="chat.my.first.server" type="valid"/>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
Authentication succeeded!
Dialback was successful.
Created a new session.
Route 'chat.my.second.server' (for pair: '{chat.my.first.server -> chat.my.second.server}') added
Authentication successful.
Authentication exists for outgoing domain pair {chat.my.first.server -> chat.my.second.server}: true
Purging queue for {chat.my.first.server -> chat.my.second.server}
Routing queued stanza: 
<iq type="get" id="522-35" from="chat.my.first.server" to="chat.my.second.server">
  <ping xmlns="urn:xmpp:ping"/>
</iq>
Authentication exists for outgoing domain pair {chat.my.first.server -> chat.my.second.server}: true
Finished processing {chat.my.first.server -> chat.my.second.server}
Adding NettyServerConnectionHandler
Netty XMPP handler added: /10.54.5.40:5269--/10.52.13.40:45924
Closing NettyConnection{peer: /10.52.13.40:45924, state: CLOSED, session: null, Netty channel handler context name: NettyServerConnectionHandler#0} with optional error: null
Flushed any final bytes, closing connection.
Notifying close listeners.
Finished closing connection.
Netty XMPP handler removed: /10.54.5.40:5269--/10.52.13.40:45924
Adding NettyServerConnectionHandler
Netty XMPP handler added: /10.54.5.40:5269--/10.52.13.40:45938
Handler on /10.54.5.40:5269--/10.52.13.40:45938 received: <?xml version="1.0" encoding="UTF-8"?>
Handler on /10.54.5.40:5269--/10.52.13.40:45938 received: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.second.server" to="chat.my.first.server" version="1.0">
Creating new session with stream ID '7yveltjba5' for local 'chat.my.first.server' to peer 'chat.my.second.server'.
Remote server is XMPP 1.0 compliant so offer TLS and SASL to establish the connection (and server dialback)
Outbound stream & feature advertisement: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" id="7yveltjba5" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Sending: <?xml version="1.0" encoding="UTF-8"?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:server" xmlns:db="jabber:server:dialback" from="chat.my.first.server" to="chat.my.second.server" id="7yveltjba5" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><dialback xmlns="urn:xmpp:features:dialback"><errors/></dialback><limits xmlns="urn:xmpp:stream-limits:0"><max-bytes>1048576</max-bytes><idle-seconds>1800</idle-seconds></limits></stream:features>
Set the domain or subdomain of the local server targeted by the remote server: chat.my.first.server
Handler on /10.54.5.40:5269--/10.52.13.40:45938 received: <db:result from="chat.my.second.server" to="chat.my.first.server">d83d108e84da948004b503e6e7871d07e43b7666</db:result>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback"
Validating domain...
Check if the remote domain already has a connection to the target domain/subdomain
Checking to see if the remote server provides stronger authentication based on SASL. If that's the case, dialback-based authentication can be skipped.
Unable to authenticate host based on stronger SASL. Proceeding with dialback...
Creating a socket connection to XMPP domain 'chat.my.second.server' ...
Use DNS to resolve remote hosts for the provided XMPP domain 'chat.my.second.server' (default port: 5269) ...
DNS SRV Lookup for service 'xmpp-server', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_xmpp-server._tcp.chat.my.second.server.' (cached result)
DNS SRV Lookup for service 'jabber', protocol 'tcp' and name 'chat.my.second.server'
No SRV record found for '_jabber._tcp.chat.my.second.server.' (cached result)
Found 1 host(s) for XMPP domain 'chat.my.second.server'.
- chat.my.second.server:5269 (no direct TLS)
Trying to create socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269 (blocks up to 120000 ms) ...
Successfully created socket connection to XMPP domain 'chat.my.second.server' using remote host: chat.my.second.server:5269!
Verifying dialback key...
Opening a new connection to chat.my.second.server/10.52.13.40:5269 that is initially not encrypted.
Verifying key ...
Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
Attempting to instantiate 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager' using the three-argument constructor that is properietary to Openfire.
Constructed trust manager. Number of trusted issuers: 146, accepts self-signed: true, checks validity: true
Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
Send the Authoritative Server a stream header and wait for answer.
Got a response.
The remote server is XMPP 1.0 compliant (or at least reports to be).
Request for verification of the key and wait for response
Key was VERIFIED by the Authoritative Server.
Successfully verified key!
Successfully validated domain!
Sending: <db:result from="chat.my.first.server" to="chat.my.second.server" type="valid"/>
Handler on /10.54.5.40:5269--/10.52.13.40:45938 received: <iq type="get" id="617-29" to="chat.my.first.server" from="chat.my.second.server"><query xmlns="jabber:iq:version"/></iq>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback"
isAnonymousRoute() invoked with a JID that's not a full JID: chat.my.first.server
Routing to remote domain: 
<iq type="result" id="617-29" from="chat.my.first.server" to="chat.my.second.server">
  <query xmlns="jabber:iq:version">
    <name>Openfire</name>
    <version>4.9.0</version>
    <os>Linux 4.18.0-553.el8_10.x86_64 (amd64) - Java 11.0.22</os>
  </query>
</iq>
An outgoing session for {chat.my.first.server -> chat.my.second.server} is available on the local cluster node. Delivering stanza.
Authentication exists for outgoing domain pair {chat.my.first.server -> chat.my.second.server}: true
Handler on /10.54.5.40:5269--/10.52.13.40:45938 received: <iq type="result" id="779-36" from="chat.my.second.server" to="chat.my.first.server"><query xmlns="jabber:iq:version"><name>Openfire</name><version>4.9.0</version><os>Linux 4.18.0-553.el8_10.x86_64 (amd64) - Java 11.0.22</os></query></iq>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback"
XEP-0092 Packet from=chat.my.second.server name=Openfire
XEP-0092 Packet from=chat.my.second.server version=4.9.0
XEP-0092 Packet from=chat.my.second.server os=Linux 4.18.0-553.el8_10.x86_64 (amd64) - Java 11.0.22
Handler on /10.54.5.40:5269--/10.52.13.40:45938 received: <iq type="result" id="522-35" from="chat.my.second.server" to="chat.my.first.server"/>
Connection '[10, 52, 13, 40]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback"
Successful server to server response received.
Session is AUTHENTICATED.
Successfully negotiated TLS connection.

Incoming Session and Outgoing Session in Server Sessions both say Dialback

Dylan_G · October 21, 2024, 6:14am

Do the STARTLS logs help?

guus · October 24, 2024, 12:29pm

Possibly, but I can’t be sure without investing quite a bit of time to dig through those.

Dylan_G · October 25, 2024, 5:21am

Hi all, it turns out the issue was related to some CoPP policies on the routers between the two domains that were the cause of the issues. Once those were removed I was able to successfully communicate on both Openfire 4.7.5 and 4.9.0. Thanks for all the help.

guus · October 25, 2024, 7:13am

Ah, good to see that resolved. Is there anything that could have realistically been reported by Openfire to make the cause more obvious?