diff --git a/cmd/proxy/actions/app.go b/cmd/proxy/actions/app.go index c1955d56..2c6a06a0 100644 --- a/cmd/proxy/actions/app.go +++ b/cmd/proxy/actions/app.go @@ -56,10 +56,8 @@ func App(conf *config.Config) (http.Handler, error) { lggr := log.New(conf.CloudRuntime, logLvl) r := mux.NewRouter() - if conf.GoEnv == "development" { - r.Use(mw.RequestLogger) - } r.Use(mw.LogEntryMiddleware(lggr)) + r.Use(mw.RequestLogger) r.Use(secure.New(secure.Options{ SSLRedirect: conf.ForceSSL, SSLProxyHeaders: map[string]string{"X-Forwarded-Proto": "https"}, diff --git a/go.mod b/go.mod index ff52647f..5d00f562 100644 --- a/go.mod +++ b/go.mod @@ -30,11 +30,14 @@ require ( github.com/hashicorp/go-multierror v1.0.0 github.com/hashicorp/hcl2 v0.0.0-20190503213020-640445e16309 github.com/kelseyhightower/envconfig v1.3.0 + github.com/kylelemons/godebug v1.1.0 // indirect github.com/minio/minio-go/v6 v6.0.43 github.com/mitchellh/go-homedir v1.1.0 github.com/philhofer/fwd v1.0.0 // indirect + github.com/pkg/errors v0.8.1 // indirect github.com/sirupsen/logrus v1.4.2 github.com/spf13/afero v1.1.2 + github.com/spf13/pflag v1.0.3 // indirect github.com/stretchr/testify v1.3.0 github.com/technosophos/moniker v0.0.0-20180509230615-a5dbd03a2245 github.com/tidwall/pretty v0.0.0-20180105212114-65a9db5fad51 // indirect diff --git a/go.sum b/go.sum index 1a3d52ce..5685aacf 100644 --- a/go.sum +++ b/go.sum @@ -182,6 +182,8 @@ github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= github.com/kylelemons/godebug v0.0.0-20170820004349-d65d576e9348 h1:MtvEpTB6LX3vkb4ax0b5D2DHbNAUsen0Gx5wZoq3lV4= github.com/kylelemons/godebug v0.0.0-20170820004349-d65d576e9348/go.mod h1:B69LEHPfb2qLo0BaaOLcbitczOKLWTsrBG9LczfCD4k= +github.com/kylelemons/godebug v1.1.0 h1:RPNrshWIDI6G2gRW9EHilWtl7Z6Sb1BR0xunSBf0SNc= +github.com/kylelemons/godebug v1.1.0/go.mod h1:9/0rRGxNHcop5bhtWyNeEfOS8JIWk580+fNqagV/RAw= github.com/markbates/hmax v1.0.0 h1:yo2N0gBoCnUMKhV/VRLHomT6Y9wUm+oQQENuWJqCdlM= github.com/markbates/hmax v1.0.0/go.mod h1:cOkR9dktiESxIMu+65oc/r/bdY4bE8zZw3OLhLx0X2c= github.com/mattn/go-colorable v0.0.9 h1:UVL0vNpWh04HeJXV0KLcaT7r06gOH2l4OW6ddYRUIY4= @@ -216,6 +218,8 @@ github.com/philhofer/fwd v1.0.0/go.mod h1:gk3iGcWd9+svBvR0sR+KPcfE+RNWozjowpeBVG github.com/pierrec/lz4 v2.0.5+incompatible/go.mod h1:pdkljMzZIN41W+lC3N2tnIh5sFi+IEE17M5jbnwPHcY= github.com/pkg/errors v0.8.0 h1:WdK/asTD0HN+q6hsWO3/vpuAkAr+tw6aNJNDFFf0+qw= github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/prometheus/client_golang v0.8.0/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw= @@ -255,6 +259,8 @@ github.com/spf13/cobra v0.0.3/go.mod h1:1l0Ry5zgKvJasoi3XT1TypsSe7PqH0Sj9dhYf7v3 github.com/spf13/pflag v1.0.1/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= github.com/spf13/pflag v1.0.2 h1:Fy0orTDgHdbnzHcsOgfCN4LtHf0ec3wwtiwJqwvf3Gc= github.com/spf13/pflag v1.0.2/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= +github.com/spf13/pflag v1.0.3 h1:zPAT6CGy6wXeQ7NtTnaTerfKOsV6V6F8agHXFiazDkg= +github.com/spf13/pflag v1.0.3/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= diff --git a/pkg/log/format.go b/pkg/log/format.go index 01cdc01e..f1e69d06 100644 --- a/pkg/log/format.go +++ b/pkg/log/format.go @@ -1,6 +1,13 @@ package log import ( + "bytes" + "fmt" + "sort" + "strings" + "time" + + "github.com/fatih/color" "github.com/sirupsen/logrus" ) @@ -15,7 +22,46 @@ func getGCPFormatter() logrus.Formatter { } func getDevFormatter() logrus.Formatter { - return &logrus.TextFormatter{} + return devFormatter{} +} + +type devFormatter struct{} + +const lightGrey = 0xffccc + +func (devFormatter) Format(e *logrus.Entry) ([]byte, error) { + var buf bytes.Buffer + var sprintf func(format string, a ...interface{}) string + switch e.Level { + case logrus.DebugLevel: + sprintf = color.New(lightGrey).Sprintf + case logrus.WarnLevel: + sprintf = color.YellowString + case logrus.ErrorLevel: + sprintf = color.RedString + default: + sprintf = color.CyanString + } + lvl := strings.ToUpper(e.Level.String()) + buf.WriteString(sprintf(lvl)) + buf.WriteString("[" + e.Time.Format(time.Kitchen) + "]") + buf.WriteString(": ") + buf.WriteString(e.Message) + buf.WriteByte('\t') + for _, k := range sortFields(e.Data) { + fmt.Fprintf(&buf, "%s=%s ", color.MagentaString(k), e.Data[k]) + } + buf.WriteByte('\n') + return buf.Bytes(), nil +} + +func sortFields(data logrus.Fields) []string { + keys := []string{} + for k := range data { + keys = append(keys, k) + } + sort.Strings(keys) + return keys } func getDefaultFormatter() logrus.Formatter { diff --git a/pkg/middleware/log_entry.go b/pkg/middleware/log_entry.go index 77b03066..4d2acee6 100644 --- a/pkg/middleware/log_entry.go +++ b/pkg/middleware/log_entry.go @@ -16,7 +16,6 @@ func LogEntryMiddleware(lggr *log.Logger) mux.MiddlewareFunc { ent := lggr.WithFields(logrus.Fields{ "http-method": r.Method, "http-path": r.URL.Path, - "http-url": r.URL.String(), }) ctx := log.SetEntryInContext(r.Context(), ent) diff --git a/pkg/middleware/log_entry_test.go b/pkg/middleware/log_entry_test.go index c2825e7e..14e88d8b 100644 --- a/pkg/middleware/log_entry_test.go +++ b/pkg/middleware/log_entry_test.go @@ -34,6 +34,6 @@ func TestLogContext(t *testing.T) { req, _ := http.NewRequest("GET", "/test", nil) r.ServeHTTP(w, req) - expected := `{"http-method":"GET","http-path":"/test","http-url":"/test","level":"info","msg":"test"}` + expected := `{"http-method":"GET","http-path":"/test","level":"info","msg":"test"}` assert.True(t, strings.Contains(buf.String(), expected), fmt.Sprintf("%s should contain: %s", buf.String(), expected)) } diff --git a/pkg/middleware/request.go b/pkg/middleware/request.go index 6948cb3c..1bff12e6 100644 --- a/pkg/middleware/request.go +++ b/pkg/middleware/request.go @@ -5,6 +5,8 @@ import ( "net/http" "github.com/fatih/color" + "github.com/gomods/athens/pkg/log" + logrus "github.com/sirupsen/logrus" ) type responseWriter struct { @@ -23,18 +25,14 @@ func RequestLogger(h http.Handler) http.Handler { f := func(w http.ResponseWriter, r *http.Request) { rw := &responseWriter{w, 0} h.ServeHTTP(rw, r) - fmt.Println( - fmtRequest( - r.Method, - r.URL.Path, - rw.statusCode, - ), - ) + log.EntryFromContext(r.Context()).WithFields(logrus.Fields{ + "http-status": fmtResponseCode(rw.statusCode), + }).Infof("incoming request") } return http.HandlerFunc(f) } -func fmtRequest(method, path string, statusCode int) string { +func fmtResponseCode(statusCode int) string { if statusCode == 0 { statusCode = 200 } @@ -47,11 +45,5 @@ func fmtRequest(method, path string, statusCode int) string { default: status = color.HiRedString("%v", status) } - return fmt.Sprintf( - "%v %v %v [%v]", - color.CyanString("handler:"), - method, - path, - status, - ) + return status }