Giter Club home page Giter Club logo

slog-fiber's Introduction

slog: Fiber middleware

tag Go Version GoDoc Build Status Go report Coverage Contributors License

Fiber middleware to log http requests using slog.

See also:

๐Ÿš€ Install

go get github.com/samber/slog-fiber

Compatibility: go >= 1.21

No breaking changes will be made to exported APIs before v2.0.0.

๐Ÿ’ก Usage

Minimal

import (
	"github.com/gofiber/fiber/v2"
	"github.com/gofiber/fiber/v2/middleware/recover"
	slogfiber "github.com/samber/slog-fiber"
	"log/slog"
)

// Create a slog logger, which:
//   - Logs to stdout.
logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

app := fiber.New()

app.Use(slogfiber.New(logger))
app.Use(recover.New())

app.Get("/", func(c *fiber.Ctx) error {
	return c.SendString("Hello, World ๐Ÿ‘‹!")
})

app.Listen(":4242")

// output:
// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production request.time=2023-10-15T20:32:58.626+02:00 request.method=GET request.path=/ request.route="" request.ip=127.0.0.1:63932 request.length=0 response.time=2023-10-15T20:32:58.926+02:00 response.latency=100ms response.status=200 response.length=7 id=229c7fc8-64f5-4467-bc4a-940700503b0d

OTEL

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

config := slogfiber.Config{
	WithSpanID:  true,
	WithTraceID: true,
}

app := fiber.New()
app.Use(slogfiber.NewWithConfig(logger, config))

Custom log levels

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

config := slogfiber.Config{
	DefaultLevel:     slog.LevelInfo,
	ClientErrorLevel: slog.LevelWarn,
	ServerErrorLevel: slog.LevelError,
}

app := fiber.New()
app.Use(slogfiber.NewWithConfig(logger, config))

Verbose

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

config := slogfiber.Config{
	WithRequestBody: true,
	WithResponseBody: true,
	WithRequestHeader: true,
	WithResponseHeader: true,
}

app := fiber.New()
app.Use(slogfiber.NewWithConfig(logger, config))

Filters

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

app := fiber.New()
app.Use(
	slogfiber.NewWithFilters(
		logger,
		slogfiber.Accept(func (c *fiber.Ctx) bool {
			return xxx
		}),
		slogfiber.IgnoreStatus(401, 404),
	),
)
app.Use(recover.New())

Available filters:

  • Accept / Ignore
  • AcceptMethod / IgnoreMethod
  • AcceptStatus / IgnoreStatus
  • AcceptStatusGreaterThan / IgnoreStatusLessThan
  • AcceptStatusGreaterThanOrEqual / IgnoreStatusLessThanOrEqual
  • AcceptPath / IgnorePath
  • AcceptPathContains / IgnorePathContains
  • AcceptPathPrefix / IgnorePathPrefix
  • AcceptPathSuffix / IgnorePathSuffix
  • AcceptPathMatch / IgnorePathMatch
  • AcceptHost / IgnoreHost
  • AcceptHostContains / IgnoreHostContains
  • AcceptHostPrefix / IgnoreHostPrefix
  • AcceptHostSuffix / IgnoreHostSuffix
  • AcceptHostMatch / IgnoreHostMatch

Using custom time formatters

// Create a slog logger, which:
//   - Logs to stdout.
//   - RFC3339 with UTC time format.
logger := slog.New(
	slogformatter.NewFormatterHandler(
		slogformatter.TimezoneConverter(time.UTC),
		slogformatter.TimeFormatter(time.RFC3339, nil),
	)(
		slog.NewTextHandler(os.Stdout, nil),
	),
)

app := fiber.New()

app.Use(slogfiber.New(logger))
app.Use(recover.New())

app.Get("/", func(c *fiber.Ctx) error {
	return c.SendString("Hello, World ๐Ÿ‘‹!")
})

app.Listen(":4242")

// output:
// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production request.time=2023-10-15T20:32:58Z request.method=GET request.path=/ request.route="" request.ip=127.0.0.1:63932 request.length=0 response.time=2023-10-15T20:32:58Z response.latency=100ms response.status=200 response.length=7 id=229c7fc8-64f5-4467-bc4a-940700503b0d

Using custom logger sub-group

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

app := fiber.New()

app.Use(slogfiber.New(logger.WithGroup("http")))
app.Use(recover.New())

