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

all: Replace various log.Printf calls with tfsdklog calls #940

Merged
merged 1 commit into from Apr 14, 2022

Conversation

bflad
Copy link
Member

@bflad bflad commented Apr 13, 2022

Reference: #863

By default, the standard library log package will include the short timestamp and date flags, which when output will prefix any messaging, e.g.

# From log.Printf("[DEBUG] Test message")
2022/01/26 16:25:33 [DEBUG] Test message

When a provider is running in production and the log output is being sent across the go-plugin boundary, Terraform CLI generally expects a hc-log formatted entry (square bracket log level prefixed message) or will output the raw message. So in many cases, this class of logging shows up in production logs as the raw message and the log level is not recognized, which is confusing for practitioners and provider developers:

2022-01-26T16:25:33.123-0800 [INFO] provider.terraform-provider-example_v9.9.9_x5: 2022/01/26 16:25:33 [DEBUG] Test Message: timestamp=2022-01-26T16:25:33.123-0800

Setting the log package default logger to not include those flags via log.SetFlags(0) early in the SDK lifecycle may represent a breaking change for any providers depending on the current behavior, so this easier class of fix is not acceptable.

Now that this SDK implements the tfsdklog package, logging can be converted to that style, which fixes the above issue and these messages will now also include all the gathered logging context up to the call such as the RPC name and a request UUID.

There are quite a few other log.Printf() calls across the project, however they are non-trivial to update as:

  • The logging context is not present or not guaranteed to be present (as is the case with (helper/resource.StateChangeConf).WaitContext())
  • The functions/methods are exported, so changing the signature is an unacceptable change
  • The functions/methods while unexported are eventually surfaced via an exported type/function, so it could indirectly require breaking changes

Given that helper/resource.StateChangeConf, which also underlies helper/resource.Retry* functionality, is quite common across provider usage, a separate custom logging solution may be introduced there as a separate change.

Reference: #863

By default, the standard library `log` package will include the short timestamp and date flags, which when output will prefix any messaging, e.g.

```text
# From log.Printf("[DEBUG] Test message")
2022/01/26 16:25:33 [DEBUG] Test message
```

When a provider is running in production and the log output is being sent across the go-plugin boundary, Terraform CLI generally expects a hc-log formatted entry (square bracket log level prefixed message) or will output the raw message. So in many cases, this class of logging shows up in production logs as the raw message and the log level is not recognized, which is confusing for practitioners and provider developers:

```text
2022-01-26T16:25:33.123-0800 [INFO] provider.terraform-provider-example_v9.9.9_x5: 2022/01/26 16:25:33 [DEBUG] Test Message: timestamp=2022-01-26T16:25:33.123-0800
```

Setting the `log` package default logger to not include those flags via `log.SetFlags(0)` early in the SDK lifecycle may represent a breaking change for any providers depending on the current behavior, so this easier class of fix is not acceptable.

Now that this SDK implements the `tfsdklog` package, logging can be converted to that style, which fixes the above issue and these messages will now also include all the gathered logging context up to the call such as the RPC name and a request UUID.

There are quite a few other `log.Printf()` calls across the project, however they are non-trivial to update as:

* The logging context is not present or not guaranteed to be present (as is the case with `(helper/resource.StateChangeConf).WaitContext()`)
* The functions/methods are exported, so changing the signature is an unacceptable change
* The functions/methods while unexported are eventually surfaced via an exported type/function, so it could indirectly require breaking changes

Given that `helper/resource.StateChangeConf`, which also underlies `helper/resource.Retry*` functionality, is quite common across provider usage, a separate custom logging solution may be introduced there as a separate change.
@bflad bflad added the bug Something isn't working label Apr 13, 2022
@bflad bflad added this to the v2.14.0 milestone Apr 13, 2022
@bflad bflad requested a review from a team as a code owner April 13, 2022 13:06
@@ -330,7 +329,7 @@ func runProviderCommand(ctx context.Context, t testing.T, f func() error, wd *pl
// started.
err := f()
if err != nil {
log.Printf("[WARN] Got error running Terraform: %s", err)
logging.HelperResourceWarn(ctx, "Error running Terraform CLI command", map[string]interface{}{logging.KeyError: err})
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nothing to change here, but for when we go 1.18 here, we could consider using map[string]any{...} instead. It's still not ideal (I wish we could have variadic argument list that could enforce even-ness), but a bit shorter.

What do you think?

Again, there is nothing to change here.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do agree that once we're minimum Go 1.18 we should change all the interface{} usage to any 😉 #834

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Of course there is already a story for this :D

@bflad bflad merged commit 5d701f2 into main Apr 14, 2022
@bflad bflad deleted the bflad-log-to-tfsdklog branch April 14, 2022 16:51
@github-actions
Copy link

I'm going to lock this pull request because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active contributions.
If you have found a problem that seems related to this change, 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 May 15, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants