tls: expose keylog event on TLSSocket

Exposes SSL_CTX_set_keylog_callback in the form of a `keylog` event
that is emitted on clients and servers. This enables easy debugging
of TLS connections with i.e. Wireshark, which is a long-requested
feature.

PR-URL: #27654
Refs: #2363
Reviewed-By: Anna Henningsen <[email protected]>
Reviewed-By: James M Snell <[email protected]>
Reviewed-By: Ben Noordhuis <[email protected]>
Reviewed-By: Sam Roberts <[email protected]>
Reviewed-By: Rich Trott <[email protected]>

Author: mildsunrise

doc/api/tls.md

@@ -334,6 +334,34 @@ added: v0.3.2
 The `tls.Server` class is a subclass of `net.Server` that accepts encrypted
 connections using TLS or SSL.
 
+### Event: 'keylog'
+<!-- YAML
+added: REPLACEME
+-->
+
+* `line` {Buffer} Line of ASCII text, in NSS `SSLKEYLOGFILE` format.
+* `tlsSocket` {tls.TLSSocket} The `tls.TLSSocket` instance on which it was
+  generated.
+
+The `keylog` event is emitted when key material is generated or received by
+a connection to this server (typically before handshake has completed, but not
+necessarily). This keying material can be stored for debugging, as it allows
+captured TLS traffic to be decrypted. It may be emitted multiple times for
+each socket.
+
+A typical use case is to append received lines to a common text file, which
+is later used by software (such as Wireshark) to decrypt the traffic:
+
+```js
+const logFile = fs.createWriteStream('/tmp/ssl-keys.log', { flags: 'a' });
+// ...
+server.on('keylog', (line, tlsSocket) => {
+  if (tlsSocket.remoteAddress !== '...')
+    return; // Only log keys for a particular IP
+  logFile.write(line);
+});
+```
+
 ### Event: 'newSession'
 <!-- YAML
 added: v0.9.2
@@ -624,6 +652,27 @@ changes:
 
 Construct a new `tls.TLSSocket` object from an existing TCP socket.
 
+### Event: 'keylog'
+<!-- YAML
+added: REPLACEME
+-->
+
+* `line` {Buffer} Line of ASCII text, in NSS `SSLKEYLOGFILE` format.
+
+The `keylog` event is emitted on a client `tls.TLSSocket` when key material
+is generated or received by the socket. This keying material can be stored
+for debugging, as it allows captured TLS traffic to be decrypted. It may
+be emitted multiple times, before or after the handshake completes.
+
+A typical use case is to append received lines to a common text file, which
+is later used by software (such as Wireshark) to decrypt the traffic:
+
+```js
+const logFile = fs.createWriteStream('/tmp/ssl-keys.log', { flags: 'a' });
+// ...
+tlsSocket.on('keylog', (line) => logFile.write(line));
+```
+
 ### Event: 'OCSPResponse'
 <!-- YAML
 added: v0.11.13

lib/_tls_wrap.js

@@ -286,6 +286,18 @@ function onnewsession(sessionId, session) {
 }
 
 
+function onkeylogclient(line) {
+  debug('client onkeylog');
+  this[owner_symbol].emit('keylog', line);
+}
+
+function onkeylog(line) {
+  debug('server onkeylog');
+  const owner = this[owner_symbol];
+  if (owner.server)
+    owner.server.emit('keylog', line, owner);
+}
+
 function onocspresponse(resp) {
   debug('client onocspresponse');
   this[owner_symbol].emit('OCSPResponse', resp);
@@ -571,6 +583,7 @@ TLSSocket.prototype._init = function(socket, wrap) {
     ssl.onclienthello = loadSession;
     ssl.oncertcb = loadSNI;
     ssl.onnewsession = onnewsession;
+    ssl.onkeylog = onkeylog;
     ssl.lastHandshakeTime = 0;
     ssl.handshakes = 0;
 
@@ -580,6 +593,8 @@ TLSSocket.prototype._init = function(socket, wrap) {
         // Also starts the client hello parser as a side effect.
         ssl.enableSessionCallbacks();
       }
+      if (this.server.listenerCount('keylog') > 0)
+        ssl.enableKeylogCallback();
       if (this.server.listenerCount('OCSPRequest') > 0)
         ssl.enableCertCb();
     }
@@ -605,9 +620,24 @@ TLSSocket.prototype._init = function(socket, wrap) {
 
       ssl.enableSessionCallbacks();
 
-      // Remover this listener since its no longer needed.
+      // Remove this listener since it's no longer needed.
       this.removeListener('newListener', newListener);
     }
+
+    ssl.onkeylog = onkeylogclient;
+
+    // Only call .onkeylog if there is a keylog listener.
+    this.on('newListener', keylogNewListener);
+
+    function keylogNewListener(event) {
+      if (event !== 'keylog')
+        return;
+
+      ssl.enableKeylogCallback();
+
+      // Remove this listener since it's no longer needed.
+      this.removeListener('newListener', keylogNewListener);
+    }
   }
 
   ssl.onerror = onerror;

src/env.h

@@ -252,6 +252,7 @@ constexpr size_t kFsStatsBufferLength = kFsStatsFieldsNumber * 2;
   V(onexit_string, "onexit")                                                   \
   V(onhandshakedone_string, "onhandshakedone")                                 \
   V(onhandshakestart_string, "onhandshakestart")                               \
