Apache log (#15)

* support apache log format * lint:warns
go-pkgz · Apr 6, 2021 · 608fee9 · 608fee9
1 parent 78d77b6
commit 608fee9
Show file tree

Hide file tree

Showing 3 changed files with 144 additions and 35 deletions.
diff --git a/logger/logger.go b/logger/logger.go
@@ -12,26 +12,41 @@ import (
 	"net/http"
 	"net/url"
 	"regexp"
+	"strconv"
 	"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
+	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
+	apacheCombined bool
 }
 
 // Backend is logging backend
 type Backend interface {
 	Logf(format string, args ...interface{})
 }
 
+type logParts struct {
+	duration   time.Duration
+	rawURL     string
+	method     string
+	remoteIP   string
+	statusCode int
+	respSize   int
+
+	prefix string
+	user   string
+	body   string
+}
+
 type stdBackend struct{}
 
 func (s stdBackend) Logf(format string, args ...interface{}) {
@@ -61,6 +76,11 @@ func New(options ...Option) *Middleware {
 // 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)
 
@@ -88,42 +108,91 @@ func (l *Middleware) Handler(next http.Handler) http.Handler {
 				remoteIP = l.ipFn(remoteIP)
 			}
 
-			var bld strings.Builder
-			if l.prefix != "" {
-				_, _ = bld.WriteString(l.prefix)
-				_, _ = bld.WriteString(" ")
+			p := &logParts{
+				duration:   t2.Sub(t1),
+				rawURL:     rawurl,
+				method:     r.Method,
+				remoteIP:   remoteIP,
+				statusCode: ww.status,
+				respSize:   ww.size,
+				prefix:     l.prefix,
+				user:       user,
+				body:       body,
 			}
 
-			_, _ = bld.WriteString(fmt.Sprintf("%s - %s - %s - %d (%d) - %v", r.Method, rawurl, remoteIP, ww.status, ww.size, t2.Sub(t1)))
+			l.log.Logf(formater(r, p))
+		}()
 
-			if user != "" {
-				_, _ = bld.WriteString(" - ")
-				_, _ = bld.WriteString(user)
-			}
+		next.ServeHTTP(ww, r)
+	}
+	return http.HandlerFunc(fn)
+}
 
-			if l.subjFn != nil {
-				if subj, err := l.subjFn(r); err == nil {
-					_, _ = bld.WriteString(" - ")
-					_, _ = bld.WriteString(subj)
-				}
-			}
+func (l *Middleware) formatDefault(r *http.Request, p *logParts) string {
+	var bld strings.Builder
+	if l.prefix != "" {
+		_, _ = bld.WriteString(l.prefix)
+		_, _ = bld.WriteString(" ")
+	}
 
-			if traceID := r.Header.Get("X-Request-ID"); traceID != "" {
-				_, _ = bld.WriteString(" - ")
-				_, _ = bld.WriteString(traceID)
-			}
+	_, _ = bld.WriteString(fmt.Sprintf("%s - %s - %s - %d (%d) - %v",
+		p.method, p.rawURL, p.remoteIP, p.statusCode, p.respSize, p.duration))
 
-			if body != "" {
-				_, _ = bld.WriteString(" - ")
-				_, _ = bld.WriteString(body)
-			}
+	if p.user != "" {
+		_, _ = bld.WriteString(" - ")
+		_, _ = bld.WriteString(p.user)
+	}
 
-			l.log.Logf("%s", bld.String())
-		}()
+	if l.subjFn != nil {
+		if subj, err := l.subjFn(r); err == nil {
+			_, _ = bld.WriteString(" - ")
+			_, _ = bld.WriteString(subj)
+		}
+	}
 
-		next.ServeHTTP(ww, r)
+	if traceID := r.Header.Get("X-Request-ID"); traceID != "" {
+		_, _ = bld.WriteString(" - ")
+		_, _ = bld.WriteString(traceID)
 	}
-	return http.HandlerFunc(fn)
+
+	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,}`)

diff --git a/logger/logger_test.go b/logger/logger_test.go
@@ -305,3 +305,37 @@ func TestSanitizeReqURL(t *testing.T) {
 		})
 	}
 }
+
+func TestLoggerApacheCombined(t *testing.T) {
+
+	handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		_, err := w.Write([]byte("blah blah"))
+		require.NoError(t, err)
+	})
+
+	lb := &mockLgr{}
+	l := New(Log(lb), ApacheCombined,
+		IPfn(func(ip string) string {
+			return ip + "!masked"
+		}),
+		UserFn(func(r *http.Request) (string, error) {
+			return "user", nil
+		}),
+	)
+
+	ts := httptest.NewServer(l.Handler(handler))
+	defer ts.Close()
+
+	resp, err := http.Post(ts.URL+"/blah?password=secret&key=val&var=123", "", bytes.NewBufferString("1234567890 abcdefg"))
+	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 := lb.buf.String()
+	t.Log(s)
+	assert.True(t, strings.HasPrefix(s, "127.0.0.1!masked - user ["))
+	assert.True(t, strings.HasSuffix(s, ` "POST /blah?key=val&password=********&var=123" HTTP/1.1" 200 9 "" "Go-http-client/1.1"`), s)
+}
diff --git a/logger/options.go b/logger/options.go
@@ -49,7 +49,13 @@ func SubjFn(subjFn func(r *http.Request) (string, error)) Option {
 	}
 }
 
-// Log sets logging backend. 
+// ApacheCombined sets format to Apache Combined Log.
+// See http://httpd.apache.org/docs/2.2/logs.html#combined
+func ApacheCombined(l *Middleware) {
+	l.apacheCombined = true
+}
+
+// Log sets logging backend.
 func Log(log Backend) Option {
 	return func(l *Middleware) {
 		l.log = log