Switch the keylog BIO to a callback.

The keylog BIO is internally synchronized by the SSL_CTX lock, but an
application may wish to log keys from multiple SSL_CTXs. This is in
preparation for switching Chromium to use a separate SSL_CTX per profile
to more naturally split up the session caches.

It will also be useful for routing up SSLKEYLOGFILE in WebRTC. There,
each log line must be converted to an IPC up from the renderer
processes.

This will require changes in Chromium when we roll BoringSSL.

BUG=458365,webrtc:4417

Change-Id: I2945bdb4def0a9c36e751eab3d5b06c330d66b54
Reviewed-on: https://boringssl-review.googlesource.com/6514
Reviewed-by: Adam Langley <agl@google.com>
diff --git a/include/openssl/ssl.h b/include/openssl/ssl.h
index d59eb84..0791441 100644
--- a/include/openssl/ssl.h
+++ b/include/openssl/ssl.h
@@ -2683,13 +2683,15 @@
 /* SSL_set_msg_callback_arg sets the |arg| parameter of the message callback. */
 OPENSSL_EXPORT void SSL_set_msg_callback_arg(SSL *ssl, void *arg);
 
-/* SSL_CTX_set_keylog_bio sets configures all SSL objects attached to |ctx| to
- * log session material to |keylog_bio|. This is intended for debugging use
- * with tools like Wireshark. |ctx| takes ownership of |keylog_bio|.
+/* SSL_CTX_set_keylog_callback configures a callback to log key material. This
+ * is intended for debugging use with tools like Wireshark. The |cb| function
+ * should log |line| followed by a newline, synchronizing with any concurrent
+ * access to the log.
  *
  * The format is described in
  * https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSS/Key_Log_Format. */
