Structured Logging, Metrics, and Graceful Shutdown in Go on Ubuntu

Series Production Go Web Service with Fiber Part 4/6 All parts

The bookmarkd API works and now has real accounts behind it, but if it started misbehaving in production right now, you would have almost no way to find out why. There are no logs beyond whatever Fiber prints to stdout by default, nothing exporting request latency or error rates, and a sudo systemctl stop currently kills in-flight requests instead of letting them finish. This part fixes all three.

This continues from JWT Authentication and Middleware in a Go API on Ubuntu, where registration, login, and per-user bookmarks landed. Nothing here changes the routes or the store; this part is purely about making the running service observable and safe to restart.

This tutorial is for developers who have bookmarkd running with authentication from Part 3 and want it to behave like a service you can actually operate: structured logs a log pipeline can parse, metrics Prometheus can scrape, health endpoints a load balancer can poll, and a shutdown sequence that does not drop requests mid-flight.

Conceptual Overview

Structured logging means every log line is a machine-parseable record, typically JSON, with consistent fields, instead of a free-form sentence. method=GET path=/v1/bookmarks status=200 duration_ms=4 is something a log aggregator can filter and graph; “handled a request in 4ms” is not. Go’s standard library has shipped log/slog since Go 1.21 specifically for this, and it needs no third-party dependency to emit JSON.

Prometheus metrics are numeric measurements exposed on an HTTP endpoint (conventionally /metrics) in a plain-text format that a Prometheus server scrapes on an interval. The three metric types this tutorial adds are a counter (http_requests_total, which only goes up), a histogram (http_request_duration_seconds, which buckets how long requests take so you can compute percentiles later), and a gauge (http_requests_in_flight, which goes up and down as requests start and finish).

Liveness and readiness are two different questions a health check answers. Liveness asks “is this process still running and not deadlocked,” and a failing liveness check tells an orchestrator to restart the process. Readiness asks “is this instance currently able to serve traffic,” and a failing readiness check tells a load balancer to stop sending requests here without necessarily restarting anything, which matters during startup (the database pool is not ready yet) or a temporary downstream outage.

Graceful shutdown means that when the process receives a termination signal, it stops accepting new connections but gives existing requests a bounded amount of time to finish before the process actually exits, rather than cutting them off instantly.

Prerequisites

Before starting, make sure you have:

  • The bookmarkd project from Part 3, with authentication working, on api-01 at 10.20.0.51.
  • Go 1.25 installed.
  • Optionally, a Prometheus server to scrape the new /metrics endpoint; see How to Set Up Prometheus and Grafana Monitoring on Ubuntu if you do not have one yet. This tutorial’s steps work without one, since you can query /metrics directly with curl.

Step 1: Replace the Default Logger with slog

Fiber’s own middleware/logger prints readable text by default, but it does not use log/slog, so it will not merge cleanly with the rest of your application’s logs. Instead, build a small slog-based request logging middleware that runs on every request.

Create internal/handler/logging.go:

package handler

import (
	"log/slog"
	"time"

	"github.com/gofiber/fiber/v3"
)

func RequestLogger(logger *slog.Logger) fiber.Handler {
	return func(c fiber.Ctx) error {
		start := time.Now()

		err := c.Next()

		status := c.Response().StatusCode()
		duration := time.Since(start)

		attrs := []slog.Attr{
			slog.String("method", c.Method()),
			slog.String("path", c.Path()),
			slog.Int("status", status),
			slog.Duration("duration", duration),
			slog.String("request_id", c.GetRespHeader("X-Request-Id")),
		}

		switch {
		case status >= 500:
			logger.LogAttrs(c.Context(), slog.LevelError, "request failed", attrs...)
		case status >= 400:
			logger.LogAttrs(c.Context(), slog.LevelWarn, "request completed", attrs...)
		default:
			logger.LogAttrs(c.Context(), slog.LevelInfo, "request completed", attrs...)
		}

		return err
	}
}

Add the request ID and panic recovery middleware, both shipped with Fiber:

go get github.com/gofiber/fiber/v3
import (
	"github.com/gofiber/fiber/v3/middleware/recover"
	"github.com/gofiber/fiber/v3/middleware/requestid"
)

In cmd/api/main.go, build the JSON logger and register the middleware in order: request ID first (so the logger can read it), then recovery, then the request logger, then everything else.

logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
	Level: slog.LevelInfo,
}))
slog.SetDefault(logger)