app.Get("/", func(c *fiber.Ctx) error {
	return c.SendString("Hello, World ๐Ÿ‘‹!")
})

app.Listen(":4242")

// output:
// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production http.request.time=2023-10-15T20:32:58.626+02:00 http.request.method=GET http.request.path=/ http.request.route="" http.request.ip=127.0.0.1:63932 http.request.length=0 http.response.time=2023-10-15T20:32:58.926+02:00 http.response.latency=100ms http.response.status=200 http.response.length=7 http.id=229c7fc8-64f5-4467-bc4a-940700503b0d

Add logger to a single route

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

app := fiber.New()

app.Use(recover.New())

app.Get("/", slogfiber.New(logger), func(c *fiber.Ctx) error {
	return c.SendString("Hello, World ๐Ÿ‘‹!")
})

app.Listen(":4242")

Adding custom attributes

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

// Add an attribute to all log entries made through this logger.
logger = logger.With("env", "production")

app := fiber.New()

app.Use(slogfiber.New(logger))
app.Use(recover.New())

app.Get("/", func(c *fiber.Ctx) error {
	// Add an attribute to a single log entry.
	slogfiber.AddCustomAttributes(c, slog.String("foo", "bar"))
	return c.SendString("Hello, World ๐Ÿ‘‹!")
})

app.Listen(":4242")

// output:
// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production request.time=2023-10-15T20:32:58.626+02:00 request.method=GET request.path=/ request.route="" request.ip=127.0.0.1:63932 request.length=0 response.time=2023-10-15T20:32:58.926+02:00 response.latency=100ms response.status=200 response.length=7 id=229c7fc8-64f5-4467-bc4a-940700503b0d foo=bar

JSON output

logger := slog.New(slog.NewJSONHandler(os.Stdout, nil)),

app := fiber.New()

app.Use(slogfiber.New(logger))
app.Use(recover.New())

app.Get("/", func(c *fiber.Ctx) error {
	return c.SendString("Hello, World ๐Ÿ‘‹!")
})

app.Listen(":4242")

// output:
// {"time":"2023-10-15T20:32:58.926+02:00","level":"INFO","msg":"Incoming request","env":"production","http":{"request":{"time":"2023-10-15T20:32:58.626+02:00","method":"GET","path":"/","route":"","ip":"127.0.0.1:55296","length":0},"response":{"time":"2023-10-15T20:32:58.926+02:00","latency":100000,"status":200,"length":7},"id":"04201917-d7ba-4b20-a3bb-2fffba5f2bd9"}}

๐Ÿค Contributing

Don't hesitate ;)

# Install some dev dependencies
make tools

# Run tests
make test
# or
make watch-test

๐Ÿ‘ค Contributors

Contributors

๐Ÿ’ซ Show your support

Give a โญ๏ธ if this project helped you!

GitHub Sponsors

๐Ÿ“ License

Copyright ยฉ 2023 Samuel Berthe.

This project is MIT licensed.

slog-fiber's People

Contributors

dassump avatar dependabot[bot] avatar griggsca91 avatar jippi avatar samber avatar sandrolain avatar usysrc avatar

Stargazers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

Watchers

 avatar  avatar

slog-fiber's Issues

Response body discarded with middleware

Using the below configuration

func StartAndServe() {

	logger := slog.Default()
	port := os.Getenv("PORT")

	slog.Info("Starting server on port", "port", port)
	app := fiber.New()

	group := app.Group("/api")
	group.Use(slogfiber.New(logger))

	group.Get("/lookup/:ipaddress", getGeoInfo)

	err := app.Listen(":" + port)
	if err != nil {
		slog.Error("Error starting server", "error", err)
	}
}

The call to getGeoInfo mapped above returns a simple 3 value JSON object

{
	"city": "Johannesburg",
	"region": "Gauteng",
	"country": "South Africa"
}

from the return call below.

	return c.Status(fiber.StatusOK).JSON(lresp)

With group.Use(slogfiber.New(logger)) included the JSON is truncated from the response and nothing but OK is returned.

Below is the information logged by slogfiber.

2023-09-14T20:13:00.410576+02:00 INF Incoming request time="2023-09-14 20:13:00.410563 +0200 SAST" latency=94.375ยตs method=GET host=localhost:3000 path=/api/lookup/105.30.58.8 route=/api/lookup/:ipaddress status=200 ip=127.0.0.1 user-agent=insomnia/2023.5.8 referer="" request-id=717e4157-3f6e-4d86-a51c-92e1c7015786

