Inspecting Goroutine States
Sometimes it can be useful to get a view of all running goroutines: how many there are, which function they are currently executing, and what their current status is (running, waiting for a channel receive / send operation, waiting for a mutex, waiting for a syscall, etc.). For example, this information can help you figure out why certain parts of Prometheus (like a scrape loop) are stuck, or whether there is a goroutine leak.
The /debug/pprof/goroutine endpoint gives us exactly this information, and it is useful directly from the web browser.
By default, this endpoint will return a text format like this:
goroutine profile: total 46
7 @ 0x43e10e 0x44e5a5 0x27fe95f 0x471281
# 0x27fe95e github.com/prometheus/prometheus/scrape.(*scrapeLoop).run+0x3fe /app/scrape/scrape.go:1182
6 @ 0x43e10e 0x436b97 0x46b8a5 0x4e5287 0x4e657a 0x4e6568 0x52ab05 0x53bbe5 0x70d3ea 0x673be3 0x673d13 0x70e1d9 0x471281
# 0x46b8a4 internal/poll.runtime_pollWait+0x84 /usr/local/go/src/runtime/netpoll.go:343
# 0x4e5286 internal/poll.(*pollDesc).wait+0x26 /usr/local/go/src/internal/poll/fd_poll_runtime.go:84
# 0x4e6579 internal/poll.(*pollDesc).waitRead+0x279 /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
# 0x4e6567 internal/poll.(*FD).Read+0x267 /usr/local/go/src/internal/poll/fd_unix.go:164
# 0x52ab04 net.(*netFD).Read+0x24 /usr/local/go/src/net/fd_posix.go:55
# 0x53bbe4 net.(*conn).Read+0x44 /usr/local/go/src/net/net.go:179
# 0x70d3e9 net/http.(*persistConn).Read+0x49 /usr/local/go/src/net/http/transport.go:1954
# 0x673be2 bufio.(*Reader).fill+0x102 /usr/local/go/src/bufio/bufio.go:113
# 0x673d12 bufio.(*Reader).Peek+0x52 /usr/local/go/src/bufio/bufio.go:151
# 0x70e1d8 net/http.(*persistConn).readLoop+0x1b8 /usr/local/go/src/net/http/transport.go:2118
6 @ 0x43e10e 0x44e5a5 0x70fba5 0x471281
# 0x70fba4 net/http.(*persistConn).writeLoop+0xe4 /usr/local/go/src/net/http/transport.go:2421
[...]However, by appending a ?debug=2 parameter to the URL (yielding /debug/pprof/goroutine?debug=2), the format becomes somewhat more human-readable and useful:
goroutine 10742989 [running]:
runtime/pprof.writeGoroutineStacks({0x7efc81c29998, 0xc00255cc80})
/usr/local/go/src/runtime/pprof/pprof.go:703 +0x6a
runtime/pprof.writeGoroutine({0x7efc81c29998?, 0xc00255cc80?}, 0x4103c5?)
/usr/local/go/src/runtime/pprof/pprof.go:692 +0x25
runtime/pprof.(*Profile).WriteTo(0x3204180?, {0x7efc81c29998?, 0xc00255cc80?}, 0xc?)
/usr/local/go/src/runtime/pprof/pprof.go:329 +0x146
net/http/pprof.handler.ServeHTTP({0xc003cb720d, 0x9}, {0x7efc81c28890, 0xc00255cc80}, 0x0?)
/usr/local/go/src/net/http/pprof/pprof.go:267 +0x4a8
net/http/pprof.Index({0x7efc81c28890?, 0xc00255cc80}, 0xc002c62200?)
/usr/local/go/src/net/http/pprof/pprof.go:384 +0xe5
github.com/prometheus/prometheus/web.serveDebug({0x7efc81c28890, 0xc00255cc80}, 0xc002c62200)
/app/web/web.go:520 +0x2c5
net/http.HandlerFunc.ServeHTTP(0x7efc81c28890?, {0x7efc81c28890?, 0xc00255cc80?}, 0x40fe89?)
/usr/local/go/src/net/http/server.go:2136 +0x29
github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerResponseSize.func1({0x7efc81c28890?, 0xc00255cc30?}, 0xc002c62200)
/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:296 +0xca
net/http.HandlerFunc.ServeHTTP(0x48?, {0x7efc81c28890?, 0xc00255cc30?}, 0x7efc841764b8?)
/usr/local/go/src/net/http/server.go:2136 +0x29
github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerDuration.func2({0x7efc81c28890, 0xc00255cc30}, 0xc002c62200)
/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:109 +0xc2
net/http.HandlerFunc.ServeHTTP(0x3f64c80?, {0x7efc81c28890?, 0xc00255cc30?}, 0x32d7480?)
/usr/local/go/src/net/http/server.go:2136 +0x29
github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerCounter.func1({0x3f64c80?, 0xc004304180?}, 0xc002c62200)
/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:147 +0xb6
github.com/prometheus/prometheus/web.New.setPathWithPrefix.func20.1({0x3f64c80, 0xc004304180}, 0xc002c62100)
/app/web/web.go:805 +0xb3
github.com/prometheus/common/route.(*Router).handle.func1({0x3f64c80, 0xc004304180}, 0xc002c62000, {0xc002141c00, 0x1, 0x10040dea5?})
/go/pkg/mod/github.com/prometheus/[email protected]/route/route.go:83 +0x1f6
github.com/julienschmidt/httprouter.(*Router).ServeHTTP(0xc0007f97a0, {0x3f64c80, 0xc004304180}, 0xc002c62000)
/go/pkg/mod/github.com/julienschmidt/[email protected]/router.go:387 +0x7eb
github.com/prometheus/common/route.(*Router).ServeHTTP(0xc0099cc400?, {0x3f64c80?, 0xc004304180?}, 0xc000f05408?)
/go/pkg/mod/github.com/prometheus/[email protected]/route/route.go:126 +0x25
net/http.(*ServeMux).ServeHTTP(0x3f6e2e0?, {0x3f64c80, 0xc004304180}, 0xc002c62000)
/usr/local/go/src/net/http/server.go:2514 +0x142
go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*middleware).serveHTTP(0xc0004a5810, {0x3f5d410?, 0xc002e610a0}, 0xc002b9bf00, {0x3f3e7e0, 0xc000733240})
/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/net/http/[email protected]/handler.go:229 +0x1202
go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.NewMiddleware.func1.1({0x3f5d410?, 0xc002e610a0?}, 0x10?)
/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/net/http/[email protected]/handler.go:81 +0x35
net/http.HandlerFunc.ServeHTTP(0x7f013d5c7150?, {0x3f5d410?, 0xc002e610a0?}, 0x46f472?)
/usr/local/go/src/net/http/server.go:2136 +0x29
github.com/prometheus/prometheus/web.(*Handler).Run.withStackTracer.func9({0x3f5d410?, 0xc002e610a0?}, 0x0?)
/app/web/web.go:104 +0x8c
net/http.HandlerFunc.ServeHTTP(0x5b578c0?, {0x3f5d410?, 0xc002e610a0?}, 0xc000f05b50?)
/usr/local/go/src/net/http/server.go:2136 +0x29
net/http.serverHandler.ServeHTTP({0xc001835a10?}, {0x3f5d410?, 0xc002e610a0?}, 0x6?)
/usr/local/go/src/net/http/server.go:2938 +0x8e
net/http.(*conn).serve(0xc002f797a0, {0x3f6e2e0, 0xc0009b2480})
/usr/local/go/src/net/http/server.go:2009 +0x5f4
created by net/http.(*Server).Serve in goroutine 349
/usr/local/go/src/net/http/server.go:3086 +0x5cb
goroutine 1 [chan receive, 57724 minutes]:
github.com/oklog/run.(*Group).Run(0xc00250d850)
/go/pkg/mod/github.com/oklog/[email protected]/group.go:43 +0x155
main.main()
/app/cmd/prometheus/main.go:1179 +0xa98c
goroutine 17 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc000132280)
/go/pkg/mod/[email protected]/stats/view/worker.go:292 +0x9f
created by go.opencensus.io/stats/view.init.0 in goroutine 1
/go/pkg/mod/[email protected]/stats/view/worker.go:34 +0x8d
[...]This output lists the call stack for each goroutine, preceded by a goroutine <goroutine-number> [<goroutine status>] line. The status of a goroutine indicates whether it is currently running or waiting for some external action or condition (e.g. [chan receive, 158485 minutes], [select], etc.). If you see a goroutine here that is waiting for an unexpectedly long time, this might point to a problem.