π΅οΈββοΈ Exercise 8: Goroutine Sleep Detective - Runtime State Monitoring
In this exercise, you’ll modify the Go runtime scheduler to log goroutine state transitions! π Every time a goroutine goes to sleep waiting for something, it will announce itself: “Hello, I’m goroutine 42, going to sleep waiting for channel receive”!
π― Learning Objectives
By the end of this exercise, you will:
- β Understand Go’s goroutine scheduler state transitions
- β Know where goroutines block in the runtime
- β Modify the scheduler for debugging insights
π§ Background: Goroutine States
Go manages goroutines through different states:
_Grunnable
- Ready to run but not executing_Grunning
- Currently executing_Gwaiting
- Blocked waiting for something (our target!)_Gsyscall
- Executing a system call- …
When a goroutine needs to wait (for channels, mutexes, sleep, etc.), it “parks” and transitions to _Gwaiting
state.
π Step 1: Understanding the Park Mechanism
The gopark
function is called by ALL synchronization primitives when a goroutine needs to wait.
cd go/src/runtime
grep -n "func gopark" proc.go
Key functions:
gopark()
- Initiates parking a goroutinepark_m()
- Actually changes the state to_Gwaiting
Step 2: Find the State Transition Code
# Look at where the state actually changes
grep -n -A 5 "func park_m" proc.go
Around line 4237, you’ll see:
casgstatus(gp, _Grunning, _Gwaiting)
This is the exact line where a goroutine transitions from running to waiting. Perfect for our logging!
Step 3: Add Goroutine Sleep Logging
Edit proc.go
:
You’ll need to add logging in three locations where goroutines transition to the waiting state:
Location 1: casGToWaiting
function (around line 1366)
Find the casGToWaiting
function and add logging after setting the wait reason:
func casGToWaiting(gp *g, old uint32, reason waitReason) {
// Set the wait reason before calling casgstatus, because casgstatus will use it.
gp.waitreason = reason
if gp.goid > 1 { // Skip system goroutines 0 and 1
print("Hello, I'm goroutine ", gp.goid, ", going to sleep waiting for ", gp.waitreason.String(), "\n")
}
casgstatus(gp, old, _Gwaiting)
}
Location 2: casGFromPreempted
function (around line 1411)
Find where preempted goroutines transition to waiting:
func casGFromPreempted(gp *g, old, new uint32) bool {
// ... existing code ...
if bubble := gp.bubble; bubble != nil {
if gp.goid > 1 { // Skip system goroutines 0 and 1
print("Hello, I'm goroutine ", gp.goid, ", going to sleep waiting for ", gp.waitreason.String(), "\n")
}
bubble.changegstatus(gp, _Gpreempted, _Gwaiting)
}
return true
}
Location 3: park_m
function (around line 4240)
Find the park_m
function and add logging before the direct casgstatus
call:
// Add this before: casgstatus(gp, _Grunning, _Gwaiting)
if gp.goid > 1 { // Skip system goroutines 0 and 1
print("Hello, I'm goroutine ", gp.goid, ", going to sleep waiting for ", gp.waitreason.String(), "\n")
}
casgstatus(gp, _Grunning, _Gwaiting)
π§ Understanding the Code
gp.goid
- Unique goroutine IDgp.waitreason.String()
- Human-readable reason for waiting (channel, mutex, sleep, etc.)print()
- Runtime print function (outputs to stderr)gp.goid > 1
- Skip system goroutines to reduce noise
Step 4: Rebuild Go Runtime
cd ../ # back to go/src
./make.bash
Step 5: Test Channel Blocking
Create a channel_test.go
file:
package main
import "time"
func main() {
ch := make(chan string)
// Start goroutine that will block on receive
go func() {
msg := <-ch // Should trigger our logging!
println("Received:", msg)
}()
// Let the goroutine start and block
time.Sleep(100 * time.Millisecond)
// Send something
ch <- "Hello!"
time.Sleep(10 * time.Millisecond)
}
Build and run with our modified Go:
../go/bin/go build channel_test.go
./channel_test
Note: We build the binary first and then run it directly. This avoids mixing goroutines from the compiler/build process with goroutines from our program, giving us cleaner output!
Expected output:
Hello, I'm goroutine 4, going to sleep waiting for GC scavenge wait
Hello, I'm goroutine 3, going to sleep waiting for GC sweep wait
Hello, I'm goroutine 2, going to sleep waiting for force gc (idle)
Hello, I'm goroutine 6, going to sleep waiting for chan receive
Hello, I'm goroutine 5, going to sleep waiting for GOMAXPROCS updater (idle)
Received: Hello!
π You can now see goroutines blocking!
Understanding What We Did
- Found the Park Function: Located where goroutines transition to waiting state
- Added Logging: Inserted print statement before state change
- Captured Wait Reason: Used
gp.waitreason.String()
for human-readable output - Tested Scenarios: Verified with channels, mutexes, sleep, and select
Common wait reasons you’ll see:
chan receive
/chan send
sync mutex lock
sleep
GC
π What We Learned
- π Goroutine Lifecycle: How goroutines transition between states
- π
ΏοΈ Park Mechanism: The
gopark
andpark_m
functions - π Synchronization Internals: Where channels, mutexes, and select cause blocking
- π οΈ Runtime Debugging: How to add observability to the Go runtime
- π Concurrency Visibility: Real-time observation of blocking operations
π‘ Extension Ideas
Try these additional modifications: π
- β Add goroutine wakeup logging (when they resume running)
- β Add emojis for different wait reasons (π’ channel, π mutex, π΄ sleep)
- β Include timestamps to measure blocking duration
- β Filter logging by specific wait reasons only
Cleanup
To remove the logging:
cd go/src/runtime
git checkout proc.go
cd ../
./make.bash
Summary
You’ve gained X-ray vision into Go’s concurrency model! Your modified runtime now announces every goroutine blocking operation:
Hello, I'm goroutine 18, going to sleep waiting for chan receive
Hello, I'm goroutine 19, going to sleep waiting for sync mutex lock
Hello, I'm goroutine 20, going to sleep waiting for sleep
This exercise revealed the internal workings of Go’s scheduler and how synchronization primitives interact with the runtime! π΅οΈββοΈβ¨
Continue to Exercise 9 or return to the main workshop