From ccf9de06d7b9dd9b0e6ecb10f0e6950141daec12 Mon Sep 17 00:00:00 2001 From: johha Date: Fri, 30 Jan 2026 13:29:37 +0100 Subject: [PATCH 1/6] Use slog logger and remove redundant logs --- s3/client/aws_s3_blobstore.go | 10 ++++------ s3/client/client.go | 3 +-- 2 files changed, 5 insertions(+), 8 deletions(-) diff --git a/s3/client/aws_s3_blobstore.go b/s3/client/aws_s3_blobstore.go index 854b778..73404fe 100644 --- a/s3/client/aws_s3_blobstore.go +++ b/s3/client/aws_s3_blobstore.go @@ -4,7 +4,7 @@ import ( "errors" "fmt" "io" - "log" + "log/slog" "strings" "time" @@ -84,18 +84,16 @@ func (b *awsS3Client) Put(src io.ReadSeeker, dest string) error { if err != nil { if _, ok := err.(manager.MultiUploadFailure); ok { if retry == maxRetries { - log.Println("Upload retry limit exceeded:", err.Error()) return fmt.Errorf("upload retry limit exceeded: %s", err.Error()) } retry++ time.Sleep(time.Second * time.Duration(retry)) continue } - log.Println("Upload failed:", err.Error()) return fmt.Errorf("upload failure: %s", err.Error()) } - log.Println("Successfully uploaded file to", putResult.Location) + slog.Info("Successfully uploaded file", "location", putResult.Location) return nil } } @@ -134,13 +132,13 @@ func (b *awsS3Client) Exists(dest string) (bool, error) { _, err := b.s3Client.HeadObject(context.TODO(), existsParams) if err == nil { - log.Printf("File '%s' exists in bucket '%s'\n", dest, b.s3cliConfig.BucketName) + slog.Info("Blob exists in bucket", "bucket", b.s3cliConfig.BucketName, "blob", dest) return true, nil } var apiErr smithy.APIError if errors.As(err, &apiErr) && apiErr.ErrorCode() == "NotFound" { - log.Printf("File '%s' does not exist in bucket '%s'\n", dest, b.s3cliConfig.BucketName) + slog.Info("Blob does not exist in bucket", "bucket", b.s3cliConfig.BucketName, "blob", dest) return false, nil } return false, err diff --git a/s3/client/client.go b/s3/client/client.go index 647362e..f5853cc 100644 --- a/s3/client/client.go +++ b/s3/client/client.go @@ -2,7 +2,6 @@ package client import ( "errors" - "log" "os" "time" @@ -43,7 +42,7 @@ func (c *S3CompatibleClient) Get(src string, dest string) error { func (c *S3CompatibleClient) Put(src string, dest string) error { sourceFile, err := os.Open(src) if err != nil { - log.Fatalln(err) + return err } defer sourceFile.Close() //nolint:errcheck return c.awsS3BlobstoreClient.Put(sourceFile, dest) From 9e137ebd689119351cb563eda0a52425648ba187 Mon Sep 17 00:00:00 2001 From: johha Date: Fri, 30 Jan 2026 13:35:39 +0100 Subject: [PATCH 2/6] Add http logger middleware for s3 debug logs --- s3/client/s3middleware/http_logger.go | 56 ++++++++++++++++ s3/client/s3middleware/http_logger_test.go | 65 +++++++++++++++++++ .../s3middleware/middleware_suite_test.go | 13 ++++ s3/client/sdk.go | 10 +++ 4 files changed, 144 insertions(+) create mode 100644 s3/client/s3middleware/http_logger.go create mode 100644 s3/client/s3middleware/http_logger_test.go create mode 100644 s3/client/s3middleware/middleware_suite_test.go diff --git a/s3/client/s3middleware/http_logger.go b/s3/client/s3middleware/http_logger.go new file mode 100644 index 0000000..0cdac46 --- /dev/null +++ b/s3/client/s3middleware/http_logger.go @@ -0,0 +1,56 @@ +package s3middleware + +import ( + "log/slog" + "net/http" + "time" +) + +type roundTripperFunc func(*http.Request) (*http.Response, error) + +func (f roundTripperFunc) RoundTrip(req *http.Request) (*http.Response, error) { return f(req) } + +func NewS3LoggingTransport(base http.RoundTripper) http.RoundTripper { + if base == nil { + base = http.DefaultTransport + } + + return roundTripperFunc(func(req *http.Request) (*http.Response, error) { + start := time.Now() + resp, err := base.RoundTrip(req) + duration := time.Since(start) + + attrs := []any{ + "method", req.Method, + "url", req.URL.String(), + "host", req.Host, + "request_content_length", req.ContentLength, + "duration_ms", duration.Milliseconds(), + } + + if resp != nil { + for k, v := range parseResponseFields(resp) { + attrs = append(attrs, k, v) + } + } + + if err != nil { + attrs = append(attrs, "error", err.Error()) + slog.Error("s3 http request failed", attrs...) + return resp, err + } + + slog.Debug("s3 http request", attrs...) + + return resp, nil + }) +} + +func parseResponseFields(resp *http.Response) map[string]any { + responseFields := make(map[string]any) + responseFields["status_code"] = resp.StatusCode + responseFields["response_content_length"] = resp.ContentLength + responseFields["request_id"] = resp.Header.Get("x-amz-request-id") + responseFields["extended_request_id"] = resp.Header.Get("x-amz-id-2") + return responseFields +} diff --git a/s3/client/s3middleware/http_logger_test.go b/s3/client/s3middleware/http_logger_test.go new file mode 100644 index 0000000..602d9db --- /dev/null +++ b/s3/client/s3middleware/http_logger_test.go @@ -0,0 +1,65 @@ +package s3middleware + +import ( + "bytes" + "errors" + "io" + "log/slog" + "net/http" + "net/http/httptest" + "strings" + + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" +) + +var _ = Describe("HttpLogger", func() { + var buf bytes.Buffer + BeforeEach(func() { + buf.Reset() + logger := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) + slog.SetDefault(logger) + }) + + Context("when transport returns response,", func() { + It("log with 's3 http request' message", func() { + mockTransport := roundTripperFunc(func(req *http.Request) (*http.Response, error) { + return &http.Response{ + StatusCode: 200, + Body: io.NopCloser(strings.NewReader("OK")), + Header: http.Header{"X-Amz-Request-Id": []string{"request-id"}, "X-Amz-Id-2": []string{"extended-request-id"}}, + ContentLength: 3, + }, nil + }) + loggingTransport := NewS3LoggingTransport(mockTransport) + req := httptest.NewRequest("GET", "http://example.com/test", nil) + _, _ = loggingTransport.RoundTrip(req) //nolint:errcheck + logs := buf.String() + Expect(logs).To(ContainSubstring(`"msg":"s3 http request"`)) + Expect(logs).To(ContainSubstring(`"method":"GET"`)) + Expect(logs).To(ContainSubstring(`"status_code":200`)) + Expect(logs).To(ContainSubstring(`"request_id":"request-id"`)) + Expect(logs).To(ContainSubstring(`"extended_request_id":"extended-request-id"`)) + Expect(logs).To(ContainSubstring(`"response_content_length":3`)) + }) + }) + + Context("when transport returns error,", func() { + It("log with 's3 http request failed' message", func() { + + hostNotFound := errors.New("dial tcp: lookup example.com: no such host") + + mockTransport := roundTripperFunc(func(req *http.Request) (*http.Response, error) { + return nil, hostNotFound + }) + loggingTransport := NewS3LoggingTransport(mockTransport) + req := httptest.NewRequest("GET", "http://example.com/test", nil) + _, _ = loggingTransport.RoundTrip(req) //nolint:errcheck + logs := buf.String() + Expect(logs).To(ContainSubstring(`"msg":"s3 http request failed"`)) + Expect(logs).To(ContainSubstring(`"method":"GET"`)) + Expect(logs).To(ContainSubstring(`"error"`)) + Expect(logs).To(ContainSubstring("no such host")) + }) + }) +}) diff --git a/s3/client/s3middleware/middleware_suite_test.go b/s3/client/s3middleware/middleware_suite_test.go new file mode 100644 index 0000000..e673c31 --- /dev/null +++ b/s3/client/s3middleware/middleware_suite_test.go @@ -0,0 +1,13 @@ +package s3middleware + +import ( + "testing" + + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" +) + +func TestMiddleware(t *testing.T) { + RegisterFailHandler(Fail) + RunSpecs(t, "S3 Middleware") +} diff --git a/s3/client/sdk.go b/s3/client/sdk.go index e61ba69..da94a4f 100644 --- a/s3/client/sdk.go +++ b/s3/client/sdk.go @@ -13,6 +13,8 @@ import ( "github.com/aws/aws-sdk-go-v2/service/sts" "github.com/aws/smithy-go/middleware" boshhttp "github.com/cloudfoundry/bosh-utils/httpclient" + "github.com/cloudfoundry/storage-cli/common" + "github.com/cloudfoundry/storage-cli/s3/client/s3middleware" s3cli_config "github.com/cloudfoundry/storage-cli/s3/config" ) @@ -40,6 +42,14 @@ func NewAwsS3ClientWithApiOptions( httpClient = boshhttp.CreateDefaultClientInsecureSkipVerify() } + if common.IsDebug() { + if t, ok := httpClient.Transport.(http.RoundTripper); ok { + httpClient.Transport = s3middleware.NewS3LoggingTransport(t) + } else { + httpClient.Transport = s3middleware.NewS3LoggingTransport(http.DefaultTransport) + } + } + options := []func(*config.LoadOptions) error{ config.WithHTTPClient(httpClient), } From 84aaa1a1bb442b3aa85c099d31b8f6d255725272 Mon Sep 17 00:00:00 2001 From: johha Date: Fri, 30 Jan 2026 13:36:56 +0100 Subject: [PATCH 3/6] Rename and move existing middlewares for better structure --- .../{middlewares.go => s3middleware/accept_encoding_fix.go} | 2 +- s3/client/sdk.go | 2 +- s3/integration/{middlewares.go => test_middlewares.go} | 0 s3/integration/utils.go | 3 ++- 4 files changed, 4 insertions(+), 3 deletions(-) rename s3/client/{middlewares.go => s3middleware/accept_encoding_fix.go} (99%) rename s3/integration/{middlewares.go => test_middlewares.go} (100%) diff --git a/s3/client/middlewares.go b/s3/client/s3middleware/accept_encoding_fix.go similarity index 99% rename from s3/client/middlewares.go rename to s3/client/s3middleware/accept_encoding_fix.go index 0063973..cacae3d 100644 --- a/s3/client/middlewares.go +++ b/s3/client/s3middleware/accept_encoding_fix.go @@ -1,4 +1,4 @@ -package client +package s3middleware import ( "context" diff --git a/s3/client/sdk.go b/s3/client/sdk.go index da94a4f..97261c7 100644 --- a/s3/client/sdk.go +++ b/s3/client/sdk.go @@ -25,7 +25,7 @@ func NewAwsS3Client(c *s3cli_config.S3Cli) (*s3.Client, error) { // Setup middleware fixing request to Google - they expect the 'accept-encoding' header // to not be included in the signature of the request. Not needed for "sign" commands // since they only generate pre-signed URLs without making actual HTTP requests. - apiOptions = append(apiOptions, AddFixAcceptEncodingMiddleware) + apiOptions = append(apiOptions, s3middleware.AddFixAcceptEncodingMiddleware) } return NewAwsS3ClientWithApiOptions(c, apiOptions) } diff --git a/s3/integration/middlewares.go b/s3/integration/test_middlewares.go similarity index 100% rename from s3/integration/middlewares.go rename to s3/integration/test_middlewares.go diff --git a/s3/integration/utils.go b/s3/integration/utils.go index 8bec3be..f79647d 100644 --- a/s3/integration/utils.go +++ b/s3/integration/utils.go @@ -10,6 +10,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/s3" "github.com/aws/smithy-go/middleware" "github.com/cloudfoundry/storage-cli/s3/client" + "github.com/cloudfoundry/storage-cli/s3/client/s3middleware" "github.com/cloudfoundry/storage-cli/s3/config" . "github.com/onsi/ginkgo/v2" //nolint:staticcheck @@ -98,7 +99,7 @@ func CreateTracingS3Client(s3Config *config.S3Cli, calls *[]string) (*s3.Client, var apiOptions []func(stack *middleware.Stack) error // Setup middleware fixing request to Google - they expect the 'accept-encoding' header // to not be included in the signature of the request. - apiOptions = append(apiOptions, client.AddFixAcceptEncodingMiddleware) + apiOptions = append(apiOptions, s3middleware.AddFixAcceptEncodingMiddleware) // Use the centralized client creation logic with a custom middleware apiOptions = append(apiOptions, func(stack *middleware.Stack) error { return stack.Initialize.Add(createS3TracingMiddleware(calls), middleware.Before) From 3a43ad03225bbe40888d5ef6d8b3ad247b4d8eda Mon Sep 17 00:00:00 2001 From: johha Date: Fri, 30 Jan 2026 13:55:04 +0100 Subject: [PATCH 4/6] fix linting --- s3/client/sdk.go | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/s3/client/sdk.go b/s3/client/sdk.go index 97261c7..f792623 100644 --- a/s3/client/sdk.go +++ b/s3/client/sdk.go @@ -43,11 +43,7 @@ func NewAwsS3ClientWithApiOptions( } if common.IsDebug() { - if t, ok := httpClient.Transport.(http.RoundTripper); ok { - httpClient.Transport = s3middleware.NewS3LoggingTransport(t) - } else { - httpClient.Transport = s3middleware.NewS3LoggingTransport(http.DefaultTransport) - } + httpClient.Transport = s3middleware.NewS3LoggingTransport(httpClient.Transport) } options := []func(*config.LoadOptions) error{ From e819abfcb3e04c086625802780f1c6df4266c185 Mon Sep 17 00:00:00 2001 From: johha Date: Fri, 30 Jan 2026 13:57:14 +0100 Subject: [PATCH 5/6] re-enable s3 integration test triggers --- .github/workflows/s3-integration.yml | 16 +++++++--------- README.md | 4 +--- 2 files changed, 8 insertions(+), 12 deletions(-) diff --git a/.github/workflows/s3-integration.yml b/.github/workflows/s3-integration.yml index cccfdd5..e4b5358 100644 --- a/.github/workflows/s3-integration.yml +++ b/.github/workflows/s3-integration.yml @@ -2,15 +2,13 @@ name: S3 Integration Tests on: workflow_dispatch: - # temporarily disabled until S3 implementation uses new structured logging format - # blocked by https://github.com/cloudfoundry/bosh-s3cli/pull/60 which needs to be integrated first - # pull_request: - # paths: - # - ".github/workflows/s3-integration.yml" - # - "s3/**" - # push: - # branches: - # - main + pull_request: + paths: + - ".github/workflows/s3-integration.yml" + - "s3/**" + push: + branches: + - main jobs: # AWS S3 US Integration Tests diff --git a/README.md b/README.md index 5685434..ebcb763 100644 --- a/README.md +++ b/README.md @@ -21,9 +21,7 @@ Key points - additional endpoints needed by CAPI still missing - [Gcs](./gcs/README.md) - [S3](./s3/README.md) - - additional endpoints needed by CAPI still missing - - dev blocked by https://github.com/cloudfoundry/bosh-s3cli/pull/60 - - integration tests disabled (they fail on logging format changes) + - additional endpoints needed by CAPI still missing ## Build From be51c1c6b17f086c255e257f385c6bef03626858 Mon Sep 17 00:00:00 2001 From: johha Date: Fri, 30 Jan 2026 17:03:43 +0100 Subject: [PATCH 6/6] Remove 'object does not exist' log This log message was redundant was clients already log if a blob does not exist, e.g. '{"time":"2026-01-30T17:17:05.405448+01:00","level":"INFO","msg":"Blob does not exist in bucket","bucket":"storage-cli","blob":"bommel3"}' --- main.go | 1 - s3/integration/assertions.go | 7 ++----- 2 files changed, 2 insertions(+), 6 deletions(-) diff --git a/main.go b/main.go index fb5c89a..3069907 100644 --- a/main.go +++ b/main.go @@ -23,7 +23,6 @@ func fatalLog(cmd string, err error) { // If the object exists the exit status is 0, otherwise it is 3 // We are using `3` since `1` and `2` have special meanings if _, ok := err.(*storage.NotExistsError); ok { - slog.Error("performing operation", "command", cmd, "error", err) os.Exit(3) } slog.Error("performing operation", "command", cmd, "error", err) diff --git a/s3/integration/assertions.go b/s3/integration/assertions.go index 9513352..fb05003 100644 --- a/s3/integration/assertions.go +++ b/s3/integration/assertions.go @@ -10,13 +10,11 @@ import ( "strings" "time" - "github.com/cloudfoundry/storage-cli/s3/client" - "github.com/cloudfoundry/storage-cli/s3/config" - "github.com/onsi/gomega/gbytes" - "github.com/aws/aws-sdk-go-v2/aws" "github.com/aws/aws-sdk-go-v2/service/s3" "github.com/aws/aws-sdk-go-v2/service/s3/types" + "github.com/cloudfoundry/storage-cli/s3/client" + "github.com/cloudfoundry/storage-cli/s3/config" . "github.com/onsi/gomega" //nolint:staticcheck ) @@ -99,7 +97,6 @@ func AssertLifecycleWorks(s3CLIPath string, cfg *config.S3Cli) { s3CLISession, err = RunS3CLI(s3CLIPath, configPath, storageType, "exists", s3Filename) Expect(err).ToNot(HaveOccurred()) Expect(s3CLISession.ExitCode()).To(Equal(3)) - Expect(s3CLISession.Err).Should(gbytes.Say(`"error":"object does not exist"`)) } func AssertOnPutFailures(cfg *config.S3Cli, content, errorMessage string) {