internal: Introduce logging unit testing

internal/logging/context_test.go

@@ -0,0 +1,49 @@
+package logging_test
+
+import (
+	"bytes"
+	"context"
+	"testing"
+
+	"github.com/google/go-cmp/cmp"
+	"github.com/hashicorp/terraform-plugin-framework/internal/logging"
+	"github.com/hashicorp/terraform-plugin-log/tfsdklog"
+	"github.com/hashicorp/terraform-plugin-log/tfsdklogtest"
+)
+
+func TestInitContext(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+
+	// Simulate root logger fields that would have been associated by
+	// terraform-plugin-go prior to the InitContext() call.
+	ctx = tfsdklog.With(ctx, "tf_rpc", "GetProviderSchema")
+	ctx = tfsdklog.With(ctx, "tf_req_id", "123-testing-123")
+
+	ctx = logging.InitContext(ctx)
+
+	logging.FrameworkTrace(ctx, "test message")
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":    "trace",
+			"@message":  "test message",
+			"@module":   "sdk.framework",
+			"tf_rpc":    "GetProviderSchema",
+			"tf_req_id": "123-testing-123",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}

internal/logging/framework_test.go

@@ -0,0 +1,159 @@
+package logging_test
+
+import (
+	"bytes"
+	"context"
+	"testing"
+
+	"github.com/google/go-cmp/cmp"
+	"github.com/hashicorp/terraform-plugin-framework/internal/logging"
+	"github.com/hashicorp/terraform-plugin-go/tftypes"
+	"github.com/hashicorp/terraform-plugin-log/tfsdklogtest"
+)
+
+func TestFrameworkDebug(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+	ctx = logging.InitContext(ctx)
+
+	logging.FrameworkDebug(ctx, "test message")
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":   "debug",
+			"@message": "test message",
+			"@module":  "sdk.framework",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}
+
+func TestFrameworkError(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+	ctx = logging.InitContext(ctx)
+
+	logging.FrameworkError(ctx, "test message")
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":   "error",
+			"@message": "test message",
+			"@module":  "sdk.framework",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}
+
+func TestFrameworkTrace(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+	ctx = logging.InitContext(ctx)
+
+	logging.FrameworkTrace(ctx, "test message")
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":   "trace",
+			"@message": "test message",
+			"@module":  "sdk.framework",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}
+
+func TestFrameworkWarn(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+	ctx = logging.InitContext(ctx)
+
+	logging.FrameworkWarn(ctx, "test message")
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":   "warn",
+			"@message": "test message",
+			"@module":  "sdk.framework",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}
+
+func TestFrameworkWithAttributePath(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+	ctx = logging.InitContext(ctx)
+
+	ctx = logging.FrameworkWithAttributePath(ctx, tftypes.NewAttributePath().WithAttributeName("test_attr").String())
+	logging.FrameworkTrace(ctx, "test message")
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":            "trace",
+			"@message":          "test message",
+			"@module":           "sdk.framework",
+			"tf_attribute_path": "AttributeName(\"test_attr\")",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}

internal/proto6server/serve.go

