]> git.ipfire.org Git - thirdparty/freeradius-server.git/commitdiff
Add OpenSSL BIOs that are plumbed into our logging system
authorArran Cudbard-Bell <a.cudbardb@freeradius.org>
Mon, 7 Jun 2021 00:37:22 +0000 (19:37 -0500)
committerArran Cudbard-Bell <a.cudbardb@freeradius.org>
Thu, 10 Jun 2021 22:44:38 +0000 (17:44 -0500)
15 files changed:
src/lib/eap_aka_sim/crypto.c
src/lib/eap_aka_sim/decode.c
src/lib/eap_aka_sim/encode.c
src/lib/eap_aka_sim/id.c
src/lib/server/log.c
src/lib/server/log.h
src/lib/sim/milenage.c
src/lib/tls/base-h
src/lib/tls/base.c
src/lib/tls/ctx.c
src/lib/tls/engine.c
src/lib/tls/log.c
src/lib/tls/log.h
src/modules/rlm_cipher/rlm_cipher.c
src/modules/rlm_eap/types/rlm_eap_ttls/ttls.c

index 05f5d9f410e326c3e3cfd9ba1de469168154e197..a5dcc42ade75a147667bb6e2ca72234d229f3aac 100644 (file)
@@ -39,10 +39,11 @@ RCSID("$Id$")
 #include <freeradius-devel/sim/common.h>
 #include <freeradius-devel/sim/milenage.h>
 #include <freeradius-devel/tls/base.h>
+#include <freeradius-devel/tls/log.h>
+#include <freeradius-devel/util/atexit.h>
 #include <freeradius-devel/util/proto.h>
 #include <freeradius-devel/util/rand.h>
 #include <freeradius-devel/util/sha1.h>
-#include <freeradius-devel/util/atexit.h>
 #include <openssl/evp.h>
 
 #include "base.h"
