detached da00894

fix(logging): add comprehensive UI event logging and prevent stdout leak to TUI

commit
da00894a7fd1fd32fa40a09cb4337e74c3120d19
author
bnema · · 2025-10-26 15:31 UTC
parent
c0e6952
signature
unsigned
3 files · +105 -10
Unified
UnifiedSplit
M cmd/archup-installer/main.go +2 -1
@@ -38,6 +38,7 @@ func main() {
3838 fmt.Fprintf(os.Stderr, "Failed to create logger: %v\n", err)
3939 os.Exit(1)
4040 }
41+ defer log.Close()
4142
4243 // Handle --cleanup flag
4344 if *doCleanup {
@@ -79,7 +80,7 @@ func main() {
7980 }
8081
8182 // Create UI model
82- model := ui.NewModel(orchestrator, cfg, version)
83+ model := ui.NewModel(orchestrator, cfg, log, version)
8384
8485 // Run Bubbletea app
8586 p := tea.NewProgram(model, tea.WithAltScreen())
@@ -38,6 +38,7 @@ func main() {
38 fmt.Fprintf(os.Stderr, "Failed to create logger: %v\n", err)38 fmt.Fprintf(os.Stderr, "Failed to create logger: %v\n", err)
39 os.Exit(1)39 os.Exit(1)
40 }40 }
41+ defer log.Close()
41 42
42 // Handle --cleanup flag43 // Handle --cleanup flag
43 if *doCleanup {44 if *doCleanup {
@@ -79,7 +80,7 @@ func main() {
79 }80 }
80 81
81 // Create UI model82 // Create UI model
82- model := ui.NewModel(orchestrator, cfg, version)83+ model := ui.NewModel(orchestrator, cfg, log, version)
83 84
84 // Run Bubbletea app85 // Run Bubbletea app
85 p := tea.NewProgram(model, tea.WithAltScreen())86 p := tea.NewProgram(model, tea.WithAltScreen())
M internal/logger/logger.go +56 -7
@@ -2,6 +2,7 @@ package logger
22
33 import (
44 "fmt"
5+ "io"
56 "log/slog"
67 "os"
78 "strings"
@@ -11,30 +12,70 @@ import (
1112
1213 // Logger wraps slog.Logger and adds dry-run mode support
1314 type Logger struct {
14- slog *slog.Logger
15- logPath string
16- dryRun bool
15+ slog *slog.Logger
16+ logPath string
17+ dryRun bool
18+ logFile *os.File
19+}
20+
21+// syncWriter wraps an io.Writer to sync after every write
22+type syncWriter struct {
23+ w interface {
24+ io.Writer
25+ Sync() error
26+ }
27+}
28+
29+func (sw *syncWriter) Write(p []byte) (n int, err error) {
30+ n, err = sw.w.Write(p)
31+ if err != nil {
32+ return n, err
33+ }
34+ // Sync to disk immediately to ensure logs are written even on crash
35+ if syncErr := sw.w.Sync(); syncErr != nil {
36+ // Log sync error but don't fail the write
37+ fmt.Fprintf(os.Stderr, "Warning: failed to sync log file: %v\n", syncErr)
38+ }
39+ return n, err
1740 }
1841
1942 // New creates a new Logger with optional file logging and dry-run mode
2043 func New(logPath string, dryRun bool) (*Logger, error) {
21- // Create slog handler
22- handler := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
44+ // Open log file for writing with sync flag for immediate writes
45+ logFile, err := os.OpenFile(logPath, os.O_CREATE|os.O_WRONLY|os.O_APPEND|os.O_SYNC, 0644)
46+ if err != nil {
47+ return nil, fmt.Errorf("failed to open log file: %w", err)
48+ }
49+
50+ // Wrap log file with sync writer to ensure immediate disk writes
51+ syncLogFile := &syncWriter{w: logFile}
52+
53+ // Only write to log file (not stdout) to avoid interfering with TUI
54+ // If you need stdout logging for debugging, add it back temporarily
55+ handler := slog.NewTextHandler(syncLogFile, &slog.HandlerOptions{
2356 Level: slog.LevelInfo,
2457 })
2558
26- return &Logger{
59+ logger := &Logger{
2760 slog: slog.New(handler),
2861 logPath: logPath,
62+ logFile: logFile,
2963 dryRun: dryRun,
30- }, nil
64+ }
65+
66+ // Write initial log entry to verify logging works
67+ logger.Info("Logger initialized", "log_path", logPath, "dry_run", dryRun)
68+
69+ return logger, nil
3170 }
3271
3372 // NewFromSlog creates a Logger from an existing slog.Logger
73+// Note: This does not create a log file - the provided slog.Logger should handle output
3474 func NewFromSlog(slogLogger *slog.Logger, logPath string, dryRun bool) *Logger {
3575 return &Logger{
3676 slog: slogLogger,
3777 logPath: logPath,
78+ logFile: nil, // No log file for this constructor
3879 dryRun: dryRun,
3980 }
4081 }
@@ -126,3 +167,11 @@ func (l *Logger) ExecWithConfig(cfg system.RunConfig) system.CommandResult {
126167 func (l *Logger) Slog() *slog.Logger {
127168 return l.slog
128169 }
170+
171+// Close closes the log file (call this when done)
172+func (l *Logger) Close() error {
173+ if l.logFile != nil {
174+ return l.logFile.Close()
175+ }
176+ return nil
177+}
@@ -2,6 +2,7 @@ package logger
2 2
3 import (3 import (
4 "fmt"4 "fmt"
5+ "io"
5 "log/slog"6 "log/slog"
6 "os"7 "os"
7 "strings"8 "strings"
@@ -11,30 +12,70 @@ import (
11 12
12 // Logger wraps slog.Logger and adds dry-run mode support13 // Logger wraps slog.Logger and adds dry-run mode support
13 type Logger struct {14 type Logger struct {
14- slog *slog.Logger15+ slog *slog.Logger
15- logPath string16+ logPath string
16- dryRun bool17+ dryRun bool
18+ logFile *os.File
19+}
20+
21+// syncWriter wraps an io.Writer to sync after every write
22+type syncWriter struct {
23+ w interface {
24+ io.Writer
25+ Sync() error
26+ }
27+}
28+
29+func (sw *syncWriter) Write(p []byte) (n int, err error) {
30+ n, err = sw.w.Write(p)
31+ if err != nil {
32+ return n, err
33+ }
34+ // Sync to disk immediately to ensure logs are written even on crash
35+ if syncErr := sw.w.Sync(); syncErr != nil {
36+ // Log sync error but don't fail the write
37+ fmt.Fprintf(os.Stderr, "Warning: failed to sync log file: %v\n", syncErr)
38+ }
39+ return n, err
17 }40 }
18 41
19 // New creates a new Logger with optional file logging and dry-run mode42 // New creates a new Logger with optional file logging and dry-run mode
20 func New(logPath string, dryRun bool) (*Logger, error) {43 func New(logPath string, dryRun bool) (*Logger, error) {
21- // Create slog handler44+ // Open log file for writing with sync flag for immediate writes
22- handler := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{45+ logFile, err := os.OpenFile(logPath, os.O_CREATE|os.O_WRONLY|os.O_APPEND|os.O_SYNC, 0644)
46+ if err != nil {
47+ return nil, fmt.Errorf("failed to open log file: %w", err)
48+ }
49+
50+ // Wrap log file with sync writer to ensure immediate disk writes
51+ syncLogFile := &syncWriter{w: logFile}
52+
53+ // Only write to log file (not stdout) to avoid interfering with TUI
54+ // If you need stdout logging for debugging, add it back temporarily
55+ handler := slog.NewTextHandler(syncLogFile, &slog.HandlerOptions{
23 Level: slog.LevelInfo,56 Level: slog.LevelInfo,
24 })57 })
25 58
26- return &Logger{59+ logger := &Logger{
27 slog: slog.New(handler),60 slog: slog.New(handler),
28 logPath: logPath,61 logPath: logPath,
62+ logFile: logFile,
29 dryRun: dryRun,63 dryRun: dryRun,
30- }, nil64+ }
65+
66+ // Write initial log entry to verify logging works
67+ logger.Info("Logger initialized", "log_path", logPath, "dry_run", dryRun)
68+
69+ return logger, nil
31 }70 }
32 71
33 // NewFromSlog creates a Logger from an existing slog.Logger72 // NewFromSlog creates a Logger from an existing slog.Logger
73+// Note: This does not create a log file - the provided slog.Logger should handle output
34 func NewFromSlog(slogLogger *slog.Logger, logPath string, dryRun bool) *Logger {74 func NewFromSlog(slogLogger *slog.Logger, logPath string, dryRun bool) *Logger {
35 return &Logger{75 return &Logger{
36 slog: slogLogger,76 slog: slogLogger,
37 logPath: logPath,77 logPath: logPath,
78+ logFile: nil, // No log file for this constructor
38 dryRun: dryRun,79 dryRun: dryRun,
39 }80 }
40 }81 }
@@ -126,3 +167,11 @@ func (l *Logger) ExecWithConfig(cfg system.RunConfig) system.CommandResult {
126 func (l *Logger) Slog() *slog.Logger {167 func (l *Logger) Slog() *slog.Logger {
127 return l.slog168 return l.slog
128 }169 }
170+
171+// Close closes the log file (call this when done)
172+func (l *Logger) Close() error {
173+ if l.logFile != nil {
174+ return l.logFile.Close()
175+ }
176+ return nil
177+}
M internal/ui/model.go +47 -2
@@ -4,6 +4,7 @@ import (
44 "fmt"
55
66 "github.com/bnema/archup/internal/config"
7+ "github.com/bnema/archup/internal/logger"
78 "github.com/bnema/archup/internal/phases"
89 "github.com/bnema/archup/internal/ui/components"
910 "github.com/bnema/archup/internal/ui/styles"
@@ -33,6 +34,7 @@ type Model struct {
3334 config *config.Config
3435 currentForm *huh.Form
3536 output *components.OutputViewer
37+ logger *logger.Logger
3638 version string
3739 width int
3840 height int
@@ -40,11 +42,13 @@ type Model struct {
4042 }
4143
4244 // NewModel creates a new installer model
43-func NewModel(orchestrator *phases.Orchestrator, cfg *config.Config, version string) *Model {
45+func NewModel(orchestrator *phases.Orchestrator, cfg *config.Config, log *logger.Logger, version string) *Model {
46+ log.Info("UI Model created", "version", version)
4447 return &Model{
4548 state: StateShowLogo,
4649 orchestrator: orchestrator,
4750 config: cfg,
51+ logger: log,
4852 version: version,
4953 width: 80,
5054 height: 24,
@@ -66,23 +70,51 @@ func (m *Model) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
6670 m.output.SetSize(msg.Width, msg.Height-10)
6771
6872 case tea.KeyMsg:
73+ m.logger.Info("Key pressed", "key", msg.String(), "state", m.state)
74+
6975 switch msg.String() {
7076 case "ctrl+c":
77+ m.logger.Info("User cancelled installation")
7178 return m, tea.Quit
7279
7380 case "enter":
7481 switch m.state {
7582 case StateShowLogo:
76- // Move to preflight form
83+ m.logger.Info("Moving to preflight form")
84+ m.state = StatePreflightForm
85+ m.currentForm = CreatePreflightForm(m.config)
86+ return m, m.currentForm.Init()
87+
88+ case StateConfirmation:
89+ m.logger.Info("User confirmed installation - starting execution")
90+ m.state = StateExecuting
91+ return m, m.executeNextPhase()
92+ }
93+
94+ case "backspace", "esc":
95+ m.logger.Info("User navigating back", "from_state", m.state)
96+ switch m.state {
97+ case StateDiskForm:
7798 m.state = StatePreflightForm
7899 m.currentForm = CreatePreflightForm(m.config)
79100 return m, m.currentForm.Init()
101+
102+ case StateOptionsForm:
103+ m.state = StateDiskForm
104+ m.currentForm = CreateDiskSelectionForm(m.config)
105+ return m, m.currentForm.Init()
106+
107+ case StateConfirmation:
108+ m.state = StateOptionsForm
109+ m.currentForm = CreateOptionsForm(m.config)
110+ return m, m.currentForm.Init()
80111 }
81112 }
82113
83114 case phaseCompleteMsg:
84115 switch {
85116 case msg.err != nil:
117+ m.logger.Error("Phase execution failed", "error", msg.err)
86118 m.err = msg.err
87119 m.state = StateError
88120 return m, tea.Quit
@@ -91,9 +123,11 @@ func (m *Model) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
91123 // Check if all phases complete
92124 switch {
93125 case m.orchestrator.IsComplete():
126+ m.logger.Info("All phases completed successfully")
94127 m.state = StateComplete
95128 return m, tea.Quit
96129 default:
130+ m.logger.Info("Continuing to next phase")
97131 // Continue with next phase
98132 return m, m.executeNextPhase()
99133 }
@@ -179,8 +213,15 @@ func (m *Model) View() string {
179213
180214 // handleFormComplete handles form completion and moves to next state
181215 func (m *Model) handleFormComplete() tea.Cmd {
216+ m.logger.Info("Form completed", "state", m.state)
217+
182218 switch m.state {
183219 case StatePreflightForm:
220+ m.logger.Info("Preflight form completed",
221+ "hostname", m.config.Hostname,
222+ "username", m.config.Username,
223+ "use_same_password_for_encryption", m.config.UseSamePasswordForEncryption)
224+
184225 // Handle encryption password setting based on checkbox
185226 switch {
186227 case m.config.UseSamePasswordForEncryption:
@@ -192,11 +233,15 @@ func (m *Model) handleFormComplete() tea.Cmd {
192233 return m.currentForm.Init()
193234
194235 case StateDiskForm:
236+ m.logger.Info("Disk selection completed", "disk", m.config.TargetDisk)
195237 m.state = StateOptionsForm
196238 m.currentForm = CreateOptionsForm(m.config)
197239 return m.currentForm.Init()
198240
199241 case StateOptionsForm:
242+ m.logger.Info("Options form completed",
243+ "kernel", m.config.KernelChoice,
244+ "encryption", m.config.EncryptionType)
200245 // Move directly to confirmation
201246 // Encryption password is already handled in preflight form
202247 m.state = StateConfirmation
@@ -4,6 +4,7 @@ import (
4 "fmt"4 "fmt"
5 5
6 "github.com/bnema/archup/internal/config"6 "github.com/bnema/archup/internal/config"
7+ "github.com/bnema/archup/internal/logger"
7 "github.com/bnema/archup/internal/phases"8 "github.com/bnema/archup/internal/phases"
8 "github.com/bnema/archup/internal/ui/components"9 "github.com/bnema/archup/internal/ui/components"
9 "github.com/bnema/archup/internal/ui/styles"10 "github.com/bnema/archup/internal/ui/styles"
@@ -33,6 +34,7 @@ type Model struct {
33 config *config.Config34 config *config.Config
34 currentForm *huh.Form35 currentForm *huh.Form
35 output *components.OutputViewer36 output *components.OutputViewer
37+ logger *logger.Logger
36 version string38 version string
37 width int39 width int
38 height int40 height int
@@ -40,11 +42,13 @@ type Model struct {
40 }42 }
41 43
42 // NewModel creates a new installer model44 // NewModel creates a new installer model
43-func NewModel(orchestrator *phases.Orchestrator, cfg *config.Config, version string) *Model {45+func NewModel(orchestrator *phases.Orchestrator, cfg *config.Config, log *logger.Logger, version string) *Model {
46+ log.Info("UI Model created", "version", version)
44 return &Model{47 return &Model{
45 state: StateShowLogo,48 state: StateShowLogo,
46 orchestrator: orchestrator,49 orchestrator: orchestrator,
47 config: cfg,50 config: cfg,
51+ logger: log,
48 version: version,52 version: version,
49 width: 80,53 width: 80,
50 height: 24,54 height: 24,
@@ -66,23 +70,51 @@ func (m *Model) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
66 m.output.SetSize(msg.Width, msg.Height-10)70 m.output.SetSize(msg.Width, msg.Height-10)
67 71
68 case tea.KeyMsg:72 case tea.KeyMsg:
73+ m.logger.Info("Key pressed", "key", msg.String(), "state", m.state)
74+
69 switch msg.String() {75 switch msg.String() {
70 case "ctrl+c":76 case "ctrl+c":
77+ m.logger.Info("User cancelled installation")
71 return m, tea.Quit78 return m, tea.Quit
72 79
73 case "enter":80 case "enter":
74 switch m.state {81 switch m.state {
75 case StateShowLogo:82 case StateShowLogo:
76- // Move to preflight form83+ m.logger.Info("Moving to preflight form")
84+ m.state = StatePreflightForm
85+ m.currentForm = CreatePreflightForm(m.config)
86+ return m, m.currentForm.Init()
87+
88+ case StateConfirmation:
89+ m.logger.Info("User confirmed installation - starting execution")
90+ m.state = StateExecuting
91+ return m, m.executeNextPhase()
92+ }
93+
94+ case "backspace", "esc":
95+ m.logger.Info("User navigating back", "from_state", m.state)
96+ switch m.state {
97+ case StateDiskForm:
77 m.state = StatePreflightForm98 m.state = StatePreflightForm
78 m.currentForm = CreatePreflightForm(m.config)99 m.currentForm = CreatePreflightForm(m.config)
79 return m, m.currentForm.Init()100 return m, m.currentForm.Init()
101+
102+ case StateOptionsForm:
103+ m.state = StateDiskForm
104+ m.currentForm = CreateDiskSelectionForm(m.config)
105+ return m, m.currentForm.Init()
106+
107+ case StateConfirmation:
108+ m.state = StateOptionsForm
109+ m.currentForm = CreateOptionsForm(m.config)
110+ return m, m.currentForm.Init()
80 }111 }
81 }112 }
82 113
83 case phaseCompleteMsg:114 case phaseCompleteMsg:
84 switch {115 switch {
85 case msg.err != nil:116 case msg.err != nil:
117+ m.logger.Error("Phase execution failed", "error", msg.err)
86 m.err = msg.err118 m.err = msg.err
87 m.state = StateError119 m.state = StateError
88 return m, tea.Quit120 return m, tea.Quit
@@ -91,9 +123,11 @@ func (m *Model) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
91 // Check if all phases complete123 // Check if all phases complete
92 switch {124 switch {
93 case m.orchestrator.IsComplete():125 case m.orchestrator.IsComplete():
126+ m.logger.Info("All phases completed successfully")
94 m.state = StateComplete127 m.state = StateComplete
95 return m, tea.Quit128 return m, tea.Quit
96 default:129 default:
130+ m.logger.Info("Continuing to next phase")
97 // Continue with next phase131 // Continue with next phase
98 return m, m.executeNextPhase()132 return m, m.executeNextPhase()
99 }133 }
@@ -179,8 +213,15 @@ func (m *Model) View() string {
179 213
180 // handleFormComplete handles form completion and moves to next state214 // handleFormComplete handles form completion and moves to next state
181 func (m *Model) handleFormComplete() tea.Cmd {215 func (m *Model) handleFormComplete() tea.Cmd {
216+ m.logger.Info("Form completed", "state", m.state)
217+
182 switch m.state {218 switch m.state {
183 case StatePreflightForm:219 case StatePreflightForm:
220+ m.logger.Info("Preflight form completed",
221+ "hostname", m.config.Hostname,
222+ "username", m.config.Username,
223+ "use_same_password_for_encryption", m.config.UseSamePasswordForEncryption)
224+
184 // Handle encryption password setting based on checkbox225 // Handle encryption password setting based on checkbox
185 switch {226 switch {
186 case m.config.UseSamePasswordForEncryption:227 case m.config.UseSamePasswordForEncryption:
@@ -192,11 +233,15 @@ func (m *Model) handleFormComplete() tea.Cmd {
192 return m.currentForm.Init()233 return m.currentForm.Init()
193 234
194 case StateDiskForm:235 case StateDiskForm:
236+ m.logger.Info("Disk selection completed", "disk", m.config.TargetDisk)
195 m.state = StateOptionsForm237 m.state = StateOptionsForm
196 m.currentForm = CreateOptionsForm(m.config)238 m.currentForm = CreateOptionsForm(m.config)
197 return m.currentForm.Init()239 return m.currentForm.Init()
198 240
199 case StateOptionsForm:241 case StateOptionsForm:
242+ m.logger.Info("Options form completed",
243+ "kernel", m.config.KernelChoice,
244+ "encryption", m.config.EncryptionType)
200 // Move directly to confirmation245 // Move directly to confirmation
201 // Encryption password is already handled in preflight form246 // Encryption password is already handled in preflight form
202 m.state = StateConfirmation247 m.state = StateConfirmation

Keyboard shortcuts

Single-key shortcuts are on. ctrl k and esc work whatever this says.

ctrl k :
go to a section, branch, tag, file or repository
?
this list
j k
move the row cursor down / up
enter
open the row under the cursor; on Files, a directory opens or closes in place
↑ ↓ ← → home end
in the file tree (focus on a row): previous / next row, close / open a directory or go to its parent / first entry, first / last row. They never open a file
l h
on Files: open a directory or a file / close a directory or go up to its parent, then to the parent page. Elsewhere: into the side panel (on a merge request, its files) / back to the content; there j k move between its controls
g g G
first / last row
/
filter the list; on Files, find a file anywhere in the repository (esc clears, enter opens the best match)
b
switch branch or tag
g s g f g c g b g m g i g r g a
tabs: summary, files, commits, branches & tags, merge requests, issues, releases, actions (when available)
g h
home
w
wide mode: use the whole width of the screen, or not (remembered)
y
copy a permalink pinned to the commit
d u x
diff: split / unified / collapse or expand all
e E
diff: the whole file in view / every file, with the lines the hunks hide
n
merge request: next note in the diff
esc
close a dialog, leave a field

Branches 1

Tags 0

    ↑↓ moveenter openesc close