runtime/pprof: stop logging an error if CPU sampling rate is already configured

The runtime.SetCPUProfileRate function configures the CPU profiling
sampling rate and starts profiling if the rate is non-zero. If the
function is called with a non-zero rate and profiling is already
enabled, the function logs a warning to standard error. This is a
hard-coded print and can't be turned off. However,
runtime.SetCPUProfileRate is the only way to configure the profiling
frequency, since pprof.StartCPUProfile doesn't provide an option to
change the rate. That function calls runtime.SetCPUProfileRate with a
hard-coded default of 100. This means that the following code logs an
error:

	runtime.SetCPUProfileRate(200)
	pprof.StartCPUProfile(w)

The error is misleading. CPU profiling is working after the second call,
sampling at 200 Hz as intended. The error is also annoying for something
like a continuous profiling library, which stops and starts CPU
profiling regularly and thus prints a useless log repeatedly.

This CL gives pprof.StartCPUProfile a way to set the sampling rate and
start profiling without logging the error if the user already set the
sampling rate. Calling runtime.SetCPUProfileRate twice with a non-zero
rate will still log an error.

Fixes #79900

Change-Id: Icb89bb4ed66689c5a91ce5a677edff126a6a6964
Reviewed-on: https://go-review.googlesource.com/c/go/+/787580
Reviewed-by: Carlos Amedee <carlos@golang.org>
Reviewed-by: Florian Lehner <lhnr.flrn@gmail.com>
Auto-Submit: Nick Ripley <nick.ripley@datadoghq.com>
Reviewed-by: Michael Pratt <mpratt@google.com>
LUCI-TryBot-Result: golang-scoped@luci-project-accounts.iam.gserviceaccount.com <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>

src/runtime/cpuprof.go

@@ -66,6 +66,13 @@ var cpuprof cpuProfile
 // the [testing] package's -test.cpuprofile flag instead of calling
 // SetCPUProfileRate directly.
 func SetCPUProfileRate(hz int) {
+	setCPUProfileRate(hz, true)
+}
+
+// setCPUProfileRate sets the CPU profiling rate to hz. Setting a non-zero rate
+// when the rate is already non-zero is a no-op. An error is printed in this case
+// if warn is true.
+func setCPUProfileRate(hz int, warn bool) {
 	// Clamp hz to something reasonable.
 	if hz < 0 {
 		hz = 0
@@ -77,7 +84,9 @@ func SetCPUProfileRate(hz int) {
 	lock(&cpuprof.lock)
 	if hz > 0 {
 		if cpuprof.on || cpuprof.log != nil {
-			print("runtime: cannot set cpu profile rate until previous profile has finished.\n")
+			if warn {
+				print("runtime: cannot set cpu profile rate until previous profile has finished.\n")
+			}
 			unlock(&cpuprof.lock)
 			return
 		}
@@ -209,6 +218,15 @@ func CPUProfile() []byte {
 	panic("CPUProfile no longer available")
 }
 
+// pprof_setCPUProfileRate is provided to runtime/pprof.StartCPUProfile,
+// to enable CPU profiling without logging an error if the user has already
+// configured the profiling rate.
+//
+//go:linkname pprof_setCPUProfileRate
+func pprof_setCPUProfileRate(hz int) {
+	setCPUProfileRate(hz, false)
+}
+
 // runtime/pprof.runtime_cyclesPerSecond should be an internal detail,
 // but widely used packages access it using linkname.
 // Notable members of the hall of shame include:

src/runtime/pprof/pprof.go

@@ -904,7 +904,7 @@ func StartCPUProfile(w io.Writer) error {
 		return fmt.Errorf("cpu profiling already in use")
 	}
 	cpu.profiling = true
-	runtime.SetCPUProfileRate(hz)
+	pprof_setCPUProfileRate(hz)
 	go profileWriter(w)
 	return nil
 }
@@ -952,7 +952,7 @@ func StopCPUProfile() {
 		return
 	}
 	cpu.profiling = false
-	runtime.SetCPUProfileRate(0)
+	pprof_setCPUProfileRate(0)
 	<-cpu.done
 }
 
@@ -1055,3 +1055,6 @@ func pprof_fpunwindExpand(dst, src []uintptr) int
 
 //go:linkname pprof_makeProfStack runtime.pprof_makeProfStack
 func pprof_makeProfStack() []uintptr
+
+//go:linkname pprof_setCPUProfileRate runtime.pprof_setCPUProfileRate
+func pprof_setCPUProfileRate(hz int)

src/runtime/pprof/pprof_test.go

@@ -663,6 +663,45 @@ func TestCPUProfileWithFork(t *testing.T) {
 	}
 }
 
+func TestCPUProfileRateErrorLog(t *testing.T) {
+	testenv.MustHaveExec(t)
+
+	switch os.Getenv("GO_TEST_CPU_PROFILE_RATE_SCENARIO") {
+	case "DoubleSet":
+		runtime.SetCPUProfileRate(100)
+		runtime.SetCPUProfileRate(500) // should log error: profile already active
+		runtime.SetCPUProfileRate(0)
+		return
+	case "SetThenStart":
+		runtime.SetCPUProfileRate(500)
+		if err := StartCPUProfile(io.Discard); err != nil {
+			fmt.Fprintf(os.Stderr, "StartCPUProfile: unexpected error: %v\n", err)
+		}
+		StopCPUProfile()
+		return
+	}
+
+	for _, tc := range []struct {
+		scenario string
+		want     string
+	}{
+		{"DoubleSet", "runtime: cannot set cpu profile rate until previous profile has finished."},
+		{"SetThenStart", ""},
+	} {
+		t.Run(tc.scenario, func(t *testing.T) {
+			cmd := testenv.CleanCmdEnv(testenv.Command(t, testenv.Executable(t),
+				"-test.run="+"^"+t.Name()+"$"))
+			cmd.Env = append(cmd.Env, "GO_TEST_CPU_PROFILE_RATE_SCENARIO="+tc.scenario)
+			var stderr bytes.Buffer
+			cmd.Stderr = &stderr
+			cmd.Run()
+			if got := strings.TrimSpace(stderr.String()); got != tc.want {
+				t.Errorf("got error output %q, wanted %q", got, tc.want)
+			}
+		})
+	}
+}
+
 // Test that profiler does not observe runtime.gogo as "user" goroutine execution.
 // If it did, it would see inconsistent state and would either record an incorrect stack
 // or crash because the stack was malformed.