Hallucinate some logs

Hallucinate more logs

fix(utils/db.go): handle auto migration errors gracefully

fix(utils/modifycommand.go): improve file matching accuracy

fix(processor/regex.go): improve capture group deduplication logic

fix(utils/db.go): add logging for database wrapper initialization

feat(processor/regex.go): preserve input order when deduplicating capture groups

fix(utils/modifycommand.go): add logging for file matching skips

feat(processor/regex.go): add logging for capture group processing

feat(main.go): add trace logging for arguments and parallel workers

fix(main.go): add trace logging for file content

fix(utils/db.go): add logging for database opening

fix(main.go): add trace logging for file processing

fix(utils/modifycommand.go): improve file matching by using absolute paths

feat(modifycommand.go): add trace logging for file matching in AssociateFilesWithCommands

feat(main.go): add per-file association summary for better visibility when debugging

main.go

@@ -1,11 +1,13 @@
 package main
 
 import (
+	"errors"
 	"flag"
 	"fmt"
 	"os"
 	"sort"
 	"sync"
+	"sync/atomic"
 	"time"
 
 	"cook/processor"
@@ -16,11 +18,14 @@ import (
 	logger "git.site.quack-lab.dev/dave/cylogger"
 )
 
+// mainLogger is a scoped logger for the main package.
+var mainLogger = logger.Default.WithPrefix("main")
+
 type GlobalStats struct {
-	TotalMatches            int
-	TotalModifications      int
-	ProcessedFiles          int
-	FailedFiles             int
+	TotalMatches            int64
+	TotalModifications      int64
+	ProcessedFiles          int64
+	FailedFiles             int64
 	ModificationsPerCommand sync.Map
 }
 
@@ -41,7 +46,7 @@ func main() {
 		fmt.Fprintf(os.Stderr, "        Set logging level: ERROR, WARNING, INFO, DEBUG, TRACE (default \"INFO\")\n")
 		fmt.Fprintf(os.Stderr, "\nExamples:\n")
 		fmt.Fprintf(os.Stderr, "  Regex mode (default):\n")
-		fmt.Fprintf(os.Stderr, "    %s \"<value>(\\d+)</value>\" \"*1.5\" data.xml\n", os.Args[0])
+		fmt.Fprintf(os.Stderr, "    %s \"<value>(\\\\d+)</value>\" \"*1.5\" data.xml\n", os.Args[0])
 		fmt.Fprintf(os.Stderr, "\nNote: v1, v2, etc. are used to refer to capture groups as numbers.\n")
 		fmt.Fprintf(os.Stderr, "      s1, s2, etc. are used to refer to capture groups as strings.\n")
 		fmt.Fprintf(os.Stderr, "      Helper functions: num(str) converts string to number, str(num) converts number to string\n")
@@ -55,89 +60,118 @@ func main() {
 	args := flag.Args()
 
 	logger.InitFlag()
-	logger.Info("Initializing with log level: %s", logger.GetLevel().String())
+	mainLogger.Info("Initializing with log level: %s", logger.GetLevel().String())
+	mainLogger.Trace("Full argv: %v", os.Args)
 
 	if flag.NArg() == 0 {
 		flag.Usage()
 		return
 	}
 
+	mainLogger.Debug("Getting database connection")
 	db, err := utils.GetDB()
 	if err != nil {
-		logger.Error("Failed to get database: %v", err)
+		mainLogger.Error("Failed to get database: %v", err)
 		return
 	}
+	mainLogger.Debug("Database connection established")
 
 	workdone, err := HandleSpecialArgs(args, err, db)
 	if err != nil {
-		logger.Error("Failed to handle special args: %v", err)
+		mainLogger.Error("Failed to handle special args: %v", err)
 		return
 	}
 	if workdone {
+		mainLogger.Info("Special arguments handled, exiting.")
 		return
 	}
 
 	// The plan is:
 	// Load all commands
+	mainLogger.Debug("Loading commands from arguments")
+	mainLogger.Trace("Arguments: %v", args)
 	commands, err := utils.LoadCommands(args)
 	if err != nil || len(commands) == 0 {
-		logger.Error("Failed to load commands: %v", err)
+		mainLogger.Error("Failed to load commands: %v", err)
 		flag.Usage()
 		return
 	}
+	mainLogger.Info("Loaded %d commands", len(commands))
 
 	if *utils.Filter != "" {
-		logger.Info("Filtering commands by name: %s", *utils.Filter)
+		mainLogger.Info("Filtering commands by name: %s", *utils.Filter)
 		commands = utils.FilterCommands(commands, *utils.Filter)
-		logger.Info("Filtered %d commands", len(commands))
+		mainLogger.Info("Filtered %d commands", len(commands))
 	}
 
 	// Then aggregate all the globs and deduplicate them
+	mainLogger.Debug("Aggregating globs and deduplicating")
 	globs := utils.AggregateGlobs(commands)
-	logger.Debug("Aggregated %d globs before deduplication", utils.CountGlobsBeforeDedup(commands))
+	mainLogger.Debug("Aggregated %d globs before deduplication", utils.CountGlobsBeforeDedup(commands))
 
 	for _, command := range commands {
-		logger.Trace("Command: %s", command.Name)
-		logger.Trace("Regex: %s", command.Regex)
-		logger.Trace("Files: %v", command.Files)
-		logger.Trace("Lua: %s", command.Lua)
-		logger.Trace("Reset: %t", command.Reset)
-		logger.Trace("Isolate: %t", command.Isolate)
-		logger.Trace("LogLevel: %s", command.LogLevel)
+		mainLogger.Trace("Command: %s", command.Name)
+		mainLogger.Trace("Regex: %s", command.Regex)
+		mainLogger.Trace("Files: %v", command.Files)
+		mainLogger.Trace("Lua: %s", command.Lua)
+		mainLogger.Trace("Reset: %t", command.Reset)
+		mainLogger.Trace("Isolate: %t", command.Isolate)
+		mainLogger.Trace("LogLevel: %s", command.LogLevel)
 	}
 
 	// Resolve all the files for all the globs
-	logger.Info("Found %d unique file patterns", len(globs))
+	mainLogger.Info("Found %d unique file patterns", len(globs))
+	mainLogger.Debug("Expanding glob patterns to files")
 	files, err := utils.ExpandGLobs(globs)
 	if err != nil {
-		logger.Error("Failed to expand file patterns: %v", err)
+		mainLogger.Error("Failed to expand file patterns: %v", err)
 		return
 	}
-	logger.Info("Found %d files to process", len(files))
+	mainLogger.Info("Found %d files to process", len(files))
+	mainLogger.Trace("Files to process: %v", files)
 
 	// Somehow connect files to commands via globs..
 	// For each file check every glob of every command
 	// Maybe memoize this part
 	// That way we know what commands affect what files
+	mainLogger.Debug("Associating files with commands")
 	associations, err := utils.AssociateFilesWithCommands(files, commands)
 	if err != nil {
-		logger.Error("Failed to associate files with commands: %v", err)
+		mainLogger.Error("Failed to associate files with commands: %v", err)
 		return
 	}
+	mainLogger.Debug("Files associated with commands")
+	mainLogger.Trace("File-command associations: %v", associations)
+	// Per-file association summary for better visibility when debugging
+	for file, assoc := range associations {
+		cmdNames := make([]string, 0, len(assoc.Commands))
+		for _, c := range assoc.Commands {
+			cmdNames = append(cmdNames, c.Name)
+		}
+		isoNames := make([]string, 0, len(assoc.IsolateCommands))
+		for _, c := range assoc.IsolateCommands {
+			isoNames = append(isoNames, c.Name)
+		}
+		mainLogger.Debug("File %q has %d regular and %d isolate commands", file, len(assoc.Commands), len(assoc.IsolateCommands))
+		mainLogger.Trace("\tRegular: %v", cmdNames)
+		mainLogger.Trace("\tIsolate: %v", isoNames)
+	}
 
+	mainLogger.Debug("Resetting files where necessary")
 	err = utils.ResetWhereNecessary(associations, db)
 	if err != nil {
-		logger.Error("Failed to reset files where necessary: %v", err)
+		mainLogger.Error("Failed to reset files where necessary: %v", err)
 		return
 	}
+	mainLogger.Debug("Files reset where necessary")
 
 	// Then for each file run all commands associated with the file
 	workers := make(chan struct{}, *utils.ParallelFiles)
 	wg := sync.WaitGroup{}
+	mainLogger.Debug("Starting file processing with %d parallel workers", *utils.ParallelFiles)
 
 	// Add performance tracking
 	startTime := time.Now()
-	var fileMutex sync.Mutex
 
 	// Create a map to store loggers for each command
 	commandLoggers := make(map[string]*logger.Logger)
@@ -157,10 +191,10 @@ func main() {
 		cmdLogLevel := logger.ParseLevel(command.LogLevel)
 
 		// Create a logger with the command name as a field
-		commandLoggers[command.Name] = logger.WithField("command", cmdName)
+		commandLoggers[command.Name] = logger.Default.WithField("command", cmdName)
 		commandLoggers[command.Name].SetLevel(cmdLogLevel)
 
-		logger.Debug("Created logger for command %q with log level %s", cmdName, cmdLogLevel.String())
+		mainLogger.Debug("Created logger for command %q with log level %s", cmdName, cmdLogLevel.String())
 	}
 
 	for file, association := range associations {
@@ -172,51 +206,72 @@ func main() {
 			// Track per-file processing time
 			fileStartTime := time.Now()
 
-			logger.Debug("Reading file %q", file)
+			mainLogger.Debug("Reading file %q", file)
 			fileData, err := os.ReadFile(file)
 			if err != nil {
-				logger.Error("Failed to read file %q: %v", file, err)
+				mainLogger.Error("Failed to read file %q: %v", file, err)
+				atomic.AddInt64(&stats.FailedFiles, 1)
 				return
 			}
 			fileDataStr := string(fileData)
+			mainLogger.Trace("File %q content: %s", file, utils.LimitString(fileDataStr, 500))
 
-			logger.Debug("Saving file %q to database", file)
+			isChanged := false
+			mainLogger.Debug("Running isolate commands for file %q", file)
+			fileDataStr, err = RunIsolateCommands(association, file, fileDataStr)
+			if err != nil && err != NothingToDo {
+				mainLogger.Error("Failed to run isolate commands for file %q: %v", file, err)
+				atomic.AddInt64(&stats.FailedFiles, 1)
+				return
+			}
+			if err != NothingToDo {
+				isChanged = true
+			}
+
+			mainLogger.Debug("Running other commands for file %q", file)
+			fileDataStr, err = RunOtherCommands(file, fileDataStr, association, commandLoggers)
+			if err != nil && err != NothingToDo {
+				mainLogger.Error("Failed to run other commands for file %q: %v", file, err)
+				atomic.AddInt64(&stats.FailedFiles, 1)
+				return
+			}
+			if err != NothingToDo {
+				isChanged = true
+			}
+
+			if isChanged {
+				mainLogger.Debug("Saving file %q to database", file)
 				err = db.SaveFile(file, fileData)
 				if err != nil {
-				logger.Error("Failed to save file %q to database: %v", file, err)
+					mainLogger.Error("Failed to save file %q to database: %v", file, err)
+					atomic.AddInt64(&stats.FailedFiles, 1)
 					return
 				}
-
-			logger.Debug("Running isolate commands for file %q", file)
-			fileDataStr, err = RunIsolateCommands(association, file, fileDataStr, &fileMutex)
-			if err != nil {
-				logger.Error("Failed to run isolate commands for file %q: %v", file, err)
-				return
+				mainLogger.Debug("File %q saved to database", file)
 			}
 
-			logger.Debug("Running other commands for file %q", file)
-			fileDataStr, err = RunOtherCommands(file, fileDataStr, association, &fileMutex, commandLoggers)
-			if err != nil {
-				logger.Error("Failed to run other commands for file %q: %v", file, err)
-				return
-			}
-
-			logger.Debug("Writing file %q", file)
+			mainLogger.Debug("Writing file %q", file)
 			err = os.WriteFile(file, []byte(fileDataStr), 0644)
 			if err != nil {
-				logger.Error("Failed to write file %q: %v", file, err)
+				mainLogger.Error("Failed to write file %q: %v", file, err)
+				atomic.AddInt64(&stats.FailedFiles, 1)
 				return
 			}
+			mainLogger.Debug("File %q written", file)
 
-			logger.Debug("File %q processed in %v", file, time.Since(fileStartTime))
+			// Only increment ProcessedFiles once per file, after all processing is complete
+			atomic.AddInt64(&stats.ProcessedFiles, 1)
+
+			mainLogger.Debug("File %q processed in %v", file, time.Since(fileStartTime))
 		}, file, commands)
 	}
 	wg.Wait()
 
 	processingTime := time.Since(startTime)
-	logger.Info("Processing completed in %v", processingTime)
-	if stats.ProcessedFiles > 0 {
-		logger.Info("Average time per file: %v", processingTime/time.Duration(stats.ProcessedFiles))
+	mainLogger.Info("Processing completed in %v", processingTime)
+	processedFiles := atomic.LoadInt64(&stats.ProcessedFiles)
+	if processedFiles > 0 {
+		mainLogger.Info("Average time per file: %v", processingTime/time.Duration(processedFiles))
 	}
 
 	// TODO: Also give each command its own logger, maybe prefix it with something... Maybe give commands a name?
@@ -226,44 +281,46 @@ func main() {
 	// TODO: What to do with git? Figure it out ....
 
 	// if *gitFlag {
-	// 	logger.Info("Git integration enabled, setting up git repository")
+	// 	mainLogger.Info("Git integration enabled, setting up git repository")
 	// 	err := setupGit()
 	// 	if err != nil {
-	// 		logger.Error("Failed to setup git: %v", err)
+	// 		mainLogger.Error("Failed to setup git: %v", err)
 	// 		fmt.Fprintf(os.Stderr, "Error setting up git: %v\n", err)
 	// 		return
 	// 	}
 	// }
 
-	// logger.Debug("Expanding file patterns")
+	// mainLogger.Debug("Expanding file patterns")
 	// files, err := expandFilePatterns(filePatterns)
 	// if err != nil {
-	// 	logger.Error("Failed to expand file patterns: %v", err)
+	// 	mainLogger.Error("Failed to expand file patterns: %v", err)
 	// 	fmt.Fprintf(os.Stderr, "Error expanding file patterns: %v\n", err)
 	// 	return
 	// }
 
 	// if *gitFlag {
-	// 	logger.Info("Cleaning up git files before processing")
+	// 	mainLogger.Info("Cleaning up git files before processing")
 	// 	err := cleanupGitFiles(files)
 	// 	if err != nil {
-	// 		logger.Error("Failed to cleanup git files: %v", err)
+	// 		mainLogger.Error("Failed to cleanup git files: %v", err)
 	// 		fmt.Fprintf(os.Stderr, "Error cleaning up git files: %v\n", err)
 	// 		return
 	// 	}
 	// }
 	// if *resetFlag {
-	// 	logger.Info("Files reset to their original state, nothing more to do")
+	// 	mainLogger.Info("Files reset to their original state, nothing more to do")
 	// 	log.Printf("Files reset to their original state, nothing more to do")
 	// 	return
 	// }
 
 	// Print summary
-	if stats.TotalModifications == 0 {
-		logger.Warning("No modifications were made in any files")
+	totalModifications := atomic.LoadInt64(&stats.TotalModifications)
+	if totalModifications == 0 {
+		mainLogger.Warning("No modifications were made in any files")
 	} else {
-		logger.Info("Operation complete! Modified %d values in %d/%d files",
-			stats.TotalModifications, stats.ProcessedFiles, stats.ProcessedFiles+stats.FailedFiles)
+		failedFiles := atomic.LoadInt64(&stats.FailedFiles)
+		mainLogger.Info("Operation complete! Modified %d values in %d/%d files",
+			totalModifications, processedFiles, processedFiles+failedFiles)
 		sortedCommands := []string{}
 		stats.ModificationsPerCommand.Range(func(key, value interface{}) bool {
 			sortedCommands = append(sortedCommands, key.(string))
@@ -274,41 +331,48 @@ func main() {
 		for _, command := range sortedCommands {
 			count, _ := stats.ModificationsPerCommand.Load(command)
 			if count.(int) > 0 {
-				logger.Info("\tCommand %q made %d modifications", command, count)
+				mainLogger.Info("\tCommand %q made %d modifications", command, count)
 			} else {
-				logger.Warning("\tCommand %q made no modifications", command)
+				mainLogger.Warning("\tCommand %q made no modifications", command)
 			}
 		}
 	}
 }
 
 func HandleSpecialArgs(args []string, err error, db utils.DB) (bool, error) {
+	handleSpecialArgsLogger := logger.Default.WithPrefix("HandleSpecialArgs")
+	handleSpecialArgsLogger.Debug("Handling special arguments: %v", args)
 	switch args[0] {
 	case "reset":
+		handleSpecialArgsLogger.Info("Resetting all files")
 		err = utils.ResetAllFiles(db)
 		if err != nil {
-			logger.Error("Failed to reset all files: %v", err)
+			handleSpecialArgsLogger.Error("Failed to reset all files: %v", err)
 			return true, err
 		}
-		logger.Info("All files reset")
+		handleSpecialArgsLogger.Info("All files reset")
 		return true, nil
 	case "dump":
+		handleSpecialArgsLogger.Info("Dumping all files from database")
 		err = db.RemoveAllFiles()
 		if err != nil {
-			logger.Error("Failed to remove all files from database: %v", err)
+			handleSpecialArgsLogger.Error("Failed to remove all files from database: %v", err)
 			return true, err
 		}
-		logger.Info("All files removed from database")
+		handleSpecialArgsLogger.Info("All files removed from database")
 		return true, nil
 	}
+	handleSpecialArgsLogger.Debug("No special arguments handled, returning false")
 	return false, nil
 }
 
 func CreateExampleConfig() {
+	createExampleConfigLogger := logger.Default.WithPrefix("CreateExampleConfig")
+	createExampleConfigLogger.Debug("Creating example configuration file")
 	commands := []utils.ModifyCommand{
 		{
 			Name:     "DoubleNumericValues",
-			Regex:    "<value>(\\d+)</value>",
+			Regex:    "<value>(\\d+)<\\/value>",
 			Lua:      "v1 * 2",
 			Files:    []string{"data/*.xml"},
 			LogLevel: "INFO",
@@ -322,7 +386,7 @@ func CreateExampleConfig() {
 		},
 		{
 			Name:     "IsolatedTagUpdate",
-			Regex:    "<tag>(.*?)</tag>",
+			Regex:    "<tag>(.*?)<\\/tag>",
 			Lua:      "string.upper(s1)",
 			Files:    []string{"config.xml"},
 			Isolate:  true,
@@ -333,22 +397,30 @@ func CreateExampleConfig() {
 
 	data, err := yaml.Marshal(commands)
 	if err != nil {
-		logger.Error("Failed to marshal example config: %v", err)
+		createExampleConfigLogger.Error("Failed to marshal example config: %v", err)
 		return
 	}
 
+	createExampleConfigLogger.Debug("Writing example_cook.yml")
 	err = os.WriteFile("example_cook.yml", data, 0644)
 	if err != nil {
-		logger.Error("Failed to write example_cook.yml: %v", err)
+		createExampleConfigLogger.Error("Failed to write example_cook.yml: %v", err)
 		return
 	}
 
-	logger.Info("Wrote example_cook.yml")
+	createExampleConfigLogger.Info("Wrote example_cook.yml")
 }
 
-func RunOtherCommands(file string, fileDataStr string, association utils.FileCommandAssociation, fileMutex *sync.Mutex, commandLoggers map[string]*logger.Logger) (string, error) {
+var NothingToDo = errors.New("nothing to do")
+
+func RunOtherCommands(file string, fileDataStr string, association utils.FileCommandAssociation, commandLoggers map[string]*logger.Logger) (string, error) {
+	runOtherCommandsLogger := mainLogger.WithPrefix("RunOtherCommands").WithField("file", file)
+	runOtherCommandsLogger.Debug("Running other commands for file")
+	runOtherCommandsLogger.Trace("File data before modifications: %s", utils.LimitString(fileDataStr, 200))
+
 	// Aggregate all the modifications and execute them
 	modifications := []utils.ReplaceCommand{}
+	numCommandsConsidered := 0
 	for _, command := range association.Commands {
 		// Use command-specific logger if available, otherwise fall back to default logger
 		cmdLogger := logger.Default
@@ -356,10 +428,11 @@ func RunOtherCommands(file string, fileDataStr string, association utils.FileCom
 			cmdLogger = cmdLog
 		}
 
-		cmdLogger.Info("Processing file %q with command %q", file, command.Regex)
+		cmdLogger.Debug("Begin processing file with command %q", command.Regex)
+		numCommandsConsidered++
 		newModifications, err := processor.ProcessRegex(fileDataStr, command, file)
 		if err != nil {
-			logger.Error("Failed to process file %q with command %q: %v", file, command.Regex, err)
+			runOtherCommandsLogger.Error("Failed to process file with command %q: %v", command.Regex, err)
 			continue
 		}
 		modifications = append(modifications, newModifications...)
@@ -373,49 +446,65 @@ func RunOtherCommands(file string, fileDataStr string, association utils.FileCom
 		stats.ModificationsPerCommand.Store(command.Name, count.(int)+len(newModifications))
 
 		cmdLogger.Debug("Command %q generated %d modifications", command.Name, len(newModifications))
+		cmdLogger.Trace("Modifications generated by command %q: %v", command.Name, newModifications)
+		if len(newModifications) == 0 {
+			cmdLogger.Debug("No modifications yielded by command %q", command.Name)
+		}
 	}
 
+	runOtherCommandsLogger.Debug("Aggregated %d modifications from %d commands", len(modifications), numCommandsConsidered)
+	runOtherCommandsLogger.Trace("All aggregated modifications: %v", modifications)
+
 	if len(modifications) == 0 {
-		logger.Warning("No modifications found for file %q", file)
-		return fileDataStr, nil
+		runOtherCommandsLogger.Warning("No modifications found for file")
+		return fileDataStr, NothingToDo
 	}
+	runOtherCommandsLogger.Debug("Executing %d modifications for file", len(modifications))
 
 	// Sort commands in reverse order for safe replacements
 	var count int
 	fileDataStr, count = utils.ExecuteModifications(modifications, fileDataStr)
+	runOtherCommandsLogger.Trace("File data after modifications: %s", utils.LimitString(fileDataStr, 200))
 
-	fileMutex.Lock()
-	stats.ProcessedFiles++
-	stats.TotalModifications += count
-	fileMutex.Unlock()
+	atomic.AddInt64(&stats.TotalModifications, int64(count))
 
-	logger.Info("Executed %d modifications for file %q", count, file)
+	runOtherCommandsLogger.Info("Executed %d modifications for file", count)
 	return fileDataStr, nil
 }
 
-func RunIsolateCommands(association utils.FileCommandAssociation, file string, fileDataStr string, fileMutex *sync.Mutex) (string, error) {
+func RunIsolateCommands(association utils.FileCommandAssociation, file string, fileDataStr string) (string, error) {
+	runIsolateCommandsLogger := mainLogger.WithPrefix("RunIsolateCommands").WithField("file", file)
+	runIsolateCommandsLogger.Debug("Running isolate commands for file")
+	runIsolateCommandsLogger.Trace("File data before isolate modifications: %s", utils.LimitString(fileDataStr, 200))
+
+	anythingDone := false
 	for _, isolateCommand := range association.IsolateCommands {
-		logger.Info("Processing file %q with isolate command %q", file, isolateCommand.Regex)
+		runIsolateCommandsLogger.Debug("Begin processing file with isolate command %q", isolateCommand.Regex)
 		modifications, err := processor.ProcessRegex(fileDataStr, isolateCommand, file)
 		if err != nil {
-			logger.Error("Failed to process file %q with isolate command %q: %v", file, isolateCommand.Regex, err)
+			runIsolateCommandsLogger.Error("Failed to process file with isolate command %q: %v", isolateCommand.Regex, err)
 			continue
 		}
 
 		if len(modifications) == 0 {
-			logger.Warning("No modifications found for file %q", file)
+			runIsolateCommandsLogger.Debug("Isolate command %q produced no modifications", isolateCommand.Name)
 			continue
 		}
+		anythingDone = true
 
+		runIsolateCommandsLogger.Debug("Executing %d isolate modifications for file", len(modifications))
+		runIsolateCommandsLogger.Trace("Isolate modifications: %v", modifications)
 		var count int
 		fileDataStr, count = utils.ExecuteModifications(modifications, fileDataStr)
+		runIsolateCommandsLogger.Trace("File data after isolate modifications: %s", utils.LimitString(fileDataStr, 200))
 
-		fileMutex.Lock()
-		stats.ProcessedFiles++
-		stats.TotalModifications += count
-		fileMutex.Unlock()
+		atomic.AddInt64(&stats.TotalModifications, int64(count))
 
-		logger.Info("Executed %d isolate modifications for file %q", count, file)
+		runIsolateCommandsLogger.Info("Executed %d isolate modifications for file", count)
+	}
+	if !anythingDone {
+		runIsolateCommandsLogger.Debug("No isolate modifications were made for file")
+		return fileDataStr, NothingToDo
 	}
 	return fileDataStr, nil
 }

processor/processor.go

@@ -6,151 +6,106 @@ import (
 	"net/http"
 	"strings"
 
+	"cook/utils"
+
 	logger "git.site.quack-lab.dev/dave/cylogger"
 	lua "github.com/yuin/gopher-lua"
 )
 
+// processorLogger is a scoped logger for the processor package.
+var processorLogger = logger.Default.WithPrefix("processor")
+
 // Maybe we make this an interface again for the shits and giggles
 // We will see, it could easily be...
 
 func NewLuaState() (*lua.LState, error) {
+	newLStateLogger := processorLogger.WithPrefix("NewLuaState")
+	newLStateLogger.Debug("Creating new Lua state")
 	L := lua.NewState()
 	// defer L.Close()
 
 	// Load math library
-	logger.Debug("Loading Lua math library")
+	newLStateLogger.Debug("Loading Lua math library")
 	L.Push(L.GetGlobal("require"))
 	L.Push(lua.LString("math"))
 	if err := L.PCall(1, 1, nil); err != nil {
-		logger.Error("Failed to load Lua math library: %v", err)
+		newLStateLogger.Error("Failed to load Lua math library: %v", err)
 		return nil, fmt.Errorf("error loading Lua math library: %v", err)
 	}
+	newLStateLogger.Debug("Lua math library loaded")
 
 	// Initialize helper functions
-	logger.Debug("Initializing Lua helper functions")
+	newLStateLogger.Debug("Initializing Lua helper functions")
 	if err := InitLuaHelpers(L); err != nil {
-		logger.Error("Failed to initialize Lua helper functions: %v", err)
+		newLStateLogger.Error("Failed to initialize Lua helper functions: %v", err)
 		return nil, err
 	}
+	newLStateLogger.Debug("Lua helper functions initialized")
 
+	newLStateLogger.Debug("New Lua state created successfully")
 	return L, nil
 }
 
-// func Process(filename string, pattern string, luaExpr string) (int, int, error) {
-// 	logger.Debug("Processing file %q with pattern %q", filename, pattern)
-//
-// 	// Read file content
-// 	cwd, err := os.Getwd()
-// 	if err != nil {
-// 		logger.Error("Failed to get current working directory: %v", err)
-// 		return 0, 0, fmt.Errorf("error getting current working directory: %v", err)
-// 	}
-//
-// 	fullPath := filepath.Join(cwd, filename)
-// 	logger.Trace("Reading file from: %s", fullPath)
-//
-// 	stat, err := os.Stat(fullPath)
-// 	if err != nil {
-// 		logger.Error("Failed to stat file %s: %v", fullPath, err)
-// 		return 0, 0, fmt.Errorf("error getting file info: %v", err)
-// 	}
-// 	logger.Debug("File size: %d bytes, modified: %s", stat.Size(), stat.ModTime().Format(time.RFC3339))
-//
-// 	content, err := os.ReadFile(fullPath)
-// 	if err != nil {
-// 		logger.Error("Failed to read file %s: %v", fullPath, err)
-// 		return 0, 0, fmt.Errorf("error reading file: %v", err)
-// 	}
-//
-// 	fileContent := string(content)
-// 	logger.Trace("File read successfully: %d bytes, hash: %x", len(content), md5sum(content))
-//
-// 	// Detect and log file type
-// 	fileType := detectFileType(filename, fileContent)
-// 	if fileType != "" {
-// 		logger.Debug("Detected file type: %s", fileType)
-// 	}
-//
-// 	// Process the content
-// 	logger.Debug("Starting content processing")
-// 	modifiedContent, modCount, matchCount, err := ProcessContent(fileContent, pattern, luaExpr)
-// 	if err != nil {
-// 		logger.Error("Processing error: %v", err)
-// 		return 0, 0, err
-// 	}
-//
-// 	logger.Debug("Processing results: %d matches, %d modifications", matchCount, modCount)
-//
-// 	// If we made modifications, save the file
-// 	if modCount > 0 {
-// 		// Calculate changes summary
-// 		changePercent := float64(len(modifiedContent)) / float64(len(fileContent)) * 100
-// 		logger.Info("File size change: %d → %d bytes (%.1f%%)",
-// 			len(fileContent), len(modifiedContent), changePercent)
-//
-// 		logger.Debug("Writing modified content to %s", fullPath)
-// 		err = os.WriteFile(fullPath, []byte(modifiedContent), 0644)
-// 		if err != nil {
-// 			logger.Error("Failed to write to file %s: %v", fullPath, err)
-// 			return 0, 0, fmt.Errorf("error writing file: %v", err)
-// 		}
-// 		logger.Debug("File written successfully, new hash: %x", md5sum([]byte(modifiedContent)))
-// 	} else if matchCount > 0 {
-// 		logger.Debug("No content modifications needed for %d matches", matchCount)
-// 	} else {
-// 		logger.Debug("No matches found in file")
-// 	}
-//
-// 	return modCount, matchCount, nil
-// }
-
 // FromLua converts a Lua table to a struct or map recursively
 func FromLua(L *lua.LState, luaValue lua.LValue) (interface{}, error) {
+	fromLuaLogger := processorLogger.WithPrefix("FromLua").WithField("luaType", luaValue.Type().String())
+	fromLuaLogger.Debug("Converting Lua value to Go interface")
 	switch v := luaValue.(type) {
-	// Well shit...
-	// Tables in lua are both maps and arrays
-	// As arrays they are ordered and as maps, obviously, not
-	// So when we parse them to a go map we fuck up the order for arrays
-	// We have to find a better way....
 	case *lua.LTable:
+		fromLuaLogger.Debug("Processing Lua table")
 		isArray, err := IsLuaTableArray(L, v)
 		if err != nil {
+			fromLuaLogger.Error("Failed to determine if Lua table is array: %v", err)
 			return nil, err
 		}
+		fromLuaLogger.Debug("Lua table is array: %t", isArray)
 		if isArray {
+			fromLuaLogger.Debug("Converting Lua table to Go array")
 			result := make([]interface{}, 0)
 			v.ForEach(func(key lua.LValue, value lua.LValue) {
 				converted, _ := FromLua(L, value)
 				result = append(result, converted)
 			})
+			fromLuaLogger.Trace("Converted Go array: %v", result)
 			return result, nil
 		} else {
+			fromLuaLogger.Debug("Converting Lua table to Go map")
 			result := make(map[string]interface{})
 			v.ForEach(func(key lua.LValue, value lua.LValue) {
 				converted, _ := FromLua(L, value)
 				result[key.String()] = converted
 			})
+			fromLuaLogger.Trace("Converted Go map: %v", result)
 			return result, nil
 		}
 	case lua.LString:
+		fromLuaLogger.Debug("Converting Lua string to Go string")
+		fromLuaLogger.Trace("Lua string: %q", string(v))
 		return string(v), nil
 	case lua.LBool:
+		fromLuaLogger.Debug("Converting Lua boolean to Go boolean")
+		fromLuaLogger.Trace("Lua boolean: %t", bool(v))
 		return bool(v), nil
 	case lua.LNumber:
+		fromLuaLogger.Debug("Converting Lua number to Go float64")
+		fromLuaLogger.Trace("Lua number: %f", float64(v))
 		return float64(v), nil
 	default:
+		fromLuaLogger.Debug("Unsupported Lua type, returning nil")
 		return nil, nil
 	}
 }
 
 func IsLuaTableArray(L *lua.LState, v *lua.LTable) (bool, error) {
-	logger.Trace("Checking if Lua table is an array")
+	isLuaTableArrayLogger := processorLogger.WithPrefix("IsLuaTableArray")
+	isLuaTableArrayLogger.Debug("Checking if Lua table is an array")
+	isLuaTableArrayLogger.Trace("Lua table input: %v", v)
 	L.SetGlobal("table_to_check", v)
 
 	// Use our predefined helper function from InitLuaHelpers
 	err := L.DoString(`is_array = isArray(table_to_check)`)
 	if err != nil {
-		logger.Error("Error determining if table is an array: %v", err)
+		isLuaTableArrayLogger.Error("Error determining if table is an array: %v", err)
 		return false, fmt.Errorf("error determining if table is array: %w", err)
 	}
 
@@ -158,13 +113,15 @@ func IsLuaTableArray(L *lua.LState, v *lua.LTable) (bool, error) {
 	isArray := L.GetGlobal("is_array")
 	// LVIsFalse returns true if a given LValue is a nil or false otherwise false.
 	result := !lua.LVIsFalse(isArray)
-	logger.Trace("Lua table is array: %v", result)
+	isLuaTableArrayLogger.Debug("Lua table is array: %t", result)
+	isLuaTableArrayLogger.Trace("isArray result Lua value: %v", isArray)
 	return result, nil
 }
 
 // InitLuaHelpers initializes common Lua helper functions
 func InitLuaHelpers(L *lua.LState) error {
-	logger.Debug("Loading Lua helper functions")
+	initLuaHelpersLogger := processorLogger.WithPrefix("InitLuaHelpers")
+	initLuaHelpersLogger.Debug("Loading Lua helper functions")
 
 	helperScript := `
 -- Custom Lua helpers for math operations
@@ -245,26 +202,21 @@ end
 modified = false
 `
 	if err := L.DoString(helperScript); err != nil {
-		logger.Error("Failed to load Lua helper functions: %v", err)
+		initLuaHelpersLogger.Error("Failed to load Lua helper functions: %v", err)
 		return fmt.Errorf("error loading helper functions: %v", err)
 	}
+	initLuaHelpersLogger.Debug("Lua helper functions loaded")
 
-	logger.Debug("Setting up Lua print function to Go")
+	initLuaHelpersLogger.Debug("Setting up Lua print function to Go")
 	L.SetGlobal("print", L.NewFunction(printToGo))
 	L.SetGlobal("fetch", L.NewFunction(fetch))
+	initLuaHelpersLogger.Debug("Lua print and fetch functions bound to Go")
 	return nil
 }
 
-// LimitString truncates a string to maxLen and adds "..." if truncated
-func LimitString(s string, maxLen int) string {
-	s = strings.ReplaceAll(s, "\n", "\\n")
-	if len(s) <= maxLen {
-		return s
-	}
-	return s[:maxLen-3] + "..."
-}
-
 func PrependLuaAssignment(luaExpr string) string {
+	prependLuaAssignmentLogger := processorLogger.WithPrefix("PrependLuaAssignment").WithField("originalLuaExpr", luaExpr)
+	prependLuaAssignmentLogger.Debug("Prepending Lua assignment if necessary")
 	// Auto-prepend v1 for expressions starting with operators
 	if strings.HasPrefix(luaExpr, "*") ||
 		strings.HasPrefix(luaExpr, "/") ||
@@ -273,30 +225,29 @@ func PrependLuaAssignment(luaExpr string) string {
 		strings.HasPrefix(luaExpr, "^") ||
 		strings.HasPrefix(luaExpr, "%") {
 		luaExpr = "v1 = v1" + luaExpr
+		prependLuaAssignmentLogger.Debug("Prepended 'v1 = v1' due to operator prefix")
 	} else if strings.HasPrefix(luaExpr, "=") {
 		// Handle direct assignment with = operator
 		luaExpr = "v1 " + luaExpr
+		prependLuaAssignmentLogger.Debug("Prepended 'v1' due to direct assignment operator")
 	}
 
 	// Add assignment if needed
 	if !strings.Contains(luaExpr, "=") {
 		luaExpr = "v1 = " + luaExpr
+		prependLuaAssignmentLogger.Debug("Prepended 'v1 =' as no assignment was found")
 	}
+	prependLuaAssignmentLogger.Trace("Final Lua expression after prepending: %q", luaExpr)
 	return luaExpr
 }
 
 // BuildLuaScript prepares a Lua expression from shorthand notation
 func BuildLuaScript(luaExpr string) string {
-	logger.Debug("Building Lua script from expression: %s", luaExpr)
+	buildLuaScriptLogger := processorLogger.WithPrefix("BuildLuaScript").WithField("inputLuaExpr", luaExpr)
+	buildLuaScriptLogger.Debug("Building full Lua script from expression")
 
 	luaExpr = PrependLuaAssignment(luaExpr)
 
-	// This allows the user to specify whether or not they modified a value
-	// If they do nothing we assume they did modify (no return at all)
-	// If they return before our return then they themselves specify what they did
-	// If nothing is returned lua assumes nil
-	// So we can say our value was modified if the return value is either nil or true
-	// If the return value is false then the user wants to keep the original
 	fullScript := fmt.Sprintf(`
 		function run()
 			%s
@@ -304,11 +255,14 @@ func BuildLuaScript(luaExpr string) string {
 		local res = run()
 		modified = res == nil or res
 	`, luaExpr)
+	buildLuaScriptLogger.Trace("Generated full Lua script: %q", utils.LimitString(fullScript, 200))
 
 	return fullScript
 }
 
 func printToGo(L *lua.LState) int {
+	printToGoLogger := processorLogger.WithPrefix("printToGo")
+	printToGoLogger.Debug("Lua print function called, redirecting to Go logger")
 	top := L.GetTop()
 
 	args := make([]interface{}, top)
@@ -322,20 +276,26 @@ func printToGo(L *lua.LState) int {
 		parts = append(parts, fmt.Sprintf("%v", arg))
 	}
 	message := strings.Join(parts, " ")
+	printToGoLogger.Trace("Lua print message: %q", message)
 
 	// Use the LUA log level with a script tag
 	logger.Lua("%s", message)
+	printToGoLogger.Debug("Message logged from Lua")
 	return 0
 }
 
 func fetch(L *lua.LState) int {
+	fetchLogger := processorLogger.WithPrefix("fetch")
+	fetchLogger.Debug("Lua fetch function called")
 	// Get URL from first argument
 	url := L.ToString(1)
 	if url == "" {
+		fetchLogger.Error("Fetch failed: URL is required")
 		L.Push(lua.LNil)
 		L.Push(lua.LString("URL is required"))
 		return 2
 	}
+	fetchLogger.Debug("Fetching URL: %q", url)
 
 	// Get options from second argument if provided
 	var method string = "GET"
@@ -345,30 +305,38 @@ func fetch(L *lua.LState) int {
 	if L.GetTop() > 1 {
 		options := L.ToTable(2)
 		if options != nil {
+			fetchLogger.Debug("Processing fetch options")
 			// Get method
 			if methodVal := options.RawGetString("method"); methodVal != lua.LNil {
 				method = methodVal.String()
+				fetchLogger.Trace("Method from options: %q", method)
 			}
 
 			// Get headers
 			if headersVal := options.RawGetString("headers"); headersVal != lua.LNil {
 				if headersTable, ok := headersVal.(*lua.LTable); ok {
+					fetchLogger.Trace("Processing headers table")
 					headersTable.ForEach(func(key lua.LValue, value lua.LValue) {
 						headers[key.String()] = value.String()
+						fetchLogger.Trace("Header: %q = %q", key.String(), value.String())
 					})
 				}
+				fetchLogger.Trace("All headers: %v", headers)
 			}
 
 			// Get body
 			if bodyVal := options.RawGetString("body"); bodyVal != lua.LNil {
 				body = bodyVal.String()
+				fetchLogger.Trace("Body from options: %q", utils.LimitString(body, 100))
 			}
 		}
 	}
+	fetchLogger.Debug("Fetch request details: Method=%q, URL=%q, BodyLength=%d, Headers=%v", method, url, len(body), headers)
 
 	// Create HTTP request
 	req, err := http.NewRequest(method, url, strings.NewReader(body))
 	if err != nil {
+		fetchLogger.Error("Error creating HTTP request: %v", err)
 		L.Push(lua.LNil)
 		L.Push(lua.LString(fmt.Sprintf("Error creating request: %v", err)))
 		return 2
@@ -378,24 +346,33 @@ func fetch(L *lua.LState) int {
 	for key, value := range headers {
 		req.Header.Set(key, value)
 	}
+	fetchLogger.Debug("HTTP request created and headers set")
+	fetchLogger.Trace("HTTP Request: %+v", req)
 
 	// Make request
 	client := &http.Client{}
 	resp, err := client.Do(req)
 	if err != nil {
+		fetchLogger.Error("Error making HTTP request: %v", err)
 		L.Push(lua.LNil)
 		L.Push(lua.LString(fmt.Sprintf("Error making request: %v", err)))
 		return 2
 	}
-	defer resp.Body.Close()
+	defer func() {
+		fetchLogger.Debug("Closing HTTP response body")
+		resp.Body.Close()
+	}()
+	fetchLogger.Debug("HTTP request executed. Status Code: %d", resp.StatusCode)
 
 	// Read response body
 	bodyBytes, err := io.ReadAll(resp.Body)
 	if err != nil {
+		fetchLogger.Error("Error reading response body: %v", err)
 		L.Push(lua.LNil)
 		L.Push(lua.LString(fmt.Sprintf("Error reading response: %v", err)))
 		return 2
 	}
+	fetchLogger.Trace("Response body length: %d", len(bodyBytes))
 
 	// Create response table
 	responseTable := L.NewTable()
@@ -403,14 +380,18 @@ func fetch(L *lua.LState) int {
 	responseTable.RawSetString("statusText", lua.LString(resp.Status))
 	responseTable.RawSetString("ok", lua.LBool(resp.StatusCode >= 200 && resp.StatusCode < 300))
 	responseTable.RawSetString("body", lua.LString(string(bodyBytes)))
+	fetchLogger.Debug("Created Lua response table")
 
 	// Set headers in response
 	headersTable := L.NewTable()
 	for key, values := range resp.Header {
 		headersTable.RawSetString(key, lua.LString(values[0]))
+		fetchLogger.Trace("Response header: %q = %q", key, values[0])
 	}
 	responseTable.RawSetString("headers", headersTable)
+	fetchLogger.Trace("Full response table: %v", responseTable)
 
 	L.Push(responseTable)
+	fetchLogger.Debug("Pushed response table to Lua stack")
 	return 1
 }

processor/regex.go

@@ -12,6 +12,9 @@ import (
 	lua "github.com/yuin/gopher-lua"
 )
 
+// regexLogger is a scoped logger for the processor/regex package.
+var regexLogger = logger.Default.WithPrefix("processor/regex")
+
 type CaptureGroup struct {
 	Name    string
 	Value   string
@@ -23,52 +26,59 @@ type CaptureGroup struct {
 // The filename here exists ONLY so we can pass it to the lua environment
 // It's not used for anything else
 func ProcessRegex(content string, command utils.ModifyCommand, filename string) ([]utils.ReplaceCommand, error) {
-	var commands []utils.ReplaceCommand
-	logger.Trace("Processing regex: %q", command.Regex)
+	processRegexLogger := regexLogger.WithPrefix("ProcessRegex").WithField("commandName", command.Name).WithField("file", filename)
+	processRegexLogger.Debug("Starting regex processing for file")
+	processRegexLogger.Trace("Initial file content length: %d", len(content))
+	processRegexLogger.Trace("Command details: %+v", command)
 
+	var commands []utils.ReplaceCommand
 	// Start timing the regex processing
 	startTime := time.Now()
 
 	// We don't HAVE to do this multiple times for a pattern
 	// But it's quick enough for us to not care
 	pattern := resolveRegexPlaceholders(command.Regex)
+	processRegexLogger.Debug("Resolved regex placeholders. Pattern: %s", pattern)
+
 	// I'm not too happy about having to trim regex, we could have meaningful whitespace or newlines
 	// But it's a compromise that allows us to use | in yaml
 	// Otherwise we would have to escape every god damn pair of quotation marks
 	// And a bunch of other shit
 	pattern = strings.TrimSpace(pattern)
-	logger.Debug("Compiling regex pattern: %s", pattern)
+	processRegexLogger.Debug("Trimmed regex pattern: %s", pattern)
 
 	patternCompileStart := time.Now()
 	compiledPattern, err := regexp.Compile(pattern)
 	if err != nil {
-		logger.Error("Error compiling pattern: %v", err)
+		processRegexLogger.Error("Error compiling pattern %q: %v", pattern, err)
 		return commands, fmt.Errorf("error compiling pattern: %v", err)
 	}
-	logger.Debug("Compiled pattern successfully in %v: %s", time.Since(patternCompileStart), pattern)
+	processRegexLogger.Debug("Compiled pattern successfully in %v", time.Since(patternCompileStart))
 
 	// Same here, it's just string concatenation, it won't kill us
 	// More important is that we don't fuck up the command
 	// But we shouldn't be able to since it's passed by value
-	previous := command.Lua
+	previousLuaExpr := command.Lua
 	luaExpr := BuildLuaScript(command.Lua)
-	logger.Debug("Transformed Lua expression: %q → %q", previous, luaExpr)
+	processRegexLogger.Debug("Transformed Lua expression: %q → %q", previousLuaExpr, luaExpr)
+	processRegexLogger.Trace("Full Lua script: %q", utils.LimitString(luaExpr, 200))
 
 	// Process all regex matches
 	matchFindStart := time.Now()
 	indices := compiledPattern.FindAllStringSubmatchIndex(content, -1)
 	matchFindDuration := time.Since(matchFindStart)
 
-	logger.Debug("Found %d matches in content of length %d (search took %v)",
+	processRegexLogger.Debug("Found %d matches in content of length %d (search took %v)",
 		len(indices), len(content), matchFindDuration)
+	processRegexLogger.Trace("Match indices: %v", indices)
 
 	// Log pattern complexity metrics
 	patternComplexity := estimatePatternComplexity(pattern)
-	logger.Debug("Pattern complexity estimate: %d", patternComplexity)
+	processRegexLogger.Debug("Pattern complexity estimate: %d", patternComplexity)
 
 	if len(indices) == 0 {
-		logger.Warning("No matches found for regex: %q", pattern)
-		logger.Debug("Total regex processing time: %v", time.Since(startTime))
+		processRegexLogger.Warning("No matches found for regex: %q", pattern)
+		processRegexLogger.Debug("Total regex processing time: %v", time.Since(startTime))
 		return commands, nil
 	}
 
@@ -77,12 +87,13 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 	// By going backwards we fuck up all the indices to the end of the file that we don't care about
 	// Because there either aren't any (last match) or they're already modified (subsequent matches)
 	for i, matchIndices := range indices {
-		logger.Debug("Processing match %d of %d", i+1, len(indices))
-		logger.Trace("Match indices: %v (match position %d-%d)", matchIndices, matchIndices[0], matchIndices[1])
+		matchLogger := processRegexLogger.WithField("matchNum", i+1)
+		matchLogger.Debug("Processing match %d of %d", i+1, len(indices))
+		matchLogger.Trace("Match indices: %v (match position %d-%d)", matchIndices, matchIndices[0], matchIndices[1])
 
 		L, err := NewLuaState()
 		if err != nil {
-			logger.Error("Error creating Lua state: %v", err)
+			matchLogger.Error("Error creating Lua state: %v", err)
 			return commands, fmt.Errorf("error creating Lua state: %v", err)
 		}
 		L.SetGlobal("file", lua.LString(filename))
@@ -90,7 +101,7 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 		// Maybe we want to close them every iteration
 		// We'll leave it as is for now
 		defer L.Close()
-		logger.Trace("Lua state created successfully for match %d", i+1)
+		matchLogger.Trace("Lua state created successfully for match %d", i+1)
 
 		// Why we're doing this whole song and dance of indices is to properly handle empty matches
 		// Plus it's a little cleaner to surgically replace our matches
@@ -99,20 +110,17 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 		// So when we're cutting open the array we say 0:7 + modified + 7:end
 		// As if concatenating in the middle of the array
 		// Plus it supports lookarounds
-		match := content[matchIndices[0]:matchIndices[1]]
-		matchPreview := match
-		if len(match) > 50 {
-			matchPreview = match[:47] + "..."
-		}
-		logger.Trace("Matched content: %q (length: %d)", matchPreview, len(match))
+		matchContent := content[matchIndices[0]:matchIndices[1]]
+		matchPreview := utils.LimitString(matchContent, 50)
+		matchLogger.Trace("Matched content: %q (length: %d)", matchPreview, len(matchContent))
 
 		groups := matchIndices[2:]
 		if len(groups) <= 0 {
-			logger.Warning("No capture groups found for match %q and regex %q", matchPreview, pattern)
+			matchLogger.Warning("No capture groups found for match %q and regex %q", matchPreview, pattern)
 			continue
 		}
 		if len(groups)%2 == 1 {
-			logger.Warning("Invalid number of group indices (%d), should be even: %v", len(groups), groups)
+			matchLogger.Warning("Invalid number of group indices (%d), should be even: %v", len(groups), groups)
 			continue
 		}
 
@@ -123,11 +131,11 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 				validGroups++
 			}
 		}
-		logger.Debug("Found %d valid capture groups in match", validGroups)
+		matchLogger.Debug("Found %d valid capture groups in match", validGroups)
 
 		for _, index := range groups {
 			if index == -1 {
-				logger.Warning("Negative index encountered in match indices %v. This may indicate an issue with the regex pattern or an empty/optional capture group.", matchIndices)
+				matchLogger.Warning("Negative index encountered in match indices %v. This may indicate an issue with the regex pattern or an empty/optional capture group.", matchIndices)
 				continue
 			}
 		}
@@ -142,6 +150,7 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 			start := groups[i*2]
 			end := groups[i*2+1]
 			if start == -1 || end == -1 {
+				matchLogger.Debug("Skipping empty or unmatched capture group #%d (name: %q)", i+1, name)
 				continue
 			}
 
@@ -154,75 +163,80 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 
 			// Include name info in log if available
 			if name != "" {
-				logger.Trace("Capture group '%s': %q (pos %d-%d)", name, value, start, end)
+				matchLogger.Trace("Capture group '%s': %q (pos %d-%d)", name, value, start, end)
 			} else {
-				logger.Trace("Capture group #%d: %q (pos %d-%d)", i+1, value, start, end)
+				matchLogger.Trace("Capture group #%d: %q (pos %d-%d)", i+1, value, start, end)
 			}
 		}
 
 		// Use the DeduplicateGroups flag to control whether to deduplicate capture groups
 		if !command.NoDedup {
-			logger.Debug("Deduplicating capture groups as specified in command settings")
+			matchLogger.Debug("Deduplicating capture groups as specified in command settings")
 			captureGroups = deduplicateGroups(captureGroups)
+			matchLogger.Trace("Capture groups after deduplication: %v", captureGroups)
+		} else {
+			matchLogger.Debug("Skipping deduplication of capture groups (NoDedup is true)")
 		}
 
 		if err := toLua(L, captureGroups); err != nil {
-			logger.Error("Failed to set Lua variables: %v", err)
+			matchLogger.Error("Failed to set Lua variables for capture groups: %v", err)
 			continue
 		}
-		logger.Trace("Set %d capture groups as Lua variables", len(captureGroups))
+		matchLogger.Debug("Set %d capture groups as Lua variables", len(captureGroups))
+		matchLogger.Trace("Lua globals set for capture groups")
 
 		if err := L.DoString(luaExpr); err != nil {
-			logger.Error("Lua script execution failed: %v\nScript: %s\nCapture Groups: %+v",
-				err, luaExpr, captureGroups)
+			matchLogger.Error("Lua script execution failed: %v\nScript: %s\nCapture Groups: %+v",
+				err, utils.LimitString(luaExpr, 200), captureGroups)
 			continue
 		}
-		logger.Trace("Lua script executed successfully")
+		matchLogger.Debug("Lua script executed successfully")
 
 		// Get modifications from Lua
-		captureGroups, err = fromLua(L, captureGroups)
+		updatedCaptureGroups, err := fromLua(L, captureGroups)
 		if err != nil {
-			logger.Error("Failed to retrieve modifications from Lua: %v", err)
+			matchLogger.Error("Failed to retrieve modifications from Lua: %v", err)
 			continue
 		}
-		logger.Trace("Retrieved updated values from Lua")
+		matchLogger.Debug("Retrieved updated values from Lua")
+		matchLogger.Trace("Updated capture groups from Lua: %v", updatedCaptureGroups)
 
 		replacement := ""
 		replacementVar := L.GetGlobal("replacement")
 		if replacementVar.Type() != lua.LTNil {
 			replacement = replacementVar.String()
-			logger.Debug("Using global replacement: %q", replacement)
+			matchLogger.Debug("Using global replacement variable from Lua: %q", replacement)
 		}
 
 		// Check if modification flag is set
 		modifiedVal := L.GetGlobal("modified")
 		if modifiedVal.Type() != lua.LTBool || !lua.LVAsBool(modifiedVal) {
-			logger.Debug("Skipping match - no modifications made by Lua script")
+			matchLogger.Debug("Skipping match - no modifications indicated by Lua script")
 			continue
 		}
 
 		if replacement == "" {
 			// Apply the modifications to the original match
-			replacement = match
+			replacement = matchContent
 
 			// Count groups that were actually modified
-			modifiedGroups := 0
-			for _, capture := range captureGroups {
+			modifiedGroupsCount := 0
+			for _, capture := range updatedCaptureGroups {
 				if capture.Value != capture.Updated {
-					modifiedGroups++
+					modifiedGroupsCount++
 				}
 			}
-			logger.Info("%d of %d capture groups identified for modification", modifiedGroups, len(captureGroups))
+			matchLogger.Info("%d of %d capture groups identified for modification", modifiedGroupsCount, len(updatedCaptureGroups))
 
-			for _, capture := range captureGroups {
+			for _, capture := range updatedCaptureGroups {
 				if capture.Value == capture.Updated {
-					logger.Info("Capture group unchanged: %s", LimitString(capture.Value, 50))
+					matchLogger.Debug("Capture group unchanged: %s", utils.LimitString(capture.Value, 50))
 					continue
 				}
 
 				// Log what changed with context
-				logger.Debug("Capture group %s scheduled for modification: %q → %q",
-					capture.Name, capture.Value, capture.Updated)
+				matchLogger.Debug("Capture group %q scheduled for modification: %q → %q",
+					capture.Name, utils.LimitString(capture.Value, 50), utils.LimitString(capture.Updated, 50))
 
 				// Indices of the group are relative to content
 				// To relate them to match we have to subtract the match start index
@@ -232,42 +246,57 @@ func ProcessRegex(content string, command utils.ModifyCommand, filename string)
 					To:   capture.Range[1],
 					With: capture.Updated,
 				})
+				matchLogger.Trace("Added replacement command: %+v", commands[len(commands)-1])
 			}
 		} else {
+			matchLogger.Debug("Using full replacement string from Lua: %q", utils.LimitString(replacement, 50))
 			commands = append(commands, utils.ReplaceCommand{
 				From: matchIndices[0],
 				To:   matchIndices[1],
 				With: replacement,
 			})
+			matchLogger.Trace("Added full replacement command: %+v", commands[len(commands)-1])
 		}
 	}
 
-	logger.Debug("Total regex processing time: %v", time.Since(startTime))
+	processRegexLogger.Debug("Total regex processing time: %v", time.Since(startTime))
+	processRegexLogger.Debug("Generated %d total modifications", len(commands))
 	return commands, nil
 }
 
 func deduplicateGroups(captureGroups []*CaptureGroup) []*CaptureGroup {
-	deduplicatedGroups := make([]*CaptureGroup, 0)
+	deduplicateGroupsLogger := regexLogger.WithPrefix("deduplicateGroups")
+	deduplicateGroupsLogger.Debug("Starting deduplication of capture groups")
+	deduplicateGroupsLogger.Trace("Input capture groups: %v", captureGroups)
+
+	// Preserve input order and drop any group that overlaps with an already accepted group
+	accepted := make([]*CaptureGroup, 0, len(captureGroups))
 	for _, group := range captureGroups {
+		groupLogger := deduplicateGroupsLogger.WithField("groupName", group.Name).WithField("groupRange", group.Range)
+		groupLogger.Debug("Processing capture group")
+
 		overlaps := false
-		logger.Debug("Checking capture group: %s with range %v", group.Name, group.Range)
-		for _, existingGroup := range deduplicatedGroups {
-			logger.Debug("Comparing with existing group: %s with range %v", existingGroup.Name, existingGroup.Range)
-			if group.Range[0] < existingGroup.Range[1] && group.Range[1] > existingGroup.Range[0] {
+		for _, kept := range accepted {
+			// Overlap if start < keptEnd and end > keptStart (adjacent is allowed)
+			if group.Range[0] < kept.Range[1] && group.Range[1] > kept.Range[0] {
 				overlaps = true
-				logger.Warning("Detected overlap between capture group '%s' and existing group '%s' in range %v-%v and %v-%v", group.Name, existingGroup.Name, group.Range[0], group.Range[1], existingGroup.Range[0], existingGroup.Range[1])
 				break
 			}
 		}
+
 		if overlaps {
-			// We CAN just continue despite this fuckup
-			logger.Warning("Overlapping capture group: %s", group.Name)
+			groupLogger.Warning("Overlapping capture group detected and skipped.")
 			continue
 		}
-		logger.Debug("No overlap detected for capture group: %s. Adding to deduplicated groups.", group.Name)
-		deduplicatedGroups = append(deduplicatedGroups, group)
+
+		groupLogger.Debug("Capture group does not overlap with previously accepted groups. Adding.")
+		accepted = append(accepted, group)
 	}
-	return deduplicatedGroups
+
+	deduplicateGroupsLogger.Debug("Finished deduplication. Original %d groups, %d deduplicated.", len(captureGroups), len(accepted))
+	deduplicateGroupsLogger.Trace("Deduplicated groups: %v", accepted)
+
+	return accepted
 }
 
 // The order of these replaces is important
@@ -276,105 +305,183 @@ func deduplicateGroups(captureGroups []*CaptureGroup) []*CaptureGroup {
 // Expand to another capture group in the capture group
 // We really only want one (our named) capture group
 func resolveRegexPlaceholders(pattern string) string {
+	resolveLogger := regexLogger.WithPrefix("resolveRegexPlaceholders").WithField("originalPattern", utils.LimitString(pattern, 100))
+	resolveLogger.Debug("Resolving regex placeholders in pattern")
+
 	// Handle special pattern modifications
 	if !strings.HasPrefix(pattern, "(?s)") {
 		pattern = "(?s)" + pattern
+		resolveLogger.Debug("Prepended '(?s)' to pattern for single-line mode")
 	}
 
 	namedGroupNum := regexp.MustCompile(`(?:(\?<[^>]+>)(!num))`)
 	pattern = namedGroupNum.ReplaceAllStringFunc(pattern, func(match string) string {
+		funcLogger := resolveLogger.WithPrefix("namedGroupNumReplace").WithField("match", utils.LimitString(match, 50))
+		funcLogger.Debug("Processing named group !num placeholder")
 		parts := namedGroupNum.FindStringSubmatch(match)
 		if len(parts) != 3 {
+			funcLogger.Warning("Unexpected number of submatches for namedGroupNum: %d. Returning original match.", len(parts))
 			return match
 		}
 		replacement := `-?\d*\.?\d+`
+		funcLogger.Trace("Replacing !num in named group with: %q", replacement)
 		return parts[1] + replacement
 	})
+	resolveLogger.Debug("Handled named group !num placeholders")
+
 	pattern = strings.ReplaceAll(pattern, "!num", `(-?\d*\.?\d+)`)
+	resolveLogger.Debug("Replaced !num with numeric capture group")
+
 	pattern = strings.ReplaceAll(pattern, "!any", `.*?`)
+	resolveLogger.Debug("Replaced !any with non-greedy wildcard")
+
 	repPattern := regexp.MustCompile(`!rep\(([^,]+),\s*(\d+)\)`)
 	// !rep(pattern, count) repeats the pattern n times
 	// Inserting !any between each repetition
 	pattern = repPattern.ReplaceAllStringFunc(pattern, func(match string) string {
+		funcLogger := resolveLogger.WithPrefix("repPatternReplace").WithField("match", utils.LimitString(match, 50))
+		funcLogger.Debug("Processing !rep placeholder")
 		parts := repPattern.FindStringSubmatch(match)
 		if len(parts) != 3 {
+			funcLogger.Warning("Unexpected number of submatches for repPattern: %d. Returning original match.", len(parts))
 			return match
 		}
 		repeatedPattern := parts[1]
-		count := parts[2]
-		repetitions, _ := strconv.Atoi(count)
-		return strings.Repeat(repeatedPattern+".*?", repetitions-1) + repeatedPattern
+		countStr := parts[2]
+		repetitions, err := strconv.Atoi(countStr)
+		if err != nil {
+			funcLogger.Error("Failed to parse repetition count %q: %v. Returning original match.", countStr, err)
+			return match
+		}
+
+		var finalReplacement string
+		if repetitions > 0 {
+			finalReplacement = strings.Repeat(repeatedPattern+".*?", repetitions-1) + repeatedPattern
+		} else {
+			finalReplacement = ""
+		}
+
+		funcLogger.Trace("Replaced !rep with %d repetitions of %q: %q", repetitions, utils.LimitString(repeatedPattern, 30), utils.LimitString(finalReplacement, 100))
+		return finalReplacement
 	})
+	resolveLogger.Debug("Handled !rep placeholders")
+
+	resolveLogger.Debug("Finished resolving regex placeholders")
+	resolveLogger.Trace("Final resolved pattern: %q", utils.LimitString(pattern, 100))
 	return pattern
 }
 
 // ToLua sets capture groups as Lua variables (v1, v2, etc. for numeric values and s1, s2, etc. for strings)
 func toLua(L *lua.LState, data interface{}) error {
+	toLuaLogger := regexLogger.WithPrefix("toLua")
+	toLuaLogger.Debug("Setting capture groups as Lua variables")
+
 	captureGroups, ok := data.([]*CaptureGroup)
 	if !ok {
+		toLuaLogger.Error("Invalid data type for toLua. Expected []*CaptureGroup, got %T", data)
 		return fmt.Errorf("expected []*CaptureGroup for captures, got %T", data)
 	}
+	toLuaLogger.Trace("Input capture groups: %v", captureGroups)
 
 	groupindex := 0
 	for _, capture := range captureGroups {
+		groupLogger := toLuaLogger.WithField("captureGroup", capture.Name).WithField("value", utils.LimitString(capture.Value, 50))
+		groupLogger.Debug("Processing capture group for Lua")
+
 		if capture.Name == "" {
 			// We don't want to change the name of the capture group
 			// Even if it's empty
 			tempName := fmt.Sprintf("%d", groupindex+1)
 			groupindex++
+			groupLogger.Debug("Unnamed capture group, assigning temporary name: %q", tempName)
 
 			L.SetGlobal("s"+tempName, lua.LString(capture.Value))
+			groupLogger.Trace("Set Lua global s%s = %q", tempName, capture.Value)
 
 			val, err := strconv.ParseFloat(capture.Value, 64)
 			if err == nil {
 				L.SetGlobal("v"+tempName, lua.LNumber(val))
+				groupLogger.Trace("Set Lua global v%s = %f", tempName, val)
+			} else {
+				groupLogger.Trace("Value %q is not numeric, skipping v%s assignment", capture.Value, tempName)
 			}
 		} else {
 			val, err := strconv.ParseFloat(capture.Value, 64)
 			if err == nil {
 				L.SetGlobal(capture.Name, lua.LNumber(val))
+				groupLogger.Trace("Set Lua global %s = %f (numeric)", capture.Name, val)
 			} else {
 				L.SetGlobal(capture.Name, lua.LString(capture.Value))
+				groupLogger.Trace("Set Lua global %s = %q (string)", capture.Name, capture.Value)
 			}
 		}
 	}
 
+	toLuaLogger.Debug("Finished setting capture groups as Lua variables")
 	return nil
 }
 
 // FromLua implements the Processor interface for RegexProcessor
 func fromLua(L *lua.LState, captureGroups []*CaptureGroup) ([]*CaptureGroup, error) {
+	fromLuaLogger := regexLogger.WithPrefix("fromLua")
+	fromLuaLogger.Debug("Retrieving modifications from Lua for capture groups")
+	fromLuaLogger.Trace("Initial capture groups: %v", captureGroups)
+
 	captureIndex := 0
 	for _, capture := range captureGroups {
-		if capture.Name == "" {
-			capture.Name = fmt.Sprintf("%d", captureIndex+1)
+		groupLogger := fromLuaLogger.WithField("originalCaptureName", capture.Name).WithField("originalValue", utils.LimitString(capture.Value, 50))
+		groupLogger.Debug("Processing capture group to retrieve updated value")
 
-			vVarName := fmt.Sprintf("v%s", capture.Name)
-			sVarName := fmt.Sprintf("s%s", capture.Name)
+		if capture.Name == "" {
+			// This case means it was an unnamed capture group originally.
+			// We need to reconstruct the original temporary name to fetch its updated value.
+			// The name will be set to an integer if it was empty, then incremented.
+			// So, we use the captureIndex to get the correct 'vX' and 'sX' variables.
+			tempName := fmt.Sprintf("%d", captureIndex+1)
+			groupLogger.Debug("Retrieving updated value for unnamed group (temp name: %q)", tempName)
+
+			vVarName := fmt.Sprintf("v%s", tempName)
+			sVarName := fmt.Sprintf("s%s", tempName)
 			captureIndex++
 
 			vLuaVal := L.GetGlobal(vVarName)
 			sLuaVal := L.GetGlobal(sVarName)
 
+			groupLogger.Trace("Lua values for unnamed group: v=%v, s=%v", vLuaVal, sLuaVal)
+
 			if sLuaVal.Type() == lua.LTString {
 				capture.Updated = sLuaVal.String()
+				groupLogger.Trace("Updated value from s%s (string): %q", tempName, capture.Updated)
 			}
 			// Numbers have priority
 			if vLuaVal.Type() == lua.LTNumber {
 				capture.Updated = vLuaVal.String()
+				groupLogger.Trace("Updated value from v%s (numeric): %q", tempName, capture.Updated)
 			}
 		} else {
-			// Easy shit
-			capture.Updated = L.GetGlobal(capture.Name).String()
+			// Easy shit, directly use the named capture group
+			updatedValue := L.GetGlobal(capture.Name)
+			if updatedValue.Type() != lua.LTNil {
+				capture.Updated = updatedValue.String()
+				groupLogger.Trace("Updated value for named group %q: %q", capture.Name, capture.Updated)
+			} else {
+				groupLogger.Debug("Named capture group %q not found in Lua globals or is nil. Keeping original value.", capture.Name)
+				capture.Updated = capture.Value // Keep original if not found or nil
 			}
 		}
+		groupLogger.Debug("Finished processing capture group. Original: %q, Updated: %q", utils.LimitString(capture.Value, 50), utils.LimitString(capture.Updated, 50))
+	}
 
+	fromLuaLogger.Debug("Finished retrieving modifications from Lua")
+	fromLuaLogger.Trace("Final updated capture groups: %v", captureGroups)
 	return captureGroups, nil
 }
 
 // estimatePatternComplexity gives a rough estimate of regex pattern complexity
 // This can help identify potentially problematic patterns
 func estimatePatternComplexity(pattern string) int {
+	estimateComplexityLogger := regexLogger.WithPrefix("estimatePatternComplexity").WithField("pattern", utils.LimitString(pattern, 100))
+	estimateComplexityLogger.Debug("Estimating regex pattern complexity")
 	complexity := len(pattern)
 
 	// Add complexity for potentially expensive operations
@@ -387,5 +494,6 @@ func estimatePatternComplexity(pattern string) int {
 	complexity += strings.Count(pattern, "\\1") * 3 // Backreferences
 	complexity += strings.Count(pattern, "{") * 2   // Counted repetition
 
+	estimateComplexityLogger.Debug("Estimated pattern complexity: %d", complexity)
 	return complexity
 }

utils/db.go

@@ -1,15 +1,17 @@
 package utils
 
 import (
-	"fmt"
 	"path/filepath"
 	"time"
 
-	"git.site.quack-lab.dev/dave/cylogger"
+	logger "git.site.quack-lab.dev/dave/cylogger"
 	"gorm.io/driver/sqlite"
 	"gorm.io/gorm"
 )
 
+// dbLogger is a scoped logger for the utils/db package.
+var dbLogger = logger.Default.WithPrefix("utils/db")
+
 type DB interface {
 	DB() *gorm.DB
 	Raw(sql string, args ...any) *gorm.DB
@@ -29,92 +31,125 @@ type DBWrapper struct {
 	db *gorm.DB
 }
 
-var db *DBWrapper
+var globalDB *DBWrapper
 
 func GetDB() (DB, error) {
+	getDBLogger := dbLogger.WithPrefix("GetDB")
+	getDBLogger.Debug("Attempting to get database connection")
 	var err error
 
 	dbFile := filepath.Join("data.sqlite")
+	getDBLogger.Debug("Opening database file: %q", dbFile)
 	db, err := gorm.Open(sqlite.Open(dbFile), &gorm.Config{
 		// SkipDefaultTransaction: true,
 		PrepareStmt: true,
 		// Logger:      gormlogger.Default.LogMode(gormlogger.Silent),
 	})
 	if err != nil {
+		getDBLogger.Error("Failed to open database: %v", err)
 		return nil, err
 	}
-	db.AutoMigrate(&FileSnapshot{})
+	getDBLogger.Debug("Database opened successfully, running auto migration")
+	if err := db.AutoMigrate(&FileSnapshot{}); err != nil {
+		getDBLogger.Error("Auto migration failed: %v", err)
+		return nil, err
+	}
+	getDBLogger.Debug("Auto migration completed")
 
-	return &DBWrapper{db: db}, nil
+	globalDB = &DBWrapper{db: db}
+	getDBLogger.Debug("Database wrapper initialized")
+	return globalDB, nil
 }
 
 // Just a wrapper
 func (db *DBWrapper) Raw(sql string, args ...any) *gorm.DB {
+	rawLogger := dbLogger.WithPrefix("Raw").WithField("sql", sql)
+	rawLogger.Debug("Executing raw SQL query with args: %v", args)
 	return db.db.Raw(sql, args...)
 }
 
 func (db *DBWrapper) DB() *gorm.DB {
+	dbLogger.WithPrefix("DB").Debug("Returning GORM DB instance")
 	return db.db
 }
 
 func (db *DBWrapper) FileExists(filePath string) (bool, error) {
+	fileExistsLogger := dbLogger.WithPrefix("FileExists").WithField("filePath", filePath)
+	fileExistsLogger.Debug("Checking if file exists in database")
 	var count int64
 	err := db.db.Model(&FileSnapshot{}).Where("file_path = ?", filePath).Count(&count).Error
+	if err != nil {
+		fileExistsLogger.Error("Error checking if file exists: %v", err)
+		return false, err
+	}
+	fileExistsLogger.Debug("File exists: %t", count > 0)
 	return count > 0, err
 }
 
 func (db *DBWrapper) SaveFile(filePath string, fileData []byte) error {
-	log := cylogger.Default.WithPrefix(fmt.Sprintf("SaveFile: %q", filePath))
+	saveFileLogger := dbLogger.WithPrefix("SaveFile").WithField("filePath", filePath)
+	saveFileLogger.Debug("Attempting to save file to database")
+	saveFileLogger.Trace("File data length: %d", len(fileData))
+
 	exists, err := db.FileExists(filePath)
 	if err != nil {
-		log.Error("Error checking if file exists: %v", err)
+		saveFileLogger.Error("Error checking if file exists: %v", err)
 		return err
 	}
-	log.Debug("File exists: %t", exists)
-	// Nothing to do, file already exists
 	if exists {
-		log.Debug("File already exists, skipping save")
+		saveFileLogger.Debug("File already exists, skipping save")
 		return nil
 	}
-	log.Debug("Saving file to database")
-	return db.db.Create(&FileSnapshot{
+	saveFileLogger.Debug("Creating new file snapshot in database")
+	err = db.db.Create(&FileSnapshot{
 		Date:     time.Now(),
 		FilePath: filePath,
 		FileData: fileData,
 	}).Error
+	if err != nil {
+		saveFileLogger.Error("Failed to create file snapshot: %v", err)
+	} else {
+		saveFileLogger.Debug("File saved successfully to database")
+	}
+	return err
 }
 
 func (db *DBWrapper) GetFile(filePath string) ([]byte, error) {
-	log := cylogger.Default.WithPrefix(fmt.Sprintf("GetFile: %q", filePath))
-	log.Debug("Getting file from database")
+	getFileLogger := dbLogger.WithPrefix("GetFile").WithField("filePath", filePath)
+	getFileLogger.Debug("Getting file from database")
 	var fileSnapshot FileSnapshot
 	err := db.db.Model(&FileSnapshot{}).Where("file_path = ?", filePath).First(&fileSnapshot).Error
 	if err != nil {
+		getFileLogger.Error("Failed to get file from database: %v", err)
 		return nil, err
 	}
-	log.Debug("File found in database")
+	getFileLogger.Debug("File found in database")
+	getFileLogger.Trace("Retrieved file data length: %d", len(fileSnapshot.FileData))
 	return fileSnapshot.FileData, nil
 }
 
 func (db *DBWrapper) GetAllFiles() ([]FileSnapshot, error) {
-	log := cylogger.Default.WithPrefix("GetAllFiles")
-	log.Debug("Getting all files from database")
+	getAllFilesLogger := dbLogger.WithPrefix("GetAllFiles")
+	getAllFilesLogger.Debug("Getting all files from database")
 	var fileSnapshots []FileSnapshot
 	err := db.db.Model(&FileSnapshot{}).Find(&fileSnapshots).Error
 	if err != nil {
+		getAllFilesLogger.Error("Failed to get all files from database: %v", err)
 		return nil, err
 	}
-	log.Debug("Found %d files in database", len(fileSnapshots))
+	getAllFilesLogger.Debug("Found %d files in database", len(fileSnapshots))
+	getAllFilesLogger.Trace("File snapshots retrieved: %v", fileSnapshots)
 	return fileSnapshots, nil
 }
 
 func (db *DBWrapper) RemoveAllFiles() error {
-	log := cylogger.Default.WithPrefix("RemoveAllFiles")
-	log.Debug("Removing all files from database")
+	removeAllFilesLogger := dbLogger.WithPrefix("RemoveAllFiles")
+	removeAllFilesLogger.Debug("Removing all files from database")
 	err := db.db.Exec("DELETE FROM file_snapshots").Error
 	if err != nil {
-		return err
+		removeAllFilesLogger.Error("Failed to remove all files from database: %v", err)
+	} else {
+		removeAllFilesLogger.Debug("All files removed from database")
 	}
-	log.Debug("All files removed from database")
-	return nil
+	return err
 }

utils/file.go

@@ -1,96 +1,142 @@
 package utils
 
 import (
-	"fmt"
 	"os"
 	"path/filepath"
+	"strconv"
 	"strings"
 
-	"git.site.quack-lab.dev/dave/cylogger"
+	logger "git.site.quack-lab.dev/dave/cylogger"
 )
 
+// fileLogger is a scoped logger for the utils/file package.
+var fileLogger = logger.Default.WithPrefix("utils/file")
+
 func CleanPath(path string) string {
-	log := cylogger.Default.WithPrefix(fmt.Sprintf("CleanPath: %q", path))
-	log.Trace("Start")
+	cleanPathLogger := fileLogger.WithPrefix("CleanPath")
+	cleanPathLogger.Debug("Cleaning path: %q", path)
+	cleanPathLogger.Trace("Original path: %q", path)
 	path = filepath.Clean(path)
 	path = strings.ReplaceAll(path, "\\", "/")
-	log.Trace("Done: %q", path)
+	cleanPathLogger.Trace("Cleaned path result: %q", path)
 	return path
 }
 
 func ToAbs(path string) string {
-	log := cylogger.Default.WithPrefix(fmt.Sprintf("ToAbs: %q", path))
-	log.Trace("Start")
+	toAbsLogger := fileLogger.WithPrefix("ToAbs")
+	toAbsLogger.Debug("Converting path to absolute: %q", path)
+	toAbsLogger.Trace("Input path: %q", path)
 	if filepath.IsAbs(path) {
-		log.Trace("Path is already absolute: %q", path)
-		return CleanPath(path)
+		toAbsLogger.Debug("Path is already absolute, cleaning it.")
+		cleanedPath := CleanPath(path)
+		toAbsLogger.Trace("Already absolute path after cleaning: %q", cleanedPath)
+		return cleanedPath
 	}
 	cwd, err := os.Getwd()
 	if err != nil {
-		log.Error("Error getting cwd: %v", err)
+		toAbsLogger.Error("Error getting current working directory: %v", err)
 		return CleanPath(path)
 	}
-	log.Trace("Cwd: %q", cwd)
-	return CleanPath(filepath.Join(cwd, path))
+	toAbsLogger.Trace("Current working directory: %q", cwd)
+	cleanedPath := CleanPath(filepath.Join(cwd, path))
+	toAbsLogger.Trace("Converted absolute path result: %q", cleanedPath)
+	return cleanedPath
+}
+
+// LimitString truncates a string to maxLen and adds "..." if truncated
+func LimitString(s string, maxLen int) string {
+	limitStringLogger := fileLogger.WithPrefix("LimitString").WithField("originalLength", len(s)).WithField("maxLength", maxLen)
+	limitStringLogger.Debug("Limiting string length")
+	s = strings.ReplaceAll(s, "\n", "\\n")
+	if len(s) <= maxLen {
+		limitStringLogger.Trace("String length (%d) is within max length (%d), no truncation", len(s), maxLen)
+		return s
+	}
+	limited := s[:maxLen-3] + "..."
+	limitStringLogger.Trace("String truncated from %d to %d characters: %q", len(s), len(limited), limited)
+	return limited
+}
+
+// StrToFloat converts a string to a float64, returning 0 on error.
+func StrToFloat(s string) float64 {
+	strToFloatLogger := fileLogger.WithPrefix("StrToFloat").WithField("inputString", s)
+	strToFloatLogger.Debug("Attempting to convert string to float")
+	f, err := strconv.ParseFloat(s, 64)
+	if err != nil {
+		strToFloatLogger.Warning("Failed to convert string %q to float, returning 0: %v", s, err)
+		return 0
+	}
+	strToFloatLogger.Trace("Successfully converted %q to float: %f", s, f)
+	return f
 }
 
 func ResetWhereNecessary(associations map[string]FileCommandAssociation, db DB) error {
-	log := cylogger.Default.WithPrefix("ResetWhereNecessary")
-	log.Debug("Start")
+	resetWhereNecessaryLogger := fileLogger.WithPrefix("ResetWhereNecessary")
+	resetWhereNecessaryLogger.Debug("Starting reset where necessary operation")
+	resetWhereNecessaryLogger.Trace("File-command associations input: %v", associations)
 	dirtyFiles := make(map[string]struct{})
 	for _, association := range associations {
+		resetWhereNecessaryLogger.Debug("Processing association for file: %q", association.File)
 		for _, command := range association.Commands {
-			log.Debug("Checking command %q for file %q", command.Name, association.File)
+			resetWhereNecessaryLogger.Debug("Checking command %q for reset requirement", command.Name)
+			resetWhereNecessaryLogger.Trace("Command details: %v", command)
 			if command.Reset {
-				log.Debug("Command %q requires reset for file %q", command.Name, association.File)
+				resetWhereNecessaryLogger.Debug("Command %q requires reset for file %q, marking as dirty", command.Name, association.File)
 				dirtyFiles[association.File] = struct{}{}
 			}
 		}
 		for _, command := range association.IsolateCommands {
-			log.Debug("Checking isolate command %q for file %q", command.Name, association.File)
+			resetWhereNecessaryLogger.Debug("Checking isolate command %q for reset requirement", command.Name)
+			resetWhereNecessaryLogger.Trace("Isolate command details: %v", command)
 			if command.Reset {
-				log.Debug("Isolate command %q requires reset for file %q", command.Name, association.File)
+				resetWhereNecessaryLogger.Debug("Isolate command %q requires reset for file %q, marking as dirty", command.Name, association.File)
 				dirtyFiles[association.File] = struct{}{}
 			}
 		}
 	}
-	log.Debug("Dirty files: %v", dirtyFiles)
+	resetWhereNecessaryLogger.Debug("Identified %d files that need to be reset", len(dirtyFiles))
+	resetWhereNecessaryLogger.Trace("Dirty files identified: %v", dirtyFiles)
+
 	for file := range dirtyFiles {
-		log.Debug("Resetting file %q", file)
+		resetWhereNecessaryLogger.Debug("Resetting file %q", file)
 		fileData, err := db.GetFile(file)
 		if err != nil {
-			log.Warning("Failed to get file %q: %v", file, err)
+			resetWhereNecessaryLogger.Warning("Failed to get original content for file %q from database: %v", file, err)
 			continue
 		}
-		log.Debug("Writing file %q to disk", file)
+		resetWhereNecessaryLogger.Trace("Retrieved original file data length for %q: %d", file, len(fileData))
+		resetWhereNecessaryLogger.Debug("Writing original content back to file %q", file)
 		err = os.WriteFile(file, fileData, 0644)
 		if err != nil {
-			log.Warning("Failed to write file %q: %v", file, err)
+			resetWhereNecessaryLogger.Warning("Failed to write original content back to file %q: %v", file, err)
 			continue
 		}
-		log.Debug("File %q written to disk", file)
+		resetWhereNecessaryLogger.Debug("Successfully reset file %q", file)
 	}
-	log.Debug("Done")
+	resetWhereNecessaryLogger.Debug("Finished reset where necessary operation")
 	return nil
 }
 
 func ResetAllFiles(db DB) error {
-	log := cylogger.Default.WithPrefix("ResetAllFiles")
-	log.Debug("Start")
+	resetAllFilesLogger := fileLogger.WithPrefix("ResetAllFiles")
+	resetAllFilesLogger.Debug("Starting reset all files operation")
 	fileSnapshots, err := db.GetAllFiles()
 	if err != nil {
+		resetAllFilesLogger.Error("Failed to get all file snapshots from database: %v", err)
 		return err
 	}
-	log.Debug("Found %d files in database", len(fileSnapshots))
+	resetAllFilesLogger.Debug("Found %d files in database to reset", len(fileSnapshots))
+	resetAllFilesLogger.Trace("File snapshots retrieved: %v", fileSnapshots)
+
 	for _, fileSnapshot := range fileSnapshots {
-		log.Debug("Resetting file %q", fileSnapshot.FilePath)
+		resetAllFilesLogger.Debug("Resetting file %q", fileSnapshot.FilePath)
 		err = os.WriteFile(fileSnapshot.FilePath, fileSnapshot.FileData, 0644)
 		if err != nil {
-			log.Warning("Failed to write file %q: %v", fileSnapshot.FilePath, err)
+			resetAllFilesLogger.Warning("Failed to write file %q to disk: %v", fileSnapshot.FilePath, err)
 			continue
 		}
-		log.Debug("File %q written to disk", fileSnapshot.FilePath)
+		resetAllFilesLogger.Debug("File %q written to disk successfully", fileSnapshot.FilePath)
 	}
-	log.Debug("Done")
+	resetAllFilesLogger.Debug("Finished reset all files operation")
 	return nil
 }

utils/flags.go

@@ -2,9 +2,19 @@ package utils
 
 import (
 	"flag"
+
+	logger "git.site.quack-lab.dev/dave/cylogger"
 )
 
+// flagsLogger is a scoped logger for the utils/flags package.
+var flagsLogger = logger.Default.WithPrefix("utils/flags")
+
 var (
 	ParallelFiles = flag.Int("P", 100, "Number of files to process in parallel")
 	Filter        = flag.String("f", "", "Filter commands before running them")
 )
+
+func init() {
+	flagsLogger.Debug("Initializing flags")
+	flagsLogger.Trace("ParallelFiles initial value: %d, Filter initial value: %q", *ParallelFiles, *Filter)
+}

utils/modifycommand.go

@@ -11,6 +11,9 @@ import (
 	"gopkg.in/yaml.v3"
 )
 
+// modifyCommandLogger is a scoped logger for the utils/modifycommand package.
+var modifyCommandLogger = logger.Default.WithPrefix("utils/modifycommand")
+
 type ModifyCommand struct {
 	Name     string   `yaml:"name"`
 	Regex    string   `yaml:"regex"`
@@ -22,21 +25,29 @@ type ModifyCommand struct {
 	NoDedup  bool     `yaml:"nodedup"`
 	Disabled bool     `yaml:"disable"`
 }
+
 type CookFile []ModifyCommand
 
 func (c *ModifyCommand) Validate() error {
+	validateLogger := modifyCommandLogger.WithPrefix("Validate").WithField("commandName", c.Name)
+	validateLogger.Debug("Validating command")
 	if c.Regex == "" {
+		validateLogger.Error("Validation failed: Regex pattern is required")
 		return fmt.Errorf("pattern is required")
 	}
 	if c.Lua == "" {
+		validateLogger.Error("Validation failed: Lua expression is required")
 		return fmt.Errorf("lua expression is required")
 	}
 	if len(c.Files) == 0 {
+		validateLogger.Error("Validation failed: At least one file is required")
 		return fmt.Errorf("at least one file is required")
 	}
 	if c.LogLevel == "" {
+		validateLogger.Debug("LogLevel not specified, defaulting to INFO")
 		c.LogLevel = "INFO"
 	}
+	validateLogger.Debug("Command validated successfully")
 	return nil
 }
 
@@ -44,34 +55,47 @@ func (c *ModifyCommand) Validate() error {
 var matchesMemoTable map[string]bool = make(map[string]bool)
 
 func Matches(path string, glob string) (bool, error) {
+	matchesLogger := modifyCommandLogger.WithPrefix("Matches").WithField("path", path).WithField("glob", glob)
+	matchesLogger.Debug("Checking if path matches glob")
 	key := fmt.Sprintf("%s:%s", path, glob)
 	if matches, ok := matchesMemoTable[key]; ok {
-		logger.Debug("Found match for file %q and glob %q in memo table", path, glob)
+		matchesLogger.Debug("Found match in memo table: %t", matches)
 		return matches, nil
 	}
 	matches, err := doublestar.Match(glob, path)
 	if err != nil {
+		matchesLogger.Error("Failed to match glob: %v", err)
 		return false, fmt.Errorf("failed to match glob %s with file %s: %w", glob, path, err)
 	}
 	matchesMemoTable[key] = matches
+	matchesLogger.Debug("Match result: %t, storing in memo table", matches)
 	return matches, nil
 }
 
 func SplitPattern(pattern string) (string, string) {
+	splitPatternLogger := modifyCommandLogger.WithPrefix("SplitPattern").WithField("pattern", pattern)
+	splitPatternLogger.Debug("Splitting pattern")
+	splitPatternLogger.Trace("Original pattern: %q", pattern)
 	static, pattern := doublestar.SplitPattern(pattern)
 
 	cwd, err := os.Getwd()
 	if err != nil {
+		splitPatternLogger.Error("Error getting current working directory: %v", err)
 		return "", ""
 	}
+	splitPatternLogger.Trace("Current working directory: %q", cwd)
 	if static == "" {
+		splitPatternLogger.Debug("Static part is empty, defaulting to current working directory")
 		static = cwd
 	}
 	if !filepath.IsAbs(static) {
+		splitPatternLogger.Debug("Static part is not absolute, joining with current working directory")
 		static = filepath.Join(cwd, static)
 		static = filepath.Clean(static)
+		splitPatternLogger.Trace("Static path after joining and cleaning: %q", static)
 	}
 	static = strings.ReplaceAll(static, "\\", "/")
+	splitPatternLogger.Trace("Final static path: %q, Remaining pattern: %q", static, pattern)
 	return static, pattern
 }
 
@@ -82,180 +106,262 @@ type FileCommandAssociation struct {
 }
 
 func AssociateFilesWithCommands(files []string, commands []ModifyCommand) (map[string]FileCommandAssociation, error) {
+	associateFilesLogger := modifyCommandLogger.WithPrefix("AssociateFilesWithCommands")
+	associateFilesLogger.Debug("Associating files with commands")
+	associateFilesLogger.Trace("Input files: %v", files)
+	associateFilesLogger.Trace("Input commands: %v", commands)
 	associationCount := 0
 	fileCommands := make(map[string]FileCommandAssociation)
 
 	for _, file := range files {
 		file = strings.ReplaceAll(file, "\\", "/")
+		associateFilesLogger.Debug("Processing file: %q", file)
 		fileCommands[file] = FileCommandAssociation{
 			File:            file,
 			IsolateCommands: []ModifyCommand{},
 			Commands:        []ModifyCommand{},
 		}
 		for _, command := range commands {
+			associateFilesLogger.Debug("Checking command %q for file %q", command.Name, file)
 			for _, glob := range command.Files {
 				glob = strings.ReplaceAll(glob, "\\", "/")
 				static, pattern := SplitPattern(glob)
-				patternFile := strings.Replace(file, static+`/`, "", 1)
+				associateFilesLogger.Trace("Glob parts for %q → static=%q pattern=%q", glob, static, pattern)
+
+				// Build absolute path for the current file to compare with static
+				cwd, err := os.Getwd()
+				if err != nil {
+					associateFilesLogger.Warning("Failed to get CWD when matching %q for file %q: %v", glob, file, err)
+					continue
+				}
+				var absFile string
+				if filepath.IsAbs(file) {
+					absFile = filepath.Clean(file)
+				} else {
+					absFile = filepath.Clean(filepath.Join(cwd, file))
+				}
+				absFile = strings.ReplaceAll(absFile, "\\", "/")
+				associateFilesLogger.Trace("Absolute file path resolved for matching: %q", absFile)
+
+				// Only match if the file is under the static root
+				if !(strings.HasPrefix(absFile, static+"/") || absFile == static) {
+					associateFilesLogger.Trace("Skipping glob %q for file %q because file is outside static root %q", glob, file, static)
+					continue
+				}
+
+				patternFile := strings.TrimPrefix(absFile, static+`/`)
+				associateFilesLogger.Trace("Pattern-relative path used for match: %q", patternFile)
 				matches, err := Matches(patternFile, pattern)
 				if err != nil {
-					logger.Trace("Failed to match glob %s with file %s: %v", glob, file, err)
+					associateFilesLogger.Warning("Failed to match glob %q with file %q: %v", glob, file, err)
 					continue
 				}
 				if matches {
-					logger.Debug("Found match for file %q and command %q", file, command.Regex)
+					associateFilesLogger.Debug("File %q matches glob %q. Associating with command %q", file, glob, command.Name)
 					association := fileCommands[file]
 
 					if command.Isolate {
+						associateFilesLogger.Debug("Command %q is an isolate command, adding to isolate list", command.Name)
 						association.IsolateCommands = append(association.IsolateCommands, command)
 					} else {
+						associateFilesLogger.Debug("Command %q is a regular command, adding to regular list", command.Name)
 						association.Commands = append(association.Commands, command)
 					}
 					fileCommands[file] = association
 					associationCount++
+				} else {
+					associateFilesLogger.Trace("File %q did not match glob %q (pattern=%q, rel=%q)", file, glob, pattern, patternFile)
 				}
 			}
 		}
-		logger.Debug("Found %d commands for file %q", len(fileCommands[file].Commands), file)
-		if len(fileCommands[file].Commands) == 0 {
-			logger.Info("No commands found for file %q", file)
+		currentFileCommands := fileCommands[file]
+		associateFilesLogger.Debug("Finished processing file %q. Found %d regular commands and %d isolate commands", file, len(currentFileCommands.Commands), len(currentFileCommands.IsolateCommands))
+		associateFilesLogger.Trace("Commands for file %q: %v", file, currentFileCommands.Commands)
+		associateFilesLogger.Trace("Isolate commands for file %q: %v", file, currentFileCommands.IsolateCommands)
 	}
-		if len(fileCommands[file].IsolateCommands) > 0 {
-			logger.Info("Found %d isolate commands for file %q", len(fileCommands[file].IsolateCommands), file)
-		}
-	}
-	logger.Info("Found %d associations between %d files and %d commands", associationCount, len(files), len(commands))
+	associateFilesLogger.Info("Completed association. Found %d total associations for %d files and %d commands", associationCount, len(files), len(commands))
 	return fileCommands, nil
 }
 
 func AggregateGlobs(commands []ModifyCommand) map[string]struct{} {
-	logger.Info("Aggregating globs for %d commands", len(commands))
+	aggregateGlobsLogger := modifyCommandLogger.WithPrefix("AggregateGlobs")
+	aggregateGlobsLogger.Debug("Aggregating glob patterns from commands")
+	aggregateGlobsLogger.Trace("Input commands for aggregation: %v", commands)
 	globs := make(map[string]struct{})
 	for _, command := range commands {
+		aggregateGlobsLogger.Debug("Processing command %q for glob patterns", command.Name)
 		for _, glob := range command.Files {
-			glob = strings.Replace(glob, "~", os.Getenv("HOME"), 1)
-			glob = strings.ReplaceAll(glob, "\\", "/")
-			globs[glob] = struct{}{}
+			resolvedGlob := strings.Replace(glob, "~", os.Getenv("HOME"), 1)
+			resolvedGlob = strings.ReplaceAll(resolvedGlob, "\\", "/")
+			aggregateGlobsLogger.Trace("Adding glob: %q (resolved to %q)", glob, resolvedGlob)
+			globs[resolvedGlob] = struct{}{}
 		}
 	}
-	logger.Info("Found %d unique globs", len(globs))
+	aggregateGlobsLogger.Debug("Finished aggregating globs. Found %d unique glob patterns", len(globs))
+	aggregateGlobsLogger.Trace("Aggregated unique globs: %v", globs)
 	return globs
 }
 
 func ExpandGLobs(patterns map[string]struct{}) ([]string, error) {
+	expandGlobsLogger := modifyCommandLogger.WithPrefix("ExpandGLobs")
+	expandGlobsLogger.Debug("Expanding glob patterns to actual files")
+	expandGlobsLogger.Trace("Input patterns for expansion: %v", patterns)
 	var files []string
 	filesMap := make(map[string]bool)
 
 	cwd, err := os.Getwd()
 	if err != nil {
+		expandGlobsLogger.Error("Failed to get current working directory: %v", err)
 		return nil, fmt.Errorf("failed to get current working directory: %w", err)
 	}
+	expandGlobsLogger.Debug("Current working directory: %q", cwd)
 
-	logger.Debug("Expanding patterns from directory: %s", cwd)
 	for pattern := range patterns {
-		logger.Trace("Processing pattern: %s", pattern)
+		expandGlobsLogger.Debug("Processing glob pattern: %q", pattern)
 		static, pattern := SplitPattern(pattern)
-		matches, _ := doublestar.Glob(os.DirFS(static), pattern)
-		logger.Debug("Found %d matches for pattern %s", len(matches), pattern)
+		matches, err := doublestar.Glob(os.DirFS(static), pattern)
+		if err != nil {
+			expandGlobsLogger.Warning("Error expanding glob %q in %q: %v", pattern, static, err)
+			continue
+		}
+		expandGlobsLogger.Debug("Found %d matches for pattern %q", len(matches), pattern)
+		expandGlobsLogger.Trace("Raw matches for pattern %q: %v", pattern, matches)
 		for _, m := range matches {
 			m = filepath.Join(static, m)
 			info, err := os.Stat(m)
 			if err != nil {
-				logger.Warning("Error getting file info for %s: %v", m, err)
+				expandGlobsLogger.Warning("Error getting file info for %q: %v", m, err)
 				continue
 			}
 			if !info.IsDir() && !filesMap[m] {
-				logger.Trace("Adding file to process list: %s", m)
+				expandGlobsLogger.Trace("Adding unique file to list: %q", m)
 				filesMap[m], files = true, append(files, m)
 			}
 		}
 	}
 
 	if len(files) > 0 {
-		logger.Debug("Found %d files to process: %v", len(files), files)
+		expandGlobsLogger.Debug("Finished expanding globs. Found %d unique files to process", len(files))
+		expandGlobsLogger.Trace("Unique files to process: %v", files)
+	} else {
+		expandGlobsLogger.Warning("No files found after expanding glob patterns.")
 	}
 	return files, nil
 }
 
 func LoadCommands(args []string) ([]ModifyCommand, error) {
+	loadCommandsLogger := modifyCommandLogger.WithPrefix("LoadCommands")
+	loadCommandsLogger.Debug("Loading commands from arguments (cook files or direct patterns)")
+	loadCommandsLogger.Trace("Input arguments: %v", args)
 	commands := []ModifyCommand{}
 
-	logger.Info("Loading commands from cook files: %s", args)
 	for _, arg := range args {
-		newcommands, err := LoadCommandsFromCookFiles(arg)
+		loadCommandsLogger.Debug("Processing argument for commands: %q", arg)
+		newCommands, err := LoadCommandsFromCookFiles(arg)
 		if err != nil {
+			loadCommandsLogger.Error("Failed to load commands from argument %q: %v", arg, err)
 			return nil, fmt.Errorf("failed to load commands from cook files: %w", err)
 		}
-		logger.Info("Successfully loaded %d commands from cook files", len(newcommands))
-		for _, cmd := range newcommands {
+		loadCommandsLogger.Debug("Successfully loaded %d commands from %q", len(newCommands), arg)
+		for _, cmd := range newCommands {
 			if cmd.Disabled {
-				logger.Info("Skipping disabled command: %s", cmd.Name)
+				loadCommandsLogger.Debug("Skipping disabled command: %q", cmd.Name)
 				continue
 			}
 			commands = append(commands, cmd)
+			loadCommandsLogger.Trace("Added command %q. Current total commands: %d", cmd.Name, len(commands))
 		}
-		logger.Info("Now total commands: %d", len(commands))
 	}
 
-	logger.Info("Loaded %d commands from all cook file", len(commands))
+	loadCommandsLogger.Info("Finished loading commands. Total %d commands loaded", len(commands))
 	return commands, nil
 }
 
 func LoadCommandsFromCookFiles(pattern string) ([]ModifyCommand, error) {
+	loadCookFilesLogger := modifyCommandLogger.WithPrefix("LoadCommandsFromCookFiles").WithField("pattern", pattern)
+	loadCookFilesLogger.Debug("Loading commands from cook files based on pattern")
+	loadCookFilesLogger.Trace("Input pattern: %q", pattern)
 	static, pattern := SplitPattern(pattern)
 	commands := []ModifyCommand{}
 	cookFiles, err := doublestar.Glob(os.DirFS(static), pattern)
 	if err != nil {
+		loadCookFilesLogger.Error("Failed to glob cook files for pattern %q: %v", pattern, err)
 		return nil, fmt.Errorf("failed to glob cook files: %w", err)
 	}
+	loadCookFilesLogger.Debug("Found %d cook files for pattern %q", len(cookFiles), pattern)
+	loadCookFilesLogger.Trace("Cook files found: %v", cookFiles)
 
 	for _, cookFile := range cookFiles {
 		cookFile = filepath.Join(static, cookFile)
 		cookFile = filepath.Clean(cookFile)
 		cookFile = strings.ReplaceAll(cookFile, "\\", "/")
-		logger.Info("Loading commands from cook file: %s", cookFile)
+		loadCookFilesLogger.Debug("Loading commands from individual cook file: %q", cookFile)
 
 		cookFileData, err := os.ReadFile(cookFile)
 		if err != nil {
+			loadCookFilesLogger.Error("Failed to read cook file %q: %v", cookFile, err)
 			return nil, fmt.Errorf("failed to read cook file: %w", err)
 		}
-		newcommands, err := LoadCommandsFromCookFile(cookFileData)
+		loadCookFilesLogger.Trace("Read %d bytes from cook file %q", len(cookFileData), cookFile)
+		newCommands, err := LoadCommandsFromCookFile(cookFileData)
 		if err != nil {
+			loadCookFilesLogger.Error("Failed to load commands from cook file data for %q: %v", cookFile, err)
 			return nil, fmt.Errorf("failed to load commands from cook file: %w", err)
 		}
-		commands = append(commands, newcommands...)
+		commands = append(commands, newCommands...)
+		loadCookFilesLogger.Debug("Added %d commands from cook file %q. Total commands now: %d", len(newCommands), cookFile, len(commands))
 	}
 
+	loadCookFilesLogger.Debug("Finished loading commands from cook files. Total %d commands", len(commands))
 	return commands, nil
 }
 
 func LoadCommandsFromCookFile(cookFileData []byte) ([]ModifyCommand, error) {
+	loadCommandLogger := modifyCommandLogger.WithPrefix("LoadCommandsFromCookFile")
+	loadCommandLogger.Debug("Unmarshaling commands from cook file data")
+	loadCommandLogger.Trace("Cook file data length: %d", len(cookFileData))
 	commands := []ModifyCommand{}
 	err := yaml.Unmarshal(cookFileData, &commands)
 	if err != nil {
+		loadCommandLogger.Error("Failed to unmarshal cook file data: %v", err)
 		return nil, fmt.Errorf("failed to unmarshal cook file: %w", err)
 	}
+	loadCommandLogger.Debug("Successfully unmarshaled %d commands", len(commands))
+	loadCommandLogger.Trace("Unmarshaled commands: %v", commands)
 	return commands, nil
 }
 
 // CountGlobsBeforeDedup counts the total number of glob patterns across all commands before deduplication
 func CountGlobsBeforeDedup(commands []ModifyCommand) int {
+	countGlobsLogger := modifyCommandLogger.WithPrefix("CountGlobsBeforeDedup")
+	countGlobsLogger.Debug("Counting glob patterns before deduplication")
 	count := 0
 	for _, cmd := range commands {
+		countGlobsLogger.Trace("Processing command %q, adding %d globs", cmd.Name, len(cmd.Files))
 		count += len(cmd.Files)
 	}
+	countGlobsLogger.Debug("Total glob patterns before deduplication: %d", count)
 	return count
 }
 
 func FilterCommands(commands []ModifyCommand, filter string) []ModifyCommand {
+	filterCommandsLogger := modifyCommandLogger.WithPrefix("FilterCommands").WithField("filter", filter)
+	filterCommandsLogger.Debug("Filtering commands")
+	filterCommandsLogger.Trace("Input commands: %v", commands)
 	filteredCommands := []ModifyCommand{}
 	filters := strings.Split(filter, ",")
+	filterCommandsLogger.Trace("Split filters: %v", filters)
 	for _, cmd := range commands {
-		for _, filter := range filters {
-			if strings.Contains(cmd.Name, filter) {
+		filterCommandsLogger.Debug("Checking command %q against filters", cmd.Name)
+		for _, f := range filters {
+			if strings.Contains(cmd.Name, f) {
+				filterCommandsLogger.Debug("Command %q matches filter %q, adding to filtered list", cmd.Name, f)
 				filteredCommands = append(filteredCommands, cmd)
+				break // Command matches, no need to check other filters
 			}
 		}
 	}
+	filterCommandsLogger.Debug("Finished filtering commands. Found %d filtered commands", len(filteredCommands))
+	filterCommandsLogger.Trace("Filtered commands: %v", filteredCommands)
 	return filteredCommands
 }

utils/replacecommand.go

@@ -7,6 +7,9 @@ import (
 	logger "git.site.quack-lab.dev/dave/cylogger"
 )
 
+// replaceCommandLogger is a scoped logger for the utils/replacecommand package.
+var replaceCommandLogger = logger.Default.WithPrefix("utils/replacecommand")
+
 type ReplaceCommand struct {
 	From int
 	To   int
@@ -14,45 +17,63 @@ type ReplaceCommand struct {
 }
 
 func ExecuteModifications(modifications []ReplaceCommand, fileData string) (string, int) {
+	executeModificationsLogger := replaceCommandLogger.WithPrefix("ExecuteModifications")
+	executeModificationsLogger.Debug("Executing a batch of text modifications")
+	executeModificationsLogger.Trace("Number of modifications: %d, Original file data length: %d", len(modifications), len(fileData))
 	var err error
 
 	sort.Slice(modifications, func(i, j int) bool {
 		return modifications[i].From > modifications[j].From
 	})
-	logger.Trace("Preparing to apply %d replacement commands in reverse order", len(modifications))
+	executeModificationsLogger.Debug("Modifications sorted in reverse order for safe replacement")
+	executeModificationsLogger.Trace("Sorted modifications: %v", modifications)
 
 	executed := 0
-	for _, modification := range modifications {
+	for idx, modification := range modifications {
+		executeModificationsLogger.Debug("Applying modification %d/%d", idx+1, len(modifications))
+		executeModificationsLogger.Trace("Current modification details: From=%d, To=%d, With=%q", modification.From, modification.To, modification.With)
 		fileData, err = modification.Execute(fileData)
 		if err != nil {
-			logger.Error("Failed to execute replacement: %v", err)
+			executeModificationsLogger.Error("Failed to execute replacement for modification %+v: %v", modification, err)
 			continue
 		}
 		executed++
+		executeModificationsLogger.Trace("File data length after modification: %d", len(fileData))
 	}
-	logger.Info("Successfully applied %d text replacements", executed)
+	executeModificationsLogger.Info("Successfully applied %d text replacements", executed)
 	return fileData, executed
 }
 
 func (m *ReplaceCommand) Execute(fileDataStr string) (string, error) {
+	executeLogger := replaceCommandLogger.WithPrefix("Execute").WithField("modification", fmt.Sprintf("From:%d,To:%d,With:%q", m.From, m.To, m.With))
+	executeLogger.Debug("Attempting to execute single replacement")
 	err := m.Validate(len(fileDataStr))
 	if err != nil {
+		executeLogger.Error("Failed to validate modification: %v", err)
 		return fileDataStr, fmt.Errorf("failed to validate modification: %v", err)
 	}
 
-	logger.Trace("Replace pos %d-%d with %q", m.From, m.To, m.With)
-	return fileDataStr[:m.From] + m.With + fileDataStr[m.To:], nil
+	executeLogger.Trace("Applying replacement: fileDataStr[:%d] + %q + fileDataStr[%d:]", m.From, m.With, m.To)
+	result := fileDataStr[:m.From] + m.With + fileDataStr[m.To:]
+	executeLogger.Trace("Replacement executed. Result length: %d", len(result))
+	return result, nil
 }
 
 func (m *ReplaceCommand) Validate(maxsize int) error {
+	validateLogger := replaceCommandLogger.WithPrefix("Validate").WithField("modification", fmt.Sprintf("From:%d,To:%d,With:%q", m.From, m.To, m.With)).WithField("maxSize", maxsize)
+	validateLogger.Debug("Validating replacement command against max size")
 	if m.To < m.From {
+		validateLogger.Error("Validation failed: 'To' (%d) is less than 'From' (%d)", m.To, m.From)
 		return fmt.Errorf("command to is less than from: %v", m)
 	}
 	if m.From > maxsize || m.To > maxsize {
+		validateLogger.Error("Validation failed: 'From' (%d) or 'To' (%d) is greater than max size (%d)", m.From, m.To, maxsize)
 		return fmt.Errorf("command from or to is greater than replacement length: %v", m)
 	}
 	if m.From < 0 || m.To < 0 {
+		validateLogger.Error("Validation failed: 'From' (%d) or 'To' (%d) is less than 0", m.From, m.To)
 		return fmt.Errorf("command from or to is less than 0: %v", m)
 	}
+	validateLogger.Debug("Modification command validated successfully")
 	return nil
 }