Skip to content

schedstat: per-cycle GC mark assist breakdown #8

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
tbg merged 1 commit into from
May 8, 2026
Merged

schedstat: per-cycle GC mark assist breakdown #8

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
181 changes: 92 additions & 89 deletions main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -651,14 +651,6 @@ func collectGCAnalysis(db *sql.DB) (*GCReport, error) {
g.STW = stw
}

ma, err := collectMarkAssist(db)
if err != nil {
return nil, err
}
if ma != nil {
g.MarkAssist = ma
}

cmp, err := collectGCLatencyComparison(db)
if err != nil {
return nil, err
Expand All @@ -667,14 +659,6 @@ func collectGCAnalysis(db *sql.DB) (*GCReport, error) {
g.LatencyComparison = cmp
}

if opts.verbose {
pc, err := collectPerCycleBreakdown(db)
if err != nil {
return nil, err
}
g.PerCycle = pc
}

sweep, err := collectSweepSummary(db)
if err != nil {
return nil, err
Expand All @@ -683,6 +667,14 @@ func collectGCAnalysis(db *sql.DB) (*GCReport, error) {
g.Sweep = sweep
}

pc, err := collectPerCycleGCDetail(db)
if err != nil {
return nil, err
}
if pc != nil {
g.PerCycle = pc
}

return g, nil
}

Expand Down Expand Up @@ -755,66 +747,6 @@ func collectSTWSummary(db *sql.DB) (*GCSTWSummary, error) {
}, nil
}

func collectMarkAssist(db *sql.DB) (*GCMarkAssist, error) {
var totalEvents int
var totalGoroutines int
var totalNs, maxSingleNs sql.NullFloat64
err := db.QueryRow(`
SELECT COUNT(*), COUNT(DISTINCT scope_id), SUM(duration_ns), MAX(duration_ns)
FROM gc_ranges
WHERE name = 'GC mark assist'
`).Scan(&totalEvents, &totalGoroutines, &totalNs, &maxSingleNs)
if err != nil {
return nil, fmt.Errorf("mark assist summary: %w", err)
}
if totalEvents == 0 {
return nil, nil
}

out := &GCMarkAssist{
TotalEvents: totalEvents,
TotalGoroutines: totalGoroutines,
TotalNs: nullF64ToInt64Ptr(totalNs),
MaxSingleNs: nullF64ToInt64Ptr(maxSingleNs),
}

rows, err := db.Query(`
WITH t0 AS (
SELECT MIN(end_time_ns - duration_ns) as v FROM g_transitions
WHERE from_state = 'runnable' AND to_state = 'running'
)
SELECT
r.scope_id,
COALESCE(g.name, '(unknown)') as gname,
COUNT(*) as assists,
SUM(r.duration_ns) as total_assist_ns,
MAX(r.duration_ns) as max_assist_ns,
(arg_max(r.start_time_ns, r.duration_ns) - (SELECT v FROM t0)) / 1e6 as worst_at_ms
FROM gc_ranges r
LEFT JOIN goroutines g ON r.scope_id = g.g
WHERE r.name = 'GC mark assist'
GROUP BY r.scope_id, gname
ORDER BY total_assist_ns DESC
LIMIT $1
`, opts.top)
if err != nil {
return nil, fmt.Errorf("mark assist top goroutines: %w", err)
}
defer rows.Close()

for rows.Next() {
var e MarkAssistGEntry
var totNs, mxNs float64
if err := rows.Scan(&e.G, &e.Name, &e.Assists, &totNs, &mxNs, &e.WorstAtMs); err != nil {
return nil, err
}
e.TotalNs = int64(totNs)
e.MaxNs = int64(mxNs)
out.TopGoroutines = append(out.TopGoroutines, e)
}
return out, rows.Err()
}