app.Use(requestid.New())
app.Use(recover.New())
app.Use(handler.RequestLogger(logger))

Restart the service and make a request:

curl -s http://localhost:8080/v1/bookmarks -H "Authorization: Bearer $ACCESS_TOKEN"

The server’s stdout now shows a single JSON line per request:

{"time":"2026-08-13T10:04:12Z","level":"INFO","msg":"request completed","method":"GET","path":"/v1/bookmarks","status":200,"duration":"3.1ms","request_id":"c1a9..."}

This is exactly the shape a log shipper like Promtail or Vector can parse without regular expressions, unlike a free-text log line. If you have already worked through Structured Logging in Node.js with Winston on Ubuntu, the goal here is the same, just achieved with the standard library instead of a third-party package.

Step 2: Expose Prometheus Metrics

Add the Prometheus client and Fiber’s adaptor package, which converts a standard net/http.Handler into a Fiber handler:

go get github.com/prometheus/client_golang/prometheus
go get github.com/prometheus/client_golang/prometheus/promhttp
go get github.com/prometheus/client_golang/prometheus/promauto

Create internal/handler/metrics.go:

package handler

import (
	"strconv"
	"time"

	"github.com/gofiber/fiber/v3"
	"github.com/prometheus/client_golang/prometheus"
	"github.com/prometheus/client_golang/prometheus/promauto"
)

var (
	requestsTotal = promauto.NewCounterVec(prometheus.CounterOpts{
		Name: "http_requests_total",
		Help: "Total number of HTTP requests processed.",
	}, []string{"method", "path", "status"})

	requestDuration = promauto.NewHistogramVec(prometheus.HistogramOpts{
		Name:    "http_request_duration_seconds",
		Help:    "HTTP request duration in seconds.",
		Buckets: prometheus.DefBuckets,
	}, []string{"method", "path"})

	requestsInFlight = promauto.NewGauge(prometheus.GaugeOpts{
		Name: "http_requests_in_flight",
		Help: "Number of HTTP requests currently being served.",
	})
)

func Metrics() fiber.Handler {
	return func(c fiber.Ctx) error {
		requestsInFlight.Inc()
		defer requestsInFlight.Dec()

		start := time.Now()
		err := c.Next()

		status := strconv.Itoa(c.Response().StatusCode())
		requestsTotal.WithLabelValues(c.Method(), c.Route().Path, status).Inc()
		requestDuration.WithLabelValues(c.Method(), c.Route().Path).Observe(time.Since(start).Seconds())

		return err
	}
}

Using c.Route().Path rather than c.Path() for the label matters: c.Path() returns the literal request path, so /v1/bookmarks/1234 and /v1/bookmarks/5678 would each create a new label value, and Prometheus metrics with unbounded label cardinality eventually cause real memory problems on the Prometheus server. c.Route().Path returns the matched route pattern, /v1/bookmarks/:id, which stays constant no matter how many different IDs are requested.

Register the middleware and the /metrics endpoint itself in main.go:

import (
	"github.com/gofiber/fiber/v3/middleware/adaptor"
	"github.com/prometheus/client_golang/prometheus/promhttp"
)

app.Use(handler.Metrics())
app.Get("/metrics", adaptor.HTTPHandler(promhttp.Handler()))

Check it:

curl -s http://localhost:8080/metrics | grep http_requests_total
# HELP http_requests_total Total number of HTTP requests processed.
# TYPE http_requests_total counter
http_requests_total{method="GET",path="/v1/bookmarks",status="200"} 3

Step 3: Add Liveness and Readiness Endpoints

Fiber ships a ready-made middleware/healthcheck package for exactly this. Register it before the authenticated routes so it is reachable without a token:

import "github.com/gofiber/fiber/v3/middleware/healthcheck"

app.Use(healthcheck.New(healthcheck.Config{
	LivenessProbe: func(c fiber.Ctx) bool {
		return true
	},
	LivenessEndpoint: "/livez",
	ReadinessProbe: func(c fiber.Ctx) bool {
		ctx, cancel := context.WithTimeout(c.Context(), 2*time.Second)
		defer cancel()
		return pool.Ping(ctx) == nil
	},
	ReadinessEndpoint: "/readyz",
}))

The liveness probe here is intentionally trivial: as long as the process can respond at all, it is alive. The readiness probe is not, since it pings the actual PostgreSQL pool with a short timeout, so /readyz correctly reports failure if the database becomes unreachable, even though the process itself is still very much running.

