Logging Strategies

6 minute read

Logging Overview

Effective logging is crucial for understanding provider behavior, debugging issues, and maintaining production systems. The Plugin Framework uses tflog for structured, context-aware logging.

Log Levels

Available Levels

import "github.com/hashicorp/terraform-plugin-log/tflog"

// TRACE: Very detailed information
tflog.Trace(ctx, "Entering function")

// DEBUG: Detailed debugging information
tflog.Debug(ctx, "Cache configuration", map[string]interface{}{
    "name": "test-cache",
    "type": "redis",
})

// INFO: Informational messages
tflog.Info(ctx, "Cache created successfully")

// WARN: Warning messages
tflog.Warn(ctx, "Using deprecated configuration")

// ERROR: Error messages
tflog.Error(ctx, "Failed to create cache", map[string]interface{}{
    "error": err.Error(),
})

When to Use Each Level

// TRACE: Function entry/exit, detailed flow
func (r *CacheResource) Create(ctx context.Context, req resource.CreateRequest, resp *resource.CreateResponse) {
    tflog.Trace(ctx, "CacheResource.Create started")
    defer tflog.Trace(ctx, "CacheResource.Create completed")
    
    // Implementation...
}

// DEBUG: Important values, decision points
tflog.Debug(ctx, "Validating cache configuration", map[string]interface{}{
    "name":      plan.Name.ValueString(),
    "node_type": plan.NodeType.ValueString(),
})

// INFO: Significant operations
tflog.Info(ctx, "Cache creation initiated", map[string]interface{}{
    "cache_id": cacheID,
})

// WARN: Deprecated features, suboptimal configs
if config.LegacyMode.ValueBool() {
    tflog.Warn(ctx, "Legacy mode is deprecated and will be removed in v3.0")
}

// ERROR: Operation failures
if err != nil {
    tflog.Error(ctx, "API request failed", map[string]interface{}{
        "operation": "CreateCache",
        "error":     err.Error(),
    })
}

Structured Logging

Basic Structure

func (r *CacheResource) Create(ctx context.Context, req resource.CreateRequest, resp *resource.CreateResponse) {
    var plan CacheResourceModel
    resp.Diagnostics.Append(req.Plan.Get(ctx, &plan)...)
    
    tflog.Debug(ctx, "Creating cache", map[string]interface{}{
        "name":           plan.Name.ValueString(),
        "node_type":      plan.NodeType.ValueString(),
        "engine":         plan.Engine.ValueString(),
        "engine_version": plan.EngineVersion.ValueString(),
    })
    
    // Create cache
    cache, err := r.client.CreateCache(ctx, &client.CreateCacheInput{
        Name:          plan.Name.ValueString(),
        NodeType:      plan.NodeType.ValueString(),
        Engine:        plan.Engine.ValueString(),
        EngineVersion: plan.EngineVersion.ValueString(),
    })
    
    if err != nil {
        tflog.Error(ctx, "Failed to create cache", map[string]interface{}{
            "name":  plan.Name.ValueString(),
            "error": err.Error(),
        })
        resp.Diagnostics.AddError("API Error", fmt.Sprintf("Failed to create cache: %s", err))
        return
    }
    
    tflog.Info(ctx, "Cache created successfully", map[string]interface{}{
        "cache_id": cache.ID,
        "name":     cache.Name,
    })
}

Complex Objects

func logNetworkConfig(ctx context.Context, config *NetworkConfigModel) {
    var subnets []string
    config.SubnetIDs.ElementsAs(ctx, &subnets, false)
    
    var securityGroups []string
    config.SecurityGroupIDs.ElementsAs(ctx, &securityGroups, false)
    
    tflog.Debug(ctx, "Network configuration", map[string]interface{}{
        "vpc_id":           config.VPCID.ValueString(),
        "subnet_ids":       subnets,
        "security_groups":  securityGroups,
        "subnet_count":     len(subnets),
        "security_group_count": len(securityGroups),
    })
}

