commit 3f7f22e1a835567249f07617ca86b0fc0f0b9ab8
parent d473ebf2456db831d1d193818fa94b020fd42edc
Author: Florian Dold <dold@taler.net>
Date: Tue, 25 Aug 2026 11:41:40 +0200
payment: distinguish merchant transport failures
Also slightly increase systemd limits, they're too conservative for the
current libcurl settings.
Diffstat:
8 files changed, 532 insertions(+), 24 deletions(-)
diff --git a/README b/README
@@ -154,6 +154,9 @@ Paivana reads an INI-style `.conf` file. The only section used is
with no BIND_TO there are two (IPv4 and IPv6). Paivana
also spends file descriptors on outbound requests from
the same table, so leave headroom below `ulimit -n`.
+ Paivana warns at startup when the soft limit is below twice
+ CONNECTION_LIMIT plus a small reserve. The shipped systemd
+ service sets `LimitNOFILE=4096` for the default limit.
PER_IP_CONNECTION_LIMIT
Concurrent connections accepted from any one client
address, default 32; 0 disables the check. Set it to 0
diff --git a/debian/paivana-httpd.service b/debian/paivana-httpd.service
@@ -37,6 +37,12 @@ RestartPreventExitStatus=6 9
# invalidate every access cookie, so an hourly restart meant a customer
# paying at 10:59 was shown the paywall again at 11:01.
RuntimeMaxSec=3600s
+
+# The default CONNECTION_LIMIT is 512, and an active request may consume
+# both an accepted client socket and an outbound origin/merchant socket.
+# Leave room for listeners, resolver activity and libcurl's idle pool too;
+# systemd's common 1024-descriptor soft default is not sufficient.
+LimitNOFILE=4096
# -f: we are served over a Unix socket by nginx/Apache (see the
# shipped site configs), so the client address has to come from the
# forwarding headers -- a Unix peer has no address of its own, and
diff --git a/src/backend/paivana-httpd.c b/src/backend/paivana-httpd.c
@@ -118,6 +118,46 @@ static struct GNUNET_CURL_RescheduleContext *proxy_ctx_rc;
/**
+ * Warn when the process cannot plausibly sustain its configured client
+ * connection limit. A request may hold one inbound socket and one
+ * outbound socket (to the origin or merchant) at the same time, while
+ * listeners, the scheduler and libcurl's idle connection caches need
+ * additional descriptors. Running out during curl_connect() is
+ * especially confusing: the merchant API reports it as status zero,
+ * just like every other transport failure.
+ */
+static void
+check_file_descriptor_limit (void)
+{
+#if HAVE_SYS_RESOURCE_H
+ struct rlimit lim;
+ unsigned long long recommended;
+
+ if (0 != getrlimit (RLIMIT_NOFILE,
+ &lim))
+ {
+ GNUNET_log_strerror (GNUNET_ERROR_TYPE_WARNING,
+ "getrlimit");
+ return;
+ }
+ /* Two descriptors per accepted connection, plus conservative room
+ for listeners, logs, resolver activity and reusable idle sockets. */
+ recommended = 2ULL * PH_connection_limit + 64ULL;
+ if ( (RLIM_INFINITY != lim.rlim_cur) &&
+ ((unsigned long long) lim.rlim_cur < recommended) )
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Open-file soft limit %llu is below the recommended %llu"
+ " for CONNECTION_LIMIT=%u; descriptor exhaustion may"
+ " cause immediate merchant transport failures. Lower"
+ " CONNECTION_LIMIT or raise LimitNOFILE/`ulimit -n'\n",
+ (unsigned long long) lim.rlim_cur,
+ recommended,
+ PH_connection_limit);
+#endif
+}
+
+
+/**
* Load one of the `TRUSTED_PROXIES` options.
*
* The GNUnet policy parsers are lenient in ways that matter here, so
@@ -541,6 +581,7 @@ run (void *cls,
PH_max_request_size = PH_request_buffer_max;
}
}
+ check_file_descriptor_limit ();
{
struct GNUNET_TIME_Relative st;
diff --git a/src/backend/paivana-httpd_pay.c b/src/backend/paivana-httpd_pay.c
@@ -23,6 +23,7 @@
* @file paivana-httpd_pay.c
* @brief payment processing logic
*/
+#include "platform.h"
#include <microhttpd.h>
#include <gnunet/gnunet_util_lib.h>
#include <taler/taler_mhd_lib.h>
@@ -104,6 +105,15 @@ struct PayRequest
struct TALER_MERCHANT_GetPrivateOrderHandle *co;
/**
+ * When @e co was started. The merchant client API reports every
+ * transport failure as HTTP status zero, without the CURLcode that
+ * would distinguish a timeout from (for example) a refused stale
+ * pooled connection. The elapsed time still lets us distinguish a
+ * request that reached our deadline from one that failed before it.
+ */
+ struct GNUNET_TIME_Absolute merchant_request_started;
+
+ /**
* Response to return, NULL if not yet determined.
*/
struct MHD_Response *response;
@@ -152,6 +162,87 @@ static struct PayRequest *ph_head;
*/
static struct PayRequest *ph_tail;
+/**
+ * Number of consecutive merchant order lookups that ended without an
+ * HTTP response. This is diagnostic state only: a real response of
+ * any status resets it. In particular, a growing number here makes a
+ * persistent resolver/connection-pool/backend problem visible in the
+ * log instead of making each redemption look like an isolated timeout.
+ */
+static unsigned int merchant_transport_failures;
+
+
+/**
+ * Log process descriptor usage while a merchant transport failure is
+ * live. Linux exposes this cheaply through /proc; elsewhere the
+ * directory may not exist and this diagnostic quietly stays absent.
+ * Failure to open it with EMFILE/ENFILE is itself useful evidence.
+ */
+static void
+log_file_descriptor_usage (void)
+{
+ DIR *dir;
+ struct dirent *entry;
+ unsigned int open_fds = 0;
+
+ dir = opendir ("/proc/self/fd");
+ if (NULL == dir)
+ {
+ int ec = errno;
+
+ if ( (EMFILE == ec) ||
+ (ENFILE == ec) )
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Could not inspect open descriptors after merchant"
+ " transport failure: %s; descriptor exhaustion is"
+ " likely\n",
+ strerror (ec));
+ else
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Could not inspect /proc/self/fd after merchant"
+ " transport failure: %s\n",
+ strerror (ec));
+ return;
+ }
+ while (NULL != (entry = readdir (dir)))
+ if ( (0 != strcmp (entry->d_name,
+ ".")) &&
+ (0 != strcmp (entry->d_name,
+ "..")) )
+ open_fds++;
+ GNUNET_break (0 == closedir (dir));
+ /* The directory descriptor was present during the scan and is closed
+ now, so report the number that remains after this function. */
+ if (0 != open_fds)
+ open_fds--;
+#if HAVE_SYS_RESOURCE_H
+ {
+ struct rlimit lim;
+
+ if (0 == getrlimit (RLIMIT_NOFILE,
+ &lim))
+ {
+ if (RLIM_INFINITY == lim.rlim_cur)
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Process had %u open file descriptors at merchant"
+ " transport failure (soft limit is unlimited)\n",
+ open_fds);
+ else
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Process had %u open file descriptors at merchant"
+ " transport failure (soft limit %llu)\n",
+ open_fds,
+ (unsigned long long) lim.rlim_cur);
+ return;
+ }
+ }
+#endif
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Process had %u open file descriptors at merchant"
+ " transport failure (soft limit unavailable)\n",
+ open_fds);
+}
+
void
PAIVANA_HTTPD_payment_shutdown ()
@@ -333,12 +424,49 @@ static void
order_status_cb (struct PayRequest *ph,
const struct TALER_MERCHANT_GetPrivateOrderResponse *osr)
{
+ struct GNUNET_TIME_Relative elapsed;
+ char *elapsed_s;
+ char *timeout_s;
+ unsigned int active_lookups = 0;
+
+ elapsed = GNUNET_TIME_absolute_get_duration (
+ ph->merchant_request_started);
+ /* GNUNET_STRINGS_relative_time_to_string() reuses one static buffer,
+ so keep copies before putting both values in one log message. */
+ elapsed_s = GNUNET_strdup (
+ GNUNET_STRINGS_relative_time_to_string (elapsed,
+ true));
+ timeout_s = GNUNET_strdup (
+ GNUNET_STRINGS_relative_time_to_string (MERCHANT_ORDER_TIMEOUT,
+ true));
+ for (const struct PayRequest *pos = ph_head;
+ NULL != pos;
+ pos = pos->next)
+ active_lookups++;
ph->co = NULL;
GNUNET_CONTAINER_DLL_remove (ph_head,
ph_tail,
ph);
MHD_resume_connection (ph->connection);
TALER_MHD_daemon_trigger ();
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Merchant order lookup for `%s' completed with HTTP status"
+ " %u after %s\n",
+ ph->order_id,
+ osr->hr.http_status,
+ elapsed_s);
+ if (0 != osr->hr.http_status)
+ {
+ if (0 != merchant_transport_failures)
+ GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+ "Merchant backend at `%s' answered order `%s' after %u"
+ " consecutive lookup%s without an HTTP response\n",
+ PH_merchant_base_url,
+ ph->order_id,
+ merchant_transport_failures,
+ (1 == merchant_transport_failures) ? "" : "s");
+ merchant_transport_failures = 0;
+ }
switch (osr->hr.http_status)
{
case MHD_HTTP_OK:
@@ -364,7 +492,11 @@ order_status_cb (struct PayRequest *ph,
if (! check_contract (ph,
osr->details.ok.details.paid.contract_terms))
+ {
+ GNUNET_free (elapsed_s);
+ GNUNET_free (timeout_s);
return;
+ }
/* The client address is bound into the cookie MAC; computing
the cookie over an empty address would produce a cookie that
PAIVANA_HTTPD_check_cookie can never match, silently denying
@@ -469,38 +601,71 @@ order_status_cb (struct PayRequest *ph,
what tells them apart, being NULL only in the former case. */
if (NULL != osr->hr.reply)
{
+ merchant_transport_failures = 0;
GNUNET_break_op (0);
GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
"Merchant backend at `%s' sent an unusable reply for"
- " order `%s'\n",
+ " order `%s' after %s\n",
PH_merchant_base_url,
- ph->order_id);
+ ph->order_id,
+ elapsed_s);
ph->response = TALER_MHD_make_error (TALER_EC_PAIVANA_BACKEND_ERROR,
ph->order_id);
ph->response_status = MHD_HTTP_BAD_GATEWAY;
break;
}
- /* Nothing came back: the request hit #MERCHANT_ORDER_TIMEOUT, or
- the backend was unreachable. Either way the client has waited
- for us rather than been answered, which is what separates 504
- from the 502 above. */
- GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
- "Merchant backend at `%s' did not answer for order `%s'"
- " within %s; giving up on this redemption\n",
- PH_merchant_base_url,
- ph->order_id,
- GNUNET_STRINGS_relative_time_to_string (MERCHANT_ORDER_TIMEOUT,
- true));
- /* GENERIC_TIMEOUT's hint ("trying again might help") is the one
- that is true for the client here; GET_ORDER_FAILED says "this
- should never happen, consult the logs", which is wrong advice
- for a backend that was merely slow. A dedicated
- PAIVANA_BACKEND_TIMEOUT would be better still, but that is a
- GANA registration and so its own change in another
- repository. */
- ph->response = TALER_MHD_make_error (TALER_EC_GENERIC_TIMEOUT,
- ph->order_id);
- ph->response_status = MHD_HTTP_GATEWAY_TIMEOUT;
+ if (UINT_MAX != merchant_transport_failures)
+ merchant_transport_failures++;
+ log_file_descriptor_usage ();
+ if (GNUNET_TIME_relative_cmp (elapsed,
+ >=,
+ MERCHANT_ORDER_TIMEOUT))
+ {
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Merchant backend at `%s' returned no HTTP response for"
+ " order `%s' by the %s deadline (elapsed %s; %u"
+ " concurrent merchant lookup%s including this one; %u"
+ " consecutive transport failure%s)\n",
+ PH_merchant_base_url,
+ ph->order_id,
+ timeout_s,
+ elapsed_s,
+ active_lookups,
+ (1 == active_lookups) ? "" : "s",
+ merchant_transport_failures,
+ (1 == merchant_transport_failures) ? "" : "s");
+ /* GENERIC_TIMEOUT's hint ("trying again might help") is the one
+ that is true once our own deadline was actually reached. */
+ ph->response = TALER_MHD_make_error (TALER_EC_GENERIC_TIMEOUT,
+ ph->order_id);
+ ph->response_status = MHD_HTTP_GATEWAY_TIMEOUT;
+ }
+ else
+ {
+ /* The merchant API does not expose CURLcode, so DNS failure,
+ connection refusal, TLS failure and a dead reused connection
+ are indistinguishable here. What they have in common is that
+ they failed before our timeout. Calling that a timeout hid the
+ most useful fact from both the operator and the client. */
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Merchant backend at `%s' returned no HTTP response for"
+ " order `%s' after %s, before the %s deadline; this is"
+ " an early transport failure (for example DNS, TCP, TLS"
+ " or a stale reused connection), not a Paivana timeout"
+ " (%u concurrent merchant lookup%s including this one;"
+ " %u consecutive transport failure%s)\n",
+ PH_merchant_base_url,
+ ph->order_id,
+ elapsed_s,
+ timeout_s,
+ active_lookups,
+ (1 == active_lookups) ? "" : "s",
+ merchant_transport_failures,
+ (1 == merchant_transport_failures) ? "" : "s");
+ ph->response = TALER_MHD_make_error (TALER_EC_PAIVANA_BACKEND_REFUSED,
+ ph->order_id);
+ ph->response_status = MHD_HTTP_BAD_GATEWAY;
+ }
break;
default:
{
@@ -519,6 +684,8 @@ order_status_cb (struct PayRequest *ph,
}
break;
}
+ GNUNET_free (elapsed_s);
+ GNUNET_free (timeout_s);
}
@@ -640,6 +807,7 @@ PAIVANA_HTTPD_payment_handle (struct PayRequest *ph,
{
enum TALER_ErrorCode ec;
+ ph->merchant_request_started = GNUNET_TIME_absolute_get ();
ec = TALER_MERCHANT_get_private_order_start (ph->co,
&order_status_cb,
ph);
diff --git a/src/tests/README b/src/tests/README
@@ -1,12 +1,16 @@
paivana tests
=============
-This directory contains five test programs:
+This directory contains six test programs:
reverse_proxy an integration suite for the reverse-proxy side of
paivana-httpd, driven by test_reverse_proxy.sh
paywall an integration suite for the paywall itself, driven
by test_paywall.sh against a real GNU Taler system
+ payment_backend_failure
+ a small integration test that distinguishes an
+ immediate merchant transport failure from an
+ elapsed order deadline
client_address a unit test for the client address the access
cookie is keyed on (test_client_address.c)
cookie_header a unit test for the `Set-Cookie` line paivana emits
@@ -894,6 +898,20 @@ test cases use it to confirm that responses are coming back from
the expected backend.
+Payment-backend failure diagnostics
+-----------------------------------
+
+`test_payment_backend_failure.sh` starts paivana against a small Python
+merchant stub, lets template loading finish, and then stops the stub. A
+redemption against the now-refused port must return promptly as 502 / error
+9801, with the elapsed time and active/consecutive lookup counts in the log;
+it must not claim that the five-second deadline elapsed. The stub is then
+restarted to prove that a real HTTP response resets the consecutive-failure
+count, and finally holds an order lookup open long enough to verify the true
+timeout path remains 504 / error 11. It needs neither PostgreSQL nor a full
+Taler deployment.
+
+
The paywall suite
-----------------
diff --git a/src/tests/meson.build b/src/tests/meson.build
@@ -226,6 +226,18 @@ test(
timeout: 900,
)
+# The payment endpoint's two status-zero outcomes: an immediate merchant
+# transport failure and a request that actually reaches Paivana's deadline.
+# This uses a tiny local merchant stub, so unlike the full paywall test it
+# needs neither PostgreSQL nor the rest of the Taler deployment.
+test(
+ 'payment_backend_failure',
+ files('test_payment_backend_failure.sh'),
+ env: test_env,
+ depends: [paivana_httpd_exe],
+ timeout: 30,
+)
+
# What the reverse proxy costs: N curl clients at a fixed-size static
# page, first straight at upstream_rs and then through paivana in front
# of it. Registered with benchmark() rather than test() deliberately --
diff --git a/src/tests/payment_backend_stub.py b/src/tests/payment_backend_stub.py
@@ -0,0 +1,91 @@
+#!/usr/bin/env python3
+"""Small merchant HTTP stub for payment-backend failure tests."""
+
+import json
+import sys
+import time
+from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer
+from urllib.parse import urlsplit
+
+
+TOKEN = "secret-token:stub"
+TEMPLATE_ID = "premium"
+
+
+class ReusableServer(ThreadingHTTPServer):
+ allow_reuse_address = True
+ daemon_threads = True
+
+
+class Handler(BaseHTTPRequestHandler):
+ protocol_version = "HTTP/1.1"
+
+ def log_message(self, fmt, *args):
+ sys.stderr.write("payment_backend_stub: " + fmt % args + "\n")
+
+ def reply(self, status, body):
+ encoded = json.dumps(body, separators=(",", ":")).encode()
+ self.send_response(status)
+ self.send_header("Content-Type", "application/json")
+ self.send_header("Content-Length", str(len(encoded)))
+ self.send_header("Connection", "close")
+ self.end_headers()
+ self.wfile.write(encoded)
+
+ def do_GET(self):
+ if self.headers.get("Authorization") != f"Bearer {TOKEN}":
+ self.reply(401, {"code": 2000, "hint": "wrong bearer token"})
+ return
+ path = urlsplit(self.path).path
+ if path == "/private/templates":
+ self.reply(
+ 200,
+ {
+ "templates": [
+ {
+ "template_id": TEMPLATE_ID,
+ "template_description": "Paywalled content",
+ }
+ ]
+ },
+ )
+ return
+ if path == f"/private/templates/{TEMPLATE_ID}":
+ self.reply(
+ 200,
+ {
+ "template_description": "Paywalled content",
+ "template_contract": {
+ "template_type": "paivana",
+ "summary": "Access to the article",
+ "website_regex": ".*",
+ "max_pickup_duration": {"d_us": 3600000000},
+ "choices": [
+ {"amount": "TESTKUDOS:1", "description": "One article"}
+ ],
+ },
+ },
+ )
+ return
+ if path == "/private/orders/timeout-order":
+ # Longer than Paivana's five-second order deadline. The
+ # client will close the connection before this reply.
+ time.sleep(10)
+ self.reply(404, {"code": 2906, "hint": "late test reply"})
+ return
+ if path.startswith("/private/orders/"):
+ self.reply(404, {"code": 2906, "hint": "unknown test order"})
+ return
+ self.reply(404, {"code": 2906, "hint": "unknown test endpoint"})
+
+
+def main():
+ if len(sys.argv) != 2:
+ raise SystemExit(f"usage: {sys.argv[0]} PORT")
+ server = ReusableServer(("127.0.0.1", int(sys.argv[1])), Handler)
+ print(f"payment_backend_stub listening on {server.server_port}", flush=True)
+ server.serve_forever()
+
+
+if __name__ == "__main__":
+ main()
diff --git a/src/tests/test_payment_backend_failure.sh b/src/tests/test_payment_backend_failure.sh
@@ -0,0 +1,169 @@
+#!/usr/bin/env bash
+# Distinguish a merchant transport failure from an elapsed order timeout.
+
+set -eu
+
+function here() {
+ cd -- "$(dirname -- "$0")" && pwd
+}
+
+SRCDIR="${SRCDIR:-$(here)}"
+BUILDDIR="${BUILDDIR:-$PWD}"
+PAIVANA_HTTPD="${PAIVANA_HTTPD:-$BUILDDIR/../backend/paivana-httpd}"
+PORT_BASE="${PAIVANA_PORT_BASE:-18400}"
+MERCHANT_PORT=$((PORT_BASE + 120))
+PAIVANA_PORT=$((PORT_BASE + 121))
+SCRATCH="$(mktemp -d -t paivana-payment-failure.XXXXXX)"
+STUB_PID=""
+PAIVANA_PID=""
+
+function cleanup() {
+ set +e
+ [ -n "$STUB_PID" ] && kill -TERM "$STUB_PID" 2>/dev/null
+ [ -n "$PAIVANA_PID" ] && kill -TERM "$PAIVANA_PID" 2>/dev/null
+ wait "$STUB_PID" 2>/dev/null
+ wait "$PAIVANA_PID" 2>/dev/null
+ if [ "${KEEP_TMP:-0}" = "1" ]; then
+ echo "Temp files kept in $SCRATCH" >&2
+ else
+ rm -rf "$SCRATCH"
+ fi
+ return 0
+}
+trap cleanup EXIT
+
+function port_is_free() {
+ ! (exec 3<>"/dev/tcp/127.0.0.1/$1") 2>/dev/null
+}
+
+function wait_for_port() {
+ local port="$1" pid="$2" tries=50
+ while [ "$tries" -gt 0 ]; do
+ if ! port_is_free "$port"; then
+ return 0
+ fi
+ kill -0 "$pid" 2>/dev/null || return 1
+ sleep 0.1
+ tries=$((tries - 1))
+ done
+ return 1
+}
+
+function fail() {
+ echo "FAIL: $*" >&2
+ echo "==> paivana.log <==" >&2
+ tail -n 80 "$SCRATCH/paivana.log" >&2 || true
+ echo "==> merchant.log <==" >&2
+ tail -n 40 "$SCRATCH/merchant.log" >&2 || true
+ exit 1
+}
+
+function start_stub() {
+ python3 "$SRCDIR/payment_backend_stub.py" "$MERCHANT_PORT" \
+ >>"$SCRATCH/merchant.log" 2>&1 &
+ STUB_PID=$!
+ wait_for_port "$MERCHANT_PORT" "$STUB_PID" \
+ || fail "merchant stub did not start"
+}
+
+function redemption_body() {
+ local order="$1"
+ printf '{"order_id":"%s","website":"http://127.0.0.1:%u/article",' \
+ "$order" "$PAIVANA_PORT"
+ printf '"expiration":{"t_s":2000000000},'
+ printf '"nonce":"000G40R40M30E209185GR38E1W"}'
+}
+
+function redeem() {
+ local order="$1"
+ curl -sS -o "$SCRATCH/response.json" -w '%{http_code} %{time_total}\n' \
+ -H 'Content-Type: application/json' -X POST \
+ "http://127.0.0.1:$PAIVANA_PORT/.well-known/paivana" \
+ -d "$(redemption_body "$order")"
+}
+
+function expect_error() {
+ local want_code="$1" want_detail="$2"
+ python3 - "$SCRATCH/response.json" "$want_code" "$want_detail" <<'PY'
+import json
+import sys
+
+with open(sys.argv[1], encoding="utf-8") as f:
+ body = json.load(f)
+if body.get("code") != int(sys.argv[2]):
+ raise SystemExit(f"error code {body.get('code')}, want {sys.argv[2]}: {body}")
+if body.get("detail") != sys.argv[3]:
+ raise SystemExit(f"detail {body.get('detail')!r}, want {sys.argv[3]!r}")
+PY
+}
+
+command -v curl >/dev/null 2>&1 || { echo "SKIP: curl not found"; exit 77; }
+command -v python3 >/dev/null 2>&1 || { echo "SKIP: python3 not found"; exit 77; }
+[ -x "$PAIVANA_HTTPD" ] || { echo "SKIP: paivana-httpd not found"; exit 77; }
+if ! port_is_free "$MERCHANT_PORT" || ! port_is_free "$PAIVANA_PORT"; then
+ echo "SKIP: test ports are occupied; change PAIVANA_PORT_BASE" >&2
+ exit 77
+fi
+
+mkdir -p "$SCRATCH/configd" "$SCRATCH/prefix/share/paivana/templates"
+cp "$SRCDIR/../frontend/paywall.en.must.j2" \
+ "$SCRATCH/prefix/share/paivana/templates/"
+export PAIVANA_BASE_CONFIG="$SCRATCH/configd"
+export PAIVANA_PREFIX="$SCRATCH/prefix/"
+
+cat >"$SCRATCH/paivana.conf" <<EOF
+[paivana]
+DESTINATION_BASE_URL = http://127.0.0.1:9/
+BASE_URL = http://127.0.0.1:$PAIVANA_PORT/
+MERCHANT_BACKEND_URL = http://127.0.0.1:$MERCHANT_PORT/
+MERCHANT_ACCESS_TOKEN = secret-token:stub
+SECRET = payment-backend-failure-test
+SERVE = tcp
+PORT = $PAIVANA_PORT
+EOF
+
+start_stub
+"$PAIVANA_HTTPD" -c "$SCRATCH/paivana.conf" -L DEBUG \
+ >"$SCRATCH/paivana.log" 2>&1 &
+PAIVANA_PID=$!
+wait_for_port "$PAIVANA_PORT" "$PAIVANA_PID" || fail "paivana did not start"
+
+# A refused connection completes immediately. It must no longer be
+# presented as a five-second timeout.
+kill -TERM "$STUB_PID"
+wait "$STUB_PID" || true
+STUB_PID=""
+read -r status elapsed < <(redeem transport-failure)
+[ "$status" = "502" ] || fail "early transport failure returned HTTP $status"
+expect_error 9801 transport-failure || fail "unexpected early-failure JSON"
+python3 - "$elapsed" <<'PY' || fail "early failure took $elapsed seconds"
+import sys
+raise SystemExit(0 if float(sys.argv[1]) < 2.0 else 1)
+PY
+grep -q "early transport failure" "$SCRATCH/paivana.log" \
+ || fail "early-failure diagnostic missing from log"
+grep -q "1 concurrent merchant lookup including this one" "$SCRATCH/paivana.log" \
+ || fail "active lookup count missing from log"
+
+# A real HTTP response proves recovery and resets the consecutive
+# transport-failure counter.
+start_stub
+read -r status elapsed < <(redeem recovered-order)
+[ "$status" = "404" ] || fail "recovered backend returned HTTP $status"
+expect_error 9802 recovered-order || fail "unexpected recovery JSON"
+grep -q 'answered order .*recovered-order.* after 1 consecutive lookup' \
+ "$SCRATCH/paivana.log" || fail "recovery diagnostic missing from log"
+
+# A backend that holds the long poll beyond Paivana's own deadline is a
+# genuine timeout and must retain the 504/code-11 response.
+read -r status elapsed < <(redeem timeout-order)
+[ "$status" = "504" ] || fail "elapsed deadline returned HTTP $status"
+expect_error 11 timeout-order || fail "unexpected timeout JSON"
+python3 - "$elapsed" <<'PY' || fail "timeout returned after only $elapsed seconds"
+import sys
+raise SystemExit(0 if float(sys.argv[1]) >= 4.5 else 1)
+PY
+grep -q "by the 5 s deadline" "$SCRATCH/paivana.log" \
+ || fail "deadline diagnostic missing from log"
+
+echo "payment backend failure diagnostics: OK"