Panic when using the 404 middleware

slog-fiber seems to panic when using 404 middleware and sending requests to non existent routes.

func SetupFiber(client *client.Client, logger *slog.Logger) *fiber.App {
	app := fiber.New()

	app.Use(requestid.New())

	app.Use(slogfiber.New(logger))

	app.Use(func(c *fiber.Ctx) error {
		c.Locals("client", client)
		return c.Next()
	})

	http.SetupRoutes(app)

	app.Use(func(c *fiber.Ctx) error {
		return c.Status(fiber.StatusNotFound).SendString("Not Found")
	})

	return app
}

Steps to reproduce:

  • Setup slog-fiber using the above code
  • Send a request to non existent route

Output:

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x2 addr=0x18 pc=0x102d8ae48]

goroutine 12 [running]:
github.com/nt/e/cmd/ed/app.SetupFiber.New.NewWithConfig.func4(0x251f779d11e70701?)
        /Users/varunshoor/go/pkg/mod/github.com/samber/[email protected]/middleware.go:79 +0x778
github.com/gofiber/fiber/v2.(*Ctx).Next(0x1400002b380?)
        /Users/varunshoor/go/pkg/mod/github.com/gofiber/fiber/[email protected]/ctx.go:967 +0x48
github.com/nt/e/cmd/ed/app.SetupFiber.New.func3(0x102ecdd20?)
        /Users/varunshoor/go/pkg/mod/github.com/gofiber/fiber/[email protected]/middleware/requestid/requestid.go:31 +0xdc
github.com/gofiber/fiber/v2.(*App).next(0x1400015c500, 0x14000146300)
        /Users/varunshoor/go/pkg/mod/github.com/gofiber/fiber/[email protected]/router.go:145 +0x188
github.com/gofiber/fiber/v2.(*App).handler(0x1400015c500, 0x102c4c248?)
        /Users/varunshoor/go/pkg/mod/github.com/gofiber/fiber/[email protected]/router.go:172 +0x74
github.com/valyala/fasthttp.(*Server).serveConn(0x14000172000, {0x102f54f20?, 0x1400006e250})
        /Users/varunshoor/go/pkg/mod/github.com/valyala/[email protected]/server.go:2357 +0xdd0
github.com/valyala/fasthttp.(*workerPool).workerFunc(0x14000116640, 0x1400007b6a0)
        /Users/varunshoor/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:224 +0x70
github.com/valyala/fasthttp.(*workerPool).getCh.func1()
        /Users/varunshoor/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:196 +0x38
created by github.com/valyala/fasthttp.(*workerPool).getCh in goroutine 1
        /Users/varunshoor/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:195 +0x208
exit status 2

I am still learning Go so not sure how to fix this

fiber use rate limiter panic

app := fiber.New(fiber.Config{
  Concurrency:  512 * 1024,
  ErrorHandler: errorx.Handler,
})

app.Use(slogfiber.New(slog.Default().WithGroup("http")))

app.Use(limiter.New(limiter.Config{
  Max:               1,
  Expiration:        2 * time.Second,
  LimiterMiddleware: limiter.SlidingWindow{},
}))

when rate limit occur panic

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x8cd848]

goroutine 59 [running]:
skeleton/cmd/server.NewHttpServer.New.NewWithConfig.func2(0xab6b40?)
        /home/user/go/pkg/mod/github.com/samber/[email protected]/middleware.go:79 +0xa68
github.com/gofiber/fiber/v2.(*App).next(0xc0000ba000, 0xc000004300)
        /home/user/go/pkg/mod/github.com/gofiber/fiber/[email protected]/router.go:145 +0x1b2
github.com/gofiber/fiber/v2.(*App).handler(0xc0000ba000, 0x48f80f?)
        /home/user/go/pkg/mod/github.com/gofiber/fiber/[email protected]/router.go:172 +0x78
github.com/valyala/fasthttp.(*Server).serveConn(0xc0000be000, {0xc6b9b8?, 0xc00012a670})
        /home/user/go/pkg/mod/github.com/valyala/[email protected]/server.go:2357 +0x11d4
github.com/valyala/fasthttp.(*workerPool).workerFunc(0xc0000360a0, 0xc000154a20)
        /home/user/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:224 +0xa4
github.com/valyala/fasthttp.(*workerPool).getCh.func1()
        /home/user/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:196 +0x32