curl -s -i http://localhost:8080/livez
curl -s -i http://localhost:8080/readyz

Both should return HTTP/1.1 200 OK with the database reachable. Stop PostgreSQL temporarily on db-01 and query /readyz again to confirm it now returns a failing status while /livez still returns 200.

Step 4: Graceful Shutdown

Update cmd/api/main.go to listen for SIGTERM and SIGINT, and give in-flight requests time to finish before exiting:

func main() {
	// ... pool setup, app setup, and route registration from earlier parts ...

	go func() {
		if err := app.Listen(":8080", fiber.ListenConfig{
			DisableStartupMessage: false,
		}); err != nil {
			logger.Error("server stopped", slog.Any("error", err))
		}
	}()

	quit := make(chan os.Signal, 1)
	signal.Notify(quit, syscall.SIGINT, syscall.SIGTERM)
	<-quit

	logger.Info("shutdown signal received, draining connections")

	shutdownCtx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
	defer cancel()

	if err := app.ShutdownWithContext(shutdownCtx); err != nil {
		logger.Error("forced shutdown after timeout", slog.Any("error", err))
	}

	pool.Close()
	logger.Info("shutdown complete")
}

app.Listen now runs in its own goroutine so the main goroutine is free to block on signal.Notify instead. Once SIGTERM arrives (this is the signal systemd sends by default on systemctl stop), app.ShutdownWithContext stops accepting new connections immediately but lets requests already in progress finish, up to the 15-second timeout. Only after that returns does the code close the database pool, which matters because a request finishing its last database query during shutdown still needs that pool open.

Restart the service and confirm the sequence works:

sudo systemctl restart bookmarkd
sudo systemctl stop bookmarkd
sudo journalctl -u bookmarkd -n 10 --no-pager

You should see the shutdown signal received and shutdown complete log lines in order, rather than the process disappearing mid-log-line.

Common Mistakes and Troubleshooting

/metrics grows unbounded label values over time. This almost always means a handler is using the raw request path instead of the matched route pattern as a label, exactly the mistake avoided above with c.Route().Path. Check every prometheus.Labels call for anything derived directly from user input, like an ID or a query string.

Logs print as plain text instead of JSON. Confirm slog.SetDefault(logger) runs before any other package logs anything, and that nothing else in the codebase still calls log.Println or Fiber’s own default logger, which bypasses slog entirely.

systemctl stop still kills requests instantly. Check the systemd unit’s TimeoutStopSec is not set lower than the shutdown context’s timeout (15 seconds in this tutorial); if systemd sends SIGKILL before the graceful shutdown finishes, none of this code gets a chance to run.

/readyz returns 200 even when the database is down. Confirm the readiness probe function actually calls pool.Ping with a real context and returns its error, rather than always returning true. It is easy to leave a placeholder return true in place after copying the liveness probe.

Best Practices

  • Log at the edge, not everywhere. One request-level log line per request, as built here, is usually more useful than scattering logger.Info calls throughout business logic; add more only where a specific decision needs explaining.
  • Give every metric a bounded label set. HTTP method, matched route, and status code are safe; user IDs, raw paths, and free-text values are not.
  • Keep readiness checks cheap and fast. A 2-second timeout on the database ping, as used here, prevents a slow database from making the readiness check itself the bottleneck.
  • Set a shutdown timeout shorter than your orchestrator’s kill timeout. If systemd or Kubernetes will force-kill the process after 30 seconds, give your own graceful shutdown a smaller budget, so it always has a chance to log and exit cleanly instead of racing a SIGKILL.
  • Never expose /metrics to the public internet. It reveals internal route structure and request volume; keep it reachable only from your monitoring network, either with a firewall rule or by putting it behind Nginx with an IP allowlist.

Conclusion

bookmarkd now logs every request as structured JSON, exposes request count, latency, and in-flight metrics on /metrics, answers liveness and readiness checks honestly, and shuts down without dropping in-flight requests. None of this changed a single route or database query from the previous parts; it wraps the existing application in the operational behavior a real deployment needs.

The service still has no automated tests, which means every change so far has been verified by hand with curl. Part 5 fixes that with table-driven unit tests, route-level tests using Fiber’s built-in test client, and integration tests that run against a real, disposable PostgreSQL instance with testcontainers.

All tutorials →

Latest Tutorials

Support this site