Add DEBUG-level logging to the "http" state storage backend (#2120)

Signed-off-by: Bari, Haider <haider.bari@fmr.com>
Co-authored-by: Bari, Haider <haider.bari@fmr.com>
This commit is contained in:
Haider Bari 2024-11-20 14:36:45 +00:00 committed by GitHub
parent 2448204201
commit dbea01eea6
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 196 additions and 0 deletions

View File

@ -12,6 +12,7 @@ import (
"encoding/json"
"fmt"
"io"
"log"
"net/http"
"net/url"
@ -48,6 +49,8 @@ func (c *httpClient) httpRequest(method string, url *url.URL, data []byte, what
body = data
}
log.Printf("[DEBUG] Executing HTTP remote state request for: %q", what)
// Create the request
req, err := retryablehttp.NewRequest(method, url.String(), body)
if err != nil {
@ -75,10 +78,14 @@ func (c *httpClient) httpRequest(method string, url *url.URL, data []byte, what
// Make the request
resp, err := c.Client.Do(req)
if err != nil {
return nil, fmt.Errorf("Failed to %s: %w", what, err)
}
log.Printf("[DEBUG] HTTP remote state request for %q returned status code: %d", what, resp.StatusCode)
log.Printf("[DEBUG] HTTP response headers: %s", parseHeadersForLog(resp))
return resp, nil
}
@ -101,8 +108,10 @@ func (c *httpClient) Lock(info *statemgr.LockInfo) (string, error) {
c.jsonLockInfo = jsonLockInfo
return info.ID, nil
case http.StatusUnauthorized:
log.Printf("[DEBUG] LOCK, Unauthorized: %s", parseResponseBodyForLog(resp))
return "", fmt.Errorf("HTTP remote state endpoint requires auth")
case http.StatusForbidden:
log.Printf("[DEBUG] LOCK, Forbidden: %s", parseResponseBodyForLog(resp))
return "", fmt.Errorf("HTTP remote state endpoint invalid auth")
case http.StatusConflict, http.StatusLocked:
body, err := io.ReadAll(resp.Body)
@ -125,6 +134,7 @@ func (c *httpClient) Lock(info *statemgr.LockInfo) (string, error) {
Err: fmt.Errorf("HTTP remote state already locked: ID=%s", existing.ID),
}
default:
log.Printf("[DEBUG] LOCK, %d: %s", resp.StatusCode, parseResponseBodyForLog(resp))
return "", fmt.Errorf("Unexpected HTTP response code %d", resp.StatusCode)
}
}
@ -144,6 +154,7 @@ func (c *httpClient) Unlock(id string) error {
case http.StatusOK:
return nil
default:
log.Printf("[DEBUG] UNLOCK, %d: %s", resp.StatusCode, parseResponseBodyForLog(resp))
return fmt.Errorf("Unexpected HTTP response code %d", resp.StatusCode)
}
}
@ -164,12 +175,16 @@ func (c *httpClient) Get() (*remote.Payload, error) {
case http.StatusNotFound:
return nil, nil
case http.StatusUnauthorized:
log.Printf("[DEBUG] GET STATE, Unauthorized: %s", parseResponseBodyForLog(resp))
return nil, fmt.Errorf("HTTP remote state endpoint requires auth")
case http.StatusForbidden:
log.Printf("[DEBUG] GET STATE, Forbidden: %s", parseResponseBodyForLog(resp))
return nil, fmt.Errorf("HTTP remote state endpoint invalid auth")
case http.StatusInternalServerError:
log.Printf("[DEBUG] GET STATE, Internal Server Error: %s", parseResponseBodyForLog(resp))
return nil, fmt.Errorf("HTTP remote state internal server error")
default:
log.Printf("[DEBUG] GET STATE, %d: %s", resp.StatusCode, parseResponseBodyForLog(resp))
return nil, fmt.Errorf("Unexpected HTTP response code %d", resp.StatusCode)
}
@ -241,6 +256,7 @@ func (c *httpClient) Put(data []byte) error {
case http.StatusOK, http.StatusCreated, http.StatusNoContent:
return nil
default:
log.Printf("[DEBUG] UPLOAD STATE, %d: %s", resp.StatusCode, parseResponseBodyForLog(resp))
return fmt.Errorf("HTTP error: %d", resp.StatusCode)
}
}
@ -258,6 +274,7 @@ func (c *httpClient) Delete() error {
case http.StatusOK:
return nil
default:
log.Printf("[DEBUG] DELETE STATE, %d: %s", resp.StatusCode, parseResponseBodyForLog(resp))
return fmt.Errorf("HTTP error: %d", resp.StatusCode)
}
}

View File