created by github.com/valyala/fasthttp.(*workerPool).getCh in goroutine 15
        /home/user/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:195 +0x1ab

Panic when an 4xx-5xx status is returned without an error

I encountered a panic when a route returns a status of 4xx or 5xx but not an error.

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x2 addr=0x18 pc=0x104989910]

goroutine 7 [running]:
main.main.New.NewWithConfig.func10(0x14000014600?)
	/Users/chris/Documents/slog-fiber/middleware.go:194 +0x1490
github.com/gofiber/fiber/v2.(*App).next(0x14000140a00, 0x14000014600)
	/Users/chris/go/pkg/mod/github.com/gofiber/fiber/[email protected]/router.go:145 +0x188
github.com/gofiber/fiber/v2.(*App).handler(0x14000140a00, 0x104950358?)
	/Users/chris/go/pkg/mod/github.com/gofiber/fiber/[email protected]/router.go:172 +0x74
github.com/valyala/fasthttp.(*Server).serveConn(0x14000174000, {0x104aa0cc8?, 0x1400004c228})
	/Users/chris/go/pkg/mod/github.com/valyala/[email protected]/server.go:2359 +0xdd0
github.com/valyala/fasthttp.(*workerPool).workerFunc(0x1400010e960, 0x14000070540)
	/Users/chris/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:224 +0x70
github.com/valyala/fasthttp.(*workerPool).getCh.func1()
	/Users/chris/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:196 +0x38
created by github.com/valyala/fasthttp.(*workerPool).getCh in goroutine 1
	/Users/chris/go/pkg/mod/github.com/valyala/[email protected]/workerpool.go:195 +0x208

I have an example in this draft pr of how to replicate it, just call localhost:4242/crashme and you should get a panic that points to https://github.com/griggsca91/slog-fiber/blob/main/middleware.go#L194.

I did test a small fix that would be to just replace the err with the logErr above, so if that's an appropriate solution, I can go ahead and make the PR for it.

Is it possible to add custom attrs from fiber context?

For example request/response body or request ID.

Currently there is request id being added (that can be disabled).
What if I want to use the request ID middleware, in order to use a custom header / generator.
How I could log that?

Thanks!

AddCustomAttributes doesn't work in the app.ErrorHandler

I have a custom error handler. In it I do a simple slogfiber.AddCustomAttributes() so I can hopefully add the error itself to the log message. However, none of the attributes added in the error handler ever make it into the output.

func apiErrorHandler(ctx *fiber.Ctx, err error) error {
	slogfiber.AddCustomAttributes(ctx, slog.String("hi", "there"))

	var e *fiber.Error
	code := fiber.StatusInternalServerError
	if errors.As(err, &e) {
		code = e.Code
	}

	return ctx.Status(code).JSON(...)
}

The hi key with value there is always missing, and so is any other attribute added in the error handler.

Default log level for 4XX ERROR status is WARN.

The default level for error status 400,404,422 is WARN. How can i dynamically set the level of other status a part from 200 to be ERROR?
Here's my log configuration

l := slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{AddSource: true, Level: &slog.LevelVar{}}))

s.app.Use(
	slogfiber.New(l)
)

kong logs

Do you have an example of logging a Kong proxy log?

If I run the fiber web service with slog-fiver (default param) + kong proxy, it will work ok.
If I run the fiber web service with slog-fiver (following param) + kong proxy, it will not work ok.

cfg := slogfiber.Config{
	WithUserAgent:      true,
	WithRequestID:      true,
	WithRequestBody:    true,
	WithRequestHeader:  true,
	WithResponseBody:   true,
	WithResponseHeader: true,
	WithSpanID:         true,
	WithTraceID:        true,
	DefaultLevel:     slog.LevelInfo,
	ClientErrorLevel: slog.LevelWarn,
	ServerErrorLevel: slog.LevelError,
}

Incorrect response.status code

In many cases the registered status code is 200, but this should not be.

I'm using this code to test

package main

import (
	"log/slog"
	"os"

	"github.com/gofiber/fiber/v2"
	"github.com/gofiber/fiber/v2/middleware/recover"
	slogfiber "github.com/samber/slog-fiber"
)

