feat: add log level for better debugging

This commit is contained in:
Jonas Kaninda
2024-11-10 19:58:53 +01:00
parent 0d406e3256
commit bbaf47fa0c
13 changed files with 96 additions and 42 deletions

View File

@@ -41,6 +41,7 @@ var ServerCmd = &cobra.Command{
if err != nil { if err != nil {
logger.Fatal("Could not load configuration: %v", err) logger.Fatal("Could not load configuration: %v", err)
} }
gs.SetEnv()
if err := gs.Start(ctx); err != nil { if err := gs.Start(ctx); err != nil {
logger.Fatal("Could not start server: %v", err) logger.Fatal("Could not start server: %v", err)

View File

@@ -16,9 +16,10 @@ gateway:
readTimeout: 15 readTimeout: 15
idleTimeout: 30 idleTimeout: 30
# Rate limiting # Rate limiting
rateLimiter: 0 rateLimit: 0
accessLog: /dev/Stdout accessLog: /dev/Stdout
errorLog: /dev/stderr errorLog: /dev/stderr
logLevel: info
disableRouteHealthCheckError: false disableRouteHealthCheckError: false
disableDisplayRouteOnStart: false disableDisplayRouteOnStart: false
disableKeepAlive: false disableKeepAlive: false

View File

@@ -0,0 +1,30 @@
---
title: General troubleshooting steps
layout: default
parent: Quickstart
nav_order: 6
---
# Logging
### Set the log level to TRACE
Setting the log level to trace configures the server to trace-log all the headers given in forward auth requests.
This is helpful to confirm that certain required Headers are correctly forwarded from the reverse proxy.
### When using the environment variable
Set the Goma log level to TRACE:
Add the following block to your .env file:
```shell
GOMA_LOG_LEVEL=trace
```
### When using a configuration file
Edit the Goma settings and set `logLevel: trace`.

View File

@@ -2,7 +2,7 @@
title: SSL Certificate title: SSL Certificate
layout: default layout: default
parent: Quickstart parent: Quickstart
nav_order: 4 nav_order: 5
--- ---

View File

@@ -102,9 +102,19 @@ func (GatewayServer) Config(configFile string) (*GatewayServer, error) {
middlewares: c.Middlewares, middlewares: c.Middlewares,
}, nil }, nil
} }
func GetConfigPaths() string {
return util.GetStringEnv("GOMAY_CONFIG_FILE", ConfigFile) // SetEnv sets environment variables
func (gatewayServer GatewayServer) SetEnv() {
util.SetEnv("GOMA_LOG_LEVEL", gatewayServer.gateway.LogLevel)
util.SetEnv("GOMA_ERROR_LOG", gatewayServer.gateway.ErrorLog)
util.SetEnv("GOMA_ACCESS_LOG", gatewayServer.gateway.AccessLog)
} }
func GetConfigPaths() string {
return util.GetStringEnv("GOMA_CONFIG_FILE", ConfigFile)
}
// InitConfig initializes configs
func InitConfig(cmd *cobra.Command) { func InitConfig(cmd *cobra.Command) {
configFile, _ := cmd.Flags().GetString("output") configFile, _ := cmd.Flags().GetString("output")
if configFile == "" { if configFile == "" {
@@ -114,6 +124,8 @@ func InitConfig(cmd *cobra.Command) {
return return
} }
// initConfig initializes configs
func initConfig(configFile string) { func initConfig(configFile string) {
if configFile == "" { if configFile == "" {
configFile = GetConfigPaths() configFile = GetConfigPaths()

View File

@@ -65,7 +65,7 @@ func ProxyErrorHandler(w http.ResponseWriter, r *http.Request, err error) {
// HealthCheckHandler handles health check of routes // HealthCheckHandler handles health check of routes
func (heathRoute HealthCheckRoute) HealthCheckHandler(w http.ResponseWriter, r *http.Request) { func (heathRoute HealthCheckRoute) HealthCheckHandler(w http.ResponseWriter, r *http.Request) {
logger.Info("%s %s %s %s", r.Method, r.RemoteAddr, r.URL, r.UserAgent()) logger.Debug("%s %s %s %s", r.Method, r.RemoteAddr, r.URL, r.UserAgent())
wg := sync.WaitGroup{} wg := sync.WaitGroup{}
wg.Add(len(heathRoute.Routes)) wg.Add(len(heathRoute.Routes))
var routes []HealthCheckRouteResponse var routes []HealthCheckRouteResponse
@@ -80,11 +80,11 @@ func (heathRoute HealthCheckRoute) HealthCheckHandler(w http.ResponseWriter, r *
} }
routes = append(routes, HealthCheckRouteResponse{Name: route.Name, Status: "unhealthy", Error: "Error: " + err.Error()}) routes = append(routes, HealthCheckRouteResponse{Name: route.Name, Status: "unhealthy", Error: "Error: " + err.Error()})
} else { } else {
logger.Info("Route %s is healthy", route.Name) logger.Debug("Route %s is healthy", route.Name)
routes = append(routes, HealthCheckRouteResponse{Name: route.Name, Status: "healthy", Error: ""}) routes = append(routes, HealthCheckRouteResponse{Name: route.Name, Status: "healthy", Error: ""})
} }
} else { } else {
logger.Warn("Route %s's healthCheck is undefined", route.Name) logger.Debug("Route %s's healthCheck is undefined", route.Name)
routes = append(routes, HealthCheckRouteResponse{Name: route.Name, Status: "undefined", Error: ""}) routes = append(routes, HealthCheckRouteResponse{Name: route.Name, Status: "undefined", Error: ""})
} }
}() }()

View File

@@ -46,7 +46,7 @@ func (intercept InterceptErrors) ErrorInterceptor(next http.Handler) http.Handle
rec := newResponseRecorder(w) rec := newResponseRecorder(w)
next.ServeHTTP(rec, r) next.ServeHTTP(rec, r)
if canIntercept(rec.statusCode, intercept.Errors) { if canIntercept(rec.statusCode, intercept.Errors) {
logger.Error("Backend error") logger.Debug("Backend error")
logger.Error("An error occurred from the backend with the status code: %d", rec.statusCode) logger.Error("An error occurred from the backend with the status code: %d", rec.statusCode)
w.Header().Set("Content-Type", "application/json") w.Header().Set("Content-Type", "application/json")
//Update Origin Cors Headers //Update Origin Cors Headers

View File

@@ -82,6 +82,7 @@ func (jwtAuth JwtAuth) AuthMiddleware(next http.Handler) http.Handler {
} }
return return
} }
logger.Trace("JWT Auth response headers: %v", authReq.Header)
// Copy headers from the original request to the new request // Copy headers from the original request to the new request
for name, values := range r.Header { for name, values := range r.Header {
for _, value := range values { for _, value := range values {
@@ -96,8 +97,8 @@ func (jwtAuth JwtAuth) AuthMiddleware(next http.Handler) http.Handler {
client := &http.Client{} client := &http.Client{}
authResp, err := client.Do(authReq) authResp, err := client.Do(authReq)
if err != nil || authResp.StatusCode != http.StatusOK { if err != nil || authResp.StatusCode != http.StatusOK {
logger.Info("%s %s %s %s", r.Method, getRealIP(r), r.URL, r.UserAgent()) logger.Debug("%s %s %s %s", r.Method, getRealIP(r), r.URL, r.UserAgent())
logger.Warn("Proxy authentication error") logger.Debug("Proxy authentication error")
w.Header().Set("Content-Type", "application/json") w.Header().Set("Content-Type", "application/json")
w.WriteHeader(http.StatusUnauthorized) w.WriteHeader(http.StatusUnauthorized)
err = json.NewEncoder(w).Encode(ProxyResponseError{ err = json.NewEncoder(w).Encode(ProxyResponseError{
@@ -139,10 +140,11 @@ func (jwtAuth JwtAuth) AuthMiddleware(next http.Handler) http.Handler {
// AuthMiddleware checks for the Authorization header and verifies the credentials // AuthMiddleware checks for the Authorization header and verifies the credentials
func (basicAuth AuthBasic) AuthMiddleware(next http.Handler) http.Handler { func (basicAuth AuthBasic) AuthMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
logger.Trace("Basic-Auth request headers: %v", r.Header)
// Get the Authorization header // Get the Authorization header
authHeader := r.Header.Get("Authorization") authHeader := r.Header.Get("Authorization")
if authHeader == "" { if authHeader == "" {
logger.Error("Proxy error, missing Authorization header") logger.Debug("Proxy error, missing Authorization header")
w.Header().Set("WWW-Authenticate", `Basic realm="Restricted"`) w.Header().Set("WWW-Authenticate", `Basic realm="Restricted"`)
w.Header().Set("Content-Type", "application/json") w.Header().Set("Content-Type", "application/json")
w.WriteHeader(http.StatusUnauthorized) w.WriteHeader(http.StatusUnauthorized)
@@ -175,7 +177,7 @@ func (basicAuth AuthBasic) AuthMiddleware(next http.Handler) http.Handler {
// Decode the base64 encoded username:password string // Decode the base64 encoded username:password string
payload, err := base64.StdEncoding.DecodeString(authHeader[len("Basic "):]) payload, err := base64.StdEncoding.DecodeString(authHeader[len("Basic "):])
if err != nil { if err != nil {
logger.Error("Proxy error, missing Basic Authorization header") logger.Debug("Proxy error, missing Basic Authorization header")
w.Header().Set("Content-Type", "application/json") w.Header().Set("Content-Type", "application/json")
w.WriteHeader(http.StatusUnauthorized) w.WriteHeader(http.StatusUnauthorized)
err := json.NewEncoder(w).Encode(ProxyResponseError{ err := json.NewEncoder(w).Encode(ProxyResponseError{

View File

@@ -66,7 +66,7 @@ func (rl *RateLimiter) RateLimitMiddleware() mux.MiddlewareFunc {
rl.mu.Unlock() rl.mu.Unlock()
if client.RequestCount > rl.Requests { if client.RequestCount > rl.Requests {
logger.Error("Too many requests from IP: %s %s %s", clientID, r.URL, r.UserAgent()) logger.Debug("Too many requests from IP: %s %s %s", clientID, r.URL, r.UserAgent())
w.Header().Set("Content-Type", "application/json") w.Header().Set("Content-Type", "application/json")
w.WriteHeader(http.StatusTooManyRequests) w.WriteHeader(http.StatusTooManyRequests)
//Update Origin Cors Headers //Update Origin Cors Headers

View File

@@ -30,6 +30,8 @@ import (
func (proxyRoute ProxyRoute) ProxyHandler() http.HandlerFunc { func (proxyRoute ProxyRoute) ProxyHandler() http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) {
logger.Info("%s %s %s %s", r.Method, getRealIP(r), r.URL.Path, r.UserAgent()) logger.Info("%s %s %s %s", r.Method, getRealIP(r), r.URL.Path, r.UserAgent())
logger.Trace("Request params: %s", r.URL.RawQuery)
logger.Trace("Request Headers: %s", r.Header)
// Check Method if is allowed // Check Method if is allowed
if len(proxyRoute.methods) > 0 { if len(proxyRoute.methods) > 0 {
if !slices.Contains(proxyRoute.methods, r.Method) { if !slices.Contains(proxyRoute.methods, r.Method) {

View File

@@ -188,6 +188,7 @@ type Gateway struct {
BlockCommonExploits bool `yaml:"blockCommonExploits"` BlockCommonExploits bool `yaml:"blockCommonExploits"`
AccessLog string `yaml:"accessLog" env:"GOMA_ACCESS_LOG, overwrite"` AccessLog string `yaml:"accessLog" env:"GOMA_ACCESS_LOG, overwrite"`
ErrorLog string `yaml:"errorLog" env:"GOMA_ERROR_LOG=, overwrite"` ErrorLog string `yaml:"errorLog" env:"GOMA_ERROR_LOG=, overwrite"`
LogLevel string `yaml:"logLevel" env:"GOMA_LOG_LEVEL, overwrite"`
// DisableHealthCheckStatus enable and disable routes health check // DisableHealthCheckStatus enable and disable routes health check
DisableHealthCheckStatus bool `yaml:"disableHealthCheckStatus"` DisableHealthCheckStatus bool `yaml:"disableHealthCheckStatus"`
// DisableRouteHealthCheckError allows enabling and disabling backend healthcheck errors // DisableRouteHealthCheckError allows enabling and disabling backend healthcheck errors

View File

@@ -33,23 +33,15 @@ type Logger struct {
// Info returns info log // Info returns info log
func Info(msg string, args ...interface{}) { func Info(msg string, args ...interface{}) {
log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout"))) log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout")))
formattedMessage := fmt.Sprintf(msg, args...) logWithCaller("INFO", msg, args...)
if len(args) == 0 {
log.Printf("INFO: %s\n", msg)
} else {
log.Printf("INFO: %s\n", formattedMessage)
}
} }
// Warn returns warning log // Warn returns warning log
func Warn(msg string, args ...interface{}) { func Warn(msg string, args ...interface{}) {
log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout"))) log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout")))
formattedMessage := fmt.Sprintf(msg, args...) logWithCaller("WARN", msg, args...)
if len(args) == 0 {
log.Printf("WARN: %s\n", msg)
} else {
log.Printf("WARN: %s\n", formattedMessage)
}
} }
// Error logs error messages // Error logs error messages
@@ -60,36 +52,47 @@ func Error(msg string, args ...interface{}) {
func Fatal(msg string, args ...interface{}) { func Fatal(msg string, args ...interface{}) {
log.SetOutput(os.Stdout) log.SetOutput(os.Stdout)
formattedMessage := fmt.Sprintf(msg, args...) logWithCaller("ERROR", msg, args...)
if len(args) == 0 {
log.Printf("ERROR: %s\n", msg)
} else {
log.Printf("ERROR: %s\n", formattedMessage)
}
os.Exit(1) os.Exit(1)
} }
func Debug(msg string, args ...interface{}) { func Debug(msg string, args ...interface{}) {
log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout"))) log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout")))
logWithCaller("DEBUG", msg, args...) logLevel := util.GetStringEnv("GOMA_LOG_LEVEL", "")
if logLevel == "trace" || logLevel == "debug" {
logWithCaller("DEBUG", msg, args...)
}
}
func Trace(msg string, args ...interface{}) {
log.SetOutput(getStd(util.GetStringEnv("GOMA_ACCESS_LOG", "/dev/stdout")))
logLevel := util.GetStringEnv("GOMA_LOG_LEVEL", "")
if logLevel == "trace" {
logWithCaller("DEBUG", msg, args...)
}
} }
// Helper function to format and log messages with file and line number // Helper function to format and log messages with file and line number
func logWithCaller(level, msg string, args ...interface{}) { func logWithCaller(level, msg string, args ...interface{}) {
formattedMessage := fmt.Sprintf(msg, args...) // Format message if there are additional arguments
_, file, line, ok := runtime.Caller(2) // Get the caller's file and line number (skip 2 frames) formattedMessage := msg
if len(args) > 0 {
formattedMessage = fmt.Sprintf(msg, args...)
}
// Get the caller's file and line number (skip 2 frames)
_, file, line, ok := runtime.Caller(2)
if !ok { if !ok {
file = "unknown" file = "unknown"
line = 0 line = 0
} }
// Log message with caller information if GOMA_LOG_LEVEL is trace
if len(args) == 0 { logLevel := util.GetStringEnv("GOMA_LOG_LEVEL", "")
log.Printf("%s: %s (File: %s, Line: %d)\n", level, msg, file, line) if logLevel == "trace" {
} else {
log.Printf("%s: %s (File: %s, Line: %d)\n", level, formattedMessage, file, line) log.Printf("%s: %s (File: %s, Line: %d)\n", level, formattedMessage, file, line)
} else {
log.Printf("%s: %s\n", level, formattedMessage)
} }
} }

View File

@@ -73,9 +73,11 @@ func GetBoolEnv(key string, defaultValue bool) bool {
// SetEnv Set env // SetEnv Set env
func SetEnv(name, value string) { func SetEnv(name, value string) {
err := os.Setenv(name, value) if len(value) != 0 {
if err != nil { err := os.Setenv(name, value)
return if err != nil {
return
}
} }
} }