From 0faeee703dff9287eeb5eb726fcb4c5bc69d0413 Mon Sep 17 00:00:00 2001 From: Gabriel Adrian Samfira Date: Wed, 27 Aug 2025 00:25:17 +0000 Subject: [PATCH] Make the debug-log command more useful The debug-log command now supports log level filtering and attribute filtering. The log level filtering will only be able to set the minimum log level as low as the server is configured to stream. If the server has its log level set as INFO, then setting the log level in the CLI to DEBUG will have no effect. But anything above what the server sends, is within the control of the client to filter. This is all done client side. Attribute filters are useful if you need to watch the logs for a particular worker, entity, etc. Signed-off-by: Gabriel Adrian Samfira --- apiserver/controllers/controllers.go | 2 +- cmd/garm-cli/cmd/log.go | 26 +- cmd/garm-cli/common/common.go | 249 ++++++++++++++++++ cmd/garm/main.go | 30 +-- util/logging.go | 64 ++++- websocket/client.go | 10 +- .../websocket}/events/events.go | 0 .../websocket}/events/params.go | 0 8 files changed, 343 insertions(+), 38 deletions(-) rename {apiserver => workers/websocket}/events/events.go (100%) rename {apiserver => workers/websocket}/events/params.go (100%) diff --git a/apiserver/controllers/controllers.go b/apiserver/controllers/controllers.go index 66aa6db9..019671eb 100644 --- a/apiserver/controllers/controllers.go +++ b/apiserver/controllers/controllers.go @@ -30,7 +30,6 @@ import ( gErrors "github.com/cloudbase/garm-provider-common/errors" "github.com/cloudbase/garm-provider-common/util" - "github.com/cloudbase/garm/apiserver/events" "github.com/cloudbase/garm/apiserver/params" "github.com/cloudbase/garm/auth" "github.com/cloudbase/garm/config" @@ -39,6 +38,7 @@ import ( "github.com/cloudbase/garm/runner" //nolint:typecheck garmUtil "github.com/cloudbase/garm/util" wsWriter "github.com/cloudbase/garm/websocket" + "github.com/cloudbase/garm/workers/websocket/events" ) func NewAPIController(r *runner.Runner, authenticator *auth.Authenticator, hub *wsWriter.Hub, apiCfg config.APIServer) (*APIController, error) { diff --git a/cmd/garm-cli/cmd/log.go b/cmd/garm-cli/cmd/log.go index e930ae69..a7d2dfba 100644 --- a/cmd/garm-cli/cmd/log.go +++ b/cmd/garm-cli/cmd/log.go @@ -16,6 +16,7 @@ package cmd import ( "context" "os/signal" + "strings" "github.com/spf13/cobra" @@ -23,7 +24,12 @@ import ( "github.com/cloudbase/garm/cmd/garm-cli/common" ) -var eventsFilters string +var ( + eventsFilters string + logLevel string + filters []string + enableColor bool +) var logCmd = &cobra.Command{ Use: "debug-log", @@ -34,7 +40,19 @@ var logCmd = &cobra.Command{ ctx, stop := signal.NotifyContext(context.Background(), signals...) defer stop() - reader, err := garmWs.NewReader(ctx, mgr.BaseURL, "/api/v1/ws/logs", mgr.Token, common.PrintWebsocketMessage) + // Parse filters into map + attributeFilters := make(map[string]string) + for _, filter := range filters { + parts := strings.SplitN(filter, "=", 2) + if len(parts) == 2 { + attributeFilters[parts[0]] = parts[1] + } + } + + // Create log formatter with filters + logFormatter := common.NewLogFormatter(logLevel, attributeFilters, enableColor) + + reader, err := garmWs.NewReader(ctx, mgr.BaseURL, "/api/v1/ws/logs", mgr.Token, logFormatter.FormatWebsocketMessage) if err != nil { return err } @@ -49,5 +67,9 @@ var logCmd = &cobra.Command{ } func init() { + logCmd.Flags().StringVar(&logLevel, "log-level", "", "Minimum log level to display (DEBUG, INFO, WARN, ERROR)") + logCmd.Flags().StringArrayVar(&filters, "filter", []string{}, "Filter logs by attribute (format: key=value) or message content (msg=text). You can specify this option multiple times. The filter will return true for any of the attributes you set.") + logCmd.Flags().BoolVar(&enableColor, "enable-color", true, "Enable color logging (auto-detects terminal support)") + rootCmd.AddCommand(logCmd) } diff --git a/cmd/garm-cli/common/common.go b/cmd/garm-cli/common/common.go index 08189d21..1f607cb4 100644 --- a/cmd/garm-cli/common/common.go +++ b/cmd/garm-cli/common/common.go @@ -15,8 +15,14 @@ package common import ( + "encoding/json" "errors" "fmt" + "os" + "runtime" + "sort" + "strings" + "time" "github.com/manifoldco/promptui" "github.com/nbutton23/zxcvbn-go" @@ -74,3 +80,246 @@ func PrintWebsocketMessage(_ int, msg []byte) error { fmt.Println(util.SanitizeLogEntry(string(msg))) return nil } + +type LogFormatter struct { + MinLevel string + AttributeFilters map[string]string + EnableColor bool +} + +type LogRecord struct { + Time string `json:"time"` + Level string `json:"level"` + Msg string `json:"msg"` + Attrs map[string]interface{} `json:",inline"` +} + +// Color codes for different log levels +const ( + ColorReset = "\033[0m" + ColorRed = "\033[31m" + ColorYellow = "\033[33m" + ColorBlue = "\033[34m" + ColorMagenta = "\033[35m" + ColorCyan = "\033[36m" + ColorWhite = "\033[37m" + ColorGray = "\033[90m" +) + +func (lf *LogFormatter) colorizeLevel(level string) string { + if !lf.EnableColor { + return level + } + + levelUpper := strings.TrimSpace(strings.ToUpper(level)) + switch levelUpper { + case "ERROR": + return ColorRed + level + ColorReset + case "WARN", "WARNING": + return ColorYellow + level + ColorReset + case "INFO": + return ColorBlue + level + ColorReset + case "DEBUG": + return ColorMagenta + level + ColorReset + default: + return level + } +} + +func (lf *LogFormatter) shouldFilterLevel(level string) bool { + if lf.MinLevel == "" { + return false + } + + levelMap := map[string]int{ + "DEBUG": 0, + "INFO": 1, + "WARN": 2, + "ERROR": 3, + } + + minLevelNum, exists := levelMap[strings.ToUpper(lf.MinLevel)] + if !exists { + return false + } + + currentLevelNum, exists := levelMap[strings.ToUpper(level)] + if !exists { + return false + } + + return currentLevelNum < minLevelNum +} + +func (lf *LogFormatter) matchesAttributeFilters(attrs map[string]interface{}, msg string) bool { + if len(lf.AttributeFilters) == 0 { + return true + } + + for key, expectedValue := range lf.AttributeFilters { + // Special handling for message filtering + if key == "msg" { + if strings.Contains(msg, expectedValue) { + return true + } + } + + // Regular attribute filtering + actualValue, exists := attrs[key] + if exists { + actualStr := fmt.Sprintf("%v", actualValue) + if actualStr == expectedValue { + return true + } + } + } + + return false +} + +func (lf *LogFormatter) FormatWebsocketMessage(_ int, msg []byte) error { + // Try to parse as JSON log record + var logRecord LogRecord + err := json.Unmarshal(msg, &logRecord) + if err != nil { + // If it's not JSON, print as-is (sanitized) + _, err = fmt.Println(util.SanitizeLogEntry(string(msg))) + return err + } + + // Apply level filtering + if lf.shouldFilterLevel(logRecord.Level) { + return nil + } + + // Parse additional attributes from the JSON + var fullRecord map[string]interface{} + if err := json.Unmarshal(msg, &fullRecord); err == nil { + // Remove standard fields and keep only attributes + delete(fullRecord, "time") + delete(fullRecord, "level") + delete(fullRecord, "msg") + logRecord.Attrs = fullRecord + } + + // Apply attribute filtering + if !lf.matchesAttributeFilters(logRecord.Attrs, logRecord.Msg) { + return nil + } + + // Format timestamp to fixed width + timeStr := logRecord.Time + if t, err := time.Parse(time.RFC3339Nano, logRecord.Time); err == nil { + timeStr = t.Format("2006-01-02 15:04:05.000") + } + + // Format log level to fixed width (5 characters) + levelStr := lf.colorizeLevel(fmt.Sprintf("%-5s", strings.ToUpper(logRecord.Level))) + + // Highlight message if it matches a msg filter + msgStr := logRecord.Msg + if msgFilter, hasMsgFilter := lf.AttributeFilters["msg"]; hasMsgFilter { + if strings.Contains(msgStr, msgFilter) && lf.EnableColor { + msgStr = ColorYellow + msgStr + ColorReset + } + } + + output := fmt.Sprintf("%s [%s] %s", timeStr, levelStr, msgStr) + + // Add attributes if any + if len(logRecord.Attrs) > 0 { + // Get sorted keys for consistent output + var keys []string + for k := range logRecord.Attrs { + keys = append(keys, k) + } + sort.Strings(keys) + + var attrPairs []string + for _, k := range keys { + v := logRecord.Attrs[k] + attrStr := fmt.Sprintf("%s=%v", k, v) + + // Highlight filtered attributes + if filterValue, isFiltered := lf.AttributeFilters[k]; isFiltered && fmt.Sprintf("%v", v) == filterValue { + if lf.EnableColor { + attrStr = ColorYellow + attrStr + ColorGray + } + } else if lf.EnableColor { + attrStr = ColorGray + attrStr + } + + attrPairs = append(attrPairs, attrStr) + } + if len(attrPairs) > 0 { + if lf.EnableColor { + output += " " + strings.Join(attrPairs, " ") + ColorReset + } else { + output += " " + strings.Join(attrPairs, " ") + } + } + } + + fmt.Println(output) + return nil +} + +// supportsColor checks if the current terminal/environment supports ANSI colors. +// This is best effort. There is no reliable way to determine if a terminal supports +// color. Set NO_COLOR=1 to disable color if your terminal doesn't support it, but this +// function returns true. +func supportsColor() bool { + // Check NO_COLOR environment variable (universal standard) + if os.Getenv("NO_COLOR") != "" { + return false + } + + // Check FORCE_COLOR environment variable + if os.Getenv("FORCE_COLOR") != "" { + return true + } + + // On Windows, check for modern terminal support + if runtime.GOOS == "windows" { + // Check for Windows Terminal + if os.Getenv("WT_SESSION") != "" { + return true + } + // Check for ConEmu + if os.Getenv("ConEmuANSI") == "ON" { + return true + } + // Check for other modern terminals + term := os.Getenv("TERM") + if strings.Contains(term, "color") || term == "xterm-256color" || term == "screen-256color" { + return true + } + // Modern PowerShell and cmd.exe with VT processing + if os.Getenv("TERM_PROGRAM") != "" { + return true + } + // Default to false for older Windows cmd.exe + return false + } + + // On Unix-like systems, check TERM + term := os.Getenv("TERM") + if term == "" || term == "dumb" { + return false + } + + return true +} + +func NewLogFormatter(minLevel string, attributeFilters map[string]string, color bool) *LogFormatter { + var enableColor bool + if color && supportsColor() { + enableColor = true + } + + return &LogFormatter{ + MinLevel: minLevel, + AttributeFilters: attributeFilters, + EnableColor: enableColor, + } +} diff --git a/cmd/garm/main.go b/cmd/garm/main.go index 28879322..cba3a064 100644 --- a/cmd/garm/main.go +++ b/cmd/garm/main.go @@ -18,7 +18,6 @@ import ( "context" "flag" "fmt" - "io" "log" "log/slog" "net" @@ -104,16 +103,6 @@ func setupLogging(ctx context.Context, logCfg config.Logging, hub *websocket.Hub } }() - writers := []io.Writer{ - logWriter, - } - - if hub != nil { - writers = append(writers, hub) - } - - wr := io.MultiWriter(writers...) - var logLevel slog.Level switch logCfg.LogLevel { case config.LevelDebug: @@ -134,16 +123,25 @@ func setupLogging(ctx context.Context, logCfg config.Logging, hub *websocket.Hub Level: logLevel, } - var han slog.Handler + var fileHan slog.Handler switch logCfg.LogFormat { case config.FormatJSON: - han = slog.NewJSONHandler(wr, &opts) + fileHan = slog.NewJSONHandler(logWriter, &opts) default: - han = slog.NewTextHandler(wr, &opts) + fileHan = slog.NewTextHandler(logWriter, &opts) } - wrapped := garmUtil.ContextHandler{ - Handler: han, + handlers := []slog.Handler{ + fileHan, + } + + if hub != nil { + wsHan := slog.NewJSONHandler(hub, &opts) + handlers = append(handlers, wsHan) + } + + wrapped := &garmUtil.SlogMultiHandler{ + Handlers: handlers, } slog.SetDefault(slog.New(wrapped)) } diff --git a/util/logging.go b/util/logging.go index 4c37ed34..99c69da7 100644 --- a/util/logging.go +++ b/util/logging.go @@ -25,20 +25,58 @@ const ( slogCtxFields slogContextKey = "slog_ctx_fields" ) -type ContextHandler struct { - slog.Handler -} - -func (h ContextHandler) Handle(ctx context.Context, r slog.Record) error { - attrs, ok := ctx.Value(slogCtxFields).([]slog.Attr) - if ok { - for _, v := range attrs { - r.AddAttrs(v) - } - } - return h.Handler.Handle(ctx, r) -} +var _ slog.Handler = &SlogMultiHandler{} func WithSlogContext(ctx context.Context, attrs ...slog.Attr) context.Context { return context.WithValue(ctx, slogCtxFields, attrs) } + +type SlogMultiHandler struct { + Handlers []slog.Handler +} + +func (m *SlogMultiHandler) Enabled(ctx context.Context, level slog.Level) bool { + // Enabled if any handler is enabled + for _, h := range m.Handlers { + if h.Enabled(ctx, level) { + return true + } + } + return false +} + +func (m *SlogMultiHandler) Handle(ctx context.Context, r slog.Record) error { + record := r.Clone() + attrs, ok := ctx.Value(slogCtxFields).([]slog.Attr) + if ok { + for _, v := range attrs { + record.AddAttrs(v) + } + } + + var firstErr error + for _, h := range m.Handlers { + if err := h.Handle(ctx, record); err != nil && firstErr == nil { + firstErr = err + } + } + return firstErr +} + +func (m *SlogMultiHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + hs := make([]slog.Handler, len(m.Handlers)) + for i, h := range m.Handlers { + hs[i] = h.WithAttrs(attrs) + } + return &SlogMultiHandler{ + Handlers: hs, + } +} + +func (m *SlogMultiHandler) WithGroup(name string) slog.Handler { + hs := make([]slog.Handler, len(m.Handlers)) + for i, h := range m.Handlers { + hs[i] = h.WithGroup(name) + } + return &SlogMultiHandler{hs} +} diff --git a/websocket/client.go b/websocket/client.go index 820e49ce..be3b5bc0 100644 --- a/websocket/client.go +++ b/websocket/client.go @@ -143,20 +143,18 @@ func (c *Client) Write(msg []byte) (int, error) { defer c.mux.Unlock() if !c.running { - return 0, fmt.Errorf("client is stopped") + return 0, fmt.Errorf("websocket client is stopped") } tmp := make([]byte, len(msg)) copy(tmp, msg) - timer := time.NewTimer(5 * time.Second) - defer timer.Stop() select { - case <-timer.C: - return 0, fmt.Errorf("timed out sending message to client") case c.send <- tmp: + return len(tmp), nil + default: + return 0, fmt.Errorf("timed out sending message to websocket client") } - return len(tmp), nil } // clientReader waits for options changes from the client. The client can at any time diff --git a/apiserver/events/events.go b/workers/websocket/events/events.go similarity index 100% rename from apiserver/events/events.go rename to workers/websocket/events/events.go diff --git a/apiserver/events/params.go b/workers/websocket/events/params.go similarity index 100% rename from apiserver/events/params.go rename to workers/websocket/events/params.go