runtime: dropg after emitting trace event in preemptPark

Because we dropg before emitting a trace event in preemptPark, we end up
failing to emit a status for the goroutine if this happens to be the
first event for it in the generation. We only really see this with
multiple subscribers in TestSubscribers.

This is for two reasons:
1. If we are missing a status event for a non-initial generation then
   the trace parser won't validate that (an oversight, but we can only
   enforce that for new traces because of this bug), and
2. If we're starting the tracer fresh, then we have a STW which
   effectively guarantees that the first event for a goroutine cannot
   come from preemptPark.

Therefore, we cannot observe this situation unless the first generation
manifests the bug, but prior to having flight recording and/or multiple
subscribers being able to "cut" the trace data at any point, this was
impossible.

The fix is simple: dropg only after emitting the trace event. This is
also safe, because the tracer doesn't care. The tracer will also start
taking a stack trace of the goroutine in this circumstance, but that is
also safe, since we are able to generally unwind the stack of
asynchronously preempted goroutines, and here we're at the very, very
end of asynchronous preemption where all the state to do so is already
set up.

Fixes #75665.

Change-Id: I7ee1142697d0a53b62d4c5647aa53775d2f6976a
Reviewed-on: https://go-review.googlesource.com/c/go/+/729400
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Cherry Mui <cherryyz@google.com>

diff --git a/src/runtime/proc.go b/src/runtime/proc.go
index 4bca9f1347d45bf6f9c38c2ad9eb6bf63b0c6583..465a1adb601eca8d4b1e66c77607297bdbd4dc97 100644 (file)
--- a/src/runtime/proc.go
+++ b/src/runtime/proc.go
@@ -4385,7 +4385,6 @@ func preemptPark(gp *g) {
        // up. Hence, we set the scan bit to lock down further
        // transitions until we can dropg.
        casGToPreemptScan(gp, _Grunning, _Gscan|_Gpreempted)
-       dropg()
 
        // Be careful about ownership as we trace this next event.
        //
@@ -4411,10 +4410,19 @@ func preemptPark(gp *g) {
        if trace.ok() {
                trace.GoPark(traceBlockPreempted, 0)
        }
+
+       // Drop the goroutine from the M. Only do this after the tracer has
+       // emitted an event, because it needs the association for GoPark to
+       // work correctly.
+       dropg()
+
+       // Drop the scan bit and release the trace locker if necessary.
        casfrom_Gscanstatus(gp, _Gscan|_Gpreempted, _Gpreempted)
        if trace.ok() {
                traceRelease(trace)
        }
+
+       // All done.
        schedule()
 }
 

diff --git a/src/runtime/trace/subscribe_test.go b/src/runtime/trace/subscribe_test.go
index 869ab0e75b6b440d344fce9e6727746a7b1b6c9f..2822094a026dd27fbdd5ff3999261c8f2a3b1f58 100644 (file)
--- a/src/runtime/trace/subscribe_test.go
+++ b/src/runtime/trace/subscribe_test.go
@@ -17,9 +17,10 @@ import (
 
 func TestSubscribers(t *testing.T) {
        validate := func(t *testing.T, source string, tr []byte) {
+               t.Log("validating", source)
                defer func() {
                        if t.Failed() {
-                               testtrace.Dump(t, "trace", tr, *dumpTraces)
+                               testtrace.Dump(t, "TestSubscribers."+source, tr, *dumpTraces)
                        }
                }()