[shell-operator] Replace Logrus with slog (#671)

Signed-off-by: Pavel Okhlopkov <pavel.okhlopkov@flant.com>
Co-authored-by: Pavel Okhlopkov <pavel.okhlopkov@flant.com>

.github/workflows/lint.yaml

@@ -36,7 +36,7 @@ jobs:
 
       - name: Run golangci-lint
         run: |
-          curl -sSfL https://raw.githubusercontent.com/golangci/golangci-lint/master/install.sh | sh -s -- -b . v1.59.1
+          curl -sSfL https://raw.githubusercontent.com/golangci/golangci-lint/master/install.sh | sh -s -- -b . v1.60.1
           ./golangci-lint run --sort-results --build-tags integration,test
 
 

.golangci.yaml

@@ -1,7 +1,5 @@
 run:
   timeout: 15m
-  skip-dirs:
-  - test/integration
 linters:
   disable-all: true
   enable:
@@ -24,6 +22,7 @@ linters:
     - nolintlint
     - prealloc
     - revive
+    - sloglint
     - staticcheck
     - stylecheck
     - unconvert
@@ -39,6 +38,33 @@ linters-settings:
     local-prefixes: github.com/flant/
   nolintlint:
     allow-unused: true
+  sloglint:
+      # Enforce not mixing key-value pairs and attributes.
+      no-mixed-args: true
+      # Enforce using key-value pairs only (overrides no-mixed-args, incompatible with attr-only).
+      kv-only: false
+      # Enforce using attributes only (overrides no-mixed-args, incompatible with kv-only).
+      attr-only: false
+      # Enforce not using global loggers.
+      no-global: ""
+      # Enforce using methods that accept a context.
+      context: ""
+      # Enforce using static values for log messages.
+      static-msg: false
+      # Enforce using constants instead of raw keys.
+      no-raw-keys: false
+      # Enforce a single key naming convention.
+      key-naming-case: ""
+      # Enforce not using specific keys.
+      forbidden-keys:
+        - level
+        - msg
+        - logger
+        - source
+        - stacktrace
+        - time
+      # Enforce putting arguments on separate lines.
+      args-on-sep-lines: false
   depguard:
     rules:
       Main:
@@ -48,6 +74,8 @@ linters-settings:
           - pkg: "gopkg.in/satori/go.uuid.v1"
             desc: "Use https://github.com/gofrs/uuid instead. Satori/go.uuid is no longer maintained and has critical vulnerabilities."
 issues:
+  exclude-dirs:
+    - test/integration
   exclude:
     # Using underscores is a common practice, refactor in the future
     - "var-naming: don't use an underscore in package name" # revive

cmd/shell-operator/main.go

@@ -2,13 +2,12 @@ package main
 
 import (
 	"fmt"
-	"math/rand"
 	"os"
-	"time"
 
+	"github.com/deckhouse/deckhouse/pkg/log"
 	"gopkg.in/alecthomas/kingpin.v2"
 
-	"github.com/flant/kube-client/klogtologrus"
+	"github.com/flant/kube-client/klogtolog"
 	"github.com/flant/shell-operator/pkg/app"
 	"github.com/flant/shell-operator/pkg/debug"
 	"github.com/flant/shell-operator/pkg/jq"
@@ -19,17 +18,20 @@ import (
 func main() {
 	kpApp := kingpin.New(app.AppName, fmt.Sprintf("%s %s: %s", app.AppName, app.Version, app.AppDescription))
 
+	logger := log.NewLogger(log.Options{})
+	log.SetDefault(logger)
+
 	// override usage template to reveal additional commands with information about start command
 	kpApp.UsageTemplate(app.OperatorUsageTemplate(app.AppName))
 
 	// Initialize klog wrapper when all values are parsed
-	kpApp.Action(func(c *kingpin.ParseContext) error {
-		klogtologrus.InitAdapter(app.DebugKubernetesAPI)
+	kpApp.Action(func(_ *kingpin.ParseContext) error {
+		klogtolog.InitAdapter(app.DebugKubernetesAPI, logger.Named("klog"))
 		return nil
 	})
 
 	// print version
-	kpApp.Command("version", "Show version.").Action(func(c *kingpin.ParseContext) error {
+	kpApp.Command("version", "Show version.").Action(func(_ *kingpin.ParseContext) error {
 		fmt.Printf("%s %s\n", app.AppName, app.Version)
 		fmt.Println(jq.FilterInfo())
 		return nil
@@ -38,14 +40,11 @@ func main() {
 	// start main loop
 	startCmd := kpApp.Command("start", "Start shell-operator.").
 		Default().
-		Action(func(c *kingpin.ParseContext) error {
+		Action(func(_ *kingpin.ParseContext) error {
 			app.AppStartMessage = fmt.Sprintf("%s %s", app.AppName, app.Version)
 
-			// Init rand generator.
-			rand.Seed(time.Now().UnixNano())
-
 			// Init logging and initialize a ShellOperator instance.
-			operator, err := shell_operator.Init()
+			operator, err := shell_operator.Init(logger.Named("shell-operator"))
 			if err != nil {
 				os.Exit(1)
 			}

go.mod

@@ -1,9 +1,10 @@
 module github.com/flant/shell-operator
 
-go 1.22
+go 1.22.8
 
 require (
-	github.com/flant/kube-client v1.2.0
+	github.com/deckhouse/deckhouse/pkg/log v0.0.0-20241102120041-7e44e3e22ab9
+	github.com/flant/kube-client v1.2.1
 	github.com/flant/libjq-go v1.6.3-0.20201126171326-c46a40ff22ee // branch: master
 	github.com/go-chi/chi/v5 v5.1.0
 	github.com/go-openapi/spec v0.19.8
@@ -17,7 +18,6 @@ require (
 	github.com/onsi/gomega v1.34.2
 	github.com/pkg/errors v0.9.1
 	github.com/prometheus/client_golang v1.20.5
-	github.com/sirupsen/logrus v1.9.3
 	github.com/stretchr/testify v1.9.0
 	golang.org/x/time v0.7.0
 	gopkg.in/alecthomas/kingpin.v2 v2.2.6
@@ -36,6 +36,7 @@ replace github.com/go-openapi/validate => github.com/flant/go-openapi-validate v
 require github.com/gojuno/minimock/v3 v3.4.0
 
 require (
+	github.com/DataDog/gostackparse v0.7.0 // indirect
 	github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751 // indirect
 	github.com/alecthomas/units v0.0.0-20211218093645-b94a6e3cc137 // indirect
 	github.com/asaskevich/govalidator v0.0.0-20200428143746-21a406dcc535 // indirect

go.sum

@@ -1,4 +1,6 @@
 github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU=
+github.com/DataDog/gostackparse v0.7.0 h1:i7dLkXHvYzHV308hnkvVGDL3BR4FWl7IsXNPz/IGQh4=
+github.com/DataDog/gostackparse v0.7.0/go.mod h1:lTfqcJKqS9KnXQGnyQMCugq3u1FP6UZMfWR0aitKFMM=
 github.com/PuerkitoBio/purell v1.1.0/go.mod h1:c11w/QuzBsJSee3cPx9rAFu61PvFxuPbtSwDGJws/X0=
 github.com/PuerkitoBio/purell v1.1.1/go.mod h1:c11w/QuzBsJSee3cPx9rAFu61PvFxuPbtSwDGJws/X0=
 github.com/PuerkitoBio/urlesc v0.0.0-20170810143723-de5bf2ad4578/go.mod h1:uGdkoq3SwY9Y+13GIhn11/XLaGBb4BfwItxLd5jeuXE=
@@ -22,15 +24,17 @@ github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ3
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/deckhouse/deckhouse/pkg/log v0.0.0-20241102120041-7e44e3e22ab9 h1:gCV1iKcaE69x3Knzj8isyVyEtRuG2YI4nmLIzBHBWeQ=
+github.com/deckhouse/deckhouse/pkg/log v0.0.0-20241102120041-7e44e3e22ab9/go.mod h1:Mk5HRzkc5pIcDIZ2JJ6DPuuqnwhXVkb3you8M8Mg+4w=
 github.com/docker/go-units v0.4.0/go.mod h1:fgPhTUdO+D/Jk86RDLlptpiXQzgHJF7gydDDbaIK4Dk=
 github.com/emicklei/go-restful/v3 v3.11.0 h1:rAQeMHw1c7zTmncogyy8VvRZwtkmkZ4FxERmMY4rD+g=
 github.com/emicklei/go-restful/v3 v3.11.0/go.mod h1:6n3XBCmQQb25CM2LCACGz8ukIrRry+4bhvbpWn3mrbc=
 github.com/evanphx/json-patch v5.6.0+incompatible h1:jBYDEEiFBPxA0v50tFdvOzQQTCvpL6mnFh5mB2/l16U=
 github.com/evanphx/json-patch v5.6.0+incompatible/go.mod h1:50XU6AFN0ol/bzJsmQLiYLvXMP4fmwYFNcr97nuDLSk=
 github.com/flant/go-openapi-validate v0.19.12-flant.0 h1:xk6kvc9fHKMgUdB6J7kbpbLR5vJOUzKAK8p3nrD7mDk=
 github.com/flant/go-openapi-validate v0.19.12-flant.0/go.mod h1:Rzou8hA/CBw8donlS6WNEUQupNvUZ0waH08tGe6kAQ4=
-github.com/flant/kube-client v1.2.0 h1:cOjnZgwoJVm4scqsMGcgO6qctJ+Z6wRVTFqvyhoAOiQ=
-github.com/flant/kube-client v1.2.0/go.mod h1:qjNvqCqnBqS+kc9Hj+wMBbkFzfdyGyiX4r4teE/0Pm8=
+github.com/flant/kube-client v1.2.1 h1:8lHF8+wGZrhsXM6TeS3CNAPupXyx7UJLkBvNMpCe/ZI=
+github.com/flant/kube-client v1.2.1/go.mod h1:62vCzrIUzWMU4DB0Pn6/02Pu7uwKh5/mHGWy2NmxZAk=
 github.com/flant/libjq-go v1.6.3-0.20201126171326-c46a40ff22ee h1:evii83J+/6QGNvyf6tjQ/p27DPY9iftxIBb37ALJRTg=
 github.com/flant/libjq-go v1.6.3-0.20201126171326-c46a40ff22ee/go.mod h1:f+REaGl/+pZR97rbTcwHEka/MAipoQQ2Mc0iQUj4ak0=
 github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo=
@@ -255,8 +259,6 @@ github.com/sergi/go-diff v1.0.0/go.mod h1:0CfEIISq7TuYL3j771MWULgwwjU+GofnZX9QAm
 github.com/sirupsen/logrus v1.4.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo=
 github.com/sirupsen/logrus v1.4.1/go.mod h1:ni0Sbl8bgC9z8RoU9G6nDWqqs/fq4eDPysMBDgk/93Q=
 github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE=
-github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
-github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
 github.com/spf13/cobra v0.0.3/go.mod h1:1l0Ry5zgKvJasoi3XT1TypsSe7PqH0Sj9dhYf7v3XqQ=
 github.com/spf13/pflag v1.0.3/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4=
 github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA=
@@ -341,7 +343,6 @@ golang.org/x/sys v0.0.0-20191120155948-bd437916bb0e/go.mod h1:h1NjWce9XRLGQEsW7w
 golang.org/x/sys v0.0.0-20200323222414-85ca7c5b95cd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20210112080510-489259a85091/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
-golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220908164124-27713097b956/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.24.0 h1:Twjiwq9dn6R1fQcyiK+wQyHWfaz/BJB+YIpzU/Cv3Xg=
 golang.org/x/sys v0.24.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=

pkg/app/app.go

@@ -148,7 +148,7 @@ Use "%s debug-options" for a list of debug options for start command.
 
 // CommandWithDefaultUsageTemplate is used to workaround an absence of per-command usage templates
 func CommandWithDefaultUsageTemplate(kpApp *kingpin.Application, name, help string) *kingpin.CmdClause {
-	return kpApp.Command(name, help).PreAction(func(context *kingpin.ParseContext) error {
+	return kpApp.Command(name, help).PreAction(func(_ *kingpin.ParseContext) error {
 		kpApp.UsageTemplate(kingpin.DefaultUsageTemplate)
 		return nil
 	})

pkg/app/log.go

@@ -1,12 +1,11 @@
 package app
 
 import (
-	"bytes"
 	"fmt"
 	"strings"
 	"time"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/deckhouse/deckhouse/pkg/log"
 	"gopkg.in/alecthomas/kingpin.v2"
 
 	"github.com/flant/shell-operator/pkg/config"
@@ -45,68 +44,56 @@ func DefineLoggingFlags(cmd *kingpin.CmdClause) {
 }
 
 // SetupLogging sets logger formatter and level.
-func SetupLogging(runtimeConfig *config.Config) {
-	jsonFormatter := log.JSONFormatter{DisableTimestamp: LogNoTime}
-	textFormatter := log.TextFormatter{DisableTimestamp: LogNoTime, DisableColors: true}
-	colorFormatter := log.TextFormatter{DisableTimestamp: LogNoTime, ForceColors: true, FullTimestamp: true}
-	switch strings.ToLower(LogType) {
-	case "json":
-		log.SetFormatter(&jsonFormatter)
-	case "text":
-		log.SetFormatter(&textFormatter)
-	case "color":
-		log.SetFormatter(&colorFormatter)
-	default:
-		log.SetFormatter(&jsonFormatter)
-	}
-	if LogProxyHookJSON {
-		formatter := log.StandardLogger().Formatter
-		log.SetFormatter(&ProxyJsonWrapperFormatter{WrappedFormatter: formatter})
-	}
+func SetupLogging(runtimeConfig *config.Config, logger *log.Logger) {
+	// TODO: if we need formatters - add to logger
+	// jsonFormatter := log.JSONFormatter{DisableTimestamp: LogNoTime}
+	// textFormatter := log.TextFormatter{DisableTimestamp: LogNoTime, DisableColors: true}
+	// colorFormatter := log.TextFormatter{DisableTimestamp: LogNoTime, ForceColors: true, FullTimestamp: true}
+	// switch strings.ToLower(LogType) {
+	// case "json":
+	// 	log.SetFormatter(&jsonFormatter)
+	// case "text":
+	// 	log.SetFormatter(&textFormatter)
+	// case "color":
+	// 	log.SetFormatter(&colorFormatter)
+	// default:
+	// 	log.SetFormatter(&jsonFormatter)
+	// }
+	// if LogProxyHookJSON {
+	// 	formatter := log.StandardLogger().Formatter
+	// 	log.SetFormatter(&ProxyJsonWrapperFormatter{WrappedFormatter: formatter})
+	// }
 
-	setLogLevel(LogLevel)
+	log.SetDefaultLevel(log.LogLevelFromStr(LogLevel))
 
 	runtimeConfig.Register("log.level",
 		fmt.Sprintf("Global log level. Default duration for debug level is %s", ForcedDurationForDebugLevel),
 		strings.ToLower(LogLevel),
-		func(oldValue string, newValue string) error {
-			log.Infof("Set log level to '%s'", newValue)
-			setLogLevel(newValue)
+		func(_ string, newValue string) error {
+			logger.Infof("Set log level to '%s'", newValue)
+			log.SetDefaultLevel(log.LogLevelFromStr(newValue))
 			return nil
-		}, func(oldValue string, newValue string) time.Duration {
+		}, func(_ string, newValue string) time.Duration {
 			if strings.ToLower(newValue) == "debug" {
 				return ForcedDurationForDebugLevel
 			}
 			return 0
 		})
 }
 
-func setLogLevel(logLevel string) {
-	switch strings.ToLower(logLevel) {
-	case "debug":
-		log.SetLevel(log.DebugLevel)
-	case "error":
-		log.SetLevel(log.ErrorLevel)
-	case "info":
-		log.SetLevel(log.InfoLevel)
-	default:
-		log.SetLevel(log.InfoLevel)
-	}
-}
-
-type ProxyJsonWrapperFormatter struct {
-	WrappedFormatter log.Formatter
-}
+// type ProxyJsonWrapperFormatter struct {
+// 	WrappedFormatter log.Formatter
+// }
 
-func (f *ProxyJsonWrapperFormatter) Format(entry *log.Entry) ([]byte, error) {
-	// if proxying the json message is intended, just return the bytes
-	// TODO: Find a more elegant way to carry this info
-	if entry.Data[ProxyJsonLogKey] == true {
-		b := bytes.NewBufferString(entry.Message)
-		b.WriteString("\n")
-		return b.Bytes(), nil
-	}
+// func (f *ProxyJsonWrapperFormatter) Format(entry *log.Entry) ([]byte, error) {
+// 	// if proxying the json message is intended, just return the bytes
+// 	// TODO: Find a more elegant way to carry this info
+// 	if entry.Data[ProxyJsonLogKey] == true {
+// 		b := bytes.NewBufferString(entry.Message)
+// 		b.WriteString("\n")
+// 		return b.Bytes(), nil
+// 	}
 
-	// otherwise, use the wrapped formatter
-	return f.WrappedFormatter.Format(entry)
-}
+// 	// otherwise, use the wrapped formatter
+// 	return f.WrappedFormatter.Format(entry)
+// }

pkg/config/config.go

@@ -2,12 +2,13 @@ package config
 
 import (
 	"fmt"
+	"log/slog"
 	"sort"
 	"strings"
 	"sync"
 	"time"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/deckhouse/deckhouse/pkg/log"
 )
 
 /**
@@ -42,16 +43,16 @@ type Config struct {
 	temporalValues map[string]*TemporalValue
 	expireTicker   *time.Ticker
 
-	logEntry *log.Entry
+	logger *log.Logger
 }
 
-func NewConfig() *Config {
+func NewConfig(logger *log.Logger) *Config {
 	return &Config{
 		params:         make(map[string]*Parameter),
 		values:         make(map[string]string),
 		temporalValues: make(map[string]*TemporalValue),
 		errors:         make(map[string]error),
-		logEntry:       log.WithField("component", "runtimeConfig"),
+		logger:         logger.With(slog.String("component", "runtimeConfig")),
 	}
 }
 
@@ -254,7 +255,7 @@ func (c *Config) expireOverrides() {
 
 	for _, expire := range expires {
 		name, oldValue, newValue := expire[0], expire[1], expire[2]
-		c.logEntry.Debugf("Parameter '%s' expired", name)
+		c.logger.Debug("Parameter is expired", slog.String("parameter", name))
 		c.callOnChange(name, oldValue, newValue)
 	}
 }
@@ -266,8 +267,8 @@ func (c *Config) callOnChange(name string, oldValue string, newValue string) {
 	}
 	err := c.params[name].onChange(oldValue, newValue)
 	if err != nil {
-		c.logEntry.Errorf("OnChange handler failed for '%s' during value change from '%s' to '%s': %v",
-			name, oldValue, newValue, err)
+		c.logger.Error("OnChange handler failed for parameter during value change values",
+			slog.String("parameter", name), slog.String("old_value", oldValue), slog.String("new_value", newValue), slog.String("error", err.Error()))
 	}
 	c.m.Lock()
 	delete(c.errors, name)