|
| 1 | +# coz-go |
| 2 | + |
| 3 | +Go support for the [`coz` causal profiler](https://github.com/plasma-umass/coz). |
| 4 | + |
| 5 | +A traditional profiler tells you *where* your program spends time. Coz tells you |
| 6 | +whether optimizing a line would actually make the program faster — which, in |
| 7 | +concurrent code, is a different question. |
| 8 | + |
| 9 | +Works on **Linux** and **macOS**. |
| 10 | + |
| 11 | +## Usage |
| 12 | + |
| 13 | +First [install `coz`](https://github.com/plasma-umass/coz#installation), then add |
| 14 | +the module: |
| 15 | + |
| 16 | +``` |
| 17 | +go get github.com/plasma-umass/coz/go |
| 18 | +``` |
| 19 | + |
| 20 | +Mark the points where your program makes progress. For throughput — "I wish this |
| 21 | +happened more often": |
| 22 | + |
| 23 | +```go |
| 24 | +import coz "github.com/plasma-umass/coz/go" |
| 25 | + |
| 26 | +for _, req := range requests { |
| 27 | + handle(req) |
| 28 | + coz.Progress() // equivalent of COZ_PROGRESS |
| 29 | +} |
| 30 | +``` |
| 31 | + |
| 32 | +`coz.ProgressNamed("requests")` is the equivalent of `COZ_PROGRESS_NAMED`. |
| 33 | + |
| 34 | +For latency — "I wish this finished sooner" — mark both ends of the operation: |
| 35 | + |
| 36 | +```go |
| 37 | +func handle(req Request) { |
| 38 | + defer coz.Scope("request")() // COZ_BEGIN now, COZ_END on return |
| 39 | + // ... |
| 40 | +} |
| 41 | +``` |
| 42 | + |
| 43 | +`Scope` fires its end counter even on an early return or a panic. If you need the |
| 44 | +two halves apart, `coz.Begin("request")` and `coz.End("request")` are available. |
| 45 | + |
| 46 | +On a hot path you can hoist the counter lookup out of the loop: |
| 47 | + |
| 48 | +```go |
| 49 | +requests := coz.NewThroughput("requests") |
| 50 | +for _, req := range reqs { |
| 51 | + handle(req) |
| 52 | + requests.Increment() |
| 53 | +} |
| 54 | +``` |
| 55 | + |
| 56 | +`coz.Available()` reports whether the program is running under `coz run`. |
| 57 | + |
| 58 | +## Building and running |
| 59 | + |
| 60 | +Profiling requires **cgo** (`CGO_ENABLED=1`, the default when a C toolchain is |
| 61 | +present), because reaching libcoz means calling `dlsym`. With `CGO_ENABLED=0` |
| 62 | +this package still builds — every entry point compiles to a no-op — so you can |
| 63 | +leave progress points in code that also ships as a static binary. |
| 64 | + |
| 65 | +Coz needs DWARF line tables, and it cannot read the compressed DWARF that Go's |
| 66 | +linker emits by default. Build with compression off: |
| 67 | + |
| 68 | +``` |
| 69 | +go build -ldflags=-compressdwarf=false -o myapp . |
| 70 | +coz run --- ./myapp |
| 71 | +coz plot --text |
| 72 | +``` |
| 73 | + |
| 74 | +Without `-compressdwarf=false`, Go emits `.zdebug_*` (ELF) / `__zdebug_*` |
| 75 | +(Mach-O) sections and coz will report "Debug information was not found." |
| 76 | + |
| 77 | +If line attribution looks coarse because of inlining, also pass |
| 78 | +`-gcflags=all=-l` to disable inlining, or `-gcflags=all='-N -l'` to disable |
| 79 | +optimization entirely. Both change the performance profile of the program, so |
| 80 | +prefer leaving them off unless you need the extra source fidelity. |
| 81 | + |
| 82 | +## Example |
| 83 | + |
| 84 | +`example/toy.go` runs two goroutines per round; one does twice the work of the |
| 85 | +other, so it sits on the critical path. |
| 86 | + |
| 87 | +``` |
| 88 | +go build -ldflags=-compressdwarf=false -o toy ./example |
| 89 | +coz run --- ./toy |
| 90 | +coz plot --text |
| 91 | +``` |
| 92 | + |
| 93 | +``` |
| 94 | +Source Line | Slope | R² | Max Speedup | Points |
| 95 | +---------------------------+---------+-------+-------------+------- |
| 96 | +go/example/toy.go:35 | 1.082 | 0.91 | + 29.9% | 4 |
| 97 | +go/example/toy.go:41 | 0.137 | 1.00 | + 8.9% | 2 |
| 98 | +``` |
| 99 | + |
| 100 | +Line 35 is the loop inside `slowWork` and line 41 the loop inside `fastWork`. |
| 101 | +Coz correctly predicts that speeding up `slowWork` speeds up the program roughly |
| 102 | +proportionally, while `fastWork` is nearly irrelevant. |
| 103 | + |
| 104 | +## Caveats |
| 105 | + |
| 106 | +**Do not use `runtime/pprof` CPU profiling at the same time.** Coz samples with |
| 107 | +`SIGPROF`, which is the same signal Go's own CPU profiler uses; the two cannot |
| 108 | +both own it. Calling `pprof.StartCPUProfile` under `coz run` will fight coz for |
| 109 | +the signal. Memory, block, and mutex profiles are unaffected. |
| 110 | + |
| 111 | +**Results are per-OS-thread, not per-goroutine.** Coz's virtual speedup works by |
| 112 | +delaying threads. Go multiplexes goroutines onto OS threads (`GOMAXPROCS`), so a |
| 113 | +progress point tells you about the thread that executed it, and a goroutine that |
| 114 | +migrates between threads is not tracked as a unit. In practice this is fine for |
| 115 | +CPU-bound work, but a goroutine that is descheduled mid-operation may attribute |
| 116 | +some of its delay elsewhere. |
| 117 | + |
| 118 | +**Progress points must be reached often enough.** Coz needs at least a handful of |
| 119 | +progress-point visits per experiment (roughly 5), and each experiment runs for |
| 120 | +about half a second. A program that reaches its progress point a dozen times |
| 121 | +total will produce very few data points. |
| 122 | + |
| 123 | +**On Linux, `coz plot` reports `Runtime: 0.0s` for Go programs.** Go's runtime |
| 124 | +exits with a direct `exit_group` syscall rather than libc's `exit`, so coz's |
| 125 | +shutdown hook never runs and the final `runtime` record is not written. The |
| 126 | +per-experiment records are flushed as they complete, so the profile itself is |
| 127 | +intact; only the total-runtime line (used for phase correction) is missing. |
| 128 | + |
| 129 | +## How it works |
| 130 | + |
| 131 | +`coz_shim.c` resolves `_coz_get_counter` and `_coz_add_delays` out of the |
| 132 | +injected `libcoz` with `dlsym(RTLD_DEFAULT, ...)`. That means the package does |
| 133 | +not need `coz.h` installed at build time, and a binary built against it runs |
| 134 | +normally when `libcoz` is absent — every entry point degrades to a no-op. |
| 135 | + |
| 136 | +Incrementing a counter is a plain relaxed atomic add on memory owned by `libcoz`, |
| 137 | +performed from Go, so there is no cgo call on the hot path on Linux. On macOS |
| 138 | +each progress point additionally calls `_coz_add_delays()`, because macOS has no |
| 139 | +per-thread sampling timer and a worker thread only discovers the virtual delay it |
| 140 | +owes when it reaches a progress point. This mirrors `_COZ_CHECK_DELAYS` in |
| 141 | +`include/coz.h`. |
0 commit comments