diff --git a/main.go b/main.go index e2cacff..10de2fa 100644 --- a/main.go +++ b/main.go @@ -712,7 +712,7 @@ func printMarkAssist(db *sql.DB, w io.Writer) error { if err := rows.Scan(&scopeID, &gname, &assists, &totalAssistNs, &maxAssistNs, &worstAtMs); err != nil { return err } - fmt.Fprintf(w, " G%-8d %-40s %d assists, total %s, max %s @ t=%.0fms\n", + fmt.Fprintf(w, " g%-8d %-40s %d assists, total %s, max %s @ t=%.0fms\n", scopeID, shortenFunc(gname), assists, fmtDuration(totalAssistNs), fmtDuration(maxAssistNs), worstAtMs) } return rows.Err() diff --git a/testdata/experiment-upsert1000-gateway.txt b/testdata/experiment-upsert1000-gateway.txt index 40e53a4..a1acaf1 100644 --- a/testdata/experiment-upsert1000-gateway.txt +++ b/testdata/experiment-upsert1000-gateway.txt @@ -118,11 +118,11 @@ GC cycles: 1, total: 30.31ms, avg: 30.31ms, min: 30.31ms, max: 30.31ms start trace: 1 pauses, total 4.2µs, max 4.2µs Mark assist: 963 events across 836 goroutines, total: 93.39ms, max single: 1.26ms Top affected goroutines: - G1222 kv/kvserver.(*RaftTransport).raftMessageBatch.func1 95 assists, total 11.64ms, max 1.26ms @ t=4266ms - G1012 internal/transport.(*http2Client).reader 7 assists, total 1.05ms, max 313.7µs @ t=4255ms - G1285 kv/kvserver.(*RaftTransport).startProcessNewQueue.func3 7 assists, total 715.2µs, max 139.8µs @ t=4252ms - G916 util/stop.(*Stopper).RunAsyncTaskEx.func1 4 assists, total 594.2µs, max 296.7µs @ t=4250ms - G919 util/stop.(*Stopper).RunAsyncTaskEx.func1 4 assists, total 566.5µs, max 210.7µs @ t=4250ms + g1222 kv/kvserver.(*RaftTransport).raftMessageBatch.func1 95 assists, total 11.64ms, max 1.26ms @ t=4266ms + g1012 internal/transport.(*http2Client).reader 7 assists, total 1.05ms, max 313.7µs @ t=4255ms + g1285 kv/kvserver.(*RaftTransport).startProcessNewQueue.func3 7 assists, total 715.2µs, max 139.8µs @ t=4252ms + g916 util/stop.(*Stopper).RunAsyncTaskEx.func1 4 assists, total 594.2µs, max 296.7µs @ t=4250ms + g919 util/stop.(*Stopper).RunAsyncTaskEx.func1 4 assists, total 566.5µs, max 210.7µs @ t=4250ms Scheduling latency during GC vs normal: count p50 p99 max During GC: 4969 74.6µs 7.51ms 9.44ms diff --git a/testdata/experiment-upsert1000-leaseholder.txt b/testdata/experiment-upsert1000-leaseholder.txt index bcd3cdd..775aafb 100644 --- a/testdata/experiment-upsert1000-leaseholder.txt +++ b/testdata/experiment-upsert1000-leaseholder.txt @@ -192,11 +192,11 @@ GC cycles: 2, total: 88.55ms, avg: 44.27ms, min: 31.41ms, max: 57.14ms start trace: 1 pauses, total 49.0µs, max 49.0µs Mark assist: 1039 events across 698 goroutines, total: 97.13ms, max single: 1.75ms Top affected goroutines: - G1046 pkg/ts.(*poller).start.func1 97 assists, total 9.18ms, max 1.75ms @ t=9935ms - G2504794 cockroachdb/pebble.(*DB).flush 20 assists, total 5.54ms, max 1.67ms @ t=9944ms - G1055 util/stop.(*Stopper).RunAsyncTaskEx.func1 46 assists, total 3.53ms, max 181.4µs @ t=9923ms - G718 util/stop.(*Stopper).RunAsyncTaskEx.func1 40 assists, total 3.50ms, max 354.9µs @ t=9938ms - G720 util/stop.(*Stopper).RunAsyncTaskEx.func1 38 assists, total 2.81ms, max 149.8µs @ t=9927ms + g1046 pkg/ts.(*poller).start.func1 97 assists, total 9.18ms, max 1.75ms @ t=9935ms + g2504794 cockroachdb/pebble.(*DB).flush 20 assists, total 5.54ms, max 1.67ms @ t=9944ms + g1055 util/stop.(*Stopper).RunAsyncTaskEx.func1 46 assists, total 3.53ms, max 181.4µs @ t=9923ms + g718 util/stop.(*Stopper).RunAsyncTaskEx.func1 40 assists, total 3.50ms, max 354.9µs @ t=9938ms + g720 util/stop.(*Stopper).RunAsyncTaskEx.func1 38 assists, total 2.81ms, max 149.8µs @ t=9927ms Scheduling latency during GC vs normal: count p50 p99 max During GC: 9730 79.7µs 16.28ms 21.76ms diff --git a/testdata/single-node-lowcpu-gcassist.txt b/testdata/single-node-lowcpu-gcassist.txt index e3ed975..f7f183c 100644 --- a/testdata/single-node-lowcpu-gcassist.txt +++ b/testdata/single-node-lowcpu-gcassist.txt @@ -16,11 +16,11 @@ GC cycles: 2, total: 25.78ms, avg: 12.89ms, min: 11.62ms, max: 14.16ms start trace: 1 pauses, total 4.5µs, max 4.5µs Mark assist: 72 events across 30 goroutines, total: 33.43ms, max single: 3.48ms Top affected goroutines: - G1068065 sql/pgwire.(*Server).serveImpl.func4 4 assists, total 4.72ms, max 3.25ms @ t=73ms - G1067930 sql/pgwire.(*Server).serveImpl.func4 3 assists, total 4.38ms, max 3.48ms @ t=72ms - G1068084 sql/pgwire.(*Server).serveImpl.func4 5 assists, total 3.78ms, max 3.24ms @ t=73ms - G1058917 sql/pgwire.(*Server).serveImpl.func4 6 assists, total 3.50ms, max 1.64ms @ t=71ms - G1068213 sql/pgwire.(*Server).serveImpl.func4 6 assists, total 3.50ms, max 1.68ms @ t=75ms + g1068065 sql/pgwire.(*Server).serveImpl.func4 4 assists, total 4.72ms, max 3.25ms @ t=73ms + g1067930 sql/pgwire.(*Server).serveImpl.func4 3 assists, total 4.38ms, max 3.48ms @ t=72ms + g1068084 sql/pgwire.(*Server).serveImpl.func4 5 assists, total 3.78ms, max 3.24ms @ t=73ms + g1058917 sql/pgwire.(*Server).serveImpl.func4 6 assists, total 3.50ms, max 1.64ms @ t=71ms + g1068213 sql/pgwire.(*Server).serveImpl.func4 6 assists, total 3.50ms, max 1.68ms @ t=75ms Scheduling latency during GC vs normal: count p50 p99 max During GC: 869 4.5µs 456.6µs 1.06ms