Files
Dmitry VerkhoturovandGitHub 1f34984dab Bump go-pkgz/rest to v1.24.0 and opt in to wildcard origins with credentials (#2157)
rest.CORS refuses "*" together with credentials since go-pkgz/rest#52, so the
bump and the option have to land together: the option does not exist in v1.22.0
and the panic fires at construction, inside routes(), which makes it a startup
failure rather than a request-time one.

The wildcard stays. The comment widget is embedded on arbitrary third-party
sites, so the set of origins is not knowable, which is why the escape hatch was
asked for upstream instead of accepting the panic. What it costs is unchanged
and now written next to the call: any site a signed-in user visits can read
authenticated responses, so state-changing requests have to keep being protected
by something other than the origin, X-XSRF-Token today.

The example module is tidied in the same commit, as it reaches go-pkgz/rest
through the replace directive and its indirect graph would otherwise keep the
old pin and fail the readonly module check in CI.

The bump also carries testify to v1.12.0, which drops go-spew and go-difflib
from the module graph.
2026-08-19 00:33:13 -05:00

388 lines
9.3 KiB
Go

// Package logger implements logging middleware
package logger
import (
"bufio"
"bytes"
"fmt"
"io"
"log"
"net"
"net/http"
"net/url"
"regexp"
"strconv"
"strings"
"time"
"github.com/go-pkgz/rest/realip"
)
// Middleware is a logger for rest requests.
type Middleware struct {
prefix string
logBody bool
maxBodySize int
ipFn func(ip string) string
userFn func(r *http.Request) (string, error)
subjFn func(r *http.Request) (string, error)
bodyFn func(body string, truncated bool) string
log Backend
apacheCombined bool
}
// Backend is logging backend
type Backend interface {
Logf(format string, args ...any)
}
type logParts struct {
duration time.Duration
rawURL string
method string
remoteIP string
statusCode int
respSize int
host string
prefix string
user string
body string
}
type stdBackend struct{}
func (s stdBackend) Logf(format string, args ...any) {
log.Printf(format, args...)
}
// Logger is a default logger middleware with "REST" prefix
func Logger(next http.Handler) http.Handler {
l := New(Prefix("REST"))
return l.Handler(next)
}
// New makes rest logger with given options
func New(options ...Option) *Middleware {
res := Middleware{
prefix: "",
maxBodySize: 1024,
log: stdBackend{},
}
for _, opt := range options {
opt(&res)
}
return &res
}
// Handler middleware prints http log
func (l *Middleware) Handler(next http.Handler) http.Handler {
formater := l.formatDefault
if l.apacheCombined {
formater = l.formatApacheCombined
}
fn := func(w http.ResponseWriter, r *http.Request) {
ww := newCustomResponseWriter(w)
user := ""
if l.userFn != nil {
if u, err := l.userFn(r); err == nil {
user = u
}
}
body := l.getBody(r)
t1 := time.Now()
defer func() {
t2 := time.Now()
u := *r.URL // shallow copy
u.RawQuery = l.sanitizeQuery(u.RawQuery)
rawurl := u.String()
if unescURL, err := url.QueryUnescape(rawurl); err == nil {
rawurl = unescURL
}
// unescaping can surface line breaks the encoded url hid, collapse them the same way
// the body is collapsed so an embedded break can't forge additional log records
rawurl = lineBreaks.Replace(rawurl)
remoteIP, err := realip.Get(r)
if err != nil {
remoteIP = "unknown ip"
}
if l.ipFn != nil { // mask ip with ipFn
remoteIP = l.ipFn(remoteIP)
}
server := r.URL.Hostname()
if server == "" {
server = strings.Split(r.Host, ":")[0]
}
p := &logParts{
duration: t2.Sub(t1),
rawURL: rawurl,
method: r.Method,
host: server,
remoteIP: remoteIP,
statusCode: ww.status,
respSize: ww.size,
prefix: l.prefix,
user: user,
body: body,
}
l.log.Logf("%s", formater(r, p))
}()
next.ServeHTTP(ww, r)
}
return http.HandlerFunc(fn)
}
func (l *Middleware) formatDefault(r *http.Request, p *logParts) string {
var bld strings.Builder
if l.prefix != "" {
_, _ = bld.WriteString(l.prefix)
_, _ = bld.WriteString(" ")
}
_, _ = fmt.Fprintf(&bld, "%s - %s - %s - %s - %d (%d) - %v",
p.method, p.rawURL, p.host, p.remoteIP, p.statusCode, p.respSize, p.duration)
if p.user != "" {
_, _ = bld.WriteString(" - ")
_, _ = bld.WriteString(p.user)
}
if l.subjFn != nil {
if subj, err := l.subjFn(r); err == nil {
_, _ = bld.WriteString(" - ")
_, _ = bld.WriteString(subj)
}
}
if traceID := r.Header.Get("X-Request-ID"); traceID != "" {
_, _ = bld.WriteString(" - ")
_, _ = bld.WriteString(traceID)
}
if p.body != "" {
_, _ = bld.WriteString(" - ")
_, _ = bld.WriteString(p.body)
}
return bld.String()
}
// 127.0.0.1 - frank [10/Oct/2000:13:55:36 -0700] "GET /apache_pb.gif HTTP/1.0" 200 2326 "http://www.example.com/start.html" "Mozilla/4.08 [en] (Win98; I ;Nav)"
// nolint gosec
func (l *Middleware) formatApacheCombined(r *http.Request, p *logParts) string {
username := "-"
if p.user != "" {
username = p.user
}
var bld strings.Builder
bld.WriteString(p.remoteIP)
bld.WriteString(" - ")
bld.WriteString(username)
bld.WriteString(" [")
bld.WriteString(time.Now().Format("02/Jan/2006:15:04:05 -0700"))
bld.WriteString(`] "`)
bld.WriteString(p.method)
bld.WriteString(" ")
bld.WriteString(p.rawURL)
bld.WriteString(" ")
bld.WriteString(r.Proto)
bld.WriteString(`" `)
bld.WriteString(strconv.Itoa(p.statusCode))
bld.WriteString(" ")
bld.WriteString(strconv.Itoa(p.respSize))
bld.WriteString(` "`)
bld.WriteString(r.Header.Get("Referer"))
bld.WriteString(`" "`)
bld.WriteString(r.Header.Get("User-Agent"))
bld.WriteString(`"`)
return bld.String()
}
var reMultWhtsp = regexp.MustCompile(`[\s\p{Zs}]{2,}`)
// lineBreaks maps every character that can start a new line to a space, so a body
// can't forge extra log records. reMultWhtsp only collapses runs of two or more, so
// a lone CR or a Unicode line separator would otherwise slip through.
var lineBreaks = strings.NewReplacer(
"\n", " ", // LF
"\r", " ", // CR
"\v", " ", // vertical tab
"\f", " ", // form feed
"\u0085", " ", // NEL
"\u2028", " ", // line separator
"\u2029", " ", // paragraph separator
)
func (l *Middleware) getBody(r *http.Request) string {
if !l.logBody {
return ""
}
reader, body, hasMore, err := peek(r.Body, int64(l.maxBodySize))
if err != nil {
return ""
}
// "The Server will close the request body. The ServeHTTP Handler does not need to."
// https://golang.org/pkg/net/http/#Request
// so we can use ioutil.NopCloser() to make io.ReadCloser.
// note that below assignment is not approved by the docs:
// "Except for reading the body, handlers should not modify the provided Request."
// https://golang.org/pkg/net/http/#Handler
r.Body = io.NopCloser(reader)
// the transform owns the logged body: it receives the body (capped at
// maxBodySize) and a flag telling it whether more was dropped, and decides
// how to render it - mask values, summarize, or emit a marker for a
// truncated body. an empty body has nothing to transform, so it is left
// alone. without a transform the body is logged as read, with the "..."
// marker appended when it was truncated.
switch {
case l.bodyFn != nil && body != "":
body = l.bodyFn(body, hasMore)
case hasMore:
body += "..."
}
// always collapse to a single line, regardless of the transform, so an
// embedded line break in the body can't forge additional log lines.
if body != "" {
body = lineBreaks.Replace(body)
body = reMultWhtsp.ReplaceAllString(body, " ")
}
return body
}
// peek the first n bytes as string
func peek(r io.Reader, n int64) (reader io.Reader, s string, hasMore bool, err error) {
if n < 0 {
n = 0
}
buf := new(bytes.Buffer)
_, err = io.CopyN(buf, r, n+1)
if err == io.EOF {
str := buf.String()
return buf, str, false, nil
}
if err != nil {
return r, "", false, err
}
// one extra byte is successfully read
s = buf.String()
s = s[:len(s)-1]
return io.MultiReader(buf, r), s, true, nil
}
var keysToHide = []string{"password", "passwd", "secret", "credentials", "token"}
// Hide query values for keysToHide. May change order of query params.
// May escape unescaped query params.
func (l *Middleware) sanitizeQuery(rawQuery string) string {
// note that we skip non-nil error further
query, err := url.ParseQuery(rawQuery)
isHidden := func(key string) bool {
for _, k := range keysToHide {
if strings.EqualFold(k, key) {
return true
}
}
return false
}
present := false
for key, values := range query {
if isHidden(key) {
present = true
for i := range values {
values[i] = "********"
}
}
}
// short circuit
if (err == nil) && !present {
return rawQuery
}
return query.Encode()
}
// AnonymizeIP is a function to reset the last part of IPv4 to 0.
// from 123.212.12.78 it will make 123.212.12.0
func AnonymizeIP(ip string) string {
if ip == "" {
return ""
}
parts := strings.Split(ip, ".")
if len(parts) != 4 {
return ip
}
return strings.Join(parts[:3], ".") + ".0"
}
// customResponseWriter is an HTTP response logger that keeps HTTP status code and
// the number of bytes written.
// It implements http.ResponseWriter, http.Flusher and http.Hijacker.
// Note that type assertion from http.ResponseWriter(customResponseWriter) to
// http.Flusher and http.Hijacker is always succeed but underlying http.ResponseWriter
// may not implement them.
type customResponseWriter struct {
http.ResponseWriter
status int
size int
}
func newCustomResponseWriter(w http.ResponseWriter) *customResponseWriter {
return &customResponseWriter{
ResponseWriter: w,
status: 200,
}
}
// WriteHeader implements http.ResponseWriter and saves status
func (c *customResponseWriter) WriteHeader(status int) {
c.status = status
c.ResponseWriter.WriteHeader(status)
}
// Write implements http.ResponseWriter and tracks number of bytes written
func (c *customResponseWriter) Write(b []byte) (int, error) {
size, err := c.ResponseWriter.Write(b)
c.size += size
return size, err
}
// Flush implements http.Flusher
func (c *customResponseWriter) Flush() {
if f, ok := c.ResponseWriter.(http.Flusher); ok {
f.Flush()
}
}
// Hijack implements http.Hijacker
func (c *customResponseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) {
if hj, ok := c.ResponseWriter.(http.Hijacker); ok {
return hj.Hijack()
}
return nil, nil, fmt.Errorf("ResponseWriter does not implement the Hijacker interface")
}