@ -0,0 +1,49 @@
// Copyright (c) The OpenTofu Authors
// SPDX-License-Identifier: MPL-2.0
// Copyright (c) 2023 HashiCorp, Inc.
// SPDX-License-Identifier: MPL-2.0
package http
import (
"encoding/json"
"io"
"log"
"net/http"
"strings"
)
// Helper function to parse response body bytes into a string for logging
func parseResponseBodyForLog(resp *http.Response) string {
body, err := io.ReadAll(resp.Body)
if err != nil {
log.Printf("[ERROR] Failed to read HTTP response body for Logging: %v", err)
return ""
}
return string(body)
}
// Helper function to parse http headers into a json string for logging
func parseHeadersForLog(resp *http.Response) string {
// Blacklist of Header keys that need to be masked
var blacklist = map[string]bool{
"authorization": true,
"cookie": true,
"set-cookie": true,
}
headers := make(map[string]string, len(resp.Header))
for key := range resp.Header {
if blacklist[strings.ToLower(key)] {
headers[key] = "[MASKED]"
} else {
headers[key] = resp.Header.Get(key)
}
}
headersJSON, err := json.Marshal(headers)
if err != nil {
log.Printf("[ERROR] Failed to marshal headers to JSON for Logging: %v", err)
return ""
}
return string(headersJSON)
}

View File

@ -0,0 +1,130 @@
// Copyright (c) The OpenTofu Authors
// SPDX-License-Identifier: MPL-2.0
// Copyright (c) 2023 HashiCorp, Inc.
// SPDX-License-Identifier: MPL-2.0
package http
import (
"bytes"
"fmt"
"io"
"net/http"
"testing"
)
// HTTP request body reader that deliberately causes a read error
type errorReader struct{}
func (e *errorReader) Read(_ []byte) (int, error) {
return 0, fmt.Errorf("read error")
}
func (e *errorReader) Close() error {
return nil
}
func TestParseResponseBodyForLog(t *testing.T) {
testCases := []struct {
name string
responseBody string
expectedOutput string
}{{
name: "Valid json response body",
responseBody: `{"error":"Unauthorized"}`,
expectedOutput: `{"error":"Unauthorized"}`,
},
{
name: "Empty response body",
responseBody: "",
expectedOutput: "",
},
{
name: "Response body with special characters",
responseBody: "Special characters: !@#$%^&*()",
expectedOutput: "Special characters: !@#$%^&*()",
},
}
for _, tt := range testCases {
t.Run(tt.name, func(t *testing.T) {
resp := &http.Response{
Body: io.NopCloser(bytes.NewBufferString(tt.responseBody)),
}
output := parseResponseBodyForLog(resp)
if output != tt.expectedOutput {
t.Errorf("parseResponseBody() = %v; want %v", output, tt.expectedOutput)
}
})
}
t.Run("Error reading response body", func(t *testing.T) {
resp := &http.Response{
Body: io.NopCloser(&errorReader{}),
}
output := parseResponseBodyForLog(resp)
if output != "" {
t.Errorf("parseResponseBody() = %v; want %v", output, "")
}
})
}
func TestParseHeadersForLog(t *testing.T) {
testCases := []struct {
name string
headers http.Header
expectedOutput string
}{
{
name: "Headers with sensitive information",
headers: http.Header{
"Authorization": []string{"token"},
"Set-Cookie": []string{"cookies"},
"Cookie": []string{"cookies"},
"Content-Type": []string{"application/json"},
},
expectedOutput: `{"Authorization":"[MASKED]","Content-Type":"application/json","Cookie":"[MASKED]","Set-Cookie":"[MASKED]"}`,
},
{
name: "Case senstive test with sensitive information Headers",
headers: http.Header{
"authorization": []string{"token"},
"set-Cookie": []string{"cookies"},
"cookie": []string{"cookies"},
"content-type": []string{"application/json"},
},
expectedOutput: `{"authorization":"[MASKED]","content-type":"","cookie":"[MASKED]","set-Cookie":"[MASKED]"}`,
},
{
name: "Headers without sensitive information",
headers: http.Header{
"Content-Type": []string{"application/json"},
"Access-Control-Allow-Origin": []string{"*"},
"Connection": []string{"Keep-Alive"},
"Server": []string{"Apache"},
"Keep-Alive": []string{"timeout=5, max=997"},
},
expectedOutput: `{"Access-Control-Allow-Origin":"*","Connection":"Keep-Alive","Content-Type":"application/json","Keep-Alive":"timeout=5, max=997","Server":"Apache"}`,
},
{
name: "Empty headers",
headers: http.Header{},
expectedOutput: "{}",
},
}
for _, tt := range testCases {
t.Run(tt.name, func(t *testing.T) {
resp := &http.Response{
Header: tt.headers,
}
output := parseHeadersForLog(resp)
if output != tt.expectedOutput {
t.Errorf("parseResponseHeaders() = %v; want %v", output, tt.expectedOutput)
}
})
}
}