Add SSLKEYLOGFILE support to k6

fixes #1043

cmd/integration_test.go

@@ -14,6 +14,7 @@ import (
 	"github.com/stretchr/testify/require"
 	"go.k6.io/k6/lib/consts"
 	"go.k6.io/k6/lib/testutils"
+	"go.k6.io/k6/lib/testutils/httpmultibin"
 )
 
 const (
@@ -249,6 +250,38 @@ func TestMetricsAndThresholds(t *testing.T) {
 	require.Equal(t, expected, teardownThresholds)
 }
 
+func TestSSLKEYLOGFILE(t *testing.T) {
+	t.Parallel()
+
+	// TODO don't use insecureSkipTLSVerify when/if tlsConfig is given to the runner from outside
+	tb := httpmultibin.NewHTTPMultiBin(t)
+	ts := newGlobalTestState(t)
+	ts.args = []string{"k6", "run", "-"}
+	ts.envVars = map[string]string{"SSLKEYLOGFILE": "./ssl.log"}
+	ts.stdIn = bytes.NewReader([]byte(tb.Replacer.Replace(`
+    import http from "k6/http"
+    export const options = {
+      hosts: {
+        "HTTPSBIN_DOMAIN": "HTTPSBIN_IP",
+      },
+      insecureSkipTLSVerify: true,
+    }
+
+    export default () => {
+      http.get("HTTPSBIN_URL/get");
+    }
+  `)))
+
+	newRootCommand(ts.globalState).execute()
+
+	assert.True(t,
+		testutils.LogContains(ts.loggerHook.Drain(), logrus.WarnLevel, "SSLKEYLOGFILE was specified"))
+	sslloglines, err := afero.ReadFile(ts.fs, filepath.Join(ts.cwd, "ssl.log"))
+	require.NoError(t, err)
+	// TODO maybe have multiple depending on the ciphers used as that seems to change it
+	require.Regexp(t, "^CLIENT_[A-Z_]+ [0-9a-f]+ [0-9a-f]+\n", string(sslloglines))
+}
+
 // TODO: add a hell of a lot more integration tests, including some that spin up
 // a test HTTP server and actually check if k6 hits it
 

cmd/run.go

@@ -268,6 +268,11 @@ func (c *cmdRun) run(cmd *cobra.Command, args []string) error {
 	logger.Debug("Waiting for engine processes to finish...")
 	engineWait()
 	logger.Debug("Everything has finished, exiting k6!")
+	if test.keywriter != nil {
+		if err := test.keywriter.Close(); err != nil {
+			logger.WithError(err).Warn("Error while closing the SSLKEYLOGFILE")
+		}
+	}
 	if interrupt != nil {
 		return interrupt
 	}

cmd/runtime_options.go

@@ -117,6 +117,12 @@ func getRuntimeOptions(flags *pflag.FlagSet, environment map[string]string) (lib
 		}
 	}
 
+	if envVar, ok := environment["SSLKEYLOGFILE"]; ok {
+		if !opts.KeyWriter.Valid {
+			opts.KeyWriter = null.StringFrom(envVar)
+		}
+	}
+
 	if opts.IncludeSystemEnvVars.Bool { // If enabled, gather the actual system environment variables
 		opts.Env = environment
 	}

cmd/test_load.go

@@ -4,6 +4,10 @@ import (
 	"archive/tar"
 	"bytes"
 	"fmt"
+	"io"
+	"os"
+	"path/filepath"
+	"sync"
 
 	"github.com/spf13/afero"
 	"github.com/spf13/cobra"
@@ -25,12 +29,15 @@ const (
 // and configured k6 test.
 type loadedTest struct {
 	sourceRootPath  string // contains the raw string the user supplied
+	pwd             string
 	source          *loader.SourceData
+	fs              afero.Fs
 	fileSystems     map[string]afero.Fs
 	runtimeOptions  lib.RuntimeOptions
 	metricsRegistry *metrics.Registry
 	builtInMetrics  *metrics.BuiltinMetrics
 	initRunner      lib.Runner // TODO: rename to something more appropriate
+	keywriter       io.Closer
 
 	// Only set if cliConfigGetter is supplied to loadAndConfigureTest() or if
 	// consolidateDeriveAndValidateConfig() is manually called.
@@ -49,7 +56,7 @@ func loadAndConfigureTest(
 
 	sourceRootPath := args[0]
 	gs.logger.Debugf("Resolving and reading test '%s'...", sourceRootPath)
-	src, fileSystems, err := readSource(gs, sourceRootPath)
+	src, fileSystems, pwd, err := readSource(gs, sourceRootPath)
 	if err != nil {
 		return nil, err
 	}
@@ -67,8 +74,10 @@ func loadAndConfigureTest(
 
 	registry := metrics.NewRegistry()
 	test := &loadedTest{
+		pwd:             pwd,
 		sourceRootPath:  sourceRootPath,
 		source:          src,
+		fs:              gs.fs,
 		fileSystems:     fileSystems,
 		runtimeOptions:  runtimeOptions,
 		metricsRegistry: registry,
@@ -106,6 +115,17 @@ func (lt *loadedTest) initializeFirstRunner(gs *globalState) error {
 		BuiltinMetrics: lt.builtInMetrics,
 		Registry:       lt.metricsRegistry,
 	}
+	if lt.runtimeOptions.KeyWriter.Valid {
+		logger.Warnf("SSLKEYLOGFILE was specified, logging TLS connection keys to '%s'...",
+			lt.runtimeOptions.KeyWriter.String)
+		keyfileName := filepath.Join(lt.pwd, lt.runtimeOptions.KeyWriter.String)
+		f, err := lt.fs.OpenFile(keyfileName, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0o600)
+		if err != nil {
+			return err
+		}
+		lt.keywriter = f
+		state.KeyLogger = &syncWriter{w: f}
+	}
 	switch testType {
 	case testTypeJS:
 		logger.Debug("Trying to load as a JS test...")
@@ -145,15 +165,15 @@ func (lt *loadedTest) initializeFirstRunner(gs *globalState) error {
 
 // readSource is a small wrapper around loader.ReadSource returning
 // result of the load and filesystems map
-func readSource(globalState *globalState, filename string) (*loader.SourceData, map[string]afero.Fs, error) {
+func readSource(globalState *globalState, filename string) (*loader.SourceData, map[string]afero.Fs, string, error) {
 	pwd, err := globalState.getwd()
 	if err != nil {
-		return nil, nil, err
+		return nil, nil, "", err
 	}
 
 	filesystems := loader.CreateFilesystems(globalState.fs)
 	src, err := loader.ReadSource(globalState.logger, filename, pwd, filesystems, globalState.stdIn)
-	return src, filesystems, err
+	return src, filesystems, pwd, err
 }
 
 func detectTestType(data []byte) string {
@@ -206,3 +226,14 @@ func (lt *loadedTest) consolidateDeriveAndValidateConfig(
 
 	return nil
 }
+
+type syncWriter struct {
+	w io.Writer
+	m sync.Mutex
+}
+
+func (cw *syncWriter) Write(b []byte) (int, error) {
+	cw.m.Lock()
+	defer cw.m.Unlock()
+	return cw.w.Write(b)
+}

js/runner.go

@@ -79,6 +79,8 @@ type Runner struct {
 
 	console   *console
 	setupData []byte
+
+	keylogger io.Writer
 }
 
 // New returns a new Runner for the provide source
@@ -126,6 +128,7 @@ func NewFromBundle(rs *lib.RuntimeState, b *Bundle) (*Runner, error) {
 		ActualResolver: net.LookupIP,
 		builtinMetrics: rs.BuiltinMetrics,
 		registry:       rs.Registry,
+		keylogger:      rs.KeyLogger,
 	}
 
 	err = r.SetOptions(r.Bundle.Options)
@@ -201,6 +204,7 @@ func (r *Runner) newVU(idLocal, idGlobal uint64, samplesOut chan<- metrics.Sampl
 		MaxVersion:         uint16(tlsVersions.Max),
 		Certificates:       certs,
 		Renegotiation:      tls.RenegotiateFreelyAsClient,
+		KeyLogWriter:       r.keylogger,
 	}
 	// Follow NameToCertificate in https://pkg.go.dev/crypto/[email protected]#Config, leave this field nil
 	// when it is empty

lib/runtime_state.go

@@ -1,6 +1,8 @@
 package lib
 
 import (
+	"io"
+
 	"github.com/sirupsen/logrus"
 	"go.k6.io/k6/metrics"
 )
@@ -11,5 +13,6 @@ type RuntimeState struct {
 	// TODO maybe have a struct `Metrics` with `Registry` and `Builtin` ?
 	Registry       *metrics.Registry
 	BuiltinMetrics *metrics.BuiltinMetrics
+	KeyLogger      io.Writer
 	Logger         *logrus.Logger
 }