fix(bonfire): keep the order of lines printed above a live view and drain them before it ends

- each PrintAbove block is one bubbletea print message sent straight to
  the program's queue under liveMu, so the event loop prints it in call
  order instead of a command goroutine racing it back
- runLive unregisters, sends finishMsg and waits under liveMu, so a late
  printer writes after the final frame and no line is lost
- TestPrintAboveOrderedNoLoss pins order and no loss for spinner,
  progress, process and a printer racing the finish (CR-01)

modules/bonfire/live.go

@@ -46,10 +46,18 @@ type (
 	}
 	// finishMsg ends a live view; err is the result of the work.
 	finishMsg struct{ err error }
-	// printAboveMsg is a line to print above the view.
-	printAboveMsg string
 )
 
+// printLine is the message that prints s, one or more lines, above the
+// running view. It is bubbletea's own Println message, sent straight to
+// the program's queue: the event loop prints it itself, in the order the
+// messages arrive. Returning tea.Println as a command instead would run
+// it on a goroutine of its own, so lines would race each other and a line
+// still in flight when the view quits would be lost.
+func printLine(s string) tea.Msg {
+	return tea.Println(s)()
+}
+
 // itemState is the display state of one item in the process view.
 type itemState int
 
@@ -306,24 +314,6 @@ func (m processModel) View() tea.View {
 	return tea.NewView(b.String())
 }
 
