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

Shortcut logging when the level isn't active #722

Closed

Conversation

lawrencejones
Copy link

This commit addresses this issue:
#721

When working with large terraform resource attributes, logging can become the primary cost to running plan/apply. This is because the context logger used by tfsdklog is very expensive, the SDK framework itself is very verbose, and even the log level means Debug/Trace logs won't be emitted we still build the log.

As we log via the internal logging package anyway, we can avoid this performance issue by maintaining a package-local log-level which is initialised at the same time as we init the contextual logger. Then our logging package can avoid calling into the tfsdklog (which is where we pay the performance penalty) unless it believes the level is active, which in most cases avoids 99% of the log cost.

@lawrencejones lawrencejones requested a review from a team as a code owner April 11, 2023 13:09
lawrencejones added a commit to incident-io/terraform-provider-incident that referenced this pull request Apr 11, 2023
Introduce a resource that can manage entries in bulk, which:

1. Solves terraform performance issues when dealing with a lot of
   entries
2. Reduces pressure on our API when working with entries

To achieve this we've forked the terraform sdk framework to improve
performance when logging, which is necessary to avoid massive plan times
on large nested objects.

Relevant links are:
- PR for logging change
  (hashicorp/terraform-plugin-framework#722)
- Issue in upstream
  (hashicorp/terraform-plugin-framework#721)
lawrencejones added a commit to incident-io/terraform-provider-incident that referenced this pull request Apr 11, 2023
Introduce a resource that can manage entries in bulk, which:

1. Solves terraform performance issues when dealing with a lot of
   entries
2. Reduces pressure on our API when working with entries

To achieve this we've forked the terraform sdk framework to improve
performance when logging, which is necessary to avoid massive plan times
on large nested objects.

Relevant links are:
- PR for logging change
  (hashicorp/terraform-plugin-framework#722)
- Issue in upstream
  (hashicorp/terraform-plugin-framework#721)
lawrencejones added a commit to incident-io/terraform-provider-incident that referenced this pull request Apr 11, 2023
Introduce a resource that can manage entries in bulk, which:

1. Solves terraform performance issues when dealing with a lot of
   entries
2. Reduces pressure on our API when working with entries

To achieve this we've forked the terraform sdk framework to improve
performance when logging, which is necessary to avoid massive plan times
on large nested objects.

Relevant links are:
- PR for logging change
  (hashicorp/terraform-plugin-framework#722)
- Issue in upstream
  (hashicorp/terraform-plugin-framework#721)
lawrencejones added a commit to incident-io/terraform-provider-incident that referenced this pull request Apr 11, 2023
Introduce a resource that can manage entries in bulk, which:

1. Solves terraform performance issues when dealing with a lot of
   entries
2. Reduces pressure on our API when working with entries

To achieve this we've forked the terraform sdk framework to improve
performance when logging, which is necessary to avoid massive plan times
on large nested objects.

Relevant links are:
- PR for logging change
  (hashicorp/terraform-plugin-framework#722)
- Issue in upstream
  (hashicorp/terraform-plugin-framework#721)
This commit addresses this issue:
hashicorp#721

When working with large terraform resource attributes, logging can
become the primary cost to running plan/apply. This is because the
context logger used by tfsdklog is very expensive, the SDK framework
itself is very verbose, and even the log level means Debug/Trace logs
won't be emitted we still build the log.

As we log via the internal logging package anyway, we can avoid this
performance issue by maintaining a package-local log-level which is
initialised at the same time as we init the contextual logger. Then our
logging package can avoid calling into the tfsdklog (which is where we
pay the performance penalty) unless it believes the level is active,
which in most cases avoids 99% of the log cost.
Copy link
Contributor

@bflad bflad left a comment

Choose a reason for hiding this comment

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

Hi @lawrencejones 👋 Thank you for submitting this.

We can certainly introduce some additional logic here to check the logging level before doing all the work to fetch the logger from context.Context, however the framework's logging environment variable level is not the only one that influences which level the logger is running at. For example, the "global" TF_LOG environment variable also will enable logging.

I think what we'll want here is:

  • Ensuring the existing logging testing is passing
  • terraform-plugin-log loggers to expose their effective logging level based on all its prior configuration
  • For that logging level to be a terraform-plugin-log type, rather than falling back to the hclog type
  • Releasing that and switching the implementation here

No worries if this is more work than expected here. If you are interested though, it might be best to raise an upstream issue in terraform-plugin-log to expose the effective logging level.

@bflad
Copy link
Contributor

bflad commented Apr 19, 2023

Please refer to #721 (comment).

@bflad
Copy link
Contributor

bflad commented Jun 1, 2023

Thank you for this submission. Superseded by upstream terraform-plugin-log changes via #744 so we can roll this out across the other SDKs as well -- if we still find there are performance issues, we can determine next steps in a fresh new issue.

@bflad bflad closed this Jun 1, 2023
@github-actions
Copy link

github-actions bot commented Jul 2, 2023

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 Jul 2, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants