Confusing to use in an application already using `log/slog`

[stephenafamo]

It is likely that an application using slog will want to use its own pre-configured *slog.Logger or provide a slog.Handler that a logger should be created from.

The design of the package makes it confusing to do this.

Sure, I can manually create a httplog.Logger, but the options mix what is required for "configuring the logger" and what is used in logging.

l := &httplog.Logger{
  Logger: myExistingSlogLogger,
  Options: httplog.Options{
    JSON: true, // I'm guessing this does nothing
  },
}

I would suggest that the package asks only for a slog.Handler and only uses options to configure what to log:

func Handler(h slog.Handler, opts Options) func(next http.Handler) http.Handler {
    if h == nil {
        h = slog.Default().Handler()
    }
    // implementation
}

type Options struct {
    // Level determines what level to log request details at
    Level slog.Level 

    // Concise mode includes fewer log details during the request flow. For example
    // excluding details like request content length, user-agent and other details.
    // This is useful if during development your console is too noisy.
    Concise bool

    // RequestHeaders enables logging of all request headers, however sensitive
    // headers like authorization, cookie and set-cookie are hidden.
    RequestHeaders bool

    // SkipRequestHeaders are additional requests headers which are redacted from the logs
    SkipRequestHeaders []string

    // QuietDownRoutes are routes which are temporarily excluded from logging for a QuietDownPeriod after it occurs
    // for the first time
    // to cancel noise from logging for routes that are known to be noisy.
    QuietDownRoutes []string

    // QuietDownPeriod is the duration for which a route is excluded from logging after it occurs for the first time
    // if the route is in QuietDownRoutes
    QuietDownPeriod time.Duration
}

I understand that my changes would be breaking (so that means a v3 so soon after a v2), but I think it becomes easier to use with other slog compatible packages.

[diamondburned]

Aside from manually creating the httplog.Logger, the README suggests to use httplog.NewLogger which not only has this issue but also somehow messes up the global slog (how does it even do this?).

It also seems to use os.Stdout as the default, which is very strange. There is also currently no way to change the level that the logger logs at. The LogLevel in Options is confusingly designed to override the global one, not to determine what level to log at.

[pkieltyka]

It shouldn’t touch global slog, and you can pass options.Writer.

it certainly could be better and more carefully designed, but I actually don’t have time and it works for my purposes. My suggestion is to submit a PR, or write your own package @diamondburned

[diamondburned]

submit a PR

Should a PR make the v3 breaking changes described in this issue, or should it make the changes without being breaking? Part of the current issue is the fact that the README documents httplog.NewLogger already, so I'm not sure what the preferable approach is here.

[bronger]

It shouldn’t touch global slog, and you can pass options.Writer.

FWIW, I had configured log level to DEBUG in my program, then switched to the new httplog, and all DEBUG messages were gone until I explicitly re-defined the log level to DEBUG in the call of NewLogger.

[judofyr]

An additional feature request here: I'd like to get the slog.Handler from the ctx dynamically. This is already being configured with different attributes in earlier middlewares.

[aep]

submit a PR

Should a PR make the v3 breaking changes described in this issue, or should it make the changes without being breaking? Part of the current issue is the fact that the README documents httplog.NewLogger already, so I'm not sure what the preferable approach is here.

may i suggest to just leave NewLogger as is but remove it from the docs and create a new function? the current one is clearly wrong, so no point in keeping it except for not breaking existing code, specifically go-chi examples where it doesnt really matter.

[dropwhile]

I ran across this as well, and managed to work around it by using this as my middleware:

var skipPaths = []string{}
var logOptions = httplog.Options{
    Concise:        true,
    RequestHeaders: true,
    HideRequestHeaders: []string{
        "accept",
        "accept-encoding",
        "accept-language",
        "accept-ranges",
        "connection",
        "cookie",
        "user-agent",
    },
    QuietDownRoutes: []string{
        "/",
        "/ping",
    },
    QuietDownPeriod: 10 * time.Second,
}

func RequestLogger() func(next http.Handler) http.Handler {
    httpLogger := &httplog.Logger{
        Logger:  slog.Default(),
        Options: logOptions,
    }
    return httplog.Handler(httpLogger, skipPaths)
}

Definitely a work-around, but it seems to be doing the job for now.

[Shubhaankar-Sharma]

hey guys, @stephenafamo @diamondburned @dropwhile @bronger https://github.com/go-chi/httplog/pull/43/files this fixes the default slogger being modified, the json options etc work... normally you would enable json logging in prod since its structured logging which is ingested by cloud providers...

