Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
179 changes: 179 additions & 0 deletions repro_issue_185.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,179 @@
#!/usr/bin/env bash
#
# repro_issue_185.sh — Reproduce the TCP-reset bug behind issue #185 / PR #389.
#
# Symptom: `hey`/clients see "connection reset by peer" (and pooled keepalive
# clients log `Unsolicited response received on idle HTTP channel starting with
# "HTTP/1.1 ..."`) when SLEdge answers a request *before* it has finished reading
# the request body.
#
# Why a plain bodyless GET does NOT reproduce it:
# 429/500/503 are emitted from on_client_request_received(), which only runs
# after the FULL request (body included) has been read. So those are clean.
#
# The reproducible path is 404. In on_client_request_receiving()
# (runtime/src/listener_thread.c, ~line 200) the route is matched the moment the
# URL is parsed from the *request line* — before the body arrives:
#
# if (session->route == NULL && strlen(session->http_request.full_url) > 0) {
# route = http_router_match_route(...);
# if (route == NULL) { ...404...; on_client_response_header_sending(); return; }
# }
#
# So: POST a sizeable body to a NON-existent route. SLEdge writes the 404 and
# close()es the socket while the client is still sending. On Linux, close() with
# unread data in the kernel receive buffer discards it and emits a RST instead of
# a graceful FIN -> "connection reset by peer".
#
# Expected result:
# * On master / fix/docker-dev-setup (unpatched): a nonzero number of
# "connection reset by peer" errors -> BUG REPRODUCED.
# * On fix/issue-185-graceful-close (patched tcp_session_close): 0 resets.
#
# Usage:
# ./repro_issue_185.sh
#
# Tunables (env vars):
# PORT=10000 tenant listen port
# REQUESTS=2400 total requests (hey -n)
# CONCURRENCY=32 concurrent connections (hey -c)
# BODY_BYTES=100000 request body size (~100 KB); larger = more resets
#
set -euo pipefail

PORT="${PORT:-10000}"
REQUESTS="${REQUESTS:-2400}"
CONCURRENCY="${CONCURRENCY:-32}"
BODY_BYTES="${BODY_BYTES:-100000}"

# --- locate the repo (this script lives at the repo root) ---------------------
REPO_ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd -P)"
BIN_DIR="$REPO_ROOT/runtime/bin"
SLEDGERT="$BIN_DIR/sledgert"
WASM="$BIN_DIR/empty.wasm.so"

red() { printf '\033[1;31m%s\033[0m\n' "$*"; }
green() { printf '\033[0;32m%s\033[0m\n' "$*"; }
info() { printf '\033[0;36m==> %s\033[0m\n' "$*"; }

# --- prerequisites ------------------------------------------------------------
if ! command -v hey >/dev/null 2>&1; then
red "ERROR: 'hey' is not installed. Install it with:"
echo " go install github.com/rakyll/hey@latest (then add \$(go env GOPATH)/bin to PATH)"
echo " or: apt-get install -y hey"
exit 1
fi

if [[ ! -x "$SLEDGERT" ]]; then
red "ERROR: $SLEDGERT not found. Build the runtime first, e.g.:"
echo " make runtime # builds runtime/bin/sledgert"
echo " make install # full build incl. wasm apps"
exit 1
fi

if [[ ! -f "$WASM" ]]; then
red "ERROR: $WASM not found. Build the sample apps first, e.g.:"
echo " make install # builds the wasm apps incl. empty.wasm.so"
exit 1
fi

# Warn (don't block) if running on a branch that already contains the fix.
if grep -q 'shutdown(client_socket' "$REPO_ROOT/runtime/include/tcp_session.h" 2>/dev/null; then
info "NOTE: tcp_session.h contains the graceful-close fix — you are on a PATCHED"
info " checkout, so you should see 0 resets (the fix working). To see the BUG,"
info " check out an unpatched branch (e.g. master) and 'make runtime' first."
fi

# --- write a minimal tenant spec ----------------------------------------------
SPEC="$(mktemp /tmp/issue185-spec.XXXXXX.json)"
cat > "$SPEC" <<EOF
[
{
"name": "gwu",
"port": $PORT,
"routes": [
{
"route": "/empty",
"path": "empty.wasm.so",
"admissions-percentile": 70,
"relative-deadline-us": 50000,
"http-resp-content-type": "text/plain"
}
]
}
]
EOF

# --- generate the request body ------------------------------------------------
BODY="$(mktemp /tmp/issue185-body.XXXXXX)"
head -c "$BODY_BYTES" /dev/zero | tr '\0' 'x' > "$BODY"

# --- launch sledgert ----------------------------------------------------------
LOG="$(mktemp /tmp/issue185-sledge.XXXXXX.log)"
SLEDGE_PID=""

cleanup() {
[[ -n "$SLEDGE_PID" ]] && kill "$SLEDGE_PID" 2>/dev/null || true
rm -f "$SPEC" "$BODY" "$LOG"
}
trap cleanup EXIT

info "Starting sledgert on port $PORT (route /empty -> empty.wasm.so)"
# sledgert resolves the relative "empty.wasm.so" path against its CWD, and needs
# runtime/bin on LD_LIBRARY_PATH for libsledge/libck. 'exec' makes sledgert
# replace the subshell so $! is sledgert's own PID (so cleanup kills it).
( cd "$BIN_DIR" && exec env LD_LIBRARY_PATH="$BIN_DIR:${LD_LIBRARY_PATH:-}" "$SLEDGERT" "$SPEC" ) >"$LOG" 2>&1 &
SLEDGE_PID=$!

