commit cd419645f7a2644ddd613849d1c61d264ef30107
parent 92e1a4ebf55100e9b831ac621b3c9c4ae83511d6
Author: Florian Dold <dold@taler.net>
Date: Wed, 26 Aug 2026 22:09:18 +0200
payment: route merchant calls through an internal URL
Keep the public merchant URL in browser-facing payment data while allowing Paivana to use a cleartext HTTP instance URL over a Unix socket. Add forced-fresh diagnostics and regression coverage for intermittent pooled-connection failures.
Diffstat:
12 files changed, 1033 insertions(+), 47 deletions(-)
diff --git a/NEWS b/NEWS
@@ -4,7 +4,19 @@ Unreleased:
within the original five-second deadline, preventing a stale pooled
connection from intermittently turning a completed payment into error
9801. Merchant-related error JSON now includes `merchant_http_status',
- with zero meaning that no HTTP response was received.
+ with zero meaning that no HTTP response was received. When both attempts
+ fail early, the sampled warning queues one bounded, forced-fresh request
+ for the same order and logs its addresses, HTTP result, OS errno,
+ connection count and DNS/TCP/TLS/first-byte timings. This distinguishes a
+ shared connection-pool failure from general backend reachability without
+ logging the bearer token or response body.
+
+ - MERCHANT_BACKEND_INTERNAL_URL may now select a private HTTP(S) route for
+ Paivana's merchant API calls while MERCHANT_BACKEND_URL remains the public
+ URL advertised to browsers and wallets. In particular, a public HTTPS
+ merchant can be reached through a cleartext MERCHANT_BACKEND_UNIX_PATH
+ without attempting TLS over that socket or exposing an internal URL in the
+ paywall.
- High-load operation is now fail-fast and bounded. CONNECTION_LIMIT
defaults to 384 and may not exceed the select()-safe descriptor budget;
diff --git a/README b/README
@@ -97,6 +97,8 @@ Paivana reads an INI-style `.conf` file. The only section used is
[paivana]
DESTINATION_BASE_URL = https://example.com/
MERCHANT_BACKEND_URL = https://backend.demo.taler.net/instances/sandbox/
+ # Optional server-side route; useful with MERCHANT_BACKEND_UNIX_PATH.
+ # MERCHANT_BACKEND_INTERNAL_URL = http://backend.internal/instances/sandbox/
MERCHANT_ACCESS_TOKEN = secret-token:sandbox
BASE_URL = http://localhost:9967/
SERVE = tcp
@@ -107,7 +109,10 @@ Paivana reads an INI-style `.conf` file. The only section used is
Key Description
---------------------- -----------------------------------------------------
DESTINATION_BASE_URL Upstream server to proxy to once payment is confirmed.
- MERCHANT_BACKEND_URL Base URL of the Taler merchant backend.
+ MERCHANT_BACKEND_URL Public base URL of the Taler merchant backend.
+ It is advertised to browsers and wallets as well
+ as used for backend requests unless an internal
+ URL is configured below.
MERCHANT_ACCESS_TOKEN Bearer token for all calls to the merchant backend.
BASE_URL Public base URL of Paivana. Required unless `-f`
is given, in which case it is derived from the
@@ -192,9 +197,21 @@ Paivana reads an INI-style `.conf` file. The only section used is
URL is still what the request line and `Host` are built
from, so it remains required.
MERCHANT_BACKEND_UNIX_PATH
- The same for the merchant backend, relative to
- `MERCHANT_BACKEND_URL`. An unusable value is a warning and
- the setting is then ignored, not a startup failure.
+ Unix-domain socket to reach the merchant backend. The URL
+ scheme of `MERCHANT_BACKEND_INTERNAL_URL` (or, when absent,
+ `MERCHANT_BACKEND_URL`) is still spoken over that socket:
+ use `http` for a cleartext socket and `https` only for a
+ TLS-speaking socket. An unusable path is a warning and the
+ setting is then ignored, not a startup failure.
+ MERCHANT_BACKEND_INTERNAL_URL
+ Complete merchant-instance base URL used only for Paivana's
+ server-side template and order requests. It must be an HTTP(S)
+ URL ending in `/` and include the instance path. Defaults to
+ `MERCHANT_BACKEND_URL`. Set this to an `http` URL together with
+ `MERCHANT_BACKEND_UNIX_PATH` when a public HTTPS merchant is
+ exposed locally through a cleartext socket; browser-facing
+ pay-template URIs, JavaScript and CSP continue to use the public
+ `MERCHANT_BACKEND_URL`.
Running
@@ -235,6 +252,19 @@ covers unpaywalled. Transient backend outages are the service manager's
job to ride out -- the shipped `paivana-httpd.service` restarts with an
increasing back-off, and does not restart on a configuration error.
+An order-status request that fails before receiving any HTTP response is
+retried once inside the original five-second deadline. If that retry also
+fails early, Paivana's sampled warning is followed by one diagnostic GET for
+the same order with a forced fresh connection. Its log record reports whether
+an HTTP status was completed or merely observed before a transfer error, the
+new-connection count, local and remote addresses, OS errno, HTTP version and
+DNS/TCP/TLS/first-byte/total timings. The diagnostic uses the existing
+authenticated merchant context but never logs its bearer token or response
+body, and its result does not change the error returned to the client. A real
+HTTP status from the forced-fresh request, after both shared-context attempts
+failed, is strong evidence for a connection-pool/reuse problem rather than a
+merchant application outage.
+
An instance that offers no template at all is refused for the same
reason: with nothing to sell, no URL ever matches a paywall and the
entire site would be served for free without a word of warning. Serving
diff --git a/debian/etc/paivana/paivana.conf b/debian/etc/paivana/paivana.conf
@@ -8,6 +8,11 @@ SERVE = systemd
# start without them.
# DESTINATION_BASE_URL = http://localhost:8080/
# MERCHANT_BACKEND_URL = http://localhost:9966/
+# If Paivana should use a different server-side route while advertising the
+# public URL above, set both of these. The URL scheme is spoken over the
+# socket, so use http:// for a cleartext Unix listener.
+# MERCHANT_BACKEND_INTERNAL_URL = http://merchant.internal/instances/paivana/
+# MERCHANT_BACKEND_UNIX_PATH = /run/taler-merchant/merchant-http.sock
# Which HTTP port does the backend listen on? Only used if "SERVE" is 'tcp'.
# PORT = 9967
diff --git a/src/backend/paivana-httpd.c b/src/backend/paivana-httpd.c
@@ -49,6 +49,10 @@ char *PH_target_server_unixpath;
char *PH_merchant_base_url;
+char *PH_merchant_internal_url;
+
+char *PH_merchant_unixpath;
+
char *PH_base_url;
struct GNUNET_CURL_Context *PH_merchant_ctx;
@@ -410,6 +414,8 @@ finish_shutdown (void)
GNUNET_free (PH_trusted_proxies4);
GNUNET_free (PH_trusted_proxies6);
GNUNET_free (PH_merchant_base_url);
+ GNUNET_free (PH_merchant_internal_url);
+ GNUNET_free (PH_merchant_unixpath);
GNUNET_free (PH_base_url);
if (PH_have_whitelist_ex)
{
@@ -1002,6 +1008,34 @@ run (void *cls,
GNUNET_SCHEDULER_shutdown ();
return;
}
+ if (GNUNET_OK !=
+ GNUNET_CONFIGURATION_get_value_string (
+ c,
+ "paivana",
+ "MERCHANT_BACKEND_INTERNAL_URL",
+ &PH_merchant_internal_url))
+ PH_merchant_internal_url = GNUNET_strdup (PH_merchant_base_url);
+ if (! TALER_is_web_url (PH_merchant_internal_url))
+ {
+ GNUNET_log_config_invalid (GNUNET_ERROR_TYPE_ERROR,
+ "paivana",
+ "MERCHANT_BACKEND_INTERNAL_URL",
+ "not a web url");
+ PH_global_ret = EXIT_NOTCONFIGURED;
+ GNUNET_SCHEDULER_shutdown ();
+ return;
+ }
+ if ('/' != PH_merchant_internal_url[
+ strlen (PH_merchant_internal_url) - 1])
+ {
+ GNUNET_log_config_invalid (GNUNET_ERROR_TYPE_ERROR,
+ "paivana",
+ "MERCHANT_BACKEND_INTERNAL_URL",
+ "must end with a '/'");
+ PH_global_ret = EXIT_NOTCONFIGURED;
+ GNUNET_SCHEDULER_shutdown ();
+ return;
+ }
}
{
char *merchant_unix_path;
@@ -1020,6 +1054,11 @@ run (void *cls,
"MERCHANT_BACKEND_UNIX_PATH",
"invalid path; ignoring the setting");
}
+ else
+ {
+ PH_merchant_unixpath = merchant_unix_path;
+ merchant_unix_path = NULL;
+ }
GNUNET_free (merchant_unix_path);
}
}
diff --git a/src/backend/paivana-httpd.h b/src/backend/paivana-httpd.h
@@ -78,11 +78,24 @@ extern char *PH_target_server_base_url;
extern char *PH_target_server_unixpath;
/**
- * Merchant backend base URL.
+ * Public merchant backend base URL advertised to browsers and wallets.
*/
extern char *PH_merchant_base_url;
/**
+ * Merchant backend base URL used for Paivana's private API requests.
+ * Defaults to a copy of #PH_merchant_base_url.
+ */
+extern char *PH_merchant_internal_url;
+
+/**
+ * Optional Unix socket used to reach the merchant backend. Kept so the
+ * forced-fresh transport diagnostic follows the same route as the regular
+ * merchant client.
+ */
+extern char *PH_merchant_unixpath;
+
+/**
* Base URL of this site as seen by the client. If not set,
* we will try to determine it from "X-Forwarded-Host" and
* "Host" and "X-Forwarded-Port" headers.
diff --git a/src/backend/paivana-httpd_pay.c b/src/backend/paivana-httpd_pay.c
@@ -24,7 +24,9 @@
* @brief payment processing logic
*/
#include "platform.h"
+#include <curl/curl.h>
#include <microhttpd.h>
+#include <gnunet/gnunet_curl_lib.h>
#include <gnunet/gnunet_util_lib.h>
#include <taler/taler_mhd_lib.h>
#include <taler/taler_json_lib.h>
@@ -194,6 +196,27 @@ static unsigned int merchant_transport_failures;
static unsigned int active_merchant_lookups;
/**
+ * One forced-fresh request started after a sampled early transport failure.
+ * It is diagnostic only: the client's response is still determined by the
+ * two regular merchant API attempts. Keeping these in a DLL lets shutdown
+ * cancel both a not-yet-started scheduler task and a live curl job safely.
+ */
+struct MerchantTransportDiagnostic
+{
+ struct MerchantTransportDiagnostic *next;
+ struct MerchantTransportDiagnostic *prev;
+ struct GNUNET_SCHEDULER_Task *task;
+ struct GNUNET_CURL_Job *job;
+ CURL *easy;
+ char *url;
+ char *order_id;
+ char error[CURL_ERROR_SIZE];
+};
+
+static struct MerchantTransportDiagnostic *diagnostic_head;
+static struct MerchantTransportDiagnostic *diagnostic_tail;
+
+/**
* Merchant transport diagnostics are useful immediately and then at most once
* per minute per failure class. A minute is short enough for an operator to
* see a persistent outage in routine monitoring, while reducing 32 concurrent
@@ -235,6 +258,261 @@ static struct MerchantFailureLogState failure_logs[MFC_COUNT];
/**
+ * Discard a diagnostic response body without retaining contract data.
+ */
+static size_t
+discard_diagnostic_body (void *cls,
+ const void *data,
+ size_t data_size)
+{
+ (void) cls;
+ (void) data;
+ return data_size;
+}
+
+
+/**
+ * Make curl's fixed-size error buffer safe to embed in one log record.
+ */
+static void
+sanitize_diagnostic_error (char *error)
+{
+ for (char *p = error; '\0' != *p; p++)
+ if (iscntrl ((unsigned char) *p) ||
+ ('"' == *p) ||
+ ('\\' == *p))
+ *p = ' ';
+}
+
+
+/**
+ * Release a completed diagnostic after GNUnet has removed and cleaned up its
+ * easy handle. In particular, CURLOPT_ERRORBUFFER requires @e md->error to
+ * remain alive until that cleanup is over, which happens after the completion
+ * callback returns.
+ */
+static void
+free_completed_diagnostic (void *cls)
+{
+ struct MerchantTransportDiagnostic *md = cls;
+
+ md->task = NULL;
+ GNUNET_CONTAINER_DLL_remove (diagnostic_head,
+ diagnostic_tail,
+ md);
+ GNUNET_free (md->url);
+ GNUNET_free (md->order_id);
+ GNUNET_free (md);
+}
+
+
+/**
+ * Report the result while the easy handle still exists, then release our
+ * closure on the next scheduler turn. GNUnet removes and destroys the curl
+ * job after this callback returns.
+ */
+static void
+fresh_diagnostic_finished (void *cls,
+ long completed_http_status,
+ const void *body,
+ size_t body_size)
+{
+ struct MerchantTransportDiagnostic *md = cls;
+ long observed_http_status = 0;
+ long new_connections = -1;
+ long os_errno = 0;
+ long http_version = 0;
+ const char *remote_ip = NULL;
+ const char *local_ip = NULL;
+ double dns_s = 0;
+ double tcp_s = 0;
+ double tls_s = 0;
+ double first_byte_s = 0;
+ double total_s = 0;
+
+ (void) body;
+ (void) body_size;
+ md->job = NULL;
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_RESPONSE_CODE,
+ &observed_http_status);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_NUM_CONNECTS,
+ &new_connections);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_OS_ERRNO,
+ &os_errno);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_HTTP_VERSION,
+ &http_version);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_PRIMARY_IP,
+ &remote_ip);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_LOCAL_IP,
+ &local_ip);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_NAMELOOKUP_TIME,
+ &dns_s);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_CONNECT_TIME,
+ &tcp_s);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_APPCONNECT_TIME,
+ &tls_s);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_STARTTRANSFER_TIME,
+ &first_byte_s);
+ (void) curl_easy_getinfo (md->easy,
+ CURLINFO_TOTAL_TIME,
+ &total_s);
+ sanitize_diagnostic_error (md->error);
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Forced-fresh merchant diagnostic for order `%s': completed"
+ " HTTP status %ld, observed HTTP status %ld, curl error"
+ " \"%s\", new connections %ld, local address %s, remote"
+ " address %s, OS errno %ld, HTTP version %ld; timings in"
+ " seconds (TCP Fast Open enabled): DNS %.6f, TCP %.6f, TLS"
+ " %.6f, first byte %.6f, total %.6f%s\n",
+ md->order_id,
+ completed_http_status,
+ observed_http_status,
+ md->error,
+ new_connections,
+ (NULL != local_ip) ? local_ip : "<none>",
+ (NULL != remote_ip) ? remote_ip : "<none>",
+ os_errno,
+ http_version,
+ dns_s,
+ tcp_s,
+ tls_s,
+ first_byte_s,
+ total_s,
+ (0 != completed_http_status)
+ ? "; a fresh connection reached the merchant after the shared"
+ " merchant context failed"
+ : "");
+ md->easy = NULL;
+ md->task = GNUNET_SCHEDULER_add_now (&free_completed_diagnostic,
+ md);
+}
+
+
+/**
+ * Start a forced-fresh request after the failed merchant job has completely
+ * left libcurl's multi handle. This is the useful A/B comparison with the
+ * two regular attempts, which share the long-lived connection pool.
+ */
+static void
+start_fresh_diagnostic (void *cls)
+{
+ struct MerchantTransportDiagnostic *md = cls;
+ struct GNUNET_CURL_StreamHandlers sh = {
+ .scb = &discard_diagnostic_body,
+ .scb_cls = md,
+ .jcc = &fresh_diagnostic_finished,
+ .jcc_cls = md
+ };
+ CURLcode cc;
+
+ md->task = NULL;
+ md->easy = curl_easy_init ();
+ if (NULL == md->easy)
+ goto fail;
+ md->error[0] = '\0';
+#define SET_DIAGNOSTIC_OPTION(opt,val) do { \
+ cc = curl_easy_setopt (md->easy, opt, val); \
+ if (CURLE_OK != cc) \
+ goto setopt_fail; \
+ } while (0)
+ SET_DIAGNOSTIC_OPTION (CURLOPT_URL,
+ md->url);
+ SET_DIAGNOSTIC_OPTION (CURLOPT_ERRORBUFFER,
+ md->error);
+ SET_DIAGNOSTIC_OPTION (CURLOPT_CONNECTTIMEOUT_MS,
+ 1500L);
+ SET_DIAGNOSTIC_OPTION (CURLOPT_TIMEOUT_MS,
+ 2000L);
+ SET_DIAGNOSTIC_OPTION (CURLOPT_ACCEPT_ENCODING,
+ "");
+ SET_DIAGNOSTIC_OPTION (CURLOPT_TCP_FASTOPEN,
+ 1L);
+ SET_DIAGNOSTIC_OPTION (CURLOPT_FRESH_CONNECT,
+ 1L);
+ SET_DIAGNOSTIC_OPTION (CURLOPT_FORBID_REUSE,
+ 1L);
+ if (NULL != PH_merchant_unixpath)
+ SET_DIAGNOSTIC_OPTION (CURLOPT_UNIX_SOCKET_PATH,
+ PH_merchant_unixpath);
+#undef SET_DIAGNOSTIC_OPTION
+ md->job = GNUNET_CURL_job_add_stream (PH_merchant_ctx,
+ md->easy,
+ NULL,
+ &sh);
+ if (NULL != md->job)
+ return;
+ md->easy = NULL; /* GNUNET_CURL_job_add_stream() released it. */
+ goto fail;
+
+setopt_fail:
+#undef SET_DIAGNOSTIC_OPTION
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Could not configure forced-fresh merchant diagnostic for"
+ " order `%s': %s\n",
+ md->order_id,
+ curl_easy_strerror (cc));
+ curl_easy_cleanup (md->easy);
+ md->easy = NULL;
+fail:
+ GNUNET_CONTAINER_DLL_remove (diagnostic_head,
+ diagnostic_tail,
+ md);
+ GNUNET_free (md->url);
+ GNUNET_free (md->order_id);
+ GNUNET_free (md);
+}
+
+
+/**
+ * Queue one credential-safe diagnostic of the exact failed order lookup.
+ * The bearer token is attached by #PH_merchant_ctx and is never copied here.
+ */
+static void
+queue_fresh_diagnostic (const struct PayRequest *ph)
+{
+ struct MerchantTransportDiagnostic *md;
+ char *path;
+ char *paivana_id;
+
+ GNUNET_asprintf (&path,
+ "private/orders/%s",
+ ph->order_id);
+ paivana_id = PAIVANA_HTTPD_compute_paivana_id (ph->expiration,
+ ph->website,
+ &ph->nonce);
+ md = GNUNET_new (struct MerchantTransportDiagnostic);
+ md->url = TALER_url_join (PH_merchant_internal_url,
+ path,
+ "session_id",
+ paivana_id,
+ NULL);
+ GNUNET_free (paivana_id);
+ GNUNET_free (path);
+ if (NULL == md->url)
+ {
+ GNUNET_free (md);
+ return;
+ }
+ md->order_id = GNUNET_strdup (ph->order_id);
+ GNUNET_CONTAINER_DLL_insert (diagnostic_head,
+ diagnostic_tail,
+ md);
+ md->task = GNUNET_SCHEDULER_add_now (&start_fresh_diagnostic,
+ md);
+}
+
+
+/**
* Decide whether to emit a merchant failure warning now.
*
* @param fc failure class
@@ -366,6 +644,21 @@ log_file_descriptor_usage (void)
void
PAIVANA_HTTPD_payment_shutdown ()
{
+ while (NULL != diagnostic_head)
+ {
+ struct MerchantTransportDiagnostic *md = diagnostic_head;
+
+ if (NULL != md->task)
+ GNUNET_SCHEDULER_cancel (md->task);
+ if (NULL != md->job)
+ GNUNET_CURL_job_cancel (md->job);
+ GNUNET_CONTAINER_DLL_remove (diagnostic_head,
+ diagnostic_tail,
+ md);
+ GNUNET_free (md->url);
+ GNUNET_free (md->order_id);
+ GNUNET_free (md);
+ }
while (NULL != ph_head)
{
struct PayRequest *ph = ph_head;
@@ -468,7 +761,7 @@ start_merchant_order_lookup (struct PayRequest *ph,
GNUNET_assert (NULL == ph->co);
ph->co = TALER_MERCHANT_get_private_order_create (PH_merchant_ctx,
- PH_merchant_base_url,
+ PH_merchant_internal_url,
ph->order_id);
if (NULL == ph->co)
return TALER_EC_GENERIC_INTERNAL_INVARIANT_FAILURE;
@@ -742,7 +1035,7 @@ order_status_cb (struct PayRequest *ph,
"Merchant backend at `%s' answered order `%s' after %u"
" consecutive lookup%s without an HTTP response (%u"
" repetitive diagnostic%s suppressed)\n",
- PH_merchant_base_url,
+ PH_merchant_internal_url,
ph->order_id,
merchant_transport_failures,
(1 == merchant_transport_failures) ? "" : "s",
@@ -869,7 +1162,7 @@ order_status_cb (struct PayRequest *ph,
GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
"Merchant backend at `%s' rejected our credentials (HTTP"
" %u); check MERCHANT_ACCESS_TOKEN\n",
- PH_merchant_base_url,
+ PH_merchant_internal_url,
osr->hr.http_status);
ph->response = make_merchant_error (TALER_EC_PAIVANA_BACKEND_REFUSED,
NULL,
@@ -899,7 +1192,7 @@ order_status_cb (struct PayRequest *ph,
"Merchant backend at `%s' sent an unusable reply for"
" order `%s' after %s (%u similar diagnostic%s"
" suppressed)\n",
- PH_merchant_base_url,
+ PH_merchant_internal_url,
ph->order_id,
elapsed_s,
suppressed,
@@ -928,7 +1221,7 @@ order_status_cb (struct PayRequest *ph,
" concurrent merchant lookup%s including this one; %u"
" consecutive transport failure%s; %u similar"
" diagnostic%s suppressed)\n",
- PH_merchant_base_url,
+ PH_merchant_internal_url,
ph->order_id,
timeout_s,
elapsed_s,
@@ -967,7 +1260,7 @@ order_status_cb (struct PayRequest *ph,
" (%u concurrent merchant lookup%s including this one;"
" %u consecutive transport failure%s; %u similar"
" diagnostic%s suppressed)\n",
- PH_merchant_base_url,
+ PH_merchant_internal_url,
ph->order_id,
elapsed_s,
timeout_s,
@@ -977,6 +1270,7 @@ order_status_cb (struct PayRequest *ph,
(1 == merchant_transport_failures) ? "" : "s",
suppressed,
(1 == suppressed) ? "" : "s");
+ queue_fresh_diagnostic (ph);
}
ph->response = make_merchant_error (TALER_EC_PAIVANA_BACKEND_REFUSED,
ph->order_id,
diff --git a/src/backend/paivana-httpd_templates.c b/src/backend/paivana-httpd_templates.c
@@ -288,7 +288,7 @@ load_timeout (void *cls)
GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
"Merchant backend at `%s' did not answer our template queries"
" within %s; giving up instead of never starting to serve\n",
- PH_merchant_base_url,
+ PH_merchant_internal_url,
GNUNET_STRINGS_relative_time_to_string (TEMPLATE_LOAD_TIMEOUT,
true));
PH_global_ret = EXIT_FAILURE;
@@ -319,7 +319,7 @@ templates_ready (void)
" refusing to start, as every request would then be"
" forwarded for free. Pass -n if serving the site without"
" a paywall is what you want.\n",
- PH_merchant_base_url);
+ PH_merchant_internal_url);
PH_global_ret = EXIT_NOTCONFIGURED;
GNUNET_SCHEDULER_shutdown ();
return;
@@ -1271,7 +1271,7 @@ start_template_fetches (void)
GNUNET_assert (TLS_WAITING == t->load_state);
t->gt = TALER_MERCHANT_get_private_template_create (
PH_merchant_ctx,
- PH_merchant_base_url,
+ PH_merchant_internal_url,
t->template_id);
if (NULL == t->gt)
{
@@ -1409,7 +1409,7 @@ PAIVANA_HTTPD_load_templates ()
&load_timeout,
NULL);
gpt = TALER_MERCHANT_get_private_templates_create (PH_merchant_ctx,
- PH_merchant_base_url);
+ PH_merchant_internal_url);
if (NULL == gpt)
{
GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
diff --git a/src/tests/README b/src/tests/README
@@ -901,18 +901,24 @@ the expected backend.
Payment-backend failure diagnostics
-----------------------------------
-`test_payment_backend_failure.sh` starts paivana against a small Python
-merchant stub and first drops an order lookup before sending any HTTP
-response. Paivana must retry that idempotent GET once within its original
-five-second budget and return the second attempt's response. The test 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 and `merchant_http_status: 0' in the error JSON; it must not claim
-that the five-second deadline elapsed. The 404 cases likewise assert the
-actual merchant status in that field. The stub is 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.
+`test_payment_backend_failure.sh` starts Paivana against a small Python
+merchant stub through `merchant_fault_proxy.py`. Paivana advertises a public
+HTTPS merchant URL while its template and order requests use a distinct HTTP
+URL through the proxy's Unix listener, including the full merchant-instance
+prefix. The test verifies that the internal URL does not leak into the
+paywall, and that malformed internal URLs fail at startup. Template and
+warm-up order requests leave a real persistent merchant connection idle. The
+fault frontend then resets the next order lookup on that reused connection
+before forwarding or access-logging it, also covering libcurl's internal fresh
+retry and Paivana's application retry. Paivana must return promptly as 502 /
+error 9801 with `merchant_http_status: 0`, while its forced-fresh diagnostic
+and five separate curl processes all reach the merchant. The test explicitly
+verifies that none of the failed attempts appears in either the frontend or
+merchant access log. It then stops the stub to cover a refused port, restarts
+it to prove a real HTTP response resets the consecutive-failure count, and
+finally holds an order lookup open long enough to retain the 504 / error 11
+timeout path. This deterministic version needs neither PostgreSQL nor a full
+Taler deployment.
The paywall suite
@@ -925,6 +931,20 @@ and anastasis suites start theirs -- creates a Paivana template on the
merchant instance, buys access with `taler-wallet-cli`, and checks what
the daemon does with the result. 31 checks, about 25 seconds.
+The production failure has a real-stack reproduction mode:
+
+ PAIVANA_REPRO_MERCHANT_POOL_FAILURE=1 \
+ meson test -C build --print-errorlogs paywall
+
+In this mode the same fault frontend sits between Paivana and the real
+PostgreSQL-backed merchant, but remains unarmed through startup, withdrawal and
+payment. Once the wallet has paid a genuine order, the test arms exactly that
+order path and proves all of the reported production properties together:
+Paivana returns 502 / code 9801 / merchant status zero; the first reset was on
+an idle pooled connection; no failed request reached the frontend access log;
+the forced-fresh diagnostic receives HTTP 200; and five subsequent fresh order
+status requests all succeed through the same frontend.
+
It skips (exit 77) rather than failing when the environment cannot
support it: no `taler-unified-setup.sh`, `taler-wallet-cli`,
`taler-merchant-httpd`, `jq`, `python3` or PostgreSQL, no built paywall
diff --git a/src/tests/merchant_fault_proxy.py b/src/tests/merchant_fault_proxy.py
@@ -0,0 +1,324 @@
+#!/usr/bin/env python3
+"""Merchant frontend that can reset selected requests before access log.
+
+The proxy is deliberately small and HTTP/1.1-only. It accepts TCP or Unix
+socket clients, optionally terminates TLS, keeps client and upstream
+connections alive, and forwards one
+request/response at a time. For the configured path, the first N requests are
+reset after their headers have arrived but before a byte is sent upstream.
+Consequently its FAULT log proves the transport attempt happened, while
+neither its ACCESS log nor the merchant backend sees an HTTP request.
+"""
+
+import argparse
+import os
+import socket
+import ssl
+import struct
+import threading
+import time
+from urllib.parse import urlsplit
+
+
+def log(message):
+ print(message, flush=True)
+
+
+def recv_until(sock, buffer, marker):
+ while marker not in buffer:
+ chunk = sock.recv(65536)
+ if not chunk:
+ return None, b""
+ buffer += chunk
+ if len(buffer) > 1024 * 1024:
+ raise RuntimeError("HTTP header exceeded 1 MiB")
+ head, buffer = buffer.split(marker, 1)
+ return head + marker, buffer
+
+
+def content_length(header):
+ for line in header.split(b"\r\n")[1:]:
+ name, sep, value = line.partition(b":")
+ if sep and name.strip().lower() == b"content-length":
+ return int(value.strip())
+ return 0
+
+
+def connection_closes(header):
+ for line in header.split(b"\r\n")[1:]:
+ name, sep, value = line.partition(b":")
+ if sep and name.strip().lower() == b"connection":
+ return b"close" in value.lower()
+ return False
+
+
+def transfer_is_chunked(header):
+ for line in header.split(b"\r\n")[1:]:
+ name, sep, value = line.partition(b":")
+ if sep and name.strip().lower() == b"transfer-encoding":
+ return b"chunked" in value.lower()
+ return False
+
+
+def relay_exact(source, destination, initial, length):
+ data = initial
+ if len(data) > length:
+ destination.sendall(data[:length])
+ return data[length:]
+ if data:
+ destination.sendall(data)
+ length -= len(data)
+ while length:
+ chunk = source.recv(min(65536, length))
+ if not chunk:
+ raise EOFError("connection closed in fixed-length HTTP body")
+ destination.sendall(chunk)
+ length -= len(chunk)
+ return b""
+
+
+def relay_chunked(source, destination, initial):
+ buffer = initial
+ while True:
+ line, buffer = recv_until(source, buffer, b"\r\n")
+ if line is None:
+ raise EOFError("connection closed in chunk-size line")
+ destination.sendall(line)
+ size_text = line[:-2].split(b";", 1)[0]
+ size = int(size_text, 16)
+ if size:
+ buffer = relay_exact(source, destination, buffer, size + 2)
+ continue
+ # The zero chunk is followed by zero or more trailer lines and one
+ # blank line. Reading a line at a time also handles the usual no-
+ # trailer form, which contains only that final CRLF.
+ while True:
+ trailer, buffer = recv_until(source, buffer, b"\r\n")
+ if trailer is None:
+ raise EOFError("connection closed in chunk trailers")
+ destination.sendall(trailer)
+ if trailer == b"\r\n":
+ return buffer
+
+
+def reset_connection(sock):
+ try:
+ sock.setsockopt(socket.SOL_SOCKET,
+ socket.SO_LINGER,
+ struct.pack("ii", 1, 0))
+ except OSError:
+ pass
+ try:
+ sock.close()
+ except OSError:
+ pass
+
+
+class FaultBudget:
+ def __init__(self, path, count, control_file):
+ self.path = path
+ self.remaining = count
+ self.issued = 0
+ self.control_file = control_file
+ self.control_version = None
+ self.lock = threading.Lock()
+
+ def refresh(self):
+ if not self.control_file:
+ return
+ try:
+ stat = os.stat(self.control_file)
+ version = (stat.st_mtime_ns, stat.st_size)
+ if version == self.control_version:
+ return
+ with open(self.control_file, encoding="utf-8") as stream:
+ fields = stream.read().strip().split()
+ except FileNotFoundError:
+ return
+ if len(fields) != 2:
+ raise RuntimeError(
+ "fault control file must contain: PATH COUNT")
+ self.path = fields[0]
+ self.remaining = int(fields[1])
+ self.issued = 0
+ self.control_version = version
+ log(f"ARM path={self.path} count={self.remaining}")
+
+ def consume(self, path):
+ with self.lock:
+ self.refresh()
+ if path != self.path or self.remaining == 0:
+ return None
+ self.remaining -= 1
+ self.issued += 1
+ return self.issued
+
+
+class Proxy:
+ def __init__(self, args):
+ self.args = args
+ self.faults = FaultBudget(args.fault_path,
+ args.fault_count,
+ args.control_file)
+ self.context = None
+ if args.cert:
+ self.context = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER)
+ self.context.minimum_version = ssl.TLSVersion.TLSv1_2
+ self.context.set_alpn_protocols(["http/1.1"])
+ self.context.load_cert_chain(args.cert, args.key)
+ self.connection_id = 0
+ self.connection_lock = threading.Lock()
+
+ def next_connection_id(self):
+ with self.connection_lock:
+ self.connection_id += 1
+ return self.connection_id
+
+ def handle(self, raw_client):
+ connection_id = self.next_connection_id()
+ stage = "TLS handshake"
+ if self.context:
+ try:
+ client = self.context.wrap_socket(raw_client, server_side=True)
+ except (ssl.SSLError, OSError):
+ raw_client.close()
+ return
+ else:
+ client = raw_client
+ try:
+ stage = "upstream connect"
+ upstream = socket.create_connection(
+ (self.args.upstream_host, self.args.upstream_port), timeout=2)
+ upstream.settimeout(self.args.io_timeout)
+ client.settimeout(self.args.io_timeout)
+ except OSError as exc:
+ log(f"UPSTREAM_CONNECT_ERROR connection={connection_id} error={exc}")
+ reset_connection(client)
+ return
+
+ client_buffer = b""
+ upstream_buffer = b""
+ prior_requests = 0
+ last_response = time.monotonic()
+ try:
+ while True:
+ stage = "request headers from client"
+ request, client_buffer = recv_until(
+ client, client_buffer, b"\r\n\r\n")
+ if request is None:
+ return
+ request_line = request.split(b"\r\n", 1)[0].decode(
+ "iso-8859-1", "replace")
+ parts = request_line.split(" ")
+ if len(parts) != 3:
+ raise RuntimeError(f"malformed request line {request_line!r}")
+ method, target, _ = parts
+ path = urlsplit(target).path
+ idle_ms = int((time.monotonic() - last_response) * 1000)
+ fault_index = self.faults.consume(path)
+ if fault_index is not None:
+ log("FAULT "
+ f"index={fault_index} connection={connection_id} "
+ f"path={path} reused={'yes' if prior_requests else 'no'} "
+ f"prior_requests={prior_requests} idle_ms={idle_ms}")
+ reset_connection(client)
+ upstream.close()
+ return
+
+ body_length = content_length(request)
+ stage = "request headers to upstream"
+ upstream.sendall(request)
+ stage = "request body to upstream"
+ client_buffer = relay_exact(
+ client, upstream, client_buffer, body_length)
+ prior_requests += 1
+ log("ACCESS "
+ f"connection={connection_id} request={prior_requests} "
+ f"method={method} path={path}")
+
+ stage = "response headers from upstream"
+ response, upstream_buffer = recv_until(
+ upstream, upstream_buffer, b"\r\n\r\n")
+ if response is None:
+ raise EOFError("upstream closed before response headers")
+ stage = "response headers to client"
+ client.sendall(response)
+ status_parts = response.split(b"\r\n", 1)[0].split(b" ")
+ no_body = (method == "HEAD" or
+ (len(status_parts) > 1 and
+ (status_parts[1][:1] == b"1" or
+ status_parts[1] in (b"204", b"304"))))
+ if transfer_is_chunked(response):
+ stage = "chunked response body to client"
+ upstream_buffer = relay_chunked(
+ upstream, client, upstream_buffer)
+ elif not no_body:
+ length = content_length(response)
+ if length:
+ stage = "fixed response body to client"
+ upstream_buffer = relay_exact(
+ upstream, client, upstream_buffer, length)
+ last_response = time.monotonic()
+ if connection_closes(request) or connection_closes(response):
+ return
+ except (EOFError, OSError, RuntimeError, ValueError) as exc:
+ log(f"CONNECTION_ERROR connection={connection_id} "
+ f"stage={stage} error={exc}")
+ finally:
+ try:
+ client.close()
+ except OSError:
+ pass
+ try:
+ upstream.close()
+ except OSError:
+ pass
+
+ def serve(self):
+ if self.args.listen_unix:
+ if os.path.exists(self.args.listen_unix):
+ raise RuntimeError(
+ f"Unix listener path already exists: {self.args.listen_unix}")
+ listener = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
+ listener.bind(self.args.listen_unix)
+ listen_address = self.args.listen_unix
+ else:
+ listener = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
+ listener.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
+ listener.bind((self.args.listen_host, self.args.listen_port))
+ listen_address = (f"{listener.getsockname()[0]}:"
+ f"{listener.getsockname()[1]}")
+ listener.listen(128)
+ log(f"READY {listen_address}")
+ while True:
+ client, _ = listener.accept()
+ thread = threading.Thread(target=self.handle,
+ args=(client,),
+ daemon=True)
+ thread.start()
+
+
+def main():
+ parser = argparse.ArgumentParser()
+ parser.add_argument("--listen-host", default="127.0.0.1")
+ listen = parser.add_mutually_exclusive_group(required=True)
+ listen.add_argument("--listen-port", type=int)
+ listen.add_argument("--listen-unix")
+ parser.add_argument("--upstream-host", default="127.0.0.1")
+ parser.add_argument("--upstream-port", type=int, required=True)
+ parser.add_argument("--fault-path")
+ parser.add_argument("--fault-count", type=int, default=2)
+ parser.add_argument("--control-file")
+ parser.add_argument("--io-timeout", type=float, default=300)
+ parser.add_argument("--cert")
+ parser.add_argument("--key")
+ args = parser.parse_args()
+ if bool(args.cert) != bool(args.key):
+ parser.error("--cert and --key must be specified together")
+ if not args.fault_path and not args.control_file:
+ parser.error("one of --fault-path or --control-file is required")
+ Proxy(args).serve()
+
+
+if __name__ == "__main__":
+ main()
diff --git a/src/tests/payment_backend_stub.py b/src/tests/payment_backend_stub.py
@@ -15,6 +15,7 @@ TEMPLATE_ID = "premium"
TEMPLATE_COUNT = int(os.environ.get("PAIVANA_STUB_TEMPLATE_COUNT", "1"))
CONTRACT_PADDING = int(os.environ.get("PAIVANA_STUB_CONTRACT_PADDING", "0"))
DETAIL_DELAY = float(os.environ.get("PAIVANA_STUB_DETAIL_DELAY", "0"))
+BASE_PATH = os.environ.get("PAIVANA_STUB_BASE_PATH", "").rstrip("/")
detail_lock = threading.Lock()
active_details = 0
retry_order_dropped = False
@@ -43,7 +44,6 @@ class Handler(BaseHTTPRequestHandler):
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)
@@ -52,6 +52,11 @@ class Handler(BaseHTTPRequestHandler):
self.reply(401, {"code": 2000, "hint": "wrong bearer token"})
return
path = urlsplit(self.path).path
+ if BASE_PATH:
+ if not path.startswith(BASE_PATH + "/"):
+ self.reply(404, {"code": 2906, "hint": "wrong base path"})
+ return
+ path = path[len(BASE_PATH):]
if path == "/private/templates":
self.reply(
200,
diff --git a/src/tests/test_payment_backend_failure.sh b/src/tests/test_payment_backend_failure.sh
@@ -11,17 +11,23 @@ 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))
+MERCHANT_BACKEND_PORT=$((PORT_BASE + 120))
PAIVANA_PORT=$((PORT_BASE + 121))
SCRATCH="$(mktemp -d -t paivana-payment-failure.XXXXXX)"
+MERCHANT_SOCKET="$SCRATCH/merchant.sock"
+PUBLIC_MERCHANT_URL="https://public-merchant.example/instances/paivana/"
+INTERNAL_MERCHANT_URL="http://merchant.invalid/instances/paivana/"
STUB_PID=""
+PROXY_PID=""
PAIVANA_PID=""
function cleanup() {
set +e
[ -n "$STUB_PID" ] && kill -TERM "$STUB_PID" 2>/dev/null
+ [ -n "$PROXY_PID" ] && kill -TERM "$PROXY_PID" 2>/dev/null
[ -n "$PAIVANA_PID" ] && kill -TERM "$PAIVANA_PID" 2>/dev/null
wait "$STUB_PID" 2>/dev/null
+ wait "$PROXY_PID" 2>/dev/null
wait "$PAIVANA_PID" 2>/dev/null
if [ "${KEEP_TMP:-0}" = "1" ]; then
echo "Temp files kept in $SCRATCH" >&2
@@ -49,23 +55,53 @@ function wait_for_port() {
return 1
}
+function wait_for_unix_socket() {
+ local path="$1" pid="$2" tries=50
+ while [ "$tries" -gt 0 ]; do
+ if [ -S "$path" ] &&
+ grep -Fxq "READY $path" "$SCRATCH/proxy.log"
+ 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
+ echo "==> proxy.log <==" >&2
+ tail -n 60 "$SCRATCH/proxy.log" >&2 || true
exit 1
}
function start_stub() {
- python3 "$SRCDIR/payment_backend_stub.py" "$MERCHANT_PORT" \
+ PAIVANA_STUB_BASE_PATH=/instances/paivana \
+ python3 "$SRCDIR/payment_backend_stub.py" "$MERCHANT_BACKEND_PORT" \
>>"$SCRATCH/merchant.log" 2>&1 &
STUB_PID=$!
- wait_for_port "$MERCHANT_PORT" "$STUB_PID" \
+ wait_for_port "$MERCHANT_BACKEND_PORT" "$STUB_PID" \
|| fail "merchant stub did not start"
}
+function start_proxy() {
+ python3 "$SRCDIR/merchant_fault_proxy.py" \
+ --listen-unix "$MERCHANT_SOCKET" \
+ --upstream-port "$MERCHANT_BACKEND_PORT" \
+ --fault-path /instances/paivana/private/orders/diagnostic-order \
+ --fault-count 3 \
+ >>"$SCRATCH/proxy.log" 2>&1 &
+ PROXY_PID=$!
+ wait_for_unix_socket "$MERCHANT_SOCKET" "$PROXY_PID" \
+ || fail "merchant fault frontend did not start"
+}
+
function redemption_body() {
local order="$1"
printf '{"order_id":"%s","website":"http://127.0.0.1:%u/article",' \
@@ -106,7 +142,8 @@ 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
+if ! port_is_free "$MERCHANT_BACKEND_PORT" || \
+ ! port_is_free "$PAIVANA_PORT"; then
echo "SKIP: test ports are occupied; change PAIVANA_PORT_BASE" >&2
exit 77
fi
@@ -121,7 +158,9 @@ 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_BACKEND_URL = $PUBLIC_MERCHANT_URL
+MERCHANT_BACKEND_INTERNAL_URL = $INTERNAL_MERCHANT_URL
+MERCHANT_BACKEND_UNIX_PATH = $MERCHANT_SOCKET
MERCHANT_ACCESS_TOKEN = secret-token:stub
SECRET = payment-backend-failure-test
SERVE = tcp
@@ -134,23 +173,113 @@ CONNECTION_LIMIT = 4
PAYMENT_CONNECTION_LIMIT = 2
EOF
+function expect_invalid_internal_url() {
+ local value="$1" label="$2"
+ local cfg="$SCRATCH/invalid-internal.conf"
+ local log="$SCRATCH/invalid-internal.log"
+
+ sed "s|^MERCHANT_BACKEND_INTERNAL_URL =.*|MERCHANT_BACKEND_INTERNAL_URL = $value|" \
+ "$SCRATCH/paivana.conf" > "$cfg"
+ if timeout 3 "$PAIVANA_HTTPD" -c "$cfg" -L WARNING >"$log" 2>&1; then
+ fail "Paivana accepted $label internal merchant URL"
+ fi
+ grep -q 'MERCHANT_BACKEND_INTERNAL_URL' "$log" || \
+ fail "Paivana did not diagnose $label internal merchant URL"
+}
+
+expect_invalid_internal_url 'not-a-web-url/' malformed
+expect_invalid_internal_url 'http://merchant.invalid/instances/paivana' \
+ unterminated
+
start_stub
+start_proxy
"$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"
+grep -q 'GET /instances/paivana/private/templates ' \
+ "$SCRATCH/merchant.log" || fail "template request lost merchant instance prefix"
+grep -q 'GET /instances/paivana/private/templates/premium ' \
+ "$SCRATCH/merchant.log" || fail "template detail lost merchant instance prefix"
-# Losing a merchant connection before any response is safe to retry because
-# the order lookup is a GET. The stub drops retry-order's first lookup and
-# answers its second, reproducing the stale-idle-connection failure seen in
-# production without making the test depend on a TCP keepalive timeout.
-read -r status elapsed < <(redeem retry-order)
-[ "$status" = "404" ] || fail "retried merchant lookup returned HTTP $status"
-expect_error 9802 retry-order 404 || fail "unexpected retry response JSON"
+# The server-side URL is deliberately unreachable over TCP and cleartext over
+# the Unix socket, while every browser-facing value must retain public HTTPS.
+status=$(curl -sS -D "$SCRATCH/paywall.headers" \
+ -o "$SCRATCH/paywall.body" -w '%{http_code}' \
+ "http://127.0.0.1:$PAIVANA_PORT/.well-known/paivana/templates/premium")
+[ "$status" = 402 ] || fail "paywall page returned HTTP $status"
+grep -qi '^Paivana: taler://pay-template/public-merchant.example/instances/paivana/premium' \
+ "$SCRATCH/paywall.headers" || fail "paywall header did not use public URL"
+grep -qi "connect-src 'self' https://public-merchant.example" \
+ "$SCRATCH/paywall.headers" || fail "paywall CSP did not use public URL"
+grep -q 'https://public-merchant.example/instances/paivana/' \
+ "$SCRATCH/paywall.body" || fail "paywall body did not use public URL"
+if grep -q 'merchant.invalid' "$SCRATCH/paywall.body"; then
+ fail "internal merchant URL leaked into paywall body"
+fi
+
+# Warm the merchant pool with an ordinary order lookup. Together with the
+# startup template requests this leaves a known-good persistent connection in
+# Paivana's merchant curl context, which is what the production process has
+# between its infrequent genuine payment attempts.
+read -r status elapsed < <(redeem warm-order)
+[ "$status" = "404" ] || fail "merchant warm-up returned HTTP $status"
+expect_error 9802 warm-order 404 || fail "unexpected warm-up response JSON"
+[ "$(grep -c '/private/orders/warm-order' "$SCRATCH/merchant.log")" = 1 ] || \
+ fail "merchant warm-up did not use exactly one request"
+
+# The frontend has kept the merchant connection from warm-order alive.
+# Let it become genuinely idle, then have the frontend reset the next three
+# matching transport attempts before forwarding or access-logging them. The
+# first fault must therefore be an idle reused TCP connection. libcurl retries
+# that reused-connection failure internally, and Paivana retries the completed
+# status-zero operation once more; the observed topology therefore requires
+# three resets. A fresh request remains healthy once that window has passed.
+sleep 0.3
+read -r status elapsed < <(redeem diagnostic-order)
+[ "$status" = "502" ] || fail "diagnostic trigger returned HTTP $status"
+expect_error 9801 diagnostic-order 0 || fail "unexpected diagnostic-trigger JSON"
+for _ in $(seq 1 50); do
+ grep -q 'Forced-fresh merchant diagnostic for order `diagnostic-order' \
+ "$SCRATCH/paivana.log" && break
+ sleep 0.1
+done
+grep -q 'Forced-fresh merchant diagnostic for order `diagnostic-order.*completed HTTP status 404' \
+ "$SCRATCH/paivana.log" || fail "successful fresh-connection diagnostic missing"
+grep -q 'Forced-fresh merchant diagnostic for order `diagnostic-order.*new connections 1' \
+ "$SCRATCH/paivana.log" || fail "fresh diagnostic did not report a new connection"
grep -q "retrying once within the original 5 s deadline" \
- "$SCRATCH/paivana.log" || fail "merchant retry diagnostic missing"
-[ "$(grep -c '/private/orders/retry-order' "$SCRATCH/merchant.log")" = 2 ] || \
- fail "merchant lookup was not attempted exactly twice"
+ "$SCRATCH/paivana.log" || fail "Paivana application retry diagnostic missing"
+grep -q 'FAULT index=1 .*path=/instances/paivana/private/orders/diagnostic-order reused=yes' \
+ "$SCRATCH/proxy.log" || fail "first fault did not use the idle merchant connection"
+[ "$(grep -c 'FAULT .*path=/instances/paivana/private/orders/diagnostic-order' "$SCRATCH/proxy.log")" = 3 ] || \
+ fail "frontend did not cover libcurl and Paivana retry attempts"
+[ "$(grep -c '/private/orders/diagnostic-order' "$SCRATCH/merchant.log")" = 1 ] || \
+ fail "merchant saw a failed order request or missed the fresh diagnostic"
+[ "$(grep -c 'ACCESS .*path=/instances/paivana/private/orders/diagnostic-order' "$SCRATCH/proxy.log")" = 1 ] || \
+ fail "frontend access log contains a failed order request"
+if grep -q 'secret-token:stub' "$SCRATCH/paivana.log"; then
+ fail "merchant bearer token leaked into Paivana's log"
+fi
+
+for _ in $(seq 1 5); do
+ status=$(curl -sS -H 'Authorization: Bearer secret-token:stub' \
+ --unix-socket "$MERCHANT_SOCKET" \
+ -o /dev/null -w '%{http_code}' \
+ "${INTERNAL_MERCHANT_URL}private/orders/diagnostic-order")
+ [ "$status" = "404" ] || fail "fresh merchant curl returned HTTP $status"
+done
+[ "$(grep -c '/private/orders/diagnostic-order' "$SCRATCH/merchant.log")" = 6 ] || \
+ fail "fresh order-status curls did not all reach the merchant"
+
+# A normal merchant response resets both warning sampling and the consecutive
+# operational failure count. The diagnostic itself deliberately does not.
+read -r status elapsed < <(redeem diagnostic-recovery-order)
+[ "$status" = "404" ] || fail "diagnostic recovery returned HTTP $status"
+expect_error 9802 diagnostic-recovery-order 404 || \
+ fail "unexpected diagnostic-recovery JSON"
+grep -q 'answered order .*diagnostic-recovery-order.* after 1 consecutive lookup' \
+ "$SCRATCH/paivana.log" || fail "diagnostic recovery log missing"
# A refused connection completes immediately. It must no longer be
# presented as a five-second timeout.
@@ -168,6 +297,13 @@ 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"
+for _ in $(seq 1 50); do
+ grep -q 'Forced-fresh merchant diagnostic for order `transport-failure' \
+ "$SCRATCH/paivana.log" && break
+ sleep 0.1
+done
+grep -q 'Forced-fresh merchant diagnostic for order `transport-failure.*completed HTTP status 0' \
+ "$SCRATCH/paivana.log" || fail "failed fresh-connection diagnostic missing"
# A real HTTP response proves recovery and resets the consecutive
# transport-failure counter.
diff --git a/src/tests/test_paywall.sh b/src/tests/test_paywall.sh
@@ -37,6 +37,10 @@
# from one to the other. paivana_id.py re-derives it from the definition
# src/frontend/paywall.js implements, which is what makes this a test of
# both ends rather than of one end twice.
+#
+# Set PAIVANA_REPRO_MERCHANT_POOL_FAILURE=1 to pay a genuine order and then
+# reproduce the production status-zero failure through merchant_fault_proxy.py
+# instead of completing the successful redemption checks.
set -eu
@@ -48,9 +52,11 @@ set -eu
PORT_BASE="${PAIVANA_PORT_BASE:-18400}"
PAIVANA_PORT=$((PORT_BASE + 110))
ORIGIN_PORT=$((PORT_BASE + 111))
+MERCHANT_PROXY_PORT=$((PORT_BASE + 112))
MERCHANT_PORT=9966
EXCHANGE_PORT=8081
BANK_PORT=8082
+FAULT_REPRO="${PAIVANA_REPRO_MERCHANT_POOL_FAILURE:-0}"
function here() {
cd -- "$(dirname -- "$0")" && pwd
@@ -164,6 +170,10 @@ for p in "$PAIVANA_PORT" "$ORIGIN_PORT" "$MERCHANT_PORT" "$EXCHANGE_PORT" "$BANK
do
port_is_free "$p" || BUSY="$BUSY $p"
done
+if [ "$FAULT_REPRO" = 1 ] && ! port_is_free "$MERCHANT_PROXY_PORT"
+then
+ BUSY="$BUSY $MERCHANT_PROXY_PORT"
+fi
if [ -n "$BUSY" ]
then
# The Taler ports are the ones the merchant suite uses, so this is
@@ -241,6 +251,7 @@ setup -c "$CONF" \
-f -d x-taler-bank -u exchange-account-2
MERCHANT_URL="http://localhost:$MERCHANT_PORT/"
+PAIVANA_MERCHANT_URL="$MERCHANT_URL"
AUTH="Authorization: Bearer secret-token:super_secret"
RESP="$SCRATCH/response.json"
@@ -264,6 +275,22 @@ STATUS=$(merchant_post management/instances \
[ "$STATUS" = "204" ] || exit_fail "creating the instance: got $STATUS, $(cat "$RESP")"
echo " OK"
+if [ "$FAULT_REPRO" = 1 ]
+then
+ echo -n "Starting the merchant fault frontend ..."
+ python3 "$SRCDIR/merchant_fault_proxy.py" \
+ --listen-port "$MERCHANT_PROXY_PORT" \
+ --upstream-port "$MERCHANT_PORT" \
+ --control-file "$SCRATCH/merchant-fault.control" \
+ > "$SCRATCH/merchant-proxy.log" 2>&1 &
+ MERCHANT_PROXY_PID=$!
+ PIDS="$PIDS $MERCHANT_PROXY_PID"
+ wait_for_port "$MERCHANT_PROXY_PORT" "$MERCHANT_PROXY_PID" \
+ || exit_fail "the merchant fault frontend did not start"
+ PAIVANA_MERCHANT_URL="http://127.0.0.1:$MERCHANT_PROXY_PORT/"
+ echo " OK"
+fi
+
echo -n "Configuring merchant bank account ..."
STATUS=$(merchant_post private/accounts \
'{"payto_uri":"payto://x-taler-bank/localhost/fortythree?receiver-name=fortythree"}')
@@ -297,7 +324,7 @@ cat > "$SCRATCH/paivana.conf" <<EOF
[paivana]
DESTINATION_BASE_URL = http://localhost:$ORIGIN_PORT/
BASE_URL = $BASE_URL
-MERCHANT_BACKEND_URL = $MERCHANT_URL
+MERCHANT_BACKEND_URL = $PAIVANA_MERCHANT_URL
MERCHANT_ACCESS_TOKEN = secret-token:super_secret
# A fixed secret so that a cookie minted here can be reasoned about; a
# real deployment must not do this (see the manual on SECRET).
@@ -375,8 +402,14 @@ else
fi
PAIVANA_HEADER=$(grep -i '^paivana:' "$SCRATCH/page.hdr" | tr -d '\r' | cut -d' ' -f2-)
+if [ "$FAULT_REPRO" = 1 ]
+then
+ EXPECTED_PAY_TEMPLATE="taler+http://pay-template/127.0.0.1:$MERCHANT_PROXY_PORT/premium"
+else
+ EXPECTED_PAY_TEMPLATE="taler+http://pay-template/localhost:$MERCHANT_PORT/premium"
+fi
case "$PAIVANA_HEADER" in
- "taler+http://pay-template/localhost:$MERCHANT_PORT/premium")
+ "$EXPECTED_PAY_TEMPLATE")
ok "the Paivana header carries the pay-template URI"
;;
*)
@@ -555,7 +588,7 @@ echo "-- redeeming --"
function redeem() {
local website="$1" expiration="$2" nonce="$3" order="$4" hdr="$5"
- curl -s -D "$hdr" -o /dev/null -w "%{http_code}" -X POST \
+ curl -s -D "$hdr" -o "$SCRATCH/redeem.body" -w "%{http_code}" -X POST \
-H "Content-Type: application/json" \
"${BASE_URL}.well-known/paivana" \
-d "$(jq -n --arg o "$order" --arg n "$nonce" \
@@ -563,7 +596,82 @@ function redeem() {
'{order_id:$o,nonce:$n,expiration:{t_s:$e},website:$w}')"
}
+if [ "$FAULT_REPRO" = 1 ]
+then
+ # Atomic replacement keeps the proxy from observing a truncated control
+ # file. Three resets cover libcurl's retry of an idle reused connection
+ # and Paivana's one application-level retry; the forced-fresh diagnostic
+ # that follows is allowed through to the real merchant.
+ printf '/private/orders/%s 3\n' "$ORDER_ID" \
+ > "$SCRATCH/merchant-fault.control.new"
+ mv "$SCRATCH/merchant-fault.control.new" \
+ "$SCRATCH/merchant-fault.control"
+fi
+
STATUS=$(redeem "$WEBSITE" "$EXPIRATION" "$NONCE" "$ORDER_ID" "$SCRATCH/redeem.hdr")
+if [ "$FAULT_REPRO" = 1 ]
+then
+ if [ "$STATUS" = 502 ] && \
+ [ "$(jq -r '.code' < "$SCRATCH/redeem.body")" = 9801 ] && \
+ [ "$(jq -r '.merchant_http_status' < "$SCRATCH/redeem.body")" = 0 ]
+ then
+ ok "Paivana reproduces 502/error 9801 with merchant_http_status zero"
+ else
+ fail "faulted redemption returned $STATUS: $(cat "$SCRATCH/redeem.body")"
+ fi
+
+ for _ in $(seq 1 50)
+ do
+ grep -q "Forced-fresh merchant diagnostic for order \`$ORDER_ID'.*completed HTTP status 200" \
+ "$SCRATCH/paivana.log" && break
+ sleep 0.1
+ done
+ if grep -q "Forced-fresh merchant diagnostic for order \`$ORDER_ID'.*completed HTTP status 200" \
+ "$SCRATCH/paivana.log"
+ then
+ ok "a forced-fresh request reaches the real merchant immediately afterwards"
+ else
+ fail "the forced-fresh merchant diagnostic did not recover"
+ fi
+
+ if grep -q "FAULT index=1 .*path=/private/orders/$ORDER_ID reused=yes" \
+ "$SCRATCH/merchant-proxy.log" && \
+ [ "$(grep -c "FAULT .*path=/private/orders/$ORDER_ID" \
+ "$SCRATCH/merchant-proxy.log")" = 3 ]
+ then
+ ok "the first failed transport used an idle pooled connection and all retries were covered"
+ else
+ fail "fault frontend did not exercise the expected pooled/retry path"
+ fi
+
+ if [ "$(grep -c "ACCESS .*path=/private/orders/$ORDER_ID" \
+ "$SCRATCH/merchant-proxy.log")" = 1 ]
+ then
+ ok "none of Paivana's failed attempts reached the frontend access log"
+ else
+ fail "a failed order lookup appeared in the frontend access log"
+ fi
+
+ FRESH_URL="${PAIVANA_MERCHANT_URL}private/orders/${ORDER_ID}"
+ FRESH_URL="$FRESH_URL?session_id=$(urlenc "$PAIVANA_ID")"
+ FRESH_OK=1
+ for _ in $(seq 1 5)
+ do
+ STATUS=$(curl -s -o "$RESP" -w "%{http_code}" -H "$AUTH" "$FRESH_URL")
+ [ "$STATUS" = 200 ] || FRESH_OK=0
+ done
+ if [ "$FRESH_OK" = 1 ]
+ then
+ ok "five fresh order-status curls all succeed through the same frontend"
+ else
+ fail "a fresh order-status curl failed after the Paivana incident"
+ fi
+
+ echo "=== $CHECKS checks, $FAILS failures ==="
+ [ "$FAILS" = 0 ]
+ exit
+fi
+
if [ "$STATUS" = "303" ]
then
ok "a paid order is redeemed with 303"
