Skip to content

Commit 6dd8b0b

Browse files
pdrobnjakclaude
andcommitted
fix(benchmark): capture CPU and fgprof profiles sequentially to avoid corruption
Go's CPU profiler and fgprof conflict when running concurrently on the same process, producing empty or corrupted profiles. Switch from parallel background captures to sequential execution (CPU first, then fgprof), measure actual capture duration for accurate remaining-time calculation, and make BASE_DIR overridable so benchmark-compare.sh can route profiles to per-label directories. Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
1 parent d22930c commit 6dd8b0b

File tree

2 files changed

+57
-49
lines changed

2 files changed

+57
-49
lines changed

benchmark/benchmark-compare.sh

Lines changed: 36 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -171,6 +171,7 @@ for i in $(seq 0 $((NUM-1))); do
171171

172172
BENCHMARK_PHASE=start \
173173
SEI_HOME="$home_dir" \
174+
BASE_DIR="$BASE_DIR/$label" \
174175
SEID_BIN="$seid" \
175176
PORT_OFFSET="$port_offset" \
176177
LOG_FILE="$log_file" \
@@ -192,7 +193,11 @@ sleep "$PPROF_WAIT" || true
192193

193194
echo ""
194195
echo "=== Capturing profiles (30s CPU + 30s fgprof + heap + goroutine + block + mutex) ==="
195-
PPROF_PIDS=()
196+
set +e
197+
PROFILE_CAPTURE_START=$(date +%s)
198+
199+
# Capture CPU across all nodes first, then fgprof, then remaining profiles.
200+
# CPU and fgprof cannot run together on the same process.
196201
for i in $(seq 0 $((NUM-1))); do
197202
label="${LABELS[$i]}"
198203
port_offset=$((i * 100))
@@ -201,44 +206,57 @@ for i in $(seq 0 $((NUM-1))); do
201206
mkdir -p "$profile_dir"
202207

203208
# CPU profile (30s) — on-CPU time only
209+
echo " [$label] capturing cpu"
204210
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/profile?seconds=30" \
205-
-o "$profile_dir/cpu.pb.gz" &
206-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
211+
-o "$profile_dir/cpu.pb.gz"
212+
done
213+
214+
for i in $(seq 0 $((NUM-1))); do
215+
label="${LABELS[$i]}"
216+
port_offset=$((i * 100))
217+
PPROF_PORT=$((6060 + port_offset))
218+
profile_dir="$BASE_DIR/$label/pprof"
207219

208220
# fgprof (30s) — wall-clock time (on-CPU + off-CPU/I/O/blocking)
221+
echo " [$label] capturing fgprof"
209222
curl -s "http://localhost:${PPROF_PORT}/debug/fgprof?seconds=30" \
210-
-o "$profile_dir/fgprof.pb.gz" &
211-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
223+
-o "$profile_dir/fgprof.pb.gz"
224+
done
225+
226+
for i in $(seq 0 $((NUM-1))); do
227+
label="${LABELS[$i]}"
228+
port_offset=$((i * 100))
229+
PPROF_PORT=$((6060 + port_offset))
230+
profile_dir="$BASE_DIR/$label/pprof"
231+
232+
echo " [$label] capturing heap/goroutine/block/mutex"
212233

213234
# Heap snapshot
214235
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/heap?debug=0" \
215-
-o "$profile_dir/heap.pb.gz" &
216-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
236+
-o "$profile_dir/heap.pb.gz"
217237

218238
# Goroutine dump
219239
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/goroutine?debug=0" \
220-
-o "$profile_dir/goroutine.pb.gz" &
221-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
240+
-o "$profile_dir/goroutine.pb.gz"
222241

223242
# Block profile (time waiting on channels/mutexes)
224243
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/block?debug=0" \
225-
-o "$profile_dir/block.pb.gz" &
226-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
244+
-o "$profile_dir/block.pb.gz"
227245

228246
# Mutex contention profile
229247
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/mutex?debug=0" \
230-
-o "$profile_dir/mutex.pb.gz" &
231-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
248+
-o "$profile_dir/mutex.pb.gz"
232249

233250
echo " [$label] capturing from localhost:${PPROF_PORT} -> $profile_dir/"
234251
done
235252

236-
# Wait for all profile captures to finish
237-
for pid in "${PPROF_PIDS[@]}"; do
238-
wait "$pid" 2>/dev/null || true
239-
done
240253
echo " profile capture complete."
241254

255+
set -e
256+
257+
PROFILE_CAPTURE_END=$(date +%s)
258+
PROFILE_CAPTURE_SECS=$(( PROFILE_CAPTURE_END - PROFILE_CAPTURE_START ))
259+
242260
# Verify profile sizes
243261
for i in $(seq 0 $((NUM-1))); do
244262
label="${LABELS[$i]}"
@@ -253,7 +271,7 @@ for i in $(seq 0 $((NUM-1))); do
253271
done
254272

