HDFS-9854. Log cipher suite negotiation more verbosely. Contributed by Wei-Chiu Chuang.

(cherry picked from commit d1dd248b75)
(cherry picked from commit 59cd23e279)

hadoop-hdfs-project/hadoop-hdfs-client/src/main/java/org/apache/hadoop/hdfs/protocol/datatransfer/sasl/SaslDataTransferClient.java

@@ -238,7 +238,7 @@ public class SaslDataTransferClient {
     if (encryptionKey != null) {
       LOG.debug("SASL client doing encrypted handshake for addr = {}, "
           + "datanodeId = {}", addr, datanodeId);
-      return getEncryptedStreams(underlyingOut, underlyingIn,
+      return getEncryptedStreams(addr, underlyingOut, underlyingIn,
           encryptionKey);
     } else if (!UserGroupInformation.isSecurityEnabled()) {
       LOG.debug("SASL client skipping handshake in unsecured configuration for "
@@ -275,13 +275,15 @@ public class SaslDataTransferClient {
   /**
    * Sends client SASL negotiation for specialized encrypted handshake.
    *
+   * @param addr connection address
    * @param underlyingOut connection output stream
    * @param underlyingIn connection input stream
    * @param encryptionKey for an encrypted SASL handshake
    * @return new pair of streams, wrapped after SASL negotiation
    * @throws IOException for any error
    */
-  private IOStreamPair getEncryptedStreams(OutputStream underlyingOut,
+  private IOStreamPair getEncryptedStreams(InetAddress addr,
+      OutputStream underlyingOut,
       InputStream underlyingIn, DataEncryptionKey encryptionKey)
       throws IOException {
     Map<String, String> saslProps = createSaslPropertiesForEncryption(
@@ -294,8 +296,8 @@ public class SaslDataTransferClient {
     char[] password = encryptionKeyToPassword(encryptionKey.encryptionKey);
     CallbackHandler callbackHandler = new SaslClientCallbackHandler(userName,
         password);
-    return doSaslHandshake(underlyingOut, underlyingIn, userName, saslProps,
+    return doSaslHandshake(addr, underlyingOut, underlyingIn, userName,
-        callbackHandler);
+        saslProps, callbackHandler);
   }
 
   /**
@@ -384,8 +386,8 @@ public class SaslDataTransferClient {
     char[] password = buildClientPassword(accessToken);
     CallbackHandler callbackHandler = new SaslClientCallbackHandler(userName,
         password);
-    return doSaslHandshake(underlyingOut, underlyingIn, userName, saslProps,
+    return doSaslHandshake(addr, underlyingOut, underlyingIn, userName,
-        callbackHandler);
+        saslProps, callbackHandler);
   }
 
   /**
@@ -418,6 +420,7 @@ public class SaslDataTransferClient {
   /**
    * This method actually executes the client-side SASL handshake.
    *
+   * @param addr connection address
    * @param underlyingOut connection output stream
    * @param underlyingIn connection input stream
    * @param userName SASL user name
@@ -426,8 +429,9 @@ public class SaslDataTransferClient {
    * @return new pair of streams, wrapped after SASL negotiation
    * @throws IOException for any error
    */
-  private IOStreamPair doSaslHandshake(OutputStream underlyingOut,
+  private IOStreamPair doSaslHandshake(InetAddress addr,
-      InputStream underlyingIn, String userName, Map<String, String> saslProps,
+      OutputStream underlyingOut, InputStream underlyingIn, String userName,
+      Map<String, String> saslProps,
       CallbackHandler callbackHandler) throws IOException {
 
     DataOutputStream out = new DataOutputStream(underlyingOut);
@@ -447,12 +451,12 @@ public class SaslDataTransferClient {
       byte[] remoteResponse = readSaslMessage(in);
       byte[] localResponse = sasl.evaluateChallengeOrResponse(remoteResponse);
       List<CipherOption> cipherOptions = null;
+      String cipherSuites = conf.get(
+          DFS_ENCRYPT_DATA_TRANSFER_CIPHER_SUITES_KEY);
       if (requestedQopContainsPrivacy(saslProps)) {
         // Negotiate cipher suites if configured.  Currently, the only supported
         // cipher suite is AES/CTR/NoPadding, but the protocol allows multiple
         // values for future expansion.
-        String cipherSuites = conf.get(
-            DFS_ENCRYPT_DATA_TRANSFER_CIPHER_SUITES_KEY);
         if (cipherSuites != null && !cipherSuites.isEmpty()) {
           if (!cipherSuites.equals(CipherSuite.AES_CTR_NOPADDING.getName())) {
             throw new IOException(String.format("Invalid cipher suite, %s=%s",
@@ -479,6 +483,20 @@ public class SaslDataTransferClient {
       if (sasl.isNegotiatedQopPrivacy()) {
         // Unwrap the negotiated cipher option
         cipherOption = unwrap(response.cipherOption, sasl);
+        if (LOG.isDebugEnabled()) {
+          if (cipherOption == null) {
+            // No cipher suite is negotiated
+            if (cipherSuites != null && !cipherSuites.isEmpty()) {
+              // the client accepts some cipher suites, but the server does not.
+              LOG.debug("Client accepts cipher suites {}, "
+                      + "but server {} does not accept any of them",
+                  cipherSuites, addr.toString());
+            }
+          } else {
+            LOG.debug("Client using cipher suite {} with server {}",
+                cipherOption.getCipherSuite().getName(), addr.toString());
+          }
+        }
       }
 
       // If negotiated cipher option is not null, we will use it to create

hadoop-hdfs-project/hadoop-hdfs/CHANGES.txt

@@ -929,6 +929,9 @@ Release 2.8.0 - UNRELEASED
 
     HDFS-9844. Correct path creation in getTrashRoot to handle root dir. (zhz)
 
+    HDFS-9854. Log cipher suite negotiation more verbosely
+    (Wei-Chiu Chuang via cnauroth)
+
   OPTIMIZATIONS
 
     HDFS-8026. Trace FSOutputSummer#writeChecksumChunks rather than

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/protocol/datatransfer/sasl/SaslDataTransferServer.java

@@ -18,6 +18,7 @@
 package org.apache.hadoop.hdfs.protocol.datatransfer.sasl;
 
 import static org.apache.hadoop.hdfs.client.HdfsClientConfigKeys.DFS_DATA_TRANSFER_PROTECTION_KEY;
+import static org.apache.hadoop.hdfs.client.HdfsClientConfigKeys.DFS_ENCRYPT_DATA_TRANSFER_CIPHER_SUITES_KEY;
 import static org.apache.hadoop.hdfs.protocol.datatransfer.sasl.DataTransferSaslUtil.*;
 
 import java.io.ByteArrayInputStream;
@@ -40,6 +41,7 @@ import javax.security.sasl.SaslException;
 
 import org.apache.commons.codec.binary.Base64;
 import org.apache.hadoop.classification.InterfaceAudience;
+import org.apache.hadoop.conf.Configuration;
 import org.apache.hadoop.crypto.CipherOption;
 import org.apache.hadoop.hdfs.net.Peer;
 import org.apache.hadoop.hdfs.protocol.DatanodeID;
@@ -175,7 +177,7 @@ public class SaslDataTransferServer {
           return encryptionKeyToPassword(getEncryptionKeyFromUserName(userName));
         }
       });
-    return doSaslHandshake(underlyingOut, underlyingIn, saslProps,
+    return doSaslHandshake(peer, underlyingOut, underlyingIn, saslProps,
         callbackHandler);
   }
 
@@ -295,7 +297,7 @@ public class SaslDataTransferServer {
           return buildServerPassword(userName);
         }
     });
-    return doSaslHandshake(underlyingOut, underlyingIn, saslProps,
+    return doSaslHandshake(peer, underlyingOut, underlyingIn, saslProps,
         callbackHandler);
   }
 
@@ -338,6 +340,7 @@ public class SaslDataTransferServer {
   /**
    * This method actually executes the server-side SASL handshake.
    *
+   * @param peer connection peer
    * @param underlyingOut connection output stream
    * @param underlyingIn connection input stream
    * @param saslProps properties of SASL negotiation
@@ -345,7 +348,7 @@ public class SaslDataTransferServer {
    * @return new pair of streams, wrapped after SASL negotiation
    * @throws IOException for any error
    */
-  private IOStreamPair doSaslHandshake(OutputStream underlyingOut,
+  private IOStreamPair doSaslHandshake(Peer peer, OutputStream underlyingOut,
       InputStream underlyingIn, Map<String, String> saslProps,
       CallbackHandler callbackHandler) throws IOException {
 
@@ -378,11 +381,23 @@ public class SaslDataTransferServer {
       CipherOption cipherOption = null;
       if (sasl.isNegotiatedQopPrivacy()) {
         // Negotiate a cipher option
-        cipherOption = negotiateCipherOption(dnConf.getConf(), cipherOptions);
+        Configuration conf = dnConf.getConf();
-        if (cipherOption != null) {
+        cipherOption = negotiateCipherOption(conf, cipherOptions);
-          if (LOG.isDebugEnabled()) {
+        if (LOG.isDebugEnabled()) {
-            LOG.debug("Server using cipher suite " + 
+          if (cipherOption == null) {
-                cipherOption.getCipherSuite().getName());
+            // No cipher suite is negotiated
+            String cipherSuites =
+                conf.get(DFS_ENCRYPT_DATA_TRANSFER_CIPHER_SUITES_KEY);
+            if (cipherSuites != null && !cipherSuites.isEmpty()) {
+              // the server accepts some cipher suites, but the client does not.
+              LOG.debug("Server accepts cipher suites {}, "
+                      + "but client {} does not accept any of them",
+                  cipherSuites, peer.getRemoteAddressString());
+            }
+          } else {
+            LOG.debug("Server using cipher suite {} with client {}",
+                cipherOption.getCipherSuite().getName(),
+                peer.getRemoteAddressString());
           }
         }
       }