func main() {
	app := fiber.New()
	app.Use(slogfiber.New(slog.New(slog.NewTextHandler(os.Stdout, nil))), recover.New())
	app.Get("/", func(c *fiber.Ctx) error { return c.SendStatus(fiber.StatusOK) })
	app.Post("/bad", func(c *fiber.Ctx) error { return c.SendStatus(fiber.StatusBadRequest) })
	app.Get("/die", func(c *fiber.Ctx) error { panic("OK") })
	app.Post("/force", func(c *fiber.Ctx) error { return fiber.NewError(fiber.StatusUnauthorized) })
	app.Listen(":8080")
}

Test 1: Get / (Expected: 200 | Received: 200)

$ curl -X GET localhost:8080/

time=2024-03-07T23:28:05.091-03:00 level=INFO msg="Incoming request" request.time=2024-03-07T23:28:05.091-03:00 request.method=GET request.host=localhost:8080 request.path=/ request.query="" request.params=map[] request.route=/ request.ip=127.0.0.1 request.x-forwarded-for=[] request.referer="" request.length=0 response.time=2024-03-07T23:28:05.091-03:00 response.latency=47.75ยตs response.status=200 response.length=2 id=4be25d05-8447-499e-b2fb-53464e3f7952

Test 2: Post / (Expected: 405 | Received: 200)

$ curl -X POST localhost:8080/

time=2024-03-07T23:28:22.615-03:00 level=INFO msg="Incoming request" request.time=2024-03-07T23:28:22.615-03:00 request.method=POST request.host=localhost:8080 request.path=/ request.query="" request.params=map[] request.route=/ request.ip=127.0.0.1 request.x-forwarded-for=[] request.referer="" request.length=0 response.time=2024-03-07T23:28:22.615-03:00 response.latency=41.125ยตs response.status=200 response.length=0 id=d92de5c2-06d6-45f1-882f-381765884d8a

Test 3: Post /bad (Expected: 400 | Received: 400)

$ curl -X POST localhost:8080/bad

time=2024-03-07T23:28:39.510-03:00 level=WARN msg="Bad Request" request.time=2024-03-07T23:28:39.510-03:00 request.method=POST request.host=localhost:8080 request.path=/bad request.query="" request.params=map[] request.route=/bad request.ip=127.0.0.1 request.x-forwarded-for=[] request.referer="" request.length=0 response.time=2024-03-07T23:28:39.510-03:00 response.latency=21.375ยตs response.status=400 response.length=11 id=4fe8f6d7-c20d-4140-998b-9e361e2c8b0a

Test 4: Get /die (Expected: 500 | Received: 200)

$ curl -X GET localhost:8080/die

time=2024-03-07T23:28:52.796-03:00 level=INFO msg="Incoming request" request.time=2024-03-07T23:28:52.796-03:00 request.method=GET request.host=localhost:8080 request.path=/die request.query="" request.params=map[] request.route=/die request.ip=127.0.0.1 request.x-forwarded-for=[] request.referer="" request.length=0 response.time=2024-03-07T23:28:52.796-03:00 response.latency=45.959ยตs response.status=200 response.length=0 id=23796a85-ec18-4279-98fb-f5708ac9482b

Test 5: Post /force (Expected: 401 | Received: 200)

$ curl -X POST localhost:8080/force

time=2024-03-07T23:40:35.343-03:00 level=INFO msg="Incoming request" request.time=2024-03-07T23:40:35.343-03:00 request.method=POST request.host=localhost:8080 request.path=/force request.query="" request.params=map[] request.route=/force request.ip=127.0.0.1 request.x-forwarded-for=[] request.referer="" request.length=0 response.time=2024-03-07T23:40:35.343-03:00 response.latency=18.667ยตs response.status=200 response.length=0 id=d88d82b1-9087-42a0-a75b-960ff50d63ac

Test 6: Get /notfound (Expected: 404 | Received: 200)

curl -X GET localhost:8080/notfound

time=2024-03-07T23:29:26.894-03:00 level=INFO msg="Incoming request" request.time=2024-03-07T23:29:26.894-03:00 request.method=GET request.host=localhost:8080 request.path=/notfound request.query="" request.params=map[] request.route=/ request.ip=127.0.0.1 request.x-forwarded-for=[] request.referer="" request.length=0 response.time=2024-03-07T23:29:26.894-03:00 response.latency=20.042ยตs response.status=200 response.length=0 id=595de28b-ab0b-442b-ae0b-688d665b59d0

With these tests I believe that when the request reaches the ErrorHandler due to an error handled or not, the problem occurs.

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    ๐Ÿ–– Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. ๐Ÿ“Š๐Ÿ“ˆ๐ŸŽ‰

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google โค๏ธ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.