From 08f0775b42f8be0ae24881476320da0ab2fe38ae Mon Sep 17 00:00:00 2001 From: diego Date: Tue, 6 Oct 2026 10:04:38 -0300 Subject: [PATCH] gpu: the agent never said when it dropped GPU records gpuprobe.Stats already counted every kind of loss -- KernelDropped, StacksEvicted, SequenceGaps, StacksMissing, SinkRejected -- and nothing printed them. gpuprofile.Profiler exposed no Stats() at all, so the agent could not read them even in principle. A capture that lost most of its GPU work still reported only "GPU profile written to ... (N samples)", and N alone cannot tell a quiet GPU from a lossy capture. Same shape as #109, where the debuginfod counters existed and nothing printed them. Measured on an RTX 3090, same PyTorch workload and 25s window, with only PERFAGENT_GPU_SAMPLE_PERIOD differing: period=8 records=45316 lost=2653 (5.5%) period=1 records=8507 lost=77289 (90%) kernel_dropped dominates: 2436 then 57353. The adapter is not at fault -- run with PERFAGENT_GPU_LOG and no agent attached it emits identically at both periods (launches=35404 activity_kernels=35404 launch_batch_dropped=0 cupti_dropped=0) and the sampler is exact (4406 sampled at 8, all 35404 at 1). The loss is the BPF event ringbuf, a compiled-in 4 MB with no override. What overflows is the CUPTI kernel activity records, and those carry the GPU time itself -- so lowering the sampling period to buy attribution SHRINKS the profile instead of merely coarsening it. That is the opposite of what the knob reads like it does, and nothing in the output said so. So: Profiler.Stats(), a "gpu: LOST" line naming each counter when any is non-zero, and --gpu-ring-bytes to size the buffer. The size is rounded up to a power-of-two page multiple and bounded, because the kernel rejects a bad max_entries with a bare EINVAL far from the knob that set it. Verified, same workload and window, period=1, ring size the only difference: 4 MB (default) records=3645 kernel_dropped=41149 seq_gaps=13340 64 MB records=16119 kernel_dropped=0 seq_gaps=0 Both overflow counters go to exactly zero and 4.4x more records survive, which is the signature of relieving ring overflow rather than a general improvement. One limit on that result: it is a single pair. Four confirmation runs returned either an empty capture or a workload that never finished, on a GPU that had started failing with cudaErrorLaunchTimeout, so n=2 is owed once the machine is healthy. Attribution is a fair question to ask of a change like this, and the answer is that record loss depresses it. With --profile alongside --gpu, period 8 attached 2618 of 2621 resolved stacks (99.9%) while period 1 attached 1246 of 4735 (26.3%) -- the kernel records a stack would attach TO are exactly what the ringbuf was dropping. Recovering the records should recover most of that, but this PR does not measure it, so it does not claim it. --- gpuprobe/consumer.go | 48 +++++++++++++++++++++++++++++++++ gpuprobe/ringbytes_test.go | 55 ++++++++++++++++++++++++++++++++++++++ gpuprofile/profiler.go | 14 ++++++++++ main.go | 11 +++++++- perfagent/agent.go | 35 ++++++++++++++++++++++++ perfagent/options.go | 17 ++++++++++++ 6 files changed, 179 insertions(+), 1 deletion(-) create mode 100644 gpuprobe/ringbytes_test.go diff --git a/gpuprobe/consumer.go b/gpuprobe/consumer.go index e558685..a19aba5 100644 --- a/gpuprobe/consumer.go +++ b/gpuprobe/consumer.go @@ -437,6 +437,12 @@ type Config struct { // an offer that would pass it is refused and counted, again in // CubinsRejectedTooLarge. CubinTotalBytes int64 + + // EventRingBytes sizes the BPF event ringbuf. Zero keeps the + // compiled-in 4 MB. Must be a power of two and a multiple of the page + // size -- the kernel rejects anything else, so it is rounded up and + // validated here rather than failing deep in the verifier. + EventRingBytes int } const ( @@ -1703,6 +1709,28 @@ func Attach(cfg Config) (c *Consumer, err error) { } }() + // Size the event ringbuf before load. The compiled-in 4 MB holds a + // default-period capture comfortably, but the event rate scales with + // 1/PERFAGENT_GPU_SAMPLE_PERIOD: at period=1 a PyTorch step rate that + // loses ~5% of records at the default loses ~90%, nearly all of it + // kernel_dropped -- batches the ringbuf had no room for. Those carry the + // kernel activity records that ARE the GPU time, so the profile shrinks + // rather than merely losing attribution. Raising the buffer is what lets + // a low period mean "more attribution" instead of "less profile". + if c.cfg.EventRingBytes > 0 { + m, ok := spec.Maps["events"] + if !ok { + err = fmt.Errorf("event ringbuf map %q not in spec", "events") + return + } + size, rerr := roundRingBytes(c.cfg.EventRingBytes) + if rerr != nil { + err = rerr + return + } + m.MaxEntries = size + } + if err = spec.LoadAndAssign(&c.objs, nil); err != nil { err = fmt.Errorf("load gpu usdt objects: %w", err) return @@ -3376,3 +3404,23 @@ func (c *Consumer) Close() error { errs = append(errs, c.objs.Close()) return errors.Join(errs...) } + +// roundRingBytes rounds n up to a power of two that is also a multiple of the +// page size, which is what BPF_MAP_TYPE_RINGBUF requires of max_entries. The +// kernel rejects a bad size at load time with a bare EINVAL, far from the +// knob that caused it, so the rounding and the bound both happen here. +func roundRingBytes(n int) (uint32, error) { + if n <= 0 { + return 0, fmt.Errorf("event ringbuf size must be positive, got %d", n) + } + const maxRingBytes = 1 << 30 // 1 GiB of locked memory is already absurd + if n > maxRingBytes { + return 0, fmt.Errorf("event ringbuf size %d exceeds the %d-byte cap", n, maxRingBytes) + } + page := os.Getpagesize() + size := page + for size < n { + size <<= 1 + } + return uint32(size), nil +} diff --git a/gpuprobe/ringbytes_test.go b/gpuprobe/ringbytes_test.go new file mode 100644 index 0000000..733d44a --- /dev/null +++ b/gpuprobe/ringbytes_test.go @@ -0,0 +1,55 @@ +package gpuprobe + +import ( + "os" + "testing" +) + +// TestRoundRingBytes pins the two properties BPF_MAP_TYPE_RINGBUF requires of +// max_entries -- a power of two, and a multiple of the page size -- plus the +// bounds. A size that satisfies neither is rejected by the verifier with a +// bare EINVAL far from the knob that set it, which is what this rounding is +// for. +func TestRoundRingBytes(t *testing.T) { + page := os.Getpagesize() + + t.Run("rounds up to a power-of-two page multiple", func(t *testing.T) { + for _, in := range []int{1, page - 1, page, page + 1, 4 << 20, (4 << 20) + 1, 100 << 20} { + got, err := roundRingBytes(in) + if err != nil { + t.Fatalf("roundRingBytes(%d): unexpected error %v", in, err) + } + n := int(got) + if n < in { + t.Errorf("roundRingBytes(%d) = %d, rounded DOWN", in, n) + } + if n&(n-1) != 0 { + t.Errorf("roundRingBytes(%d) = %d, not a power of two", in, n) + } + if n%page != 0 { + t.Errorf("roundRingBytes(%d) = %d, not a multiple of page %d", in, n, page) + } + // Rounding up must not overshoot past the next power of two. + if in > page && n >= in*2 { + t.Errorf("roundRingBytes(%d) = %d, overshot", in, n) + } + } + }) + + t.Run("rejects non-positive", func(t *testing.T) { + for _, in := range []int{0, -1, -(4 << 20)} { + if _, err := roundRingBytes(in); err == nil { + t.Errorf("roundRingBytes(%d): want error, got nil", in) + } + } + }) + + t.Run("rejects absurd", func(t *testing.T) { + if _, err := roundRingBytes((1 << 30) + 1); err == nil { + t.Error("roundRingBytes(1GiB+1): want error, got nil") + } + if _, err := roundRingBytes(1 << 30); err != nil { + t.Errorf("roundRingBytes(1GiB): want ok, got %v", err) + } + }) +} diff --git a/gpuprofile/profiler.go b/gpuprofile/profiler.go index 43e136e..12523c4 100644 --- a/gpuprofile/profiler.go +++ b/gpuprofile/profiler.go @@ -71,6 +71,10 @@ type Config struct { // to a busy process overruns them and loses GPU time outright. Zero means // DefaultDrainEvery. DrainEvery time.Duration + + // EventRingBytes sizes the BPF event ringbuf. Zero keeps the + // compiled-in default, which is sized for a default-period capture. + EventRingBytes int } // DefaultDrainEvery matches cmd/gpu-cuda-profile's default. @@ -136,6 +140,7 @@ func New(cfg Config) (*Profiler, error) { Symbolizer: cfg.Symbolizer, Modules: store, KeepInstrumentationFrames: cfg.KeepInstrumentationFrames, + EventRingBytes: cfg.EventRingBytes, }) if err != nil { return nil, fmt.Errorf("gpuprofile: attach to %s: %w", cfg.ShimPath, err) @@ -241,6 +246,15 @@ func (p *Profiler) Samples() int { return p.samples } +// Stats reports the consumer's ingestion counters: what arrived off the +// ringbuf and what was lost on the way. The profile alone cannot show this -- +// a capture that dropped most of its launches still writes a well-formed +// profile, just a smaller one -- so the caller needs the counters to tell a +// quiet GPU from a lossy capture. +func (p *Profiler) Stats() gpuprobe.Stats { + return p.consumer.Stats() +} + // stop cancels the run loop once and waits for the final drain. func (p *Profiler) stop() { p.mu.Lock() diff --git a/main.go b/main.go index 038c567..4cb6174 100644 --- a/main.go +++ b/main.go @@ -42,7 +42,13 @@ var ( flagGPUShim = flag.String("gpu-shim", "", "The CUPTI adapter the target loaded. Must be the SAME FILE it mapped: the uprobe attaches "+ "by inode, so identical bytes at another path is a different target and nothing is captured") - flagGPUOutput = flag.String("gpu-output", "", "Output path for GPU profile (default: auto-generated)") + flagGPUOutput = flag.String("gpu-output", "", "Output path for GPU profile (default: auto-generated)") + flagGPURingBytes = flag.Int("gpu-ring-bytes", 0, + "Size of the BPF event ringbuf for --gpu, in bytes (rounded up to a "+ + "power-of-two page multiple; 0 keeps the 4MB default). Lowering "+ + "PERFAGENT_GPU_SAMPLE_PERIOD in the target multiplies the event rate, "+ + "and the records that overflow carry the GPU time itself, so an "+ + "undersized buffer SHRINKS the profile. Check the 'gpu: LOST' line") flagPMUOutput = flag.String("pmu-output", "", "Output path for PMU metrics (default: stdout)") flagFlamegraph = flag.String("flamegraph-output", "", "Also write a self-contained interactive HTML flame graph of the profile. "+ @@ -258,6 +264,9 @@ func buildOptions() []perfagent.Option { perfagent.WithGPU(*flagGPUShim), perfagent.WithGPUProfilePath(outputPath), ) + if *flagGPURingBytes > 0 { + opts = append(opts, perfagent.WithGPUEventRingBytes(*flagGPURingBytes)) + } if path := flamegraphPath(*flagFlamegraph, "gpu"); path != "" { opts = append(opts, perfagent.WithGPUFlamegraph(path)) diff --git a/perfagent/agent.go b/perfagent/agent.go index 1c9e6ac..82e18c0 100644 --- a/perfagent/agent.go +++ b/perfagent/agent.go @@ -622,6 +622,7 @@ func (a *Agent) Start(ctx context.Context) error { Symbolizer: a.symbolizer, PCSampling: a.config.GPUPCSampling, KeepInstrumentationFrames: a.config.GPUKeepInstrumentationFrames, + EventRingBytes: a.config.GPUEventRingBytes, }) if err != nil { a.cleanup() @@ -858,9 +859,43 @@ func (a *Agent) logDebuginfodStats() { st.FileModeAddrs, st.FileModeFetchFails, st.FileModeLocalHits, st.FileModeParseFails) } +// logGPUStats prints the GPU consumer's ingestion counters. +// +// Same shape as issue #109: the counters existed in gpuprobe.Stats and +// nothing printed them, so a capture that lost most of its GPU work still +// reported only "GPU profile written to ... (N samples)" and looked like a +// success. N alone cannot distinguish a quiet GPU from a lossy capture. +// +// The loss counters are called out separately from the volume ones because +// a non-zero value in any of them means the profile under-reports: samples +// the kernel could not deliver, and stacks evicted from the side table +// before their kernel record arrived, are both GPU work that happened and +// is not in the file. +func (a *Agent) logGPUStats() { + if a.gpuProfiler == nil { + return + } + st := a.gpuProfiler.Stats() + log.Printf("perf-agent: gpu: batches=%d records=%d sampled_launches=%d "+ + "stacks_resolved=%d stacks_attached=%d", + st.Batches, st.Records, st.SampledLaunches, + st.StacksResolved, st.StacksAttached) + if lost := st.KernelDropped + st.StacksEvicted + st.SequenceGaps + + st.StacksMissing + st.SinkRejected; lost > 0 { + log.Printf("perf-agent: gpu: LOST %d record(s): kernel_dropped=%d "+ + "stacks_evicted=%d sequence_gaps=%d stacks_missing=%d sink_rejected=%d "+ + "-- the profile under-reports GPU work. A smaller "+ + "PERFAGENT_GPU_SAMPLE_PERIOD raises the event rate and makes this "+ + "worse; raise the period or shorten the capture", + lost, st.KernelDropped, st.StacksEvicted, st.SequenceGaps, + st.StacksMissing, st.SinkRejected) + } +} + // cleanup releases profiler resources. func (a *Agent) cleanup() { a.logDebuginfodStats() + a.logGPUStats() if a.cpuProfiler != nil { a.cpuProfiler.Close() a.cpuProfiler = nil diff --git a/perfagent/options.go b/perfagent/options.go index ce2eb73..dc9e70f 100644 --- a/perfagent/options.go +++ b/perfagent/options.go @@ -68,6 +68,10 @@ type Config struct { // identical bytes at another path is a different target. GPUShimPath string + // GPUEventRingBytes sizes the BPF event ringbuf for the GPU pipeline. + // Zero keeps the compiled-in default. See WithGPUEventRingBytes. + GPUEventRingBytes int + // GPUProfilePath is the output path for the GPU profile. GPUProfilePath string @@ -373,6 +377,19 @@ func WithGPU(shimPath string) Option { } } +// WithGPUEventRingBytes sizes the BPF event ringbuf for the GPU pipeline. +// +// The default is sized for a capture at the shim's default sampling period. +// Lowering PERFAGENT_GPU_SAMPLE_PERIOD in the target multiplies the event +// rate, and the records that overflow are the kernel activity records that +// carry GPU time -- so an undersized buffer shrinks the profile rather than +// just coarsening it. Zero keeps the default. +func WithGPUEventRingBytes(n int) Option { + return func(c *Config) { + c.GPUEventRingBytes = n + } +} + // WithGPUProfilePath sets where the GPU profile is written. func WithGPUProfilePath(path string) Option { return func(c *Config) { c.GPUProfilePath = path }