Improve end-to-end request ID propagation

api/api_test.go

@@ -884,16 +884,12 @@ func Test_Sign(t *testing.T) {
 		CsrPEM: CertificateRequest{csr},
 		OTT:    "foobarzar",
 	})
-	if err != nil {
-		t.Fatal(err)
-	}
+	require.NoError(t, err)
 	invalid, err := json.Marshal(SignRequest{
 		CsrPEM: CertificateRequest{csr},
 		OTT:    "",
 	})
-	if err != nil {
-		t.Fatal(err)
-	}
+	require.NoError(t, err)
 
 	expected1 := []byte(`{"crt":"` + strings.ReplaceAll(certPEM, "\n", `\n`) + `\n","ca":"` + strings.ReplaceAll(rootPEM, "\n", `\n`) + `\n","certChain":["` + strings.ReplaceAll(certPEM, "\n", `\n`) + `\n","` + strings.ReplaceAll(rootPEM, "\n", `\n`) + `\n"]}`)
 	expected2 := []byte(`{"crt":"` + strings.ReplaceAll(stepCertPEM, "\n", `\n`) + `\n","ca":"` + strings.ReplaceAll(rootPEM, "\n", `\n`) + `\n","certChain":["` + strings.ReplaceAll(stepCertPEM, "\n", `\n`) + `\n","` + strings.ReplaceAll(rootPEM, "\n", `\n`) + `\n"]}`)

authority/provisioner/webhook.go

@@ -15,7 +15,7 @@ import (
 	"time"
 
 	"github.com/pkg/errors"
-	"github.com/smallstep/certificates/logging"
+	"github.com/smallstep/certificates/internal/requestid"
 	"github.com/smallstep/certificates/templates"
 	"github.com/smallstep/certificates/webhook"
 	"go.step.sm/linkedca"
@@ -171,9 +171,8 @@ retry:
 		return nil, err
 	}
 
-	requestID, ok := logging.GetRequestID(ctx)
-	if ok {
-		req.Header.Set("X-Request-ID", requestID)
+	if requestID, ok := requestid.FromContext(ctx); ok {
+		req.Header.Set("X-Request-Id", requestID)
 	}
 
 	secret, err := base64.StdEncoding.DecodeString(w.Secret)

authority/provisioner/webhook_test.go

@@ -17,7 +17,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/smallstep/certificates/logging"
+	"github.com/smallstep/certificates/internal/requestid"
 	"github.com/smallstep/certificates/webhook"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -101,10 +101,10 @@ func TestWebhookController_isCertTypeOK(t *testing.T) {
 	}
 }
 
