Skip to content

Commit

Permalink
Merge pull request #661 from hashicorp/f-s3-logging
Browse files Browse the repository at this point in the history
Removes S3 object bodies from HTTP request/response logs
  • Loading branch information
gdavison authored Sep 20, 2023
2 parents 3b0502f + 70bf9f1 commit ceb3158
Show file tree
Hide file tree
Showing 7 changed files with 142 additions and 19 deletions.
1 change: 1 addition & 0 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ require (
go.opentelemetry.io/contrib/instrumentation/github.com/aws/aws-sdk-go-v2/otelaws v0.44.0
go.opentelemetry.io/otel v1.18.0
golang.org/x/exp v0.0.0-20230905200255-921286631fa9
golang.org/x/text v0.13.0
)

require (
Expand Down
2 changes: 2 additions & 0 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -95,6 +95,8 @@ golang.org/x/sys v0.0.0-20220503163025-988cb79eb6c6/go.mod h1:oPkhp1MJrh7nUepCBc
golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.12.0 h1:CM0HF96J0hcLAwsHPJZjfdNzs0gftsLfgKt57wWHJ0o=
golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/text v0.13.0 h1:ablQoSUd0tRdKxZewP80B+BaqeKJuVhuRxj/dkrun3k=
golang.org/x/text v0.13.0/go.mod h1:TvPlkZtksWOMsz7fbANvkp4WM8x/WCo/om8BMLbz+aE=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.4.0 h1:D8xgwECY7CYvx+Y2n4sBz93Jn9JRvxdiyyo8CTfuKaY=
Expand Down
34 changes: 25 additions & 9 deletions logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -103,7 +103,7 @@ func (r *requestResponseLogger) HandleDeserialize(ctx context.Context, in middle

rc := smithyRequest.Build(ctx)

requestFields, err := logging.DecomposeHTTPRequest(rc)
requestFields, err := logging.DecomposeHTTPRequest(ctx, rc)
if err != nil {
return out, metadata, fmt.Errorf("decomposing request: %w", err)
}
Expand All @@ -127,7 +127,7 @@ func (r *requestResponseLogger) HandleDeserialize(ctx context.Context, in middle
return out, metadata, fmt.Errorf("unknown response type: %T", out.RawResponse)
}

responseFields, err := decomposeHTTPResponse(smithyResponse.Response, elapsed)
responseFields, err := decomposeHTTPResponse(ctx, smithyResponse.Response, elapsed)
if err != nil {
return out, metadata, fmt.Errorf("decomposing response: %w", err)
}
Expand All @@ -137,7 +137,7 @@ func (r *requestResponseLogger) HandleDeserialize(ctx context.Context, in middle
return out, metadata, err
}

func decomposeHTTPResponse(resp *http.Response, elapsed time.Duration) (map[string]any, error) {
func decomposeHTTPResponse(ctx context.Context, resp *http.Response, elapsed time.Duration) (map[string]any, error) {
var attributes []attribute.KeyValue

attributes = append(attributes, attribute.Int64("http.duration", elapsed.Milliseconds()))
Expand All @@ -146,11 +146,11 @@ func decomposeHTTPResponse(resp *http.Response, elapsed time.Duration) (map[stri

attributes = append(attributes, logging.DecomposeResponseHeaders(resp)...)

bodyAttribute, err := decomposeResponseBody(resp)
bodyLogger := responseBodyLogger(ctx)
err := bodyLogger.Log(ctx, resp, &attributes)
if err != nil {
return nil, err
}
attributes = append(attributes, bodyAttribute)

result := make(map[string]any, len(attributes))
for _, attribute := range attributes {
Expand All @@ -160,10 +160,24 @@ func decomposeHTTPResponse(resp *http.Response, elapsed time.Duration) (map[stri
return result, nil
}

func decomposeResponseBody(resp *http.Response) (kv attribute.KeyValue, err error) {
func responseBodyLogger(ctx context.Context) logging.ResponseBodyLogger {
if awsmiddleware.GetServiceID(ctx) == "S3" {
if op := awsmiddleware.GetOperationName(ctx); op == "GetObject" {
return &logging.S3ObjectResponseBodyLogger{}
}
}

return &defaultResponseBodyLogger{}
}

var _ logging.ResponseBodyLogger = &defaultResponseBodyLogger{}

type defaultResponseBodyLogger struct{}

func (l *defaultResponseBodyLogger) Log(ctx context.Context, resp *http.Response, attrs *[]attribute.KeyValue) error {
content, err := io.ReadAll(resp.Body)
if err != nil {
return kv, err
return err
}

// Restore the body reader
Expand All @@ -173,8 +187,10 @@ func decomposeResponseBody(resp *http.Response) (kv attribute.KeyValue, err erro

body, err := logging.ReadTruncatedBody(reader, logging.MaxResponseBodyLen)
if err != nil {
return kv, err
return err
}

return attribute.String("http.response.body", body), nil
*attrs = append(*attrs, attribute.String("http.response.body", body))

return nil
}
119 changes: 110 additions & 9 deletions logging/http.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ package logging
import (
"bufio"
"bytes"
"context"
"errors"
"fmt"
"io"
Expand All @@ -16,10 +17,12 @@ import (
"strconv"
"strings"

awsmiddleware "github.com/aws/aws-sdk-go-v2/aws/middleware"
"github.com/hashicorp/aws-sdk-go-base/v2/internal/slices"
"go.opentelemetry.io/otel/attribute"
"go.opentelemetry.io/otel/semconv/v1.17.0/httpconv"
semconv "go.opentelemetry.io/otel/semconv/v1.4.0"
"golang.org/x/text/message"
)

const (
Expand All @@ -28,7 +31,7 @@ const (
MaxResponseBodyLen = 4096
)

func DecomposeHTTPRequest(req *http.Request) (map[string]any, error) {
func DecomposeHTTPRequest(ctx context.Context, req *http.Request) (map[string]any, error) {
var attributes []attribute.KeyValue

attributes = append(attributes, httpconv.ClientRequest(req)...)
Expand All @@ -39,11 +42,11 @@ func DecomposeHTTPRequest(req *http.Request) (map[string]any, error) {

attributes = append(attributes, decomposeRequestHeaders(req)...)

bodyAttribute, err := decomposeRequestBody(req)
bodyLogger := requestBodyLogger(ctx)
err := bodyLogger.Log(ctx, req, &attributes)
if err != nil {
return nil, err
}
attributes = append(attributes, bodyAttribute)

result := make(map[string]any, len(attributes))
for _, attribute := range attributes {
Expand Down Expand Up @@ -90,28 +93,126 @@ func decomposeRequestHeaders(req *http.Request) []attribute.KeyValue {
return results
}

func decomposeRequestBody(req *http.Request) (kv attribute.KeyValue, err error) {
type RequestBodyLogger interface {
Log(ctx context.Context, req *http.Request, attrs *[]attribute.KeyValue) error
}

type ResponseBodyLogger interface {
Log(ctx context.Context, resp *http.Response, attrs *[]attribute.KeyValue) error
}

func requestBodyLogger(ctx context.Context) RequestBodyLogger {
if awsmiddleware.GetServiceID(ctx) == "S3" {
if op := awsmiddleware.GetOperationName(ctx); op == "PutObject" || op == "UploadPart" {
return &s3ObjectRequestBodyLogger{}
}
}

return &defaultRequestBodyLogger{}
}

var _ RequestBodyLogger = &defaultRequestBodyLogger{}

type defaultRequestBodyLogger struct{}

func (l *defaultRequestBodyLogger) Log(ctx context.Context, req *http.Request, attrs *[]attribute.KeyValue) error {
reqBytes, err := httputil.DumpRequestOut(req, true)
if err != nil {
return kv, err
return err
}

reader := textproto.NewReader(bufio.NewReader(bytes.NewReader(reqBytes)))

if _, err = reader.ReadLine(); err != nil {
return kv, err
return err
}

if _, err = reader.ReadMIMEHeader(); err != nil {
return kv, err
return err
}

body, err := ReadTruncatedBody(reader, maxRequestBodyLen)
if err != nil {
return kv, err
return err
}

return attribute.String("http.request.body", body), nil
*attrs = append(*attrs, attribute.String("http.request.body", body))

return nil
}

var _ RequestBodyLogger = &s3ObjectRequestBodyLogger{}

type s3ObjectRequestBodyLogger struct{}

func (l *s3ObjectRequestBodyLogger) Log(ctx context.Context, req *http.Request, attrs *[]attribute.KeyValue) error {
length := outgoingLength(req)
contentType := req.Header.Get("Content-Type")

body := s3BodyRedacted(length, contentType)

*attrs = append(*attrs, attribute.String("http.request.body", body))

return nil
}

var _ ResponseBodyLogger = &S3ObjectResponseBodyLogger{}

type S3ObjectResponseBodyLogger struct{}

func (l *S3ObjectResponseBodyLogger) Log(ctx context.Context, resp *http.Response, attrs *[]attribute.KeyValue) error {
length := resp.ContentLength
contentType := resp.Header.Get("Content-Type")

body := s3BodyRedacted(length, contentType)

*attrs = append(*attrs, attribute.String("http.response.body", body))

return nil
}

func s3BodyRedacted(length int64, contentType string) string {
body := fmt.Sprintf("[Redacted: %s", formatByteSize(length))

if contentType != "" {
body += fmt.Sprintf(", Type: %s", contentType)
}

body += "]"

return body
}

const byteSizeStep = 1024.0

func formatByteSize(size int64) string {
p := message.NewPrinter(message.MatchLanguage("en"))

if size <= 1024*1.5 {
return p.Sprintf("%d bytes", size)
}

sizef := float64(size) / byteSizeStep
var unit string
for _, unit = range []string{"KB", "MB", "GB"} {
if sizef < byteSizeStep {
break
}
sizef /= byteSizeStep
}
return p.Sprintf("%.1f %s (%d bytes)", sizef, unit, size)
}

// outgoingLength is a copy of the unexported
// (*http.Request).outgoingLength method.
func outgoingLength(req *http.Request) int64 {
if req.Body == nil || req.Body == http.NoBody {
return 0
}
if req.ContentLength != 0 {
return req.ContentLength
}
return -1
}

func RequestHeaderAttributeKey(k string) attribute.Key {
Expand Down
1 change: 1 addition & 0 deletions v2/awsv1shim/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,7 @@ require (
go.opentelemetry.io/otel/trace v1.18.0 // indirect
golang.org/x/exp v0.0.0-20230905200255-921286631fa9 // indirect
golang.org/x/sys v0.12.0 // indirect
golang.org/x/text v0.13.0 // indirect
)

replace github.com/hashicorp/aws-sdk-go-base/v2 => ../..
2 changes: 2 additions & 0 deletions v2/awsv1shim/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -123,6 +123,8 @@ golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
golang.org/x/text v0.3.7/go.mod h1:u+2+/6zg+i71rQMx5EYifcz6MCKuco9NR6JIITiCfzQ=
golang.org/x/text v0.4.0/go.mod h1:mrYo+phRRbMaCq/xk9113O4dZlRixOauAjOtrjsXDZ8=
golang.org/x/text v0.13.0 h1:ablQoSUd0tRdKxZewP80B+BaqeKJuVhuRxj/dkrun3k=
golang.org/x/text v0.13.0/go.mod h1:TvPlkZtksWOMsz7fbANvkp4WM8x/WCo/om8BMLbz+aE=
golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
golang.org/x/tools v0.1.12/go.mod h1:hNGJHUnrk76NpqgfD5Aqm5Crs+Hm0VOH/i9J2+nxYbc=
Expand Down
2 changes: 1 addition & 1 deletion v2/awsv1shim/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ func logRequest(r *request.Request) {

bodySeekable := aws.IsReaderSeekable(r.Body)

requestFields, err := logging.DecomposeHTTPRequest(r.HTTPRequest)
requestFields, err := logging.DecomposeHTTPRequest(ctx, r.HTTPRequest)
if err != nil {
tflog.Error(ctx, fmt.Sprintf("decomposing request: %s", err))
return
Expand Down

0 comments on commit ceb3158

Please sign in to comment.