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

@@ -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,

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.