Fix/butler debugging

internal/app/util.go

@@ -1,10 +1,21 @@
 package app
 
 import (
+	"context"
+	"fmt"
+	"os"
+	"os/exec"
+	"path/filepath"
 	"regexp"
+	"runtime"
+	"time"
 
+	"HyLauncher/internal/env"
+	"HyLauncher/internal/patch"
+	"HyLauncher/internal/platform"
 	"HyLauncher/internal/service"
 	"HyLauncher/pkg/hyerrors"
+	"HyLauncher/pkg/logger"
 )
 
 func (a *App) GetLogs() (string, error) {
@@ -32,3 +43,100 @@ func (a *App) validatePlayerName(name string) error {
 
 	return nil
 }
+
+type ButlerDiagnosticResult struct {
+	Success      bool   `json:"success"`
+	Version      string `json:"version,omitempty"`
+	Error        string `json:"error,omitempty"`
+	Details      string `json:"details,omitempty"`
+	DebugLogPath string `json:"debugLogPath,omitempty"`
+}
+
+func (a *App) TestButler() ButlerDiagnosticResult {
+	logger.Info("Starting Butler diagnostic test")
+
+	butlerPath, err := patch.GetButlerExec()
+	if err != nil {
+		logger.Error("Butler diagnostic: cannot find butler", "error", err)
+		return ButlerDiagnosticResult{
+			Success: false,
+			Error:   fmt.Sprintf("Cannot find butler: %v", err),
+		}
+	}
+
+	// Test 1: Check butler version
+	ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second)
+	defer cancel()
+
+	versionCmd := exec.CommandContext(ctx, butlerPath, "--version")
+	platform.HideConsoleWindow(versionCmd)
+	versionOutput, versionErr := versionCmd.CombinedOutput()
+
+	versionStr := string(versionOutput)
+	if versionErr != nil {
+		logger.Error("Butler diagnostic: version check failed", "error", versionErr, "output", versionStr)
+		return ButlerDiagnosticResult{
+			Success: false,
+			Error:   fmt.Sprintf("Version check failed: %v", versionErr),
+			Details: versionStr,
+		}
+	}
+
+	logger.Info("Butler diagnostic: version check passed", "version", versionStr)
+
+	// Test 2: Check butler can access filesystem
+	testDir := filepath.Join(env.GetCacheDir(), "butler-test")
+	_ = os.RemoveAll(testDir)
+	_ = os.MkdirAll(testDir, 0755)
+	defer os.RemoveAll(testDir)
+
+	// Create a simple test file
+	testFile := filepath.Join(testDir, "test.txt")
+	testContent := []byte("hello world")
+	if err := os.WriteFile(testFile, testContent, 0644); err != nil {
+		logger.Error("Butler diagnostic: failed to create test file", "error", err)
+		return ButlerDiagnosticResult{
+			Success: false,
+			Version: versionStr,
+			Error:   fmt.Sprintf("Failed to create test file: %v", err),
+		}
+	}
+
+	// Test 3: Check environment
+	envInfo := fmt.Sprintf(
+		"OS: %s\nArch: %s\nGo Version: %s\nButler Path: %s\nTest Dir: %s\nPATH: %s\nTEMP: %s\nTMPDIR: %s",
+		runtime.GOOS,
+		runtime.GOARCH,
+		runtime.Version(),
+		butlerPath,
+		testDir,
+		os.Getenv("PATH"),
+		os.Getenv("TEMP"),
+		os.Getenv("TMPDIR"),
+	)
+
+	// Write comprehensive debug log
+	debugLogPath := filepath.Join(env.GetCacheDir(), "butler-diagnostic.log")
+	debugContent := fmt.Sprintf(
+		"=== BUTLER DIAGNOSTIC REPORT ===\n"+
+			"Time: %s\n\n"+
+			"=== ENVIRONMENT ===\n%s\n\n"+
+			"=== VERSION OUTPUT ===\n%s\n",
+		time.Now().Format(time.RFC3339),
+		envInfo,
+		versionStr,
+	)
+
+	if err := os.WriteFile(debugLogPath, []byte(debugContent), 0644); err != nil {
+		logger.Warn("Butler diagnostic: failed to write debug log", "error", err)
+	}
+
+	logger.Info("Butler diagnostic completed successfully", "version", versionStr, "debugLog", debugLogPath)
+
+	return ButlerDiagnosticResult{
+		Success:      true,
+		Version:      versionStr,
+		Details:      envInfo,
+		DebugLogPath: debugLogPath,
+	}
+}

