diff --git a/.changelog/891.txt b/.changelog/891.txt new file mode 100644 index 00000000000..0fbaca3f7df --- /dev/null +++ b/.changelog/891.txt @@ -0,0 +1,7 @@ +```release-note:note +helper/resource: The new terraform-plugin-log `sdk.helper_resource` logger inherits the `TF_LOG`, `TF_LOG_PATH_MASK`, and `TF_ACC_LOG_PATH` environment variable settings, similar to the prior logging. The `TF_LOG_SDK_HELPER_RESOURCE` environment variable can be used to separately control the new logger level. +``` + +```release-note:enhancement +helper/resource: Added terraform-plugin-log `sdk.helper_resource` logger and extensive `TRACE` log entries +``` diff --git a/helper/logging/logging.go b/helper/logging/logging.go index 3a2afafae28..235586aed86 100644 --- a/helper/logging/logging.go +++ b/helper/logging/logging.go @@ -1,7 +1,6 @@ package logging import ( - "context" "fmt" "io" "io/ioutil" @@ -11,7 +10,6 @@ import ( "syscall" "github.com/hashicorp/logutils" - "github.com/hashicorp/terraform-plugin-log/tfsdklog" testing "github.com/mitchellh/go-testing-interface" ) @@ -138,12 +136,3 @@ func isValidLogLevel(level string) bool { return false } - -// GetTestLogContext creates a context that is registered to the SDK log sink. -// This function is for internal usage only and is not supported by the project's -// compatibility promises. -func GetTestLogContext(t testing.T) context.Context { - ctx := context.Background() - ctx = tfsdklog.RegisterTestSink(ctx, t) - return ctx -} diff --git a/helper/resource/plugin.go b/helper/resource/plugin.go index 6bc10e95ee3..8777121d7d9 100644 --- a/helper/resource/plugin.go +++ b/helper/resource/plugin.go @@ -13,7 +13,6 @@ import ( "github.com/hashicorp/terraform-exec/tfexec" "github.com/hashicorp/terraform-plugin-go/tfprotov5" "github.com/hashicorp/terraform-plugin-go/tfprotov6" - "github.com/hashicorp/terraform-plugin-sdk/v2/helper/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/plugintest" "github.com/hashicorp/terraform-plugin-sdk/v2/plugin" @@ -26,7 +25,7 @@ type providerFactories struct { protov6 map[string]func() (tfprotov6.ProviderServer, error) } -func runProviderCommand(t testing.T, f func() error, wd *plugintest.WorkingDir, factories providerFactories) error { +func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *plugintest.WorkingDir, factories providerFactories) error { // don't point to this as a test failure location // point to whatever called it t.Helper() @@ -35,7 +34,7 @@ func runProviderCommand(t testing.T, f func() error, wd *plugintest.WorkingDir, // reattach behavior in Terraform. This ensures we get test coverage // and enables the use of delve as a debugger. - ctx, cancel := context.WithCancel(logging.GetTestLogContext(t)) + ctx, cancel := context.WithCancel(ctx) defer cancel() // this is needed so Terraform doesn't default to expecting protocol 4; diff --git a/helper/resource/testing.go b/helper/resource/testing.go index c53f18d4717..d05ac561d2e 100644 --- a/helper/resource/testing.go +++ b/helper/resource/testing.go @@ -1,6 +1,7 @@ package resource import ( + "context" "errors" "flag" "fmt" @@ -16,9 +17,9 @@ import ( "github.com/hashicorp/terraform-plugin-go/tfprotov5" "github.com/hashicorp/terraform-plugin-go/tfprotov6" - "github.com/hashicorp/terraform-plugin-sdk/v2/helper/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/addrs" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/plugintest" "github.com/hashicorp/terraform-plugin-sdk/v2/terraform" ) @@ -583,6 +584,9 @@ func ParallelTest(t testing.T, c TestCase) { func Test(t testing.T, c TestCase) { t.Helper() + ctx := context.Background() + ctx = logging.InitTestContext(ctx, t) + // We only run acceptance tests if an env var is set because they're // slow and generally require some outside configuration. You can opt out // of this with OverrideEnvVar on individual TestCases. @@ -593,8 +597,6 @@ func Test(t testing.T, c TestCase) { return } - logging.SetOutput(t) - // Copy any explicitly passed providers to factories, this is for backwards compatibility. if len(c.Providers) > 0 { c.ProviderFactories = map[string]func() (*schema.Provider, error){} @@ -610,26 +612,34 @@ func Test(t testing.T, c TestCase) { } } + logging.HelperResourceDebug(ctx, "Starting TestCase") + // Run the PreCheck if we have it. // This is done after the auto-configure to allow providers // to override the default auto-configure parameters. if c.PreCheck != nil { + logging.HelperResourceDebug(ctx, "Calling TestCase PreCheck") + c.PreCheck() + + logging.HelperResourceDebug(ctx, "Called TestCase PreCheck") } sourceDir, err := os.Getwd() if err != nil { t.Fatalf("Error getting working dir: %s", err) } - helper := plugintest.AutoInitProviderHelper(sourceDir) + helper := plugintest.AutoInitProviderHelper(ctx, sourceDir) defer func(helper *plugintest.Helper) { err := helper.Close() if err != nil { - log.Printf("Error cleaning up temporary test files: %s", err) + logging.HelperResourceError(ctx, "Unable to clean up temporary test files", logging.KeyError, err) } }(helper) - runNewTest(t, c, helper) + runNewTest(ctx, t, c, helper) + + logging.HelperResourceDebug(ctx, "Finished TestCase") } // testProviderConfig takes the list of Providers in a TestCase and returns a diff --git a/helper/resource/testing_config.go b/helper/resource/testing_config.go index 1e39294fd7f..e28426fde3b 100644 --- a/helper/resource/testing_config.go +++ b/helper/resource/testing_config.go @@ -1,14 +1,21 @@ package resource import ( + "context" "errors" "fmt" - "log" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/terraform" ) -func testStepTaint(state *terraform.State, step TestStep) error { +func testStepTaint(ctx context.Context, state *terraform.State, step TestStep) error { + if len(step.Taint) == 0 { + return nil + } + + logging.HelperResourceTrace(ctx, fmt.Sprintf("Using TestStep Taint: %v", step.Taint)) + for _, p := range step.Taint { m := state.RootModule() if m == nil { @@ -18,7 +25,7 @@ func testStepTaint(state *terraform.State, step TestStep) error { if !ok { return fmt.Errorf("resource %q not found in state", p) } - log.Printf("[WARN] Test: Explicitly tainting resource %q", p) + logging.HelperResourceWarn(ctx, fmt.Sprintf("Explicitly tainting resource %q", p)) rs.Taint() } return nil diff --git a/helper/resource/testing_new.go b/helper/resource/testing_new.go index 3f6f4136e62..9b0e172039f 100644 --- a/helper/resource/testing_new.go +++ b/helper/resource/testing_new.go @@ -1,8 +1,8 @@ package resource import ( + "context" "fmt" - "log" "reflect" "strings" @@ -13,15 +13,16 @@ import ( "github.com/hashicorp/terraform-plugin-go/tfprotov5" "github.com/hashicorp/terraform-plugin-go/tfprotov6" "github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/plugintest" "github.com/hashicorp/terraform-plugin-sdk/v2/terraform" ) -func runPostTestDestroy(t testing.T, c TestCase, wd *plugintest.WorkingDir, factories map[string]func() (*schema.Provider, error), v5factories map[string]func() (tfprotov5.ProviderServer, error), v6factories map[string]func() (tfprotov6.ProviderServer, error), statePreDestroy *terraform.State) error { +func runPostTestDestroy(ctx context.Context, t testing.T, c TestCase, wd *plugintest.WorkingDir, factories map[string]func() (*schema.Provider, error), v5factories map[string]func() (tfprotov5.ProviderServer, error), v6factories map[string]func() (tfprotov6.ProviderServer, error), statePreDestroy *terraform.State) error { t.Helper() - err := runProviderCommand(t, func() error { - return wd.Destroy() + err := runProviderCommand(ctx, t, func() error { + return wd.Destroy(ctx) }, wd, providerFactories{ legacy: factories, protov5: v5factories, @@ -31,26 +32,34 @@ func runPostTestDestroy(t testing.T, c TestCase, wd *plugintest.WorkingDir, fact } if c.CheckDestroy != nil { + logging.HelperResourceTrace(ctx, "Using TestCase CheckDestroy") + logging.HelperResourceDebug(ctx, "Calling TestCase CheckDestroy") + if err := c.CheckDestroy(statePreDestroy); err != nil { return err } + + logging.HelperResourceDebug(ctx, "Called TestCase CheckDestroy") } return nil } -func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { +func runNewTest(ctx context.Context, t testing.T, c TestCase, helper *plugintest.Helper) { t.Helper() spewConf := spew.NewDefaultConfig() spewConf.SortKeys = true - wd := helper.RequireNewWorkingDir(t) + wd := helper.RequireNewWorkingDir(ctx, t) + + ctx = logging.TestTerraformPathContext(ctx, wd.GetHelper().TerraformExecPath()) + ctx = logging.TestWorkingDirectoryContext(ctx, wd.GetHelper().WorkingDirectory()) defer func() { var statePreDestroy *terraform.State var err error - err = runProviderCommand(t, func() error { - statePreDestroy, err = getState(t, wd) + err = runProviderCommand(ctx, t, func() error { + statePreDestroy, err = getState(ctx, t, wd) if err != nil { return err } @@ -65,7 +74,7 @@ func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { } if !stateIsEmpty(statePreDestroy) { - err := runPostTestDestroy(t, c, wd, c.ProviderFactories, c.ProtoV5ProviderFactories, c.ProtoV6ProviderFactories, statePreDestroy) + err := runPostTestDestroy(ctx, t, c, wd, c.ProviderFactories, c.ProtoV5ProviderFactories, c.ProtoV6ProviderFactories, statePreDestroy) if err != nil { t.Fatalf("Error running post-test destroy, there may be dangling resources: %s", err.Error()) } @@ -79,12 +88,12 @@ func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { t.Fatal(err) } - err = wd.SetConfig(providerCfg) + err = wd.SetConfig(ctx, providerCfg) if err != nil { t.Fatalf("Error setting test config: %s", err) } - err = runProviderCommand(t, func() error { - return wd.Init() + err = runProviderCommand(ctx, t, func() error { + return wd.Init(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -99,25 +108,39 @@ func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { var appliedCfg string for i, step := range c.Steps { + ctx = logging.TestStepNumberContext(ctx, i+1) + + logging.HelperResourceDebug(ctx, "Starting TestStep") + if step.PreConfig != nil { + logging.HelperResourceDebug(ctx, "Calling TestStep PreConfig") step.PreConfig() + logging.HelperResourceDebug(ctx, "Called TestStep PreConfig") } if step.SkipFunc != nil { + logging.HelperResourceDebug(ctx, "Calling TestStep SkipFunc") + skip, err := step.SkipFunc() if err != nil { t.Fatal(err) } + + logging.HelperResourceDebug(ctx, "Called TestStep SkipFunc") + if skip { t.Logf("Skipping step %d/%d due to SkipFunc", i+1, len(c.Steps)) - log.Printf("[WARN] Skipping step %d/%d due to SkipFunc", i+1, len(c.Steps)) + logging.HelperResourceWarn(ctx, "Skipping TestStep due to SkipFunc") continue } } if step.ImportState { - err := testStepNewImportState(t, c, helper, wd, step, appliedCfg) + logging.HelperResourceTrace(ctx, "TestStep is ImportState mode") + + err := testStepNewImportState(ctx, t, c, helper, wd, step, appliedCfg) if step.ExpectError != nil { + logging.HelperResourceDebug(ctx, "Checking TestStep ExpectError") if err == nil { t.Fatalf("Step %d/%d error running import: expected an error but got none", i+1, len(c.Steps)) } @@ -126,18 +149,26 @@ func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { } } else { if err != nil && c.ErrorCheck != nil { + logging.HelperResourceDebug(ctx, "Calling TestCase ErrorCheck") err = c.ErrorCheck(err) } if err != nil { t.Fatalf("Step %d/%d error running import: %s", i+1, len(c.Steps), err) } } + + logging.HelperResourceDebug(ctx, "Finished TestStep") + continue } if step.Config != "" { - err := testStepNewConfig(t, c, wd, step) + logging.HelperResourceTrace(ctx, "TestStep is Config mode") + + err := testStepNewConfig(ctx, t, c, wd, step) if step.ExpectError != nil { + logging.HelperResourceDebug(ctx, "Checking TestStep ExpectError") + if err == nil { t.Fatalf("Step %d/%d, expected an error but got none", i+1, len(c.Steps)) } @@ -146,13 +177,21 @@ func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { } } else { if err != nil && c.ErrorCheck != nil { + logging.HelperResourceDebug(ctx, "Calling TestCase ErrorCheck") + err = c.ErrorCheck(err) + + logging.HelperResourceDebug(ctx, "Called TestCase ErrorCheck") } if err != nil { t.Fatalf("Step %d/%d error: %s", i+1, len(c.Steps), err) } } + appliedCfg = step.Config + + logging.HelperResourceDebug(ctx, "Finished TestStep") + continue } @@ -160,10 +199,10 @@ func runNewTest(t testing.T, c TestCase, helper *plugintest.Helper) { } } -func getState(t testing.T, wd *plugintest.WorkingDir) (*terraform.State, error) { +func getState(ctx context.Context, t testing.T, wd *plugintest.WorkingDir) (*terraform.State, error) { t.Helper() - jsonState, err := wd.State() + jsonState, err := wd.State(ctx) if err != nil { return nil, err } @@ -189,7 +228,7 @@ func planIsEmpty(plan *tfjson.Plan) bool { return true } -func testIDRefresh(c TestCase, t testing.T, wd *plugintest.WorkingDir, step TestStep, r *terraform.ResourceState) error { +func testIDRefresh(ctx context.Context, t testing.T, c TestCase, wd *plugintest.WorkingDir, step TestStep, r *terraform.ResourceState) error { t.Helper() spewConf := spew.NewDefaultConfig() @@ -207,24 +246,24 @@ func testIDRefresh(c TestCase, t testing.T, wd *plugintest.WorkingDir, step Test if err != nil { return err } - err = wd.SetConfig(cfg) + err = wd.SetConfig(ctx, cfg) if err != nil { t.Fatalf("Error setting import test config: %s", err) } defer func() { - err = wd.SetConfig(step.Config) + err = wd.SetConfig(ctx, step.Config) if err != nil { t.Fatalf("Error resetting test config: %s", err) } }() // Refresh! - err = runProviderCommand(t, func() error { - err = wd.Refresh() + err = runProviderCommand(ctx, t, func() error { + err = wd.Refresh(ctx) if err != nil { t.Fatalf("Error running terraform refresh: %s", err) } - state, err = getState(t, wd) + state, err = getState(ctx, t, wd) if err != nil { return err } @@ -247,6 +286,11 @@ func testIDRefresh(c TestCase, t testing.T, wd *plugintest.WorkingDir, step Test } actual := actualR.Primary.Attributes expected := r.Primary.Attributes + + if len(c.IDRefreshIgnore) > 0 { + logging.HelperResourceTrace(ctx, fmt.Sprintf("Using TestCase IDRefreshIgnore: %v", c.IDRefreshIgnore)) + } + // Remove fields we're ignoring for _, v := range c.IDRefreshIgnore { for k := range actual { diff --git a/helper/resource/testing_new_config.go b/helper/resource/testing_new_config.go index 9900cc3965d..3b2908d126c 100644 --- a/helper/resource/testing_new_config.go +++ b/helper/resource/testing_new_config.go @@ -1,17 +1,19 @@ package resource import ( + "context" "errors" "fmt" tfjson "github.com/hashicorp/terraform-json" testing "github.com/mitchellh/go-testing-interface" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/plugintest" "github.com/hashicorp/terraform-plugin-sdk/v2/terraform" ) -func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step TestStep) error { +func testStepNewConfig(ctx context.Context, t testing.T, c TestCase, wd *plugintest.WorkingDir, step TestStep) error { t.Helper() var idRefreshCheck *terraform.ResourceState @@ -20,8 +22,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step if !step.Destroy { var state *terraform.State var err error - err = runProviderCommand(t, func() error { - state, err = getState(t, wd) + err = runProviderCommand(ctx, t, func() error { + state, err = getState(ctx, t, wd) if err != nil { return err } @@ -33,20 +35,20 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step if err != nil { return err } - if err := testStepTaint(state, step); err != nil { + if err := testStepTaint(ctx, state, step); err != nil { return fmt.Errorf("Error when tainting resources: %s", err) } } - err := wd.SetConfig(step.Config) + err := wd.SetConfig(ctx, step.Config) if err != nil { return fmt.Errorf("Error setting config: %w", err) } // require a refresh before applying // failing to do this will result in data sources not being updated - err = runProviderCommand(t, func() error { - return wd.Refresh() + err = runProviderCommand(ctx, t, func() error { + return wd.Refresh(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -59,12 +61,14 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // subsequent Apply, and use the follow-up Plan that checks for // permadiffs if !step.PlanOnly { + logging.HelperResourceDebug(ctx, "Running Terraform CLI plan and apply") + // Plan! - err := runProviderCommand(t, func() error { + err := runProviderCommand(ctx, t, func() error { if step.Destroy { - return wd.CreateDestroyPlan() + return wd.CreateDestroyPlan(ctx) } - return wd.CreatePlan() + return wd.CreatePlan(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -77,8 +81,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // that the destroy steps can verify their behavior in the // check function var stateBeforeApplication *terraform.State - err = runProviderCommand(t, func() error { - stateBeforeApplication, err = getState(t, wd) + err = runProviderCommand(ctx, t, func() error { + stateBeforeApplication, err = getState(ctx, t, wd) if err != nil { return err } @@ -92,8 +96,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step } // Apply the diff, creating real resources - err = runProviderCommand(t, func() error { - return wd.Apply() + err = runProviderCommand(ctx, t, func() error { + return wd.Apply(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -107,8 +111,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // Get the new state var state *terraform.State - err = runProviderCommand(t, func() error { - state, err = getState(t, wd) + err = runProviderCommand(ctx, t, func() error { + state, err = getState(ctx, t, wd) if err != nil { return err } @@ -123,6 +127,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // Run any configured checks if step.Check != nil { + logging.HelperResourceTrace(ctx, "Using TestStep Check") + state.IsBinaryDrivenTest = true if step.Destroy { if err := step.Check(stateBeforeApplication); err != nil { @@ -137,13 +143,14 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step } // Test for perpetual diffs by performing a plan, a refresh, and another plan + logging.HelperResourceDebug(ctx, "Running Terraform CLI plan to check for perpetual differences") // do a plan - err = runProviderCommand(t, func() error { + err = runProviderCommand(ctx, t, func() error { if step.Destroy { - return wd.CreateDestroyPlan() + return wd.CreateDestroyPlan(ctx) } - return wd.CreatePlan() + return wd.CreatePlan(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -153,9 +160,9 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step } var plan *tfjson.Plan - err = runProviderCommand(t, func() error { + err = runProviderCommand(ctx, t, func() error { var err error - plan, err = wd.SavedPlan() + plan, err = wd.SavedPlan(ctx) return err }, wd, providerFactories{ legacy: c.ProviderFactories, @@ -167,9 +174,9 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step if !planIsEmpty(plan) && !step.ExpectNonEmptyPlan { var stdout string - err = runProviderCommand(t, func() error { + err = runProviderCommand(ctx, t, func() error { var err error - stdout, err = wd.SavedPlanRawStdout() + stdout, err = wd.SavedPlanRawStdout(ctx) return err }, wd, providerFactories{ legacy: c.ProviderFactories, @@ -183,8 +190,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // do a refresh if !step.Destroy || (step.Destroy && !step.PreventPostDestroyRefresh) { - err := runProviderCommand(t, func() error { - return wd.Refresh() + err := runProviderCommand(ctx, t, func() error { + return wd.Refresh(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -195,11 +202,11 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step } // do another plan - err = runProviderCommand(t, func() error { + err = runProviderCommand(ctx, t, func() error { if step.Destroy { - return wd.CreateDestroyPlan() + return wd.CreateDestroyPlan(ctx) } - return wd.CreatePlan() + return wd.CreatePlan(ctx) }, wd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -208,9 +215,9 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step return fmt.Errorf("Error running second post-apply plan: %w", err) } - err = runProviderCommand(t, func() error { + err = runProviderCommand(ctx, t, func() error { var err error - plan, err = wd.SavedPlan() + plan, err = wd.SavedPlan(ctx) return err }, wd, providerFactories{ legacy: c.ProviderFactories, @@ -223,9 +230,9 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // check if plan is empty if !planIsEmpty(plan) && !step.ExpectNonEmptyPlan { var stdout string - err = runProviderCommand(t, func() error { + err = runProviderCommand(ctx, t, func() error { var err error - stdout, err = wd.SavedPlanRawStdout() + stdout, err = wd.SavedPlanRawStdout(ctx) return err }, wd, providerFactories{ legacy: c.ProviderFactories, @@ -243,8 +250,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // If we've never checked an id-only refresh and our state isn't // empty, find the first resource and test it. var state *terraform.State - err = runProviderCommand(t, func() error { - state, err = getState(t, wd) + err = runProviderCommand(ctx, t, func() error { + state, err = getState(ctx, t, wd) if err != nil { return err } @@ -257,6 +264,8 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step return err } if idRefresh && idRefreshCheck == nil && !state.Empty() { + logging.HelperResourceTrace(ctx, "Using TestCase IDRefreshName") + // Find the first non-nil resource in the state for _, m := range state.Modules { if len(m.Resources) > 0 { @@ -275,7 +284,7 @@ func testStepNewConfig(t testing.T, c TestCase, wd *plugintest.WorkingDir, step // this fails. If refresh isn't read-only, then this will have // caught a different bug. if idRefreshCheck != nil { - if err := testIDRefresh(c, t, wd, step, idRefreshCheck); err != nil { + if err := testIDRefresh(ctx, t, c, wd, step, idRefreshCheck); err != nil { return fmt.Errorf( "[ERROR] Test: ID-only test failed: %s", err) } diff --git a/helper/resource/testing_new_import_state.go b/helper/resource/testing_new_import_state.go index 71770b31426..1dc98143a64 100644 --- a/helper/resource/testing_new_import_state.go +++ b/helper/resource/testing_new_import_state.go @@ -1,17 +1,20 @@ package resource import ( + "context" + "fmt" "reflect" "strings" "github.com/davecgh/go-spew/spew" testing "github.com/mitchellh/go-testing-interface" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/plugintest" "github.com/hashicorp/terraform-plugin-sdk/v2/terraform" ) -func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, wd *plugintest.WorkingDir, step TestStep, cfg string) error { +func testStepNewImportState(ctx context.Context, t testing.T, c TestCase, helper *plugintest.Helper, wd *plugintest.WorkingDir, step TestStep, cfg string) error { t.Helper() spewConf := spew.NewDefaultConfig() @@ -24,8 +27,8 @@ func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, // get state from check sequence var state *terraform.State var err error - err = runProviderCommand(t, func() error { - state, err = getState(t, wd) + err = runProviderCommand(ctx, t, func() error { + state, err = getState(ctx, t, wd) if err != nil { return err } @@ -42,38 +45,61 @@ func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, var importId string switch { case step.ImportStateIdFunc != nil: + logging.HelperResourceTrace(ctx, "Using TestStep ImportStateIdFunc for import identifier") + var err error + + logging.HelperResourceDebug(ctx, "Calling TestStep ImportStateIdFunc") + importId, err = step.ImportStateIdFunc(state) + if err != nil { t.Fatal(err) } + + logging.HelperResourceDebug(ctx, "Called TestStep ImportStateIdFunc") case step.ImportStateId != "": + logging.HelperResourceTrace(ctx, "Using TestStep ImportStateId for import identifier") + importId = step.ImportStateId default: + logging.HelperResourceTrace(ctx, "Using resource identifier for import identifier") + resource, err := testResource(step, state) if err != nil { t.Fatal(err) } importId = resource.Primary.ID } - importId = step.ImportStateIdPrefix + importId + + if step.ImportStateIdPrefix != "" { + logging.HelperResourceTrace(ctx, "Prepending TestStep ImportStateIdPrefix for import identifier") + + importId = step.ImportStateIdPrefix + importId + } + + logging.HelperResourceTrace(ctx, fmt.Sprintf("Using import identifier: %s", importId)) // Create working directory for import tests if step.Config == "" { + logging.HelperResourceTrace(ctx, "Using prior TestStep Config for import") + step.Config = cfg if step.Config == "" { t.Fatal("Cannot import state with no specified config") } } - importWd := helper.RequireNewWorkingDir(t) + importWd := helper.RequireNewWorkingDir(ctx, t) defer importWd.Close() - err = importWd.SetConfig(step.Config) + err = importWd.SetConfig(ctx, step.Config) if err != nil { t.Fatalf("Error setting test config: %s", err) } - err = runProviderCommand(t, func() error { - return importWd.Init() + logging.HelperResourceDebug(ctx, "Running Terraform CLI init and import") + + err = runProviderCommand(ctx, t, func() error { + return importWd.Init(ctx) }, importWd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -82,8 +108,8 @@ func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, t.Fatalf("Error running init: %s", err) } - err = runProviderCommand(t, func() error { - return importWd.Import(step.ResourceName, importId) + err = runProviderCommand(ctx, t, func() error { + return importWd.Import(ctx, step.ResourceName, importId) }, importWd, providerFactories{ legacy: c.ProviderFactories, protov5: c.ProtoV5ProviderFactories, @@ -93,8 +119,8 @@ func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, } var importState *terraform.State - err = runProviderCommand(t, func() error { - importState, err = getState(t, importWd) + err = runProviderCommand(ctx, t, func() error { + importState, err = getState(ctx, t, importWd) if err != nil { return err } @@ -109,6 +135,8 @@ func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, // Go through the imported state and verify if step.ImportStateCheck != nil { + logging.HelperResourceTrace(ctx, "Using TestStep ImportStateCheck") + var states []*terraform.InstanceState for _, r := range importState.RootModule().Resources { if r.Primary != nil { @@ -117,13 +145,20 @@ func testStepNewImportState(t testing.T, c TestCase, helper *plugintest.Helper, states = append(states, is) } } + + logging.HelperResourceDebug(ctx, "Calling TestStep ImportStateCheck") + if err := step.ImportStateCheck(states); err != nil { t.Fatal(err) } + + logging.HelperResourceDebug(ctx, "Called TestStep ImportStateCheck") } // Verify that all the states match if step.ImportStateVerify { + logging.HelperResourceTrace(ctx, "Using TestStep ImportStateVerify") + newResources := importState.RootModule().Resources oldResources := state.RootModule().Resources diff --git a/internal/logging/context.go b/internal/logging/context.go index 5076a696288..2fde858bb17 100644 --- a/internal/logging/context.go +++ b/internal/logging/context.go @@ -4,11 +4,64 @@ import ( "context" "github.com/hashicorp/terraform-plugin-log/tfsdklog" + helperlogging "github.com/hashicorp/terraform-plugin-sdk/v2/helper/logging" + testing "github.com/mitchellh/go-testing-interface" ) // InitContext creates SDK logger contexts. func InitContext(ctx context.Context) context.Context { + ctx = tfsdklog.NewRootSDKLogger(ctx) + ctx = tfsdklog.NewSubsystem(ctx, SubsystemHelperResource, tfsdklog.WithLevelFromEnv(EnvTfLogSdkHelperResource)) ctx = tfsdklog.NewSubsystem(ctx, SubsystemHelperSchema, tfsdklog.WithLevelFromEnv(EnvTfLogSdkHelperSchema)) return ctx } + +// InitTestContext registers the terraform-plugin-log/tfsdklog test sink, +// configures the standard library log package, and creates SDK logger +// contexts. +// +// It may be possible to eliminate the helper/logging handling if all +// log package calls are replaced with tfsdklog and any go-plugin or +// terraform-exec logger configurations are updated to the tfsdklog logger. +func InitTestContext(ctx context.Context, t testing.T) context.Context { + helperlogging.SetOutput(t) + + ctx = tfsdklog.RegisterTestSink(ctx, t) + ctx = InitContext(ctx) + ctx = TestNameContext(ctx, t.Name()) + + return ctx +} + +// TestNameContext adds the current test name to loggers. +func TestNameContext(ctx context.Context, testName string) context.Context { + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperResource, KeyTestName, testName) + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperSchema, KeyTestName, testName) + + return ctx +} + +// TestStepNumberContext adds the current test step number to loggers. +func TestStepNumberContext(ctx context.Context, stepNumber int) context.Context { + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperResource, KeyTestStepNumber, stepNumber) + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperSchema, KeyTestStepNumber, stepNumber) + + return ctx +} + +// TestTerraformPathContext adds the current test Terraform CLI path to loggers. +func TestTerraformPathContext(ctx context.Context, terraformPath string) context.Context { + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperResource, KeyTestTerraformPath, terraformPath) + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperSchema, KeyTestTerraformPath, terraformPath) + + return ctx +} + +// TestWorkingDirectoryContext adds the current test working directory to loggers. +func TestWorkingDirectoryContext(ctx context.Context, workingDirectory string) context.Context { + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperResource, KeyTestWorkingDirectory, workingDirectory) + ctx = tfsdklog.SubsystemWith(ctx, SubsystemHelperSchema, KeyTestWorkingDirectory, workingDirectory) + + return ctx +} diff --git a/internal/logging/environment_variables.go b/internal/logging/environment_variables.go index 224fd046d07..643d6b83586 100644 --- a/internal/logging/environment_variables.go +++ b/internal/logging/environment_variables.go @@ -2,6 +2,11 @@ package logging // Environment variables. const ( + // EnvTfLogSdkHelperResource is an environment variable that sets the logging + // level of SDK helper/resource loggers. Infers root SDK logging level, if + // unset. + EnvTfLogSdkHelperResource = "TF_LOG_SDK_HELPER_RESOURCE" + // EnvTfLogSdkHelperSchema is an environment variable that sets the logging // level of SDK helper/schema loggers. Infers root SDK logging level, if // unset. diff --git a/internal/logging/helper_resource.go b/internal/logging/helper_resource.go new file mode 100644 index 00000000000..f5eaec0ba71 --- /dev/null +++ b/internal/logging/helper_resource.go @@ -0,0 +1,32 @@ +package logging + +import ( + "context" + + "github.com/hashicorp/terraform-plugin-log/tfsdklog" +) + +const ( + // SubsystemHelperResource is the tfsdklog subsystem name for helper/resource. + SubsystemHelperResource = "helper_resource" +) + +// HelperResourceTrace emits a helper/resource subsystem log at TRACE level. +func HelperResourceTrace(ctx context.Context, msg string, args ...interface{}) { + tfsdklog.SubsystemTrace(ctx, SubsystemHelperResource, msg, args) +} + +// HelperResourceDebug emits a helper/resource subsystem log at DEBUG level. +func HelperResourceDebug(ctx context.Context, msg string, args ...interface{}) { + tfsdklog.SubsystemDebug(ctx, SubsystemHelperResource, msg, args) +} + +// HelperResourceWarn emits a helper/resource subsystem log at WARN level. +func HelperResourceWarn(ctx context.Context, msg string, args ...interface{}) { + tfsdklog.SubsystemWarn(ctx, SubsystemHelperResource, msg, args) +} + +// HelperResourceError emits a helper/resource subsystem log at ERROR level. +func HelperResourceError(ctx context.Context, msg string, args ...interface{}) { + tfsdklog.SubsystemError(ctx, SubsystemHelperResource, msg, args) +} diff --git a/internal/logging/keys.go b/internal/logging/keys.go index d8d4301779d..6b1f94dec1d 100644 --- a/internal/logging/keys.go +++ b/internal/logging/keys.go @@ -8,9 +8,24 @@ package logging // Refer to the terraform-plugin-go logging keys as well, which should be // equivalent to these when possible. const ( + // The type of data source being operated on, such as "archive_file" + KeyDataSourceType = "tf_data_source_type" + + // Underlying Go error string when logging an error. + KeyError = "error" + // The type of resource being operated on, such as "random_pet" KeyResourceType = "tf_resource_type" - // The type of data source being operated on, such as "archive_file" - KeyDataSourceType = "tf_data_source_type" + // The name of the test being executed. + KeyTestName = "test_name" + + // The TestStep number of the test being executed. Starts at 1. + KeyTestStepNumber = "test_step_number" + + // The path to the Terraform CLI used for an acceptance test. + KeyTestTerraformPath = "test_terraform_path" + + // The working directory of the acceptance test. + KeyTestWorkingDirectory = "test_working_directory" ) diff --git a/internal/plugintest/config.go b/internal/plugintest/config.go index c6664748ad0..6ce87970e20 100644 --- a/internal/plugintest/config.go +++ b/internal/plugintest/config.go @@ -14,6 +14,7 @@ import ( "github.com/hashicorp/hc-install/product" "github.com/hashicorp/hc-install/releases" "github.com/hashicorp/hc-install/src" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" ) // Config is used to configure the test helper. In most normal test programs @@ -29,7 +30,7 @@ type Config struct { // DiscoverConfig uses environment variables and other means to automatically // discover a reasonable test helper configuration. -func DiscoverConfig(sourceDir string) (*Config, error) { +func DiscoverConfig(ctx context.Context, sourceDir string) (*Config, error) { tfVersion := strings.TrimPrefix(os.Getenv(EnvTfAccTerraformVersion), "v") tfPath := os.Getenv(EnvTfAccTerraformPath) @@ -42,6 +43,8 @@ func DiscoverConfig(sourceDir string) (*Config, error) { var sources []src.Source switch { case tfPath != "": + logging.HelperResourceTrace(ctx, fmt.Sprintf("Adding potential Terraform CLI source of exact path: %s", tfPath)) + sources = append(sources, &fs.AnyVersion{ ExactBinPath: tfPath, }) @@ -52,12 +55,17 @@ func DiscoverConfig(sourceDir string) (*Config, error) { return nil, fmt.Errorf("invalid Terraform version: %w", err) } + logging.HelperResourceTrace(ctx, fmt.Sprintf("Adding potential Terraform CLI source of releases.hashicorp.com exact version %q for installation in: %s", tfVersion, tfDir)) + sources = append(sources, &releases.ExactVersion{ InstallDir: tfDir, Product: product.Terraform, Version: tfVersion, }) default: + logging.HelperResourceTrace(ctx, "Adding potential Terraform CLI source of local filesystem PATH lookup") + logging.HelperResourceTrace(ctx, fmt.Sprintf("Adding potential Terraform CLI source of checkpoint.hashicorp.com latest version for installation in: %s", tfDir)) + sources = append(sources, &fs.AnyVersion{ Product: &product.Terraform, }) @@ -73,6 +81,10 @@ func DiscoverConfig(sourceDir string) (*Config, error) { return nil, err } + ctx = logging.TestTerraformPathContext(ctx, tfExec) + + logging.HelperResourceDebug(ctx, "Found Terraform CLI") + return &Config{ SourceDir: sourceDir, TerraformExec: tfExec, diff --git a/internal/plugintest/helper.go b/internal/plugintest/helper.go index eab2477754f..8ea6756fd4f 100644 --- a/internal/plugintest/helper.go +++ b/internal/plugintest/helper.go @@ -1,11 +1,13 @@ package plugintest import ( + "context" "fmt" "io/ioutil" "os" "github.com/hashicorp/terraform-exec/tfexec" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" ) // AutoInitProviderHelper is the main entrypoint for testing provider plugins @@ -17,8 +19,8 @@ import ( // available for upgrade tests, and then will return an object containing the // results of that initialization which can then be stored in a global variable // for use in other tests. -func AutoInitProviderHelper(sourceDir string) *Helper { - helper, err := AutoInitHelper(sourceDir) +func AutoInitProviderHelper(ctx context.Context, sourceDir string) *Helper { + helper, err := AutoInitHelper(ctx, sourceDir) if err != nil { fmt.Fprintf(os.Stderr, "cannot run Terraform provider tests: %s\n", err) os.Exit(1) @@ -46,13 +48,13 @@ type Helper struct { // way to get the standard init behavior based on environment variables, and // callers should use this unless they have an unusual requirement that calls // for constructing a config in a different way. -func AutoInitHelper(sourceDir string) (*Helper, error) { - config, err := DiscoverConfig(sourceDir) +func AutoInitHelper(ctx context.Context, sourceDir string) (*Helper, error) { + config, err := DiscoverConfig(ctx, sourceDir) if err != nil { return nil, err } - return InitHelper(config) + return InitHelper(ctx, config) } // InitHelper prepares a testing helper with the given configuration. @@ -64,7 +66,7 @@ func AutoInitHelper(sourceDir string) (*Helper, error) { // If this function returns an error then it may have left some temporary files // behind in the system's temporary directory. There is currently no way to // automatically clean those up. -func InitHelper(config *Config) (*Helper, error) { +func InitHelper(ctx context.Context, config *Config) (*Helper, error) { tempDir := os.Getenv(EnvTfAccTempDir) baseDir, err := ioutil.TempDir(tempDir, "plugintest") if err != nil { @@ -100,14 +102,17 @@ func (h *Helper) Close() error { // If the working directory object is not itself closed by the time the test // program exits, the Close method on the helper itself will attempt to // delete it. -func (h *Helper) NewWorkingDir() (*WorkingDir, error) { +func (h *Helper) NewWorkingDir(ctx context.Context) (*WorkingDir, error) { dir, err := ioutil.TempDir(h.baseDir, "work") if err != nil { return nil, err } + ctx = logging.TestWorkingDirectoryContext(ctx, dir) + // symlink the provider source files into the config directory // e.g. testdata + logging.HelperResourceTrace(ctx, "Symlinking source directories to work directory") err = symlinkDirectoriesOnly(h.sourceDir, dir) if err != nil { return nil, err @@ -129,10 +134,10 @@ func (h *Helper) NewWorkingDir() (*WorkingDir, error) { // RequireNewWorkingDir is a variant of NewWorkingDir that takes a TestControl // object and will immediately fail the running test if the creation of the // working directory fails. -func (h *Helper) RequireNewWorkingDir(t TestControl) *WorkingDir { +func (h *Helper) RequireNewWorkingDir(ctx context.Context, t TestControl) *WorkingDir { t.Helper() - wd, err := h.NewWorkingDir() + wd, err := h.NewWorkingDir(ctx) if err != nil { t := testingT{t} t.Fatalf("failed to create new working directory: %s", err) @@ -141,6 +146,11 @@ func (h *Helper) RequireNewWorkingDir(t TestControl) *WorkingDir { return wd } +// WorkingDirectory returns the working directory being used when running tests. +func (h *Helper) WorkingDirectory() string { + return h.baseDir +} + // TerraformExecPath returns the location of the Terraform CLI executable that // should be used when running tests. func (h *Helper) TerraformExecPath() string { diff --git a/internal/plugintest/working_dir.go b/internal/plugintest/working_dir.go index ac45d776866..8b555f462c9 100644 --- a/internal/plugintest/working_dir.go +++ b/internal/plugintest/working_dir.go @@ -11,6 +11,7 @@ import ( "github.com/hashicorp/terraform-exec/tfexec" tfjson "github.com/hashicorp/terraform-json" + "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" ) const ( @@ -82,7 +83,7 @@ func (wd *WorkingDir) GetHelper() *Helper { // This must be called at least once before any call to Init, Plan, Apply, or // Destroy to establish the configuration. Any previously-set configuration is // discarded and any saved plan is cleared. -func (wd *WorkingDir) SetConfig(cfg string) error { +func (wd *WorkingDir) SetConfig(ctx context.Context, cfg string) error { configFilename := filepath.Join(wd.baseDir, ConfigFileName) err := ioutil.WriteFile(configFilename, []byte(cfg), 0700) if err != nil { @@ -106,7 +107,7 @@ func (wd *WorkingDir) SetConfig(cfg string) error { } // Changing configuration invalidates any saved plan. - err = wd.ClearPlan() + err = wd.ClearPlan(ctx) if err != nil { return err } @@ -117,31 +118,59 @@ func (wd *WorkingDir) SetConfig(cfg string) error { // // Any remote objects tracked by the state are not destroyed first, so this // will leave them dangling in the remote system. -func (wd *WorkingDir) ClearState() error { +func (wd *WorkingDir) ClearState(ctx context.Context) error { + logging.HelperResourceTrace(ctx, "Clearing Terraform state") + err := os.Remove(filepath.Join(wd.baseDir, "terraform.tfstate")) + if os.IsNotExist(err) { + logging.HelperResourceTrace(ctx, "No Terraform state to clear") return nil } - return err + + if err != nil { + return err + } + + logging.HelperResourceTrace(ctx, "Cleared Terraform state") + + return nil } // ClearPlan deletes any saved plan present in the working directory. -func (wd *WorkingDir) ClearPlan() error { +func (wd *WorkingDir) ClearPlan(ctx context.Context) error { + logging.HelperResourceTrace(ctx, "Clearing Terraform plan") + err := os.Remove(wd.planFilename()) + if os.IsNotExist(err) { + logging.HelperResourceTrace(ctx, "No Terraform plan to clear") return nil } - return err + + if err != nil { + return err + } + + logging.HelperResourceTrace(ctx, "Cleared Terraform plan") + + return nil } // Init runs "terraform init" for the given working directory, forcing Terraform // to use the current version of the plugin under test. -func (wd *WorkingDir) Init() error { +func (wd *WorkingDir) Init(ctx context.Context) error { if _, err := os.Stat(wd.configFilename()); err != nil { return fmt.Errorf("must call SetConfig before Init") } - return wd.tf.Init(context.Background(), tfexec.Reattach(wd.reattachInfo)) + logging.HelperResourceTrace(ctx, "Calling Terraform CLI init command") + + err := wd.tf.Init(context.Background(), tfexec.Reattach(wd.reattachInfo)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI init command") + + return err } func (wd *WorkingDir) configFilename() string { @@ -154,15 +183,25 @@ func (wd *WorkingDir) planFilename() string { // CreatePlan runs "terraform plan" to create a saved plan file, which if successful // will then be used for the next call to Apply. -func (wd *WorkingDir) CreatePlan() error { +func (wd *WorkingDir) CreatePlan(ctx context.Context) error { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI plan command") + _, err := wd.tf.Plan(context.Background(), tfexec.Reattach(wd.reattachInfo), tfexec.Refresh(false), tfexec.Out(PlanFileName)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI plan command") + return err } // CreateDestroyPlan runs "terraform plan -destroy" to create a saved plan // file, which if successful will then be used for the next call to Apply. -func (wd *WorkingDir) CreateDestroyPlan() error { +func (wd *WorkingDir) CreateDestroyPlan(ctx context.Context) error { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI plan -destroy command") + _, err := wd.tf.Plan(context.Background(), tfexec.Reattach(wd.reattachInfo), tfexec.Refresh(false), tfexec.Out(PlanFileName), tfexec.Destroy(true)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI plan -destroy command") + return err } @@ -170,13 +209,19 @@ func (wd *WorkingDir) CreateDestroyPlan() error { // successfully and the saved plan has not been cleared in the meantime then // this will apply the saved plan. Otherwise, it will implicitly create a new // plan and apply it. -func (wd *WorkingDir) Apply() error { +func (wd *WorkingDir) Apply(ctx context.Context) error { args := []tfexec.ApplyOption{tfexec.Reattach(wd.reattachInfo), tfexec.Refresh(false)} if wd.HasSavedPlan() { args = append(args, tfexec.DirOrPlan(PlanFileName)) } - return wd.tf.Apply(context.Background(), args...) + logging.HelperResourceTrace(ctx, "Calling Terraform CLI apply command") + + err := wd.tf.Apply(context.Background(), args...) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI apply command") + + return err } // Destroy runs "terraform destroy". It does not consider or modify any saved @@ -184,8 +229,14 @@ func (wd *WorkingDir) Apply() error { // // If destroy fails then remote objects might still exist, and continue to // exist after a particular test is concluded. -func (wd *WorkingDir) Destroy() error { - return wd.tf.Destroy(context.Background(), tfexec.Reattach(wd.reattachInfo), tfexec.Refresh(false)) +func (wd *WorkingDir) Destroy(ctx context.Context) error { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI destroy command") + + err := wd.tf.Destroy(context.Background(), tfexec.Reattach(wd.reattachInfo), tfexec.Refresh(false)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI destroy command") + + return err } // HasSavedPlan returns true if there is a saved plan in the working directory. If @@ -199,19 +250,25 @@ func (wd *WorkingDir) HasSavedPlan() bool { // // If no plan is saved or if the plan file cannot be read, SavedPlan returns // an error. -func (wd *WorkingDir) SavedPlan() (*tfjson.Plan, error) { +func (wd *WorkingDir) SavedPlan(ctx context.Context) (*tfjson.Plan, error) { if !wd.HasSavedPlan() { return nil, fmt.Errorf("there is no current saved plan") } - return wd.tf.ShowPlanFile(context.Background(), wd.planFilename(), tfexec.Reattach(wd.reattachInfo)) + logging.HelperResourceTrace(ctx, "Calling Terraform CLI apply command") + + plan, err := wd.tf.ShowPlanFile(context.Background(), wd.planFilename(), tfexec.Reattach(wd.reattachInfo)) + + logging.HelperResourceTrace(ctx, "Calling Terraform CLI apply command") + + return plan, err } // SavedPlanRawStdout returns a human readable stdout capture of the current saved plan file, if any. // // If no plan is saved or if the plan file cannot be read, SavedPlanRawStdout returns // an error. -func (wd *WorkingDir) SavedPlanRawStdout() (string, error) { +func (wd *WorkingDir) SavedPlanRawStdout(ctx context.Context) (string, error) { if !wd.HasSavedPlan() { return "", fmt.Errorf("there is no current saved plan") } @@ -220,7 +277,13 @@ func (wd *WorkingDir) SavedPlanRawStdout() (string, error) { wd.tf.SetStdout(&ret) defer wd.tf.SetStdout(ioutil.Discard) + + logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command") + _, err := wd.tf.ShowPlanFileRaw(context.Background(), wd.planFilename(), tfexec.Reattach(wd.reattachInfo)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI show command") + if err != nil { return "", err } @@ -232,23 +295,47 @@ func (wd *WorkingDir) SavedPlanRawStdout() (string, error) { // // If the state cannot be read, State returns an error. -func (wd *WorkingDir) State() (*tfjson.State, error) { - return wd.tf.Show(context.Background(), tfexec.Reattach(wd.reattachInfo)) +func (wd *WorkingDir) State(ctx context.Context) (*tfjson.State, error) { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI show command") + + state, err := wd.tf.Show(context.Background(), tfexec.Reattach(wd.reattachInfo)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI show command") + + return state, err } // Import runs terraform import -func (wd *WorkingDir) Import(resource, id string) error { - return wd.tf.Import(context.Background(), resource, id, tfexec.Config(wd.baseDir), tfexec.Reattach(wd.reattachInfo)) +func (wd *WorkingDir) Import(ctx context.Context, resource, id string) error { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI import command") + + err := wd.tf.Import(context.Background(), resource, id, tfexec.Config(wd.baseDir), tfexec.Reattach(wd.reattachInfo)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI import command") + + return err } // Refresh runs terraform refresh -func (wd *WorkingDir) Refresh() error { - return wd.tf.Refresh(context.Background(), tfexec.Reattach(wd.reattachInfo)) +func (wd *WorkingDir) Refresh(ctx context.Context) error { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI refresh command") + + err := wd.tf.Refresh(context.Background(), tfexec.Reattach(wd.reattachInfo)) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI refresh command") + + return err } // Schemas returns an object describing the provider schemas. // // If the schemas cannot be read, Schemas returns an error. -func (wd *WorkingDir) Schemas() (*tfjson.ProviderSchemas, error) { - return wd.tf.ProvidersSchema(context.Background()) +func (wd *WorkingDir) Schemas(ctx context.Context) (*tfjson.ProviderSchemas, error) { + logging.HelperResourceTrace(ctx, "Calling Terraform CLI providers schema command") + + providerSchemas, err := wd.tf.ProvidersSchema(context.Background()) + + logging.HelperResourceTrace(ctx, "Called Terraform CLI providers schema command") + + return providerSchemas, err }