From 5c13aca5e980c118b75329c1bf660a0c1bd80a48 Mon Sep 17 00:00:00 2001 From: jordanstephens Date: Thu, 12 Mar 2026 16:48:50 -0700 Subject: [PATCH 1/3] always write all logs to debug.log, never print debug to terminal - All log levels (including debug) are always written to ~/.local/state/defang/debug-*.log, renamed atomically to debug.log on exit - Debug logs are never printed to the terminal, even with --debug - If --debug is set, a reminder message is printed on exit with the log path - slog debug messages now always flow through to the file (Enabled() = true) Co-Authored-By: Claude Sonnet 4.6 --- src/cmd/cli/main.go | 41 +++++++++++++++++++++++++++++++ src/pkg/logs/slog.go | 3 --- src/pkg/term/colorizer.go | 45 +++++++++++++++++++++++++++------- src/pkg/term/colorizer_test.go | 25 ++++++++++++++----- 4 files changed, 96 insertions(+), 18 deletions(-) diff --git a/src/cmd/cli/main.go b/src/cmd/cli/main.go index 9fe6caa0b..7f86a0032 100644 --- a/src/cmd/cli/main.go +++ b/src/cmd/cli/main.go @@ -3,12 +3,16 @@ package main import ( "bytes" "context" + "fmt" "log/slog" "os" "os/signal" + "path/filepath" "runtime/debug" + "sync" "github.com/DefangLabs/defang/src/cmd/cli/command" + "github.com/DefangLabs/defang/src/pkg/cli/client" "github.com/DefangLabs/defang/src/pkg/logs" "github.com/DefangLabs/defang/src/pkg/term" "github.com/DefangLabs/defang/src/pkg/track" @@ -28,6 +32,11 @@ func main() { setUidGidFromFile(homeDir) } + // Set up always-on debug log file; all log levels are written here. + // defer handles the normal-exit path; the explicit call handles os.Exit. + flushDebugLog := setupDebugLog() + defer flushDebugLog() + // Handle Ctrl+C so we can exit gracefully ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt) @@ -47,6 +56,7 @@ func main() { if !ok { ec = 1 // should not happen since we always return ExitCode } + flushDebugLog() // os.Exit skips defers, so flush explicitly os.Exit(int(ec)) } } @@ -56,3 +66,34 @@ func skipLines(buf []byte, n int) []byte { lines := bytes.SplitN(buf, []byte{'\n'}, n) return lines[len(lines)-1] } + +// setupDebugLog creates a temp debug log file, wires it into DefaultTerm, and +// returns a flush function that closes and atomically renames the file to +// debug.log. The flush function is idempotent — safe to call multiple times. +func setupDebugLog() func() { + stateDir := client.StateDir + if err := os.MkdirAll(stateDir, 0700); err != nil { + return func() {} + } + + finalPath := filepath.Join(stateDir, "debug.log") + f, err := os.CreateTemp(stateDir, "debug-*.log") + if err != nil { + return func() {} + } + tmpPath := f.Name() + + term.SetDebugLog(f) + + var once sync.Once + return func() { + once.Do(func() { + term.SetDebugLog(nil) + f.Close() + os.Rename(tmpPath, finalPath) //nolint:errcheck + if term.DoDebug() { + fmt.Fprintf(os.Stderr, " * Debug log written to: %s\n", finalPath) + } + }) + } +} diff --git a/src/pkg/logs/slog.go b/src/pkg/logs/slog.go index a840c47cf..52a445e53 100644 --- a/src/pkg/logs/slog.go +++ b/src/pkg/logs/slog.go @@ -66,9 +66,6 @@ func (h *termHandler) Handle(ctx context.Context, r slog.Record) error { } func (h *termHandler) Enabled(ctx context.Context, level slog.Level) bool { - if level == slog.LevelDebug { - return h.t.DoDebug() - } return true } diff --git a/src/pkg/term/colorizer.go b/src/pkg/term/colorizer.go index 89f9cf134..64ff7cb69 100644 --- a/src/pkg/term/colorizer.go +++ b/src/pkg/term/colorizer.go @@ -23,6 +23,8 @@ type Term struct { hasDarkBg bool warnings []string + + debugLog io.Writer // always-on file writer for all log levels; nil until set } var DefaultTerm = NewTerm(os.Stdin, os.Stdout, os.Stderr) @@ -85,6 +87,16 @@ func (t *Term) SetDebug(debug bool) { t.debug = debug } +func (t *Term) SetDebugLog(w io.Writer) { + t.debugLog = w +} + +func (t *Term) teeLog(msg string) { + if t.debugLog != nil { + fmt.Fprint(t.debugLog, msg) + } +} + func (t *Term) SetJSON(json bool) { if json { t.ForceColor(false) @@ -211,17 +223,19 @@ func (t *Term) Printf(format string, v ...any) (int, error) { } func (t *Term) Debug(v ...any) (int, error) { - if !t.debug { + if t.debugLog == nil { return 0, nil } - return output(t.err, DebugColor, ensurePrefix(debugPrefix, fmt.Sprintln(v...))) + msg := ensurePrefix(debugPrefix, fmt.Sprintln(v...)) + return fmt.Fprint(t.debugLog, msg) } func (t *Term) Debugf(format string, v ...any) (int, error) { - if !t.debug { + if t.debugLog == nil { return 0, nil } - return output(t.err, DebugColor, ensureNewline(ensurePrefix(debugPrefix, fmt.Sprintf(format, v...)))) + msg := ensureNewline(ensurePrefix(debugPrefix, fmt.Sprintf(format, v...))) + return fmt.Fprint(t.debugLog, msg) } func (t *Term) outOrErr() *termenv.Output { @@ -232,32 +246,41 @@ func (t *Term) outOrErr() *termenv.Output { } func (t *Term) Info(v ...any) (int, error) { - return output(t.outOrErr(), InfoColor, ensurePrefix(infoPrefix, fmt.Sprintln(v...))) + msg := ensurePrefix(infoPrefix, fmt.Sprintln(v...)) + t.teeLog(msg) + return output(t.outOrErr(), InfoColor, msg) } func (t *Term) Infof(format string, v ...any) (int, error) { - return output(t.outOrErr(), InfoColor, ensureNewline(ensurePrefix(infoPrefix, fmt.Sprintf(format, v...)))) + msg := ensureNewline(ensurePrefix(infoPrefix, fmt.Sprintf(format, v...))) + t.teeLog(msg) + return output(t.outOrErr(), InfoColor, msg) } func (t *Term) Warn(v ...any) (int, error) { msg := ensurePrefix(warnPrefix, fmt.Sprintln(v...)) t.warnings = append(t.warnings, msg) + t.teeLog(msg) return output(t.outOrErr(), WarnColor, msg) } func (t *Term) Warnf(format string, v ...any) (int, error) { msg := ensureNewline(ensurePrefix(warnPrefix, fmt.Sprintf(format, v...))) t.warnings = append(t.warnings, msg) + t.teeLog(msg) return output(t.outOrErr(), WarnColor, msg) } func (t *Term) Error(v ...any) (int, error) { - return output(t.err, ErrorColor, fmt.Sprintln(v...)) + msg := fmt.Sprintln(v...) + t.teeLog(msg) + return output(t.err, ErrorColor, msg) } func (t *Term) Errorf(format string, v ...any) (int, error) { - line := ensureNewline(fmt.Sprintf(format, v...)) - return output(t.err, ErrorColor, line) + msg := ensureNewline(fmt.Sprintf(format, v...)) + t.teeLog(msg) + return output(t.err, ErrorColor, msg) } // Deprecated: use proper error handling instead @@ -372,6 +395,10 @@ func SetDebug(debug bool) { DefaultTerm.SetDebug(debug) } +func SetDebugLog(w io.Writer) { + DefaultTerm.SetDebugLog(w) +} + func SetJSON(json bool) { DefaultTerm.SetJSON(json) } diff --git a/src/pkg/term/colorizer_test.go b/src/pkg/term/colorizer_test.go index 295adfca6..2c41e8874 100644 --- a/src/pkg/term/colorizer_test.go +++ b/src/pkg/term/colorizer_test.go @@ -74,9 +74,10 @@ func TestAddingPrefix(t *testing.T) { t.Cleanup(func() { DefaultTerm = defaultTerm }) - var stdout, stderr bytes.Buffer + var stdout, stderr, debugLog bytes.Buffer DefaultTerm = NewTerm(os.Stdin, &stdout, &stderr) DefaultTerm.SetDebug(true) + DefaultTerm.SetDebugLog(&debugLog) Debug("Hello, World!") Debugf("Hello, %s!", "World") @@ -110,16 +111,28 @@ func TestAddingPrefix(t *testing.T) { } } - expectedErr := []string{ + if stderr.String() != "" { + t.Errorf("Expected stderr to be empty (debug goes to log file), got %q", stderr.String()) + } + + expectedLog := []string{ " - Hello, World!", " - Hello, World!", " - Hello, World!", " - Hello, World!", + " * Hello, World!", + " * Hello, World!", + " * Hello, World!", + " * Hello, World!", + " ! Hello, World!", + " ! Hello, World!", + " ! Hello, World!", + " ! Hello, World!", } - gotErr := strings.Split(strings.TrimRight(stderr.String(), "\n"), "\n") - for i, line := range gotErr { - if line != expectedErr[i] { - t.Errorf("Expected line %v in stderr to be %q, got %q", i, expectedErr[i], line) + gotLog := strings.Split(strings.TrimRight(debugLog.String(), "\n"), "\n") + for i, line := range gotLog { + if line != expectedLog[i] { + t.Errorf("Expected line %v in debug log to be %q, got %q", i, expectedLog[i], line) } } } From 11b8925033c0ad253d83921427735c1de825a838 Mon Sep 17 00:00:00 2001 From: jordanstephens Date: Thu, 12 Mar 2026 16:58:55 -0700 Subject: [PATCH 2/3] fix debug output leaking to stdout via term.Println/Printc Replace direct term.Println/Printc calls inside DoDebug() guards with term.Debug/Debugf so those dumps go to the log file instead of stdout. Co-Authored-By: Claude Sonnet 4.6 --- src/cmd/cli/main.go | 3 +-- src/pkg/cli/compose/loader.go | 2 +- src/pkg/cli/composeUp.go | 6 ++++-- src/pkg/cli/generate.go | 6 +----- 4 files changed, 7 insertions(+), 10 deletions(-) diff --git a/src/cmd/cli/main.go b/src/cmd/cli/main.go index 7f86a0032..c875cad38 100644 --- a/src/cmd/cli/main.go +++ b/src/cmd/cli/main.go @@ -3,7 +3,6 @@ package main import ( "bytes" "context" - "fmt" "log/slog" "os" "os/signal" @@ -92,7 +91,7 @@ func setupDebugLog() func() { f.Close() os.Rename(tmpPath, finalPath) //nolint:errcheck if term.DoDebug() { - fmt.Fprintf(os.Stderr, " * Debug log written to: %s\n", finalPath) + term.Infof("Debug log written to: %s", finalPath) } }) } diff --git a/src/pkg/cli/compose/loader.go b/src/pkg/cli/compose/loader.go index 3044da40d..a7ea36e38 100644 --- a/src/pkg/cli/compose/loader.go +++ b/src/pkg/cli/compose/loader.go @@ -120,7 +120,7 @@ func (l *Loader) loadProject(ctx context.Context, suppressWarn bool) (*Project, if term.DoDebug() { b, _ := yaml.Marshal(project) - term.Println(string(b)) + term.Debug(string(b)) } l.cached = project diff --git a/src/pkg/cli/composeUp.go b/src/pkg/cli/composeUp.go index 8f1089e43..ed753535f 100644 --- a/src/pkg/cli/composeUp.go +++ b/src/pkg/cli/composeUp.go @@ -204,9 +204,11 @@ func ComposeUp(ctx context.Context, fabric client.FabricClient, provider client. } if term.DoDebug() { - term.Println("Project:", project.Name) + term.Debugf("Project: %s", project.Name) for _, serviceInfo := range resp.Services { - PrintObject(serviceInfo.Service.Name, serviceInfo) + if b, err := MarshalPretty(serviceInfo.Service.Name, serviceInfo); err == nil { + term.Debug(string(b)) + } } } return resp, project, nil diff --git a/src/pkg/cli/generate.go b/src/pkg/cli/generate.go index 3147ed6ca..971e63be1 100644 --- a/src/pkg/cli/generate.go +++ b/src/pkg/cli/generate.go @@ -39,11 +39,7 @@ func GenerateWithAI(ctx context.Context, client client.FabricClient, args Genera if term.DoDebug() { // Print the files that were generated for _, file := range response.Files { - term.Printc(term.DebugColor, file.Name+"\n```") - term.Printc(term.DebugColor, file.Content) - term.Printc(term.DebugColor, "```") - term.Println("") - term.Println("") + term.Debugf("%s\n```\n%s\n```\n", file.Name, file.Content) } } From 632937075366fa30943b872f9bbe17e08908bfce Mon Sep 17 00:00:00 2001 From: jordanstephens Date: Thu, 12 Mar 2026 17:31:46 -0700 Subject: [PATCH 3/3] remove unnecessary DoDebug guards --- src/pkg/cli/compose/context.go | 5 ++--- src/pkg/cli/compose/loader.go | 6 ++---- src/pkg/cli/composeUp.go | 12 ++++++------ src/pkg/cli/generate.go | 8 +++----- 4 files changed, 13 insertions(+), 18 deletions(-) diff --git a/src/pkg/cli/compose/context.go b/src/pkg/cli/compose/context.go index 40d1106a1..329db6277 100644 --- a/src/pkg/cli/compose/context.go +++ b/src/pkg/cli/compose/context.go @@ -446,9 +446,8 @@ func createArchive(ctx context.Context, root string, dockerfile string, contentT doProgress := term.StdoutCanColor() && term.IsTerminal() err := walkContextFolder(root, dockerfile, writeIgnoreFileYes, func(path string, de os.DirEntry, slashPath string) error { - if term.DoDebug() { - term.Debug("Adding", slashPath) - } else if doProgress { + term.Debug("Adding", slashPath) + if doProgress { term.Printf("%4d %s\r", fileCount, slashPath) defer term.ClearLine() } diff --git a/src/pkg/cli/compose/loader.go b/src/pkg/cli/compose/loader.go index a7ea36e38..f3e123bfd 100644 --- a/src/pkg/cli/compose/loader.go +++ b/src/pkg/cli/compose/loader.go @@ -118,10 +118,8 @@ func (l *Loader) loadProject(ctx context.Context, suppressWarn bool) (*Project, return nil, err } - if term.DoDebug() { - b, _ := yaml.Marshal(project) - term.Debug(string(b)) - } + b, _ := yaml.Marshal(project) + term.Debug(string(b)) l.cached = project return project, nil diff --git a/src/pkg/cli/composeUp.go b/src/pkg/cli/composeUp.go index ed753535f..8cd029ac9 100644 --- a/src/pkg/cli/composeUp.go +++ b/src/pkg/cli/composeUp.go @@ -203,12 +203,12 @@ func ComposeUp(ctx context.Context, fabric client.FabricClient, provider client. term.Warn("Unable to update deployment history; deployment will proceed anyway.") } - if term.DoDebug() { - term.Debugf("Project: %s", project.Name) - for _, serviceInfo := range resp.Services { - if b, err := MarshalPretty(serviceInfo.Service.Name, serviceInfo); err == nil { - term.Debug(string(b)) - } + term.Debugf("Project: %s", project.Name) + for _, serviceInfo := range resp.Services { + if b, err := MarshalPretty(serviceInfo.Service.Name, serviceInfo); err != nil { + term.Debugf("MarshalPretty error: %v", err) + } else { + term.Debug(string(b)) } } return resp, project, nil diff --git a/src/pkg/cli/generate.go b/src/pkg/cli/generate.go index 971e63be1..e632da22c 100644 --- a/src/pkg/cli/generate.go +++ b/src/pkg/cli/generate.go @@ -36,11 +36,9 @@ func GenerateWithAI(ctx context.Context, client client.FabricClient, args Genera return nil, err } - if term.DoDebug() { - // Print the files that were generated - for _, file := range response.Files { - term.Debugf("%s\n```\n%s\n```\n", file.Name, file.Content) - } + // file.Content can be large; skip string formatting when debug output won't be captured + for _, file := range response.Files { + term.Debugf("%s\n```\n%s\n```\n", file.Name, file.Content) } // Write each file to disk