slog
The slog library is great and Fiber is also great. Yet somehow, I didn’t find a neat integration guide such that, the request attributes are added by default to all the log statements.
Yes, you can manually add all the attributes each time you write a log statement.
slog.Info("Login request received", "user_id", `user", "method", c.Method(), "path", c.Path())
This is just redundant work. What if there was a way so that all these request attributes gets added for each log statement automatically.
Goal here is to add as much contextual information to a log statement with less to no redundant work. This will be very useful for traceability when we injest these logs to Cloudwatch or Elasticsearch.
Lack of integration between logging middleware in Fiber and slog
Fiber does come with a logging middleware which prints just request details. There’s also a package called slog-fiber which allows
you to use slog in go fiber middleware. These do not solve my requirement of automatically adding request attributes to each log statements.
So, What would an ideal log statement contain?
- Timestamp (Local or UTC)
- Source file
- Message
- Traceable attributes
- request_id: This could be an uuid
- path
- method
- source_ip
- Log attributes
Implementation
Before we get started, I’d like to tell you there are three parts in slog API.
- Frontend: Logger that receives data from the user.
- Record: Data that gets logged.
- Backend: JSONHandler, TextHandler or your own implementation of Handler interface.
Custom handler which wraps slog.Handler interface.
type FiberHandler struct {
slog.Handler
}
Middleware which includes request details to Locals.
app.Use(func(c *fiber.Ctx) error {
requestId := uuid.NewString()
c.Locals(RequestId, requestId)
c.Locals(Method, c.Method())
c.Locals(Path, c.Path())
c.Locals(SourceIP, c.IP())
return c.Next()
})
Write a simple handler which extracts request details from context
type ContextKey string
const (
Request ContextKey = "request"
RequestId ContextKey = "request_id"
Method ContextKey = "method"
Path ContextKey = "path"
SourceIP ContextKey = "source_ip"
)
func (l FiberHandler) Handle(ctx context.Context, r slog.Record) error {
if ctx.Value(RequestId) == nil {
return l.Handler.Handle(ctx, r)
}
requestId := ctx.Value(RequestId).(string)
sourceIp := ctx.Value(SourceIP).(string)
path := ctx.Value(Path).(string)
method := ctx.Value(Method).(string)
requestGroup := slog.Group(
string(Request),
slog.String(string(RequestId), requestId),
slog.String(string(SourceIP), sourceIp),
slog.String(string(Method), method),
slog.String(string(Path), path),
)
r.AddAttrs(requestGroup)
// call the actual slog handler to log this modified record
return l.Handler.Handle(ctx, r)
}
That’s pretty much it
Putting it all together
// main.go
package main
import (
"log/slog"
"os"
"github.com/gofiber/fiber/v2"
"github.com/google/uuid"
)
func main() {
handler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
})
fh := FiberHandler{Handler: handler}
// Create a new logger with the custom handler
logger := slog.New(fh)
// Set it as the default logger
slog.SetDefault(logger)
app := fiber.New()
app.Use(func(c *fiber.Ctx) error {
requestId := uuid.NewString()
c.Locals(RequestId, requestId)
c.Locals(Method, c.Method())
c.Locals(Path, c.Path())
c.Locals(SourceIP, c.IP())
return c.Next()
})
app.Get("/", func(c *fiber.Ctx) error {
// Note that we are not adding any request attributes manually
slog.InfoContext(c.Context(), "Received a request")
return c.SendString("Hello")
})
if err := app.Listen(":3000"); err != nil {
slog.Error("unable to start fiber application", "err", err)
os.Exit(1)
}
}
// logger.go
package main
import (
"context"
"log/slog"
)
type FiberHandler struct {
slog.Handler
}
func (l FiberHandler) Handle(ctx context.Context, r slog.Record) error {
if ctx.Value(RequestId) == nil {
return l.Handler.Handle(ctx, r)
}
requestId := ctx.Value(RequestId).(string)
sourceIp := ctx.Value(SourceIP).(string)
path := ctx.Value(Path).(string)
method := ctx.Value(Method).(string)
requestGroup := slog.Group(
string(Request),
slog.String(string(RequestId), requestId),
slog.String(string(SourceIP), sourceIp),
slog.String(string(Method), method),
slog.String(string(Path), path),
)
r.AddAttrs(requestGroup)
return l.Handler.Handle(ctx, r)
}
type ContextKey string
const (
Request ContextKey = "request"
RequestId ContextKey = "request_id"
Method ContextKey = "method"
Path ContextKey = "path"
SourceIP ContextKey = "source_ip"
)
That’s pretty much it! If anyone tries to access ’/’, you’ll get this log printed with all the above request attributes
// Formatted for readability
{
"time": "2024-09-02T23:01:38.166407279+05:30",
"level": "INFO",
"source": {
"function": "main.main.func2",
"file": "/home/nithin/workspace/go/demo-project/main.go",
"line": 36
},
"msg": "Hello there",
"request": {
"request_id": "386e9b95-df56-4264-820c-0cd20ad33670",
"source_ip": "127.0.0.1",
"method": "GET",
"path": "/"
}
}
Further steps
Furthermore, we can add user related information inside each handler function to improve traceability. But, in this case, we have to use a child logger constructed with attributes.
app.Get("/", func(c *fiber.Ctx) error {
logger := slog.With(slog.Group(
"user",
slog.Int64("user_id", 1),
slog.String("username", "humanbeeng"),
))
logger.InfoContext(c.Context(), "Hello there")
return c.SendString("Hello")
})
{
"time": "2024-09-02T23:13:25.450521132+05:30",
"level": "INFO",
"source": {
"function": "main.main.func2",
"file": "/home/nithin/workspace/go/demo-project/main.go",
"line": 41
},
"msg": "Hello there",
"user": {
"user_id": 1,
"username": "humanbeeng"
}
}
- Nowadays I’ve learned that we should not be logging in the inner layers, ie, service and repository layers since it creates redundancy. Rather, just enrich the errors occurred in these layers with additional context and return the error.
- Any change to logging level configuration should not require any code change. Try achieving this, such that server restart is not required.
Links
Plug
If you are using any webhook testing platform such as requestinspector or webhook.site, consider using my open source platform Checkpost. You get to choose your custom subdomain and use it to monitor http requests/webhooks for absolutely free.