From 769e90a37d2c39e1d4f9fa7f20bfe9d1c9d84bec Mon Sep 17 00:00:00 2001 From: Tor Brede Vekterli Date: Tue, 16 Jul 2019 14:41:24 +0000 Subject: Propagate peer address for TLS codec/context and print on error Buffer emitted log messages on the peer's IP address to avoid log flooding in the case of a misbehaving client that keeps sending bogus requests. --- .../net/tls/openssl_impl/openssl_impl_test.cpp | 2 +- .../src/vespa/vespalib/net/tls/crypto_codec.cpp | 6 +++-- vespalib/src/vespa/vespalib/net/tls/crypto_codec.h | 5 +++- .../net/tls/impl/openssl_crypto_codec_impl.cpp | 30 +++++++++++++++------- .../net/tls/impl/openssl_crypto_codec_impl.h | 6 ++++- .../net/tls/impl/openssl_tls_context_impl.cpp | 23 ++++++++++------- .../net/tls/impl/openssl_tls_context_impl.h | 3 ++- .../vespa/vespalib/net/tls/tls_crypto_engine.cpp | 2 +- 8 files changed, 52 insertions(+), 25 deletions(-) diff --git a/vespalib/src/tests/net/tls/openssl_impl/openssl_impl_test.cpp b/vespalib/src/tests/net/tls/openssl_impl/openssl_impl_test.cpp index 8ee10deead1..78838ce2cd2 100644 --- a/vespalib/src/tests/net/tls/openssl_impl/openssl_impl_test.cpp +++ b/vespalib/src/tests/net/tls/openssl_impl/openssl_impl_test.cpp @@ -97,7 +97,7 @@ struct Fixture { static std::unique_ptr create_openssl_codec( const std::shared_ptr& ctx, CryptoCodec::Mode mode) { auto ctx_impl = std::dynamic_pointer_cast(ctx); - return std::make_unique(std::move(ctx_impl), mode); + return std::make_unique(std::move(ctx_impl), SocketAddress(), mode); } EncodeResult do_encode(CryptoCodec& codec, Output& buffer, vespalib::stringref plaintext) { diff --git a/vespalib/src/vespa/vespalib/net/tls/crypto_codec.cpp b/vespalib/src/vespa/vespalib/net/tls/crypto_codec.cpp index 680d6472470..c54990b3782 100644 --- a/vespalib/src/vespa/vespalib/net/tls/crypto_codec.cpp +++ b/vespalib/src/vespa/vespalib/net/tls/crypto_codec.cpp @@ -6,10 +6,12 @@ namespace vespalib::net::tls { -std::unique_ptr CryptoCodec::create_default_codec(std::shared_ptr ctx, Mode mode) { +std::unique_ptr CryptoCodec::create_default_codec( + std::shared_ptr ctx, const SocketAddress& peer_address, Mode mode) +{ auto ctx_impl = std::dynamic_pointer_cast(ctx); // only takes by const ref assert(ctx_impl); - return std::make_unique(std::move(ctx_impl), mode); + return std::make_unique(std::move(ctx_impl), peer_address, mode); } } diff --git a/vespalib/src/vespa/vespalib/net/tls/crypto_codec.h b/vespalib/src/vespa/vespalib/net/tls/crypto_codec.h index fc5303dbc5b..5d9684461d7 100644 --- a/vespalib/src/vespa/vespalib/net/tls/crypto_codec.h +++ b/vespalib/src/vespa/vespalib/net/tls/crypto_codec.h @@ -1,6 +1,7 @@ // Copyright 2018 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. #pragma once +#include #include namespace vespalib::net::tls { @@ -178,7 +179,9 @@ public: * * Throws CryptoException if resources cannot be allocated for the codec. */ - static std::unique_ptr create_default_codec(std::shared_ptr ctx, Mode mode); + static std::unique_ptr create_default_codec(std::shared_ptr ctx, + const SocketAddress& peer_address, + Mode mode); }; } diff --git a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp index 3049c02b798..374c156effa 100644 --- a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp +++ b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp @@ -17,7 +17,7 @@ #include #include -#include +#include LOG_SETUP(".vespalib.net.tls.openssl_crypto_codec_impl"); #if (OPENSSL_VERSION_NUMBER < 0x10000000L) @@ -159,15 +159,23 @@ vespalib::string ssl_error_from_stack() { return vespalib::string(buf); } -void log_ssl_error(const char* source, int ssl_error) { - LOG(error, "%s returned unexpected error: %s (%s)", - source, ssl_error_to_str(ssl_error), ssl_error_from_stack().c_str()); +void log_ssl_error(const char* source, const SocketAddress& peer_address, int ssl_error) { + // Buffer the emitted log messages on the peer's IP address. This prevents a single misbehaving + // client from flooding our logs, while at the same time ensuring that logs for other clients + // aren't lost. + LOGBT(error, peer_address.ip_address(), + "%s (with peer '%s') returned unexpected error: %s (%s)", + source, peer_address.spec().c_str(), + ssl_error_to_str(ssl_error), ssl_error_from_stack().c_str()); } } // anon ns -OpenSslCryptoCodecImpl::OpenSslCryptoCodecImpl(std::shared_ptr ctx, Mode mode) +OpenSslCryptoCodecImpl::OpenSslCryptoCodecImpl(std::shared_ptr ctx, + const SocketAddress& peer_address, + Mode mode) : _ctx(std::move(ctx)), + _peer_address(peer_address), _ssl(::SSL_new(_ctx->native_context())), _mode(mode), _deferred_handshake_params(), @@ -214,6 +222,10 @@ OpenSslCryptoCodecImpl::OpenSslCryptoCodecImpl(std::shared_ptr(consumed)); } else { - log_ssl_error("SSL_do_handshake()", ssl_result); + log_ssl_error("SSL_do_handshake()", _peer_address, ssl_result); ConnectionStatistics::get(_mode == Mode::Server).inc_failed_tls_handshakes(); return handshake_failed(); } @@ -327,7 +339,7 @@ EncodeResult OpenSslCryptoCodecImpl::encode(const char* plaintext, size_t plaint // SSL_write encodes plaintext to ciphertext and writes to _output_bio const int consumed = ::SSL_write(_ssl.get(), plaintext, to_consume); if (consumed < 0) { - log_ssl_error("SSL_write()", ::SSL_get_error(_ssl.get(), consumed)); + log_ssl_error("SSL_write()", _peer_address, ::SSL_get_error(_ssl.get(), consumed)); ConnectionStatistics::get(_mode == Mode::Server).inc_broken_tls_connections(); return encode_failed(); // TODO explicitly detect and log TLS renegotiation error (SSL_ERROR_WANT_READ)? } else if (consumed != to_consume) { @@ -391,7 +403,7 @@ DecodeResult OpenSslCryptoCodecImpl::remap_ssl_read_failure_to_decode_result(int LOG(debug, "SSL_read() returned SSL_ERROR_ZERO_RETURN; connection has been shut down normally by the peer"); return decode_peer_has_closed(); default: - log_ssl_error("SSL_read()", ssl_error); + log_ssl_error("SSL_read()", _peer_address, ssl_error); ConnectionStatistics::get(_mode == Mode::Server).inc_broken_tls_connections(); return decode_failed(); } @@ -403,7 +415,7 @@ EncodeResult OpenSslCryptoCodecImpl::half_close(char* ciphertext, size_t ciphert const int pending_before = BIO_pending(_output_bio); int ssl_result = ::SSL_shutdown(_ssl.get()); if (ssl_result < 0) { - log_ssl_error("SSL_shutdown()", ::SSL_get_error(_ssl.get(), ssl_result)); + log_ssl_error("SSL_shutdown()", _peer_address, ::SSL_get_error(_ssl.get(), ssl_result)); return encode_failed(); } const int pending_after = BIO_pending(_output_bio); diff --git a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.h b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.h index ef7e0998994..14200de449a 100644 --- a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.h +++ b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.h @@ -2,6 +2,7 @@ #pragma once #include "openssl_typedefs.h" +#include #include #include #include @@ -45,6 +46,7 @@ class OpenSslCryptoCodecImpl : public CryptoCodec { // The context maintains shared verification callback state, so it must be // kept alive explictly for at least as long as any codecs. std::shared_ptr _ctx; + SocketAddress _peer_address; SslPtr _ssl; ::BIO* _input_bio; // Owned by _ssl ::BIO* _output_bio; // Owned by _ssl @@ -52,7 +54,7 @@ class OpenSslCryptoCodecImpl : public CryptoCodec { std::optional _deferred_handshake_params; std::optional _deferred_handshake_result; public: - OpenSslCryptoCodecImpl(std::shared_ptr ctx, Mode mode); + OpenSslCryptoCodecImpl(std::shared_ptr ctx, const SocketAddress& peer_address, Mode mode); ~OpenSslCryptoCodecImpl() override; /* @@ -85,6 +87,8 @@ public: DecodeResult decode(const char* ciphertext, size_t ciphertext_size, char* plaintext, size_t plaintext_size) noexcept override; EncodeResult half_close(char* ciphertext, size_t ciphertext_size) noexcept override; + + const SocketAddress& peer_address() const noexcept { return _peer_address; } private: HandshakeResult do_handshake_and_consume_peer_input_bytes() noexcept; DecodeResult drain_and_produce_plaintext_from_ssl(char* plaintext, size_t plaintext_size) noexcept; diff --git a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.cpp b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.cpp index c87dc1d2148..98675ec6b0b 100644 --- a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.cpp +++ b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.cpp @@ -2,6 +2,7 @@ #include "iana_cipher_map.h" #include "openssl_typedefs.h" #include "openssl_tls_context_impl.h" +#include "openssl_crypto_codec_impl.h" #include #include #include @@ -17,7 +18,7 @@ #include #include -#include +#include LOG_SETUP(".vespalib.net.tls.openssl_tls_context_impl"); #if (OPENSSL_VERSION_NUMBER < 0x10000000L) @@ -402,8 +403,6 @@ bool fill_certificate_subject_alternate_names(::X509* cert, PeerCredentials& cre } // anon ns -// TODO if/when we want to move per-connection peer credentials into the crypto codec/socket -// itself, we probably need to set the verification callback (data) on _SSL_, not _SSL_CTX_..! // Note: we try to be as conservative as possible. If anything looks out of place, we fail // secure by denying the connection. // @@ -426,19 +425,22 @@ int OpenSslTlsContextImpl::verify_cb_wrapper(int preverified_ok, ::X509_STORE_CT void* data = ::X509_STORE_CTX_get_ex_data(store_ctx, ::SSL_get_ex_data_X509_STORE_CTX_idx()); LOG_ASSERT(data != nullptr); auto* ssl = static_cast<::SSL*>(data); + data = SSL_get_app_data(ssl); + LOG_ASSERT(data != nullptr); + auto* codec_impl = static_cast(data); const ::SSL_CTX* ssl_ctx = ::SSL_get_SSL_CTX(ssl); LOG_ASSERT(ssl_ctx != nullptr); auto* self = static_cast(SSL_CTX_get_app_data(ssl_ctx)); LOG_ASSERT(self != nullptr); - if (self->verify_trusted_certificate(store_ctx)) { + if (self->verify_trusted_certificate(store_ctx, codec_impl->peer_address())) { return 1; } ConnectionStatistics::get(SSL_in_accept_init(ssl) != 0).inc_invalid_peer_credentials(); return 0; } -bool OpenSslTlsContextImpl::verify_trusted_certificate(::X509_STORE_CTX* store_ctx) { +bool OpenSslTlsContextImpl::verify_trusted_certificate(::X509_STORE_CTX* store_ctx, const SocketAddress& peer_address) { const auto authz_mode = authorization_mode(); // TODO consider if we want to fill in peer credentials even if authorization is disabled if (authz_mode == AuthorizationMode::Disable) { @@ -459,13 +461,16 @@ bool OpenSslTlsContextImpl::verify_trusted_certificate(::X509_STORE_CTX* store_c try { const bool verified_by_cb = _cert_verify_callback->verify(creds); if (!verified_by_cb) { - // TODO we should print the peer's remote address too, but that information is - // not currently available to us here. - LOG(warning, "Certificate verification failed for %s", to_string(creds).c_str()); + // Buffer warnings on peer IP address to avoid log flooding. + LOGBT(warning, peer_address.ip_address(), + "Certificate verification of peer '%s' failed with %s", + peer_address.spec().c_str(), to_string(creds).c_str()); return (authz_mode != AuthorizationMode::Enforce); } } catch (std::exception& e) { - LOG(error, "Got exception during certificate verification callback: %s", e.what()); + LOGBT(error, peer_address.ip_address(), + "Got exception during certificate verification callback for peer '%s': %s", + peer_address.spec().c_str(), e.what()); return false; } // we don't expect any non-std::exception derived exceptions, so let them terminate the process. return true; diff --git a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.h b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.h index 31814dad8ba..c519b1ae874 100644 --- a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.h +++ b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_tls_context_impl.h @@ -2,6 +2,7 @@ #pragma once #include "openssl_typedefs.h" +#include #include #include #include @@ -46,7 +47,7 @@ private: void set_ssl_ctx_self_reference(); void set_accepted_cipher_suites(const std::vector& ciphers); - bool verify_trusted_certificate(::X509_STORE_CTX* store_ctx); + bool verify_trusted_certificate(::X509_STORE_CTX* store_ctx, const SocketAddress& peer_address); static int verify_cb_wrapper(int preverified_ok, ::X509_STORE_CTX* store_ctx); }; diff --git a/vespalib/src/vespa/vespalib/net/tls/tls_crypto_engine.cpp b/vespalib/src/vespa/vespalib/net/tls/tls_crypto_engine.cpp index 7d0d3287965..58d99cc7108 100644 --- a/vespalib/src/vespa/vespalib/net/tls/tls_crypto_engine.cpp +++ b/vespalib/src/vespa/vespalib/net/tls/tls_crypto_engine.cpp @@ -15,7 +15,7 @@ std::unique_ptr TlsCryptoEngine::create_tls_crypto_socket(SocketHandle socket, bool is_server) { auto mode = is_server ? net::tls::CryptoCodec::Mode::Server : net::tls::CryptoCodec::Mode::Client; - auto codec = net::tls::CryptoCodec::create_default_codec(_tls_ctx, mode); + auto codec = net::tls::CryptoCodec::create_default_codec(_tls_ctx, SocketAddress::peer_address(socket.get()), mode); return std::make_unique(std::move(socket), std::move(codec)); } -- cgit v1.2.3 From 3ddc807a4961a56e27e46127b14c73a36260d4b2 Mon Sep 17 00:00:00 2001 From: Tor Brede Vekterli Date: Tue, 16 Jul 2019 14:56:25 +0000 Subject: Drop log level from error to warning Indicates a misconfigured client, but is not semantically an internal error. --- vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp index 374c156effa..5315754d53a 100644 --- a/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp +++ b/vespalib/src/vespa/vespalib/net/tls/impl/openssl_crypto_codec_impl.cpp @@ -163,7 +163,7 @@ void log_ssl_error(const char* source, const SocketAddress& peer_address, int ss // Buffer the emitted log messages on the peer's IP address. This prevents a single misbehaving // client from flooding our logs, while at the same time ensuring that logs for other clients // aren't lost. - LOGBT(error, peer_address.ip_address(), + LOGBT(warning, peer_address.ip_address(), "%s (with peer '%s') returned unexpected error: %s (%s)", source, peer_address.spec().c_str(), ssl_error_to_str(ssl_error), ssl_error_from_stack().c_str()); -- cgit v1.2.3