feat: log resource drift as warning in build logs

dannykopping · dannykopping · commit 8d86feb5260c · 2025-06-13T10:11:44.000+02:00
Signed-off-by: Danny Kopping &lt;dannykopping@gmail.com&gt;
diff --git a/provisioner/terraform/executor.go b/provisioner/terraform/executor.go
@@ -322,20 +322,12 @@ func (e *executor) plan(ctx, killCtx context.Context, env, vars []string, logr l
 
 	// When a prebuild claim attempt is made, log a warning if a resource is due to be replaced, since this will obviate
 	// the point of prebuilding if the expensive resource is replaced once claimed!
-	var (
-		isPrebuildClaimAttempt = !destroy && metadata.GetPrebuiltWorkspaceBuildStage().IsPrebuiltWorkspaceClaim()
-		resReps                []*proto.ResourceReplacement
-	)
+	// We now also log drift for all builds to help with debugging resource replacements.
+	var resReps []*proto.ResourceReplacement
 	if repsFromPlan := findResourceReplacements(plan); len(repsFromPlan) > 0 {
-		if isPrebuildClaimAttempt {
-			// TODO(dannyk): we should log drift always (not just during prebuild claim attempts); we're validating that this output
-			//				 will not be overwhelming for end-users, but it'll certainly be super valuable for template admins
-			//				 to diagnose this resource replacement issue, at least.
-			//				 Once prebuilds moves out of beta, consider deleting this condition.
-
-			// Lock held before calling (see top of method).
-			e.logDrift(ctx, killCtx, planfilePath, logr)
-		}
+		// Log drift details for all builds to help with debugging resource replacements.
+		// Lock held before calling (see top of method).
+		e.logDrift(ctx, killCtx, planfilePath, logr)
 
 		resReps = make([]*proto.ResourceReplacement, 0, len(repsFromPlan))
 		for n, p := range repsFromPlan {
diff --git a/provisioner/terraform/executor_internal_test.go b/provisioner/terraform/executor_internal_test.go
@@ -1,13 +1,21 @@
 package terraform
 
 import (
+	"context"
 	"encoding/json"
+	"os"
+	"path/filepath"
+	"strings"
+	"sync"
 	"testing"
 
 	tfjson "github.com/hashicorp/terraform-json"
 	"github.com/stretchr/testify/require"
+	"go.opentelemetry.io/otel/trace/noop"
 
+	"github.com/coder/coder/v2/coderd/database"
 	"github.com/coder/coder/v2/provisionersdk/proto"
+	"github.com/coder/coder/v2/testutil"
 )
 
 type mockLogger struct {
@@ -173,3 +181,180 @@ func TestOnlyDataResources(t *testing.T) {
 		})
 	}
 }
+
+func TestLogDrift_WithRealTerraformPlan(t *testing.T) {
+	t.Parallel()
+
+	logger := testutil.Logger(t)
+	tmpDir := t.TempDir()
+
+	binPath, err := Install(t.Context(), logger, true, tmpDir, TerraformVersion)
+	require.NoError(t, err)
+
+	tfConfig := `
+terraform {
+  required_providers {
+    local = {
+      source = "hashicorp/local"
+      version = "~> 2.0"
+    }
+  }
+}
+
+resource "local_file" "test_file" {
+  content  = "initial content"
+  filename = "test.txt"
+}
+`
+
+	tfFile := filepath.Join(tmpDir, "main.tf")
+	require.NoError(t, os.WriteFile(tfFile, []byte(tfConfig), 0o644))
+
+	// Create a minimal server for the executor.
+	mockSrv := &server{
+		logger:  logger,
+		execMut: &sync.Mutex{},
+		tracer:  noop.NewTracerProvider().Tracer("test"),
+	}
+
+	e := &executor{
+		logger:     logger,
+		binaryPath: binPath,
+		workdir:    tmpDir,
+		mut:        mockSrv.execMut,
+		server:     mockSrv,
+		timings:    newTimingAggregator(database.ProvisionerJobTimingStagePlan),
+	}
+
+	// These contexts must be explicitly separate from the test context.
+	// We have a log message which prints when these contexts are canceled (or when the test completes if using t.Context()),
+	// and this log output would be confusing to the casual reader, while innocuous.
+	// See interruptCommandOnCancel in executor.go.
+	ctx := context.Background()
+	killCtx := context.Background()
+
+	var mockSink mockLogger
+	err = e.init(ctx, killCtx, &mockSink)
+	require.NoError(t, err)
+
+	// Create initial plan to establish state.
+	_, err = e.plan(ctx, killCtx, e.basicEnv(), []string{}, &mockSink, &proto.Metadata{
+		WorkspaceTransition: proto.WorkspaceTransition_START,
+	})
+	require.NoError(t, err)
+
+	// Apply the plan to create initial state.
+	_, err = e.apply(ctx, killCtx, e.basicEnv(), &mockSink)
+	require.NoError(t, err)
+
+	// Now modify the terraform configuration to cause drift.
+	driftConfig := `
+terraform {
+  required_providers {
+    local = {
+      source = "hashicorp/local"
+      version = "~> 2.0"
+    }
+  }
+}
+
+resource "local_file" "test_file" {
+  content  = "changed content that forces replacement"
+  filename = "test.txt"
+}
+`
+
+	// Write the modified configuration.
+	require.NoError(t, os.WriteFile(tfFile, []byte(driftConfig), 0o644))
+
+	// Create a new plan that will show the drift/replacement.
+	driftLogger := &mockLogger{}
+	planResult, err := e.plan(ctx, killCtx, e.basicEnv(), []string{}, driftLogger, &proto.Metadata{
+		WorkspaceTransition: proto.WorkspaceTransition_START,
+	})
+	require.NoError(t, err)
+
+	// Verify we detected resource replacements (this triggers logDrift).
+	require.NotEmpty(t, planResult.ResourceReplacements, "Should detect resource replacements that trigger drift logging")
+
+	// Verify that drift logs were captured.
+	require.NotEmpty(t, driftLogger.logs, "logDrift should produce log output")
+
+	// Check that we have logs showing the resource replacement(s).
+	var (
+		foundReplacementLog, foundInfoLogs, foundWarnLogs bool
+	)
+
+	for _, log := range driftLogger.logs {
+		t.Logf("[%s] %s", log.Level.String(), log.Output)
+
+		if strings.Contains(log.Output, "# forces replacement") {
+			foundReplacementLog = true
+			require.Equal(t, proto.LogLevel_WARN, log.Level, "Lines containing '# forces replacement' should be logged at WARN level")
+			foundWarnLogs = true
+		}
+
+		if log.Level == proto.LogLevel_INFO {
+			foundInfoLogs = true
+		}
+	}
+
+	// Verify we found the expected log types.
+	require.True(t, foundReplacementLog, "Should find log lines containing '# forces replacement'")
+	require.True(t, foundInfoLogs, "Should find INFO level logs showing the drift details")
+	require.True(t, foundWarnLogs, "Should find WARN level logs for resource replacements")
+
+	// Verify that the drift shows the resource change.
+	logOutput := strings.Join(func() []string {
+		var outputs []string
+		for _, log := range driftLogger.logs {
+			outputs = append(outputs, log.Output)
+		}
+		return outputs
+	}(), "\n")
+
+	require.Contains(t, logOutput, "local_file.test_file", "Drift logs should mention the specific resource")
+}
+
+func TestResourceReplaceLogWriter(t *testing.T) {
+	t.Parallel()
+
+	var logr mockLogger
+	logger := testutil.Logger(t)
+	writer, doneLogging := resourceReplaceLogWriter(&logr, logger)
+
+	// Test input with both normal lines and replacement lines.
+	testInput := `  # local_file.test_file will be replaced
+-/+ resource "local_file" "test_file" {
+      ~ content  = "initial content" -> "changed content" # forces replacement
+      ~ filename = "test.txt"
+        id       = "1234567890"
+    }
+
+Plan: 1 to add, 0 to change, 1 to destroy.`
+
+	_, err := writer.Write([]byte(testInput))
+	require.NoError(t, err)
+	err = writer.Close()
+	require.NoError(t, err)
+	<-doneLogging
+
+	// Verify the logs
+	require.NotEmpty(t, logr.logs, "Should produce log output")
+
+	var foundReplacementWarn, foundInfoLogs bool
+
+	for _, log := range logr.logs {
+		t.Logf("[%s] %s", log.Level.String(), log.Output)
+
+		if strings.Contains(log.Output, "# forces replacement") {
+			require.Equal(t, proto.LogLevel_WARN, log.Level, "Lines containing '# forces replacement' should be WARN level")
+			foundReplacementWarn = true
+		} else if log.Level == proto.LogLevel_INFO {
+			foundInfoLogs = true
+		}
+	}
+
+	require.True(t, foundReplacementWarn, "Should find WARN level log for '# forces replacement' line")
+	require.True(t, foundInfoLogs, "Should find INFO level logs for other lines")
+}
