log: support for user defined log levels

[fatih]

This PR brings support for better log level handling. Terraform logs
are already written in the form which
https://github.com/hashicorp/logutils can understand easily. Based on
this fact we know have the followings:

• A new TF_LOG_LEVEL environment variable which the user can control
• Users can pass levels in the form of "info", "Info" or "INFO"
• If an invalid log level is passed, we print a warning but still
  continue
• All changes are backwards compatible with the current logs

Some pictures:

Without any changes:

With TF_LOG_LEVEL=info:

With a wrong log level:

[apparentlymart]

Thanks for working on this! It seems like it'd be very useful, since the existing logs are incredibly verbose. (I'm sure that this change would expose some cases where existing logs may be better changed to a new level, or have a level added; e.g. detecting your home directory is arguably no more than DEBUG.)

In terms of the "user-interface" for this, it seems a little awkward that a user must set both TF_LOG and TF_LOG_LEVEL. I wonder if instead we could say that TF_LOG itself now takes the various log levels as values, so you can just say (for example) TF_LOG=WARNING and have that both turn on logging and set the filter all at once.

For compatibility with existing usage patterns the values 1, true and yes could be treated as undocumented aliases for TRACE, but any new docs would say to set TF_LOG=TRACE in order to see all of the logs. (I'd also keep your behavior of warning but continuing with no filter when an invalid level is selected, to take care of any other existing users setting TF_LOG to other non-empty values.)

How does that sound?

[fatih]

Hi @apparentlymart

In terms of the "user-interface" for this, it seems a little awkward that a user must set both TF_LOG and TF_LOG_LEVEL. I wonder if instead we could say that TF_LOG itself now takes the various log levels as values, so you can just say (for example) TF_LOG=WARNING and have that both turn on logging and set the filter all at once.

You are right, I just wanted to break the functionality. Adding an option without touching the first one seems to be ok for me. But your approach is just fine and even better :) I'll update the PR with the changes.

[fatih]

I've updated it and the current usage is like the following:

Using it with info:

Old usage. It's still backwards compatible, though we display an error message for a proper usage:

[apparentlymart]

Thanks @fatih! That looks awesome.

Since this is a change to the interface I'm not going to just merge this in right now since I want to give other folks a chance to chime in. @phinze does this look good to you?

[apparentlymart]

I rebased this and merged it as 0090c06. Thanks for this. It should make debugging easier if we can hide all of those noisy TRACE lines!

[ghost]

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.