diff --git a/s3api/controllers/base.go b/s3api/controllers/base.go index b3285ca..c2cf133 100644 --- a/s3api/controllers/base.go +++ b/s3api/controllers/base.go @@ -20,8 +20,8 @@ import ( "errors" "fmt" "io" + "log" "net/http" - "os" "strconv" "strings" @@ -113,6 +113,7 @@ func (c S3ApiController) GetActions(ctx *fiber.Ctx) error { return SendResponse(ctx, err) } + ctx.Locals("logResBody", false) res, err := c.be.GetObject(bucket, key, acceptRange, ctx.Response().BodyWriter()) if err != nil { return SendResponse(ctx, err) @@ -148,7 +149,7 @@ func (c S3ApiController) GetActions(ctx *fiber.Ctx) error { Value: lastmod, }, }) - return ctx.SendStatus(http.StatusOK) + return SendResponse(ctx, err) } func getstring(s *string) string { @@ -333,6 +334,7 @@ func (c S3ApiController) PutActions(ctx *fiber.Ctx) error { } body := io.ReadSeeker(bytes.NewReader([]byte(ctx.Body()))) + ctx.Locals("logReqBody", false) etag, err := c.be.PutObjectPart(bucket, keyStart, uploadId, partNumber, contentLength, body) ctx.Response().Header.Set("Etag", etag) @@ -381,6 +383,7 @@ func (c S3ApiController) PutActions(ctx *fiber.Ctx) error { return SendResponse(ctx, err) } + ctx.Locals("logReqBody", false) etag, err := c.be.PutObject(&s3.PutObjectInput{ Bucket: &bucket, Key: &keyStart, @@ -643,13 +646,14 @@ func SendResponse(ctx *fiber.Ctx, err error) error { return ctx.Send(s3err.GetAPIErrorResponse(serr, "", "", "")) } - fmt.Fprintf(os.Stderr, "Internal Error, req:\n%v\nerr: %v\n", - ctx.Request().Header.String(), err) - + log.Printf("Internal Error, %v", err) + ctx.Status(http.StatusInternalServerError) return ctx.Send(s3err.GetAPIErrorResponse( s3err.GetAPIError(s3err.ErrInternalError), "", "", "")) } + utils.LogCtxDetails(ctx, []byte{}) + // https://github.com/gofiber/fiber/issues/2080 // ctx.SendStatus() sets incorrect content length on HEAD request ctx.Status(http.StatusOK) @@ -664,8 +668,8 @@ func SendXMLResponse(ctx *fiber.Ctx, resp any, err error) error { return ctx.Send(s3err.GetAPIErrorResponse(serr, "", "", "")) } - fmt.Fprintf(os.Stderr, "Internal Error, req:\n%v\nerr: %v\n", - ctx.Request().Header.String(), err) + log.Printf("Internal Error, %v", err) + ctx.Status(http.StatusInternalServerError) return ctx.Send(s3err.GetAPIErrorResponse( s3err.GetAPIError(s3err.ErrInternalError), "", "", "")) @@ -683,5 +687,7 @@ func SendXMLResponse(ctx *fiber.Ctx, resp any, err error) error { } } + utils.LogCtxDetails(ctx, b) + return ctx.Send(b) } diff --git a/s3api/controllers/base_test.go b/s3api/controllers/base_test.go index 9239bb6..1e49e0c 100644 --- a/s3api/controllers/base_test.go +++ b/s3api/controllers/base_test.go @@ -27,7 +27,6 @@ import ( "github.com/aws/aws-sdk-go-v2/service/s3" "github.com/aws/aws-sdk-go-v2/service/s3/types" "github.com/gofiber/fiber/v2" - "github.com/valyala/fasthttp" "github.com/versity/versitygw/auth" "github.com/versity/versitygw/backend" "github.com/versity/versitygw/s3err" @@ -98,6 +97,7 @@ func TestS3ApiController_ListBuckets(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Get("/", s3ApiController.ListBuckets) @@ -118,6 +118,7 @@ func TestS3ApiController_ListBuckets(t *testing.T) { appErr.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) appErr.Get("/", s3ApiControllerErr.ListBuckets) @@ -191,6 +192,7 @@ func TestS3ApiController_GetActions(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Get("/:bucket/:key/*", s3ApiController.GetActions) @@ -301,6 +303,7 @@ func TestS3ApiController_ListActions(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) @@ -321,6 +324,7 @@ func TestS3ApiController_ListActions(t *testing.T) { appError.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) appError.Get("/:bucket", s3ApiControllerError.ListActions) @@ -416,6 +420,7 @@ func TestS3ApiController_PutBucketActions(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Put("/:bucket", s3ApiController.PutBucketActions) @@ -505,6 +510,7 @@ func TestS3ApiController_PutActions(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Put("/:bucket/:key/*", s3ApiController.PutActions) @@ -637,6 +643,7 @@ func TestS3ApiController_DeleteBucket(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) @@ -659,6 +666,7 @@ func TestS3ApiController_DeleteBucket(t *testing.T) { appErr.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) appErr.Delete("/:bucket", s3ApiControllerErr.DeleteBucket) @@ -722,6 +730,7 @@ func TestS3ApiController_DeleteObjects(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Post("/:bucket", s3ApiController.DeleteObjects) @@ -794,6 +803,7 @@ func TestS3ApiController_DeleteActions(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Delete("/:bucket/:key/*", s3ApiController.DeleteActions) @@ -813,6 +823,7 @@ func TestS3ApiController_DeleteActions(t *testing.T) { appErr.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) appErr.Delete("/:bucket", s3ApiControllerErr.DeleteBucket) @@ -885,6 +896,7 @@ func TestS3ApiController_HeadBucket(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) @@ -906,6 +918,7 @@ func TestS3ApiController_HeadBucket(t *testing.T) { appErr.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) @@ -983,6 +996,7 @@ func TestS3ApiController_HeadObject(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Head("/:bucket/:key/*", s3ApiController.HeadObject) @@ -1004,6 +1018,7 @@ func TestS3ApiController_HeadObject(t *testing.T) { appErr.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) appErr.Head("/:bucket/:key/*", s3ApiControllerErr.HeadObject) @@ -1072,6 +1087,7 @@ func TestS3ApiController_CreateActions(t *testing.T) { app.Use(func(ctx *fiber.Ctx) error { ctx.Locals("access", "valid access") ctx.Locals("isRoot", true) + ctx.Locals("isDebug", false) return ctx.Next() }) app.Post("/:bucket/:key/*", s3ApiController.CreateActions) @@ -1150,6 +1166,15 @@ func Test_XMLresponse(t *testing.T) { } app := fiber.New() + var ctx fiber.Ctx + // Mocking the fiber ctx + app.Get("/:bucket/:key", func(c *fiber.Ctx) error { + ctx = *c + return nil + }) + + app.Test(httptest.NewRequest(http.MethodGet, "/my-bucket/my-key", nil)) + tests := []struct { name string args args @@ -1159,7 +1184,7 @@ func Test_XMLresponse(t *testing.T) { { name: "Internal-server-error", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: nil, err: s3err.GetAPIError(16), }, @@ -1169,7 +1194,7 @@ func Test_XMLresponse(t *testing.T) { { name: "Error-not-implemented", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: nil, err: s3err.GetAPIError(50), }, @@ -1179,7 +1204,7 @@ func Test_XMLresponse(t *testing.T) { { name: "Invalid-request-body", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: make(chan int), err: nil, }, @@ -1189,7 +1214,7 @@ func Test_XMLresponse(t *testing.T) { { name: "Successful-response", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: "Valid response", err: nil, }, @@ -1208,6 +1233,8 @@ func Test_XMLresponse(t *testing.T) { if statusCode != tt.statusCode { t.Errorf("response() %v code = %v, wantErr %v", tt.name, statusCode, tt.wantErr) } + + tt.args.ctx.Status(http.StatusOK) }) } } @@ -1219,6 +1246,14 @@ func Test_response(t *testing.T) { err error } app := fiber.New() + var ctx fiber.Ctx + // Mocking the fiber ctx + app.Get("/:bucket/:key", func(c *fiber.Ctx) error { + ctx = *c + return nil + }) + + app.Test(httptest.NewRequest(http.MethodGet, "/my-bucket/my-key", nil)) tests := []struct { name string @@ -1229,7 +1264,7 @@ func Test_response(t *testing.T) { { name: "Internal-server-error", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: nil, err: s3err.GetAPIError(16), }, @@ -1239,7 +1274,7 @@ func Test_response(t *testing.T) { { name: "Error-not-implemented", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: nil, err: s3err.GetAPIError(50), }, @@ -1249,7 +1284,7 @@ func Test_response(t *testing.T) { { name: "Successful-response", args: args{ - ctx: app.AcquireCtx(&fasthttp.RequestCtx{}), + ctx: &ctx, resp: "Valid response", err: nil, }, diff --git a/s3api/middlewares/logger.go b/s3api/middlewares/logger.go new file mode 100644 index 0000000..17c7182 --- /dev/null +++ b/s3api/middlewares/logger.go @@ -0,0 +1,44 @@ +// Copyright 2023 Versity Software +// This file is licensed under the Apache License, Version 2.0 +// (the "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, +// software distributed under the License is distributed on an +// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +// KIND, either express or implied. See the License for the +// specific language governing permissions and limitations +// under the License. + +package middlewares + +import ( + "fmt" + "log" + + "github.com/gofiber/fiber/v2" +) + +func RequestLogger(isDebug bool) fiber.Handler { + return func(ctx *fiber.Ctx) error { + ctx.Locals("isDebug", isDebug) + if isDebug { + log.Println("Request headers: ") + ctx.Request().Header.VisitAll(func(key, val []byte) { + log.Printf("%s: %s", key, val) + }) + + if ctx.Request().URI().QueryArgs().Len() != 0 { + fmt.Println() + log.Println("Request query arguments: ") + ctx.Request().URI().QueryArgs().VisitAll(func(key, val []byte) { + log.Printf("%s: %s", key, val) + }) + } + } + + return ctx.Next() + } +} diff --git a/s3api/server.go b/s3api/server.go index b52835e..b2c9f79 100644 --- a/s3api/server.go +++ b/s3api/server.go @@ -45,10 +45,16 @@ func New(app *fiber.App, be backend.Backend, root middlewares.RootUserConfig, po opt(server) } - app.Use(middlewares.VerifyV4Signature(root, iam, region, server.debug)) + // Logging middlewares app.Use(logger.New()) + app.Use(middlewares.RequestLogger(server.debug)) + + // Authentication middlewares + app.Use(middlewares.VerifyV4Signature(root, iam, region, server.debug)) app.Use(middlewares.VerifyMD5Body()) + server.router.Init(app, be, iam) + return server, nil } diff --git a/s3api/utils/logger.go b/s3api/utils/logger.go new file mode 100644 index 0000000..8bb2682 --- /dev/null +++ b/s3api/utils/logger.go @@ -0,0 +1,55 @@ +// Copyright 2023 Versity Software +// This file is licensed under the Apache License, Version 2.0 +// (the "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, +// software distributed under the License is distributed on an +// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +// KIND, either express or implied. See the License for the +// specific language governing permissions and limitations +// under the License. + +package utils + +import ( + "fmt" + "log" + + "github.com/gofiber/fiber/v2" +) + +func LogCtxDetails(ctx *fiber.Ctx, respBody []byte) { + isDebug, ok := ctx.Locals("isDebug").(bool) + _, notLogReqBody := ctx.Locals("logReqBody").(bool) + _, notLogResBody := ctx.Locals("logResBody").(bool) + if isDebug && ok { + // Log request body + if !notLogReqBody { + fmt.Println() + log.Printf("Request Body: %s", ctx.Request().Body()) + } + + // Log path parameters + fmt.Println() + log.Println("Path parameters: ") + for key, val := range ctx.AllParams() { + log.Printf("%s: %s", key, val) + } + + // Log response headers + fmt.Println() + log.Println("Response Headers: ") + ctx.Response().Header.VisitAll(func(key, val []byte) { + log.Printf("%s: %s", key, val) + }) + + // Log response body + if !notLogResBody && len(respBody) > 0 { + fmt.Println() + log.Printf("Response body %s", ctx.Response().Body()) + } + } +}