diff --git a/cmd/root.go b/cmd/root.go index 297ccfb..1f29146 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -5,6 +5,7 @@ import ( "os" "github.com/kyoh86/xdg" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" "github.com/spf13/viper" ) @@ -37,6 +38,12 @@ func initConfig() { viper.SetConfigName("gotest") } viper.ReadInConfig() + if viper.GetString("env") == "production" { + log.SetFormatter(&log.JSONFormatter{}) + log.SetOutput(os.Stdout) + } else { + log.SetFormatter(&log.TextFormatter{}) + } } // Execute the root command diff --git a/go.mod b/go.mod index f355500..8515420 100644 --- a/go.mod +++ b/go.mod @@ -3,9 +3,11 @@ module git.bloy.org/mike/gotest go 1.12 require ( + github.com/google/uuid v1.1.1 github.com/gorilla/mux v1.7.3 github.com/joho/godotenv v1.3.0 github.com/kyoh86/xdg v1.0.0 + github.com/sirupsen/logrus v1.4.2 github.com/spf13/cobra v0.0.5 github.com/spf13/viper v1.3.2 ) diff --git a/go.sum b/go.sum index 5653de9..d777b29 100644 --- a/go.sum +++ b/go.sum @@ -8,6 +8,8 @@ github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/fsnotify/fsnotify v1.4.7 h1:IXs+QLmnXW2CcXuY+8Mzv/fWEsPGWxqefPtCP5CnV9I= github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo= +github.com/google/uuid v1.1.1 h1:Gkbcsh/GbpXz7lPftLA3P6TYMwjCLYm83jiFQZF/3gY= +github.com/google/uuid v1.1.1/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/gorilla/mux v1.7.3 h1:gnP5JzjVOuiZD07fKKToCAOjS0yOpj/qPETTXCCS6hw= github.com/gorilla/mux v1.7.3/go.mod h1:1lud6UwP+6orDFRuTfBEV8e9/aOM/c4fVVCaMa2zaAs= github.com/hashicorp/hcl v1.0.0 h1:0Anlzjpi4vEasTeNFn2mLJgTSwt0+6sfsiTG8qcWGx4= @@ -15,6 +17,7 @@ github.com/hashicorp/hcl v1.0.0/go.mod h1:E5yfLk+7swimpb2L/Alb/PJmXilQ/rhwaUYs4T github.com/inconshreveable/mousetrap v1.0.0/go.mod h1:PxqpIevigyE2G7u3NXJIT2ANytuPF1OarO4DADm73n8= github.com/joho/godotenv v1.3.0 h1:Zjp+RcGpHhGlrMbJzXTrZZPrWj+1vfm90La1wgB6Bhc= github.com/joho/godotenv v1.3.0/go.mod h1:7hK45KPybAkOC6peb+G5yklZfMxEjkZhHbwpqxOKXbg= +github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= github.com/kyoh86/xdg v1.0.0 h1:TD1layQ0epNApNwGRblnQnT3S/2UH/gCQN1cmXWotvE= github.com/kyoh86/xdg v1.0.0/go.mod h1:Z5mDqe0fxyxn3W2yTxsBAOQqIrXADQIh02wrTnaRM38= github.com/magiconair/properties v1.8.0 h1:LLgXmsheXeRoUOBOjtwPQCWIYqM/LU1ayDtDePerRcY= @@ -27,6 +30,8 @@ github.com/pelletier/go-toml v1.2.0/go.mod h1:5z9KED0ma1S8pY6P1sdut58dfprrGBbd/9 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/russross/blackfriday v1.5.2/go.mod h1:JO/DiYxRf+HjHt06OyowR9PTA263kcR/rfWxYHBV53g= +github.com/sirupsen/logrus v1.4.2 h1:SPIRibHv4MatM3XXNO2BJeFLZwZ2LvZgfQ5+UNI2im4= +github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE= github.com/spf13/afero v1.1.2 h1:m8/z1t7/fwjysjQRYbP0RD+bUIF/8tJwPdEZsI83ACI= github.com/spf13/afero v1.1.2/go.mod h1:j4pytiNVoe2o6bmDsKpLACNPDBIoEAkihy7loJ1B0CQ= github.com/spf13/cast v1.3.0 h1:oget//CVOEoFewqQxwr0Ej5yjygnqGkvggSE/gB35Q8= @@ -39,6 +44,7 @@ github.com/spf13/pflag v1.0.3 h1:zPAT6CGy6wXeQ7NtTnaTerfKOsV6V6F8agHXFiazDkg= github.com/spf13/pflag v1.0.3/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= github.com/spf13/viper v1.3.2 h1:VUFqw5KcqRf7i70GOzW7N+Q7+gxVBkSSqiXB12+JQ4M= github.com/spf13/viper v1.3.2/go.mod h1:ZiWeW+zYFKm7srdB9IoDzzZXaJaI5eL9QjNiN/DMA2s= +github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1w= github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/ugorji/go/codec v0.0.0-20181204163529-d75b2dcb6bc8/go.mod h1:VFNgLljTbGfSG7qAOspJ7OScBnGdDN/yBr0sguwnwf0= @@ -46,6 +52,8 @@ github.com/xordataexchange/crypt v0.0.3-0.20170626215501-b2862e3d0a77/go.mod h1: golang.org/x/crypto v0.0.0-20181203042331-505ab145d0a9/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/sys v0.0.0-20181205085412-a5c9d58dba9a h1:1n5lsVfiQW3yfsRGu98756EH1YthsFqr/5mxHduZW2A= golang.org/x/sys v0.0.0-20181205085412-a5c9d58dba9a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190422165155-953cdadca894 h1:Cz4ceDQGXuKRnVBDTS23GTn/pU5OE2C0WrNTOYK1Uuc= +golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/text v0.3.0 h1:g61tztE5qeGQ89tm6NTjjM9VPIm088od1l6aSorWRWg= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= diff --git a/web/middleware.go b/web/middleware.go new file mode 100644 index 0000000..744c6f9 --- /dev/null +++ b/web/middleware.go @@ -0,0 +1,150 @@ +package web + +import ( + "context" + "net/http" + "time" + + "github.com/google/uuid" + "github.com/gorilla/mux" + log "github.com/sirupsen/logrus" +) + +type contextKey int + +// context keys to be used when inspecting request contexts +const ( + requestIDKey contextKey = iota + correlationIDKey + loggerKey +) + +// Header names for middleware to use +const ( + RequestIDHeader string = "X-Request-Id" + CorrelationIDHeader = "X-Correlation-Id" +) + +// CorrelationIDFromRequest gets a correlation id from the request, if it +// exists. +func CorrelationIDFromRequest(req *http.Request) string { + var id string + if str := req.Header.Get(CorrelationIDHeader); str != "" { + id = str + } + return id +} + +func getFromContext(ctx context.Context, key contextKey) (value string, ok bool) { + if v := ctx.Value(key); v != nil { + value = v.(string) + ok = true + return + } + value, ok = "", false + return +} + +func CorrelationIDFromContext(ctx context.Context) (value string, ok bool) { + return getFromContext(ctx, correlationIDKey) +} + +func RequestIDFromContext(ctx context.Context) (value string, ok bool) { + return getFromContext(ctx, requestIDKey) +} + +func LoggerFromContext(ctx context.Context) *log.Entry { + if v := ctx.Value(loggerKey); v != nil { + return v.(*log.Entry) + } + return log.WithFields(log.Fields{}) +} + +type loggingResponseWriter struct { + http.ResponseWriter + size, status int + start time.Time +} + +// This idea is taken from the violetear responsewriter +// https://github.com/nbari/violetear/blob/master/responsewriter.go +func newLoggingResponseWriter(w http.ResponseWriter) *loggingResponseWriter { + return &loggingResponseWriter{ + ResponseWriter: w, + start: time.Now(), + status: http.StatusOK, + } +} + +func (w *loggingResponseWriter) Status() int { + return w.status +} + +func (w *loggingResponseWriter) Size() int { + return w.size +} + +func (w *loggingResponseWriter) ElapsedTime() string { + return time.Since(w.start).String() +} + +func (w *loggingResponseWriter) Write(data []byte) (int, error) { + size, err := w.ResponseWriter.Write(data) + w.size += size + return size, err +} + +func (w *loggingResponseWriter) WriteHeader(statusCode int) { + w.status = statusCode + w.ResponseWriter.WriteHeader(statusCode) +} + +func middleware(r *mux.Router) *mux.Router { + r.Use(loggingMw) + r.Use(discworldMw) + log.Info("using") + return r +} + +func discworldMw(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Clacks-Overhead", "GNU Terry Pratchett") + next.ServeHTTP(w, r) + }) +} + +func loggingMw(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + newW := newLoggingResponseWriter(w) + correlationID := CorrelationIDFromRequest(r) + if correlationID == "" { + correlationID = uuid.New().String() + } + requestID := uuid.New().String() + contextLogger := log.WithFields(log.Fields{ + "requestID": requestID, + "correlationID": correlationID, + }) + ctx := r.Context() + ctx = context.WithValue(ctx, requestIDKey, requestID) + ctx = context.WithValue(ctx, correlationIDKey, correlationID) + ctx = context.WithValue(ctx, loggerKey, contextLogger) + r = r.WithContext(ctx) + w.Header().Set(CorrelationIDHeader, correlationID) + w.Header().Set(RequestIDHeader, requestID) + requestLogger := contextLogger.WithFields( + log.Fields{ + "path": r.URL.Path, + "query_string": r.URL.RawQuery, + "method": r.Method, + }) + requestLogger.Info("Start web request") + next.ServeHTTP(newW, r) + requestLogger.WithFields( + log.Fields{ + "status": newW.Status(), + "size": newW.Size(), + "duration": newW.ElapsedTime()}). + Info("End web request") + }) +} diff --git a/web/router.go b/web/router.go index e0353c5..01aab31 100644 --- a/web/router.go +++ b/web/router.go @@ -2,30 +2,34 @@ package web import ( "fmt" - "log" "net/http" "github.com/gorilla/mux" + log "github.com/sirupsen/logrus" "github.com/spf13/viper" ) -// Router creates the default http router -func Router() *mux.Router { +func router() *mux.Router { r := mux.NewRouter() r.HandleFunc("/", root) return r } func root(resp http.ResponseWriter, req *http.Request) { + logger := LoggerFromContext(req.Context()) if req.URL.Path != "/" { http.NotFound(resp, req) + logger.Warning("404 Not found") return } fmt.Fprintf(resp, "Hello World!") + logger.Info("root page") } // RunServer runs the webserver with the router and middleware func RunServer() { - router := Router() + router := middleware(router()) + addr := viper.GetString("addr") + log.WithFields(log.Fields{"addr": addr}).Info("Webserver starting") log.Fatal(http.ListenAndServe(viper.GetString("addr"), router)) }