[Shubhaankar-Sharma]

@diamondburned it logs on os.StdOut by default on the default pretty logger which is meant for dev purposes... and well for prod you should make it os.StdErr imo... which is why the option exists :)

[Shubhaankar-Sharma]

@stephenafamo i agree, ill work on including an optional slogger in the create httplog function, so that you can inject your own slogger, other than that what else do you feel is wrong with the structure?

[stephenafamo]

Thanks for taking a look at this @Shubhaankar-Sharma

I have nothing else to add to what was in my original comment.

1. Ability to use my own Handler
2. Clearer configuration

[VojtechVitek]

Hi everyone,

I've created a prototype for github.com/go-chi/httplog/v3 and I'm seeking feedback.

Here's the repo you can play around with: https://github.com/golang-cz/httplog

It’s a brand new implementation that has log/slog in its core. It provides some new features like request/response body logging, supports error stack traces, per-request overrides (change its behavior based on session type or header) and can be simply used with traceid middleware.

Please take a look at it, run the _example/ and submit any issues with feedback / bugs / ideas.

I'll create a PR against this repo sometime next week. But since it's a complete rewrite, it will likely be difficult to review the changes.

cc @stephenafamo @Shubhaankar-Sharma @diamondburned @dropwhile @aep @judofyr @bronger

Best, Vojtech

[bronger]

I've created a prototype for github.com/go-chi/httplog/v3 and I'm seeking feedback.

Here's the repo you can play around with: https://github.com/golang-cz/httplog

Works fine on my site, thank you!

[judofyr]

@VojtechVitek: Very nice work, but this doesn't quite work for mine use case. In this case I already have an slog.Logger which is part of the Context. I want to be able to somehow retrieve it like this:

func (l *Logger) Handle(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        ctx := r.Context()
+++         logger := l.opts.GetLoggerFromContext(ctx)
        log := &Log{
            Level:           l.opts.Level,
            Req:             r,
            LogRequestBody:  l.opts.LogRequestBody,
            LogResponseBody: l.opts.LogResponseBody,
        }

I'm not quite sure what's the best design for this would be. One potential variant could be to do something like:

func Middleware(getLogger func(ctx context.Context) *slog.Logger) http.Handler {
  return func(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
      ctx := r.Context()
      logger := getLogger(ctx)
      // Same code as before
    }
  }
}

[VojtechVitek]

Hi @judofyr, see this message in the official slog/log blog post:

After two months and about 300 comments, we felt we were ready for an actual proposal and accompanying design doc. The proposal issue garnered over 800 comments and resulted in many improvements to the API and the implementation. Here are two examples of API changes, both concerning context.Context:

Originally the API supported adding loggers to a context. Many felt that this was a convenient way to plumb a logger easily through levels of code that didn’t care about it. But others felt it was smuggling in an implicit dependency, making the code harder to understand. Ultimately, we removed the feature as being too controversial.

We also wrestled with the related question of passing a context to logging methods, trying a number of designs. We initially resisted the standard pattern of passing the context as the first argument because we didn’t want every logging call to require a context, but ultimately created two sets of logging methods, one with a context and one without.

The proposed https://github.com/golang-cz/httplog repo follows the same decision. It doesn't pass logger via context but it provides a custom (extendable) handler instead, where you can print context values as additional log attributes.

In case of HTTP middleware, this is even more complicated, since the top-most middleware (where we print the request log) doesn't have access to the context values created downstream, as the context is unwrapped on the way back up from the final HTTP handler.

That is why we introduced httplog.SetAttrs(ctx, attrs...) helper that stores additional attributes into the context storage created by the top-most middleware, which then makes them available to the backend interface (slog.Handler). Example:

r.Get("/", func(w http.ResponseWriter, r *http.Request) {
    ctx := r.Context()

    // Set additional attribute(s) on the request log:
    httplog.SetAttrs(ctx, slog.String("userId", "id"))

    w.Write([]byte("."))
})

I'm not 100% sure what your use-case is, but I think you might be after this:

r.Get("/do-work", func(w http.ResponseWriter, r *http.Request) {
    ctx := r.Context()

    // Create a custom logger including request attributes from httplog:
    customLogger := httplog.WithAttrs(ctx, slog.String("op", "do-work"))

    // Pass it down to your implementation:
    worker := worker{logger: customLogger}
    worker.DoWork(ctx)

    // Or if you want to continue passing loggers via context yourself:
    ctx = withLogger(ctx, customLogger)
    doWork(ctx)

    // ...
})

Does this help?