WIP: updated log level on some log entries and added environment variable expansion for command line and its arguments

cmd/exec/exec.go

@@ -12,6 +12,7 @@ import (
 
 	"gitea.suyono.dev/suyono/wingmate"
 	"gitea.suyono.dev/suyono/wingmate/cmd/cli"
+	wmenv "gitea.suyono.dev/suyono/wingmate/task/env"
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
 	"golang.org/x/sys/unix"
@@ -74,7 +75,7 @@ func main() {
 	if selfArgs, childArgs, err = cli.SplitArgs(os.Args); err != nil {
 		selfArgs = os.Args
 	}
-	app.childArgs = childArgs
+	app.childArgs = wmenv.ExpandEnv(os.Environ(), childArgs)
 	app.err = err
 
 	rootCmd.SetArgs(selfArgs[1:])

cmd/wingmate/wingmate.go

@@ -22,6 +22,7 @@ func main() {
 	)
 
 	_ = wingmate.NewLog(os.Stderr, wingmate.Time|wingmate.Caller)
+	wingmate.SetGlobalLevel(wingmate.InfoLevel)
 	config.SetVersion(version)
 	config.ParseFlags()
 

config/config.go

@@ -30,6 +30,7 @@ const (
 	WMPidProxyPathFlag       = "pid-proxy"
 	WMExecPathFlag           = "exec"
 	PathConfigFlag           = "config"
+	GlobalLogConfig          = "log_level"
 )
 
 type Config struct {
@@ -84,9 +85,11 @@ func Read() (*Config, error) {
 	_ = viper.BindEnv(PathConfig)
 	_ = viper.BindEnv(PidProxyPathConfig)
 	_ = viper.BindEnv(ExecPathConfig)
+	_ = viper.BindEnv(GlobalLogConfig)
 	viper.SetDefault(PathConfig, DefaultConfigPath)
 	viper.SetDefault(PidProxyPathConfig, PidProxyPathDefault)
 	viper.SetDefault(ExecPathConfig, ExecPathDefault)
+	viper.SetDefault(GlobalLogConfig, wingmate.InfoLevelStr)
 
 	var (
 		dirent                  []os.DirEntry
@@ -101,6 +104,7 @@ func Read() (*Config, error) {
 		crones                  []CronTask
 	)
 
+	wingmate.SetGlobalLevelStr(viper.GetString(GlobalLogConfig))
 	serviceAvailable = false
 	cronAvailable = false
 	outConfig := &Config{
@@ -111,7 +115,7 @@ func Read() (*Config, error) {
 	svcdir = filepath.Join(configPath, ServiceDirName)
 	dirent, err = os.ReadDir(svcdir)
 	if err != nil {
-		wingmate.Log().Error().Msgf("encounter error when reading service directory %s: %+v", svcdir, err)
+		wingmate.Log().Warn().Msgf("encounter error when reading service directory %s: %+v", svcdir, err)
 	}
 	if len(dirent) > 0 {
 		for _, d := range dirent {
@@ -134,7 +138,7 @@ func Read() (*Config, error) {
 		cronAvailable = true
 	}
 	if err != nil {
-		wingmate.Log().Error().Msgf("encounter error when reading crontab %s: %+v", crontabfile, err)
+		wingmate.Log().Warn().Msgf("encounter error when reading crontab %s: %+v", crontabfile, err)
 	}
 
 	wingmateConfigAvailable = false

init/cron.go

@@ -23,6 +23,7 @@ func (i *Init) cron(wg *sync.WaitGroup, cron CronTask, exitFlag <-chan any) {
 		stdout     io.ReadCloser
 		stderr     io.ReadCloser
 		cmd        *exec.Cmd
+		patchedEnv []string
 	)
 
 	ticker := time.NewTicker(time.Second * 30)
@@ -34,8 +35,9 @@ cron:
 				wingmate.Log().Error().Str(cronTag, cron.Name()).Msgf("%+v", err)
 				goto fail
 			}
-			cmd = exec.Command(cron.Command(), cron.Arguments()...)
+			patchedEnv = cron.PatchEnv(os.Environ())
-			cmd.Env = cron.PatchEnv(os.Environ())
+			cmd = exec.Command(cron.Command(patchedEnv...), cron.Arguments(patchedEnv...)...)
+			cmd.Env = patchedEnv
 
 			if len(cron.WorkingDir()) > 0 {
 				cmd.Dir = cron.WorkingDir()

init/init.go

@@ -23,8 +23,8 @@ type TaskStatus interface {
 
 type Task interface {
 	Name() string
-	Command() string
+	Command(...string) string
-	Arguments() []string
+	Arguments(...string) []string
 	EnvLen() int
 	Environ() []string
 	PatchEnv([]string) []string

init/service.go

@@ -25,6 +25,7 @@ func (i *Init) service(wg *sync.WaitGroup, task ServiceTask, exitFlag <-chan any
 		stdout     io.ReadCloser
 		failStatus bool
 		cmd        *exec.Cmd
+		patchedEnv []string
 	)
 
 	defer func() {
@@ -39,8 +40,10 @@ service:
 			failStatus = true
 			goto fail
 		}
-		cmd = exec.Command(task.Command(), task.Arguments()...)
+
-		cmd.Env = task.PatchEnv(os.Environ())
+		patchedEnv = task.PatchEnv(os.Environ())
+		cmd = exec.Command(task.Command(patchedEnv...), task.Arguments(patchedEnv...)...)
+		cmd.Env = patchedEnv
 
 		if len(task.WorkingDir()) > 0 {
 			cmd.Dir = task.WorkingDir()
@@ -104,5 +107,5 @@ func (i *Init) pipeReader(wg *sync.WaitGroup, pipe io.ReadCloser, tag, serviceNa
 		wingmate.Log().Error().Str(tag, serviceName).Msgf("got error when reading pipe: %#v", err)
 	}
 
-	wingmate.Log().Info().Str(tag, serviceName).Msg("closing pipe")
+	wingmate.Log().Debug().Str(tag, serviceName).Msg("closing pipe")
 }

init/signal-pump.go

@@ -52,9 +52,9 @@ func (i *Init) sigTermPump(startTime time.Time, selfExit <-chan any) status {
 	t := time.NewTicker(time.Millisecond * 100)
 	defer t.Stop()
 
-	wingmate.Log().Info().Msg("start pumping SIGTERM signal")
+	wingmate.Log().Debug().Msg("start pumping SIGTERM signal")
 	defer func() {
-		wingmate.Log().Info().Msg("stop pumping SIGTERM signal")
+		wingmate.Log().Debug().Msg("stop pumping SIGTERM signal")
 	}()
 
 	for time.Since(startTime) < time.Duration(time.Second*4) {

init/waiter.go

@@ -20,7 +20,7 @@ func (i *Init) waiter(wg *sync.WaitGroup, runningFlag <-chan any, sigHandlerFlag
 	defer wg.Done()
 
 	defer func() {
-		wingmate.Log().Info().Msg("waiter exiting...")
+		wingmate.Log().Debug().Msg("waiter exiting...")
 	}()
 
 	running = true
@@ -41,7 +41,7 @@ wait:
 			} else {
 				select {
 				case <-runningFlag:
-					wingmate.Log().Info().Msg("waiter received shutdown signal...")
+					wingmate.Log().Debug().Msg("waiter received shutdown signal...")
 					running = false
 				default:
 				}
@@ -55,14 +55,14 @@ wait:
 					if flagged {
 						close(sigHandlerFlag)
 						flagged = false
-						wingmate.Log().Warn().Msg("waiter: inner flag")
+						wingmate.Log().Debug().Msg("waiter: inner flag")
 					}
-					wingmate.Log().Warn().Msg("waiter: no child left")
+					wingmate.Log().Debug().Msg("waiter: no child left")
 					break wait
 				}
 			}
 
-			wingmate.Log().Warn().Msgf("Wait4 returns error: %+v", err)
+			wingmate.Log().Debug().Msgf("Wait4 returns error: %+v", err)
 			waitingForSignal = true
 		}
 	}

logger.go

@@ -17,6 +17,26 @@ const (
 	Caller
 )
 
+const (
+	PanicLevel = 5 - iota
+	FatalLevel
+	ErrorLevel
+	WarnLevel
+	InfoLevel
+	DebugLevel
+	TraceLevel
+)
+
+const (
+	PanicLevelStr = "panic"
+	FatalLevelStr = "fatal"
+	ErrorLevelStr = "error"
+	WarnLevelStr  = "warn"
+	InfoLevelStr  = "info"
+	DebugLevelStr = "debug"
+	TraceLevelStr = "trace"
+)
+
 var (
 	w *wrapper
 )
@@ -41,13 +61,51 @@ func Log() logger.Log {
 	return w
 }
 
+func SetGlobalLevel(level int) {
+	switch level {
+	case PanicLevel:
+		zerolog.SetGlobalLevel(zerolog.PanicLevel)
+	case FatalLevel:
+		zerolog.SetGlobalLevel(zerolog.FatalLevel)
+	case ErrorLevel:
+		zerolog.SetGlobalLevel(zerolog.ErrorLevel)
+	case WarnLevel:
+		zerolog.SetGlobalLevel(zerolog.WarnLevel)
+	case InfoLevel:
+		zerolog.SetGlobalLevel(zerolog.InfoLevel)
+	case DebugLevel:
+		zerolog.SetGlobalLevel(zerolog.DebugLevel)
+	case TraceLevel:
+		zerolog.SetGlobalLevel(zerolog.TraceLevel)
+	}
+}
+
+func SetGlobalLevelStr(level string) {
+	switch level {
+	case PanicLevelStr:
+		zerolog.SetGlobalLevel(zerolog.PanicLevel)
+	case FatalLevelStr:
+		zerolog.SetGlobalLevel(zerolog.FatalLevel)
+	case ErrorLevelStr:
+		zerolog.SetGlobalLevel(zerolog.ErrorLevel)
+	case WarnLevelStr:
+		zerolog.SetGlobalLevel(zerolog.WarnLevel)
+	case InfoLevelStr:
+		zerolog.SetGlobalLevel(zerolog.InfoLevel)
+	case DebugLevelStr:
+		zerolog.SetGlobalLevel(zerolog.DebugLevel)
+	case TraceLevelStr:
+		zerolog.SetGlobalLevel(zerolog.TraceLevel)
+	}
+}
+
 func (w *wrapper) flagPass(e *zerolog.Event) *zerolog.Event {
 	if w.flag&Time != 0 {
 		e = e.Time(timeTag, time.Now())
 	}
 
 	if w.flag&Caller != 0 {
-		e = e.Caller()
+		e = e.Caller(2)
 	}
 
 	return e
@@ -57,6 +115,14 @@ func (w *wrapper) Info() logger.Content {
 	return (*eventWrapper)(w.flagPass(w.log.Info()))
 }
 
+func (w *wrapper) Debug() logger.Content {
+	return (*eventWrapper)(w.flagPass(w.log.Debug()))
+}
+
+func (w *wrapper) Trace() logger.Content {
+	return (*eventWrapper)(w.flagPass(w.log.Trace()))
+}
+
 func (w *wrapper) Warn() logger.Content {
 	return (*eventWrapper)(w.flagPass(w.log.Warn()))
 }

logger/logger.go

@@ -7,13 +7,15 @@ type Content interface {
 	Err(error) Content
 }
 
-type Level interface {
+type LogLevel interface {
 	Info() Content
 	Warn() Content
 	Error() Content
 	Fatal() Content
+	Debug() Content
+	Trace() Content
 }
 
 type Log interface {
-	Level
+	LogLevel
 }

task/cron.go

@@ -4,6 +4,7 @@ import (
 	"crypto/sha256"
 	"encoding/json"
 	"fmt"
+	wmenv "gitea.suyono.dev/suyono/wingmate/task/env"
 	"time"
 
 	"gitea.suyono.dev/suyono/wingmate"
@@ -224,19 +225,25 @@ func (c *CronTask) UtilDepCheck() error {
 	return nil
 }
 
-func (c *CronTask) Command() string {
+func (c *CronTask) Command(env ...string) string {
+	if len(env) > 0 {
+		return wmenv.ExpandEnv(env, []string{c.cmdLine[0]})[0]
+	}
 	return c.cmdLine[0]
 }
 
-func (c *CronTask) Arguments() []string {
+func (c *CronTask) Arguments(env ...string) []string {
 	if len(c.cmdLine) == 1 {
 		return nil
 	}
 
-	retval := make([]string, len(c.cmdLine)-1)
+	argCopy := make([]string, len(c.cmdLine)-1)
-	copy(retval, c.cmdLine[1:])
+	copy(argCopy, c.cmdLine[1:])
+	if len(env) > 0 {
+		argCopy = wmenv.ExpandEnv(env, argCopy)
+	}
 
-	return retval
+	return argCopy
 }
 
 func (c *CronTask) EnvLen() int {
@@ -250,7 +257,7 @@ func (c *CronTask) Environ() []string {
 }
 
 func (c *CronTask) PatchEnv(env []string) []string {
-	return patchEnv(env, c.environ)
+	return wmenv.PatchEnv(env, c.environ)
 }
 
 func (c *CronTask) Setsid() bool {

task/env/env.go

@@ -0,0 +1,97 @@
+package env
+
+import (
+	"fmt"
+	"gitea.suyono.dev/suyono/wingmate"
+	"regexp"
+	"strings"
+)
+
+var (
+	envCapture     = regexp.MustCompile(`\$+[a-zA-Z_][a-zA-Z0-9_]*|\$+{[a-zA-Z_][a-zA-Z0-9_]*}`)
+	envEsc         = regexp.MustCompile(`^\$\$+[^$]+$`)  // escaped, starts with two or more $ character
+	envRef         = regexp.MustCompile(`^\$([^$]+)$`)   // capture the variable name
+	envRefExplicit = regexp.MustCompile(`^\${([^$]+)}$`) // capture the variable name - explicit
+)
+
+func expandEnv(envMap map[string]string, input string) string {
+	if envEsc.MatchString(input) {
+		return input
+	}
+
+	if envName := envRefExplicit.FindStringSubmatch(input); envName != nil && envName[1] != "" {
+		exVal, ok := envMap[envName[1]]
+		if !ok {
+			return ""
+		}
+		return exVal
+	}
+
+	if envName := envRef.FindStringSubmatch(input); envName != nil && envName[1] != "" {
+		exVal, ok := envMap[envName[1]]
+		if !ok {
+			return ""
+		}
+		return exVal
+	}
+	return input
+
+}
+
+func PatchEnv(existing, new []string) []string {
+	tMap := make(map[string]string)
+	for _, e := range existing {
+		key, value, ok := strings.Cut(e, "=")
+		if !ok {
+			wingmate.Log().Warn().Msgf("removing invalid environment:", e)
+			continue
+		}
+		tMap[key] = value
+	}
+
+	for _, e := range new {
+		key, value, ok := strings.Cut(e, "=")
+		if !ok {
+			wingmate.Log().Warn().Msgf("removing invalid environment:", e)
+			continue
+		}
+
+		if strings.ContainsAny(key, "$") {
+			wingmate.Log().Error().Err(fmt.Errorf("variable name contains $")).Msgf("removing invalid environment:", e)
+			continue
+		}
+
+		value = envCapture.ReplaceAllStringFunc(value, func(rep string) string {
+			return expandEnv(tMap, rep)
+		})
+
+		tMap[key] = value
+	}
+
+	outEnv := make([]string, 0, len(existing))
+	for key, val := range tMap {
+		outEnv = append(outEnv, fmt.Sprintf("%s=%s", key, val))
+	}
+
+	return outEnv
+}
+
+func ExpandEnv(env []string, input []string) []string {
+	envMap := make(map[string]string)
+	for _, e := range env {
+		key, value, ok := strings.Cut(e, "=")
+		if !ok {
+			wingmate.Log().Warn().Msgf("removing bad environment:", e)
+			continue
+		}
+		envMap[key] = value
+	}
+
+	for i, s := range input {
+		s = envCapture.ReplaceAllStringFunc(s, func(rep string) string {
+			return expandEnv(envMap, rep)
+		})
+		input[i] = s
+	}
+	return input
+}

task/task.go

@@ -4,19 +4,9 @@ import (
 	"crypto/sha256"
 	"encoding/json"
 	"fmt"
-	"regexp"
-	"strings"
-
 	"gitea.suyono.dev/suyono/wingmate"
-
 	wminit "gitea.suyono.dev/suyono/wingmate/init"
-)
+	wmenv "gitea.suyono.dev/suyono/wingmate/task/env"
-
-var (
-	envCapture     = regexp.MustCompile(`\$+[a-zA-Z_][a-zA-Z0-9_]*|\$+{[a-zA-Z_][a-zA-Z0-9_]*}`)
-	envEsc         = regexp.MustCompile(`^\$\$+[^\$]+$`)  // escaped, starts with two or more $ character
-	envRef         = regexp.MustCompile(`^\$([^\$]+)$`)   // capture the variable name
-	envRefExplicit = regexp.MustCompile(`^\${([^\$]+)}$`) // capture the variable name - explicit
 )
 
 type config interface {
@@ -227,6 +217,7 @@ func (t *ServiceTask) Name() string {
 }
 
 func (t *ServiceTask) prepareCommandLine() []string {
+	//TODO: is this method used somewhere? if not, can I remove this?
 	if len(t.cmdLine) > 0 {
 		return t.cmdLine
 	}
@@ -288,19 +279,25 @@ func (t *ServiceTask) UtilDepCheck() error {
 	return nil
 }
 
-func (t *ServiceTask) Command() string {
+func (t *ServiceTask) Command(env ...string) string {
+	if len(env) > 0 {
+		return wmenv.ExpandEnv(env, []string{t.cmdLine[0]})[0]
+	}
 	return t.cmdLine[0]
 }
 
-func (t *ServiceTask) Arguments() []string {
+func (t *ServiceTask) Arguments(env ...string) []string {
 	if len(t.cmdLine) == 1 {
 		return nil
 	}
 
-	retval := make([]string, len(t.cmdLine)-1)
+	argCopy := make([]string, len(t.cmdLine)-1)
-	copy(retval, t.cmdLine[1:])
+	copy(argCopy, t.cmdLine[1:])
+	if len(env) > 0 {
+		argCopy = wmenv.ExpandEnv(env, argCopy)
+	}
 
-	return retval
+	return argCopy
 }
 
 func (t *ServiceTask) EnvLen() int {
@@ -314,7 +311,7 @@ func (t *ServiceTask) Environ() []string {
 }
 
 func (t *ServiceTask) PatchEnv(env []string) []string {
-	return patchEnv(env, t.environ)
+	return wmenv.PatchEnv(env, t.environ)
 }
 
 func (t *ServiceTask) Setsid() bool {
@@ -385,60 +382,3 @@ func validate(validators ...func() error) error {
 	}
 	return nil
 }
-
-func patchEnv(existing, new []string) []string {
-	tMap := make(map[string]string)
-	for _, e := range existing {
-		key, value, ok := strings.Cut(e, "=")
-		if !ok {
-			wingmate.Log().Warn().Msgf("removing invalid environment:", e)
-			continue
-		}
-		tMap[key] = value
-	}
-
-	for _, e := range new {
-		key, value, ok := strings.Cut(e, "=")
-		if !ok {
-			wingmate.Log().Warn().Msgf("removing invalid environment:", e)
-			continue
-		}
-
-		if strings.ContainsAny(key, "$") {
-			wingmate.Log().Error().Err(fmt.Errorf("variable name contains $")).Msgf("removing invalid environment:", e)
-			continue
-		}
-
-		value = envCapture.ReplaceAllStringFunc(value, func(rep string) string {
-			if envEsc.MatchString(rep) {
-				return rep
-			}
-
-			if envName := envRefExplicit.FindStringSubmatch(rep); envName != nil && envName[1] != "" {
-				exVal, ok := tMap[envName[1]]
-				if !ok {
-					return ""
-				}
-				return exVal
-			}
-
-			if envName := envRef.FindStringSubmatch(rep); envName != nil && envName[1] != "" {
-				exVal, ok := tMap[envName[1]]
-				if !ok {
-					return ""
-				}
-				return exVal
-			}
-			return rep
-		})
-
-		tMap[key] = value
-	}
-
-	outEnv := make([]string, 0, len(existing))
-	for key, val := range tMap {
-		outEnv = append(outEnv, fmt.Sprintf("%s=%s", key, val))
-	}
-
-	return outEnv
-}

task/task_test.go

@@ -112,17 +112,20 @@ func TestServiceTaskPatchEnv(t *testing.T) {
 	}
 
 	for _, tt := range tests {
-		t.Run(tt.name+" - service", func(t *testing.T) {
+		t.Run(tt.name, func(t *testing.T) {
+			t.Run("service", func(t *testing.T) {
 				st := NewServiceTask(tt.name)
 				st.SetEnv(tt.serviceEnv...)
 				result := st.PatchEnv(tt.systemEnv)
 				assert.ElementsMatch(t, result, tt.expected)
 			})
-		t.Run(tt.name+" - cron", func(t *testing.T) {
+
+			t.Run("cron", func(t *testing.T) {
 				st := NewCronTask(tt.name)
 				st.SetEnv(tt.serviceEnv...)
 				result := st.PatchEnv(tt.systemEnv)
 				assert.ElementsMatch(t, result, tt.expected)
 			})
+		})
 	}
 }