Verbose vault logging

Dockerfile.dev

@@ -1,4 +1,4 @@
-FROM golang:1.21-alpine as build
+FROM golang:1.23-alpine as build
 
 LABEL maintainer="MinIO Inc <dev@min.io>"
 

cmd/kes/server.go

@@ -79,13 +79,15 @@ func serverCmd(args []string) {
 		tlsCertFlag  string
 		mtlsAuthFlag string
 		devFlag      bool
+		verboseFlag  bool
 	)
 	cmd.StringVar(&addrFlag, "addr", "", "The address of the server")
 	cmd.StringVar(&configFlag, "config", "", "Path to the server configuration file")
 	cmd.StringVar(&tlsKeyFlag, "key", "", "Path to the TLS private key")
 	cmd.StringVar(&tlsCertFlag, "cert", "", "Path to the TLS certificate")
 	cmd.StringVar(&mtlsAuthFlag, "auth", "", "Controls how the server handles mTLS authentication")
 	cmd.BoolVar(&devFlag, "dev", false, "Start the KES server in development mode")
+	cmd.BoolVar(&verboseFlag, "verbose", false, "Log verbose output")
 	if err := cmd.Parse(args[1:]); err != nil {
 		if errors.Is(err, flag.ErrHelp) {
 			os.Exit(2)
@@ -122,12 +124,12 @@ func serverCmd(args []string) {
 		return
 	}
 
-	if err := startServer(addrFlag, configFlag); err != nil {
+	if err := startServer(addrFlag, configFlag, verboseFlag); err != nil {
 		cli.Fatal(err)
 	}
 }
 
-func startServer(addrFlag, configFlag string) error {
+func startServer(addrFlag, configFlag string, verbose bool) error {
 	var memLocked bool
 	if runtime.GOOS == "linux" {
 		memLocked = mlockall() == nil
@@ -174,18 +176,23 @@ func startServer(addrFlag, configFlag string) error {
 	ctx, cancel := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM)
 	defer cancel()
 
+	srv := &kes.Server{}
+	if rawConfig.Log != nil {
+		srv.ErrLevel.Set(rawConfig.Log.ErrLevel)
+		srv.AuditLevel.Set(rawConfig.Log.AuditLevel)
+	}
+	if verbose || srv.ErrLevel.Level() == slog.LevelDebug {
+		slog.SetLogLoggerLevel(slog.LevelDebug)
+	}
+
 	conf, err := rawConfig.Config(ctx)
 	if err != nil {
 		return err
 	}
 	defer conf.Keys.Close()
 
-	srv := &kes.Server{}
 	conf.Cache = configureCache(conf.Cache)
-	if rawConfig.Log != nil {
-		srv.ErrLevel.Set(rawConfig.Log.ErrLevel)
-		srv.AuditLevel.Set(rawConfig.Log.AuditLevel)
-	}
+
 	sighup := make(chan os.Signal, 10)
 	signal.Notify(sighup, syscall.SIGHUP)
 	defer signal.Stop(sighup)

internal/keystore/vault/log.go

@@ -0,0 +1,76 @@
+package vault
+
+import (
+	"context"
+	"crypto/sha256"
+	"encoding/hex"
+	"fmt"
+	"log/slog"
+	"net/http"
+	"time"
+
+	vaultapi "github.com/hashicorp/vault/api"
+)
+
+// NewLoggerTransport returns a new http.RoundTripper that logs HTTP requests and responses
+// (when debug logging is enabled).
+func NewLoggerTransport(ctx context.Context, rt http.RoundTripper) http.RoundTripper {
+	if !slog.Default().Enabled(ctx, slog.LevelDebug) {
+		return rt
+	}
+	return &loggingTransport{
+		RoundTripper: rt,
+	}
+}
+
+type loggingTransport struct {
+	http.RoundTripper
+}
+
+func (lt *loggingTransport) RoundTrip(req *http.Request) (*http.Response, error) {
+	rt := lt.RoundTripper
+	if rt == nil {
+		rt = http.DefaultTransport
+	}
+
+	start := time.Now()
+	resp, err := rt.RoundTrip(req)
+
+	// don't log health checks
+	if req.URL.Path != "/v1/sys/health" {
+		auth := obfuscateToken(req.Header.Get(vaultapi.AuthHeaderName))
+		switch {
+		case err != nil:
+			slog.Debug("HTTP error",
+				slog.String("method", req.Method),
+				slog.String("url", req.URL.String()),
+				slog.String("auth", auth),
+				slog.Duration("duration", time.Since(start)),
+				slog.String("error", err.Error()))
+		case resp.StatusCode >= 300:
+			slog.Debug("HTTP error response",
+				slog.String("method", req.Method),
+				slog.String("url", req.URL.String()),
+				slog.String("auth", auth),
+				slog.Duration("duration", time.Since(start)),
+				slog.String("status", resp.Status))
+		default:
+			slog.Debug("HTTP success response",
+				slog.String("method", req.Method),
+				slog.String("url", req.URL.String()),
+				slog.String("auth", auth),
+				slog.Duration("duration", time.Since(start)),
+				slog.String("status", resp.Status))
+		}
+	}
+
+	return resp, err
+}
+
+func obfuscateToken(token string) string {
+	if len(token) == 0 {
+		return ""
+	}
+	hash := sha256.Sum256([]byte(token))
+	return fmt.Sprintf("%s (hashed)", hex.EncodeToString(hash[:16]))
+}

internal/keystore/vault/vault.go

@@ -17,6 +17,7 @@ import (
 	"encoding/base64"
 	"errors"
 	"fmt"
+	"log/slog"
 	"net/http"
 	"os"
 	"path"
@@ -112,6 +113,7 @@ func Connect(ctx context.Context, c *Config) (*Store, error) {
 		tr.DisableKeepAlives = true
 		tr.MaxIdleConnsPerHost = -1
 	}
+	config.HttpClient.Transport = NewLoggerTransport(ctx, config.HttpClient.Transport)
 	vaultClient, err := vaultapi.NewClient(config)
 	if err != nil {
 		return nil, err
@@ -135,7 +137,25 @@ func Connect(ctx context.Context, c *Config) (*Store, error) {
 		authenticate = client.AuthenticateWithK8S(c.K8S)
 	}
 
-	auth, err := authenticate(ctx)
+	// log authentication events
+	lastAuthSuccess := false
+	authenticateLogged := func(ctx context.Context) (*vaultapi.Secret, error) {
+		secret, err := authenticate(ctx)
+		if err != nil {
+			if lastAuthSuccess {
+				slog.Info("Authentication failed (not logged anymore until next successful authentication)", slog.String("error", err.Error()))
+				lastAuthSuccess = false
+			}
+		} else {
+			if slog.Default().Enabled(ctx, slog.LevelDebug) {
+				slog.Debug("Authentication successful", slog.String("token", obfuscateToken(secret.Auth.ClientToken)))
+			}
+			lastAuthSuccess = true
+		}
+		return secret, err
+	}
+
+	auth, err := authenticateLogged(ctx)
 	if err != nil {
 		return nil, err
 	}

internal/sys/build.go

@@ -16,7 +16,7 @@ import (
 type BinaryInfo struct {
 	Version  string // The version of this binary
 	CommitID string // The git commit hash
-	Runtime  string // The Go runtime version, e.g. go1.21.0
+	Runtime  string // The Go runtime version, e.g. go1.23.5
 	Compiler string // The Go compiler used to build this binary
 }