-OPENSSL_EXPORT void SSL_CTX_set_keylog_bio(SSL_CTX *ctx, BIO *keylog_bio);
+OPENSSL_EXPORT void SSL_CTX_set_keylog_callback(
+    SSL_CTX *ctx, void (*cb)(const SSL *ssl, const char *line));
 
 enum ssl_renegotiate_mode_t {
   ssl_renegotiate_never = 0,
@@ -3738,9 +3740,9 @@
   uint8_t *ocsp_response;
   size_t ocsp_response_length;
 
-  /* If not NULL, session key material will be logged to this BIO for debugging
-   * purposes. The format matches NSS's and is readable by Wireshark. */
-  BIO *keylog_bio;
+  /* keylog_callback, if not NULL, is the key logging callback. See
+   * |SSL_CTX_set_keylog_callback|. */
+  void (*keylog_callback)(const SSL *ssl, const char *line);
 
   /* current_time_cb, if not NULL, is the function to use to get the current
    * time. It sets |*out_clock| to the current time. */
diff --git a/ssl/internal.h b/ssl/internal.h
index 77d8e58..e278aea 100644
--- a/ssl/internal.h
+++ b/ssl/internal.h
@@ -1233,21 +1233,21 @@
 
 int tls1_record_handshake_hashes_for_channel_id(SSL *s);
 
-/* ssl_ctx_log_rsa_client_key_exchange logs |premaster| to |ctx|, if logging is
- * enabled. It returns one on success and zero on failure. The entry is
- * identified by the first 8 bytes of |encrypted_premaster|. */
-int ssl_ctx_log_rsa_client_key_exchange(SSL_CTX *ctx,
-                                        const uint8_t *encrypted_premaster,
-                                        size_t encrypted_premaster_len,
-                                        const uint8_t *premaster,
-                                        size_t premaster_len);
+/* ssl_log_rsa_client_key_exchange logs |premaster|, if logging is enabled for
+ * |ssl|. It returns one on success and zero on failure. The entry is identified
+ * by the first 8 bytes of |encrypted_premaster|. */
+int ssl_log_rsa_client_key_exchange(const SSL *ssl,
+                                    const uint8_t *encrypted_premaster,
+                                    size_t encrypted_premaster_len,
+                                    const uint8_t *premaster,
+                                    size_t premaster_len);
 
-/* ssl_ctx_log_master_secret logs |master| to |ctx|, if logging is enabled. It
+/* ssl_log_master_secret logs |master|, if logging is enabled for |ssl|. It
  * returns one on success and zero on failure. The entry is identified by
  * |client_random|. */
-int ssl_ctx_log_master_secret(SSL_CTX *ctx, const uint8_t *client_random,
-                              size_t client_random_len, const uint8_t *master,
-                              size_t master_len);
+int ssl_log_master_secret(const SSL *ssl, const uint8_t *client_random,
+                          size_t client_random_len, const uint8_t *master,
+                          size_t master_len);
 
 /* ssl3_can_false_start returns one if |s| is allowed to False Start and zero
  * otherwise. */
diff --git a/ssl/s3_both.c b/ssl/s3_both.c
index 31e36c7..1416bb3 100644
--- a/ssl/s3_both.c
+++ b/ssl/s3_both.c
@@ -170,9 +170,9 @@
     memcpy(p, s->s3->tmp.finish_md, n);
 
     /* Log the master secret, if logging is enabled. */
-    if (!ssl_ctx_log_master_secret(s->ctx, s->s3->client_random,
-                                   SSL3_RANDOM_SIZE, s->session->master_key,
-                                   s->session->master_key_length)) {
+    if (!ssl_log_master_secret(s, s->s3->client_random, SSL3_RANDOM_SIZE,
+                               s->session->master_key,
+                               s->session->master_key_length)) {
       return 0;
     }
 
diff --git a/ssl/s3_clnt.c b/ssl/s3_clnt.c
index 352dae3..b881966 100644
--- a/ssl/s3_clnt.c
+++ b/ssl/s3_clnt.c
@@ -1709,8 +1709,7 @@
       n += enc_pms_len;
 
       /* Log the premaster secret, if logging is enabled. */
-      if (!ssl_ctx_log_rsa_client_key_exchange(s->ctx, p, enc_pms_len, pms,
-                                               pms_len)) {
+      if (!ssl_log_rsa_client_key_exchange(s, p, enc_pms_len, pms, pms_len)) {
         goto err;
       }
 
diff --git a/ssl/ssl_lib.c b/ssl/ssl_lib.c
index c78a91a..aaebf32 100644
--- a/ssl/ssl_lib.c
+++ b/ssl/ssl_lib.c
@@ -343,7 +343,6 @@
   OPENSSL_free(ctx->ocsp_response);
   OPENSSL_free(ctx->signed_cert_timestamp_list);
   EVP_PKEY_free(ctx->tlsext_channel_id_private);
-  BIO_free(ctx->keylog_bio);
 
   OPENSSL_free(ctx);
 }
@@ -2252,9 +2251,9 @@
   ssl->msg_callback_arg = arg;
 }
 
-void SSL_CTX_set_keylog_bio(SSL_CTX *ctx, BIO *keylog_bio) {
-  BIO_free(ctx->keylog_bio);
-  ctx->keylog_bio = keylog_bio;
+void SSL_CTX_set_keylog_callback(SSL_CTX *ctx,
+                                 void (*cb)(const SSL *ssl, const char *line)) {
+  ctx->keylog_callback = cb;
 }
 
 static int cbb_add_hex(CBB *cbb, const uint8_t *in, size_t in_len) {
@@ -2274,18 +2273,12 @@
   return 1;
 }
 
-int ssl_ctx_log_rsa_client_key_exchange(SSL_CTX *ctx,
-                                        const uint8_t *encrypted_premaster,
-                                        size_t encrypted_premaster_len,
-                                        const uint8_t *premaster,
-                                        size_t premaster_len) {
-  BIO *bio = ctx->keylog_bio;
-  CBB cbb;
-  uint8_t *out;
-  size_t out_len;
-  int ret;
-
-  if (bio == NULL) {
+int ssl_log_rsa_client_key_exchange(const SSL *ssl,
+                                    const uint8_t *encrypted_premaster,
+                                    size_t encrypted_premaster_len,
+                                    const uint8_t *premaster,
+                                    size_t premaster_len) {
+  if (ssl->ctx->keylog_callback == NULL) {
     return 1;
   }
 
@@ -2294,7 +2287,9 @@
     return 0;
   }
 
-  CBB_zero(&cbb);
+  CBB cbb;
+  uint8_t *out;
+  size_t out_len;
   if (!CBB_init(&cbb, 4 + 16 + 1 + premaster_len * 2 + 1) ||
       !CBB_add_bytes(&cbb, (const uint8_t *)"RSA ", 4) ||
       /* Only the first 8 bytes of the encrypted premaster secret are
@@ -2302,30 +2297,21 @@
       !cbb_add_hex(&cbb, encrypted_premaster, 8) ||
       !CBB_add_bytes(&cbb, (const uint8_t *)" ", 1) ||
       !cbb_add_hex(&cbb, premaster, premaster_len) ||
-      !CBB_add_bytes(&cbb, (const uint8_t *)"\n", 1) ||
+      !CBB_add_u8(&cbb, 0 /* NUL */) ||
       !CBB_finish(&cbb, &out, &out_len)) {
     CBB_cleanup(&cbb);
     return 0;
   }
 
-  CRYPTO_MUTEX_lock_write(&ctx->lock);
-  ret = BIO_write(bio, out, out_len) >= 0 && BIO_flush(bio);
-  CRYPTO_MUTEX_unlock(&ctx->lock);
-
+  ssl->ctx->keylog_callback(ssl, (const char *)out);
   OPENSSL_free(out);
-  return ret;
+  return 1;
 }
 
-int ssl_ctx_log_master_secret(SSL_CTX *ctx, const uint8_t *client_random,
-                              size_t client_random_len, const uint8_t *master,
-                              size_t master_len) {
-  BIO *bio = ctx->keylog_bio;
-  CBB cbb;
-  uint8_t *out;
-  size_t out_len;
-  int ret;
-
-  if (bio == NULL) {
+int ssl_log_master_secret(const SSL *ssl, const uint8_t *client_random,
+                          size_t client_random_len, const uint8_t *master,
+                          size_t master_len) {
+  if (ssl->ctx->keylog_callback == NULL) {
     return 1;
   }
 
@@ -2334,24 +2320,23 @@
     return 0;
   }
 
-  CBB_zero(&cbb);
+  CBB cbb;
+  uint8_t *out;
+  size_t out_len;
   if (!CBB_init(&cbb, 14 + 64 + 1 + master_len * 2 + 1) ||
       !CBB_add_bytes(&cbb, (const uint8_t *)"CLIENT_RANDOM ", 14) ||
       !cbb_add_hex(&cbb, client_random, 32) ||
       !CBB_add_bytes(&cbb, (const uint8_t *)" ", 1) ||
       !cbb_add_hex(&cbb, master, master_len) ||
-      !CBB_add_bytes(&cbb, (const uint8_t *)"\n", 1) ||
+      !CBB_add_u8(&cbb, 0 /* NUL */) ||
       !CBB_finish(&cbb, &out, &out_len)) {
     CBB_cleanup(&cbb);
     return 0;
   }
 
-  CRYPTO_MUTEX_lock_write(&ctx->lock);
-  ret = BIO_write(bio, out, out_len) >= 0 && BIO_flush(bio);
-  CRYPTO_MUTEX_unlock(&ctx->lock);
-
+  ssl->ctx->keylog_callback(ssl, (const char *)out);
   OPENSSL_free(out);
-  return ret;
+  return 1;
 }
 
 int SSL_is_init_finished(const SSL *ssl) {
diff --git a/tool/client.cc b/tool/client.cc
index cd8353b..c09f457 100644
--- a/tool/client.cc
+++ b/tool/client.cc
@@ -14,6 +14,8 @@
 
 #include <openssl/base.h>
 
+#include <stdio.h>
+
 #include <openssl/err.h>
 #include <openssl/pem.h>
 #include <openssl/ssl.h>
@@ -119,6 +121,13 @@
   return SSL_TLSEXT_ERR_OK;
 }
 
+static FILE *g_keylog_file = nullptr;
+
+static void KeyLogCallback(const SSL *ssl, const char *line) {
+  fprintf(g_keylog_file, "%s\n", line);
+  fflush(g_keylog_file);
+}
+
 bool Client(const std::vector<std::string> &args) {
   if (!InitSocketLibrary()) {
     return false;
@@ -135,12 +144,12 @@
 
   const char *keylog_file = getenv("SSLKEYLOGFILE");
   if (keylog_file) {
-    BIO *keylog_bio = BIO_new_file(keylog_file, "a");
-    if (!keylog_bio) {
-      ERR_print_errors_cb(PrintErrorCallback, stderr);
+    g_keylog_file = fopen(keylog_file, "a");
+    if (g_keylog_file == nullptr) {
+      perror("fopen");
       return false;
     }
-    SSL_CTX_set_keylog_bio(ctx.get(), keylog_bio);
+    SSL_CTX_set_keylog_callback(ctx.get(), KeyLogCallback);
   }
 
   if (args_map.count("-cipher") != 0 &&