mirror
/
go
mirror of https://github.com/golang/go.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

internal/trace: remove remnanats of v1 tracer 

This change removes unused parts of the v1 tracer in preperation of
the move of the v2 tracer into the trace package.

Updates #67367

Change-Id: I3e53a8afdef72dc90c2d5b514380d1077d284bc7
Reviewed-on: https://go-review.googlesource.com/c/go/+/584537
Reviewed-by: Michael Knyszek <mknyszek@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
This commit is contained in:
Carlos Amedee 2024-05-07 15:37:10 -04:00
parent e95f6af008
commit 664088b898
36 changed files with 11 additions and 2241 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

158
src/internal/trace/gc.go
View File

@ -45,164 +45,6 @@ const (
UtilPerProc
)
// MutatorUtilization returns a set of mutator utilization functions
// for the given trace. Each function will always end with 0
// utilization. The bounds of each function are implicit in the first
// and last event; outside of these bounds each function is undefined.
//
// If the UtilPerProc flag is not given, this always returns a single
// utilization function. Otherwise, it returns one function per P.
func MutatorUtilization(events []*Event, flags UtilFlags) [][]MutatorUtil {
if len(events) == 0 {
return nil
}
type perP struct {
// gc > 0 indicates that GC is active on this P.
gc int
// series the logical series number for this P. This
// is necessary because Ps may be removed and then
// re-added, and then the new P needs a new series.
series int
}
ps := []perP{}
stw := 0
out := [][]MutatorUtil{}
assists := map[uint64]bool{}
block := map[uint64]*Event{}
bgMark := map[uint64]bool{}
for _, ev := range events {
switch ev.Type {
case EvGomaxprocs:
gomaxprocs := int(ev.Args[0])
if len(ps) > gomaxprocs {
if flags&UtilPerProc != 0 {
// End each P's series.
for _, p := range ps[gomaxprocs:] {
out[p.series] = addUtil(out[p.series], MutatorUtil{ev.Ts, 0})
}
}
ps = ps[:gomaxprocs]
}
for len(ps) < gomaxprocs {
// Start new P's series.
series := 0
if flags&UtilPerProc != 0 || len(out) == 0 {
series = len(out)
out = append(out, []MutatorUtil{{ev.Ts, 1}})
}
ps = append(ps, perP{series: series})
}
case EvSTWStart:
if flags&UtilSTW != 0 {
stw++
}
case EvSTWDone:
if flags&UtilSTW != 0 {
stw--
}
case EvGCMarkAssistStart:
if flags&UtilAssist != 0 {
ps[ev.P].gc++
assists[ev.G] = true
}
case EvGCMarkAssistDone:
if flags&UtilAssist != 0 {
ps[ev.P].gc--
delete(assists, ev.G)
}
case EvGCSweepStart:
if flags&UtilSweep != 0 {
ps[ev.P].gc++
}
case EvGCSweepDone:
if flags&UtilSweep != 0 {
ps[ev.P].gc--
}
case EvGoStartLabel:
if flags&UtilBackground != 0 && strings.HasPrefix(ev.SArgs[0], "GC ") && ev.SArgs[0] != "GC (idle)" {
// Background mark worker.
//
// If we're in per-proc mode, we don't
// count dedicated workers because
// they kick all of the goroutines off
// that P, so don't directly
// contribute to goroutine latency.
if !(flags&UtilPerProc != 0 && ev.SArgs[0] == "GC (dedicated)") {
bgMark[ev.G] = true
ps[ev.P].gc++
}
}
fallthrough
case EvGoStart:
if assists[ev.G] {
// Unblocked during assist.
ps[ev.P].gc++
}
block[ev.G] = ev.Link
default:
if ev != block[ev.G] {
continue
}
if assists[ev.G] {
// Blocked during assist.
ps[ev.P].gc--
}
if bgMark[ev.G] {
// Background mark worker done.
ps[ev.P].gc--
delete(bgMark, ev.G)
}
delete(block, ev.G)
}
if flags&UtilPerProc == 0 {
// Compute the current average utilization.
if len(ps) == 0 {
continue
}
gcPs := 0
if stw > 0 {
gcPs = len(ps)
} else {
for i := range ps {
if ps[i].gc > 0 {
gcPs++
}
}
}
mu := MutatorUtil{ev.Ts, 1 - float64(gcPs)/float64(len(ps))}
// Record the utilization change. (Since
// len(ps) == len(out), we know len(out) > 0.)
out[0] = addUtil(out[0], mu)
} else {
// Check for per-P utilization changes.
for i := range ps {
p := &ps[i]
util := 1.0
if stw > 0 || p.gc > 0 {
util = 0.0
}
out[p.series] = addUtil(out[p.series], MutatorUtil{ev.Ts, util})
}
}
}
// Add final 0 utilization event to any remaining series. This
// is important to mark the end of the trace. The exact value
// shouldn't matter since no window should extend beyond this,
// but using 0 is symmetric with the start of the trace.
mu := MutatorUtil{events[len(events)-1].Ts, 0}
for i := range ps {
out[ps[i].series] = addUtil(out[ps[i].series], mu)
}
return out
}
// MutatorUtilizationV2 returns a set of mutator utilization functions
// for the given v2 trace, passed as an io.Reader. Each function will
// always end with 0 utilization. The bounds of each function are implicit