-// withRequestID is a helper that calls into [logging.WithRequestID] and returns
-// a new context with the requestID added to the provided context.
+// withRequestID is a helper that calls into [requestid.NewContext] and returns
+// a new context with the requestID added.
 func withRequestID(ctx context.Context, requestID string) context.Context {
-	return logging.WithRequestID(ctx, requestID)
+	return requestid.NewContext(ctx, requestID)
 }
 
 func TestWebhookController_Enrich(t *testing.T) {

ca/acmeClient.go

@@ -48,6 +48,7 @@ func NewACMEClient(endpoint string, contact []string, opts ...ClientOption) (*AC
 		return nil, errors.Wrapf(err, "creating GET request %s failed", endpoint)
 	}
 	req.Header.Set("User-Agent", UserAgent)
+	enforceRequestID(req)
 	resp, err := ac.client.Do(req)
 	if err != nil {
 		return nil, errors.Wrapf(err, "client GET %s failed", endpoint)
@@ -109,6 +110,7 @@ func (c *ACMEClient) GetNonce() (string, error) {
 		return "", errors.Wrapf(err, "creating GET request %s failed", c.dir.NewNonce)
 	}
 	req.Header.Set("User-Agent", UserAgent)
+	enforceRequestID(req)
 	resp, err := c.client.Do(req)
 	if err != nil {
 		return "", errors.Wrapf(err, "client GET %s failed", c.dir.NewNonce)
@@ -188,6 +190,7 @@ func (c *ACMEClient) post(payload []byte, url string, headerOps ...withHeaderOpt
 	}
 	req.Header.Set("Content-Type", "application/jose+json")
 	req.Header.Set("User-Agent", UserAgent)
+	enforceRequestID(req)
 	resp, err := c.client.Do(req)
 	if err != nil {
 		return nil, errors.Wrapf(err, "client POST %s failed", c.dir.NewOrder)

ca/ca.go

@@ -29,6 +29,7 @@ import (
 	"github.com/smallstep/certificates/cas/apiv1"
 	"github.com/smallstep/certificates/db"
 	"github.com/smallstep/certificates/internal/metrix"
+	"github.com/smallstep/certificates/internal/requestid"
 	"github.com/smallstep/certificates/logging"
 	"github.com/smallstep/certificates/monitoring"
 	"github.com/smallstep/certificates/scep"
@@ -329,15 +330,21 @@ func (ca *CA) Init(cfg *config.Config) (*CA, error) {
 	}
 
 	// Add logger if configured
+	var legacyTraceHeader string
 	if len(cfg.Logger) > 0 {
 		logger, err := logging.New("ca", cfg.Logger)
 		if err != nil {
 			return nil, err
 		}
+		legacyTraceHeader = logger.GetTraceHeader()
 		handler = logger.Middleware(handler)
 		insecureHandler = logger.Middleware(insecureHandler)
 	}
 
+	// always use request ID middleware; traceHeader is provided for backwards compatibility (for now)
+	handler = requestid.New(legacyTraceHeader).Middleware(handler)
+	insecureHandler = requestid.New(legacyTraceHeader).Middleware(insecureHandler)
+
 	// Create context with all the necessary values.
 	baseContext := buildContext(auth, scepAuthority, acmeDB, acmeLinker)
 

ca/ca_test.go

@@ -289,6 +289,9 @@ ZEp7knvU2psWRw==
 
 			if assert.Equals(t, rr.Code, tc.status) {
 				body := &ClosingBuffer{rr.Body}
+				resp := &http.Response{
+					Body: body,
+				}
 				if rr.Code < http.StatusBadRequest {
 					var sign api.SignResponse
 					assert.FatalError(t, readJSON(body, &sign))
@@ -325,7 +328,7 @@ ZEp7knvU2psWRw==
 					assert.FatalError(t, err)
 					assert.Equals(t, intermediate, realIntermediate)
 				} else {
-					err := readError(body)
+					err := readError(resp)
 					if tc.errMsg == "" {
 						assert.FatalError(t, errors.New("must validate response error"))
 					}
@@ -369,6 +372,9 @@ func TestCAProvisioners(t *testing.T) {
 
 			if assert.Equals(t, rr.Code, tc.status) {
 				body := &ClosingBuffer{rr.Body}
+				resp := &http.Response{
+					Body: body,
+				}
 				if rr.Code < http.StatusBadRequest {
 					var resp api.ProvisionersResponse
 
@@ -379,7 +385,7 @@ func TestCAProvisioners(t *testing.T) {
 					assert.FatalError(t, err)
 					assert.Equals(t, a, b)
 				} else {
-					err := readError(body)
+					err := readError(resp)
 					if tc.errMsg == "" {
 						assert.FatalError(t, errors.New("must validate response error"))
 					}
@@ -436,12 +442,15 @@ func TestCAProvisionerEncryptedKey(t *testing.T) {
 
 			if assert.Equals(t, rr.Code, tc.status) {
 				body := &ClosingBuffer{rr.Body}
+				resp := &http.Response{
+					Body: body,
+				}
 				if rr.Code < http.StatusBadRequest {
 					var ek api.ProvisionerKeyResponse
 					assert.FatalError(t, readJSON(body, &ek))
 					assert.Equals(t, ek.Key, tc.expectedKey)
 				} else {
-					err := readError(body)
+					err := readError(resp)
 					if tc.errMsg == "" {
 						assert.FatalError(t, errors.New("must validate response error"))
 					}
@@ -498,12 +507,15 @@ func TestCARoot(t *testing.T) {
 
 			if assert.Equals(t, rr.Code, tc.status) {
 				body := &ClosingBuffer{rr.Body}
+				resp := &http.Response{
+					Body: body,
+				}
 				if rr.Code < http.StatusBadRequest {
 					var root api.RootResponse
 					assert.FatalError(t, readJSON(body, &root))
 					assert.Equals(t, root.RootPEM.Certificate, rootCrt)
 				} else {
-					err := readError(body)
+					err := readError(resp)
 					if tc.errMsg == "" {
 						assert.FatalError(t, errors.New("must validate response error"))
 					}
@@ -641,6 +653,9 @@ func TestCARenew(t *testing.T) {
 
 			if assert.Equals(t, rr.Code, tc.status) {
 				body := &ClosingBuffer{rr.Body}
+				resp := &http.Response{
+					Body: body,
+				}
 				if rr.Code < http.StatusBadRequest {
 					var sign api.SignResponse
 					assert.FatalError(t, readJSON(body, &sign))
@@ -673,7 +688,7 @@ func TestCARenew(t *testing.T) {
 
 					assert.Equals(t, *sign.TLSOptions, authority.DefaultTLSOptions)
 				} else {
-					err := readError(body)
+					err := readError(resp)
 					if tc.errMsg == "" {
 						assert.FatalError(t, errors.New("must validate response error"))
 					}