Checkout: only customer fields on order updates, verified PayPal capture, safe logging (#6)
Co-authored-by: Michael Czechowski <mail@librete.ch>
This commit was merged in pull request #6.
This commit is contained in:
libretech authored and 
Michael Czechowski committed
1 parent
9b0c6af8b7
commit
5002cac469
24 files changed
+2911
-313
No files matched your search
@@ -0,0 +1,375 @@
|
||||
import { test } from "node:test";
|
||||
import assert from "node:assert/strict";
|
||||
import { readFileSync } from "node:fs";
|
||||
import {
|
||||
ALREADY_PAID,
|
||||
NOT_CONFIRMED,
|
||||
NOT_FOUND,
|
||||
NOT_MATCHING,
|
||||
NOT_RECORDED,
|
||||
NOT_THIS_ORDER,
|
||||
ORDER_CHANGED,
|
||||
PAYPAL_FAILED,
|
||||
capturePayment,
|
||||
captureRequestId
|
||||
} from "../../src/checkout/capture-payment.ts";
|
||||
import { formatLogLine } from "../../src/logging/format.ts";
|
||||
|
||||
const UUID = "11111111-2222-4333-8444-555555555555";
|
||||
const PAYPAL_ORDER_ID = "5O190127TN364715T";
|
||||
const OTHER_PAYPAL_ORDER_ID = "8MC585209K746392H";
|
||||
const CAPTURE_ID = "3C679366HH908993F";
|
||||
// The server's time when the capture request arrives.
|
||||
const NOW = new Date("2026-10-08T19:13:05.000Z");
|
||||
const CREDENTIALS = "RFVNTVlfQ0xJRU5UX0lEOkRVTU1ZX0NMSUVOVF9TRUNSRVQ="; // base64 of the dummy "DUMMY_CLIENT_ID:DUMMY_CLIENT_SECRET"
|
||||
|
||||
// PayPal's Orders v2 JSON for the order below, see paypal-verify.test.ts. Every call returns a fresh copy to change.
|
||||
const fixture = (name: string) => JSON.parse(readFileSync(new URL(`./fixtures/${name}`, import.meta.url), "utf8"));
|
||||
|
||||
// The row the capture reads with strapi.db.query("api::order.order").findOne({ where: { uuid } }) after a checkout stored the
|
||||
// PayPal order it created: subtotal 17.90, delivery 4.95, total 22.85.
|
||||
const orderRow = (overrides = {}) => ({
|
||||
id: 4711,
|
||||
uuid: UUID,
|
||||
email: "erika@example.org",
|
||||
subtotal: 17.9,
|
||||
total: 22.85,
|
||||
VAT: 2.86,
|
||||
paymentAuthorised: false,
|
||||
paymentStatus: null,
|
||||
invoiceSent: false,
|
||||
paypalOrderId: PAYPAL_ORDER_ID,
|
||||
paypalCaptureId: null,
|
||||
paymentCapturedAt: null,
|
||||
...overrides
|
||||
});
|
||||
|
||||
/**
|
||||
* Fakes of the dependencies over one order row, which record every call and every log line. updateOrder writes like the
|
||||
* controller's update with where { id, paypalOrderId }: only while the row still carries that PayPal order, else it answers null.
|
||||
* duringCapture runs while PayPal captures, as a request that changes the order at that moment would.
|
||||
*/
|
||||
const setup = ({
|
||||
row = orderRow(),
|
||||
paypalOrder = fixture("paypal-order-approved.json"),
|
||||
captured = fixture("paypal-order-captured.json"),
|
||||
getError = undefined,
|
||||
captureError = undefined,
|
||||
updateError = undefined,
|
||||
duringCapture = (row) => {}
|
||||
} = {}) => {
|
||||
const calls = { findOrder: [], getPayPalOrder: [], capturePayPalOrder: [], updateOrder: [] };
|
||||
const logs = [];
|
||||
const deps = {
|
||||
findOrder: async (uuid) => {
|
||||
calls.findOrder.push(uuid);
|
||||
return row !== null && row.uuid === uuid ? { ...row } : null;
|
||||
},
|
||||
getPayPalOrder: async (id) => {
|
||||
calls.getPayPalOrder.push(id);
|
||||
if (getError) throw getError;
|
||||
return paypalOrder;
|
||||
},
|
||||
capturePayPalOrder: async (id, requestId) => {
|
||||
calls.capturePayPalOrder.push({ id, requestId });
|
||||
duringCapture(row);
|
||||
if (captureError) throw captureError;
|
||||
return captured;
|
||||
},
|
||||
updateOrder: async (id, paypalOrderId, data) => {
|
||||
calls.updateOrder.push({ id, paypalOrderId, data });
|
||||
if (updateError) throw updateError;
|
||||
if (row.id !== id || row.paypalOrderId !== paypalOrderId) return null;
|
||||
Object.assign(row, data);
|
||||
return { ...row };
|
||||
},
|
||||
log: {
|
||||
info: (message, fields) => logs.push({ level: "info", message, fields }),
|
||||
warn: (message, fields) => logs.push({ level: "warn", message, fields }),
|
||||
error: (message, fields) => logs.push({ level: "error", message, fields })
|
||||
}
|
||||
};
|
||||
return { deps, calls, logs, row };
|
||||
};
|
||||
|
||||
const capture = (deps, { uuid = UUID, paypalOrderId = PAYPAL_ORDER_ID } = {}) => capturePayment(deps, { uuid, paypalOrderId, now: NOW });
|
||||
|
||||
const paypalCalls = (calls) => calls.getPayPalOrder.length + calls.capturePayPalOrder.length;
|
||||
|
||||
// What must never reach the log: the credentials of a failed request, and the buyer's data in PayPal's responses.
|
||||
const NEVER_LOGGED = [CREDENTIALS, "Authorization", "Erika", "Mustermann", "erika", "Musterstraße", "QYR5Z8XDVJNXQ", "INSTRUMENT_DECLINED"];
|
||||
|
||||
/** Checks the recorded log, and each line as the console shows it (config/logger.ts formats with formatLogLine). */
|
||||
const assertCleanLog = (logs) => {
|
||||
const lines = logs.map(({ level, message, fields }) =>
|
||||
formatLogLine({ timestamp: "2026-10-08 19:13:05.000", level, message: `app:${level[0]}:order-controller: ${message}`, ...fields })
|
||||
);
|
||||
for (const text of [JSON.stringify(logs), ...lines]) {
|
||||
for (const value of NEVER_LOGGED) assert.ok(!text.includes(value), `the log holds ${value}: ${text}`);
|
||||
}
|
||||
};
|
||||
|
||||
// What the PayPal SDK throws for an error response: @apimatic/core's ApiError, here the SDK's CustomError, with the request, whose
|
||||
// Authorization header holds the client credentials (token request) or an access token, and PayPal's error body.
|
||||
const paypalApiError = (statusCode: number, message: string) =>
|
||||
Object.assign(new Error(message), {
|
||||
request: {
|
||||
method: "POST",
|
||||
url: `https://api-m.sandbox.paypal.com/v2/checkout/orders/${PAYPAL_ORDER_ID}/capture`,
|
||||
headers: { Authorization: `Basic ${CREDENTIALS}`, "PayPal-Request-Id": captureRequestId(UUID, PAYPAL_ORDER_ID) }
|
||||
},
|
||||
statusCode,
|
||||
headers: { "paypal-debug-id": "f1a2b3c4d5e6f" },
|
||||
body: JSON.stringify({ name: "UNPROCESSABLE_ENTITY", details: [{ issue: "INSTRUMENT_DECLINED" }], debug_id: "f1a2b3c4d5e6f" })
|
||||
});
|
||||
|
||||
// What axios throws when PayPal cannot be reached: the request config with its headers.
|
||||
const networkError = (message = "getaddrinfo EAI_AGAIN api-m.sandbox.paypal.com") =>
|
||||
Object.assign(new Error(message), {
|
||||
name: "AxiosError",
|
||||
code: "EAI_AGAIN",
|
||||
config: { method: "post", url: "https://api-m.sandbox.paypal.com/v1/oauth2/token", headers: { Authorization: `Basic ${CREDENTIALS}` } }
|
||||
});
|
||||
|
||||
// The capture
|
||||
|
||||
test("captures the PayPal order the checkout stored and writes exactly the payment fields", async () => {
|
||||
const { deps, calls, logs } = setup();
|
||||
const result = await capture(deps);
|
||||
|
||||
assert.equal(result.status, 200);
|
||||
assert.equal(result.alreadyCaptured, false);
|
||||
assert.deepEqual(calls.findOrder, [UUID]);
|
||||
assert.deepEqual(calls.getPayPalOrder, [PAYPAL_ORDER_ID]);
|
||||
assert.deepEqual(calls.capturePayPalOrder, [{ id: PAYPAL_ORDER_ID, requestId: `capture-${UUID}-${PAYPAL_ORDER_ID}` }]);
|
||||
assert.deepEqual(calls.updateOrder, [
|
||||
{
|
||||
id: 4711,
|
||||
paypalOrderId: PAYPAL_ORDER_ID,
|
||||
data: { paymentAuthorised: true, paymentStatus: "captured", paypalCaptureId: CAPTURE_ID, paymentCapturedAt: "2026-10-08T19:13:05.000Z" }
|
||||
}
|
||||
]);
|
||||
// the controller answers the updated order, sanitized
|
||||
assert.equal(result.order.paymentAuthorised, true);
|
||||
assert.deepEqual(logs, [{ level: "info", message: "Captured the payment", fields: { order: 4711, capture: CAPTURE_ID } }]);
|
||||
assertCleanLog(logs);
|
||||
});
|
||||
|
||||
test("sends the same PayPal-Request-Id on every attempt, so that PayPal captures once", async () => {
|
||||
assert.equal(captureRequestId(UUID, PAYPAL_ORDER_ID), "capture-11111111-2222-4333-8444-555555555555-5O190127TN364715T");
|
||||
// PayPal accepts at most 108 characters
|
||||
assert.ok(captureRequestId(UUID, PAYPAL_ORDER_ID).length <= 108);
|
||||
|
||||
// The first attempt times out after PayPal may have captured. The retry repeats the id, and PayPal answers the first capture.
|
||||
const first = setup({ captureError: Object.assign(networkError("timeout of 30000ms exceeded"), { code: "ECONNABORTED" }) });
|
||||
assert.deepEqual(await capture(first.deps), { status: 502, message: PAYPAL_FAILED });
|
||||
const retry = setup();
|
||||
assert.equal((await capture(retry.deps)).status, 200);
|
||||
|
||||
assert.equal(first.calls.capturePayPalOrder[0].requestId, retry.calls.capturePayPalOrder[0].requestId);
|
||||
});
|
||||
|
||||
// Paying a cheap order, capturing an expensive one
|
||||
|
||||
test("rejects a PayPal order the checkout did not store on the order, without asking PayPal", async () => {
|
||||
// The buyer paid order A with PayPal order OTHER_PAYPAL_ORDER_ID and calls the capture of the expensive order B with it.
|
||||
const { deps, calls, logs, row } = setup({ row: orderRow({ id: 4712, uuid: UUID, total: 249 }) });
|
||||
|
||||
assert.deepEqual(await capture(deps, { paypalOrderId: OTHER_PAYPAL_ORDER_ID }), { status: 409, message: NOT_THIS_ORDER });
|
||||
assert.equal(paypalCalls(calls), 0);
|
||||
assert.equal(calls.updateOrder.length, 0);
|
||||
assert.equal(row.paymentAuthorised, false);
|
||||
assert.deepEqual(logs, [
|
||||
{
|
||||
level: "warn",
|
||||
message: "Rejected a capture with a PayPal order the checkout did not create for the order",
|
||||
fields: { order: 4712, hasPayPalOrder: true }
|
||||
}
|
||||
]);
|
||||
});
|
||||
|
||||
test("rejects every PayPal order for an order without a stored one, without asking PayPal", async () => {
|
||||
// no checkout yet, an order from before the checkout stored it, or a cart changed since the checkout
|
||||
for (const paypalOrderId of [null, undefined, ""]) {
|
||||
const { deps, calls, logs } = setup({ row: orderRow({ paypalOrderId }) });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 409, message: NOT_THIS_ORDER });
|
||||
assert.equal(paypalCalls(calls) + calls.updateOrder.length, 0);
|
||||
assert.equal(logs[0].fields.hasPayPalOrder, false);
|
||||
}
|
||||
|
||||
// a request without a PayPal order id
|
||||
const { deps, calls } = setup();
|
||||
assert.deepEqual(await capture(deps, { paypalOrderId: "" }), { status: 409, message: NOT_THIS_ORDER });
|
||||
assert.equal(paypalCalls(calls), 0);
|
||||
});
|
||||
|
||||
test("does not capture a PayPal order whose amount is not the order total", async () => {
|
||||
const paypalOrder = fixture("paypal-order-approved.json");
|
||||
paypalOrder.purchase_units[0].amount.value = "2.29";
|
||||
const { deps, calls, logs } = setup({ paypalOrder });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 409, message: NOT_MATCHING });
|
||||
assert.deepEqual(calls.getPayPalOrder, [PAYPAL_ORDER_ID]);
|
||||
assert.equal(calls.capturePayPalOrder.length, 0);
|
||||
assert.equal(calls.updateOrder.length, 0);
|
||||
assert.deepEqual(logs, [
|
||||
{
|
||||
level: "warn",
|
||||
message: "Rejected a capture: the PayPal order does not match the order",
|
||||
fields: { order: 4711, reason: "the PayPal order amount 2.29 is not the order total 22.85" }
|
||||
}
|
||||
]);
|
||||
assertCleanLog(logs);
|
||||
});
|
||||
|
||||
test("does not capture a PayPal order created for another order, in another currency or not approved", async () => {
|
||||
const cases: [(paypalOrder) => void, string][] = [
|
||||
[
|
||||
(paypalOrder) => (paypalOrder.purchase_units[0].custom_id = "99999999-8888-4777-8666-555555555555"),
|
||||
"the custom_id of the PayPal order is not the order's uuid"
|
||||
],
|
||||
[(paypalOrder) => (paypalOrder.purchase_units[0].amount.currency_code = "USD"), "the PayPal order currency is USD, not EUR"],
|
||||
[(paypalOrder) => (paypalOrder.status = "CREATED"), "the PayPal order status is CREATED, not APPROVED"]
|
||||
];
|
||||
for (const [change, reason] of cases) {
|
||||
const paypalOrder = fixture("paypal-order-approved.json");
|
||||
change(paypalOrder);
|
||||
const { deps, calls, logs } = setup({ paypalOrder });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 409, message: NOT_MATCHING });
|
||||
assert.equal(calls.capturePayPalOrder.length + calls.updateOrder.length, 0);
|
||||
assert.equal(logs[0].fields.reason, reason);
|
||||
assertCleanLog(logs);
|
||||
}
|
||||
});
|
||||
|
||||
// A paid order
|
||||
|
||||
test("answers alreadyCaptured for a paid order and the PayPal order it was paid with, without a call or a write", async () => {
|
||||
const { deps, calls, logs } = setup({ row: orderRow({ paymentAuthorised: true, paymentStatus: "captured", paypalCaptureId: CAPTURE_ID }) });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 200, alreadyCaptured: true });
|
||||
assert.equal(paypalCalls(calls) + calls.updateOrder.length, 0);
|
||||
assert.deepEqual(logs, []);
|
||||
});
|
||||
|
||||
test("rejects another PayPal order for a paid order, without a call or a write", async () => {
|
||||
const paidRows = [
|
||||
orderRow({ paymentAuthorised: true, paymentStatus: "captured", paypalCaptureId: CAPTURE_ID }),
|
||||
// paid before the checkout stored the PayPal order
|
||||
orderRow({ paymentAuthorised: true, paymentStatus: "authorised", paypalOrderId: null })
|
||||
];
|
||||
for (const row of paidRows) {
|
||||
const { deps, calls } = setup({ row });
|
||||
|
||||
assert.deepEqual(await capture(deps, { paypalOrderId: OTHER_PAYPAL_ORDER_ID }), { status: 409, message: ALREADY_PAID });
|
||||
assert.equal(paypalCalls(calls) + calls.updateOrder.length, 0);
|
||||
}
|
||||
});
|
||||
|
||||
test("answers 404 for a missing order, without asking PayPal", async () => {
|
||||
const { deps, calls } = setup({ row: null });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 404, message: NOT_FOUND });
|
||||
assert.equal(paypalCalls(calls), 0);
|
||||
|
||||
// No uuid: no lookup at all, since Strapi drops an undefined where condition and would find any order.
|
||||
for (const uuid of ["", undefined]) {
|
||||
const { deps, calls } = setup();
|
||||
assert.deepEqual(await capturePayment(deps, { uuid, paypalOrderId: PAYPAL_ORDER_ID, now: NOW }), { status: 404, message: NOT_FOUND });
|
||||
assert.deepEqual(calls.findOrder, []);
|
||||
}
|
||||
});
|
||||
|
||||
// PayPal fails
|
||||
|
||||
test("answers 502 when PayPal fails, and logs the error's name, message and status code but not its request", async () => {
|
||||
const failures: [string, Error & { statusCode?: number }][] = [
|
||||
["getError", paypalApiError(401, "Authentication failed due to missing authorization header, or invalid authentication credentials.")],
|
||||
["getError", networkError()],
|
||||
["captureError", paypalApiError(422, "The requested action could not be performed, semantically incorrect, or failed business validation.")],
|
||||
["captureError", networkError()]
|
||||
];
|
||||
for (const [failing, error] of failures) {
|
||||
const { deps, calls, logs, row } = setup({ [failing]: error });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 502, message: PAYPAL_FAILED });
|
||||
assert.equal(calls.capturePayPalOrder.length, failing === "getError" ? 0 : 1);
|
||||
assert.equal(calls.updateOrder.length, 0);
|
||||
assert.equal(row.paymentAuthorised, false);
|
||||
assert.equal(logs.length, 1);
|
||||
assert.equal(logs[0].level, "error");
|
||||
assert.deepEqual(logs[0].fields, { order: 4711, error: { name: error.name, message: error.message, statusCode: error.statusCode } });
|
||||
assertCleanLog(logs);
|
||||
}
|
||||
});
|
||||
|
||||
// After PayPal answered the capture
|
||||
|
||||
test("keeps the order unpaid and answers 502 when the capture does not match, logging the order and the reason only", async () => {
|
||||
const pending = fixture("paypal-order-captured.json");
|
||||
pending.purchase_units[0].payments.captures[0].status = "PENDING";
|
||||
const lower = fixture("paypal-order-captured.json");
|
||||
lower.purchase_units[0].payments.captures[0].amount.value = "2.29";
|
||||
const minimal = { id: PAYPAL_ORDER_ID, status: "COMPLETED", links: [] };
|
||||
|
||||
const cases: [unknown, string][] = [
|
||||
[pending, "the capture status is PENDING, not COMPLETED"],
|
||||
[lower, "the capture amount 2.29 is not the order total 22.85"],
|
||||
[minimal, "the capture response has no capture"]
|
||||
];
|
||||
for (const [captured, reason] of cases) {
|
||||
const { deps, calls, logs, row } = setup({ captured });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 502, message: NOT_CONFIRMED });
|
||||
assert.equal(calls.updateOrder.length, 0);
|
||||
assert.equal(row.paymentAuthorised, false);
|
||||
assert.deepEqual(logs, [
|
||||
{
|
||||
level: "error",
|
||||
message: "The PayPal capture does not match the order, which stays unpaid: check the PayPal order for a refund",
|
||||
fields: { order: 4711, reason }
|
||||
}
|
||||
]);
|
||||
assertCleanLog(logs);
|
||||
}
|
||||
});
|
||||
|
||||
test("keeps the order unpaid when its cart or address changed during the capture", async () => {
|
||||
// addProduct, removeProduct and updateByUuid clear paypalOrderId in the write that changes the order
|
||||
const { deps, calls, logs, row } = setup({
|
||||
duringCapture: (row) => {
|
||||
row.total = 249;
|
||||
row.paypalOrderId = null;
|
||||
}
|
||||
});
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 409, message: ORDER_CHANGED });
|
||||
assert.equal(calls.updateOrder.length, 1);
|
||||
assert.equal(row.paymentAuthorised, false);
|
||||
assert.deepEqual(logs, [
|
||||
{
|
||||
level: "error",
|
||||
message: "PayPal captured the payment, but the order changed during the capture and stays unpaid: check the order for a refund",
|
||||
fields: { order: 4711, capture: CAPTURE_ID }
|
||||
}
|
||||
]);
|
||||
});
|
||||
|
||||
test("answers 500 when the order cannot be marked paid after the capture, and logs the capture", async () => {
|
||||
const { deps, logs } = setup({ updateError: new Error("Connection terminated unexpectedly") });
|
||||
|
||||
assert.deepEqual(await capture(deps), { status: 500, message: NOT_RECORDED });
|
||||
assert.deepEqual(logs, [
|
||||
{
|
||||
level: "error",
|
||||
message: "PayPal captured the payment, but the order could not be marked paid: check the order",
|
||||
fields: {
|
||||
order: 4711,
|
||||
capture: CAPTURE_ID,
|
||||
error: { name: "Error", message: "Connection terminated unexpectedly", statusCode: undefined }
|
||||
}
|
||||
}
|
||||
]);
|
||||
});
|
||||
Reference in new issue
Block a user