Skip to content

O
Openfire
Commit 8ad81f2f authored by Guus der Kinderen's avatar Guus der Kinderen
Browse files
Options

Improving logging for S2S / dialback 

The S2S (federation) code was not big on logging. This commit
introduces new logging, and structures the logged messages.
This commit does not introduce functional changes.
parent 80386d5f
Hide whitespace changes
Inline Side-by-side
Showing with 258 additions and 181 deletions
src/java/org/jivesoftware/openfire/server/ServerDialback.java
View file @ 8ad81f2f
......@@ -208,36 +208,39 @@ public class ServerDialback {
* @return an OutgoingServerSession if the domain was authenticated or <tt>null</tt> if none.
*/
public LocalOutgoingServerSession createOutgoingSession(String localDomain, String remoteDomain, int port) {
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Create Outgoing Session from: " + localDomain + " to: " + remoteDomain + " (port: " + port+ ")]" );
log.debug( "Creating new outgoing session..." );
String hostname = null;
int realPort = port;
try {
// Establish a TCP connection to the Receiving Server
Socket socket = new Socket();
// Get a list of real hostnames to connect to using DNS lookup of the specified hostname
log.debug( "Get a list of real hostnames to connect to using DNS lookup of the specified hostname." );
List<DNSUtil.HostAddress> hosts = DNSUtil.resolveXMPPDomain(remoteDomain, port);
for (Iterator<DNSUtil.HostAddress> it = hosts.iterator(); it.hasNext();) {
try {
DNSUtil.HostAddress address = it.next();
hostname = address.getHost();
realPort = address.getPort();
Log.debug("ServerDialback: OS - Trying to connect to " + remoteDomain + ":" + port +
"(DNS lookup: " + hostname + ":" + realPort + ")");
log.debug( "Trying to create plain socket connection to: {}:{} ...", hostname, realPort );
// Establish a TCP connection to the Receiving Server
socket.connect(new InetSocketAddress(hostname, realPort),
RemoteServerManager.getSocketTimeout());
Log.debug("ServerDialback: OS - Connection to " + remoteDomain + ":" + port + " successful");
socket.connect(new InetSocketAddress(hostname, realPort), RemoteServerManager.getSocketTimeout());
log.debug( "Plain socket connection to {}:{} successful!", hostname, realPort );
break;
}
catch (Exception e) {
Log.warn("Error trying to connect to remote server: " + remoteDomain +
"(DNS lookup: " + hostname + ":" + realPort + ")", e);
log.debug( "An exception occurred while trying to create a plain socket connection to: {}:{}", hostname, realPort, e );
log.warn( "Unable to create plain socket connection to: {}:{}. Cause: {} (a full stacktrace is logged on debug level)", hostname, realPort, e.getMessage() );
// TODO should this not stop processing? lots of this code is very similar to the implementation in LocalOutgoingServerSession. Should implementations be merged?
}
}
connection =
new SocketConnection(XMPPServer.getInstance().getPacketDeliverer(), socket,
false);
// Get a writer for sending the open stream tag
// Send to the Receiving Server a stream header
log.debug( "Send the stream header and wait for response..." );
StringBuilder stream = new StringBuilder();
stream.append("<stream:stream");
stream.append(" xmlns:stream=\"http://etherx.jabber.org/streams\"");
......@@ -261,27 +264,34 @@ public class ServerDialback {
for (int eventType = xpp.getEventType(); eventType != XmlPullParser.START_TAG;) {
eventType = xpp.next();
}
log.debug( "Got a response. Check if the remote server supports dialback..." );
if ("jabber:server:dialback".equals(xpp.getNamespace("db"))) {
log.debug( "Dialback seems to be supported by the remote server." );
// Restore default timeout
socket.setSoTimeout(soTimeout);
String id = xpp.getAttributeValue("", "id");
OutgoingServerSocketReader socketReader = new OutgoingServerSocketReader(reader);
if (authenticateDomain(socketReader, localDomain, remoteDomain, id)) {
log.debug( "Successfully authenticated the connection with dialback." );
// Domain was validated so create a new OutgoingServerSession
StreamID streamID = new BasicStreamIDFactory().createStreamID(id);
LocalOutgoingServerSession session = new LocalOutgoingServerSession(localDomain, connection, socketReader, streamID);
connection.init(session);
// Set the hostname as the address of the session
session.setAddress(new JID(null, remoteDomain, null));
log.debug( "Successfully created new outgoing session!" );
return session;
}
else {
log.debug( "Failed to authenticate the connection with dialback." );
// Close the connection
connection.close();
}
}
else {
Log.debug("ServerDialback: OS - Invalid namespace in packet: " + xpp.getText());
log.debug("Error! Invalid namespace in packet: '{}'. Closing connection.", xpp.getText() );
// Send an invalid-namespace stream error condition in the response
connection.deliverRawText(
new StreamError(StreamError.Condition.invalid_namespace).toXML());
......@@ -289,25 +299,14 @@ public class ServerDialback {
connection.close();
}
}
catch (IOException e) {
Log.debug("ServerDialback: Error connecting to the remote server: " + remoteDomain + "(DNS lookup: " +
hostname + ":" + realPort + ")", e);
// Close the connection
if (connection != null) {
connection.close();
}
}
catch (Exception e) {
Log.error("Error creating outgoing session to remote server: " + remoteDomain +
"(DNS lookup: " +
hostname +
")",
e);
log.error( "An exception occurred while creating outgoing session to remote server:", e );
// Close the connection
if (connection != null) {
connection.close();
}
}
log.warn( "Unable to create a new outgoing session" );
return null;
}
......@@ -325,14 +324,16 @@ public class ServerDialback {
* @param id the stream id to be used for creating the dialback key.
* @return true if the Receiving Server authenticated the domain with the Authoritative Server.
*/
public boolean authenticateDomain(OutgoingServerSocketReader socketReader, String domain,
String hostname, String id) {
String key = AuthFactory.createDigest(id, getSecretkey());
Log.debug("ServerDialback: OS - Sent dialback key to host: " + hostname + " id: " + id + " from domain: " +
domain);
public boolean authenticateDomain(OutgoingServerSocketReader socketReader, String domain, String hostname, String id) {
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Authenticate domain: " + domain + " (id " + id + ") with hostname: " + hostname + "]" );
log.debug( "Authenticating domain ..." );
String key = AuthFactory.createDigest( id, getSecretkey() );
synchronized (socketReader) {
// Send a dialback key to the Receiving Server
log.debug( "Sending dialback key and wait for the validation response..." );
StringBuilder sb = new StringBuilder();
sb.append("<db:result");
sb.append(" from=\"").append(domain).append("\"");
......@@ -344,42 +345,27 @@ public class ServerDialback {
// Process the answer from the Receiving Server
try {
while (true) {
Element doc = socketReader.getElement(RemoteServerManager.getSocketTimeout(),
TimeUnit.MILLISECONDS);
Element doc = socketReader.getElement(RemoteServerManager.getSocketTimeout(), TimeUnit.MILLISECONDS);
if (doc == null) {
Log.debug("ServerDialback: OS - Time out waiting for answer in validation from: " + hostname +
" id: " +
id +
" for domain: " +
domain);
log.debug( "Failed to authenticate domain: Time out waiting for validation response." );
return false;
}
else if ("db".equals(doc.getNamespacePrefix()) && "result".equals(doc.getName())) {
boolean success = "valid".equals(doc.attributeValue("type"));
Log.debug("ServerDialback: OS - Validation " + (success ? "GRANTED" : "FAILED") + " from: " +
hostname +
" id: " +
id +
" for domain: " +
domain);
return success;
if ( "valid".equals(doc.attributeValue("type")) ) {
log.debug( "Authenticated succeeded!" );
return true;
} else {
log.debug( "Failed to authenticate domain: the validation response was received, but did not grant authentication." );
return false;
}
}
else {
Log.warn("ServerDialback: OS - Ignoring unexpected answer in validation from: " + hostname + " id: " +
id +
" for domain: " +
domain +
" answer:" +
doc.asXML());
log.warn( "Ignoring unexpected answer while waiting for dialback validation: " + doc.asXML() );
}
}
}
catch (InterruptedException e) {
Log.debug("ServerDialback: OS - Validation FAILED from: " + hostname +
" id: " +
id +
" for domain: " +
domain, e);
log.debug( "Failed to authenticate domain: An interrupt was received while waiting for validation response (is Openfire shutting down?)" );
return false;
}
}
......@@ -510,24 +496,24 @@ public class ServerDialback {
StringBuilder sb;
String recipient = doc.attributeValue("to");
String hostname = doc.attributeValue("from");
Log.debug("ServerDialback: RS - Received dialback key from host: " + hostname + " to: " + recipient);
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Validate remote domain:" + recipient + "(id " + streamID + ") for: " + hostname + "]" );
log.debug( "Validating domain...");
if (!RemoteServerManager.canAccess(hostname)) {
// Remote server is not allowed to establish a connection to this server
connection.deliverRawText(new StreamError(StreamError.Condition.policy_violation).toXML());
// Close the underlying connection
connection.close();
Log.debug("ServerDialback: RS - Error, hostname is not allowed to establish a connection to " +
"this server: " +
recipient);
log.debug( "Unable to validate domain: Remote server is not allowed to establish a connection to this server." );
return false;
}
else if (isHostUnknown(recipient)) {
dialbackError(recipient, hostname, new PacketError(PacketError.Condition.item_not_found, PacketError.Type.cancel, "Service not hosted here"));
Log.debug("ServerDialback: RS - Error, hostname not recognized: " + recipient);
log.debug( "Unable to validate domain: Hostname not recognized." );
return false;
}
else {
// Check if the remote server already has a connection to the target domain/subdomain
log.debug( "Check if the remote server already has a connection to the target domain/subdomain" );
boolean alreadyExists = false;
for (IncomingServerSession session : sessionManager.getIncomingServerSessions(hostname)) {
if (recipient.equals(session.getLocalDomain())) {
......@@ -536,13 +522,13 @@ public class ServerDialback {
}
if (alreadyExists && !sessionManager.isMultipleServerConnectionsAllowed()) {
dialbackError(recipient, hostname, new PacketError(PacketError.Condition.resource_constraint, PacketError.Type.cancel, "Incoming session already exists"));
Log.debug("ServerDialback: RS - Error, incoming connection already exists from: " + hostname);
log.debug( "Unable to validate domain: An incoming connection already exists from this remote host, and multiple connections are not allowed." );
return false;
}
else {
log.debug( "Checking to see if the remote host provides stronger authentication based on SASL. If that's the case, dialback-based authentication can be skipped." );
if (SASLAuthentication.verifyCertificates(connection.getPeerCertificates(), hostname, true)) {
// If the remote host passes strong auth, just skip the dialback.
Log.debug("ServerDialback: RS - Sending key verification result to OS: " + hostname);
log.debug( "Host authenticated based on SASL. Weaker dialback-based authentication is skipped." );
sb = new StringBuilder();
sb.append("<db:result");
sb.append(" from=\"").append(recipient).append("\"");
......@@ -550,53 +536,56 @@ public class ServerDialback {
sb.append(" type=\"valid\"");
sb.append("/>");
connection.deliverRawText(sb.toString());
log.debug( "Domain validated successfully!" );
return true;
}
log.debug( "Unable to authenticate host based on stronger SASL. Proceeding with dialback..." );
String key = doc.getTextTrim();
// Get a list of real hostnames and try to connect using DNS lookup of the specified domain
List<DNSUtil.HostAddress> hosts = DNSUtil.resolveXMPPDomain(hostname,
RemoteServerManager.getPortForServer(hostname));
log.debug( "Get a list of real hostnames and try to using DNS lookup of the specified domain." );
List<DNSUtil.HostAddress> hosts = DNSUtil.resolveXMPPDomain(hostname, RemoteServerManager.getPortForServer(hostname));
Socket socket = new Socket();
String realHostname = null;
int realPort;
for (Iterator<DNSUtil.HostAddress> it = hosts.iterator(); it.hasNext();) {
for (Iterator<DNSUtil.HostAddress> it = hosts.iterator(); it.hasNext();) { // TODO Remove code duplication (also in LocalOutgoingServerSession)
try {
DNSUtil.HostAddress address = it.next();
realHostname = address.getHost();
realPort = address.getPort();
Log.debug("ServerDialback: RS - Trying to connect to Authoritative Server: " + hostname +
"(DNS lookup: " + realHostname + ":" + realPort + ")");
log.debug( "Trying to create plain socket connection to: {}:{} ...", realHostname, realPort );
// Establish a TCP connection to the Receiving Server
socket.connect(new InetSocketAddress(realHostname, realPort),
RemoteServerManager.getSocketTimeout());
Log.debug("ServerDialback: RS - Connection to AS: " + hostname + " successful");
socket.connect(new InetSocketAddress(realHostname, realPort), RemoteServerManager.getSocketTimeout());
log.debug( "Plain socket connection to {}:{} successful!", realHostname, realPort );
break;
}
catch (Exception e) {
Log.warn("Error trying to connect to remote server: " + hostname +
"(DNS lookup: " + realHostname + ")", e);
log.debug( "An exception occurred while trying to create a plain socket connection to: {}", realHostname, e );
log.warn( "Unable to create plain socket connection to: {}. Cause: {} (a full stacktrace is logged on debug level)", realHostname, e.getMessage() );
}
}
if (!socket.isConnected()) {
log.debug( "Unable to validate domain: No server available for verifying key of remote server." );
dialbackError(recipient, hostname, new PacketError(PacketError.Condition.remote_server_not_found, PacketError.Type.cancel, "Unable to connect to authoritative server"));
Log.warn("No server available for verifying key of remote server: " + hostname);
try {
socket.close();
} catch (IOException e) {
Log.warn("Socket error on close", e);
log.warn("Socket error on close", e);
}
return false;
}
try {
log.debug( "Verifying dialback key..." );
VerifyResult result = verifyKey(key, streamID.toString(), recipient, hostname, socket);
switch(result) {
case valid:
case invalid:
boolean valid = (result == VerifyResult.valid);
Log.debug("ServerDialback: RS - Sending key verification result to OS: " + hostname);
log.debug( "Dialback key is" + (valid? "valid":"invalid") + ". Sending verification result to remote host." );
sb = new StringBuilder();
sb.append("<db:result");
sb.append(" from=\"").append(recipient).append("\"");
......@@ -607,19 +596,24 @@ public class ServerDialback {
connection.deliverRawText(sb.toString());
if (!valid) {
// Close the underlying connection
log.debug( "Close the underlying connection as key verification failed." );
connection.close();
log.debug( "Unable to validate domain: dialback key is invalid." );
return false;
} else {
log.debug( "Successfully validated domain!" );
return true;
}
return valid;
default:
break;
}
log.debug( "Unable to validate domain: key verification did not complete (the AS likely returned an error or a time out occurred)." );
dialbackError(recipient, hostname, new PacketError(PacketError.Condition.remote_server_timeout, PacketError.Type.cancel, "Authoritative server returned error"));
return false;
}
catch (Exception e) {
dialbackError(recipient, hostname, new PacketError(PacketError.Condition.remote_server_timeout, PacketError.Type.cancel, "Authoritative server failed"));
Log.warn("Error verifying key of remote server: " + hostname, e);
log.warn( "Unable to validate domain: An exception occurred while verifying the dialback key.", e );
return false;
}
}
......@@ -638,9 +632,12 @@ public class ServerDialback {
}
private VerifyResult sendVerifyKey(String key, String streamID, String recipient, String hostname, Writer writer, XMPPPacketReader reader, Socket socket) throws IOException, XmlPullParserException, RemoteConnectionFailedException {
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Verify key with AS: " + hostname + " for: " + recipient + " (id " + streamID + ")]" );
VerifyResult result = VerifyResult.error;
TLSStreamHandler tlsStreamHandler;
// Send the Authoritative Server a stream header
log.debug( "Send the Authoritative Server a stream header and wait for answer." );
StringBuilder stream = new StringBuilder();
stream.append("<stream:stream");
stream.append(" xmlns:stream=\"http://etherx.jabber.org/streams\"");
......@@ -661,13 +658,15 @@ public class ServerDialback {
for (int eventType = xpp.getEventType(); eventType != XmlPullParser.START_TAG;) {
eventType = xpp.next();
}
if ((xpp.getAttributeValue("", "version") != null) &&
(xpp.getAttributeValue("", "version").equals("1.0"))) {
log.debug( "Got a response. Check if the remote server is XMPP 1.0 compliant..." ); // TODO there's code duplication here with LocalOutgoingServerSession.
if ((xpp.getAttributeValue("", "version") != null) && (xpp.getAttributeValue("", "version").equals("1.0"))) {
log.debug( "The remote server is XMPP 1.0 compliant (or at least reports to be).");
Document doc;
try {
doc = reader.parseDocument();
} catch (DocumentException e) {
Log.warn("XML Error!", e);
log.warn("Unable to verify key: XML Error!", e);
return VerifyResult.error;
}
Element features = doc.getRootElement();
......@@ -678,14 +677,16 @@ public class ServerDialback {
try {
doc = reader.parseDocument();
} catch (DocumentException e) {
Log.warn("XML Error!", e);
log.warn("Unable to verify key: XML Error!", e);
return VerifyResult.error;
}
if (!doc.getRootElement().getName().equals("proceed")) {
Log.warn("Got {} instead of proceed for starttls", doc.getRootElement().getName());
Log.debug("Like this: {}", doc.asXML());
log.warn("Unable to verify key: Got {} instead of proceed for starttls", doc.getRootElement().getName());
log.debug("Like this: {}", doc.asXML());
return VerifyResult.error;
}
log.debug( "Negotiating TLS with AS... " );
// Ugly hacks, apparently, copied from SocketConnection.
final ConnectionManagerImpl connectionManager = ((ConnectionManagerImpl) XMPPServer.getInstance().getConnectionManager());
tlsStreamHandler = new TLSStreamHandler(socket, connectionManager.getListener( ConnectionType.SOCKET_S2S, false ).generateConnectionConfiguration(), true);
......@@ -693,15 +694,14 @@ public class ServerDialback {
tlsStreamHandler.start();
// Use new wrapped writers
writer = new BufferedWriter(new OutputStreamWriter(tlsStreamHandler.getOutputStream(), StandardCharsets.UTF_8));
reader.getXPPParser().setInput(new InputStreamReader(tlsStreamHandler.getInputStream(),
StandardCharsets.UTF_8));
reader.getXPPParser().setInput(new InputStreamReader(tlsStreamHandler.getInputStream(),StandardCharsets.UTF_8));
log.debug( "Successfully negotiated TLS with AS... " );
/// Recurses!
return sendVerifyKey(key, streamID, recipient, hostname, writer, reader, socket);
}
}
if ("jabber:server:dialback".equals(xpp.getNamespace("db"))) {
Log.debug("ServerDialback: RS - Asking AS to verify dialback key for id" + streamID);
// Request for verification of the key
log.debug("Request for verification of the key and wait for response");
StringBuilder sb = new StringBuilder();
sb.append("<db:verify");
sb.append(" from=\"").append(recipient).append("\"");
......@@ -742,24 +742,24 @@ public class ServerDialback {
throw new RemoteConnectionFailedException("Invalid From");
}
else if ("valid".equals(doc.attributeValue("type"))){
Log.debug("ServerDialback: RS - Key was VERIFIED by the Authoritative Server for: {}", hostname);
log.debug("Key was VERIFIED by the Authoritative Server.");
result = VerifyResult.valid;
}
else if ("invalid".equals(doc.attributeValue("type"))){
Log.debug("ServerDialback: RS - Key was NOT VERIFIED by the Authoritative Server for: {}", hostname);
log.debug("Key was NOT VERIFIED by the Authoritative Server.");
result = VerifyResult.invalid;
}
else {
Log.debug("ServerDialback: RS - Key was ERRORED by the Authoritative Server for: {}", hostname);
log.debug("Key was ERRORED by the Authoritative Server.");
result = VerifyResult.error;
}
}
else {
Log.debug("ServerDialback: db:verify answer was: " + doc.asXML());
log.debug("db:verify answer was: " + doc.asXML());
}
}
catch (DocumentException | RuntimeException e) {
Log.error("An error occured connecting to the Authoritative Server", e);
log.error("An error occurred while connecting to the Authoritative Server:", e);
// Thrown an error so <remote-connection-failed/> stream error condition is
// sent to the Originating Server
throw new RemoteConnectionFailedException("Error connecting to the Authoritative Server");
......@@ -780,9 +780,11 @@ public class ServerDialback {
/**
* Verifies the key with the Authoritative Server.
*/
private VerifyResult verifyKey(String key, String streamID, String recipient, String hostname,
Socket socket) throws IOException, XmlPullParserException,
RemoteConnectionFailedException {
private VerifyResult verifyKey(String key, String streamID, String recipient, String hostname, Socket socket) throws IOException, XmlPullParserException, RemoteConnectionFailedException {
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Verify key with AS: " + hostname + " for: " + recipient + " (id " + streamID + ")]" );
log.debug( "Verifying key ..." );
XMPPPacketReader reader;
Writer writer = null;
// Set a read timeout
......@@ -792,17 +794,13 @@ public class ServerDialback {
reader = new XMPPPacketReader();
reader.setXPPFactory(FACTORY);
reader.getXPPParser().setInput(new InputStreamReader(socket.getInputStream(),
CHARSET));
reader.getXPPParser().setInput(new InputStreamReader(socket.getInputStream(), CHARSET));
// Get a writer for sending the open stream tag
writer =
new BufferedWriter(new OutputStreamWriter(socket.getOutputStream(),
CHARSET));
writer = new BufferedWriter(new OutputStreamWriter(socket.getOutputStream(), CHARSET));
result = sendVerifyKey(key, streamID, recipient, hostname, writer, reader, socket);
}
finally {
try {
Log.debug("ServerDialback: RS - Closing connection to Authoritative Server: " + hostname);
// Close the stream
StringBuilder sb = new StringBuilder();
sb.append("</stream:stream>");
......@@ -815,6 +813,22 @@ public class ServerDialback {
// Do nothing
}
}
switch ( result ) {
case valid:
log.debug( "Successfully verified key!" );
break;
case invalid:
log.debug( "Unable to verify key: AS reports that the key is invalid." );
break;
default:
case decline:
case error:
log.debug( "Unable to verify key: An error occurred." );
break;
}
return result;
}
......@@ -833,7 +847,10 @@ public class ServerDialback {
String verifyTO = doc.attributeValue("to");
String key = doc.getTextTrim();
String id = doc.attributeValue("id");
Log.debug("ServerDialback: AS - Verifying key for host: " + verifyFROM + " id: " + id);
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Verify key for RS: " + verifyFROM + " (id " + id+ ")]" );
log.debug( "Verifying key... ");
// TODO If the value of the 'to' address does not match a recognized hostname,
// then generate a <host-unknown/> stream error condition
......@@ -855,10 +872,7 @@ public class ServerDialback {
sb.append(verified ? "valid" : "invalid");
sb.append("\" id=\"").append(id).append("\"/>");
connection.deliverRawText(sb.toString());
Log.debug("ServerDialback: AS - Key was: " + (verified ? "VALID" : "INVALID") + " for host: " +
verifyFROM +
" id: " +
id);
log.debug("Verification successful! Key was: " + (verified ? "VALID" : "INVALID"));
return verified;
}
......
src/java/org/jivesoftware/openfire/session/LocalOutgoingServerSession.java
View file @ 8ad81f2f
......@@ -122,35 +122,41 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
* @return True if the domain was authenticated by the remote server.
*/
public static boolean authenticateDomain(final String domain, final String hostname) {
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Authenticate domain: " + domain + " (hostname: " + hostname + ")]" );
log.debug( "Authenticating... " );
if (hostname == null || hostname.length() == 0 || hostname.trim().indexOf(' ') > -1) {
// Do nothing if the target hostname is empty, null or contains whitespaces
log.warn( "Unable to authenticate a domain when an empty hostname is provided!" );
return false;
}
try {
// Check if the remote hostname is in the blacklist
if (!RemoteServerManager.canAccess(hostname)) {
log.info( "Unable to authenticate: Hostname is not accessible according to our configuration (typical causes: server federation is disabled, or hostname is blacklisted)." );
return false;
}
log.debug( "Searching for a pre-existing session to this hostname... If one exists, it will be re-used to authenticate this domain." );
OutgoingServerSession session;
// Check if a session, that is using server dialback, already exists to the desired
// hostname (i.e. remote server). If no one exists then create a new session. The same
// session will be used for the same hostname for all the domains to authenticate
SessionManager sessionManager = SessionManager.getInstance();
if (sessionManager == null) {
// Server is shutting down while we are trying to create a new s2s connection
log.warn( "Unable to authenticate: the SessionManager instance is not available. This should not occur unless Openfire is starting up or shutting down." );
return false;
}
session = sessionManager.getOutgoingServerSession(hostname);
if (session == null) {
log.debug( "There is no pre-existing session to this hostname." );
log.debug( "Searching for pre-existing sessions to other hostnames that previously authenticated this domain... If one exists, it will be re-used to authenticate this domain." );
// Try locating if the remote server has previously authenticated with this server
for (IncomingServerSession incomingSession : sessionManager.getIncomingServerSessions(hostname)) {
for (String otherHostname : incomingSession.getValidatedDomains()) {
session = sessionManager.getOutgoingServerSession(otherHostname);
if (session != null) {
if (session.isUsingServerDialback()) {
// A session to the same remote server but with different hostname
// was found. Use this session.
log.debug( "A session to the same remote server but with different hostname ('{}') was found. This session will be re-used.", otherHostname );
break;
} else {
session = null;
......@@ -158,35 +164,51 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
}
}
}
if (session == null) {
log.debug( "There are no pre-existing session to other hostnames for this domain." );
}
}
if (session == null) {
log.debug( "Creating new authenticated session..." );
int port = RemoteServerManager.getPortForServer(hostname);
session = createOutgoingSession(domain, hostname, port);
if (session != null) {
log.debug( "Created a new session." );
// Add the validated domain as an authenticated domain
session.addAuthenticatedDomain(domain);
// Add the new hostname to the list of names that the server may have
session.addHostname(hostname);
// Notify the SessionManager that a new session has been created
sessionManager.outgoingServerSessionCreated((LocalOutgoingServerSession) session);
log.debug( "Authentication successful." );
return true;
} else {
Log.warn("Fail to connect to {} for {}", hostname, domain);
log.warn( "Unable to authenticate: Fail to create new session." );
return false;
}
}
// A session already exists. The session was established using server dialback so
// it is possible to do piggybacking to authenticate more domains
log.debug( "A session already exists. The session was established using server dialback so it is possible to do piggybacking to authenticate more domains." );
if (session.getAuthenticatedDomains().contains(domain) && session.getHostnames().contains(hostname)) {
// Do nothing since the domain has already been authenticated
log.debug( "Authentication successful (domain was already authenticated in the pre-existing session)." );
return true;
}
// A session already exists so authenticate the domain using that session
return session.authenticateSubdomain(domain, hostname);
if ( session.authenticateSubdomain( domain, hostname ) ) {
log.debug( "Authentication successful (domain authentication was added using a pre-existing session)." );
return true;
} else {
log.warn( "Unable to authenticate: Unable to add authentication to pre-exising session." );
return false;
}
}
catch (Exception e) {
Log.error("Error authenticating domain with remote server: " + hostname, e);
log.error( "An exception occurred while authenticating domain with remote server!", e );
}
log.warn( "Unable to authenticate: exhausted session (re-)usage options." );
return false;
}
......@@ -202,8 +224,10 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
* @param port default port to use to establish the connection.
* @return new outgoing session to a remote server.
*/
private static LocalOutgoingServerSession createOutgoingSession(String domain, String hostname,
int port) {
private static LocalOutgoingServerSession createOutgoingSession(String domain, String hostname, int port) {
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Create outgoing session to: " + domain + " (" + hostname + ":"+ port+")]" );
log.debug( "Creating new session..." );
String localDomainName = XMPPServer.getInstance().getServerInfo().getXMPPDomain();
boolean useTLS = JiveGlobals.getBooleanProperty(ConnectionSettings.Server.TLS_ENABLED, true);
......@@ -217,7 +241,7 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
String realHostname = null;
int realPort = port;
Socket socket = null;
// Get a list of real hostnames to connect to using DNS lookup of the specified hostname
log.debug( "Get a list of real hostnames to connect to using DNS lookup of the specified hostname." );
List<DNSUtil.HostAddress> hosts = DNSUtil.resolveXMPPDomain(hostname, port);
for (Iterator<DNSUtil.HostAddress> it = hosts.iterator(); it.hasNext();) {
try {
......@@ -225,28 +249,26 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
DNSUtil.HostAddress address = it.next();
realHostname = address.getHost();
realPort = address.getPort();
Log.debug("LocalOutgoingServerSession: OS - Trying to connect to " + hostname + ":" + port +
"(DNS lookup: " + realHostname + ":" + realPort + ")");
// Establish a TCP connection to the Receiving Server
socket.connect(new InetSocketAddress(realHostname, realPort),
RemoteServerManager.getSocketTimeout());
Log.debug("LocalOutgoingServerSession: OS - Plain connection to " + hostname + ":" + port + " successful");
log.debug( "Trying to create plain socket connection to: {}:{} ...", realHostname, realPort );
socket.connect(new InetSocketAddress(realHostname, realPort), RemoteServerManager.getSocketTimeout());
log.debug( "Plain socket connection to {}:{} successful!", realHostname, realPort );
break;
}
catch (Exception e) {
Log.warn("Error trying to connect to remote server: " + hostname +
"(DNS lookup: " + realHostname + ":" + realPort + "): " + e.toString());
log.debug( "An exception occurred while trying to create a plain socket connection to: {}:{}", realHostname, realPort, e );
log.warn( "Unable to create plain socket connection to: {}:{}. Cause: {} (a full stacktrace is logged on debug level)", realHostname, realPort, e.getMessage() );
try {
if (socket != null) {
socket.close();
}
}
catch (IOException ex) {
Log.debug("Additional exception while trying to close socket when connection to remote server failed: " + ex.toString());
log.debug( "Additional exception while trying to close socket when connection to remote server failed.", ex);
}
}
}
if (!socket.isConnected()) {
log.info( "Unable to create new session: Cannot create a plain socket connection with any applicable host." );
return null;
}
......@@ -256,7 +278,7 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
new SocketConnection(XMPPServer.getInstance().getPacketDeliverer(), socket,
false);
// Send the stream header
log.debug( "Send the stream header and wait for response..." );
StringBuilder openingStream = new StringBuilder();
openingStream.append("<stream:stream");
openingStream.append(" xmlns:db=\"jabber:server:dialback\"");
......@@ -282,51 +304,58 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
String serverVersion = xpp.getAttributeValue("", "version");
String id = xpp.getAttributeValue("", "id");
log.debug( "Got a response (stream ID: {}, version: {}). Check if the remote server is XMPP 1.0 compliant...", id, serverVersion );
// Check if the remote server is XMPP 1.0 compliant
if (serverVersion != null && decodeVersion(serverVersion)[0] >= 1) {
log.debug( "The remote server is XMPP 1.0 compliant (or at least reports to be)." );
// Restore default timeout
socket.setSoTimeout(soTimeout);
// Get the stream features
log.debug( "Processing stream features of the remote server..." );
Element features = reader.parseDocument().getRootElement();
if (features != null) {
// Check if TLS is enabled
log.debug( "Check if both us as well as the remote server have enabled STARTTLS and/or dialback ..." );
if (useTLS && features.element("starttls") != null) {
// Secure the connection with TLS and authenticate using SASL
LocalOutgoingServerSession answer;
answer = secureAndAuthenticate(hostname, connection, reader, openingStream,
domain);
log.debug( "Both us and the remote server support the STARTTLS feature. Secure and authenticate the connection with TLS & SASL..." );
LocalOutgoingServerSession answer = secureAndAuthenticate(hostname, connection, reader, openingStream, domain);
if (answer != null) {
log.debug( "Successfully secured/authenticated the connection with TLS/SASL)!" );
// Everything went fine so return the secured and
// authenticated connection
log.debug( "Successfully created new session!" );
return answer;
}
log.debug( "Unable to secure and authenticate the connection with TLS & SASL." );
}
// Check if we are going to try server dialback (XMPP 1.0)
else if (ServerDialback.isEnabled() && features.element("dialback") != null) {
Log.debug("LocalOutgoingServerSession: OS - About to try connecting using server dialback XMPP 1.0 with: " + hostname);
log.debug( "Both us and the remote server support the 'dialback' feature. Authenticate the connection with dialback..." );
ServerDialback method = new ServerDialback(connection, domain);
OutgoingServerSocketReader newSocketReader = new OutgoingServerSocketReader(reader);
if (method.authenticateDomain(newSocketReader, domain, hostname, id)) {
Log.debug("LocalOutgoingServerSession: OS - SERVER DIALBACK XMPP 1.0 with " + hostname + " was successful");
log.debug( "Successfully authenticated the connection with dialback!" );
StreamID streamID = new BasicStreamIDFactory().createStreamID(id);
LocalOutgoingServerSession session = new LocalOutgoingServerSession(domain, connection, newSocketReader, streamID);
connection.init(session);
// Set the hostname as the address of the session
session.setAddress(new JID(null, hostname, null));
log.debug( "Successfully created new session!" );
return session;
}
else {
Log.debug("LocalOutgoingServerSession: OS - Error, SERVER DIALBACK with " + hostname + " failed");
log.debug( "Unable to authenticate the connection with dialback." );
}
}
}
else {
Log.debug("LocalOutgoingServerSession: OS - Error, <starttls> was not received");
log.debug( "Error! No data from the remote server (expected a 'feature' element).");
}
} else {
log.debug( "The remote server is not XMPP 1.0 compliant." );
}
// Something went wrong so close the connection and try server dialback over
// a plain connection
log.debug( "Something went wrong so close the connection and try server dialback over a plain connection" );
if (connection != null) {
connection.close();
}
......@@ -334,7 +363,7 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
catch (SSLHandshakeException e)
{
// This is a failure as described in RFC3620, section 5.4.3.2 "STARTTLS Failure".
Log.info( "STARTTLS negotiation (with {} at {}:{}) failed.", hostname, realHostname, realPort, e );
log.info( "STARTTLS negotiation (with {}:{}) failed. Closing connection (without sending any data such as <failure/> or </stream>).", realHostname, realPort, e );
// The receiving entity is expected to close the socket *without* sending any more data (<failure/> nor </stream>).
// It is probably (see OF-794) best if we, as the initiating entity, therefor don't send any data either.
......@@ -345,56 +374,69 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
catch (Exception e)
{
// This might be RFC3620, section 5.4.2.2 "Failure Case" or even an unrelated problem. Handle 'normally'.
Log.warn( "An exception occurred while creating an encrypted session (with {} at {}:{})", hostname, realHostname, realPort, e );
log.warn( "An exception occurred while creating an encrypted session (with {}:{}). Closing connection.", realHostname, realPort, e );
if (connection != null) {
connection.close();
}
}
if (ServerDialback.isEnabled()) {
Log.debug("LocalOutgoingServerSession: OS - Going to try connecting using server dialback with: " + hostname);
// Use server dialback (pre XMPP 1.0) over a plain connection
return new ServerDialback().createOutgoingSession(domain, hostname, port);
if (ServerDialback.isEnabled())
{
log.debug( "Unable to create a new session. Going to try connecting using server dialback as a fallback." );
// Use server dialback (pre XMPP 1.0) over a plain connection
final LocalOutgoingServerSession outgoingSession = new ServerDialback().createOutgoingSession( domain, hostname, port );
if ( outgoingSession != null) { // TODO this success handler behaves differently from a similar success handler above. Shouldn't those be the same?
log.debug( "Successfully created new session (using dialback as a fallback)!" );
return outgoingSession;
} else {
log.warn( "Unable to create a new session: Dialback (as a fallback) failed." );
return null;
}
}
else
{
log.warn( "Unable to create a new session: exhausted all options (not trying dialback as a fallback, as server dialback is disabled by configuration." );
return null;
}
return null;
}
private static LocalOutgoingServerSession secureAndAuthenticate(String hostname,
SocketConnection connection, XMPPPacketReader reader, StringBuilder openingStream,
String domain) throws Exception {
final Logger log = LoggerFactory.getLogger(LocalOutgoingServerSession.class.getName()+"['"+hostname+"']");
private static LocalOutgoingServerSession secureAndAuthenticate(String hostname, SocketConnection connection, XMPPPacketReader reader, StringBuilder openingStream, String domain) throws Exception {
final Logger log = LoggerFactory.getLogger(Log.getName() + "[Secure/Authenticate connection to: " + domain + " (" + hostname + ")]" );
Element features;
log.debug("Indicating we want TLS to " + hostname);
connection.deliverRawText("<starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>");
log.debug( "Securing and authenticating connection...");
log.debug( "Indicating we want TLS and wait for response." );
connection.deliverRawText( "<starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>" );
MXParser xpp = reader.getXPPParser();
// Wait for the <proceed> response
Element proceed = reader.parseDocument().getRootElement();
if (proceed != null && proceed.getName().equals("proceed")) {
log.debug("Negotiating TLS...");
log.debug( "Recevied 'proceed' from remote server. Negotiating TLS..." );
try {
// boolean needed = JiveGlobals.getBooleanProperty(ConnectionSettings.Server.TLS_CERTIFICATE_VERIFY, true) &&
// JiveGlobals.getBooleanProperty(ConnectionSettings.Server.TLS_CERTIFICATE_CHAIN_VERIFY, true) &&
// !JiveGlobals.getBooleanProperty(ConnectionSettings.Server.TLS_ACCEPT_SELFSIGNED_CERTS, false);
connection.startTLS(true);
} catch(Exception e) {
log.debug("Got an exception whilst negotiating TLS: " + e.getMessage());
log.debug("TLS negotiation failed: " + e.getMessage());
throw e;
}
log.debug("TLS negotiation was successful.");
log.debug( "TLS negotiation was successful. Connection secured. Proceeding with authentication..." );
if (!SASLAuthentication.verifyCertificates(connection.getPeerCertificates(), hostname, true)) {
log.debug("X.509/PKIX failure on outbound session");
if (ServerDialback.isEnabled() || ServerDialback.isEnabledForSelfSigned()) {
log.debug("Will continue with dialback.");
log.debug( "SASL authentication failed. Will continue with dialback." );
} else {
log.warn("No TLS auth, but TLS auth required.");
log.warn( "Unable to authenticated the connection: SASL authentication failed (and dialback is not available)." );
return null;
}
}
// TLS negotiation was successful so initiate a new stream
connection.deliverRawText(openingStream.toString());
log.debug( "TLS negotiation was successful so initiate a new stream." );
connection.deliverRawText( openingStream.toString() );
// Reset the parser to use the new secured reader
xpp.setInput(new InputStreamReader(connection.getTLSStreamHandler().getInputStream(), StandardCharsets.UTF_8));
......@@ -483,34 +525,54 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
}
final boolean dialbackOffered = features.element("dialback") != null;
log.debug("Offering dialback functionality: {}",dialbackOffered);
log.debug("Offering EXTERNAL SASL: {}", saslEXTERNALoffered);
log.debug("Remote server is offering dialback: {}, EXTERNAL SASL:", dialbackOffered, saslEXTERNALoffered );
LocalOutgoingServerSession result = null;
// first, try SASL
// first, try SASL
if (saslEXTERNALoffered) {
log.debug( "Trying to authenticate with EXTERNAL SASL." );
result = attemptSASLexternal(connection, xpp, reader, domain, hostname, id, openingStream);
if (result == null) {
log.debug( "Failed to authenticate with EXTERNAL SASL." );
} else {
log.debug( "Successfully authenticated with EXTERNAL SASL." );
}
}
// SASL unavailable or failed, try dialback.
if (result == null) {
// SASL unavailable or failed, try dialback.
log.debug( "Trying to authenticate with dialback." );
result = attemptDialbackOverTLS(connection, reader, domain, hostname, id);
if (result == null) {
log.debug( "Failed to authenticate with dialback." );
} else {
log.debug( "Successfully authenticated with dialback." );
}
}
return result;
if ( result != null ) {
log.debug( "Successfully secured and authenticated connection!" );
return result;
} else {
log.warn( "Unable to secure and authenticate connection: Exhausted all options." );
return null;
}
}
else {
log.debug("Cannot create outgoing server session, as neither SASL mechanisms nor SERVER DIALBACK were offered by " + hostname);
log.debug( "Failed to secure and authenticate connection: neither SASL mechanisms nor SERVER DIALBACK were offered by the remote host." );
return null;
}
}
else {
log.debug("Error, <proceed> was not received!");
log.debug( "Failed to secure and authenticate connection: <proceed> was not received!" );
return null;
}
}
private static LocalOutgoingServerSession attemptDialbackOverTLS(Connection connection, XMPPPacketReader reader, String domain, String hostname, String id) {
final Logger log = LoggerFactory.getLogger(LocalOutgoingServerSession.class.getName()+"['"+hostname+"']");
final Logger log = LoggerFactory.getLogger( Log.getName() + "[Dialback over TLS for: " + domain + " (" + hostname + ") Stream ID: " + id + "]" );
if (ServerDialback.isEnabled() || ServerDialback.isEnabledForSelfSigned()) {
log.debug("Trying to connecting using dialback over TLS.");
ServerDialback method = new ServerDialback(connection, domain);
......@@ -536,7 +598,8 @@ public class LocalOutgoingServerSession extends LocalServerSession implements Ou
}
private static LocalOutgoingServerSession attemptSASLexternal(SocketConnection connection, MXParser xpp, XMPPPacketReader reader, String domain, String hostname, String id, StringBuilder openingStream) throws DocumentException, IOException, XmlPullParserException {
final Logger log = LoggerFactory.getLogger(LocalOutgoingServerSession.class.getName()+"['"+hostname+"']");
final Logger log = LoggerFactory.getLogger( Log.getName() + "[EXTERNAL SASL for: " + domain + " (" + hostname + ") Stream ID: " + id + "]" );
log.debug("Starting EXTERNAL SASL.");
if (doExternalAuthentication(domain, connection, reader)) {
log.debug("EXTERNAL SASL was successful.");
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment

Technounit-GROUP 2023