hashicorp / hashicorp/terraform-plugin-sdk

Using the default logger causes duplicate timestamp and severity values in log entries

Open
#863 4 comments 1 reaction 1 assignee Claimed by @bflad View on GitHub
bug
Dominant language
Go
Stars
485
Forks
244
Avg merge
19h 57m
Merged PRs (30d)
4

Description

### SDK version

```
github.com/hashicorp/terraform-plugin-sdk/v2 v2.10.1
```

### Terraform version

```
Terraform v1.1.4
on darwin_amd64
+ provider registry.terraform.io/hashicorp/aws v3.73.0
```

### Expected Behavior

Log lines should look like the following

> 2022-01-26T16:25:33.123-0800 [DEBUG] provider.terraform-provider-aws_v3.73.0_x5: Waiting for state to become: [success]: timestamp=2022-01-26T16:25:33.123-0800

### Actual Behavior

Log lines look like the following

> 2022-01-26T16:25:33.123-0800 [INFO] provider.terraform-provider-aws_v3.73.0_x5: 2022/01/26 16:25:33 [DEBUG] Waiting for state to become: [success]: timestamp=2022-01-26T16:25:33.123-0800

I assume the first set, `2022-01-26T16:25:33.123-0800 [INFO] provider.terraform-provider-aws_v3.73.0_x5:` comes from the Terraform CLI.

The second set, `2022/01/26 16:25:33 [DEBUG]`, comes from the AWS provider.

Level inference is also not working, since the provider is specifying `DEBUG`, but Terraform is logging as `INFO`.

### Steps to Reproduce

1. Call `TF_LOG=DEBUG terraform plan` with a configuration using the AWS provider.

### Additional Information

We are using the standard logger as provided by `terraform-plugin-sdk`.

Disabling the date and time on the default logger by calling `log.SetFlags(0)` before `plugin.Serve(opts)` is a workaround.

Adding fractional seconds and UTC using `log.SetFlags(log.Ldate | log.Ltime | log.Lmicroseconds | log.LUTC)` does not work as a workaround

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.