-// liveModel wraps a view so lines from PrintAbove print above it.
-type liveModel struct {
-	inner tea.Model
-}
-
-func (m liveModel) Init() tea.Cmd { return m.inner.Init() }
-
-func (m liveModel) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
-	if line, ok := msg.(printAboveMsg); ok {
-		return m, tea.Println(string(line))
-	}
-	inner, cmd := m.inner.Update(msg)
-	m.inner = inner
-	return m, cmd
-}
-
-func (m liveModel) View() tea.View { return m.inner.View() }
-
 // The running live program, for PrintAbove. Only one live view runs at a
 // time; widgets started while one runs print plain lines.
 var (
@@ -341,12 +331,13 @@ func liveActive() bool {
 // runLive runs model as a bubbletea program on out while work runs on the
 // calling goroutine. work gets a send function for progress messages. When
 // work returns, the program is unregistered (so PrintAbove stops sending to
-// it), told to finish and waited for; it never receives lines after that.
+// it), told to finish and waited for, all under liveMu; it never receives
+// lines after that.
 func runLive(ctx context.Context, out io.Writer, c *console, model tea.Model, work func(send func(tea.Msg)) error) error {
 	if ctx == nil {
 		ctx = context.Background()
 	}
-	prog := tea.NewProgram(liveModel{inner: model},
+	prog := tea.NewProgram(model,
 		tea.WithInput(nil),
 		tea.WithOutput(out),
 		tea.WithoutSignalHandler(),
@@ -364,11 +355,14 @@ func runLive(ctx context.Context, out io.Writer, c *console, model tea.Model, wo
 
 	err := work(prog.Send)
 
+	// Unregister, finish and wait as one step: a printer that arrives
+	// meanwhile waits for the lock and then writes after the final frame,
+	// so no line reaches a stopped program or races the last frame.
 	liveMu.Lock()
 	activeProg = nil
-	liveMu.Unlock()
 	prog.Send(finishMsg{err: err})
 	<-finished
+	liveMu.Unlock()
 	return err
 }
 
@@ -380,8 +374,8 @@ func printAboveLines(s string) bool {
 	if activeProg == nil {
 		return false
 	}
-	for _, line := range strings.Split(strings.TrimSuffix(s, "\n"), "\n") {
-		activeProg.Send(printAboveMsg(line))
-	}
+	// One message for the whole block, sent while holding liveMu: blocks
+	// from different goroutines keep the order of their calls.
+	activeProg.Send(printLine(strings.TrimSuffix(s, "\n")))
 	return true
 }

modules/bonfire/live_test.go

@@ -2,9 +2,13 @@ package bonfire
 
 import (
 	"bytes"
+	"context"
 	"errors"
 	"fmt"
+	"io"
+	"regexp"
 	"strings"
+	"sync"
 	"testing"
 	"time"
 
@@ -206,21 +210,20 @@ func TestLiveModels(t *testing.T) {
 	})
 
 	t.Run("print above", func(t *testing.T) {
-		var m tea.Model = liveModel{inner: newSpinnerModel(p, "x")}
-		before := frame(m)
-		m, cmd := m.Update(printAboveMsg("a log line"))
-		if cmd == nil || frame(m) != before {
-			t.Error("printAboveMsg did not become a Println command or reached the inner model")
+		// A printed block is one message for the program's queue, not a
+		// command bubbletea would run on a goroutine of its own.
+		msg := printLine("first\nsecond")
+		if msg == nil {
+			t.Fatal("printLine returned no message")
 		}
-		m, _ = m.Update(itemMsg{done: 1, total: 2})
-		if !strings.Contains(frame(m), "1/2") {
-			t.Errorf("other messages do not reach the inner model: %q", frame(m))
+		if _, isCmd := msg.(tea.Cmd); isCmd {
+			t.Error("printLine returned a command")
 		}
 	})
 
 	t.Run("program end to end", func(t *testing.T) {
 		var buf bytes.Buffer
-		prog := tea.NewProgram(liveModel{inner: newSpinnerModel(p, "Importing posts")},
+		prog := tea.NewProgram(newSpinnerModel(p, "Importing posts"),
 			tea.WithInput(nil),
 			tea.WithOutput(&buf),
 			tea.WithoutSignalHandler(),
@@ -233,7 +236,7 @@ func TestLiveModels(t *testing.T) {
 			done <- err
 		}()
 		prog.Send(itemMsg{done: 1, total: 2, item: "first"})
-		prog.Send(printAboveMsg("imported first"))
+		prog.Send(printLine("imported first"))
 		prog.Send(itemMsg{done: 2, total: 2, item: "second"})
 		prog.Send(finishMsg{})
 		select {
@@ -253,3 +256,174 @@ func TestLiveModels(t *testing.T) {
 		}
 	})
 }
+
+// lockedBuffer is a bytes.Buffer safe for a live program and other
+// goroutines writing at the same time.
+type lockedBuffer struct {
+	mu  sync.Mutex
+	buf bytes.Buffer
+}
+
+func (b *lockedBuffer) Write(p []byte) (int, error) {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+	return b.buf.Write(p)
+}
+
+func (b *lockedBuffer) String() string {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+	return b.buf.String()
+}
+
+var numberedLine = regexp.MustCompile(`(line|bg)-\d{3}`)
+
+// numbered returns the numbered lines of the ANSI-stripped output in the
+// order they appear.
+func numbered(out string) []string {
+	return numberedLine.FindAllString(ansi.Strip(out), -1)
+}
+
+// printNumbered prints line-<from> .. line-<to-1> through the console's
+// print paths in turn: Println, Printf, Info and bonfire.PrintAbove.
+func printNumbered(c *console, from, to int) {
+	for i := from; i < to; i++ {
+		line := fmt.Sprintf("line-%03d", i)
+		switch i % 4 {
+		case 0:
+			c.Println(line)
+		case 1:
+			c.Printf("%s\n", line)
+		case 2:
+			c.Info(line)
+		case 3:
+			if !PrintAbove(line) {
+				c.Println(line)
+			}
+		}
+	}
+}
+
+// checkNumbered fails unless out holds line-000 .. line-<n-1> exactly once
+// and in order.
+func checkNumbered(t *testing.T, run int, out string, n int) {
+	t.Helper()
+	got := numbered(out)
+	for i := 0; i < n; i++ {
+		want := fmt.Sprintf("line-%03d", i)
+		if i >= len(got) {
+			t.Fatalf("run %d: %d of %d lines printed, %s missing:\n%s", run, len(got), n, want, ansi.Strip(out))
+		}
+		if got[i] != want {
+			t.Fatalf("run %d: line %d is %s, want %s (lines: %v)", run, i, got[i], want, got)
+		}
+	}
+	if len(got) != n {
+		t.Fatalf("run %d: %d lines printed, want %d: %v", run, len(got), n, got)
+	}
+}
+
+// TestPrintAboveOrderedNoLoss (CR-01): every line printed while a spinner,
+// progress or process view runs appears once and in order; a line printed
+// from another goroutine while the view finishes is not lost.
+func TestPrintAboveOrderedNoLoss(t *testing.T) {
+	const runs, lines = 20, 100
+	newTTY := func(out io.Writer) *console {
+		return newConsole(strings.NewReader(""), out, io.Discard, noEnv, boolPtr(true), boolPtr(true))
+	}
+
+	t.Run("spinner", func(t *testing.T) {
+		for run := range runs {
+			out := &lockedBuffer{}
+			c := newTTY(out)
+			if err := c.Spinner("working", func() error {
+				printNumbered(c, 0, lines)
+				return nil
+			}); err != nil {
+				t.Fatal(err)
+			}
+			checkNumbered(t, run, out.String(), lines)
+		}
+	})
+
+	t.Run("progress", func(t *testing.T) {
+		for run := range runs {
+			out := &lockedBuffer{}
+			c := newTTY(out)
+			if err := c.Progress(lines, func(p Progress) error {
+				printNumbered(c, 0, 40)
+				Failed(p, "item-a", errors.New("first failure"))
+				printNumbered(c, 40, 80)
+				Failed(p, "item-b", errors.New("second failure"))
+				printNumbered(c, 80, lines)
+				return nil
+			}); err != nil {
+				t.Fatal(err)
+			}
+			got := out.String()
+			checkNumbered(t, run, got, lines)
+			for _, want := range []string{"item-a: first failure", "item-b: second failure"} {
+				if !strings.Contains(ansi.Strip(got), want) {
+					t.Fatalf("run %d: failure line %q missing:\n%s", run, want, ansi.Strip(got))
+				}
+			}
+		}
+	})
+
+	t.Run("process", func(t *testing.T) {
+		items := []string{"a", "b", "c", "d"}
+		for run := range runs {
+			out := &lockedBuffer{}
+			c := newTTY(out)
+			next := 0
+			err := Process(context.Background(), c, "Pushing", items, func(context.Context, string) error {
+				printNumbered(c, next, next+lines/len(items))
+				next += lines / len(items)
+				return nil
+			})
+			if err != nil {
+				t.Fatal(err)
+			}
+			checkNumbered(t, run, out.String(), lines)
+		}
+	})
+
+	t.Run("concurrent_finish", func(t *testing.T) {
+		const bg = 200
+		for run := range runs {
+			out := &lockedBuffer{}
+			c := newTTY(out)
+			started := make(chan struct{})
+			done := make(chan struct{})
+			if err := c.Spinner("working", func() error {
+				go func() {
+					defer close(done)
+					for i := range bg {
+						line := fmt.Sprintf("bg-%03d", i)
+						if !PrintAbove(line) {
+							_, _ = io.WriteString(out, line+"\n")
+						}
+						if i == 5 {
+							close(started)
+						}
+					}
+				}()
+				<-started
+				return nil
+			}); err != nil {
+				t.Fatal(err)
+			}
+			<-done
+			count := map[string]int{}
+			for _, l := range numbered(out.String()) {
+				count[l]++
+			}
+			for i := range bg {
+				l := fmt.Sprintf("bg-%03d", i)
+				if count[l] != 1 {
+					t.Fatalf("run %d: %s printed %d times:\n%s", run, l, count[l], ansi.Strip(out.String()))
+				}
+			}
+		}
+	})
+}

modules/bonfire/widgets.go

@@ -129,7 +129,7 @@ func (p *liveProgress) Current(item string) {
 
 func (p *liveProgress) Fail(item string, err error) {
 	p.send(itemMsg{done: p.current, total: p.total, item: item, err: err})
-	p.send(printAboveMsg(failureLine(item, err)))
+	p.send(printLine(failureLine(item, err)))
 }
 
 func failureLine(item string, err error) string {