[log] Add debug logging to CLI and workflow processing modules

pkg/cli/add_workflow_compilation.go

@@ -7,10 +7,13 @@ import (
 	"strings"
 
 	"github.com/githubnext/gh-aw/pkg/console"
+	"github.com/githubnext/gh-aw/pkg/logger"
 	"github.com/githubnext/gh-aw/pkg/stringutil"
 	"github.com/githubnext/gh-aw/pkg/workflow"
 )
 
+var addWorkflowCompilationLog = logger.New("cli:add_workflow_compilation")
+
 // updateWorkflowTitle updates the H1 title in workflow content by appending a number.
 // This is used when creating multiple numbered copies of a workflow.
 func updateWorkflowTitle(content string, number int) string {
@@ -36,6 +39,8 @@ func compileWorkflow(filePath string, verbose bool, quiet bool, engineOverride s
 // compileWorkflowWithRefresh compiles a workflow file with optional stop time refresh.
 // This function handles the compilation process and ensures .gitattributes is updated.
 func compileWorkflowWithRefresh(filePath string, verbose bool, quiet bool, engineOverride string, refreshStopTime bool) error {
+	addWorkflowCompilationLog.Printf("Compiling workflow: file=%s, refresh_stop_time=%v, engine=%s", filePath, refreshStopTime, engineOverride)
+
 	// Create compiler with auto-detected version and action mode
 	compiler := workflow.NewCompiler(
 		workflow.WithVerbose(verbose),
@@ -45,9 +50,12 @@ func compileWorkflowWithRefresh(filePath string, verbose bool, quiet bool, engin
 	compiler.SetRefreshStopTime(refreshStopTime)
 	compiler.SetQuiet(quiet)
 	if err := CompileWorkflowWithValidation(compiler, filePath, verbose, false, false, false, false, false); err != nil {
+		addWorkflowCompilationLog.Printf("Compilation failed: %v", err)
 		return err
 	}
 
+	addWorkflowCompilationLog.Print("Compilation completed successfully")
+
 	// Ensure .gitattributes marks .lock.yml files as generated
 	if err := ensureGitAttributes(); err != nil {
 		if verbose {
@@ -70,6 +78,8 @@ func compileWorkflowWithTracking(filePath string, verbose bool, quiet bool, engi
 // compileWorkflowWithTrackingAndRefresh compiles a workflow, tracks generated files, and optionally refreshes stop time.
 // This function ensures that the file tracker records all files created or modified during compilation.
 func compileWorkflowWithTrackingAndRefresh(filePath string, verbose bool, quiet bool, engineOverride string, tracker *FileTracker, refreshStopTime bool) error {
+	addWorkflowCompilationLog.Printf("Compiling workflow with tracking: file=%s, refresh_stop_time=%v", filePath, refreshStopTime)
+
 	// Generate the expected lock file path
 	lockFile := stringutil.MarkdownToLockFile(filePath)
 
@@ -79,6 +89,8 @@ func compileWorkflowWithTrackingAndRefresh(filePath string, verbose bool, quiet
 		lockFileExists = true
 	}
 
+	addWorkflowCompilationLog.Printf("Lock file %s exists: %v", lockFile, lockFileExists)
+
 	// Check if .gitattributes exists before ensuring it
 	gitRoot, err := findGitRoot()
 	if err != nil {

pkg/cli/add_workflow_pr.go

@@ -7,20 +7,30 @@ import (
 	"strings"
 
 	"github.com/githubnext/gh-aw/pkg/console"
+	"github.com/githubnext/gh-aw/pkg/logger"
 )
 
+var addWorkflowPRLog = logger.New("cli:add_workflow_pr")
+
 // addWorkflowsWithPR handles workflow addition with PR creation and returns the PR number and URL.
 func addWorkflowsWithPR(workflows []*WorkflowSpec, number int, verbose bool, quiet bool, engineOverride string, name string, force bool, appendText string, push bool, noGitattributes bool, fromWildcard bool, workflowDir string, noStopAfter bool, stopAfter string) (int, string, error) {
+	addWorkflowPRLog.Printf("Adding %d workflow(s) with PR creation", len(workflows))
+
 	// Get current branch for restoration later
 	currentBranch, err := getCurrentBranch()
 	if err != nil {
+		addWorkflowPRLog.Printf("Failed to get current branch: %v", err)
 		return 0, "", fmt.Errorf("failed to get current branch: %w", err)
 	}
 
+	addWorkflowPRLog.Printf("Current branch: %s", currentBranch)
+
 	// Create temporary branch with random 4-digit number
 	randomNum := rand.Intn(9000) + 1000 // Generate number between 1000-9999
 	branchName := fmt.Sprintf("add-workflow-%s-%04d", strings.ReplaceAll(workflows[0].WorkflowPath, "/", "-"), randomNum)
 
+	addWorkflowPRLog.Printf("Creating temporary branch: %s", branchName)
+
 	if err := createAndSwitchBranch(branchName, verbose); err != nil {
 		return 0, "", fmt.Errorf("failed to create branch %s: %w", branchName, err)
 	}
@@ -39,7 +49,9 @@ func addWorkflowsWithPR(workflows []*WorkflowSpec, number int, verbose bool, qui
 	}()
 
 	// Add workflows using the normal function logic
+	addWorkflowPRLog.Print("Adding workflows to repository")
 	if err := addWorkflowsNormal(workflows, number, verbose, quiet, engineOverride, name, force, appendText, push, noGitattributes, fromWildcard, workflowDir, noStopAfter, stopAfter); err != nil {
+		addWorkflowPRLog.Printf("Failed to add workflows: %v", err)
 		// Rollback on error
 		if rollbackErr := tracker.RollbackAllFiles(verbose); rollbackErr != nil && verbose {
 			fmt.Fprintln(os.Stderr, console.FormatWarningMessage(fmt.Sprintf("Failed to rollback files: %v", rollbackErr)))
@@ -48,6 +60,7 @@ func addWorkflowsWithPR(workflows []*WorkflowSpec, number int, verbose bool, qui
 	}
 
 	// Stage all files before creating PR
+	addWorkflowPRLog.Print("Staging workflow files")
 	if err := tracker.StageAllFiles(verbose); err != nil {
 		if rollbackErr := tracker.RollbackAllFiles(verbose); rollbackErr != nil && verbose {
 			fmt.Fprintln(os.Stderr, console.FormatWarningMessage(fmt.Sprintf("Failed to rollback files: %v", rollbackErr)))
@@ -87,22 +100,28 @@ func addWorkflowsWithPR(workflows []*WorkflowSpec, number int, verbose bool, qui
 	}
 
 	// Push branch
+	addWorkflowPRLog.Printf("Pushing branch %s to remote", branchName)
 	if err := pushBranch(branchName, verbose); err != nil {
+		addWorkflowPRLog.Printf("Failed to push branch: %v", err)
 		if rollbackErr := tracker.RollbackAllFiles(verbose); rollbackErr != nil && verbose {
 			fmt.Fprintln(os.Stderr, console.FormatWarningMessage(fmt.Sprintf("Failed to rollback files: %v", rollbackErr)))
 		}
 		return 0, "", fmt.Errorf("failed to push branch %s: %w", branchName, err)
 	}
 
 	// Create PR
+	addWorkflowPRLog.Printf("Creating pull request: %s", prTitle)
 	prNumber, prURL, err := createPR(branchName, prTitle, prBody, verbose)
 	if err != nil {
+		addWorkflowPRLog.Printf("Failed to create PR: %v", err)
 		if rollbackErr := tracker.RollbackAllFiles(verbose); rollbackErr != nil && verbose {
 			fmt.Fprintln(os.Stderr, console.FormatWarningMessage(fmt.Sprintf("Failed to rollback files: %v", rollbackErr)))
 		}
 		return 0, "", fmt.Errorf("failed to create PR: %w", err)
 	}
 
+	addWorkflowPRLog.Printf("Successfully created PR #%d: %s", prNumber, prURL)
+
 	// Success - no rollback needed
 
 	// Switch back to original branch

pkg/cli/mcp_inspect_inspector.go

@@ -10,13 +10,17 @@ import (
 	"time"
 
 	"github.com/githubnext/gh-aw/pkg/console"
+	"github.com/githubnext/gh-aw/pkg/logger"
 	"github.com/githubnext/gh-aw/pkg/parser"
 	"github.com/githubnext/gh-aw/pkg/workflow"
 )
 
+var mcpInspectorLog = logger.New("cli:mcp_inspect_inspector")
+
 // spawnMCPInspector launches the official @modelcontextprotocol/inspector tool
 // and spawns any stdio MCP servers beforehand
 func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) error {
+	mcpInspectorLog.Printf("Spawning MCP inspector: workflow_file=%s, server_filter=%s", workflowFile, serverFilter)
 	// Check if npx is available
 	if _, err := exec.LookPath("npx"); err != nil {
 		return fmt.Errorf("npx not found. Please install Node.js and npm to use the MCP inspector: %w", err)
@@ -60,9 +64,12 @@ func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) e
 		// Extract MCP configurations from the merged frontmatter
 		mcpConfigs, err = parser.ExtractMCPConfigurations(frontmatterForMCP, serverFilter)
 		if err != nil {
+			mcpInspectorLog.Printf("Failed to extract MCP configurations: %v", err)
 			return err
 		}
 
+		mcpInspectorLog.Printf("Extracted %d MCP server configurations from workflow", len(mcpConfigs))
+
 		if len(mcpConfigs) > 0 {
 			fmt.Fprintln(os.Stderr, console.FormatInfoMessage(fmt.Sprintf("Found %d MCP server(s) in workflow:", len(mcpConfigs))))
 			for _, config := range mcpConfigs {
@@ -79,6 +86,7 @@ func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) e
 			}
 
 			if len(stdioServers) > 0 {
+				mcpInspectorLog.Printf("Starting %d stdio MCP servers", len(stdioServers))
 				fmt.Fprintln(os.Stderr, console.FormatInfoMessage("Starting stdio MCP servers..."))
 
 				for _, config := range stdioServers {
@@ -111,10 +119,12 @@ func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) e
 
 					// Start the server process
 					if err := cmd.Start(); err != nil {
+						mcpInspectorLog.Printf("Failed to start MCP server %s: %v", config.Name, err)
 						fmt.Fprintln(os.Stderr, console.FormatWarningMessage(fmt.Sprintf("Failed to start server %s: %v", config.Name, err)))
 						continue
 					}
 
+					mcpInspectorLog.Printf("Started MCP server %s (PID: %d, type: %s)", config.Name, cmd.Process.Pid, config.Type)
 					serverProcesses = append(serverProcesses, cmd)
 
 					// Monitor the process in the background
@@ -166,6 +176,7 @@ func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) e
 	// Set up cleanup function for stdio servers
 	defer func() {
 		if len(serverProcesses) > 0 {
+			mcpInspectorLog.Printf("Cleaning up %d MCP server processes", len(serverProcesses))
 			fmt.Fprintln(os.Stderr, console.FormatInfoMessage("Cleaning up MCP servers..."))
 			for i, cmd := range serverProcesses {
 				if cmd.Process != nil {
@@ -197,6 +208,7 @@ func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) e
 		}
 	}()
 
+	mcpInspectorLog.Print("Launching @modelcontextprotocol/inspector")
 	fmt.Fprintln(os.Stderr, console.FormatInfoMessage("Launching @modelcontextprotocol/inspector..."))
 	fmt.Fprintln(os.Stderr, console.FormatInfoMessage("Visit http://localhost:5173 after the inspector starts"))
 	if len(serverProcesses) > 0 {
@@ -209,5 +221,11 @@ func spawnMCPInspector(workflowFile string, serverFilter string, verbose bool) e
 	cmd.Stderr = os.Stderr
 	cmd.Stdin = os.Stdin
 
-	return cmd.Run()
+	err := cmd.Run()
+	if err != nil {
+		mcpInspectorLog.Printf("MCP inspector exited with error: %v", err)
+	} else {
+		mcpInspectorLog.Print("MCP inspector exited successfully")
+	}
+	return err
 }

pkg/cli/mcp_tool_table.go

@@ -4,9 +4,12 @@ import (
 	"fmt"
 
 	"github.com/githubnext/gh-aw/pkg/console"
+	"github.com/githubnext/gh-aw/pkg/logger"
 	"github.com/githubnext/gh-aw/pkg/parser"
 )
 
+var mcpToolTableLog = logger.New("cli:mcp_tool_table")
+
 // MCPToolTableOptions configures how the MCP tool table is rendered
 type MCPToolTableOptions struct {
 	// TruncateLength is the maximum length for tool descriptions before truncation
@@ -33,7 +36,11 @@ func DefaultMCPToolTableOptions() MCPToolTableOptions {
 // renderMCPToolTable renders an MCP tool table with configurable options
 // This is the shared rendering logic used by both mcp list-tools and mcp inspect commands
 func renderMCPToolTable(info *parser.MCPServerInfo, opts MCPToolTableOptions) string {
+	mcpToolTableLog.Printf("Rendering MCP tool table: server=%s, tool_count=%d, truncate=%d",
+		info.Config.Name, len(info.Tools), opts.TruncateLength)
+
 	if len(info.Tools) == 0 {
+		mcpToolTableLog.Print("No tools to render")
 		return ""
 	}
 
@@ -49,6 +56,8 @@ func renderMCPToolTable(info *parser.MCPServerInfo, opts MCPToolTableOptions) st
 		allowedMap[allowed] = true
 	}
 
+	mcpToolTableLog.Printf("Tool permissions: has_wildcard=%v, allowed_count=%d", hasWildcard, len(allowedMap))
+
 	// Build table headers and rows
 	headers := []string{"Tool Name", "Allow", "Description"}
 	rows := make([][]string, 0, len(info.Tools))
@@ -114,7 +123,10 @@ func renderMCPToolTable(info *parser.MCPServerInfo, opts MCPToolTableOptions) st
 // renderMCPHierarchyTree renders all MCP servers and their tools as a tree structure
 // This provides a hierarchical view of the MCP configuration
 func renderMCPHierarchyTree(configs []parser.MCPServerConfig, serverInfos map[string]*parser.MCPServerInfo) string {
+	mcpToolTableLog.Printf("Rendering MCP hierarchy tree: server_count=%d", len(configs))
+
 	if len(configs) == 0 {
+		mcpToolTableLog.Print("No MCP servers to render")
 		return ""
 	}
 

pkg/cli/update_merge.go

@@ -7,13 +7,17 @@ import (
 	"path/filepath"
 
 	"github.com/githubnext/gh-aw/pkg/console"
+	"github.com/githubnext/gh-aw/pkg/logger"
 	"github.com/githubnext/gh-aw/pkg/stringutil"
 )
 
+var updateMergeLog = logger.New("cli:update_merge")
+
 // hasLocalModifications checks if the local workflow file has been modified from its source
 // It resolves the source field and imports on the remote content, then compares with local
 // Note: stop-after field is ignored during comparison as it's a deployment-specific setting
 func hasLocalModifications(sourceContent, localContent, sourceSpec string, verbose bool) bool {
+	updateMergeLog.Printf("Checking for local modifications: source_spec=%s", sourceSpec)
 	// Normalize both contents
 	sourceNormalized := stringutil.NormalizeWhitespace(sourceContent)
 	localNormalized := stringutil.NormalizeWhitespace(localContent)
@@ -67,6 +71,8 @@ func hasLocalModifications(sourceContent, localContent, sourceSpec string, verbo
 	// Compare the normalized contents
 	hasModifications := sourceResolvedNormalized != localNormalized
 
+	updateMergeLog.Printf("Local modifications detected: %v", hasModifications)
+
 	if verbose && hasModifications {
 		fmt.Fprintln(os.Stderr, console.FormatVerboseMessage("Local modifications detected"))
 	}
@@ -77,13 +83,16 @@ func hasLocalModifications(sourceContent, localContent, sourceSpec string, verbo
 // MergeWorkflowContent performs a 3-way merge of workflow content using git merge-file
 // It returns the merged content, whether conflicts exist, and any error
 func MergeWorkflowContent(base, current, new, oldSourceSpec, newRef string, verbose bool) (string, bool, error) {
+	updateMergeLog.Printf("Starting 3-way merge: old_ref=%s, new_ref=%s", oldSourceSpec, newRef)
+
 	if verbose {
 		fmt.Fprintln(os.Stderr, console.FormatVerboseMessage("Performing 3-way merge using git merge-file"))
 	}
 
 	// Parse the old source spec to get the current ref
 	sourceSpec, err := parseSourceSpec(oldSourceSpec)
 	if err != nil {
+		updateMergeLog.Printf("Failed to parse source spec: %v", err)
 		return "", false, fmt.Errorf("failed to parse source spec: %w", err)
 	}
 	currentSourceSpec := fmt.Sprintf("%s/%s@%s", sourceSpec.Repo, sourceSpec.Path, sourceSpec.Ref)
@@ -159,18 +168,22 @@ func MergeWorkflowContent(base, current, new, oldSourceSpec, newRef string, verb
 				// Conflicts found (exit codes 1-127 indicate conflicts)
 				// Exit codes >= 128 typically indicate system errors
 				hasConflicts = true
+				updateMergeLog.Printf("Merge conflicts detected: exit_code=%d", exitCode)
 				if verbose {
 					fmt.Fprintln(os.Stderr, console.FormatWarningMessage(fmt.Sprintf("Merge conflicts detected (exit code: %d)", exitCode)))
 				}
 			} else {
 				// Real error (exit code >= 128)
+				updateMergeLog.Printf("Git merge-file failed: exit_code=%d", exitCode)
 				return "", false, fmt.Errorf("git merge-file failed: %w\nOutput: %s", err, output)
 			}
 		} else {
 			return "", false, fmt.Errorf("failed to execute git merge-file: %w", err)
 		}
 	}
 
+	updateMergeLog.Printf("Merge completed: has_conflicts=%v", hasConflicts)
+
 	// Read the merged content from the current file (git merge-file updates it in-place)
 	mergedContent, err := os.ReadFile(currentFile)
 	if err != nil {