DEV Community 👩‍💻👨‍💻

Discussion on: Contextual Logging In Go

Collapse
 
kunde21 profile image
Chad Kunde

The http Request contains its respective context at r.Context() and can be assigned a new context using r = r.WithContext(ctx).

Go rewards the concept of handling the error as close to the source as possible, so adding contextual data to the logger makes more sense. By logging the error where it's generated, there's no reason to thread that same error value up through the call stack.

This isn't necessarily production-ready (as admitted by the author) because there's no protection on the context. By moving the loading and extracting to a separate package, the type restrictions benefit you:

package myctxlog
type logKey struct{}
func WithLogger(ctx context.Context, logger zerolog.Logger) context.Context {
    return context.WithValue(ctx, logKey{}, logger)
}

func FromContext(ctx context.Context) zerolog.Logger {
    l := ctx.Value(logKey{})
    if l == nil {
        return <default value>
    }
    return l.(zerolog.Logger)
}
Enter fullscreen mode Exit fullscreen mode

By doing so, the type checking will ensure that only a zerolog.Logger is allowed to be loaded into the context. Your risk of error is eliminated. Now, the resulting handler looks like:

package main

import (
  "context"
  "fmt"
  "net/http"
  "os"
  "strings"
  "time"

  "github.com/google/uuid"
  "github.com/rs/zerolog"
  "github.com/rs/zerolog/log"
  "github.com/<mypackage>/ctxlog"
)

func main() {
  configureBaseLogger()
  log.Info().Msg("testing")

  // NOTE:  configured logger can be injected in the middleware instead of using a global variable.
  http.Handle("/", middleware(handler))

  if err := http.ListenAndServe(":8000", nil) ; err != nil {
    log.Error().Msg(err.Error())
  }
}

func configureBaseLogger() {
  output := zerolog.ConsoleWriter{
    Out: os.Stdout,
    FormatTimestamp: func(i interface{}) string {
      parse, _ := time.Parse(time.RFC3339, i.(string))
      return parse.Format("2006-01-02 15:04:05")
    },
    FormatLevel: func(i interface{}) string {
      return strings.ToUpper(fmt.Sprintf(" %-6s ", i))
    },
  }

  log.Logger = zerolog.New(output).With().
    Timestamp().CallerWithSkipFrameCount(2).Logger()
}

type HandlerFuncWithStatus func(writer http.ResponseWriter, request *http.Request) int

func middleware(next HandlerFuncWithStatus) http.HandlerFunc {
  return func(writer http.ResponseWriter, request *http.Request) {
    requestId := request.Header.Get("x-request-id")
    if requestId == "" {
      requestId = uuid.New().String()
    }

    subLogger := log.With().Str("requestId", requestId).Logger()

    subLogger.Info().
      Str("path", request.URL.Path).
      Str("method", request.Method).Msg("in")

    statusCode := next(writer, request.WithContext(
        ctxlog.WithLogger(r.Context(), subLogger)
    )
    // NOTE:  status code is set to 200 when the first write is initiated.
    writer.WriteHeader(statusCode)

    subLogger.Info().Int("status", statusCode).Msg("out")
  }
}

func anotherFunc(ctx context.Context) {
  logger := ctxlog.FromContext(ctx)
  // USE:  Error can be logged with all context at the point of error generation.  No need to thread it back up the call stack unless other error handling is involved.
  logger.Info().Msg("inside anotherFunc")
}

func handler (writer http.ResponseWriter, request *http.Request) int {
  logger := ctxlog.FromContext(ctx)
  logger.Info().Msg("inside handler")

  anotherFunc(request.Context())

  return 204
}
Enter fullscreen mode Exit fullscreen mode
Collapse
 
clavinjune profile image
Clavin June Author

@kunde21 Yes, of course, using iota is not a good one to put value with, using a predefined struct would works!