Log requests when TF_LOG=debug

[ag-TJNII]

Terraform CLI and Provider Versions

registry.terraform.io/hashicorp/http 3.4.2
Terraform: 1.3.4

Use Cases or Problem Statement

I recently ran into an issue with redirects, where a redirected API call was failing. I had to determine what was happening entirely with server side logs and adding local_file resources due to a lack of debug output. This kind of debugging may be impossible depending on the server in use and environment Terraform is running in, leading to no way to debug issues.

When I run Terraform with TF_LOG=debug I get a flood of debug logging, including request and response headers from the AWS provider for the backend state handling. However, for the HTTP data provider I only see the following:

module.component_repo_ecr_image_lookup.data.http.resource_name: Reading...
2024-03-12T17:54:48.860Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: performing request: tf_rpc=ReadDataSource @caller=github.com/terraform-providers/terraform-provider-http/internal/provider/data_source_http.go:429 @module=http method=GET tf_provider_addr=registry.terraform.io/hashicorp/http tf_req_id=5052bfd6-5c99-4ea6-db75-f12d82503ade tf_data_source_type=http url="map[ForceQuery:false Fragment: Host:[HOST] OmitHost:false Opaque: Path:[PATH] RawFragment: RawPath: RawQuery:[Query Params] Scheme:https User:<nil>]" timestamp=2024-03-12T17:54:48.860Z
2024-03-12T17:54:49.106Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: @module=sdk.framework tf_attribute_path=url tf_rpc=ReadDataSource @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 tf_data_source_type=http tf_provider_addr=registry.terraform.io/hashicorp/http tf_req_id=989cb941-45b7-29c4-6c50-518591197d96 timestamp=2024-03-12T17:54:49.106Z
2024-03-12T17:54:49.107Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: tf_data_source_type=http tf_req_id=989cb941-45b7-29c4-6c50-518591197d96 @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 @module=sdk.framework tf_attribute_path=request_headers["PRIVATE-TOKEN"] tf_provider_addr=registry.terraform.io/hashicorp/http tf_rpc=ReadDataSource timestamp=2024-03-12T17:54:49.106Z
2024-03-12T17:54:49.107Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: tf_attribute_path=request_headers tf_data_source_type=http tf_req_id=989cb941-45b7-29c4-6c50-518591197d96 @module=sdk.framework @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 tf_provider_addr=registry.terraform.io/hashicorp/http tf_rpc=ReadDataSource timestamp=2024-03-12T17:54:49.106Z
2024-03-12T17:54:49.752Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: tf_attribute_path=request_headers["Authorization"] tf_data_source_type=http tf_provider_addr=registry.terraform.io/hashicorp/http tf_rpc=ReadDataSource @module=sdk.framework tf_req_id=5052bfd6-5c99-4ea6-db75-f12d82503ade @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 timestamp=2024-03-12T17:54:49.752Z
2024-03-12T17:54:49.752Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: @module=sdk.framework tf_attribute_path=request_headers["Accept"] tf_data_source_type=http tf_rpc=ReadDataSource @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 tf_provider_addr=registry.terraform.io/hashicorp/http tf_req_id=5052bfd6-5c99-4ea6-db75-f12d82503ade timestamp=2024-03-12T17:54:49.752Z
2024-03-12T17:54:49.752Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: tf_rpc=ReadDataSource tf_data_source_type=http tf_provider_addr=registry.terraform.io/hashicorp/http tf_req_id=5052bfd6-5c99-4ea6-db75-f12d82503ade @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 @module=sdk.framework tf_attribute_path=request_headers timestamp=2024-03-12T17:54:49.752Z
2024-03-12T17:54:49.752Z [DEBUG] provider.terraform-provider-http_v3.4.2_x5: Value switched to prior value due to semantic equality logic: @caller=github.com/hashicorp/[email protected]/internal/fwschemadata/value_semantic_equality.go:85 tf_provider_addr=registry.terraform.io/hashicorp/http tf_req_id=5052bfd6-5c99-4ea6-db75-f12d82503ade tf_rpc=ReadDataSource @module=sdk.framework tf_attribute_path=url tf_data_source_type=http timestamp=2024-03-12T17:54:49.752Z
module.component_repo_ecr_image_lookup.data.http.resource_name: Read complete after 1s [id=https://[URI]]

What actually happened was:

• The provider made a request to the configured API URL
• The provider received a redirect
• The provider followed the redirect
• The redirected request returned an error

However, there is no sign of this from the logging above. Most of, if not all of, the TF_LOG=debug output isn't useful for troubleshooting the actual HTTP interaction. In order to actually root cause I needed to add a local_file resource, set the provider output as the contents, target the local file in a plan, and then at least I could see the request and response headers of the final call. Combining this clue with the server data the I was able to root cause. This is obnoxious in local dev and an impossibility in CI.

Proposal

When TF_LOG=debug the provider should log the request and response headers of all requests, including redirects.

How much impact is this issue causing?

Medium

Additional Information

No response

Code of Conduct

• I agree to follow this project's Code of Conduct