perf: add m5 instrumentation pass

commit: 5e9d5796e8939790b843b1daa5e0bf3c7bb99c21
author: brice · 3mo ago · 2026-07-02 16:16 UTC
parent: fb67a13
signature: GPG VerifiedCD88F9E564E0102646FB6077A1A07C7C7C3E349D · arch-gpg Verified for the committer email

6 files · +163 -9

A docs/performance.md +19 -0

@@ -0,0 +1,19 @@
	1	+	# Performance methodology (M5)
	2	+
	3	+	Enable daemon pprof explicitly with `VEV_PPROF_ADDR=127.0.0.1:6060 vev --daemon` (or by exporting the variable before launching clients). When unset, no debug HTTP server is started.
	4	+
	5	+	Run microbenchmarks with:
	6	+
	7	+	```sh
	8	+	go test ./pkg/renderer ./pkg/vt ./internal/adapters/ipc -bench=. -benchmem
	9	+	```
	10	+
	11	+	Demo flood workloads are scripted in `scripts/bench-workloads.sh` for `yes`, `seq`, and `cat` styles. Capture bytes/frame and syscalls/frame externally (for example with `strace -c` around the client/daemon) and allocations with `-benchmem`/pprof.
	12	+
	13	+	Comparison table placeholders (record local machine details before filling):
	14	+
	15	+	\| workload \| vev baseline \| tmux baseline \| notes \|
	16	+	\| --- \| --- \| --- \| --- \|
	17	+	\| yes \| TODO local run \| TODO local run \| same terminal size \|
	18	+	\| seq \| TODO local run \| TODO local run \| same duration \|
	19	+	\| cat \| TODO local run \| TODO local run \| same input file \|

@@ -0,0 +1,19 @@
	1	+	# Performance methodology (M5)
	2	+
	3	+	Enable daemon pprof explicitly with `VEV_PPROF_ADDR=127.0.0.1:6060 vev --daemon` (or by exporting the variable before launching clients). When unset, no debug HTTP server is started.
	4	+
	5	+	Run microbenchmarks with:
	6	+
	7	+	```sh
	8	+	go test ./pkg/renderer ./pkg/vt ./internal/adapters/ipc -bench=. -benchmem
	9	+	```
	10	+
	11	+	Demo flood workloads are scripted in `scripts/bench-workloads.sh` for `yes`, `seq`, and `cat` styles. Capture bytes/frame and syscalls/frame externally (for example with `strace -c` around the client/daemon) and allocations with `-benchmem`/pprof.
	12	+
	13	+	Comparison table placeholders (record local machine details before filling):
	14	+
	15	+	\| workload \| vev baseline \| tmux baseline \| notes \|
	16	+	\| --- \| --- \| --- \| --- \|
	17	+	\| yes \| TODO local run \| TODO local run \| same terminal size \|
	18	+	\| seq \| TODO local run \| TODO local run \| same duration \|
	19	+	\| cat \| TODO local run \| TODO local run \| same input file \|

A internal/adapters/ipc/transport_benchmark_test.go +31 -0

@@ -0,0 +1,31 @@
	1	+	package ipc
	2	+
	3	+	import (
	4	+	"net"
	5	+	"testing"
	6	+
	7	+	"github.com/bnema/vev/internal/ports"
	8	+	)
	9	+
	10	+	func BenchmarkTransportRecvReuse(b *testing.B) {
	11	+	c1, c2 := net.Pipe()
	12	+	defer func() { _ = c1.Close() }()
	13	+	defer func() { _ = c2.Close() }()
	14	+	tr := NewTransport(c2)
	15	+	payload := []byte("payload payload payload")
	16	+	done := make(chan struct{})
	17	+	go func() {
	18	+	defer close(done)
	19	+	for i := 0; i < b.N; i++ {
	20	+	_ = NewTransport(c1).Send(ports.Frame{Type: ports.MsgOutput, Payload: payload})
	21	+	}
	22	+	}()
	23	+	b.ReportAllocs()
	24	+	b.ResetTimer()
	25	+	for i := 0; i < b.N; i++ {
	26	+	if _, err := tr.Recv(); err != nil {
	27	+	b.Fatal(err)
	28	+	}
	29	+	}
	30	+	<-done
	31	+	}