37
src/internal/trace/gc_test.go
View File

@ -5,12 +5,10 @@
package trace
import (
"bytes"
tracev2 "internal/trace/v2"
"internal/trace/v2/testtrace"
"io"
"math"
"os"
"testing"
"time"
)
@ -118,17 +116,6 @@ func TestMMUTrace(t *testing.T) {
}
}
}
t.Run("V1", func(t *testing.T) {
data, err := os.ReadFile("testdata/stress_1_10_good")
if err != nil {
t.Fatalf("failed to read input file: %v", err)
}
events, err := Parse(bytes.NewReader(data), "")
if err != nil {
t.Fatalf("failed to parse trace: %s", err)
}
check(t, MutatorUtilization(events.Events, UtilSTW|UtilBackground|UtilAssist))
})
t.Run("V2", func(t *testing.T) {
testPath := "v2/testdata/tests/go122-gc-stress.test"
r, _, err := testtrace.ParseFile(testPath)
@ -155,30 +142,6 @@ func TestMMUTrace(t *testing.T) {
})
}
func BenchmarkMMU(b *testing.B) {
data, err := os.ReadFile("testdata/stress_1_10_good")
if err != nil {
b.Fatalf("failed to read input file: %v", err)
}
events, err := Parse(bytes.NewReader(data), "")
if err != nil {
b.Fatalf("failed to parse trace: %s", err)
}
mu := MutatorUtilization(events.Events, UtilSTW|UtilBackground|UtilAssist|UtilSweep)
b.ResetTimer()
for i := 0; i < b.N; i++ {
mmuCurve := NewMMUCurve(mu)
xMin, xMax := time.Microsecond, time.Second
logMin, logMax := math.Log(float64(xMin)), math.Log(float64(xMax))
const samples = 100
for i := 0; i < samples; i++ {
window := time.Duration(math.Exp(float64(i)/(samples-1)*(logMax-logMin) + logMin))
mmuCurve.MMU(window)
}
}
}
func mmuSlow(util []MutatorUtil, window time.Duration) (mmu float64) {
if max := time.Duration(util[len(util)-1].Time - util[0].Time); window > max {
window = max

358
src/internal/trace/goroutines.go
View File

@ -1,358 +0,0 @@
// Copyright 2014 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package trace
import (
"sort"
"strings"
)
// GDesc contains statistics and execution details of a single goroutine.
type GDesc struct {
ID uint64
Name string
PC uint64
CreationTime int64
StartTime int64
EndTime int64
// List of regions in the goroutine, sorted based on the start time.
Regions []*UserRegionDesc
// Statistics of execution time during the goroutine execution.
GExecutionStat
*gdesc // private part.
}
// UserRegionDesc represents a region and goroutine execution stats
// while the region was active.
type UserRegionDesc struct {
TaskID uint64
Name string
// Region start event. Normally EvUserRegion start event or nil,
// but can be EvGoCreate event if the region is a synthetic
// region representing task inheritance from the parent goroutine.
Start *Event
// Region end event. Normally EvUserRegion end event or nil,
// but can be EvGoStop or EvGoEnd event if the goroutine
// terminated without explicitly ending the region.
End *Event
GExecutionStat
}
// GExecutionStat contains statistics about a goroutine's execution
// during a period of time.
type GExecutionStat struct {
ExecTime int64
SchedWaitTime int64
IOTime int64
BlockTime int64
SyscallTime int64
GCTime int64
SweepTime int64
TotalTime int64
}
// sub returns the stats v-s.
func (s GExecutionStat) sub(v GExecutionStat) (r GExecutionStat) {
r = s
r.ExecTime -= v.ExecTime
r.SchedWaitTime -= v.SchedWaitTime
r.IOTime -= v.IOTime
r.BlockTime -= v.BlockTime
r.SyscallTime -= v.SyscallTime
r.GCTime -= v.GCTime
r.SweepTime -= v.SweepTime
r.TotalTime -= v.TotalTime
return r
}
// snapshotStat returns the snapshot of the goroutine execution statistics.
// This is called as we process the ordered trace event stream. lastTs and
// activeGCStartTime are used to process pending statistics if this is called
// before any goroutine end event.
func (g *GDesc) snapshotStat(lastTs, activeGCStartTime int64) (ret GExecutionStat) {
ret = g.GExecutionStat
if g.gdesc == nil {
return ret // finalized GDesc. No pending state.
}
if activeGCStartTime != 0 { // terminating while GC is active
if g.CreationTime < activeGCStartTime {
ret.GCTime += lastTs - activeGCStartTime
} else {
// The goroutine's lifetime completely overlaps
// with a GC.
ret.GCTime += lastTs - g.CreationTime
}
}
if g.TotalTime == 0 {
ret.TotalTime = lastTs - g.CreationTime
}
if g.lastStartTime != 0 {
ret.ExecTime += lastTs - g.lastStartTime
}
if g.blockNetTime != 0 {
ret.IOTime += lastTs - g.blockNetTime
}
if g.blockSyncTime != 0 {
ret.BlockTime += lastTs - g.blockSyncTime
}
if g.blockSyscallTime != 0 {
ret.SyscallTime += lastTs - g.blockSyscallTime
}
if g.blockSchedTime != 0 {
ret.SchedWaitTime += lastTs - g.blockSchedTime
}
if g.blockSweepTime != 0 {
ret.SweepTime += lastTs - g.blockSweepTime
}
return ret
}
// finalize is called when processing a goroutine end event or at
// the end of trace processing. This finalizes the execution stat
// and any active regions in the goroutine, in which case trigger is nil.
func (g *GDesc) finalize(lastTs, activeGCStartTime int64, trigger *Event) {
if trigger != nil {
g.EndTime = trigger.Ts
}
finalStat := g.snapshotStat(lastTs, activeGCStartTime)
g.GExecutionStat = finalStat
// System goroutines are never part of regions, even though they
// "inherit" a task due to creation (EvGoCreate) from within a region.
// This may happen e.g. if the first GC is triggered within a region,
// starting the GC worker goroutines.
if !IsSystemGoroutine(g.Name) {
for _, s := range g.activeRegions {
s.End = trigger
s.GExecutionStat = finalStat.sub(s.GExecutionStat)
g.Regions = append(g.Regions, s)
}
}
*(g.gdesc) = gdesc{}
}
// gdesc is a private part of GDesc that is required only during analysis.
type gdesc struct {
lastStartTime int64
blockNetTime int64
blockSyncTime int64
blockSyscallTime int64
blockSweepTime int64
blockGCTime int64
blockSchedTime int64
activeRegions []*UserRegionDesc // stack of active regions
}
// GoroutineStats generates statistics for all goroutines in the trace.
func GoroutineStats(events []*Event) map[uint64]*GDesc {
gs := make(map[uint64]*GDesc)
var lastTs int64
var gcStartTime int64 // gcStartTime == 0 indicates gc is inactive.
for _, ev := range events {
lastTs = ev.Ts
switch ev.Type {
case EvGoCreate:
g := &GDesc{ID: ev.Args[0], CreationTime: ev.Ts, gdesc: new(gdesc)}
g.blockSchedTime = ev.Ts
// When a goroutine is newly created, inherit the task
// of the active region. For ease handling of this
// case, we create a fake region description with the
// task id. This isn't strictly necessary as this
// goroutine may not be associated with the task, but
// it can be convenient to see all children created
// during a region.
if creatorG := gs[ev.G]; creatorG != nil && len(creatorG.gdesc.activeRegions) > 0 {
regions := creatorG.gdesc.activeRegions
s := regions[len(regions)-1]
if s.TaskID != 0 {
g.gdesc.activeRegions = []*UserRegionDesc{
{TaskID: s.TaskID, Start: ev},
}
}
}
gs[g.ID] = g
case EvGoStart, EvGoStartLabel:
g := gs[ev.G]
if g.PC == 0 && len(ev.Stk) > 0 {
g.PC = ev.Stk[0].PC
g.Name = ev.Stk[0].Fn
}
g.lastStartTime = ev.Ts
if g.StartTime == 0 {
g.StartTime = ev.Ts
}
if g.blockSchedTime != 0 {
g.SchedWaitTime += ev.Ts - g.blockSchedTime
g.blockSchedTime = 0
}
case EvGoEnd, EvGoStop:
g := gs[ev.G]
g.finalize(ev.Ts, gcStartTime, ev)
case EvGoBlockSend, EvGoBlockRecv, EvGoBlockSelect,
EvGoBlockSync, EvGoBlockCond:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockSyncTime = ev.Ts
case EvGoSched, EvGoPreempt:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockSchedTime = ev.Ts
case EvGoSleep, EvGoBlock:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
case EvGoBlockNet:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockNetTime = ev.Ts
case EvGoBlockGC:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockGCTime = ev.Ts
case EvGoUnblock:
g := gs[ev.Args[0]]
if g.blockNetTime != 0 {
g.IOTime += ev.Ts - g.blockNetTime
g.blockNetTime = 0
}
if g.blockSyncTime != 0 {
g.BlockTime += ev.Ts - g.blockSyncTime
g.blockSyncTime = 0
}
g.blockSchedTime = ev.Ts
case EvGoSysBlock:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockSyscallTime = ev.Ts
case EvGoSysExit:
g := gs[ev.G]
if g.blockSyscallTime != 0 {
g.SyscallTime += ev.Ts - g.blockSyscallTime
g.blockSyscallTime = 0
}
g.blockSchedTime = ev.Ts
case EvGCSweepStart:
g := gs[ev.G]
if g != nil {
// Sweep can happen during GC on system goroutine.
g.blockSweepTime = ev.Ts
}
case EvGCSweepDone:
g := gs[ev.G]
if g != nil && g.blockSweepTime != 0 {
g.SweepTime += ev.Ts - g.blockSweepTime
g.blockSweepTime = 0
}
case EvGCStart:
gcStartTime = ev.Ts
case EvGCDone:
for _, g := range gs {
if g.EndTime != 0 {
continue
}
if gcStartTime < g.CreationTime {
g.GCTime += ev.Ts - g.CreationTime
} else {
g.GCTime += ev.Ts - gcStartTime
}
}
gcStartTime = 0 // indicates gc is inactive.
case EvUserRegion:
g := gs[ev.G]
switch mode := ev.Args[1]; mode {
case 0: // region start
g.activeRegions = append(g.activeRegions, &UserRegionDesc{
Name: ev.SArgs[0],
TaskID: ev.Args[0],
Start: ev,
GExecutionStat: g.snapshotStat(lastTs, gcStartTime),
})
case 1: // region end
var sd *UserRegionDesc
if regionStk := g.activeRegions; len(regionStk) > 0 {
n := len(regionStk)
sd = regionStk[n-1]
regionStk = regionStk[:n-1] // pop
g.activeRegions = regionStk
} else {
sd = &UserRegionDesc{
Name: ev.SArgs[0],
TaskID: ev.Args[0],
}
}
sd.GExecutionStat = g.snapshotStat(lastTs, gcStartTime).sub(sd.GExecutionStat)
sd.End = ev
g.Regions = append(g.Regions, sd)
}
}
}
for _, g := range gs {
g.finalize(lastTs, gcStartTime, nil)
// sort based on region start time
sort.Slice(g.Regions, func(i, j int) bool {
x := g.Regions[i].Start
y := g.Regions[j].Start
if x == nil {
return true
}
if y == nil {
return false
}
return x.Ts < y.Ts
})
g.gdesc = nil
}
return gs
}
// RelatedGoroutines finds a set of goroutines related to goroutine goid.
func RelatedGoroutines(events []*Event, goid uint64) map[uint64]bool {
// BFS of depth 2 over "unblock" edges
// (what goroutines unblock goroutine goid?).
gmap := make(map[uint64]bool)
gmap[goid] = true
for i := 0; i < 2; i++ {
gmap1 := make(map[uint64]bool)
for g := range gmap {
gmap1[g] = true
}
for _, ev := range events {
if ev.Type == EvGoUnblock && gmap[ev.Args[0]] {
gmap1[ev.G] = true
}
}
gmap = gmap1
}
gmap[0] = true // for GC events
return gmap
}
func IsSystemGoroutine(entryFn string) bool {
// This mimics runtime.isSystemGoroutine as closely as
// possible.
// Also, locked g in extra M (with empty entryFn) is system goroutine.
return entryFn == "" || entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.")
}

20
src/internal/trace/mkcanned.bash
View File

@ -1,20 +0,0 @@
#!/usr/bin/env bash
# Copyright 2016 The Go Authors. All rights reserved.
# Use of this source code is governed by a BSD-style
# license that can be found in the LICENSE file.
# mkcanned.bash creates canned traces for the trace test suite using
# the current Go version.
set -e
if [ $# != 1 ]; then
echo "usage: $0 <label>" >&2
exit 1
fi
go test -run '^$' -bench ClientServerParallel4 -benchtime 10x -trace "testdata/http_$1_good" net/http
go test -run 'TraceStress$|TraceStressStartStop$|TestUserTaskRegion$' runtime/trace -savetraces
mv ../../runtime/trace/TestTraceStress.trace "testdata/stress_$1_good"
mv ../../runtime/trace/TestTraceStressStartStop.trace "testdata/stress_start_stop_$1_good"
mv ../../runtime/trace/TestUserTaskRegion.trace "testdata/user_task_region_$1_good"

285
src/internal/trace/order.go
View File

@ -1,285 +0,0 @@
// Copyright 2016 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package trace
import (
"fmt"
"sort"
)
type eventBatch struct {
events []*Event
selected bool
}
type orderEvent struct {
ev *Event
batch int
g uint64
init gState
next gState
}
type gStatus int
type gState struct {
seq uint64
status gStatus
}
const (
gDead gStatus = iota
gRunnable
gRunning
gWaiting
unordered = ^uint64(0)
garbage = ^uint64(0) - 1
noseq = ^uint64(0)
seqinc = ^uint64(0) - 1
)
// order1007 merges a set of per-P event batches into a single, consistent stream.
// The high level idea is as follows. Events within an individual batch are in
// correct order, because they are emitted by a single P. So we need to produce
// a correct interleaving of the batches. To do this we take first unmerged event
// from each batch (frontier). Then choose subset that is "ready" to be merged,
// that is, events for which all dependencies are already merged. Then we choose
// event with the lowest timestamp from the subset, merge it and repeat.
// This approach ensures that we form a consistent stream even if timestamps are
// incorrect (condition observed on some machines).
func order1007(m map[int][]*Event) (events []*Event, err error) {
pending := 0
// The ordering of CPU profile sample events in the data stream is based on
// when each run of the signal handler was able to acquire the spinlock,
// with original timestamps corresponding to when ReadTrace pulled the data
// off of the profBuf queue. Re-sort them by the timestamp we captured
// inside the signal handler.
sort.Stable(eventList(m[ProfileP]))
var batches []*eventBatch
for _, v := range m {
pending += len(v)
batches = append(batches, &eventBatch{v, false})
}
gs := make(map[uint64]gState)
var frontier []orderEvent
for ; pending != 0; pending-- {
for i, b := range batches {
if b.selected || len(b.events) == 0 {
continue
}
ev := b.events[0]
g, init, next := stateTransition(ev)
if !transitionReady(g, gs[g], init) {
continue
}
frontier = append(frontier, orderEvent{ev, i, g, init, next})
b.events = b.events[1:]
b.selected = true
// Get rid of "Local" events, they are intended merely for ordering.
switch ev.Type {
case EvGoStartLocal:
ev.Type = EvGoStart
case EvGoUnblockLocal:
ev.Type = EvGoUnblock
case EvGoSysExitLocal:
ev.Type = EvGoSysExit
}
}
if len(frontier) == 0 {
return nil, fmt.Errorf("no consistent ordering of events possible")
}
sort.Sort(orderEventList(frontier))
f := frontier[0]
frontier[0] = frontier[len(frontier)-1]
frontier = frontier[:len(frontier)-1]
events = append(events, f.ev)
transition(gs, f.g, f.init, f.next)
if !batches[f.batch].selected {
panic("frontier batch is not selected")
}
batches[f.batch].selected = false
}
// At this point we have a consistent stream of events.
// Make sure time stamps respect the ordering.
// The tests will skip (not fail) the test case if they see this error.
if !sort.IsSorted(eventList(events)) {
return nil, ErrTimeOrder
}
// The last part is giving correct timestamps to EvGoSysExit events.
// The problem with EvGoSysExit is that actual syscall exit timestamp (ev.Args[2])
// is potentially acquired long before event emission. So far we've used
// timestamp of event emission (ev.Ts).
// We could not set ev.Ts = ev.Args[2] earlier, because it would produce
// seemingly broken timestamps (misplaced event).
// We also can't simply update the timestamp and resort events, because
// if timestamps are broken we will misplace the event and later report
// logically broken trace (instead of reporting broken timestamps).
lastSysBlock := make(map[uint64]int64)
for _, ev := range events {
switch ev.Type {
case EvGoSysBlock, EvGoInSyscall:
lastSysBlock[ev.G] = ev.Ts
case EvGoSysExit:
ts := int64(ev.Args[2])
if ts == 0 {
continue
}
block := lastSysBlock[ev.G]
if block == 0 {
return nil, fmt.Errorf("stray syscall exit")
}
if ts < block {
return nil, ErrTimeOrder
}
ev.Ts = ts
}
}
sort.Stable(eventList(events))
return
}
// stateTransition returns goroutine state (sequence and status) when the event
// becomes ready for merging (init) and the goroutine state after the event (next).
func stateTransition(ev *Event) (g uint64, init, next gState) {
switch ev.Type {
case EvGoCreate:
g = ev.Args[0]
init = gState{0, gDead}
next = gState{1, gRunnable}
case EvGoWaiting, EvGoInSyscall:
g = ev.G
init = gState{1, gRunnable}
next = gState{2, gWaiting}
case EvGoStart, EvGoStartLabel:
g = ev.G
init = gState{ev.Args[1], gRunnable}
next = gState{ev.Args[1] + 1, gRunning}
case EvGoStartLocal:
// noseq means that this event is ready for merging as soon as
// frontier reaches it (EvGoStartLocal is emitted on the same P
// as the corresponding EvGoCreate/EvGoUnblock, and thus the latter
// is already merged).
// seqinc is a stub for cases when event increments g sequence,
// but since we don't know current seq we also don't know next seq.
g = ev.G
init = gState{noseq, gRunnable}
next = gState{seqinc, gRunning}
case EvGoBlock, EvGoBlockSend, EvGoBlockRecv, EvGoBlockSelect,
EvGoBlockSync, EvGoBlockCond, EvGoBlockNet, EvGoSleep,
EvGoSysBlock, EvGoBlockGC:
g = ev.G
init = gState{noseq, gRunning}
next = gState{noseq, gWaiting}
case EvGoSched, EvGoPreempt:
g = ev.G
init = gState{noseq, gRunning}
next = gState{noseq, gRunnable}
case EvGoUnblock, EvGoSysExit:
g = ev.Args[0]
init = gState{ev.Args[1], gWaiting}
next = gState{ev.Args[1] + 1, gRunnable}
case EvGoUnblockLocal, EvGoSysExitLocal:
g = ev.Args[0]
init = gState{noseq, gWaiting}
next = gState{seqinc, gRunnable}
case EvGCStart:
g = garbage
init = gState{ev.Args[0], gDead}
next = gState{ev.Args[0] + 1, gDead}
default:
// no ordering requirements
g = unordered
}
return
}
func transitionReady(g uint64, curr, init gState) bool {
return g == unordered || (init.seq == noseq || init.seq == curr.seq) && init.status == curr.status
}
func transition(gs map[uint64]gState, g uint64, init, next gState) {
if g == unordered {
return
}
curr := gs[g]
if !transitionReady(g, curr, init) {
panic("event sequences are broken")
}
switch next.seq {
case noseq:
next.seq = curr.seq
case seqinc:
next.seq = curr.seq + 1
}
gs[g] = next
}
// order1005 merges a set of per-P event batches into a single, consistent stream.
func order1005(m map[int][]*Event) (events []*Event, err error) {
for _, batch := range m {
events = append(events, batch...)
}
for _, ev := range events {
if ev.Type == EvGoSysExit {
// EvGoSysExit emission is delayed until the thread has a P.
// Give it the real sequence number and time stamp.
ev.seq = int64(ev.Args[1])
if ev.Args[2] != 0 {
ev.Ts = int64(ev.Args[2])
}
}
}
sort.Sort(eventSeqList(events))
if !sort.IsSorted(eventList(events)) {
return nil, ErrTimeOrder
}
return
}
type orderEventList []orderEvent
func (l orderEventList) Len() int {
return len(l)
}
func (l orderEventList) Less(i, j int) bool {
return l[i].ev.Ts < l[j].ev.Ts
}
func (l orderEventList) Swap(i, j int) {
l[i], l[j] = l[j], l[i]
}
type eventList []*Event
func (l eventList) Len() int {
return len(l)
}
func (l eventList) Less(i, j int) bool {
return l[i].Ts < l[j].Ts
}
func (l eventList) Swap(i, j int) {
l[i], l[j] = l[j], l[i]
}
type eventSeqList []*Event
func (l eventSeqList) Len() int {
return len(l)
}
func (l eventSeqList) Less(i, j int) bool {
return l[i].seq < l[j].seq
}
func (l eventSeqList) Swap(i, j int) {
l[i], l[j] = l[j], l[i]
}

1102
src/internal/trace/parser.go
View File

File diff suppressed because it is too large Load Diff

123
src/internal/trace/parser_test.go
View File

@ -1,123 +0,0 @@
// Copyright 2015 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package trace
import (
"bytes"
"os"
"path/filepath"
"strings"
"testing"
)
func TestCorruptedInputs(t *testing.T) {
// These inputs crashed parser previously.
tests := []string{
"gotrace\x00\x020",
"gotrace\x00Q00\x020",
"gotrace\x00T00\x020",
"gotrace\x00\xc3\x0200",
"go 1.5 trace\x00\x00\x00\x00\x020",
"go 1.5 trace\x00\x00\x00\x00Q00\x020",
"go 1.5 trace\x00\x00\x00\x00T00\x020",
"go 1.5 trace\x00\x00\x00\x00\xc3\x0200",
}
for _, data := range tests {
res, err := Parse(strings.NewReader(data), "")
if err == nil || res.Events != nil || res.Stacks != nil {
t.Fatalf("no error on input: %q", data)
}
}
}
func TestParseCanned(t *testing.T) {
files, err := os.ReadDir("./testdata")
if err != nil {
t.Fatalf("failed to read ./testdata: %v", err)
}
for _, f := range files {
info, err := f.Info()
if err != nil {
t.Fatal(err)
}
if testing.Short() && info.Size() > 10000 {
continue
}
name := filepath.Join("./testdata", f.Name())
data, err := os.ReadFile(name)
if err != nil {
t.Fatal(err)
}
// 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.
ver, res, err := parse(bytes.NewReader(data), "")
switch {
case strings.HasSuffix(f.Name(), "_good"):
if err != nil {
t.Errorf("failed to parse good trace %v: %v", f.Name(), err)
}
checkTrace(t, ver, res)
case strings.HasSuffix(f.Name(), "_unordered"):
if err != ErrTimeOrder {
t.Errorf("unordered trace is not detected %v: %v", f.Name(), err)
}
default:
t.Errorf("unknown input file suffix: %v", f.Name())
}
}
}
// 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) {
tests := map[string]int{
"go 1.5 trace\x00\x00\x00\x00": 1005,
"go 1.7 trace\x00\x00\x00\x00": 1007,
"go 1.10 trace\x00\x00\x00": 1010,
"go 1.25 trace\x00\x00\x00": 1025,
"go 1.234 trace\x00\x00": 1234,
"go 1.2345 trace\x00": -1,
"go 0.0 trace\x00\x00\x00\x00": -1,
"go a.b trace\x00\x00\x00\x00": -1,
}
for header, ver := range tests {
ver1, err := parseHeader([]byte(header))
if ver == -1 {
if err == nil {
t.Fatalf("no error on input: %q, version %v", header, ver1)
}
} else {
if err != nil {
t.Fatalf("failed to parse: %q (%v)", header, err)
}
if ver != ver1 {
t.Fatalf("wrong version: %v, want %v, input: %q", ver1, ver, header)
}
}
}
}
func TestTimestampOverflow(t *testing.T) {
// Test that parser correctly handles large timestamps (long tracing).
w := NewWriter()
w.Emit(EvBatch, 0, 0)
w.Emit(EvFrequency, 1e9)
for ts := uint64(1); ts < 1e16; ts *= 2 {
w.Emit(EvGoCreate, ts, ts, 0, 0)
}
if _, err := Parse(w, ""); err != nil {
t.Fatalf("failed to parse: %v", err)
}
}

8
src/internal/trace/summary.go
View File

@ -7,6 +7,7 @@ package trace
import (
tracev2 "internal/trace/v2"
"sort"
"strings"
"time"
)
@ -665,3 +666,10 @@ func RelatedGoroutinesV2(events []tracev2.Event, goid tracev2.GoID) map[tracev2.
}
return gmap
}
func IsSystemGoroutine(entryFn string) bool {
// This mimics runtime.isSystemGoroutine as closely as
// possible.
// Also, locked g in extra M (with empty entryFn) is system goroutine.
return entryFn == "" || entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.")
}

BIN
src/internal/trace/testdata/http_1_10_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/http_1_11_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/http_1_19_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/http_1_21_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/http_1_5_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/http_1_7_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/http_1_9_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_10_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_11_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_19_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_21_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_5_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_5_unordered vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_7_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_1_9_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_10_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_11_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_19_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_21_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_5_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_7_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/stress_start_stop_1_9_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/user_task_region_1_11_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/user_task_region_1_19_good vendored
View File

Binary file not shown.

BIN
src/internal/trace/testdata/user_task_region_1_21_good vendored
View File

Binary file not shown.

49
src/internal/trace/writer.go
View File

@ -1,49 +0,0 @@
// Copyright 2017 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package trace
import "bytes"
// Writer is a test trace writer.
type Writer struct {
bytes.Buffer
}
func NewWriter() *Writer {
w := new(Writer)
w.Write([]byte("go 1.9 trace\x00\x00\x00\x00"))
return w
}
// Emit writes an event record to the trace.
// See Event types for valid types and required arguments.
func (w *Writer) Emit(typ byte, args ...uint64) {
nargs := byte(len(args)) - 1
if nargs > 3 {
nargs = 3
}
buf := []byte{typ | nargs<<6}
if nargs == 3 {
buf = append(buf, 0)
}
for _, a := range args {
buf = appendVarint(buf, a)
}
if nargs == 3 {
buf[1] = byte(len(buf) - 2)
}
n, err := w.Write(buf)
if n != len(buf) || err != nil {
panic("failed to write")
}
}
func appendVarint(buf []byte, v uint64) []byte {
for ; v >= 0x80; v >>= 7 {
buf = append(buf, 0x80|byte(v))
}
buf = append(buf, byte(v))
return buf
}

60
src/runtime/testdata/testprogcgo/issue29707.go vendored
View File

@ -1,60 +0,0 @@
// Copyright 2011 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
//go:build !plan9 && !windows
// +build !plan9,!windows
// This is for issue #29707
package main
/*
#include <pthread.h>
extern void* callbackTraceParser(void*);
typedef void* (*cbTraceParser)(void*);
static void testCallbackTraceParser(cbTraceParser cb) {
pthread_t thread_id;
pthread_create(&thread_id, NULL, cb, NULL);
pthread_join(thread_id, NULL);
}
*/
import "C"
import (
"bytes"
"fmt"
traceparser "internal/trace"
"runtime/trace"
"time"
"unsafe"
)
func init() {
register("CgoTraceParser", CgoTraceParser)
}
//export callbackTraceParser
func callbackTraceParser(unsafe.Pointer) unsafe.Pointer {
time.Sleep(time.Millisecond)
return nil
}
func CgoTraceParser() {
buf := new(bytes.Buffer)
trace.Start(buf)
C.testCallbackTraceParser(C.cbTraceParser(C.callbackTraceParser))
trace.Stop()
_, err := traceparser.Parse(buf, "")
if err == traceparser.ErrTimeOrder {
fmt.Println("ErrTimeOrder")
} else if err != nil {
fmt.Println("Parse error: ", err)
} else {
fmt.Println("OK")
}
}

52
src/runtime/trace_cgo_test.go
View File

@ -10,7 +10,6 @@ import (
"bytes"
"fmt"
"internal/testenv"
"internal/trace"
tracev2 "internal/trace/v2"
"io"
"os"
@ -38,14 +37,10 @@ func TestTraceUnwindCGO(t *testing.T) {
"goCalledFromC",
"goCalledFromCThread",
}
logs := make(map[string]*trace.Event)
logs := make(map[string]*tracev2.Event)
for _, category := range wantLogs {
logs[category] = nil
}
logsV2 := make(map[string]*tracev2.Event)
for _, category := range wantLogs {
logsV2[category] = nil
}
for _, tracefpunwindoff := range []int{1, 0} {
env := fmt.Sprintf("GODEBUG=tracefpunwindoff=%d", tracefpunwindoff)
got := runBuiltTestProg(t, exe, "Trace", env)
@ -61,8 +56,8 @@ func TestTraceUnwindCGO(t *testing.T) {
}
for category := range logs {
event := mustFindLogV2(t, bytes.NewReader(traceData), category)
if wantEvent := logsV2[category]; wantEvent == nil {
logsV2[category] = &event
if wantEvent := logs[category]; wantEvent == nil {
logs[category] = &event
} else if got, want := dumpStackV2(&event), dumpStackV2(wantEvent); got != want {
t.Errorf("%q: got stack:\n%s\nwant stack:\n%s\n", category, got, want)
}
@ -70,47 +65,6 @@ func TestTraceUnwindCGO(t *testing.T) {
}
}
// mustFindLog returns the EvUserLog event with the given category in events. It
// fails if no event or multiple events match the category.
func mustFindLog(t *testing.T, events []*trace.Event, category string) *trace.Event {
t.Helper()
var candidates []*trace.Event
for _, e := range events {
if e.Type == trace.EvUserLog && len(e.SArgs) >= 1 && e.SArgs[0] == category {
candidates = append(candidates, e)
}
}
if len(candidates) == 0 {
t.Errorf("could not find log with category: %q", category)
} else if len(candidates) > 1 {
t.Errorf("found more than one log with category: %q", category)
}
return candidates[0]
}
// dumpStack returns e.Stk as a string.
func dumpStack(e *trace.Event) string {
var buf bytes.Buffer
for _, f := range e.Stk {
file := strings.TrimPrefix(f.File, runtime.GOROOT())
fmt.Fprintf(&buf, "%s\n\t%s:%d\n", f.Fn, file, f.Line)
}
return buf.String()
}
// parseTrace parses the given trace or skips the test if the trace is broken
// due to known issues. Partially copied from runtime/trace/trace_test.go.
func parseTrace(t *testing.T, r io.Reader) []*trace.Event {
res, err := trace.Parse(r, "")
if err == trace.ErrTimeOrder {
t.Skipf("skipping trace: %v", err)
}
if err != nil {
t.Fatalf("failed to parse trace: %v", err)
}
return res.Events
}
func mustFindLogV2(t *testing.T, trace io.Reader, category string) tracev2.Event {
r, err := tracev2.NewReader(trace)
if err != nil {