runtime: record mutex event before readying

Currently, semrelease1 readies the next waiter before recording a
mutex event. However, if the next waiter is expecting to look at the
mutex profile, as is the case in TestMutexProfile, this may delay
recording the event too much.

Swap the order of these operations so semrelease1 records the mutex
event before readying the next waiter. This also means readying the
next waiter is the very last thing semrelease1 does, which seems
appropriate.

Fixes #19139.

Change-Id: I1a62063599fdb5d49bd86061a180c0a2d659474b
Reviewed-on: https://go-review.googlesource.com/45751
Run-TryBot: Austin Clements <austin@google.com>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: Peter Weinberger <pjw@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>

src/runtime/pprof/pprof_test.go

@@ -542,6 +542,10 @@ func blockMutex() {
 		time.Sleep(blockDelay)
 		mu.Unlock()
 	}()
+	// Note: Unlock releases mu before recording the mutex event,
+	// so it's theoretically possible for this to proceed and
+	// capture the profile before the event is recorded. As long
+	// as this is blocked before the unlock happens, it's okay.
 	mu.Lock()
 }
 
@@ -560,7 +564,6 @@ func blockCond() {
 }
 
 func TestMutexProfile(t *testing.T) {
-	testenv.SkipFlaky(t, 19139)
 	old := runtime.SetMutexProfileFraction(1)
 	defer runtime.SetMutexProfileFraction(old)
 	if old != 0 {

src/runtime/sema.go

@@ -182,6 +182,9 @@ func semrelease1(addr *uint32, handoff bool) {
 	unlock(&root.lock)
 	if s != nil { // May be slow, so unlock first
 		acquiretime := s.acquiretime
+		if acquiretime != 0 {
+			mutexevent(t0-acquiretime, 3)
+		}
 		if s.ticket != 0 {
 			throw("corrupted semaphore ticket")
 		}
@@ -189,9 +192,6 @@ func semrelease1(addr *uint32, handoff bool) {
 			s.ticket = 1
 		}
 		readyWithTime(s, 5)
-		if acquiretime != 0 {
-			mutexevent(t0-acquiretime, 3)
-		}
 	}
 }