stw_trace.go

     1  // Copyright 2025 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package main
     6  
     7  import (
     8  	"context"
     9  	"log"
    10  	"math/rand/v2"
    11  	"os"
    12  	"runtime"
    13  	"runtime/debug"
    14  	"runtime/metrics"
    15  	"runtime/trace"
    16  	"sync/atomic"
    17  )
    18  
    19  func init() {
    20  	register("TraceSTW", TraceSTW)
    21  	register("TraceGCSTW", TraceGCSTW)
    22  }
    23  
    24  // The parent writes to ping and waits for the children to write back
    25  // via pong to show that they are running.
    26  var ping atomic.Uint32
    27  var pong [2]atomic.Uint32
    28  
    29  // Tell runners to stop.
    30  var stop atomic.Bool
    31  
    32  func traceSTWTarget(i int) {
    33  	for !stop.Load() {
    34  		// Async preemption often takes 100ms+ to preempt this loop on
    35  		// windows-386. This makes the test flaky, as the traceReadCPU
    36  		// timer often fires by the time STW finishes, jumbling the
    37  		// goroutine scheduling. As a workaround, ensure we have a
    38  		// morestack call for prompt preemption.
    39  		ensureMorestack()
    40  
    41  		pong[i].Store(ping.Load())
    42  	}
    43  }
    44  
    45  func TraceSTW() {
    46  	ctx := context.Background()
    47  
    48  	// The idea here is to have 2 target goroutines that are constantly
    49  	// running. When the world restarts after STW, we expect these
    50  	// goroutines to continue execution on the same M and P.
    51  	//
    52  	// Set GOMAXPROCS=4 to make room for the 2 target goroutines, 1 parent,
    53  	// and 1 slack for potential misscheduling.
    54  	//
    55  	// Disable the GC because GC STW generally moves goroutines (see
    56  	// https://go.dev/issue/65694). Alternatively, we could just ignore the
    57  	// trace if the GC runs.
    58  	runtime.GOMAXPROCS(4)
    59  	debug.SetGCPercent(-1)
    60  
    61  	if err := trace.Start(os.Stdout); err != nil {
    62  		log.Fatalf("failed to start tracing: %v", err)
    63  	}
    64  	defer trace.Stop()
    65  
    66  	for i := range 2 {
    67  		go traceSTWTarget(i)
    68  	}
    69  
    70  	// Wait for children to start running.
    71  	ping.Store(1)
    72  	for pong[0].Load() != 1 {}
    73  	for pong[1].Load() != 1 {}
    74  
    75  	trace.Log(ctx, "TraceSTW", "start")
    76  
    77  	// STW
    78  	var ms runtime.MemStats
    79  	runtime.ReadMemStats(&ms)
    80  
    81  	// Make sure to run long enough for the children to schedule again
    82  	// after STW.
    83  	ping.Store(2)
    84  	for pong[0].Load() != 2 {}
    85  	for pong[1].Load() != 2 {}
    86  
    87  	trace.Log(ctx, "TraceSTW", "end")
    88  
    89  	stop.Store(true)
    90  }
    91  
    92  // Variant of TraceSTW for GC STWs. We want the GC mark workers to start on
    93  // previously-idle Ps, rather than bumping the current P.
    94  func TraceGCSTW() {
    95  	ctx := context.Background()
    96  
    97  	// The idea here is to have 2 target goroutines that are constantly
    98  	// running. When the world restarts after STW, we expect these
    99  	// goroutines to continue execution on the same M and P.
   100  	//
   101  	// Set GOMAXPROCS=8 to make room for the 2 target goroutines, 1 parent,
   102  	// 2 dedicated workers, and a bit of slack.
   103  	//
   104  	// Disable the GC initially so we can be sure it only triggers once we
   105  	// are ready.
   106  	runtime.GOMAXPROCS(8)
   107  	debug.SetGCPercent(-1)
   108  
   109  	if err := trace.Start(os.Stdout); err != nil {
   110  		log.Fatalf("failed to start tracing: %v", err)
   111  	}
   112  	defer trace.Stop()
   113  
   114  	for i := range 2 {
   115  		go traceSTWTarget(i)
   116  	}
   117  
   118  	// Wait for children to start running.
   119  	ping.Store(1)
   120  	for pong[0].Load() != 1 {}
   121  	for pong[1].Load() != 1 {}
   122  
   123  	trace.Log(ctx, "TraceSTW", "start")
   124  
   125  	// STW
   126  	triggerGC()
   127  
   128  	// Make sure to run long enough for the children to schedule again
   129  	// after STW. This is included for good measure, but the goroutines
   130  	// really ought to have already scheduled since the entire GC
   131  	// completed.
   132  	ping.Store(2)
   133  	for pong[0].Load() != 2 {}
   134  	for pong[1].Load() != 2 {}
   135  
   136  	trace.Log(ctx, "TraceSTW", "end")
   137  
   138  	stop.Store(true)
   139  }
   140  
   141  func triggerGC() {
   142  	// Allocate a bunch to trigger the GC rather than using runtime.GC. The
   143  	// latter blocks until the GC is complete, which is convenient, but
   144  	// messes with scheduling as it gives this P a chance to steal the
   145  	// other goroutines before their Ps get up and running again.
   146  
   147  	// Bring heap size up prior to enabling the GC to ensure that there is
   148  	// a decent amount of work in case the GC triggers immediately upon
   149  	// re-enabling.
   150  	for range 1000 {
   151  		alloc()
   152  	}
   153  
   154  	sample := make([]metrics.Sample, 1)
   155  	sample[0].Name = "/gc/cycles/total:gc-cycles"
   156  	metrics.Read(sample)
   157  
   158  	start := sample[0].Value.Uint64()
   159  
   160  	debug.SetGCPercent(100)
   161  
   162  	// Keep allocating until the GC is complete. We really only need to
   163  	// continue until the mark workers are scheduled, but there isn't a
   164  	// good way to measure that.
   165  	for {
   166  		metrics.Read(sample)
   167  		if sample[0].Value.Uint64() != start {
   168  			return
   169  		}
   170  
   171  		alloc()
   172  	}
   173  }
   174  
   175  // Allocate a tree data structure to generate plenty of scan work for the GC.
   176  
   177  type node struct {
   178  	children []*node
   179  }
   180  
   181  var gcSink node
   182  
   183  func alloc() {
   184  	// 10% chance of adding a node a each layer.
   185  
   186  	curr := &gcSink
   187  	for {
   188  		if len(curr.children) == 0 || rand.Float32() < 0.1 {
   189  			curr.children = append(curr.children, new(node))
   190  			return
   191  		}
   192  
   193  		i := rand.IntN(len(curr.children))
   194  		curr = curr.children[i]
   195  	}
   196  }
   197  
   198  // Manually insert a morestack call. Leaf functions can omit morestack, but
   199  // non-leaf functions should include them.
   200  
   201  //go:noinline
   202  func ensureMorestack() {
   203  	ensureMorestack1()
   204  }
   205  
   206  //go:noinline
   207  func ensureMorestack1() {
   208  }
   209
View as plain text