remove user info func, convert to separate logger mw

httperrors.go

@@ -19,10 +19,7 @@ func SendErrorJSON(w http.ResponseWriter, r *http.Request, code int, err error,
 }
 
 func errDetailsMsg(r *http.Request, code int, err error, details string) string {
-	uinfoStr := ""
-	if user, e := GetUserInfo(r); e == nil {
-		uinfoStr = user.String() + " - "
-	}
+
 	q := r.URL.String()
 	if qun, e := url.QueryUnescape(q); e == nil {
 		q = qun
@@ -40,5 +37,5 @@ func errDetailsMsg(r *http.Request, code int, err error, details string) string
 	if pos := strings.Index(remoteIP, ":"); pos >= 0 {
 		remoteIP = remoteIP[:pos]
 	}
-	return fmt.Sprintf("%s - %v - %d - %s%s - %s%s", details, err, code, uinfoStr, remoteIP, q, srcFileInfo)
+	return fmt.Sprintf("%s - %v - %d - %s - %s%s", details, err, code, remoteIP, q, srcFileInfo)
 }

httperrors_test.go

@@ -50,10 +50,9 @@ func TestErrorDetailsMsgWithUser(t *testing.T) {
 	callerFn := func() {
 		req, err := http.NewRequest("GET", "https://example.com/test?k1=v1&k2=v2", nil)
 		req.RemoteAddr = "127.0.0.1:1234"
-		req = SetUserInfo(req, uinfo{name: "test", id: "id"})
 		require.Nil(t, err)
 		msg := errDetailsMsg(req, 500, errors.New("error 500"), "error details 123456")
-		assert.Equal(t, "error details 123456 - error 500 - 500 - test/id - 127.0.0.1 - https://example.com/test?k1=v1&k2=v2 [caused by go-pkgz/rest/httperrors_test.go:58 rest.TestErrorDetailsMsgWithUser]", msg)
+		assert.Equal(t, "error details 123456 - error 500 - 500 - 127.0.0.1 - https://example.com/test?k1=v1&k2=v2 [caused by go-pkgz/rest/httperrors_test.go:57 rest.TestErrorDetailsMsgWithUser]", msg)
 	}
 	callerFn()
 }

logger/logger.go

@@ -0,0 +1,130 @@
+package logger
+
+import (
+	"bytes"
+	"fmt"
+	"io/ioutil"
+	"log"
+	"net/http"
+	"net/url"
+	"regexp"
+	"strings"
+	"time"
+
+	"github.com/go-chi/chi/middleware"
+)
+
+var reMultWhtsp = regexp.MustCompile(`[\s\p{Zs}]{2,}`)
+
+// Middleware for logging rest requests
+type Middleware struct {
+	prefix      string
+	maxBodySize int
+	flags       []Flag
+	ipFn        func(ip string) string
+	userFn      func(r *http.Request) (string, error)
+}
+
+// Flag type
+type Flag int
+
+// logger flags enum
+const (
+	All Flag = iota
+	User
+	Body
+	None
+)
+
+// New makes rest Logger with given options
+func New(options ...Option) Middleware {
+	res := Middleware{
+		prefix:      "",
+		maxBodySize: 1024,
+		flags:       []Flag{All},
+	}
+	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) {
+
+		if l.inLogFlags(None) { // skip logging
+			next.ServeHTTP(w, r)
+			return
+		}
+
+		ww := middleware.NewWrapResponseWriter(w, 1)
+		body, user := l.getBodyAndUser(r)
+		t1 := time.Now()
+		defer func() {
+			t2 := time.Now()
+
+			q := r.URL.String()
+			if qun, err := url.QueryUnescape(q); err == nil {
+				q = qun
+			}
+
+			remoteIP := strings.Split(r.RemoteAddr, ":")[0]
+			if strings.HasPrefix(r.RemoteAddr, "[") {
+				remoteIP = strings.Split(r.RemoteAddr, "]:")[0] + "]"
+			}
+
+			if l.ipFn != nil { // mask ip with ipFn
+				remoteIP = l.ipFn(remoteIP)
+			}
+
+			log.Printf("%s %s - %s - %s - %d (%d) - %v %s %s",
+				l.prefix, r.Method, q, remoteIP, ww.Status(), ww.BytesWritten(), t2.Sub(t1), user, body)
+		}()
+
+		next.ServeHTTP(ww, r)
+	}
+	return http.HandlerFunc(fn)
+}
+
+func (l *Middleware) getBodyAndUser(r *http.Request) (body string, user string) {
+	ctx := r.Context()
+	if ctx == nil {
+		return "", ""
+	}
+
+	if l.inLogFlags(Body) {
+		if content, err := ioutil.ReadAll(r.Body); err == nil {
+			body = string(content)
+			r.Body = ioutil.NopCloser(bytes.NewReader(content))
+
+			if len(body) > 0 {
+				body = strings.Replace(body, "\n", " ", -1)
+				body = reMultWhtsp.ReplaceAllString(body, " ")
+			}
+
+			if len(body) > l.maxBodySize {
+				body = body[:l.maxBodySize] + "..."
+			}
+		}
+	}
+
+	if l.inLogFlags(User) && l.userFn != nil {
+		u, err := l.userFn(r)
+		if err == nil && u != "" {
+			user = fmt.Sprintf(" - %s", u)
+		}
+	}
+
+	return body, user
+}
+
+func (l *Middleware) inLogFlags(f Flag) bool {
+	for _, flg := range l.flags {
+		if (flg == All && f != None) || flg == f {
+			return true
+		}
+	}
+	return false
+}

