Skip to content

Commit

Permalink
Clean up logging and log failed API requests
Browse files Browse the repository at this point in the history
  • Loading branch information
@divolgin
divolgin committed Sep 23, 2021
1 parent fc1750a commit 539e92c
Show file tree
Hide file tree
Showing 6 changed files with 157 additions and 97 deletions.
2 changes: 2 additions & 0 deletions kustomize/overlays/dev/deployment.yaml
View file
Expand Up @@ -72,6 +72,8 @@ spec:
value: "3"
- name: POD_OWNER_KIND
value: "deployment"
- name: DEBUG
value: "false"
volumes:
- emptyDir:
medium: Memory
Expand Down
36 changes: 21 additions & 15 deletions pkg/apiserver/server.go
View file
Expand Up @@ -129,38 +129,44 @@ func Start(params *APIServerParams) {

r := mux.NewRouter()

r.Use(handlers.LoggingMiddleware, handlers.CorsMiddleware)
r.Use(handlers.CorsMiddleware)
r.Methods("OPTIONS").HandlerFunc(handlers.CORS)

debugRouter := r.NewRoute().Subrouter()
debugRouter.Use(handlers.DebugLoggingMiddleware)

loggingRouter := r.NewRoute().Subrouter()
loggingRouter.Use(handlers.LoggingMiddleware)

handler := &handlers.Handler{}

/**********************************************************************
* Unauthenticated routes
**********************************************************************/

r.HandleFunc("/healthz", handler.Healthz)
r.HandleFunc("/api/v1/login", handler.Login)
r.HandleFunc("/api/v1/login/info", handler.GetLoginInfo)
r.HandleFunc("/api/v1/logout", handler.Logout) // this route uses its own auth
r.Path("/api/v1/metadata").Methods("GET").HandlerFunc(handler.Metadata)
debugRouter.HandleFunc("/healthz", handler.Healthz)
loggingRouter.HandleFunc("/api/v1/login", handler.Login)
loggingRouter.HandleFunc("/api/v1/login/info", handler.GetLoginInfo)
loggingRouter.HandleFunc("/api/v1/logout", handler.Logout) // this route uses its own auth
loggingRouter.Path("/api/v1/metadata").Methods("GET").HandlerFunc(handler.Metadata)

r.HandleFunc("/api/v1/oidc/login", handler.OIDCLogin)
r.HandleFunc("/api/v1/oidc/login/callback", handler.OIDCLoginCallback)
loggingRouter.HandleFunc("/api/v1/oidc/login", handler.OIDCLogin)
loggingRouter.HandleFunc("/api/v1/oidc/login/callback", handler.OIDCLoginCallback)

r.Path("/api/v1/troubleshoot/{appId}/{bundleId}").Methods("PUT").HandlerFunc(handler.UploadSupportBundle)
r.Path("/api/v1/troubleshoot/supportbundle/{bundleId}/redactions").Methods("PUT").HandlerFunc(handler.SetSupportBundleRedactions)
loggingRouter.Path("/api/v1/troubleshoot/{appId}/{bundleId}").Methods("PUT").HandlerFunc(handler.UploadSupportBundle)
loggingRouter.Path("/api/v1/troubleshoot/supportbundle/{bundleId}/redactions").Methods("PUT").HandlerFunc(handler.SetSupportBundleRedactions)

// This the handler for license API and should be called by the application only.
r.Path("/license/v1/license").Methods("GET").HandlerFunc(handler.GetPlatformLicenseCompatibility)
loggingRouter.Path("/license/v1/license").Methods("GET").HandlerFunc(handler.GetPlatformLicenseCompatibility)

/**********************************************************************
* KOTS token auth routes
**********************************************************************/

r.Path("/api/v1/kots/ports").Methods("GET").HandlerFunc(handler.GetApplicationPorts)
r.Path("/api/v1/upload").Methods("PUT").HandlerFunc(handler.UploadExistingApp)
r.Path("/api/v1/download").Methods("GET").HandlerFunc(handler.DownloadApp)
r.Path("/api/v1/airgap/install").Methods("POST").HandlerFunc(handler.UploadInitialAirgapApp)
debugRouter.Path("/api/v1/kots/ports").Methods("GET").HandlerFunc(handler.GetApplicationPorts)
loggingRouter.Path("/api/v1/upload").Methods("PUT").HandlerFunc(handler.UploadExistingApp)
loggingRouter.Path("/api/v1/download").Methods("GET").HandlerFunc(handler.DownloadApp)
loggingRouter.Path("/api/v1/airgap/install").Methods("POST").HandlerFunc(handler.UploadInitialAirgapApp)

/**********************************************************************
* Session auth routes
Expand Down
2 changes: 1 addition & 1 deletion pkg/handlers/handlers.go
View file
Expand Up @@ -28,7 +28,7 @@ func init() {
}

func RegisterSessionAuthRoutes(r *mux.Router, kotsStore store.Store, handler KOTSHandler, middleware *policy.Middleware) {
r.Use(RequireValidSessionMiddleware(kotsStore))
r.Use(LoggingMiddleware, RequireValidSessionMiddleware(kotsStore))

// Installation
r.Name("UploadNewLicense").Path("/api/v1/license").Methods("POST").
Expand Down
65 changes: 51 additions & 14 deletions pkg/handlers/middleware.go
View file
Expand Up @@ -12,6 +12,20 @@ import (
"github.com/replicatedhq/kots/pkg/store"
)

type loggingResponseWriter struct {
http.ResponseWriter
StatusCode int
}

func NewLoggingResponseWriter(w http.ResponseWriter) *loggingResponseWriter {
return &loggingResponseWriter{w, http.StatusOK}
}

func (lrw *loggingResponseWriter) WriteHeader(code int) {
lrw.StatusCode = code
lrw.ResponseWriter.WriteHeader(code)
}

func CorsMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
if handleOptionsRequest(w, r) {
Expand All @@ -21,23 +35,46 @@ func CorsMiddleware(next http.Handler) http.Handler {
})
}

func DebugLoggingMiddleware(next http.Handler) http.Handler {
if os.Getenv("DEBUG") != "true" {
return next
}

return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
startTime := time.Now()

lrw := NewLoggingResponseWriter(w)
next.ServeHTTP(lrw, r)

logger.Debugf(
"method=%s status=%d duration=%s request=%s",
r.Method,
lrw.StatusCode,
time.Since(startTime).String(),
r.RequestURI,
)
})
}

func LoggingMiddleware(next http.Handler) http.Handler {
debug := os.Getenv("DEBUG") == "true"
if debug {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
startTime := time.Now()
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
startTime := time.Now()

next.ServeHTTP(w, r)
lrw := NewLoggingResponseWriter(w)
next.ServeHTTP(lrw, r)

logger.Debugf(
"request=%s method=%s duration=%s",
r.RequestURI,
r.Method,
time.Since(startTime).String(),
)
})
}
return next
if os.Getenv("DEBUG") != "true" && lrw.StatusCode < http.StatusBadRequest {
return
}

logger.Infof(
"method=%s status=%d duration=%s request=%s",
r.Method,
lrw.StatusCode,
time.Since(startTime).String(),
r.RequestURI,
)
})
}

func RequireValidSessionMiddleware(kotsStore store.Store) mux.MiddlewareFunc {
Expand Down
138 changes: 78 additions & 60 deletions pkg/logger/clilogger.go
View file
Expand Up @@ -103,29 +103,32 @@ func (l *CLILogger) ActionWithSpinner(msg string, args ...interface{}) {
fmt.Printf(" • ")
fmt.Printf(msg, args...)

if isatty.IsTerminal(os.Stdout.Fd()) {
s := spin.New()

fmt.Printf(" %s", s.Next())

l.spinnerStopCh = make(chan bool)
l.spinnerMsg = msg
l.spinnerArgs = args

go func() {
for {
select {
case <-l.spinnerStopCh:
return
case <-time.After(time.Millisecond * 100):
fmt.Printf("\r")
fmt.Printf(" • ")
fmt.Printf(msg, args...)
fmt.Printf(" %s", s.Next())
}
}
}()
if !isatty.IsTerminal(os.Stdout.Fd()) {
fmt.Println()
return
}

s := spin.New()

fmt.Printf(" %s", s.Next())

l.spinnerStopCh = make(chan bool)
l.spinnerMsg = msg
l.spinnerArgs = args

go func() {
for {
select {
case <-l.spinnerStopCh:
return
case <-time.After(time.Millisecond * 100):
fmt.Printf("\r")
fmt.Printf(" • ")
fmt.Printf(msg, args...)
fmt.Printf(" %s", s.Next())
}
}
}()
}

func (l *CLILogger) ChildActionWithSpinner(msg string, args ...interface{}) {
Expand All @@ -136,36 +139,44 @@ func (l *CLILogger) ChildActionWithSpinner(msg string, args ...interface{}) {
fmt.Printf(" • ")
fmt.Printf(msg, args...)

if isatty.IsTerminal(os.Stdout.Fd()) {
s := spin.New()

fmt.Printf(" %s", s.Next())

l.spinnerStopCh = make(chan bool)
l.spinnerMsg = msg
l.spinnerArgs = args

go func() {
for {
select {
case <-l.spinnerStopCh:
return
case <-time.After(time.Millisecond * 100):
fmt.Printf("\r")
fmt.Printf(" • ")
fmt.Printf(msg, args...)
fmt.Printf(" %s", s.Next())
}
}
}()
if !isatty.IsTerminal(os.Stdout.Fd()) {
fmt.Println()
return
}

s := spin.New()

fmt.Printf(" %s", s.Next())

l.spinnerStopCh = make(chan bool)
l.spinnerMsg = msg
l.spinnerArgs = args

go func() {
for {
select {
case <-l.spinnerStopCh:
return
case <-time.After(time.Millisecond * 100):
fmt.Printf("\r")
fmt.Printf(" • ")
fmt.Printf(msg, args...)
fmt.Printf(" %s", s.Next())
}
}
}()
}

func (l *CLILogger) FinishChildSpinner() {
if l == nil || l.isSilent {
return
}

if !isatty.IsTerminal(os.Stdout.Fd()) {
fmt.Println(" • ✓")
return
}

green := color.New(color.FgHiGreen)

fmt.Printf("\r")
Expand All @@ -174,17 +185,20 @@ func (l *CLILogger) FinishChildSpinner() {
green.Printf(" ✓")
fmt.Printf(" \n")

if isatty.IsTerminal(os.Stdout.Fd()) {
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}

func (l *CLILogger) FinishSpinner() {
if l == nil || l.isSilent {
return
}

if !isatty.IsTerminal(os.Stdout.Fd()) {
fmt.Println(" • ✓")
return
}

green := color.New(color.FgHiGreen)

fmt.Printf("\r")
Expand All @@ -193,17 +207,20 @@ func (l *CLILogger) FinishSpinner() {
green.Printf(" ✓")
fmt.Printf(" \n")

if isatty.IsTerminal(os.Stdout.Fd()) {
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}

func (l *CLILogger) FinishSpinnerWithError() {
if l == nil || l.isSilent {
return
}

if !isatty.IsTerminal(os.Stdout.Fd()) {
fmt.Println(" • ✗")
return
}

red := color.New(color.FgHiRed)

fmt.Printf("\r")
Expand All @@ -212,10 +229,8 @@ func (l *CLILogger) FinishSpinnerWithError() {
red.Printf(" ✗")
fmt.Printf(" \n")

if isatty.IsTerminal(os.Stdout.Fd()) {
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}

// FinishSpinnerWithWarning if no color is provided, color.FgYellow will be used
Expand All @@ -224,6 +239,11 @@ func (l *CLILogger) FinishSpinnerWithWarning(c *color.Color) {
return
}

if !isatty.IsTerminal(os.Stdout.Fd()) {
fmt.Println(" • !")
return
}

if c == nil {
c = color.New(color.FgYellow)
}
Expand All @@ -234,10 +254,8 @@ func (l *CLILogger) FinishSpinnerWithWarning(c *color.Color) {
c.Printf(" !")
fmt.Printf(" \n")

if isatty.IsTerminal(os.Stdout.Fd()) {
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}
l.spinnerStopCh <- true
close(l.spinnerStopCh)
}

func (l *CLILogger) Error(err error) {
Expand Down

0 comments on commit 539e92c

Please sign in to comment.