Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 3 commits into from Apr 14, 2022

Conversation

bflad
Copy link
Member

@bflad bflad commented Apr 12, 2022

Reference: #922 (will wait to see if there are other issues before closing)

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:

$ 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
...

…H_MASK` environment variable value when both `TF_ACC_LOG_PATH` and `TF_LOG_PATH_MASK` are set

Reference: #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
...
```
@bflad bflad added the bug Something isn't working label Apr 12, 2022
@bflad bflad added this to the v2.14.0 milestone Apr 12, 2022
@bflad bflad requested a review from a team as a code owner April 12, 2022 18:39
Copy link
Contributor

@detro detro left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good, but I have a question about how we could ensure we don't log lines that can lead to confusion in case someone sets both env vars

@@ -124,6 +126,50 @@ 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)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I looked at https://pkg.go.dev/github.com/hashicorp/terraform-exec@v0.16.1/tfexec but I can't find exactly what setting that TF_DISABLE_PLUGIN_TLS means.

Does it mean that we want TF to not fetch providers using https?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Comment on lines 142 to 171
if logPath := os.Getenv(EnvTfAccLogPath); logPath != "" {
logging.HelperResourceTrace(
ctx,
fmt.Sprintf("Setting terraform-exec log path via %s environment variable", EnvTfAccLogPath),
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)
}
}

// 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 logPathMask := os.Getenv(EnvTfLogPathMask); logPathMask != "" {
// Escape special characters which may appear if we have subtests
testName := strings.Replace(t.Name(), "/", "__", -1)
logPath := fmt.Sprintf(logPathMask, testName)

logging.HelperResourceTrace(
ctx,
fmt.Sprintf("Setting terraform-exec log path via %s environment variable", EnvTfLogPathMask),
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)
}
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think technically this is spot on, but there is an issue I can imagine could confuse users: if one sets both TF_ACC_LOG_PATH and TF_LOG_PATH_MASK, the latter wins (agreed) but they will see 2 log traces. This could lead to confusion as we know that the latter log is the one to trust, but a practitioner won't necessarily follow the logic.

Could we instead check for those env vars presence, before we commit with a log and the remaining logic that sets logPath?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updated the implementation -- does this now do what you had in mind?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👨‍🍳 💋

Copy link
Contributor

@detro detro left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👩‍🍳 💋

@bflad bflad merged commit b8263cd into main Apr 14, 2022
@bflad bflad deleted the bflad-cli-tflogpathmask branch April 14, 2022 16:51
@github-actions
Copy link

I'm going to lock this pull request because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active contributions.
If you have found a problem that seems related to this change, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators May 15, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants