Repository navigation
Description
Follow-up to #104.
Severity: low: c46b500 behaves as #109, #110 and #111 intend; the gaps are in what the suite would catch if that code changed. Likelihood: the four gaps are certain: each mutant passes the whole suite.
I reran the mutants of #104 on c46b500. Of the 16 it lists, 15 now fail a test: the four #87 mutants, both #82 mutants, the three #91 checkpoint mutants, the #67, #89 and public.streams index mutants, and the three #92 timing mutants. I did not recheck the test-name items of #104.
Four mutants pass the whole suite at c46b500. For each one there is a killing test below that passes on c46b500 and fails on the mutant.
-
fix(subscriptions): stop a losing claim from writing the subscription row #90
Storage.Lock: without the{:error, _error} = reply -> replyclause intry_acquire_exclusive_transaction_lock/4, the five lock test files pass. chore(test): close the mutation and naming gaps in the test suite #111 added "a claim returns the error of a statement that cannot take the lock", but that test claims on a schema that does not exist. Since fix(subscriptions): report an unmigrated schema or missing grants from a node that loses every claim, and point upgraders to guides/Upgrades.md #110,claim_subscription_lock/3runsprobe_lock_generation/3first, the probe fails on that schema, and the test never reaches the lock statement. The clause can still be reached: when onlypg_try_advisory_xact_lockis refused, the real code returns the error andAdvisoryLocksstays up, while with the mutantAdvisoryLocksexits withCaseClauseError. -
fix(subscriptions): keep a subscription alive and reading when a read fails while catching up #109
SubscriptionFsm.catch_up_from_stream/2: narrowing the{:error, _error}branch to{:error, %Postgrex.Error{}}passes. Every fix(subscriptions): keep a subscription alive and reading when a read fails while catching up #109 test that makes a read fail does it with a schema that does not exist. The error behind A caught-up subscription exits with CaseClauseError when its catch-up read fails, and is not restarted #101,%DBConnection.ConnectionError{reason: :queue_timeout}from a busy pool, and the string errors of the events query would crash the subscription again, and no test would fail. -
fix(subscriptions): keep a subscription alive and reading when a read fails while catching up #109: replacing
retry_intervalwith0in theProcess.send_after/3call passes. The tests check that a retry arrives, never that it waits. -
fix(subscriptions): keep a subscription alive and reading when a read fails while catching up #109
SubscriptionFsm.retry_catch_up/1: dropping the:catching_upmatch, so that a retry reads in every state, passes, and "ignores a retry for a subscription that is no longer waiting on one" passes with it. That test retries a:subscribedsubscription on an empty stream, where a read changes nothing. Stale retries do happen: the timers are never cancelled, and in my runs every timer still pending when a read succeeded fired afterwards.
The mutants and the runs
# 1. lib/event_store/storage/lock.ex, try_acquire_exclusive_transaction_lock/4
case Postgrex.query(conn, query, [subscription_id], opts) do
{:ok, %Postgrex.Result{rows: [[true]]}} -> :ok
{:ok, %Postgrex.Result{rows: [[false]]}} -> {:error, :lock_already_taken}
- {:error, _error} = reply -> reply
end
# 2. lib/event_store/subscriptions/subscription_fsm.ex, catch_up_from_stream/2
- {:error, _error} ->
+ {:error, %Postgrex.Error{}} ->
# 3. the same branch
- Process.send_after(self(), :retry_catch_up, retry_interval)
+ Process.send_after(self(), :retry_catch_up, 0)
# 4. lib/event_store/subscriptions/subscription_fsm.ex, retry_catch_up/1
- def retry_catch_up(%__MODULE__{state: :catching_up, data: %SubscriptionState{} = data} = fsm) do
+ def retry_catch_up(%__MODULE__{data: %SubscriptionState{} = data} = fsm) do
catch_up_from_stream(fsm, data)
end
- def retry_catch_up(%__MODULE__{} = fsm), do: fsm
-| mutant | target files, seeds 1, 2 and 3 | whole suite, seed 1 |
|---|---|---|
| 1 | 101 passed in each run: storage/subscription_lock_test.exs, advisory_locks_test.exs, advisory_locks_protocol_test.exs, subscriptions/subscription_locking_test.exs, subscriptions/subscription_unmigrated_schema_test.exs |
634 passed |
| 2 | 46 passed in each run: subscriptions/subscription_fsm_test.exs, subscriptions/subscription_catch_up_retry_test.exs, checkout_retries_test.exs |
634 passed |
| 3 | 46 passed in each run, same files | 634 passed |
| 4 | 46 passed in each run, same files | 634 passed |
The whole suite is mix test with the default exclusions: 634 passed (2 doctests, 2 properties, 630 tests), 25 excluded.
Control for mutant 1: with the clause and the probe_lock_generation/3 line both removed, "a claim returns the error of a statement that cannot take the lock" fails with CaseClauseError on undefined_table in seeds 1 to 3 (98 of 101 pass; the other two failures are the tests in subscription_unmigrated_schema_test.exs that need the probe). So the probe running first is what keeps the test away from the clause.
Mutant 1 at store level: I revoked EXECUTE on pg_try_advisory_xact_lock(int, int) from PUBLIC and ran the session mode pool as a role with SELECT and UPDATE on subscriptions, so that the probe passes and only the lock statement fails. With the real code AdvisoryLocks.try_subscription_lock/3 returned {:error, %Postgrex.Error{}} and AdvisoryLocks was still alive 1 s later. With the mutant the call exited and AdvisoryLocks terminated with {:case_clause, {:error, %Postgrex.Error{postgres: %{code: :insufficient_privilege}}}}.
Stale retries: with ten acks during a failed read, eleven :retry_catch_up messages arrived after I removed the cause of the failure. The first one read and succeeded; with the :catching_up match in place the other ten did nothing. With mutant 4 such a retry reads: in the killing tests below it moved a :subscribed and a :max_capacity subscription to :request_catch_up.
The killing tests ran alone, not inside the whole suite, with seeds 1 and 2. On c46b500 all five pass. Against each mutant exactly the intended tests fail: mutant 1 with CaseClauseError, mutant 2 with CaseClauseError on %DBConnection.ConnectionError{reason: :queue_timeout}, mutant 3 with "Unexpectedly received message :retry_catch_up", and mutant 4 fails both stale-retry tests.
Killing test for mutant 1
It creates and drops its own database and role, so that revoking EXECUTE from PUBLIC touches nothing else. DROP DATABASE ... WITH (FORCE) needs PostgreSQL 13 or later.
defmodule EventStore.Storage.MutantKillersLockTest do
use EventStore.StorageCase
alias EventStore.Storage.Lock
@database "eventstore_test_xact_lock_denied"
@role "eventstore_xact_lock_denied"
setup %{conn: conn, postgrex_config: postgrex_config} do
drop = fn ->
Postgrex.query!(conn, ~s|DROP DATABASE IF EXISTS "#{@database}" WITH (FORCE)|, [])
Postgrex.query!(conn, ~s|DROP ROLE IF EXISTS "#{@role}"|, [])
end
drop.()
on_exit(fn -> drop.() end)
Postgrex.query!(conn, ~s|CREATE ROLE "#{@role}" LOGIN PASSWORD 'secret'|, [])
Postgrex.query!(conn, ~s|CREATE DATABASE "#{@database}" TEMPLATE template0|, [])
{:ok, admin} = Postgrex.start_link(Keyword.put(postgrex_config, :database, @database))
Postgrex.query!(
admin,
"CREATE TABLE public.subscriptions (subscription_id bigint PRIMARY KEY, " <>
"lock_generation bigint NOT NULL DEFAULT 0, last_seen bigint)",
[]
)
Postgrex.query!(admin, "INSERT INTO public.subscriptions (subscription_id) VALUES (1)", [])
Postgrex.query!(admin, ~s|GRANT SELECT, UPDATE ON public.subscriptions TO "#{@role}"|, [])
Postgrex.query!(
admin,
"REVOKE EXECUTE ON FUNCTION pg_catalog.pg_try_advisory_xact_lock(integer, integer) FROM PUBLIC",
[]
)
GenServer.stop(admin)
role_config =
Keyword.merge(postgrex_config, database: @database, username: @role, password: "secret")
[role_conn: start_supervised!({Postgrex, role_config}, id: :role_conn)]
end
test "a claim returns the error when only the advisory lock statement is refused", context do
assert {:error, %Postgrex.Error{postgres: %{code: :insufficient_privilege} = postgres}} =
Lock.claim_subscription_lock(context.role_conn, 1, schema: "public")
assert postgres.message =~ "pg_try_advisory_xact_lock"
end
endKilling tests for mutants 2, 3 and 4
In the pool test the read waits in the pool queue until DBConnection drops it, 5 430 ms in my run, and query_timeout: 100 does not shorten that wait.
defmodule EventStore.Subscriptions.MutantKillersFsmTest do
use EventStore.StorageCase
alias EventStore.{EventFactory, Storage, UUID}
alias EventStore.Storage.Lock
alias EventStore.Subscriptions.{SubscriptionFsm, SubscriptionState}
setup context do
stream_uuid = UUID.uuid4()
subscription_name = UUID.uuid4()
{:ok, %Storage.Subscription{subscription_id: subscription_id}} =
Storage.subscribe_to_stream(context.conn, stream_uuid, subscription_name,
schema: context.schema
)
{:ok, %Lock.Lease{token: fencing_token}} =
Lock.claim_subscription_lock(context.conn, subscription_id, schema: context.schema)
on_exit(fn -> :ok = Lock.unlock(context.conn, subscription_id, schema: context.schema) end)
[
stream_uuid: stream_uuid,
subscription_name: subscription_name,
subscription_id: subscription_id,
fencing_token: fencing_token
]
end
test "a read that fails because the pool has no connection to give is retried", context do
%{conn: conn} = context
fsm = fsm(context, state: :request_catch_up, retry_interval: 20, query_timeout: 100)
test_pid = self()
holder =
Task.async(fn ->
Postgrex.transaction(conn, fn _held ->
send(test_pid, :connection_held)
receive do: (:release -> :ok)
end)
end)
assert_receive :connection_held, 5_000
assert %SubscriptionFsm{state: :catching_up} = SubscriptionFsm.catch_up(fsm)
assert_receive :retry_catch_up, 1_000
send(holder.pid, :release)
assert {:ok, :ok} = Task.await(holder)
end
test "the wait before the next read is not shorter than the retry interval", context do
fsm =
fsm(context,
state: :request_catch_up,
schema: "no_such_schema",
retry_interval: 5_000
)
assert %SubscriptionFsm{state: :catching_up} = SubscriptionFsm.catch_up(fsm)
refute_receive :retry_catch_up, 300
end
for state <- [:subscribed, :max_capacity] do
test "a stale retry leaves a #{state} subscription alone even with events to read", context do
fsm = fsm(context, state: unquote(state))
fsm = SubscriptionFsm.connect_subscriber(fsm, self(), buffer_size: 10)
:ok = TestEventStore.append_to_stream(context.stream_uuid, 0, EventFactory.create_events(3))
assert ^fsm = SubscriptionFsm.retry_catch_up(fsm)
refute_received {:events, _events}
end
end
defp fsm(context, overrides) do
data = %SubscriptionState{
conn: context.conn,
schema: Keyword.get(overrides, :schema, context.schema),
stream_uuid: context.stream_uuid,
subscription_name: context.subscription_name,
subscription_id: context.subscription_id,
fencing_token: context.fencing_token,
last_ack: 0,
checkpoints_pending: 0,
checkpoint_after: 0,
checkpoint_threshold: 1,
retry_interval: Keyword.get(overrides, :retry_interval, 60_000),
query_timeout: Keyword.get(overrides, :query_timeout, 15_000),
event_store: TestEventStore,
serializer: context.serializer,
correlation_id_type: context.correlation_id_type,
causation_id_type: context.causation_id_type,
max_size: 1_000,
last_received: 0,
last_sent: 0,
transient: false
}
%SubscriptionFsm{state: Keyword.fetch!(overrides, :state), data: data}
end
end
Activity