diff --git a/CHANGELOG.md b/CHANGELOG.md index 6092e2b..b82e6a5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,48 @@ Changes are listed newest first, with an independent version for every individua T5/T6 script and each native plugin. Current versions are recorded in [versions.json](versions.json); see the [version policy](README.md#versioning). +## 2026-10-13 + +### Bank failure diagnostics — TWS #14 + +| Component | Version | Affected source | +| --- | --- | --- | +| `tws_t5_bank.gsc` | `2.0.2` | `t5/scripts/tws_t5_bank.gsc` | +| `tws_t6_bank.gsc` | `2.0.2` | `t6/scripts/tws_t6_bank.gsc` | +| `t5-plugin` | `1.2.0` | `t5/plugins/tws-t5-gsc-utils/src/component/bank.cpp`, `src/utils/bank.cpp`, `src/utils/bank.hpp` | +| `t6-plugin` | `1.2.0` | `t6/plugins/tws-t6-gsc-utils/src/component/bank.cpp`, `src/utils/bank.cpp`, `src/utils/bank.hpp` | + +- Both engines log startup script/loaded TWS plugin versions, effective endpoint, + safe server identity, credential format validation and pending journal count. + Add diagnostic correlation for every HTTP attempt without changing API IDs; + balance requests keep their empty acknowledgment ID contract. +- Distinguish creation, transport, HTTP, missing diagnostics, JSON/schema, + response-ID and application failures, with safe HTTP/curl/timing fields. + Native acknowledgment parsing adds fixed failure reasons without changing + existing validity rules. Only known bounded response codes reach logs; never + log credentials, headers, bodies or native exception contents. +- Log journal load/write/removal failures and settlement decision, attempts, + pending duration, next retry delay and resolution. Suppress identical failures + for 30 seconds, report suppression counts, and log reason changes and recovery + immediately. Recovered pending duration starts at this map's journal load. + Preserve points, durable decisions, retry behavior and player-facing messages. +- Compatibility: both scripts require matching plugin `1.2.0+` for the additive + `bankVersion()` native and parser reason field. No new EC/agent or third-party + dependency requirement; existing common/telemetry and migration requirements + remain. Upstream pins and native loader `plugin_version()` are unchanged. +- Deployment: build/install both DLLs and **restart the full server processes**; + install matching scripts, restarting the map if copied after process startup. + Verify installed DLL/GSC hashes against the release artifacts and startup + version logs, particularly Ascension's reported stale GSC artifact. No deployment + performed. Windows DLL builds, GSC compilation and live T5/T6 checks remain + required; see [bank diagnostics](README.md#bank-diagnostics--tws-14). +- Validation: 44 portable script fixture groups passed, including actual EC + bank service/SQLite integration at checkout `d614707`. Fixtures assert safe + startup/outcome logs, missing diagnostics, HTTP 401, timeout, malformed/schema + acknowledgments, ID mismatch, storage failures, rate limiting and recovery, + alongside existing accounting/replay tests. Native parser/storage/process-restart + and registration-adapter checks run with address/undefined-behavior sanitizers. + ## 2026-10-12 ### String bank identities — TWS #15 diff --git a/README.md b/README.md index ec6c222..6e7d64d 100644 --- a/README.md +++ b/README.md @@ -183,7 +183,7 @@ shared by GUID across games and survive map/server restarts. Transfers do not change `score_total`; bank-assisted matches still count on existing leaderboards. Deploy [Electric Cherry #146](https://gitea.thewrightserver.net/josh/electric-cherry/issues/146) -first, then build/install both native plugins `1.1.0` and **restart the server +first, then build/install both native plugins `1.2.0` and **restart the server processes**. The plugins provide `bankLoad`, `bankStore`, `bankRemove` and `bankResponse`. Removing the bank script is necessary to omit these linking requirements; disabling it by dvar does not avoid linking. @@ -226,6 +226,62 @@ are not refunded when a match ends or its process crashes. As with any live score, the journal cannot make game memory and the remote database atomic across a machine/storage failure. +### Bank diagnostics — TWS #14 + +Bank scripts `2.0.2` require their matching TWS plugins `1.2.0+`. Startup logs +report the script version, the loaded plugin's TWS version via `bankVersion()`, +the effective endpoint, a validated server ID, credential format validation, +and the loaded journal count. Credential validation checks the local format; +HTTP 401/403 still identifies a credential rejected by EC. A failed journal load +logs `pending=unknown` and disables the bank; invalid configuration reports that +journals were not loaded. Server IDs outside the bounded log-safe token alphabet +are shown as `invalid`/`unavailable` without changing the configured API identity. + +Each HTTP attempt receives a local `correlation=bank--` +for console diagnostics, including `.b`. These IDs are scoped to a map/process +log, never sent to EC, and never replace durable transfer IDs. Balance requests +still omit the API request ID and require an empty response ID. Transfer logs +also include their original request ID, linking prepare, journal and settlement. + +Outcomes distinguish request creation, transport failure, HTTP rejection, +missing diagnostics/response, invalid acknowledgment (with a fixed parser reason), +request-ID mismatch, unexpected state, and valid application rejection. Available +HTTP status, curl code and cumulative DNS/connect/TLS/total milliseconds are +included; absent or malformed fields say `unavailable`. Only allowlisted response +codes reach logs; unfamiliar codes say `unknown`. No token, authorization header, +raw response/request body, transport exception or private configuration contents +are logged. Existing point accounting, journal format, API payloads, retry delays +and player-facing messages are unchanged. + +Settlement lines add the durable decision, attempt count, pending seconds, next +retry delay, cleanup failures and eventual resolution. Pending time begins when +a new cancel decision is attempted; recovered journals measure from this map's +load, so downtime is not included. Counters reset on map/process restart. Repeated +identical failures per action are summarized at most every 30 seconds, with a +`suppressed` count. Reason/status/code changes and recovery log immediately. +Native storage logs similarly identify load/write/remove failures and recovery. +Rate-limited attempts retain their correlation internally; only emitted lines +appear in the console. No log history or retry metadata is added to the journal. + +Build/install both updated DLLs and **restart each full server process**, then +install the corresponding scripts and restart the map if they were copied after +startup. `bankVersion()` is a new linking requirement even when the bank is +disabled by dvar. No EC/agent change or new third-party dependency is required; +existing bank API, common/telemetry and endpoint-migration requirements still apply. +Verify deployed DLL and GSC SHA-256 hashes against the built release artifacts, +and confirm startup reports `script=2.0.2 plugin=1.2.0` before interpreting results. +An old bank script checksum on Ascension was reported in issue #14; deploying +only the DLL does not update GSC. No deployment was performed here. + +Run `node tools/check_bank.mjs --ec-root /path/to/electric-cherry` and +`python3 tools/test_plugin_bank.py`. On **both T5 and T6**, compile/link and test +successful `.b`/deposit/withdrawal, HTTP 401/403, timeout, malformed JSON/schema, +wrong response ID, unwritable/corrupt journals and settlement recovery after a +map/process restart. Check first/change/recovery logs, 30-second suppression, +HTTP timings, unchanged player messages/points and one remote ledger entry per +transfer. Keep journal files intact during failure tests. Windows DLL/GSC builds, +installed-artifact verification and these live game checks remain required. + ### Bank identity validation Bank scripts `2.0.1` use T5's `player getGuid()` and T6's persistent diff --git a/t5/plugins/README.md b/t5/plugins/README.md index d02b2e5..989cd51 100644 --- a/t5/plugins/README.md +++ b/t5/plugins/README.md @@ -109,3 +109,23 @@ decisions and strict response validation for the new bank script. Build and install the DLL, then restart the full process. No upstream pins or external dependencies changed. See [bank setup and recovery](../../README.md#player-bank-t5-and-t6). Portable checks: `python3 tools/test_plugin_bank.py`. + +## Bank diagnostics (TWS 1.2.0) + +`bankVersion()` returns the loaded DLL's TWS component version, independently of +upstream pins and the native loader's unchanged `plugin_version()` value. +`bankResponse()` now also returns `reason`: `ok` on success, otherwise one of +`empty_body`, `body_limit`, `invalid_json`, `schema`, `field_limit`, `state`, +`amount_range`, `ok_state`, `missing_id`, or `zero_transfer`. Invalid responses +clear all parsed fields. Existing acknowledgment acceptance rules are unchanged. +The returned `code` on valid responses remains API data; bank scripts allowlist +it before logging. Callers must never log arbitrary response fields. + +Native journal logs name load/write/remove, limit identical failures to one +per 30 seconds, and log recovery with suppressed counts. Exception text, journal +contents and credentials are excluded. The new scripts require this DLL even +when disabled by dvar because `bankVersion()` must link. No new third-party +dependencies or upstream pin changes are required. Rebuild/install the DLL and +restart the full server process; see the [diagnostic rollout](../../README.md#bank-diagnostics--tws-14). +Portable checks: `python3 tools/test_plugin_bank.py` executes the real parser, +storage and native registration adapter with sanitizers and engine shims. diff --git a/t5/plugins/tws-t5-gsc-utils/src/component/bank.cpp b/t5/plugins/tws-t5-gsc-utils/src/component/bank.cpp index 5bfe796..805783a 100644 --- a/t5/plugins/tws-t5-gsc-utils/src/component/bank.cpp +++ b/t5/plugins/tws-t5-gsc-utils/src/component/bank.cpp @@ -3,6 +3,8 @@ #include "gsc.hpp" #include "game/scripting/array.hpp" #include +#include +#include namespace bank { @@ -13,11 +15,33 @@ namespace bank return {"tws-bank/t5", server, endpoint}; } - void storage_error() + // Only fixed operation names are printed, never exception text or paths + // from private configuration. Per-operation state has bounded memory. + void storage_result(size_t operation, bool failed) { - // Do not echo parse exceptions: their text can contain player data. - printf("^1[tws_bank] Outbox operation failed; check tws-bank/t5 files, disk space and permissions. Existing reports retained.\n"); + struct status + { + bool failed = false; + std::chrono::steady_clock::time_point logged{}; + unsigned suppressed = 0; + }; + static std::array states; + constexpr const char* names[] = {"load", "write", "remove"}; + auto& state = states[operation]; + const auto now = std::chrono::steady_clock::now(); + if (failed && state.failed && now - state.logged < std::chrono::seconds(30)) + { + ++state.suppressed; + return; + } + if (failed || state.failed) + printf("[tws_bank] native_storage operation=%s outcome=%s suppressed=%u\n", + names[operation], failed ? "storage_failure" : "recovered", state.suppressed); + state.failed = failed; + state.logged = now; + state.suppressed = 0; } + } class component final : public component_interface @@ -25,6 +49,7 @@ namespace bank public: void on_startup([[maybe_unused]] plugin::plugin* plugin) override { + gsc::function::add("bankversion", []() { return std::string("1.2.0"); }); gsc::function::add("bankload", [](const std::string& server, const std::string& endpoint) -> scripting::script_value { try @@ -38,25 +63,27 @@ namespace bank entry["body"] = value.body; entries.emplace_back(entry); } + storage_result(0, false); return entries; } - catch (...) { storage_error(); return {}; } + catch (...) { storage_result(0, true); return {}; } }); gsc::function::add("bankstore", [](const std::string& server, const std::string& endpoint, const std::string& body) { - try { spool(server, endpoint).store(body); return true; } - catch (...) { storage_error(); return false; } + try { spool(server, endpoint).store(body); storage_result(1, false); return true; } + catch (...) { storage_result(1, true); return false; } }); gsc::function::add("bankremove", [](const std::string& server, const std::string& endpoint, const std::string& id) { - try { spool(server, endpoint).erase(id); return true; } - catch (...) { storage_error(); return false; } + try { spool(server, endpoint).erase(id); storage_result(2, false); return true; } + catch (...) { storage_result(2, true); return false; } }); gsc::function::add("bankresponse", [](const std::string& response) { const auto ack = utils::bank::parse_acknowledgement(response); scripting::array result; result["valid"] = ack.valid; + result["reason"] = ack.reason; result["state"] = ack.state; result["code"] = ack.code; result["request_id"] = ack.id; diff --git a/t5/plugins/tws-t5-gsc-utils/src/utils/bank.cpp b/t5/plugins/tws-t5-gsc-utils/src/utils/bank.cpp index d823772..5b81194 100644 --- a/t5/plugins/tws-t5-gsc-utils/src/utils/bank.cpp +++ b/t5/plugins/tws-t5-gsc-utils/src/utils/bank.cpp @@ -29,30 +29,42 @@ namespace utils::bank acknowledgement parse_acknowledgement(const std::string& response) { - acknowledgement result; - if (response.empty() || response.size() >= max_body_size) return result; + auto invalid = [](const char* reason) + { + acknowledgement value; + value.reason = reason; + return value; + }; + if (response.empty()) return invalid("empty_body"); + if (response.size() >= max_body_size) return invalid("body_limit"); const auto data = nlohmann::json::parse(response, nullptr, false); - if (!data.is_object()) return result; + if (data.is_discarded()) return invalid("invalid_json"); + if (!data.is_object()) return invalid("schema"); try { - if (!data.at("ok").is_boolean()) return result; + acknowledgement result; + if (!data.at("ok").is_boolean()) return invalid("schema"); result.state = data.at("state").get(); result.code = data.at("code").get(); result.id = data.at("request_id").get(); - if (result.id.size() > 64 || result.code.size() > 64 || - (result.state != "balance" && result.state != "prepared" && result.state != "committed" && - result.state != "cancelled" && result.state != "rejected")) return {}; + if (result.id.size() > 64 || result.code.size() > 64) + return invalid("field_limit"); + if (result.state != "balance" && result.state != "prepared" && result.state != "committed" && + result.state != "cancelled" && result.state != "rejected") return invalid("state"); for (const auto* key : {"amount", "balance"}) - if (!data.at(key).is_number_integer() || data.at(key) < 0 || data.at(key) > 1000000) return {}; + if (!data.at(key).is_number_integer() || data.at(key) < 0 || data.at(key) > 1000000) + return invalid("amount_range"); result.amount = data.at("amount").get(); result.balance = data.at("balance").get(); - if (data.at("ok").get() != (result.state != "rejected") || - (result.state != "balance" && result.id.empty()) || - ((result.state == "prepared" || result.state == "committed") && result.amount == 0)) return {}; + if (data.at("ok").get() != (result.state != "rejected")) return invalid("ok_state"); + if (result.state != "balance" && result.id.empty()) return invalid("missing_id"); + if ((result.state == "prepared" || result.state == "committed") && result.amount == 0) + return invalid("zero_transfer"); result.valid = true; + result.reason = "ok"; + return result; } - catch (...) { return {}; } - return result; + catch (...) { return invalid("schema"); } } outbox::outbox(std::filesystem::path root, std::string server, std::string endpoint) diff --git a/t5/plugins/tws-t5-gsc-utils/src/utils/bank.hpp b/t5/plugins/tws-t5-gsc-utils/src/utils/bank.hpp index a12602e..f671f62 100644 --- a/t5/plugins/tws-t5-gsc-utils/src/utils/bank.hpp +++ b/t5/plugins/tws-t5-gsc-utils/src/utils/bank.hpp @@ -10,6 +10,8 @@ namespace utils::bank { bool valid = false; std::string state, code, id; + // Fixed diagnostic vocabulary; never includes response text. + std::string reason = "schema"; int amount = 0, balance = 0; }; acknowledgement parse_acknowledgement(const std::string& response); diff --git a/t5/scripts/README.md b/t5/scripts/README.md index 39f03f8..e33363a 100644 --- a/t5/scripts/README.md +++ b/t5/scripts/README.md @@ -34,9 +34,13 @@ break T5's connect handshake. Existing dvar names are unchanged. ## Player bank +Bank `2.0.2` requires plugin `1.2.0+` for startup version reporting and bounded +parser diagnostics. Install the DLL and restart the full server process before +loading these scripts. Follow the [diagnostic rollout and live checks](../../README.md#bank-diagnostics--tws-14). + The optional `tws_t5_bank.gsc` adds `.b`, `.d ` and `.w ` and registers them in help. It requires common and telemetry -`1.0.0` or newer, the TWS t5 plugin `1.1.0`, Electric Cherry's bank API and +`1.0.0` or newer, the TWS t5 plugin `1.2.0`, Electric Cherry's bank API and a private per-server credential. Follow [bank setup and recovery](../../README.md#player-bank-t5-and-t6), including a full process restart for the plugin. Bank `2.0.0+` uses only `https://ec.thewrightserver.net/api/bank` and ignores `tws_bank_url`. diff --git a/t5/scripts/tws_t5_bank.gsc b/t5/scripts/tws_t5_bank.gsc index 929c020..64b2984 100644 --- a/t5/scripts/tws_t5_bank.gsc +++ b/t5/scripts/tws_t5_bank.gsc @@ -10,16 +10,33 @@ init() level.bank_url = "https://ec.thewrightserver.net/api/bank"; level.bank_server = GetDvar("tws_server_id"); level.bank_token = GetDvar("tws_bank_token"); + level.bank_logs = []; + level.bank_diagnostic_serial = 0; + credentials = "valid"; + if (level.bank_token.size < 40 || getSubStr(level.bank_token, 0, 8) != "ec_bank_") + credentials = "invalid"; + print("[tws_bank] startup script=2.0.2 plugin=" + bankVersion() + + " endpoint=" + level.bank_url + " server=" + bank_log_token(level.bank_server) + + " credentials=" + credentials); // A private per-server cfg supplies this; never embed bank credentials. if (level.bank_server == "" || level.bank_token.size < 40 || getSubStr(level.bank_token, 0, 8) != "ec_bank_") { - print("^1[tws_bank] Disabled: configure tws_server_id and a private tws_bank_token"); + print("^1[tws_bank] Disabled: configure tws_server_id and a private tws_bank_token; pending=not_loaded"); return; } level.bank_queue = bankLoad(level.bank_server, level.bank_url); if (!isDefined(level.bank_queue)) + { + print("[tws_bank] startup journal_load=failure pending=unknown bank=disabled"); return; + } + print("[tws_bank] startup journal_load=success pending=" + level.bank_queue.size); + for (i = 0; i < level.bank_queue.size; i++) + { + level.bank_queue[i]["since"] = getTime(); + level.bank_queue[i]["attempts"] = 0; + } level.bank_read = 0; level.bank_write = level.bank_queue.size; level.bank_busy = false; @@ -217,8 +234,9 @@ bank_transfer(entry, args) data["capacity"] = capacity; data["decision"] = "cancel"; body = jsonSerialize(data); + pending_since = getTime(); // Persist cancellation BEFORE prepare can reach EC, including lost replies. - if (!bankStore(level.bank_server, level.bank_url, body)) + if (!bank_store(body, id, "cancel")) { bank_say(entry, "^3Bank storage unavailable. Your points are unchanged."); return; @@ -236,7 +254,7 @@ bank_transfer(entry, args) commit_body = jsonSerialize(data); // No yield between recording the decision and updating the balance. // Do not change score_total: bank funds are not earned match points. - if (bankStore(level.bank_server, level.bank_url, commit_body)) + if (bank_store(commit_body, id, "commit")) { if (operation == "deposit") player.score -= transfer; @@ -263,6 +281,8 @@ bank_transfer(entry, args) pending["id"] = id; pending["body"] = body; pending["decision"] = data["decision"]; + pending["since"] = pending_since; + pending["attempts"] = 0; level.bank_queue[level.bank_write] = pending; level.bank_write++; } @@ -282,8 +302,118 @@ bank_error(code) return "^3Bank rejected the transfer. Your points are unchanged."; } +// Only locally generated identities/configured server names pass through here. +// Never use this to print response fields: those use fixed vocabularies below. +bank_log_token(value) +{ + if (!isDefined(value) || typeof(value) != "string" || value.size == 0 || value.size > 128) + return "unavailable"; + allowed = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789_.:-"; + for (i = 0; i < value.size; i++) + { + found = false; + for (j = 0; j < allowed.size; j++) + if (value[i] == allowed[j]) + found = true; + if (!found) + return "invalid"; + } + return value; +} + +bank_response_code(code) +{ + // Unknown values may contain secrets or console controls, even if short. + codes = strTok("ok insufficient_balance empty bank_limit points_limit not_in_match pending invalid_request unauthorized forbidden not_found conflict disabled", " "); + for (i = 0; i < codes.size; i++) + if (isDefined(code) && code == codes[i]) + return codes[i]; + return "unknown"; +} + +bank_response_reason(reason) +{ + reasons = strTok("empty_body body_limit invalid_json schema field_limit state amount_range ok_state missing_id zero_transfer", " "); + for (i = 0; i < reasons.size; i++) + if (isDefined(reason) && reason == reasons[i]) + return reasons[i]; + return "unknown"; +} + +bank_diagnostic_number(diagnostics, key) +{ + if (!isDefined(diagnostics) || typeof(diagnostics) != "array" || !isDefined(diagnostics[key])) + return "unavailable"; + value = diagnostics[key]; + if ((typeof(value) != "int" && typeof(value) != "float") || value < 0 || value > 2147483647) + return "unavailable"; + return "" + int(value); +} + +bank_http_details(diagnostics) +{ + detail = ""; + keys = strTok("http_status curl_code dns_ms connect_ms tls_ms total_ms", " "); + for (i = 0; i < keys.size; i++) + detail += " " + keys[i] + "=" + bank_diagnostic_number(diagnostics, keys[i]); + return detail; +} + +// Fixed keys bound memory. Correlation IDs/timings never form the signature. +// Report first failure, reason/status/code changes, 30s reminders and recovery. +bank_log(key, signature, detail, failed) +{ + now = getTime(); + previous = level.bank_logs[key]; + suppressed = 0; + recovery = ""; + if (isDefined(previous)) + { + suppressed = previous["suppressed"]; + if (failed && previous["signature"] == signature && now >= previous["time"] && now - previous["time"] < 30000) + { + previous["suppressed"]++; + level.bank_logs[key] = previous; + return; + } + if (previous["failed"] && !failed) + recovery = " recovery=true"; + } + print("[tws_bank] " + detail + recovery + " suppressed=" + suppressed); + current = []; + current["signature"] = signature; + current["time"] = now; + current["failed"] = failed; + current["suppressed"] = 0; + level.bank_logs[key] = current; +} + +bank_store(body, id, decision) +{ + saved = bankStore(level.bank_server, level.bank_url, body); + outcome = "success"; + if (!saved) + outcome = "storage_failure"; + bank_log("write_" + decision, outcome, "journal_write decision=" + decision + + " request_id=" + bank_log_token(id) + " outcome=" + outcome, !saved); + return saved; +} + +bank_http_outcome(action, id, correlation, reason, code, diagnostics, failed) +{ + level.bank_http_signature = reason + ":" + code + ":" + + bank_diagnostic_number(diagnostics, "http_status") + ":" + bank_diagnostic_number(diagnostics, "curl_code"); + level.bank_http_detail = "correlation=" + correlation + " action=" + action + + " request_id=" + bank_log_token(id) + " outcome=" + reason + " code=" + code + bank_http_details(diagnostics); + // Settlement adds progress and cleanup outcome before logging this attempt. + if (action != "commit" && action != "cancel") + bank_log(action, level.bank_http_signature, level.bank_http_detail, failed); +} + bank_http(action, body, id) { + level.bank_diagnostic_serial++; + correlation = "bank-" + getTime() + "-" + level.bank_diagnostic_serial; headers = []; headers["Content-Type"] = "application/json"; headers["Authorization"] = "Bearer " + level.bank_token; @@ -295,15 +425,46 @@ bank_http(action, body, id) options["timeout_ms"] = 15000; request = http::request(level.bank_url + "/" + action, options); if (!isDefined(request)) + { + bank_http_outcome(action, id, correlation, "request_creation", "none", undefined, true); return undefined; + } request waittill("done", response, success, error, diagnostics); - if (!isDefined(success) || !success || !isDefined(response) || - !isDefined(diagnostics) || !isDefined(diagnostics["http_status"]) || - diagnostics["http_status"] != 200) + reason = "ok"; + if (!isDefined(success) || !success) + reason = "transport_failure"; + else if (bank_diagnostic_number(diagnostics, "http_status") == "unavailable") + reason = "missing_diagnostics"; + else if (diagnostics["http_status"] != 200) + reason = "http_rejection"; + else if (!isDefined(response)) + reason = "missing_response"; + if (reason != "ok") + { + bank_http_outcome(action, id, correlation, reason, "none", diagnostics, true); return undefined; + } reply = bankResponse(response); - if (!reply["valid"] || reply["request_id"] != id) + if (!isDefined(reply) || !isDefined(reply["valid"]) || !reply["valid"]) + { + reason = "unknown"; + if (isDefined(reply)) + reason = bank_response_reason(reply["reason"]); + bank_http_outcome(action, id, correlation, "invalid_ack_" + reason, "none", diagnostics, true); return undefined; + } + if (reply["request_id"] != id) + { + bank_http_outcome(action, id, correlation, "request_id_mismatch", "none", diagnostics, true); + return undefined; + } + if (reply["state"] == "rejected") + reason = "application_rejection"; + else if ((action == "balance" && reply["state"] != "balance") || + ((action == "deposit" || action == "withdraw") && reply["state"] != "prepared") || + ((action == "commit" || action == "cancel") && !bank_resolved(action, reply["state"]))) + reason = "unexpected_state"; + bank_http_outcome(action, id, correlation, reason, bank_response_code(reply["code"]), diagnostics, reason != "ok"); return reply; } @@ -325,12 +486,20 @@ bank_sender() continue; } entry = level.bank_queue[level.bank_read]; + entry["attempts"]++; + level.bank_queue[level.bank_read] = entry; reply = bank_http(entry["decision"], entry["body"], entry["id"]); + duration = int((getTime() - entry["since"]) / 1000); + progress = " decision=" + entry["decision"] + " attempt=" + entry["attempts"] + + " pending_seconds=" + duration; + outcome = "pending"; if (isDefined(reply) && bank_resolved(entry["decision"], reply["state"])) { // Cleanup failures never reapply points; settlement is idempotent. if (bankRemove(level.bank_server, level.bank_url, entry["id"])) { + bank_log("settlement", "resolved", level.bank_http_detail + progress + + " journal_remove=success settlement=resolved next_retry_seconds=0", false); level.bank_queue[level.bank_read] = undefined; level.bank_read++; if (level.bank_read == level.bank_write) @@ -342,8 +511,10 @@ bank_sender() delay = 1; continue; } + outcome = "journal_remove_failure"; } - print("^1[tws_bank] Transfer settlement pending; retaining durable decision and retrying"); + bank_log("settlement", level.bank_http_signature + ":" + outcome, level.bank_http_detail + progress + + " settlement=" + outcome + " next_retry_seconds=" + delay, true); wait delay; delay *= 2; if (delay > 30) diff --git a/t6/plugins/README.md b/t6/plugins/README.md index af8412a..2a7b631 100644 --- a/t6/plugins/README.md +++ b/t6/plugins/README.md @@ -109,3 +109,23 @@ decisions and strict response validation for the new bank script. Build and install the DLL, then restart the full process. No upstream pins or external dependencies changed. See [bank setup and recovery](../../README.md#player-bank-t5-and-t6). Portable checks: `python3 tools/test_plugin_bank.py`. + +## Bank diagnostics (TWS 1.2.0) + +`bankVersion()` returns the loaded DLL's TWS component version, independently of +upstream pins and the native loader's unchanged `plugin_version()` value. +`bankResponse()` now also returns `reason`: `ok` on success, otherwise one of +`empty_body`, `body_limit`, `invalid_json`, `schema`, `field_limit`, `state`, +`amount_range`, `ok_state`, `missing_id`, or `zero_transfer`. Invalid responses +clear all parsed fields. Existing acknowledgment acceptance rules are unchanged. +The returned `code` on valid responses remains API data; bank scripts allowlist +it before logging. Callers must never log arbitrary response fields. + +Native journal logs name load/write/remove, limit identical failures to one +per 30 seconds, and log recovery with suppressed counts. Exception text, journal +contents and credentials are excluded. The new scripts require this DLL even +when disabled by dvar because `bankVersion()` must link. No new third-party +dependencies or upstream pin changes are required. Rebuild/install the DLL and +restart the full server process; see the [diagnostic rollout](../../README.md#bank-diagnostics--tws-14). +Portable checks: `python3 tools/test_plugin_bank.py` executes the real parser, +storage and native registration adapter with sanitizers and engine shims. diff --git a/t6/plugins/tws-t6-gsc-utils/src/component/bank.cpp b/t6/plugins/tws-t6-gsc-utils/src/component/bank.cpp index a7d29a3..d3a745b 100644 --- a/t6/plugins/tws-t6-gsc-utils/src/component/bank.cpp +++ b/t6/plugins/tws-t6-gsc-utils/src/component/bank.cpp @@ -3,6 +3,8 @@ #include "gsc.hpp" #include "game/scripting/array.hpp" #include +#include +#include namespace bank { @@ -13,11 +15,33 @@ namespace bank return {"tws-bank/t6", server, endpoint}; } - void storage_error() + // Only fixed operation names are printed, never exception text or paths + // from private configuration. Per-operation state has bounded memory. + void storage_result(size_t operation, bool failed) { - // Do not echo parse exceptions: their text can contain player data. - printf("^1[tws_bank] Outbox operation failed; check tws-bank/t6 files, disk space and permissions. Existing reports retained.\n"); + struct status + { + bool failed = false; + std::chrono::steady_clock::time_point logged{}; + unsigned suppressed = 0; + }; + static std::array states; + constexpr const char* names[] = {"load", "write", "remove"}; + auto& state = states[operation]; + const auto now = std::chrono::steady_clock::now(); + if (failed && state.failed && now - state.logged < std::chrono::seconds(30)) + { + ++state.suppressed; + return; + } + if (failed || state.failed) + printf("[tws_bank] native_storage operation=%s outcome=%s suppressed=%u\n", + names[operation], failed ? "storage_failure" : "recovered", state.suppressed); + state.failed = failed; + state.logged = now; + state.suppressed = 0; } + } class component final : public component_interface @@ -25,6 +49,7 @@ namespace bank public: void on_startup([[maybe_unused]] plugin::plugin* plugin) override { + gsc::function::add("bankversion", []() { return std::string("1.2.0"); }); gsc::function::add("bankload", [](const std::string& server, const std::string& endpoint) -> scripting::script_value { try @@ -38,25 +63,27 @@ namespace bank entry["body"] = value.body; entries.emplace_back(entry); } + storage_result(0, false); return entries; } - catch (...) { storage_error(); return {}; } + catch (...) { storage_result(0, true); return {}; } }); gsc::function::add("bankstore", [](const std::string& server, const std::string& endpoint, const std::string& body) { - try { spool(server, endpoint).store(body); return true; } - catch (...) { storage_error(); return false; } + try { spool(server, endpoint).store(body); storage_result(1, false); return true; } + catch (...) { storage_result(1, true); return false; } }); gsc::function::add("bankremove", [](const std::string& server, const std::string& endpoint, const std::string& id) { - try { spool(server, endpoint).erase(id); return true; } - catch (...) { storage_error(); return false; } + try { spool(server, endpoint).erase(id); storage_result(2, false); return true; } + catch (...) { storage_result(2, true); return false; } }); gsc::function::add("bankresponse", [](const std::string& response) { const auto ack = utils::bank::parse_acknowledgement(response); scripting::array result; result["valid"] = ack.valid; + result["reason"] = ack.reason; result["state"] = ack.state; result["code"] = ack.code; result["request_id"] = ack.id; diff --git a/t6/plugins/tws-t6-gsc-utils/src/utils/bank.cpp b/t6/plugins/tws-t6-gsc-utils/src/utils/bank.cpp index d823772..5b81194 100644 --- a/t6/plugins/tws-t6-gsc-utils/src/utils/bank.cpp +++ b/t6/plugins/tws-t6-gsc-utils/src/utils/bank.cpp @@ -29,30 +29,42 @@ namespace utils::bank acknowledgement parse_acknowledgement(const std::string& response) { - acknowledgement result; - if (response.empty() || response.size() >= max_body_size) return result; + auto invalid = [](const char* reason) + { + acknowledgement value; + value.reason = reason; + return value; + }; + if (response.empty()) return invalid("empty_body"); + if (response.size() >= max_body_size) return invalid("body_limit"); const auto data = nlohmann::json::parse(response, nullptr, false); - if (!data.is_object()) return result; + if (data.is_discarded()) return invalid("invalid_json"); + if (!data.is_object()) return invalid("schema"); try { - if (!data.at("ok").is_boolean()) return result; + acknowledgement result; + if (!data.at("ok").is_boolean()) return invalid("schema"); result.state = data.at("state").get(); result.code = data.at("code").get(); result.id = data.at("request_id").get(); - if (result.id.size() > 64 || result.code.size() > 64 || - (result.state != "balance" && result.state != "prepared" && result.state != "committed" && - result.state != "cancelled" && result.state != "rejected")) return {}; + if (result.id.size() > 64 || result.code.size() > 64) + return invalid("field_limit"); + if (result.state != "balance" && result.state != "prepared" && result.state != "committed" && + result.state != "cancelled" && result.state != "rejected") return invalid("state"); for (const auto* key : {"amount", "balance"}) - if (!data.at(key).is_number_integer() || data.at(key) < 0 || data.at(key) > 1000000) return {}; + if (!data.at(key).is_number_integer() || data.at(key) < 0 || data.at(key) > 1000000) + return invalid("amount_range"); result.amount = data.at("amount").get(); result.balance = data.at("balance").get(); - if (data.at("ok").get() != (result.state != "rejected") || - (result.state != "balance" && result.id.empty()) || - ((result.state == "prepared" || result.state == "committed") && result.amount == 0)) return {}; + if (data.at("ok").get() != (result.state != "rejected")) return invalid("ok_state"); + if (result.state != "balance" && result.id.empty()) return invalid("missing_id"); + if ((result.state == "prepared" || result.state == "committed") && result.amount == 0) + return invalid("zero_transfer"); result.valid = true; + result.reason = "ok"; + return result; } - catch (...) { return {}; } - return result; + catch (...) { return invalid("schema"); } } outbox::outbox(std::filesystem::path root, std::string server, std::string endpoint) diff --git a/t6/plugins/tws-t6-gsc-utils/src/utils/bank.hpp b/t6/plugins/tws-t6-gsc-utils/src/utils/bank.hpp index a12602e..f671f62 100644 --- a/t6/plugins/tws-t6-gsc-utils/src/utils/bank.hpp +++ b/t6/plugins/tws-t6-gsc-utils/src/utils/bank.hpp @@ -10,6 +10,8 @@ namespace utils::bank { bool valid = false; std::string state, code, id; + // Fixed diagnostic vocabulary; never includes response text. + std::string reason = "schema"; int amount = 0, balance = 0; }; acknowledgement parse_acknowledgement(const std::string& response); diff --git a/t6/scripts/README.md b/t6/scripts/README.md index d6112f5..a86dc47 100644 --- a/t6/scripts/README.md +++ b/t6/scripts/README.md @@ -14,7 +14,7 @@ private server token. | `tws_t6_telemetry.gsc` | Async queued game reports (game_start/heartbeat/round_change/game_end) | tws-t6-gsc-utils | | `tws_t6_join.gsc` | `.join` chat command lets a spectator newcomer enter mid-match once | Common | | `tws_t6_leaderboard.gsc` | Private map high-round record and every tied holder on connection | Common, tws-t6-gsc-utils | -| `tws_t6_bank.gsc` | Persistent shared GUID bank | Common, telemetry, TWS plugin 1.1.0 | +| `tws_t6_bank.gsc` | Persistent shared GUID bank | Common, telemetry, TWS plugin 1.2.0 | ## Install @@ -44,9 +44,13 @@ its plugin dependency during linking. The same rule applies to leaderboard. ## Player bank +Bank `2.0.2` requires plugin `1.2.0+` for startup version reporting and bounded +parser diagnostics. Install the DLL and restart the full server process before +loading these scripts. Follow the [diagnostic rollout and live checks](../../README.md#bank-diagnostics--tws-14). + The optional `tws_t6_bank.gsc` adds `.b`, `.d ` and `.w ` and registers them in help. It requires common and telemetry -`1.0.0` or newer, the TWS t6 plugin `1.1.0`, Electric Cherry's bank API and +`1.0.0` or newer, the TWS t6 plugin `1.2.0`, Electric Cherry's bank API and a private per-server credential. Follow [bank setup and recovery](../../README.md#player-bank-t5-and-t6), including a full process restart for the plugin. Bank `2.0.0+` uses only `https://ec.thewrightserver.net/api/bank` and ignores `tws_bank_url`. diff --git a/t6/scripts/tws_t6_bank.gsc b/t6/scripts/tws_t6_bank.gsc index e59e065..96fbd77 100644 --- a/t6/scripts/tws_t6_bank.gsc +++ b/t6/scripts/tws_t6_bank.gsc @@ -14,16 +14,33 @@ init() level.bank_url = "https://ec.thewrightserver.net/api/bank"; level.bank_server = GetDvar("tws_server_id"); level.bank_token = GetDvar("tws_bank_token"); + level.bank_logs = []; + level.bank_diagnostic_serial = 0; + credentials = "valid"; + if (level.bank_token.size < 40 || getSubStr(level.bank_token, 0, 8) != "ec_bank_") + credentials = "invalid"; + println("[tws_bank] startup script=2.0.2 plugin=" + bankVersion() + + " endpoint=" + level.bank_url + " server=" + bank_log_token(level.bank_server) + + " credentials=" + credentials); // A private per-server cfg supplies this; never embed bank credentials. if (level.bank_server == "" || level.bank_token.size < 40 || getSubStr(level.bank_token, 0, 8) != "ec_bank_") { - println("^1[tws_bank] Disabled: configure tws_server_id and a private tws_bank_token"); + println("^1[tws_bank] Disabled: configure tws_server_id and a private tws_bank_token; pending=not_loaded"); return; } level.bank_queue = bankLoad(level.bank_server, level.bank_url); if (!isDefined(level.bank_queue)) + { + println("[tws_bank] startup journal_load=failure pending=unknown bank=disabled"); return; + } + println("[tws_bank] startup journal_load=success pending=" + level.bank_queue.size); + for (i = 0; i < level.bank_queue.size; i++) + { + level.bank_queue[i]["since"] = getTime(); + level.bank_queue[i]["attempts"] = 0; + } level.bank_read = 0; level.bank_write = level.bank_queue.size; level.bank_busy = false; @@ -222,8 +239,9 @@ bank_transfer(entry, args) data["capacity"] = capacity; data["decision"] = "cancel"; body = jsonSerialize(data); + pending_since = getTime(); // Persist cancellation BEFORE prepare can reach EC, including lost replies. - if (!bankStore(level.bank_server, level.bank_url, body)) + if (!bank_store(body, id, "cancel")) { bank_say(entry, "^3Bank storage unavailable. Your points are unchanged."); return; @@ -241,7 +259,7 @@ bank_transfer(entry, args) commit_body = jsonSerialize(data); // No yield between recording the decision and updating the balance. // Do not change score_total: bank funds are not earned match points. - if (bankStore(level.bank_server, level.bank_url, commit_body)) + if (bank_store(commit_body, id, "commit")) { if (operation == "deposit") player.score -= transfer; @@ -268,6 +286,8 @@ bank_transfer(entry, args) pending["id"] = id; pending["body"] = body; pending["decision"] = data["decision"]; + pending["since"] = pending_since; + pending["attempts"] = 0; level.bank_queue[level.bank_write] = pending; level.bank_write++; } @@ -287,8 +307,118 @@ bank_error(code) return "^3Bank rejected the transfer. Your points are unchanged."; } +// Only locally generated identities/configured server names pass through here. +// Never use this to print response fields: those use fixed vocabularies below. +bank_log_token(value) +{ + if (!isDefined(value) || typeof(value) != "string" || value.size == 0 || value.size > 128) + return "unavailable"; + allowed = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789_.:-"; + for (i = 0; i < value.size; i++) + { + found = false; + for (j = 0; j < allowed.size; j++) + if (value[i] == allowed[j]) + found = true; + if (!found) + return "invalid"; + } + return value; +} + +bank_response_code(code) +{ + // Unknown values may contain secrets or console controls, even if short. + codes = strTok("ok insufficient_balance empty bank_limit points_limit not_in_match pending invalid_request unauthorized forbidden not_found conflict disabled", " "); + for (i = 0; i < codes.size; i++) + if (isDefined(code) && code == codes[i]) + return codes[i]; + return "unknown"; +} + +bank_response_reason(reason) +{ + reasons = strTok("empty_body body_limit invalid_json schema field_limit state amount_range ok_state missing_id zero_transfer", " "); + for (i = 0; i < reasons.size; i++) + if (isDefined(reason) && reason == reasons[i]) + return reasons[i]; + return "unknown"; +} + +bank_diagnostic_number(diagnostics, key) +{ + if (!isDefined(diagnostics) || typeof(diagnostics) != "array" || !isDefined(diagnostics[key])) + return "unavailable"; + value = diagnostics[key]; + if ((typeof(value) != "int" && typeof(value) != "float") || value < 0 || value > 2147483647) + return "unavailable"; + return "" + int(value); +} + +bank_http_details(diagnostics) +{ + detail = ""; + keys = strTok("http_status curl_code dns_ms connect_ms tls_ms total_ms", " "); + for (i = 0; i < keys.size; i++) + detail += " " + keys[i] + "=" + bank_diagnostic_number(diagnostics, keys[i]); + return detail; +} + +// Fixed keys bound memory. Correlation IDs/timings never form the signature. +// Report first failure, reason/status/code changes, 30s reminders and recovery. +bank_log(key, signature, detail, failed) +{ + now = getTime(); + previous = level.bank_logs[key]; + suppressed = 0; + recovery = ""; + if (isDefined(previous)) + { + suppressed = previous["suppressed"]; + if (failed && previous["signature"] == signature && now >= previous["time"] && now - previous["time"] < 30000) + { + previous["suppressed"]++; + level.bank_logs[key] = previous; + return; + } + if (previous["failed"] && !failed) + recovery = " recovery=true"; + } + println("[tws_bank] " + detail + recovery + " suppressed=" + suppressed); + current = []; + current["signature"] = signature; + current["time"] = now; + current["failed"] = failed; + current["suppressed"] = 0; + level.bank_logs[key] = current; +} + +bank_store(body, id, decision) +{ + saved = bankStore(level.bank_server, level.bank_url, body); + outcome = "success"; + if (!saved) + outcome = "storage_failure"; + bank_log("write_" + decision, outcome, "journal_write decision=" + decision + + " request_id=" + bank_log_token(id) + " outcome=" + outcome, !saved); + return saved; +} + +bank_http_outcome(action, id, correlation, reason, code, diagnostics, failed) +{ + level.bank_http_signature = reason + ":" + code + ":" + + bank_diagnostic_number(diagnostics, "http_status") + ":" + bank_diagnostic_number(diagnostics, "curl_code"); + level.bank_http_detail = "correlation=" + correlation + " action=" + action + + " request_id=" + bank_log_token(id) + " outcome=" + reason + " code=" + code + bank_http_details(diagnostics); + // Settlement adds progress and cleanup outcome before logging this attempt. + if (action != "commit" && action != "cancel") + bank_log(action, level.bank_http_signature, level.bank_http_detail, failed); +} + bank_http(action, body, id) { + level.bank_diagnostic_serial++; + correlation = "bank-" + getTime() + "-" + level.bank_diagnostic_serial; headers = []; headers["Content-Type"] = "application/json"; headers["Authorization"] = "Bearer " + level.bank_token; @@ -300,15 +430,46 @@ bank_http(action, body, id) options["timeout_ms"] = 15000; request = http::request(level.bank_url + "/" + action, options); if (!isDefined(request)) + { + bank_http_outcome(action, id, correlation, "request_creation", "none", undefined, true); return undefined; + } request waittill("done", response, success, error, diagnostics); - if (!isDefined(success) || !success || !isDefined(response) || - !isDefined(diagnostics) || !isDefined(diagnostics["http_status"]) || - diagnostics["http_status"] != 200) + reason = "ok"; + if (!isDefined(success) || !success) + reason = "transport_failure"; + else if (bank_diagnostic_number(diagnostics, "http_status") == "unavailable") + reason = "missing_diagnostics"; + else if (diagnostics["http_status"] != 200) + reason = "http_rejection"; + else if (!isDefined(response)) + reason = "missing_response"; + if (reason != "ok") + { + bank_http_outcome(action, id, correlation, reason, "none", diagnostics, true); return undefined; + } reply = bankResponse(response); - if (!reply["valid"] || reply["request_id"] != id) + if (!isDefined(reply) || !isDefined(reply["valid"]) || !reply["valid"]) + { + reason = "unknown"; + if (isDefined(reply)) + reason = bank_response_reason(reply["reason"]); + bank_http_outcome(action, id, correlation, "invalid_ack_" + reason, "none", diagnostics, true); return undefined; + } + if (reply["request_id"] != id) + { + bank_http_outcome(action, id, correlation, "request_id_mismatch", "none", diagnostics, true); + return undefined; + } + if (reply["state"] == "rejected") + reason = "application_rejection"; + else if ((action == "balance" && reply["state"] != "balance") || + ((action == "deposit" || action == "withdraw") && reply["state"] != "prepared") || + ((action == "commit" || action == "cancel") && !bank_resolved(action, reply["state"]))) + reason = "unexpected_state"; + bank_http_outcome(action, id, correlation, reason, bank_response_code(reply["code"]), diagnostics, reason != "ok"); return reply; } @@ -330,12 +491,20 @@ bank_sender() continue; } entry = level.bank_queue[level.bank_read]; + entry["attempts"]++; + level.bank_queue[level.bank_read] = entry; reply = bank_http(entry["decision"], entry["body"], entry["id"]); + duration = int((getTime() - entry["since"]) / 1000); + progress = " decision=" + entry["decision"] + " attempt=" + entry["attempts"] + + " pending_seconds=" + duration; + outcome = "pending"; if (isDefined(reply) && bank_resolved(entry["decision"], reply["state"])) { // Cleanup failures never reapply points; settlement is idempotent. if (bankRemove(level.bank_server, level.bank_url, entry["id"])) { + bank_log("settlement", "resolved", level.bank_http_detail + progress + + " journal_remove=success settlement=resolved next_retry_seconds=0", false); level.bank_queue[level.bank_read] = undefined; level.bank_read++; if (level.bank_read == level.bank_write) @@ -347,8 +516,10 @@ bank_sender() delay = 1; continue; } + outcome = "journal_remove_failure"; } - println("^1[tws_bank] Transfer settlement pending; retaining durable decision and retrying"); + bank_log("settlement", level.bank_http_signature + ":" + outcome, level.bank_http_detail + progress + + " settlement=" + outcome + " next_retry_seconds=" + delay, true); wait delay; delay *= 2; if (delay > 30) diff --git a/tools/check_bank.mjs b/tools/check_bank.mjs index 796bcc0..5f2888a 100644 --- a/tools/check_bank.mjs +++ b/tools/check_bank.mjs @@ -72,8 +72,8 @@ function engine(game, options = {}) { if (game === 't6') player.guid = identity; const entry = { player, active: true }; const recovered = (options.recovered ?? []).map(report => ({...report})); - const saved = recovered.map(report => JSON.parse(report.body)), writes = [], sent = [], messages = [], order = [], loaded = [], dvarsRead = []; - let serial = 0; + const saved = recovered.map(report => JSON.parse(report.body)), writes = [], sent = [], messages = [], order = [], loaded = [], dvarsRead = [], logs = []; + let serial = 0, now = 1000; const dvars = { zombiemode: '1', tws_server_id: 'server', tws_bank_token: privateToken, ...options.dvars }; function assertScope(server, url) { assert.equal(server, dvars.tws_server_id); @@ -84,13 +84,14 @@ function engine(game, options = {}) { GetDvar: name => { dvarsRead.push(name); return dvars[name] ?? ''; }, getSubStr: (value, start, end) => value.substring(start, end), registerHelpCommand: () => {}, isDefined: v => v !== undefined && v !== null, is_true: v => !!v, isAlive: p => p.alive, - int: Math.trunc, + int: Math.trunc, getTime: () => now, strTok: (text, delimiter) => text.split(delimiter), + bankVersion: () => "1.2.0", ...(game === 't5' ? {getGuid: p => { assert.equal(p, player); return identity; }} : {}), - gscType: value => typeof value === 'number' ? Number.isInteger(value) ? 'int' : 'float' : typeof value, + gscType: value => typeof value === 'number' ? Number.isInteger(value) ? 'int' : 'float' : value && typeof value === 'object' ? 'array' : typeof value, jsonSerialize: a => JSON.stringify(Object.fromEntries(Object.entries(a))), bank_say: (_entry, message) => messages.push(message), telemetryNewMatch: () => `${options.idPrefix ?? 'request'}-${++serial}`, - bankLoad: (server, url) => { assertScope(server, url); loaded.push({ server, url }); return recovered; }, + bankLoad: (server, url) => { assertScope(server, url); loaded.push({ server, url }); return options.loadFailure ? undefined : recovered; }, bankStore: (server, url, body) => { assertScope(server, url); const data = JSON.parse(body); assertContract(data.decision, data); @@ -112,14 +113,14 @@ function engine(game, options = {}) { } const state = action === 'commit' ? 'committed' : action === 'cancel' ? 'cancelled' : action === 'balance' ? 'balance' : options.state ?? 'prepared'; const reply = { valid: true, state, request_id: action === 'balance' ? '' : options.wrongId ? 'wrong' : JSON.parse(sent.at(-1).body).request_id, amount: options.amount ?? 2000, balance: options.balance ?? 5000, code: options.code ?? 'ok' }; - return [JSON.stringify(reply), !options.timeout, '', options.missingDiagnostics ? undefined : { http_status: options.status ?? 200 }]; + return [options.missingResponse ? undefined : JSON.stringify(reply), !options.timeout, privateToken, options.missingDiagnostics ? undefined : options.diagnostics ?? { http_status: options.status ?? 200, curl_code: options.timeout ? 28 : 0, dns_ms:1, connect_ms:2, tls_ms:3, total_ms:options.timeout ? 15000 : 4 }]; }, - bankResponse: data => options.malformed ? { valid: false } : {valid:true, ...JSON.parse(data)}, - print: () => {}, println: () => {} + bankResponse: data => options.malformed ? { valid: false, reason: options.reason ?? "invalid_json" } : {valid:true, ...JSON.parse(data)}, + print: message => logs.push(message), println: message => logs.push(message) }); vm.runInContext([...functionsByName].filter(([name]) => !excluded.has(name)).map(([, code]) => code).join('\n'), c); c.init(); - return { c, player, entry, saved, writes, sent, messages, order, loaded, dvarsRead, run: args => c.bank_transfer(entry,args) }; + return { c, player, entry, saved, writes, sent, messages, order, loaded, dvarsRead, logs, advance: ms => { now += ms; }, run: args => c.bank_transfer(entry,args) }; } let checks = 0; function journalEntries(engine) { @@ -185,6 +186,80 @@ for (const game of ['t5','t6']) { assert.equal(engine(game, {dvars}).loaded.length, 0); } }); + test('startup reports versions, scope, credential validation and journal count safely', () => { + const e = engine(game); + assert.match(e.logs.join('\n'), /script=2\.0\.2 plugin=1\.2\.0/); + assert(e.logs.some(line => line.includes(`endpoint=${publicEndpoint} server=server credentials=valid`))); + assert(e.logs.some(line => line.includes('journal_load=success pending=0'))); + const invalid = engine(game, {dvars:{tws_bank_token:'secret-invalid-token'}}); + assert(invalid.logs.some(line => line.includes('credentials=invalid'))); + assert(!invalid.logs.join('').includes('secret-invalid-token')); + const load = engine(game, {loadFailure:true}); + assert.match(load.logs.join('\n'), /journal_load=failure pending=unknown bank=disabled/); + assert.equal(load.c.level.bank_write, undefined); + }); + test('requests classify failures and preserve the API identity contract', () => { + for (const [options, outcome] of [ + [{}, 'ok'], [{noHandle:true}, 'request_creation'], [{timeout:true}, 'transport_failure'], + [{status:401}, 'http_rejection'], [{missingDiagnostics:true}, 'missing_diagnostics'], + [{missingResponse:true}, 'missing_response'], [{malformed:true}, 'invalid_ack_invalid_json'], + [{malformed:true,reason:'schema'}, 'invalid_ack_schema'], [{wrongId:true}, 'request_id_mismatch'], + [{state:'rejected', code:'pending'}, 'application_rejection'], [{state:'committed'}, 'unexpected_state'] + ]) { + const e = engine(game, options); e.run(['.d','2000']); + const line = e.logs.find(line => line.includes('action=deposit')); + assert(line, JSON.stringify(options)); assert(line.includes(`outcome=${outcome} `), line); + assert.match(line, /correlation=bank-1000-1 action=deposit request_id=request-1/); + assert.match(line, /http_status=\w+ curl_code=\w+ dns_ms=\w+ connect_ms=\w+ tls_ms=\w+ total_ms=\w+/); + } + const e = engine(game); e.run(['.b']); e.run(['.b']); + const lines = e.logs.filter(line => line.includes('action=balance')); + assert.equal(lines.length, 2); + assert.match(lines[0], /correlation=bank-1000-1/); assert.match(lines[1], /correlation=bank-1000-2/); + for (const request of e.sent) assert(!Object.hasOwn(JSON.parse(request.body), 'request_id')); + assert.equal(e.saved.length, 0); + }); + test('diagnostics exclude secrets, arbitrary codes, bodies and malformed timing fields', () => { + for (const diagnostics of [undefined, {}, 'secret', {http_status:200, curl_code:privateToken, dns_ms:-1, connect_ms:{}, tls_ms:1e30, total_ms:'raw-body'}]) { + const e = engine(game, {diagnostics, state:'rejected', code:privateToken}); e.run(['.d','2000']); + const text = e.logs.join('\n'); + for (const secret of [privateToken, 'Authorization', 'Bearer ', 'raw-body', '18446744073709551615']) assert(!text.includes(secret)); + } + const e = engine(game, {malformed:true, reason:privateToken}); e.run(['.b']); + assert.match(e.logs.at(-1), /invalid_ack_unknown/); assert(!e.logs.join('').includes(privateToken)); + for (const code of [privateToken, 'oops\ninjected', '^1red', 'x'.repeat(1000), 'custom_code']) { + assert.equal(e.c.bank_response_code(code), 'unknown'); + } + for (const diagnostics of [undefined, {}, [], false, 'secret', {http_status:'200'}, {http_status:-1}]) + assert.equal(e.c.bank_diagnostic_number(diagnostics, 'http_status'), 'unavailable'); + }); + test('failures are limited by reason, with summaries, changed status and immediate recovery', () => { + const options = {status:401}, e = engine(game, options); + e.run(['.b']); e.run(['.b']); + assert.equal(e.logs.filter(line => line.includes('action=balance')).length, 1); + e.advance(30000); e.run(['.b']); assert.match(e.logs.at(-1), /suppressed=1/); + options.status = 503; e.run(['.b']); assert.match(e.logs.at(-1), /http_status=503/); + options.status = 200; e.run(['.b']); assert.match(e.logs.at(-1), /outcome=ok.*recovery=true/); + }); + test('settlement reports retry progress, reason changes, storage failures and eventual recovery', () => { + const options = {}, e = engine(game, options); e.run(['.d','2000']); + options.timeout = true; + const sender = e.c.bank_sender(); + assert.equal(sender.next().value, 1); + assert.match(e.logs.at(-1), /decision=commit attempt=1 pending_seconds=0 settlement=pending next_retry_seconds=1/); + const count = e.logs.length; + e.advance(1000); assert.equal(sender.next().value, 2); assert.equal(e.logs.length, count); + options.timeout = false; options.removeFailure = true; + e.advance(2000); assert.equal(sender.next().value, 4); + assert.match(e.logs.at(-1), /attempt=3 pending_seconds=3 settlement=journal_remove_failure next_retry_seconds=4.*suppressed=1/); + options.removeFailure = false; e.advance(4000); sender.next(); + assert.match(e.logs.at(-1), /attempt=4 pending_seconds=7 journal_remove=success settlement=resolved next_retry_seconds=0 recovery=true/); + assert.equal(e.saved.length, 0); assert.equal(e.player.score, 1000); + for (const decision of ['cancel','commit']) { + const failed = engine(game, {storageFailure:decision}); failed.run(['.d','2000']); + assert(failed.logs.some(line => line.includes(`journal_write decision=${decision} request_id=request-1 outcome=storage_failure`))); + } + }); test('strict positive integer syntax', () => { const {c} = engine(game); for (const bad of ['', '0', '-1', '1.5', '+1', '1e3', '1000001', 'all now']) assert.equal(c.bank_amount(bad),0); diff --git a/tools/test_plugin_bank.py b/tools/test_plugin_bank.py index ad2f78c..3d010f1 100644 --- a/tools/test_plugin_bank.py +++ b/tools/test_plugin_bank.py @@ -43,10 +43,30 @@ with tempfile.TemporaryDirectory(prefix="tws-bank-") as temp: # engine interfaces. This does not validate the Windows ABI/VM linker. stub = (ROOT / "tools/tests/http_component_stub.hpp").read_text() stub = stub.replace("std::vector get_keys() const", "void emplace_back(const script_value& value) { (*data)[std::to_string(data->size())] = value; }\n std::vector get_keys() const") + stub = stub.replace('template void add(const char*, F) {}', r""" + inline std::map&)>> functions; + template void add(const char* name, F callback) + { + functions[name] = [callback](const std::vector& args) -> scripting::script_value + { + if constexpr (std::is_invocable_v) return callback(); + else if constexpr (std::is_invocable_v) return callback(args.at(0)); + else if constexpr (std::is_invocable_v) return callback(args.at(0), args.at(1)); + else return callback(args.at(0), args.at(1), args.at(2)); + }; + } +""") (directory / "component_stub.hpp").write_text(stub) component = re.sub(r'^#include[^\n]*\n', '', (plugin / "src/component/bank.cpp").read_text(), flags=re.MULTILINE) source = directory / "component.cpp" - source.write_text('#include "component_stub.hpp"\n#include "bank.hpp"\n' + component) - subprocess.run([os.environ.get("CXX", "c++"), "-std=c++20", "-Wall", "-Wextra", "-Werror", "-fsyntax-only", - "-I", str(directory), "-I", str(plugin / "src/utils"), str(source)], check=True) + source.write_text('#include "component_stub.hpp"\n#include "bank.hpp"\n#include \n' + component + (ROOT / 'tools/tests/bank_component_cases.cpp').read_text()) + subprocess.run([os.environ.get("CXX", "c++"), "-std=c++20", "-Wall", "-Wextra", "-Werror", "-fsanitize=address,undefined", + "-I", str(directory), "-I", str(plugin / "src/utils"), str(source), + str(plugin / "src/utils/bank.cpp"), "-o", str(directory / "component")], check=True) + result = subprocess.run([str(directory / "component")], cwd=directory, check=True, capture_output=True, text=True) + lines = result.stdout.splitlines() + for operation in ("load", "write", "remove"): + assert sum(f"operation={operation} outcome=storage_failure" in line for line in lines) == 1, lines + assert sum(f"operation={operation} outcome=recovered suppressed=1" in line for line in lines) == 1, lines + assert "private-secret" not in result.stdout and "Authorization" not in result.stdout print(f"PASS {game}: native storage, acknowledgment, process restart and component checks", flush=True) diff --git a/tools/tests/bank_cases.cpp b/tools/tests/bank_cases.cpp index 81945cf..3561c38 100644 --- a/tools/tests/bank_cases.cpp +++ b/tools/tests/bank_cases.cpp @@ -104,6 +104,29 @@ int main(int argc, char** argv) for (const auto& text : {"", "bad gateway", "{", "null", "{\"ok\":true}"}) assert(!parse_acknowledgement(text).valid); assert(!parse_acknowledgement(std::string(0x5000,' ')+valid.dump()).valid); + // Every validation failure exposes a fixed reason and clears response data. + const auto invalid = [](const std::string& text, const std::string& reason) + { + const auto result = parse_acknowledgement(text); + assert(!result.valid && result.reason == reason); + assert(result.state.empty() && result.code.empty() && result.id.empty()); + }; + assert(ack.reason == "ok"); + invalid("", "empty_body"); + invalid(std::string(0x5000, 'x'), "body_limit"); + invalid("secret-token-not-json", "invalid_json"); + invalid("null", "schema"); + invalid("{}", "schema"); + bad = valid; bad["code"] = std::string(65, 'x'); invalid(bad.dump(), "field_limit"); + bad = valid; bad["state"] = "secret-state"; invalid(bad.dump(), "state"); + bad = valid; bad["amount"] = -1; invalid(bad.dump(), "amount_range"); + bad = valid; bad["ok"] = false; invalid(bad.dump(), "ok_state"); + bad = valid; bad["request_id"] = ""; invalid(bad.dump(), "missing_id"); + bad = valid; bad["amount"] = 0; invalid(bad.dump(), "zero_transfer"); + bad = valid; bad["code"] = "private-token\nAuthorization: secret"; + // Compatibility: valid but unknown API codes remain available to callers; + // scripts permit only fixed known codes in diagnostics. + assert(parse_acknowledgement(bad.dump()).valid); { std::ofstream stream(file); stream << "corrupt"; } must_fail([&]{queue.load();}); must_fail([&]{queue.store(body("three","cancel"));}); diff --git a/tools/tests/bank_component_cases.cpp b/tools/tests/bank_component_cases.cpp new file mode 100644 index 0000000..77b65ac --- /dev/null +++ b/tools/tests/bank_component_cases.cpp @@ -0,0 +1,38 @@ + +// Executed with the actual registration adapter and portable engine interfaces. +#include +int main() +{ + bank::component component; + component.on_startup(nullptr); + const auto call = [](const std::string& name, std::vector args = {}) + { + return gsc::function::functions.at(name)(args); + }; + assert(call("bankversion").as() == "1.2.0"); + auto ack = call("bankresponse", {"private-secret-invalid-json"}).as(); + assert(!ack["valid"].as()); + assert(ack["reason"].as() == "invalid_json"); + assert(ack["code"].as().empty()); + assert(call("bankload", {"server", "endpoint"}).is()); + for (int i = 0; i < 2; ++i) + assert(!call("bankstore", {"server", "endpoint", "private-secret Authorization"}).as()); + const std::string body = R"({"server":"server","request_id":"one","decision":"cancel"})"; + assert(call("bankstore", {"server", "endpoint", body}).as()); + const auto root = bank::spool("server", "endpoint"); + assert(root.load().size() == 1); + // Locate only the test process's temporary outbox. + std::filesystem::path file; + for (const auto& entry : std::filesystem::recursive_directory_iterator("tws-bank")) + if (entry.path().extension() == ".json") file = entry.path(); + assert(!file.empty()); + { std::ofstream stream(file); stream << "private-secret-corrupt-journal"; } + for (int i = 0; i < 2; ++i) + { + assert(call("bankload", {"server", "endpoint"}).get_raw().type == game::SCRIPT_NONE); + assert(!call("bankremove", {"server", "endpoint", "one"}).as()); + } + std::filesystem::remove(file); + assert(call("bankload", {"server", "endpoint"}).is()); + assert(call("bankremove", {"server", "endpoint", "one"}).as()); +} diff --git a/versions.json b/versions.json index 302fd96..54f922d 100644 --- a/versions.json +++ b/versions.json @@ -1,6 +1,6 @@ { "tws_t5_afk.gsc": "1.0.0", - "tws_t5_bank.gsc": "2.0.1", + "tws_t5_bank.gsc": "2.0.2", "tws_t5_common.gsc": "1.1.0", "tws_t5_hud.gsc": "1.1.0", "tws_t5_join.gsc": "1.0.0", @@ -8,13 +8,13 @@ "tws_t5_lock.gsc": "1.0.0", "tws_t5_telemetry.gsc": "1.0.0", "tws_t6_afk.gsc": "1.0.0", - "tws_t6_bank.gsc": "2.0.1", + "tws_t6_bank.gsc": "2.0.2", "tws_t6_common.gsc": "1.1.0", "tws_t6_hud.gsc": "1.1.0", "tws_t6_join.gsc": "1.0.1", "tws_t6_leaderboard.gsc": "1.0.0", "tws_t6_lock.gsc": "1.0.0", "tws_t6_telemetry.gsc": "1.0.0", - "t5-plugin": "1.1.0", - "t6-plugin": "1.1.0" + "t5-plugin": "1.2.0", + "t6-plugin": "1.2.0" }