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