DanSandClaude Opus 5.5
7131b3673f
shim/ is an LD_PRELOAD guard around close/fclose/dup2/dup3: - before each close it resolves /proc/self/fd/N; - it reports, with a backtrace, a non-owner close of wallet.dat, database/log.* or blocks/*.dat, and every close that fails with EBADF (the second half of a double close); - FDGUARD_ABORT=1 aborts on the first hit; - run_tests.sh self-tests it (51 checks). repro/ runs a shimmed dragonxd on isolated regtest. Each run gets its own unprivileged network namespace (loopback only). The loads are: - rpc: a hammer with impatient/RST/half-open clients, work-queue bursts and long-polls; - p2p: TLS peers churned by disconnectnode, ban and kill, plus a raw TCP/TLS misbehaver; - tor: a fake control port; - mine: mining with blocknotify and autoshield. tools/tally.py groups the reports by closer. tools/scan_bdb.py finds BDB pages written into block files. With the wolfSSL CloseSocket macro in effect: - p2pmin (300 s) gives one EBADF double close per disconnect; - the full load (1200 s) gives 930 EBADF closes, 186 non-owner closes (37 of wallet/log/blk files) and a 632 KB db.log with BDB0060 PANIC; - RPC-only and Tor-only loads give none. After the fix, every count is 0 and db.log stays empty. The README has the commands and the numbers. Paths come from the environment (GOLDEN, BIN, RUNS, SHIM, ASMAP and the Sapling params). Run output goes to $RUNS, outside the tree. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
157 lines
9.6 KiB
Bash
Executable File
157 lines
9.6 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# run.sh <name> <seconds> -- run INSIDE the network namespace (go.sh does that).
|
|
# Env knobs:
|
|
# LOADS=rpc,p2p,tor,mine which load generators run (default all four); p2pmin = 1 helper + disconnectnode every DISC_INT s
|
|
# WQ=4 RT=2 -rpcworkqueue / -rpcthreads of the target
|
|
# GUARD=all FDGUARD_GUARD (db,blk | all)
|
|
# SHIMON=1 run the target under LD_PRELOAD=libfdguard.so
|
|
# STRACE=0 1 = also wrap the target in strace (failed fd syscalls only)
|
|
# TRACE=0 1 = FDGUARD_TRACE_ALL (one line per open/close; big)
|
|
# MINE_INT=3 seconds between generate 1
|
|
# HAMMER_ARGS=... override the hammer thread mix
|
|
# STOP_ON_HIT=0 1 = end the run 60 s after the first NON-OWNER db/blk close
|
|
# EXTRA=... extra target args
|
|
source "$REPRO/common.sh"
|
|
NAME=$1; DUR=${2:-600}
|
|
OUT=$RUNS/$NAME
|
|
LOADS=${LOADS:-rpc,p2p,tor,mine}; WQ=${WQ:-4}; RT=${RT:-2}; GUARD=${GUARD:-all}
|
|
SHIMON=${SHIMON:-1}; STRACE=${STRACE:-0}; TRACE=${TRACE:-0}; MINE_INT=${MINE_INT:-3}
|
|
STOP_ON_HIT=${STOP_ON_HIT:-0}
|
|
HAMMER_ARGS=${HAMMER_ARGS:---normal 8 --impatient 8 --slowfire 2 --halfopen 3 --pipeline 3 --garbage 2 --slowread 2 --longpoll 4 --burst-size 16 --burst-every 2}
|
|
has() { case ",$LOADS," in *",$1,"*) return 0;; esac; return 1; }
|
|
|
|
mkdir -p "$OUT/logs"; rm -f "$OUT/STOP"
|
|
DD_T=$OUT/target; DD_H1=$OUT/helper1; DD_H2=$OUT/helper2
|
|
exec > >(tee -a "$OUT/run.txt") 2>&1
|
|
echo "=== repro run $NAME $(date -u +%FT%TZ) dur=${DUR}s loads=$LOADS wq=$WQ rt=$RT guard=$GUARD shim=$SHIMON strace=$STRACE"
|
|
echo "netns check (must be ENETUNREACH=101): $(python3 -c 'import socket;print(socket.socket().connect_ex(("1.1.1.1",80)))')"
|
|
echo "binary: $DRAGONXD build-id: $(readelf -n "$DRAGONXD" | awk '/Build ID/{print $3}')"
|
|
echo "dragonxd already running in this namespace? $(pgrep -a -x dragonxd | wc -l) (other agents' nodes live in other namespaces)"
|
|
|
|
PIDS=()
|
|
cleanup() {
|
|
echo "--- cleanup $(date -u +%T)"
|
|
touch "$OUT/STOP"
|
|
for p in "${PIDS[@]}"; do kill "$p" 2>/dev/null; done
|
|
stop_daemon "$DD_H2" "$RPC_H2"; stop_daemon "$DD_H1" "$RPC_H1"
|
|
if [ -n "$TPID" ] && kill -0 "$TPID" 2>/dev/null; then
|
|
timeout 20 "$CLI" -regtest -datadir="$DD_T" -rpcuser=$RPCUSER -rpcpassword=$RPCPASS -rpcport=$RPC_T stop >/dev/null 2>&1
|
|
for _ in $(seq 1 60); do kill -0 "$TPID" 2>/dev/null || break; sleep 1; done
|
|
# abandoned longpoll getblocktemplate calls can hold every -rpcthreads worker, so RPC stop may never run:
|
|
# fall back to SIGTERM (same clean StartShutdown path), SIGKILL only as a last resort
|
|
kill -0 "$TPID" 2>/dev/null && { echo "RPC stop did not finish in 60 s -> SIGTERM"; kill -TERM "$TPID"; }
|
|
for _ in $(seq 1 180); do kill -0 "$TPID" 2>/dev/null || break; sleep 1; done
|
|
kill -0 "$TPID" 2>/dev/null && { echo "target did not stop -> SIGKILL"; kill -9 "$TPID"; }
|
|
fi
|
|
[ -n "$WPID" ] && wait "$WPID" 2>/dev/null; echo "target exit status: $?"
|
|
for p in "${PIDS[@]}"; do kill -9 "$p" 2>/dev/null; done
|
|
summarize
|
|
}
|
|
summarize() {
|
|
local DL=$DD_T/regtest/debug.log
|
|
echo "=== markers in target debug.log"
|
|
for m in "${MARKERS[@]}"; do printf ' [%6d] %s\n' "$(grep -c -- "$m" "$DL" 2>/dev/null)" "$m"; done
|
|
echo " db.log bytes: $(stat -c %s "$DD_T/regtest/db.log" 2>/dev/null || echo absent)"
|
|
grep -q 'Shutdown: done' "$DL" && echo " clean shutdown: yes" || echo " clean shutdown: NO"
|
|
if [ "$SHIMON" = 1 ]; then
|
|
echo "=== fdguard reports"; grep -o '=== FDGUARD #[0-9]* [A-Z-]*' "$OUT/fdguard.log" | awk '{print $4}' | sort | uniq -c
|
|
grep '^S ' "$OUT/fdguard.log" | tail -1
|
|
python3 "$REPRO/../shim/symbolize.py" --summary "$OUT/fdguard.log" > "$OUT/fdguard.summary.txt" 2>&1
|
|
head -60 "$OUT/fdguard.summary.txt"
|
|
fi
|
|
echo "=== BDB-page-in-blockfile detector"
|
|
python3 "$REPRO/tools/scan_bdb.py" "$DD_T"/regtest/blocks/blk*.dat "$DD_T"/regtest/blocks/rev*.dat 2>&1 | tail -15
|
|
echo "=== end $(date -u +%FT%TZ)"
|
|
}
|
|
trap cleanup EXIT
|
|
trap 'exit 130' INT TERM
|
|
|
|
echo "--- prep datadirs"
|
|
prep_golden "$DD_T"
|
|
prep_fresh "$DD_H1" "$RPC_H1"; prep_fresh "$DD_H2" "$RPC_H2"
|
|
cat > "$OUT/blocknotify.sh" <<EOF
|
|
#!/bin/sh
|
|
# pool-like blocknotify: a couple of dragonx-cli calls per block
|
|
$CLI -regtest -datadir=$DD_T -rpcuser=$RPCUSER -rpcpassword=$RPCPASS -rpcport=$RPC_T getblock "\$1" >/dev/null 2>&1
|
|
$CLI -regtest -datadir=$DD_T -rpcuser=$RPCUSER -rpcpassword=$RPCPASS -rpcport=$RPC_T getblocktemplate >/dev/null 2>&1
|
|
echo "\$(date +%s) \$1" >> $OUT/logs/blocknotify.log
|
|
EOF
|
|
chmod +x "$OUT/blocknotify.sh"
|
|
|
|
if has tor; then
|
|
nice -n 10 python3 "$REPRO/tools/faketor.py" --port $TORPORT > "$OUT/logs/faketor.txt" 2>&1 & PIDS+=($!)
|
|
TORARGS="-listenonion=1 -torcontrol=127.0.0.1:$TORPORT -debug=tor"
|
|
else
|
|
TORARGS="-listenonion=0"
|
|
fi
|
|
if has p2p || has p2pmin; then P2PARGS="-listen=1 -bind=127.0.0.1 -port=$P2P_T -allowlist=127.0.0.0/8 -maxinboundfromip=100"
|
|
else P2PARGS="-listen=0 -port=$P2P_T"; fi
|
|
|
|
TARGS=(-regtest -datadir="$DD_T" -testnode=1 -checkpoints=0 $P2PARGS -connect=127.0.0.1:1 -dnsseed=0 -dns=0
|
|
-asmap="$DD_T/asmap.dat" -rpcuser=$RPCUSER -rpcpassword=$RPCPASS -rpcport=$RPC_T
|
|
-txindex=1 -autoshield=1 -rpcworkqueue=$WQ -rpcthreads=$RT
|
|
"-blocknotify=$OUT/blocknotify.sh %s" $TORARGS -debug=net -debug=tls -printtoconsole=0 -daemon=0 $EXTRA)
|
|
echo "target args: ${TARGS[*]}" | sed "s/$RPCPASS/***/g"
|
|
ENVV=()
|
|
if [ "$SHIMON" = 1 ]; then
|
|
ENVV=(FDGUARD_LOG="$OUT/fdguard.log" FDGUARD_GUARD="$GUARD" FDGUARD_ABORT=0 FDGUARD_STATS_SEC=60 FDGUARD_MAXREPORTS=2000 LD_PRELOAD="$SHIM")
|
|
[ "$TRACE" = 1 ] && ENVV+=(FDGUARD_TRACE_ALL=1)
|
|
fi
|
|
WRAP=()
|
|
[ "$STRACE" = 1 ] && WRAP=(strace -f -tt -qq -e trace=close,openat,accept4,socket,dup2,dup3 -e status=failed -o "$OUT/strace.txt")
|
|
( cd "$DD_T" && exec env "${ENVV[@]}" nice -n 10 "${WRAP[@]}" "$DRAGONXD" "${TARGS[@]}" ) > "$OUT/logs/target_stdout.txt" 2>&1 &
|
|
WPID=$!
|
|
echo "--- target launched (wrapper pid $WPID); waiting for RPC"
|
|
waitrpc "$DD_T" "$RPC_T" 600 || { echo "target never answered RPC"; exit 1; }
|
|
TPID=$(cat "$DD_T/regtest/hushd.pid" 2>/dev/null); [ -z "$TPID" ] && TPID=$WPID
|
|
echo "target up pid=$TPID height=$(clin "$DD_T" "$RPC_T" getblockcount) $(date -u +%T)"
|
|
|
|
T0=$(date +%s)
|
|
if has p2p; then
|
|
start_helper "$DD_H1" "$P2P_H1" "$RPC_H1" "$OUT/logs/helper1.txt"
|
|
start_helper "$DD_H2" "$P2P_H2" "$RPC_H2" "$OUT/logs/helper2.txt"
|
|
waitrpc "$DD_H1" "$RPC_H1" 120; waitrpc "$DD_H2" "$RPC_H2" 120
|
|
nice -n 10 python3 "$REPRO/tools/tcpchurn.py" --port $P2P_T --duration "$DUR" --concurrency 8 > "$OUT/logs/tcpchurn.txt" 2>&1 & PIDS+=($!)
|
|
nice -n 10 bash "$REPRO/tools/rpcchurn.sh" "$OUT" "$DUR" > "$OUT/logs/rpcchurn.txt" 2>&1 & PIDS+=($!)
|
|
fi
|
|
if has p2pmin; then
|
|
# minimal P2P: ONE well-behaved helper peer, and an ordinary "disconnectnode" every DISC_INT s
|
|
# (the helper's -addnode re-dials the target). No raw TCP/TLS churn, no bans, no kills.
|
|
start_helper "$DD_H1" "$P2P_H1" "$RPC_H1" "$OUT/logs/helper1.txt"; waitrpc "$DD_H1" "$RPC_H1" 120
|
|
( k=0; while [ ! -e "$OUT/STOP" ]; do sleep "${DISC_INT:-5}"; for a in $(clin "$DD_T" "$RPC_T" getpeerinfo 2>/dev/null | python3 -c 'import json,sys; [print(p["addr"]) for p in json.load(sys.stdin)]' 2>/dev/null); do
|
|
clin "$DD_T" "$RPC_T" disconnectnode "$a" >/dev/null 2>&1 && { k=$((k+1)); echo "$(date -u +%T.%N) disconnectnode $a" >> "$OUT/logs/disconnects.log"; }; done
|
|
sleep 1; clin "$DD_H1" "$RPC_H1" addnode "127.0.0.1:$P2P_T" onetry >/dev/null 2>&1 # helper re-dials now (its -addnode retry is ~2 min)
|
|
echo "$k" > "$OUT/logs/disconnects.txt"; done ) & PIDS+=($!)
|
|
fi
|
|
if has rpc; then
|
|
MINEARG=""; has mine && MINEARG="--mine --mine-interval $MINE_INT"
|
|
nice -n 10 python3 "$REPRO/tools/hammer.py" --port $RPC_T --user $RPCUSER --password $RPCPASS --duration "$DUR" \
|
|
$HAMMER_ARGS $MINEARG --pid "$TPID" --logfile "$OUT/logs/hammer.log" > "$OUT/logs/hammer_stdout.txt" 2>&1 & PIDS+=($!)
|
|
elif has mine; then
|
|
( while [ ! -e "$OUT/STOP" ]; do clin "$DD_T" "$RPC_T" generate 1 >/dev/null 2>&1; sleep "$MINE_INT"; done ) & PIDS+=($!)
|
|
fi
|
|
|
|
# ---- poll
|
|
end=$(( T0 + DUR )); n=0; hit_at=0
|
|
while [ "$(date +%s)" -lt "$end" ] && [ ! -e "$OUT/STOP" ]; do
|
|
sleep 30; n=$((n+1))
|
|
alive=no; kill -0 "$TPID" 2>/dev/null && alive=yes
|
|
DL=$DD_T/regtest/debug.log
|
|
h=$(clin "$DD_T" "$RPC_T" getblockcount 2>/dev/null); c=$(clin "$DD_T" "$RPC_T" getconnectioncount 2>/dev/null)
|
|
rep=$(grep -c '^=== FDGUARD' "$OUT/fdguard.log" 2>/dev/null); noc=$(grep -c 'NON-OWNER-CLOSE' "$OUT/fdguard.log" 2>/dev/null)
|
|
ebf=$(grep -c 'EBADF-CLOSE' "$OUT/fdguard.log" 2>/dev/null); epl=$(grep -c '=== FDGUARD #[0-9]* EPOLL' "$OUT/fdguard.log" 2>/dev/null)
|
|
dbnoc=$(grep -A3 'NON-OWNER-CLOSE' "$OUT/fdguard.log" 2>/dev/null | grep -c 'class=\(db\|blk\)')
|
|
printf '[poll %3d %s +%4ds] alive=%s h=%s conns=%s | fdguard reports=%s nonowner=%s(db/blk %s) ebadf=%s epoll=%s | Epoll=%s SockCloseFail=%s EBADF=%s EPERM=%s SSL_write=%s seek=%s sel=%s | db.log=%s\n' \
|
|
$n "$(date -u +%T)" $(( $(date +%s) - T0 )) $alive "$h" "$c" "$rep" "$noc" "$dbnoc" "$ebf" "$epl" \
|
|
"$(grep -c 'libevent: Epoll' "$DL")" "$(grep -c 'Socket close failed' "$DL")" "$(grep -c 'Bad file descriptor' "$DL")" \
|
|
"$(grep -c 'Operation not permitted' "$DL")" "$(grep -c 'SSL_write' "$DL")" "$(grep -c 'Unable to seek' "$DL")" \
|
|
"$(grep -c 'socket select error' "$DL")" "$(stat -c %s "$DD_T/regtest/db.log" 2>/dev/null)" | tee -a "$OUT/poll.txt"
|
|
[ "$alive" = no ] && { echo "!!! target died"; break; }
|
|
if [ "$STOP_ON_HIT" = 1 ] && [ "${dbnoc:-0}" -gt 0 ]; then
|
|
[ "$hit_at" = 0 ] && hit_at=$(date +%s)
|
|
[ $(( $(date +%s) - hit_at )) -ge 60 ] && { echo "--- stop-on-hit"; break; }
|
|
fi
|
|
done
|
|
cat "$OUT/logs/tcpchurn.txt" "$OUT/logs/rpcchurn.txt" 2>/dev/null
|
|
grep -E 'TOTAL|totals' -A12 "$OUT/logs/hammer.log" 2>/dev/null | tail -14
|