Add trace analysis tool for listing runnable goroutines

tracerunnable/README.md

@@ -0,0 +1,49 @@
+# Trace Runnable Goroutines Tool
+
+A Go tool that analyzes execution traces and lists goroutines that are runnable at a specific time offset.
+
+## Usage
+
+```bash
+go run main.go -trace <tracefile> -time <offset>
+```
+
+### Examples
+
+```bash
+# List runnable goroutines at 1.5 seconds into the trace
+go run main.go -trace trace.out -time 1.5s
+
+# List runnable goroutines at 100 milliseconds into the trace  
+go run main.go -trace trace.out -time 100ms
+
+# List runnable goroutines at 2500 microseconds into the trace
+go run main.go -trace trace.out -time 2500us
+```
+
+## How to Generate a Trace File
+
+To generate a trace file for analysis:
+
+```go
+package main
+
+import (
+    "os"
+    "runtime/trace"
+)
+
+func main() {
+    f, _ := os.Create("trace.out")
+    defer f.Close()
+
+    trace.Start(f)
+    defer trace.Stop()
+
+    // Your program logic here
+}
+```
+
+## Output
+
+The tool outputs a list of goroutine IDs that are in the runnable state at the specified time offset. A goroutine is considered runnable if it's ready to run but not currently running (waiting for a processor).

tracerunnable/go.mod

@@ -0,0 +1,3 @@
+module tracerunnable
+
+go 1.22

tracerunnable/main.go

@@ -0,0 +1,108 @@
+package main
+
+import (
+	"flag"
+	"fmt"
+	"os"
+	"runtime/trace"
+	"strconv"
+	"time"
+)
+
+var (
+	traceFile = flag.String("trace", "", "path to trace file")
+	timeOffset = flag.String("time", "", "time offset in the trace (e.g., 1.5s, 100ms, 2500us)")
+)
+
+func main() {
+	flag.Parse()
+
+	if *traceFile == "" {
+		fmt.Fprintf(os.Stderr, "Usage: %s -trace <tracefile> -time <offset>\n", os.Args[0])
+		fmt.Fprintf(os.Stderr, "Example: %s -trace trace.out -time 1.5s\n", os.Args[0])
+		os.Exit(1)
+	}
+
+	if *timeOffset == "" {
+		fmt.Fprintf(os.Stderr, "Error: time offset is required\n")
+		os.Exit(1)
+	}
+
+	duration, err := time.ParseDuration(*timeOffset)
+	if err != nil {
+		fmt.Fprintf(os.Stderr, "Error parsing time offset: %v\n", err)
+		os.Exit(1)
+	}
+
+	if err := analyzeTrace(*traceFile, duration); err != nil {
+		fmt.Fprintf(os.Stderr, "Error: %v\n", err)
+		os.Exit(1)
+	}
+}
+
+func analyzeTrace(filename string, targetTime time.Duration) error {
+	f, err := os.Open(filename)
+	if err != nil {
+		return fmt.Errorf("failed to open trace file: %w", err)
+	}
+	defer f.Close()
+
+	reader, err := trace.NewReader(f)
+	if err != nil {
+		return fmt.Errorf("failed to create trace reader: %w", err)
+	}
+
+	// Track goroutine states at the target time
+	runnableGoroutines := make(map[uint64]bool)
+	targetTimeNs := int64(targetTime.Nanoseconds())
+
+	// Find the closest event to our target time and track goroutine states
+	for {
+		event, err := reader.ReadEvent()
+		if err != nil {
+			if err.Error() == "EOF" {
+				break
+			}
+			return fmt.Errorf("failed to read trace event: %w", err)
+		}
+
+		eventTimeNs := int64(event.Time())
+
+		// If we've passed our target time, stop processing
+		if eventTimeNs > targetTimeNs {
+			break
+		}
+
+		// Track goroutine state changes
+		if gid := event.Goroutine(); gid != trace.NoGoroutine {
+			switch event.Kind() {
+			case trace.EventStateTransition:
+				// Handle goroutine state transitions
+				if st := event.StateTransition(); st.Goroutine != trace.NoGoroutine {
+					// Check if transitioning to runnable state
+					if st.New == trace.GoRunnable {
+						runnableGoroutines[uint64(st.Goroutine)] = true
+					} else if st.New == trace.GoRunning || 
+							 st.New == trace.GoWaiting ||
+							 st.New == trace.GoSyscall ||
+							 st.New == trace.GoNotExist {
+						// Remove from runnable if transitioning to other states
+						delete(runnableGoroutines, uint64(st.Goroutine))
+					}
+				}
+			}
+		}
+	}
+
+	// Output the results
+	fmt.Printf("Runnable goroutines at time offset %v:\n", targetTime)
+	if len(runnableGoroutines) == 0 {
+		fmt.Println("  (none)")
+	} else {
+		for gid := range runnableGoroutines {
+			fmt.Printf("  Goroutine %d\n", gid)
+		}
+	}
+
+	return nil
+}

tracerunnable/main_test.go

@@ -0,0 +1,75 @@
+package main
+
+import (
+	"os"
+	"runtime/trace"
+	"sync"
+	"testing"
+	"time"
+)
+
+func TestAnalyzeTrace(t *testing.T) {
+	// Create a temporary trace file
+	traceFile, err := os.CreateTemp("", "test_trace_*.out")
+	if err != nil {
+		t.Fatalf("Failed to create temp trace file: %v", err)
+	}
+	defer os.Remove(traceFile.Name())
+	defer traceFile.Close()
+
+	// Start tracing
+	if err := trace.Start(traceFile); err != nil {
+		t.Fatalf("Failed to start tracing: %v", err)
+	}
+
+	// Generate goroutines doing busywork for 10ms
+	var wg sync.WaitGroup
+	startTime := time.Now()
+
+	// Create many more goroutines than GOMAXPROCS to ensure contention
+	// This increases the chance of having runnable goroutines
+	numGoroutines := 50 // Much more than typical GOMAXPROCS
+	for i := 0; i < numGoroutines; i++ {
+		wg.Add(1)
+		go func(id int) {
+			defer wg.Done()
+
+			// Do busywork for approximately 10ms
+			for time.Since(startTime) < 10*time.Millisecond {
+				// Simulate intensive work by doing more computation
+				sum := 0
+				for j := 0; j < 10000; j++ {
+					sum += j * j
+				}
+
+				// Yield occasionally to create more scheduling events
+				if sum%1000 == 0 {
+					time.Sleep(time.Microsecond)
+				}
+			}
+		}(i)
+	}
+
+	// Wait for all goroutines to complete
+	wg.Wait()
+
+	// Stop tracing
+	trace.Stop()
+	traceFile.Close()
+
+	// Test the analyzeTrace function at 0ms offset
+	t.Run("0ms offset", func(t *testing.T) {
+		err := analyzeTrace(traceFile.Name(), 0*time.Millisecond)
+		if err != nil {
+			t.Errorf("analyzeTrace failed at 0ms offset: %v", err)
+		}
+	})
+
+	// Test the analyzeTrace function at 5ms offset
+	t.Run("5ms offset", func(t *testing.T) {
+		err := analyzeTrace(traceFile.Name(), 5*time.Millisecond)
+		if err != nil {
+			t.Errorf("analyzeTrace failed at 5ms offset: %v", err)
+		}
+	})
+}