From b8263cd69daee2ffd2750e0dbd65bbeca1b18b18 Mon Sep 17 00:00:00 2001 From: Brian Flad Date: Thu, 14 Apr 2022 12:51:54 -0400 Subject: [PATCH] helper/resource: Ensure Terraform CLI logs are written to `TF_LOG_PATH_MASK` environment variable value when both `TF_ACC_LOG_PATH` and `TF_LOG_PATH_MASK` are set (#938) Reference: https://github.com/hashicorp/terraform-plugin-sdk/issues/922 The code refactoring centralizes all `(tfexec.Terraform).Set*` method calls right after `NewTerraform()` to ensure everything is immediately configured as expected. Verification via terraform-provider-corner after `go mod edit -replace`: ```console $ TF_ACC=1 TF_LOG=TRACE TF_ACC_LOG_PATH=/tmp/oops.txt TF_LOG_PATH_MASK=/tmp/better-%s.txt go test -count=1 -run='TestAccFrameworkResourceUser_interpolateLanguage' -v ./internal/frameworkprovider === RUN TestAccFrameworkResourceUser_interpolateLanguage --- PASS: TestAccFrameworkResourceUser_interpolateLanguage (3.33s) PASS ok github.com/hashicorp/terraform-provider-corner/internal/frameworkprovider 3.659s $ ls /tmp/*.txt /tmp/better-TestAccFrameworkResourceUser_interpolateLanguage.txt /tmp/oops.txt $ cat /tmp/oops.txt $ head -20 /tmp/better-TestAccFrameworkResourceUser_interpolateLanguage.txt 2022-04-12T14:28:37.074-0400 [DEBUG] sdk.helper_resource: Starting TestCase: test_name=TestAccFrameworkResourceUser_interpolateLanguage 2022-04-12T14:28:37.074-0400 [TRACE] sdk.helper_resource: Adding potential Terraform CLI source of local filesystem PATH lookup: test_name=TestAccFrameworkResourceUser_interpolateLanguage 2022-04-12T14:28:37.074-0400 [TRACE] sdk.helper_resource: Adding potential Terraform CLI source of checkpoint.hashicorp.com latest version for installation in: /var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest-terraform902259129: test_name=TestAccFrameworkResourceUser_interpolateLanguage 2022-04-12T14:28:37.075-0400 [DEBUG] sdk.helper_resource: Found Terraform CLI: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform 2022-04-12T14:28:37.075-0400 [TRACE] sdk.helper_resource: Symlinking source directories to work directory: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273/work2021050956 2022-04-12T14:28:37.111-0400 [TRACE] sdk.helper_resource: Setting terraform-exec log path via TF_ACC_LOG_PATH environment variable: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273/work2021050956 test_terraform_log_path=/tmp/oops.txt 2022-04-12T14:28:37.111-0400 [TRACE] sdk.helper_resource: Setting terraform-exec log path via TF_LOG_PATH_MASK environment variable: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273/work2021050956 test_terraform_log_path=/tmp/better-TestAccFrameworkResourceUser_interpolateLanguage.txt 2022-04-12T14:28:37.112-0400 [TRACE] sdk.helper_resource: Clearing Terraform plan: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 2022-04-12T14:28:37.112-0400 [TRACE] sdk.helper_resource: No Terraform plan to clear: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 2022-04-12T14:28:37.112-0400 [DEBUG] sdk.helper_resource: Creating tfprotov6 provider instance: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 tf_provider_addr=registry.terraform.io/hashicorp/framework 2022-04-12T14:28:37.112-0400 [DEBUG] sdk.helper_resource: Created tfprotov6 provider instance: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 tf_provider_addr=registry.terraform.io/hashicorp/framework 2022-04-12T14:28:37.112-0400 [DEBUG] sdk.helper_resource: Starting tfprotov6 provider instance server: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 tf_provider_addr=registry.terraform.io/hashicorp/framework 2022-04-12T14:28:37.113-0400 [DEBUG] sdk.helper_resource: Started tfprotov6 provider instance server: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 tf_provider_addr=registry.terraform.io/hashicorp/framework 2022-04-12T14:28:37.113-0400 [TRACE] sdk.helper_resource: Setting Terraform CLI reattach configuration: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 tf_reattach_config="map[registry.terraform.io/-/framework:{grpc 6 62287 true {unix /var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugin1464887819}} registry.terraform.io/hashicorp/framework:{grpc 6 62287 true {unix /var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugin1464887819}}]" 2022-04-12T14:28:37.113-0400 [TRACE] sdk.helper_resource: Calling wrapped Terraform CLI command: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 2022-04-12T14:28:37.113-0400 [TRACE] sdk.helper_resource: Calling Terraform CLI init command: test_name=TestAccFrameworkResourceUser_interpolateLanguage test_terraform_path=/usr/local/bin/terraform test_working_directory=/var/folders/w8/05f3x02n27x72g0mc2jy6_180000gp/T/plugintest1623391273 2022-04-12T14:28:37.144-0400 [INFO] Terraform version: 1.1.8 2022-04-12T14:28:37.144-0400 [INFO] Go runtime version: go1.17.2 2022-04-12T14:28:37.144-0400 [INFO] CLI args: []string{"/usr/local/bin/terraform", "init", "-no-color", "-force-copy", "-input=false", "-backend=true", "-get=true", "-upgrade=false"} 2022-04-12T14:28:37.144-0400 [TRACE] Stdout is not a terminal ... ``` --- .changelog/938.txt | 3 ++ internal/logging/keys.go | 6 +++ internal/plugintest/environment_variables.go | 11 +++++ internal/plugintest/guard.go | 1 + internal/plugintest/helper.go | 48 +++++++++++++++++++- internal/plugintest/working_dir.go | 17 ------- 6 files changed, 67 insertions(+), 19 deletions(-) create mode 100644 .changelog/938.txt diff --git a/.changelog/938.txt b/.changelog/938.txt new file mode 100644 index 00000000000..0ce23689567 --- /dev/null +++ b/.changelog/938.txt @@ -0,0 +1,3 @@ +```release-note:bug +helper/resource: Ensured Terraform CLI logs are written to `TF_LOG_PATH_MASK` environment variable value when both `TF_ACC_LOG_PATH` and `TF_LOG_PATH_MASK` are set +``` diff --git a/internal/logging/keys.go b/internal/logging/keys.go index 5cc6068010d..2ba548f61d5 100644 --- a/internal/logging/keys.go +++ b/internal/logging/keys.go @@ -31,6 +31,12 @@ const ( // The TestStep number of the test being executed. Starts at 1. KeyTestStepNumber = "test_step_number" + // The path to the Terraform CLI logging file used for an acceptance test. + // + // This should match where the rest of the acceptance test logs are going + // already, but is provided for troubleshooting in case it does not. + KeyTestTerraformLogPath = "test_terraform_log_path" + // The path to the Terraform CLI used for an acceptance test. KeyTestTerraformPath = "test_terraform_path" diff --git a/internal/plugintest/environment_variables.go b/internal/plugintest/environment_variables.go index 4aa7c57c69c..ac75151a4e8 100644 --- a/internal/plugintest/environment_variables.go +++ b/internal/plugintest/environment_variables.go @@ -14,8 +14,19 @@ const ( // testing. This value sets TF_LOG_PATH in a safe manner when executing // Terraform CLI commands, which would otherwise be ignored since it could // interfere with how the underlying execution is performed. + // + // If TF_LOG_PATH_MASK is set, it takes precedence over this value. EnvTfAccLogPath = "TF_ACC_LOG_PATH" + // Environment variable with path containing the string %s, which is + // replaced with the test name, to save separate Terraform logs during + // acceptance testing. This value sets TF_LOG_PATH in a safe manner when + // executing Terraform CLI commands, which would otherwise be ignored since + // it could interfere with how the underlying execution is performed. + // + // Takes precedence over TF_ACC_LOG_PATH. + EnvTfLogPathMask = "TF_LOG_PATH_MASK" + // Environment variable with acceptance testing Terraform CLI version to // download from releases.hashicorp.com, checksum verify, and install. The // value can be any valid Terraform CLI version, such as 1.1.6, with or diff --git a/internal/plugintest/guard.go b/internal/plugintest/guard.go index 4d3270ef446..ad796be08c6 100644 --- a/internal/plugintest/guard.go +++ b/internal/plugintest/guard.go @@ -19,6 +19,7 @@ type TestControl interface { Log(args ...interface{}) FailNow() SkipNow() + Name() string } // testingT wraps a TestControl to recover some of the convenience behaviors diff --git a/internal/plugintest/helper.go b/internal/plugintest/helper.go index a1d358c6cd3..d5aecd87bce 100644 --- a/internal/plugintest/helper.go +++ b/internal/plugintest/helper.go @@ -2,9 +2,11 @@ package plugintest import ( "context" + "errors" "fmt" "io/ioutil" "os" + "strings" "github.com/hashicorp/terraform-exec/tfexec" "github.com/hashicorp/terraform-plugin-sdk/v2/internal/logging" @@ -102,7 +104,7 @@ 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(ctx context.Context) (*WorkingDir, error) { +func (h *Helper) NewWorkingDir(ctx context.Context, t TestControl) (*WorkingDir, error) { dir, err := ioutil.TempDir(h.baseDir, "work") if err != nil { return nil, err @@ -124,6 +126,48 @@ func (h *Helper) NewWorkingDir(ctx context.Context) (*WorkingDir, error) { return nil, fmt.Errorf("unable to create terraform-exec instance: %w", err) } + err = tf.SetDisablePluginTLS(true) + + if err != nil { + return nil, fmt.Errorf("unable to disable terraform-exec plugin TLS: %w", err) + } + + err = tf.SetSkipProviderVerify(true) // Only required for Terraform CLI 0.12.x + + var mismatch *tfexec.ErrVersionMismatch + if err != nil && !errors.As(err, &mismatch) { + return nil, fmt.Errorf("unable to disable terraform-exec provider verification: %w", err) + } + + var logPath, logPathEnvVar string + + if tfAccLogPath := os.Getenv(EnvTfAccLogPath); tfAccLogPath != "" { + logPath = tfAccLogPath + logPathEnvVar = EnvTfAccLogPath + } + + // Similar to helper/logging.LogOutput() and + // terraform-plugin-log/tfsdklog.RegisterTestSink(), the TF_LOG_PATH_MASK + // environment variable should take precedence over TF_ACC_LOG_PATH. + if tfLogPathMask := os.Getenv(EnvTfLogPathMask); tfLogPathMask != "" { + // Escape special characters which may appear if we have subtests + testName := strings.Replace(t.Name(), "/", "__", -1) + logPath = fmt.Sprintf(tfLogPathMask, testName) + logPathEnvVar = EnvTfLogPathMask + } + + if logPath != "" { + logging.HelperResourceTrace( + ctx, + fmt.Sprintf("Setting terraform-exec log path via %s environment variable", logPathEnvVar), + map[string]interface{}{logging.KeyTestTerraformLogPath: logPath}, + ) + + if err := tf.SetLogPath(logPath); err != nil { + return nil, fmt.Errorf("unable to set terraform-exec log path (%s): %w", logPath, err) + } + } + return &WorkingDir{ h: h, tf: tf, @@ -138,7 +182,7 @@ func (h *Helper) NewWorkingDir(ctx context.Context) (*WorkingDir, error) { func (h *Helper) RequireNewWorkingDir(ctx context.Context, t TestControl) *WorkingDir { t.Helper() - wd, err := h.NewWorkingDir(ctx) + wd, err := h.NewWorkingDir(ctx, t) if err != nil { t := testingT{t} t.Fatalf("failed to create new working directory: %s", err) diff --git a/internal/plugintest/working_dir.go b/internal/plugintest/working_dir.go index 6a398a9ea12..5309fcfb0a0 100644 --- a/internal/plugintest/working_dir.go +++ b/internal/plugintest/working_dir.go @@ -4,7 +4,6 @@ import ( "bytes" "context" "encoding/json" - "errors" "fmt" "io/ioutil" "os" @@ -91,22 +90,6 @@ func (wd *WorkingDir) SetConfig(ctx context.Context, cfg string) error { } wd.configFilename = outFilename - var mismatch *tfexec.ErrVersionMismatch - err = wd.tf.SetDisablePluginTLS(true) - if err != nil && !errors.As(err, &mismatch) { - return err - } - err = wd.tf.SetSkipProviderVerify(true) - if err != nil && !errors.As(err, &mismatch) { - return err - } - - if p := os.Getenv(EnvTfAccLogPath); p != "" { - if err := wd.tf.SetLogPath(p); err != nil { - return fmt.Errorf("unable to set log path: %w", err) - } - } - // Changing configuration invalidates any saved plan. err = wd.ClearPlan(ctx) if err != nil {