Context-Aware Logging

Subsystem Logging

// Create subsystem logger
func (r *CacheResource) Read(ctx context.Context, req resource.ReadRequest, resp *resource.ReadResponse) {
    // Add subsystem to context
    ctx = tflog.SetField(ctx, "resource", "cachecloud_cache")
    ctx = tflog.SetField(ctx, "operation", "read")
    
    tflog.Debug(ctx, "Reading cache state")
    
    // Logs will include subsystem fields automatically
}

Request ID Tracking

func (r *CacheResource) Create(ctx context.Context, req resource.CreateRequest, resp *resource.CreateResponse) {
    // Generate request ID
    requestID := uuid.New().String()
    ctx = tflog.SetField(ctx, "request_id", requestID)
    
    tflog.Info(ctx, "Starting cache creation")
    
    // All subsequent logs will include request_id
    result, err := r.client.CreateCache(ctx, input)
    
    if err != nil {
        tflog.Error(ctx, "Creation failed")
        // Error log includes request_id
        return
    }
    
    tflog.Info(ctx, "Creation completed")
    // Success log includes request_id
}

User Identity

func (p *provider) Configure(ctx context.Context, req provider.ConfigureRequest, resp *provider.ConfigureResponse) {
    var config providerModel
    resp.Diagnostics.Append(req.Config.Get(ctx, &config)...)
    
    // Add provider-level context
    ctx = tflog.SetField(ctx, "provider_version", "2.0.0")
    ctx = tflog.SetField(ctx, "api_endpoint", config.Endpoint.ValueString())
    
    // Verify credentials and add user info
    user, err := verifyCredentials(ctx, config.APIKey.ValueString())
    if err == nil {
        ctx = tflog.SetField(ctx, "user_id", user.ID)
        ctx = tflog.SetField(ctx, "organization", user.Organization)
    }
    
    tflog.Info(ctx, "Provider configured")
}

Sensitive Data Handling

Redaction

// Mask sensitive values
func (r *CacheResource) Create(ctx context.Context, req resource.CreateRequest, resp *resource.CreateResponse) {
    var plan CacheResourceModel
    resp.Diagnostics.Append(req.Plan.Get(ctx, &plan)...)
    
    // Create masked logger for sensitive fields
    ctx = tflog.MaskFieldValuesWithFieldKeys(ctx, "password")
    ctx = tflog.MaskFieldValuesWithFieldKeys(ctx, "api_key")
    ctx = tflog.MaskFieldValuesWithFieldKeys(ctx, "auth_token")
    
    tflog.Debug(ctx, "Creating cache with auth", map[string]interface{}{
        "name":     plan.Name.ValueString(),
        "password": plan.Password.ValueString(), // Will be masked
    })
}

Manual Masking

func maskSensitiveString(s string) string {
    if len(s) <= 4 {
        return "***"
    }
    return s[:2] + "***" + s[len(s)-2:]
}

tflog.Debug(ctx, "API key configured", map[string]interface{}{
    "api_key": maskSensitiveString(apiKey),
})

Performance Logging

Operation Timing

func (r *CacheResource) Read(ctx context.Context, req resource.ReadRequest, resp *resource.ReadResponse) {
    start := time.Now()
    defer func() {
        duration := time.Since(start)
        tflog.Debug(ctx, "Read operation completed", map[string]interface{}{
            "duration_ms": duration.Milliseconds(),
        })
    }()
    
    // Implementation...
}

API Call Metrics

type MetricsLogger struct {
    mu              sync.RWMutex
    operationCounts map[string]int64
    operationTimes  map[string][]time.Duration
}

func (m *MetricsLogger) LogAPICall(ctx context.Context, operation string, duration time.Duration, err error) {
    m.mu.Lock()
    m.operationCounts[operation]++
    m.operationTimes[operation] = append(m.operationTimes[operation], duration)
    m.mu.Unlock()
    
    tflog.Debug(ctx, "API call completed", map[string]interface{}{
        "operation":   operation,
        "duration_ms": duration.Milliseconds(),
        "success":     err == nil,
    })
}