@@ -197,7 +197,7 @@ func (s *Server) getProviderSchema(ctx context.Context, resp *getProviderSchemaR
 	// Reference: https://github.com/hashicorp/terraform-plugin-framework/issues/299
 	logging.FrameworkDebug(ctx, "Calling provider defined Provider GetDataSources")
 	dataSourceSchemas, diags := s.Provider.GetDataSources(ctx)
-	logging.FrameworkDebug(ctx, "Calling provider defined Provider GetDataSources")
+	logging.FrameworkDebug(ctx, "Called provider defined Provider GetDataSources")
 	resp.Diagnostics.Append(diags...)
 	if resp.Diagnostics.HasError() {
 		return

internal/proto6server/serve_test.go

@@ -1,6 +1,7 @@
 package proto6server
 
 import (
+	"bytes"
 	"context"
 	"encoding/json"
 	"strings"
@@ -11,10 +12,13 @@ import (
 	"github.com/google/go-cmp/cmp"
 	"github.com/google/go-cmp/cmp/cmpopts"
 	"github.com/hashicorp/terraform-plugin-framework/attr"
+	"github.com/hashicorp/terraform-plugin-framework/internal/logging"
+	"github.com/hashicorp/terraform-plugin-framework/internal/testing/emptyprovider"
 	"github.com/hashicorp/terraform-plugin-framework/tfsdk"
 	"github.com/hashicorp/terraform-plugin-framework/types"
 	"github.com/hashicorp/terraform-plugin-go/tfprotov6"
 	"github.com/hashicorp/terraform-plugin-go/tftypes"
+	"github.com/hashicorp/terraform-plugin-log/tfsdklogtest"
 )
 
 func TestServerCancelInFlightContexts(t *testing.T) {
@@ -300,6 +304,68 @@ func TestServerGetProviderSchema(t *testing.T) {
 	}
 }
 
+func TestServerGetProviderSchema_logging(t *testing.T) {
+	t.Parallel()
+
+	var output bytes.Buffer
+
+	ctx := tfsdklogtest.RootLogger(context.Background(), &output)
+	ctx = logging.InitContext(ctx)
+
+	testServer := &Server{
+		Provider: &emptyprovider.Provider{},
+	}
+
+	_, err := testServer.GetProviderSchema(ctx, new(tfprotov6.GetProviderSchemaRequest))
+
+	if err != nil {
+		t.Fatalf("unexpected error: %s", err)
+	}
+
+	entries, err := tfsdklogtest.MultilineJSONDecode(&output)
+
+	if err != nil {
+		t.Fatalf("unable to read multiple line JSON: %s", err)
+	}
+
+	expectedEntries := []map[string]interface{}{
+		{
+			"@level":   "debug",
+			"@message": "Calling provider defined Provider GetSchema",
+			"@module":  "sdk.framework",
+		},
+		{
+			"@level":   "debug",
+			"@message": "Called provider defined Provider GetSchema",
+			"@module":  "sdk.framework",
+		},
+		{
+			"@level":   "debug",
+			"@message": "Calling provider defined Provider GetResources",
+			"@module":  "sdk.framework",
+		},
+		{
+			"@level":   "debug",
+			"@message": "Called provider defined Provider GetResources",
+			"@module":  "sdk.framework",
+		},
+		{
+			"@level":   "debug",
+			"@message": "Calling provider defined Provider GetDataSources",
+			"@module":  "sdk.framework",
+		},
+		{
+			"@level":   "debug",
+			"@message": "Called provider defined Provider GetDataSources",
+			"@module":  "sdk.framework",
+		},
+	}
+
+	if diff := cmp.Diff(entries, expectedEntries); diff != "" {
+		t.Errorf("unexpected difference: %s", diff)
+	}
+}
+
 func TestServerGetProviderSchemaWithProviderMeta(t *testing.T) {
 	t.Parallel()
 

internal/testing/emptyprovider/provider.go

@@ -0,0 +1,34 @@
+package emptyprovider
+
+import (
+	"context"
+
+	"github.com/hashicorp/terraform-plugin-framework/diag"
+	"github.com/hashicorp/terraform-plugin-framework/tfsdk"
+)
+
+var _ tfsdk.Provider = &Provider{}
+
+// tfsdk.Provider that is completely empty, e.g.
+//
+//    - No Schema
+//    - No DataSources
+//    - No Resources
+//
+type Provider struct{}
+
+func (t *Provider) GetSchema(_ context.Context) (tfsdk.Schema, diag.Diagnostics) {
+	return tfsdk.Schema{}, nil
+}
+
+func (t *Provider) Configure(_ context.Context, _ tfsdk.ConfigureProviderRequest, _ *tfsdk.ConfigureProviderResponse) {
+	// intentionally empty
+}
+
+func (t *Provider) GetDataSources(_ context.Context) (map[string]tfsdk.DataSourceType, diag.Diagnostics) {
+	return map[string]tfsdk.DataSourceType{}, nil
+}
+
+func (t *Provider) GetResources(_ context.Context) (map[string]tfsdk.ResourceType, diag.Diagnostics) {
+	return map[string]tfsdk.ResourceType{}, nil
+}

providerserver/providerserver_test.go

@@ -4,11 +4,12 @@ import (
 	"context"
 	"testing"
 
+	"github.com/hashicorp/terraform-plugin-framework/internal/testing/emptyprovider"
 	"github.com/hashicorp/terraform-plugin-go/tfprotov6"
 )
 
 func TestNewProtocol6(t *testing.T) {
-	provider := &testProvider{}
+	provider := &emptyprovider.Provider{}
 
 	providerServerFunc := NewProtocol6(provider)
 	providerServer := providerServerFunc()
@@ -22,7 +23,7 @@ func TestNewProtocol6(t *testing.T) {
 }
 
 func TestNewProtocol6WithError(t *testing.T) {
-	provider := &testProvider{}
+	provider := &emptyprovider.Provider{}
 
 	providerServer, err := NewProtocol6WithError(provider)()