internal/patch/pwr_patcher.go

@@ -5,12 +5,12 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
-	"io"
 	"net/http"
 	"os"
 	"os/exec"
 	"path/filepath"
 	"strconv"
+	"strings"
 	"time"
 
 	"HyLauncher/internal/env"
@@ -42,124 +42,159 @@ type PatchStepsResponse struct {
 func DownloadAndApplyPWR(ctx context.Context, branch string, currentVer int, targetVer int, versionDir string, reporter *progress.Reporter) error {
 	logger.Info("Starting patch download", "branch", branch, "from", currentVer, "to", targetVer)
 
-	var pwrPath string
-
 	steps, err := fetchPatchSteps(ctx, branch, currentVer)
 	if err != nil {
-		logger.Error("Failed to fetch patch steps", "branch", branch, "error", err)
 		return fmt.Errorf("fetch patch steps: %w", err)
 	}
 
 	if len(steps) == 0 {
-		logger.Warn("No patch steps available", "branch", branch, "currentVer", currentVer)
 		return fmt.Errorf("no patch steps available")
 	}
 
-	logger.Info("Found patch steps", "count", len(steps), "branch", branch)
-	for i, step := range steps {
-		logger.Info("  Step", "index", i, "from", step.From, "to", step.To)
-	}
-
 	for i, step := range steps {
 		if targetVer > 0 && step.From >= targetVer {
-			logger.Info("Reached target version, stopping", "target", targetVer, "current", step.From)
 			break
 		}
 
 		logger.Info("Downloading patch", "from", step.From, "to", step.To, "progress", fmt.Sprintf("%d/%d", i+1, len(steps)))
-
 		if reporter != nil {
 			reporter.Report(progress.StagePatch, 0, fmt.Sprintf("Patching %d → %d (%d/%d)", step.From, step.To, i+1, len(steps)))
 		}
 
 		pwrPath, sigPath, err := downloadPatchStep(ctx, step, reporter)
 		if err != nil {
-			logger.Error("Failed to download patch", "from", step.From, "to", step.To, "error", err)
 			return fmt.Errorf("download patch step %d→%d: %w", step.From, step.To, err)
 		}
 
-		logger.Info("Applying patch", "from", step.From, "to", step.To)
 		if err := applyPWR(ctx, pwrPath, sigPath, branch, versionDir, reporter); err != nil {
 			_ = os.Remove(pwrPath)
 			_ = os.Remove(sigPath)
-			logger.Error("Failed to apply patch", "from", step.From, "to", step.To, "error", err)
 			return fmt.Errorf("apply patch %d→%d: %w", step.From, step.To, err)
 		}
-
-		logger.Info("Patch applied successfully", "from", step.From, "to", step.To)
 	}
 
-	_ = os.RemoveAll(pwrPath)
 	logger.Info("All patches applied", "totalSteps", len(steps))
-
 	return nil
 }
 
-func applyPWR(ctx context.Context, pwrFile string, sigFile string, branch string, version string, reporter *progress.Reporter) error {
+func applyPWR(ctx context.Context, pwrFile, sigFile, branch, version string, reporter *progress.Reporter) error {
 	gameDir := env.GetGameDir(branch, version)
 	stagingDir := filepath.Join(env.GetCacheDir(), "staging-temp")
-	_ = os.RemoveAll(stagingDir)
 
+	_ = os.RemoveAll(stagingDir)
 	_ = os.MkdirAll(gameDir, 0755)
 	_ = os.MkdirAll(stagingDir, 0755)
 
-	// Log what files are currently in the game directory
-	logger.Info("Game directory contents before patch", "dir", gameDir)
-	entries, _ := os.ReadDir(gameDir)
-	for _, entry := range entries {
-		logger.Info("  File", "name", entry.Name(), "isDir", entry.IsDir())
-	}
-
 	butlerPath, err := GetButlerExec()
 	if err != nil {
 		return fmt.Errorf("cannot get butler: %w", err)
 	}
 
-	logger.Info("Running butler apply", "pwr", pwrFile, "sig", sigFile, "gameDir", gameDir, "stagingDir", stagingDir)
-
 	cmd := exec.CommandContext(ctx, butlerPath,
 		"apply",
 		"--staging-dir", stagingDir,
 		"--signature", sigFile,
 		pwrFile,
 		gameDir,
 	)
-
 	platform.HideConsoleWindow(cmd)
 
-	// Capture output for logging
 	var stdoutBuf, stderrBuf bytes.Buffer
-	cmd.Stdout = io.MultiWriter(os.Stdout, &stdoutBuf)
-	cmd.Stderr = io.MultiWriter(os.Stderr, &stderrBuf)
+	cmd.Stdout = &stdoutBuf
+	cmd.Stderr = &stderrBuf
 
 	if reporter != nil {
 		reporter.Report(progress.StagePatch, 60, "Applying game patch...")
 	}
 
 	if err := cmd.Run(); err != nil {
+		return handleApplyError(ctx, err, cmd, stdoutBuf.String(), stderrBuf.String(), gameDir, stagingDir, butlerPath, sigFile, pwrFile, reporter)
+	}
+
+	cleanup(cmd, stagingDir, reporter)
+	return nil
+}
+
+func handleApplyError(ctx context.Context, err error, cmd *exec.Cmd, stdoutStr, stderrStr, gameDir, stagingDir, butlerPath, sigFile, pwrFile string, reporter *progress.Reporter) error {
+	_ = os.RemoveAll(stagingDir)
+
+	debugLogPath := writeDebugLog(cmd.Args, gameDir, stdoutStr, stderrStr, err)
+
+	if isSignatureError(stdoutStr, stderrStr) {
+		return retryAfterCleanup(ctx, gameDir, stagingDir, butlerPath, sigFile, pwrFile, reporter, err)
+	}
+
+	if exitErr, ok := err.(*exec.ExitError); ok {
+		return fmt.Errorf("butler apply failed (exit %d): %s (log: %s)", exitErr.ExitCode(), stderrStr, debugLogPath)
+	}
+	return fmt.Errorf("butler apply failed: %w (log: %s)", err, debugLogPath)
+}
+
+func isSignatureError(stdout, stderr string) bool {
+	combined := stdout + stderr
+	return strings.Contains(combined, "Verifying against signature") &&
+		(strings.Contains(combined, "expected") || strings.Contains(combined, "dirs"))
+}
+
+func retryAfterCleanup(ctx context.Context, gameDir, stagingDir, butlerPath, sigFile, pwrFile string, reporter *progress.Reporter, originalErr error) error {
+	logger.Warn("Signature verification failed - cleaning and retrying", "gameDir", gameDir)
+
+	_ = os.RemoveAll(gameDir)
+	_ = os.RemoveAll(stagingDir)
+	_ = os.MkdirAll(gameDir, 0755)
+	_ = os.MkdirAll(stagingDir, 0755)
+
+	if reporter != nil {
+		reporter.Report(progress.StagePatch, 60, "Retrying after cleaning modified files...")
+	}
+
+	retryCmd := exec.CommandContext(ctx, butlerPath,
+		"apply",
+		"--staging-dir", stagingDir,
+		"--signature", sigFile,
+		pwrFile,
+		gameDir,
+	)
+	platform.HideConsoleWindow(retryCmd)
+
+	var stdoutBuf, stderrBuf bytes.Buffer
+	retryCmd.Stdout = &stdoutBuf
+	retryCmd.Stderr = &stderrBuf
+
+	if err := retryCmd.Run(); err != nil {
 		_ = os.RemoveAll(stagingDir)
-		stdoutStr := stdoutBuf.String()
-		stderrStr := stderrBuf.String()
-		logger.Error("Butler apply failed", "error", err, "stdout", stdoutStr, "stderr", stderrStr)
-		if exitErr, ok := err.(*exec.ExitError); ok {
-			return fmt.Errorf("butler apply failed with exit code %d: stderr=%s", exitErr.ExitCode(), stderrStr)
-		}
-		return fmt.Errorf("butler apply failed: %w", err)
+		return fmt.Errorf("patch failed even after cleanup: %w (original: %v)", err, originalErr)
 	}
 
-	logger.Info("Butler apply completed", "stdout", stdoutBuf.String())
+	logger.Info("Patch applied successfully after cleanup")
+	cleanup(retryCmd, stagingDir, reporter)
+	return nil
+}
 
+func cleanup(cmd *exec.Cmd, stagingDir string, reporter *progress.Reporter) {
 	if cmd.Process != nil {
 		_ = cmd.Process.Kill()
 		_ = cmd.Process.Release()
 	}
-
 	_ = os.RemoveAll(stagingDir)
-
 	if reporter != nil {
 		reporter.Report(progress.StagePatch, 80, "Game patched!")
 	}
-	return nil
+}
+
+func writeDebugLog(args []string, gameDir, stdout, stderr string, err error) string {
+	debugLogPath := filepath.Join(env.GetCacheDir(), fmt.Sprintf("butler-debug-%d.log", time.Now().Unix()))
+	content := fmt.Sprintf(
+		"Time: %s\nCommand: %v\nGame Dir: %s\n\nSTDOUT:\n%s\n\nSTDERR:\n%s\n\nError: %v\n",
+		time.Now().Format(time.RFC3339),
+		args,
+		gameDir,
+		stdout,
+		stderr,
+		err,
+	)
+	_ = os.WriteFile(debugLogPath, []byte(content), 0644)
+	return debugLogPath
 }
 
 func fetchPatchSteps(ctx context.Context, branch string, currentVer int) ([]PatchStep, error) {
@@ -179,7 +214,6 @@ func fetchPatchSteps(ctx context.Context, branch string, currentVer int) ([]Patc
 	if err != nil {
 		return nil, fmt.Errorf("create request: %w", err)
 	}
-
 	req.Header.Set("Content-Type", "application/json")
 
 	client := &http.Client{Timeout: 30 * time.Second}
@@ -211,13 +245,13 @@ func downloadPatchStep(ctx context.Context, step PatchStep, reporter *progress.R
 	pwrDest := filepath.Join(cacheDir, pwrFileName)
 	sigDest := filepath.Join(cacheDir, sigFileName)
 
-	_, pwrErr := os.Stat(pwrDest)
-	_, sigErr := os.Stat(sigDest)
-	if pwrErr == nil && sigErr == nil {
-		if reporter != nil {
-			reporter.Report(progress.StagePWR, 100, "Patch files cached")
+	if _, pwrErr := os.Stat(pwrDest); pwrErr == nil {
+		if _, sigErr := os.Stat(sigDest); sigErr == nil {
+			if reporter != nil {
+				reporter.Report(progress.StagePWR, 100, "Patch files cached")
+			}
+			return pwrDest, sigDest, nil
 		}
-		return pwrDest, sigDest, nil
 	}
 
 	if reporter != nil {