func (m *MetricsLogger) LogSummary(ctx context.Context) {
    m.mu.RLock()
    defer m.mu.RUnlock()
    
    tflog.Info(ctx, "Operation summary", map[string]interface{}{
        "total_operations": len(m.operationCounts),
        "operations":       m.operationCounts,
    })
}

Client Logging

HTTP Request Logging

type LoggingTransport struct {
    next http.RoundTripper
}

func (t *LoggingTransport) RoundTrip(req *http.Request) (*http.Response, error) {
    ctx := req.Context()
    start := time.Now()
    
    // Log request
    tflog.Trace(ctx, "HTTP request", map[string]interface{}{
        "method": req.Method,
        "url":    req.URL.String(),
        "headers": sanitizeHeaders(req.Header),
    })
    
    resp, err := t.next.RoundTrip(req)
    
    duration := time.Since(start)
    
    if err != nil {
        tflog.Error(ctx, "HTTP request failed", map[string]interface{}{
            "method":      req.Method,
            "url":         req.URL.String(),
            "error":       err.Error(),
            "duration_ms": duration.Milliseconds(),
        })
        return nil, err
    }
    
    tflog.Debug(ctx, "HTTP response", map[string]interface{}{
        "method":      req.Method,
        "url":         req.URL.String(),
        "status":      resp.StatusCode,
        "duration_ms": duration.Milliseconds(),
    })
    
    return resp, nil
}

func sanitizeHeaders(headers http.Header) map[string]string {
    sanitized := make(map[string]string)
    for key, values := range headers {
        if strings.ToLower(key) == "authorization" {
            sanitized[key] = "***REDACTED***"
        } else {
            sanitized[key] = strings.Join(values, ", ")
        }
    }
    return sanitized
}

Error Logging

Comprehensive Error Context

func (r *CacheResource) Update(ctx context.Context, req resource.UpdateRequest, resp *resource.UpdateResponse) {
    var plan, state CacheResourceModel
    resp.Diagnostics.Append(req.Plan.Get(ctx, &plan)...)
    resp.Diagnostics.Append(req.State.Get(ctx, &state)...)
    
    if resp.Diagnostics.HasError() {
        tflog.Error(ctx, "Failed to retrieve state", map[string]interface{}{
            "diagnostics": diagnosticsToStrings(resp.Diagnostics),
        })
        return
    }
    
    // Update operation
    updated, err := r.client.UpdateCache(ctx, state.ID.ValueString(), &client.UpdateCacheInput{
        Name:     plan.Name.ValueString(),
        NodeType: plan.NodeType.ValueString(),
    })
    
    if err != nil {
        // Log detailed error information
        tflog.Error(ctx, "Update operation failed", map[string]interface{}{
            "cache_id":   state.ID.ValueString(),
            "old_name":   state.Name.ValueString(),
            "new_name":   plan.Name.ValueString(),
            "error":      err.Error(),
            "error_type": fmt.Sprintf("%T", err),
        })
        
        // Check for specific error types
        if apiErr, ok := err.(*client.APIError); ok {
            tflog.Error(ctx, "API error details", map[string]interface{}{
                "status_code": apiErr.StatusCode,
                "error_code":  apiErr.Code,
                "message":     apiErr.Message,
            })
        }
        
        resp.Diagnostics.AddError("Update Failed", fmt.Sprintf("Failed to update cache: %s", err))
        return
    }
    
    tflog.Info(ctx, "Cache updated successfully", map[string]interface{}{
        "cache_id": updated.ID,
        "name":     updated.Name,
    })
}

func diagnosticsToStrings(diags diag.Diagnostics) []string {
    var result []string
    for _, d := range diags {
        result = append(result, fmt.Sprintf("%s: %s", d.Summary(), d.Detail()))
    }
    return result
}

