From 4660abad3aa81cea81c929ac5a1f03ccab48c92a Mon Sep 17 00:00:00 2001 From: Michael Yang Date: Thu, 28 Oct 2021 14:06:53 -0700 Subject: [PATCH] Update logging formatting/encoder (#547) * logging * update version logging --- internal/cmd/version.go | 5 ++-- internal/engine/engine.go | 4 +-- internal/kubernetes/kubernetes.go | 3 +- internal/logging/logger.go | 50 ++++++++++++++++++++++++------- internal/registry/http.go | 19 ------------ internal/registry/registry.go | 6 ++-- 6 files changed, 50 insertions(+), 37 deletions(-) diff --git a/internal/cmd/version.go b/internal/cmd/version.go index e9beff7dee..c38d0675c7 100644 --- a/internal/cmd/version.go +++ b/internal/cmd/version.go @@ -10,6 +10,7 @@ import ( "text/tabwriter" "github.com/infrahq/infra/internal" + "github.com/infrahq/infra/internal/logging" "golang.org/x/mod/semver" ) @@ -89,11 +90,11 @@ func checkUpdate(clientVersion, serverVersion string) error { } if clientSemVer != "v0.0.0-development" && semver.Compare(latestSemVer, clientSemVer) > 0 { - fmt.Fprintf(os.Stderr, "Infra CLI (%s) is out of date. Please update to %s.\n", clientVersion, latestVersion) + logging.S.Warnf("Infra CLI (%s) is out of date. Please update to %s.", clientVersion, latestVersion) } if serverSemVer != "v0.0.0-development" && semver.IsValid(serverSemVer) && semver.Compare(latestSemVer, serverSemVer) > 0 { - fmt.Fprintf(os.Stderr, "Infra (%s) is out of date. Please update to %s.\n", serverVersion, latestVersion) + logging.S.Warnf("Infra (%s) is out of date. Please update to %s.", serverVersion, latestVersion) } return nil diff --git a/internal/engine/engine.go b/internal/engine/engine.go index a2d0fd7f78..b6e3c13fce 100644 --- a/internal/engine/engine.go +++ b/internal/engine/engine.go @@ -7,12 +7,12 @@ import ( "encoding/json" "errors" "fmt" + "io" "io/ioutil" "net" "net/http" "net/http/httputil" "net/url" - "os" "regexp" "strings" "sync" @@ -443,7 +443,7 @@ func Run(options *Options) error { tlsServer := &http.Server{ Addr: ":443", TLSConfig: tlsConfig, - Handler: handlers.LoggingHandler(os.Stdout, mux), + Handler: handlers.CustomLoggingHandler(io.Discard, mux, logging.ZapLogFormatter), } logging.L.Info("serving on port 443") diff --git a/internal/kubernetes/kubernetes.go b/internal/kubernetes/kubernetes.go index 35db89c3f1..b40273dda5 100644 --- a/internal/kubernetes/kubernetes.go +++ b/internal/kubernetes/kubernetes.go @@ -19,7 +19,6 @@ import ( "github.com/infrahq/infra/internal/logging" "github.com/infrahq/infra/secrets" "github.com/jessevdk/go-flags" - "go.uber.org/zap" corev1 "k8s.io/api/core/v1" rbacv1 "k8s.io/api/rbac/v1" k8sErrors "k8s.io/apimachinery/pkg/api/errors" @@ -180,7 +179,7 @@ func (k *Kubernetes) updateRoleBindings(subjects map[namespaceRole][]rbacv1.Subj if k8sErrors.IsNotFound(err) { // the namespace does not exist // we can proceed in this case, the role mapping is just not applicable to this cluster - logging.L.Warn("skipping unapplicable namespace for this cluster: "+rb.Namespace, zap.Error(err)) + logging.S.Warnf("skipping unapplicable namespace for this cluster: %s %s", rb.Namespace, err.Error()) continue } diff --git a/internal/logging/logger.go b/internal/logging/logger.go index 6a59981e42..88fa4189b4 100644 --- a/internal/logging/logger.go +++ b/internal/logging/logger.go @@ -2,7 +2,13 @@ package logging import ( + "io" + "os" + + "github.com/gorilla/handlers" "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "golang.org/x/term" ) var ( @@ -10,21 +16,45 @@ var ( S *zap.SugaredLogger = zap.S() ) -func Initialize(level string) (*zap.Logger, error) { - config := zap.NewProductionConfig() +func Initialize(l string) (*zap.Logger, error) { atom := zap.NewAtomicLevel() - - err := atom.UnmarshalText([]byte(level)) - if err != nil { + if err := atom.UnmarshalText([]byte(l)); err != nil { return nil, err } - config.Level = atom + var ( + encoder zapcore.Encoder + writer zapcore.WriteSyncer + ) - logger, err := config.Build() - if err != nil { - return nil, err + if term.IsTerminal(int(os.Stdin.Fd())) { + writer = zapcore.Lock(os.Stderr) + encoder = zapcore.NewConsoleEncoder(zapcore.EncoderConfig{ + MessageKey: "message", + + LevelKey: "level", + EncodeLevel: zapcore.CapitalColorLevelEncoder, + + TimeKey: "time", + EncodeTime: zapcore.ISO8601TimeEncoder, + + CallerKey: "caller", + EncodeCaller: zapcore.ShortCallerEncoder, + }) + } else { + writer = zapcore.Lock(os.Stdout) + encoder = zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()) } - return logger, nil + core := zapcore.NewCore(encoder, writer, atom) + + return zap.New(core), nil +} + +func ZapLogFormatter(_ io.Writer, params handlers.LogFormatterParams) { + L.Debug("handled request", + zap.String("method", params.Request.Method), + zap.String("path", params.URL.Path), + zap.Int("status", params.StatusCode), + zap.Int("size", params.Size)) } diff --git a/internal/registry/http.go b/internal/registry/http.go index a352ae76a7..7c6650ab44 100644 --- a/internal/registry/http.go +++ b/internal/registry/http.go @@ -9,9 +9,7 @@ import ( "strings" "time" - "github.com/go-chi/chi/middleware" "github.com/infrahq/infra/internal/logging" - "go.uber.org/zap" "gopkg.in/square/go-jose.v2" "gorm.io/gorm" ) @@ -59,23 +57,6 @@ func deleteAuthCookie(w http.ResponseWriter) { }) } -func ZapLoggerHttpMiddleware(next http.Handler) http.HandlerFunc { - return func(w http.ResponseWriter, r *http.Request) { - ww := middleware.NewWrapResponseWriter(w, r.ProtoMajor) - t1 := time.Now() - - next.ServeHTTP(ww, r) - - logging.L.Info("finished http method call", - zap.String("method", r.Method), - zap.String("path", r.URL.Path), - zap.Int("status", ww.Status()), - zap.String("proto", r.Proto), - zap.Duration("time_ms", time.Since(t1)), - ) - } -} - type Http struct { db *gorm.DB } diff --git a/internal/registry/registry.go b/internal/registry/registry.go index 1405ab23b2..7149eec0a5 100644 --- a/internal/registry/registry.go +++ b/internal/registry/registry.go @@ -6,6 +6,7 @@ package registry import ( "errors" "fmt" + "io" "io/fs" "io/ioutil" "net/http" @@ -19,6 +20,7 @@ import ( assetfs "github.com/elazarl/go-bindata-assetfs" "github.com/getsentry/sentry-go" sentryhttp "github.com/getsentry/sentry-go/http" + "github.com/gorilla/handlers" "github.com/goware/urlx" "github.com/infrahq/infra/internal" "github.com/infrahq/infra/internal/api" @@ -351,7 +353,7 @@ func (r *Registry) runServer() error { plaintextServer := http.Server{ Addr: ":80", - Handler: ZapLoggerHttpMiddleware(sentryHandler.Handle(mux)), + Handler: handlers.CustomLoggingHandler(io.Discard, sentryHandler.Handle(mux), logging.ZapLogFormatter), } go func() { @@ -374,7 +376,7 @@ func (r *Registry) runServer() error { tlsServer := &http.Server{ Addr: ":443", TLSConfig: tlsConfig, - Handler: ZapLoggerHttpMiddleware(sentryHandler.Handle(mux)), + Handler: handlers.CustomLoggingHandler(io.Discard, sentryHandler.Handle(mux), logging.ZapLogFormatter), } if err := tlsServer.ListenAndServeTLS("", ""); err != nil {