Skip to content

Commit 1e7bd47

Browse files
bushidocodesclaude
bushidocodes
and
claude
authored
fix: graceful TCP close to stop RST on early error responses (#185) (#389)
* fix: graceful TCP close to stop RST on early error responses (#185) SLEdge frequently answers a request before it has finished reading it: the short-circuit error responses (400/404/429/500/503) in the listener thread write the response and close the socket while the client may still be sending its request body. tcp_session_close() did a bare close(). On Linux, close() with unread data still in the kernel receive buffer discards that data and emits a TCP RST instead of a graceful FIN. The client's HTTP stack reports this as "connection reset by peer" or, on a pooled keepalive connection, as the Go net/http warning "Unsolicited response received on idle HTTP channel" that issue #185 describes. Close gracefully instead: half-close the write side so the client receives our FIN (and, holding a complete response, stops sending), then drain any already-buffered inbound data so close() no longer sees unread data. The drain is non-blocking and bounded (32 x 8 KiB) so the single listener thread can never block or spin on a slow client. Verified in the Docker dev environment with hey: POSTing a 100 KB body to a rejected (404) route went from ~159 "connection reset by peer" errors per 2400 requests to 0, with no change to normal 200-response throughput (~15k rps) or the bodyless GET -> 429/503 path. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * test: add repro script for issue #185 TCP-reset bug Self-contained script that reproduces the "connection reset by peer" / "Unsolicited response received on idle HTTP channel" failure behind #185: launches sledgert with a single valid route, then POSTs a sizeable body to a non-existent route so the server emits a 404 (matched at the request line, in on_client_request_receiving) and close()s while the body is still in flight, producing a RST. Reports the reset count and prints BUG REPRODUCED when nonzero. Run on an unpatched checkout to see the bug; on this branch the graceful-close fix drops the reset count to 0. Helps reviewers reproduce the concrete failure case requested in PR #389 review. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent f763bc1 commit 1e7bd47

2 files changed

Lines changed: 221 additions & 0 deletions

File tree

‎repro_issue_185.sh‎

Lines changed: 179 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,179 @@
1+
#!/usr/bin/env bash
2+
#
3+
# repro_issue_185.sh — Reproduce the TCP-reset bug behind issue #185 / PR #389.
4+
#
5+
# Symptom: `hey`/clients see "connection reset by peer" (and pooled keepalive
6+
# clients log `Unsolicited response received on idle HTTP channel starting with
7+
# "HTTP/1.1 ..."`) when SLEdge answers a request *before* it has finished reading
8+
# the request body.
9+
#
10+
# Why a plain bodyless GET does NOT reproduce it:
11+
# 429/500/503 are emitted from on_client_request_received(), which only runs
12+
# after the FULL request (body included) has been read. So those are clean.
13+
#
14+
# The reproducible path is 404. In on_client_request_receiving()
15+
# (runtime/src/listener_thread.c, ~line 200) the route is matched the moment the
16+
# URL is parsed from the *request line* — before the body arrives:
17+
#
18+
# if (session->route == NULL && strlen(session->http_request.full_url) > 0) {
19+
# route = http_router_match_route(...);
20+
# if (route == NULL) { ...404...; on_client_response_header_sending(); return; }
21+
# }
22+
#
23+
# So: POST a sizeable body to a NON-existent route. SLEdge writes the 404 and
24+
# close()es the socket while the client is still sending. On Linux, close() with
25+
# unread data in the kernel receive buffer discards it and emits a RST instead of
26+
# a graceful FIN -> "connection reset by peer".
27+
#
28+
# Expected result:
29+
# * On master / fix/docker-dev-setup (unpatched): a nonzero number of
30+
# "connection reset by peer" errors -> BUG REPRODUCED.
31+
# * On fix/issue-185-graceful-close (patched tcp_session_close): 0 resets.
32+
#
33+
# Usage:
34+
# ./repro_issue_185.sh
35+
#
36+
# Tunables (env vars):
37+
# PORT=10000 tenant listen port
38+
# REQUESTS=2400 total requests (hey -n)
39+
# CONCURRENCY=32 concurrent connections (hey -c)
40+
# BODY_BYTES=100000 request body size (~100 KB); larger = more resets
41+
#
42+
set -euo pipefail
43+
44+
PORT="${PORT:-10000}"
45+
REQUESTS="${REQUESTS:-2400}"
46+
CONCURRENCY="${CONCURRENCY:-32}"
47+
BODY_BYTES="${BODY_BYTES:-100000}"
48+
49+
# --- locate the repo (this script lives at the repo root) ---------------------
50+
REPO_ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd -P)"
51+
BIN_DIR="$REPO_ROOT/runtime/bin"
52+
SLEDGERT="$BIN_DIR/sledgert"
53+
WASM="$BIN_DIR/empty.wasm.so"
54+
55+
red() { printf '\033[1;31m%s\033[0m\n' "$*"; }
56+
green() { printf '\033[0;32m%s\033[0m\n' "$*"; }
57+
info() { printf '\033[0;36m==> %s\033[0m\n' "$*"; }
58+
59+
# --- prerequisites ------------------------------------------------------------
60+
if ! command -v hey >/dev/null 2>&1; then
61+
red "ERROR: 'hey' is not installed. Install it with:"
62+
echo " go install github.com/rakyll/hey@latest (then add \$(go env GOPATH)/bin to PATH)"
63+
echo " or: apt-get install -y hey"
64+
exit 1
65+
fi
66+
67+
if [[ ! -x "$SLEDGERT" ]]; then
68+
red "ERROR: $SLEDGERT not found. Build the runtime first, e.g.:"
69+
echo " make runtime # builds runtime/bin/sledgert"
70+
echo " make install # full build incl. wasm apps"
71+
exit 1
72+
fi
73+
74+
if [[ ! -f "$WASM" ]]; then
75+
red "ERROR: $WASM not found. Build the sample apps first, e.g.:"
76+
echo " make install # builds the wasm apps incl. empty.wasm.so"
77+
exit 1
78+
fi
79+
80+
# Warn (don't block) if running on a branch that already contains the fix.
81+
if grep -q 'shutdown(client_socket' "$REPO_ROOT/runtime/include/tcp_session.h" 2>/dev/null; then
82+
info "NOTE: tcp_session.h contains the graceful-close fix — you are on a PATCHED"
83+
info " checkout, so you should see 0 resets (the fix working). To see the BUG,"
84+
info " check out an unpatched branch (e.g. master) and 'make runtime' first."
85+
fi
86+
87+
# --- write a minimal tenant spec ----------------------------------------------
88+
SPEC="$(mktemp /tmp/issue185-spec.XXXXXX.json)"
89+
cat > "$SPEC" <<EOF
90+
[
91+
{
92+
"name": "gwu",
93+
"port": $PORT,
94+
"routes": [
95+
{
96+
"route": "/empty",
97+
"path": "empty.wasm.so",
98+
"admissions-percentile": 70,
99+
"relative-deadline-us": 50000,
100+
"http-resp-content-type": "text/plain"
101+
}
102+
]
103+
}
104+
]
105+
EOF
106+
107+
# --- generate the request body ------------------------------------------------
108+
BODY="$(mktemp /tmp/issue185-body.XXXXXX)"
109+
head -c "$BODY_BYTES" /dev/zero | tr '\0' 'x' > "$BODY"
110+
111+
# --- launch sledgert ----------------------------------------------------------
112+
LOG="$(mktemp /tmp/issue185-sledge.XXXXXX.log)"
113+
SLEDGE_PID=""
114+
115+
cleanup() {
116+
[[ -n "$SLEDGE_PID" ]] && kill "$SLEDGE_PID" 2>/dev/null || true
117+
rm -f "$SPEC" "$BODY" "$LOG"
118+
}
119+
trap cleanup EXIT
120+
121+
info "Starting sledgert on port $PORT (route /empty -> empty.wasm.so)"
122+
# sledgert resolves the relative "empty.wasm.so" path against its CWD, and needs
123+
# runtime/bin on LD_LIBRARY_PATH for libsledge/libck. 'exec' makes sledgert
124+
# replace the subshell so $! is sledgert's own PID (so cleanup kills it).
125+
( cd "$BIN_DIR" && exec env LD_LIBRARY_PATH="$BIN_DIR:${LD_LIBRARY_PATH:-}" "$SLEDGERT" "$SPEC" ) >"$LOG" 2>&1 &
126+
SLEDGE_PID=$!
127+
128+
# --- wait for the tenant port to accept connections ---------------------------
129+
info "Waiting for port $PORT to come up..."
130+
for _ in $(seq 1 50); do
131+
if ! kill -0 "$SLEDGE_PID" 2>/dev/null; then
132+
red "sledgert exited during startup. Log:"
133+
cat "$LOG"
134+
exit 1
135+
fi
136+
if (exec 3<>"/dev/tcp/127.0.0.1/$PORT") 2>/dev/null; then
137+
exec 3>&- 3<&- 2>/dev/null || true
138+
break
139+
fi
140+
sleep 0.2
141+
done
142+
143+
# Sanity checks: valid route -> 200, missing route (bodyless) -> 404 (clean).
144+
ok="$(curl -s -o /dev/null -w '%{http_code}' -X POST --data hi "http://127.0.0.1:$PORT/empty" || true)"
145+
nf="$(curl -s -o /dev/null -w '%{http_code}' "http://127.0.0.1:$PORT/nope" || true)"
146+
info "Sanity: POST /empty -> $ok , GET /nope (bodyless) -> $nf"
147+
if [[ "$ok" != "200" ]]; then
148+
red "sledgert is not serving the valid route as expected. Log:"
149+
cat "$LOG"
150+
exit 1
151+
fi
152+
153+
# --- the load that triggers the bug -------------------------------------------
154+
info "Firing $REQUESTS POSTs ($BODY_BYTES-byte body, concurrency $CONCURRENCY) at /nope (non-existent route)"
155+
HEY_OUT="$(mktemp /tmp/issue185-hey.XXXXXX)"
156+
hey -n "$REQUESTS" -c "$CONCURRENCY" -m POST -D "$BODY" "http://127.0.0.1:$PORT/nope" > "$HEY_OUT" 2>&1 || true
157+
158+
echo
159+
echo "----- hey status code distribution -----"
160+
sed -n '/Status code distribution/,/^$/p' "$HEY_OUT" || true
161+
162+
# Each reset is a distinct connection (unique source port), so count lines.
163+
RESETS="$(grep -c 'connection reset by peer' "$HEY_OUT" || true)"
164+
EPIPES="$(grep -c 'broken pipe' "$HEY_OUT" || true)"
165+
rm -f "$HEY_OUT"
166+
167+
echo
168+
echo "============================================================"
169+
echo " 'connection reset by peer' errors : $RESETS"
170+
echo " 'broken pipe' (EPIPE) errors : $EPIPES (known large-body limitation)"
171+
echo "============================================================"
172+
if [[ "${RESETS:-0}" -gt 0 ]]; then
173+
red "BUG REPRODUCED: SLEdge sent RSTs on early 404 responses (issue #185)."
174+
echo "On fix/issue-185-graceful-close this count drops to 0."
175+
else
176+
green "No resets observed. If you are on the patched branch, this is the FIX working."
177+
echo "If you expected the bug: confirm you 'make runtime' on an unpatched branch,"
178+
echo "and try a larger BODY_BYTES (e.g. BODY_BYTES=1000000) or higher CONCURRENCY."
179+
fi

‎runtime/include/tcp_session.h‎

Lines changed: 42 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,12 +6,21 @@
66
#include <stdbool.h>
77
#include <string.h>
88
#include <sys/socket.h>
9+
#include <threads.h>
910
#include <unistd.h>
1011

1112
#include "debuglog.h"
1213
#include "likely.h"
1314
#include "panic.h"
1415

16+
/*
17+
* Bound on the non-blocking drain performed during a graceful close. 32 passes of an 8 KiB buffer
18+
* (256 KiB) is far larger than any already-buffered request remainder we expect to see, while still
19+
* guaranteeing the single listener thread cannot be held by a misbehaving client. See tcp_session_close().
20+
*/
21+
#define TCP_SESSION_CLOSE_DRAIN_MAX_PASSES 32
22+
#define TCP_SESSION_CLOSE_DRAIN_BUFFER_LENGTH 8192
23+
1524
static inline void
1625
tcp_session_close(int client_socket, struct sockaddr *client_address)
1726
{
@@ -20,6 +29,39 @@ tcp_session_close(int client_socket, struct sockaddr *client_address)
2029
assert(client_socket != STDOUT_FILENO);
2130
assert(client_socket != STDERR_FILENO);
2231

32+
/*
33+
* Graceful close to avoid sending the client a TCP RST (issue #185).
34+
*
35+
* SLEdge often answers a request before it has finished reading it: the short-circuit error
36+
* responses (400/404/429/500/503) are written and the socket closed while the client may still be
37+
* sending its request body. A bare close() with unread data still in the kernel receive buffer makes
38+
* Linux discard that data and emit a RST instead of a graceful FIN. The client's HTTP stack then
39+
* reports it as "connection reset by peer" or, on a pooled keepalive connection, as the Go net/http
40+
* warning "Unsolicited response received on idle HTTP channel" that issue #185 describes.
41+
*
42+
* We instead (1) half-close the write side so the client receives our FIN (and, having a complete
43+
* response, stops sending), then (2) drain any already-buffered inbound data so close() no longer
44+
* sees unread data. The drain is non-blocking and bounded, so the listener thread can never block or
45+
* spin on a slow client. This removes the RST for every request the client has finished sending
46+
* (all bodyless GETs and small POSTs - i.e. the reported scenario). A client that keeps streaming a
47+
* large body to a rejected route may still observe its own write abort as EPIPE; fully suppressing
48+
* that would require lingering on the request in the event loop, which is out of scope here.
49+
*/
50+
shutdown(client_socket, SHUT_WR);
51+
52+
thread_local static char drain[TCP_SESSION_CLOSE_DRAIN_BUFFER_LENGTH];
53+
for (int pass = 0; pass < TCP_SESSION_CLOSE_DRAIN_MAX_PASSES; pass++) {
54+
ssize_t drained = read(client_socket, drain, sizeof(drain));
55+
if (drained == 0) break; /* EOF: client closed its side, nothing left to drain */
56+
if (drained < 0) {
57+
if (errno == EINTR) continue;
58+
/* EAGAIN/EWOULDBLOCK: receive buffer is empty, so close() will not RST. Any other
59+
* error means the connection is already broken. Either way, stop draining. */
60+
break;
61+
}
62+
/* Drained a full buffer; more may be queued, so loop again (bounded). */
63+
}
64+
2365
if (unlikely(close(client_socket) < 0)) {
2466
char client_address_text[INET6_ADDRSTRLEN] = {'\0'};
2567
if (unlikely(inet_ntop(AF_INET, &client_address, client_address_text, INET6_ADDRSTRLEN) == NULL)) {

0 commit comments

Comments
 (0)