From 79ab6bb6ec2e8dfcfada2e526fcd75fce5f2b000 Mon Sep 17 00:00:00 2001 From: Paddy Carver Date: Mon, 13 Dec 2021 10:25:25 -0800 Subject: [PATCH] Introduce some logging. Start logging using tflog. This largely just inserts logging at decision points in the serve.go file of tfsdk, which is where the most invisible, impactful decisions are made. Over time, logging should be introduced in more places on an as-needed basis or as we touch those parts of the code. Fixes #63. --- go.mod | 10 +++++++--- go.sum | 23 +++++++++++++++++++---- tfsdk/serve.go | 19 +++++++++++++++++-- 3 files changed, 43 insertions(+), 9 deletions(-) diff --git a/go.mod b/go.mod index 8f920c0c4..f0ef7fbfa 100644 --- a/go.mod +++ b/go.mod @@ -5,18 +5,22 @@ go 1.17 require ( github.com/google/go-cmp v0.5.6 github.com/hashicorp/terraform-plugin-go v0.4.0 + github.com/hashicorp/terraform-plugin-log v0.2.0 ) require ( + github.com/fatih/color v1.7.0 // indirect github.com/golang/protobuf v1.4.2 // indirect - github.com/hashicorp/go-hclog v0.0.0-20180709165350-ff2cf002a8dd // indirect + github.com/hashicorp/go-hclog v0.16.1 // indirect github.com/hashicorp/go-plugin v1.3.0 // indirect github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb // indirect - github.com/mitchellh/go-testing-interface v0.0.0-20171004221916-a61a99592b77 // indirect + github.com/mattn/go-colorable v0.1.4 // indirect + github.com/mattn/go-isatty v0.0.10 // indirect + github.com/mitchellh/go-testing-interface v1.14.1 // indirect github.com/oklog/run v1.0.0 // indirect github.com/vmihailenco/msgpack v4.0.4+incompatible // indirect golang.org/x/net v0.0.0-20200301022130-244492dfa37a // indirect - golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a // indirect + golang.org/x/sys v0.0.0-20191008105621-543471e840be // indirect golang.org/x/text v0.3.2 // indirect golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543 // indirect google.golang.org/appengine v1.6.5 // indirect diff --git a/go.sum b/go.sum index 7c8e2cec1..0ca071bf9 100644 --- a/go.sum +++ b/go.sum @@ -3,12 +3,15 @@ github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03 github.com/census-instrumentation/opencensus-proto v0.2.1/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU= github.com/client9/misspell v0.3.4/go.mod h1:qj6jICC3Q7zFZvVWo7KLAzC3yx5G7kyvSDkc90ppPyw= github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGXZJjfX53e64911xZQV5JYwmTeXPW+k8Sc= -github.com/davecgh/go-spew v1.1.0 h1:ZDRjVQ15GmhC3fiQ8ni8+OwkZQO4DARzQgrnXU1Liz8= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/envoyproxy/go-control-plane v0.9.0/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymFceY/DCBVvsKhRF0iEA4= github.com/envoyproxy/go-control-plane v0.9.1-0.20191026205805-5f8ba28d4473/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymFceY/DCBVvsKhRF0iEA4= github.com/envoyproxy/go-control-plane v0.9.4/go.mod h1:6rpuAdCZL397s3pYoYcLgu1mIlRU8Am5FuJP05cCM98= github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c= +github.com/fatih/color v1.7.0 h1:DkWD4oS2D8LGGgTQ6IvwJJXSL5Vp2ffcQg58nFV38Ys= +github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5KwzbycvMj4= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= github.com/golang/mock v1.1.1/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfbm0A= github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U= @@ -30,12 +33,15 @@ github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/ github.com/google/go-cmp v0.5.2/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.6 h1:BKbKCqvP6I+rmFHt06ZmyQtvB8xAkWdhFyr0ZUNZcxQ= github.com/google/go-cmp v0.5.6/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= -github.com/hashicorp/go-hclog v0.0.0-20180709165350-ff2cf002a8dd h1:rNuUHR+CvK1IS89MMtcF0EpcVMZtjKfPRp4MEmt/aTs= github.com/hashicorp/go-hclog v0.0.0-20180709165350-ff2cf002a8dd/go.mod h1:9bjs9uLqI8l75knNv3lV1kA55veR+WUPSiKIWcQHudI= +github.com/hashicorp/go-hclog v0.16.1 h1:IVQwpTGNRRIHafnTs2dQLIk4ENtneRIEEJWOVDqz99o= +github.com/hashicorp/go-hclog v0.16.1/go.mod h1:whpDNt7SSdeAju8AWKIWsul05p54N/39EeqMAyrmvFQ= github.com/hashicorp/go-plugin v1.3.0 h1:4d/wJojzvHV1I4i/rrjVaeuyxWrLzDE1mDCyDy8fXS8= github.com/hashicorp/go-plugin v1.3.0/go.mod h1:F9eH4LrE/ZsRdbwhfjs9k9HoDUwAHnYtXdgmf1AVNs0= github.com/hashicorp/terraform-plugin-go v0.4.0 h1:LFbXNeLDo0J/wR0kUzSPq0RpdmFh2gNedzU0n/gzPAo= github.com/hashicorp/terraform-plugin-go v0.4.0/go.mod h1:7u/6nt6vaiwcWE2GuJKbJwNlDFnf5n95xKw4hqIVr58= +github.com/hashicorp/terraform-plugin-log v0.2.0 h1:rjflRuBqCnSk3UHOR25MP1G5BDLKktTA6lNjjcAnBfI= +github.com/hashicorp/terraform-plugin-log v0.2.0/go.mod h1:E1kJmapEHzqu1x6M++gjvhzM2yMQNXPVWZRCB8sgYjg= github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb h1:b5rjCoWHc7eqmAS4/qyk21ZsHyb6Mxv/jykxvNTkU4M= github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb/go.mod h1:+NfK9FKeTrX5uv1uIXGdwYDTeHna2qgaIlx54MXqjAM= github.com/jhump/protoreflect v1.6.0 h1:h5jfMVslIg6l29nsMs0D8Wj17RDVdNYti0vDN/PZZoE= @@ -45,8 +51,14 @@ github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORN github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= -github.com/mitchellh/go-testing-interface v0.0.0-20171004221916-a61a99592b77 h1:7GoSOOW2jpsfkntVKaS2rAr1TJqfcxotyaUcuxoZSzg= +github.com/mattn/go-colorable v0.1.4 h1:snbPLB8fVfU9iwbbo30TPtbLRzwWu6aJS6Xh4eaaviA= +github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE= +github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= +github.com/mattn/go-isatty v0.0.10 h1:qxFzApOv4WsAL965uUPIsXzAKCZxN2p9UqdhFS4ZW10= +github.com/mattn/go-isatty v0.0.10/go.mod h1:qgIWMr58cqv1PHHyhnkY9lrL7etaEgOFcMEpPG5Rm84= github.com/mitchellh/go-testing-interface v0.0.0-20171004221916-a61a99592b77/go.mod h1:kRemZodwjscx+RGhAo8eIhFbs2+BFgRtFPeD/KE+zxI= +github.com/mitchellh/go-testing-interface v1.14.1 h1:jrgshOhYAUVNMAJiKbEu7EqAwgJJ2JqpQmpLJOu07cU= +github.com/mitchellh/go-testing-interface v1.14.1/go.mod h1:gfgS7OtZj6MA4U1UrDRp04twqAjfvlZyCfX3sDjEym8= github.com/nsf/jsondiff v0.0.0-20200515183724-f29ed568f4ce h1:RPclfga2SEJmgMmz2k+Mg7cowZ8yv4Trqw9UsJby758= github.com/nsf/jsondiff v0.0.0-20200515183724-f29ed568f4ce/go.mod h1:uFMI8w+ref4v2r9jz+c9i1IfIttS/OkmLfrk1jne5hs= github.com/oklog/run v1.0.0 h1:Ru7dDtJNOyC66gQ5dQmaCa0qIsAUFY3sFpK1Xk8igrw= @@ -55,6 +67,7 @@ github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZb github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0 h1:TivCn/peBQ7UY8ooIcPgZFpTNSz0Q2U6UrFlUfqbe0Q= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/vmihailenco/msgpack v4.0.4+incompatible h1:dSLoQfGFAo3F6OoNhwUmLwVgaUXK79GlxNBwueZn0xI= @@ -77,8 +90,10 @@ golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sys v0.0.0-20180830151530-49385e6e1522/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a h1:1BGLXjeY4akVXGgbC9HugT3Jv3hCI0z56oJR5vAMgBU= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20191008105621-543471e840be h1:QAcqgptGM8IQBC9K/RC4o+O9YmqEm0diQn9QmZw/0mU= +golang.org/x/sys v0.0.0-20191008105621-543471e840be/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.2 h1:tW2bmiBqwgJj/UpqtC8EpXEZVYOwU0yG4iWbprSVAcs= golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk= diff --git a/tfsdk/serve.go b/tfsdk/serve.go index 97ea27a97..28b68cf06 100644 --- a/tfsdk/serve.go +++ b/tfsdk/serve.go @@ -12,6 +12,7 @@ import ( "github.com/hashicorp/terraform-plugin-go/tfprotov6" "github.com/hashicorp/terraform-plugin-go/tfprotov6/tf6server" "github.com/hashicorp/terraform-plugin-go/tftypes" + "github.com/hashicorp/terraform-plugin-log/tfsdklog" ) var _ tfprotov6.ProviderServer = &server{} @@ -592,21 +593,27 @@ func markComputedNilsAsUnknown(ctx context.Context, config tftypes.Value, resour } configVal, _, err := tftypes.WalkAttributePath(config, path) if err != tftypes.ErrInvalidStep && err != nil { + tfsdklog.Error(ctx, "error walking attribute path", "path", path) return val, err } else if err != tftypes.ErrInvalidStep && !configVal.(tftypes.Value).IsNull() { + tfsdklog.Trace(ctx, "attribute not null in config, not marking unknown", "path", path) return val, nil } attribute, err := resourceSchema.AttributeAtPath(path) if err != nil { if errors.Is(err, ErrPathInsideAtomicAttribute) { // ignore attributes/elements inside schema.Attributes, they have no schema of their own + tfsdklog.Trace(ctx, "attribute is a non-schema attribute, not marking unknown", "path", path) return val, nil } + tfsdklog.Error(ctx, "couldn't find attribute in resource schema", "path", path) return tftypes.Value{}, fmt.Errorf("couldn't find attribute in resource schema: %w", err) } if !attribute.Computed { + tfsdklog.Trace(ctx, "attribute is not computed in schema, not marking unknown", "path", path) return val, nil } + tfsdklog.Debug(ctx, "marking computed attribute that is null in the config as unknown", "path", path) return tftypes.NewValue(val.Type(), tftypes.UnknownValue), nil } } @@ -742,6 +749,7 @@ func (s *server) planResourceChange(ctx context.Context, req *tfprotov6.PlanReso // We only do this if there's a plan to modify; otherwise, it // represents a resource being deleted and there's no point. if !plan.IsNull() && !plan.Equal(state) { + tfsdklog.Trace(ctx, "marking computed null values as unknown") modifiedPlan, err := tftypes.Transform(plan, markComputedNilsAsUnknown(ctx, config, resourceSchema)) if err != nil { resp.Diagnostics.AddError( @@ -750,6 +758,9 @@ func (s *server) planResourceChange(ctx context.Context, req *tfprotov6.PlanReso ) return } + if !plan.Equal(modifiedPlan) { + tfsdklog.Trace(ctx, "at least one value was changed to unknown") + } plan = modifiedPlan } @@ -889,7 +900,7 @@ func (s *server) planResourceChange(ctx context.Context, req *tfprotov6.PlanReso resp.RequiresReplace = append(resp.RequiresReplace, modifyPlanResp.RequiresReplace...) // ensure deterministic RequiresReplace by sorting and deduplicating - resp.RequiresReplace = normaliseRequiresReplace(resp.RequiresReplace) + resp.RequiresReplace = normaliseRequiresReplace(ctx, resp.RequiresReplace) } // applyResourceChangeResponse is a thin abstraction to allow native Diagnostics usage @@ -910,7 +921,7 @@ func (r applyResourceChangeResponse) toTfprotov6() *tfprotov6.ApplyResourceChang // normaliseRequiresReplace sorts and deduplicates the slice of AttributePaths // used in the RequiresReplace response field. // Sorting is lexical based on the string representation of each AttributePath. -func normaliseRequiresReplace(rs []*tftypes.AttributePath) []*tftypes.AttributePath { +func normaliseRequiresReplace(ctx context.Context, rs []*tftypes.AttributePath) []*tftypes.AttributePath { if len(rs) < 2 { return rs } @@ -926,6 +937,7 @@ func normaliseRequiresReplace(rs []*tftypes.AttributePath) []*tftypes.AttributeP j := 1 for i := 1; i < len(rs); i++ { if rs[i].Equal(ret[j-1]) { + tfsdklog.Debug(ctx, "attribute found multiple times in RequiresReplace, removing duplicate", "path", rs[i]) continue } ret[j] = rs[i] @@ -1027,6 +1039,7 @@ func (s *server) applyResourceChange(ctx context.Context, req *tfprotov6.ApplyRe switch { case create && !update && !destroy: + tfsdklog.Trace(ctx, "running create") createReq := CreateResourceRequest{ Config: Config{ Schema: resourceSchema, @@ -1079,6 +1092,7 @@ func (s *server) applyResourceChange(ctx context.Context, req *tfprotov6.ApplyRe } resp.NewState = &newState case !create && update && !destroy: + tfsdklog.Trace(ctx, "running update") updateReq := UpdateResourceRequest{ Config: Config{ Schema: resourceSchema, @@ -1135,6 +1149,7 @@ func (s *server) applyResourceChange(ctx context.Context, req *tfprotov6.ApplyRe } resp.NewState = &newState case !create && !update && destroy: + tfsdklog.Trace(ctx, "running delete") destroyReq := DeleteResourceRequest{ State: State{ Schema: resourceSchema,