tls: fix --tls-keylog option

There's a typo that causes only the first socket to be logged (i.e. when the warning is emitted). In addition, server sockets aren't logged because `keylog` events are not emitted on tls.Server, not the socket. This behaviour is counterintuitive and has caused more bugs in the past, so make all sockets (server or client) emit 'keylog'. tls.Server will just re-emit these events. Refs: nodejs#30055
mildsunrise · May 12, 2020 · 4f271ad · 4f271ad
1 parent 53eb264
commit 4f271ad
Show file tree

Hide file tree

Showing 3 changed files with 41 additions and 41 deletions.
diff --git a/doc/api/tls.md b/doc/api/tls.md
@@ -701,7 +701,7 @@ added:
 
 * `line` {Buffer} Line of ASCII text, in NSS `SSLKEYLOGFILE` format.
 
-The `keylog` event is emitted on a client `tls.TLSSocket` when key material
+The `keylog` event is emitted on a `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.

diff --git a/lib/_tls_wrap.js b/lib/_tls_wrap.js
@@ -372,16 +372,9 @@ function onPskClientCallback(hint, maxPskLen, maxIdentityLen) {
   return { psk: ret.psk, identity: ret.identity };
 }
 
-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);
+  debug('onkeylog');
+  this[owner_symbol].emit('keylog', line);
 }
 
 function onocspresponse(resp) {
@@ -663,13 +656,26 @@ TLSSocket.prototype._init = function(socket, wrap) {
   if (requestCert || rejectUnauthorized)
     ssl.setVerifyMode(requestCert, rejectUnauthorized);
 
+  // Only call .onkeylog if there is a keylog listener.
+  ssl.onkeylog = onkeylog;
+  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);
+  }
+
   if (options.isServer) {
     ssl.onhandshakestart = onhandshakestart;
     ssl.onhandshakedone = onhandshakedone;
     ssl.onclienthello = loadSession;
     ssl.oncertcb = loadSNI;
     ssl.onnewsession = onnewsession;
-    ssl.onkeylog = onkeylog;
     ssl.lastHandshakeTime = 0;
     ssl.handshakes = 0;
 
@@ -679,8 +685,6 @@ 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();
     }
@@ -709,39 +713,23 @@ TLSSocket.prototype._init = function(socket, wrap) {
       // 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);
-    }
   }
 
   if (tlsKeylog) {
     if (warnOnTlsKeylog) {
       warnOnTlsKeylog = false;
       process.emitWarning('Using --tls-keylog makes TLS connections insecure ' +
         'by writing secret key material to file ' + tlsKeylog);
-      ssl.enableKeylogCallback();
-      this.on('keylog', (line) => {
-        appendFile(tlsKeylog, line, { mode: 0o600 }, (err) => {
-          if (err && warnOnTlsKeylogError) {
-            warnOnTlsKeylogError = false;
-            process.emitWarning('Failed to write TLS keylog (this warning ' +
-              'will not be repeated): ' + err);
-          }
-        });
-      });
     }
+    this.on('keylog', (line) => {
+      appendFile(tlsKeylog, line, { mode: 0o600 }, (err) => {
+        if (err && warnOnTlsKeylogError) {
+          warnOnTlsKeylogError = false;
+          process.emitWarning('Failed to write TLS keylog (this warning ' +
+            'will not be repeated): ' + err);
+        }
+      });
+    });
   }
 
   ssl.onerror = onerror;
@@ -1044,6 +1032,10 @@ function onSocketTLSError(err) {
   }
 }
 
+function onSocketKeylog(line) {
+  this._tlsOptions.server.emit('keylog', line, this);
+}
+
 function onSocketClose(err) {
   // Closed because of error - no need to emit it twice
   if (err)
@@ -1076,6 +1068,9 @@ function tlsConnectionListener(rawSocket) {
 
   socket.on('secure', onServerSocketSecure);
 
+  if (this.listenerCount('keylog') > 0)
+    socket.on('keylog', onSocketKeylog);
+
   socket[kErrorEmitted] = false;
   socket.on('close', onSocketClose);
   socket.on('_tlsError', onSocketTLSError);

diff --git a/test/parallel/test-tls-enable-keylog-cli.js b/test/parallel/test-tls-enable-keylog-cli.js
@@ -24,8 +24,11 @@ const child = fork(__filename, ['test'], {
 child.on('close', common.mustCall((code, signal) => {
   assert.strictEqual(code, 0);
   assert.strictEqual(signal, null);
-  const log = fs.readFileSync(file, 'utf8');
-  assert(/SECRET/.test(log));
+  const log = fs.readFileSync(file, 'utf8').trim().split('\n');
+  // Both client and server should log their secrets,
+  // so we should have two identical lines in the log
+  assert.strictEqual(log.length, 2);
+  assert.strictEqual(log[0], log[1]);
 }));
 
 function test() {
@@ -40,7 +43,9 @@ function test() {
     },
     server: {
       cert: keys.agent6.cert,
-      key: keys.agent6.key
+      key: keys.agent6.key,
+      // Number of keylog events is dependent on protocol version
+      maxVersion: 'TLSv1.2',
     },
   }, common.mustCall((err, pair, cleanup) => {
     if (pair.server.err) {