From aa2d99c3c322816004373e744823d8be95552972 Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Tue, 19 Sep 2023 12:50:19 -0700 Subject: [PATCH 1/3] Removes S3 object bodies from request logs --- logger.go | 2 +- logging/http.go | 93 ++++++++++++++++++++++++++++++++++++++---- v2/awsv1shim/logger.go | 2 +- 3 files changed, 86 insertions(+), 11 deletions(-) diff --git a/logger.go b/logger.go index 6d202cde..2e38dab3 100644 --- a/logger.go +++ b/logger.go @@ -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) } diff --git a/logging/http.go b/logging/http.go index 87b95cd6..87c5696c 100644 --- a/logging/http.go +++ b/logging/http.go @@ -6,6 +6,7 @@ package logging import ( "bufio" "bytes" + "context" "errors" "fmt" "io" @@ -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 ( @@ -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)...) @@ -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 { @@ -90,28 +93,100 @@ 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 +} + +func requestBodyLogger(ctx context.Context) RequestBodyLogger { + if awsmiddleware.GetServiceID(ctx) == "S3" { + if op := awsmiddleware.GetOperationName(ctx); op == "PutObject" || op == "UploadPart" { + return &s3ObjectBodyLogger{} + } + } + + 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 = &s3ObjectBodyLogger{} + +type s3ObjectBodyLogger struct{} + +func (l *s3ObjectBodyLogger) Log(ctx context.Context, req *http.Request, attrs *[]attribute.KeyValue) error { + length := outgoingLength(req) + + body := fmt.Sprintf("[Payload: %s", formatByteSize(length)) + + if contentType := req.Header.Get("Content-Type"); contentType != "" { + body += fmt.Sprintf(", Type: %s", contentType) + } + + body += "]" + + *attrs = append(*attrs, attribute.String("http.request.body", body)) + + return nil +} + +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 { diff --git a/v2/awsv1shim/logger.go b/v2/awsv1shim/logger.go index 8c34d4e9..04103f3c 100644 --- a/v2/awsv1shim/logger.go +++ b/v2/awsv1shim/logger.go @@ -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 From e67a68a77f4fa7cd6fe69ae42cdf4af66104511e Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Tue, 19 Sep 2023 16:35:04 -0700 Subject: [PATCH 2/3] Removes S3 object bodies from response logs --- logger.go | 32 ++++++++++++++++++++++++-------- logging/http.go | 44 +++++++++++++++++++++++++++++++++++--------- 2 files changed, 59 insertions(+), 17 deletions(-) diff --git a/logger.go b/logger.go index 2e38dab3..299119a4 100644 --- a/logger.go +++ b/logger.go @@ -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) } @@ -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())) @@ -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 { @@ -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 @@ -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 } diff --git a/logging/http.go b/logging/http.go index 87c5696c..42857f58 100644 --- a/logging/http.go +++ b/logging/http.go @@ -97,10 +97,14 @@ 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 &s3ObjectBodyLogger{} + return &s3ObjectRequestBodyLogger{} } } @@ -137,24 +141,46 @@ func (l *defaultRequestBodyLogger) Log(ctx context.Context, req *http.Request, a return nil } -var _ RequestBodyLogger = &s3ObjectBodyLogger{} +var _ RequestBodyLogger = &s3ObjectRequestBodyLogger{} -type s3ObjectBodyLogger struct{} +type s3ObjectRequestBodyLogger struct{} -func (l *s3ObjectBodyLogger) Log(ctx context.Context, req *http.Request, attrs *[]attribute.KeyValue) error { +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{} - body := fmt.Sprintf("[Payload: %s", formatByteSize(length)) +func (l *S3ObjectResponseBodyLogger) Log(ctx context.Context, resp *http.Response, attrs *[]attribute.KeyValue) error { + length := resp.ContentLength + contentType := resp.Header.Get("Content-Type") - if contentType := req.Header.Get("Content-Type"); contentType != "" { + 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 += "]" - *attrs = append(*attrs, attribute.String("http.request.body", body)) - - return nil + return body } const byteSizeStep = 1024.0 From 70bf9f14852df26f2ec98e2772187c59f80e15e5 Mon Sep 17 00:00:00 2001 From: Graham Davison Date: Tue, 19 Sep 2023 17:05:47 -0700 Subject: [PATCH 3/3] `go mod tidy` --- go.mod | 1 + go.sum | 2 ++ v2/awsv1shim/go.mod | 1 + v2/awsv1shim/go.sum | 2 ++ 4 files changed, 6 insertions(+) diff --git a/go.mod b/go.mod index caa51d86..0d731095 100644 --- a/go.mod +++ b/go.mod @@ -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 ( diff --git a/go.sum b/go.sum index deaaf905..88183f7f 100644 --- a/go.sum +++ b/go.sum @@ -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= diff --git a/v2/awsv1shim/go.mod b/v2/awsv1shim/go.mod index 73095a52..c45e2382 100644 --- a/v2/awsv1shim/go.mod +++ b/v2/awsv1shim/go.mod @@ -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 => ../.. diff --git a/v2/awsv1shim/go.sum b/v2/awsv1shim/go.sum index 82c335a0..51fa8514 100644 --- a/v2/awsv1shim/go.sum +++ b/v2/awsv1shim/go.sum @@ -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=