logger/logger_test.go

@@ -0,0 +1,104 @@
+package logger
+
+import (
+	"bytes"
+	"errors"
+	"io/ioutil"
+	"log"
+	"net/http"
+	"net/http/httptest"
+	"strings"
+	"testing"
+
+	"github.com/go-chi/chi"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestMiddleware_Logger(t *testing.T) {
+	buf := bytes.Buffer{}
+	log.SetOutput(&buf)
+
+	router := chi.NewRouter()
+	l := New(Prefix("[INFO] REST"), Flags(All),
+		IPfn(func(ip string) string {
+			return ip + "!masked"
+		}),
+		UserFn(func(r *http.Request) (string, error) {
+			return "user", nil
+		}),
+	)
+
+	router.Use(l.Handler)
+	router.Get("/blah", func(w http.ResponseWriter, r *http.Request) {
+		w.WriteHeader(200)
+		w.Write([]byte("blah blah"))
+	})
+	ts := httptest.NewServer(router)
+	defer ts.Close()
+
+	resp, err := http.Get(ts.URL + "/blah")
+	require.Nil(t, err)
+	assert.Equal(t, 200, resp.StatusCode)
+	defer resp.Body.Close()
+	b, err := ioutil.ReadAll(resp.Body)
+	assert.NoError(t, err)
+	assert.Equal(t, "blah blah", string(b))
+
+	s := buf.String()
+	t.Log(s)
+	assert.True(t, strings.Contains(s, "[INFO] REST GET - /blah - 127.0.0.1!masked - 200 (9) -"))
+	assert.True(t, strings.Contains(s, " - user"))
+}
+
+func TestMiddleware_LoggerNone(t *testing.T) {
+	buf := bytes.Buffer{}
+	log.SetOutput(&buf)
+
+	l := New(Prefix("[INFO] REST"), Flags(None))
+	router := chi.NewRouter()
+	router.Use(l.Handler)
+	router.Get("/blah", func(w http.ResponseWriter, r *http.Request) {
+		w.WriteHeader(200)
+		w.Write([]byte("blah blah"))
+	})
+	ts := httptest.NewServer(router)
+	defer ts.Close()
+
+	resp, err := http.Get(ts.URL + "/blah")
+	require.Nil(t, err)
+	assert.Equal(t, 200, resp.StatusCode)
+	defer resp.Body.Close()
+	b, err := ioutil.ReadAll(resp.Body)
+	assert.NoError(t, err)
+	assert.Equal(t, "blah blah", string(b))
+	assert.Equal(t, "", buf.String())
+}
+
+func TestMiddleware_GetBodyAndUser(t *testing.T) {
+	req, err := http.NewRequest("GET", "http://example.com/request", strings.NewReader("body"))
+	require.Nil(t, err)
+	l := New()
+
+	body, user := l.getBodyAndUser(req)
+	assert.Equal(t, "body", body)
+	assert.Equal(t, "", user, "no user")
+
+	l = New(Flags(User, Body), UserFn(func(r *http.Request) (string, error) {
+		return "user1/id1", nil
+	}))
+	_, user = l.getBodyAndUser(req)
+	assert.Equal(t, ` - user1/id1`, user, "no user")
+
+	l = New(UserFn(func(r *http.Request) (string, error) {
+		return "", errors.New("err")
+	}))
+	body, user = l.getBodyAndUser(req)
+	assert.Equal(t, "body", body)
+	assert.Equal(t, "", user, "no user")
+
+	l = New(Flags(User))
+	body, user = l.getBodyAndUser(req)
+	assert.Equal(t, "", body)
+	assert.Equal(t, "", user, "no user")
+}

logger/options.go

@@ -0,0 +1,45 @@
+package logger
+
+import (
+	"net/http"
+)
+
+// Option func type
+type Option func(l *Middleware)
+
+// Flags functional option defines output modes
+func Flags(flags ...Flag) Option {
+	return func(l *Middleware) {
+		l.flags = flags
+	}
+}
+
+// MaxBodySize functional option defines the largest body size to log.
+func MaxBodySize(max int) Option {
+	return func(l *Middleware) {
+		if max >= 0 {
+			l.maxBodySize = max
+		}
+	}
+}
+
+// Prefix functional option defines log line prefix.
+func Prefix(prefix string) Option {
+	return func(l *Middleware) {
+		l.prefix = prefix
+	}
+}
+
+// IPfn functional option defines ip masking function.
+func IPfn(ipFn func(ip string) string) Option {
+	return func(l *Middleware) {
+		l.ipFn = ipFn
+	}
+}
+
+// UserFn functional option defines user name function.
+func UserFn(userFn func(r *http.Request) (string, error)) Option {
+	return func(l *Middleware) {
+		l.userFn = userFn
+	}
+}