@@ -119,13 +120,13 @@ int fr_aka_sim_crypto_init_checkcode(TALLOC_CTX *ctx, fr_aka_sim_checkcode_t **c
 
        (*checkcode)->md_ctx = EVP_MD_CTX_create();
        if (!(*checkcode)->md_ctx) {
-               tls_strerror_printf("Failed creating MD ctx");
+               fr_tls_log_strerror_printf("Failed creating MD ctx");
        error:
                TALLOC_FREE(*checkcode);
                return -1;
        }
        if (EVP_DigestInit_ex((*checkcode)->md_ctx, md, NULL) != 1) {
-               tls_strerror_printf("Failed intialising MD ctx");
+               fr_tls_log_strerror_printf("Failed intialising MD ctx");
                goto error;
        }
 
@@ -164,7 +165,7 @@ int fr_aka_sim_crypto_update_checkcode(fr_aka_sim_checkcode_t *checkcode, eap_pa
         *      Digest the header
         */
        if (EVP_DigestUpdate(checkcode->md_ctx, &eap_hdr, sizeof(eap_hdr)) != 1) {
-               tls_strerror_printf("Failed digesting EAP header");
+               fr_tls_log_strerror_printf("Failed digesting EAP header");
                return -1;
        }
 
@@ -174,7 +175,7 @@ int fr_aka_sim_crypto_update_checkcode(fr_aka_sim_checkcode_t *checkcode, eap_pa
         *      Digest the packet
         */
        if (EVP_DigestUpdate(checkcode->md_ctx, eap_packet->type.data, eap_packet->type.length) != 1) {
-               tls_strerror_printf("Failed digesting packet data");
+               fr_tls_log_strerror_printf("Failed digesting packet data");
                return -1;
        }
 
@@ -199,7 +200,7 @@ ssize_t fr_aka_sim_crypto_finalise_checkcode(TALLOC_CTX *ctx, uint8_t **out, fr_
        len = (size_t)EVP_MD_CTX_size((*checkcode).md_ctx);
        MEM(buff = talloc_array(ctx, uint8_t, len));
        if (EVP_DigestFinal_ex((*checkcode).md_ctx, buff, NULL) != 1) {
-               tls_strerror_printf("Failed finalising checkcode digest");
+               fr_tls_log_strerror_printf("Failed finalising checkcode digest");
                return -1;
        }
        *out = buff;
@@ -313,7 +314,7 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
        FR_PROTO_HEX_DUMP(key, key_len, "MAC key");
        pkey = EVP_PKEY_new_mac_key(EVP_PKEY_HMAC, NULL, key, key_len);
        if (!pkey) {
-               tls_strerror_printf("Failed creating HMAC signing key");
+               fr_tls_log_strerror_printf("Failed creating HMAC signing key");
        error:
                if (pkey) EVP_PKEY_free(pkey);
                if (md_ctx) EVP_MD_CTX_destroy(md_ctx);
@@ -322,12 +323,12 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
 
        md_ctx = EVP_MD_CTX_create();
        if (!md_ctx) {
-               tls_strerror_printf("Failed creating HMAC ctx");
+               fr_tls_log_strerror_printf("Failed creating HMAC ctx");
                goto error;
        }
 
        if (EVP_DigestSignInit(md_ctx, NULL, md, NULL, pkey) != 1) {
-               tls_strerror_printf("Failed initialising digest");
+               fr_tls_log_strerror_printf("Failed initialising digest");
                goto error;
        }
 
@@ -344,7 +345,7 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
 
        FR_PROTO_HEX_DUMP((uint8_t *)&eap_hdr, sizeof(eap_hdr), "MAC digest input (eap header)");
        if (EVP_DigestSignUpdate(md_ctx, &eap_hdr, sizeof(eap_hdr)) != 1) {
-               tls_strerror_printf("Failed digesting EAP data");
+               fr_tls_log_strerror_printf("Failed digesting EAP data");
                goto error;
        }
 
@@ -367,7 +368,7 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
                         *      AT_MAC header and reserved bytes.
                         */
                        if (EVP_DigestSignUpdate(md_ctx, p, mac - p) != 1) {
-                               tls_strerror_printf("Failed digesting packet data (before MAC)");
+                               fr_tls_log_strerror_printf("Failed digesting packet data (before MAC)");
                                goto error;
                        }
                        p += mac - p;
@@ -379,7 +380,7 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
                         *      simulated the zeroed out Mac.
                         */
                        if (EVP_DigestSignUpdate(md_ctx, zero, sizeof(zero)) != 1) {
-                               tls_strerror_printf("Failed digesting zeroed MAC");
+                               fr_tls_log_strerror_printf("Failed digesting zeroed MAC");
                                goto error;
                        }
                        p += sizeof(zero);
@@ -402,7 +403,7 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
                 *      Digest the rest of the packet.
                 */
                if (EVP_DigestSignUpdate(md_ctx, p, end - p) != 1) {
-                       tls_strerror_printf("Failed digesting packet data");
+                       fr_tls_log_strerror_printf("Failed digesting packet data");
                        goto error;
                }
        }
@@ -416,13 +417,13 @@ ssize_t fr_aka_sim_crypto_sign_packet(uint8_t out[static AKA_SIM_MAC_DIGEST_SIZE
        if (hmac_extra) {
                FR_PROTO_HEX_DUMP(hmac_extra, hmac_extra_len, "MAC digest input (extra)");
                if (EVP_DigestSignUpdate(md_ctx, hmac_extra, hmac_extra_len) != 1) {
-                       tls_strerror_printf("Failed digesting HMAC extra data");
+                       fr_tls_log_strerror_printf("Failed digesting HMAC extra data");
                        goto error;
                }
        }
 
        if (EVP_DigestSignFinal(md_ctx, digest, &digest_len) != 1) {
-               tls_strerror_printf("Failed finalising digest");
+               fr_tls_log_strerror_printf("Failed finalising digest");
                goto error;
        }
 
@@ -710,7 +711,7 @@ static int ck_ik_prime_derive(fr_aka_sim_keys_t *keys)
 
        pkey = EVP_PKEY_new_mac_key(EVP_PKEY_HMAC, NULL, k, sizeof(k));
        if (!pkey) {
-               tls_strerror_printf("Failed creating HMAC signing key");
+               fr_tls_log_strerror_printf("Failed creating HMAC signing key");
        error:
                if (pkey) EVP_PKEY_free(pkey);
                if (md_ctx) EVP_MD_CTX_destroy(md_ctx);
@@ -719,12 +720,12 @@ static int ck_ik_prime_derive(fr_aka_sim_keys_t *keys)
 
        md_ctx = EVP_MD_CTX_create();
        if (!md_ctx) {
-               tls_strerror_printf("Failed creating HMAC ctx");
+               fr_tls_log_strerror_printf("Failed creating HMAC ctx");
                goto error;
        }
 
        if (EVP_DigestSignInit(md_ctx, NULL, EVP_sha256(), NULL, pkey) != 1) {
-               tls_strerror_printf("Failed initialising digest");
+               fr_tls_log_strerror_printf("Failed initialising digest");
                goto error;
        }
 
@@ -779,7 +780,7 @@ static int aka_prime_prf(uint8_t *out, size_t outlen,
 
        pkey = EVP_PKEY_new_mac_key(EVP_PKEY_HMAC, NULL, key, key_len);
        if (!pkey) {
-               tls_strerror_printf("Failed creating HMAC signing key");
+               fr_tls_log_strerror_printf("Failed creating HMAC signing key");
        error:
                if (pkey) EVP_PKEY_free(pkey);
                if (md_ctx) EVP_MD_CTX_destroy(md_ctx);
@@ -788,12 +789,12 @@ static int aka_prime_prf(uint8_t *out, size_t outlen,
 
        md_ctx = EVP_MD_CTX_create();
        if (!md_ctx) {
-               tls_strerror_printf("Failed creating HMAC ctx");
+               fr_tls_log_strerror_printf("Failed creating HMAC ctx");
                goto error;
        }
 
        if (EVP_DigestSignInit(md_ctx, NULL, EVP_sha256(), NULL, pkey) != 1) {
-               tls_strerror_printf("Failed initialising digest");
+               fr_tls_log_strerror_printf("Failed initialising digest");
                goto error;
        }
 
@@ -1076,24 +1077,24 @@ int fr_aka_sim_crypto_kdf_0_reauth(fr_aka_sim_keys_t *keys)
         */
        md_ctx = EVP_MD_CTX_create();
        if (!md_ctx) {
-               tls_strerror_printf("Failed creating MD ctx");
+               fr_tls_log_strerror_printf("Failed creating MD ctx");
        error:
                EVP_MD_CTX_destroy(md_ctx);
                return -1;
        }
 
        if (EVP_DigestInit_ex(md_ctx, EVP_sha1(), NULL) != 1) {
-               tls_strerror_printf("Failed initialising digest");
+               fr_tls_log_strerror_printf("Failed initialising digest");
                goto error;
        }
 
        if (EVP_DigestUpdate(md_ctx, buf, p - buf) != 1) {
-               tls_strerror_printf("Failed digesting crypto data");
+               fr_tls_log_strerror_printf("Failed digesting crypto data");
                goto error;
        }
 
        if (EVP_DigestFinal_ex(md_ctx, keys->reauth.xkey_prime, &len) != 1) {
-               tls_strerror_printf("Failed finalising digest");
+               fr_tls_log_strerror_printf("Failed finalising digest");
                goto error;
        }
 
index d2a618d1ca0ce04679099a08ac19f6ce270b4532..06e5590b33d222db7106adf3b476f69d734fa151 100644 (file)
 
 RCSID("$Id$")
 
-#include <freeradius-devel/util/base.h>
-#include <freeradius-devel/util/sha1.h>
-#include <freeradius-devel/util/debug.h>
+#include <freeradius-devel/io/test_point.h>
 #include <freeradius-devel/server/module.h>
 #include <freeradius-devel/tls/base.h>
-#include <freeradius-devel/io/test_point.h>
+#include <freeradius-devel/tls/log.h>
+#include <freeradius-devel/util/base.h>
+#include <freeradius-devel/util/debug.h>
+#include <freeradius-devel/util/sha1.h>
 
 #include <freeradius-devel/eap/types.h>
 #include "attrs.h"
@@ -181,7 +182,7 @@ static ssize_t sim_value_decrypt(TALLOC_CTX *ctx, uint8_t **out,
 
        evp_ctx = aka_sim_crypto_cipher_ctx();
        if (!EVP_DecryptInit_ex(evp_ctx, evp_cipher, NULL, packet_ctx->k_encr, packet_ctx->iv)) {
-               tls_strerror_printf("%s: Failed setting decryption parameters", __FUNCTION__);
+               fr_tls_log_strerror_printf("%s: Failed setting decryption parameters", __FUNCTION__);
        error:
                talloc_free(decr);
                return -1;
@@ -200,13 +201,13 @@ static ssize_t sim_value_decrypt(TALLOC_CTX *ctx, uint8_t **out,
         */
        EVP_CIPHER_CTX_set_padding(evp_ctx, 0);
        if (!EVP_DecryptUpdate(evp_ctx, decr, (int *)&len, data, attr_len)) {
-               tls_strerror_printf("%s: Failed decrypting attribute", __FUNCTION__);
+               fr_tls_log_strerror_printf("%s: Failed decrypting attribute", __FUNCTION__);
                goto error;
        }
        decr_len = len;
 
        if (!EVP_DecryptFinal_ex(evp_ctx, decr + decr_len, (int *)&len)) {
-               tls_strerror_printf("%s: Failed decrypting attribute", __FUNCTION__);
+               fr_tls_log_strerror_printf("%s: Failed decrypting attribute", __FUNCTION__);
                goto error;
        }
        decr_len += len;
index c86655141f5c9acf8323b3d60ec532a8c62b4491..3ac1c42295a5d3008d09fc5f9df3c1c08568df55 100644 (file)
 
 RCSID("$Id$")
 
-#include <freeradius-devel/util/dbuff.h>
-#include <freeradius-devel/util/base.h>
-#include <freeradius-devel/util/sha1.h>
-#include <freeradius-devel/util/debug.h>
+#include <freeradius-devel/io/test_point.h>
 #include <freeradius-devel/server/module.h>
 #include <freeradius-devel/tls/base.h>
-#include <freeradius-devel/io/test_point.h>
+#include <freeradius-devel/tls/log.h>
+#include <freeradius-devel/util/base.h>
+#include <freeradius-devel/util/dbuff.h>
+#include <freeradius-devel/util/debug.h>
+#include <freeradius-devel/util/sha1.h>
 
 #include <freeradius-devel/eap/types.h>
 #include "base.h"
@@ -200,7 +201,7 @@ static ssize_t encode_encrypted_value(fr_dbuff_t *dbuff,
        evp_ctx = aka_sim_crypto_cipher_ctx();
        if (unlikely(EVP_EncryptInit_ex(evp_ctx, evp_cipher, NULL,
                                        packet_ctx->k_encr, packet_ctx->iv) != 1)) {
-               tls_strerror_printf("Failed initialising AES-128-ECB context");
+               fr_tls_log_strerror_printf("Failed initialising AES-128-ECB context");
        error:
                talloc_free(encr);
                return PAIR_ENCODE_FATAL_ERROR;
@@ -225,13 +226,13 @@ static ssize_t encode_encrypted_value(fr_dbuff_t *dbuff,
         */
        EVP_CIPHER_CTX_set_padding(evp_ctx, 0);
        if (unlikely(EVP_EncryptUpdate(evp_ctx, encr, (int *)&len, fr_dbuff_start(&work_dbuff), total_len) != 1)) {
-               tls_strerror_printf("%s: Failed encrypting attribute", __FUNCTION__);
+               fr_tls_log_strerror_printf("%s: Failed encrypting attribute", __FUNCTION__);
                goto error;
        }
        encr_len = len;
 
        if (unlikely(EVP_EncryptFinal_ex(evp_ctx, encr + encr_len, (int *)&len) != 1)) {
-               tls_strerror_printf("%s: Failed finalising encrypted attribute", __FUNCTION__);
+               fr_tls_log_strerror_printf("%s: Failed finalising encrypted attribute", __FUNCTION__);
                goto error;
        }
        encr_len += len;
index 51bb2b6828daa8e5f21e1962f95f52dea0928a40..25875fa22e14fc868d56e23144f17213ecc9f8b9 100644 (file)
@@ -469,7 +469,7 @@ int fr_aka_sim_id_3gpp_pseudonym_encrypt(char out[AKA_SIM_3GPP_PSEUDONYM_LEN + 1
         */
        evp_ctx = aka_sim_crypto_cipher_ctx();
        if (unlikely(EVP_EncryptInit_ex(evp_ctx, EVP_aes_128_ecb(), NULL, key, NULL) != 1)) {
-               tls_strerror_printf("Failed initialising AES-128-ECB context");
+               fr_tls_log_strerror_printf("Failed initialising AES-128-ECB context");
        error:
                return -1;
        }
@@ -486,13 +486,13 @@ int fr_aka_sim_id_3gpp_pseudonym_encrypt(char out[AKA_SIM_3GPP_PSEUDONYM_LEN + 1
         */
        EVP_CIPHER_CTX_set_padding(evp_ctx, 0);
        if (unlikely(EVP_EncryptUpdate(evp_ctx, encr, (int *)&len, padded, sizeof(padded)) != 1)) {
-               tls_strerror_printf("Failed encrypting padded IMSI");
+               fr_tls_log_strerror_printf("Failed encrypting padded IMSI");
                goto error;
        }
        encr_len = len;
 
        if (unlikely(EVP_EncryptFinal_ex(evp_ctx, encr + len, (int *)&len) != 1)) {
-               tls_strerror_printf("Failed finalising encrypted IMSI");
+               fr_tls_log_strerror_printf("Failed finalising encrypted IMSI");
                goto error;
        }
        encr_len += len;
@@ -612,7 +612,7 @@ int fr_aka_sim_id_3gpp_pseudonym_decrypt(char out[AKA_SIM_IMSI_MAX_LEN + 1],
 
        evp_ctx = aka_sim_crypto_cipher_ctx();
        if (unlikely(EVP_DecryptInit_ex(evp_ctx, EVP_aes_128_ecb(), NULL, key, NULL) != 1)) {
-               tls_strerror_printf("Failed initialising AES-128-ECB context");
+               fr_tls_log_strerror_printf("Failed initialising AES-128-ECB context");
        error:
                return -1;
        }
@@ -628,13 +628,13 @@ int fr_aka_sim_id_3gpp_pseudonym_decrypt(char out[AKA_SIM_IMSI_MAX_LEN + 1],
         */
        EVP_CIPHER_CTX_set_padding(evp_ctx, 0);
        if (unlikely(EVP_DecryptUpdate(evp_ctx, decr, (int *)&len, dec, sizeof(dec)) != 1)) {
-               tls_strerror_printf("Failed decypting IMSI");
+               fr_tls_log_strerror_printf("Failed decypting IMSI");
                goto error;
        }
        decr_len = len;
 
        if (unlikely(EVP_DecryptFinal_ex(evp_ctx, decr + len, (int *)&len) != 1)) {
-               tls_strerror_printf("Failed finalising decypted IMSI");
+               fr_tls_log_strerror_printf("Failed finalising decypted IMSI");
                goto error;
        }
        decr_len += len;
index d9485591bafb040fa694f601b752b535e4b2417e..b32c1027af916bab5884d6b7aa5abc3610f72546 100644 (file)
@@ -60,7 +60,7 @@ fr_table_num_sorted_t const syslog_facility_table[] = {
 #endif
 
 #ifdef LOG_AUTHPRIV
-       { L("authpriv"),                LOG_AUTHPRIV    },
+       { L("authpriv"),        LOG_AUTHPRIV    },
 #endif
 
 #ifdef LOG_CRON
index d11e6ed822aaa99f88ce81be39d11d1c57b619c1..1496cfced8d5dba6137e0a6d74c9bdb7a10447a8 100644 (file)
@@ -81,6 +81,13 @@ typedef struct {
        char const      *prefix;        //!< To add to log messages.
 } log_fd_event_ctx_t;
 
+/** Function signature for log_request functions
+ *
+ */
+typedef void (*log_request_func_t)(fr_log_type_t type, fr_log_lvl_t lvl, request_t *request,
+                                  char const *file, int line,
+                                  char const *fmt, ...);
+
 extern fr_table_num_sorted_t const syslog_facility_table[];
 extern size_t syslog_facility_table_len;
 extern fr_table_num_sorted_t const syslog_severity_table[];
index a2d15015754dba427b7b37bb93730a1dd25a5df3..d7c07a38985f205142cffc3ac7f1e250186bb518 100644 (file)
@@ -35,7 +35,7 @@ static inline int aes_128_encrypt_block(EVP_CIPHER_CTX *evp_ctx,
        size_t len;
 
        if (unlikely(EVP_EncryptInit_ex(evp_ctx, EVP_aes_128_ecb(), NULL, key, NULL) != 1)) {
-               tls_strerror_printf("Failed initialising AES-128-ECB context");
+               fr_tls_log_strerror_printf("Failed initialising AES-128-ECB context");
                return -1;
        }
 
@@ -52,7 +52,7 @@ static inline int aes_128_encrypt_block(EVP_CIPHER_CTX *evp_ctx,
        EVP_CIPHER_CTX_set_padding(evp_ctx, 0);
        if (unlikely(EVP_EncryptUpdate(evp_ctx, out, (int *)&len, in, 16) != 1) ||
            unlikely(EVP_EncryptFinal_ex(evp_ctx, out + len, (int *)&len) != 1)) {
-               tls_strerror_printf("Failed encrypting data");
+               fr_tls_log_strerror_printf("Failed encrypting data");
                return -1;
        }
 
@@ -89,7 +89,7 @@ static int milenage_f1(uint8_t mac_a[MILENAGE_MAC_A_SIZE],
 
        evp_ctx = EVP_CIPHER_CTX_new();
        if (!evp_ctx) {
-               tls_strerror_printf("Failed allocating EVP context");
+               fr_tls_log_strerror_printf("Failed allocating EVP context");
                return -1;
        }
 
@@ -164,7 +164,7 @@ static int milenage_f2345(uint8_t res[MILENAGE_RES_SIZE],
 
        evp_ctx = EVP_CIPHER_CTX_new();
        if (!evp_ctx) {
-               tls_strerror_printf("Failed allocating EVP context");
+               fr_tls_log_strerror_printf("Failed allocating EVP context");
                return -1;
        }
 
@@ -249,7 +249,7 @@ int milenage_opc_generate(uint8_t opc[MILENAGE_OPC_SIZE],
 
        evp_ctx = EVP_CIPHER_CTX_new();
        if (!evp_ctx) {
-               tls_strerror_printf("Failed allocating EVP context");
+               fr_tls_log_strerror_printf("Failed allocating EVP context");
                return -1;
        }
        ret = aes_128_encrypt_block(evp_ctx, ki, op, tmp);
index 412848300f02db02d69bf35a3ab4dd85803d5764..a8ca738632bec5251c38b6aae45fef78e55155cb 100644 (file)
@@ -51,8 +51,6 @@ RCSIDH(tls_h, "$Id$")
 #include <openssl/ssl.h>
 #include <openssl/err.h>
 
-#include "log.h"
-
 #ifdef __cplusplus
 extern "C" {
 #endif
index 6acfdc66a922f2db627ac70214d3ecef8496503d..ed15e6c637c2c29fa49c11db94eacc8bd69d66ad 100644 (file)
@@ -38,6 +38,8 @@ USES_APPLE_DEPRECATED_API     /* OpenSSL API has been deprecated by Apple */
 #include <freeradius-devel/tls/engine.h>
 #include <freeradius-devel/util/debug.h>
 
+#include "log.h"
+
 static uint32_t instance_count = 0;
 
 /** The context which holds any memory OpenSSL allocates
@@ -482,6 +484,8 @@ void fr_openssl_free(void)
        TALLOC_FREE(global_mutexes);
 
        fr_dict_autofree(tls_dict);
+
+       fr_tls_log_free();
 }
 #else
 /** Free any memory alloced by libssl
@@ -500,6 +504,8 @@ void fr_openssl_free(void)
        OPENSSL_cleanup();
 
        fr_dict_autofree(tls_dict);
+
+       fr_tls_log_free();
 }
 #endif
 
@@ -558,6 +564,8 @@ int fr_openssl_init(void)
         */
        fr_tls_engine_load_builtin();
 
+       fr_tls_log_init();
+
        instance_count++;
 
        return 0;
index 578bd8d8f4f5285390b164af89ee0e101614328f..2a6b9f16bce06ad6116c9bbd4b59781c96751025 100644 (file)
@@ -30,8 +30,9 @@ USES_APPLE_DEPRECATED_API     /* OpenSSL API has been deprecated by Apple */
 #ifdef WITH_TLS
 #define LOG_PREFIX "tls - "
 
-#include <freeradius-devel/util/debug.h>
+#include <freeradius-devel/tls/log.h>
 #include <freeradius-devel/util/base16.h>
+#include <freeradius-devel/util/debug.h>
 #include <freeradius-devel/util/misc.h>
 #include <freeradius-devel/util/syserror.h>
 
@@ -40,6 +41,7 @@ USES_APPLE_DEPRECATED_API     /* OpenSSL API has been deprecated by Apple */
 
 #include "base.h"
 #include "missing.h"
+#include "log.h"
 
 #ifndef OPENSSL_NO_ECDH
 static int ctx_ecdh_curve_set(SSL_CTX *ctx, char const *ecdh_curve, bool disable_single_dh_use)
@@ -247,14 +249,14 @@ static int tls_ctx_load_cert_chain(SSL_CTX *ctx, fr_tls_chain_conf_t const *chai
                 */
                case FR_TLS_CHAIN_VERIFY_SOFT:
                        if (!SSL_CTX_build_cert_chain(ctx, mode)) {
-                               tls_strerror_printf(NULL);
+                               fr_tls_log_strerror_printf(NULL);
                                PWARN("Failed verifying chain");
                        }
                        break;
 
                case FR_TLS_CHAIN_VERIFY_HARD:
                        if (!SSL_CTX_build_cert_chain(ctx, mode)) {
-                               tls_strerror_printf(NULL);
+                               fr_tls_log_strerror_printf(NULL);
                                PERROR("Failed verifying chain");
                                return -1;
                        }
index 1f25f57717ee1d1e2620f7ed1359bf9134678cec..709890d3edca1dd5520d4a75f61a05814b6ac370 100644 (file)
@@ -335,13 +335,13 @@ int fr_tls_engine_init(ENGINE **e_out,
                 *      success or 0 on error.
                 */
                if (ret != 1) {
-                       tls_strerror_printf("control %s failed (%i)", ctrl->name, ret);
+                       fr_tls_log_strerror_printf("control %s failed (%i)", ctrl->name, ret);
                        goto error;
                }
        }
 
        if (unlikely(ENGINE_init(e) != 1)) {
-               tls_strerror_printf("failed initialising engine %s", id);
+               fr_tls_log_strerror_printf("failed initialising engine %s", id);
                goto error;
        }
 
index a3f9416be57d580521193158fd07a460d6b62896..59e1fed1ae6643a67d86e95c280e509af1762a8f 100644 (file)
@@ -18,9 +18,9 @@
  * $Id$
  *
  * @file tls/log.c
- * @brief Retrieve errors and log messages from OpenSSL's overly complex log system.
+ * @brief Retrieve errors and log messages from OpenSSL's overly complex logging system.
  *
- * @copyright 2016 Arran Cudbard-Bell (a.cudbardb@freeradius.org)
+ * @copyright 2016,2021 Arran Cudbard-Bell (a.cudbardb@freeradius.org)
  * @copyright 2016 The FreeRADIUS server project
  */
 RCSID("$Id$")
@@ -32,9 +32,89 @@ USES_APPLE_DEPRECATED_API    /* OpenSSL API has been deprecated by Apple */
 #include <freeradius-devel/server/base.h>
 #include <freeradius-devel/util/debug.h>
 
-#include "base.h"
+#include "log.h"
 #include "missing.h"
 
+/** Holds the state of a log BIO
+ *
+ * Most of these fields are expected to change between uses of the BIO.
+ *
+ * BIOs do not have indexed extension structures like other structures in OpenSSL,
+ * so we're forced to place all information in a structure, and populate it just
+ * prior to a BIO being used.
+ *
+ * These BIOs are thread local to avoid conflicts or locking issues.
+ */
+typedef struct {
+       BIO                     *bio;           //!< Logging bio to write to.
+       fr_sbuff_t              sbuff;          //!< Used to aggregate line data.
+       fr_sbuff_uctx_talloc_t  tctx;           //!< extra talloc information for the sbuff.
+       fr_sbuff_marker_t       logged_m;       //!< How much data has been written.
+
+       request_t               *request;       //!< the current request.  Only used for the
+                                               ///< request log BIOs.
+       fr_log_type_t           type;           //!< The type of log messages the bio will produce.
+       fr_log_lvl_t            lvl;            //!< Level to log message at.
+       char const              *file;          //!< File this log bio was bound on.
+       int                     *line;          //!< Line this log bio was bound on.
+} fr_tls_log_bio_t;
+
+/** Template for the thread local request log BIOs
+ */
+static BIO_METHOD      *tls_request_log_meth;
+
+/** Template for the global log BIOs
+ */
+static BIO_METHOD      *tls_global_log_meth;
+
+/** Thread local request log BIO
+ */
+static _Thread_local   fr_tls_log_bio_t        *request_log_bio;
+
+/** Thread local global log BIO
+ */
+static _Thread_local   fr_tls_log_bio_t        *global_log_bio;
+
+static void _tls_ctx_print_cert_line(char const *file, int line,
+                                    request_t *request, int index, X509 *cert)
+{
+       char            subject[1024];
+
+       X509_NAME_oneline(X509_get_subject_name(cert), subject, sizeof(subject));
+       subject[sizeof(subject) - 1] = '\0';
+
+       if (request) {
+               log_request(L_DBG, fr_debug_lvl, request, file, line,
+                           "[%i] %s %s", index, fr_tls_utils_x509_pkey_type(cert), subject);
+       } else {
+               fr_log(LOG_DST, fr_debug_lvl, file, line,
+                      "[%i] %s %s", index, fr_tls_utils_x509_pkey_type(cert), subject);
+       }
+}
+
+DIAG_OFF(DIAG_UNKNOWN_PRAGMAS)
+DIAG_OFF(used-but-marked-unused)       /* fix spurious warnings for sk macros */
+/** Print out the current stack of certs
+ *
+ * @param[in] file     File where this function is being called.
+ * @param[in] line     Line where this function is being called.
+ * @param[in] request  Current request, may be NULL.
+ * @param[in] chain    The certificate chain.
+ * @param[in] cert     The leaf certificate.
+ */
+void _fr_tls_log_certificate_chain(char const *file, int line,
+                               request_t *request, STACK_OF(X509) *chain, X509 *cert)
+{
+       int i;
+
+       for (i = sk_X509_num(chain); i > 0 ; i--) {
+               _tls_ctx_print_cert_line(file, line, request, i, sk_X509_value(chain, i - 1));
+       }
+       _tls_ctx_print_cert_line(file, line, request, i, cert);
+}
+DIAG_ON(used-but-marked-unused)
+DIAG_ON(DIAG_UNKNOWN_PRAGMAS)
+
 DIAG_OFF(format-nonliteral)
 /** Print errors in the TLS thread local error stack
  *
@@ -119,6 +199,87 @@ static int fr_tls_log_error_va(request_t *request, char const *msg, va_list ap)
 }
 DIAG_ON(format-nonliteral)
 
+/** Print errors raised by OpenSSL I/O functions
+ *
+ * Drains the thread local OpenSSL error queue, and prints out errors
+ * based on the SSL handle and the return code of the I/O  function.
+ *
+ * OpenSSL lists I/O functions to be:
+ *   - SSL_connect
+ *   - SSL_accept
+ *   - SSL_do_handshake
+ *   - SSL_read
+ *   - SSL_peek
+ *   - SSL_write
+ *
+ * @param request      The current request (may be NULL).
+ * @param session      The current tls_session.
+ * @param ret          from the I/O operation.
+ * @param msg          Error message describing the operation being attempted.
+ * @param ...          Arguments for msg.
+ * @return
+ *     - 0 TLS session may still be viable.
+ *     - -1 TLS session cannot continue.
+ */
+int fr_tls_log_io_error(request_t *request, fr_tls_session_t *session, int ret, char const *msg, ...)
+{
+       int     error;
+       va_list ap;
+
+       if (ERR_peek_error()) {
+               va_start(ap, msg);
+               fr_tls_log_error_va(request, msg, ap);
+               va_end(ap);
+       }
+
+       error = SSL_get_error(session->ssl, ret);
+       switch (error) {
+       /*
+        *      These seem to be harmless and already "dealt
+        *      with" by our non-blocking environment. NB:
+        *      "ZERO_RETURN" is the clean "error"
+        *      indicating a successfully closed SSL
+        *      tunnel. We let this happen because our IO
+        *      loop should not appear to have broken on
+        *      this condition - and outside the IO loop, the
+        *      "shutdown" state is checked.
+        *
+        *      Don't print anything if we ignore the error.
+        */
+       case SSL_ERROR_NONE:
+       case SSL_ERROR_WANT_READ:
+       case SSL_ERROR_WANT_WRITE:
+       case SSL_ERROR_WANT_X509_LOOKUP:
+       case SSL_ERROR_ZERO_RETURN:
+               break;
+
+       /*
+        *      These seem to be indications of a genuine
+        *      error that should result in the SSL tunnel
+        *      being regarded as "dead".
+        */
+       case SSL_ERROR_SYSCALL:
+               ROPTIONAL(REDEBUG, ERROR, "System call (I/O) error (%i)", ret);
+               return -1;
+
+       case SSL_ERROR_SSL:
+               ROPTIONAL(REDEBUG, ERROR, "TLS protocol error (%i)", ret);
+               return -1;
+
+       /*
+        *      For any other errors that (a) exist, and (b)
+        *      crop up - we need to interpret what to do with
+        *      them - so "politely inform" the caller that
+        *      the code needs updating here.
+        */
+       default:
+               ROPTIONAL(REDEBUG, ERROR, "TLS session error %i (%i)", error, ret);
+               return -1;
+       }
+
+       return 0;
+}
+
 /** Print errors in the TLS thread local error stack
  *
  * Drains the thread local OpenSSL error queue, and prints out errors.
@@ -140,14 +301,6 @@ int fr_tls_log_error(request_t *request, char const *msg, ...)
        return ret;
 }
 
-/** Clear errors in the TLS thread local error stack
- *
- */
-void tls_log_clear(void)
-{
-       while (ERR_get_error() != 0);
-}
-
 DIAG_OFF(format-nonliteral)
 /** Print errors in the TLS thread local error stack
  *
@@ -225,7 +378,7 @@ DIAG_ON(format-nonliteral)
  * @param[in] ...      Arguments for msg.
  * @return the number of errors drained from the stack.
  */
-int tls_strerror_printf(char const *msg, ...)
+int fr_tls_log_strerror_printf(char const *msg, ...)
 {
        va_list ap;
        int ret;
@@ -237,124 +390,304 @@ int tls_strerror_printf(char const *msg, ...)
        return ret;
 }
 
-static void _tls_ctx_print_cert_line(char const *file, int line,
-                                    request_t *request, int index, X509 *cert)
+/** Clear errors in the TLS thread local error stack
+ *
+ */
+void tls_log_clear(void)
 {
-       char            subject[1024];
+       while (ERR_get_error() != 0);
+}
 
-       X509_NAME_oneline(X509_get_subject_name(cert), subject, sizeof(subject));
-       subject[sizeof(subject) - 1] = '\0';
+/** Converts BIO_write() calls to request log calls
+ *
+ * This callback is used to glue the output of OpenSSL functions into request log calls.
+ *
+ * @param[in] bio      that was written to.
+ * @param[in] in       data being written to BIO.
+ * @param[in] len      Length of data being written.
+ */
+static int tls_log_request_bio_write_cb(BIO *bio, char const *in, int len)
+{
+       fr_tls_log_bio_t        *lb = talloc_get_type_abort(BIO_get_data(bio), fr_tls_log_bio_t);
+       request_t               *request = talloc_get_type_abort(lb->request, request_t);
+       log_request_func_t      func;
+       char                    *le;
 
-       if (request) {
-               log_request(L_DBG, fr_debug_lvl, request, file, line,
-                           "[%i] %s %s", index, fr_tls_utils_x509_pkey_type(cert), subject);
+       /*
+        *      Pick the right logging function based on the type
+        */
+       if ((lb->type == L_ERR) || (lb->type == L_DBG_ERR) || (lb->type == L_DBG_ERR_REQ)) {
+               func = log_request_error;
        } else {
-               fr_log(LOG_DST, fr_debug_lvl, file, line,
-                      "[%i] %s %s", index, fr_tls_utils_x509_pkey_type(cert), subject);
+               func = log_request;
+       }
+
+       /*
+        *      OpenSSL feeds us data in fragments so we need
+        *      to aggregate it, then look for new line chars
+        *      as an indication we need to print the line.
+        */
+       fr_sbuff_in_bstrncpy(&lb->sbuff, in, len);
+
+       /*
+        *      Split incoming data on new lines or nul bytes.
+        */
+       while (fr_sbuff_behind(&lb->logged_m)) {
+               le = memchr(fr_sbuff_current(&lb->logged_m), '\n',
+                           fr_sbuff_current(&lb->sbuff) - fr_sbuff_current(&lb->logged_m));
+               /*
+                *      Wait until we have a complete line
+                */
+               if (le == NULL) break;
+
+               /*
+                *      Skip empty lines
+                */
+               if ((le - fr_sbuff_current(&lb->logged_m)) > 0) {
+                       func(lb->type, lb->lvl, request, __FILE__, __LINE__, "%pV",
+                            fr_box_strvalue_len(fr_sbuff_current(&lb->logged_m),
+                                                le - fr_sbuff_current(&lb->logged_m)));
+               }
+
+               fr_sbuff_set(&lb->logged_m, le + 1);
        }
+
+       /*
+        *      Clear out printed data
+        */
+       fr_sbuff_shift(&lb->sbuff, fr_sbuff_used(&lb->logged_m));
+
+       return len;     /* Amount of data written */
 }
 
-DIAG_OFF(DIAG_UNKNOWN_PRAGMAS)
-DIAG_OFF(used-but-marked-unused)       /* fix spurious warnings for sk macros */
-/** Print out the current stack of certs
+/** Converts BIO_puts() calls to request log calls
  *
- * @param[in] file     File where this function is being called.
- * @param[in] line     Line where this function is being called.
- * @param[in] request  Current request, may be NULL.
- * @param[in] chain    The certificate chain.
- * @param[in] cert     The leaf certificate.
+ * This callback is used to glue the output of OpenSSL functions into request log calls.
+ *
+ * @param[in] bio      that was written to.
+ * @param[in] in       data being written to BIO.
  */
-void _fr_tls_log_certificate_chain(char const *file, int line,
-                               request_t *request, STACK_OF(X509) *chain, X509 *cert)
+static int tls_log_request_bio_puts_cb(BIO *bio, char const *in)
 {
-       int i;
-
-       for (i = sk_X509_num(chain); i > 0 ; i--) {
-               _tls_ctx_print_cert_line(file, line, request, i, sk_X509_value(chain, i - 1));
-       }
-       _tls_ctx_print_cert_line(file, line, request, i, cert);
+       return tls_log_request_bio_write_cb(bio, in, strlen(in));
 }
-DIAG_ON(used-but-marked-unused)
-DIAG_ON(DIAG_UNKNOWN_PRAGMAS)
 
-/** Print errors raised by OpenSSL I/O functions
+/** Converts BIO_write() calls to global log calls
  *
- * Drains the thread local OpenSSL error queue, and prints out errors
- * based on the SSL handle and the return code of the I/O  function.
- *
- * OpenSSL lists I/O functions to be:
- *   - SSL_connect
- *   - SSL_accept
- *   - SSL_do_handshake
- *   - SSL_read
- *   - SSL_peek
- *   - SSL_write
+ * This callback is used to glue the output of OpenSSL functions into global log calls.
  *
- * @param request      The current request (may be NULL).
- * @param session      The current tls_session.
- * @param ret          from the I/O operation.
- * @param msg          Error message describing the operation being attempted.
- * @param ...          Arguments for msg.
- * @return
- *     - 0 TLS session may still be viable.
- *     - -1 TLS session cannot continue.
+ * @param[in] bio      that was written to.
+ * @param[in] in       data being written to BIO.
+ * @param[in] len      Length of data being written.
  */
-int fr_tls_log_io_error(request_t *request, fr_tls_session_t *session, int ret, char const *msg, ...)
+static int tls_log_global_bio_write_cb(BIO *bio, char const *in, int len)
 {
-       int     error;
-       va_list ap;
+       fr_tls_log_bio_t        *lb = talloc_get_type_abort(BIO_get_data(bio), fr_tls_log_bio_t);
+       char                    *le;
 
-       if (ERR_peek_error()) {
-               va_start(ap, msg);
-               fr_tls_log_error_va(request, msg, ap);
-               va_end(ap);
-       }
+       /*
+        *      OpenSSL feeds us data in fragments so we need
+        *      to aggregate it, then look for new line chars
+        *      as an indication we need to print the line.
+        */
+       fr_sbuff_in_bstrncpy(&lb->sbuff, in, len);
 
-       error = SSL_get_error(session->ssl, ret);
-       switch (error) {
        /*
-        *      These seem to be harmless and already "dealt
-        *      with" by our non-blocking environment. NB:
-        *      "ZERO_RETURN" is the clean "error"
-        *      indicating a successfully closed SSL
-        *      tunnel. We let this happen because our IO
-        *      loop should not appear to have broken on
-        *      this condition - and outside the IO loop, the
-        *      "shutdown" state is checked.
-        *
-        *      Don't print anything if we ignore the error.
+        *      Split incoming data on new lines or nul bytes.
         */
-       case SSL_ERROR_NONE:
-       case SSL_ERROR_WANT_READ:
-       case SSL_ERROR_WANT_WRITE:
-       case SSL_ERROR_WANT_X509_LOOKUP:
-       case SSL_ERROR_ZERO_RETURN:
-               break;
+       while (fr_sbuff_behind(&lb->logged_m)) {
+               le = memchr(fr_sbuff_current(&lb->logged_m), '\n',
+                           fr_sbuff_current(&lb->sbuff) - fr_sbuff_current(&lb->logged_m));
+               /*
+                *      Wait until we have a complete line
+                */
+               if (le == NULL) break;
+
+               /*
+                *      Skip empty lines
+                */
+               if ((le - fr_sbuff_current(&lb->logged_m)) > 0) {
+                       if (fr_debug_lvl >= lb->lvl) fr_log(lb->type, lb->lvl, __FILE__, __LINE__,
+                                                           "%pV",
+                                                           fr_box_strvalue_len(fr_sbuff_current(&lb->logged_m),
+                                                                               le - fr_sbuff_current(&lb->logged_m)));
+               }
+
+               fr_sbuff_set(&lb->logged_m, le + 1);
+       }
 
        /*
-        *      These seem to be indications of a genuine
-        *      error that should result in the SSL tunnel
-        *      being regarded as "dead".
+        *      Clear out printed data
         */
-       case SSL_ERROR_SYSCALL:
-               ROPTIONAL(REDEBUG, ERROR, "System call (I/O) error (%i)", ret);
-               return -1;
+       fr_sbuff_shift(&lb->sbuff, fr_sbuff_used(&lb->logged_m));
 
-       case SSL_ERROR_SSL:
-               ROPTIONAL(REDEBUG, ERROR, "TLS protocol error (%i)", ret);
-               return -1;
+       return len;     /* Amount of data written */
+}
+
+/** Converts BIO_puts() calls to global log calls
+ *
+ * This callback is used to glue the output of OpenSSL functions into global log calls.
+ *
+ * @param[in] bio      that was written to.
+ * @param[in] in       data being written to BIO.
+ */
+static int tls_log_global_bio_puts_cb(BIO *bio, char const *in)
+{
+       return tls_log_global_bio_write_cb(bio, in, strlen(in));
+}
+
+/** Frees a logging bio and its underlying OpenSSL BIO *
+ *
+ */
+static void _fr_tls_log_bio_free(void *log_bio)
+{
+       fr_tls_log_bio_t        *our_log_bio = talloc_get_type_abort(log_bio, fr_tls_log_bio_t);
 
+       BIO_free(our_log_bio->bio);
+       our_log_bio->bio = NULL;
+       talloc_free(our_log_bio);
+}
+
+/** Return a request log BIO to use with OpenSSL logging functions
+ *
+ * @note The contents of the BIO will only be written to the logging system on finding
+ *       a new line.  If data remains in the BIO when it is re-initialised (this function
+ *       is called again), that data will be discarded.
+ *
+ * @note The returned BIO should be assumed to be invalid if the request yields.
+ *
+ * @param[in] file     of caller.
+ * @Parma[in] line     of caller.
+ * @param[in] request  to temporarily associate with logging BIO.
+ * @param[in] type     to temporarily assign to logging bio.
+ * @param[in] lvl      to temporarily assign to logging bio.
+ * @return A thread local BIO to pass to OpenSSL logging functions.
+ */
+BIO *_fr_tls_request_log_bio(char const *file, int line, request_t *request, fr_log_type_t type, fr_log_lvl_t lvl)
+{
+       if (unlikely(!request_log_bio)) {
+               fr_tls_log_bio_t        *lb;
+
+               MEM(lb = talloc(NULL, fr_tls_log_bio_t));
+               *lb = (fr_tls_log_bio_t) {
+                       .bio = BIO_new(tls_request_log_meth),
+                       .request = request,
+                       .type = type,
+                       .lvl = lvl,
+                       .file = file,
+                       .line = line
+               };
+               MEM(lb->bio);
+               BIO_set_data(lb->bio, lb);      /* So we can retrieve the fr_tls_lb_t in the callbacks */
+               fr_sbuff_init_talloc(lb, &lb->sbuff, &lb->tctx, 1024, 10 * 1024);       /* start 1k, max 10k */
+               fr_atexit_thread_local(request_log_bio, _fr_tls_log_bio_free, lb);
+               fr_sbuff_marker(&lb->logged_m, &lb->sbuff);
+               return lb->bio;
+       }
+
+       fr_sbuff_set(&request_log_bio->logged_m, fr_sbuff_start(&request_log_bio->sbuff));
+       fr_sbuff_reset_talloc(&request_log_bio->sbuff); /* Reset to initial size */
+       request_log_bio->request = request;
+       request_log_bio->type = type;
+       request_log_bio->lvl = lvl;
+       request_log_bio->file = file;
+       request_log_bio->line = line;
+
+       return request_log_bio->bio;
+}
+
+/** Return a global log BIO to use with OpenSSL logging functions
+ *
+ * @note The contents of the BIO will only be written to the logging system on finding
+ *       a new line.  If data remains in the BIO when it is re-initialised (this function
+ *       is called again), that data will be discarded.
+ *
+ * @note The returned BIO should be assumed to be invalid if the current request yields.
+ *
+ * @param[in] file     of caller.
+ * @Parma[in] line     of caller.
+ * @param[in] type     to temporarily assign to logging bio.
+ * @param[in] lvl      to temporarily assign to logging bio.
+ * @return A thread local BIO to pass to OpenSSL logging functions.
+ */
+BIO *_fr_tls_global_log_bio(char const *file, int line, fr_log_type_t type, fr_log_lvl_t lvl)
+{
+       if (unlikely(!global_log_bio)) {
+               fr_tls_log_bio_t        *lb;
+
+               MEM(lb = talloc(NULL, fr_tls_log_bio_t));
+               *lb = (fr_tls_log_bio_t) {
+                       .bio = BIO_new(tls_global_log_meth),
+                       .type = type,
+                       .lvl = lvl,
+                       .file = file,
+                       .line = line
+               };
+               MEM(lb->bio);
+               BIO_set_data(lb->bio, lb);      /* So we can retrieve the fr_tls_lb_t in the callbacks */
+               fr_sbuff_init_talloc(lb, &lb->sbuff, &lb->tctx, 1024, 10 * 1024);       /* start 1k, max 10k */
+               fr_atexit_thread_local(global_log_bio, _fr_tls_log_bio_free, lb);
+               fr_sbuff_marker(&lb->logged_m, &lb->sbuff);
+               return lb->bio;
+       }
+
+       fr_sbuff_set(&global_log_bio->logged_m, fr_sbuff_start(&global_log_bio->sbuff));
+       fr_sbuff_reset_talloc(&request_log_bio->sbuff); /* Reset to initial size */
+       global_log_bio->type = type;
+       global_log_bio->lvl = lvl;
+       global_log_bio->file = file;
+       global_log_bio->line = line;
+
+       return global_log_bio->bio;
+}
+
+/** Initialise the BIO logging meths which are used to create thread local logging BIOs
+ *
+ */
+int fr_tls_log_init(void)
+{
        /*
-        *      For any other errors that (a) exist, and (b)
-        *      crop up - we need to interpret what to do with
-        *      them - so "politely inform" the caller that
-        *      the code needs updating here.
+        *      As per the boringSSL documentation
+        *
+        *      BIO_TYPE_START is the first user-allocated |BIO| type.
+        *      No pre-defined type, flag bits aside, may exceed this
+        *      value.
+        *
+        *      The low byte here defines the BIO ID, and the high byte
+        *      defines its capabilities.
         */
-       default:
-               ROPTIONAL(REDEBUG, ERROR, "TLS session error %i (%i)", error, ret);
+       tls_request_log_meth = BIO_meth_new(BIO_get_new_index() | BIO_TYPE_SOURCE_SINK, "fr_tls_request_log");
+       if (unlikely(!tls_request_log_meth)) return -1;
+
+       BIO_meth_set_write(tls_request_log_meth, tls_log_request_bio_write_cb);
+       BIO_meth_set_puts(tls_request_log_meth, tls_log_request_bio_puts_cb);
+
+       tls_global_log_meth = BIO_meth_new(BIO_get_new_index() | BIO_TYPE_SOURCE_SINK, "fr_tls_global_log");
+       if (unlikely(!tls_global_log_meth)) {
+               BIO_meth_free(tls_request_log_meth);
+               tls_request_log_meth = NULL;
                return -1;
        }
 
+       BIO_meth_set_write(tls_global_log_meth, tls_log_global_bio_write_cb);
+       BIO_meth_set_puts(tls_global_log_meth, tls_log_global_bio_puts_cb);
+
        return 0;
 }
+
+/** Free the global log method templates
+ *
+ */
+void fr_tls_log_free(void)
+{
+       if (tls_request_log_meth) {
+               BIO_meth_free(tls_request_log_meth);
+               tls_request_log_meth = NULL;
+       }
+
+       if (tls_global_log_meth) {
+               BIO_meth_free(tls_global_log_meth);
+               tls_global_log_meth = NULL;
+       }
+}
 #endif /* WITH_TLS */
index 662fe686f0e47adf9a456968424b1810b65a6bd4..dc6efbd84b7f0c120e002d2224c26ed4bf58f44f 100644 (file)
  * @brief Prototypes for TLS logging functions
  *
  * @copyright 2017 The FreeRADIUS project
+ * @copyright 2021 Arran Cudbard-Bell (a.cudbardb@freeradius.org)
  */
 RCSIDH(tls_log_h, "$Id$")
 
 #include <stdbool.h>
 #include <stdint.h>
 
-/*
- *     tls/log.c
+#include <freeradius-devel/server/request.h>
+#include <openssl/bio.h>
+
+#include "base.h"
+
+#define                fr_tls_log_certificate_chain(_request, _chain, _cert) \
+                       _fr_tls_log_certificate_chain( __FILE__, __LINE__, _request, _chain, _cert)
+void           _fr_tls_log_certificate_chain(char const *file, int line,
+                                             request_t *request, STACK_OF(X509) *chain, X509 *cert);
+
+int            fr_tls_log_io_error(request_t *request, fr_tls_session_t *session, int ret, char const *msg, ...)
+                                   CC_HINT(format (printf, 4, 5));
+
+int            fr_tls_log_error(request_t *request, char const *msg, ...) CC_HINT(format (printf, 2, 3));
+
+int            fr_tls_log_strerror_printf(char const *msg, ...) CC_HINT(format (printf, 1, 2));
+
+void           tls_log_clear(void);
+
+/** Return a BIO that writes to the log of the specified request
+ *
+ * @note BIO should be considered invalid if the request yields
+ *
+ * @param[in] _request to associate with the logging BIO.
+ * @param[in] _type    of log messages.
+ * @param[in] _lvl     to print log messages at.
+ * @return A BIO.
  */
-void   tls_log_clear(void);
+#define                fr_tls_request_log_bio(_request, _type, _lvl) \
+                       _fr_tls_request_log_bio(__FILE__, __LINE__, _request, _type, _lvl)
+BIO            *_fr_tls_request_log_bio(char const *file, int line, request_t *request,
+                                        fr_log_type_t type, fr_log_lvl_t lvl) CC_HINT(nonnull);
+
+/** Return a BIO that writes to the global log
+ *
+ * @note BIO should be considered invalid if the request yields
+ *
+ * @param[in] _type    of log messages.
+ * @param[in] _lvl     to print log messages at.
+ * @return A BIO.
+ */
+#define                fr_tls_global_log_bio(_type, _lvl) \
+                       _fr_tls_global_log_bio(__FILE__, __LINE__, _type, _lvl)
+BIO            *_fr_tls_global_log_bio(char const *file, int line, fr_log_type_t type, fr_log_lvl_t lvl);
+
+int            fr_tls_log_init(void);  /* Called from fr_openssl_init() */
 
-int    tls_strerror_printf(char const *msg, ...) CC_HINT(format (printf, 1, 2));
+void           fr_tls_log_free(void);  /* Called from fr_openssl_init() */
 #endif
index b4efb77baf5ce0d9ad93b5549bc14c560aff332f..1bf93d63f70c787314c59e3eedaebc7451e6ba69 100644 (file)
@@ -29,8 +29,9 @@ RCSID("$Id$")
 
 #include <freeradius-devel/server/base.h>
 #include <freeradius-devel/server/module.h>
-#include <freeradius-devel/util/debug.h>
 #include <freeradius-devel/tls/base.h>
+#include <freeradius-devel/tls/log.h>
+#include <freeradius-devel/util/debug.h>
 
 #include <openssl/crypto.h>
 #include <openssl/pem.h>
@@ -364,7 +365,7 @@ static int cipher_rsa_private_key_file_load(TALLOC_CTX *ctx, void *out, void *pa
        fclose(fp);
 
        if (!pkey) {
-               tls_strerror_printf(NULL);
+               fr_tls_log_strerror_printf(NULL);
                cf_log_perr(ci, "Error loading private certificate file \"%s\"", filename);
 
                return -1;
@@ -427,7 +428,7 @@ static int cipher_rsa_certificate_file_load(TALLOC_CTX *ctx, void *out, void *pa
        fclose(fp);
 
        if (!cert) {
-               tls_strerror_printf(NULL);
+               fr_tls_log_strerror_printf(NULL);
                cf_log_perr(ci, "Error loading certificate file \"%s\"", filename);
 
                return -1;
@@ -447,7 +448,7 @@ static int cipher_rsa_certificate_file_load(TALLOC_CTX *ctx, void *out, void *pa
         */
        pkey = X509_get_pubkey(cert);
        if (!pkey) {
-               tls_strerror_printf(NULL);
+               fr_tls_log_strerror_printf(NULL);
                cf_log_perr(ci, "Failed extracting public key from certificate");
 
                return -1;
@@ -948,7 +949,7 @@ static int cipher_xlat_instantiate(void *xlat_inst, UNUSED xlat_exp_t const *exp
 static int cipher_rsa_padding_params_set(EVP_PKEY_CTX *evp_pkey_ctx, cipher_rsa_t const *rsa_inst)
 {
        if (unlikely(EVP_PKEY_CTX_set_rsa_padding(evp_pkey_ctx, rsa_inst->padding)) <= 0) {
-               tls_strerror_printf(NULL);
+               fr_tls_log_strerror_printf(NULL);
                PERROR("%s: Failed setting RSA padding type", __FUNCTION__);
                return -1;
        }
@@ -965,13 +966,13 @@ static int cipher_rsa_padding_params_set(EVP_PKEY_CTX *evp_pkey_ctx, cipher_rsa_
         */
        case RSA_PKCS1_OAEP_PADDING:
                if (unlikely(EVP_PKEY_CTX_set_rsa_oaep_md(evp_pkey_ctx, rsa_inst->oaep->oaep_digest) <= 0)) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed setting OAEP digest", __FUNCTION__);
                        return -1;
                }
 
                if (unlikely(EVP_PKEY_CTX_set_rsa_mgf1_md(evp_pkey_ctx, rsa_inst->oaep->mgf1_digest) <= 0)) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed setting MGF1 digest", __FUNCTION__);
                        return -1;
                }
@@ -989,7 +990,7 @@ static int cipher_rsa_padding_params_set(EVP_PKEY_CTX *evp_pkey_ctx, cipher_rsa_
                         */
                        MEM(label = talloc_bstrndup(evp_pkey_ctx, rsa_inst->oaep->label, label_len));
                        if (unlikely(EVP_PKEY_CTX_set0_rsa_oaep_label(evp_pkey_ctx, label, label_len) <= 0)) {
-                               tls_strerror_printf(NULL);
+                               fr_tls_log_strerror_printf(NULL);
                                PERROR("%s: Failed setting OAEP padding label", __FUNCTION__);
                                OPENSSL_free(label);
                                return -1;
@@ -1030,7 +1031,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 */
                ti->evp_encrypt_ctx = EVP_PKEY_CTX_new(inst->rsa->certificate_file, NULL);
                if (!ti->evp_encrypt_ctx) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed allocating encrypt EVP_PKEY_CTX", __FUNCTION__);
                        return -1;
                }
@@ -1042,7 +1043,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 *      Configure encrypt
                 */
                if (unlikely(EVP_PKEY_encrypt_init(ti->evp_encrypt_ctx) <= 0)) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed initialising encrypt EVP_PKEY_CTX", __FUNCTION__);
                        return XLAT_ACTION_FAIL;
                }
@@ -1056,7 +1057,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 */
                ti->evp_verify_ctx = EVP_PKEY_CTX_new(inst->rsa->certificate_file, NULL);
                if (!ti->evp_verify_ctx) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed allocating verify EVP_PKEY_CTX", __FUNCTION__);
                        return -1;
                }
@@ -1068,7 +1069,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 *      Configure verify
                 */
                if (unlikely(EVP_PKEY_verify_init(ti->evp_verify_ctx) <= 0)) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed initialising verify EVP_PKEY_CTX", __FUNCTION__);
                        return XLAT_ACTION_FAIL;
                }
@@ -1084,7 +1085,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                }
 
                if (unlikely(EVP_PKEY_CTX_set_signature_md(ti->evp_verify_ctx, inst->rsa->sig_digest)) <= 0) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed setting signature digest type", __FUNCTION__);
                        return XLAT_ACTION_FAIL;
                }
@@ -1096,7 +1097,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 */
                ti->evp_decrypt_ctx = EVP_PKEY_CTX_new(inst->rsa->private_key_file, NULL);
                if (!ti->evp_decrypt_ctx) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed allocating decrypt EVP_PKEY_CTX", __FUNCTION__);
                        return -1;
                }
@@ -1108,7 +1109,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 *      Configure decrypt
                 */
                if (unlikely(EVP_PKEY_decrypt_init(ti->evp_decrypt_ctx) <= 0)) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed initialising decrypt EVP_PKEY_CTX", __FUNCTION__);
                        return XLAT_ACTION_FAIL;
                }
@@ -1122,7 +1123,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 */
                ti->evp_sign_ctx = EVP_PKEY_CTX_new(inst->rsa->private_key_file, NULL);
                if (!ti->evp_sign_ctx) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed allocating sign EVP_PKEY_CTX", __FUNCTION__);
                        return -1;
                }
@@ -1134,7 +1135,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 *      Configure sign
                 */
                if (unlikely(EVP_PKEY_sign_init(ti->evp_sign_ctx) <= 0)) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed initialising sign EVP_PKEY_CTX", __FUNCTION__);
                        return XLAT_ACTION_FAIL;
                }
@@ -1150,7 +1151,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                }
 
                if (unlikely(EVP_PKEY_CTX_set_signature_md(ti->evp_sign_ctx, inst->rsa->sig_digest)) <= 0) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed setting signature digest type", __FUNCTION__);
                        return XLAT_ACTION_FAIL;
                }
@@ -1160,7 +1161,7 @@ static int cipher_rsa_thread_instantiate(UNUSED CONF_SECTION const *conf, void *
                 */
                ti->evp_md_ctx = EVP_MD_CTX_create();
                if (!ti->evp_md_ctx) {
-                       tls_strerror_printf(NULL);
+                       fr_tls_log_strerror_printf(NULL);
                        PERROR("%s: Failed allocating EVP_MD_CTX", __FUNCTION__);
                        return -1;
                }
@@ -1269,7 +1270,7 @@ static int mod_bootstrap(void *instance, CONF_SECTION *conf)
                        if (inst->rsa->private_key_file && inst->rsa->x509_certificate_file) {
                                if (X509_check_private_key(inst->rsa->x509_certificate_file,
                                                           inst->rsa->private_key_file) == 0) {
-                                       tls_strerror_printf(NULL);
+                                       fr_tls_log_strerror_printf(NULL);
                                        cf_log_perr(conf, "Private key does not match the certificate public key");
                                        return -1;
                                }
index fe98af5a4b1fe3940bc00305c79970601cb47206..9da85ee5c3ea9d70c8759653a6223e15044a3e61 100644 (file)
@@ -26,6 +26,7 @@
 RCSID("$Id$")
 
 #include <freeradius-devel/eap/chbind.h>
+#include <freeradius-devel/tls/log.h>
 #include "eap_ttls.h"
 
 #define FR_DIAMETER_AVP_FLAG_VENDOR    0x80
@@ -282,7 +283,7 @@ do_value:
 
                        if (SSL_export_keying_material(ssl, challenge, sizeof(challenge),
                                                       label, sizeof(label) - 1, NULL, 0, 0) != 1) {
-                               tls_strerror_printf("Failed generating phase2 challenge");
+                               fr_tls_log_strerror_printf("Failed generating phase2 challenge");
                                goto error;
                        }