From ca67207492874893844c608ab7b144401714d43d Mon Sep 17 00:00:00 2001
From: Herman Slatman <hermanslatman@hotmail.com>
Date: Wed, 25 Sep 2024 11:26:37 +0200
Subject: [PATCH] Remove `go-kit` usage from core SCEP code

This commit removes usage of `go-kit` from the core code. We still
allow a `go-kit` logger to be injected for backwards compatibility
purposes.

One behavioral change is introduced, resulting in the logging
calls not setting the log level directly. If one needs the old
behavior, they should initialize the logger like this:

 `logger = level.NewInjector(logger, level.DebugValue())`

This will ensure the logger will add a `level=debug` attribute for
the log lines where those were removed.
---
 scep.go      | 10 ----------
 scep_test.go | 50 +++++++++++++++++++++++++++++++++++++++++++++++++-
 2 files changed, 49 insertions(+), 11 deletions(-)

diff --git a/scep.go b/scep.go
index 2184fb6..8004af2 100644
--- a/scep.go
+++ b/scep.go
@@ -14,7 +14,6 @@ import (
 	"errors"
 	"fmt"
 
-	"github.com/go-kit/kit/log/level"
 	"github.com/smallstep/pkcs7"
 
 	"github.com/smallstep/scep/cryptoutil"
@@ -27,12 +26,6 @@ var (
 	errUnknownMessageType = errors.New("scep: unknown messageType")
 )
 
-// prepare the go-kit leveled logging configuration
-var (
-	levelKey   = level.Key()
-	levelDebug = level.DebugValue()
-)
-
 // The MessageType attribute specifies the type of operation performed
 // by the transaction.  This attribute MUST be included in all PKI
 // messages.
@@ -276,7 +269,6 @@ func ParsePKIMessage(data []byte, opts ...Option) (*PKIMessage, error) {
 	}
 
 	msg.logger.Log(
-		levelKey, levelDebug,
 		"msg", "parsed scep pkiMessage",
 		"scep_message_type", msgType,
 		"transaction_id", tID,
@@ -369,7 +361,6 @@ func (msg *PKIMessage) DecryptPKIEnvelope(cert *x509.Certificate, key crypto.Pri
 	}
 
 	logKeyVals := []interface{}{
-		levelKey, levelDebug,
 		"msg", "decrypt pkiEnvelope",
 	}
 	defer func() { msg.logger.Log(logKeyVals...) }()
@@ -613,7 +604,6 @@ func NewCSRRequest(csr *x509.CertificateRequest, tmpl *PKIMessage, opts ...Optio
 	}
 
 	conf.logger.Log(
-		levelKey, levelDebug,
 		"msg", "creating SCEP CSR request",
 		"transaction_id", tID,
 		"signer_cn", tmpl.SignerCert.Subject.CommonName,
diff --git a/scep_test.go b/scep_test.go
index cd92a3d..0d47b5f 100644
--- a/scep_test.go
+++ b/scep_test.go
@@ -1,6 +1,7 @@
 package scep
 
 import (
+	"bytes"
 	"crypto"
 	"crypto/rand"
 	"crypto/rsa"
@@ -13,6 +14,8 @@ import (
 	"math/big"
 	"os"
 	"path"
+	"regexp"
+	"strings"
 	"testing"
 	"time"
 
@@ -22,17 +25,29 @@ import (
 	"github.com/smallstep/scep/cryptoutil"
 )
 
+var newLines = regexp.MustCompile("\r?\n")
+
 func testParsePKIMessage(t *testing.T, data []byte) *PKIMessage {
 	t.Helper()
 
-	logger := log.NewLogfmtLogger(os.Stderr)
+	buf := bytes.Buffer{}
+	logger := log.NewLogfmtLogger(&buf)
 	logger = level.NewFilter(logger, level.AllowDebug())
+	logger = level.NewInjector(logger, level.DebugValue())
+
 	msg, err := ParsePKIMessage(data, WithLogger(logger))
 	if err != nil {
 		t.Fatal(err)
 	}
 
 	validateParsedPKIMessage(t, msg)
+
+	lines := newLines.Split(strings.TrimSpace(buf.String()), -1)
+	if len(lines) != 1 {
+		t.Errorf("expected single log line")
+	}
+	validateLogLevelDebug(t, lines)
+
 	return msg
 }
 
@@ -57,6 +72,39 @@ func validateParsedPKIMessage(t *testing.T, msg *PKIMessage) {
 	}
 }
 
+// textAttrs captures all key=value pairs produced the go-kit logger
+var textAttrs = regexp.MustCompile(`(\w+(?:\.\w+)*)=("(?:\\"|[^"])*"|\[.*?\]|[^ ]+)`)
+
+// splitTextAttrs splits the input string into key=value pairs. Every pair is
+// returned as a single string.
+func splitTextAttrs(input string) []string {
+	return textAttrs.FindAllString(input, -1)
+}
+
+// validateLogLevelDebug validates the input string has the debug level
+// set on each non-empty line.
+func validateLogLevelDebug(t *testing.T, lines []string) {
+	t.Helper()
+
+	for _, line := range lines {
+		if line == "" {
+			continue
+		}
+
+		attrs := splitTextAttrs(line)
+		countLogLevel := 0
+		for _, a := range attrs {
+			if a == "level=debug" {
+				countLogLevel += 1
+			}
+		}
+
+		if countLogLevel != 1 {
+			t.Errorf("expected log level debug to be set once; found %d occurrences", countLogLevel)
+		}
+	}
+}
+
 // Tests the case when servers reply with PKCS #7 signed-data that contains no
 // certificates assuming that the client can request CA certificates using
 // GetCaCert request.