@@ -0,0 +1,31 @@
	1	+	package ipc
	2	+
	3	+	import (
	4	+	"net"
	5	+	"testing"
	6	+
	7	+	"github.com/bnema/vev/internal/ports"
	8	+	)
	9	+
	10	+	func BenchmarkTransportRecvReuse(b *testing.B) {
	11	+	c1, c2 := net.Pipe()
	12	+	defer func() { _ = c1.Close() }()
	13	+	defer func() { _ = c2.Close() }()
	14	+	tr := NewTransport(c2)
	15	+	payload := []byte("payload payload payload")
	16	+	done := make(chan struct{})
	17	+	go func() {
	18	+	defer close(done)
	19	+	for i := 0; i < b.N; i++ {
	20	+	_ = NewTransport(c1).Send(ports.Frame{Type: ports.MsgOutput, Payload: payload})
	21	+	}
	22	+	}()
	23	+	b.ReportAllocs()
	24	+	b.ResetTimer()
	25	+	for i := 0; i < b.N; i++ {
	26	+	if _, err := tr.Recv(); err != nil {
	27	+	b.Fatal(err)
	28	+	}
	29	+	}
	30	+	<-done
	31	+	}

M internal/app/run.go +11 -0


@@ -10,6 +10,8 @@ import (
10	10		"fmt"
11	11		"io"
12	12		"log/slog"
	13	+	"net/http"
	14	+	_ "net/http/pprof"
13	15		"os"
14	16		"os/signal"
15	17		"syscall"

@@ -158,6 +160,15 @@ func runDaemon() error {
158	160		ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGTERM, syscall.SIGINT)
159	161		defer stop()
160	162
	163	+	if addr := os.Getenv("VEV_PPROF_ADDR"); addr != "" {
	164	+	go func() {
	165	+	if err := http.ListenAndServe(addr, nil); err != nil && !errors.Is(err, http.ErrServerClosed) {
	166	+	slog.Error("pprof server exited", "err", err)
	167	+	}
	168	+	}()
	169	+	slog.Info("pprof enabled", "addr", addr)
	170	+	}
	171	+
161	172		slog.Info("daemon starting", "socket", ln.Addr())
162	173		d := daemon.New(pty.NewFactory(), clock.New(), slog.Default())
163	174		if err := d.Serve(ctx, ln); err != nil {


@@ -10,6 +10,8 @@ import (
10	"fmt"	10		"fmt"
11	"io"	11		"io"
12	"log/slog"	12		"log/slog"
		13	+	"net/http"
		14	+	_ "net/http/pprof"
13	"os"	15		"os"
14	"os/signal"	16		"os/signal"
15	"syscall"	17		"syscall"

@@ -158,6 +160,15 @@ func runDaemon() error {
158	ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGTERM, syscall.SIGINT)	160		ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGTERM, syscall.SIGINT)
159	defer stop()	161		defer stop()
160		162
		163	+	if addr := os.Getenv("VEV_PPROF_ADDR"); addr != "" {
		164	+	go func() {
		165	+	if err := http.ListenAndServe(addr, nil); err != nil && !errors.Is(err, http.ErrServerClosed) {
		166	+	slog.Error("pprof server exited", "err", err)
		167	+	}
		168	+	}()
		169	+	slog.Info("pprof enabled", "addr", addr)
		170	+	}
		171	+
161	slog.Info("daemon starting", "socket", ln.Addr())	172		slog.Info("daemon starting", "socket", ln.Addr())
162	d := daemon.New(pty.NewFactory(), clock.New(), slog.Default())	173		d := daemon.New(pty.NewFactory(), clock.New(), slog.Default())
163	if err := d.Serve(ctx, ln); err != nil {	174		if err := d.Serve(ctx, ln); err != nil {

M internal/usecase/daemon/daemon.go +25 -8


@@ -45,10 +45,16 @@ import (
45	45		"github.com/bnema/vev/pkg/vt"
46	46		)
47	47
48		-	// debounceInterval is the fixed window opened on the first dirty signal: all
49		-	// further dirties arriving within it are absorbed and coalesced into a single
50		-	// render. It bounds render frequency to ~100Hz per session.
51		-	const debounceInterval = 10 * time.Millisecond
	48	+	// Scheduler debounce bounds. Idle updates use the minimum for low latency;
	49	+	// sustained floods step toward the maximum to reduce frame/syscall pressure.
	50	+	const (
	51	+	minDebounceInterval = 2 * time.Millisecond
	52	+	maxDebounceInterval = 16 * time.Millisecond
	53	+	debounceStep = 2 * time.Millisecond
	54	+	)
	55	+
	56	+	// debounceInterval is kept as a test/back-compat alias for the initial delay.
	57	+	const debounceInterval = minDebounceInterval
52	58
53	59		// ptyReadBufSize is the PTY reader's read buffer.
54	60		const ptyReadBufSize = 32 * 1024

@@ -951,10 +957,12 @@ func (d Daemon) ptyReader(sess session, win *window) {
951	957		}
952	958		}
953	959
954		-	// scheduler debounces dirty signals: the first opens a fixed window during
955		-	// which further dirties are absorbed, then it renders exactly once.
	960	+	// scheduler debounces dirty signals. The first dirty opens a short window;
	961	+	// sustained floods progressively widen that window, while isolated updates
	962	+	// return to the minimum delay for interactive latency.
956	963		func (d Daemon) scheduler(sess session, win *window) {
957	964		defer d.sessWg.Done()
	965	+	delay := minDebounceInterval
958	966		for {
959	967		select {
960	968		case <-sess.ctx.Done():

@@ -964,7 +972,8 @@ func (d Daemon) scheduler(sess session, win *window) {
964	972		case <-win.dirty:
965	973		}
966	974
967		-	timer := d.clock.NewTimer(debounceInterval)
	975	+	coalesced := 0
	976	+	timer := d.clock.NewTimer(delay)
968	977		absorb:
969	978		for {
970	979		select {

@@ -975,11 +984,19 @@ func (d Daemon) scheduler(sess session, win *window) {
975	984		timer.Stop()
976	985		return
977	986		case <-win.dirty:
978		-	// Coalesced into the pending render.
	987	+	coalesced++
979	988		case <-timer.C():
980	989		break absorb
981	990		}
982	991		}
	992	+	if coalesced == 0 {
	993	+	delay = minDebounceInterval
	994	+	} else if delay < maxDebounceInterval {
	995	+	delay += debounceStep
	996	+	if delay > maxDebounceInterval {
	997	+	delay = maxDebounceInterval
	998	+	}
	999	+	}
983	1000		d.render(sess, win)
984	1001		}
985	1002		}

 	"github.com/bnema/vev/pkg/vt"
 )
-// debounceInterval is the fixed window opened on the first dirty signal: all
+// Scheduler debounce bounds. Idle updates use the minimum for low latency;
-// further dirties arriving within it are absorbed and coalesced into a single
+// sustained floods step toward the maximum to reduce frame/syscall pressure.
-// render. It bounds render frequency to ~100Hz per session.
+const (
-const debounceInterval = 10 * time.Millisecond
+	minDebounceInterval = 2 * time.Millisecond
+	maxDebounceInterval = 16 * time.Millisecond
+	debounceStep        = 2 * time.Millisecond
+)
+// debounceInterval is kept as a test/back-compat alias for the initial delay.
+const debounceInterval = minDebounceInterval
 // ptyReadBufSize is the PTY reader's read buffer.
 const ptyReadBufSize = 32 * 1024
 	}
 }
-// scheduler debounces dirty signals: the first opens a fixed window during
+// scheduler debounces dirty signals. The first dirty opens a short window;
-// which further dirties are absorbed, then it renders exactly once.
+// sustained floods progressively widen that window, while isolated updates
+// return to the minimum delay for interactive latency.
 func (d *Daemon) scheduler(sess *session, win *window) {
 	defer d.sessWg.Done()
+	delay := minDebounceInterval
 	for {
 		select {
 		case <-sess.ctx.Done():
 		case <-win.dirty:
 		}
-		timer := d.clock.NewTimer(debounceInterval)
+		coalesced := 0
+		timer := d.clock.NewTimer(delay)
 	absorb:
 		for {
 			select {
 				timer.Stop()
 				return
 			case <-win.dirty:
-				// Coalesced into the pending render.
+				coalesced++
 			case <-timer.C():
 				break absorb
 			}
 		}
+		if coalesced == 0 {
+			delay = minDebounceInterval
+		} else if delay < maxDebounceInterval {
+			delay += debounceStep
+			if delay > maxDebounceInterval {
+				delay = maxDebounceInterval
+			}
+		}
 		d.render(sess, win)
 	}
 }

M internal/usecase/daemon/daemon_test.go +53 -1


@@ -933,7 +933,7 @@ func TestSchedulerDebounceCoalesces(t *testing.T) {
933	933		timerCh := make(chan time.Time, 1)
934	934		newTimerCalled := make(chan struct{}, 4)
935	935
936		-	mc.EXPECT().NewTimer(debounceInterval).RunAndReturn(func(time.Duration) ports.Timer {
	936	+	mc.EXPECT().NewTimer(mock.Anything).RunAndReturn(func(time.Duration) ports.Timer {
937	937		select {
938	938		case newTimerCalled <- struct{}{}:
939	939		default:

@@ -991,6 +991,58 @@ func TestSchedulerDebounceCoalesces(t *testing.T) {
991	991		require.Equal(t, int32(1), outputs.Load(), "N dirties in one window must render exactly once")
992	992		}
993	993
	994	+	func TestSchedulerAdaptiveDebounceFloodAndIdle(t *testing.T) {
	995	+	mc := portsmocks.NewMockClock(t)
	996	+	timers := make(chan chan time.Time, 4)
	997	+	var delaysMu sync.Mutex
	998	+	var delays []time.Duration
	999	+	mc.EXPECT().NewTimer(mock.Anything).RunAndReturn(func(d time.Duration) ports.Timer {
	1000	+	delaysMu.Lock()
	1001	+	delays = append(delays, d)
	1002	+	delaysMu.Unlock()
	1003	+	mt := portsmocks.NewMockTimer(t)
	1004	+	ch := make(chan time.Time, 1)
	1005	+	mt.EXPECT().C().Return(ch).Maybe()
	1006	+	mt.EXPECT().Stop().Return(true).Maybe()
	1007	+	timers <- ch
	1008	+	return mt
	1009	+	}).Maybe()
	1010	+
	1011	+	tr := portsmocks.NewMockTransport(t)
	1012	+	tr.EXPECT().Send(mock.Anything).Return(nil).Maybe()
	1013	+	d := New(nil, mc, slog.New(slog.NewTextHandler(io.Discard, nil)))
	1014	+	sctx, cancel := context.WithCancel(context.Background())
	1015	+	win := &window{screen: vt.NewScreen(20, 5), dirty: make(chan struct{}, 1), size: domain.Size{Cols: 20, Rows: 5}}
	1016	+	ac := &attachedClient{tr: tr, rend: renderer.New(renderer.Capabilities{})}
	1017	+	sess := &session{id: "s", name: "s", windows: []*window{win}, ctx: sctx, cancel: cancel, client: ac}
	1018	+	d.sessWg.Add(1)
	1019	+	go d.scheduler(sess, win)
	1020	+
	1021	+	for range 2 {
	1022	+	win.dirty <- struct{}{}
	1023	+	ch := <-timers
	1024	+	for range 4 {
	1025	+	select {
	1026	+	case win.dirty <- struct{}{}:
	1027	+	default:
	1028	+	}
	1029	+	}
	1030	+	ch <- time.Now()
	1031	+	}
	1032	+	win.dirty <- struct{}{}
	1033	+	ch := <-timers
	1034	+	ch <- time.Now()
	1035	+
	1036	+	cancel()
	1037	+	d.sessWg.Wait()
	1038	+	delaysMu.Lock()
	1039	+	defer delaysMu.Unlock()
	1040	+	require.GreaterOrEqual(t, len(delays), 3)
	1041	+	require.Equal(t, minDebounceInterval, delays[0])
	1042	+	require.Greater(t, delays[1], delays[0], "sustained flood should widen debounce")
	1043	+	require.Greater(t, delays[2], delays[1], "continued flood should keep adapting")
	1044	+	}
	1045	+
994	1046		// --- resize ordering --------------------------------------------------------
995	1047
996	1048		func TestResizeOrdersPTYBeforeScreen(t *testing.T) {


@@ -933,7 +933,7 @@ func TestSchedulerDebounceCoalesces(t *testing.T) {
933		timerCh := make(chan time.Time, 1)	933		timerCh := make(chan time.Time, 1)
934		newTimerCalled := make(chan struct{}, 4)	934		newTimerCalled := make(chan struct{}, 4)
935			935
936	-	mc.EXPECT().NewTimer(debounceInterval).RunAndReturn(func(time.Duration) ports.Timer {	936	+	mc.EXPECT().NewTimer(mock.Anything).RunAndReturn(func(time.Duration) ports.Timer {
937		select {	937		select {
938		case newTimerCalled <- struct{}{}:	938		case newTimerCalled <- struct{}{}:
939		default:	939		default:

@@ -991,6 +991,58 @@ func TestSchedulerDebounceCoalesces(t *testing.T) {
991		require.Equal(t, int32(1), outputs.Load(), "N dirties in one window must render exactly once")	991		require.Equal(t, int32(1), outputs.Load(), "N dirties in one window must render exactly once")
992		}	992		}
993			993
			994	+	func TestSchedulerAdaptiveDebounceFloodAndIdle(t *testing.T) {
			995	+	mc := portsmocks.NewMockClock(t)
			996	+	timers := make(chan chan time.Time, 4)
			997	+	var delaysMu sync.Mutex
			998	+	var delays []time.Duration
			999	+	mc.EXPECT().NewTimer(mock.Anything).RunAndReturn(func(d time.Duration) ports.Timer {
			1000	+	delaysMu.Lock()
			1001	+	delays = append(delays, d)
			1002	+	delaysMu.Unlock()
			1003	+	mt := portsmocks.NewMockTimer(t)
			1004	+	ch := make(chan time.Time, 1)
			1005	+	mt.EXPECT().C().Return(ch).Maybe()
			1006	+	mt.EXPECT().Stop().Return(true).Maybe()
			1007	+	timers <- ch
			1008	+	return mt
			1009	+	}).Maybe()
			1010	+
			1011	+	tr := portsmocks.NewMockTransport(t)
			1012	+	tr.EXPECT().Send(mock.Anything).Return(nil).Maybe()
			1013	+	d := New(nil, mc, slog.New(slog.NewTextHandler(io.Discard, nil)))
			1014	+	sctx, cancel := context.WithCancel(context.Background())
			1015	+	win := &window{screen: vt.NewScreen(20, 5), dirty: make(chan struct{}, 1), size: domain.Size{Cols: 20, Rows: 5}}
			1016	+	ac := &attachedClient{tr: tr, rend: renderer.New(renderer.Capabilities{})}
			1017	+	sess := &session{id: "s", name: "s", windows: []*window{win}, ctx: sctx, cancel: cancel, client: ac}
			1018	+	d.sessWg.Add(1)
			1019	+	go d.scheduler(sess, win)
			1020	+
			1021	+	for range 2 {
			1022	+	win.dirty <- struct{}{}
			1023	+	ch := <-timers
			1024	+	for range 4 {
			1025	+	select {
			1026	+	case win.dirty <- struct{}{}:
			1027	+	default:
			1028	+	}
			1029	+	}
			1030	+	ch <- time.Now()
			1031	+	}
			1032	+	win.dirty <- struct{}{}
			1033	+	ch := <-timers
			1034	+	ch <- time.Now()
			1035	+
			1036	+	cancel()
			1037	+	d.sessWg.Wait()
			1038	+	delaysMu.Lock()
			1039	+	defer delaysMu.Unlock()
			1040	+	require.GreaterOrEqual(t, len(delays), 3)
			1041	+	require.Equal(t, minDebounceInterval, delays[0])
			1042	+	require.Greater(t, delays[1], delays[0], "sustained flood should widen debounce")
			1043	+	require.Greater(t, delays[2], delays[1], "continued flood should keep adapting")
			1044	+	}
			1045	+
994		// --- resize ordering --------------------------------------------------------	1046		// --- resize ordering --------------------------------------------------------
995			1047
996		func TestResizeOrdersPTYBeforeScreen(t *testing.T) {	1048		func TestResizeOrdersPTYBeforeScreen(t *testing.T) {

A scripts/bench-workloads.sh +24 -0

@@ -0,0 +1,24 @@
	1	+	#!/usr/bin/env bash
	2	+	set -euo pipefail
	3	+
	4	+	# Demo workload driver for comparing vev and tmux manually.
	5	+	# Usage: TARGET=vev\|tmux WORKLOAD=yes\|seq\|cat DURATION=5 ./scripts/bench-workloads.sh
	6	+	TARGET=${TARGET:-vev}
	7	+	WORKLOAD=${WORKLOAD:-yes}
	8	+	DURATION=${DURATION:-5}
	9	+
	10	+	case "$WORKLOAD" in
	11	+	yes) CMD='yes vev-benchmark' ;;
	12	+	seq) CMD='while :; do seq 1 20000; done' ;;
	13	+	cat) CMD='cat go.sum go.mod >/dev/null; while :; do cat go.sum; done' ;;
	14	+	*) echo "unknown WORKLOAD: $WORKLOAD" >&2; exit 2 ;;
	15	+	esac
	16	+
	17	+	echo "target=$TARGET workload=$WORKLOAD duration=${DURATION}s"
	18	+	echo "command=$CMD"
	19	+	case "$TARGET" in
	20	+	vev) timeout "$DURATION" ./vev new bench -- sh -lc "$CMD" ;;
	21	+	tmux) timeout "$DURATION" tmux new-session -d -s vev-bench "$CMD" && sleep "$DURATION" && tmux kill-session -t vev-bench ;;
	22	+	raw) timeout "$DURATION" sh -lc "$CMD" ;;
	23	+	*) echo "unknown TARGET: $TARGET" >&2; exit 2 ;;
	24	+	esac

@@ -0,0 +1,24 @@
	1	+	#!/usr/bin/env bash
	2	+	set -euo pipefail
	3	+
	4	+	# Demo workload driver for comparing vev and tmux manually.
	5	+	# Usage: TARGET=vev\|tmux WORKLOAD=yes\|seq\|cat DURATION=5 ./scripts/bench-workloads.sh
	6	+	TARGET=${TARGET:-vev}
	7	+	WORKLOAD=${WORKLOAD:-yes}
	8	+	DURATION=${DURATION:-5}
	9	+
	10	+	case "$WORKLOAD" in
	11	+	yes) CMD='yes vev-benchmark' ;;
	12	+	seq) CMD='while :; do seq 1 20000; done' ;;
	13	+	cat) CMD='cat go.sum go.mod >/dev/null; while :; do cat go.sum; done' ;;
	14	+	*) echo "unknown WORKLOAD: $WORKLOAD" >&2; exit 2 ;;
	15	+	esac
	16	+
	17	+	echo "target=$TARGET workload=$WORKLOAD duration=${DURATION}s"
	18	+	echo "command=$CMD"
	19	+	case "$TARGET" in
	20	+	vev) timeout "$DURATION" ./vev new bench -- sh -lc "$CMD" ;;
	21	+	tmux) timeout "$DURATION" tmux new-session -d -s vev-bench "$CMD" && sleep "$DURATION" && tmux kill-session -t vev-bench ;;
	22	+	raw) timeout "$DURATION" sh -lc "$CMD" ;;
	23	+	*) echo "unknown TARGET: $TARGET" >&2; exit 2 ;;
	24	+	esac