func collectGCLatencyComparison(db *sql.DB) (*GCLatencyComparison, error) {
var cycleCount int
if err := db.QueryRow(`SELECT COUNT(*) FROM gc_cycles`).Scan(&cycleCount); err != nil {
Expand Down Expand Up @@ -900,10 +832,26 @@ func collectGCLatencyComparison(db *sql.DB) (*GCLatencyComparison, error) {
return out, nil
}

func collectPerCycleBreakdown(db *sql.DB) (*GCPerCycleBreakdown, error) {
rows, err := db.Query(`
// collectPerCycleGCDetail returns one entry per GC cycle with that cycle's
// mark-assist totals and the top-N affected goroutines. Returns nil if the
// trace contains no GC cycles.
func collectPerCycleGCDetail(db *sql.DB) (*GCPerCycleDetail, error) {
var cycleCount int
if err := db.QueryRow(`SELECT COUNT(*) FROM gc_cycles`).Scan(&cycleCount); err != nil {
return nil, fmt.Errorf("gc cycle count: %w", err)
}
if cycleCount == 0 {
return nil, nil
}

cycleRows, err := db.Query(`
WITH t0 AS (
SELECT MIN(end_time_ns - duration_ns) as v FROM g_transitions
WHERE from_state = 'runnable' AND to_state = 'running'
)
SELECT
gc.cycle,
(gc.start_time_ns - (SELECT v FROM t0)) / 1e6 as start_ms,
gc.duration_ns,
COUNT(r.name) as assists,
COUNT(DISTINCT r.scope_id) as goroutines,
Expand All @@ -913,26 +861,81 @@ func collectPerCycleBreakdown(db *sql.DB) (*GCPerCycleBreakdown, error) {
ON r.name = 'GC mark assist'
AND r.start_time_ns < gc.end_time_ns
AND r.end_time_ns > gc.start_time_ns
GROUP BY gc.cycle, gc.duration_ns, gc.start_time_ns
GROUP BY gc.cycle, gc.start_time_ns, gc.duration_ns
ORDER BY gc.start_time_ns
`)
if err != nil {
return nil, fmt.Errorf("per-cycle breakdown: %w", err)
return nil, fmt.Errorf("per-cycle detail: %w", err)
}
defer rows.Close()
defer cycleRows.Close()

out := &GCPerCycleBreakdown{}
for rows.Next() {
var e GCCycleEntry
out := &GCPerCycleDetail{}
cycleIdx := map[int]int{} // cycle number → index in out.Cycles
for cycleRows.Next() {
var c GCCycleDetail
var dur, assist float64
if err := rows.Scan(&e.Cycle, &dur, &e.Assists, &e.Goroutines, &assist); err != nil {
if err := cycleRows.Scan(&c.Cycle, &c.StartMs, &dur, &c.AssistEvents, &c.AssistGoroutines, &assist); err != nil {
return nil, err
}
e.DurationNs = int64(dur)
e.AssistTimeNs = int64(assist)
out.Cycles = append(out.Cycles, e)
c.DurationNs = int64(dur)
c.AssistTotalNs = int64(assist)
cycleIdx[c.Cycle] = len(out.Cycles)
out.Cycles = append(out.Cycles, c)
}
return out, rows.Err()
if err := cycleRows.Err(); err != nil {
return nil, err
}

gRows, err := db.Query(`
WITH t0 AS (
SELECT MIN(end_time_ns - duration_ns) as v FROM g_transitions
WHERE from_state = 'runnable' AND to_state = 'running'
),
per_g AS (
SELECT
gc.cycle,
r.scope_id,
COALESCE(g.name, '(unknown)') as gname,
COUNT(*) as assists,
SUM(r.duration_ns) as total_assist_ns,
MAX(r.duration_ns) as max_assist_ns,
(arg_max(r.start_time_ns, r.duration_ns) - (SELECT v FROM t0)) / 1e6 as worst_at_ms
FROM gc_cycles gc
JOIN gc_ranges r
ON r.name = 'GC mark assist'
AND r.start_time_ns < gc.end_time_ns
AND r.end_time_ns > gc.start_time_ns
LEFT JOIN goroutines g ON r.scope_id = g.g
GROUP BY gc.cycle, r.scope_id, gname
),
ranked AS (
SELECT *, ROW_NUMBER() OVER (PARTITION BY cycle ORDER BY total_assist_ns DESC) as rn
FROM per_g
)
SELECT cycle, scope_id, gname, assists, total_assist_ns, max_assist_ns, worst_at_ms
FROM ranked
WHERE rn <= $1
ORDER BY cycle, total_assist_ns DESC
`, opts.top)
if err != nil {
return nil, fmt.Errorf("per-cycle goroutines: %w", err)
}
defer gRows.Close()

for gRows.Next() {
var cycle int
var e CycleAssistG
var totNs, mxNs float64
if err := gRows.Scan(&cycle, &e.G, &e.Name, &e.Assists, &totNs, &mxNs, &e.WorstAtMs); err != nil {
return nil, err
}
e.TotalNs = int64(totNs)
e.MaxNs = int64(mxNs)
if i, ok := cycleIdx[cycle]; ok {
out.Cycles[i].TopGoroutines = append(out.Cycles[i].TopGoroutines, e)
}
}
return out, gRows.Err()
}

func collectSweepSummary(db *sql.DB) (*GCSweepSummary, error) {
Expand Down
95 changes: 41 additions & 54 deletions report.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -417,10 +417,9 @@ func (r *ByCreatorReport) String() string {
type GCReport struct {
CycleSummary *GCCycleSummary `json:"cycle_summary,omitempty"`
STW *GCSTWSummary `json:"stw,omitempty"`
MarkAssist *GCMarkAssist `json:"mark_assist,omitempty"`
LatencyComparison *GCLatencyComparison `json:"latency_comparison,omitempty"`
PerCycle *GCPerCycleBreakdown `json:"per_cycle,omitempty"`
Sweep *GCSweepSummary `json:"sweep,omitempty"`
PerCycle *GCPerCycleDetail `json:"per_cycle,omitempty"`
}

func (g *GCReport) String() string {
Expand All @@ -432,18 +431,15 @@ func (g *GCReport) String() string {
if g.STW != nil {
b.WriteString(g.STW.String())
}
if g.MarkAssist != nil {
b.WriteString(g.MarkAssist.String())
}
if g.LatencyComparison != nil {
b.WriteString(g.LatencyComparison.String())
}
if g.PerCycle != nil {
b.WriteString(g.PerCycle.String())
}
if g.Sweep != nil {
b.WriteString(g.Sweep.String())
}
if g.PerCycle != nil {
b.WriteString(g.PerCycle.String())
}
return b.String()
}

Expand Down Expand Up @@ -491,39 +487,6 @@ func (g *GCSTWSummary) String() string {
return b.String()
}

type GCMarkAssist struct {
TotalEvents int `json:"total_events"`
TotalGoroutines int `json:"total_goroutines"`
TotalNs *int64 `json:"total_ns,omitempty"`
MaxSingleNs *int64 `json:"max_single_ns,omitempty"`
TopGoroutines []MarkAssistGEntry `json:"top_goroutines,omitempty"`
}

type MarkAssistGEntry struct {
G int64 `json:"g"`
Name string `json:"name"`
Assists int `json:"assists"`
TotalNs int64 `json:"total_ns"`
MaxNs int64 `json:"max_ns"`
WorstAtMs float64 `json:"worst_at_ms"`
}

func (g *GCMarkAssist) String() string {
if g.TotalEvents == 0 {
return ""
}
var b strings.Builder
fmt.Fprintf(&b, " Mark assist: %d events across %d goroutines, total: %s, max single: %s\n",
g.TotalEvents, g.TotalGoroutines, fmtNsPtr(g.TotalNs), fmtNsPtr(g.MaxSingleNs))
b.WriteString(" Top affected goroutines:\n")
for _, e := range g.TopGoroutines {
fmt.Fprintf(&b, " g%-8d %-40s %d assists, total %s, max %s @ t=%.0fms\n",
e.G, shortenFunc(e.Name), e.Assists,
fmtDuration(float64(e.TotalNs)), fmtDuration(float64(e.MaxNs)), e.WorstAtMs)
}
return b.String()
}

type GCLatencyComparison struct {
DuringGC LatencyBucket `json:"during_gc"`
NonGC LatencyBucket `json:"non_gc"`
Expand Down Expand Up @@ -559,25 +522,49 @@ func (g *GCLatencyComparison) String() string {
return b.String()
}

type GCPerCycleBreakdown struct {
Cycles []GCCycleEntry `json:"cycles"`
// GCPerCycleDetail is the per-cycle GC mark-assist breakdown. For each GC
// cycle we show its start time, duration, mark-assist totals, and the top
// affected goroutines (by total assist time within the cycle).
type GCPerCycleDetail struct {
Cycles []GCCycleDetail `json:"cycles"`
}

type GCCycleEntry struct {
Cycle int `json:"cycle"`
DurationNs int64 `json:"duration_ns"`
Assists int `json:"assists"`
Goroutines int `json:"goroutines"`
AssistTimeNs int64 `json:"assist_time_ns"`
type GCCycleDetail struct {
Cycle int `json:"cycle"`
StartMs float64 `json:"start_ms"`
DurationNs int64 `json:"duration_ns"`
AssistEvents int `json:"assist_events"`
AssistGoroutines int `json:"assist_goroutines"`
AssistTotalNs int64 `json:"assist_total_ns"`
TopGoroutines []CycleAssistG `json:"top_goroutines,omitempty"`
}

func (g *GCPerCycleBreakdown) String() string {
type CycleAssistG struct {
G int64 `json:"g"`
Name string `json:"name"`
Assists int `json:"assists"`
TotalNs int64 `json:"total_ns"`
MaxNs int64 `json:"max_ns"`
WorstAtMs float64 `json:"worst_at_ms"`
}

func (g *GCPerCycleDetail) String() string {
var b strings.Builder
b.WriteString(" Per-cycle breakdown:\n")
fmt.Fprintf(&b, " %-6s %-12s %-8s %-12s %-12s\n", "Cycle", "Duration", "Assists", "Goroutines", "Assist Time")
for _, c := range g.Cycles {
fmt.Fprintf(&b, " %-6d %-12s %-8d %-12d %-12s\n",
c.Cycle, fmtDuration(float64(c.DurationNs)), c.Assists, c.Goroutines, fmtDuration(float64(c.AssistTimeNs)))
if c.AssistEvents == 0 {
fmt.Fprintf(&b, "\n Cycle %d @ t=%.0fms, duration: %s (no mark assists)\n",
c.Cycle, c.StartMs, fmtDuration(float64(c.DurationNs)))
continue
}
fmt.Fprintf(&b, "\n Cycle %d @ t=%.0fms, duration: %s\n",
c.Cycle, c.StartMs, fmtDuration(float64(c.DurationNs)))
fmt.Fprintf(&b, " Mark assist: %d events, %d goroutines, total: %s\n",
c.AssistEvents, c.AssistGoroutines, fmtDuration(float64(c.AssistTotalNs)))
for _, r := range c.TopGoroutines {
fmt.Fprintf(&b, " g%-8d %-40s %d assists, total %s, max %s @ t=%.0fms\n",
r.G, shortenFunc(r.Name), r.Assists,
fmtDuration(float64(r.TotalNs)), fmtDuration(float64(r.MaxNs)), r.WorstAtMs)
}
}
return b.String()
}
Expand Down
Loading
Loading