Nice debug logs (#463)

* Nice debug logs

* fixup! Merge branch 'main' into nice-debug-logs

Author: bbasata

.changes/unreleased/NOTES-20250325-084449.yaml

@@ -0,0 +1,5 @@
+kind: NOTES
+body: reduced the volume of DEBUG-level logging to make it easier to visually scan debug output
+time: 2025-03-25T08:44:49.949718-04:00
+custom:
+    Issue: "463"

helper/resource/plugin.go

@@ -178,14 +178,14 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 		providerName = strings.TrimPrefix(providerName, "terraform-provider-")
 		providerAddress := getProviderAddr(providerName)
 
-		logging.HelperResourceDebug(ctx, "Creating sdkv2 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Creating sdkv2 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		provider, err := factory()
 		if err != nil {
 			return fmt.Errorf("unable to create provider %q from factory: %w", providerName, err)
 		}
 
-		logging.HelperResourceDebug(ctx, "Created sdkv2 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Created sdkv2 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		// keep track of the running factory, so we can make sure it's
 		// shut down.
@@ -215,14 +215,14 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 			ProviderAddr:        providerAddress,
 		}
 
-		logging.HelperResourceDebug(ctx, "Starting sdkv2 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Starting sdkv2 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		config, closeCh, err := plugin.DebugServe(ctx, opts)
 		if err != nil {
 			return fmt.Errorf("unable to serve provider %q: %w", providerName, err)
 		}
 
-		logging.HelperResourceDebug(ctx, "Started sdkv2 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Started sdkv2 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		tfexecConfig := tfexec.ReattachConfig{
 			Protocol:        config.Protocol,
@@ -272,14 +272,14 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 			}
 		}
 
-		logging.HelperResourceDebug(ctx, "Creating tfprotov5 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Creating tfprotov5 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		provider, err := factory()
 		if err != nil {
 			return fmt.Errorf("unable to create provider %q from factory: %w", providerName, err)
 		}
 
-		logging.HelperResourceDebug(ctx, "Created tfprotov5 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Created tfprotov5 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		// keep track of the running factory, so we can make sure it's
 		// shut down.
@@ -303,14 +303,14 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 			ProviderAddr:        providerAddress,
 		}
 
-		logging.HelperResourceDebug(ctx, "Starting tfprotov5 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Starting tfprotov5 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		config, closeCh, err := plugin.DebugServe(ctx, opts)
 		if err != nil {
 			return fmt.Errorf("unable to serve provider %q: %w", providerName, err)
 		}
 
-		logging.HelperResourceDebug(ctx, "Started tfprotov5 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Started tfprotov5 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		tfexecConfig := tfexec.ReattachConfig{
 			Protocol:        config.Protocol,
@@ -361,14 +361,14 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 			}
 		}
 
-		logging.HelperResourceDebug(ctx, "Creating tfprotov6 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Creating tfprotov6 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		provider, err := factory()
 		if err != nil {
 			return fmt.Errorf("unable to create provider %q from factory: %w", providerName, err)
 		}
 
-		logging.HelperResourceDebug(ctx, "Created tfprotov6 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Created tfprotov6 provider instance", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		// keep track of the running factory, so we can make sure it's
 		// shut down.
@@ -388,14 +388,14 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 			ProviderAddr:        providerAddress,
 		}
 
-		logging.HelperResourceDebug(ctx, "Starting tfprotov6 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Starting tfprotov6 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		config, closeCh, err := plugin.DebugServe(ctx, opts)
 		if err != nil {
 			return fmt.Errorf("unable to serve provider %q: %w", providerName, err)
 		}
 
-		logging.HelperResourceDebug(ctx, "Started tfprotov6 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
+		logging.HelperResourceTrace(ctx, "Started tfprotov6 provider instance server", map[string]interface{}{logging.KeyProviderAddress: providerAddress})
 
 		tfexecConfig := tfexec.ReattachConfig{
 			Protocol:        config.Protocol,
@@ -441,7 +441,7 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
 	}
 
 	logging.HelperResourceTrace(ctx, "Called wrapped Terraform CLI command")
-	logging.HelperResourceDebug(ctx, "Stopping providers")
+	logging.HelperResourceTrace(ctx, "Stopping providers")
 
 	// cancel the servers so they'll return. Otherwise, this closeCh won't
 	// get closed, and we'll hang here.

helper/resource/testing.go

@@ -929,11 +929,7 @@ func Test(t testing.T, c TestCase) {
 	// This is done after creating the helper because a working directory is required
 	// to retrieve the Terraform version.
 	if c.TerraformVersionChecks != nil {
-		logging.HelperResourceDebug(ctx, "Calling TestCase Terraform version checks")
-
 		runTFVersionChecks(ctx, t, helper.TerraformVersion(), c.TerraformVersionChecks)
-
-		logging.HelperResourceDebug(ctx, "Called TestCase Terraform version checks")
 	}
 
 	runNewTest(ctx, t, c, helper)

helper/resource/testing_new.go

@@ -129,8 +129,6 @@ func runNewTest(ctx context.Context, t testing.T, c TestCase, helper *plugintest
 		}
 	}
 
-	logging.HelperResourceDebug(ctx, "Starting TestSteps")
-
 	// use this to track last step successfully applied
 	// acts as default for import tests
 	var appliedCfg string