From 7bc4c6ed4b582b7f3f9f64d1a47129f7463b1cf2 Mon Sep 17 00:00:00 2001 From: Brian Flad Date: Mon, 7 Nov 2022 15:32:39 -0500 Subject: [PATCH] helper/resource: Various small fixes (#1091) Reference: https://github.com/hashicorp/terraform-plugin-sdk/issues/1063 Reference: https://github.com/hashicorp/go-plugin/pull/220 This includes the following small bug fixes: - Clarifies/fixes the trace logging during `terraform show` commands - Improves performance slightly for `terraform show` raw plan usage (terraform-exec already captures and returns stdout for raw plans) - Prevents a goroutine leak specific to the detached stop context in `schema.GRPCProvider` Previously, leak detection on testing would contain an entry per Terraform command such as: ``` [Goroutine 276 in state select, with github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema.mergeStop on top of the stack: goroutine 276 [select]: github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema.mergeStop({0x103a5f298?, 0x14000390c00?}, 0x1400033e5f0, 0x140004bb560) /Users/bflad/src/github.com/hashicorp/terraform-plugin-sdk/helper/schema/grpc_provider.go:46 +0x64 created by github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema.(*GRPCProviderServer).StopContext /Users/bflad/src/github.com/hashicorp/terraform-plugin-sdk/helper/schema/grpc_provider.go:63 +0x178 ] ``` Leaked goroutines such as: ``` [Goroutine 53 in state select, with github.com/hashicorp/go-plugin.(*gRPCBrokerServer).Recv on top of the stack: goroutine 53 [select]: github.com/hashicorp/go-plugin.(*gRPCBrokerServer).Recv(0x29?) /Users/bflad/go/pkg/mod/github.com/hashicorp/go-plugin@v1.4.4/grpc_broker.go:121 +0x58 github.com/hashicorp/go-plugin.(*GRPCBroker).Run(0x140003ca190) /Users/bflad/go/pkg/mod/github.com/hashicorp/go-plugin@v1.4.4/grpc_broker.go:411 +0x40 created by github.com/hashicorp/go-plugin.(*GRPCServer).Init /Users/bflad/go/pkg/mod/github.com/hashicorp/go-plugin@v1.4.4/grpc_server.go:85 +0x424 ] ``` Will likely require a fix upstream in go-plugin. --- .changelog/1091.txt | 3 ++ helper/resource/plugin.go | 21 +++++++++- helper/resource/plugin_test.go | 63 ++++++++++++++++++++++++++++++ internal/plugintest/working_dir.go | 23 ++++------- 4 files changed, 94 insertions(+), 16 deletions(-) create mode 100644 .changelog/1091.txt diff --git a/.changelog/1091.txt b/.changelog/1091.txt new file mode 100644 index 00000000000..07d544d6e32 --- /dev/null +++ b/.changelog/1091.txt @@ -0,0 +1,3 @@ +```release-note:bug +helper/resource: Prevented goroutine leak per Terraform command when testing terraform-plugin-sdk based providers via `Providers` or `ProviderFactories` +``` diff --git a/helper/resource/plugin.go b/helper/resource/plugin.go index 5f5bb64e80d..120f04276b3 100644 --- a/helper/resource/plugin.go +++ b/helper/resource/plugin.go @@ -157,6 +157,13 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl host = v } + // schema.Provider have a global stop context that is created outside + // the server context and have their own associated goroutine. Since + // Terraform does not call the StopProvider RPC to stop the server in + // reattach mode, ensure that we save these servers to later call that + // RPC and end those goroutines. + legacyProviderServers := make([]*schema.GRPCProviderServer, 0, len(factories.legacy)) + // Spin up gRPC servers for every provider factory, start a // WaitGroup to listen for all of the close channels. var wg sync.WaitGroup @@ -180,13 +187,19 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl // shut down. wg.Add(1) + grpcProviderServer := schema.NewGRPCProviderServer(provider) + legacyProviderServers = append(legacyProviderServers, grpcProviderServer) + + // Ensure StopProvider is always called when returning early. + defer grpcProviderServer.StopProvider(ctx, nil) //nolint:errcheck // does not return errors + // configure the settings our plugin will be served with // the GRPCProviderFunc wraps a non-gRPC provider server // into a gRPC interface, and the logger just discards logs // from go-plugin. opts := &plugin.ServeOpts{ GRPCProviderFunc: func() tfprotov5.ProviderServer { - return schema.NewGRPCProviderServer(provider) + return grpcProviderServer }, Logger: hclog.New(&hclog.LoggerOptions{ Name: "plugintest", @@ -430,6 +443,12 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl // get closed, and we'll hang here. cancel() + // For legacy providers, call the StopProvider RPC so the StopContext + // goroutine is cleaned up properly. + for _, legacyProviderServer := range legacyProviderServers { + legacyProviderServer.StopProvider(ctx, nil) //nolint:errcheck // does not return errors + } + logging.HelperResourceTrace(ctx, "Waiting for providers to stop") // wait for the servers to actually shut down; it may take a moment for diff --git a/helper/resource/plugin_test.go b/helper/resource/plugin_test.go index c7389bdcb68..acb3ffd9544 100644 --- a/helper/resource/plugin_test.go +++ b/helper/resource/plugin_test.go @@ -1,13 +1,17 @@ package resource import ( + "context" "fmt" + "os" "testing" "github.com/google/go-cmp/cmp" "github.com/hashicorp/terraform-plugin-go/tfprotov5" "github.com/hashicorp/terraform-plugin-go/tfprotov6" + "github.com/hashicorp/terraform-plugin-sdk/v2/diag" "github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/plugintest" ) func TestProtoV5ProviderFactoriesMerge(t *testing.T) { @@ -234,3 +238,62 @@ func TestSdkProviderFactoriesMerge(t *testing.T) { }) } } + +func TestRunProviderCommand(t *testing.T) { + currentDir, err := os.Getwd() + + if err != nil { + t.Fatalf("unable to get working directory: %s", err) + } + + ctx := context.Background() + funcCalled := false + helper := plugintest.AutoInitProviderHelper(ctx, currentDir) + + err = runProviderCommand( + ctx, + t, + func() error { + funcCalled = true + return nil + }, + helper.RequireNewWorkingDir(ctx, t), + &providerFactories{ + legacy: map[string]func() (*schema.Provider, error){ + "examplecloud": func() (*schema.Provider, error) { //nolint:unparam // required signature + return &schema.Provider{ + ResourcesMap: map[string]*schema.Resource{ + "examplecloud_thing": { + CreateContext: func(ctx context.Context, d *schema.ResourceData, i interface{}) diag.Diagnostics { + d.SetId("id") + + return nil + }, + DeleteContext: func(_ context.Context, _ *schema.ResourceData, _ interface{}) diag.Diagnostics { + return nil + }, + ReadContext: func(_ context.Context, d *schema.ResourceData, _ interface{}) diag.Diagnostics { + return nil + }, + Schema: map[string]*schema.Schema{ + "id": { + Computed: true, + Type: schema.TypeString, + }, + }, + }, + }, + }, nil + }, + }, + }, + ) + + if err != nil { + t.Fatal(err) + } + + if !funcCalled { + t.Error("expected func to be called") + } +} diff --git a/internal/plugintest/working_dir.go b/internal/plugintest/working_dir.go index 3558ac6e1d7..159399350f6 100644 --- a/internal/plugintest/working_dir.go +++ b/internal/plugintest/working_dir.go @@ -1,11 +1,9 @@ package plugintest import ( - "bytes" "context" "encoding/json" "fmt" - "io" "os" "path/filepath" @@ -281,11 +279,11 @@ func (wd *WorkingDir) SavedPlan(ctx context.Context) (*tfjson.Plan, error) { return nil, fmt.Errorf("there is no current saved plan") } - logging.HelperResourceTrace(ctx, "Calling Terraform CLI apply command") + logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command for JSON plan") plan, err := wd.tf.ShowPlanFile(context.Background(), wd.planFilename(), tfexec.Reattach(wd.reattachInfo)) - logging.HelperResourceTrace(ctx, "Calling Terraform CLI apply command") + logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command for JSON plan") return plan, err } @@ -299,22 +297,17 @@ func (wd *WorkingDir) SavedPlanRawStdout(ctx context.Context) (string, error) { return "", fmt.Errorf("there is no current saved plan") } - var ret bytes.Buffer - - wd.tf.SetStdout(&ret) - defer wd.tf.SetStdout(io.Discard) - - logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command") + logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command for stdout plan") - _, err := wd.tf.ShowPlanFileRaw(context.Background(), wd.planFilename(), tfexec.Reattach(wd.reattachInfo)) + stdout, err := wd.tf.ShowPlanFileRaw(context.Background(), wd.planFilename(), tfexec.Reattach(wd.reattachInfo)) - logging.HelperResourceTrace(ctx, "Called Terraform CLI show command") + logging.HelperResourceTrace(ctx, "Called Terraform CLI show command for stdout plan") if err != nil { return "", err } - return ret.String(), nil + return stdout, nil } // State returns an object describing the current state. @@ -322,11 +315,11 @@ func (wd *WorkingDir) SavedPlanRawStdout(ctx context.Context) (string, error) { // If the state cannot be read, State returns an error. func (wd *WorkingDir) State(ctx context.Context) (*tfjson.State, error) { - logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command") + logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command for JSON state") state, err := wd.tf.Show(context.Background(), tfexec.Reattach(wd.reattachInfo)) - logging.HelperResourceTrace(ctx, "Called Terraform CLI show command") + logging.HelperResourceTrace(ctx, "Called Terraform CLI show command for JSON state") return state, err }