Files
remark42/backend/vendor/github.com/go-pkgz/rest/logger/logger.go
T

276 lines
6.2 KiB
Go

package logger
import (
"bufio"
"bytes"
"fmt"
"io"
"io/ioutil"
"log"
"net"
"net/http"
"net/url"
"regexp"
"strings"
"time"
)
// 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)
log Backend
}
// Backend is logging backend
type Backend interface {
Logf(format string, args ...interface{})
}
type stdBackend struct{}
func (s stdBackend) Logf(format string, args ...interface{}) {
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 {
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
}
remoteIP := l.remoteIP(r)
if l.ipFn != nil { // mask ip with ipFn
remoteIP = l.ipFn(remoteIP)
}
var bld strings.Builder
if l.prefix != "" {
bld.WriteString(l.prefix)
bld.WriteString(" ")
}
bld.WriteString(fmt.Sprintf("%s - %s - %s - %d (%d) - %v", r.Method, rawurl, remoteIP, ww.status, ww.size, t2.Sub(t1)))
if user != "" {
bld.WriteString(" - ")
bld.WriteString(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 body != "" {
bld.WriteString(" - ")
bld.WriteString(body)
}
l.log.Logf("%s", bld.String())
}()
next.ServeHTTP(ww, r)
}
return http.HandlerFunc(fn)
}
var reMultWhtsp = regexp.MustCompile(`[\s\p{Zs}]{2,}`)
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 = ioutil.NopCloser(reader)
if len(body) > 0 {
body = strings.Replace(body, "\n", " ", -1)
body = reMultWhtsp.ReplaceAllString(body, " ")
}
if hasMore {
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 {
return buf, buf.String(), 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()
}
// remoteIP gets address from X-Forwarded-For and than from request's remote address
func (l *Middleware) remoteIP(r *http.Request) (remoteIP string) {
if remoteIP = r.Header.Get("X-Forwarded-For"); remoteIP == "" {
remoteIP = r.RemoteAddr
}
remoteIP = strings.Split(remoteIP, ":")[0]
if strings.HasPrefix(remoteIP, "[") {
remoteIP = strings.Split(remoteIP, "]:")[0] + "]"
}
return remoteIP
}
// 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")
}