Logging Middleware

The logging middleware records every KV operation with structured fields using Go's standard log/slog package. Each log entry includes the operation type, key, and latency, making it straightforward to trace performance and debug issues.

Installation

import "github.com/xraph/grove/kv/middleware"

Usage

import (
    "log/slog"

    "github.com/xraph/grove/kv"
    "github.com/xraph/grove/kv/middleware"
)

store, err := kv.Open(drv,
    kv.WithHook(middleware.NewLogging(slog.Default())),
)

Constructor

func NewLogging(logger *slog.Logger) *LoggingHook

Parameter	Description
`logger`	An `*slog.Logger` instance for structured log output

How It Works

The logging hook implements both PreQueryHook and PostQueryHook:

BeforeQuery records the start time in qc.Values under the key _log_start.
AfterQuery calculates the elapsed time and emits a structured log entry.

Log Fields

Each log entry includes:

Field	Type	Description
`op`	`string`	Operation name (e.g., `"GET"`, `"SET"`, `"DEL"`)
`key`	`string`	The key being operated on
`latency`	`duration`	Time elapsed between BeforeQuery and AfterQuery

Example Output

With the default text handler:

level=INFO msg="kv command" op=GET key=user:123 latency=1.234ms
level=INFO msg="kv command" op=SET key=user:123 latency=2.567ms
level=INFO msg="kv command" op=DEL key=user:123 latency=0.891ms

With a JSON handler:

{"level":"INFO","msg":"kv command","op":"GET","key":"user:123","latency":"1.234ms"}

Integration with Structured Logging

The middleware accepts any *slog.Logger, so you can configure it with custom handlers, levels, and attributes:

Custom Logger with Attributes

logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
    Level: slog.LevelDebug,
})).With(
    slog.String("service", "user-api"),
    slog.String("component", "kv"),
)

store, err := kv.Open(drv,
    kv.WithHook(middleware.NewLogging(logger)),
)

This produces log entries with the additional service and component fields on every KV operation.

Using with Third-Party Loggers

Any logger that provides an *slog.Logger interface works. For example, with a Zap-backed slog handler:

import "go.uber.org/zap/exp/zapslog"

zapLogger, _ := zap.NewProduction()
slogLogger := slog.New(zapslog.NewHandler(zapLogger.Core()))

store, err := kv.Open(drv,
    kv.WithHook(middleware.NewLogging(slogLogger)),
)

Middleware Ordering

Place the logging hook early in the middleware chain if you want to capture the total latency including all other middleware. Place it later if you want to measure only the time spent in the driver:

// Logs total latency (including namespace prefixing, cache check, etc.)
store, err := kv.Open(drv,
    kv.WithHook(middleware.NewLogging(logger)),
    kv.WithHook(middleware.NewNamespace("tenant:acme")),
    kv.WithHook(middleware.NewCache(1000, 5*time.Minute)),
)

// Logs only driver latency (excludes middleware overhead)
store, err := kv.Open(drv,
    kv.WithHook(middleware.NewNamespace("tenant:acme")),
    kv.WithHook(middleware.NewCache(1000, 5*time.Minute)),
    kv.WithHook(middleware.NewLogging(logger)),
)

API Reference

Method	Description
`NewLogging(logger)`	Create a new logging hook with the given `*slog.Logger`

Logging Middleware

On this page