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

Downstream Logger Unit Testing #61

Closed
bflad opened this issue May 4, 2022 · 1 comment · Fixed by #62
Closed

Downstream Logger Unit Testing #61

bflad opened this issue May 4, 2022 · 1 comment · Fixed by #62
Labels
enhancement New feature or request
Milestone

Comments

@bflad
Copy link
Contributor

bflad commented May 4, 2022

terraform-plugin-log version

v0.3.0

Use cases

Downstream SDKs (and potentially providers?) should be able to implement unit testing to verify their logging setup is working as expected, especially when creating subsystems. This module uses some internally available functionality in the internal/loggertest package to create root loggers which output to a predefined io.Writer, e.g.

func SDKRoot(ctx context.Context, output io.Writer) context.Context {
	return tfsdklog.NewRootSDKLogger(
		ctx,
		logging.WithoutLocation(),
		logging.WithoutTimestamp(),
		logging.WithOutput(output),
	)
}

And unit testing such as:

func TestTrace(t *testing.T) {
	t.Parallel()

	testCases := map[string]struct {
		message          string
		additionalFields []map[string]interface{}
		expectedOutput   []map[string]interface{}
	}{
		"no-fields": {
			message: "test message",
			expectedOutput: []map[string]interface{}{
				{
					"@level":   hclog.Trace.String(),
					"@message": "test message",
					"@module":  "sdk",
				},
			},
		},
		"fields-single-map": {
			message: "test message",
			additionalFields: []map[string]interface{}{
				{
					"test-key-1": "test-value-1",
					"test-key-2": "test-value-2",
					"test-key-3": "test-value-3",
				},
			},
			expectedOutput: []map[string]interface{}{
				{
					"@level":     hclog.Trace.String(),
					"@message":   "test message",
					"@module":    "sdk",
					"test-key-1": "test-value-1",
					"test-key-2": "test-value-2",
					"test-key-3": "test-value-3",
				},
			},
		},
		"fields-multiple-maps": {
			message: "test message",
			additionalFields: []map[string]interface{}{
				{
					"test-key-1": "test-value-1-map1",
					"test-key-2": "test-value-2-map1",
					"test-key-3": "test-value-3-map1",
				},
				{
					"test-key-4": "test-value-4-map2",
					"test-key-1": "test-value-1-map2",
					"test-key-5": "test-value-5-map2",
				},
			},
			expectedOutput: []map[string]interface{}{
				{
					"@level":     hclog.Trace.String(),
					"@message":   "test message",
					"@module":    "sdk",
					"test-key-1": "test-value-1-map2",
					"test-key-2": "test-value-2-map1",
					"test-key-3": "test-value-3-map1",
					"test-key-4": "test-value-4-map2",
					"test-key-5": "test-value-5-map2",
				},
			},
		},
	}

	for name, testCase := range testCases {
		name, testCase := name, testCase

		t.Run(name, func(t *testing.T) {
			t.Parallel()

			var outputBuffer bytes.Buffer

			ctx := context.Background()
			ctx = loggertest.SDKRoot(ctx, &outputBuffer)

			tfsdklog.Trace(ctx, testCase.message, testCase.additionalFields...)

			got, err := loggertest.MultilineJSONDecode(&outputBuffer)

			if err != nil {
				t.Fatalf("unable to read multiple line JSON: %s", err)
			}

			if diff := cmp.Diff(testCase.expectedOutput, got); diff != "" {
				t.Errorf("unexpected output difference: %s", diff)
			}
		})
	}
}

It should be possible for other modules to also implement similar unit testing.

Attempted solutions

Manual verification. 😢

Proposals

Initially I was thinking something like proposal 1, but proposal 2 might make life much simpler for everyone.

Proposal 1

Export logging.WithoutLocation(), logging.WithoutTimestamp(), and logging.WithOutput() functions in at least the tfsdklog package, denoting they are only intended for unit testing.

Proposal 2

Create "unit testing" packages (e.g. tfsdklogtest) that expose the root loggers, similar to loggertest. e.g.

// package tflogtest

func RootLogger(ctx context.Context, output io.Writer) context.Context {
	return tfsdklog.NewRootProviderLogger(
		ctx,
		logging.WithoutLocation(),
		logging.WithoutTimestamp(),
		logging.WithOutput(output),
	)
}

// package tfsdklogtest

func RootLogger(ctx context.Context, output io.Writer) context.Context {
	return tfsdklog.NewRootSDKLogger(
		ctx,
		logging.WithoutLocation(),
		logging.WithoutTimestamp(),
		logging.WithOutput(output),
	)
}
@bflad bflad added the enhancement New feature or request label May 4, 2022
bflad added a commit to hashicorp/terraform-plugin-framework that referenced this issue May 4, 2022
…y RPC logic

Verified with terraform-provider-corner. Creating unit testing for this setup requires something like hashicorp/terraform-plugin-log#61 upstream.

Previously:

```text
2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Calling provider defined Provider GetResources: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange
2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Called provider defined Provider GetResources: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange
2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Calling provider defined ResourceType GetSchema: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange
```

Now:

```text
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Calling provider defined Provider GetResources
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Called provider defined Provider GetResources
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Calling provider defined ResourceType GetSchema
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Called provider defined ResourceType GetSchema
```
@bflad bflad added this to the v0.4.0 milestone May 4, 2022
bflad added a commit that referenced this issue May 4, 2022
bflad added a commit that referenced this issue May 4, 2022
bflad added a commit that referenced this issue May 4, 2022
bflad added a commit to hashicorp/terraform-plugin-framework that referenced this issue May 4, 2022
…y RPC logic (#314)

Verified with terraform-provider-corner. Creating unit testing for this setup requires something like hashicorp/terraform-plugin-log#61 upstream.

Previously:

```text
2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Calling provider defined Provider GetResources: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange
2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Called provider defined Provider GetResources: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange
2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Calling provider defined ResourceType GetSchema: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange
```

Now:

```text
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Calling provider defined Provider GetResources
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Called provider defined Provider GetResources
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Calling provider defined ResourceType GetSchema
2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Called provider defined ResourceType GetSchema
```
@bflad bflad closed this as completed in #62 May 4, 2022
bflad added a commit that referenced this issue May 4, 2022
@github-actions
Copy link

github-actions bot commented Jun 4, 2022

I'm going to lock this issue because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active issues.
If you have found a problem that seems similar to this, 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 Jun 4, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
enhancement New feature or request
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant