mirror of
https://github.com/golang/go.git
synced 2025-12-08 06:10:04 +00:00
runtime: emit STW events for all pauses, not just those for the GC
Currently STW events are only emitted for GC STWs. There's little reason why the trace can't contain events for every STW: they're rare so don't take up much space in the trace, yet being able to see when the world was stopped is often critical to debugging certain latency issues, especially when they stem from user-level APIs. This change adds new "kinds" to the EvGCSTWStart event, renames the GCSTW events to just "STW," and lets the parser deal with unknown STW kinds for future backwards compatibility. But, this change must break trace compatibility, so it bumps the trace version to Go 1.21. This change also includes a small cleanup in the trace command, which previously checked for STW events when deciding whether user tasks overlapped with a GC. Looking at the source, I don't see a way for STW events to ever enter the stream that that code looks at, so that condition has been deleted. Change-Id: I9a5dc144092c53e92eb6950e9a5504a790ac00cf Reviewed-on: https://go-review.googlesource.com/c/go/+/494495 Reviewed-by: Michael Pratt <mpratt@google.com> TryBot-Result: Gopher Robot <gobot@golang.org> Run-TryBot: Michael Knyszek <mknyszek@google.com>
This commit is contained in:
parent
944911af56
commit
b1aadd034c
19 changed files with 177 additions and 69 deletions
|
|
@ -494,7 +494,7 @@ func (region *regionDesc) duration() time.Duration {
|
||||||
func (task *taskDesc) overlappingGCDuration(evs []*trace.Event) (overlapping time.Duration) {
|
func (task *taskDesc) overlappingGCDuration(evs []*trace.Event) (overlapping time.Duration) {
|
||||||
for _, ev := range evs {
|
for _, ev := range evs {
|
||||||
// make sure we only consider the global GC events.
|
// make sure we only consider the global GC events.
|
||||||
if typ := ev.Type; typ != trace.EvGCStart && typ != trace.EvGCSTWStart {
|
if typ := ev.Type; typ != trace.EvGCStart {
|
||||||
continue
|
continue
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|
|
||||||
|
|
@ -764,12 +764,12 @@ func generateTrace(params *traceParams, consumer traceConsumer) error {
|
||||||
case trace.EvGCStart:
|
case trace.EvGCStart:
|
||||||
ctx.emitSlice(ev, "GC")
|
ctx.emitSlice(ev, "GC")
|
||||||
case trace.EvGCDone:
|
case trace.EvGCDone:
|
||||||
case trace.EvGCSTWStart:
|
case trace.EvSTWStart:
|
||||||
if ctx.mode&modeGoroutineOriented != 0 {
|
if ctx.mode&modeGoroutineOriented != 0 {
|
||||||
continue
|
continue
|
||||||
}
|
}
|
||||||
ctx.emitSlice(ev, fmt.Sprintf("STW (%s)", ev.SArgs[0]))
|
ctx.emitSlice(ev, fmt.Sprintf("STW (%s)", ev.SArgs[0]))
|
||||||
case trace.EvGCSTWDone:
|
case trace.EvSTWDone:
|
||||||
case trace.EvGCMarkAssistStart:
|
case trace.EvGCMarkAssistStart:
|
||||||
// Mark assists can continue past preemptions, so truncate to the
|
// Mark assists can continue past preemptions, so truncate to the
|
||||||
// whichever comes first. We'll synthesize another slice if
|
// whichever comes first. We'll synthesize another slice if
|
||||||
|
|
|
||||||
|
|
@ -27,6 +27,7 @@ type UtilFlags int
|
||||||
|
|
||||||
const (
|
const (
|
||||||
// UtilSTW means utilization should account for STW events.
|
// UtilSTW means utilization should account for STW events.
|
||||||
|
// This includes non-GC STW events, which are typically user-requested.
|
||||||
UtilSTW UtilFlags = 1 << iota
|
UtilSTW UtilFlags = 1 << iota
|
||||||
// UtilBackground means utilization should account for
|
// UtilBackground means utilization should account for
|
||||||
// background mark workers.
|
// background mark workers.
|
||||||
|
|
@ -93,11 +94,11 @@ func MutatorUtilization(events []*Event, flags UtilFlags) [][]MutatorUtil {
|
||||||
}
|
}
|
||||||
ps = append(ps, perP{series: series})
|
ps = append(ps, perP{series: series})
|
||||||
}
|
}
|
||||||
case EvGCSTWStart:
|
case EvSTWStart:
|
||||||
if flags&UtilSTW != 0 {
|
if flags&UtilSTW != 0 {
|
||||||
stw++
|
stw++
|
||||||
}
|
}
|
||||||
case EvGCSTWDone:
|
case EvSTWDone:
|
||||||
if flags&UtilSTW != 0 {
|
if flags&UtilSTW != 0 {
|
||||||
stw--
|
stw--
|
||||||
}
|
}
|
||||||
|
|
|
||||||
|
|
@ -151,7 +151,7 @@ func readTrace(r io.Reader) (ver int, events []rawEvent, strings map[uint64]stri
|
||||||
return
|
return
|
||||||
}
|
}
|
||||||
switch ver {
|
switch ver {
|
||||||
case 1005, 1007, 1008, 1009, 1010, 1011, 1019:
|
case 1005, 1007, 1008, 1009, 1010, 1011, 1019, 1021:
|
||||||
// Note: When adding a new version, confirm that canned traces from the
|
// Note: When adding a new version, confirm that canned traces from the
|
||||||
// old version are part of the test suite. Add them using mkcanned.bash.
|
// old version are part of the test suite. Add them using mkcanned.bash.
|
||||||
break
|
break
|
||||||
|
|
@ -420,18 +420,29 @@ func parseEvents(ver int, rawEvents []rawEvent, strings map[uint64]string) (even
|
||||||
if raw.typ == EvGoStartLabel {
|
if raw.typ == EvGoStartLabel {
|
||||||
e.SArgs = []string{strings[e.Args[2]]}
|
e.SArgs = []string{strings[e.Args[2]]}
|
||||||
}
|
}
|
||||||
case EvGCSTWStart:
|
case EvSTWStart:
|
||||||
e.G = 0
|
e.G = 0
|
||||||
switch e.Args[0] {
|
if ver < 1021 {
|
||||||
case 0:
|
switch e.Args[0] {
|
||||||
e.SArgs = []string{"mark termination"}
|
case 0:
|
||||||
case 1:
|
e.SArgs = []string{"mark termination"}
|
||||||
e.SArgs = []string{"sweep termination"}
|
case 1:
|
||||||
default:
|
e.SArgs = []string{"sweep termination"}
|
||||||
err = fmt.Errorf("unknown STW kind %d", e.Args[0])
|
default:
|
||||||
return
|
err = fmt.Errorf("unknown STW kind %d", e.Args[0])
|
||||||
|
return
|
||||||
|
}
|
||||||
|
} else if ver == 1021 {
|
||||||
|
if kind := e.Args[0]; kind < uint64(len(stwReasonStringsGo121)) {
|
||||||
|
e.SArgs = []string{stwReasonStringsGo121[kind]}
|
||||||
|
} else {
|
||||||
|
e.SArgs = []string{"unknown"}
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
// Can't make any assumptions.
|
||||||
|
e.SArgs = []string{"unknown"}
|
||||||
}
|
}
|
||||||
case EvGCStart, EvGCDone, EvGCSTWDone:
|
case EvGCStart, EvGCDone, EvSTWDone:
|
||||||
e.G = 0
|
e.G = 0
|
||||||
case EvGoEnd, EvGoStop, EvGoSched, EvGoPreempt,
|
case EvGoEnd, EvGoStop, EvGoSched, EvGoPreempt,
|
||||||
EvGoSleep, EvGoBlock, EvGoBlockSend, EvGoBlockRecv,
|
EvGoSleep, EvGoBlock, EvGoBlockSend, EvGoBlockRecv,
|
||||||
|
|
@ -653,20 +664,20 @@ func postProcessTrace(ver int, events []*Event) error {
|
||||||
}
|
}
|
||||||
evGC.Link = ev
|
evGC.Link = ev
|
||||||
evGC = nil
|
evGC = nil
|
||||||
case EvGCSTWStart:
|
case EvSTWStart:
|
||||||
evp := &evSTW
|
evp := &evSTW
|
||||||
if ver < 1010 {
|
if ver < 1010 {
|
||||||
// Before 1.10, EvGCSTWStart was per-P.
|
// Before 1.10, EvSTWStart was per-P.
|
||||||
evp = &p.evSTW
|
evp = &p.evSTW
|
||||||
}
|
}
|
||||||
if *evp != nil {
|
if *evp != nil {
|
||||||
return fmt.Errorf("previous STW is not ended before a new one (offset %v, time %v)", ev.Off, ev.Ts)
|
return fmt.Errorf("previous STW is not ended before a new one (offset %v, time %v)", ev.Off, ev.Ts)
|
||||||
}
|
}
|
||||||
*evp = ev
|
*evp = ev
|
||||||
case EvGCSTWDone:
|
case EvSTWDone:
|
||||||
evp := &evSTW
|
evp := &evSTW
|
||||||
if ver < 1010 {
|
if ver < 1010 {
|
||||||
// Before 1.10, EvGCSTWDone was per-P.
|
// Before 1.10, EvSTWDone was per-P.
|
||||||
evp = &p.evSTW
|
evp = &p.evSTW
|
||||||
}
|
}
|
||||||
if *evp == nil {
|
if *evp == nil {
|
||||||
|
|
@ -1015,7 +1026,7 @@ func argNum(raw rawEvent, ver int) int {
|
||||||
if ver < 1007 {
|
if ver < 1007 {
|
||||||
narg-- // 1.7 added an additional seq arg
|
narg-- // 1.7 added an additional seq arg
|
||||||
}
|
}
|
||||||
case EvGCSTWStart:
|
case EvSTWStart:
|
||||||
if ver < 1010 {
|
if ver < 1010 {
|
||||||
narg-- // 1.10 added an argument
|
narg-- // 1.10 added an argument
|
||||||
}
|
}
|
||||||
|
|
@ -1038,8 +1049,8 @@ const (
|
||||||
EvProcStop = 6 // stop of P [timestamp]
|
EvProcStop = 6 // stop of P [timestamp]
|
||||||
EvGCStart = 7 // GC start [timestamp, seq, stack id]
|
EvGCStart = 7 // GC start [timestamp, seq, stack id]
|
||||||
EvGCDone = 8 // GC done [timestamp]
|
EvGCDone = 8 // GC done [timestamp]
|
||||||
EvGCSTWStart = 9 // GC mark termination start [timestamp, kind]
|
EvSTWStart = 9 // GC mark termination start [timestamp, kind]
|
||||||
EvGCSTWDone = 10 // GC mark termination done [timestamp]
|
EvSTWDone = 10 // GC mark termination done [timestamp]
|
||||||
EvGCSweepStart = 11 // GC sweep start [timestamp, stack id]
|
EvGCSweepStart = 11 // GC sweep start [timestamp, stack id]
|
||||||
EvGCSweepDone = 12 // GC sweep done [timestamp, swept, reclaimed]
|
EvGCSweepDone = 12 // GC sweep done [timestamp, swept, reclaimed]
|
||||||
EvGoCreate = 13 // goroutine creation [timestamp, new goroutine id, new stack id, stack id]
|
EvGoCreate = 13 // goroutine creation [timestamp, new goroutine id, new stack id, stack id]
|
||||||
|
|
@ -1098,8 +1109,8 @@ var EventDescriptions = [EvCount]struct {
|
||||||
EvProcStop: {"ProcStop", 1005, false, []string{}, nil},
|
EvProcStop: {"ProcStop", 1005, false, []string{}, nil},
|
||||||
EvGCStart: {"GCStart", 1005, true, []string{"seq"}, nil}, // in 1.5 format it was {}
|
EvGCStart: {"GCStart", 1005, true, []string{"seq"}, nil}, // in 1.5 format it was {}
|
||||||
EvGCDone: {"GCDone", 1005, false, []string{}, nil},
|
EvGCDone: {"GCDone", 1005, false, []string{}, nil},
|
||||||
EvGCSTWStart: {"GCSTWStart", 1005, false, []string{"kindid"}, []string{"kind"}}, // <= 1.9, args was {} (implicitly {0})
|
EvSTWStart: {"STWStart", 1005, false, []string{"kindid"}, []string{"kind"}}, // <= 1.9, args was {} (implicitly {0})
|
||||||
EvGCSTWDone: {"GCSTWDone", 1005, false, []string{}, nil},
|
EvSTWDone: {"STWDone", 1005, false, []string{}, nil},
|
||||||
EvGCSweepStart: {"GCSweepStart", 1005, true, []string{}, nil},
|
EvGCSweepStart: {"GCSweepStart", 1005, true, []string{}, nil},
|
||||||
EvGCSweepDone: {"GCSweepDone", 1005, false, []string{"swept", "reclaimed"}, nil}, // before 1.9, format was {}
|
EvGCSweepDone: {"GCSweepDone", 1005, false, []string{"swept", "reclaimed"}, nil}, // before 1.9, format was {}
|
||||||
EvGoCreate: {"GoCreate", 1005, true, []string{"g", "stack"}, nil},
|
EvGoCreate: {"GoCreate", 1005, true, []string{"g", "stack"}, nil},
|
||||||
|
|
@ -1140,3 +1151,24 @@ var EventDescriptions = [EvCount]struct {
|
||||||
EvUserLog: {"UserLog", 1011, true, []string{"id", "keyid"}, []string{"category", "message"}},
|
EvUserLog: {"UserLog", 1011, true, []string{"id", "keyid"}, []string{"category", "message"}},
|
||||||
EvCPUSample: {"CPUSample", 1019, true, []string{"ts", "p", "g"}, nil},
|
EvCPUSample: {"CPUSample", 1019, true, []string{"ts", "p", "g"}, nil},
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// Copied from src/runtime/proc.go:stwReasonStrings in Go 1.21.
|
||||||
|
var stwReasonStringsGo121 = [...]string{
|
||||||
|
"unknown",
|
||||||
|
"GC mark termination",
|
||||||
|
"GC sweep termination",
|
||||||
|
"write heap dump",
|
||||||
|
"goroutine profile",
|
||||||
|
"goroutine profile cleanup",
|
||||||
|
"all goroutines stack trace",
|
||||||
|
"read mem stats",
|
||||||
|
"AllThreadsSyscall",
|
||||||
|
"GOMAXPROCS",
|
||||||
|
"start trace",
|
||||||
|
"stop trace",
|
||||||
|
"CountPagesInUse (test)",
|
||||||
|
"ReadMetricsSlow (test)",
|
||||||
|
"ReadMemStatsSlow (test)",
|
||||||
|
"PageCachePagesLeaked (test)",
|
||||||
|
"ResetDebugLog (test)",
|
||||||
|
}
|
||||||
|
|
|
||||||
|
|
@ -52,12 +52,13 @@ func TestParseCanned(t *testing.T) {
|
||||||
}
|
}
|
||||||
// Instead of Parse that requires a proper binary name for old traces,
|
// Instead of Parse that requires a proper binary name for old traces,
|
||||||
// we use 'parse' that omits symbol lookup if an empty string is given.
|
// we use 'parse' that omits symbol lookup if an empty string is given.
|
||||||
_, _, err = parse(bytes.NewReader(data), "")
|
ver, res, err := parse(bytes.NewReader(data), "")
|
||||||
switch {
|
switch {
|
||||||
case strings.HasSuffix(f.Name(), "_good"):
|
case strings.HasSuffix(f.Name(), "_good"):
|
||||||
if err != nil {
|
if err != nil {
|
||||||
t.Errorf("failed to parse good trace %v: %v", f.Name(), err)
|
t.Errorf("failed to parse good trace %v: %v", f.Name(), err)
|
||||||
}
|
}
|
||||||
|
checkTrace(t, ver, res)
|
||||||
case strings.HasSuffix(f.Name(), "_unordered"):
|
case strings.HasSuffix(f.Name(), "_unordered"):
|
||||||
if err != ErrTimeOrder {
|
if err != ErrTimeOrder {
|
||||||
t.Errorf("unordered trace is not detected %v: %v", f.Name(), err)
|
t.Errorf("unordered trace is not detected %v: %v", f.Name(), err)
|
||||||
|
|
@ -68,6 +69,18 @@ func TestParseCanned(t *testing.T) {
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// checkTrace walks over a good trace and makes a bunch of additional checks
|
||||||
|
// that may not cause the parser to outright fail.
|
||||||
|
func checkTrace(t *testing.T, ver int, res ParseResult) {
|
||||||
|
for _, ev := range res.Events {
|
||||||
|
if ver >= 1021 {
|
||||||
|
if ev.Type == EvSTWStart && ev.SArgs[0] == "unknown" {
|
||||||
|
t.Errorf("found unknown STW event; update stwReasonStrings?")
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
func TestParseVersion(t *testing.T) {
|
func TestParseVersion(t *testing.T) {
|
||||||
tests := map[string]int{
|
tests := map[string]int{
|
||||||
"go 1.5 trace\x00\x00\x00\x00": 1005,
|
"go 1.5 trace\x00\x00\x00\x00": 1005,
|
||||||
|
|
|
||||||
BIN
src/internal/trace/testdata/http_1_21_good
vendored
Normal file
BIN
src/internal/trace/testdata/http_1_21_good
vendored
Normal file
Binary file not shown.
BIN
src/internal/trace/testdata/stress_1_21_good
vendored
Normal file
BIN
src/internal/trace/testdata/stress_1_21_good
vendored
Normal file
Binary file not shown.
BIN
src/internal/trace/testdata/stress_start_stop_1_21_good
vendored
Normal file
BIN
src/internal/trace/testdata/stress_start_stop_1_21_good
vendored
Normal file
Binary file not shown.
BIN
src/internal/trace/testdata/user_task_region_1_21_good
vendored
Normal file
BIN
src/internal/trace/testdata/user_task_region_1_21_good
vendored
Normal file
Binary file not shown.
|
|
@ -25,7 +25,7 @@ func GOMAXPROCS(n int) int {
|
||||||
return ret
|
return ret
|
||||||
}
|
}
|
||||||
|
|
||||||
stopTheWorldGC("GOMAXPROCS")
|
stopTheWorldGC(stwGOMAXPROCS)
|
||||||
|
|
||||||
// newprocs will be processed by startTheWorld
|
// newprocs will be processed by startTheWorld
|
||||||
newprocs = int32(n)
|
newprocs = int32(n)
|
||||||
|
|
|
||||||
|
|
@ -35,7 +35,7 @@ func DumpDebugLog() string {
|
||||||
}
|
}
|
||||||
|
|
||||||
func ResetDebugLog() {
|
func ResetDebugLog() {
|
||||||
stopTheWorld("ResetDebugLog")
|
stopTheWorld(stwForTestResetDebugLog)
|
||||||
for l := allDloggers; l != nil; l = l.allLink {
|
for l := allDloggers; l != nil; l = l.allLink {
|
||||||
l.w.write = 0
|
l.w.write = 0
|
||||||
l.w.tick, l.w.nano = 0, 0
|
l.w.tick, l.w.nano = 0, 0
|
||||||
|
|
|
||||||
|
|
@ -276,7 +276,7 @@ var ReadUnaligned32 = readUnaligned32
|
||||||
var ReadUnaligned64 = readUnaligned64
|
var ReadUnaligned64 = readUnaligned64
|
||||||
|
|
||||||
func CountPagesInUse() (pagesInUse, counted uintptr) {
|
func CountPagesInUse() (pagesInUse, counted uintptr) {
|
||||||
stopTheWorld("CountPagesInUse")
|
stopTheWorld(stwForTestCountPagesInUse)
|
||||||
|
|
||||||
pagesInUse = uintptr(mheap_.pagesInUse.Load())
|
pagesInUse = uintptr(mheap_.pagesInUse.Load())
|
||||||
|
|
||||||
|
|
@ -319,7 +319,7 @@ func (p *ProfBuf) Close() {
|
||||||
}
|
}
|
||||||
|
|
||||||
func ReadMetricsSlow(memStats *MemStats, samplesp unsafe.Pointer, len, cap int) {
|
func ReadMetricsSlow(memStats *MemStats, samplesp unsafe.Pointer, len, cap int) {
|
||||||
stopTheWorld("ReadMetricsSlow")
|
stopTheWorld(stwForTestReadMetricsSlow)
|
||||||
|
|
||||||
// Initialize the metrics beforehand because this could
|
// Initialize the metrics beforehand because this could
|
||||||
// allocate and skew the stats.
|
// allocate and skew the stats.
|
||||||
|
|
@ -347,7 +347,7 @@ func ReadMetricsSlow(memStats *MemStats, samplesp unsafe.Pointer, len, cap int)
|
||||||
// ReadMemStatsSlow returns both the runtime-computed MemStats and
|
// ReadMemStatsSlow returns both the runtime-computed MemStats and
|
||||||
// MemStats accumulated by scanning the heap.
|
// MemStats accumulated by scanning the heap.
|
||||||
func ReadMemStatsSlow() (base, slow MemStats) {
|
func ReadMemStatsSlow() (base, slow MemStats) {
|
||||||
stopTheWorld("ReadMemStatsSlow")
|
stopTheWorld(stwForTestReadMemStatsSlow)
|
||||||
|
|
||||||
// Run on the system stack to avoid stack growth allocation.
|
// Run on the system stack to avoid stack growth allocation.
|
||||||
systemstack(func() {
|
systemstack(func() {
|
||||||
|
|
@ -1193,7 +1193,7 @@ func CheckScavengedBitsCleared(mismatches []BitsMismatch) (n int, ok bool) {
|
||||||
}
|
}
|
||||||
|
|
||||||
func PageCachePagesLeaked() (leaked uintptr) {
|
func PageCachePagesLeaked() (leaked uintptr) {
|
||||||
stopTheWorld("PageCachePagesLeaked")
|
stopTheWorld(stwForTestPageCachePagesLeaked)
|
||||||
|
|
||||||
// Walk over destroyed Ps and look for unflushed caches.
|
// Walk over destroyed Ps and look for unflushed caches.
|
||||||
deadp := allp[len(allp):cap(allp)]
|
deadp := allp[len(allp):cap(allp)]
|
||||||
|
|
|
||||||
|
|
@ -19,7 +19,7 @@ import (
|
||||||
|
|
||||||
//go:linkname runtime_debug_WriteHeapDump runtime/debug.WriteHeapDump
|
//go:linkname runtime_debug_WriteHeapDump runtime/debug.WriteHeapDump
|
||||||
func runtime_debug_WriteHeapDump(fd uintptr) {
|
func runtime_debug_WriteHeapDump(fd uintptr) {
|
||||||
stopTheWorld("write heap dump")
|
stopTheWorld(stwWriteHeapDump)
|
||||||
|
|
||||||
// Keep m on this G's stack instead of the system stack.
|
// Keep m on this G's stack instead of the system stack.
|
||||||
// Both readmemstats_m and writeheapdump_m have pretty large
|
// Both readmemstats_m and writeheapdump_m have pretty large
|
||||||
|
|
|
||||||
|
|
@ -658,10 +658,7 @@ func gcStart(trigger gcTrigger) {
|
||||||
now := nanotime()
|
now := nanotime()
|
||||||
work.tSweepTerm = now
|
work.tSweepTerm = now
|
||||||
work.pauseStart = now
|
work.pauseStart = now
|
||||||
if traceEnabled() {
|
systemstack(func() { stopTheWorldWithSema(stwGCSweepTerm) })
|
||||||
traceGCSTWStart(1)
|
|
||||||
}
|
|
||||||
systemstack(stopTheWorldWithSema)
|
|
||||||
// Finish sweep before we start concurrent scan.
|
// Finish sweep before we start concurrent scan.
|
||||||
systemstack(func() {
|
systemstack(func() {
|
||||||
finishsweep_m()
|
finishsweep_m()
|
||||||
|
|
@ -726,7 +723,7 @@ func gcStart(trigger gcTrigger) {
|
||||||
|
|
||||||
// Concurrent mark.
|
// Concurrent mark.
|
||||||
systemstack(func() {
|
systemstack(func() {
|
||||||
now = startTheWorldWithSema(traceEnabled())
|
now = startTheWorldWithSema()
|
||||||
work.pauseNS += now - work.pauseStart
|
work.pauseNS += now - work.pauseStart
|
||||||
work.tMark = now
|
work.tMark = now
|
||||||
memstats.gcPauseDist.record(now - work.pauseStart)
|
memstats.gcPauseDist.record(now - work.pauseStart)
|
||||||
|
|
@ -848,10 +845,7 @@ top:
|
||||||
work.tMarkTerm = now
|
work.tMarkTerm = now
|
||||||
work.pauseStart = now
|
work.pauseStart = now
|
||||||
getg().m.preemptoff = "gcing"
|
getg().m.preemptoff = "gcing"
|
||||||
if traceEnabled() {
|
systemstack(func() { stopTheWorldWithSema(stwGCMarkTerm) })
|
||||||
traceGCSTWStart(0)
|
|
||||||
}
|
|
||||||
systemstack(stopTheWorldWithSema)
|
|
||||||
// The gcphase is _GCmark, it will transition to _GCmarktermination
|
// The gcphase is _GCmark, it will transition to _GCmarktermination
|
||||||
// below. The important thing is that the wb remains active until
|
// below. The important thing is that the wb remains active until
|
||||||
// all marking is complete. This includes writes made by the GC.
|
// all marking is complete. This includes writes made by the GC.
|
||||||
|
|
@ -878,7 +872,7 @@ top:
|
||||||
if restart {
|
if restart {
|
||||||
getg().m.preemptoff = ""
|
getg().m.preemptoff = ""
|
||||||
systemstack(func() {
|
systemstack(func() {
|
||||||
now := startTheWorldWithSema(traceEnabled())
|
now := startTheWorldWithSema()
|
||||||
work.pauseNS += now - work.pauseStart
|
work.pauseNS += now - work.pauseStart
|
||||||
memstats.gcPauseDist.record(now - work.pauseStart)
|
memstats.gcPauseDist.record(now - work.pauseStart)
|
||||||
})
|
})
|
||||||
|
|
@ -1092,7 +1086,7 @@ func gcMarkTermination() {
|
||||||
throw("failed to set sweep barrier")
|
throw("failed to set sweep barrier")
|
||||||
}
|
}
|
||||||
|
|
||||||
systemstack(func() { startTheWorldWithSema(traceEnabled()) })
|
systemstack(func() { startTheWorldWithSema() })
|
||||||
|
|
||||||
// Flush the heap profile so we can start a new cycle next GC.
|
// Flush the heap profile so we can start a new cycle next GC.
|
||||||
// This is relatively expensive, so we don't do it with the
|
// This is relatively expensive, so we don't do it with the
|
||||||
|
|
|
||||||
|
|
@ -901,7 +901,7 @@ func goroutineProfileWithLabelsConcurrent(p []StackRecord, labels []unsafe.Point
|
||||||
|
|
||||||
ourg := getg()
|
ourg := getg()
|
||||||
|
|
||||||
stopTheWorld("profile")
|
stopTheWorld(stwGoroutineProfile)
|
||||||
// Using gcount while the world is stopped should give us a consistent view
|
// Using gcount while the world is stopped should give us a consistent view
|
||||||
// of the number of live goroutines, minus the number of goroutines that are
|
// of the number of live goroutines, minus the number of goroutines that are
|
||||||
// alive and permanently marked as "system". But to make this count agree
|
// alive and permanently marked as "system". But to make this count agree
|
||||||
|
|
@ -966,7 +966,7 @@ func goroutineProfileWithLabelsConcurrent(p []StackRecord, labels []unsafe.Point
|
||||||
tryRecordGoroutineProfile(gp1, Gosched)
|
tryRecordGoroutineProfile(gp1, Gosched)
|
||||||
})
|
})
|
||||||
|
|
||||||
stopTheWorld("profile cleanup")
|
stopTheWorld(stwGoroutineProfileCleanup)
|
||||||
endOffset := goroutineProfile.offset.Swap(0)
|
endOffset := goroutineProfile.offset.Swap(0)
|
||||||
goroutineProfile.active = false
|
goroutineProfile.active = false
|
||||||
goroutineProfile.records = nil
|
goroutineProfile.records = nil
|
||||||
|
|
@ -1101,7 +1101,7 @@ func goroutineProfileWithLabelsSync(p []StackRecord, labels []unsafe.Pointer) (n
|
||||||
return gp1 != gp && readgstatus(gp1) != _Gdead && !isSystemGoroutine(gp1, false)
|
return gp1 != gp && readgstatus(gp1) != _Gdead && !isSystemGoroutine(gp1, false)
|
||||||
}
|
}
|
||||||
|
|
||||||
stopTheWorld("profile")
|
stopTheWorld(stwGoroutineProfile)
|
||||||
|
|
||||||
// World is stopped, no locking required.
|
// World is stopped, no locking required.
|
||||||
n = 1
|
n = 1
|
||||||
|
|
@ -1187,7 +1187,7 @@ func saveg(pc, sp uintptr, gp *g, r *StackRecord) {
|
||||||
// into buf after the trace for the current goroutine.
|
// into buf after the trace for the current goroutine.
|
||||||
func Stack(buf []byte, all bool) int {
|
func Stack(buf []byte, all bool) int {
|
||||||
if all {
|
if all {
|
||||||
stopTheWorld("stack trace")
|
stopTheWorld(stwAllGoroutinesStack)
|
||||||
}
|
}
|
||||||
|
|
||||||
n := 0
|
n := 0
|
||||||
|
|
|
||||||
|
|
@ -347,7 +347,7 @@ func init() {
|
||||||
// which is a snapshot as of the most recently completed garbage
|
// which is a snapshot as of the most recently completed garbage
|
||||||
// collection cycle.
|
// collection cycle.
|
||||||
func ReadMemStats(m *MemStats) {
|
func ReadMemStats(m *MemStats) {
|
||||||
stopTheWorld("read mem stats")
|
stopTheWorld(stwReadMemStats)
|
||||||
|
|
||||||
systemstack(func() {
|
systemstack(func() {
|
||||||
readmemstats_m(m)
|
readmemstats_m(m)
|
||||||
|
|
|
||||||
|
|
@ -739,7 +739,7 @@ func syscall_runtime_doAllThreadsSyscall(trap, a1, a2, a3, a4, a5, a6 uintptr) (
|
||||||
// N.B. Internally, this function does not depend on STW to
|
// N.B. Internally, this function does not depend on STW to
|
||||||
// successfully change every thread. It is only needed for user
|
// successfully change every thread. It is only needed for user
|
||||||
// expectations, per above.
|
// expectations, per above.
|
||||||
stopTheWorld("doAllThreadsSyscall")
|
stopTheWorld(stwAllThreadsSyscall)
|
||||||
|
|
||||||
// This function depends on several properties:
|
// This function depends on several properties:
|
||||||
//
|
//
|
||||||
|
|
|
||||||
|
|
@ -1157,6 +1157,59 @@ func casGFromPreempted(gp *g, old, new uint32) bool {
|
||||||
return gp.atomicstatus.CompareAndSwap(_Gpreempted, _Gwaiting)
|
return gp.atomicstatus.CompareAndSwap(_Gpreempted, _Gwaiting)
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// stwReason is an enumeration of reasons the world is stopping.
|
||||||
|
type stwReason uint8
|
||||||
|
|
||||||
|
// Reasons to stop-the-world.
|
||||||
|
//
|
||||||
|
// Avoid reusing reasons and add new ones instead.
|
||||||
|
const (
|
||||||
|
stwUnknown stwReason = iota // "unknown"
|
||||||
|
stwGCMarkTerm // "GC mark termination"
|
||||||
|
stwGCSweepTerm // "GC sweep termination"
|
||||||
|
stwWriteHeapDump // "write heap dump"
|
||||||
|
stwGoroutineProfile // "goroutine profile"
|
||||||
|
stwGoroutineProfileCleanup // "goroutine profile cleanup"
|
||||||
|
stwAllGoroutinesStack // "all goroutines stack trace"
|
||||||
|
stwReadMemStats // "read mem stats"
|
||||||
|
stwAllThreadsSyscall // "AllThreadsSyscall"
|
||||||
|
stwGOMAXPROCS // "GOMAXPROCS"
|
||||||
|
stwStartTrace // "start trace"
|
||||||
|
stwStopTrace // "stop trace"
|
||||||
|
stwForTestCountPagesInUse // "CountPagesInUse (test)"
|
||||||
|
stwForTestReadMetricsSlow // "ReadMetricsSlow (test)"
|
||||||
|
stwForTestReadMemStatsSlow // "ReadMemStatsSlow (test)"
|
||||||
|
stwForTestPageCachePagesLeaked // "PageCachePagesLeaked (test)"
|
||||||
|
stwForTestResetDebugLog // "ResetDebugLog (test)"
|
||||||
|
)
|
||||||
|
|
||||||
|
func (r stwReason) String() string {
|
||||||
|
return stwReasonStrings[r]
|
||||||
|
}
|
||||||
|
|
||||||
|
// If you add to this list, also add it to src/internal/trace/parser.go.
|
||||||
|
// If you change the values of any of the stw* constants, bump the trace
|
||||||
|
// version number and make a copy of this.
|
||||||
|
var stwReasonStrings = [...]string{
|
||||||
|
stwUnknown: "unknown",
|
||||||
|
stwGCMarkTerm: "GC mark termination",
|
||||||
|
stwGCSweepTerm: "GC sweep termination",
|
||||||
|
stwWriteHeapDump: "write heap dump",
|
||||||
|
stwGoroutineProfile: "goroutine profile",
|
||||||
|
stwGoroutineProfileCleanup: "goroutine profile cleanup",
|
||||||
|
stwAllGoroutinesStack: "all goroutines stack trace",
|
||||||
|
stwReadMemStats: "read mem stats",
|
||||||
|
stwAllThreadsSyscall: "AllThreadsSyscall",
|
||||||
|
stwGOMAXPROCS: "GOMAXPROCS",
|
||||||
|
stwStartTrace: "start trace",
|
||||||
|
stwStopTrace: "stop trace",
|
||||||
|
stwForTestCountPagesInUse: "CountPagesInUse (test)",
|
||||||
|
stwForTestReadMetricsSlow: "ReadMetricsSlow (test)",
|
||||||
|
stwForTestReadMemStatsSlow: "ReadMemStatsSlow (test)",
|
||||||
|
stwForTestPageCachePagesLeaked: "PageCachePagesLeaked (test)",
|
||||||
|
stwForTestResetDebugLog: "ResetDebugLog (test)",
|
||||||
|
}
|
||||||
|
|
||||||
// stopTheWorld stops all P's from executing goroutines, interrupting
|
// stopTheWorld stops all P's from executing goroutines, interrupting
|
||||||
// all goroutines at GC safe points and records reason as the reason
|
// all goroutines at GC safe points and records reason as the reason
|
||||||
// for the stop. On return, only the current goroutine's P is running.
|
// for the stop. On return, only the current goroutine's P is running.
|
||||||
|
|
@ -1171,10 +1224,10 @@ func casGFromPreempted(gp *g, old, new uint32) bool {
|
||||||
// This is also used by routines that do stack dumps. If the system is
|
// This is also used by routines that do stack dumps. If the system is
|
||||||
// in panic or being exited, this may not reliably stop all
|
// in panic or being exited, this may not reliably stop all
|
||||||
// goroutines.
|
// goroutines.
|
||||||
func stopTheWorld(reason string) {
|
func stopTheWorld(reason stwReason) {
|
||||||
semacquire(&worldsema)
|
semacquire(&worldsema)
|
||||||
gp := getg()
|
gp := getg()
|
||||||
gp.m.preemptoff = reason
|
gp.m.preemptoff = reason.String()
|
||||||
systemstack(func() {
|
systemstack(func() {
|
||||||
// Mark the goroutine which called stopTheWorld preemptible so its
|
// Mark the goroutine which called stopTheWorld preemptible so its
|
||||||
// stack may be scanned.
|
// stack may be scanned.
|
||||||
|
|
@ -1188,14 +1241,14 @@ func stopTheWorld(reason string) {
|
||||||
// have already completed by the time we exit.
|
// have already completed by the time we exit.
|
||||||
// Don't provide a wait reason because we're still executing.
|
// Don't provide a wait reason because we're still executing.
|
||||||
casGToWaiting(gp, _Grunning, waitReasonStoppingTheWorld)
|
casGToWaiting(gp, _Grunning, waitReasonStoppingTheWorld)
|
||||||
stopTheWorldWithSema()
|
stopTheWorldWithSema(reason)
|
||||||
casgstatus(gp, _Gwaiting, _Grunning)
|
casgstatus(gp, _Gwaiting, _Grunning)
|
||||||
})
|
})
|
||||||
}
|
}
|
||||||
|
|
||||||
// startTheWorld undoes the effects of stopTheWorld.
|
// startTheWorld undoes the effects of stopTheWorld.
|
||||||
func startTheWorld() {
|
func startTheWorld() {
|
||||||
systemstack(func() { startTheWorldWithSema(false) })
|
systemstack(func() { startTheWorldWithSema() })
|
||||||
|
|
||||||
// worldsema must be held over startTheWorldWithSema to ensure
|
// worldsema must be held over startTheWorldWithSema to ensure
|
||||||
// gomaxprocs cannot change while worldsema is held.
|
// gomaxprocs cannot change while worldsema is held.
|
||||||
|
|
@ -1221,7 +1274,7 @@ func startTheWorld() {
|
||||||
// stopTheWorldGC has the same effect as stopTheWorld, but blocks
|
// stopTheWorldGC has the same effect as stopTheWorld, but blocks
|
||||||
// until the GC is not running. It also blocks a GC from starting
|
// until the GC is not running. It also blocks a GC from starting
|
||||||
// until startTheWorldGC is called.
|
// until startTheWorldGC is called.
|
||||||
func stopTheWorldGC(reason string) {
|
func stopTheWorldGC(reason stwReason) {
|
||||||
semacquire(&gcsema)
|
semacquire(&gcsema)
|
||||||
stopTheWorld(reason)
|
stopTheWorld(reason)
|
||||||
}
|
}
|
||||||
|
|
@ -1265,7 +1318,10 @@ var gcsema uint32 = 1
|
||||||
// startTheWorldWithSema and stopTheWorldWithSema.
|
// startTheWorldWithSema and stopTheWorldWithSema.
|
||||||
// Holding worldsema causes any other goroutines invoking
|
// Holding worldsema causes any other goroutines invoking
|
||||||
// stopTheWorld to block.
|
// stopTheWorld to block.
|
||||||
func stopTheWorldWithSema() {
|
func stopTheWorldWithSema(reason stwReason) {
|
||||||
|
if traceEnabled() {
|
||||||
|
traceSTWStart(reason)
|
||||||
|
}
|
||||||
gp := getg()
|
gp := getg()
|
||||||
|
|
||||||
// If we hold a lock, then we won't be able to stop another M
|
// If we hold a lock, then we won't be able to stop another M
|
||||||
|
|
@ -1344,7 +1400,7 @@ func stopTheWorldWithSema() {
|
||||||
worldStopped()
|
worldStopped()
|
||||||
}
|
}
|
||||||
|
|
||||||
func startTheWorldWithSema(emitTraceEvent bool) int64 {
|
func startTheWorldWithSema() int64 {
|
||||||
assertWorldStopped()
|
assertWorldStopped()
|
||||||
|
|
||||||
mp := acquirem() // disable preemption because it can be holding p in a local var
|
mp := acquirem() // disable preemption because it can be holding p in a local var
|
||||||
|
|
@ -1388,8 +1444,8 @@ func startTheWorldWithSema(emitTraceEvent bool) int64 {
|
||||||
|
|
||||||
// Capture start-the-world time before doing clean-up tasks.
|
// Capture start-the-world time before doing clean-up tasks.
|
||||||
startTime := nanotime()
|
startTime := nanotime()
|
||||||
if emitTraceEvent {
|
if traceEnabled() {
|
||||||
traceGCSTWDone()
|
traceSTWDone()
|
||||||
}
|
}
|
||||||
|
|
||||||
// Wakeup an additional proc in case we have excessive runnable goroutines
|
// Wakeup an additional proc in case we have excessive runnable goroutines
|
||||||
|
|
|
||||||
|
|
@ -31,8 +31,8 @@ const (
|
||||||
traceEvProcStop = 6 // stop of P [timestamp]
|
traceEvProcStop = 6 // stop of P [timestamp]
|
||||||
traceEvGCStart = 7 // GC start [timestamp, seq, stack id]
|
traceEvGCStart = 7 // GC start [timestamp, seq, stack id]
|
||||||
traceEvGCDone = 8 // GC done [timestamp]
|
traceEvGCDone = 8 // GC done [timestamp]
|
||||||
traceEvGCSTWStart = 9 // GC STW start [timestamp, kind]
|
traceEvSTWStart = 9 // STW start [timestamp, kind]
|
||||||
traceEvGCSTWDone = 10 // GC STW done [timestamp]
|
traceEvSTWDone = 10 // STW done [timestamp]
|
||||||
traceEvGCSweepStart = 11 // GC sweep start [timestamp, stack id]
|
traceEvGCSweepStart = 11 // GC sweep start [timestamp, stack id]
|
||||||
traceEvGCSweepDone = 12 // GC sweep done [timestamp, swept, reclaimed]
|
traceEvGCSweepDone = 12 // GC sweep done [timestamp, swept, reclaimed]
|
||||||
traceEvGoCreate = 13 // goroutine creation [timestamp, new goroutine id, new stack id, stack id]
|
traceEvGoCreate = 13 // goroutine creation [timestamp, new goroutine id, new stack id, stack id]
|
||||||
|
|
@ -171,7 +171,8 @@ type gTraceState struct {
|
||||||
|
|
||||||
// mTraceState is per-M state for the tracer.
|
// mTraceState is per-M state for the tracer.
|
||||||
type mTraceState struct {
|
type mTraceState struct {
|
||||||
startingTrace bool // this M is in TraceStart, potentially before traceEnabled is true
|
startingTrace bool // this M is in TraceStart, potentially before traceEnabled is true
|
||||||
|
tracedSTWStart bool // this M traced a STW start, so it should trace an end
|
||||||
}
|
}
|
||||||
|
|
||||||
// pTraceState is per-P state for the tracer.
|
// pTraceState is per-P state for the tracer.
|
||||||
|
|
@ -247,7 +248,7 @@ func StartTrace() error {
|
||||||
// Do not stop the world during GC so we ensure we always see
|
// Do not stop the world during GC so we ensure we always see
|
||||||
// a consistent view of GC-related events (e.g. a start is always
|
// a consistent view of GC-related events (e.g. a start is always
|
||||||
// paired with an end).
|
// paired with an end).
|
||||||
stopTheWorldGC("start tracing")
|
stopTheWorldGC(stwStartTrace)
|
||||||
|
|
||||||
// Prevent sysmon from running any code that could generate events.
|
// Prevent sysmon from running any code that could generate events.
|
||||||
lock(&sched.sysmonlock)
|
lock(&sched.sysmonlock)
|
||||||
|
|
@ -377,7 +378,7 @@ func StartTrace() error {
|
||||||
func StopTrace() {
|
func StopTrace() {
|
||||||
// Stop the world so that we can collect the trace buffers from all p's below,
|
// Stop the world so that we can collect the trace buffers from all p's below,
|
||||||
// and also to avoid races with traceEvent.
|
// and also to avoid races with traceEvent.
|
||||||
stopTheWorldGC("stop tracing")
|
stopTheWorldGC(stwStopTrace)
|
||||||
|
|
||||||
// See the comment in StartTrace.
|
// See the comment in StartTrace.
|
||||||
lock(&sched.sysmonlock)
|
lock(&sched.sysmonlock)
|
||||||
|
|
@ -560,7 +561,7 @@ func readTrace0() (buf []byte, park bool) {
|
||||||
trace.headerWritten = true
|
trace.headerWritten = true
|
||||||
trace.lockOwner = nil
|
trace.lockOwner = nil
|
||||||
unlock(&trace.lock)
|
unlock(&trace.lock)
|
||||||
return []byte("go 1.19 trace\x00\x00\x00"), false
|
return []byte("go 1.21 trace\x00\x00\x00"), false
|
||||||
}
|
}
|
||||||
// Optimistically look for CPU profile samples. This may write new stack
|
// Optimistically look for CPU profile samples. This may write new stack
|
||||||
// records, and may write new tracing buffers.
|
// records, and may write new tracing buffers.
|
||||||
|
|
@ -1485,12 +1486,23 @@ func traceGCDone() {
|
||||||
traceEvent(traceEvGCDone, -1)
|
traceEvent(traceEvGCDone, -1)
|
||||||
}
|
}
|
||||||
|
|
||||||
func traceGCSTWStart(kind int) {
|
func traceSTWStart(reason stwReason) {
|
||||||
traceEvent(traceEvGCSTWStart, -1, uint64(kind))
|
// Don't trace if this STW is for trace start/stop, since traceEnabled
|
||||||
|
// switches during a STW.
|
||||||
|
if reason == stwStartTrace || reason == stwStopTrace {
|
||||||
|
return
|
||||||
|
}
|
||||||
|
getg().m.trace.tracedSTWStart = true
|
||||||
|
traceEvent(traceEvSTWStart, -1, uint64(reason))
|
||||||
}
|
}
|
||||||
|
|
||||||
func traceGCSTWDone() {
|
func traceSTWDone() {
|
||||||
traceEvent(traceEvGCSTWDone, -1)
|
mp := getg().m
|
||||||
|
if !mp.trace.tracedSTWStart {
|
||||||
|
return
|
||||||
|
}
|
||||||
|
mp.trace.tracedSTWStart = false
|
||||||
|
traceEvent(traceEvSTWDone, -1)
|
||||||
}
|
}
|
||||||
|
|
||||||
// traceGCSweepStart prepares to trace a sweep loop. This does not
|
// traceGCSweepStart prepares to trace a sweep loop. This does not
|
||||||
|
|
|
||||||
Loading…
Add table
Add a link
Reference in a new issue