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) }