# --- wait for the tenant port to accept connections ---------------------------
info "Waiting for port $PORT to come up..."
for _ in $(seq 1 50); do
if ! kill -0 "$SLEDGE_PID" 2>/dev/null; then
red "sledgert exited during startup. Log:"
cat "$LOG"
exit 1
fi
if (exec 3<>"/dev/tcp/127.0.0.1/$PORT") 2>/dev/null; then
exec 3>&- 3<&- 2>/dev/null || true
break
fi
sleep 0.2
done

# Sanity checks: valid route -> 200, missing route (bodyless) -> 404 (clean).
ok="$(curl -s -o /dev/null -w '%{http_code}' -X POST --data hi "http://127.0.0.1:$PORT/empty" || true)"
nf="$(curl -s -o /dev/null -w '%{http_code}' "http://127.0.0.1:$PORT/nope" || true)"
info "Sanity: POST /empty -> $ok , GET /nope (bodyless) -> $nf"
if [[ "$ok" != "200" ]]; then
red "sledgert is not serving the valid route as expected. Log:"
cat "$LOG"
exit 1
fi

# --- the load that triggers the bug -------------------------------------------
info "Firing $REQUESTS POSTs ($BODY_BYTES-byte body, concurrency $CONCURRENCY) at /nope (non-existent route)"
HEY_OUT="$(mktemp /tmp/issue185-hey.XXXXXX)"
hey -n "$REQUESTS" -c "$CONCURRENCY" -m POST -D "$BODY" "http://127.0.0.1:$PORT/nope" > "$HEY_OUT" 2>&1 || true

echo
echo "----- hey status code distribution -----"
sed -n '/Status code distribution/,/^$/p' "$HEY_OUT" || true

# Each reset is a distinct connection (unique source port), so count lines.
RESETS="$(grep -c 'connection reset by peer' "$HEY_OUT" || true)"
EPIPES="$(grep -c 'broken pipe' "$HEY_OUT" || true)"
rm -f "$HEY_OUT"

echo
echo "============================================================"
echo " 'connection reset by peer' errors : $RESETS"
echo " 'broken pipe' (EPIPE) errors : $EPIPES (known large-body limitation)"
echo "============================================================"
if [[ "${RESETS:-0}" -gt 0 ]]; then
red "BUG REPRODUCED: SLEdge sent RSTs on early 404 responses (issue #185)."
echo "On fix/issue-185-graceful-close this count drops to 0."
else
green "No resets observed. If you are on the patched branch, this is the FIX working."
echo "If you expected the bug: confirm you 'make runtime' on an unpatched branch,"
echo "and try a larger BODY_BYTES (e.g. BODY_BYTES=1000000) or higher CONCURRENCY."
fi
42 changes: 42 additions & 0 deletions runtime/include/tcp_session.h
Original file line number Diff line number Diff line change
Expand Up @@ -6,12 +6,21 @@
#include <stdbool.h>
#include <string.h>
#include <sys/socket.h>
#include <threads.h>
#include <unistd.h>

#include "debuglog.h"
#include "likely.h"
#include "panic.h"

/*
* Bound on the non-blocking drain performed during a graceful close. 32 passes of an 8 KiB buffer
* (256 KiB) is far larger than any already-buffered request remainder we expect to see, while still
* guaranteeing the single listener thread cannot be held by a misbehaving client. See tcp_session_close().
*/
#define TCP_SESSION_CLOSE_DRAIN_MAX_PASSES 32
#define TCP_SESSION_CLOSE_DRAIN_BUFFER_LENGTH 8192

static inline void
tcp_session_close(int client_socket, struct sockaddr *client_address)
{
Expand All @@ -20,6 +29,39 @@ tcp_session_close(int client_socket, struct sockaddr *client_address)
assert(client_socket != STDOUT_FILENO);
assert(client_socket != STDERR_FILENO);

/*
* Graceful close to avoid sending the client a TCP RST (issue #185).
*
* SLEdge often answers a request before it has finished reading it: the short-circuit error
* responses (400/404/429/500/503) are written and the socket closed while the client may still be
* sending its request body. A bare close() with unread data still in the kernel receive buffer makes
* Linux discard that data and emit a RST instead of a graceful FIN. The client's HTTP stack then
* reports it 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.
*
* We instead (1) half-close the write side so the client receives our FIN (and, having a complete
* response, stops sending), then (2) drain any already-buffered inbound data so close() no longer
* sees unread data. The drain is non-blocking and bounded, so the listener thread can never block or
* spin on a slow client. This removes the RST for every request the client has finished sending
* (all bodyless GETs and small POSTs - i.e. the reported scenario). A client that keeps streaming a
* large body to a rejected route may still observe its own write abort as EPIPE; fully suppressing
* that would require lingering on the request in the event loop, which is out of scope here.
*/
shutdown(client_socket, SHUT_WR);

thread_local static char drain[TCP_SESSION_CLOSE_DRAIN_BUFFER_LENGTH];
for (int pass = 0; pass < TCP_SESSION_CLOSE_DRAIN_MAX_PASSES; pass++) {
ssize_t drained = read(client_socket, drain, sizeof(drain));
if (drained == 0) break; /* EOF: client closed its side, nothing left to drain */
if (drained < 0) {
if (errno == EINTR) continue;
/* EAGAIN/EWOULDBLOCK: receive buffer is empty, so close() will not RST. Any other
* error means the connection is already broken. Either way, stop draining. */
break;
}
/* Drained a full buffer; more may be queued, so loop again (bounded). */
}

if (unlikely(close(client_socket) < 0)) {
char client_address_text[INET6_ADDRSTRLEN] = {'\0'};
if (unlikely(inet_ntop(AF_INET, &client_address, client_address_text, INET6_ADDRSTRLEN) == NULL)) {
Expand Down
Loading