2024.05.24 09:13:26.048 [30mTRACE[m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.openfire.nio.NettyConnection - Closing NettyConnection{peer: gateway.com/192.168.75.1:5269, state: CLOSED, session: LocalOutgoingServerSession{address=server2.com, streamID=1ni3xc8s3x, status=AUTHENTICATED, isEncrypted=true, isDetached=false, authenticationMethod=SASL_EXTERNAL, outgoingDomainPairs={{server1.com -> server2.com}}}, Netty channel handler context name: NettyOutboundConnectionHandler#0} with optional error: null
2024.05.24 09:13:26.073 [30mTRACE[m [nioEventLoopGroup-9-1]: org.jivesoftware.openfire.nio.NettyConnection - Flushed any final bytes, closing connection.
2024.05.24 09:13:26.074 [30mTRACE[m [nioEventLoopGroup-9-1]: org.jivesoftware.openfire.nio.NettyConnection - Notifying close listeners.
2024.05.24 09:13:26.074 [30mTRACE[m [nioEventLoopGroup-9-1]: org.jivesoftware.openfire.spi.LocalRoutingTable - Remove local route 'server2.com' (for pair: '{server1.com -> server2.com}') removed
2024.05.24 09:13:26.074 [30mTRACE[m [nioEventLoopGroup-9-1]: org.jivesoftware.openfire.nio.NettyConnection - Finished closing connection.
2024.05.24 09:13:26.074 [32mINFO [m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.util.S2STestService - Sending server to server ping request to server2.com
2024.05.24 09:13:26.074 [30mTRACE[m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.openfire.spi.RoutingTableImpl - Routing to remote domain:
2024.05.24 09:13:26.082 [30mTRACE[m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.openfire.spi.RoutingTableImpl - A new outgoing session for {server1.com -> server2.com} is needed. Instantiating a new queue stanza for delivery when that's done.
2024.05.24 09:13:26.082 [36mDEBUG[m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.openfire.server.OutgoingSessionPromise - Created new PacketProcessor for {server1.com -> server2.com}
2024.05.24 09:13:26.082 [30mTRACE[m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor - Queuing stanza to intended recipient 'server2.com' in the outgoing session promise to domain '{server1.com -> server2.com}':
2024.05.24 09:13:26.099 [30mTRACE[m [nioEventLoopGroup-9-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Netty XMPP handler removed: /192.168.75.128:50060--gateway.com/192.168.75.1:5269
2024.05.24 09:13:26.099 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor - Start for {server1.com -> server2.com}
2024.05.24 09:13:26.102 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor - Start establishing a connection for {server1.com -> server2.com}
2024.05.24 09:13:26.102 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - Start domain authentication ...
2024.05.24 09:13:26.102 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - Searching for pre-existing outgoing sessions to the remote domain (if one exists, it will be re-used) ...
2024.05.24 09:13:26.102 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - 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) ...
2024.05.24 09:13:26.103 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - There are no pre-existing session to other domains hosted on the remote domain.
2024.05.24 09:13:26.103 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - Unable to re-use an existing session. Creating a new session ...
2024.05.24 09:13:26.103 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Create outgoing session for: {server1.com -> server2.com}] - Creating new session...
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@4777c8d4
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@434844e2
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@64ac2ef
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@4eceb10b
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@3706e16e
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@3668cc38
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@66653da0
2024.05.24 09:13:26.104 [30mTRACE[m [S2SOutgoingPromise-3]: io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.WindowsSelectorImpl@5d188e8e
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.nio.NettySessionInitializer - Creating plain socket connection to a host that belongs to the remote XMPP domain.
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.SocketUtil - Creating a socket connection to XMPP domain 'server2.com' ...
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.SocketUtil - Use DNS to resolve remote hosts for the provided XMPP domain 'server2.com' (default port: 5269) ...
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.DNSUtil - Answering lookup for domain 'server2.com' from DNS override property. Returning: gateway.com:5269
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.SocketUtil - Found 1 host(s) for XMPP domain 'server2.com'.
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.SocketUtil - - gateway.com:5269 (no direct TLS)
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.SocketUtil - Trying to create socket connection to XMPP domain 'server2.com' using remote host: gateway.com:5269 (blocks up to 120000 ms) ...
2024.05.24 09:13:26.104 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.net.SocketUtil - Successfully created socket connection to XMPP domain 'server2.com' using remote host: gateway.com:5269!
2024.05.24 09:13:26.175 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.nio.NettySessionInitializer - Opening a new connection to gateway.com/192.168.75.1:5269 that is initially not encrypted.
2024.05.24 09:13:26.181 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyOutboundConnectionHandler - Adding NettyOutboundConnectionHandler
2024.05.24 09:13:26.182 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Netty XMPP handler added: null
2024.05.24 09:13:26.187 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.nio.NettySessionInitializer - Send the stream header and wait for response...
2024.05.24 09:13:26.187 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.nio.NettySessionInitializer - Sending:
2024.05.24 09:13:26.202 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.203 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.206 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received: 10485761800
2024.05.24 09:13:26.206 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.StanzaHandler - Connection '[-64, -88, 75, 1]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
2024.05.24 09:13:26.209 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Both us and the remote server support the STARTTLS feature. Encrypt and authenticate the connection with TLS & SASL...
2024.05.24 09:13:26.209 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Indicating we want TLS and wait for response.
2024.05.24 09:13:26.209 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnection - Sending:
2024.05.24 09:13:26.214 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.214 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.StanzaHandler - Connection '[-64, -88, 75, 1]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
2024.05.24 09:13:26.215 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Received 'proceed' from remote server. Negotiating TLS...
2024.05.24 09:13:26.215 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Encrypting and authenticating connection ...
2024.05.24 09:13:26.215 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Configured TrustManager class: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager
2024.05.24 09:13:26.215 [36mDEBUG[m [nioEventLoopGroup-10-1]: 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.05.24 09:13:26.215 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Constructed trust manager. Number of trusted issuers: 145, accepts self-signed: true, checks validity: true
2024.05.24 09:13:26.215 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.spi.EncryptionArtifactFactory - Successfully instantiated 'class org.jivesoftware.openfire.keystore.OpenfireX509TrustManager'.
2024.05.24 09:13:26.235 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Attempting to verify a chain of 1 certificates.
2024.05.24 09:13:26.235 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Attempting to accept the self-signed certificate of this chain of length one, as instructed by configuration.
2024.05.24 09:13:26.235 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Chain of one appears to be self-signed. Adding it to the set of trusted issuers.
2024.05.24 09:13:26.235 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Validating chain with 1 certificates, using 144 trust anchors.
2024.05.24 09:13:26.280 [36mDEBUG[m [nioEventLoopGroup-10-1]: io.netty.handler.ssl.SslHandler - [id: 0xb540185c, L:/192.168.75.128:50080 - R:gateway.com/192.168.75.1:5269] HANDSHAKEN: protocol:TLSv1.2 cipher suite:TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384
2024.05.24 09:13:26.280 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.util.CertificateManager - CertificateManager: Subject Alternative Name Mapping returned [*.gateway.com, gateway.com]
2024.05.24 09:13:26.280 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyOutboundConnectionHandler - TLS negotiation with 'server2.com' was successful, but peer's certificates are not valid for its domain.
2024.05.24 09:13:26.280 [33mWARN [m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyOutboundConnectionHandler - As peer's certificates are not valid for its domain ('server2.com'), the SASL EXTERNAL authentication mechanism cannot be used. The Server Dialback authentication mechanism is available.
2024.05.24 09:13:26.280 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnection - Sending:
2024.05.24 09:13:26.289 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.289 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.291 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Session not authenticated yet, unable to setAuthenticationMethod().
2024.05.24 09:13:26.291 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received: EXTERNAL10485761800
2024.05.24 09:13:26.291 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.StanzaHandler - Connection '[-64, -88, 75, 1]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
2024.05.24 09:13:26.291 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Check if both us as well as the remote server have enabled STARTTLS and/or dialback ...
2024.05.24 09:13:26.291 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Remote server is offering dialback: false, EXTERNAL SASL: true
2024.05.24 09:13:26.291 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Trying to authenticate with EXTERNAL SASL.
2024.05.24 09:13:26.291 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - Starting EXTERNAL SASL for: {server1.com -> server2.com}
2024.05.24 09:13:26.291 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnection - Sending: Z3JjLmJpY2VzLm9yZw==
2024.05.24 09:13:26.307 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.307 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.StanzaHandler - Connection '[-64, -88, 75, 1]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
2024.05.24 09:13:26.307 [36mDEBUG[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.RespondingServerStanzaHandler - EXTERNAL SASL was successful.
2024.05.24 09:13:26.307 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnection - Sending:
2024.05.24 09:13:26.310 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - Created a new session.
2024.05.24 09:13:26.310 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.spi.LocalRoutingTable - Route 'server2.com' (for pair: '{server1.com -> server2.com}') added
2024.05.24 09:13:26.310 [36mDEBUG[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'server1.com' to remote domain: 'server2.com'] - Authentication successful.
2024.05.24 09:13:26.312 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.312 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received:
2024.05.24 09:13:26.312 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.nio.NettyConnectionHandler - Handler on /192.168.75.128:50080--gateway.com/192.168.75.1:5269 received: 10485761800
2024.05.24 09:13:26.312 [30mTRACE[m [nioEventLoopGroup-10-1]: org.jivesoftware.openfire.net.StanzaHandler - Connection '[-64, -88, 75, 1]' defined namespace prefixes on its original 'stream' element: xmlns:db="jabber:server:dialback", xmlns:stream="http://etherx.jabber.org/streams"
2024.05.24 09:13:26.312 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession - Authentication exists for outgoing domain pair {server1.com -> server2.com}: true
2024.05.24 09:13:26.316 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor - Purging queue for {server1.com -> server2.com}
2024.05.24 09:13:26.316 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor - Routing queued stanza:
2024.05.24 09:13:26.317 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.session.LocalOutgoingServerSession - Authentication exists for outgoing domain pair {server1.com -> server2.com}: true
2024.05.24 09:13:26.318 [30mTRACE[m [S2SOutgoingPromise-3]: org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor - Finished processing {server1.com -> server2.com}
2024.05.24 09:13:28.125 [36mDEBUG[m [nioEventLoopGroup-9-1]: io.netty.buffer.PoolThreadCache - Freed 19 thread-local buffer(s) from thread: nioEventLoopGroup-9-1
2024.05.24 09:13:42.869 [30mTRACE[m [Jetty-QTP-AdminConsole-35]: org.jivesoftware.admin.AuthCheckFilter - Address '127.0.0.1' is not an IPv6 address.
2024.05.24 09:13:42.871 [36mDEBUG[m [Jetty-QTP-AdminConsole-35]: org.jivesoftware.admin.AuthCheckFilter - IP address '127.0.0.1' does pass the block list.
2024.05.24 09:13:42.871 [36mDEBUG[m [Jetty-QTP-AdminConsole-35]: org.jivesoftware.admin.AuthCheckFilter - IP address '127.0.0.1' does pass the allow list.
2024.05.24 09:13:42.873 [36mDEBUG[m [Jetty-QTP-AdminConsole-35]: org.jivesoftware.util.WebManager - Unable to get user: no session or no auth token on session.
2024.05.24 09:15:05.432 [30mTRACE[m [TaskEngine-pool-5]: org.jivesoftware.openfire.pubsub.CachingPubsubPersistenceProvider - Flushing pending nodes (count: 0)
2024.05.24 09:15:26.083 [32mINFO [m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.util.S2STestService - Session is AUTHENTICATED.
2024.05.24 09:15:26.084 [32mINFO [m [Jetty-QTP-AdminConsole-63]: org.jivesoftware.util.S2STestService - Successfully negotiated TLS connection.