From 5716a30813f7b1a315593dfd7d16ff224ac4da9f Mon Sep 17 00:00:00 2001 From: Jeff Mitchell Date: Fri, 19 May 2023 17:15:58 -0400 Subject: [PATCH] Update nodeenrollment to fix TLS issue; add debug (#3231) * Add more logging to worker auth rotation and test flags This makes it much easier to figure out when and why rotation is happening and control it for tests/debugging. * Update auth rotation logic Because we were looking at validity period of client certs, which may not have matched the actual rotation interval, it was possible (mostly in test scenarios) for the rotation to happen multiple times on the roots before we actually hit the worker rotation interval. This changes how the interval is calculated by looking at the difference between not-after values on the certs to understand the rotation interval being used by the controller. We then use that as the starting point for calculating a next-rotation time. --- go.mod | 2 +- go.sum | 4 +- internal/daemon/worker/auth_rotation.go | 182 ++++++++++++++---------- internal/daemon/worker/testing.go | 7 +- internal/server/job/options_test.go | 6 +- internal/server/service_rotate_roots.go | 2 - 6 files changed, 115 insertions(+), 88 deletions(-) diff --git a/go.mod b/go.mod index b8ffae59d..86217aa4e 100644 --- a/go.mod +++ b/go.mod @@ -96,7 +96,7 @@ require ( github.com/hashicorp/cap/ldap v0.0.0-20230123181313-9c0fb924b0d9 github.com/hashicorp/go-kms-wrapping/extras/kms/v2 v2.0.0-20221122211539-47c893099f13 github.com/hashicorp/go-version v1.3.0 - github.com/hashicorp/nodeenrollment v0.2.1 + github.com/hashicorp/nodeenrollment v0.2.2 github.com/jimlambrt/gldap v0.1.6-0.20230501161051-4e73db4906d4 github.com/kelseyhightower/envconfig v1.4.0 github.com/mikesmitty/edkey v0.0.0-20170222072505-3356ea4e686a diff --git a/go.sum b/go.sum index 739b1ccc8..faa94efe7 100644 --- a/go.sum +++ b/go.sum @@ -760,8 +760,8 @@ github.com/hashicorp/golang-lru v0.5.4 h1:YDjusn29QI/Das2iO9M0BHnIbxPeyuCHsjMW+l github.com/hashicorp/golang-lru v0.5.4/go.mod h1:iADmTwqILo4mZ8BN3D2Q6+9jd8WM5uGBxy+E8yxSoD4= github.com/hashicorp/hcl v1.0.0 h1:0Anlzjpi4vEasTeNFn2mLJgTSwt0+6sfsiTG8qcWGx4= github.com/hashicorp/hcl v1.0.0/go.mod h1:E5yfLk+7swimpb2L/Alb/PJmXilQ/rhwaUYs4T20WEQ= -github.com/hashicorp/nodeenrollment v0.2.1 h1:T0YlpXCy9icscpoA99zMIc8JqfR7FXvxJdfAWNmV+sE= -github.com/hashicorp/nodeenrollment v0.2.1/go.mod h1:Do2FvaFHgnnMaqhdSTBX+TkQP0ep8VVQ0rOr+ZjUbJU= +github.com/hashicorp/nodeenrollment v0.2.2 h1:bMCt4m4g5TAbSUX7CLBwtGuLlhXc8HzdzS7oHNVbwok= +github.com/hashicorp/nodeenrollment v0.2.2/go.mod h1:Do2FvaFHgnnMaqhdSTBX+TkQP0ep8VVQ0rOr+ZjUbJU= github.com/hashicorp/vault/api v1.3.1 h1:pkDkcgTh47PRjY1NEFeofqR4W/HkNUi9qIakESO2aRM= github.com/hashicorp/vault/api v1.3.1/go.mod h1:QeJoWxMFt+MsuWcYhmwRLwKEXrjwAFFywzhptMsTIUw= github.com/hashicorp/vault/sdk v0.1.13/go.mod h1:B+hVj7TpuQY1Y/GPbCpffmgd+tSEwvhkWnjtSYCaS2M= diff --git a/internal/daemon/worker/auth_rotation.go b/internal/daemon/worker/auth_rotation.go index 7643ce2dd..5add09b22 100644 --- a/internal/daemon/worker/auth_rotation.go +++ b/internal/daemon/worker/auth_rotation.go @@ -28,14 +28,15 @@ func (w *Worker) startAuthRotationTicking(cancelCtx context.Context) { // The default time to use when we encounter an error or some other reason // we can't get a better reset time const defaultResetDuration = time.Hour - timer := time.NewTimer(defaultResetDuration) - // You're not supposed to call reset on timers that haven't been stopped or - // expired, so we stop it here so it resets in the loop below. That way if - // we want to adjust time, e.g. for tests, we can set the resetDuration - // value from within the loop - timer.Stop() var resetDuration time.Duration // will start at 0, so we run immediately + timer := time.NewTimer(defaultResetDuration) + lastRotation := time.Time{}.UTC() for { + // You're not supposed to call reset on timers that haven't been stopped or + // expired, so we stop it here and reset it to the current resetDuration. That way if + // we want to adjust time, e.g. for tests, we can set the resetDuration + // value from within the loop + timer.Stop() if w.TestOverrideAuthRotationPeriod != 0 { resetDuration = w.TestOverrideAuthRotationPeriod } @@ -58,15 +59,18 @@ func (w *Worker) startAuthRotationTicking(cancelCtx context.Context) { ) if err != nil { if errors.Is(err, nodeenrollment.ErrNotFound) { - // Be silent + // Be silent, but check again soon + resetDuration = 5 * time.Second continue } event.WriteError(cancelCtx, op, err) + resetDuration = 5 * time.Second continue } if currentNodeCreds == nil { event.WriteSysEvent(cancelCtx, op, "no error loading worker pki auth creds but nil creds, skipping rotation") + resetDuration = 5 * time.Second continue } @@ -81,18 +85,29 @@ func (w *Worker) startAuthRotationTicking(cancelCtx context.Context) { continue } - var earliestValid, latestValid time.Time - // Go through the bundles and find the full range of time that we - // have valid certificates - var args []any - for i, bundle := range currentNodeCreds.CertificateBundles { - if curr := bundle.CertificateNotBefore.AsTime(); earliestValid.IsZero() || curr.Before(earliestValid) { - earliestValid = curr + var current, next *types.CertificateBundle + // Go through the bundles and intuit the rotation interval + for _, bundle := range currentNodeCreds.CertificateBundles { + if current == nil { + current = bundle + continue } - if curr := bundle.CertificateNotAfter.AsTime(); latestValid.IsZero() || curr.After(latestValid) { - latestValid = curr + if current.CertificateNotAfter.AsTime().Before(bundle.CertificateNotAfter.AsTime()) { + next = bundle + } else { + next = current + current = bundle } + } + rotationInterval := next.CertificateNotAfter.AsTime().Sub(current.CertificateNotAfter.AsTime()) + // This is useful output, but doesn't do anything other than output information + str := "current" + var args []any + for i, bundle := range []*types.CertificateBundle{current, next} { + if i == 1 { + str = "next" + } cert, err := x509.ParseCertificate(bundle.CertificateDer) if err != nil { event.WriteError(cancelCtx, op, fmt.Errorf("error parsing leaf certificate in current worker auth bundle: %w", err)) @@ -109,9 +124,9 @@ func (w *Worker) startAuthRotationTicking(cancelCtx context.Context) { continue } args = append(args, - fmt.Sprintf("leaf_cert_%d_id", i), certKeyId, - fmt.Sprintf("leaf_cert_%d_not_before", i), cert.NotBefore.Format(time.RFC3339), - fmt.Sprintf("leaf_cert_%d_not_after", i), cert.NotAfter.Format(time.RFC3339), + fmt.Sprintf("leaf_cert_%s_id", str), certKeyId, + fmt.Sprintf("leaf_cert_%s_not_before", str), cert.NotBefore.Format(time.RFC3339), + fmt.Sprintf("leaf_cert_%s_not_after", str), cert.NotAfter.Format(time.RFC3339), ) caCert, err := x509.ParseCertificate(bundle.CaCertificateDer) if err != nil { @@ -129,54 +144,42 @@ func (w *Worker) startAuthRotationTicking(cancelCtx context.Context) { continue } args = append(args, - fmt.Sprintf("ca_cert_%d_id", i), caCertKeyId, - fmt.Sprintf("ca_cert_%d_not_before", i), caCert.NotBefore.Format(time.RFC3339), - fmt.Sprintf("ca_cert_%d_not_after", i), caCert.NotAfter.Format(time.RFC3339), + fmt.Sprintf("ca_cert_%s_id", str), caCertKeyId, + fmt.Sprintf("ca_cert_%s_not_before", str), caCert.NotBefore.Format(time.RFC3339), + fmt.Sprintf("ca_cert_%s_not_after", str), caCert.NotAfter.Format(time.RFC3339), ) } - // Ensure that our time periods aren't somehow quite messed up - now := time.Now() + + // We'll rotate the first time we get this far, which is fine -- + // better to rotate early than late -- and then we'll rotate at + // halfway through the current rotation interval + now := time.Now().UTC() + nextRotation := lastRotation.Add(rotationInterval / 2) event.WriteSysEvent(cancelCtx, op, "checking if worker auth should rotate", append( args, "now", now.Format(time.RFC3339), - "earliest_valid", earliestValid.Format(time.RFC3339), - "latest_valid", latestValid.Format(time.RFC3339), + "last_rotation", lastRotation.Format(time.RFC3339), + "intuited_rotation_interval", rotationInterval.String(), + "next_rotation", nextRotation.Format(time.RFC3339), )..., ) - if earliestValid.After(now) || latestValid.Before(now) || earliestValid.After(latestValid) { - // We basically have no valid creds so we can't rotate. - // TODO (maybe): Have this trigger a new set of creds and request? - event.WriteSysEvent(cancelCtx, op, "not within worker creds validity period, unsure what to do, not rotating") + + // See if we don't need to do anything + if !lastRotation.IsZero() && now.Before(nextRotation) { + resetDuration = lastRotation.Add(rotationInterval / 2).Sub(now) continue } - // Figure out the midpoint; if we're after it, try to rotate - var shouldRotate bool - delta := latestValid.Sub(earliestValid) - switch { - case w.TestOverrideAuthRotationPeriod != 0: - shouldRotate = true - default: - resetDuration = latestValid.Sub(now) / 2 - shouldRotate = now.After(earliestValid.Add(delta / 2)) - } - - if !shouldRotate { - event.WriteSysEvent(cancelCtx, op, "not time to rotate yet", - "now", now.Format(time.RFC3339), - "midpoint", earliestValid.Add(delta/2).Format(time.RFC3339), - "next_check", now.Add(resetDuration).Format(time.RFC3339), - ) - continue - } - - if err := rotateWorkerAuth(cancelCtx, w, currentNodeCreds); err != nil { + newRotationInterval, err := rotateWorkerAuth(cancelCtx, w, currentNodeCreds) + if err != nil { + resetDuration = 5 * time.Second event.WriteError(cancelCtx, op, err) continue } - event.WriteSysEvent(cancelCtx, op, "worker credentials rotated", "next_check", now.Add(resetDuration).Format(time.RFC3339)) - - // TODO (maybe): Calculate new delta and set a custom retry time on the timer? + lastRotation := now + nextRotation = lastRotation.Add(newRotationInterval / 2) + resetDuration = nextRotation.Sub(now) + event.WriteSysEvent(cancelCtx, op, "worker credentials rotated", "next_rotation", nextRotation) } } } @@ -186,7 +189,7 @@ func (w *Worker) startAuthRotationTicking(cancelCtx context.Context) { // it is meant to be called from other functions that have validated these // inputs and is separated out purely for (a) cleanliness/readability of the // ticking function and (b) possible future re-use. -func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.NodeCredentials) error { +func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.NodeCredentials) (time.Duration, error) { const op = "worker.rotateWorkerAuth" randReaderOpt := nodeenrollment.WithRandomReader(w.conf.SecureRandomReader) @@ -194,11 +197,11 @@ func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.No // Ensure we can get some needed values prior to actually doing generation client := w.controllerMultihopConn.Load() if client == nil { - return berrors.New(ctx, berrors.Internal, op, "nil multihop client") + return 0, berrors.New(ctx, berrors.Internal, op, "nil multihop client") } multihopClient, ok := client.(multihop.MultihopServiceClient) if !ok { - return berrors.New(ctx, berrors.Internal, op, "multihop client is not the right type") + return 0, berrors.New(ctx, berrors.Internal, op, "multihop client is not the right type") } // Generate a new set of credentials but don't persist them yet @@ -210,24 +213,24 @@ func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.No nodeenrollment.WithSkipStorage(true), ) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } err = newNodeCreds.SetPreviousEncryptionKey(currentNodeCreds) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } // Get a signed request from the new credentials fetchReq, err := newNodeCreds.CreateFetchNodeCredentialsRequest(ctx, randReaderOpt) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } // Encrypt the values to the server encFetchReq, err := nodeenrollment.EncryptMessage(ctx, fetchReq, currentNodeCreds, randReaderOpt) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } resp, err := multihopClient.RotateNodeCredentials(ctx, &types.RotateNodeCredentialsRequest{ @@ -235,7 +238,7 @@ func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.No EncryptedFetchNodeCredentialsRequest: encFetchReq, }) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } // Decrypt the response using current credentials @@ -246,7 +249,7 @@ func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.No currentNodeCreds, fetchResp, ); err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } // Call handle on the inner response, which will be encrypted to the @@ -259,59 +262,80 @@ func rotateWorkerAuth(ctx context.Context, w *Worker, currentNodeCreds *types.No nodeenrollment.WithStorageWrapper(w.conf.WorkerAuthStorageKms), ) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } newKeyId, err := nodeenrollment.KeyIdFromPkix(newNodeCreds.CertificatePublicKeyPkix) if err != nil { - return berrors.Wrap(ctx, err, op) + return 0, berrors.Wrap(ctx, err, op) } w.WorkerAuthCurrentKeyId.Store(newKeyId) + var current, next *types.CertificateBundle + // Go through the bundles and intuit the rotation interval + for _, bundle := range newNodeCreds.CertificateBundles { + if current == nil { + current = bundle + continue + } + if current.CertificateNotAfter.AsTime().Before(bundle.CertificateNotAfter.AsTime()) { + next = bundle + } else { + next = current + current = bundle + } + } + rotationInterval := next.CertificateNotAfter.AsTime().Sub(current.CertificateNotAfter.AsTime()) + + // This is useful output, but doesn't do anything other than output information + str := "current" var args []any - for i, bundle := range newNodeCreds.GetCertificateBundles() { + for i, bundle := range []*types.CertificateBundle{current, next} { + if i == 1 { + str = "next" + } cert, err := x509.ParseCertificate(bundle.CertificateDer) if err != nil { - event.WriteError(ctx, op, fmt.Errorf("error parsing leaf certificate in new worker auth bundle: %w", err)) + event.WriteError(ctx, op, fmt.Errorf("error parsing leaf certificate in current worker auth bundle: %w", err)) continue } certPkixBytes, err := x509.MarshalPKIXPublicKey(cert.PublicKey) if err != nil { - event.WriteError(ctx, op, fmt.Errorf("error marshaling leaf certificate public key in new worker auth bundle: %w", err)) + event.WriteError(ctx, op, fmt.Errorf("error marshaling leaf certificate public key in current worker auth bundle: %w", err)) continue } certKeyId, err := nodeenrollment.KeyIdFromPkix(certPkixBytes) if err != nil { - event.WriteError(ctx, op, fmt.Errorf("error deriving pkix string from leaf certificate public key in new worker auth bundle: %w", err)) + event.WriteError(ctx, op, fmt.Errorf("error deriving pkix string from leaf certificate public key in current worker auth bundle: %w", err)) continue } args = append(args, - fmt.Sprintf("leaf_cert_%d_id", i), certKeyId, - fmt.Sprintf("leaf_cert_%d_not_before", i), cert.NotBefore.Format(time.RFC3339), - fmt.Sprintf("leaf_cert_%d_not_after", i), cert.NotAfter.Format(time.RFC3339), + fmt.Sprintf("leaf_cert_%s_id", str), certKeyId, + fmt.Sprintf("leaf_cert_%s_not_before", str), cert.NotBefore.Format(time.RFC3339), + fmt.Sprintf("leaf_cert_%s_not_after", str), cert.NotAfter.Format(time.RFC3339), ) caCert, err := x509.ParseCertificate(bundle.CaCertificateDer) if err != nil { - event.WriteError(ctx, op, fmt.Errorf("error parsing CA certificate in new worker auth bundle: %w", err)) + event.WriteError(ctx, op, fmt.Errorf("error parsing CA certificate in current worker auth bundle: %w", err)) continue } caCertPkixBytes, err := x509.MarshalPKIXPublicKey(caCert.PublicKey) if err != nil { - event.WriteError(ctx, op, fmt.Errorf("error marshaling CA certificate public key in new worker auth bundle: %w", err)) + event.WriteError(ctx, op, fmt.Errorf("error marshaling CA certificate public key in current worker auth bundle: %w", err)) continue } caCertKeyId, err := nodeenrollment.KeyIdFromPkix(caCertPkixBytes) if err != nil { - event.WriteError(ctx, op, fmt.Errorf("error deriving pkix string from CA certificate public key in new worker auth bundle: %w", err)) + event.WriteError(ctx, op, fmt.Errorf("error deriving pkix string from CA certificate public key in current worker auth bundle: %w", err)) continue } args = append(args, - fmt.Sprintf("ca_cert_%d_id", i), caCertKeyId, - fmt.Sprintf("ca_cert_%d_not_before", i), caCert.NotBefore.Format(time.RFC3339), - fmt.Sprintf("ca_cert_%d_not_after", i), caCert.NotAfter.Format(time.RFC3339), + fmt.Sprintf("ca_cert_%s_id", str), caCertKeyId, + fmt.Sprintf("ca_cert_%s_not_before", str), caCert.NotBefore.Format(time.RFC3339), + fmt.Sprintf("ca_cert_%s_not_after", str), caCert.NotAfter.Format(time.RFC3339), ) } event.WriteSysEvent(ctx, op, "rotate worker auth job finished successfully", args...) - return nil + return rotationInterval, nil } diff --git a/internal/daemon/worker/testing.go b/internal/daemon/worker/testing.go index 79c17355b..49f73872f 100644 --- a/internal/daemon/worker/testing.go +++ b/internal/daemon/worker/testing.go @@ -463,10 +463,12 @@ func NewTestMultihopWorkers(t testing.TB, }) t.Cleanup(pkiWorker.Shutdown) + // Give time for it to be inserted into the database + time.Sleep(2 * time.Second) + // Get a server repo and worker auth repo serversRepo, err := serversRepoFn() require.NoError(err) - // Perform initial authentication of worker to controller reqBytes, err := base58.FastBase58Decoding(pkiWorker.Worker().WorkerAuthRegistrationRequest) require.NoError(err) @@ -496,6 +498,9 @@ func NewTestMultihopWorkers(t testing.TB, WorkerAuthDebuggingEnabled: enableAuthDebugging, }) + // Give time for it to be inserted into the database + time.Sleep(2 * time.Second) + // Perform initial authentication of worker to controller reqBytes, err = base58.FastBase58Decoding(childPkiWorker.Worker().WorkerAuthRegistrationRequest) require.NoError(err) diff --git a/internal/server/job/options_test.go b/internal/server/job/options_test.go index 0e6e4d453..e7d2de052 100644 --- a/internal/server/job/options_test.go +++ b/internal/server/job/options_test.go @@ -10,15 +10,15 @@ import ( func Test_GetOpts(t *testing.T) { t.Parallel() t.Run("WithRotationFrequency", func(t *testing.T) { - opts := getOpts(WithRotationFrequency(time.Minute)) testOpts := getDefaultOptions() assert.Equal(t, testOpts.withRotationFrequency, defaultRotationFrequency) + opts := getOpts(WithRotationFrequency(time.Minute)) assert.Equal(t, time.Minute, opts.withRotationFrequency) }) t.Run("WithCertificateLifetime", func(t *testing.T) { - opts := getOpts(WithCertificateLifetime(time.Minute)) testOpts := getDefaultOptions() - assert.Equal(t, testOpts.withCertificateLifetime, defaultRotationFrequency) + assert.Equal(t, testOpts.withCertificateLifetime, time.Duration(0)) + opts := getOpts(WithCertificateLifetime(time.Minute)) assert.Equal(t, time.Minute, opts.withCertificateLifetime) }) } diff --git a/internal/server/service_rotate_roots.go b/internal/server/service_rotate_roots.go index 3cea189de..408ceca04 100644 --- a/internal/server/service_rotate_roots.go +++ b/internal/server/service_rotate_roots.go @@ -34,8 +34,6 @@ func RotateRoots(ctx context.Context, workerAuthRepo *WorkerAuthRepositoryStorag } opt = append(opt, nodeenrollment.WithState(rootCerts.GetState()), - nodeenrollment.WithNotAfterClockSkew(0), - nodeenrollment.WithNotBeforeClockSkew(0), ) var current, next string