255273
# Wait remaining time
256-
REMAINING=$(( DURATION - PPROF_WAIT - 30 ))
274+
REMAINING=$(( DURATION - PPROF_WAIT - PROFILE_CAPTURE_SECS ))
257275
if [ "$REMAINING" -gt 0 ]; then
258276
echo ""
259277
echo " Continuing benchmark for ${REMAINING}s..."

benchmark/benchmark.sh

Lines changed: 21 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -325,7 +325,7 @@ fi
325325

326326
if [ "$DURATION" -gt 0 ] 2>/dev/null; then
327327
# ---- Timed run: background seid, capture profiles, extract TPS ----
328-
BASE_DIR="/tmp/sei-bench"
328+
BASE_DIR="${BASE_DIR:-/tmp/sei-bench}"
329329
PROFILE_DIR="$BASE_DIR/pprof"
330330
mkdir -p "$PROFILE_DIR"
331331

@@ -352,47 +352,37 @@ if [ "$DURATION" -gt 0 ] 2>/dev/null; then
352352
sleep "$PPROF_WAIT" || true
353353

354354
echo ""
355-
echo "=== Capturing profiles (30s CPU + 30s fgprof + heap + goroutine + block + mutex) ==="
356-
PPROF_PIDS=()
355+
echo "=== Capturing profiles (30s CPU + 30s fgprof + others) ==="
356+
set +e
357+
PROFILE_CAPTURE_START=$(date +%s)
357358

358-
# CPU profile (30s)
359+
# Capture sequentially to avoid runtime conflicts:
360+
# Go pprof CPU and fgprof profiling cannot run at the same time.
361+
echo " capturing cpu profile ..."
359362
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/profile?seconds=30" \
360-
-o "$PROFILE_DIR/cpu.pb.gz" &
361-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
363+
-o "$PROFILE_DIR/cpu.pb.gz"
362364

363-
# fgprof (30s) — wall-clock time
365+
echo " capturing fgprof ..."
364366
curl -s "http://localhost:${PPROF_PORT}/debug/fgprof?seconds=30" \
365-
-o "$PROFILE_DIR/fgprof.pb.gz" &
366-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
367+
-o "$PROFILE_DIR/fgprof.pb.gz"
367368

368-
# Heap snapshot
369+
echo " capturing heap/goroutine/block/mutex ..."
369370
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/heap?debug=0" \
370-
-o "$PROFILE_DIR/heap.pb.gz" &
371-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
372-
373-
# Goroutine dump
371+
-o "$PROFILE_DIR/heap.pb.gz"
374372
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/goroutine?debug=0" \
375-
-o "$PROFILE_DIR/goroutine.pb.gz" &
376-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
377-
378-
# Block profile
373+
-o "$PROFILE_DIR/goroutine.pb.gz"
379374
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/block?debug=0" \
380-
-o "$PROFILE_DIR/block.pb.gz" &
381-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
382-
383-
# Mutex contention profile
375+
-o "$PROFILE_DIR/block.pb.gz"
384376
curl -s "http://localhost:${PPROF_PORT}/debug/pprof/mutex?debug=0" \
385-
-o "$PROFILE_DIR/mutex.pb.gz" &
386-
PPROF_PIDS=("${PPROF_PIDS[@]}" $!)
377+
-o "$PROFILE_DIR/mutex.pb.gz"
387378

388-
echo " Capturing from localhost:${PPROF_PORT} -> $PROFILE_DIR/"
389-
390-
# Wait for all profile captures to finish
391-
for pid in "${PPROF_PIDS[@]}"; do
392-
wait "$pid" 2>/dev/null || true
393-
done
379+
echo " capturing from localhost:${PPROF_PORT} -> $PROFILE_DIR/"
394380
echo " Profile capture complete."
395381

382+
PROFILE_CAPTURE_END=$(date +%s)
383+
PROFILE_CAPTURE_SECS=$(( PROFILE_CAPTURE_END - PROFILE_CAPTURE_START ))
384+
set -e
385+
396386
# Verify profile sizes
397387
cpu_size=$(wc -c < "$PROFILE_DIR/cpu.pb.gz" 2>/dev/null | tr -d ' ' || echo 0)
398388
fgprof_size=$(wc -c < "$PROFILE_DIR/fgprof.pb.gz" 2>/dev/null | tr -d ' ' || echo 0)
@@ -403,7 +393,7 @@ if [ "$DURATION" -gt 0 ] 2>/dev/null; then
403393
echo " cpu=${cpu_size}B fgprof=${fgprof_size}B heap=${heap_size}B goroutine=${goroutine_size}B block=${block_size}B mutex=${mutex_size}B"
404394

405395
# Wait remaining time
406-
REMAINING=$(( DURATION - PPROF_WAIT - 30 ))
396+
REMAINING=$(( DURATION - PPROF_WAIT - PROFILE_CAPTURE_SECS ))
407397
if [ "$REMAINING" -gt 0 ]; then
408398
echo ""
409399
echo " Continuing benchmark for ${REMAINING}s..."

0 commit comments

Comments
 (0)