+  V(onkeylog_string, "onkeylog")                                               \
   V(onmessage_string, "onmessage")                                             \
   V(onnewsession_string, "onnewsession")                                       \
   V(onocspresponse_string, "onocspresponse")                                   \

src/node_crypto.cc

@@ -149,6 +149,8 @@ template SSL_SESSION* SSLWrap<TLSWrap>::GetSessionCallback(
     int* copy);
 template int SSLWrap<TLSWrap>::NewSessionCallback(SSL* s,
                                                   SSL_SESSION* sess);
+template void SSLWrap<TLSWrap>::KeylogCallback(const SSL* s,
+                                               const char* line);
 template void SSLWrap<TLSWrap>::OnClientHello(
     void* arg,
     const ClientHelloParser::ClientHello& hello);
@@ -1749,6 +1751,21 @@ int SSLWrap<Base>::NewSessionCallback(SSL* s, SSL_SESSION* sess) {
 }
 
 
+template <class Base>
+void SSLWrap<Base>::KeylogCallback(const SSL* s, const char* line) {
+  Base* w = static_cast<Base*>(SSL_get_app_data(s));
+  Environment* env = w->ssl_env();
+  HandleScope handle_scope(env->isolate());
+  Context::Scope context_scope(env->context());
+
+  const size_t size = strlen(line);
+  Local<Value> line_bf = Buffer::Copy(env, line, 1 + size).ToLocalChecked();
+  char* data = Buffer::Data(line_bf);
+  data[size] = '\n';
+  w->MakeCallback(env->onkeylog_string(), 1, &line_bf);
+}
+
+
 template <class Base>
 void SSLWrap<Base>::OnClientHello(void* arg,
                                   const ClientHelloParser::ClientHello& hello) {

src/node_crypto.h

@@ -256,6 +256,7 @@ class SSLWrap {
                                          int* copy);
 #endif
   static int NewSessionCallback(SSL* s, SSL_SESSION* sess);
+  static void KeylogCallback(const SSL* s, const char* line);
   static void OnClientHello(void* arg,
                             const ClientHelloParser::ClientHello& hello);
 

src/tls_wrap.cc

@@ -912,6 +912,15 @@ void TLSWrap::EnableSessionCallbacks(
                             wrap);
 }
 
+void TLSWrap::EnableKeylogCallback(
+    const FunctionCallbackInfo<Value>& args) {
+  TLSWrap* wrap;
+  ASSIGN_OR_RETURN_UNWRAP(&wrap, args.Holder());
+  CHECK_NOT_NULL(wrap->sc_);
+  SSL_CTX_set_keylog_callback(wrap->sc_->ctx_.get(),
+      SSLWrap<TLSWrap>::KeylogCallback);
+}
+
 // Check required capabilities were not excluded from the OpenSSL build:
 // - OPENSSL_NO_SSL_TRACE excludes SSL_trace()
 // - OPENSSL_NO_STDIO excludes BIO_new_fp()
@@ -1105,6 +1114,7 @@ void TLSWrap::Initialize(Local<Object> target,
   env->SetProtoMethod(t, "start", Start);
   env->SetProtoMethod(t, "setVerifyMode", SetVerifyMode);
   env->SetProtoMethod(t, "enableSessionCallbacks", EnableSessionCallbacks);
+  env->SetProtoMethod(t, "enableKeylogCallback", EnableKeylogCallback);
   env->SetProtoMethod(t, "enableTrace", EnableTrace);
   env->SetProtoMethod(t, "destroySSL", DestroySSL);
   env->SetProtoMethod(t, "enableCertCb", EnableCertCb);

src/tls_wrap.h

@@ -160,6 +160,8 @@ class TLSWrap : public AsyncWrap,
   static void SetVerifyMode(const v8::FunctionCallbackInfo<v8::Value>& args);
   static void EnableSessionCallbacks(
       const v8::FunctionCallbackInfo<v8::Value>& args);
+  static void EnableKeylogCallback(
+      const v8::FunctionCallbackInfo<v8::Value>& args);
   static void EnableTrace(const v8::FunctionCallbackInfo<v8::Value>& args);
   static void EnableCertCb(const v8::FunctionCallbackInfo<v8::Value>& args);
   static void DestroySSL(const v8::FunctionCallbackInfo<v8::Value>& args);

test/parallel/test-tls-keylog-tlsv13.js

@@ -0,0 +1,32 @@
+'use strict';
+
+const common = require('../common');
+if (!common.hasCrypto)
+  common.skip('missing crypto');
+
+const assert = require('assert');
+const tls = require('tls');
+const fixtures = require('../common/fixtures');
+
+const server = tls.createServer({
+  key: fixtures.readSync('/keys/agent2-key.pem'),
+  cert: fixtures.readSync('/keys/agent2-cert.pem'),
+  // Amount of keylog events depends on negotiated protocol
+  // version, so force a specific one:
+  minVersion: 'TLSv1.3',
+  maxVersion: 'TLSv1.3',
+}).listen(() => {
+  const client = tls.connect({
+    port: server.address().port,
+    rejectUnauthorized: false,
+  });
+
+  const verifyBuffer = (line) => assert(Buffer.isBuffer(line));
+  server.on('keylog', common.mustCall(verifyBuffer, 5));
+  client.on('keylog', common.mustCall(verifyBuffer, 5));
+
+  client.once('secureConnect', () => {
+    server.close();
+    client.end();
+  });
+});