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); 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..644fa086e6 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. @@ -35,19 +35,11 @@ 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 { - /** - * 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(); @@ -58,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<>(); @@ -66,7 +59,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 +74,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,36 +98,45 @@ public void blockUntilDone(final long timeout, final TimeUnit unit) { protected void done() { - if (!getReceivedStreamIDs().isEmpty()) { + log("Start being done"); + 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. + 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: " + lastReceivedID); + found = true; break; } Thread.sleep(10); } + if (!found) log("NEVER FOUND STREAM WE WERE (pointlessly?) WAITING FOR: " + lastReceivedID); } 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) { dialbackAuthoritativeServer.close(); dialbackAuthoritativeServer = null; } + log("disconnected"); } public synchronized void stopProcessingService() throws InterruptedException @@ -186,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. @@ -213,28 +237,35 @@ 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 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()); + dialbackAuthoritativeServer.setSoTimeout((int)SO_TIMEOUT.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 +297,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(); @@ -284,16 +315,17 @@ 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; } } } - 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 +348,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 +356,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 +365,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 +375,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 +386,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 +443,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 +457,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 +472,14 @@ public void run() } } } while (!processingService.isShutdown() && allowableSocketTimeouts > 0); - if (doLog) System.out.println("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 { - if (doLog) System.out.println("Stopped reading from socket"); + log("Stopped reading from socket" + (socket instanceof SSLSocket ? " (encrypted)" : "")); done(); } } @@ -485,11 +517,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: @@ -501,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."); } @@ -520,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."); } @@ -534,16 +570,19 @@ 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")); + + 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()); } 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 +602,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 +616,25 @@ 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."); + 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."); } } 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 +644,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 +659,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..d41b52bd1f 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,32 +139,42 @@ private class Acceptor implements Runnable boolean shouldStop = false; void stop() { + log("Start stopping accepting connections."); shouldStop = true; + try { + server.close(); + log("Closed server accepting connections."); + } catch (IOException e) { + e.printStackTrace(); + } } @Override public void run() { - if (doLog) System.out.println("Start accepting socket connections."); + log("Start accepting socket connections."); while (!shouldStop) { try { - server.setSoTimeout((int)SO_TIMEOUT.multipliedBy(10).toMillis()); + log("Waiting for new socket."); + + server.setSoTimeout((int)SO_TIMEOUT.toMillis()); final Socket socket = server.accept(); - if (doLog) System.out.println("Accepted new socket connection."); + 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 { + log("Stop accepting (interrupted?)."); break; } } } - if (doLog) System.out.println("Stopped socket accepting connections."); + log("Stopped socket accepting connections."); } } @@ -190,7 +195,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 +207,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 +217,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 +230,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 +259,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 +270,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 +325,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 +368,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");