From 8362724384b6b225a899c71cfd7b6963d09a9f68 Mon Sep 17 00:00:00 2001 From: Guus der Kinderen Date: Fri, 3 Jan 2025 22:38:53 +0100 Subject: [PATCH 1/7] Add debug logging for ServerSessionTest No functional changes to the unit tests, but adds a simple mechanism to record how much time passed between logged statements. --- .../session/AbstractRemoteServerDummy.java | 21 +++- .../LocalIncomingServerSessionTest.java | 41 ++++--- .../LocalOutgoingServerSessionTest.java | 16 ++- .../session/RemoteInitiatingServerDummy.java | 105 +++++++++--------- .../session/RemoteReceivingServerDummy.java | 57 +++++----- 5 files changed, 141 insertions(+), 99 deletions(-) diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/AbstractRemoteServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/AbstractRemoteServerDummy.java index 8f150a9b66..ecc12d3bd0 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/AbstractRemoteServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/AbstractRemoteServerDummy.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2023 Ignite Realtime Foundation. All rights reserved. + * Copyright (C) 2023-2025 Ignite Realtime Foundation. All rights reserved. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -38,6 +38,12 @@ public class AbstractRemoteServerDummy { + /** + * When switched to 'true', most XMPP interaction will be printed to standard-out. + */ + public static final boolean doLog = false; + public static long lastLog = System.currentTimeMillis(); + public static final String XMPP_DOMAIN = "remote-dummy.example.org"; private final static KeystoreTestUtils.ResultHolder SELF_SIGNED_CERTIFICATE; @@ -64,6 +70,19 @@ public class AbstractRemoteServerDummy } } + /** + * Logs a message, but only if logging is enabled (which is controlled by the {@link #doLog} field). + * + * @param message The message to be logged. + */ + public static void log(final String message) { + if (doLog) { + long delta = System.currentTimeMillis() - lastLog; + System.out.println(delta + "ms: " + message); + lastLog = System.currentTimeMillis(); + } + } + /** * Updates the TLS encryption policy that's observed by this server. */ diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalIncomingServerSessionTest.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalIncomingServerSessionTest.java index f2bcbf340f..9cf2e75a56 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalIncomingServerSessionTest.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalIncomingServerSessionTest.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2023 Ignite Realtime Foundation. All rights reserved. + * Copyright (C) 2023-2025 Ignite Realtime Foundation. All rights reserved. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -193,19 +193,20 @@ public void incomingTest(final ServerSettings localServerSettings, final ServerS throws Exception { final ExpectedOutcome expected = ExpectedOutcome.generateExpectedOutcome(remoteServerSettings, localServerSettings); - if (RemoteInitiatingServerDummy.doLog) System.out.println("Executing test:\n - Local Server, Recipient, System Under Test Settings: " + localServerSettings + "\n - Remote Server, Initiator, dummy/mock server Settings: " + remoteServerSettings + "\nExpected outcome: " + expected.getConnectionState()); + AbstractRemoteServerDummy.log("Executing test:\n - Local Server (Recipient, System Under Test) Settings: " + localServerSettings + "\n - Remote Server (Initiator, dummy/mock server) Settings: " + remoteServerSettings + "\nExpected outcome: " + expected.getConnectionState()); ConnectionListener connectionListener = null; try { - // Setup test fixture. + AbstractRemoteServerDummy.log("Setup fixture: (start setting up fixture)"); - // Remote server TLS policy. + // Setup test fixture. + AbstractRemoteServerDummy.log("Setup fixture: remote server TLS policy."); remoteInitiatingServerDummy.setEncryptionPolicy(remoteServerSettings.encryptionPolicy); - // Remote server dialback + AbstractRemoteServerDummy.log("Setup fixture: remote server dialback."); remoteInitiatingServerDummy.setDisableDialback(!remoteServerSettings.dialbackSupported); - // Remote server certificate state + AbstractRemoteServerDummy.log("Setup fixture: remote server certificate state."); switch (remoteServerSettings.certificateState) { case INVALID: remoteInitiatingServerDummy.setUseExpiredEndEntityCertificate(true); @@ -224,13 +225,13 @@ public void incomingTest(final ServerSettings localServerSettings, final ServerS throw new IllegalStateException("Unsupported remote certificate state"); } - // Local server TLS policy. + AbstractRemoteServerDummy.log("Setup fixture: local server TLS policy."); JiveGlobals.setProperty(ConnectionSettings.Server.TLS_POLICY, localServerSettings.encryptionPolicy.toString()); - // Local server dialback. + AbstractRemoteServerDummy.log("Setup fixture: local server dialback."); JiveGlobals.setProperty(ConnectionSettings.Server.DIALBACK_ENABLED, localServerSettings.dialbackSupported ? "true" : "false"); - // Local server certificate state + AbstractRemoteServerDummy.log("Setup fixture: local server certificate state."); switch (localServerSettings.certificateState) { case MISSING: // Do not install domain certificate. @@ -245,12 +246,15 @@ public void incomingTest(final ServerSettings localServerSettings, final ServerS break; } + AbstractRemoteServerDummy.log("Setup fixture: remote server init"); remoteInitiatingServerDummy.init(); if (remoteInitiatingServerDummy.getDialbackAuthoritativeServerPort() > 0) { DNSUtil.setDnsOverride(Map.of(RemoteInitiatingServerDummy.XMPP_DOMAIN, new SrvRecord("localhost", remoteInitiatingServerDummy.getDialbackAuthoritativeServerPort(), false))); } + AbstractRemoteServerDummy.log("Setup fixture: (done with setting up fixture)"); // execute system under test. + AbstractRemoteServerDummy.log("Execute system under test: (start with execution)"); JiveGlobals.setProperty(ConnectionSettings.Server.OLD_SSLPORT, String.valueOf(findFreeLocalPort())); connectionListener = new ConnectionListener(ConnectionType.SOCKET_S2S, ConnectionSettings.Server.OLD_SSLPORT, @@ -264,18 +268,22 @@ public void incomingTest(final ServerSettings localServerSettings, final ServerS identityStore.getConfiguration(), trustStore.getConfiguration(), ConnectionSettings.Server.COMPRESSION_SETTINGS); + AbstractRemoteServerDummy.log("Execute system under test: starting connection listener"); connectionListener.start(); + AbstractRemoteServerDummy.log("Execute system under test: mocking connection manager"); final ConnectionManager connectionManager = Fixtures.mockConnectionManager(); doReturn(Set.of(connectionListener)).when(connectionManager).getListeners(any(ConnectionType.class)); doReturn(connectionListener).when(connectionManager).getListener(any(ConnectionType.class), anyBoolean()); doReturn(connectionManager).when(XMPPServer.getInstance()).getConnectionManager(); - // now, make the remote server connect. + AbstractRemoteServerDummy.log("Execute system under test: make the remote server connect."); remoteInitiatingServerDummy.connect(connectionListener.getPort()); + AbstractRemoteServerDummy.log("Execute system under test: start connecting, block until done."); remoteInitiatingServerDummy.blockUntilDone(1, TimeUnit.MINUTES); + AbstractRemoteServerDummy.log("Execute system under test: done connecting."); - // get the incoming server session object. + AbstractRemoteServerDummy.log("Execute system under test: get the incoming server session object."); final LocalIncomingServerSession result; if (remoteInitiatingServerDummy.getReceivedStreamIDs().isEmpty()) { result = null; @@ -284,9 +292,11 @@ public void incomingTest(final ServerSettings localServerSettings, final ServerS final StreamID lastReceivedID = remoteInitiatingServerDummy.getReceivedStreamIDs().get(remoteInitiatingServerDummy.getReceivedStreamIDs().size()-1); result = XMPPServer.getInstance().getSessionManager().getIncomingServerSession( lastReceivedID ); } + AbstractRemoteServerDummy.log("Execute system under test: (done with execution)"); // Verify results - if (RemoteInitiatingServerDummy.doLog) System.out.println("Expect: " + expected.getConnectionState() + ", Result: " + result); + AbstractRemoteServerDummy.log("Verify results (start)"); + AbstractRemoteServerDummy.log("Expect: " + expected.getConnectionState() + ", Result: " + result); switch (expected.getConnectionState()) { case NO_CONNECTION: @@ -332,13 +342,16 @@ public void incomingTest(final ServerSettings localServerSettings, final ServerS assertEquals(2, remoteInitiatingServerDummy.getReceivedStreamFromValues().size()); break; } - if (RemoteInitiatingServerDummy.doLog) System.out.println("Expectation met."); + AbstractRemoteServerDummy.log("Expectation met."); + AbstractRemoteServerDummy.log("Verify results (done)"); } finally { // Teardown test fixture. + AbstractRemoteServerDummy.log("Teardown test fixture (start)"); trustStore.delete("unit-test"); if (connectionListener != null) { connectionListener.stop(); } + AbstractRemoteServerDummy.log("Teardown test fixture (done)"); } } @@ -376,7 +389,7 @@ private static Iterable arguments() { // failed test case. int i = 1; for (Arguments arguments : result) { - System.out.println("Test [" + i++ + "]: " + arguments.get()[0] + ", " + arguments.get()[1]); + AbstractRemoteServerDummy.log("Test [" + i++ + "]: " + arguments.get()[0] + ", " + arguments.get()[1]); } return result; } diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalOutgoingServerSessionTest.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalOutgoingServerSessionTest.java index d31df46b39..4897fd65ca 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalOutgoingServerSessionTest.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/LocalOutgoingServerSessionTest.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2023 Ignite Realtime Foundation. All rights reserved. + * Copyright (C) 2023-2025 Ignite Realtime Foundation. All rights reserved. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -232,12 +232,13 @@ public void outgoingTest(final ServerSettings localServerSettings, final ServerS throws Exception { final ExpectedOutcome expected = ExpectedOutcome.generateExpectedOutcome(localServerSettings, remoteServerSettings); - if (RemoteReceivingServerDummy.doLog) System.out.println("Executing test:\n - Local Server (Openfire, System under test) Settings: " + localServerSettings + "\n - Remote Server (dummy/mock server) Settings: " + remoteServerSettings + "\nExpected outcome: " + expected.getConnectionState()); + AbstractRemoteServerDummy.log("Executing test:\n - Local Server (Initiator, Openfire, System under test) Settings: " + localServerSettings + "\n - Remote Server (Recipient, dummy/mock server) Settings: " + remoteServerSettings + "\nExpected outcome: " + expected.getConnectionState()); JiveGlobals.setProperty("xmpp.domain", Fixtures.XMPP_DOMAIN); JiveGlobals.setProperty("xmpp.server.session.initialise-timeout", Long.toString(1)); try { + AbstractRemoteServerDummy.log("Setup fixture: (start setting up fixture)"); // Setup test fixture. // Remote server TLS policy. @@ -288,12 +289,16 @@ public void outgoingTest(final ServerSettings localServerSettings, final ServerS final DomainPair domainPair = new DomainPair(Fixtures.XMPP_DOMAIN, RemoteReceivingServerDummy.XMPP_DOMAIN); final int port = remoteReceivingServerDummy.getPort(); + AbstractRemoteServerDummy.log("Setup fixture: (done with setting up fixture)"); // Execute system under test. + AbstractRemoteServerDummy.log("Execute system under test: (start with execution)"); final LocalOutgoingServerSession result = LocalOutgoingServerSession.createOutgoingSession(domainPair, port); + AbstractRemoteServerDummy.log("Execute system under test: (done with execution)"); // Verify results - if (RemoteReceivingServerDummy.doLog) System.out.println("Expect: " + expected.getConnectionState() + ", Result: " + result); + AbstractRemoteServerDummy.log("Verify results (start)"); + AbstractRemoteServerDummy.log("Expect: " + expected.getConnectionState() + ", Result: " + result); switch (expected.getConnectionState()) { case NO_CONNECTION: @@ -323,9 +328,12 @@ public void outgoingTest(final ServerSettings localServerSettings, final ServerS assertEquals( "TLSv1.3", result.getConnection().getTLSProtocolName().get()); break; } + AbstractRemoteServerDummy.log("Verify results (done)"); } finally { // Teardown test fixture. + AbstractRemoteServerDummy.log("Teardown test fixture (start)"); trustStore.delete("unit-test"); + AbstractRemoteServerDummy.log("Teardown test fixture (start)"); } } @@ -363,7 +371,7 @@ private static Iterable arguments() { // failed test case. int i = 1; for (Arguments arguments : result) { - System.out.println("Test [" + i++ + "]: " + arguments.get()[0] + ", " + arguments.get()[1]); + AbstractRemoteServerDummy.log("Test [" + i++ + "]: " + arguments.get()[0] + ", " + arguments.get()[1]); } return result; } diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java index bd8b2fbf42..d8b69d0b1d 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2023-2024 Ignite Realtime Foundation. All rights reserved. + * Copyright (C) 2023-2025 Ignite Realtime Foundation. All rights reserved. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -43,11 +43,6 @@ public class RemoteInitiatingServerDummy extends AbstractRemoteServerDummy { - /** - * When switched to 'true', most XMPP interaction will be printed to standard-out. - */ - public static final boolean doLog = false; - private ServerSocket dialbackAuthoritativeServer; private Thread dialbackAcceptThread; private DialbackAcceptor dialbackAcceptor = new DialbackAcceptor(); @@ -66,7 +61,7 @@ public class RemoteInitiatingServerDummy extends AbstractRemoteServerDummy * help the unit test know when it can start verifying the test outcome. */ private final Phaser phaser = new Phaser(0); - + public RemoteInitiatingServerDummy(final String connectTo) { this.connectTo = connectTo; @@ -81,7 +76,7 @@ public void init() throws IOException public void connect(int port) throws IOException, InterruptedException { - if (doLog) System.out.println("connect"); + log("connect"); processingService = Executors.newCachedThreadPool(); if (dialbackAuthoritativeServer != null) { @@ -105,30 +100,38 @@ public void blockUntilDone(final long timeout, final TimeUnit unit) { protected void done() { + log("Start being done"); if (!getReceivedStreamIDs().isEmpty()) { // If we recorded a stream ID, wait for this stream to be registered in the session manager before // continuing to prevent a race condition. + log("Wait for stream to be registered in the session manager"); final Instant stopWaiting = Instant.now().plus(500, ChronoUnit.MILLIS); try { final StreamID lastReceivedID = getReceivedStreamIDs().get(getReceivedStreamIDs().size()-1); final SessionManager sessionManager = XMPPServer.getInstance().getSessionManager(); + boolean found = false; while (Instant.now().isBefore(stopWaiting)) { if (sessionManager.getIncomingServerSession( lastReceivedID ) != null) { + log("Found stream registered in the session manager"); + found = true; break; } Thread.sleep(10); } + if (!found) log("NEVER FOUND STREAM WE WERE (pointlessly?) WAITING FOR!"); } catch (InterruptedException e) { throw new RuntimeException(e); } } + log("Phaser arriving and registering"); phaser.arriveAndDeregister(); + log("Done being done"); } public void disconnect() throws InterruptedException, IOException { - if (doLog) System.out.println("disconnect"); + log("disconnect"); stopProcessingService(); stopDialbackAcceptThread(); if (dialbackAuthoritativeServer != null) { @@ -219,22 +222,22 @@ void stop() { @Override public void run() { - if (doLog) System.out.println("Start accepting socket connections (as Server Dialback Authoritative Server)."); + log("Start accepting socket connections (as Server Dialback Authoritative Server)."); while (!shouldStop) { try { dialbackAuthoritativeServer.setSoTimeout((int)SO_TIMEOUT.multipliedBy(10).toMillis()); final Socket socket = dialbackAuthoritativeServer.accept(); final InputStream is = socket.getInputStream(); final OutputStream os = socket.getOutputStream(); - if (doLog) System.out.println("DIALBACK AUTH SERVER: Accepted new socket connection."); + log("DIALBACK AUTH SERVER: Accepted new socket connection."); final byte[] buffer = new byte[1024 * 16]; int count; while ((count = is.read(buffer)) > 0) { String read = new String(buffer, 0, count); - if (doLog) System.out.println("# DIALBACK AUTH SERVER recv"); - if (doLog) System.out.println(read); - if (doLog) System.out.println(); + log("# DIALBACK AUTH SERVER recv"); + log(read); + log(""); final Document outbound = DocumentHelper.createDocument(); final Namespace namespace = new Namespace("stream", "http://etherx.jabber.org/streams"); @@ -266,13 +269,13 @@ public void run() } else if (read.equals("")) { response = ""; } else { - if (doLog) System.out.println("I don't know how to process this data."); + log("I don't know how to process this data."); } if (response != null) { - if (doLog) System.out.println("# DIALBACK AUTH SERVER send to Openfire"); - if (doLog) System.out.println(response); - if (doLog) System.out.println(); + log("# DIALBACK AUTH SERVER send to Openfire"); + log(response); + log(""); os.write(response.getBytes()); os.flush(); @@ -293,7 +296,7 @@ public void run() } } } - if (doLog) System.out.println("Stopped accepting socket connections (as Server Dialback Authoritative Server)."); + log("Stopped accepting socket connections (as Server Dialback Authoritative Server)."); } } @@ -316,7 +319,7 @@ private SocketProcessor(int port) throws IOException { socket = new Socket(); final InetSocketAddress socketAddress = new InetSocketAddress(InetAddress.getLoopbackAddress(), port); - if (doLog) System.out.println("Creating new socket to " + socketAddress); + log("Creating new socket to " + socketAddress); socket.connect(socketAddress, (int) SO_TIMEOUT.toMillis()); os = socket.getOutputStream(); is = socket.getInputStream(); @@ -324,7 +327,7 @@ private SocketProcessor(int port) throws IOException private SocketProcessor(Socket socket) throws IOException { - if (doLog) System.out.println("New session on socket"); + log("New session on socket"); this.socket = socket; os = socket.getOutputStream(); @@ -333,9 +336,9 @@ private SocketProcessor(Socket socket) throws IOException public synchronized void send(final String data) throws IOException { - if (doLog) System.out.println("# send from remote to Openfire" + (socket instanceof SSLSocket ? " (encrypted)" : "")); - if (doLog) System.out.println(data); - if (doLog) System.out.println(); + log("# send from remote to Openfire" + (socket instanceof SSLSocket ? " (encrypted)" : "")); + log(data); + log(""); os.write(data.getBytes()); os.flush(); } @@ -343,7 +346,7 @@ public synchronized void send(final String data) throws IOException @Override public void run() { - if (doLog) System.out.println("Start reading from socket" + (socket instanceof SSLSocket ? " (encrypted)" : "")); + log("Start reading from socket" + (socket instanceof SSLSocket ? " (encrypted)" : "")); try { sendStreamHeader(); @@ -354,26 +357,26 @@ public void run() while (!processingService.isShutdown() && (count = is.read(buffer)) > 0) { String read = new String(buffer, 0, count); if (read.startsWith("") + 2; read = read.substring(endProlog); } if (read.startsWith("", " xmlns:stream=\"http://etherx.jabber.org/streams\">"); - if (doLog) System.out.println("# recv (Hacked inbound stanza to include stream namespace declaration)" + (socket instanceof SSLSocket ? " (encrypted)" : "")); + log("# recv (Hacked inbound stanza to include stream namespace declaration)" + (socket instanceof SSLSocket ? " (encrypted)" : "")); } else if (read.startsWith("")) { @@ -411,10 +414,10 @@ public void run() case "failure": if (inbound.getNamespaceURI().equals("urn:ietf:params:xml:ns:xmpp-sasl")) { if (processSaslResponse(inbound)) { - if (doLog) System.out.println("Successfully authenticated using SASL! We're done setting up a connection."); + log("Successfully authenticated using SASL! We're done setting up a connection."); return; } else if (peerSupportsDialback && !disableDialback) { - if (doLog) System.out.println("Unable to authenticate using SASL! Dialback seems to be available. Trying that..."); + log("Unable to authenticate using SASL! Dialback seems to be available. Trying that..."); startDialbackAuth(); break; } else { @@ -425,7 +428,7 @@ public void run() } // intended fall-through default: - if (doLog) System.out.println("Received stanza '" + inbound.getName() + "' that I don't know how to respond to." + (socket instanceof SSLSocket ? " (encrypted)" : "")); + log("Received stanza '" + inbound.getName() + "' that I don't know how to respond to." + (socket instanceof SSLSocket ? " (encrypted)" : "")); } } else { // received an end of stream: if the peer closes the connection, then we're done trying. @@ -440,14 +443,14 @@ public void run() } } } while (!processingService.isShutdown() && allowableSocketTimeouts > 0); - if (doLog) System.out.println("Ending read loop."); + log("Ending read loop."); } catch (Throwable t) { // Log exception only when not cleanly closed. if (doLog && !processingService.isShutdown()) { t.printStackTrace(); } } finally { - if (doLog) System.out.println("Stopped reading from socket"); + log("Stopped reading from socket"); done(); } } @@ -485,11 +488,11 @@ private void negotiateFeatures(final Element features) throws IOException */ private boolean negotiateEncryption(final Element features) throws IOException { - if (doLog) System.out.println("Negotiating encryption..."); + log("Negotiating encryption..."); final Element startTLSel = features.element(QName.get("starttls", "urn:ietf:params:xml:ns:xmpp-tls")); final boolean peerSupportsStartTLS = startTLSel != null; final boolean peerRequiresStartTLS = peerSupportsStartTLS && startTLSel.element("required") != null; - if (doLog) System.out.println("Openfire " + (peerRequiresStartTLS ? "requires" : (peerSupportsStartTLS ? "supports" : "does not support" )) + " StartTLS. Our own policy: " + encryptionPolicy + "."); + log("Openfire " + (peerRequiresStartTLS ? "requires" : (peerSupportsStartTLS ? "supports" : "does not support" )) + " StartTLS. Our own policy: " + encryptionPolicy + "."); switch (encryptionPolicy) { case disabled: @@ -534,7 +537,7 @@ private boolean negotiateEncryption(final Element features) throws IOException } private void initiateTLS() throws IOException { - if (doLog) System.out.println("Initiating TLS..."); + log("Initiating TLS..."); final Document outbound = DocumentHelper.createDocument(); final Element startTls = outbound.addElement(QName.get("starttls", "urn:ietf:params:xml:ns:xmpp-tls")); send(startTls.asXML()); @@ -542,8 +545,8 @@ private void initiateTLS() throws IOException { private void processStartTLSProceed(Element proceed) throws IOException, NoSuchAlgorithmException, KeyManagementException { - if (doLog) System.out.println("Received StartTLS proceed."); - if (doLog) System.out.println("Replace the socket with one that will do TLS on the next inbound and outbound data"); + log("Received StartTLS proceed."); + log("Replace the socket with one that will do TLS on the next inbound and outbound data"); final SSLContext sc = SSLContext.getInstance("TLSv1.3"); @@ -563,7 +566,7 @@ private void processStartTLSProceed(Element proceed) throws IOException, NoSuchA final SSLSocket sslSocket = (SSLSocket) ((SSLSocketFactory) SSLSocketFactory.getDefault()).createSocket(socket, null, socket.getPort(), true); sslSocket.setSoTimeout((int) SO_TIMEOUT.multipliedBy(10).toMillis()); // TLS handshaking is resource intensive. Relax the SO_TIMEOUT value a bit, to prevent test failures in constraint environments. - sslSocket.addHandshakeCompletedListener(event -> { if (doLog) System.out.println("SSL handshake completed: " + event); }); + sslSocket.addHandshakeCompletedListener(event -> { log("SSL handshake completed: " + event); }); sslSocket.startHandshake(); // Just indicate that we would like to authenticate the client but if client @@ -577,24 +580,24 @@ private void processStartTLSProceed(Element proceed) throws IOException, NoSuchA } private void negotiateAuthentication(final Element features) throws IOException { - if (doLog) System.out.println("Negotiating authentication..."); + log("Negotiating authentication..."); final Element mechanismsEl = features.element(QName.get("mechanisms", "urn:ietf:params:xml:ns:xmpp-sasl")); final boolean peerSupportsSASLExternal = mechanismsEl != null && mechanismsEl.elements().stream().anyMatch(element -> "mechanism".equals(element.getName()) && "EXTERNAL".equals(element.getTextTrim())); peerSupportsDialback = peerAdvertisedDialbackNamespace || features.element(QName.get("dialback", "urn:xmpp:features:dialback")) != null; - if (doLog) System.out.println("Openfire " + (peerSupportsSASLExternal ? "offers" : "does not offer") + " SASL EXTERNAL, " + (peerSupportsDialback ? "supports" : "does not support") + " Server Dialback. Our own policy: SASL EXTERNAL " + (encryptionPolicy != Connection.TLSPolicy.disabled ? "available" : "not available") + ", Dialback: " + (!disableDialback ? "supported" : "not supported") + "."); + log("Openfire " + (peerSupportsSASLExternal ? "offers" : "does not offer") + " SASL EXTERNAL, " + (peerSupportsDialback ? "supports" : "does not support") + " Server Dialback. Our own policy: SASL EXTERNAL " + (encryptionPolicy != Connection.TLSPolicy.disabled ? "available" : "not available") + ", Dialback: " + (!disableDialback ? "supported" : "not supported") + "."); if (peerSupportsSASLExternal && encryptionPolicy != Connection.TLSPolicy.disabled && !alreadyTriedSaslExternal) { authenticateUsingSaslExternal(); } else if (peerSupportsDialback && !disableDialback) { startDialbackAuth(); } else { - if (doLog) System.out.println("Unable to do authentication."); + log("Unable to do authentication."); throw new InterruptedIOException("Unable to do authentication."); } } private void authenticateUsingSaslExternal() throws IOException { - if (doLog) System.out.println("Authenticating using SASL EXTERNAL"); + log("Authenticating using SASL EXTERNAL"); alreadyTriedSaslExternal = true; final Document outbound = DocumentHelper.createDocument(); final Element root = outbound.addElement(QName.get("auth", "urn:ietf:params:xml:ns:xmpp-sasl")); @@ -604,7 +607,7 @@ private void authenticateUsingSaslExternal() throws IOException { } private void startDialbackAuth() throws IOException { - if (doLog) System.out.println("Authenticating using Server Dialback"); + log("Authenticating using Server Dialback"); allowableSocketTimeouts = 10; final String key = "UNITTESTDIALBACKKEY"; @@ -619,18 +622,18 @@ private void startDialbackAuth() throws IOException { private void processDialbackResult(final Element result) throws IOException { final String type = result.attributeValue("type"); - if (doLog) System.out.println("Openfire reports Server Dialback result of type " + type); + log("Openfire reports Server Dialback result of type " + type); if (!"valid".equals(type)) { throw new InterruptedIOException("Server Dialback failed"); } - if (doLog) System.out.println("Successfully authenticated using Server Dialback! We're done setting up a connection."); + log("Successfully authenticated using Server Dialback! We're done setting up a connection."); done(); } private boolean processSaslResponse(final Element result) throws IOException { final String name = result.getName(); - if (doLog) System.out.println("Openfire reports SASL result of type " + name); + log("Openfire reports SASL result of type " + name); return "success".equals(name); } } diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java index 41ff44fb1b..512fbe7cb2 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2023-2024 Ignite Realtime Foundation. All rights reserved. + * Copyright (C) 2023-2025 Ignite Realtime Foundation. All rights reserved. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -50,11 +50,6 @@ */ public class RemoteReceivingServerDummy extends AbstractRemoteServerDummy implements AutoCloseable { - /** - * When switched to 'true', most XMPP interaction will be printed to standard-out. - */ - public static final boolean doLog = false; - private ServerSocket server; private Thread acceptThread; @@ -144,18 +139,21 @@ private class Acceptor implements Runnable boolean shouldStop = false; void stop() { + log("Start stopping accepting connections."); shouldStop = true; } @Override public void run() { - if (doLog) System.out.println("Start accepting socket connections."); + log("Start accepting socket connections."); while (!shouldStop) { try { + log("Waiting for new socket."); + server.setSoTimeout((int)SO_TIMEOUT.multipliedBy(10).toMillis()); - final Socket socket = server.accept(); - if (doLog) System.out.println("Accepted new socket connection."); + final Socket socket = server.accept(); // This cannot be interrupted, which makes the entire test run very slow. + log("Accepted new socket connection."); processingService.submit(new SocketProcessor(socket)); } catch (Throwable t) { @@ -165,11 +163,12 @@ public void run() t.printStackTrace(); } } else { + log("Stop accepting (interrupted?)."); break; } } } - if (doLog) System.out.println("Stopped socket accepting connections."); + log("Stopped socket accepting connections."); } } @@ -190,7 +189,7 @@ private class SocketProcessor implements Runnable private SocketProcessor(Socket socket) throws IOException { - if (doLog) System.out.println("New session on socket."); + log("New session on socket."); if (socket instanceof SSLSocket) { allowableSocketTimeouts = 10; // A new TLS-connection has been observed to require some extra time (when Dialback-over-TLS is happening). @@ -202,9 +201,9 @@ private SocketProcessor(Socket socket) throws IOException public synchronized void send(final String data) throws IOException { - if (doLog) System.out.println("# send from remote to Openfire" + (socket instanceof SSLSocket ? " (encrypted)" : "")); - if (doLog) System.out.println(data); - if (doLog) System.out.println(); + log("# send from remote to Openfire" + (socket instanceof SSLSocket ? " (encrypted)" : "")); + log(data); + log(""); os.write(data.getBytes()); os.flush(); } @@ -212,7 +211,7 @@ public synchronized void send(final String data) throws IOException @Override public void run() { - if (doLog) System.out.println("Start reading from socket."); + log("Start reading from socket."); try { final ByteBuffer buffer = ByteBuffer.allocate(1024*16); ReadableByteChannel channel = Channels.newChannel(is); @@ -225,16 +224,16 @@ public void run() // Ugly hack to get Dialback to work. if (read.startsWith("")) { - if (doLog) System.out.println("Peer sends a stream error. Can't use this connection anymore."); + log("Peer sends a stream error. Can't use this connection anymore."); return; } if (!read.equals("")) { @@ -254,7 +253,7 @@ public void run() processDialback(inbound); break; default: - if (doLog) System.out.println("Received stanza '" + inbound.getName() + "' that I don't know how to respond to."); + log("Received stanza '" + inbound.getName() + "' that I don't know how to respond to."); } } } @@ -265,14 +264,14 @@ public void run() } } } while (!processingService.isShutdown() && allowableSocketTimeouts > 0); - if (doLog) System.out.println("Ending read loop." + (socket instanceof SSLSocket ? " (encrypted)" : "")); + log("Ending read loop." + (socket instanceof SSLSocket ? " (encrypted)" : "")); } catch (Throwable t) { // Log exception only when not cleanly closed. if (doLog && !processingService.isShutdown()) { t.printStackTrace(); } } finally { - if (doLog) System.out.println("Stopped reading from socket"); + log("Stopped reading from socket"); } } @@ -320,23 +319,23 @@ private synchronized void sendStreamFeatures() throws IOException allowableSocketTimeouts = 10; // It's possible that the peer will start dialback. If that's happening, we need to be more forgiving in regard to socket timeouts. } final Element mechanisms = features.addElement(QName.get("mechanisms", "urn:ietf:params:xml:ns:xmpp-sasl")); - if (doLog) System.out.println(((SSLSocket) socket).getSession().getProtocol()); - if (doLog) System.out.println(((SSLSocket) socket).getSession().getCipherSuite()); + log(((SSLSocket) socket).getSession().getProtocol()); + log(((SSLSocket) socket).getSession().getCipherSuite()); try { // Throws an exception if the peer (local server) doesn't send a certificate - if (doLog) System.out.println(((SSLSocket) socket).getSession().getPeerPrincipal()); + log("" + ((SSLSocket) socket).getSession().getPeerPrincipal()); Certificate[] certificates = ((SSLSocket) socket).getSession().getPeerCertificates(); if (certificates != null && encryptionPolicy != Connection.TLSPolicy.disabled) { try { ((X509Certificate) certificates[0]).checkValidity(); // first peer certificate will belong to the local server mechanisms.addElement("mechanism").addText("EXTERNAL"); } catch (CertificateExpiredException | CertificateNotYetValidException e) { - if (doLog) System.out.println("local certificate is invalid"); + log("local certificate is invalid"); } } } catch (SSLPeerUnverifiedException e) { - if (doLog) System.out.println("local certificate is missing/unverified"); + log("local certificate is missing/unverified"); } } @@ -363,7 +362,7 @@ private synchronized void sendStartTlsProceed(Element inbound) throws Exception send(outbound.getRootElement().asXML()); - if (doLog) System.out.println("Replace the socket with one that will do TLS on the next inbound and outbound data"); + log("Replace the socket with one that will do TLS on the next inbound and outbound data"); final SSLContext sc = SSLContext.getInstance("TLSv1.3"); From d9726157f06f39b8b43f307d1f0e656f82855488 Mon Sep 17 00:00:00 2001 From: Guus der Kinderen Date: Fri, 3 Jan 2025 22:41:28 +0100 Subject: [PATCH 2/7] Speed up LocalIncomingServerSessionTest By properly detecting a stream error, the test needs not to wait for proper session teardown. --- .../openfire/session/RemoteInitiatingServerDummy.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java index d8b69d0b1d..ba04040f69 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java @@ -375,7 +375,7 @@ public void run() log(read); log(""); - if (read.startsWith(" Date: Fri, 3 Jan 2025 23:03:32 +0100 Subject: [PATCH 3/7] Speed up LocalOutgoingServerSessionTest This test uses an older SocketAcceptor, that cannot be interrupted. This means that we wait until SO_TIMEOUT before the test ends. This commit reduces the SO_TIMEOUT value. This runs the risk of introducing instability. --- .../openfire/session/RemoteReceivingServerDummy.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java index 512fbe7cb2..0f69f01b39 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java @@ -151,7 +151,7 @@ public void run() try { log("Waiting for new socket."); - server.setSoTimeout((int)SO_TIMEOUT.multipliedBy(10).toMillis()); + server.setSoTimeout((int)SO_TIMEOUT.toMillis()); final Socket socket = server.accept(); // This cannot be interrupted, which makes the entire test run very slow. log("Accepted new socket connection."); From c5c1648f71e39a163846be49f1a3f97d45b8ba41 Mon Sep 17 00:00:00 2001 From: Guus der Kinderen Date: Sat, 4 Jan 2025 14:07:38 +0100 Subject: [PATCH 4/7] Speed up LocalIncomingServerSessionTest This test uses an older SocketAcceptor, that cannot be interrupted. This means that we wait until SO_TIMEOUT before the test ends. This commit reduces the SO_TIMEOUT value. This runs the risk of introducing instability. --- .../openfire/session/RemoteInitiatingServerDummy.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java index ba04040f69..a85f834474 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java @@ -225,8 +225,8 @@ public void run() log("Start accepting socket connections (as Server Dialback Authoritative Server)."); while (!shouldStop) { try { - dialbackAuthoritativeServer.setSoTimeout((int)SO_TIMEOUT.multipliedBy(10).toMillis()); - final Socket socket = dialbackAuthoritativeServer.accept(); + dialbackAuthoritativeServer.setSoTimeout((int)SO_TIMEOUT.toMillis()); + final Socket socket = dialbackAuthoritativeServer.accept(); // This cannot be interrupted, which makes the entire test run very slow. final InputStream is = socket.getInputStream(); final OutputStream os = socket.getOutputStream(); log("DIALBACK AUTH SERVER: Accepted new socket connection."); From d16bdf1e440cfa9097f8c85c450c7822cf403eb3 Mon Sep 17 00:00:00 2001 From: Guus der Kinderen Date: Sat, 4 Jan 2025 14:20:03 +0100 Subject: [PATCH 5/7] Speed up LocalIncomingServerSessionTest and LocalOutgoingServerSessionTest Both tests use a ServerSocket that is 'slow' to shut down. By explicitly closing it, it shuts down faster, improving the duration of the test fixture teardown. --- .../session/RemoteInitiatingServerDummy.java | 14 +++++++++++--- .../session/RemoteReceivingServerDummy.java | 12 +++++++++--- 2 files changed, 20 insertions(+), 6 deletions(-) diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java index a85f834474..8d4493fbbc 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java @@ -216,7 +216,14 @@ private class DialbackAcceptor implements Runnable boolean shouldStop = false; void stop() { + log("Start stopping accepting connections (as Server Dialback Authoritative Server)."); shouldStop = true; + try { + dialbackAuthoritativeServer.close(); + log("Closed server accepting connections (as Server Dialback Authoritative Server)"); + } catch (IOException e) { + e.printStackTrace(); + } } @Override @@ -226,7 +233,7 @@ public void run() while (!shouldStop) { try { dialbackAuthoritativeServer.setSoTimeout((int)SO_TIMEOUT.toMillis()); - final Socket socket = dialbackAuthoritativeServer.accept(); // This cannot be interrupted, which makes the entire test run very slow. + final Socket socket = dialbackAuthoritativeServer.accept(); final InputStream is = socket.getInputStream(); final OutputStream os = socket.getOutputStream(); log("DIALBACK AUTH SERVER: Accepted new socket connection."); @@ -287,11 +294,12 @@ public void run() } } catch (Throwable t) { // Log exception only when not cleanly closed. - if (dialbackAcceptThread != null && !dialbackAcceptThread.isInterrupted()) { - if (!(t instanceof SocketTimeoutException) && !shouldStop) { + if (dialbackAcceptThread != null && !dialbackAcceptThread.isInterrupted() && !shouldStop) { + if (!(t instanceof SocketTimeoutException)) { // Ignore SO_TIMEOUT when not stopping. t.printStackTrace(); } } else { + log("Stop accepting (as Server Dialback Authoritative Server) (interrupted/closed)."); break; } } diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java index 0f69f01b39..d41b52bd1f 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteReceivingServerDummy.java @@ -141,6 +141,12 @@ private class Acceptor implements Runnable void stop() { log("Start stopping accepting connections."); shouldStop = true; + try { + server.close(); + log("Closed server accepting connections."); + } catch (IOException e) { + e.printStackTrace(); + } } @Override @@ -152,14 +158,14 @@ public void run() log("Waiting for new socket."); server.setSoTimeout((int)SO_TIMEOUT.toMillis()); - final Socket socket = server.accept(); // This cannot be interrupted, which makes the entire test run very slow. + final Socket socket = server.accept(); log("Accepted new socket connection."); processingService.submit(new SocketProcessor(socket)); } catch (Throwable t) { // Log exception only when not cleanly closed. - if (acceptThread != null && !acceptThread.isInterrupted()) { - if (!(t instanceof SocketTimeoutException)) { + if (acceptThread != null && !acceptThread.isInterrupted() && !shouldStop) { + if (!(t instanceof SocketTimeoutException)) { // Ignore SO_TIMEOUT when not stopping. t.printStackTrace(); } } else { From 2aa58ea15c5268289ef00352a6d9bf04deceb124 Mon Sep 17 00:00:00 2001 From: Guus der Kinderen Date: Sat, 4 Jan 2025 16:33:14 +0100 Subject: [PATCH 6/7] Speed up LocalIncomingServerSessionTest The test teardown waits for inbound stream IDs to be registered with the session manager. Many streams (those that have errored out or have been replaced with an encrypted stream) won't ever be registered in the Session Manager. The test teardown doesn't need to wait for those. This commit introduces a change that tracks the streams that are still in-flight. Test teardown will now only wait for those. --- .../session/RemoteInitiatingServerDummy.java | 51 +++++++++++++++---- 1 file changed, 40 insertions(+), 11 deletions(-) diff --git a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java index 8d4493fbbc..644fa086e6 100644 --- a/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java +++ b/xmppserver/src/test/java/org/jivesoftware/openfire/session/RemoteInitiatingServerDummy.java @@ -35,10 +35,7 @@ import java.security.cert.X509Certificate; import java.time.Instant; import java.time.temporal.ChronoUnit; -import java.util.ArrayList; -import java.util.Arrays; -import java.util.Base64; -import java.util.List; +import java.util.*; import java.util.concurrent.*; public class RemoteInitiatingServerDummy extends AbstractRemoteServerDummy @@ -53,6 +50,7 @@ public class RemoteInitiatingServerDummy extends AbstractRemoteServerDummy boolean peerSupportsDialback; private ExecutorService processingService; private final List receivedStreamIDs = new ArrayList<>(); + private final List processedStreamIDs = new ArrayList<>(); private final List receivedStreamFromValues = new ArrayList<>(); private final List receivedStreamToValues = new ArrayList<>(); @@ -101,24 +99,24 @@ public void blockUntilDone(final long timeout, final TimeUnit unit) { protected void done() { log("Start being done"); - if (!getReceivedStreamIDs().isEmpty()) { + if (!getNonProcessedStreamIDs().isEmpty()) { // If we recorded a stream ID, wait for this stream to be registered in the session manager before // continuing to prevent a race condition. - log("Wait for stream to be registered in the session manager"); + final StreamID lastReceivedID = getNonProcessedStreamIDs().get(getNonProcessedStreamIDs().size()-1); + log("Wait for stream to be registered in the session manager: " + lastReceivedID); final Instant stopWaiting = Instant.now().plus(500, ChronoUnit.MILLIS); try { - final StreamID lastReceivedID = getReceivedStreamIDs().get(getReceivedStreamIDs().size()-1); final SessionManager sessionManager = XMPPServer.getInstance().getSessionManager(); boolean found = false; while (Instant.now().isBefore(stopWaiting)) { if (sessionManager.getIncomingServerSession( lastReceivedID ) != null) { - log("Found stream registered in the session manager"); + log("Found stream registered in the session manager: " + lastReceivedID); found = true; break; } Thread.sleep(10); } - if (!found) log("NEVER FOUND STREAM WE WERE (pointlessly?) WAITING FOR!"); + if (!found) log("NEVER FOUND STREAM WE WERE (pointlessly?) WAITING FOR: " + lastReceivedID); } catch (InterruptedException e) { throw new RuntimeException(e); } @@ -138,6 +136,7 @@ public void disconnect() throws InterruptedException, IOException dialbackAuthoritativeServer.close(); dialbackAuthoritativeServer = null; } + log("disconnected"); } public synchronized void stopProcessingService() throws InterruptedException @@ -189,6 +188,28 @@ public List getReceivedStreamIDs() return receivedStreamIDs; } + /** + * Returns all stream IDs that have been received, but have not yet been marked as being processed. + * + * @return Stream IDs still being processed. + */ + public List getNonProcessedStreamIDs() + { + final List result = new ArrayList<>(receivedStreamIDs); + result.removeAll(processedStreamIDs); + return result; + } + + /** + * Mark the last received stream ID as being fully processed. This prevents the teardown from waiting for this stream + * to be established. + */ + public void markLastStreamIDasProcessed() { + final StreamID streamID = receivedStreamIDs.get(receivedStreamIDs.size() - 1); + processedStreamIDs.add(streamID); + log("Marked as processed: " + streamID); + } + /** * Returns all stream 'from' attribute values (potential duplicates, but no null values) that were received from the * peer during the setup. @@ -451,14 +472,14 @@ public void run() } } } while (!processingService.isShutdown() && allowableSocketTimeouts > 0); - log("Ending read loop."); + log("Ending read loop" + (socket instanceof SSLSocket ? " (encrypted)" : "")); } catch (Throwable t) { // Log exception only when not cleanly closed. if (doLog && !processingService.isShutdown()) { t.printStackTrace(); } } finally { - log("Stopped reading from socket"); + log("Stopped reading from socket" + (socket instanceof SSLSocket ? " (encrypted)" : "")); done(); } } @@ -512,6 +533,8 @@ private boolean negotiateEncryption(final Element features) throws IOException final Element error = root.addElement(QName.get("error", "stream", "http://etherx.jabber.org/streams")); error.addElement(QName.get("undefined-condition", "urn:ietf:params:xml:ns:xmpp-streams")); + markLastStreamIDasProcessed(); // Prevents the code from waiting on this stream to be registered with session manager during test fixture teardown. + send(root.asXML().substring(root.asXML().indexOf(">")+1)); throw new InterruptedIOException("Openfire requires TLS, we disabled it."); } @@ -531,6 +554,8 @@ private boolean negotiateEncryption(final Element features) throws IOException final Element error = root.addElement(QName.get("error", "stream", "http://etherx.jabber.org/streams")); error.addElement(QName.get("undefined-condition", "urn:ietf:params:xml:ns:xmpp-streams")); + markLastStreamIDasProcessed(); // Prevents the code from waiting on this stream to be registered with session manager during test fixture teardown. + send(root.asXML().substring(root.asXML().indexOf(">")+1)); throw new InterruptedIOException("Openfire disabled TLS, we require it."); } @@ -548,6 +573,9 @@ private void initiateTLS() throws IOException { log("Initiating TLS..."); final Document outbound = DocumentHelper.createDocument(); final Element startTls = outbound.addElement(QName.get("starttls", "urn:ietf:params:xml:ns:xmpp-tls")); + + markLastStreamIDasProcessed(); // Prevents the code from waiting on the stream (to be replaced with an encrypted one) to be registered with session manager during test fixture teardown. + send(startTls.asXML()); } @@ -600,6 +628,7 @@ private void negotiateAuthentication(final Element features) throws IOException startDialbackAuth(); } else { log("Unable to do authentication."); + markLastStreamIDasProcessed(); // Prevents the code from waiting on this stream to be registered with session manager during test fixture teardown. throw new InterruptedIOException("Unable to do authentication."); } } From a340aa9c743c26b302aa94bb4eae3e80e74aa659 Mon Sep 17 00:00:00 2001 From: Guus der Kinderen Date: Sat, 4 Jan 2025 18:48:48 +0100 Subject: [PATCH 7/7] OF-2942: Give up S2S attempts immediately on conflicting settings Abort outbound server-to-server attempts immediately (rather than waiting for a timeout), when: - the remote peer requires encryption, but the local server cannot do encryption - authentication mechanisms are exhausted (eg: no client cert for EXTERNAL, and Dialback unavailable) --- .../net/RespondingServerStanzaHandler.java | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/xmppserver/src/main/java/org/jivesoftware/openfire/net/RespondingServerStanzaHandler.java b/xmppserver/src/main/java/org/jivesoftware/openfire/net/RespondingServerStanzaHandler.java index 5a61c3c58b..efa479b1c4 100644 --- a/xmppserver/src/main/java/org/jivesoftware/openfire/net/RespondingServerStanzaHandler.java +++ b/xmppserver/src/main/java/org/jivesoftware/openfire/net/RespondingServerStanzaHandler.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2023-2024 Ignite Realtime Foundation. All rights reserved. + * Copyright (C) 2023-2025 Ignite Realtime Foundation. All rights reserved. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -72,6 +72,10 @@ private static boolean remoteFeaturesContainsStartTLS(Element doc) { return doc.element("starttls") != null; } + private static boolean remoteFeaturesRequiresStartTLS(Element doc) { + return remoteFeaturesContainsStartTLS(doc) && doc.element("starttls").element("required") != null; + } + private static boolean isSaslExternalOfferred(Element doc) { boolean saslEXTERNALoffered = false; if (doc.element("mechanisms") != null) { @@ -194,6 +198,10 @@ boolean processUnknowPacket(Element doc) { LOG.debug("I MUST use TLS but I have no StartTLS in features."); abandonSessionInitiation(); return false; + } else if (cannotUseTls() && remoteFeaturesRequiresStartTLS(doc)) { + LOG.debug("I CANNOT use TLS but remote server requires the STARTTLS feature."); + abandonSessionInitiation(); + return false; } // Authentication ------ @@ -227,6 +235,7 @@ boolean processUnknowPacket(Element doc) { return true; } else { LOG.debug("No authentication mechanism available."); + abandonSessionInitiation(); return false; } } @@ -332,6 +341,10 @@ private boolean mustUseTls() { return connection.getConfiguration().getTlsPolicy() == Connection.TLSPolicy.required; } + private boolean cannotUseTls() { + return connection.getConfiguration().getTlsPolicy() == Connection.TLSPolicy.disabled; + } + @Override void startTLS() throws Exception { connection.startTLS(true, false);