From af7f1e3a778a201a4bd6a372eb441b0f73b9c2ba Mon Sep 17 00:00:00 2001 From: Shreyas Kalyan Date: Wed, 18 Mar 2020 22:26:28 -0700 Subject: SERVER-46950 Add message-strings for TLS --- src/mongo/db/free_mon/free_mon_processor.cpp | 5 +- src/mongo/util/net/openssl_init.cpp | 7 +- src/mongo/util/net/private/ssl_expiration.cpp | 4 +- src/mongo/util/net/sock.cpp | 109 +++++++++++++++----------- src/mongo/util/net/sockaddr.cpp | 12 +-- src/mongo/util/net/socket_utils.cpp | 28 ++++--- src/mongo/util/net/ssl_manager.cpp | 44 ++++++----- src/mongo/util/net/ssl_manager_apple.cpp | 11 ++- src/mongo/util/net/ssl_manager_openssl.cpp | 99 ++++++++++++++--------- src/mongo/util/net/ssl_manager_windows.cpp | 38 +++++++-- 10 files changed, 216 insertions(+), 141 deletions(-) (limited to 'src/mongo') diff --git a/src/mongo/db/free_mon/free_mon_processor.cpp b/src/mongo/db/free_mon/free_mon_processor.cpp index 72d2fc1dfde..4498617172b 100644 --- a/src/mongo/db/free_mon/free_mon_processor.cpp +++ b/src/mongo/db/free_mon/free_mon_processor.cpp @@ -260,10 +260,11 @@ void FreeMonProcessor::run() { _queue.stop(); LOGV2_WARNING(20619, - "Uncaught exception in '{exception}' in free monitoring subsystem. " + "Uncaught exception in '{error}' in free monitoring subsystem. " "Shutting down the free monitoring subsystem.", + "Uncaught exception in free monitoring subsystem. " "Shutting down the free monitoring subsystem.", - "exception"_attr = exceptionToStatus()); + "error"_attr = exceptionToStatus()); } } diff --git a/src/mongo/util/net/openssl_init.cpp b/src/mongo/util/net/openssl_init.cpp index d7a94e07767..1ef1e0ed26d 100644 --- a/src/mongo/util/net/openssl_init.cpp +++ b/src/mongo/util/net/openssl_init.cpp @@ -153,10 +153,9 @@ void setupFIPS() { int status = FIPS_mode_set(1); if (!status) { LOGV2_FATAL(23173, - "can't activate FIPS mode: {sslManagerError}", - "can't activate FIPS mode", - "sslManagerError"_attr = - SSLManagerInterface::getSSLErrorMessage(ERR_get_error())); + "can't activate FIPS mode: {error}", + "Can't activate FIPS mode", + "error"_attr = SSLManagerInterface::getSSLErrorMessage(ERR_get_error())); fassertFailedNoTrace(16703); } LOGV2(23172, "FIPS 140-2 mode activated"); diff --git a/src/mongo/util/net/private/ssl_expiration.cpp b/src/mongo/util/net/private/ssl_expiration.cpp index 5f37d67d2f1..9bdcc797cec 100644 --- a/src/mongo/util/net/private/ssl_expiration.cpp +++ b/src/mongo/util/net/private/ssl_expiration.cpp @@ -60,6 +60,7 @@ void CertificateExpirationMonitor::taskDoWork() { // The certificate has expired. LOGV2_WARNING(23785, "Server certificate is now invalid. It expired on {certExpiration}", + "Server certificate has expired", "certExpiration"_attr = dateToISOStringUTC(_certExpiration)); return; } @@ -71,8 +72,9 @@ void CertificateExpirationMonitor::taskDoWork() { LOGV2_WARNING(23786, "Server certificate will expire on {certExpiration} in " "{validDuration}.", + "Server certificate will expire soon", "certExpiration"_attr = dateToISOStringUTC(_certExpiration), - "validDuration"_attr = durationCount(remainingValidDuration) / 24); + "validDuration"_attr = durationCount(remainingValidDuration)); } } diff --git a/src/mongo/util/net/sock.cpp b/src/mongo/util/net/sock.cpp index eedfc13fdda..574c33e2b1a 100644 --- a/src/mongo/util/net/sock.cpp +++ b/src/mongo/util/net/sock.cpp @@ -103,8 +103,9 @@ void networkWarnWithDescription(const Socket& socket, StringData call, int error #endif auto ewd = errnoWithDescription(errorCode); LOGV2_WARNING(23190, - "Failed to connect to {remoteSocketAddress}:{remoteSocketAddressPort}, " + "failed to connect to {remoteSocketAddress}:{remoteSocketAddressPort}, " "in({call}), reason: {error}", + "Failed to connect to remote host", "remoteSocketAddress"_attr = socket.remoteAddr().getAddr(), "remoteSocketAddressPort"_attr = socket.remoteAddr().getPort(), "call"_attr = call, @@ -121,14 +122,16 @@ void setSockTimeouts(int sock, double secs) { setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, reinterpret_cast(&timeout), sizeof(DWORD)); if (report && (status == SOCKET_ERROR)) LOGV2(23177, - "unable to set SO_RCVTIMEO: {wsaError}", - "wsaError"_attr = errnoWithDescription(WSAGetLastError())); + "unable to set SO_RCVTIMEO: {reason}", + "Unable to set SO_RCVTIMEO", + "reason"_attr = errnoWithDescription(WSAGetLastError())); status = setsockopt(sock, SOL_SOCKET, SO_SNDTIMEO, reinterpret_cast(&timeout), sizeof(DWORD)); if (kDebugBuild && report && (status == SOCKET_ERROR)) LOGV2(23178, - "unable to set SO_SNDTIMEO: {wsaError}", - "wsaError"_attr = errnoWithDescription(WSAGetLastError())); + "unable to set SO_SNDTIMEO: {reason}", + "Unable to set SO_SNDTIME0", + "reason"_attr = errnoWithDescription(WSAGetLastError())); #else struct timeval tv; tv.tv_sec = (int)secs; @@ -155,7 +158,7 @@ void disableNagle(int sock) { if (setsockopt(sock, level, TCP_NODELAY, (char*)&x, sizeof(x))) LOGV2_ERROR(23195, "disableNagle failed: {error}", - "disableNagle failed", + "DisableNagle failed", "error"_attr = errnoWithDescription()); #ifdef SO_KEEPALIVE @@ -183,10 +186,10 @@ SockAddr getLocalAddrForBoundSocketFd(int fd) { if (rc != 0) { LOGV2_WARNING(23191, "Could not resolve local address for socket with fd {fd}: " - "{socketError}", - "Could not resolve local address for socket", + "{error}", + "Could not resolve local address for socket with fd", "fd"_attr = fd, - "socketError"_attr = getAddrInfoStrError(socketGetLastError())); + "error"_attr = getAddrInfoStrError(socketGetLastError())); result = SockAddr(); } return result; @@ -359,6 +362,7 @@ bool Socket::connect(SockAddr& remote, Milliseconds connectTimeoutMillis) { LOGV2_WARNING(23192, "Failed to connect to {remoteAddr}:{remotePort} after " "{connectTimeout} milliseconds, giving up.", + "Failed to connect to remote host. Giving up", "remoteAddr"_attr = _remote.getAddr(), "remotePort"_attr = _remote.getPort(), "connectTimeout"_attr = connectTimeoutMillis); @@ -573,17 +577,19 @@ void Socket::handleSendError(int ret, const char* context) { #endif LOGV2_DEBUG(23181, logSeverityV1toV2(_logLevel).toInt(), - "Socket {context} send() timed out {remoteString}", + "Socket {context} send() timed out {remoteHost}", + "Socket send() to remote host timed out", "context"_attr = context, - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); throwSocketError(SocketErrorKind::SEND_TIMEOUT, remoteString()); } else if (mongo_errno != EINTR) { LOGV2_DEBUG(23182, logSeverityV1toV2(_logLevel).toInt(), - "Socket {context} send() {mongoError} {remoteString}", + "Socket {context} send() {error} {remoteHost}", + "Socket send() to remote host failed", "context"_attr = context, - "mongoError"_attr = errnoWithDescription(mongo_errno), - "remoteString"_attr = remoteString()); + "error"_attr = errnoWithDescription(mongo_errno), + "remoteHost"_attr = remoteString()); throwSocketError(SocketErrorKind::SEND_ERROR, remoteString()); } } // namespace mongo @@ -592,8 +598,9 @@ void Socket::handleRecvError(int ret, int len) { if (ret == 0) { LOGV2_DEBUG(23183, 3, - "Socket recv() conn closed? {remoteString}", - "remoteString"_attr = remoteString()); + "Socket recv() conn closed? {remoteHost}", + "Socket recv() failed; connection may have been closed", + "remoteHost"_attr = remoteString()); throwSocketError(SocketErrorKind::CLOSED, remoteString()); } @@ -618,16 +625,18 @@ void Socket::handleRecvError(int ret, int len) { // this is a timeout LOGV2_DEBUG(23184, logSeverityV1toV2(_logLevel).toInt(), - "Socket recv() timeout {remoteString}", - "remoteString"_attr = remoteString()); + "Socket recv() timeout {remoteHost}", + "Socket recv() timeout", + "remoteHost"_attr = remoteString()); throwSocketError(SocketErrorKind::RECV_TIMEOUT, remoteString()); } LOGV2_DEBUG(23185, logSeverityV1toV2(_logLevel).toInt(), - "Socket recv() {error} {remoteString}", + "Socket recv() {error} {remoteHost}", + "Socket recv() error", "error"_attr = errnoWithDescription(e), - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); throwSocketError(SocketErrorKind::RECV_ERROR, remoteString()); } @@ -681,10 +690,10 @@ bool Socket::isStillConnected() { LOGV2_DEBUG( 23186, 2, - "polling for status of connection to {remoteString}, " - "{nEvents_0_no_events_nEvents_1_error_detected_event_detected}", - "remoteString"_attr = remoteString(), - "nEvents_0_no_events_nEvents_1_error_detected_event_detected"_attr = + "polling for status of connection to {remoteHost}, {errorOrEventDetected}", + "Polling for status of connection to remote host", + "remoteHost"_attr = remoteString(), + "errorOrEventDetected"_attr = (nEvents == 0 ? "no events" : nEvents == -1 ? "error detected" : "event detected")); if (nEvents == 0) { @@ -694,10 +703,11 @@ bool Socket::isStillConnected() { // Poll itself failed, this is weird, warn and log errno LOGV2_WARNING(23193, "Socket poll() failed during connectivity check (idle {idleTimeSecs} secs, " - "remote host {remoteString}){causedBy_errnoWithDescription}", + "remote host {remoteHost}){error}", + "Socket poll() to remote host failed during connectivity check", "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString(), - "causedBy_errnoWithDescription"_attr = causedBy(errnoWithDescription())); + "remoteHost"_attr = remoteString(), + "error"_attr = causedBy(errnoWithDescription())); // Return true since it's not clear that we're disconnected. return true; @@ -722,63 +732,74 @@ bool Socket::isStillConnected() { // An error occurred during recv, warn and log errno LOGV2_WARNING(23194, "Socket recv() failed during connectivity check (idle {idleTimeSecs} " - "secs, remote host {remoteString}){causedBy_errnoWithDescription}", + "secs, remote host {remoteHost}){error}", + "Socket recv() failed during connectivity check", "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString(), - "causedBy_errnoWithDescription"_attr = causedBy(errnoWithDescription())); + "remoteHost"_attr = remoteString(), + "error"_attr = causedBy(errnoWithDescription())); } else if (recvd > 0) { // We got nonzero data from this socket, very weird? // Log and warn at runtime, log and abort at devtime // TODO: Dump the data to the log somehow? LOGV2_ERROR(23197, - "Socket found pending {recvd} bytes of data during connectivity check " - "(idle {idleTimeSecs} secs, remote host {remoteString})", + "Socket found pending {recvd} bytes of data during connectivity " + "check (idle {idleTimeSecs} secs, remote host {remoteHost})", + "Socket found pending bytes of data during connectivity check to remote " + "host", "recvd"_attr = recvd, "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); if (kDebugBuild) { std::string hex = hexdump(testBuf, recvd); - LOGV2_ERROR(23198, "Hex dump of stale log data: {hex}", "hex"_attr = hex); + LOGV2_ERROR(23198, + "Hex dump of stale log data: {hex}", + "Hex dump of stale log data", + "hex"_attr = hex); } dassert(false); } else { // recvd == 0, socket closed remotely, just return false LOGV2(23187, "Socket closed remotely, no longer connected (idle {idleTimeSecs} secs, remote " - "host {remoteString})", + "host {remoteHost})", + "Socket closed remotely, no longer connected to remote host", "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); } } else if (pollInfo.revents & POLLHUP) { // A hangup has occurred on this socket LOGV2(23188, "Socket hangup detected, no longer connected (idle {idleTimeSecs} secs, remote host " - "{remoteString})", + "{remoteHost})", + "Socket hangup detected, no longer connected to remote host", "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); } else if (pollInfo.revents & POLLERR) { // An error has occurred on this socket LOGV2(23189, "Socket error detected, no longer connected (idle {idleTimeSecs} secs, remote host " - "{remoteString})", + "{remoteHost})", + "Socket error detected, no longer connected to remote host", "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); } else if (pollInfo.revents & POLLNVAL) { // Socket descriptor itself is weird // Log and warn at runtime, log and abort at devtime LOGV2_ERROR(23199, "Socket descriptor detected as invalid (idle {idleTimeSecs} secs, remote host " - "{remoteString})", + "{remoteHost})", + "Socket descriptor detected as invalid", "idleTimeSecs"_attr = idleTimeSecs, - "remoteString"_attr = remoteString()); + "remoteHost"_attr = remoteString()); dassert(false); } else { // Don't know what poll is saying here // Log and warn at runtime, log and abort at devtime LOGV2_ERROR(23200, - "Socket had unknown event ({static_cast_int_pollInfo_revents}) (idle " + "Socket had unknown event ({pollEvents}) (idle " "{idleTimeSecs} secs, remote host {remoteString})", - "static_cast_int_pollInfo_revents"_attr = static_cast(pollInfo.revents), + "Socket had unknown event", + "pollEvents"_attr = static_cast(pollInfo.revents), "idleTimeSecs"_attr = idleTimeSecs, "remoteString"_attr = remoteString()); dassert(false); diff --git a/src/mongo/util/net/sockaddr.cpp b/src/mongo/util/net/sockaddr.cpp index 962f71aed14..33b3e50b865 100644 --- a/src/mongo/util/net/sockaddr.cpp +++ b/src/mongo/util/net/sockaddr.cpp @@ -158,10 +158,10 @@ SockAddr::SockAddr(StringData target, int port, sa_family_t familyHint) if (_hostOrIp != "0.0.0.0") { // don't log if this as it is a // CRT construction and log() may not work yet. LOGV2(23175, - "getaddrinfo(\"{host}\") failed: {reason}", - "getaddrinfo failed", + "getaddrinfo(\"{host}\") failed: {error}", + "Command getaddrinfo failed", "host"_attr = _hostOrIp, - "reason"_attr = getAddrInfoStrError(addrErr.err)); + "error"_attr = getAddrInfoStrError(addrErr.err)); _isValid = false; return; } @@ -191,10 +191,10 @@ std::vector SockAddr::createAll(StringData target, int port, sa_family auto addrErr = resolveAddrInfo(hostOrIp, port, familyHint); if (addrErr.err) { LOGV2(23176, - "getaddrinfo(\"{host}\") failed: {reason}", - "getaddrinfo failed", + "getaddrinfo(\"{host}\") failed: {error}", + "getaddrinfo invocation failed", "host"_attr = hostOrIp, - "reason"_attr = getAddrInfoStrError(addrErr.err)); + "error"_attr = getAddrInfoStrError(addrErr.err)); return {}; } diff --git a/src/mongo/util/net/socket_utils.cpp b/src/mongo/util/net/socket_utils.cpp index 11fec0298ac..3d321bf3810 100644 --- a/src/mongo/util/net/socket_utils.cpp +++ b/src/mongo/util/net/socket_utils.cpp @@ -71,9 +71,9 @@ const struct WinsockInit { WSADATA d; if (WSAStartup(MAKEWORD(2, 2), &d) != 0) { LOGV2(23201, - "ERROR: wsastartup failed {errnoWithDescription}", + "ERROR: wsastartup failed {error}", "ERROR: wsastartup failed", - "errnoWithDescription"_attr = errnoWithDescription()); + "error"_attr = errnoWithDescription()); quickExit(EXIT_NTSERVICE_ERROR); } } @@ -119,9 +119,9 @@ void setSocketKeepAliveParams(int sock, return val ? (val.get() / 1000) : default_value; } LOGV2_ERROR(23203, - "can't get KeepAlive parameter: {status}", - "can't get KeepAlive parameter", - "status"_attr = withval.getStatus()); + "can't get KeepAlive parameter: {error}", + "Can't get KeepAlive parameter", + "error"_attr = withval.getStatus()); return default_value; }; @@ -145,7 +145,7 @@ void setSocketKeepAliveParams(int sock, nullptr)) { LOGV2_ERROR(23204, "failed setting keepalive values: {error}", - "failed setting keepalive values", + "Failed setting keepalive values", "error"_attr = WSAGetLastError()); } } @@ -157,18 +157,20 @@ void setSocketKeepAliveParams(int sock, if (getsockopt(sock, level, optnum, (char*)&optval, &len)) { LOGV2_ERROR(23205, - "can't get {optname}: {errnoWithDescription}", + "can't get {optname}: {error}", + "Can't get socket option", "optname"_attr = optname, - "errnoWithDescription"_attr = errnoWithDescription()); + "error"_attr = errnoWithDescription()); } if (optval > maxval) { optval = maxval; if (setsockopt(sock, level, optnum, (char*)&optval, sizeof(optval))) { LOGV2_ERROR(23206, - "can't set {optname}: {errnoWithDescription}", + "can't set {optname}: {error}", + "Can't set socket option", "optname"_attr = optname, - "errnoWithDescription"_attr = errnoWithDescription()); + "error"_attr = errnoWithDescription()); } } }; @@ -213,9 +215,9 @@ std::string getHostName() { int ec = gethostname(buf, 127); if (ec || *buf == 0) { LOGV2(23202, - "can't get this server's hostname {errnoWithDescription}", - "can't get this server's hostname", - "errnoWithDescription"_attr = errnoWithDescription()); + "can't get this server's hostname {error}", + "Can't get this server's hostname", + "error"_attr = errnoWithDescription()); return ""; } return buf; diff --git a/src/mongo/util/net/ssl_manager.cpp b/src/mongo/util/net/ssl_manager.cpp index 56ff7878ea6..e162ac28c49 100644 --- a/src/mongo/util/net/ssl_manager.cpp +++ b/src/mongo/util/net/ssl_manager.cpp @@ -555,19 +555,21 @@ MONGO_INITIALIZER_WITH_PREREQUISITES(SSLManagerLogger, ("SSLManager", "GlobalLog if (!config.clientSubjectName.empty()) { LOGV2_DEBUG(23214, 1, - "Client Certificate Name: {clientSubjectName}", - "clientSubjectName"_attr = config.clientSubjectName); + "Client Certificate Name: {name}", + "Client certificate name", + "name"_attr = config.clientSubjectName); } if (!config.serverSubjectName().empty()) { LOGV2_DEBUG(23215, 1, - "Server Certificate Name: {serverSubjectName}", - "serverSubjectName"_attr = config.serverSubjectName()); + "Server Certificate Name: {name}", + "Server certificate name", + "name"_attr = config.serverSubjectName()); LOGV2_DEBUG(23216, 1, - "Server Certificate Expiration: {serverCertificateExpirationDate}", - "serverCertificateExpirationDate"_attr = - config.serverCertificateExpirationDate); + "Server Certificate Expiration: {expiration}", + "Server certificate expiration", + "expiration"_attr = config.serverCertificateExpirationDate); } } @@ -607,10 +609,10 @@ Status SSLX509Name::normalizeStrings() { LOGV2_DEBUG(23217, 1, "Certificate subject name contains unknown string type: " - "{entry_type} (string value is \"{entry_value}\")", + "{entryType} (string value is \"{entryValue}\")", "Certificate subject name contains unknown string type", - "entry_type"_attr = entry.type, - "entry_value"_attr = entry.value); + "entryType"_attr = entry.type, + "entryValue"_attr = entry.value); break; } } @@ -693,18 +695,18 @@ bool SSLConfiguration::isClusterMember(StringData subjectName) const { auto swClient = parseDN(subjectName); if (!swClient.isOK()) { LOGV2_WARNING(23219, - "Unable to parse client subject name: {status}", + "Unable to parse client subject name: {error}", "Unable to parse client subject name", - "status"_attr = swClient.getStatus()); + "error"_attr = swClient.getStatus()); return false; } auto& client = swClient.getValue(); auto status = client.normalizeStrings(); if (!status.isOK()) { LOGV2_WARNING(23220, - "Unable to normalize client subject name: {status}", + "Unable to normalize client subject name: {error}", "Unable to normalize client subject name", - "status"_attr = status); + "error"_attr = status); return false; } @@ -1200,9 +1202,10 @@ void recordTLSVersion(TLSVersion version, const HostAndPort& hostForLogging) { if (!versionString.empty()) { LOGV2(23218, - "Accepted connection with TLS Version {version} from connection {connection}", - "version"_attr = versionString, - "connection"_attr = hostForLogging); + "Accepted connection with TLS Version {tlsVersion} from connection {remoteHost}", + "Accepted connection with TLS", + "tlsVersion"_attr = versionString, + "remoteHost"_attr = hostForLogging); } } @@ -1230,13 +1233,16 @@ bool hostNameMatchForX509Certificates(std::string nameToMatch, std::string certH } void tlsEmitWarningExpiringClientCertificate(const SSLX509Name& peer) { - LOGV2_WARNING( - 23221, "Peer certificate '{peerSubjectName}' expires soon", "peerSubjectName"_attr = peer); + LOGV2_WARNING(23221, + "Peer certificate '{peerSubjectName}' expires soon", + "Peer certificate expires soon", + "peerSubjectName"_attr = peer); } void tlsEmitWarningExpiringClientCertificate(const SSLX509Name& peer, Days days) { LOGV2_WARNING(23222, "Peer certificate '{peerSubjectName}' expires in {days}", + "Peer certificate expiration information", "peerSubjectName"_attr = peer, "days"_attr = days); } diff --git a/src/mongo/util/net/ssl_manager_apple.cpp b/src/mongo/util/net/ssl_manager_apple.cpp index 88af2c0d93b..d2c75beb3f8 100644 --- a/src/mongo/util/net/ssl_manager_apple.cpp +++ b/src/mongo/util/net/ssl_manager_apple.cpp @@ -1471,19 +1471,17 @@ Future SSLManagerApple::parseAndValidatePeerCertificate( } const auto badCert = [&](StringData msg, bool warn = false) -> Future { - constexpr StringData prefix = "SSL peer certificate validation failed: "_sd; if (warn) { LOGV2_WARNING(23209, - "{prefix}{msg}", + "SSL peer certificate validation failed: {error}", "SSL peer certificate validation failed", - "prefix"_attr = prefix, - "msg"_attr = msg); + "error"_attr = msg); return Future::makeReady(SSLPeerInfo(sniName)); } else { LOGV2_ERROR(23212, - "SSL peer certificate validation failed {status}; connection rejected", + "SSL peer certificate validation failed {error}; connection rejected", "SSL peer certificate validation failed; connection rejected", - "status"_attr = msg); + "error"_attr = msg); return Status(ErrorCodes::SSLHandshakeFailed, msg); } }; @@ -1587,6 +1585,7 @@ Future SSLManagerApple::parseAndValidatePeerCertificate( LOGV2_DEBUG(23207, 2, "Accepted TLS connection from peer: {peerSubjectName}", + "Accepted TLS connection from peer", "peerSubjectName"_attr = peerSubjectName); // Server side. diff --git a/src/mongo/util/net/ssl_manager_openssl.cpp b/src/mongo/util/net/ssl_manager_openssl.cpp index 5d7ec9831ab..22f4170bd92 100644 --- a/src/mongo/util/net/ssl_manager_openssl.cpp +++ b/src/mongo/util/net/ssl_manager_openssl.cpp @@ -1540,8 +1540,9 @@ int ocspClientCallback(SSL* ssl, void* arg) { if (swStapleOK.getStatus() == ErrorCodes::OCSPCertificateStatusRevoked) { LOGV2_DEBUG(23225, 1, - "Stapled Certificate validation failed: {reason}", - "reason"_attr = swStapleOK.getStatus().reason()); + "Stapled Certificate validation failed: {error}", + "Stapled Certificate validation failed", + "error"_attr = swStapleOK.getStatus()); return OCSP_CLIENT_RESPONSE_NOT_ACCEPTABLE; } @@ -1965,19 +1966,19 @@ bool SSLManagerOpenSSL::_parseAndValidateCertificate(const std::string& keyFile, BIO* inBIO = BIO_new(BIO_s_file()); if (inBIO == nullptr) { LOGV2_ERROR(23243, - "failed to allocate BIO object: {openSSLError}", - "failed to allocate BIO object", - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "failed to allocate BIO object: {error}", + "Failed to allocate BIO object", + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } ON_BLOCK_EXIT([&] { BIO_free(inBIO); }); if (BIO_read_filename(inBIO, keyFile.c_str()) <= 0) { LOGV2_ERROR(23244, - "cannot read key file when setting subject name: {keyFile} {openSSLError}", - "cannot read key file when setting subject name", + "cannot read key file when setting subject name: {keyFile} {error}", + "Cannot read key file when setting subject name", "keyFile"_attr = keyFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } @@ -1985,10 +1986,10 @@ bool SSLManagerOpenSSL::_parseAndValidateCertificate(const std::string& keyFile, inBIO, nullptr, &SSLManagerOpenSSL::password_cb, static_cast(&keyPassword)); if (x509 == nullptr) { LOGV2_ERROR(23245, - "cannot retrieve certificate from keyfile: {keyFile} {openSSLError}", - "cannot retrieve certificate from keyfile", + "cannot retrieve certificate from keyfile: {keyFile} {error}", + "Cannot retrieve certificate from keyfile", "keyFile"_attr = keyFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } ON_BLOCK_EXIT([&] { X509_free(x509); }); @@ -2022,29 +2023,29 @@ bool SSLManagerOpenSSL::_setupPEM(SSL_CTX* context, PasswordFetcher* password) { if (SSL_CTX_use_certificate_chain_file(context, keyFile.c_str()) != 1) { LOGV2_ERROR(23248, - "cannot read certificate file: {keyFile} {openSSLError}", - "cannot read certificate file", + "cannot read certificate file: {keyFile} {error}", + "Cannot read certificate file", "keyFile"_attr = keyFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } BIO* inBio = BIO_new(BIO_s_file()); if (!inBio) { LOGV2_ERROR(23249, - "failed to allocate BIO object: {openSSLError}", - "failed to allocate BIO object", - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "failed to allocate BIO object: {error}", + "Failed to allocate BIO object", + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } const auto bioGuard = makeGuard([&inBio]() { BIO_free(inBio); }); if (BIO_read_filename(inBio, keyFile.c_str()) <= 0) { LOGV2_ERROR(23250, - "cannot read PEM key file: {keyFile} {openSSLError}", - "cannot read PEM key file", + "cannot read PEM key file: {keyFile} {error}", + "Cannot read PEM key file", "keyFile"_attr = keyFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } @@ -2054,29 +2055,29 @@ bool SSLManagerOpenSSL::_setupPEM(SSL_CTX* context, EVP_PKEY* privateKey = PEM_read_bio_PrivateKey(inBio, nullptr, password_cb, userdata); if (!privateKey) { LOGV2_ERROR(23251, - "cannot read PEM key file: {keyFile} {openSSLError}", - "cannot read PEM key file", + "cannot read PEM key file: {keyFile} {error}", + "Cannot read PEM key file", "keyFile"_attr = keyFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } const auto privateKeyGuard = makeGuard([&privateKey]() { EVP_PKEY_free(privateKey); }); if (SSL_CTX_use_PrivateKey(context, privateKey) != 1) { LOGV2_ERROR(23252, - "cannot use PEM key file: {keyFile} {openSSLError}", - "cannot use PEM key file", + "cannot use PEM key file: {keyFile} {error}", + "Cannot use PEM key file", "keyFile"_attr = keyFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } // Verify that the certificate and the key go together. if (SSL_CTX_check_private_key(context) != 1) { LOGV2_ERROR(23253, - "SSL certificate validation failed: {openSSLError}", + "SSL certificate validation failed: {error}", "SSL certificate validation failed", - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } @@ -2143,10 +2144,10 @@ bool SSLManagerOpenSSL::_setupCRL(SSL_CTX* context, const std::string& crlFile) int status = X509_load_crl_file(lookup, crlFile.c_str(), X509_FILETYPE_PEM); if (status == 0) { LOGV2_ERROR(23254, - "cannot read CRL file: {crlFile} {openSSLError}", - "cannot read CRL file", + "cannot read CRL file: {crlFile} {error}", + "Cannot read CRL file", "crlFile"_attr = crlFile, - "openSSLError"_attr = getSSLErrorMessage(ERR_get_error())); + "error"_attr = getSSLErrorMessage(ERR_get_error())); return false; } @@ -2155,6 +2156,7 @@ bool SSLManagerOpenSSL::_setupCRL(SSL_CTX* context, const std::string& crlFile) } else { LOGV2(4652602, "ssl imported {numberCerts} revoked certificates from the revocation list", + "SSL imported revoked certificates from the revocation list", "numberCerts"_attr = status); } @@ -2376,11 +2378,15 @@ Future SSLManagerOpenSSL::parseAndValidatePeerCertificate( if (_weakValidation) { // do not give warning if certificate warnings are suppressed if (!_suppressNoCertificateWarning) { - LOGV2_WARNING(23234, "no SSL certificate provided by peer"); + LOGV2_WARNING(23234, + "no SSL certificate provided by peer", + "No SSL certificate provided by peer"); } return SSLPeerInfo(sni); } else { - LOGV2_ERROR(23255, "no SSL certificate provided by peer; connection rejected"); + LOGV2_ERROR(23255, + "no SSL certificate provided by peer; connection rejected", + "No SSL certificate provided by peer; connection rejected"); return Status(ErrorCodes::SSLHandshakeFailed, "no SSL certificate provided by peer; connection rejected"); } @@ -2559,10 +2565,21 @@ Future SSLManagerOpenSSL::parseAndValidatePeerCertificate( msgBuilder << "The server certificate does not match the host name. Hostname: " << remoteHost << " does not match " << certificateNames.str(); std::string msg = msgBuilder.str(); + if (_allowInvalidCertificates || _allowInvalidHostnames || isUnixDomainSocket(remoteHost)) { - LOGV2_WARNING(23238, "{msg}", "msg"_attr = msg); + LOGV2_WARNING(23238, + "The server certificate does not match the host name. Hostname: " + "{remoteHost} does not match {certificateNames}", + "The server certificate does not match the remote host name", + "remoteHost"_attr = remoteHost, + "certificateNames"_attr = certificateNames.str()); } else { - LOGV2_ERROR(23257, "{msg}", "msg"_attr = msg); + LOGV2_ERROR(23257, + "The server certificate does not match the host name. Hostname: " + "{remoteHost} does not match {certificateNames}", + "The server certificate does not match the remote host name", + "remoteHost"_attr = remoteHost, + "certificateNames"_attr = certificateNames.str()); return Future::makeReady(Status(ErrorCodes::SSLHandshakeFailed, msg)); } } @@ -2656,8 +2673,10 @@ void SSLManagerOpenSSL::_handleSSLError(SSLConnectionOpenSSL* conn, int ret) { // manner. errToThrow = (code == SSL_ERROR_WANT_READ) ? SocketErrorKind::RECV_ERROR : SocketErrorKind::SEND_ERROR; - LOGV2_ERROR( - 23258, "SSL: {code}, possibly timed out during connect", "code"_attr = code); + LOGV2_ERROR(23258, + "SSL: {error}, possibly timed out during connect", + "SSL: possibly timed out during connect", + "error"_attr = code); break; case SSL_ERROR_ZERO_RETURN: @@ -2669,17 +2688,19 @@ void SSLManagerOpenSSL::_handleSSLError(SSLConnectionOpenSSL* conn, int ret) { // If ERR_get_error returned 0, the error queue is empty // check the return value of the actual SSL operation if (err != 0) { - LOGV2_ERROR(23260, "SSL: {error}", "error"_attr = getSSLErrorMessage(err)); + LOGV2_ERROR( + 23260, "SSL: {error}", "SSL error", "error"_attr = getSSLErrorMessage(err)); } else if (ret == 0) { LOGV2_ERROR(23261, "Unexpected EOF encountered during SSL communication"); } else { LOGV2_ERROR(23262, "The SSL BIO reported an I/O error {error}", + "The SSL BIO reported an I/O error", "error"_attr = errnoWithDescription()); } break; case SSL_ERROR_SSL: { - LOGV2_ERROR(23263, "SSL: {error}", "error"_attr = getSSLErrorMessage(err)); + LOGV2_ERROR(23263, "SSL: {error}", "SSL error", "error"_attr = getSSLErrorMessage(err)); break; } diff --git a/src/mongo/util/net/ssl_manager_windows.cpp b/src/mongo/util/net/ssl_manager_windows.cpp index 499c74b97eb..ccae93b440f 100644 --- a/src/mongo/util/net/ssl_manager_windows.cpp +++ b/src/mongo/util/net/ssl_manager_windows.cpp @@ -566,9 +566,9 @@ int SSLManagerWindows::SSL_write(SSLConnectionInterface* connInterface, const vo } default: LOGV2_FATAL(23283, - "Unexpected ASIO state: {wantStateInt}", + "Unexpected ASIO state: {state}", "Unexpected ASIO state", - "wantStateInt"_attr = static_cast(want)); + "state"_attr = static_cast(want)); MONGO_UNREACHABLE; } } @@ -1821,16 +1821,30 @@ Status validatePeerCertificate(const std::string& remoteHost, msg << "The server certificate does not match the host name. Hostname: " << remoteHost << " does not match " << certificateNames.str(); + if (allowInvalidCertificates) { LOGV2_WARNING(23274, "SSL peer certificate validation failed ({errorCode}): {error}", + "SSL peer certificate validation failed", "errorCode"_attr = integerToHex(certChainPolicyStatus.dwError), "error"_attr = errnoWithDescription(certChainPolicyStatus.dwError)); - LOGV2_WARNING(23275, "{msg}", "msg"_attr = msg.ss.str()); + + LOGV2_WARNING(23275, + "The server certificate does not match the host name. Hostname: " + "{remoteHost} does not match {certificateNames}", + "The server certificate does not match the host name", + "remoteHost"_attr = remoteHost, + "certificateNames"_attr = certificateNames.str()); + *peerSubjectName = SSLX509Name(); return Status::OK(); } else if (allowInvalidHostnames) { - LOGV2_WARNING(23276, "{msg}", "msg"_attr = msg.ss.str()); + LOGV2_WARNING(23276, + "The server certificate does not match the host name. Hostname: " + "{remoteHost} does not match {certificateNames}", + "The server certificate does not match the host name", + "remoteHost"_attr = remoteHost, + "certificateNames"_attr = certificateNames.str()); return Status::OK(); } else { return Status(ErrorCodes::SSLHandshakeFailed, msg); @@ -1840,7 +1854,13 @@ Status validatePeerCertificate(const std::string& remoteHost, msg << "SSL peer certificate validation failed: (" << integerToHex(certChainPolicyStatus.dwError) << ")" << errnoWithDescription(certChainPolicyStatus.dwError); - LOGV2_ERROR(23279, "{msg}", "msg"_attr = msg.ss.str()); + + + LOGV2_ERROR(23279, + "SSL peer certificate validation failed: ({errorCode}){error}", + "SSL peer certificate validation failed", + "errorCode"_attr = integerToHex(certChainPolicyStatus.dwError), + "error"_attr = errnoWithDescription(certChainPolicyStatus.dwError)); return Status(ErrorCodes::SSLHandshakeFailed, msg); } } @@ -1904,12 +1924,16 @@ Future SSLManagerWindows::parseAndValidatePeerCertificate( if (_weakValidation) { // do not give warning if "no certificate" warnings are suppressed if (!_suppressNoCertificateWarning) { - LOGV2_WARNING(23277, "no SSL certificate provided by peer"); + LOGV2_WARNING(23277, + "no SSL certificate provided by peer", + "No SSL certificate provided by peer"); } return SSLPeerInfo(sni); } else { auto msg = "no SSL certificate provided by peer; connection rejected"; - LOGV2_ERROR(23280, "{msg}", "msg"_attr = msg); + LOGV2_ERROR(23280, + "no SSL certificate provided by peer; connection rejected", + "No SSL certificate provided by peer; connection rejected"); return Status(ErrorCodes::SSLHandshakeFailed, msg); } } -- cgit v1.2.1