diff --git a/.changelog/1006.txt b/.changelog/1006.txt new file mode 100644 index 00000000000..9dda15146a9 --- /dev/null +++ b/.changelog/1006.txt @@ -0,0 +1,7 @@ +```release-note:feature +helper/logging: New `NewLoggingHTTPTransport()` and `NewSubsystemLoggingHTTPTransport()` functions, providing `http.RoundTripper` Transport implementations that log request/response using [terraform-plugin-log](https://pkg.go.dev/github.com/hashicorp/terraform-plugin-log) +``` + +```release-note:note +helper/logging: Existing `NewTransport()` is now deprecated in favour of using the new `NewLoggingHTTPTransport()` or `NewSubsystemLoggingHTTPTransport()` +``` diff --git a/.github/workflows/ci-go.yml b/.github/workflows/ci-go.yml index 56a997cd6e7..c9bc27e363d 100644 --- a/.github/workflows/ci-go.yml +++ b/.github/workflows/ci-go.yml @@ -21,7 +21,9 @@ jobs: with: go-version-file: 'go.mod' - run: go mod download - - uses: golangci/golangci-lint-action@v3.2.0 + - uses: golangci/golangci-lint-action@v3 + with: + version: latest terraform-provider-corner: defaults: run: diff --git a/.gitignore b/.gitignore index 1fa9f4e4936..637ea69288e 100644 --- a/.gitignore +++ b/.gitignore @@ -1,2 +1,6 @@ node_modules -website-preview \ No newline at end of file +website-preview + +# Jetbrains IDEs +.idea/ +*.iws diff --git a/Makefile b/Makefile index cc49a0929cf..20cb17a7a64 100644 --- a/Makefile +++ b/Makefile @@ -22,17 +22,17 @@ WEBSITE_DOCKER_RUN_FLAGS=--interactive \ default: test -test: fmtcheck generate +test: generate go test ./... +lint: + golangci-lint run + generate: go generate ./... fmt: - gofmt -w $(GOFMT_FILES) - -fmtcheck: - @sh -c "'$(CURDIR)/scripts/gofmtcheck.sh'" + gofmt -s -w -e $(GOFMT_FILES) # Run the terraform.io website to preview local content changes website: @@ -55,4 +55,4 @@ website/build-local: @docker build https://github.com/hashicorp/terraform-website.git\#$(WEBSITE_BRANCH) \ -t $(WEBSITE_DOCKER_IMAGE_LOCAL) -.PHONY: default fmt fmtcheck generate test website website/local website/build-local \ No newline at end of file +.PHONY: default fmt lint generate test website website/local website/build-local diff --git a/go.mod b/go.mod index 06c489ab0e6..0f3f3ee7bfb 100644 --- a/go.mod +++ b/go.mod @@ -19,7 +19,7 @@ require ( github.com/hashicorp/terraform-exec v0.17.2 github.com/hashicorp/terraform-json v0.14.0 github.com/hashicorp/terraform-plugin-go v0.12.0 - github.com/hashicorp/terraform-plugin-log v0.6.0 + github.com/hashicorp/terraform-plugin-log v0.7.0 github.com/mitchellh/copystructure v1.2.0 github.com/mitchellh/go-testing-interface v1.14.1 github.com/mitchellh/mapstructure v1.5.0 diff --git a/go.sum b/go.sum index fe6c0759bc0..5c003be8d9c 100644 --- a/go.sum +++ b/go.sum @@ -127,8 +127,9 @@ github.com/hashicorp/terraform-json v0.14.0 h1:sh9iZ1Y8IFJLx+xQiKHGud6/TSUCM0N8e github.com/hashicorp/terraform-json v0.14.0/go.mod h1:5A9HIWPkk4e5aeeXIBbkcOvaZbIYnAIkEyqP2pNSckM= github.com/hashicorp/terraform-plugin-go v0.12.0 h1:6wW9mT1dSs0Xq4LR6HXj1heQ5ovr5GxXNJwkErZzpJw= github.com/hashicorp/terraform-plugin-go v0.12.0/go.mod h1:kwhmaWHNDvT1B3QiSJdAtrB/D4RaKSY/v3r2BuoWK4M= -github.com/hashicorp/terraform-plugin-log v0.6.0 h1:/Vq78uSIdUSZ3iqDc9PESKtwt8YqNKN6u+khD+lLjuw= github.com/hashicorp/terraform-plugin-log v0.6.0/go.mod h1:p4R1jWBXRTvL4odmEkFfDdhUjHf9zcs/BCoNHAc7IK4= +github.com/hashicorp/terraform-plugin-log v0.7.0 h1:SDxJUyT8TwN4l5b5/VkiTIaQgY6R+Y2BQ0sRZftGKQs= +github.com/hashicorp/terraform-plugin-log v0.7.0/go.mod h1:p4R1jWBXRTvL4odmEkFfDdhUjHf9zcs/BCoNHAc7IK4= github.com/hashicorp/terraform-registry-address v0.0.0-20220623143253-7d51757b572c h1:D8aRO6+mTqHfLsK/BC3j5OAoogv1WLRWzY1AaTo3rBg= github.com/hashicorp/terraform-registry-address v0.0.0-20220623143253-7d51757b572c/go.mod h1:Wn3Na71knbXc1G8Lh+yu/dQWWJeFQEpDeJMtWMtlmNI= github.com/hashicorp/terraform-svchost v0.0.0-20200729002733-f050f53b9734 h1:HKLsbzeOsfXmKNpr3GiT18XAblV0BjCbzL8KQAMZGa0= diff --git a/helper/logging/logging_http_transport.go b/helper/logging/logging_http_transport.go new file mode 100644 index 00000000000..335e1784e22 --- /dev/null +++ b/helper/logging/logging_http_transport.go @@ -0,0 +1,288 @@ +package logging + +import ( + "bufio" + "bytes" + "context" + "errors" + "io" + "net/http" + "net/http/httputil" + "net/textproto" + "strings" + + "github.com/hashicorp/go-uuid" + "github.com/hashicorp/terraform-plugin-log/tflog" +) + +// NewLoggingHTTPTransport creates a wrapper around an *http.RoundTripper, +// designed to be used for the `Transport` field of http.Client. +// +// This logs each pair of HTTP request/response that it handles. +// The logging is done via `tflog`, that is part of the terraform-plugin-log +// library, included by this SDK. +// +// The request/response is logged via tflog.Debug, using the context.Context +// attached to the http.Request that the transport receives as input +// of http.RoundTripper RoundTrip method. +// +// It's responsibility of the developer using this transport, to ensure that each +// http.Request it handles is configured with the SDK-initialized Provider Root Logger +// context.Context, that it's passed to all resources/data-sources/provider entry-points +// (i.e. schema.Resource fields like `CreateContext`, `ReadContext`, etc.). +// +// This also gives the developer the flexibility to further configure the +// logging behaviour via the above-mentioned context: please see +// https://www.terraform.io/plugin/log/writing. +func NewLoggingHTTPTransport(t http.RoundTripper) *loggingHttpTransport { + return &loggingHttpTransport{"", t} +} + +// NewSubsystemLoggingHTTPTransport creates a wrapper around an *http.RoundTripper, +// designed to be used for the `Transport` field of http.Client. +// +// This logs each pair of HTTP request/response that it handles. +// The logging is done via `tflog`, that is part of the terraform-plugin-log +// library, included by this SDK. +// +// The request/response is logged via tflog.SubsystemDebug, using the context.Context +// attached to the http.Request that the transport receives as input +// of http.RoundTripper RoundTrip method, as well as the `subsystem` string +// provided at construction time. +// +// It's responsibility of the developer using this transport, to ensure that each +// http.Request it handles is configured with a Subsystem Logger +// context.Context that was initialized via tflog.NewSubsystem. +// +// This also gives the developer the flexibility to further configure the +// logging behaviour via the above-mentioned context: please see +// https://www.terraform.io/plugin/log/writing. +// +// Please note: setting `subsystem` to an empty string it's equivalent to +// using NewLoggingHTTPTransport. +func NewSubsystemLoggingHTTPTransport(subsystem string, t http.RoundTripper) *loggingHttpTransport { + return &loggingHttpTransport{subsystem, t} +} + +const ( + // FieldHttpOperationType is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging the type of HTTP operation via tflog. + FieldHttpOperationType = "tf_http_op_type" + + // OperationHttpRequest is the field value used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP request via tflog. + OperationHttpRequest = "request" + + // OperationHttpResponse is the field value used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP response via tflog. + OperationHttpResponse = "response" + + // FieldHttpRequestMethod is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP request method via tflog. + FieldHttpRequestMethod = "tf_http_req_method" + + // FieldHttpRequestUri is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP request URI via tflog. + FieldHttpRequestUri = "tf_http_req_uri" + + // FieldHttpRequestProtoVersion is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP request HTTP version via tflog. + FieldHttpRequestProtoVersion = "tf_http_req_version" + + // FieldHttpRequestBody is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP request body via tflog. + FieldHttpRequestBody = "tf_http_req_body" + + // FieldHttpResponseProtoVersion is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP response protocol version via tflog. + FieldHttpResponseProtoVersion = "tf_http_res_version" + + // FieldHttpResponseStatusCode is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP response status code via tflog. + FieldHttpResponseStatusCode = "tf_http_res_status_code" + + // FieldHttpResponseStatusReason is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP response status reason phrase via tflog. + FieldHttpResponseStatusReason = "tf_http_res_status_reason" + + // FieldHttpResponseBody is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP response body via tflog. + FieldHttpResponseBody = "tf_http_res_body" + + // FieldHttpTransactionId is the field key used by NewLoggingHTTPTransport + // and NewSubsystemLoggingHTTPTransport when logging an HTTP transaction via tflog. + FieldHttpTransactionId = "tf_http_trans_id" +) + +type loggingHttpTransport struct { + subsystem string + transport http.RoundTripper +} + +func (t *loggingHttpTransport) RoundTrip(req *http.Request) (*http.Response, error) { + ctx := req.Context() + ctx = t.AddTransactionIdField(ctx) + + // Decompose the request bytes in a message (HTTP body) and fields (HTTP headers), then log it + fields, err := decomposeRequestForLogging(req) + if err != nil { + t.Error(ctx, "Failed to parse request bytes for logging", map[string]interface{}{ + "error": err, + }) + } else { + t.Debug(ctx, "Sending HTTP Request", fields) + } + + // Invoke the wrapped RoundTrip now + res, err := t.transport.RoundTrip(req) + if err != nil { + return res, err + } + + // Decompose the response bytes in a message (HTTP body) and fields (HTTP headers), then log it + fields, err = decomposeResponseForLogging(res) + if err != nil { + t.Error(ctx, "Failed to parse response bytes for logging", map[string]interface{}{ + "error": err, + }) + } else { + t.Debug(ctx, "Received HTTP Response", fields) + } + + return res, nil +} + +func (t *loggingHttpTransport) Debug(ctx context.Context, msg string, fields ...map[string]interface{}) { + if t.subsystem != "" { + tflog.SubsystemDebug(ctx, t.subsystem, msg, fields...) + } else { + tflog.Debug(ctx, msg, fields...) + } +} + +func (t *loggingHttpTransport) Error(ctx context.Context, msg string, fields ...map[string]interface{}) { + if t.subsystem != "" { + tflog.SubsystemError(ctx, t.subsystem, msg, fields...) + } else { + tflog.Error(ctx, msg, fields...) + } +} + +func (t *loggingHttpTransport) AddTransactionIdField(ctx context.Context) context.Context { + tId, err := uuid.GenerateUUID() + + if err != nil { + tId = "Unable to assign Transaction ID: " + err.Error() + } + + if t.subsystem != "" { + return tflog.SubsystemSetField(ctx, t.subsystem, FieldHttpTransactionId, tId) + } else { + return tflog.SetField(ctx, FieldHttpTransactionId, tId) + + } +} + +func decomposeRequestForLogging(req *http.Request) (map[string]interface{}, error) { + fields := make(map[string]interface{}, len(req.Header)+4) + fields[FieldHttpOperationType] = OperationHttpRequest + + fields[FieldHttpRequestMethod] = req.Method + fields[FieldHttpRequestUri] = req.URL.RequestURI() + fields[FieldHttpRequestProtoVersion] = req.Proto + + // Get the full body of the request, including headers appended by http.Transport: + // this is necessary because the http.Request at this stage doesn't contain + // all the headers that will be eventually sent. + // We rely on `httputil.DumpRequestOut` to obtain the actual bytes that will be sent out. + reqBytes, err := httputil.DumpRequestOut(req, true) + if err != nil { + return nil, err + } + + // Create a reader around the request full body + reqReader := textproto.NewReader(bufio.NewReader(bytes.NewReader(reqBytes))) + + err = fieldHeadersFromRequestReader(reqReader, fields) + if err != nil { + return nil, err + } + + // Read the rest of the body content + fields[FieldHttpRequestBody] = bodyFromRestOfRequestReader(reqReader) + return fields, nil +} + +func fieldHeadersFromRequestReader(reader *textproto.Reader, fields map[string]interface{}) error { + // Ignore the first line: it contains non-header content + // that we have already captured. + // Skipping this step, would cause the following call to `ReadMIMEHeader()` + // to fail as it cannot parse the first line. + _, err := reader.ReadLine() + if err != nil { + return err + } + + // Read the MIME-style headers + mimeHeader, err := reader.ReadMIMEHeader() + if err != nil { + return err + } + + // Set the headers as fields to log + for k, v := range mimeHeader { + if len(v) == 1 { + fields[k] = v[0] + } else { + fields[k] = v + } + } + + return nil +} + +func bodyFromRestOfRequestReader(reader *textproto.Reader) string { + var builder strings.Builder + for { + line, err := reader.ReadContinuedLine() + if errors.Is(err, io.EOF) { + break + } + builder.WriteString(line) + } + + return builder.String() +} + +func decomposeResponseForLogging(res *http.Response) (map[string]interface{}, error) { + fields := make(map[string]interface{}, len(res.Header)+4) + fields[FieldHttpOperationType] = OperationHttpResponse + + fields[FieldHttpResponseProtoVersion] = res.Proto + fields[FieldHttpResponseStatusCode] = res.StatusCode + fields[FieldHttpResponseStatusReason] = res.Status + + // Set the headers as fields to log + for k, v := range res.Header { + if len(v) == 1 { + fields[k] = v[0] + } else { + fields[k] = v + } + } + + // Read the whole response body + resBody, err := io.ReadAll(res.Body) + if err != nil { + return nil, err + } + + // Wrap the bytes from the response body, back into an io.ReadCloser, + // to respect the interface of http.Response, as expected by users of the + // http.Client + res.Body = io.NopCloser(bytes.NewBuffer(resBody)) + + fields[FieldHttpResponseBody] = string(resBody) + + return fields, nil +} diff --git a/helper/logging/logging_http_transport_test.go b/helper/logging/logging_http_transport_test.go new file mode 100644 index 00000000000..b9c986fe5fc --- /dev/null +++ b/helper/logging/logging_http_transport_test.go @@ -0,0 +1,286 @@ +package logging_test + +import ( + "bytes" + "context" + "io" + "net/http" + "regexp" + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "github.com/hashicorp/go-uuid" + "github.com/hashicorp/terraform-plugin-log/tflog" + "github.com/hashicorp/terraform-plugin-log/tflogtest" + "github.com/hashicorp/terraform-plugin-sdk/v2/helper/logging" +) + +func TestNewLoggingHTTPTransport(t *testing.T) { + ctx, loggerOutput := setupRootLogger() + + transport := logging.NewLoggingHTTPTransport(http.DefaultTransport) + client := http.Client{ + Transport: transport, + Timeout: 10 * time.Second, + } + + reqBody := `An example + multiline + request body` + req, _ := http.NewRequest("GET", "https://www.terraform.io", bytes.NewBufferString(reqBody)) + res, err := client.Do(req.WithContext(ctx)) + if err != nil { + t.Fatalf("request failed: %v", err) + } + defer res.Body.Close() + + entries, err := tflogtest.MultilineJSONDecode(loggerOutput) + if err != nil { + t.Fatalf("log outtput parsing failed: %v", err) + } + + if len(entries) != 2 { + t.Fatalf("unexpected amount of logs produced; expected 2, got %d", len(entries)) + } + + if transId, ok := entries[0]["tf_http_trans_id"]; !ok || transId != entries[1]["tf_http_trans_id"] { + t.Fatalf("expected to find the same 'tf_http_trans_id' in both req/res entries, got %q", transId) + } + + transId, ok := entries[0]["tf_http_trans_id"].(string) + if !ok { + t.Fatalf("expected 'tf_http_trans_id' to be a string, got %T", transId) + } + + if _, err := uuid.ParseUUID(transId); err != nil { + t.Fatalf("expected 'tf_http_trans_id' to be contain a valid UUID, but got an error: %v", err) + } + + reqEntry := entries[0] + if diff := cmp.Diff(reqEntry, map[string]interface{}{ + "@level": "debug", + "@message": "Sending HTTP Request", + "@module": "provider", + "tf_http_op_type": "request", + "tf_http_req_method": "GET", + "tf_http_req_uri": "/", + "tf_http_req_version": "HTTP/1.1", + "tf_http_req_body": "An example multiline request body", + "tf_http_trans_id": transId, + "Accept-Encoding": "gzip", + "Host": "www.terraform.io", + "User-Agent": "Go-http-client/1.1", + "Content-Length": "37", + }); diff != "" { + t.Fatalf("unexpected difference for logging of the request:\n%s", diff) + } + + resEntry := entries[1] + expectedResEntryFields := map[string]interface{}{ + "@level": "debug", + "@module": "provider", + "@message": "Received HTTP Response", + "Content-Type": "text/html", + "tf_http_op_type": "response", + "tf_http_res_status_code": float64(200), + "tf_http_res_version": "HTTP/2.0", + "tf_http_res_status_reason": "200 OK", + "tf_http_trans_id": transId, + } + for ek, ev := range expectedResEntryFields { + if resEntry[ek] != ev { + t.Fatalf("Unexpected value for field %q; expected %q, got %q", ek, ev, resEntry[ek]) + } + } + + expectedNonEmptyEntryFields := []string{ + "tf_http_res_body", "Etag", "Date", "X-Frame-Options", "Server", + } + for _, ek := range expectedNonEmptyEntryFields { + if ev, ok := resEntry[ek]; !ok || ev == "" { + t.Fatalf("Expected field %q to contain a non-null value", ek) + } + } +} + +func TestNewSubsystemLoggingHTTPTransport(t *testing.T) { + subsys := "test-subsystem" + + ctx, loggerOutput := setupRootLogger() + ctx = tflog.NewSubsystem(ctx, subsys) + + transport := logging.NewSubsystemLoggingHTTPTransport(subsys, http.DefaultTransport) + client := http.Client{ + Transport: transport, + Timeout: 10 * time.Second, + } + + reqBody := `An example + multiline + request body` + req, _ := http.NewRequest("GET", "https://www.terraform.io", bytes.NewBufferString(reqBody)) + res, err := client.Do(req.WithContext(ctx)) + if err != nil { + t.Fatalf("request failed: %v", err) + } + defer res.Body.Close() + + entries, err := tflogtest.MultilineJSONDecode(loggerOutput) + if err != nil { + t.Fatalf("log outtput parsing failed: %v", err) + } + + if len(entries) != 2 { + t.Fatalf("unexpected amount of logs produced; expected 2, got %d", len(entries)) + } + + if transId, ok := entries[0]["tf_http_trans_id"]; !ok || transId != entries[1]["tf_http_trans_id"] { + t.Fatalf("expected to find the same 'tf_http_trans_id' in both req/res entries, got %q", transId) + } + + transId, ok := entries[0]["tf_http_trans_id"].(string) + if !ok { + t.Fatalf("expected 'tf_http_trans_id' to be a string, got %T", transId) + } + + if _, err := uuid.ParseUUID(transId); err != nil { + t.Fatalf("expected 'tf_http_trans_id' to be contain a valid UUID, but got an error: %v", err) + } + + reqEntry := entries[0] + if diff := cmp.Diff(reqEntry, map[string]interface{}{ + "@level": "debug", + "@message": "Sending HTTP Request", + "@module": "provider.test-subsystem", + "tf_http_op_type": "request", + "tf_http_req_method": "GET", + "tf_http_req_uri": "/", + "tf_http_req_version": "HTTP/1.1", + "tf_http_req_body": "An example multiline request body", + "tf_http_trans_id": transId, + "Accept-Encoding": "gzip", + "Host": "www.terraform.io", + "User-Agent": "Go-http-client/1.1", + "Content-Length": "37", + }); diff != "" { + t.Fatalf("unexpected difference for logging of the request:\n%s", diff) + } + + resEntry := entries[1] + expectedResEntryFields := map[string]interface{}{ + "@level": "debug", + "@module": "provider.test-subsystem", + "@message": "Received HTTP Response", + "Content-Type": "text/html", + "tf_http_op_type": "response", + "tf_http_res_status_code": float64(200), + "tf_http_res_version": "HTTP/2.0", + "tf_http_res_status_reason": "200 OK", + "tf_http_trans_id": transId, + } + for ek, ev := range expectedResEntryFields { + if resEntry[ek] != ev { + t.Fatalf("Unexpected value for field %q; expected %q, got %q", ek, ev, resEntry[ek]) + } + } + + expectedNonEmptyEntryFields := []string{ + "tf_http_res_body", "Etag", "Date", "X-Frame-Options", "Server", + } + for _, ek := range expectedNonEmptyEntryFields { + if ev, ok := resEntry[ek]; !ok || ev == "" { + t.Fatalf("Expected field %q to contain a non-null value", ek) + } + } +} + +func TestNewLoggingHTTPTransport_LogMasking(t *testing.T) { + ctx, loggerOutput := setupRootLogger() + ctx = tflog.MaskFieldValuesWithFieldKeys(ctx, "tf_http_op_type") + ctx = tflog.MaskAllFieldValuesRegexes(ctx, regexp.MustCompile(`.*`)) + ctx = tflog.MaskMessageStrings(ctx, "Request", "Response") + + transport := logging.NewLoggingHTTPTransport(http.DefaultTransport) + client := http.Client{ + Transport: transport, + Timeout: 10 * time.Second, + } + + req, _ := http.NewRequest("GET", "https://www.terraform.io", nil) + res, err := client.Do(req.WithContext(ctx)) + if err != nil { + t.Fatalf("request failed: %v", err) + } + defer res.Body.Close() + resBody, err := io.ReadAll(res.Body) + if err != nil { + t.Fatalf("failed to read response body: %v", err) + } + + entries, err := tflogtest.MultilineJSONDecode(loggerOutput) + if err != nil { + t.Fatalf("log outtput parsing failed: %v", err) + } + + if len(entries) != 2 { + t.Fatalf("unexpected amount of logs produced; expected 2, got %d", len(entries)) + } + + if diff := cmp.Diff(entries[0]["@message"], "Sending HTTP ***"); diff != "" { + t.Fatalf("unexpected difference for logging message of request:\n%s", diff) + } + + if diff := cmp.Diff(entries[1]["@message"], "Received HTTP ***"); diff != "" { + t.Fatalf("unexpected difference for logging message of response:\n%s", diff) + } + + expectedMaskedEntryFields := map[string]interface{}{ + "tf_http_op_type": "***", + "tf_http_res_body": "***", + } + for _, entry := range entries { + for expectedK, expectedV := range expectedMaskedEntryFields { + if entryV, ok := entry[expectedK]; ok && entryV != expectedV { + t.Fatalf("Unexpected value for field %q; expected %q, got %q", expectedK, expectedV, entry[expectedK]) + } + } + } + + if diff := cmp.Diff(entries[1]["tf_http_res_body"], string(resBody)); diff == "" { + t.Fatalf("expected HTTP response body and content of field 'tf_http_res_body' to differ, but they do not") + } +} + +func TestNewLoggingHTTPTransport_LogOmitting(t *testing.T) { + ctx, loggerOutput := setupRootLogger() + ctx = tflog.OmitLogWithMessageRegexes(ctx, regexp.MustCompile("(?i)rEsPoNsE")) + ctx = tflog.OmitLogWithFieldKeys(ctx, "tf_http_req_method") + + transport := logging.NewLoggingHTTPTransport(http.DefaultTransport) + client := http.Client{ + Transport: transport, + Timeout: 10 * time.Second, + } + + req, _ := http.NewRequest("GET", "https://www.terraform.io", nil) + res, err := client.Do(req.WithContext(ctx)) + if err != nil { + t.Fatalf("request failed: %v", err) + } + defer res.Body.Close() + + entries, err := tflogtest.MultilineJSONDecode(loggerOutput) + if err != nil { + t.Fatalf("log outtput parsing failed: %v", err) + } + + if len(entries) != 0 { + t.Fatalf("unexpected amount of logs produced; expected 0 (because they should have been omitted), got %d", len(entries)) + } +} + +func setupRootLogger() (context.Context, *bytes.Buffer) { + var output bytes.Buffer + return tflogtest.RootLogger(context.Background(), &output), &output +} diff --git a/helper/logging/transport.go b/helper/logging/transport.go index 6419605e799..bda3813d961 100644 --- a/helper/logging/transport.go +++ b/helper/logging/transport.go @@ -41,6 +41,15 @@ func (t *transport) RoundTrip(req *http.Request) (*http.Response, error) { return resp, nil } +// NewTransport creates a wrapper around a *http.RoundTripper, +// designed to be used for the `Transport` field of http.Client. +// +// This logs each pair of HTTP request/response that it handles. +// The logging is done via Go standard library `log` package. +// +// Deprecated: This will log the content of every http request/response +// at `[DEBUG]` level, without any filtering. Any sensitive information +// will appear as-is in your logs. Please use NewSubsystemLoggingHTTPTransport instead. func NewTransport(name string, t http.RoundTripper) *transport { return &transport{name, t} } diff --git a/helper/schema/provider_test.go b/helper/schema/provider_test.go index 0445e0ef880..e791df50e43 100644 --- a/helper/schema/provider_test.go +++ b/helper/schema/provider_test.go @@ -1002,8 +1002,7 @@ func TestProviderUserAgentAppendViaEnvVar(t *testing.T) { for i, tc := range testCases { t.Run(fmt.Sprintf("%d", i), func(t *testing.T) { - os.Unsetenv(uaEnvVar) - os.Setenv(uaEnvVar, tc.envVarValue) + t.Setenv(uaEnvVar, tc.envVarValue) p := &Provider{TerraformVersion: "4.5.6"} givenUA := p.UserAgent(tc.providerName, tc.providerVersion) if givenUA != tc.expected {