Enhance TLS logging during connect

For a user authenticating via X.509 certificate log the following:

    INFO 30: Client {"ip":"127.0.0.1","port":60748} using cipher 'TLS_AES_256_GCM_SHA384' authenticated as '<ud>Trond</ud>' via X509 certificate

For a client connecting and provides a certificate without a mapping
to a user:

    INFO 33: Using cipher 'TLS_AES_256_GCM_SHA384', peer certificate provided

And finally for a client connecting without a certificate:

    INFO 30: Using cipher 'TLS_AES_256_GCM_SHA384', peer certificate not provided

Change-Id: I21a0bcda861a7576815611f420742c7224f7b293
Reviewed-on: https://review.couchbase.org/c/kv_engine/+/168224
Tested-by: Build Bot <build@couchbase.com>
Reviewed-by: Dave Rigby <daver@couchbase.com>

daemon/connection.cc

@@ -1071,18 +1071,18 @@ void Connection::ssl_read_callback(bufferevent* bev, void* ctx) {
                  ssl_errors);
     }
 
-    // Lets inspect the certificate before we'll do anything further
+    // Let's inspect the certificate before we'll do anything further
     auto* ssl_st = bufferevent_openssl_get_ssl(bev);
     const auto verifyMode = SSL_get_verify_mode(ssl_st);
     const auto enabled = ((verifyMode & SSL_VERIFY_PEER) == SSL_VERIFY_PEER);
 
     bool disconnect = false;
+    cb::openssl::unique_x509_ptr cert(SSL_get_peer_certificate(ssl_st));
     if (enabled) {
         const auto mandatory =
                 ((verifyMode & SSL_VERIFY_FAIL_IF_NO_PEER_CERT) ==
                  SSL_VERIFY_FAIL_IF_NO_PEER_CERT);
         // Check certificate
-        cb::openssl::unique_x509_ptr cert(SSL_get_peer_certificate(ssl_st));
         if (cert) {
             auto [status, name] = Settings::instance().lookupUser(cert.get());
             switch (status) {
@@ -1118,7 +1118,7 @@ void Connection::ssl_read_callback(bufferevent* bev, void* ctx) {
             case cb::x509::Status::NotPresent:
                 // Note: NotPresent in this context is that there is no
                 //       mapper present in the _configuration_ which is
-                //       allowd in "Enabled" mode as it just means that we'll
+                //       allowed in "Enabled" mode as it just means that we'll
                 //       try to verify the peer.
                 if (mandatory) {
                     const char* reason =
@@ -1135,7 +1135,9 @@ void Connection::ssl_read_callback(bufferevent* bev, void* ctx) {
                 }
                 break;
             case cb::x509::Status::Success:
-                if (!instance.tryAuthFromSslCert(name)) {
+                if (!instance.tryAuthFromSslCert(name,
+                                                 SSL_get_cipher_name(ssl_st))) {
+                    // Already logged
                     const std::string reason =
                             "User [" + name + "] not defined in Couchbase";
                     audit_auth_failure(instance,
@@ -1150,10 +1152,12 @@ void Connection::ssl_read_callback(bufferevent* bev, void* ctx) {
 
     if (disconnect) {
         instance.shutdown();
-    } else {
-        LOG_INFO("{}: Using SSL cipher:{}",
+    } else if (!instance.authenticated) {
+        // tryAuthFromSslCertificate logged the cipher
+        LOG_INFO("{}: Using cipher '{}', peer certificate {}provided",
                  instance.getId(),
-                 SSL_get_cipher_name(ssl_st));
+                 SSL_get_cipher_name(ssl_st),
+                 cert ? "" : "not ");
     }
 
     // update the callback to call the normal read callback
@@ -1189,18 +1193,20 @@ void Connection::setAuthenticated(bool authenticated_,
     }
 }
 
-bool Connection::tryAuthFromSslCert(const std::string& userName) {
+bool Connection::tryAuthFromSslCert(const std::string& userName,
+                                    std::string_view cipherName) {
     try {
         auto context = cb::rbac::createInitialContext(
                 {userName, cb::sasl::Domain::Local});
         setAuthenticated(
                 true, context.second, {userName, cb::sasl::Domain::Local});
         audit_auth_success(*this);
         LOG_INFO(
-                "{}: Client {} authenticated as '{}' via X509 "
-                "certificate",
+                "{}: Client {} using cipher '{}' authenticated as '{}' via "
+                "X.509 certificate",
                 getId(),
                 getPeername(),
+                cipherName,
                 cb::UserDataView(user.name));
         // Connections authenticated by using X.509 certificates should not
         // be able to use SASL to change it's identity.

daemon/connection.h

@@ -514,7 +514,8 @@ class Connection : public DcpMessageProducersIface {
      * @return true if username has been linked to RBAC or ssl cert was not
      * presented by the client.
      */
-    bool tryAuthFromSslCert(const std::string& userName);
+    bool tryAuthFromSslCert(const std::string& userName,
+                            std::string_view cipherName);
 
     /**
      * Get the number of cookies currently bound to this connection