From c25a620650aa5a1b42597f894431f893847ff27e Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Thu, 7 Sep 2023 17:40:31 -0700 Subject: [PATCH 1/7] Adds HTTP request/response logging for S3 operations --- internal/backend/remote-state/s3/backend.go | 9 +++- .../backend/remote-state/s3/backend_test.go | 2 +- internal/backend/remote-state/s3/client.go | 41 ++++++++++++++++--- 3 files changed, 44 insertions(+), 8 deletions(-) diff --git a/internal/backend/remote-state/s3/backend.go b/internal/backend/remote-state/s3/backend.go index 997045fd0c..64b4661e72 100644 --- a/internal/backend/remote-state/s3/backend.go +++ b/internal/backend/remote-state/s3/backend.go @@ -607,6 +607,7 @@ func formatDeprecations(attrs map[string]string) string { // via PrepareConfig. func (b *Backend) Configure(obj cty.Value) tfdiags.Diagnostics { ctx := context.TODO() + log := logger() var diags tfdiags.Diagnostics if obj.IsNull() { @@ -632,6 +633,12 @@ func (b *Backend) Configure(obj cty.Value) tfdiags.Diagnostics { b.bucketName = stringAttr(obj, "bucket") b.keyName = stringAttr(obj, "key") + + log = log.With( + "tf_backend_s3.bucket", b.bucketName, + "tf_backend_s3.path", b.path, + ) + b.acl = stringAttr(obj, "acl") b.workspaceKeyPrefix = stringAttrDefault(obj, "workspace_key_prefix", "env:") b.serverSideEncryption = boolAttr(obj, "encrypt") @@ -698,8 +705,6 @@ func (b *Backend) Configure(obj cty.Value) tfdiags.Diagnostics { } } - log := logger() - ctx, baselog := baselogging.NewHcLogger(ctx, log) cfg := &awsbase.Config{ diff --git a/internal/backend/remote-state/s3/backend_test.go b/internal/backend/remote-state/s3/backend_test.go index 4ab43bf61e..228ba3e407 100644 --- a/internal/backend/remote-state/s3/backend_test.go +++ b/internal/backend/remote-state/s3/backend_test.go @@ -1328,7 +1328,7 @@ func TestBackendConfig_PrepareConfigWithEnvVars(t *testing.T) { } } -func TestBackend(t *testing.T) { +func TestBackendBasic(t *testing.T) { testACC(t) ctx := context.TODO() diff --git a/internal/backend/remote-state/s3/client.go b/internal/backend/remote-state/s3/client.go index 8bdcab79ab..bba1c0fb6b 100644 --- a/internal/backend/remote-state/s3/client.go +++ b/internal/backend/remote-state/s3/client.go @@ -21,6 +21,7 @@ import ( dynamodbtypes "github.com/aws/aws-sdk-go-v2/service/dynamodb/types" "github.com/aws/aws-sdk-go-v2/service/s3" s3types "github.com/aws/aws-sdk-go-v2/service/s3/types" + baselogging "github.com/hashicorp/aws-sdk-go-base/v2/logging" multierror "github.com/hashicorp/go-multierror" uuid "github.com/hashicorp/go-uuid" "github.com/hashicorp/terraform/internal/states/remote" @@ -61,6 +62,15 @@ var testChecksumHook func() func (c *RemoteClient) Get() (payload *remote.Payload, err error) { ctx := context.TODO() + log := logger() + log = log.With( + "tf_backend_s3.bucket", c.bucketName, + "tf_backend_s3.path", c.path, + ) + ctx, baselog := baselogging.NewHcLogger(ctx, log) + ctx = baselogging.RegisterLogger(ctx, baselog) + + log.Info("Downloading remote state") deadline := time.Now().Add(consistencyRetryTimeout) @@ -82,9 +92,14 @@ func (c *RemoteClient) Get() (payload *remote.Payload, err error) { // verify that this state is what we expect if expected, err := c.getMD5(ctx); err != nil { - log.Printf("[WARN] failed to fetch state md5: %s", err) + log.Warn("failed to fetch state MD5", + "error", err, + ) } else if len(expected) > 0 && !bytes.Equal(expected, digest) { - log.Printf("[WARN] state md5 mismatch: expected '%x', got '%x'", expected, digest) + log.Warn("state MD5 mismatch", + "expected", expected, + "actual", digest, + ) if testChecksumHook != nil { testChecksumHook() @@ -92,7 +107,7 @@ func (c *RemoteClient) Get() (payload *remote.Payload, err error) { if time.Now().Before(deadline) { time.Sleep(consistencyRetryPollInterval) - log.Println("[INFO] retrying S3 RemoteClient.Get...") + log.Info("retrying S3 RemoteClient.Get") continue } @@ -170,6 +185,13 @@ func (c *RemoteClient) get(ctx context.Context) (*remote.Payload, error) { func (c *RemoteClient) Put(data []byte) error { ctx := context.TODO() + log := logger() + log = log.With( + "tf_backend_s3.bucket", c.bucketName, + "tf_backend_s3.path", c.path, + ) + ctx, baselog := baselogging.NewHcLogger(ctx, log) + ctx = baselogging.RegisterLogger(ctx, baselog) contentType := "application/json" @@ -197,7 +219,7 @@ func (c *RemoteClient) Put(data []byte) error { input.ACL = s3types.ObjectCannedACL(c.acl) } - log.Printf("[DEBUG] Uploading remote state to S3: %#v", input) + log.Info("Uploading remote state") uploader := manager.NewUploader(c.s3Client) _, err := uploader.Upload(ctx, input) @@ -217,6 +239,13 @@ func (c *RemoteClient) Put(data []byte) error { func (c *RemoteClient) Delete() error { ctx := context.TODO() + log := logger() + log = log.With( + "tf_backend_s3.bucket", c.bucketName, + "tf_backend_s3.path", c.path, + ) + ctx, baselog := baselogging.NewHcLogger(ctx, log) + ctx = baselogging.RegisterLogger(ctx, baselog) _, err := c.s3Client.DeleteObject(ctx, &s3.DeleteObjectInput{ Bucket: aws.String(c.bucketName), @@ -228,7 +257,9 @@ func (c *RemoteClient) Delete() error { } if err := c.deleteMD5(ctx); err != nil { - log.Printf("error deleting state md5: %s", err) + log.Error("deleting state MD5", + "error", err, + ) } return nil From 2a9779574d10a5943764195be71c4d265b295558 Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Thu, 7 Sep 2023 17:46:51 -0700 Subject: [PATCH 2/7] Centralizes remote client logger configuration --- internal/backend/remote-state/s3/client.go | 27 ++++++++++------------ 1 file changed, 12 insertions(+), 15 deletions(-) diff --git a/internal/backend/remote-state/s3/client.go b/internal/backend/remote-state/s3/client.go index bba1c0fb6b..f3fd1bed90 100644 --- a/internal/backend/remote-state/s3/client.go +++ b/internal/backend/remote-state/s3/client.go @@ -22,6 +22,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/s3" s3types "github.com/aws/aws-sdk-go-v2/service/s3/types" baselogging "github.com/hashicorp/aws-sdk-go-base/v2/logging" + "github.com/hashicorp/go-hclog" multierror "github.com/hashicorp/go-multierror" uuid "github.com/hashicorp/go-uuid" "github.com/hashicorp/terraform/internal/states/remote" @@ -62,11 +63,7 @@ var testChecksumHook func() func (c *RemoteClient) Get() (payload *remote.Payload, err error) { ctx := context.TODO() - log := logger() - log = log.With( - "tf_backend_s3.bucket", c.bucketName, - "tf_backend_s3.path", c.path, - ) + log := c.logger() ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -185,11 +182,7 @@ func (c *RemoteClient) get(ctx context.Context) (*remote.Payload, error) { func (c *RemoteClient) Put(data []byte) error { ctx := context.TODO() - log := logger() - log = log.With( - "tf_backend_s3.bucket", c.bucketName, - "tf_backend_s3.path", c.path, - ) + log := c.logger() ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -239,11 +232,7 @@ func (c *RemoteClient) Put(data []byte) error { func (c *RemoteClient) Delete() error { ctx := context.TODO() - log := logger() - log = log.With( - "tf_backend_s3.bucket", c.bucketName, - "tf_backend_s3.path", c.path, - ) + log := c.logger() ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -481,6 +470,14 @@ func (c *RemoteClient) getSSECustomerKeyMD5() string { return base64.StdEncoding.EncodeToString(b[:]) } +// logger returns the S3 backend logger configured with the client's bucket and path +func (c *RemoteClient) logger() hclog.Logger { + return logger().With( + "tf_backend_s3.bucket", c.bucketName, + "tf_backend_s3.path", c.path, + ) +} + const errBadChecksumFmt = `state data in S3 does not have the expected content. This may be caused by unusually long delays in S3 processing a previous state From 61ba05b77b954733cbc851675521eb3320d84911 Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Fri, 8 Sep 2023 10:30:37 -0700 Subject: [PATCH 3/7] Adds logging for DynamoDB operations --- internal/backend/remote-state/s3/backend.go | 4 +- internal/backend/remote-state/s3/client.go | 105 ++++++++++++-------- internal/backend/remote-state/s3/logging.go | 37 +++++++ 3 files changed, 101 insertions(+), 45 deletions(-) create mode 100644 internal/backend/remote-state/s3/logging.go diff --git a/internal/backend/remote-state/s3/backend.go b/internal/backend/remote-state/s3/backend.go index 64b4661e72..1fecc86b3c 100644 --- a/internal/backend/remote-state/s3/backend.go +++ b/internal/backend/remote-state/s3/backend.go @@ -635,8 +635,8 @@ func (b *Backend) Configure(obj cty.Value) tfdiags.Diagnostics { b.keyName = stringAttr(obj, "key") log = log.With( - "tf_backend_s3.bucket", b.bucketName, - "tf_backend_s3.path", b.path, + logKeyBucket, b.bucketName, + logKeyPath, b.keyName, ) b.acl = stringAttr(obj, "acl") diff --git a/internal/backend/remote-state/s3/client.go b/internal/backend/remote-state/s3/client.go index f3fd1bed90..8a06f45450 100644 --- a/internal/backend/remote-state/s3/client.go +++ b/internal/backend/remote-state/s3/client.go @@ -183,6 +183,7 @@ func (c *RemoteClient) get(ctx context.Context) (*remote.Payload, error) { func (c *RemoteClient) Put(data []byte) error { ctx := context.TODO() log := c.logger() + ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -233,9 +234,12 @@ func (c *RemoteClient) Put(data []byte) error { func (c *RemoteClient) Delete() error { ctx := context.TODO() log := c.logger() + ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) + log.Info("Deleting remote state") + _, err := c.s3Client.DeleteObject(ctx, &s3.DeleteObjectInput{ Bucket: aws.String(c.bucketName), Key: aws.String(c.path), @@ -256,6 +260,7 @@ func (c *RemoteClient) Delete() error { func (c *RemoteClient) Lock(info *statemgr.LockInfo) (string, error) { ctx := context.TODO() + log := c.logger() if c.ddbTable == "" { return "", nil @@ -272,6 +277,12 @@ func (c *RemoteClient) Lock(info *statemgr.LockInfo) (string, error) { info.ID = lockID } + log = logWithLockInfo(log, info) + ctx, baselog := baselogging.NewHcLogger(ctx, log) + ctx = baselogging.RegisterLogger(ctx, baselog) + + log.Info("Locking remote state") + putParams := &dynamodb.PutItemInput{ Item: map[string]dynamodbtypes.AttributeValue{ "LockID": &dynamodbtypes.AttributeValueMemberS{ @@ -302,6 +313,55 @@ func (c *RemoteClient) Lock(info *statemgr.LockInfo) (string, error) { return info.ID, nil } +func (c *RemoteClient) Unlock(id string) error { + ctx := context.TODO() + log := c.logger() + + log = logWithLockID(log, id) + + ctx, baselog := baselogging.NewHcLogger(ctx, log) + ctx = baselogging.RegisterLogger(ctx, baselog) + + if c.ddbTable == "" { + return nil + } + + lockErr := &statemgr.LockError{} + + log.Info("Unlocking remote state") + + // TODO: store the path and lock ID in separate fields, and have proper + // projection expression only delete the lock if both match, rather than + // checking the ID from the info field first. + lockInfo, err := c.getLockInfo(ctx) + if err != nil { + lockErr.Err = fmt.Errorf("failed to retrieve lock info for lock ID %q: %s", id, err) + return lockErr + } + lockErr.Info = lockInfo + + if lockInfo.ID != id { + lockErr.Err = fmt.Errorf("lock ID %q does not match existing lock (%q)", id, lockInfo.ID) + return lockErr + } + + params := &dynamodb.DeleteItemInput{ + Key: map[string]dynamodbtypes.AttributeValue{ + "LockID": &dynamodbtypes.AttributeValueMemberS{ + Value: c.lockPath(), + }, + }, + TableName: aws.String(c.ddbTable), + } + _, err = c.dynClient.DeleteItem(ctx, params) + + if err != nil { + lockErr.Err = err + return lockErr + } + return nil +} + func (c *RemoteClient) getMD5(ctx context.Context) ([]byte, error) { if c.ddbTable == "" { return nil, nil @@ -420,47 +480,6 @@ func (c *RemoteClient) getLockInfo(ctx context.Context) (*statemgr.LockInfo, err return lockInfo, nil } -func (c *RemoteClient) Unlock(id string) error { - ctx := context.TODO() - - if c.ddbTable == "" { - return nil - } - - lockErr := &statemgr.LockError{} - - // TODO: store the path and lock ID in separate fields, and have proper - // projection expression only delete the lock if both match, rather than - // checking the ID from the info field first. - lockInfo, err := c.getLockInfo(ctx) - if err != nil { - lockErr.Err = fmt.Errorf("failed to retrieve lock info: %s", err) - return lockErr - } - lockErr.Info = lockInfo - - if lockInfo.ID != id { - lockErr.Err = fmt.Errorf("lock id %q does not match existing lock", id) - return lockErr - } - - params := &dynamodb.DeleteItemInput{ - Key: map[string]dynamodbtypes.AttributeValue{ - "LockID": &dynamodbtypes.AttributeValueMemberS{ - Value: c.lockPath(), - }, - }, - TableName: aws.String(c.ddbTable), - } - _, err = c.dynClient.DeleteItem(ctx, params) - - if err != nil { - lockErr.Err = err - return lockErr - } - return nil -} - func (c *RemoteClient) lockPath() string { return fmt.Sprintf("%s/%s", c.bucketName, c.path) } @@ -473,8 +492,8 @@ func (c *RemoteClient) getSSECustomerKeyMD5() string { // logger returns the S3 backend logger configured with the client's bucket and path func (c *RemoteClient) logger() hclog.Logger { return logger().With( - "tf_backend_s3.bucket", c.bucketName, - "tf_backend_s3.path", c.path, + logKeyBucket, c.bucketName, + logKeyPath, c.path, ) } diff --git a/internal/backend/remote-state/s3/logging.go b/internal/backend/remote-state/s3/logging.go new file mode 100644 index 0000000000..fe765e3e23 --- /dev/null +++ b/internal/backend/remote-state/s3/logging.go @@ -0,0 +1,37 @@ +package s3 + +import ( + "github.com/hashicorp/go-hclog" + "github.com/hashicorp/terraform/internal/states/statemgr" +) + +const ( + logKeyBucket = "tf_backend.s3.bucket" + logKeyPath = "tf_backend.s3.path" +) + +const ( + logKeyBackendLockId = "tf_backend.lock.id" + logKeyBackendLockOperation = "tf_backend.lock.operation" + logKeyBackendLockInfo = "tf_backend.lock.info" + logKeyBackendLockWho = "tf_backend.lock.who" + logKeyBackendLockVersion = "tf_backend.lock.version" + logKeyBackendLockPath = "tf_backend.lock.path" +) + +func logWithLockInfo(in hclog.Logger, info *statemgr.LockInfo) hclog.Logger { + return in.With( + logKeyBackendLockId, info.ID, + logKeyBackendLockOperation, info.Operation, + logKeyBackendLockInfo, info.Info, + logKeyBackendLockWho, info.Who, + logKeyBackendLockVersion, info.Version, + logKeyBackendLockPath, info.Path, + ) +} + +func logWithLockID(in hclog.Logger, id string) hclog.Logger { + return in.With( + logKeyBackendLockId, id, + ) +} From f2ef4e155f195c49c36900a57b1b475a24b20fda Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Fri, 8 Sep 2023 10:58:34 -0700 Subject: [PATCH 4/7] Adds `tf_backend.operation` log key --- internal/backend/remote-state/s3/backend.go | 9 +---- internal/backend/remote-state/s3/client.go | 18 +++++----- internal/backend/remote-state/s3/logging.go | 38 +++++++++++++++++++++ 3 files changed, 49 insertions(+), 16 deletions(-) diff --git a/internal/backend/remote-state/s3/backend.go b/internal/backend/remote-state/s3/backend.go index 1fecc86b3c..2474f19df1 100644 --- a/internal/backend/remote-state/s3/backend.go +++ b/internal/backend/remote-state/s3/backend.go @@ -11,7 +11,6 @@ import ( "regexp" "sort" "strings" - "sync" "time" "github.com/aws/aws-sdk-go-v2/aws" @@ -20,10 +19,8 @@ import ( "github.com/aws/aws-sdk-go-v2/service/s3" awsbase "github.com/hashicorp/aws-sdk-go-base/v2" baselogging "github.com/hashicorp/aws-sdk-go-base/v2/logging" - "github.com/hashicorp/go-hclog" "github.com/hashicorp/terraform/internal/backend" "github.com/hashicorp/terraform/internal/configs/configschema" - "github.com/hashicorp/terraform/internal/logging" "github.com/hashicorp/terraform/internal/tfdiags" "github.com/hashicorp/terraform/version" "github.com/zclconf/go-cty/cty" @@ -608,6 +605,7 @@ func formatDeprecations(attrs map[string]string) string { func (b *Backend) Configure(obj cty.Value) tfdiags.Diagnostics { ctx := context.TODO() log := logger() + log = logWithOperation(log, operationBackendConfigure) var diags tfdiags.Diagnostics if obj.IsNull() { @@ -1648,8 +1646,3 @@ func deprecatedEnvVarDiag(envvar, replacement string) tfdiags.Diagnostic { fmt.Sprintf(`The environment variable "%s" is deprecated. Use environment variable "%s" instead.`, envvar, replacement), ) } - -var logger = sync.OnceValue(func() hclog.Logger { - l := logging.HCLogger() - return l.Named("backend-s3") -}) diff --git a/internal/backend/remote-state/s3/client.go b/internal/backend/remote-state/s3/client.go index 8a06f45450..d49cfe387c 100644 --- a/internal/backend/remote-state/s3/client.go +++ b/internal/backend/remote-state/s3/client.go @@ -63,7 +63,8 @@ var testChecksumHook func() func (c *RemoteClient) Get() (payload *remote.Payload, err error) { ctx := context.TODO() - log := c.logger() + log := c.logger(operationClientGet) + ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -182,7 +183,7 @@ func (c *RemoteClient) get(ctx context.Context) (*remote.Payload, error) { func (c *RemoteClient) Put(data []byte) error { ctx := context.TODO() - log := c.logger() + log := c.logger(operationClientPut) ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -233,7 +234,7 @@ func (c *RemoteClient) Put(data []byte) error { func (c *RemoteClient) Delete() error { ctx := context.TODO() - log := c.logger() + log := c.logger(operationClientDelete) ctx, baselog := baselogging.NewHcLogger(ctx, log) ctx = baselogging.RegisterLogger(ctx, baselog) @@ -260,7 +261,7 @@ func (c *RemoteClient) Delete() error { func (c *RemoteClient) Lock(info *statemgr.LockInfo) (string, error) { ctx := context.TODO() - log := c.logger() + log := c.logger(operationLockerLock) if c.ddbTable == "" { return "", nil @@ -315,7 +316,7 @@ func (c *RemoteClient) Lock(info *statemgr.LockInfo) (string, error) { func (c *RemoteClient) Unlock(id string) error { ctx := context.TODO() - log := c.logger() + log := c.logger(operationLockerUnlock) log = logWithLockID(log, id) @@ -489,12 +490,13 @@ func (c *RemoteClient) getSSECustomerKeyMD5() string { return base64.StdEncoding.EncodeToString(b[:]) } -// logger returns the S3 backend logger configured with the client's bucket and path -func (c *RemoteClient) logger() hclog.Logger { - return logger().With( +// logger returns the S3 backend logger configured with the client's bucket and path and the operation +func (c *RemoteClient) logger(operation string) hclog.Logger { + log := logger().With( logKeyBucket, c.bucketName, logKeyPath, c.path, ) + return logWithOperation(log, operation) } const errBadChecksumFmt = `state data in S3 does not have the expected content. diff --git a/internal/backend/remote-state/s3/logging.go b/internal/backend/remote-state/s3/logging.go index fe765e3e23..8dc54b7727 100644 --- a/internal/backend/remote-state/s3/logging.go +++ b/internal/backend/remote-state/s3/logging.go @@ -1,7 +1,10 @@ package s3 import ( + "sync" + "github.com/hashicorp/go-hclog" + "github.com/hashicorp/terraform/internal/logging" "github.com/hashicorp/terraform/internal/states/statemgr" ) @@ -19,6 +22,41 @@ const ( logKeyBackendLockPath = "tf_backend.lock.path" ) +const ( + logKeyBackendOperation = "tf_backend.operation" +) + +const ( + operationBackendConfigSchema = "ConfigSchema" + operationBackendPrepareConfig = "PrepareConfig" + operationBackendConfigure = "Configure" + operationBackendStateMgr = "StateMgr" + operationBackendDeleteWorkspace = "DeleteWorkspace" + operationBackendWorkspaces = "Workspaces" +) + +const ( + operationClientGet = "Get" + operationClientPut = "Put" + operationClientDelete = "Delete" +) + +const ( + operationLockerLock = "Lock" + operationLockerUnlock = "Unlock" +) + +var logger = sync.OnceValue(func() hclog.Logger { + l := logging.HCLogger() + return l.Named("backend-s3") +}) + +func logWithOperation(in hclog.Logger, operation string) hclog.Logger { + return in.With( + logKeyBackendOperation, operation, + ) +} + func logWithLockInfo(in hclog.Logger, info *statemgr.LockInfo) hclog.Logger { return in.With( logKeyBackendLockId, info.ID, From dac8d5935faff8521fec22170475c5fa1c3abc1b Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Fri, 8 Sep 2023 11:58:01 -0700 Subject: [PATCH 5/7] Adds logging for workspace handling --- .../backend/remote-state/s3/backend_state.go | 21 +++++++++++++++++++ internal/backend/remote-state/s3/logging.go | 14 ++++++++----- 2 files changed, 30 insertions(+), 5 deletions(-) diff --git a/internal/backend/remote-state/s3/backend_state.go b/internal/backend/remote-state/s3/backend_state.go index fb8e780422..81c523951b 100644 --- a/internal/backend/remote-state/s3/backend_state.go +++ b/internal/backend/remote-state/s3/backend_state.go @@ -15,6 +15,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/s3" s3types "github.com/aws/aws-sdk-go-v2/service/s3/types" + baselogging "github.com/hashicorp/aws-sdk-go-base/v2/logging" "github.com/hashicorp/terraform/internal/backend" "github.com/hashicorp/terraform/internal/states" "github.com/hashicorp/terraform/internal/states/remote" @@ -25,6 +26,11 @@ func (b *Backend) Workspaces() ([]string, error) { const maxKeys = 1000 ctx := context.TODO() + log := logger() + log = logWithOperation(log, operationBackendWorkspaces) + log = log.With( + logKeyBucket, b.bucketName, + ) prefix := "" @@ -32,6 +38,10 @@ func (b *Backend) Workspaces() ([]string, error) { prefix = b.workspaceKeyPrefix + "/" } + log = log.With( + logKeyBackendWorkspacePrefix, prefix, + ) + params := &s3.ListObjectsV2Input{ Bucket: aws.String(b.bucketName), Prefix: aws.String(prefix), @@ -40,6 +50,9 @@ func (b *Backend) Workspaces() ([]string, error) { wss := []string{backend.DefaultStateName} + ctx, baselog := baselogging.NewHcLogger(ctx, log) + ctx = baselogging.RegisterLogger(ctx, baselog) + pages := s3.NewListObjectsV2Paginator(b.s3Client, params) for pages.HasMorePages() { page, err := pages.NextPage(ctx) @@ -102,10 +115,18 @@ func (b *Backend) keyEnv(key string) string { } func (b *Backend) DeleteWorkspace(name string, _ bool) error { + log := logger() + log = logWithOperation(log, operationBackendDeleteWorkspace) + log = log.With( + logKeyBackendWorkspace, name, + ) + if name == backend.DefaultStateName || name == "" { return fmt.Errorf("can't delete default state") } + log.Info("Deleting workspace") + client, err := b.remoteClient(name) if err != nil { return err diff --git a/internal/backend/remote-state/s3/logging.go b/internal/backend/remote-state/s3/logging.go index 8dc54b7727..14259a674f 100644 --- a/internal/backend/remote-state/s3/logging.go +++ b/internal/backend/remote-state/s3/logging.go @@ -4,6 +4,7 @@ import ( "sync" "github.com/hashicorp/go-hclog" + "github.com/hashicorp/go-uuid" "github.com/hashicorp/terraform/internal/logging" "github.com/hashicorp/terraform/internal/states/statemgr" ) @@ -23,14 +24,17 @@ const ( ) const ( - logKeyBackendOperation = "tf_backend.operation" + logKeyBackendOperation = "tf_backend.operation" + logKeyBackendRequestId = "tf_backend.req_id" // Using "req_id" to match pattern for provider logging + logKeyBackendWorkspace = "tf_backend.workspace" + logKeyBackendWorkspacePrefix = "tf_backend.workspace-prefix" ) const ( - operationBackendConfigSchema = "ConfigSchema" - operationBackendPrepareConfig = "PrepareConfig" - operationBackendConfigure = "Configure" - operationBackendStateMgr = "StateMgr" + // operationBackendConfigSchema = "ConfigSchema" + // operationBackendPrepareConfig = "PrepareConfig" + operationBackendConfigure = "Configure" + // operationBackendStateMgr = "StateMgr" operationBackendDeleteWorkspace = "DeleteWorkspace" operationBackendWorkspaces = "Workspaces" ) From 3caaa1310586909717b6705de7ff784cdd7c6f62 Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Fri, 8 Sep 2023 11:58:19 -0700 Subject: [PATCH 6/7] Adds request ID for operations --- internal/backend/remote-state/s3/logging.go | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/internal/backend/remote-state/s3/logging.go b/internal/backend/remote-state/s3/logging.go index 14259a674f..3be54cae8f 100644 --- a/internal/backend/remote-state/s3/logging.go +++ b/internal/backend/remote-state/s3/logging.go @@ -56,9 +56,16 @@ var logger = sync.OnceValue(func() hclog.Logger { }) func logWithOperation(in hclog.Logger, operation string) hclog.Logger { - return in.With( + log := in.With( logKeyBackendOperation, operation, ) + if id, err := uuid.GenerateUUID(); err == nil { + log = log.With( + logKeyBackendRequestId, id, + ) + + } + return log } func logWithLockInfo(in hclog.Logger, info *statemgr.LockInfo) hclog.Logger { From 85f68bcbde078e302337b033d792e2d5290332d7 Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Fri, 8 Sep 2023 12:39:56 -0700 Subject: [PATCH 7/7] Adds missing copyright header --- internal/backend/remote-state/s3/logging.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/internal/backend/remote-state/s3/logging.go b/internal/backend/remote-state/s3/logging.go index 3be54cae8f..956ecc650a 100644 --- a/internal/backend/remote-state/s3/logging.go +++ b/internal/backend/remote-state/s3/logging.go @@ -1,3 +1,6 @@ +// Copyright (c) HashiCorp, Inc. +// SPDX-License-Identifier: BUSL-1.1 + package s3 import (