unitel/unitelhttp/request_logger.go

package unitelhttp

import (
	"fmt"
	"time"

	"github.com/getsentry/sentry-go"
	"github.com/go-logr/logr"
	"github.com/gofiber/fiber/v2"
	"github.com/gofiber/fiber/v2/utils"
	"go.opentelemetry.io/otel/trace"
)

const reqLoggerBufSize = 1000

func RequestLogger(l logr.Logger, requestHeaders, responseHeaders bool) fiber.Handler {
	type request struct {
		Method         string
		Path           string
		Start          time.Time
		RequestHeaders map[string][]string
		OtelSpanID     *trace.SpanID
		SentrySpanID   *sentry.SpanID
	}

	type response struct {
		Status          int
		End             time.Time
		Duration        time.Duration
		ResponseHeaders map[string][]string
		OtelSpanID      *trace.SpanID
		SentrySpanID    *sentry.SpanID
	}

	reqCh := make(chan request, reqLoggerBufSize)
	resCh := make(chan response, reqLoggerBufSize)

	go func() {
		for {
			select {
			case r := <-reqCh:
				attrs := []any{
					"method", r.Method,
					"path", r.Path,
					"start", r.Start,
				}

				if r.OtelSpanID != nil {
					attrs = append(attrs, "otel_span_id", r.OtelSpanID.String())
				}

				if r.SentrySpanID != nil {
					attrs = append(attrs, "sentry_span_id", r.SentrySpanID.String())
				}

				if requestHeaders {
					for k, v := range r.RequestHeaders {
						for i, vv := range v {
							attrs = append(attrs, formatHeaderAttribute("request", k, v, i), vv)
						}
					}
				}

				l.V(1).Info("request", attrs...)

			case r := <-resCh:
				attrs := []any{
					"status", r.Status,
					"end", r.End,
					"duration", r.Duration,
				}

				if r.OtelSpanID != nil {
					attrs = append(attrs, "otel_span_id", r.OtelSpanID.String())
				}

				if r.SentrySpanID != nil {
					attrs = append(attrs, "sentry_span_id", r.SentrySpanID.String())
				}

				if responseHeaders {
					for k, v := range r.ResponseHeaders {
						for i, vv := range v {
							attrs = append(attrs, formatHeaderAttribute("response", k, v, i), vv)
						}
					}
				}

				l.V(1).Info("response", attrs...)
			}
		}
	}()

	return func(c *fiber.Ctx) error {
		var otelSpanId *trace.SpanID = nil
		if spanId := trace.SpanContextFromContext(c.UserContext()).SpanID(); spanId.IsValid() {
			otelSpanId = &spanId
		}

		var sentrySpanId *sentry.SpanID = nil
		if span := sentry.SpanFromContext(c.UserContext()); span != nil {
			sentrySpanId = &span.SpanID
		}

		// pushing the request to the logger, so we don't block the handling
		req := request{
			Method:       c.Method(),
			Path:         c.Path(),
			Start:        time.Now(),
			OtelSpanID:   otelSpanId,
			SentrySpanID: sentrySpanId,
		}

		if requestHeaders {
			req.RequestHeaders = make(map[string][]string)
			for k, v := range c.GetReqHeaders() {
				for _, vv := range v {
					req.RequestHeaders[k] = append(req.RequestHeaders[k], utils.CopyString(vv))
				}
			}
		}
		reqCh <- req

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

		status := c.Response().StatusCode()

		if err != nil {
			if e, ok := err.(*fiber.Error); ok {
				status = e.Code
			} else {
				status = fiber.StatusInternalServerError
			}
		}

		// pushing the response to the logger, so we don't block the handling
		res := response{
			Status:       status,
			End:          end,
			Duration:     end.Sub(start),
			OtelSpanID:   otelSpanId,
			SentrySpanID: sentrySpanId,
		}

		if responseHeaders {
			res.ResponseHeaders = make(map[string][]string)
			for k, v := range c.GetRespHeaders() {
				for _, vv := range v {
					res.ResponseHeaders[k] = append(res.ResponseHeaders[k], utils.CopyString(vv))
				}
			}
		}

		resCh <- res

		return err
	}
}

func formatHeaderAttribute(t, k string, v []string, i int) string {
	attr := fmt.Sprintf("%s.headers.%s", t, k)

	if len(v) != 1 {
		attr = fmt.Sprintf("%s.%d", attr, i)
	}

	return attr
}