From 0b979caade1ae5310439d52445e4e1f1852edb9c Mon Sep 17 00:00:00 2001 From: Kieran Klukas Date: Sat, 8 Aug 2026 21:56:01 -0400 Subject: [PATCH] bore: say trouble in bore's own voice httputil's proxy logged straight to stderr with its own timestamp, drawing over whatever the view was showing. Its errors now take the same shape as every other line. Notices carry severity: yellow for a bad moment, red for a broken tunnel. A warning holds until a request answers it, so a quiet tunnel still says why the last try failed. --- packages/bore/frpc.go | 26 +++++++++++++++----------- packages/bore/inspect.go | 28 +++++++++++++++++++++++++++- packages/bore/inspect_test.go | 18 ++++++++++++++++-- packages/bore/tui.go | 29 +++++++++++++++++++++-------- packages/bore/tunnel.go | 8 ++++---- packages/bore/ui.go | 32 ++++++++++++++++++++++++++++++++ 6 files changed, 115 insertions(+), 26 deletions(-) diff --git a/packages/bore/frpc.go b/packages/bore/frpc.go index c4ff48b..b755c93 100644 --- a/packages/bore/frpc.go +++ b/packages/bore/frpc.go @@ -185,7 +185,7 @@ var frpcLine = regexp.MustCompile(`^\S+ \S+ \[([IWED])\] \[[^\]]+\] (.*)$`) // run starts frpc and reports what happens in bore's own words. Verbose mode // passes frpc's output through untouched, for when the translation is hiding // the thing you need. -func run(ctx context.Context, t *Tunnel, configPath string, adminPort int, verbose bool, note func(label, text string)) error { +func run(ctx context.Context, t *Tunnel, configPath string, adminPort int, verbose bool, note func(notice)) error { cmd := exec.CommandContext(ctx, frpcBin, "-c", configPath) cmd.Stdin = os.Stdin @@ -218,7 +218,7 @@ func stoppedBySignal(exit *exec.ExitError) bool { return ok && status.Signaled() } -func narrate(out io.Reader, t *Tunnel, adminPort int, verbose bool, note func(label, text string)) { +func narrate(out io.Reader, t *Tunnel, adminPort int, verbose bool, note func(notice)) { scanner := bufio.NewScanner(out) var lastProblem string @@ -246,11 +246,11 @@ func narrate(out io.Reader, t *Tunnel, adminPort int, verbose bool, note func(la continue // the header already says where it is } if addr, err := remoteAddr(adminPort, t); err == nil { - note("remote", addr) + note(notice{label: "remote", text: addr}) } case level == "E" || level == "W": - label, message := translate(message, t) + label, message, fatal := translate(message, t) // frpc retries a failing connection every second or so; saying it // once is informative, saying it forty times is noise. if message == lastProblem { @@ -258,27 +258,31 @@ func narrate(out io.Reader, t *Tunnel, adminPort int, verbose bool, note func(la continue } if repeats > 0 { - note("", dim(fmt.Sprintf("(repeated %d times)", repeats))) + note(notice{label: "", text: dim(fmt.Sprintf("(repeated %d times)", repeats))}) } lastProblem, repeats = message, 0 - note(label, message) + note(notice{label: label, text: message, fatal: fatal}) } } if repeats > 0 { - note("", dim(fmt.Sprintf("(repeated %d times)", repeats))) + note(notice{label: "", text: dim(fmt.Sprintf("(repeated %d times)", repeats))}) } } // translate puts frpc's most common complaints in terms of what the user did, // rather than what frpc was doing at the time. -func translate(message string, t *Tunnel) (label, text string) { +// translate puts frpc's most common complaints in terms of what the user did, +// and says which of them mean the tunnel is not working. +func translate(message string, t *Tunnel) (label, text string, fatal bool) { switch { case strings.Contains(message, "connect to local service") && strings.Contains(message, "connection refused"): - return "local", fmt.Sprintf("nothing is listening on localhost:%d", t.Port) + // The tunnel is fine; there is just nothing on the other end yet. + return "local", fmt.Sprintf("nothing is listening on localhost:%d", t.Port), false case strings.Contains(message, "login to server failed"), strings.Contains(message, "connect to server error"): - return "server", strings.TrimPrefix(message, "login to server failed: ") + // Nothing is getting through at all. + return "server", strings.TrimPrefix(message, "login to server failed: "), true } - return "frpc", message + return "frpc", message, true } // stripIDs removes the run id and proxy name frpc prefixes to every message. diff --git a/packages/bore/inspect.go b/packages/bore/inspect.go index a19dd0a..aed8d6e 100644 --- a/packages/bore/inspect.go +++ b/packages/bore/inspect.go @@ -2,6 +2,7 @@ package main import ( "fmt" + "log" "net" "net/http" "net/http/httputil" @@ -26,6 +27,30 @@ type inspector struct { sink func(request) } +// proxyLog turns ReverseProxy's internal logging into one of our own lines. +// +// It logs through the standard logger by default, which writes to stderr with +// a timestamp, in nobody's style, straight through whatever we are drawing. +type proxyLog struct { + note func(notice) +} + +func (l proxyLog) Write(p []byte) (int, error) { + message := strings.TrimSpace(string(p)) + message = strings.TrimPrefix(message, "httputil: ReverseProxy ") + + // The common one by far: a dev server restarting, or a visitor navigating + // away from a page whose response was still arriving. + if strings.Contains(message, "unexpected EOF") || strings.Contains(message, "body copy") { + // A dev server restarting or a visitor navigating away. It says its + // piece and fades. + l.note(notice{label: "local", text: "the response ended early"}) + return len(p), nil + } + l.note(notice{label: "local", text: message}) + return len(p), nil +} + // request is one exchange through the tunnel. type request struct { at time.Time @@ -48,7 +73,7 @@ func (r request) render() string { ) } -func startInspector(target int, sink func(request)) (*inspector, error) { +func startInspector(target int, sink func(request), note func(notice)) (*inspector, error) { listener, err := net.Listen("tcp", "127.0.0.1:0") if err != nil { return nil, err @@ -67,6 +92,7 @@ func startInspector(target int, sink func(request)) (*inspector, error) { transport.MaxIdleConnsPerHost = 64 transport.IdleConnTimeout = 90 * time.Second proxy.Transport = transport + proxy.ErrorLog = log.New(proxyLog{note}, "", 0) // Stream responses through as they arrive rather than buffering, so server // sent events and long polling behave the way they would without us. proxy.FlushInterval = -1 diff --git a/packages/bore/inspect_test.go b/packages/bore/inspect_test.go index 1f48866..e9ddfc4 100644 --- a/packages/bore/inspect_test.go +++ b/packages/bore/inspect_test.go @@ -33,7 +33,7 @@ func TestInspectorForwards(t *testing.T) { if err != nil { t.Fatal(err) } - in, err := startInspector(target, func(request) {}) + in, err := startInspector(target, func(request) {}, func(notice) {}) if err != nil { t.Fatal(err) } @@ -66,7 +66,7 @@ func TestInspectorForwards(t *testing.T) { } // A dead upstream becomes a 502 rather than a hang. - dead, err := startInspector(19999, func(request) {}) + dead, err := startInspector(19999, func(request) {}, func(notice) {}) if err != nil { t.Fatal(err) } @@ -78,3 +78,17 @@ func TestInspectorForwards(t *testing.T) { t.Errorf("unreachable upstream: got %d, want 502", resp.StatusCode) } } + +// A warning holds until a request answers it; an error holds regardless. +func TestNoticesGoStaleOnlyOnceARequestFollows(t *testing.T) { + warned := notice{after: 3} + if warned.stale(3) { + t.Error("a warning should hold while the tunnel is quiet") + } + if !warned.stale(4) { + t.Error("a request after the warning should retire it") + } + if (notice{after: 3, fatal: true}).stale(99) { + t.Error("a fatal notice should stay until it is superseded") + } +} diff --git a/packages/bore/tui.go b/packages/bore/tui.go index 614beab..5fe3345 100644 --- a/packages/bore/tui.go +++ b/packages/bore/tui.go @@ -2,6 +2,7 @@ package main import ( "fmt" + "slices" "strings" "time" @@ -18,7 +19,7 @@ import ( // was in the terminal before is still there. type tunnelUI struct { header []headerRow - notes []string + notes []notice count int bytes int64 started time.Time @@ -32,7 +33,7 @@ type headerRow struct { type ( requestMsg request - noteMsg struct{ label, text string } + noticeMsg notice doneMsg struct{ err error } ) @@ -53,10 +54,18 @@ func (m tunnelUI) Update(msg tea.Msg) (tea.Model, tea.Cmd) { // Printed rather than stored: the terminal keeps the history. return m, tea.Println(request(msg).render()) - case noteMsg: - m.notes = append(m.notes, failStyle.Render(msg.label)+" "+msg.text) - if len(m.notes) > 2 { - m.notes = m.notes[len(m.notes)-2:] + case noticeMsg: + n := notice(msg) + n.after = m.count + // Drop what this one supersedes: anything about the same subject, and + // anything a request has already answered for. A dev server restarting + // twice should not push the tunnel's details off the screen. + m.notes = slices.DeleteFunc(m.notes, func(o notice) bool { + return o.label == n.label || o.stale(m.count) + }) + m.notes = append(m.notes, n) + if len(m.notes) > 3 { + m.notes = m.notes[len(m.notes)-3:] } case doneMsg: @@ -88,8 +97,12 @@ func (m tunnelUI) status() string { gap := strings.Repeat(" ", width-lipgloss.Width(row.label)) out.WriteString(labelStyle.Render(row.label) + gap + " " + row.value + "\n") } - for _, note := range m.notes { - out.WriteString(note + "\n") + for _, n := range m.notes { + if n.stale(m.count) { + continue + } + gap := strings.Repeat(" ", max(width-lipgloss.Width(n.label), 0)) + out.WriteString(n.style().Render(n.label) + gap + " " + n.text + "\n") } summary := "waiting for requests" diff --git a/packages/bore/tunnel.go b/packages/bore/tunnel.go index 4a0f43e..1bee36e 100644 --- a/packages/bore/tunnel.go +++ b/packages/bore/tunnel.go @@ -242,6 +242,7 @@ func start(root context.Context, t *Tunnel, opts tunnelOptions) error { } rows := headerRows(t, opts) + sec := newSection("protocol", "public", "local", "labels", "auth", "saved") // Under the full screen view, requests and notes become messages. Plain // mode prints them as they happen. @@ -249,18 +250,18 @@ func start(root context.Context, t *Tunnel, opts tunnelOptions) error { var program *tea.Program onRequest := func(r request) { lipgloss.Println(r.render()) } - onNote := func(label, text string) { newSection("status").warn(label, text) } + onNote := sec.notice if live { program = tea.NewProgram(tunnelUI{header: rows, started: time.Now()}) onRequest = func(r request) { program.Send(requestMsg(r)) } - onNote = func(label, text string) { program.Send(noteMsg{label, text}) } + onNote = func(n notice) { program.Send(noticeMsg(n)) } } // For http, frpc is pointed at the inspector rather than at the service, // so every request passes through something that can name it. localPort := t.Port if t.protocolOrDefault() == "http" && !opts.noInspect { - in, err := startInspector(t.Port, onRequest) + in, err := startInspector(t.Port, onRequest, onNote) if err != nil { return err } @@ -280,7 +281,6 @@ func start(root context.Context, t *Tunnel, opts tunnelOptions) error { defer stop() if !live { - sec := newSection("protocol", "public", "local", "labels", "auth", "saved") for _, row := range rows { sec.row(row.label, row.value) } diff --git a/packages/bore/ui.go b/packages/bore/ui.go index e555917..b4e41a6 100644 --- a/packages/bore/ui.go +++ b/packages/bore/ui.go @@ -29,6 +29,38 @@ func newSection(labels ...string) *section { return s } +// A notice is something that happened to the tunnel rather than through it. +// +// Warnings are moments: a response cut short, a dial that failed. Errors are +// states: the tunnel is not working, and saying so once and vanishing would be +// worse than useless. +type notice struct { + label string + text string + fatal bool + // after is how many requests had been served when this happened. A warning + // is the latest news until a request goes through, which is both the proof + // that it has passed and the only clock that means anything here: a tunnel + // nobody is using should still say why the last try failed. + after int +} + +// stale reports whether a request has arrived since, making this old news. +func (n notice) stale(requests int) bool { return !n.fatal && requests > n.after } + +// style is red when the tunnel is broken and yellow when it is merely a bad +// moment, matching what fail and warn mean in a section. +func (n notice) style() lipgloss.Style { + if n.fatal { + return failStyle + } + return warnStyle +} + +// notice prints one in this section's column, so it lines up with the tunnel's +// details rather than starting wherever its label happens to end. +func (s *section) notice(n notice) { s.line(n.style(), n.label, n.text) } + func (s *section) row(label, value string) { s.line(labelStyle, label, value) } func (s *section) fail(label, value string) { s.line(failStyle, label, value) } func (s *section) warn(label, value string) { s.line(warnStyle, label, value) } -- 2.51.2