diff --git a/docci.go b/docci.go index 7796341..b931fe7 100644 --- a/docci.go +++ b/docci.go @@ -35,10 +35,10 @@ func RunDocciFileWithOptions(filePath string, opts types.DocciOpts) DocciResult log := logger.GetLogger() // Read the file into a string - log.Debugf("Reading file: %s", filePath) + log.Debug("Reading file", "path", filePath) markdown, err := os.ReadFile(filePath) if err != nil { - log.Errorf("Failed to read file: %s", err.Error()) + log.Error("Failed to read file", "error", err.Error()) return DocciResult{ Success: false, ExitCode: 1, @@ -50,7 +50,7 @@ func RunDocciFileWithOptions(filePath string, opts types.DocciOpts) DocciResult log.Debug("Parsing code blocks from markdown") blocks, err := parser.ParseCodeBlocks(string(markdown)) if err != nil { - log.Errorf("Failed to parse code blocks: %s", err.Error()) + log.Error("Failed to parse code blocks", "error", err.Error()) return DocciResult{ Success: false, ExitCode: 1, @@ -58,7 +58,7 @@ func RunDocciFileWithOptions(filePath string, opts types.DocciOpts) DocciResult } } - log.Debugf("Found %d code blocks", len(blocks)) + log.Debug("Found code blocks", "count", len(blocks)) // Build executable script with validation markers log.Debug("Building executable script") @@ -76,7 +76,14 @@ func RunDocciFileWithOptions(filePath string, opts types.DocciOpts) DocciResult // Execute the script log.Debug("Executing script") - resp := executor.Exec(script) + resp, err := executor.Exec(script) + if err != nil { + return DocciResult{ + Success: false, + ExitCode: 1, + Stderr: fmt.Sprintf("execute script: %v", err), + } + } // Check assert-failure blocks if len(assertFailureMap) > 0 { @@ -95,7 +102,7 @@ func RunDocciFileWithOptions(filePath string, opts types.DocciOpts) DocciResult // Script failed as expected, continue processing } else if resp.Error != nil { // No assert-failure blocks, so error is unexpected - log.Errorf("āœ— Unexpected script execution failure: %s", resp.Error.Error()) + log.Error("Unexpected script execution failure", "error", resp.Error.Error()) return DocciResult{ Success: false, ExitCode: 1, @@ -111,10 +118,10 @@ func RunDocciFileWithOptions(filePath string, opts types.DocciOpts) DocciResult // Validate outputs if there are any validation requirements var validationErrors []error if len(validationMap) > 0 { - log.Debugf("Validating %d output expectations", len(validationMap)) + log.Debug("Validating output expectations", "count", len(validationMap)) validationErrors = executor.ValidateOutputs(blockOutputs, validationMap) if len(validationErrors) > 0 { - log.Errorf("Found %d validation errors", len(validationErrors)) + log.Error("Found validation errors", "count", len(validationErrors)) errorMsg := "\n=== Validation Errors ===\n" for _, err := range validationErrors { errorMsg += fmt.Sprintf("āŒ %s\n", err.Error()) @@ -184,17 +191,17 @@ func RunDocciFiles(filePaths []string) DocciResult { func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciResult { log := logger.GetLogger() - log.Debugf("Merging %d markdown files", len(filePaths)) + log.Debug("Merging markdown files", "count", len(filePaths)) var allBlocks []parser.CodeBlock globalIndex := 1 // Parse all files and collect blocks with filename metadata for _, filePath := range filePaths { - log.Debugf("Reading file: %s", filePath) + log.Debug("Reading file", "path", filePath) markdown, err := os.ReadFile(filePath) if err != nil { - log.Errorf("Failed to read file %s: %s", filePath, err.Error()) + log.Error("Failed to read file", "path", filePath, "error", err.Error()) return DocciResult{ Success: false, ExitCode: 1, @@ -203,11 +210,11 @@ func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciRes } // Parse code blocks with filename metadata - log.Debugf("Parsing code blocks from %s", filePath) + log.Debug("Parsing code blocks", "path", filePath) fileName := filepath.Base(filePath) blocks, err := parser.ParseCodeBlocksWithFileName(string(markdown), fileName) if err != nil { - log.Errorf("Failed to parse code blocks from %s: %s", filePath, err.Error()) + log.Error("Failed to parse code blocks", "path", filePath, "error", err.Error()) return DocciResult{ Success: false, ExitCode: 1, @@ -222,10 +229,10 @@ func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciRes } allBlocks = append(allBlocks, blocks...) - log.Debugf("Found %d code blocks in %s", len(blocks), filePath) + log.Debug("Found code blocks in file", "count", len(blocks), "path", filePath) } - log.Debugf("Total merged blocks: %d", len(allBlocks)) + log.Debug("Total merged blocks", "count", len(allBlocks)) // Build executable script with validation markers log.Debug("Building executable script from merged blocks") @@ -243,7 +250,14 @@ func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciRes // Execute the script log.Debug("Executing merged script") - resp := executor.Exec(script) + resp, err := executor.Exec(script) + if err != nil { + return DocciResult{ + Success: false, + ExitCode: 1, + Stderr: fmt.Sprintf("execute script: %v", err), + } + } // Check assert-failure blocks if len(assertFailureMap) > 0 { @@ -262,7 +276,7 @@ func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciRes // Script failed as expected, continue processing } else if resp.Error != nil { // No assert-failure blocks, so error is unexpected - log.Errorf("āœ— Unexpected script execution failure: %s", resp.Error.Error()) + log.Error("Unexpected script execution failure", "error", resp.Error.Error()) return DocciResult{ Success: false, ExitCode: 1, @@ -278,10 +292,10 @@ func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciRes // Validate outputs if there are any validation requirements var validationErrors []error if len(validationMap) > 0 { - log.Debugf("Validating %d output expectations", len(validationMap)) + log.Debug("Validating output expectations", "count", len(validationMap)) validationErrors = executor.ValidateOutputs(blockOutputs, validationMap) if len(validationErrors) > 0 { - log.Errorf("Found %d validation errors", len(validationErrors)) + log.Error("Found validation errors", "count", len(validationErrors)) errorMsg := "\n=== Validation Errors ===\n" for _, err := range validationErrors { errorMsg += fmt.Sprintf("āŒ %s\n", err.Error()) @@ -299,7 +313,7 @@ func RunDocciFilesWithOptions(filePaths []string, opts types.DocciOpts) DocciRes log.Debug("Merged script execution completed successfully") fileList := strings.Join(filePaths, ", ") - log.Infof("Successfully executed merged files: %s", fileList) + log.Info("Successfully executed merged files", "files", fileList) return DocciResult{ Success: true, diff --git a/executor/exec.go b/executor/exec.go index 80db7f9..d1d7428 100644 --- a/executor/exec.go +++ b/executor/exec.go @@ -31,7 +31,7 @@ func NewExecResponse(exitCode uint, stdout, stderr string, err error) ExecRespon // Exec runs a specific codeblock in a bash shell. // returns exit (status code, error message) -func Exec(commands string) ExecResponse { +func Exec(commands string) (ExecResponse, error) { log := logger.GetLogger() log.Debug("Executing commands in bash shell") @@ -40,16 +40,16 @@ func Exec(commands string) ExecResponse { stdout, err := cmd.StdoutPipe() if err != nil { - panic(err) + return ExecResponse{}, fmt.Errorf("create stdout pipe: %w", err) } stderr, err := cmd.StderrPipe() if err != nil { - panic(err) + return ExecResponse{}, fmt.Errorf("create stderr pipe: %w", err) } if err := cmd.Start(); err != nil { - panic(err) + return ExecResponse{}, fmt.Errorf("start command: %w", err) } var stdoutBuf, stderrBuf strings.Builder // captures output for further validation @@ -119,15 +119,15 @@ func Exec(commands string) ExecResponse { if exitError, ok := err.(*exec.ExitError); ok { exitCode := exitError.ExitCode() exitErr := exitError.Error() - log.Debugf("Command exited with code: %d, error: %s", exitCode, exitErr) - return NewExecResponse(uint(exitCode), stdoutBuf.String(), stderrBuf.String(), fmt.Errorf(exitError.Error())) + log.Debug("Command exited with code", "exitCode", exitCode, "error", exitErr) + return NewExecResponse(uint(exitCode), stdoutBuf.String(), stderrBuf.String(), fmt.Errorf(exitError.Error())), nil } else { - panic(err) + return ExecResponse{}, fmt.Errorf("wait command: %w", err) } } log.Debug("Command executed successfully") - return NewExecResponse(0, stdoutBuf.String(), stderrBuf.String(), nil) + return NewExecResponse(0, stdoutBuf.String(), stderrBuf.String(), nil), nil } // ParseBlockOutputs extracts output for each code block based on markers @@ -148,7 +148,7 @@ func ParseBlockOutputs(output string) map[int]string { marker := strings.TrimPrefix(line, "### DOCCI_BLOCK_START_") marker = strings.TrimSuffix(marker, " ###") fmt.Sscanf(marker, "%d", ¤tBlock) - log.Debugf("Found start marker for block %d", currentBlock) + log.Debug("Found start marker for block", "block", currentBlock) inBlock = true currentOutput.Reset() continue @@ -158,7 +158,7 @@ func ParseBlockOutputs(output string) map[int]string { if strings.HasPrefix(line, "### DOCCI_BLOCK_END_") && strings.HasSuffix(line, " ###") { if inBlock { blockOutputs[currentBlock] = strings.TrimSpace(currentOutput.String()) - log.Debugf("Found end marker for block %d, captured output length: %d", currentBlock, len(blockOutputs[currentBlock])) + log.Debug("Found end marker for block", "block", currentBlock, "capturedOutputLength", len(blockOutputs[currentBlock])) } inBlock = false continue @@ -178,7 +178,7 @@ func ParseBlockOutputs(output string) map[int]string { } } - log.Debugf("Parsed %d block outputs", len(blockOutputs)) + log.Debug("Parsed block outputs", "count", len(blockOutputs)) return blockOutputs } @@ -191,17 +191,17 @@ func ValidateOutputs(blockOutputs map[int]string, validationMap map[int]string) for blockIndex, expectedContains := range validationMap { output, exists := blockOutputs[blockIndex] if !exists { - log.Errorf("No output found for block %d", blockIndex) + log.Error("No output found for block", "block", blockIndex) errors = append(errors, fmt.Errorf("no output found for block %d", blockIndex)) continue } if !strings.Contains(output, expectedContains) { - log.Errorf("Block %d validation failed: output does not contain '%s'", blockIndex, expectedContains) + log.Error("Block validation failed: output does not contain expected", "block", blockIndex, "expected", expectedContains) errors = append(errors, fmt.Errorf("block %d: output does not contain expected string '%s'\nActual output:\n%s", blockIndex, expectedContains, output)) } else { - log.Debugf("Block %d validation passed: found expected string '%s'", blockIndex, expectedContains) + log.Debug("Block validation passed: found expected string", "block", blockIndex, "expected", expectedContains) } } diff --git a/gh.go b/gh.go index 5ac90bb..cb26ba2 100644 --- a/gh.go +++ b/gh.go @@ -7,7 +7,6 @@ import ( "strings" "time" - "github.com/sirupsen/logrus" "golang.org/x/mod/semver" ) @@ -115,9 +114,8 @@ func GetRealLatestReleases(r []Release) (string, string) { return latestPre, latestOfficial } -// OutOfDateCheckLog logs & returns true if it is out of date. -func OutOfDateCheckLog(logger *logrus.Logger, binName, current, latest string) bool { - +// OutOfDateCheckLog returns true if current version is out of date. +func OutOfDateCheckLog(binName, current, latest string) bool { currentVer := current if currentVer == "dev" { currentVer = "v0.0.0" diff --git a/go.mod b/go.mod index 79f99fd..e159832 100644 --- a/go.mod +++ b/go.mod @@ -3,7 +3,6 @@ module github.com/reecepbcups/docci go 1.23.7 require ( - github.com/sirupsen/logrus v1.9.3 github.com/spf13/cobra v1.9.1 github.com/stretchr/testify v1.10.0 golang.org/x/mod v0.26.0 @@ -14,6 +13,5 @@ require ( github.com/inconshreveable/mousetrap v1.1.0 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect github.com/spf13/pflag v1.0.6 // indirect - golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index 3fd4df7..f586837 100644 --- a/go.sum +++ b/go.sum @@ -1,5 +1,4 @@ github.com/cpuguy83/go-md2man/v2 v2.0.6/go.mod h1:oOW0eioCTA6cOiMLiUPZOpcVxMig6NIQQ7OS05n1F4g= -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/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8= @@ -7,22 +6,15 @@ github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLf github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= -github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= -github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/spf13/cobra v1.9.1 h1:CXSaggrXdbHK9CF+8ywj8Amf7PBRmPCOJugH954Nnlo= github.com/spf13/cobra v1.9.1/go.mod h1:nDyEzZ8ogv936Cinf6g1RU9MRY64Ir93oCnqb9wxYW0= github.com/spf13/pflag v1.0.6 h1:jFzHGLGAlb3ruxLB8MhbI6A8+AQX/2eW4qeyNZXNp2o= github.com/spf13/pflag v1.0.6/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= -github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= -github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.10.0 h1:Xv5erBjTwe/5IxqUQTdXv5kgmIvbHo3QQyRwhJsOfJA= github.com/stretchr/testify v1.10.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= golang.org/x/mod v0.26.0 h1:EGMPT//Ezu+ylkCijjPc+f4Aih7sZvaAr+O3EHBxvZg= golang.org/x/mod v0.26.0/go.mod h1:/j6NAhSk8iQ723BGAUyoAcn7SlD7s15Dp9Nd/SfeaFQ= -golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 h1:0A+M6Uqn+Eje4kHMK80dtF3JCXC4ykBgQG4Fe06QRhQ= -golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= -gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/logger/logger.go b/logger/logger.go index 70eef04..965fb87 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -1,47 +1,110 @@ package logger import ( + "context" + "fmt" "io" + "log/slog" "os" +) + +var Logger *slog.Logger - "github.com/sirupsen/logrus" +// ANSI color codes +const ( + colorReset = "\033[0m" + colorRed = "\033[31m" + colorYellow = "\033[33m" + colorBlue = "\033[34m" + colorCyan = "\033[36m" ) -var Logger *logrus.Logger +type ColorHandler struct { + out io.Writer + level slog.Leveler +} + +func (h *ColorHandler) Enabled(_ context.Context, level slog.Level) bool { + return level >= h.level.Level() +} -func init() { - Logger = logrus.New() - Logger.SetOutput(os.Stderr) - Logger.SetFormatter(&logrus.TextFormatter{ - DisableTimestamp: true, - DisableColors: false, +func (h *ColorHandler) Handle(_ context.Context, r slog.Record) error { + timeStr := r.Time.Format("15:04:05") + + var levelColor, levelStr string + switch r.Level { + case slog.LevelDebug: + levelColor = colorCyan + levelStr = "DEBUG" + case slog.LevelInfo: + levelColor = colorBlue + levelStr = "INFO" + case slog.LevelWarn: + levelColor = colorYellow + levelStr = "WARN" + case slog.LevelError: + levelColor = colorRed + levelStr = "ERROR" + default: + levelColor = colorReset + levelStr = r.Level.String() + } + + // Build attrs string + var attrs string + r.Attrs(func(a slog.Attr) bool { + attrs += fmt.Sprintf(" %s=%v", a.Key, a.Value) + return true }) - Logger.SetLevel(logrus.InfoLevel) + + fmt.Fprintf(h.out, "%s%s%s(%s) %s%s\n", + levelColor, levelStr, colorReset, timeStr, r.Message, attrs) + return nil +} + +func (h *ColorHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + return h +} + +func (h *ColorHandler) WithGroup(name string) slog.Handler { + return h +} + +func newColorHandler(out io.Writer, level slog.Leveler) *ColorHandler { + return &ColorHandler{out: out, level: level} +} + +func init() { + Logger = slog.New(newColorHandler(os.Stderr, slog.LevelInfo)) } // SetLogLevel sets the logging level based on a string func SetLogLevel(level string) { + var lvl slog.Level switch level { case "debug": - Logger.SetLevel(logrus.DebugLevel) + lvl = slog.LevelDebug case "info": - Logger.SetLevel(logrus.InfoLevel) + lvl = slog.LevelInfo case "warn", "warning": - Logger.SetLevel(logrus.WarnLevel) - case "error": - Logger.SetLevel(logrus.ErrorLevel) - case "fatal": - Logger.SetLevel(logrus.FatalLevel) - case "panic": - Logger.SetLevel(logrus.PanicLevel) + lvl = slog.LevelWarn + case "error", "fatal", "panic": + lvl = slog.LevelError case "off", "none": - Logger.SetOutput(io.Discard) + Logger = slog.New(slog.NewTextHandler(io.Discard, nil)) + return default: - Logger.SetLevel(logrus.InfoLevel) + lvl = slog.LevelInfo } + Logger = slog.New(newColorHandler(os.Stderr, lvl)) } // GetLogger returns the configured logger instance -func GetLogger() *logrus.Logger { +func GetLogger() *slog.Logger { return Logger -} \ No newline at end of file +} + +// IsDebugEnabled returns true if debug level logging is enabled +func IsDebugEnabled() bool { + return Logger.Enabled(context.Background(), slog.LevelDebug) +} diff --git a/main.go b/main.go index a4db88f..d43153c 100644 --- a/main.go +++ b/main.go @@ -97,18 +97,18 @@ File paths in the JSON config are resolved relative to the config file's locatio if err := os.Chdir(workingDir); err != nil { return fmt.Errorf("failed to change to run directory %s: %w", workingDir, err) } - log.Infof("Changed working directory to: %s", workingDir) + log.Info("changed working directory", "dir", workingDir) } if len(filePaths) == 1 { - log.Infof("Running docci on file: %s", filePaths[0]) + log.Info("running docci", "file", filePaths[0]) } else { - log.Infof("Running docci on %d files: %s", len(filePaths), strings.Join(filePaths, ", ")) + log.Info("running docci", "count", len(filePaths), "files", strings.Join(filePaths, ", ")) } // Run pre-commands if provided if len(preCommands) > 0 { - log.Debug("Running pre-commands") + log.Debug("running pre-commands") runPreCommands(preCommands) } @@ -168,18 +168,19 @@ File paths in the JSON config are resolved relative to the config file's locatio // Run cleanup commands if provided if len(cleanupCommands) > 0 { - log.Debug("Running cleanup commands") + log.Debug("running cleanup commands") runCleanupCommands(cleanupCommands) } // Exit with error if command failed if !result.Success { - log.Errorf("Command failed with exit code: %d", result.ExitCode) + log.Error("Command failed", "exitCode", result.ExitCode) os.Exit(result.ExitCode) } // Print clear success message regardless of log level - log.Info("\nšŸŽ‰ All tests completed successfully!") + fmt.Println() + log.Info("šŸŽ‰ All tests completed successfully!") log.Debug("Command completed successfully") return nil @@ -210,7 +211,7 @@ var latestCmd = &cobra.Command{ pre, latest := GetRealLatestReleases(releases) text := "Docci is up to date!" - if OutOfDateCheckLog(logger, "docci", version, latest) { + if OutOfDateCheckLog("docci", version, latest) { var t strings.Builder t.WriteString(fmt.Sprintf("\nNew version available @ %s\n", BinaryToGHApi)) t.WriteString(fmt.Sprintf("current: %s\n", version)) @@ -243,7 +244,7 @@ var validateCmd = &cobra.Command{ return fmt.Errorf("file not found: %s", filePath) } - log.Infof("Validating file: %s", filePath) + log.Info("Validating file", "file", filePath) // Read the file markdown, err := os.ReadFile(filePath) @@ -257,15 +258,13 @@ var validateCmd = &cobra.Command{ return fmt.Errorf("error parsing code blocks: %w", err) } - log.Infof("Successfully parsed %d code blocks", len(blocks)) + log.Info("Successfully parsed code blocks", "count", len(blocks)) // Show block details at debug level for i, block := range blocks { - log.Debugf("Block %d:", i+1) - log.Debugf(" Language: %s", block.Language) - log.Debugf(" Background: %v", block.Background) + log.Debug("Block details", "block", i+1, "language", block.Language, "background", block.Background) if block.OutputContains != "" { - log.Debugf(" Expected output: %s", block.OutputContains) + log.Debug("Expected output", "block", i+1, "output", block.OutputContains) } } @@ -327,7 +326,7 @@ func runPreCommands(commands []string) error { log := logger.GetLogger() log.Info("Running pre-commands") for _, command := range commands { - log.Infof("Running: %s", command) + log.Info("Running", "command", command) // Create command cmd := exec.Command("bash", "-c", command) @@ -336,7 +335,7 @@ func runPreCommands(commands []string) error { // Run the command if err := cmd.Run(); err != nil { - log.Warnf("Pre-command '%s' failed (ignoring): %v", command, err) + log.Warn("Pre-command failed (ignoring)", "command", command, "err", err) // Continue with other pre-commands even if one fails } } @@ -348,7 +347,7 @@ func runCleanupCommands(commands []string) { log := logger.GetLogger() log.Debug("Running cleanup commands") for _, command := range commands { - log.Infof("Running: %s", command) + log.Info("Running", "command", command) // Create command cmd := exec.Command("bash", "-c", command) @@ -357,7 +356,7 @@ func runCleanupCommands(commands []string) { // Run the command if err := cmd.Run(); err != nil { - log.Errorf("Error running cleanup command '%s': %v", command, err) + log.Error("Error running cleanup command", "command", command, "err", err) // Continue with other cleanup commands even if one fails } } diff --git a/parser/codeblocks.go b/parser/codeblocks.go index 337939b..c5af076 100644 --- a/parser/codeblocks.go +++ b/parser/codeblocks.go @@ -11,7 +11,6 @@ import ( "github.com/reecepbcups/docci/logger" "github.com/reecepbcups/docci/types" - "github.com/sirupsen/logrus" ) // CodeBlock represents a parsed code block with its metadata @@ -121,7 +120,7 @@ func ParseCodeBlocksWithFileName(markdown string, fileName string) ([]CodeBlock, currentBlock.finalize() codeBlocks = append(codeBlocks, *currentBlock) } else { - logger.GetLogger().Debugf("Skipping code block due to OS restriction: block requires '%s', current OS is '%s'", currentBlock.OS, GetCurrentOS()) + logger.GetLogger().Debug("Skipping code block due to OS restriction", "required_os", currentBlock.OS, "current_os", GetCurrentOS()) } currentBlock = nil } @@ -133,7 +132,7 @@ func ParseCodeBlocksWithFileName(markdown string, fileName string) ([]CodeBlock, if currentBlock != nil { currentBlock.content.WriteString(line) currentBlock.content.WriteString("\n") - logger.GetLogger().Debugf("Adding line %d to code block: %s", lineNumber, line) + logger.GetLogger().Debug("Adding line to code block", "line_number", lineNumber, "content", line) } } @@ -143,8 +142,7 @@ func ParseCodeBlocksWithFileName(markdown string, fileName string) ([]CodeBlock, // Parse tags first to check for ignore tags, err := ParseTags(line) if err != nil { - logger.GetLogger().Errorf("Error parsing tags on line %d: %v", lineNumber, err) - panic(err) // bad parses should STOP the program so the user can fix. (i.e. bad tags) + return nil, fmt.Errorf("line %d: parse tags: %w", lineNumber, err) } if tags.Ignore { @@ -213,7 +211,7 @@ func ParseCodeBlocksWithFileName(markdown string, fileName string) ([]CodeBlock, // WaitForEndpoint polls an HTTP endpoint until it's ready or timeout is reached func WaitForEndpoint(url string, timeoutSecs int) error { log := logger.GetLogger() - log.Infof("Waiting for endpoint %s to be ready (timeout: %d seconds)", url, timeoutSecs) + log.Info("Waiting for endpoint to be ready", "url", url, "timeout_secs", timeoutSecs) timeout := time.Duration(timeoutSecs) * time.Second client := &http.Client{ @@ -229,7 +227,7 @@ func WaitForEndpoint(url string, timeoutSecs int) error { resp, err := client.Get(url) if err == nil && resp.StatusCode >= 200 && resp.StatusCode < 300 { resp.Body.Close() - log.Infof("Endpoint %s is ready (status: %d)", url, resp.StatusCode) + log.Info("Endpoint is ready", "url", url, "status", resp.StatusCode) return nil } @@ -237,7 +235,7 @@ func WaitForEndpoint(url string, timeoutSecs int) error { resp.Body.Close() } - log.Debugf("Endpoint %s not ready yet (attempt failed), retrying in 1 second...", url) + log.Debug("Endpoint not ready yet, retrying in 1 second", "url", url) time.Sleep(1 * time.Second) } } @@ -257,7 +255,7 @@ func BuildExecutableScriptWithOptions(blocks []CodeBlock, opts types.DocciOpts) validationMap := make(map[int]string) // maps block index to expected output assertFailureMap := make(map[int]bool) // maps block index to assert-failure flag var backgroundPIDs []string - debugEnabled := log.Level >= logrus.DebugLevel + debugEnabled := logger.IsDebugEnabled() // Always generate markers for parsing, visibility controlled in executor @@ -336,7 +334,7 @@ func BuildExecutableScriptWithOptions(blocks []CodeBlock, opts types.DocciOpts) oldText := parts[0] newText := parts[1] blockContent = strings.ReplaceAll(blockContent, oldText, newText) - log.Debugf("Applied text replacement in block %d: '%s' -> '%s'", block.Index, oldText, newText) + log.Debug("Applied text replacement", "block", block.Index, "old", oldText, "new", newText) } } diff --git a/parser/codeblocks_test.go b/parser/codeblocks_test.go index 358b5e6..7ac5d6d 100644 --- a/parser/codeblocks_test.go +++ b/parser/codeblocks_test.go @@ -58,7 +58,10 @@ func TestCodeBlockExecute(t *testing.T) { require.Equal(t, 0, len(assertFailureMap), "Expected no assert-failure blocks") - resp := executor.Exec(script) + resp, err := executor.Exec(script) + if err != nil { + t.Fatalf("Error starting execution: %v", err) + } if resp.Error != nil { t.Errorf("Error executing code block: %v, Status Code: %d", resp.Error, resp.ExitCode) } @@ -230,7 +233,8 @@ func TestDelayPerCmdExecutionTiming(t *testing.T) { script, _, _ := BuildExecutableScript(blocks) start := time.Now() - resp := executor.Exec(script) + resp, err := executor.Exec(script) + require.NoError(t, err, "Exec should start") duration := time.Since(start) require.NoError(t, resp.Error, "Script execution should succeed") @@ -277,10 +281,11 @@ func TestCommandSubstitutionNoDebugContamination(t *testing.T) { // Build and execute the script script, _, _ := BuildExecutableScript(blocks) - resp := executor.Exec(script) + resp, err := executor.Exec(script) + require.NoError(t, err, "Exec should start") require.NoError(t, resp.Error, "Script execution should succeed") - + // The output should contain a date in the format YYYY-MM-DD // and NOT contain "Executing CMD:" or "date +" require.Contains(t, resp.Stdout, "Date is: ") diff --git a/parser/tags.go b/parser/tags.go index d6154d9..70bc880 100644 --- a/parser/tags.go +++ b/parser/tags.go @@ -37,8 +37,6 @@ type MetaTag struct { LineReplace string // docci-line-replace: Replace content at line N or N-M (e.g., "3" or "7-9") } -var tags string - const ( TagIgnore = "docci-ignore" TagOutputContains = "docci-output-contains" @@ -218,7 +216,7 @@ func ParseTags(line string) (MetaTag, error) { re := regexp.MustCompile(pattern) matches := re.FindAllString(line, -1) - logger.GetLogger().Debugf("Potential tags found: %+v", matches) + logger.GetLogger().Debug("Potential tags found", "matches", matches) return parseTagsFromPotential(matches) } @@ -231,10 +229,10 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { // if there is a = present, we need to extract the value content := "" if strings.Contains(tag, "=") { - logger.GetLogger().Debugf("Tag with content found: %s", tag) + logger.GetLogger().Debug("Tag with content found", "tag", tag) s := strings.SplitN(tag, "=", 2) // Use SplitN to only split on first = - logger.GetLogger().Debugf("Split tag into parts: %+v", s) + logger.GetLogger().Debug("Split tag into parts", "parts", s) tag = s[0] // take only the tag part before the = content = s[1] // take the content part after the = @@ -258,7 +256,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { case TagIgnore: mt.Ignore = true case TagOutputContains: - logger.GetLogger().Debugf("Output contains tag found: %s with content: %s", tag, content) + logger.GetLogger().Debug("Output contains tag found", "tag", tag, "content", content) mt.OutputContains = content case TagBackground: mt.Background = true @@ -274,7 +272,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("background kill index must be positive (1-based) in docci-background-kill, got: %d", killIndex) } mt.BackgroundKill = killIndex - logger.GetLogger().Debugf("Background kill tag found with index: %d", killIndex) + logger.GetLogger().Debug("Background kill tag found", "index", killIndex) case TagAssertFailure: mt.AssertFailure = true case TagOS: @@ -301,7 +299,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { mt.WaitForEndpoint = url mt.WaitTimeoutSecs = timeout - logger.GetLogger().Debugf("Wait for endpoint tag found: %s with timeout: %d seconds", url, timeout) + logger.GetLogger().Debug("Wait for endpoint tag found", "url", url, "timeout_seconds", timeout) case TagRetry: if content == "" { return MetaTag{}, fmt.Errorf("docci-retry requires a value (number of retry attempts)") @@ -314,7 +312,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("retry count must be positive in docci-retry, got: %d", retryCount) } mt.RetryCount = retryCount - logger.GetLogger().Debugf("Retry tag found with count: %d", retryCount) + logger.GetLogger().Debug("Retry tag found", "count", retryCount) case TagDelayBefore: if content == "" { return MetaTag{}, fmt.Errorf("docci-delay-before requires a value (delay in seconds)") @@ -327,7 +325,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("delay seconds must be positive in docci-delay-before, got: %g", delayBefore) } mt.DelayBeforeSecs = delayBefore - logger.GetLogger().Debugf("Delay before tag found with seconds: %g", delayBefore) + logger.GetLogger().Debug("Delay before tag found", "seconds", delayBefore) case TagDelayAfter: if content == "" { return MetaTag{}, fmt.Errorf("docci-delay-after requires a value (delay in seconds)") @@ -340,7 +338,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("delay seconds must be positive in docci-delay-after, got: %g", delayAfter) } mt.DelayAfterSecs = delayAfter - logger.GetLogger().Debugf("Delay after tag found with seconds: %g", delayAfter) + logger.GetLogger().Debug("Delay after tag found", "seconds", delayAfter) case TagDelayPerCmd: if content == "" { return MetaTag{}, fmt.Errorf("docci-delay-per-cmd requires a value (delay in seconds)") @@ -353,7 +351,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("delay seconds must be positive in docci-delay-per-cmd, got: %g", delayPerCmd) } mt.DelayPerCmdSecs = delayPerCmd - logger.GetLogger().Debugf("Delay per command tag found with seconds: %g", delayPerCmd) + logger.GetLogger().Debug("Delay per command tag found", "seconds", delayPerCmd) case TagIfFileNotExists: if content == "" { return MetaTag{}, fmt.Errorf("docci-if-file-not-exists requires a file path") @@ -362,7 +360,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("docci-if-file-not-exists does not support file paths with spaces: %s", content) } mt.IfFileNotExists = content - logger.GetLogger().Debugf("If file not exists tag found with path: %s", content) + logger.GetLogger().Debug("If file not exists tag found", "path", content) case TagIfNotInstalled: if content == "" { return MetaTag{}, fmt.Errorf("docci-if-not-installed requires a command name") @@ -371,7 +369,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("docci-if-not-installed does not support commands with spaces: %s", content) } mt.IfNotInstalled = content - logger.GetLogger().Debugf("If not installed tag found with command: %s", content) + logger.GetLogger().Debug("If not installed tag found", "command", content) case TagReplaceText: if content == "" { return MetaTag{}, fmt.Errorf("docci-replace-text requires a value in format 'old;new'") @@ -385,16 +383,16 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("docci-replace-text both old and new text must be non-empty, got: %s", content) } mt.ReplaceText = content - logger.GetLogger().Debugf("Replace text tag found: %s", content) + logger.GetLogger().Debug("Replace text tag found", "content", content) case TagFile: if content == "" { return MetaTag{}, fmt.Errorf("docci-file requires a file name") } mt.File = content - logger.GetLogger().Debugf("File tag found with name: %s", content) + logger.GetLogger().Debug("File tag found", "name", content) case TagResetFile: mt.ResetFile = true - logger.GetLogger().Debugf("Reset file tag found") + logger.GetLogger().Debug("Reset file tag found") case TagLineInsert: if content == "" { return MetaTag{}, fmt.Errorf("docci-line-insert requires a line number") @@ -407,7 +405,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { return MetaTag{}, fmt.Errorf("line number must be positive (1-based) in docci-line-insert, got: %d", lineNum) } mt.LineInsert = lineNum - logger.GetLogger().Debugf("Line insert tag found at line: %d", lineNum) + logger.GetLogger().Debug("Line insert tag found", "line", lineNum) case TagLineReplace: if content == "" { return MetaTag{}, fmt.Errorf("docci-line-replace requires a line number or range (e.g., '3' or '7-9')") @@ -440,7 +438,7 @@ func parseTagsFromPotential(potential []string) (MetaTag, error) { } } mt.LineReplace = content - logger.GetLogger().Debugf("Line replace tag found: %s", content) + logger.GetLogger().Debug("Line replace tag found", "range", content) default: return MetaTag{}, fmt.Errorf("unknown tag: %s", normalizedTag) } @@ -500,9 +498,9 @@ func ShouldRunBasedOnCommandInstallation(ifNotInstalledCommand string) bool { // Only run the block if the command is NOT installed isInstalled := IsCommandInstalled(ifNotInstalledCommand) if isInstalled { - logger.GetLogger().Debugf("Skipping code block: command '%s' is already installed", ifNotInstalledCommand) + logger.GetLogger().Debug("Skipping code block: command already installed", "command", ifNotInstalledCommand) } else { - logger.GetLogger().Debugf("Including code block: command '%s' is not installed", ifNotInstalledCommand) + logger.GetLogger().Debug("Including code block: command not installed", "command", ifNotInstalledCommand) } return !isInstalled } diff --git a/parser/template_helpers.go b/parser/template_helpers.go index d3453bf..4897182 100644 --- a/parser/template_helpers.go +++ b/parser/template_helpers.go @@ -6,17 +6,18 @@ import ( "strings" ) -// replaceTemplateVars replaces template variables with their values +// replaceTemplateVars replaces template variables with their values. +// Panics if unreplaced variables remain - this indicates a programming bug. func replaceTemplateVars(template string, vars map[string]string) string { result := template for key, value := range vars { result = strings.ReplaceAll(result, "{{"+key+"}}", value) } - // Check for any remaining unreplaced variables + // Check for any remaining unreplaced variables - programming bug if found remaining := findUnreplacedVars(result) if len(remaining) > 0 { - panic(fmt.Sprintf("Unreplaced template variables found: %v.\nTemplate:\n%v\n", remaining, result)) + panic(fmt.Sprintf("unreplaced template vars (bug): %v", remaining)) } return result