Log Configuration

Environment Variables

# Set log level
export TF_LOG=TRACE
export TF_LOG=DEBUG
export TF_LOG=INFO
export TF_LOG=WARN
export TF_LOG=ERROR

# Provider-specific logging
export TF_LOG_PROVIDER=TRACE

# Save logs to file
export TF_LOG_PATH=terraform.log

Conditional Logging

func (r *CacheResource) Read(ctx context.Context, req resource.ReadRequest, resp *resource.ReadResponse) {
    // Only log verbose details in TRACE mode
    if os.Getenv("TF_LOG") == "TRACE" {
        tflog.Trace(ctx, "Detailed state information", map[string]interface{}{
            "full_state": fmt.Sprintf("%+v", state),
        })
    }
    
    // Always log important information
    tflog.Info(ctx, "Reading cache", map[string]interface{}{
        "cache_id": state.ID.ValueString(),
    })
}

Testing with Logs

Capture Logs in Tests

func TestCacheResource_Create(t *testing.T) {
    var logOutput strings.Builder
    
    // Create context with log sink
    ctx := tflogtest.RootLogger(context.Background(), &logOutput)
    
    // Run test
    r := NewCacheResource()
    // ... test logic ...
    
    // Verify logs
    logs := logOutput.String()
    assert.Contains(t, logs, "Creating cache")
    assert.Contains(t, logs, "Cache created successfully")
}

Verify Log Levels

func TestLoggingLevels(t *testing.T) {
    tests := []struct {
        level    string
        contains []string
        excludes []string
    }{
        {
            level:    "ERROR",
            contains: []string{"ERROR"},
            excludes: []string{"DEBUG", "INFO"},
        },
        {
            level:    "DEBUG",
            contains: []string{"DEBUG", "INFO", "ERROR"},
            excludes: []string{"TRACE"},
        },
    }
    
    for _, tt := range tests {
        t.Run(tt.level, func(t *testing.T) {
            os.Setenv("TF_LOG", tt.level)
            // Run operation and check logs
        })
    }
}

Best Practices

1. Consistent Structure

// ✅ Good: Consistent key names
tflog.Debug(ctx, "Operation started", map[string]interface{}{
    "resource_id":   id,
    "resource_name": name,
    "operation":     "create",
})

// ❌ Bad: Inconsistent keys
tflog.Debug(ctx, "Op start", map[string]interface{}{
    "id":   id,
    "Name": name,
    "op":   "create",
})

2. Meaningful Messages

// ✅ Good: Clear, descriptive message
tflog.Info(ctx, "Cache cluster scaling initiated", map[string]interface{}{
    "cluster_id":      clusterID,
    "current_nodes":   currentCount,
    "target_nodes":    targetCount,
})

// ❌ Bad: Vague message
tflog.Info(ctx, "Scaling", map[string]interface{}{
    "id": clusterID,
})

3. Appropriate Level

// ✅ Good: Appropriate levels
tflog.Trace(ctx, "Function entry")
tflog.Debug(ctx, "Processing configuration")
tflog.Info(ctx, "Operation completed")
tflog.Error(ctx, "Operation failed")

// ❌ Bad: Everything at same level
tflog.Info(ctx, "Function entry")
tflog.Info(ctx, "Processing")
tflog.Info(ctx, "Error occurred")

Key Takeaways

✅ Use tflog for structured logging
✅ Choose appropriate log levels
✅ Add context fields for tracking
✅ Redact sensitive information
✅ Log performance metrics
✅ Provide comprehensive error context
✅ Test logging behavior
✅ Follow consistent conventions

What’s Next?

Learn debugging techniques with Delve and VSCode.

Next: Debugging Techniques →

Previous: ← Debugging & Troubleshooting
Next: Debugging Techniques →

Last updated: July 2, 2026

Share on

Twitter Facebook LinkedIn