fix: clear the open defect backlog (#334, #348, #312, #313, #357) - #370
Merged
Conversation
count_before/2 walks ETS keys ({-Score, PlayerId}); entries_around/3 handed
it the first entry's player id instead. No key ever matched, so the walk ran
to '$end_of_table' and every rank in the window started at BoardSize + 1.
Derive the start rank from the queried player's own key and step back by the
number of entries that precede them in the window, which also stays correct
when the window is truncated at either end of the board.
Closes #334
…#348) The wall-clock timeout kills a spinning callback at its deadline and the script simply spins again on the next tick, holding a scheduler for its full budget forever. luerl_sandbox:run/3 offers a reduction limit upstream but only over luerl:do/2; asobi's hot path is luerl:call_function/3 against an already-loaded state, so the poll goes into bounded_eval/2, which already spawned and monitored the worker. The budget is asobi_lua.max_reductions_per_ms (50,000) times the callback's own wall-clock budget, so it scales with a surface that spans 50 ms (think) to 5000 ms (generate_world). The rate is measured against Luerl: a 200-entity tick costs ~24k reductions while a spin sustains ~284k per ms, so the budget sits ~1000x above a normal tick and cuts a spin at ~18% of its window. Rate 0 restores the previous single-receive behaviour exactly. Overrun is {error, reductions_exhausted} - a distinct tag for the log, but handled by the same caller clause as a timeout: the result is discarded, the previous Lua state kept, the tick skipped. Killing a match because one callback overran would be worse than the spin it prevents. Closes #348
…rld loop #312: setup/0's attach list was hand-maintained beside the emitters and had drifted to 24 of 35 events. The eleven it missed were - auth_cache aside - exactly the failure and abuse signals someone turns the debug logger on to find: rate limits, anticheat violations, rejected origins, [asobi, error]. The list moves to an exported events/0 so a consumer attaches to the surface without restating it (restating it is how the drift happened, and how opentelemetry_asobi got the same stale copy), and a test derives the emitted set from the module's own compiled abstract code and asserts the two match. #313: asobi_world_ticker, asobi_zone_manager and asobi_zone_spawner emitted nothing, so an operator could not see how long a world tick takes or how many zones a node carries. Adds [asobi, world, tick] and the [asobi, zone, opened | closed] pair. world/tick is sampled - 20 events/s/world raw is too hot for a sink - so it carries max_duration_ms for the sampled window next to the sampled tick's own duration_ms, because a sampled duration alone hides the spikes worth paging on. zone/closed is gated on the zone still being in the manager's table: cleanup_zone/2 is reachable twice for the same coords, and a gauge built from opened minus closed would drift negative. Additive under ADR 0005, which is updated for the new events and the closed gaps. Closes #312
asobi_iap_SUITE inserted iap_transactions with a fixed 'txn-1' and never deleted it. The table is unique on (provider, transaction_id), so the first run passed and every later run against the same database got a 409. CI never saw it because CI gets a fresh database, which is why it survived three weeks costing only local developers - and looking like a regression in whatever unrelated work happened to be in flight. Sweeping the other suites for the same shape turned up a second, quieter cause: erlang:unique_integer/1 is unique within one runtime instance, and each rebar3 ct run is a new one, so two runs hand out the same low integers. Anything keyed on it was never run-unique despite comments saying so. That covers oauth's provider_uid (unique on (provider, provider_uid)), the store's item_defs.slug, and the global storage row (unique on (collection, key) where player_id IS NULL). asobi_oauth_SUITE was in fact already failing on a first run here for exactly this reason. Adds asobi_test_helpers:unique_id/1 (random bytes, like the existing unique_username/1) and points those fixtures at it, which also lets the suites run concurrently with themselves - something an end_per_testcase cleanup would not. asobi_lua_storage_SUITE had grown a private copy of the same helper; it now shares this one. Closes #357
bounded_eval/2 is private, and the ADR tree is not in ex_doc's extras, so neither resolved as a link.
asobi_zone_manager does not trap exits, so a supervisor shutdown kills it without running terminate/2, and asobi_world_instance stops the manager before the zone supervisor, so it never processes the zones' DOWNs either. An emit in terminate/2 would have been dead code. Pin the real behaviour in a test and document in ADR 0005 that a live-zone gauge has to be keyed on world_id and dropped on [asobi, world, finished], rather than being one global counter pair. Making the manager trap exits to close the difference is a supervision-tree change with its own shutdown-latency cost and is deliberately not made here.
🟡 Code Coverage — 74.5%6450 of 8661 lines covered. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Five open defects, none related to each other in code. One PR because they are all small, they touch disjoint files, and splitting them into five would cost five review contexts for one afternoon's backlog. Each is its own commit, so they read independently and revert independently.
Closes #334
Closes #348
Closes #312
Closes #313
Closes #357
#334 -
around/3ranks were offset by the size of the boardcount_before/2walks theordered_setcomparing ETS keys ({-Score, PlayerId});entries_around/3handed it the first entry's player id. No key ever equals a player id, so the walk always ran to'$end_of_table'and returned the board size - every rank in the window was numbered fromBoardSize + 1.GET /api/v1/leaderboards/:id/around/:player_idserved those ranks straight to clients, so an "around me" panel showed every player a rank worse than they are, disagreeing with the rank the same player got back fromsubmit.The fix derives the start rank from the queried player's own key and steps back by the number of entries that precede them in the window, which stays correct when the window is truncated at either end of the board.
Tests: 2 new cases (
around_ranks_are_absolute,around_at_board_edges), both fail on the old code and pass on the new. The first also cross-checksaround/3againstrank/2for all 10 players. The pre-existingaround_querypasses either way - it only assertslength(Entries) =:= 5, which is why the defect survived.#348 - reduction budget on Lua callbacks
The wall-clock timeout bounds latency, not work: a spinning callback is killed at its deadline and then does it again on the next tick, holding a scheduler for its full budget forever.
luerl_sandbox:run/3offers a reduction limit upstream, but only overluerl:do/2; asobi's hot path isluerl:call_function/3against an already-loaded state, so the poll went intobounded_eval/2, which already spawned and monitored the worker.What the budget is.
asobi_lua.max_reductions_per_ms(default 50,000) times that callback's own wall-clock budget. Per-ms rather than absolute because the surface spans 50 ms (think) to 5000 ms (generate_world) and scaling keeps their relative weights. The rate is measured, not guessed: a 200-entity tick costs ~24k reductions in total, a spin sustains ~284k reductions/ms, so the budget sits ~1000x above a normal tick and cuts a spin at roughly 18% of its wall-clock window. Setting it to0restores the previous single-receivebehaviour exactly.What happens when it is exceeded. The same thing that happens on a timeout: the result is discarded, the previous Luerl state is kept, the error is logged, and the tick is skipped. The callers already have a catch-all clause next to their
{error, timeout}clause, so no match or zone is ever torn down for this - killing a match because one callback overran would be worse than the spin it prevents.reductions_exhaustedis a distinct tag purely so an operator can tell "burned CPU" from "was slow" and from "allocated too much" in a log line.Sampled every 10 ms, so overshoot is bounded by one interval - the budget bounds sustained CPU, not the instantaneous peak.
handle_input/3is still unbounded by design (ADR 0002: it runs in the calling process, no child).guides/security-lua-known-limitations.mdchanges again: the section is no longer "the reduction limit Luerl offers is not applied" but "the CPU bound is sampled, not exact", and now documents the knob, the failure mode, and the two remaining limits.guides/self-hosting.mdgains the config row.Tests: 4 new.
reduction_budget_kills_spin_before_deadline_testis the one that fails on the old code (1 failure when the loader change is reverted). Stated plainly:reduction_budget_disabled_falls_back_to_timeout_testis a negative control and passes either way by design.reduction_budget_passes_normal_callback_testalso passes either way - it is a regression guard that the default rate does not kill legitimate work, not coverage of the new bound.reduction_exhaustion_renders_distinctly_testcovers the newformat_reason/1clause and fails without it.Three existing tests asserted
{error, timeout}on a spinning callback and now accept either bound, because which one fires first is machine-dependent. Their intent (the parent is not wedged; the callback is killed) is unchanged.#312 - the debug logger attached 24 of 35 events
The attach list was hand-maintained beside the emitters and had drifted. The eleven it missed were -
auth_cacheaside - exactly the failure and abuse signals someone turns the debug logger on to find: rate limits, anticheat violations, rejected origins,[asobi, error]itself.The list moves to an exported
asobi_telemetry:events/0, so a consumer attaches to the whole surface without restating it. Restating it is how the drift happened, and howopentelemetry_asobiended up with the same stale copy - that repo should now switch toevents/0(out of scope here, noted in the ADR).Tests:
attach_list_covers_every_emitted_event_testderives the emitted set from the module's own compiled abstract code (every literal event name passed totelemetry:execute/3) and asserts set equality both ways, so a new emitter without a matching entry fails the build. Verified by deleting[asobi, error]fromevents/0: the test fails. Plussetup_attaches_a_handler_to_every_event_test.#313 - no world-loop telemetry
asobi_world_ticker,asobi_zone_managerandasobi_zone_spawneremitted nothing. Adds[asobi, world, tick]and the[asobi, zone, opened | closed]pair.asobi_zone_spawneris a pure entity-template registry, not a zone lifecycle owner, and still emits nothing by design.Settling the shape the issue left open:
world/tickmeasures the full fan-out/fan-in cycle (dispatch to every zone, then the lasttick_done), which is the thing that degrades under entity load. Measurements#{duration_ms, max_duration_ms, zone_count, count}, metadata#{world_id}. Sampled - 20 events/s/world raw is too hot for a sink - roughly once a second (tick_sample_interval_ms/ tick rate). It carriesmax_duration_msfor the sampled window because a sampled duration alone hides exactly the spikes worth paging on.entity_countfrom the issue's sketch is not available at the ticker;zone_countis what it actually fans out to. A tick that never fans in (a zone died mid-tick) is not sampled rather than reported with a fabricated duration.zone/opened/zone/closedare a counter pair, since zones are lazy and a live count is not derivable from world count.closedis gated on the zone still being in the manager's ETS table, becausecleanup_zone/2is reachable more than once for the same coords - otherwise a gauge drifts negative.The gauge can still drift upward, and I could not honestly fix it here. A world teardown emits no
closedat all:asobi_zone_managerdoes not trap exits, so a supervisor shutdown kills it without runningterminate/2, andasobi_world_instancestops the manager before the zone supervisor, so it never processes the zones'DOWNs either. My first attempt put the emit interminate/2; the test I wrote for it failed, which is how I found this. Making the manager trap exits would close the gap but is a supervision-tree change with its own shutdown-latency cost, so it is documented instead: key the gauge onworld_idand drop a world's counters on[asobi, world, finished]. Both the ADR and a test now pin that.ADR 0005 is updated: new events documented,
coordsclassified unbounded, the count moves 35 -> 38, the gauge caveat recorded, and the two "known gaps" entries struck through. Additive, so a minor bump under the ADR's stability rule.Tests: 6 new (3 ticker, 3 zone manager). 5 fail when the emitters are reverted. The 6th,
manager_shutdown_emits_no_close, passes either way - it pins the documented limitation above so the ADR and the code cannot disagree silently, and is not coverage of the new events.Worth noting for anyone writing telemetry tests here: eunit's per-test process exiting
normaldoes not kill astart_linked gen_server, so a previous test's ticker keeps emitting into the next test's subscription. The subscriptions filter onworld_id/coordsfor that reason; the sampling test was green, then red, until I found it.#357 - suites leaving uniquely-constrained rows behind
asobi_iap_SUITEinsertediap_transactionswith a fixedtxn-1and never deleted it. The table is unique on(provider, transaction_id), so the first run passed and every later run against the same database got a 409. CI never saw it because CI gets a fresh database - which is why it survived three weeks costing only local developers, and looking like a regression in whatever unrelated work happened to be in flight.The sweep found a second, quieter cause.
erlang:unique_integer([positive])is unique within one runtime instance, and eachrebar3 ctrun is a new one, so two runs hand out the same low integers (measured: three fresh VMs, two produced the identical2242, 2306, 2370). Anything keyed on it was never run-unique despite comments inasobi_storage_SUITEclaiming exactly that. Affected fixtures under a unique index:asobi_oauth_SUITE-provider_uid, unique on(provider, provider_uid). This suite was already failing on a first run here, for this reason.asobi_store_SUITE-item_defs.slug.asobi_storage_SUITE- the global row (player_id IS NULL), unique on(collection, key).Also swept and cleared:
group_members,wallets,friendships,cloud_saves,leaderboard_entries,zone_snapshots,players.username- all keyed on a per-run player id, uuid, or the existing randomunique_username/1, so none can collide across runs.Adds
asobi_test_helpers:unique_id/1(random bytes, like the existingunique_username/1). Preferred over anend_per_testcasecleanup because it also lets a suite run concurrently with itself, which cleanup does not.asobi_lua_storage_SUITEhad grown a private copy of the same helper; it now shares this one.Evidence: before, the first run of
iap + storage + store + oauthfailed 2 tests on a database that already had leftovers. After, three consecutive runs pass 59/59. The two unit tests onunique_id/1are shape only, and say so in a comment - the cross-run property cannot be asserted from inside one run, and a peer-node test showingunique_integercolliding is flaky in both directions, so I dropped it rather than count it as coverage.Checks
All green on the final tree:
rebar3 fmt --check,xref,dialyzer,ex_doc(zero warnings - it caught two bad references in this branch, both fixed), fulleunit(1511 tests, 0 failures), andctfor every suite touched (65 tests, 0 failures).One process note, since it produced a red herring mid-way: running
rebar3 ctandrebar3 eunitconcurrently in the same worktree corrupts_buildand surfaces as an unrelatedundefonasobi_rate_limit_plugin. All the numbers above come from serial runs.Not done
Taure/erlang-ci, out of scope.opentelemetry_asobistill carries its own copy of the stale 24-name list. Different repo;events/0now exists for it to use.session/disconnected,ws/message_out,store/purchase,anticheat/violation) are now attached along with everything else. Still no emitters - ADR 0005 already warns not to read silence onanticheat/violationas "no cheating".