468 lines
16 KiB
Go
468 lines
16 KiB
Go
package runtimestats
|
|||
|
|
|
||
|
|
import (
|
||
|
|
"runtime"
|
||
|
|
"sort"
|
||
|
|
"strconv"
|
||
|
|
"strings"
|
||
|
|
"time"
|
||
|
|
)
|
||
|
|
|
||
|
|
/* The expensive half, and the reason it is a separate route.
|
||
|
|
|
||
|
|
Reading every goroutine's stack means stopping the world for as long as it takes to walk
|
||
|
|
them all. That is measured in milliseconds rather than seconds, but it is not something
|
||
|
|
to do on a poll every open console tab makes every thirty seconds — so this is collected
|
||
|
|
only when an operator asks, and the answer says when it was collected and what it cost.
|
||
|
|
|
||
|
|
What comes back is a text dump, and parsing text a runtime produced is exactly the sort
|
||
|
|
of thing that quietly stops working. Two rules keep that honest: parseGoroutines is pure
|
||
|
|
and pinned by tests carrying real dump text, and every unrecognised state or frame falls
|
||
|
|
into a named "other" bucket rather than being dropped — a breakdown whose parts do not
|
||
|
|
add up to the total is worse than no breakdown, so the total is always the count of
|
||
|
|
goroutines parsed and the categories always partition it. */
|
||
|
|
|
||
|
|
// Category is the readable grouping a goroutine state falls into. These are the words an
|
||
|
|
// operator is being asked to reason with, so there are six of them and none is Go jargon.
|
||
|
|
type Category string
|
||
|
|
|
||
|
|
const (
|
||
|
|
CategoryRunning Category = "running"
|
||
|
|
CategoryIO Category = "io"
|
||
|
|
CategoryWaiting Category = "waiting"
|
||
|
|
CategoryTimers Category = "timers"
|
||
|
|
CategoryRuntime Category = "runtime"
|
||
|
|
CategoryOther Category = "other"
|
||
|
|
)
|
||
|
|
|
||
|
|
// categoryLabels is the console's wording. Sent from here, the stance every label the
|
||
|
|
// gateway prints takes: a category added later reads correctly on a console that predates
|
||
|
|
// it, because the console prints what it was handed.
|
||
|
|
var categoryLabels = map[Category]string{
|
||
|
|
CategoryRunning: "Running",
|
||
|
|
CategoryIO: "Network / I/O",
|
||
|
|
CategoryWaiting: "Waiting / idle",
|
||
|
|
CategoryTimers: "Timers / scheduled work",
|
||
|
|
CategoryRuntime: "Go runtime / collection",
|
||
|
|
CategoryOther: "Other",
|
||
|
|
}
|
||
|
|
|
||
|
|
// categoryOrder is the order they are presented in: busiest kind of work first, then the
|
||
|
|
// two that mean the goroutine is doing nothing, then the runtime's own housekeeping. It is
|
||
|
|
// fixed rather than sorted by count so the table does not reorder between two collections.
|
||
|
|
var categoryOrder = []Category{
|
||
|
|
CategoryRunning, CategoryIO, CategoryWaiting, CategoryTimers, CategoryRuntime, CategoryOther,
|
||
|
|
}
|
||
|
|
|
||
|
|
// categoryDescriptions say what the operator is looking at, because "semacquire" means
|
||
|
|
// nothing to somebody who does not write Go and the whole point of this page is that they
|
||
|
|
// should not have to.
|
||
|
|
var categoryDescriptions = map[Category]string{
|
||
|
|
CategoryRunning: "On a processor now, or queued for one.",
|
||
|
|
CategoryIO: "Waiting on a network read or write — Emby, Postgres, Redis, or a television.",
|
||
|
|
CategoryWaiting: "Parked waiting for work or for a lock. Idle, and costing almost nothing.",
|
||
|
|
CategoryTimers: "Asleep until a scheduled time.",
|
||
|
|
CategoryRuntime: "The Go runtime's own housekeeping. This handful is always present.",
|
||
|
|
CategoryOther: "A state this build does not have a category for.",
|
||
|
|
}
|
||
|
|
|
||
|
|
// categoryFor maps a runtime state string onto one of the six. The GC states are tested
|
||
|
|
// first because several of them contain words the later rules would otherwise claim —
|
||
|
|
// "wait for GC cycle" is the runtime's own, not a component waiting on a channel.
|
||
|
|
func categoryFor(state string) Category {
|
||
|
|
state = strings.TrimSpace(state)
|
||
|
|
lower := strings.ToLower(state)
|
||
|
|
switch {
|
||
|
|
case strings.Contains(lower, "gc "), strings.HasPrefix(lower, "gc"),
|
||
|
|
lower == "finalizer wait", strings.HasPrefix(lower, "trace reader"),
|
||
|
|
strings.HasPrefix(lower, "dumping heap"), strings.HasPrefix(lower, "stopping the world"),
|
||
|
|
strings.HasPrefix(lower, "idle"):
|
||
|
|
return CategoryRuntime
|
||
|
|
case lower == "running", lower == "runnable", strings.HasPrefix(lower, "syscall"):
|
||
|
|
return CategoryRunning
|
||
|
|
case strings.HasPrefix(lower, "io wait"), strings.HasPrefix(lower, "netpoll"):
|
||
|
|
return CategoryIO
|
||
|
|
case strings.HasPrefix(lower, "sleep"), strings.HasPrefix(lower, "timer"):
|
||
|
|
return CategoryTimers
|
||
|
|
case strings.HasPrefix(lower, "select"), strings.HasPrefix(lower, "chan "),
|
||
|
|
strings.HasPrefix(lower, "semacquire"), strings.HasPrefix(lower, "sync."),
|
||
|
|
strings.HasPrefix(lower, "wait"), strings.HasPrefix(lower, "preempted"):
|
||
|
|
return CategoryWaiting
|
||
|
|
default:
|
||
|
|
return CategoryOther
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
/* ---------- component attribution ---------- */
|
||
|
|
|
||
|
|
type componentRule struct {
|
||
|
|
component string
|
||
|
|
// patterns are matched against every frame of the stack — the function names and the
|
||
|
|
// file paths alike — plus the "created by" line, which is often the only frame that
|
||
|
|
// still names the component a long-parked goroutine belongs to.
|
||
|
|
patterns []string
|
||
|
|
}
|
||
|
|
|
||
|
|
// componentRules is ordered, and the order is the whole of it: Memby's own packages are
|
||
|
|
// tested before the libraries they call, or every database query in the gateway would be
|
||
|
|
// filed under "Database pool" and nothing would be attributable to the feature that made
|
||
|
|
// it. First match wins.
|
||
|
|
var componentRules = []componentRule{
|
||
|
|
{"Library sync", []string{"/internal/library"}},
|
||
|
|
{"Scheduled jobs", []string{"/internal/scheduler"}},
|
||
|
|
{"Credits detection", []string{"/internal/credits"}},
|
||
|
|
{"Recommendations", []string{"/internal/recommend", "/internal/foryou", "/internal/tracearr"}},
|
||
|
|
{"Notifications", []string{"/internal/notify"}},
|
||
|
|
{"Integrations", []string{"/internal/integrations", "/internal/adminevents"}},
|
||
|
|
{"Subtitles", []string{"/internal/bazarr", "/internal/opensubtitles", "/internal/subsync"}},
|
||
|
|
{"Sonarr and Radarr", []string{"/internal/sonarr", "/internal/radarr"}},
|
||
|
|
{"Ratings", []string{"/internal/mdblist"}},
|
||
|
|
{"Emby", []string{"/internal/emby", "/internal/trickplay"}},
|
||
|
|
{"Gateway API", []string{"/internal/api", "/internal/store", "/internal/cache", "/internal/logging"}},
|
||
|
|
{"Database pool", []string{"jackc/pgx", "jackc/puddle", "database/sql"}},
|
||
|
|
{"Redis", []string{"redis/go-redis"}},
|
||
|
|
{"HTTP server", []string{"net/http.(*conn).serve", "net/http.(*Server)", "net/http.(*connReader)"}},
|
||
|
|
{"HTTP client", []string{"net/http.(*persistConn)", "net/http.(*Transport)"}},
|
||
|
|
{"Go runtime", []string{"runtime.", "runtime/pprof"}},
|
||
|
|
}
|
||
|
|
|
||
|
|
const componentUnattributed = "Unattributed"
|
||
|
|
|
||
|
|
func componentFor(info goroutineInfo) string {
|
||
|
|
haystack := info.searchText()
|
||
|
|
for _, rule := range componentRules {
|
||
|
|
for _, pattern := range rule.patterns {
|
||
|
|
if strings.Contains(haystack, pattern) {
|
||
|
|
return rule.component
|
||
|
|
}
|
||
|
|
}
|
||
|
|
}
|
||
|
|
return componentUnattributed
|
||
|
|
}
|
||
|
|
|
||
|
|
/* ---------- parsing ---------- */
|
||
|
|
|
||
|
|
type frame struct {
|
||
|
|
Function string
|
||
|
|
File string
|
||
|
|
}
|
||
|
|
|
||
|
|
type goroutineInfo struct {
|
||
|
|
ID int
|
||
|
|
State string
|
||
|
|
WaitMinutes int
|
||
|
|
Frames []frame
|
||
|
|
CreatedBy string
|
||
|
|
}
|
||
|
|
|
||
|
|
func (info goroutineInfo) searchText() string {
|
||
|
|
var builder strings.Builder
|
||
|
|
for _, one := range info.Frames {
|
||
|
|
builder.WriteString(one.Function)
|
||
|
|
builder.WriteByte('\n')
|
||
|
|
builder.WriteString(one.File)
|
||
|
|
builder.WriteByte('\n')
|
||
|
|
}
|
||
|
|
builder.WriteString(info.CreatedBy)
|
||
|
|
return builder.String()
|
||
|
|
}
|
||
|
|
|
||
|
|
// topFrame is the function the goroutine is actually sitting in, skipping the runtime
|
||
|
|
// plumbing that every parked goroutine shares. Without the skip, half the table reads
|
||
|
|
// "runtime.gopark", which is true of every waiting goroutine in the process and therefore
|
||
|
|
// tells nobody anything.
|
||
|
|
func (info goroutineInfo) topFrame() frame {
|
||
|
|
for _, one := range info.Frames {
|
||
|
|
function := one.Function
|
||
|
|
if strings.HasPrefix(function, "runtime.") || strings.HasPrefix(function, "internal/poll.runtime_") ||
|
||
|
|
strings.HasPrefix(function, "sync.runtime_") || strings.HasPrefix(function, "sync.(*") ||
|
||
|
|
strings.HasPrefix(function, "time.Sleep") {
|
||
|
|
continue
|
||
|
|
}
|
||
|
|
return one
|
||
|
|
}
|
||
|
|
if len(info.Frames) > 0 {
|
||
|
|
return info.Frames[0]
|
||
|
|
}
|
||
|
|
return frame{}
|
||
|
|
}
|
||
|
|
|
||
|
|
// parseGoroutines reads a runtime.Stack dump. It is pure so the shape of the dump can be
|
||
|
|
// pinned by a test rather than discovered when a Go release changes it.
|
||
|
|
func parseGoroutines(dump string) []goroutineInfo {
|
||
|
|
var out []goroutineInfo
|
||
|
|
var current *goroutineInfo
|
||
|
|
flush := func() {
|
||
|
|
if current != nil {
|
||
|
|
out = append(out, *current)
|
||
|
|
current = nil
|
||
|
|
}
|
||
|
|
}
|
||
|
|
for _, line := range strings.Split(dump, "\n") {
|
||
|
|
switch {
|
||
|
|
case strings.HasPrefix(line, "goroutine "):
|
||
|
|
flush()
|
||
|
|
info, ok := parseHeader(line)
|
||
|
|
if !ok {
|
||
|
|
continue
|
||
|
|
}
|
||
|
|
current = &info
|
||
|
|
case current == nil:
|
||
|
|
continue
|
||
|
|
case strings.HasPrefix(line, "created by "):
|
||
|
|
current.CreatedBy = strings.TrimPrefix(line, "created by ")
|
||
|
|
case strings.HasPrefix(line, "\t"):
|
||
|
|
// A file line belongs to the function line above it.
|
||
|
|
if len(current.Frames) > 0 {
|
||
|
|
path := strings.TrimSpace(line)
|
||
|
|
if cut := strings.LastIndex(path, " +0x"); cut > 0 {
|
||
|
|
path = path[:cut]
|
||
|
|
}
|
||
|
|
current.Frames[len(current.Frames)-1].File = path
|
||
|
|
}
|
||
|
|
case strings.TrimSpace(line) == "":
|
||
|
|
flush()
|
||
|
|
default:
|
||
|
|
current.Frames = append(current.Frames, frame{Function: functionName(line)})
|
||
|
|
}
|
||
|
|
}
|
||
|
|
flush()
|
||
|
|
return out
|
||
|
|
}
|
||
|
|
|
||
|
|
// parseHeader reads `goroutine 42 [select, 5 minutes]:`.
|
||
|
|
func parseHeader(line string) (goroutineInfo, bool) {
|
||
|
|
open := strings.Index(line, "[")
|
||
|
|
shut := strings.LastIndex(line, "]")
|
||
|
|
if open < 0 || shut < open {
|
||
|
|
return goroutineInfo{}, false
|
||
|
|
}
|
||
|
|
id, _ := strconv.Atoi(strings.TrimSpace(line[len("goroutine "):open]))
|
||
|
|
inside := line[open+1 : shut]
|
||
|
|
state := inside
|
||
|
|
minutes := 0
|
||
|
|
// The state itself can contain a comma — "chan receive, 5 minutes" and "GC worker
|
||
|
|
// (idle)" both do not, but "semacquire, 3 minutes, locked to thread" does, so only a
|
||
|
|
// part that parses as a duration is taken as one.
|
||
|
|
parts := strings.Split(inside, ", ")
|
||
|
|
state = parts[0]
|
||
|
|
for _, part := range parts[1:] {
|
||
|
|
if value, ok := parseMinutes(part); ok {
|
||
|
|
minutes = value
|
||
|
|
}
|
||
|
|
}
|
||
|
|
return goroutineInfo{ID: id, State: state, WaitMinutes: minutes}, true
|
||
|
|
}
|
||
|
|
|
||
|
|
func parseMinutes(part string) (int, bool) {
|
||
|
|
part = strings.TrimSpace(part)
|
||
|
|
if !strings.HasSuffix(part, " minutes") && !strings.HasSuffix(part, " minute") {
|
||
|
|
return 0, false
|
||
|
|
}
|
||
|
|
value, err := strconv.Atoi(strings.Fields(part)[0])
|
||
|
|
if err != nil {
|
||
|
|
return 0, false
|
||
|
|
}
|
||
|
|
return value, true
|
||
|
|
}
|
||
|
|
|
||
|
|
// functionName strips the argument list a stack dump prints after the function, since the
|
||
|
|
// arguments are addresses and would make every otherwise-identical goroutine its own group.
|
||
|
|
func functionName(line string) string {
|
||
|
|
line = strings.TrimSpace(line)
|
||
|
|
if open := strings.Index(line, "("); open > 0 {
|
||
|
|
// Method receivers are themselves parenthesised — `pkg.(*Type).Method(0x1)` — so
|
||
|
|
// the argument list is the last balanced group rather than the first bracket.
|
||
|
|
if last := strings.LastIndex(line, "("); last > 0 && !strings.HasSuffix(line[:last], ".") {
|
||
|
|
return line[:last]
|
||
|
|
}
|
||
|
|
return line[:open]
|
||
|
|
}
|
||
|
|
return line
|
||
|
|
}
|
||
|
|
|
||
|
|
/* ---------- the report ---------- */
|
||
|
|
|
||
|
|
type CategoryCount struct {
|
||
|
|
Category Category `json:"category"`
|
||
|
|
Label string `json:"label"`
|
||
|
|
Description string `json:"description"`
|
||
|
|
Count int `json:"count"`
|
||
|
|
States []StateCount `json:"states"`
|
||
|
|
}
|
||
|
|
|
||
|
|
type StateCount struct {
|
||
|
|
State string `json:"state"`
|
||
|
|
Count int `json:"count"`
|
||
|
|
}
|
||
|
|
|
||
|
|
type ComponentCount struct {
|
||
|
|
Component string `json:"component"`
|
||
|
|
Count int `json:"count"`
|
||
|
|
// LongestWaitMinutes is the age of the oldest goroutine attributed here. A component
|
||
|
|
// whose count is climbing and whose oldest is hours old is the shape of a leak; one
|
||
|
|
// that is busy and young is the shape of a busy evening.
|
||
|
|
LongestWaitMinutes int `json:"longestWaitMinutes"`
|
||
|
|
}
|
||
|
|
|
||
|
|
type StackGroup struct {
|
||
|
|
Count int `json:"count"`
|
||
|
|
Component string `json:"component"`
|
||
|
|
Category Category `json:"category"`
|
||
|
|
State string `json:"state"`
|
||
|
|
Function string `json:"function"`
|
||
|
|
File string `json:"file"`
|
||
|
|
CreatedBy string `json:"createdBy,omitempty"`
|
||
|
|
LongestWaitMinutes int `json:"longestWaitMinutes"`
|
||
|
|
}
|
||
|
|
|
||
|
|
type GoroutineReport struct {
|
||
|
|
At time.Time `json:"at"`
|
||
|
|
Total int `json:"total"`
|
||
|
|
CollectedInMs float64 `json:"collectedInMs"`
|
||
|
|
DumpBytes int `json:"dumpBytes"`
|
||
|
|
Categories []CategoryCount `json:"categories"`
|
||
|
|
Components []ComponentCount `json:"components"`
|
||
|
|
Groups []StackGroup `json:"groups"`
|
||
|
|
// GroupsTotal is how many distinct groups there were before the cap below; a gateway
|
||
|
|
// with thousands of goroutines has a long tail that would be a page nobody reads.
|
||
|
|
GroupsTotal int `json:"groupsTotal"`
|
||
|
|
Workers []Worker `json:"workers"`
|
||
|
|
}
|
||
|
|
|
||
|
|
// maxGroups caps the table. The groups are sorted by count, so what is dropped is the tail
|
||
|
|
// of one-off goroutines, which is exactly the part that says nothing.
|
||
|
|
const maxGroups = 40
|
||
|
|
|
||
|
|
// CollectGoroutines takes the dump and builds the report. This is the expensive call.
|
||
|
|
func CollectGoroutines() GoroutineReport {
|
||
|
|
begin := time.Now()
|
||
|
|
dump := stackDump()
|
||
|
|
report := buildReport(dump, time.Now())
|
||
|
|
report.CollectedInMs = float64(time.Since(begin).Microseconds()) / 1000
|
||
|
|
report.Workers = Workers()
|
||
|
|
return report
|
||
|
|
}
|
||
|
|
|
||
|
|
// StackDump is the raw text, for an operator who wants the whole thing rather than the
|
||
|
|
// summary — the on-demand snapshot that replaces any temptation to leave a profiler
|
||
|
|
// endpoint permanently open.
|
||
|
|
func StackDump() string { return stackDump() }
|
||
|
|
|
||
|
|
// stackDump grows its buffer until the whole dump fits. runtime.Stack truncates silently
|
||
|
|
// at the length of the buffer it is given, and a truncated dump would produce a breakdown
|
||
|
|
// that is quietly missing whichever goroutines came last — which on a leak is the ones
|
||
|
|
// worth seeing.
|
||
|
|
func stackDump() string {
|
||
|
|
size := 1 << 20
|
||
|
|
for {
|
||
|
|
buffer := make([]byte, size)
|
||
|
|
written := runtime.Stack(buffer, true)
|
||
|
|
if written < len(buffer) {
|
||
|
|
return string(buffer[:written])
|
||
|
|
}
|
||
|
|
if size >= 1<<26 {
|
||
|
|
return string(buffer[:written])
|
||
|
|
}
|
||
|
|
size *= 2
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
func buildReport(dump string, at time.Time) GoroutineReport {
|
||
|
|
list := parseGoroutines(dump)
|
||
|
|
report := GoroutineReport{At: at, Total: len(list), DumpBytes: len(dump)}
|
||
|
|
|
||
|
|
states := map[Category]map[string]int{}
|
||
|
|
counts := map[Category]int{}
|
||
|
|
components := map[string]*ComponentCount{}
|
||
|
|
groups := map[string]*StackGroup{}
|
||
|
|
|
||
|
|
for _, info := range list {
|
||
|
|
category := categoryFor(info.State)
|
||
|
|
counts[category]++
|
||
|
|
if states[category] == nil {
|
||
|
|
states[category] = map[string]int{}
|
||
|
|
}
|
||
|
|
states[category][info.State]++
|
||
|
|
|
||
|
|
component := componentFor(info)
|
||
|
|
entry := components[component]
|
||
|
|
if entry == nil {
|
||
|
|
entry = &ComponentCount{Component: component}
|
||
|
|
components[component] = entry
|
||
|
|
}
|
||
|
|
entry.Count++
|
||
|
|
if info.WaitMinutes > entry.LongestWaitMinutes {
|
||
|
|
entry.LongestWaitMinutes = info.WaitMinutes
|
||
|
|
}
|
||
|
|
|
||
|
|
top := info.topFrame()
|
||
|
|
key := component + "\x00" + info.State + "\x00" + top.Function
|
||
|
|
group := groups[key]
|
||
|
|
if group == nil {
|
||
|
|
group = &StackGroup{
|
||
|
|
Component: component, Category: category, State: info.State,
|
||
|
|
Function: top.Function, File: top.File, CreatedBy: info.CreatedBy,
|
||
|
|
}
|
||
|
|
groups[key] = group
|
||
|
|
}
|
||
|
|
group.Count++
|
||
|
|
if info.WaitMinutes > group.LongestWaitMinutes {
|
||
|
|
group.LongestWaitMinutes = info.WaitMinutes
|
||
|
|
}
|
||
|
|
}
|
||
|
|
|
||
|
|
for _, category := range categoryOrder {
|
||
|
|
count := counts[category]
|
||
|
|
if count == 0 {
|
||
|
|
continue
|
||
|
|
}
|
||
|
|
report.Categories = append(report.Categories, CategoryCount{
|
||
|
|
Category: category,
|
||
|
|
Label: categoryLabels[category],
|
||
|
|
Description: categoryDescriptions[category],
|
||
|
|
Count: count,
|
||
|
|
States: sortedStates(states[category]),
|
||
|
|
})
|
||
|
|
}
|
||
|
|
|
||
|
|
for _, entry := range components {
|
||
|
|
report.Components = append(report.Components, *entry)
|
||
|
|
}
|
||
|
|
sort.Slice(report.Components, func(a, b int) bool {
|
||
|
|
if report.Components[a].Count != report.Components[b].Count {
|
||
|
|
return report.Components[a].Count > report.Components[b].Count
|
||
|
|
}
|
||
|
|
return report.Components[a].Component < report.Components[b].Component
|
||
|
|
})
|
||
|
|
|
||
|
|
for _, group := range groups {
|
||
|
|
report.Groups = append(report.Groups, *group)
|
||
|
|
}
|
||
|
|
sort.Slice(report.Groups, func(a, b int) bool {
|
||
|
|
if report.Groups[a].Count != report.Groups[b].Count {
|
||
|
|
return report.Groups[a].Count > report.Groups[b].Count
|
||
|
|
}
|
||
|
|
return report.Groups[a].Function < report.Groups[b].Function
|
||
|
|
})
|
||
|
|
report.GroupsTotal = len(report.Groups)
|
||
|
|
if len(report.Groups) > maxGroups {
|
||
|
|
report.Groups = report.Groups[:maxGroups]
|
||
|
|
}
|
||
|
|
return report
|
||
|
|
}
|
||
|
|
|
||
|
|
func sortedStates(counts map[string]int) []StateCount {
|
||
|
|
out := make([]StateCount, 0, len(counts))
|
||
|
|
for state, count := range counts {
|
||
|
|
out = append(out, StateCount{State: state, Count: count})
|
||
|
|
}
|
||
|
|
sort.Slice(out, func(a, b int) bool {
|
||
|
|
if out[a].Count != out[b].Count {
|
||
|
|
return out[a].Count > out[b].Count
|
||
|
|
}
|
||
|
|
return out[a].State < out[b].State
|
||
|
|
})
|
||
|
|
return out
|
||
|
|
}
|