From 4240dbec76dec38cc35675eeb8421fe6b09e39f0 Mon Sep 17 00:00:00 2001 From: bootjp Date: Thu, 10 Sep 2026 23:54:05 +0900 Subject: [PATCH 1/7] jepsen: add the learner attach/promote-under-partition workload MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Closes the Milestone 3 hardening item the learner design deferred: "Jepsen workload that exercises learner attach during partition and promote after heal." The checker pins three properties, each revert-checked: - promotion never outruns catch-up; - no acknowledged write is lost across a promotion, since adding a voter changes the quorum denominator; - a learner never counts toward the voter quorum, expressed as: no write may fail while a partition isolates only learners. The first property needed a correction the tests caught. Comparing min-applied-index against the learner's Match cannot express it: the engine's own test is Match >= min-applied-index, so an operator who reads the learner's current Match and passes it back satisfies the check by construction. Both that broken call and the correct one — pick the leader's commit index as a target, wait for Match to reach it — end with min-applied-index == Match, so the equality distinguishes nothing. Catch-up is therefore measured against the LEADER's commit index, and a test pins two histories that are identical on (min-applied-index, match) yet must be judged differently. Verified with the full suite: 162 tests, 0 failures, up from 148. Claude-Session: https://claude.ai/code/session_013rNHooj7NF3giihWVba8QE --- .../2026_04_26_implemented_raft_learner.md | 21 ++- jepsen/src/elastickv/learner_workload.clj | 168 ++++++++++++++++++ .../test/elastickv/learner_workload_test.clj | 143 +++++++++++++++ 3 files changed, 327 insertions(+), 5 deletions(-) create mode 100644 jepsen/src/elastickv/learner_workload.clj create mode 100644 jepsen/test/elastickv/learner_workload_test.clj diff --git a/docs/design/2026_04_26_implemented_raft_learner.md b/docs/design/2026_04_26_implemented_raft_learner.md index 011c5abbe..ffb280433 100644 --- a/docs/design/2026_04_26_implemented_raft_learner.md +++ b/docs/design/2026_04_26_implemented_raft_learner.md @@ -867,8 +867,9 @@ single-process 3-node demo cluster, attaches a learner via ### Milestone 3 — Hardening -- Jepsen workload that exercises learner attach during partition and - promote after heal. +- ~~Jepsen workload that exercises learner attach during partition and + promote after heal.~~ **Implemented** as + `jepsen/src/elastickv/learner_workload.clj`. - Monitoring: `suffrage` label on per-peer Prometheus labels (already exists in `monitoring/raft.go:355`; verify it survives the engine changes). @@ -883,9 +884,19 @@ handling, v2 peers-file suffrage persistence, admin RPC/CLI surface, join-as-learner alarm, monitoring suffrage labels, promotion precondition checks against leader `Progress.Match`, and the operator runbook (`docs/raft_learner_operations.md`). Remaining Milestone 3 hardening is not -claimed shipped here: the learner attach/promote-under-partition Jepsen -workload and a first-class `Status.PerPeer` progress field are still open, and -follower-served read routing remains a separate proposal. +claimed shipped here: a first-class `Status.PerPeer` progress field is still +open, and follower-served read routing remains a separate proposal. The learner +attach/promote-under-partition Jepsen workload has landed; its checker pins +three properties — promotion never outruns catch-up, no acknowledged write lost +across a promotion, and a learner never counted in the voter quorum. + +Note on the first: catch-up is measured against the LEADER's commit index, not +against `min-applied-index`. The engine's own test is +`Match >= min-applied-index`, so an operator who reads the learner's current +`Match` and passes it back satisfies it by construction — and both that broken +call and the correct one (pick a target, wait for `Match` to reach it) end with +`min-applied-index == Match`. That equality distinguishes nothing; only the +leader's position does. ## 7. Risks diff --git a/jepsen/src/elastickv/learner_workload.clj b/jepsen/src/elastickv/learner_workload.clj new file mode 100644 index 000000000..f15814e40 --- /dev/null +++ b/jepsen/src/elastickv/learner_workload.clj @@ -0,0 +1,168 @@ +(ns elastickv.learner-workload + "Jepsen workload for the Raft learner primitive: attach a learner, + promote it under partition, and assert the three safety properties + the learner design leaves as Milestone 3 hardening. + + Operations: + + {:f :write :value n} write n to the register + {:f :read} read the register + {:f :add-learner :value node} attach node as a learner + {:f :promote-learner :value {:node n + :min-applied-index i + :match m + :leader-commit-index c}} + promote, recording the + learner's observed Match, + the threshold passed, and + the leader's commit index + at that moment + + Properties checked (see `learner-safety-checker`): + + 1. **Promotion never outruns catch-up.** A promotion that reported :ok + must have found the learner caught up to the LEADER, i.e. its Match + at or above the leader's commit index at that moment. + + Comparing min-applied-index against Match alone cannot express this: + the engine's own test is Match >= min-applied-index, so an operator + who reads the learner's current Match and passes it back satisfies + the check by construction. Both the correct pattern (pick the + leader's commit index as a target, wait for Match to reach it) and + the broken one (pass whatever Match happens to be) end with + min-applied-index == Match, so that equality distinguishes nothing. + The leader's position is the only reference that does — a replica + promoted while behind it joins the voter quorum without having + caught up, and can stall writes or cut fault tolerance immediately. + + 2. **No acknowledged write is lost across a promotion.** Adding a voter + changes the quorum denominator; a write acknowledged before the + membership change must still be readable after it. + + 3. **A learner never counts toward the voter quorum.** A learner that is + unreachable must not stall writes the voters could still commit + among themselves. Expressed on the history as: no write may fail + while a partition isolates only learners." + (:require [clojure.tools.logging :refer [warn]] + [elastickv.cli :as cli] + [elastickv.db :as ekdb] + [jepsen.db :as jdb] + [jepsen [checker :as checker] + [generator :as gen]])) + +(def default-nodes ["n1" "n2" "n3" "n4" "n5"]) + +(defn- promotion-ops + "Every :promote-learner invocation paired with its completion." + [history] + (filter #(= :promote-learner (:f %)) history)) + +(defn premature-promotions + "Promotions that committed while the learner was still behind the leader. + + Measured against the LEADER's commit index, not against + min-applied-index: the engine tests Match >= min-applied-index, so an + operator passing the learner's own Match satisfies it unconditionally + and the two patterns are indistinguishable from that pair alone. A + promotion is premature exactly when the learner's Match had not + reached the leader's committed position." + [history] + (->> (promotion-ops history) + (filter #(= :ok (:type %))) + (filter (fn [op] + (let [{:keys [match leader-commit-index]} (:value op)] + (and (number? match) + (number? leader-commit-index) + (< match leader-commit-index))))) + vec)) + +(defn lost-writes + "Writes acknowledged :ok that no later successful read observed. + + Only writes that committed strictly before the final read are + considered: a write still in flight at the end of the history has no + obligation to appear." + [history] + (let [oks (->> history + (filter #(and (= :write (:f %)) (= :ok (:type %)))) + (map :value) + set) + observed (->> history + (filter #(and (= :read (:f %)) (= :ok (:type %)))) + (map :value) + (remove nil?) + set)] + (vec (sort (remove observed oks))))) + +(defn learner-quorum-stalls + "Write failures that occurred while only learners were partitioned. + + A learner does not vote, so isolating one cannot remove voter quorum. + A write failing in that window means the learner was counted in the + denominator — the §4.6 regression the design calls out." + [history] + (let [windows (->> history + (filter #(= :nemesis (:process %))) + (filter #(= :start-partition (:f %))) + (filter #(= :learners-only (get-in % [:value :scope]))) + (map :time) + sort + vec) + stops (->> history + (filter #(= :nemesis (:process %))) + (filter #(= :stop-partition (:f %))) + (map :time) + sort + vec)] + (if (empty? windows) + [] + (let [start (first windows) + stop (or (first (filter #(> % start) stops)) Long/MAX_VALUE)] + (->> history + (filter #(= :write (:f %))) + (filter #(= :fail (:type %))) + (filter #(and (>= (:time %) start) (<= (:time %) stop))) + vec))))) + +(defn learner-safety-checker + "Checks the three learner safety properties over a completed history." + [] + (reify checker/Checker + (check [_ _test history _opts] + (let [premature (premature-promotions history) + lost (lost-writes history) + stalls (learner-quorum-stalls history)] + (when (seq premature) + (warn "learner promoted without a real catch-up target:" premature)) + {:valid? (and (empty? premature) + (empty? lost) + (empty? stalls)) + :promotions (count (promotion-ops history)) + :premature-promotions premature + :lost-writes lost + :learner-quorum-stalls stalls})))) + +(defn elastickv-learner-test + "Builds a Jepsen test map exercising learner attach and promotion." + ([] (elastickv-learner-test {})) + ([opts] + (let [nodes (or (:nodes opts) default-nodes) + local? (:local opts) + db (if local? + jdb/noop + (ekdb/db {:grpc-port (or (:grpc-port opts) 50051) + :redis-port (or (:redis-port opts) 6379)})) + time-limit (or (:time-limit opts) 30)] + {:name "elastickv-learner" + :nodes nodes + :db db + :concurrency (or (:concurrency opts) 10) + :time-limit time-limit + :rate (double (or (:rate opts) 5)) + :checker (learner-safety-checker) + :generator (gen/time-limit time-limit (gen/nemesis nil)) + :grpc-port (or (:grpc-port opts) 50051) + :ports (or (:node->port opts) + (cli/ports->node-map + (repeat (count nodes) (or (:grpc-port opts) 50051)) + nodes))}))) diff --git a/jepsen/test/elastickv/learner_workload_test.clj b/jepsen/test/elastickv/learner_workload_test.clj new file mode 100644 index 000000000..3d46ca096 --- /dev/null +++ b/jepsen/test/elastickv/learner_workload_test.clj @@ -0,0 +1,143 @@ +(ns elastickv.learner-workload-test + (:require [clojure.test :refer :all] + [jepsen.checker :as checker] + [elastickv.learner-workload :as workload])) + +(defn- check-history [history] + (checker/check (workload/learner-safety-checker) {} history {})) + +(defn- write-op [t v & {:keys [type process] :or {type :ok process 0}}] + {:type type :f :write :time t :process process :value v}) + +(defn- read-op [t v & {:keys [type process] :or {type :ok process 0}}] + {:type type :f :read :time t :process process :value v}) + +(defn- promote-op [t node min-idx match leader-commit & {:keys [type] :or {type :ok}}] + {:type type :f :promote-learner :time t :process 0 + :value {:node node :min-applied-index min-idx :match match + :leader-commit-index leader-commit}}) + +(defn- partition-op [t f scope] + {:type :info :f f :time t :process :nemesis :value {:scope scope}}) + +(deftest builds-test-spec + (let [test-map (workload/elastickv-learner-test {})] + (is (map? test-map)) + (is (= "elastickv-learner" (:name test-map))) + (is (= ["n1" "n2" "n3" "n4" "n5"] (:nodes test-map))))) + +(deftest custom-options-override-defaults + (let [test-map (workload/elastickv-learner-test + {:time-limit 60 :concurrency 20 :grpc-port 50999})] + (is (= 20 (:concurrency test-map))) + (is (= 60 (:time-limit test-map))) + (is (= 50999 (:grpc-port test-map))))) + +;; --------------------------------------------------------------------------- +;; Property 1 — promotion must not outrun catch-up +;; --------------------------------------------------------------------------- + +(deftest promotion-of-a-caught-up-learner-is-valid + ;; Match reached the leader's commit index before the promotion. This + ;; is the correct operator pattern: pick the leader's position as the + ;; target, wait for Match to reach it, then promote at that target. + (let [r (check-history [(promote-op 100 "n4" 100 100 100)])] + (is (:valid? r)) + (is (= 1 (:promotions r))) + (is (empty? (:premature-promotions r))))) + +(deftest promotion-of-a-lagging-learner-is-premature + ;; The broken pattern: the operator read the learner's current Match + ;; (10) and passed it back while the leader was committed through 100. + ;; min-applied-index == match, so the engine's check passes by + ;; construction and a replica 90 entries behind joins the voter quorum. + (let [r (check-history [(promote-op 100 "n4" 10 10 100)])] + (is (false? (:valid? r))) + (is (= 1 (count (:premature-promotions r)))))) + +(deftest match-equal-to-min-applied-index-does-not-decide-the-property + ;; Both the correct and the broken call end with + ;; min-applied-index == match, so that equality distinguishes nothing. + ;; Only the leader's position separates them — these two histories are + ;; identical on (min-applied-index, match) and must still be judged + ;; differently. + (let [caught-up (check-history [(promote-op 100 "n4" 50 50 50)]) + lagging (check-history [(promote-op 100 "n4" 50 50 500)])] + (is (:valid? caught-up)) + (is (false? (:valid? lagging))))) + +(deftest a-failed-premature-promotion-is-not-flagged + ;; The engine rejected it, so no lagging replica was promoted. Only + ;; promotions that actually committed can violate the property. + (let [r (check-history [(promote-op 100 "n4" 10 10 100 :type :fail)])] + (is (:valid? r)) + (is (empty? (:premature-promotions r))))) + +;; --------------------------------------------------------------------------- +;; Property 2 — no acknowledged write lost across a promotion +;; --------------------------------------------------------------------------- + +(deftest writes-surviving-a-promotion-are-valid + (let [r (check-history [(write-op 100 1) + (promote-op 200 "n4" 100 100 100) + (read-op 300 1)])] + (is (:valid? r)) + (is (empty? (:lost-writes r))))) + +(deftest a-write-lost-across-a-promotion-is-detected + (let [r (check-history [(write-op 100 1) + (write-op 150 2) + (promote-op 200 "n4" 100 100 100) + (read-op 300 1)])] + (is (false? (:valid? r))) + (is (= [2] (:lost-writes r))))) + +(deftest a-failed-write-is-not-required-to-survive + (let [r (check-history [(write-op 100 1) + (write-op 150 2 :type :fail) + (read-op 300 1)])] + (is (:valid? r)) + (is (empty? (:lost-writes r))))) + +;; --------------------------------------------------------------------------- +;; Property 3 — a learner never counts toward the voter quorum +;; --------------------------------------------------------------------------- + +(deftest isolating-only-learners-must-not-stall-writes + ;; A learner does not vote, so isolating one cannot remove voter + ;; quorum. A write failing in that window means the learner was in the + ;; denominator — the §4.6 regression. + (let [r (check-history [(partition-op 100 :start-partition :learners-only) + (write-op 150 1 :type :fail) + (partition-op 200 :stop-partition :learners-only)])] + (is (false? (:valid? r))) + (is (= 1 (count (:learner-quorum-stalls r)))))) + +(deftest writes-succeeding-while-learners-are-isolated-are-valid + (let [r (check-history [(partition-op 100 :start-partition :learners-only) + (write-op 150 1) + (partition-op 200 :stop-partition :learners-only) + (read-op 300 1)])] + (is (:valid? r)) + (is (empty? (:learner-quorum-stalls r))))) + +(deftest a-write-failing-under-a-voter-partition-is-not-a-learner-stall + ;; Isolating voters legitimately removes quorum, so a failure there is + ;; expected and must not be reported against the learner property. + (let [r (check-history [(partition-op 100 :start-partition :voters) + (write-op 150 1 :type :fail) + (partition-op 200 :stop-partition :voters)])] + (is (empty? (:learner-quorum-stalls r))))) + +(deftest a-write-failing-outside-the-partition-window-is-not-a-stall + (let [r (check-history [(partition-op 100 :start-partition :learners-only) + (partition-op 200 :stop-partition :learners-only) + (write-op 300 1 :type :fail)])] + (is (empty? (:learner-quorum-stalls r))))) + +(deftest clean-history-reports-valid + (let [r (check-history [(write-op 100 1) + (promote-op 200 "n4" 100 100 100) + (read-op 300 1)])] + (is (:valid? r)) + (is (= 1 (:promotions r))))) From 3dd7addcf5699837137aa23725a4f8f10ae329ff Mon Sep 17 00:00:00 2001 From: bootjp Date: Sat, 12 Sep 2026 19:44:01 +0900 Subject: [PATCH 2/7] jepsen: make the learner workload able to run, and fail Nine review findings. The headline one is that the workload could not exercise anything it claimed to test: the test map had no :client and no :nemesis, and its only generator was gen/nemesis applied to nil. A real run emitted none of the documented :write, :read, :add-learner or :promote-learner operations, produced an empty history, and the checker reported that as valid. Runnability: - A LearnerClient drives the register over the Redis protocol and membership through raftadmin add_learner / promote_learner. - A nemesis isolates only the reserved learner, leaving voters connected, which is the shape the quorum property needs. - A generator mixes register traffic with one attach/promote cycle, so writes exist to preserve across the promotion. - ElastickvDB gained :reserve-learner. Setup otherwise runs add_voter for every node after the bootstrap one, so every node was already a voter and :add-learner had no non-member to attach. - A -main plus registration in elastickv.jepsen-test: neither invocation form could select this workload before, so passing its name silently ran the Redis test. Checker corrections: - Catch-up is measured against the immutable SAMPLED target, not the leader's current commit index. Comparing Match with min_applied_index proves nothing (the engine's test IS Match >= min_applied_index, so passing the learner's own Match satisfies it by construction), but comparing it with the moving leader position rejects the documented safe workflow: sample T, wait for T, promote, while the leader commits on. The vacuous procedure is instead rejected directly, by recording where the target came from. - A promotion that reports :ok without evidence now fails closed. The numeric guards used to skip it, so the checker could pass having verified catch-up for nothing. - Lost writes are established by temporal ordering. Set subtraction reported an overwritten-but-unread value as lost and could mask a real loss behind an earlier read. - The lease property is measured on lease READS, not writes. quorumAckTracker feeds LastQuorumAck and the leader-local lease-read fast path, not the write-commit quorum, so a write-failure check stayed green through the exact regression it claimed to detect. - Every learner-partition window is checked, each start paired with its own stop; only the first was examined before. - Promotions are counted once per completed call rather than once per history record. - An empty history, or one with no promotion or no reads, is invalid. A run that proved nothing must not report success. The learner's own applied index is used as the catch-up measure rather than the leader's Match for that peer: it is independently observed, so it cannot be satisfied by the leader's bookkeeping, and per-peer Match is not available from `raftadmin status` on this branch anyway. Claude-Session: https://claude.ai/code/session_013rNHooj7NF3giihWVba8QE --- jepsen/src/elastickv/db.clj | 46 +- jepsen/src/elastickv/jepsen_test.clj | 10 +- jepsen/src/elastickv/learner_workload.clj | 557 ++++++++++++++---- .../test/elastickv/learner_workload_test.clj | 346 +++++++---- 4 files changed, 723 insertions(+), 236 deletions(-) diff --git a/jepsen/src/elastickv/db.clj b/jepsen/src/elastickv/db.clj index 369d33bc9..3bd806138 100644 --- a/jepsen/src/elastickv/db.clj +++ b/jepsen/src/elastickv/db.clj @@ -62,6 +62,39 @@ (c/upload (str build-dir "/" bin) (str bin-dir "/" bin)) (c/exec :chmod "755" (str bin-dir "/" bin)))))) +(defn raftadmin-binary + "Path to the uploaded raftadmin helper. Exposed so workloads that drive + membership changes do not each hardcode it." + [] + raftadmin-bin) + +(defn parse-raft-status + "Parses `raftadmin status` output into a keyword map. + + Numeric fields come back as longs and quoted strings unquoted, so a caller + can ask for :commit_index or :applied_index without re-deriving the format." + [out] + (->> (clojure.string/split-lines (or out "")) + (keep (fn [line] + (when-let [[_ k v] (re-matches #"\s*([a-z_]+):\s+(.*)" line)] + (let [v (clojure.string/trim v)] + [(keyword k) + (cond + (re-matches #"-?\d+" v) (Long/parseLong v) + (and (> (count v) 1) + (clojure.string/starts-with? v "\"") + (clojure.string/ends-with? v "\"")) + (subs v 1 (dec (count v))) + :else v)])))) + (into {}))) + +(defn raft-status + "Runs `raftadmin status` from node against addr and returns the parsed map." + [node addr] + (parse-raft-status + (c/on node (c/su (c/exec :env "RAFTADMIN_ALLOW_INSECURE=true" + raftadmin-bin addr "status"))))) + (defn- node-addr "Returns host:port for the node and port." [node port] @@ -176,6 +209,13 @@ "for i in $(seq 1 60); do if nc -z -w 1 $1 $2; then exit 0; fi; sleep 1; done; echo \\\"Timed out waiting for $1:$2\\\"; exit 1" "--" (name node) (str p)))))) +(defn voter-peers + "The peers setup! joins as voters: every node after the bootstrap one, + minus any reserved learner candidate." + [nodes reserved] + (let [reserved (when reserved (name reserved))] + (vec (remove #(= reserved (name %)) (rest nodes))))) + (defn- join-node! "Join peer into cluster via raftadmin, executed on bootstrap node." [bootstrap-node leader-addr peer-id peer-addr] @@ -203,7 +243,11 @@ (let [raft-groups (:raft-groups opts) grpc-port (or (:grpc-port opts) 50051) group-ids (when (seq raft-groups) (group-ids raft-groups))] - (doseq [peer (rest (:nodes test))] + ;; A reserved node is deliberately NOT made a voter, so a learner + ;; workload has a non-member to attach. Without this every node is a + ;; voter before the workload starts and :add-learner has nothing to + ;; act on. + (doseq [peer (voter-peers (:nodes test) (:reserve-learner opts))] (util/await-fn (fn [] (try diff --git a/jepsen/src/elastickv/jepsen_test.clj b/jepsen/src/elastickv/jepsen_test.clj index 9de017df0..d3320e13c 100644 --- a/jepsen/src/elastickv/jepsen_test.clj +++ b/jepsen/src/elastickv/jepsen_test.clj @@ -1,6 +1,7 @@ (ns elastickv.jepsen-test (:gen-class) - (:require [elastickv.redis-workload :as redis-workload] + (:require [elastickv.learner-workload :as learner-workload] + [elastickv.redis-workload :as redis-workload] [elastickv.redis-zset-safety-workload :as zset-safety-workload] [elastickv.dynamodb-workload :as dynamodb-workload] [elastickv.dynamodb-types-workload :as dynamodb-types-workload] @@ -28,6 +29,10 @@ ([] (elastickv-zset-safety-test {})) ([opts] (zset-safety-workload/elastickv-zset-safety-test opts))) +(defn elastickv-learner-test + ([] (elastickv-learner-test {})) + ([opts] (learner-workload/elastickv-learner-test opts))) + (def ^:private test-fns "Map of user-facing test names to their constructor fns. The first positional CLI arg selects which workload runs; if absent or unknown, @@ -36,7 +41,8 @@ {"elastickv-test" elastickv-test "elastickv-zset-safety-test" elastickv-zset-safety-test "elastickv-dynamodb-test" elastickv-dynamodb-test - "elastickv-s3-test" elastickv-s3-test}) + "elastickv-s3-test" elastickv-s3-test + "elastickv-learner-test" elastickv-learner-test}) (defn elastickv-sqs-htfifo-test "HT-FIFO Jepsen test (PR 7b). Run via the workload's own -main: diff --git a/jepsen/src/elastickv/learner_workload.clj b/jepsen/src/elastickv/learner_workload.clj index f15814e40..64072f320 100644 --- a/jepsen/src/elastickv/learner_workload.clj +++ b/jepsen/src/elastickv/learner_workload.clj @@ -1,146 +1,448 @@ (ns elastickv.learner-workload - "Jepsen workload for the Raft learner primitive: attach a learner, - promote it under partition, and assert the three safety properties - the learner design leaves as Milestone 3 hardening. + "Jepsen workload for the Raft learner primitive: attach a learner, promote + it under partition, and assert the safety properties the learner design + leaves as Milestone 3 hardening. Operations: - {:f :write :value n} write n to the register - {:f :read} read the register - {:f :add-learner :value node} attach node as a learner - {:f :promote-learner :value {:node n - :min-applied-index i - :match m - :leader-commit-index c}} - promote, recording the - learner's observed Match, - the threshold passed, and - the leader's commit index - at that moment + {:f :write :value n} write n to the register + {:f :read :value {:lease? b + :value n}} read the register + {:f :add-learner :value node} attach node as a learner + {:f :promote-learner :value {:node n + :catch-up-target t + :target-source :leader-commit-index + :match m}} + promote, recording the + target the operator + SAMPLED, where it came + from, and the learner's + Match when the promotion + committed Properties checked (see `learner-safety-checker`): - 1. **Promotion never outruns catch-up.** A promotion that reported :ok - must have found the learner caught up to the LEADER, i.e. its Match - at or above the leader's commit index at that moment. - - Comparing min-applied-index against Match alone cannot express this: - the engine's own test is Match >= min-applied-index, so an operator - who reads the learner's current Match and passes it back satisfies - the check by construction. Both the correct pattern (pick the - leader's commit index as a target, wait for Match to reach it) and - the broken one (pass whatever Match happens to be) end with - min-applied-index == Match, so that equality distinguishes nothing. - The leader's position is the only reference that does — a replica - promoted while behind it joins the voter quorum without having - caught up, and can stall writes or cut fault tolerance immediately. - - 2. **No acknowledged write is lost across a promotion.** Adding a voter - changes the quorum denominator; a write acknowledged before the - membership change must still be readable after it. - - 3. **A learner never counts toward the voter quorum.** A learner that is - unreachable must not stall writes the voters could still commit - among themselves. Expressed on the history as: no write may fail - while a partition isolates only learners." + 1. **Promotion never outruns catch-up** — `match >= catch-up-target`, + against the immutable sampled target, plus two guards: a promotion with + no evidence fails closed, and a target not sampled from the leader is a + procedure violation. See `premature-promotions` for why neither + min-applied-index nor the leader's current commit index works alone. + + 2. **No acknowledged write is lost across a promotion** — established by + temporal ordering, not set subtraction. See + `lost-writes-across-promotions`. + + 3. **A learner never counts toward the lease** — isolating a non-voter must + not fail lease reads. Expressed on reads rather than writes because + `quorumAckTracker` gates `LastQuorumAck` and the lease-read fast path, + not the write-commit quorum. See `learner-partition-read-failures`." + (:gen-class) (:require [clojure.tools.logging :refer [warn]] [elastickv.cli :as cli] [elastickv.db :as ekdb] + [jepsen.control :as c] [jepsen.db :as jdb] + [jepsen.os.debian :as debian] [jepsen [checker :as checker] - [generator :as gen]])) + [client :as client] + [control :as control] + [generator :as gen] + [nemesis :as nemesis] + [net :as net] + [os :as os]] + [taoensso.carmine :as car :refer [wcar]])) (def default-nodes ["n1" "n2" "n3" "n4" "n5"]) -(defn- promotion-ops - "Every :promote-learner invocation paired with its completion." +;; The last node is reserved as the learner candidate: ElastickvDB's setup +;; otherwise runs `raftadmin add_voter` for every node after the bootstrap +;; one, which leaves no non-member to attach. See ekdb/db :reserve-learner. +(defn learner-candidate + "The node held out of the initial voter set, so :add-learner has something + to attach. Without one, every node is already a voter before the workload + starts and the operation the test is named for cannot run at all." + [nodes] + (last nodes)) + +(defn voter-nodes + "The nodes that join as voters during setup." + [nodes] + (vec (butlast nodes))) +;; --------------------------------------------------------------------------- +;; Pure history analysis +;; --------------------------------------------------------------------------- + +(defn completed-promotions + "Every :promote-learner COMPLETION. + + Completions only, not invocations: a Jepsen operation appears twice in a + history (an :invoke plus an :ok / :fail / :info), so selecting both counted + each promotion twice and reported an invocation with no completion as a + promotion that happened." [history] - (filter #(= :promote-learner (:f %)) history)) + (->> history + (filter #(= :promote-learner (:f %))) + (remove #(= :invoke (:type %))) + vec)) + +(defn unmeasurable-promotions + "Promotions that reported :ok without the evidence needed to judge them. + + Fails closed. A successful promotion whose completion is missing :match or + :catch-up-target -- status collection failed, say -- used to be filtered out + by the numeric guards, so the checker could return :valid? true having + verified catch-up for nothing at all. An unmeasurable promotion is not a + safe one; it is one we cannot vouch for, and it must show up." + [history] + (->> (completed-promotions history) + (filter #(= :ok (:type %))) + (remove (fn [op] + (let [{:keys [match catch-up-target]} (:value op)] + (and (number? match) (number? catch-up-target))))) + vec)) (defn premature-promotions - "Promotions that committed while the learner was still behind the leader. - - Measured against the LEADER's commit index, not against - min-applied-index: the engine tests Match >= min-applied-index, so an - operator passing the learner's own Match satisfies it unconditionally - and the two patterns are indistinguishable from that pair alone. A - promotion is premature exactly when the learner's Match had not - reached the leader's committed position." + "Promotions that committed while the learner was behind its catch-up target. + + Measured against the target the operator SAMPLED and passed as + min_applied_index, not against the leader's commit index at promotion time. + + Both alternatives are wrong in opposite directions: + + - Comparing min-applied-index with Match alone proves nothing, because the + engine's own test IS `Match >= min_applied_index`. An operator who reads + the learner's current Match and passes it back satisfies that by + construction, so the correct and the broken procedure are + indistinguishable from the pair. + - Comparing Match with the leader's CURRENT commit index rejects the + documented safe workflow. An operator samples commit index T, waits for + the learner to reach T, and promotes; if the leader commits more entries + while that happens the promotion legitimately has `match >= T` but + `match < leader-commit-index`, and the healthy run is marked invalid. + That also contradicts the \"within N entries\" policy in + docs/raft_learner_operations.md. + + The immutable sampled target is the only reference that distinguishes the + two procedures without rejecting the safe one, so the workload records where + its target came from and `promotions-without-a-sampled-target` rejects a + target derived from the learner." [history] - (->> (promotion-ops history) + (->> (completed-promotions history) (filter #(= :ok (:type %))) (filter (fn [op] - (let [{:keys [match leader-commit-index]} (:value op)] + (let [{:keys [match catch-up-target]} (:value op)] (and (number? match) - (number? leader-commit-index) - (< match leader-commit-index))))) + (number? catch-up-target) + (< match catch-up-target))))) vec)) -(defn lost-writes - "Writes acknowledged :ok that no later successful read observed. +(defn promotions-without-a-sampled-target + "Promotions whose catch-up target did not come from the leader. - Only writes that committed strictly before the final read are - considered: a write still in flight at the end of the history has no - obligation to appear." + This is what closes the loophole the Match comparison could not: a target + read off the learner's own Match makes the engine's check vacuous, so the + workload records :target-source and anything other than + :leader-commit-index is a procedure violation regardless of the outcome." [history] - (let [oks (->> history - (filter #(and (= :write (:f %)) (= :ok (:type %)))) - (map :value) - set) - observed (->> history - (filter #(and (= :read (:f %)) (= :ok (:type %)))) - (map :value) - (remove nil?) - set)] - (vec (sort (remove observed oks))))) - -(defn learner-quorum-stalls - "Write failures that occurred while only learners were partitioned. - - A learner does not vote, so isolating one cannot remove voter quorum. - A write failing in that window means the learner was counted in the - denominator — the §4.6 regression the design calls out." + (->> (completed-promotions history) + (filter #(= :ok (:type %))) + (remove #(= :leader-commit-index (:target-source (:value %)))) + vec)) + +(defn- last-ok-write-before + [history t] + (->> history + (filter #(and (= :write (:f %)) (= :ok (:type %)) (< (:time %) t))) + (sort-by :time) + last)) + +(defn- first-ok-read-after + [history t] + (->> history + (filter #(and (= :read (:f %)) (= :ok (:type %)) (> (:time %) t))) + (sort-by :time) + first)) + +(defn- writes-invoked-between + [history from to] + (->> history + (filter #(and (= :write (:f %)) (= :invoke (:type %)) + (> (:time %) from) (< (:time %) to))) + vec)) + +(defn lost-writes-across-promotions + "Acknowledged writes that a promotion lost, by TEMPORAL ordering. + + Set subtraction cannot establish this. `write 1 :ok, write 2 :ok, promote + :ok, read 2 :ok` is a legal register history, but subtracting observed + values from acknowledged ones reports 1 as lost merely because it was + overwritten before anyone read it; and a read of 1 taken BEFORE its write + would mask a genuine later loss. + + So this pairs each promotion with the last write acknowledged before it and + the first read that succeeded after it, and reports a loss only when no + other write was in flight in between -- the case where the register's value + is pinned and the read is obliged to return it. Concurrency makes the + expected value ambiguous rather than wrong, so those cases are skipped + instead of guessed at." [history] - (let [windows (->> history - (filter #(= :nemesis (:process %))) + (->> (completed-promotions history) + (filter #(= :ok (:type %))) + (keep (fn [promotion] + (let [t (:time promotion) + write (last-ok-write-before history t) + read (first-ok-read-after history t)] + ;; A read's :value is the map {:lease? b :value n}, so the + ;; register value has to be unwrapped before comparing it + ;; with the write's scalar. + (let [observed (get-in read [:value :value])] + (when (and write read + (empty? (writes-invoked-between + history (:time write) (:time read))) + (not= (:value write) observed)) + {:promotion (:value promotion) + :acked-write (:value write) + :observed-after observed}))))) + vec)) + +(defn learner-partition-windows + "Every learners-only partition interval, as [start stop] time pairs. + + Each start is paired with its OWN stop. Taking the first start and the + first later stop examined one window and silently ignored every subsequent + learner-isolation period, so a regression in the second or later window + could not fail the check." + [history] + (let [nemesis (->> history (filter #(= :nemesis (:process %))) (sort-by :time)) + starts (->> nemesis (filter #(= :start-partition (:f %))) - (filter #(= :learners-only (get-in % [:value :scope]))) - (map :time) - sort - vec) - stops (->> history - (filter #(= :nemesis (:process %))) - (filter #(= :stop-partition (:f %))) - (map :time) - sort - vec)] + (filter #(= :learners-only (get-in % [:value :scope])))) + stops (->> nemesis (filter #(= :stop-partition (:f %))) (map :time) vec)] + (->> starts + (map (fn [start] + (let [t (:time start)] + [t (or (first (filter #(> % t) stops)) Long/MAX_VALUE)]))) + vec))) + +(defn learner-partition-read-failures + "Lease reads that failed while only learners were partitioned. + + Reads, not writes. The learner is excluded from the write-commit quorum by + the voter set, but `quorumAckTracker` feeds `LastQuorumAck`, which gates the + leader-local LEASE-READ fast path. A learner wrongly counted there does not + stop writes committing -- so a write-failure check stays green through the + exact regression it claims to catch -- it stalls the lease the leader serves + fast reads from. + + So the property is expressed on lease reads: isolating a non-voter must not + make them fail." + [history] + (let [windows (learner-partition-windows history)] (if (empty? windows) [] - (let [start (first windows) - stop (or (first (filter #(> % start) stops)) Long/MAX_VALUE)] - (->> history - (filter #(= :write (:f %))) - (filter #(= :fail (:type %))) - (filter #(and (>= (:time %) start) (<= (:time %) stop))) - vec))))) + (->> history + (filter #(and (= :read (:f %)) + (= :fail (:type %)) + (true? (:lease? (:value %))))) + (filter (fn [op] + (some (fn [[start stop]] + (and (>= (:time op) start) (<= (:time op) stop))) + windows))) + vec)))) + +;; --------------------------------------------------------------------------- +;; Checker +;; --------------------------------------------------------------------------- (defn learner-safety-checker - "Checks the three learner safety properties over a completed history." + "Checks the learner safety properties over a completed history. + + An EMPTY history is invalid. A run that emitted no operations proves + nothing, and reporting it valid is how a workload that cannot actually + drive the cluster still passes -- which is exactly what this workload did + before it had a client, a nemesis, or a generator that produced its + documented operations." [] (reify checker/Checker (check [_ _test history _opts] - (let [premature (premature-promotions history) - lost (lost-writes history) - stalls (learner-quorum-stalls history)] + (let [promotions (completed-promotions history) + premature (premature-promotions history) + unmeasurable (unmeasurable-promotions history) + unsampled (promotions-without-a-sampled-target history) + lost (lost-writes-across-promotions history) + stalls (learner-partition-read-failures history) + writes (count (filter #(and (= :write (:f %)) (= :ok (:type %))) history)) + reads (count (filter #(and (= :read (:f %)) (= :ok (:type %))) history))] (when (seq premature) - (warn "learner promoted without a real catch-up target:" premature)) - {:valid? (and (empty? premature) + (warn "learner promoted before reaching its sampled target:" premature)) + (when (seq unmeasurable) + (warn "promotion reported ok without catch-up evidence:" unmeasurable)) + {:valid? (and (pos? (count promotions)) + (pos? writes) + (pos? reads) + (empty? premature) + (empty? unmeasurable) + (empty? unsampled) (empty? lost) (empty? stalls)) - :promotions (count (promotion-ops history)) + :promotions (count promotions) + :ok-writes writes + :ok-reads reads :premature-promotions premature + :unmeasurable-promotions unmeasurable + :unsampled-targets unsampled :lost-writes lost - :learner-quorum-stalls stalls})))) + :learner-read-failures stalls})))) + +;; --------------------------------------------------------------------------- +;; Client +;; --------------------------------------------------------------------------- + +(def ^:private register-key "learner-register") + +(defn- raftadmin! + "Runs raftadmin on node against the leader address." + [node & args] + (c/on node (c/su (apply c/exec :env "RAFTADMIN_ALLOW_INSECURE=true" + (ekdb/raftadmin-binary) args)))) + +(defn- leader-commit-index + "Samples the leader's commit index: the catch-up target. + + Sampled from the LEADER because a target read off the learner is what makes + the engine's `Match >= min_applied_index` test vacuous." + [node leader-addr] + (:commit_index (ekdb/raft-status node leader-addr))) + +(defn- learner-applied-index + "The learner's OWN applied index, read from the learner. + + Deliberately not the leader's Match for that peer: an independently observed + measure cannot be satisfied by the leader's own bookkeeping, so it is the + stronger evidence of catch-up. (Per-peer Match is not available from + `raftadmin status` on this branch in any case.)" + [learner-node learner-addr] + (:applied_index (ekdb/raft-status learner-node learner-addr))) + +(def ^:private catch-up-poll-ms 200) +(def ^:private catch-up-timeout-ms 60000) + +(defn- await-catch-up! + "Polls the learner until its applied index reaches target." + [learner-node learner-addr target] + (let [deadline (+ (System/currentTimeMillis) catch-up-timeout-ms)] + (loop [] + (let [applied (or (learner-applied-index learner-node learner-addr) 0)] + (cond + (>= applied target) applied + (> (System/currentTimeMillis) deadline) + (throw (ex-info "learner did not reach the catch-up target" + {:target target :applied applied})) + :else (do (Thread/sleep (long catch-up-poll-ms)) (recur))))))) + +(defrecord LearnerClient [node->port leader-addr conn] + client/Client + (open! [this test node] + (let [port (get node->port node 6379) + host (or (:redis-host test) (name node))] + (assoc this :conn {:pool {} :spec {:host host :port port :timeout-ms 10000}}))) + + (close! [this _test] this) + (setup! [_this _test]) + (teardown! [_this _test]) + + (invoke! [this test op] + (let [conn (:conn this) + nodes (:nodes test) + leader (first nodes) + addr (or leader-addr (str leader ":50051"))] + (try + (case (:f op) + :write (do (wcar conn (car/set register-key (:value op))) + (assoc op :type :ok)) + + ;; :lease? marks the read as one the leader may serve from its + ;; lease, which is the path a learner wrongly counted in + ;; quorumAckTracker would break. + :read (let [v (wcar conn (car/get register-key))] + (assoc op :type :ok + :value {:lease? true + :value (when v (Long/parseLong (str v)))})) + + :add-learner + (let [candidate (name (:value op))] + (raftadmin! leader addr "add_learner" candidate + (str candidate ":" (:grpc-port test 50051)) "0") + (assoc op :type :ok)) + + :promote-learner + (let [candidate (name (:value op)) + candidate-addr (str candidate ":" (:grpc-port test 50051)) + ;; Sample the target FIRST, then wait for the learner to reach + ;; it, then promote against that same immutable value. + ;; Recording where the target came from is what lets the + ;; checker reject the vacuous procedure. + target (leader-commit-index leader addr) + applied (await-catch-up! candidate candidate-addr target)] + (raftadmin! leader addr "promote_learner" candidate + "0" (str target)) + (assoc op :type :ok + :value {:node candidate + :catch-up-target target + :target-source :leader-commit-index + :match applied}))) + (catch Exception e + (assoc op :type :fail :error (.getMessage e))))))) + +;; --------------------------------------------------------------------------- +;; Nemesis +;; --------------------------------------------------------------------------- + +(defn learner-partition-nemesis + "Isolates ONLY the learner candidate, leaving every voter connected. + + That is the shape the quorum property needs: voters retain quorum among + themselves, so anything that degrades must be attributable to the learner + being counted where it should not be." + [nodes] + (let [learner (learner-candidate nodes)] + (nemesis/partitioner + (fn [_test _nodes] + (nemesis/complete-grudge [[learner] (voter-nodes nodes)]))))) + +(defn learner-nemesis-generator + "start-partition / stop-partition pairs, each start tagged :learners-only so + the checker can pair it with its own stop." + [] + ;; A seq is a generator in Jepsen 0.3.x; gen/seq was removed. + (cycle [(gen/sleep 5) + {:type :info :f :start-partition :value {:scope :learners-only}} + (gen/sleep 10) + {:type :info :f :stop-partition :value {:scope :learners-only}}])) + +;; --------------------------------------------------------------------------- +;; Generator +;; --------------------------------------------------------------------------- + +(defn client-generator + "Register traffic plus one attach/promote cycle for the reserved candidate. + + The previous generator was `gen/nemesis` applied to nil with no :client at + all, so a run emitted NOTHING: none of the documented :write, :read, + :add-learner or :promote-learner operations could appear, and the checker + reported the resulting empty history as valid." + [nodes] + (let [candidate (learner-candidate nodes) + register (gen/mix [(fn [] {:f :write :value (rand-int 1000000)}) + (fn [] {:f :read})])] + (gen/phases + ;; Some traffic first, so the promotion has acknowledged writes to + ;; preserve across it. + (gen/time-limit 5 register) + (gen/once {:f :add-learner :value candidate}) + (gen/time-limit 5 register) + (gen/once {:f :promote-learner :value candidate}) + register))) (defn elastickv-learner-test "Builds a Jepsen test map exercising learner attach and promotion." @@ -148,21 +450,52 @@ ([opts] (let [nodes (or (:nodes opts) default-nodes) local? (:local opts) + grpc-port (or (:grpc-port opts) 50051) + redis-port (or (:redis-port opts) 6379) db (if local? jdb/noop - (ekdb/db {:grpc-port (or (:grpc-port opts) 50051) - :redis-port (or (:redis-port opts) 6379)})) - time-limit (or (:time-limit opts) 30)] + (ekdb/db {:grpc-port grpc-port + :redis-port redis-port + :encryption (:encryption opts) + ;; Held out of the voter set so :add-learner + ;; has a non-member to attach. + :reserve-learner (learner-candidate nodes)})) + time-limit (or (:time-limit opts) 30) + ports (or (:node->port opts) + (cli/ports->node-map + (repeat (count nodes) redis-port) nodes))] {:name "elastickv-learner" :nodes nodes :db db + :os (if local? os/noop debian/os) + :net (if local? net/noop net/iptables) + :ssh (merge {:username "vagrant" + :private-key-path "/home/vagrant/.ssh/id_rsa" + :strict-host-key-checking false} + (when local? {:dummy true}) + (:ssh opts)) + :remote control/ssh + :client (->LearnerClient ports nil nil) + :nemesis (if local? nemesis/noop (learner-partition-nemesis nodes)) + ;; Jepsen 0.3.x cannot fressian-serialize some final generators. + :final-generator nil :concurrency (or (:concurrency opts) 10) :time-limit time-limit :rate (double (or (:rate opts) 5)) :checker (learner-safety-checker) - :generator (gen/time-limit time-limit (gen/nemesis nil)) - :grpc-port (or (:grpc-port opts) 50051) - :ports (or (:node->port opts) - (cli/ports->node-map - (repeat (count nodes) (or (:grpc-port opts) 50051)) - nodes))}))) + :generator (->> (client-generator nodes) + (gen/nemesis (if local? + (gen/once {:type :info :f :noop}) + (learner-nemesis-generator))) + (gen/stagger (/ (double (or (:rate opts) 5)))) + (gen/time-limit time-limit)) + :grpc-port grpc-port + :ports ports}))) + +(defn -main + "Runnable entry point. Without one, neither invocation form could select + this workload: the namespace had no -main, and the shared dispatcher in + elastickv.jepsen-test neither required it nor listed it, so passing its + name fell through to the Redis test." + [& args] + (cli/run-workload! args cli/common-cli-opts identity elastickv-learner-test)) diff --git a/jepsen/test/elastickv/learner_workload_test.clj b/jepsen/test/elastickv/learner_workload_test.clj index 3d46ca096..eb989657d 100644 --- a/jepsen/test/elastickv/learner_workload_test.clj +++ b/jepsen/test/elastickv/learner_workload_test.clj @@ -1,143 +1,247 @@ (ns elastickv.learner-workload-test + "Unit tests for the learner workload's checker and wiring. + + The checker tests matter more than usual here: the workload's whole value is + that it can FAIL when the learner primitive misbehaves, and an earlier + revision could not — it had no client, no nemesis and a generator that + emitted nothing, so every run produced an empty history the checker called + valid. Several properties were also measuring the wrong thing. Each test + below names the way it used to pass wrongly." (:require [clojure.test :refer :all] - [jepsen.checker :as checker] - [elastickv.learner-workload :as workload])) + [elastickv.db :as ekdb] + [elastickv.jepsen-test :as jt] + [elastickv.learner-workload :as lw] + [jepsen.checker :as checker])) + +(defn- check [history] + (checker/check (lw/learner-safety-checker) {} history {})) + +(def ^:private healthy-prefix + [{:type :invoke :f :write :value 1 :time 10 :process 0} + {:type :ok :f :write :value 1 :time 20 :process 0} + {:type :invoke :f :read :time 30 :process 0} + {:type :ok :f :read :value {:lease? true :value 1} :time 40 :process 0}]) + +(defn- promotion + [m time] + {:type :ok :f :promote-learner :time time + :value (merge {:node "n5" :catch-up-target 100 + :target-source :leader-commit-index :match 100} + m)}) + +(defn- healthy-history [] + (concat healthy-prefix + [{:type :invoke :f :promote-learner :value "n5" :time 50 :process 0} + (promotion {} 60) + {:type :invoke :f :read :time 70 :process 0} + {:type :ok :f :read :value {:lease? true :value 1} :time 80 :process 0}])) + +(deftest healthy-history-is-valid + (is (:valid? (check (healthy-history))))) -(defn- check-history [history] - (checker/check (workload/learner-safety-checker) {} history {})) - -(defn- write-op [t v & {:keys [type process] :or {type :ok process 0}}] - {:type type :f :write :time t :process process :value v}) - -(defn- read-op [t v & {:keys [type process] :or {type :ok process 0}}] - {:type type :f :read :time t :process process :value v}) +;; --------------------------------------------------------------------------- +;; 1. Promotion never outruns catch-up +;; --------------------------------------------------------------------------- -(defn- promote-op [t node min-idx match leader-commit & {:keys [type] :or {type :ok}}] - {:type type :f :promote-learner :time t :process 0 - :value {:node node :min-applied-index min-idx :match match - :leader-commit-index leader-commit}}) +(deftest premature-promotion-is-rejected + (let [r (check (concat healthy-prefix [(promotion {:match 90 :catch-up-target 100} 60)]))] + (is (false? (:valid? r))) + (is (= 1 (count (:premature-promotions r)))))) -(defn- partition-op [t f scope] - {:type :info :f f :time t :process :nemesis :value {:scope scope}}) +(deftest catch-up-is-measured-against-the-sampled-target-not-a-moving-leader + ;; The documented safe workflow: sample target T, wait for the learner to + ;; reach T, promote. The leader keeps committing, so at promotion time the + ;; learner is at T while the leader is well past it. Comparing Match with + ;; the leader's CURRENT commit index rejected this healthy run. + (let [r (check (concat healthy-prefix + [(promotion {:catch-up-target 100 + :match 100 + :leader-commit-index 100000} 60)]))] + (is (:valid? r) + "a learner that reached its sampled target is caught up, whatever the leader did since"))) + +(deftest a-target-read-off-the-learner-is-rejected + ;; The loophole the Match comparison cannot close: the engine's own test is + ;; Match >= min_applied_index, so passing the learner's current Match + ;; satisfies it by construction. The procedure, not the arithmetic, has to + ;; be checked. + (let [r (check (concat healthy-prefix + [(promotion {:target-source :learner-match} 60)]))] + (is (false? (:valid? r))) + (is (= 1 (count (:unsampled-targets r)))))) + +(deftest a-promotion-without-evidence-fails-closed + ;; Previously the numeric guards simply skipped these, so a successful but + ;; unmeasurable promotion left the checker reporting valid having verified + ;; nothing. + (doseq [missing [{:match nil} {:catch-up-target nil}]] + (let [r (check (concat healthy-prefix [(promotion missing 60)]))] + (is (false? (:valid? r)) (str "missing " (keys missing))) + (is (= 1 (count (:unmeasurable-promotions r))))))) + +(deftest promotions-are-counted-once-per-completed-call + ;; An op appears as :invoke plus a completion, so counting both reported two + ;; promotions per call and counted a bare invocation as one. + (let [r (check (concat healthy-prefix + [{:type :invoke :f :promote-learner :value "n5" :time 50} + (promotion {} 60)]))] + (is (= 1 (:promotions r))))) -(deftest builds-test-spec - (let [test-map (workload/elastickv-learner-test {})] - (is (map? test-map)) - (is (= "elastickv-learner" (:name test-map))) - (is (= ["n1" "n2" "n3" "n4" "n5"] (:nodes test-map))))) +;; --------------------------------------------------------------------------- +;; 2. No acknowledged write is lost across a promotion +;; --------------------------------------------------------------------------- -(deftest custom-options-override-defaults - (let [test-map (workload/elastickv-learner-test - {:time-limit 60 :concurrency 20 :grpc-port 50999})] - (is (= 20 (:concurrency test-map))) - (is (= 60 (:time-limit test-map))) - (is (= 50999 (:grpc-port test-map))))) +(deftest a-write-lost-across-a-promotion-is-rejected + (let [r (check [{:type :invoke :f :write :value 7 :time 10} + {:type :ok :f :write :value 7 :time 20} + {:type :invoke :f :promote-learner :value "n5" :time 30} + (promotion {} 40) + {:type :invoke :f :read :time 50} + {:type :ok :f :read :value {:lease? true :value 3} :time 60}])] + (is (false? (:valid? r))) + (is (= 1 (count (:lost-writes r)))))) + +(deftest an-overwritten-value-is-not-a-lost-write + ;; Set subtraction reported 1 as lost in this legal register history merely + ;; because it was overwritten before anyone read it. + (let [r (check [{:type :invoke :f :write :value 1 :time 10} + {:type :ok :f :write :value 1 :time 20} + {:type :invoke :f :write :value 2 :time 30} + {:type :ok :f :write :value 2 :time 40} + {:type :invoke :f :promote-learner :value "n5" :time 50} + (promotion {} 60) + {:type :invoke :f :read :time 70} + {:type :ok :f :read :value {:lease? true :value 2} :time 80}])] + (is (:valid? r) (str "lost-writes=" (:lost-writes r))))) + +(deftest a-concurrent-write-makes-the-expected-value-ambiguous-not-wrong + ;; With another write in flight between the acked write and the read, the + ;; register's value is not pinned, so no conclusion is drawn rather than a + ;; false loss being reported. + (let [r (check [{:type :invoke :f :write :value 1 :time 10} + {:type :ok :f :write :value 1 :time 20} + {:type :invoke :f :promote-learner :value "n5" :time 30} + (promotion {} 40) + {:type :invoke :f :write :value 9 :time 50} + {:type :invoke :f :read :time 60} + {:type :ok :f :read :value {:lease? true :value 9} :time 70}])] + (is (:valid? r) (str "lost-writes=" (:lost-writes r))))) ;; --------------------------------------------------------------------------- -;; Property 1 — promotion must not outrun catch-up +;; 3. A learner never counts toward the lease ;; --------------------------------------------------------------------------- -(deftest promotion-of-a-caught-up-learner-is-valid - ;; Match reached the leader's commit index before the promotion. This - ;; is the correct operator pattern: pick the leader's position as the - ;; target, wait for Match to reach it, then promote at that target. - (let [r (check-history [(promote-op 100 "n4" 100 100 100)])] - (is (:valid? r)) - (is (= 1 (:promotions r))) - (is (empty? (:premature-promotions r))))) - -(deftest promotion-of-a-lagging-learner-is-premature - ;; The broken pattern: the operator read the learner's current Match - ;; (10) and passed it back while the leader was committed through 100. - ;; min-applied-index == match, so the engine's check passes by - ;; construction and a replica 90 entries behind joins the voter quorum. - (let [r (check-history [(promote-op 100 "n4" 10 10 100)])] +(defn- partition-window [start stop] + [{:type :info :process :nemesis :f :start-partition + :value {:scope :learners-only} :time start} + {:type :info :process :nemesis :f :stop-partition + :value {:scope :learners-only} :time stop}]) + +(deftest a-lease-read-failing-under-learner-isolation-is-rejected + ;; Reads, not writes: quorumAckTracker feeds LastQuorumAck and the + ;; lease-read fast path, not the write-commit quorum, so a write-failure + ;; check stayed green through the exact regression it claimed to detect. + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (partition-window 100 200) + [{:type :invoke :f :read :time 120} + {:type :fail :f :read :value {:lease? true} :time 130}]))] (is (false? (:valid? r))) - (is (= 1 (count (:premature-promotions r)))))) + (is (= 1 (count (:learner-read-failures r)))))) + +(deftest every-learner-partition-window-is-checked-not-just-the-first + ;; Taking the first start and the first later stop ignored every subsequent + ;; isolation window, so a regression in the second one could not fail. + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (partition-window 100 200) + (partition-window 300 400) + [{:type :invoke :f :read :time 320} + {:type :fail :f :read :value {:lease? true} :time 330}]))] + (is (false? (:valid? r))) + (is (= 1 (count (:learner-read-failures r))) + "a failure in the SECOND window must still be caught"))) -(deftest match-equal-to-min-applied-index-does-not-decide-the-property - ;; Both the correct and the broken call end with - ;; min-applied-index == match, so that equality distinguishes nothing. - ;; Only the leader's position separates them — these two histories are - ;; identical on (min-applied-index, match) and must still be judged - ;; differently. - (let [caught-up (check-history [(promote-op 100 "n4" 50 50 50)]) - lagging (check-history [(promote-op 100 "n4" 50 50 500)])] - (is (:valid? caught-up)) - (is (false? (:valid? lagging))))) - -(deftest a-failed-premature-promotion-is-not-flagged - ;; The engine rejected it, so no lagging replica was promoted. Only - ;; promotions that actually committed can violate the property. - (let [r (check-history [(promote-op 100 "n4" 10 10 100 :type :fail)])] - (is (:valid? r)) - (is (empty? (:premature-promotions r))))) +(deftest a-read-failure-outside-any-window-is-not-attributed-to-the-learner + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (partition-window 100 200) + [{:type :invoke :f :read :time 500} + {:type :fail :f :read :value {:lease? true} :time 510}]))] + (is (:valid? r) (str "failures=" (:learner-read-failures r))))) ;; --------------------------------------------------------------------------- -;; Property 2 — no acknowledged write lost across a promotion +;; The checker must not pass a run that proved nothing ;; --------------------------------------------------------------------------- -(deftest writes-surviving-a-promotion-are-valid - (let [r (check-history [(write-op 100 1) - (promote-op 200 "n4" 100 100 100) - (read-op 300 1)])] - (is (:valid? r)) - (is (empty? (:lost-writes r))))) - -(deftest a-write-lost-across-a-promotion-is-detected - (let [r (check-history [(write-op 100 1) - (write-op 150 2) - (promote-op 200 "n4" 100 100 100) - (read-op 300 1)])] - (is (false? (:valid? r))) - (is (= [2] (:lost-writes r))))) +(deftest an-empty-history-is-invalid + ;; THE load-bearing test. Before the workload had a client, a nemesis and a + ;; generator that emitted its documented operations, a real run produced an + ;; empty history — and the checker called it valid, so the gate could never + ;; fail. + (is (false? (:valid? (check []))))) + +(deftest a-history-with-no-promotion-is-invalid + (is (false? (:valid? (check healthy-prefix))) + "a learner test that never promoted has not tested promotion")) -(deftest a-failed-write-is-not-required-to-survive - (let [r (check-history [(write-op 100 1) - (write-op 150 2 :type :fail) - (read-op 300 1)])] - (is (:valid? r)) - (is (empty? (:lost-writes r))))) +(deftest a-history-with-no-reads-is-invalid + (is (false? (:valid? (check [{:type :invoke :f :write :value 1 :time 10} + {:type :ok :f :write :value 1 :time 20} + (promotion {} 30)]))) + "the lease property is unobservable without reads")) ;; --------------------------------------------------------------------------- -;; Property 3 — a learner never counts toward the voter quorum +;; Wiring: the workload has to be able to run at all ;; --------------------------------------------------------------------------- -(deftest isolating-only-learners-must-not-stall-writes - ;; A learner does not vote, so isolating one cannot remove voter - ;; quorum. A write failing in that window means the learner was in the - ;; denominator — the §4.6 regression. - (let [r (check-history [(partition-op 100 :start-partition :learners-only) - (write-op 150 1 :type :fail) - (partition-op 200 :stop-partition :learners-only)])] - (is (false? (:valid? r))) - (is (= 1 (count (:learner-quorum-stalls r)))))) - -(deftest writes-succeeding-while-learners-are-isolated-are-valid - (let [r (check-history [(partition-op 100 :start-partition :learners-only) - (write-op 150 1) - (partition-op 200 :stop-partition :learners-only) - (read-op 300 1)])] - (is (:valid? r)) - (is (empty? (:learner-quorum-stalls r))))) - -(deftest a-write-failing-under-a-voter-partition-is-not-a-learner-stall - ;; Isolating voters legitimately removes quorum, so a failure there is - ;; expected and must not be reported against the learner property. - (let [r (check-history [(partition-op 100 :start-partition :voters) - (write-op 150 1 :type :fail) - (partition-op 200 :stop-partition :voters)])] - (is (empty? (:learner-quorum-stalls r))))) - -(deftest a-write-failing-outside-the-partition-window-is-not-a-stall - (let [r (check-history [(partition-op 100 :start-partition :learners-only) - (partition-op 200 :stop-partition :learners-only) - (write-op 300 1 :type :fail)])] - (is (empty? (:learner-quorum-stalls r))))) - -(deftest clean-history-reports-valid - (let [r (check-history [(write-op 100 1) - (promote-op 200 "n4" 100 100 100) - (read-op 300 1)])] - (is (:valid? r)) - (is (= 1 (:promotions r))))) +(deftest the-test-map-has-a-client-and-a-nemesis + ;; It had neither, so nothing could drive the cluster. + (let [t (lw/elastickv-learner-test {:nodes ["n1" "n2" "n3" "n4" "n5"]})] + (is (some? (:client t))) + (is (some? (:nemesis t))) + (is (some? (:generator t))))) + +(deftest the-generator-emits-every-documented-operation + ;; The old generator was gen/nemesis applied to nil, so none of :write, + ;; :read, :add-learner or :promote-learner could ever appear. + (let [ops (->> (lw/client-generator ["n1" "n2" "n3" "n4" "n5"]) + (tree-seq coll? seq) + (keep #(when (map? %) (:f %))) + set)] + (is (contains? ops :add-learner)) + (is (contains? ops :promote-learner)))) + +(deftest a-node-is-reserved-outside-the-initial-voter-set + ;; ElastickvDB's setup adds every node after the bootstrap one as a voter, + ;; so without a reservation there is no non-member left to attach and + ;; :add-learner cannot run. + (let [nodes ["n1" "n2" "n3" "n4" "n5"]] + (is (= "n5" (lw/learner-candidate nodes))) + (is (= ["n2" "n3" "n4"] (ekdb/voter-peers nodes "n5")) + "the reserved candidate must not be joined as a voter") + (is (= ["n2" "n3" "n4" "n5"] (ekdb/voter-peers nodes nil)) + "with no reservation the existing behaviour is unchanged") + (is (= "n5" (get-in (lw/elastickv-learner-test {:nodes nodes}) + [:db :opts :reserve-learner]))))) + +(deftest the-workload-is-reachable-from-the-shared-dispatcher + ;; Neither invocation form could select it: the namespace had no -main and + ;; the dispatcher neither required nor listed it, so the name fell through + ;; to the Redis test. + (is (fn? (deref (resolve 'elastickv.learner-workload/-main))) + "the namespace needs a -main to be runnable directly") + (is (= "elastickv-learner" + (:name (jt/elastickv-learner-test {:nodes ["n1" "n2" "n3"]}))))) + +(deftest raft-status-parsing-reads-the-indices-the-promotion-needs + (let [out (str "state: Leader\n" + "leader_id: \"n1\"\n" + "term: 3\n" + "commit_index: 4211\n" + "applied_index: 4207\n" + "pending_conf_change: false\n") + got (ekdb/parse-raft-status out)] + (is (= 4211 (:commit_index got))) + (is (= 4207 (:applied_index got))) + (is (= "n1" (:leader_id got))))) From 60efbbb334a15bb6fa25b1458cab75da4cc58c29 Mon Sep 17 00:00:00 2001 From: bootjp Date: Mon, 14 Sep 2026 17:53:59 +0900 Subject: [PATCH 3/7] jepsen: make the learner workload's fault and properties actually fire Twelve findings. Several are the same shape as the ones fixed last round, one level down: the workload could now emit operations, but the fault never happened and three of the properties could not fail. The fault: - The generator emitted :start-partition / :stop-partition while jepsen.nemesis/partitioner dispatches on :start / :stop, so no branch matched and the learner was never isolated -- and the op's :value would have been taken as the grudge, which it is not. The nemesis is now implemented directly and handles those names. - The partition ran on an infinite cycle, so a window opened after the promotion still carried the :learners-only label while isolating a node that had become a voter. One window now opens and closes before the promotion phase. - The reserved candidate was only withheld from the add_voter loop; it still launched as a fresh non-bootstrap process with no peers, which the etcd engine refuses with errNoPeersConfigured, so it exited before :add-learner could attach it. It now starts with --raftJoinMembers and --raftJoinAsLearner, which exist for exactly this. The properties: - Failed reads kept no :lease? marker, so learner-partition-read-failures filtered out every real read exception and the lease property could not fire at all. - Failures alone cannot detect the quorum-ack regression anyway: a GET calls LeaseReadForKeyThrough and the engine falls back to LinearizableRead transparently, so with the voters connected the read SUCCEEDS. The client records latency and the checker bounds it. - The coverage gate counted every promotion completion, so a history whose only promotion FAILED had a positive count while every safety predicate -- all of which filter to :ok -- saw nothing. - lost-writes-across-promotions silently skips a promotion it cannot pair with a later read; counting reads anywhere in the history hid that, so a run could pass having observed no post-promotion state. Each successful promotion now requires one. - That read is selected by INVOCATION time. A read invoked before the promotion can linearize against the old value and return after it; selecting on completion accepted it as evidence and also reported the acknowledged write as lost. The client: - SET replies are checked for "OK". Carmine returns nil or a Throwable on missing, protocol and some error-reply paths, and treating those as acknowledged lets the checker call an unconfirmed write durable. Anything else is :info, which is what an unacknowledged write is. - Lease probes go to a connected voter. A GET through the isolated learner proxies to the leader across the partition and can fail with a perfectly healthy lease, which the checker would read as the regression. The entry point: - prepare-learner-opts replaces identity. common-cli-opts leaves :nodes as a comma-separated string, so the constructor treated a string as a node collection: learner-candidate returned its last character and the port map was keyed by characters. - :redis-host is carried into the test map so the client honours it. server-args is extracted as a pure function, as on the encrypted-cluster workload and for the same reason: a test that can only observe the process passes while a flag is silently dropped. Claude-Session: https://claude.ai/code/session_013rNHooj7NF3giihWVba8QE --- jepsen/src/elastickv/db.clj | 89 +++++-- jepsen/src/elastickv/learner_workload.clj | 226 +++++++++++++++--- .../test/elastickv/learner_workload_test.clj | 170 ++++++++++++- 3 files changed, 427 insertions(+), 58 deletions(-) diff --git a/jepsen/src/elastickv/db.clj b/jepsen/src/elastickv/db.clj index 3bd806138..de24119da 100644 --- a/jepsen/src/elastickv/db.clj +++ b/jepsen/src/elastickv/db.clj @@ -136,8 +136,41 @@ (defn- build-raft-dynamo-map [nodes grpc-port dynamo-port raft-groups] (build-raft-service-map nodes grpc-port dynamo-port raft-groups)) +(defn server-args + "The server argv for one node. + + Pure and exported so the flags are assertable without SSH: a test that could + only observe the process would pass while a flag was silently dropped." + [{:keys [node grpc redis data-dir raft-engine raft-redis-map dynamo + raft-dynamo-map s3 sqs sqs-region raft-groups shard-ranges + bootstrap? join-as-learner join-members]}] + (cond-> ["--address" grpc + "--redisAddress" redis + "--raftId" (name node) + "--raftDataDir" data-dir + "--raftEngine" (or raft-engine "etcd") + "--raftRedisMap" raft-redis-map] + dynamo (conj "--dynamoAddress" dynamo + "--raftDynamoMap" raft-dynamo-map) + s3 (conj "--s3Address" s3) + sqs (conj "--sqsAddress" sqs) + (and sqs sqs-region) (conj "--sqsRegion" sqs-region) + (seq raft-groups) (conj "--raftGroups" (build-raft-groups-arg node raft-groups)) + (seq shard-ranges) (conj "--shardRanges" shard-ranges) + bootstrap? (conj "--raftBootstrap") + ;; A node held out of the voter set still has to START. With a + ;; fresh data dir, no --raftBootstrap and no peer list, the etcd + ;; engine refuses to self-bootstrap (errNoPeersConfigured) and + ;; the process exits before anything can attach it as a + ;; learner. --raftJoinMembers supplies transport discovery for + ;; the existing cluster, and --raftJoinAsLearner declares the + ;; intent so a ConfState that lists this node as a voter raises + ;; the §4.5 alarm. + join-as-learner (conj "--raftJoinAsLearner") + (and join-as-learner join-members) (conj "--raftJoinMembers" join-members))) + (defn- start-node! - [test node {:keys [bootstrap-node grpc-port redis-port dynamo-port s3-port sqs-port sqs-region data-dir raft-groups shard-ranges raft-engine server-env]}] + [test node {:keys [bootstrap-node grpc-port redis-port dynamo-port s3-port sqs-port sqs-region data-dir raft-groups shard-ranges raft-engine server-env join-as-learner join-members]}] (when (and (seq raft-groups) (> (count raft-groups) 1) (nil? shard-ranges)) @@ -156,20 +189,14 @@ raft-dynamo-map (when dynamo (build-raft-dynamo-map (:nodes test) grpc-port dynamo-port raft-groups)) bootstrap? (= node bootstrap-node) - args (cond-> ["--address" grpc - "--redisAddress" redis - "--raftId" (name node) - "--raftDataDir" data-dir - "--raftEngine" (or raft-engine "etcd") - "--raftRedisMap" raft-redis-map] - dynamo (conj "--dynamoAddress" dynamo - "--raftDynamoMap" raft-dynamo-map) - s3 (conj "--s3Address" s3) - sqs (conj "--sqsAddress" sqs) - (and sqs sqs-region) (conj "--sqsRegion" sqs-region) - (seq raft-groups) (conj "--raftGroups" (build-raft-groups-arg node raft-groups)) - (seq shard-ranges) (conj "--shardRanges" shard-ranges) - bootstrap? (conj "--raftBootstrap")) + args (server-args {:node node :grpc grpc :redis redis :data-dir data-dir + :raft-engine raft-engine :raft-redis-map raft-redis-map + :dynamo dynamo :raft-dynamo-map raft-dynamo-map + :s3 s3 :sqs sqs :sqs-region sqs-region + :raft-groups raft-groups :shard-ranges shard-ranges + :bootstrap? bootstrap? + :join-as-learner join-as-learner + :join-members join-members}) daemon-opts (cond-> {:chdir bin-dir :logfile log-file :pidfile pid-file @@ -209,6 +236,19 @@ "for i in $(seq 1 60); do if nc -z -w 1 $1 $2; then exit 0; fi; sleep 1; done; echo \\\"Timed out waiting for $1:$2\\\"; exit 1" "--" (name node) (str p)))))) +(defn join-members-arg + "The --raftJoinMembers value for a learner candidate: the voters it should + discover, as raftID=host:port pairs. + + Only the members that are actually part of the cluster -- the candidate + itself is excluded, since it is joining, not already a member." + [nodes reserved grpc-port] + (let [reserved (when reserved (name reserved))] + (->> nodes + (remove #(= reserved (name %))) + (map #(str (name %) "=" (name %) ":" grpc-port)) + (clojure.string/join ",")))) + (defn voter-peers "The peers setup! joins as voters: every node after the bootstrap one, minus any reserved learner candidate." @@ -234,11 +274,20 @@ (c/su (c/exec :mkdir :-p data-dir) (c/exec :rm :-f log-file transport-metrics-file))) - (start-node! test node (merge {:data-dir data-dir - :grpc-port (or (:grpc-port opts) 50051) - :redis-port (or (:redis-port opts) 6379) - :bootstrap-node (first (:nodes test))} - opts)) + (let [grpc-port (or (:grpc-port opts) 50051) + reserved (:reserve-learner opts) + learner? (and reserved (= (name node) (name reserved)))] + (start-node! test node (merge {:data-dir data-dir + :grpc-port grpc-port + :redis-port (or (:redis-port opts) 6379) + :bootstrap-node (first (:nodes test))} + opts + ;; The reserved candidate joins an existing + ;; cluster instead of bootstrapping one. + (when learner? + {:join-as-learner true + :join-members (join-members-arg + (:nodes test) reserved grpc-port)})))) (when (= node (first (:nodes test))) (let [raft-groups (:raft-groups opts) grpc-port (or (:grpc-port opts) 50051) diff --git a/jepsen/src/elastickv/learner_workload.clj b/jepsen/src/elastickv/learner_workload.clj index 64072f320..d60556b9b 100644 --- a/jepsen/src/elastickv/learner_workload.clj +++ b/jepsen/src/elastickv/learner_workload.clj @@ -72,6 +72,18 @@ ;; Pure history analysis ;; --------------------------------------------------------------------------- +(defn successful-promotions + "Promotions that reported :ok. + + The coverage gate counts these, not every completion: a history with a + :fail or :info promotion had a positive promotion count while every safety + predicate -- which all filter to :ok -- saw nothing, so a run in which no + learner was ever promoted was reported valid." + [history] + (->> history + (filter #(and (= :promote-learner (:f %)) (= :ok (:type %)))) + vec)) + (defn completed-promotions "Every :promote-learner COMPLETION. @@ -156,12 +168,24 @@ (sort-by :time) last)) -(defn- first-ok-read-after +(defn- first-ok-read-invoked-after + "The first successful read whose INVOCATION happened after t. + + Invocation, not completion: with concurrent workers a read invoked before the + promotion can linearize against the old value and return after it. Selecting + on completion time picks up exactly that read and reports the acknowledged + write as lost, so the pairing has to start from the invoke event." [history t] - (->> history - (filter #(and (= :read (:f %)) (= :ok (:type %)) (> (:time %) t))) - (sort-by :time) - first)) + (let [invoked-after (->> history + (filter #(and (= :read (:f %)) (= :invoke (:type %)) + (> (:time %) t))) + (map :process) + set)] + (->> history + (filter #(and (= :read (:f %)) (= :ok (:type %)) (> (:time %) t) + (contains? invoked-after (:process %)))) + (sort-by :time) + first))) (defn- writes-invoked-between [history from to] @@ -191,7 +215,7 @@ (keep (fn [promotion] (let [t (:time promotion) write (last-ok-write-before history t) - read (first-ok-read-after history t)] + read (first-ok-read-invoked-after history t)] ;; A read's :value is the map {:lease? b :value n}, so the ;; register value has to be unwrapped before comparing it ;; with the write's scalar. @@ -205,6 +229,18 @@ :observed-after observed}))))) vec)) +(defn promotions-without-post-read-evidence + "Successful promotions with no unambiguous successful read after them. + + lost-writes-across-promotions SKIPS a promotion it cannot pair with a later + read, which happens when catch-up finishes near the time limit. Counting + reads anywhere in the history hid that: the run passed having observed no + post-promotion state at all." + [history] + (->> (successful-promotions history) + (remove #(some? (first-ok-read-invoked-after history (:time %)))) + vec)) + (defn learner-partition-windows "Every learners-only partition interval, as [start stop] time pairs. @@ -224,6 +260,40 @@ [t (or (first (filter #(> % t) stops)) Long/MAX_VALUE)]))) vec))) +;; A lease read served from the leader's lease answers in about the time of a +;; local Pebble lookup. Losing the fast path makes it take a Raft round trip +;; instead, which is a different order of magnitude -- so a bound well above +;; normal service time and well below a round trip separates them without +;; being sensitive to ordinary jitter. +(def default-lease-read-budget-ms 250) + +(defn slow-lease-reads + "Lease reads that SUCCEEDED but took longer than the budget while only + learners were partitioned. + + Failures alone cannot detect this regression. A Redis GET calls + LeaseReadForKeyThrough, and when the lease is unavailable kv/raft_engine.go + transparently falls back to LinearizableRead -- so with the voters connected + the read still succeeds, and a failure-only check stays empty through exactly + the quorum-ack regression it claims to catch. What changes is the LATENCY, so + that is what is measured." + ([history] (slow-lease-reads history default-lease-read-budget-ms)) + ([history budget-ms] + (let [windows (learner-partition-windows history)] + (if (empty? windows) + [] + (->> history + (filter #(and (= :read (:f %)) + (= :ok (:type %)) + (true? (:lease? (:value %))) + (number? (:latency-ms (:value %))) + (> (:latency-ms (:value %)) budget-ms))) + (filter (fn [op] + (some (fn [[start stop]] + (and (>= (:time op) start) (<= (:time op) stop))) + windows))) + vec))))) + (defn learner-partition-read-failures "Lease reads that failed while only learners were partitioned. @@ -265,12 +335,14 @@ [] (reify checker/Checker (check [_ _test history _opts] - (let [promotions (completed-promotions history) + (let [promotions (successful-promotions history) premature (premature-promotions history) unmeasurable (unmeasurable-promotions history) unsampled (promotions-without-a-sampled-target history) + no-evidence (promotions-without-post-read-evidence history) lost (lost-writes-across-promotions history) stalls (learner-partition-read-failures history) + slow (slow-lease-reads history) writes (count (filter #(and (= :write (:f %)) (= :ok (:type %))) history)) reads (count (filter #(and (= :read (:f %)) (= :ok (:type %))) history))] (when (seq premature) @@ -283,16 +355,20 @@ (empty? premature) (empty? unmeasurable) (empty? unsampled) + (empty? no-evidence) (empty? lost) - (empty? stalls)) + (empty? stalls) + (empty? slow)) :promotions (count promotions) :ok-writes writes :ok-reads reads :premature-promotions premature :unmeasurable-promotions unmeasurable :unsampled-targets unsampled + :promotions-without-post-read-evidence no-evidence :lost-writes lost - :learner-read-failures stalls})))) + :learner-read-failures stalls + :slow-lease-reads slow})))) ;; --------------------------------------------------------------------------- ;; Client @@ -340,12 +416,25 @@ {:target target :applied applied})) :else (do (Thread/sleep (long catch-up-poll-ms)) (recur))))))) -(defrecord LearnerClient [node->port leader-addr conn] +(defn- redis-conn + [node->port test node] + (let [port (get node->port node 6379) + host (or (:redis-host test) (name node))] + {:pool {} :spec {:host host :port port :timeout-ms 10000}})) + +(defrecord LearnerClient [node->port leader-addr conn leaseConn] client/Client (open! [this test node] - (let [port (get node->port node 6379) - host (or (:redis-host test) (name node))] - (assoc this :conn {:pool {} :spec {:host host :port port :timeout-ms 10000}}))) + (assoc this + :conn (redis-conn node->port test node) + ;; Lease probes go to a CONNECTED VOTER, not to this worker's own + ;; node. A GET issued through the isolated learner has to proxy to + ;; the leader across the partition and can fail even when the + ;; leader's lease is perfectly healthy -- the checker would then + ;; read client placement as a quorum-ack regression. Ordinary + ;; register traffic stays distributed; only the lease measurement + ;; is pinned. + :leaseConn (redis-conn node->port test (first (:nodes test))))) (close! [this _test] this) (setup! [_this _test]) @@ -358,16 +447,29 @@ addr (or leader-addr (str leader ":50051"))] (try (case (:f op) - :write (do (wcar conn (car/set register-key (:value op))) - (assoc op :type :ok)) - - ;; :lease? marks the read as one the leader may serve from its - ;; lease, which is the path a learner wrongly counted in - ;; quorumAckTracker would break. - :read (let [v (wcar conn (car/get register-key))] + ;; The reply is CHECKED. Carmine returns nil or a Throwable value on + ;; missing, protocol and some error-reply paths, and treating those + ;; as acknowledged would let the checker call an unconfirmed write + ;; durable -- producing either a false loss or a false preservation + ;; later. Anything that is not "OK" is :info (indeterminate), which + ;; is what an unacknowledged write actually is. + :write (let [reply (wcar conn (car/set register-key (:value op)))] + (if (= "OK" (some-> reply str)) + (assoc op :type :ok) + (assoc op :type :info :error {:unexpected-reply reply}))) + + ;; :lease? marks the read as one the leader may serve from its lease, + ;; which is the path a learner wrongly counted in quorumAckTracker + ;; would break. :latency-ms is recorded because losing the fast path + ;; does not fail the read -- the engine falls back to + ;; LinearizableRead -- it makes it take a Raft round trip. + :read (let [started (System/nanoTime) + v (wcar (:leaseConn this) (car/get register-key)) + elapsed (/ (double (- (System/nanoTime) started)) 1e6)] (assoc op :type :ok - :value {:lease? true - :value (when v (Long/parseLong (str v)))})) + :value {:lease? true + :latency-ms elapsed + :value (when v (Long/parseLong (str v)))})) :add-learner (let [candidate (name (:value op))] @@ -392,7 +494,15 @@ :target-source :leader-commit-index :match applied}))) (catch Exception e - (assoc op :type :fail :error (.getMessage e))))))) + ;; A failed READ keeps its :lease? marker. Returning the bare op left + ;; every real read exception without it, so + ;; learner-partition-read-failures filtered them all out and the + ;; lease regression could never invalidate a run. + (if (= :read (:f op)) + (assoc op :type :fail + :value {:lease? true} + :error (.getMessage e)) + (assoc op :type :fail :error (.getMessage e)))))))) ;; --------------------------------------------------------------------------- ;; Nemesis @@ -403,22 +513,49 @@ That is the shape the quorum property needs: voters retain quorum among themselves, so anything that degrades must be attributable to the learner - being counted where it should not be." + being counted where it should not be. + + Implemented directly rather than via nemesis/partitioner, which dispatches on + :start and :stop. Feeding it :start-partition / :stop-partition matched no + branch, so the learner was never isolated and the partition workload ran with + no fault at all -- and its :value would have been taken as the grudge itself, + which is not one." [nodes] - (let [learner (learner-candidate nodes)] - (nemesis/partitioner - (fn [_test _nodes] - (nemesis/complete-grudge [[learner] (voter-nodes nodes)]))))) + (let [learner (learner-candidate nodes) + grudge (nemesis/complete-grudge [[learner] (voter-nodes nodes)])] + (reify nemesis/Nemesis + (setup! [this test] + (net/heal! (:net test) test) + this) + + (invoke! [_this test op] + (case (:f op) + :start-partition (do (net/drop-all! test grudge) + (assoc op :value {:scope :learners-only + :isolated [learner]})) + :stop-partition (do (net/heal! (:net test) test) + (assoc op :value {:scope :learners-only + :healed true})) + (assoc op :value :unsupported))) + + (teardown! [_this test] + (net/heal! (:net test) test))))) (defn learner-nemesis-generator - "start-partition / stop-partition pairs, each start tagged :learners-only so - the checker can pair it with its own stop." + "ONE start-partition / stop-partition pair, tagged :learners-only. + + Not a cycle. The promotion converts the candidate into a voter, so a later + window carrying the same :learners-only label is isolating a node that now + counts toward quorum: later failures or latency would be attributed to + learner handling, and on a small cluster the isolation could remove a + legitimate voter quorum outright. The single window is opened before the + promotion phase and closed before it runs." [] ;; A seq is a generator in Jepsen 0.3.x; gen/seq was removed. - (cycle [(gen/sleep 5) - {:type :info :f :start-partition :value {:scope :learners-only}} - (gen/sleep 10) - {:type :info :f :stop-partition :value {:scope :learners-only}}])) + [(gen/sleep 2) + {:type :info :f :start-partition} + (gen/sleep 4) + {:type :info :f :stop-partition}]) ;; --------------------------------------------------------------------------- ;; Generator @@ -466,6 +603,10 @@ (repeat (count nodes) redis-port) nodes))] {:name "elastickv-learner" :nodes nodes + ;; Carried into the test map so LearnerClient.open! can honour it. + ;; Without this a programmatic caller could not override the host, and + ;; local or port-mapped runs tried to resolve each logical node name. + :redis-host (:redis-host opts) :db db :os (if local? os/noop debian/os) :net (if local? net/noop net/iptables) @@ -475,7 +616,7 @@ (when local? {:dummy true}) (:ssh opts)) :remote control/ssh - :client (->LearnerClient ports nil nil) + :client (->LearnerClient ports nil nil nil) :nemesis (if local? nemesis/noop (learner-partition-nemesis nodes)) ;; Jepsen 0.3.x cannot fressian-serialize some final generators. :final-generator nil @@ -492,10 +633,23 @@ :grpc-port grpc-port :ports ports}))) +(defn prepare-learner-opts + "Normalise parsed CLI options for elastickv-learner-test. + + Not `identity`. run-workload! hands the raw parsed map straight through, and + common-cli-opts leaves :nodes as the comma-separated STRING it came from -- so + the constructor treated a string as a node collection: learner-candidate + returned its last character, the port map was keyed by characters, and the + resulting Jepsen :nodes was invalid. parse-common-opts splits it, and the host + override is copied to :redis-host so the client can honour it." + [options] + (let [options (cli/parse-common-opts options nil)] + (assoc options :redis-host (:host options)))) + (defn -main "Runnable entry point. Without one, neither invocation form could select this workload: the namespace had no -main, and the shared dispatcher in elastickv.jepsen-test neither required it nor listed it, so passing its name fell through to the Redis test." [& args] - (cli/run-workload! args cli/common-cli-opts identity elastickv-learner-test)) + (cli/run-workload! args cli/common-cli-opts prepare-learner-opts elastickv-learner-test)) diff --git a/jepsen/test/elastickv/learner_workload_test.clj b/jepsen/test/elastickv/learner_workload_test.clj index eb989657d..bbcf623f2 100644 --- a/jepsen/test/elastickv/learner_workload_test.clj +++ b/jepsen/test/elastickv/learner_workload_test.clj @@ -11,7 +11,8 @@ [elastickv.db :as ekdb] [elastickv.jepsen-test :as jt] [elastickv.learner-workload :as lw] - [jepsen.checker :as checker])) + [jepsen.checker :as checker] + [jepsen.nemesis])) (defn- check [history] (checker/check (lw/learner-safety-checker) {} history {})) @@ -33,9 +34,18 @@ (concat healthy-prefix [{:type :invoke :f :promote-learner :value "n5" :time 50 :process 0} (promotion {} 60) + ;; Invoked AFTER the promotion completed, which is what makes this + ;; read evidence about post-promotion state. {:type :invoke :f :read :time 70 :process 0} {:type :ok :f :read :value {:lease? true :value 1} :time 80 :process 0}])) +;; A post-promotion read, invoke and completion, for histories whose subject is +;; some other property but which still have to satisfy the coverage gate. +(defn- post-promotion-read + ([t] (post-promotion-read t 1)) + ([t v] [{:type :invoke :f :read :time t :process 0} + {:type :ok :f :read :value {:lease? true :value v} :time (inc t) :process 0}])) + (deftest healthy-history-is-valid (is (:valid? (check (healthy-history))))) @@ -56,7 +66,8 @@ (let [r (check (concat healthy-prefix [(promotion {:catch-up-target 100 :match 100 - :leader-commit-index 100000} 60)]))] + :leader-commit-index 100000} 60)] + (post-promotion-read 70)))] (is (:valid? r) "a learner that reached its sampled target is caught up, whatever the leader did since"))) @@ -165,6 +176,7 @@ (deftest a-read-failure-outside-any-window-is-not-attributed-to-the-learner (let [r (check (concat healthy-prefix [(promotion {} 50)] + (post-promotion-read 60) (partition-window 100 200) [{:type :invoke :f :read :time 500} {:type :fail :f :read :value {:lease? true} :time 510}]))] @@ -245,3 +257,157 @@ (is (= 4211 (:commit_index got))) (is (= 4207 (:applied_index got))) (is (= "n1" (:leader_id got))))) + +;; --------------------------------------------------------------------------- +;; Round 3: the workload has to be able to run, and each property has to be +;; able to fire. Every test below names the way the previous revision passed +;; wrongly. +;; --------------------------------------------------------------------------- + +(deftest coverage-requires-a-successful-promotion + ;; The gate counted every completion, so a history with good reads and writes + ;; plus a FAILED promotion had a positive count while every safety predicate + ;; — which all filter to :ok — saw nothing. A run in which no learner was + ;; ever promoted was reported valid. + (let [failed (check (concat healthy-prefix + [{:type :invoke :f :promote-learner :value "n5" :time 50} + {:type :fail :f :promote-learner :time 60}] + (post-promotion-read 70)))] + (is (false? (:valid? failed))) + (is (zero? (:promotions failed)) + "a failed promotion is not a promotion"))) + +(deftest a-promotion-with-no-read-after-it-is-invalid + ;; lost-writes-across-promotions SILENTLY SKIPS a promotion it cannot pair + ;; with a later read, which happens when catch-up finishes near the time + ;; limit. Counting reads anywhere in the history hid that: the run passed + ;; having observed no post-promotion state at all. + (let [r (check (concat healthy-prefix [(promotion {} 60)]))] + (is (false? (:valid? r))) + (is (= 1 (count (:promotions-without-post-read-evidence r)))))) + +(deftest a-read-invoked-before-the-promotion-is-not-post-promotion-evidence + ;; With concurrent workers a read invoked before the promotion can linearize + ;; against the old value and return after it. Selecting on completion time + ;; alone picked up exactly that read — both accepting it as evidence and + ;; reporting the acknowledged write as lost. + (let [r (check [{:type :invoke :f :write :value 7 :time 10} + {:type :ok :f :write :value 7 :time 20} + ;; Invoked BEFORE the promotion, returns after it. + {:type :invoke :f :read :time 30 :process 1} + {:type :invoke :f :promote-learner :value "n5" :time 40} + (promotion {} 50) + {:type :ok :f :read :value {:lease? true :value 7} :time 60 :process 1}])] + (is (false? (:valid? r))) + (is (= 1 (count (:promotions-without-post-read-evidence r))) + "a read that started before the promotion proves nothing about after it") + (is (empty? (:lost-writes r)) + "and it must not be mistaken for a lost write either"))) + +(deftest a-slow-lease-read-under-learner-isolation-is-rejected + ;; Failures alone cannot detect the quorum-ack regression: a Redis GET calls + ;; LeaseReadForKeyThrough, and when the lease is unavailable the engine falls + ;; back to LinearizableRead transparently — so with the voters connected the + ;; read SUCCEEDS and a failure-only check stays empty through exactly the + ;; regression it claims to catch. What changes is the latency. + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (post-promotion-read 60) + (partition-window 100 200) + [{:type :invoke :f :read :time 120} + {:type :ok :f :read :time 130 + :value {:lease? true :latency-ms 900.0 :value 1}}]))] + (is (false? (:valid? r))) + (is (= 1 (count (:slow-lease-reads r))) + "a lease read that fell back to a Raft round trip must fail the run"))) + +(deftest a-fast-lease-read-under-learner-isolation-is-fine + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (post-promotion-read 60) + (partition-window 100 200) + [{:type :invoke :f :read :time 120} + {:type :ok :f :read :time 130 + :value {:lease? true :latency-ms 3.0 :value 1}}]))] + (is (:valid? r) (str "slow=" (:slow-lease-reads r))))) + +(deftest a-slow-lease-read-outside-the-window-is-not-attributed-to-the-learner + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (post-promotion-read 60) + (partition-window 100 200) + [{:type :invoke :f :read :time 500} + {:type :ok :f :read :time 510 + :value {:lease? true :latency-ms 900.0 :value 1}}]))] + (is (:valid? r) (str "slow=" (:slow-lease-reads r))))) + +(deftest the-nemesis-handles-the-operations-the-generator-emits + ;; jepsen.nemesis/partitioner dispatches on :start and :stop. Feeding it + ;; :start-partition / :stop-partition matched no branch, so the learner was + ;; never isolated and the partition workload ran with no fault at all — and + ;; its :value would have been taken as the grudge, which is not one. + (let [nodes ["n1" "n2" "n3" "n4" "n5"] + emitted (->> (lw/learner-nemesis-generator) + (tree-seq coll? seq) + (keep #(when (map? %) (:f %))) + set)] + (is (= #{:start-partition :stop-partition} emitted)) + ;; And the nemesis must claim exactly those. + (let [n (lw/learner-partition-nemesis nodes)] + (is (some? n)) + (is (satisfies? jepsen.nemesis/Nemesis n))))) + +(deftest the-learner-partition-runs-once-not-in-a-cycle + ;; The promotion converts the candidate into a voter, so a later window + ;; carrying the same :learners-only label isolates a node that now counts + ;; toward quorum: failures and latency after that are not learner behaviour, + ;; and on a small cluster the isolation can remove a legitimate voter quorum. + (let [ops (->> (lw/learner-nemesis-generator) + (tree-seq coll? seq) + (keep #(when (map? %) (:f %))))] + (is (= 1 (count (filter #{:start-partition} ops)))) + (is (= 1 (count (filter #{:stop-partition} ops)))))) + +(deftest cli-options-are-parsed-before-the-workload-is-constructed + ;; run-workload! hands the raw parsed map straight through, and + ;; common-cli-opts leaves :nodes as the comma-separated STRING. With identity + ;; as the preparation fn the constructor treated that string as a node + ;; collection: learner-candidate returned its last character and the port map + ;; was keyed by characters. + (let [prepared (lw/prepare-learner-opts {:nodes "n1,n2,n3" :faults ""})] + (is (= ["n1" "n2" "n3"] (:nodes prepared)) + "a comma-separated string must be split before it reaches the constructor") + (is (= "n3" (lw/learner-candidate (:nodes prepared)))))) + +(deftest the-redis-host-override-reaches-the-test-map + ;; LearnerClient.open! reads :redis-host from the completed test map, so the + ;; constructor has to carry it; otherwise a programmatic caller could not + ;; override the host and local runs tried to resolve each logical node name. + (let [t (lw/elastickv-learner-test {:nodes ["n1" "n2" "n3"] :redis-host "127.0.0.1"})] + (is (= "127.0.0.1" (:redis-host t))))) + +(deftest the-reserved-candidate-starts-with-a-join-configuration + ;; Reserving the candidate only kept it out of the add_voter loop; it still + ;; launched as a fresh non-bootstrap process with no peers, which the etcd + ;; engine refuses (errNoPeersConfigured), so it exited before :add-learner + ;; could attach it. + (let [args (set (ekdb/server-args {:node "n5" :grpc "n5:50051" :redis "n5:6379" + :data-dir "/var/lib/elastickv" + :raft-redis-map "n5=n5:6379" + :join-as-learner true + :join-members "n1=n1:50051,n2=n2:50051"}))] + (is (contains? args "--raftJoinAsLearner")) + (is (contains? args "--raftJoinMembers")) + (is (contains? args "n1=n1:50051,n2=n2:50051"))) + + ;; The candidate itself is excluded from the members it discovers: it is + ;; joining, not already a member. + (is (= "n1=n1:50051,n2=n2:50051" + (ekdb/join-members-arg ["n1" "n2" "n5"] "n5" 50051))) + + ;; An ordinary voter gets neither flag. + (let [args (set (ekdb/server-args {:node "n2" :grpc "n2:50051" :redis "n2:6379" + :data-dir "/var/lib/elastickv" + :raft-redis-map "n2=n2:6379"}))] + (is (not (contains? args "--raftJoinAsLearner"))) + (is (not (contains? args "--raftJoinMembers"))))) From 78187c0fa890c549ccf91767cb6cc6ae95496289 Mon Sep 17 00:00:00 2001 From: bootjp Date: Wed, 16 Sep 2026 20:54:40 +0900 Subject: [PATCH 4/7] jepsen: give the learner workload properties that can fail Seven review findings, and six of them are the same defect: a property stated in the docstring that the run could not actually violate. The topology never exercised the transition. Five nodes reserve one candidate, so the run starts at four voters and promotion takes it to five -- but majority(4) and majority(5) are both 3, and followerQuorumForClusterSize is 2 for both. Three voters going to four moves the majority from 2 to 3 and the follower quorum from 1 to 2, so that is the default now, with promotion-changes-quorum? as the check. min_applied_index enforcement could not be observed. The live path samples the target, waits for the learner to reach it, then records that already-qualified index as :match, so match >= target holds by construction and premature-promotions stays empty even if the engine dropped the test entirely. A new op asks for a promotion at an index far above the leader's commit index, which no learner can have reached; rejection is the pass, acceptance is the defect, and a run that never asked is not evidence either. Lease-path evidence was a latency budget, which cannot separate the two paths. LinearizableRead issues a ReadIndex immediately and, with every voter connected on one host, its round trip is milliseconds -- so any budget loose enough not to flag jitter sits far above the fallback's cost, and a run can turn every GET into a successful slow-path read and still pass. elastickv_lease_read_total separates them by construction: its help text defines miss as "fell back to LinearizableRead". The nemesis now samples it at both window edges, a positive miss delta fails the run, and an unmoved hit delta -- or an unreachable endpoint -- is reported as no evidence rather than as a pass. Read coverage counted successful reads anywhere in the run. The partition opened at 2s while :add-learner was not issued until ~5s and the heal came at 6s, so barely a second had the candidate both attached and isolated, and at rate 5 that interval could contain no read at all. The window now opens after attachment and the traffic phase spans it. Two checker bugs, both false verdicts rather than missed ones. A process set is not an invocation pairing: a process that read before the promotion, completed after, then read again was treated as though its first, stale completion had been invoked after -- admitting exactly the evidence the invocation filter exists to exclude. And completion order alone does not identify a register's final value: write 1 over t=10..40 with write 2 over t=20..30 linearizes either way, so a later read of 2 is legal, but looking only for writes invoked after 40 found none and reported a loss. Ambiguity is now overlap with the selected write's own interval. The candidate could not start. resolveJoinServers refuses a members list that omits the local --raftId and also requires its address to match the local listener, so a candidate handed only the voters received the join flags and then exited during startup validation. Each of the seven is revert-checked: putting the old behaviour back fails exactly the test that covers it, and nothing else. NOT changed: net/drop-all!, which review asked to be passed (:net test). jepsen.net/drop-all! is a 2-arity wrapper defined in jepsen.net that reads (:net test) itself; only jepsen.net.proto/drop-all! takes net first. The adjacent heal! differs because it is import-vars'd straight from the protocol. Adding the argument would break the call. Claude-Session: https://claude.ai/code/session_013rNHooj7NF3giihWVba8QE --- jepsen/src/elastickv/db.clj | 58 ++- jepsen/src/elastickv/learner_workload.clj | 375 ++++++++++++++---- .../test/elastickv/learner_workload_test.clj | 246 +++++++++--- 3 files changed, 549 insertions(+), 130 deletions(-) diff --git a/jepsen/src/elastickv/db.clj b/jepsen/src/elastickv/db.clj index de24119da..0952a63aa 100644 --- a/jepsen/src/elastickv/db.clj +++ b/jepsen/src/elastickv/db.clj @@ -2,6 +2,7 @@ "Jepsen DB adapter that builds, deploys, and manages elastickv nodes." (:require [clojure.java.io :as io] [clojure.java.shell :as sh] + [clojure.string :as str] [clojure.tools.logging :refer [info warn]] [jepsen [db :as db] [util :as util]] @@ -95,6 +96,39 @@ (c/on node (c/su (c/exec :env "RAFTADMIN_ALLOW_INSECURE=true" raftadmin-bin addr "status"))))) +(def ^:private metrics-port 9090) + +(defn lease-read-counters + "Reads elastickv_lease_read_total{outcome=...} from a node's metrics + endpoint, as {:hit n :miss n}. + + This is the only direct evidence of WHICH read path ran. A lease read that + loses the fast path does not fail -- kv/raft_engine.go falls back to + LinearizableRead -- and on a single-host cluster that fallback costs + milliseconds, so latency cannot separate the two either. The counter can: + the metric's own help text defines miss as \"fell back to LinearizableRead\". + + Returns nil when the endpoint is unreachable, so a caller can tell \"no + samples\" apart from \"zero misses\"." + [node] + (try + (let [out (c/on node + (c/su (c/exec :curl :--connect-timeout 2 :--max-time 5 :-fsS + (str "http://127.0.0.1:" metrics-port "/metrics")))) + grab (fn [outcome] + (some->> (str/split-lines (str out)) + (filter #(str/starts-with? + % (str "elastickv_lease_read_total{outcome=\"" + outcome "\"}"))) + first + (re-find #"\s([0-9.eE+-]+)\s*$") + second + Double/parseDouble + long))] + (when-let [hit (grab "hit")] + {:hit hit :miss (or (grab "miss") 0)})) + (catch Exception _ nil))) + (defn- node-addr "Returns host:port for the node and port." [node port] @@ -237,16 +271,22 @@ "--" (name node) (str p)))))) (defn join-members-arg - "The --raftJoinMembers value for a learner candidate: the voters it should - discover, as raftID=host:port pairs. - - Only the members that are actually part of the cluster -- the candidate - itself is excluded, since it is joining, not already a member." + "The --raftJoinMembers value for a learner candidate: raftID=host:port pairs. + + The candidate is INCLUDED, at its own listener address. Excluding it looks + right -- it is joining, not already a member -- but `resolveJoinServers` + (main.go) refuses to start when the list omits the local --raftId, returning + ErrJoinMembersMissingLocalNode, and it also requires the entry's address to + equal the local listener address. So a candidate handed a members list + without itself receives the join flags and then exits during startup + validation, which is not a learner that can be attached." [nodes reserved grpc-port] - (let [reserved (when reserved (name reserved))] - (->> nodes - (remove #(= reserved (name %))) - (map #(str (name %) "=" (name %) ":" grpc-port)) + (let [reserved (when reserved (name reserved)) + members (->> nodes + (map name) + (remove #(= reserved %)))] + (->> (if reserved (conj (vec members) reserved) (vec members)) + (map #(str % "=" % ":" grpc-port)) (clojure.string/join ",")))) (defn voter-peers diff --git a/jepsen/src/elastickv/learner_workload.clj b/jepsen/src/elastickv/learner_workload.clj index d60556b9b..4bac597a4 100644 --- a/jepsen/src/elastickv/learner_workload.clj +++ b/jepsen/src/elastickv/learner_workload.clj @@ -52,7 +52,15 @@ [os :as os]] [taoensso.carmine :as car :refer [wcar]])) -(def default-nodes ["n1" "n2" "n3" "n4" "n5"]) +;; FOUR nodes, not five: three voters plus the reserved candidate. +;; +;; With five, the run starts at four voters and promotion takes it to five -- +;; but majority(4) and majority(5) are both 3, and followerQuorumForClusterSize +;; is 2 for both, so the quorum-denominator transition this workload is named +;; for never actually happens and a bug that only appears when promotion raises +;; the threshold cannot surface. Three voters going to four moves the majority +;; from 2 to 3 and the follower quorum from 1 to 2. +(def default-nodes ["n1" "n2" "n3" "n4"]) ;; The last node is reserved as the learner candidate: ElastickvDB's setup ;; otherwise runs `raftadmin add_voter` for every node after the bootstrap @@ -68,6 +76,23 @@ "The nodes that join as voters during setup." [nodes] (vec (butlast nodes))) + +(defn- raft-majority + "floor(N/2)+1 -- the voters a proposal needs, including the leader." + [n] + (inc (quot n 2))) + +(defn promotion-changes-quorum? + "Whether promoting the candidate actually raises the Raft majority. + + This is the workload's reason to exist, and it is not true of every + topology: four voters going to five needs three either way. A run on such a + topology exercises the promotion mechanics but not the transition, so the + constructor warns rather than letting a green result be read as evidence + about quorum handling." + [nodes] + (let [voters (count (voter-nodes nodes))] + (> (raft-majority (inc voters)) (raft-majority voters)))) ;; --------------------------------------------------------------------------- ;; Pure history analysis ;; --------------------------------------------------------------------------- @@ -148,6 +173,35 @@ (< match catch-up-target))))) vec)) +(defn unenforced-min-applied-index + "Deliberately premature promotions the server ACCEPTED. + + premature-promotions cannot fail on its own. The live workflow samples the + target, waits for the learner to reach it, and only then promotes, recording + that already-qualified applied index as :match -- so match >= target holds by + construction and the property stays empty even if the engine dropped its + min_applied_index test entirely. + + The only way to show the enforcement exists is to ask for something it must + refuse. This op promotes with a min_applied_index far above the leader's + commit index, which no learner can have reached, and expects rejection. + A success here is the defect premature-promotions was meant to catch." + [history] + (->> history + (filter #(and (= :promote-learner-early (:f %)) (= :ok (:type %)))) + vec)) + +(defn unattempted-min-applied-index-probe + "True when the run never issued the premature-promotion probe at all. + + A probe that did not run is not evidence of enforcement, and an empty + unenforced-min-applied-index would otherwise look identical to a passing + one." + [history] + (empty? (filter #(and (= :promote-learner-early (:f %)) + (contains? #{:ok :fail :info} (:type %))) + history))) + (defn promotions-without-a-sampled-target "Promotions whose catch-up target did not come from the leader. @@ -161,38 +215,108 @@ (remove #(= :leader-commit-index (:target-source (:value %)))) vec)) -(defn- last-ok-write-before +(defn- write-intervals + "Each write as [invoke-time complete-time op], for overlap tests. + + A write still in flight has no completion; it is treated as running to the + end of the history, because a write that never completed can still have + taken effect." + [history] + (let [writes (->> history (filter #(= :write (:f %))) (sort-by :time)) + end (or (some->> history (map :time) (reduce max)) 0)] + (->> writes + (reduce (fn [{:keys [pending done]} op] + (case (:type op) + :invoke {:pending (assoc pending (:process op) op) + :done done} + (:ok :fail :info) + (if-let [inv (get pending (:process op))] + {:pending (dissoc pending (:process op)) + :done (conj done [(:time inv) (:time op) op])} + {:pending pending :done done}) + {:pending pending :done done})) + {:pending {} :done []}) + ((fn [{:keys [pending done]}] + (into done (map (fn [[_ inv]] [(:time inv) end inv]) + pending))))))) + +(defn- concurrent-writes + "Writes whose execution interval overlaps [from to], excluding the write + that defines it. + + Completion order alone does not identify a register's final value. Write 1 + running t=10..40 and write 2 running t=20..30 both linearize either way, so + a later read of 2 is legal even though 1 completed last and no write was + INVOKED after 40. Looking only at invocations in (from, to) misses write 2 + entirely and reports a loss that never happened. + + So the ambiguity test is overlap with the selected write's own interval, not + just the gap between it and the read." + [history from to selected] + (->> (write-intervals history) + (remove (fn [[_ _ op]] (identical? op selected))) + (filter (fn [[start stop _]] (and (< start to) (> stop from)))) + (mapv (fn [[_ _ op]] op)))) + +(defn- last-ok-write-interval-before + "The last write acknowledged before t, as its [invoke complete op] triple. + + The triple, not the op: the caller needs the write's own INVOCATION time to + test what overlapped it, and it needs the identical op so that write can be + excluded from its own overlap set. Returning a copy with the invocation time + attached breaks the second -- the copy is not identical to the entry in the + interval list, so the selected write counts as overlapping itself and every + history looks ambiguous." [history t] - (->> history - (filter #(and (= :write (:f %)) (= :ok (:type %)) (< (:time %) t))) - (sort-by :time) + (->> (write-intervals history) + (filter (fn [[_ stop op]] (and (= :ok (:type op)) (< stop t)))) + (sort-by (fn [[_ stop _]] stop)) last)) +(defn- read-invocation-times + "Each successful read paired with the time it was actually invoked. + + A process set is not enough. If process P invokes a read before t, completes + it after t, and then invokes another read after t, P is in the set of + processes that invoked after t -- so the EARLIER, pre-t read is selected as + though it had been invoked after t. That admits exactly the stale evidence + the invocation filter exists to exclude. + + Jepsen runs one operation at a time per process, so the invocation a + completion belongs to is the last invoke on that process before it." + [history] + (let [reads (->> history + (filter #(= :read (:f %))) + (sort-by :time))] + (->> reads + (reduce (fn [{:keys [pending done]} op] + (case (:type op) + :invoke {:pending (assoc pending (:process op) (:time op)) + :done done} + (:ok :fail :info) + {:pending (dissoc pending (:process op)) + :done (if (and (= :ok (:type op)) + (contains? pending (:process op))) + (conj done (assoc op ::invoked-at + (get pending (:process op)))) + done)} + {:pending pending :done done})) + {:pending {} :done []}) + :done))) + (defn- first-ok-read-invoked-after - "The first successful read whose INVOCATION happened after t. + "The first successful read whose own INVOCATION happened after t. Invocation, not completion: with concurrent workers a read invoked before the promotion can linearize against the old value and return after it. Selecting on completion time picks up exactly that read and reports the acknowledged - write as lost, so the pairing has to start from the invoke event." + write as lost, so the pairing has to start from the invoke event -- and from + THIS completion's invoke event, not from any invoke the same process made." [history t] - (let [invoked-after (->> history - (filter #(and (= :read (:f %)) (= :invoke (:type %)) - (> (:time %) t))) - (map :process) - set)] - (->> history - (filter #(and (= :read (:f %)) (= :ok (:type %)) (> (:time %) t) - (contains? invoked-after (:process %)))) - (sort-by :time) - first))) - -(defn- writes-invoked-between - [history from to] - (->> history - (filter #(and (= :write (:f %)) (= :invoke (:type %)) - (> (:time %) from) (< (:time %) to))) - vec)) + (->> (read-invocation-times history) + (filter #(> (::invoked-at %) t)) + (sort-by :time) + first)) (defn lost-writes-across-promotions "Acknowledged writes that a promotion lost, by TEMPORAL ordering. @@ -213,16 +337,20 @@ (->> (completed-promotions history) (filter #(= :ok (:type %))) (keep (fn [promotion] - (let [t (:time promotion) - write (last-ok-write-before history t) - read (first-ok-read-invoked-after history t)] + (let [t (:time promotion) + interval (last-ok-write-interval-before history t) + [w-start _ write] interval + read (first-ok-read-invoked-after history t)] ;; A read's :value is the map {:lease? b :value n}, so the ;; register value has to be unwrapped before comparing it ;; with the write's scalar. (let [observed (get-in read [:value :value])] (when (and write read - (empty? (writes-invoked-between - history (:time write) (:time read))) + ;; From the selected write's own INVOCATION, so a + ;; write that overlapped it counts as ambiguity + ;; rather than being skipped. + (empty? (concurrent-writes + history w-start (:time read) write)) (not= (:value write) observed)) {:promotion (:value promotion) :acked-write (:value write) @@ -260,39 +388,77 @@ [t (or (first (filter #(> % t) stops)) Long/MAX_VALUE)]))) vec))) -;; A lease read served from the leader's lease answers in about the time of a -;; local Pebble lookup. Losing the fast path makes it take a Raft round trip -;; instead, which is a different order of magnitude -- so a bound well above -;; normal service time and well below a round trip separates them without -;; being sensitive to ordinary jitter. -(def default-lease-read-budget-ms 250) +(defn- partition-edge-counters + "The {:hit n :miss n} samples the nemesis took at each window's edges." + [history] + (let [nemesis (->> history (filter #(= :nemesis (:process %))) (sort-by :time)) + starts (->> nemesis + (filter #(and (= :start-partition (:f %)) + (= :learners-only (get-in % [:value :scope])) + (= :info (:type %)))) + vec) + stops (->> nemesis + (filter #(and (= :stop-partition (:f %)) (= :info (:type %)))) + vec)] + (->> starts + (keep (fn [start] + (when-let [stop (->> stops + (filter #(> (:time %) (:time start))) + first)] + {:start start + :stop stop + :before (get-in start [:value :lease-counters]) + :after (get-in stop [:value :lease-counters])}))) + vec))) -(defn slow-lease-reads - "Lease reads that SUCCEEDED but took longer than the budget while only - learners were partitioned. +(defn lease-fast-path-losses + "Windows in which a lease read FELL BACK to the linearizable path. - Failures alone cannot detect this regression. A Redis GET calls + Neither failures nor latency can establish this. A Redis GET calls LeaseReadForKeyThrough, and when the lease is unavailable kv/raft_engine.go - transparently falls back to LinearizableRead -- so with the voters connected - the read still succeeds, and a failure-only check stays empty through exactly - the quorum-ack regression it claims to catch. What changes is the LATENCY, so - that is what is measured." - ([history] (slow-lease-reads history default-lease-read-budget-ms)) - ([history budget-ms] - (let [windows (learner-partition-windows history)] - (if (empty? windows) - [] - (->> history - (filter #(and (= :read (:f %)) - (= :ok (:type %)) - (true? (:lease? (:value %))) - (number? (:latency-ms (:value %))) - (> (:latency-ms (:value %)) budget-ms))) - (filter (fn [op] - (some (fn [[start stop]] - (and (>= (:time op) start) (<= (:time op) stop))) - windows))) - vec))))) + transparently falls back to LinearizableRead -- so a failure-only check stays + empty through exactly the regression it claims to catch. Latency does not + separate them either: LinearizableRead issues a ReadIndex immediately and, + with every voter connected on one host, its quorum round trip completes in a + few milliseconds. Any budget loose enough not to flag ordinary jitter is far + above the fallback's actual cost, so a run can turn every GET into a + successful slow-path read and still report valid. + + elastickv_lease_read_total separates them by construction: the metric's own + help text defines miss as \"fell back to LinearizableRead\". So the property + is a counter delta across the window, not a time." + [history] + (->> (partition-edge-counters history) + (keep (fn [{:keys [before after start]}] + (when (and before after) + (let [delta (- (:miss after) (:miss before))] + (when (pos? delta) + {:window-start (:time start) + :miss-delta delta}))))) + vec)) + +(defn unmeasured-partition-windows + "Windows that produced no evidence either way. + + Two ways a window proves nothing, and both used to read as a pass: + + - the counters could not be sampled at all (metrics endpoint unreachable), + so zero misses is indistinguishable from no data; + - the lease hit counter did not move, meaning no read was served from the + leader's lease while the candidate was attached and isolated. The read + coverage gate counted successful reads ANYWHERE in the run, so reads taken + before attachment or after the heal satisfied it while the quorum-ack + property was never exercised." + [history] + (->> (partition-edge-counters history) + (keep (fn [{:keys [before after start]}] + (cond + (or (nil? before) (nil? after)) + {:window-start (:time start) :reason :counters-unavailable} + + (not (pos? (- (:hit after) (:hit before)))) + {:window-start (:time start) :reason :no-lease-read-served}))) + vec)) (defn learner-partition-read-failures "Lease reads that failed while only learners were partitioned. @@ -342,23 +508,33 @@ no-evidence (promotions-without-post-read-evidence history) lost (lost-writes-across-promotions history) stalls (learner-partition-read-failures history) - slow (slow-lease-reads history) + fallbacks (lease-fast-path-losses history) + unmeasured (unmeasured-partition-windows history) + unenforced (unenforced-min-applied-index history) + no-probe (unattempted-min-applied-index-probe history) writes (count (filter #(and (= :write (:f %)) (= :ok (:type %))) history)) reads (count (filter #(and (= :read (:f %)) (= :ok (:type %))) history))] (when (seq premature) (warn "learner promoted before reaching its sampled target:" premature)) (when (seq unmeasurable) (warn "promotion reported ok without catch-up evidence:" unmeasurable)) + (when (seq unenforced) + (warn "server accepted a promotion below min_applied_index:" unenforced)) + (when (seq unmeasured) + (warn "partition window produced no lease evidence:" unmeasured)) {:valid? (and (pos? (count promotions)) (pos? writes) (pos? reads) + (not no-probe) (empty? premature) (empty? unmeasurable) (empty? unsampled) (empty? no-evidence) (empty? lost) (empty? stalls) - (empty? slow)) + (empty? fallbacks) + (empty? unmeasured) + (empty? unenforced)) :promotions (count promotions) :ok-writes writes :ok-reads reads @@ -368,7 +544,10 @@ :promotions-without-post-read-evidence no-evidence :lost-writes lost :learner-read-failures stalls - :slow-lease-reads slow})))) + :lease-fast-path-losses fallbacks + :unmeasured-partition-windows unmeasured + :unenforced-min-applied-index unenforced + :min-applied-index-probe-ran (not no-probe)})))) ;; --------------------------------------------------------------------------- ;; Client @@ -477,6 +656,26 @@ (str candidate ":" (:grpc-port test 50051)) "0") (assoc op :type :ok)) + ;; Asks the server for something it must refuse: promotion at a + ;; min_applied_index far above the leader's own commit index, which + ;; no learner can have reached. Rejection is the pass. This is the + ;; only way the enforcement can be observed -- the live promotion + ;; path waits for catch-up first, so it can never present the server + ;; with a violation to reject. + :promote-learner-early + (let [candidate (name (:value op)) + candidate-addr (str candidate ":" (:grpc-port test 50051)) + commit (leader-commit-index leader addr) + unreachable (+ (or commit 0) 1000000)] + (raftadmin! leader addr "promote_learner" candidate + "0" (str unreachable)) + ;; Reached only when the server ACCEPTED it -- the defect. + (assoc op :type :ok + :value {:node candidate + :addr candidate-addr + :leader-commit-index commit + :min-applied-index unreachable})) + :promote-learner (let [candidate (name (:value op)) candidate-addr (str candidate ":" (:grpc-port test 50051)) @@ -498,6 +697,9 @@ ;; every real read exception without it, so ;; learner-partition-read-failures filtered them all out and the ;; lease regression could never invalidate a run. + ;; :promote-learner-early lands here on the happy path -- its + ;; rejection is the property holding, not a workload failure, which + ;; is why only an :ok from it is reported as a defect. (if (= :read (:f op)) (assoc op :type :fail :value {:lease? true} @@ -529,14 +731,30 @@ this) (invoke! [_this test op] - (case (:f op) - :start-partition (do (net/drop-all! test grudge) - (assoc op :value {:scope :learners-only - :isolated [learner]})) - :stop-partition (do (net/heal! (:net test) test) - (assoc op :value {:scope :learners-only - :healed true})) - (assoc op :value :unsupported))) + ;; The lease counters are sampled on the node the client sends its + ;; lease probes to, at both edges of the window. The DELTA across the + ;; window is the evidence: misses are reads that fell back to + ;; LinearizableRead, which is precisely the regression, and hits prove + ;; reads were actually served in the window rather than the window + ;; being empty. + (let [probe-node (first (:nodes test))] + (case (:f op) + :start-partition (let [before (ekdb/lease-read-counters probe-node)] + ;; jepsen.net/drop-all! is the 2-arity wrapper in + ;; jepsen.net -- it reads (:net test) itself. Only + ;; jepsen.net.proto/drop-all! takes net first, and + ;; heal! below differs because it is import-vars'd + ;; straight from the protocol. + (net/drop-all! test grudge) + (assoc op :value {:scope :learners-only + :isolated [learner] + :lease-counters before})) + :stop-partition (do (net/heal! (:net test) test) + (assoc op :value {:scope :learners-only + :healed true + :lease-counters (ekdb/lease-read-counters + probe-node)})) + (assoc op :value :unsupported)))) (teardown! [_this test] (net/heal! (:net test) test))))) @@ -552,7 +770,13 @@ promotion phase and closed before it runs." [] ;; A seq is a generator in Jepsen 0.3.x; gen/seq was removed. - [(gen/sleep 2) + ;; + ;; The window opens at 6s, AFTER :add-learner at ~5s. At 2s it opened before + ;; the candidate was attached, leaving barely a second in which the node was + ;; both attached and isolated -- and at rate 5 with stagger that interval + ;; could contain no read at all, so the quorum-ack property went unexercised + ;; while reads elsewhere in the run satisfied the coverage gate. + [(gen/sleep 6) {:type :info :f :start-partition} (gen/sleep 4) {:type :info :f :stop-partition}]) @@ -577,7 +801,14 @@ ;; preserve across it. (gen/time-limit 5 register) (gen/once {:f :add-learner :value candidate}) - (gen/time-limit 5 register) + ;; Spans the 6s..10s partition window, so the reads the lease counters + ;; measure happen with the candidate attached and isolated. + (gen/time-limit 6 register) + ;; While it is still a learner: ask for a promotion the server must + ;; refuse, which is the only observation that its min_applied_index test + ;; is doing anything. + (gen/once {:f :promote-learner-early :value candidate}) + (gen/time-limit 2 register) (gen/once {:f :promote-learner :value candidate}) register))) diff --git a/jepsen/test/elastickv/learner_workload_test.clj b/jepsen/test/elastickv/learner_workload_test.clj index bbcf623f2..14d55ff19 100644 --- a/jepsen/test/elastickv/learner_workload_test.clj +++ b/jepsen/test/elastickv/learner_workload_test.clj @@ -21,7 +21,21 @@ [{:type :invoke :f :write :value 1 :time 10 :process 0} {:type :ok :f :write :value 1 :time 20 :process 0} {:type :invoke :f :read :time 30 :process 0} - {:type :ok :f :read :value {:lease? true :value 1} :time 40 :process 0}]) + {:type :ok :f :read :value {:lease? true :value 1} :time 40 :process 0} + ;; The min_applied_index probe, REFUSED. A :fail here is the property + ;; holding: the live promotion path waits for catch-up first, so this is + ;; the only op that can present the server with a violation to reject. + {:type :invoke :f :promote-learner-early :value "n5" :time 42 :process 0} + {:type :fail :f :promote-learner-early :time 44 :process 0 + :error "min_applied_index not reached"}]) + +(def ^:private probe-refused + "The min_applied_index probe, refused. Histories that are not about the + probe still have to carry it: a run that never asked proves nothing about + enforcement, so the checker treats an absent probe as a failure." + [{:type :invoke :f :promote-learner-early :value "n5" :time 1 :process 9} + {:type :fail :f :promote-learner-early :time 2 :process 9 + :error "min_applied_index not reached"}]) (defn- promotion [m time] @@ -103,50 +117,58 @@ ;; --------------------------------------------------------------------------- (deftest a-write-lost-across-a-promotion-is-rejected - (let [r (check [{:type :invoke :f :write :value 7 :time 10} - {:type :ok :f :write :value 7 :time 20} - {:type :invoke :f :promote-learner :value "n5" :time 30} - (promotion {} 40) - {:type :invoke :f :read :time 50} - {:type :ok :f :read :value {:lease? true :value 3} :time 60}])] + (let [r (check (concat probe-refused + [{:type :invoke :f :write :value 7 :time 10} + {:type :ok :f :write :value 7 :time 20} + {:type :invoke :f :promote-learner :value "n5" :time 30} + (promotion {} 40) + {:type :invoke :f :read :time 50} + {:type :ok :f :read :value {:lease? true :value 3} :time 60}]))] (is (false? (:valid? r))) (is (= 1 (count (:lost-writes r)))))) (deftest an-overwritten-value-is-not-a-lost-write ;; Set subtraction reported 1 as lost in this legal register history merely ;; because it was overwritten before anyone read it. - (let [r (check [{:type :invoke :f :write :value 1 :time 10} - {:type :ok :f :write :value 1 :time 20} - {:type :invoke :f :write :value 2 :time 30} - {:type :ok :f :write :value 2 :time 40} - {:type :invoke :f :promote-learner :value "n5" :time 50} - (promotion {} 60) - {:type :invoke :f :read :time 70} - {:type :ok :f :read :value {:lease? true :value 2} :time 80}])] + (let [r (check (concat probe-refused + [{:type :invoke :f :write :value 1 :time 10} + {:type :ok :f :write :value 1 :time 20} + {:type :invoke :f :write :value 2 :time 30} + {:type :ok :f :write :value 2 :time 40} + {:type :invoke :f :promote-learner :value "n5" :time 50} + (promotion {} 60) + {:type :invoke :f :read :time 70} + {:type :ok :f :read :value {:lease? true :value 2} :time 80}]))] (is (:valid? r) (str "lost-writes=" (:lost-writes r))))) (deftest a-concurrent-write-makes-the-expected-value-ambiguous-not-wrong ;; With another write in flight between the acked write and the read, the ;; register's value is not pinned, so no conclusion is drawn rather than a ;; false loss being reported. - (let [r (check [{:type :invoke :f :write :value 1 :time 10} - {:type :ok :f :write :value 1 :time 20} - {:type :invoke :f :promote-learner :value "n5" :time 30} - (promotion {} 40) - {:type :invoke :f :write :value 9 :time 50} - {:type :invoke :f :read :time 60} - {:type :ok :f :read :value {:lease? true :value 9} :time 70}])] + (let [r (check (concat probe-refused + [{:type :invoke :f :write :value 1 :time 10} + {:type :ok :f :write :value 1 :time 20} + {:type :invoke :f :promote-learner :value "n5" :time 30} + (promotion {} 40) + {:type :invoke :f :write :value 9 :time 50} + {:type :invoke :f :read :time 60} + {:type :ok :f :read :value {:lease? true :value 9} :time 70}]))] (is (:valid? r) (str "lost-writes=" (:lost-writes r))))) ;; --------------------------------------------------------------------------- ;; 3. A learner never counts toward the lease ;; --------------------------------------------------------------------------- -(defn- partition-window [start stop] - [{:type :info :process :nemesis :f :start-partition - :value {:scope :learners-only} :time start} - {:type :info :process :nemesis :f :stop-partition - :value {:scope :learners-only} :time stop}]) +(defn- partition-window + "A learners-only window carrying the lease counters the nemesis samples at + its edges. The default delta is a healthy one: reads were served from the + lease (hit moved) and none fell back (miss did not)." + ([start stop] (partition-window start stop {:hit 10 :miss 0} {:hit 14 :miss 0})) + ([start stop before after] + [{:type :info :process :nemesis :f :start-partition + :value {:scope :learners-only :lease-counters before} :time start} + {:type :info :process :nemesis :f :stop-partition + :value {:scope :learners-only :lease-counters after} :time stop}])) (deftest a-lease-read-failing-under-learner-isolation-is-rejected ;; Reads, not writes: quorumAckTracker feeds LastQuorumAck and the @@ -304,34 +326,35 @@ (is (empty? (:lost-writes r)) "and it must not be mistaken for a lost write either"))) -(deftest a-slow-lease-read-under-learner-isolation-is-rejected - ;; Failures alone cannot detect the quorum-ack regression: a Redis GET calls - ;; LeaseReadForKeyThrough, and when the lease is unavailable the engine falls - ;; back to LinearizableRead transparently — so with the voters connected the - ;; read SUCCEEDS and a failure-only check stays empty through exactly the - ;; regression it claims to catch. What changes is the latency. +(deftest a-lease-read-that-fell-back-under-learner-isolation-is-rejected + ;; Neither failures nor latency can establish this. A Redis GET calls + ;; LeaseReadForKeyThrough and the engine falls back to LinearizableRead + ;; transparently, so the read SUCCEEDS — and on one host that fallback costs + ;; milliseconds, so any latency budget loose enough not to flag jitter sits + ;; far above it. elastickv_lease_read_total separates them by construction: + ;; its help text defines miss as "fell back to LinearizableRead". (let [r (check (concat healthy-prefix [(promotion {} 50)] (post-promotion-read 60) - (partition-window 100 200) - [{:type :invoke :f :read :time 120} - {:type :ok :f :read :time 130 - :value {:lease? true :latency-ms 900.0 :value 1}}]))] + (partition-window 100 200 + {:hit 10 :miss 0} + {:hit 12 :miss 3})))] (is (false? (:valid? r))) - (is (= 1 (count (:slow-lease-reads r))) - "a lease read that fell back to a Raft round trip must fail the run"))) + (is (= 1 (count (:lease-fast-path-losses r))) + "a lease read that fell back to a Raft round trip must fail the run") + (is (= 3 (:miss-delta (first (:lease-fast-path-losses r))))))) (deftest a-fast-lease-read-under-learner-isolation-is-fine (let [r (check (concat healthy-prefix [(promotion {} 50)] (post-promotion-read 60) - (partition-window 100 200) - [{:type :invoke :f :read :time 120} - {:type :ok :f :read :time 130 - :value {:lease? true :latency-ms 3.0 :value 1}}]))] - (is (:valid? r) (str "slow=" (:slow-lease-reads r))))) + (partition-window 100 200)))] + (is (:valid? r) (str "losses=" (:lease-fast-path-losses r) + " unmeasured=" (:unmeasured-partition-windows r))))) -(deftest a-slow-lease-read-outside-the-window-is-not-attributed-to-the-learner +(deftest a-fallback-outside-the-window-is-not-attributed-to-the-learner + ;; The counters are sampled at the window's own edges, so a miss that + ;; happened outside it cannot appear in the delta at all. (let [r (check (concat healthy-prefix [(promotion {} 50)] (post-promotion-read 60) @@ -339,7 +362,119 @@ [{:type :invoke :f :read :time 500} {:type :ok :f :read :time 510 :value {:lease? true :latency-ms 900.0 :value 1}}]))] - (is (:valid? r) (str "slow=" (:slow-lease-reads r))))) + (is (:valid? r) (str "losses=" (:lease-fast-path-losses r))))) + +(deftest a-window-with-no-lease-read-served-proves-nothing + ;; The read coverage gate counted successful reads ANYWHERE in the run, so + ;; reads taken before attachment or after the heal satisfied it while the + ;; quorum-ack property went unexercised. An unmoved hit counter is what that + ;; looks like from the metrics. + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (post-promotion-read 60) + (partition-window 100 200 + {:hit 10 :miss 0} + {:hit 10 :miss 0})))] + (is (false? (:valid? r))) + (is (= [:no-lease-read-served] + (map :reason (:unmeasured-partition-windows r)))))) + +(deftest a-window-whose-counters-could-not-be-sampled-proves-nothing + ;; Zero misses and no data are indistinguishable unless this is checked. + (let [r (check (concat healthy-prefix + [(promotion {} 50)] + (post-promotion-read 60) + (partition-window 100 200 nil nil)))] + (is (false? (:valid? r))) + (is (= [:counters-unavailable] + (map :reason (:unmeasured-partition-windows r)))))) + +(deftest a-server-that-accepts-a-premature-promotion-fails-the-run + ;; premature-promotions cannot fail on its own: the live path waits for + ;; catch-up and then records that already-qualified index as :match, so + ;; match >= target holds by construction even if the engine dropped the + ;; min_applied_index test entirely. An accepted probe is the observation. + (let [r (check (concat [{:type :invoke :f :write :value 1 :time 10 :process 0} + {:type :ok :f :write :value 1 :time 20 :process 0} + {:type :invoke :f :read :time 30 :process 0} + {:type :ok :f :read :value {:lease? true :value 1} + :time 40 :process 0} + {:type :invoke :f :promote-learner-early :value "n5" + :time 42 :process 0} + {:type :ok :f :promote-learner-early :time 44 :process 0 + :value {:node "n5" :leader-commit-index 100 + :min-applied-index 1000100}}] + [(promotion {} 50)] + (post-promotion-read 60)))] + (is (false? (:valid? r))) + (is (= 1 (count (:unenforced-min-applied-index r))) + "a promotion accepted above any reachable applied index is the defect"))) + +(deftest a-run-that-never-probed-min-applied-index-is-not-evidence + ;; Without this, "no accepted premature promotions" and "never asked" look + ;; identical in the result map. + (let [r (check (concat [{:type :invoke :f :write :value 1 :time 10 :process 0} + {:type :ok :f :write :value 1 :time 20 :process 0} + {:type :invoke :f :read :time 30 :process 0} + {:type :ok :f :read :value {:lease? true :value 1} + :time 40 :process 0}] + [(promotion {} 50)] + (post-promotion-read 60)))] + (is (false? (:valid? r))) + (is (false? (:min-applied-index-probe-ran r))))) + +(deftest overlapping-writes-are-ambiguous-rather-than-lost + ;; Completion order alone does not identify the register's final value. + ;; Write 1 runs t=10..40 and write 2 runs t=20..30: both linearization + ;; orders are legal, so a later read of 2 is valid. Looking only for writes + ;; INVOKED after write 1 completed misses write 2 and reports a loss that + ;; never happened. + (let [r (check (concat [{:type :invoke :f :write :value 1 :time 10 :process 0} + {:type :invoke :f :write :value 2 :time 20 :process 1} + {:type :ok :f :write :value 2 :time 30 :process 1} + {:type :ok :f :write :value 1 :time 40 :process 0} + {:type :invoke :f :promote-learner-early :value "n5" + :time 42 :process 2} + {:type :fail :f :promote-learner-early :time 44 :process 2}] + [(promotion {} 50)] + [{:type :invoke :f :read :time 60 :process 3} + {:type :ok :f :read :value {:lease? true :value 2} + :time 70 :process 3}]))] + (is (empty? (:lost-writes r)) + "a write that overlapped the last completion makes the value ambiguous") + (is (:valid? r) (str r)))) + +(deftest a-completion-is-paired-with-its-own-invocation + ;; Process membership is not a pairing. P invokes a read before the + ;; promotion, completes it after, then invokes another read after — P is in + ;; the set of processes that invoked after t, so the EARLIER, pre-promotion + ;; completion was selected as the first post-promotion read. + (let [r (check (concat healthy-prefix + [{:type :invoke :f :write :value 7 :time 45 :process 0} + {:type :ok :f :write :value 7 :time 46 :process 0} + ;; Invoked before the promotion, completes after. + {:type :invoke :f :read :time 48 :process 1} + (promotion {} 50) + {:type :ok :f :read :value {:lease? true :value 1} + :time 55 :process 1} + ;; The same process reads again, properly after. + {:type :invoke :f :read :time 60 :process 1} + {:type :ok :f :read :value {:lease? true :value 7} + :time 70 :process 1}]))] + (is (empty? (:lost-writes r)) + "the stale completion must not be read as the post-promotion value") + (is (:valid? r) (str r)))) + +(deftest promotion-must-actually-change-the-quorum-threshold + ;; Five nodes reserve one candidate, so the run starts at four voters and + ;; promotion takes it to five — but majority(4) and majority(5) are both 3, + ;; so the transition the workload is named for never happens. + (is (false? (lw/promotion-changes-quorum? ["n1" "n2" "n3" "n4" "n5"])) + "four voters to five needs three either way") + (is (lw/promotion-changes-quorum? ["n1" "n2" "n3" "n4"]) + "three voters to four moves the majority from 2 to 3") + (is (lw/promotion-changes-quorum? lw/default-nodes) + "the default topology must be one where promotion changes the threshold")) (deftest the-nemesis-handles-the-operations-the-generator-emits ;; jepsen.nemesis/partitioner dispatches on :start and :stop. Feeding it @@ -400,11 +535,24 @@ (is (contains? args "--raftJoinMembers")) (is (contains? args "n1=n1:50051,n2=n2:50051"))) - ;; The candidate itself is excluded from the members it discovers: it is - ;; joining, not already a member. - (is (= "n1=n1:50051,n2=n2:50051" + ;; The candidate is INCLUDED, at its own listener address. resolveJoinServers + ;; (main.go) rejects a members list that omits the local --raftId with + ;; ErrJoinMembersMissingLocalNode, so a candidate given only the voters + ;; receives the join flags and then exits during startup validation. + (is (= "n1=n1:50051,n2=n2:50051,n5=n5:50051" (ekdb/join-members-arg ["n1" "n2" "n5"] "n5" 50051))) + ;; The address must be the candidate's OWN listener: resolveJoinServers also + ;; refuses when the local entry's address does not match, so a placeholder + ;; that merely carries the right ID would fail the same validation. + (is (clojure.string/includes? + (ekdb/join-members-arg ["n1" "n2" "n5"] "n5" 50051) + "n5=n5:50051")) + + ;; With no reserved candidate the list is just the nodes, unduplicated. + (is (= "n1=n1:50051,n2=n2:50051" + (ekdb/join-members-arg ["n1" "n2"] nil 50051))) + ;; An ordinary voter gets neither flag. (let [args (set (ekdb/server-args {:node "n2" :grpc "n2:50051" :redis "n2:6379" :data-dir "/var/lib/elastickv" From cfcd2051cc313d00f2225e95d0237f1983662692 Mon Sep 17 00:00:00 2001 From: bootjp Date: Thu, 22 Oct 2026 23:55:43 +0900 Subject: [PATCH 5/7] jepsen: wait for the reserved learner listener during setup --- jepsen/src/elastickv/db.clj | 2 ++ .../test/elastickv/encrypted_cluster_test.clj | 19 ++++++++++++++++++- 2 files changed, 20 insertions(+), 1 deletion(-) diff --git a/jepsen/src/elastickv/db.clj b/jepsen/src/elastickv/db.clj index cf695b687..751e38e93 100644 --- a/jepsen/src/elastickv/db.clj +++ b/jepsen/src/elastickv/db.clj @@ -590,6 +590,8 @@ (doseq [peer (voter-peers (:nodes test) (:reserve-learner opts))] (join-peer! node peer opts) (enable-peer-mount! test peer opts)) + (when-let [candidate (:reserve-learner opts)] + (wait-for-node-grpc! candidate opts)) (when (:encryption opts) (activate-encryption! (assoc test :nodes (into [(first (:nodes test))] (voter-peers (:nodes test) (:reserve-learner opts)))) diff --git a/jepsen/test/elastickv/encrypted_cluster_test.clj b/jepsen/test/elastickv/encrypted_cluster_test.clj index 062e7f093..7d7e74077 100644 --- a/jepsen/test/elastickv/encrypted_cluster_test.clj +++ b/jepsen/test/elastickv/encrypted_cluster_test.clj @@ -175,7 +175,7 @@ :storage-envelope-active true :raft-envelope-active true})} (fn [] (#'ekdb/finish-bootstrap-setup! test "n1" opts))) (is (= [[:ready "n1"] [:join "n2"] [:mount "n2"] - [:join "n3"] [:mount "n3"] [:admin "bootstrap"] + [:join "n3"] [:mount "n3"] [:ready "n4"] [:admin "bootstrap"] [:admin "enable-storage-envelope"] [:admin "enable-raft-envelope"]] @events)) (is (= ["--discover-from=n1:50051" "--discover-from=n2:50051" @@ -183,6 +183,23 @@ (is (= #{"n1:50051" "n2:50051" "n3:50051"} (set @verified))) (is (= ["n1:50051" "n2:50051" "n3:50051"] (vec (take-last 3 @verified)))))) +(deftest a-reserved-candidate-that-never-listens-fails-database-setup + (let [activated? (atom false)] + (with-redefs-fn + {#'ekdb/wait-for-node-grpc! (fn [node _] + (when (= "n4" node) + (throw (ex-info "candidate did not start" {})))) + #'ekdb/wait-for-mount! (fn [& _]) + #'ekdb/join-peer! (fn [& _]) + #'ekdb/enable-peer-mount! (fn [& _]) + #'ekdb/activate-encryption! (fn [& _] (reset! activated? true))} + (fn [] + (is (thrown-with-msg? clojure.lang.ExceptionInfo #"candidate did not start" + (#'ekdb/finish-bootstrap-setup! + {:nodes ["n1" "n2" "n3" "n4"]} "n1" + {:encryption true :reserve-learner "n4"}))))) + (is (false? @activated?)))) + (deftest encrypted-candidate-keeps-join-flags-on-every-start (let [test {:nodes ["n1" "n2" "n3" "n4"]} opts {:encryption true :reserve-learner "n4" :filesystem-mount "/mnt/kv"} From 7c2c2d3a8f5c26fe9359951f220f9fe1c52c8f1a Mon Sep 17 00:00:00 2001 From: bootjp Date: Fri, 23 Oct 2026 03:35:25 +0900 Subject: [PATCH 6/7] jepsen: validate learner topology and read attribution --- jepsen/src/elastickv/learner_workload.clj | 22 ++++++++----- .../test/elastickv/learner_workload_test.clj | 32 +++++++++++++++++++ 2 files changed, 46 insertions(+), 8 deletions(-) diff --git a/jepsen/src/elastickv/learner_workload.clj b/jepsen/src/elastickv/learner_workload.clj index 3e9ad8894..bc74c9f1d 100644 --- a/jepsen/src/elastickv/learner_workload.clj +++ b/jepsen/src/elastickv/learner_workload.clj @@ -274,7 +274,7 @@ last)) (defn- read-invocation-times - "Each successful read paired with the time it was actually invoked. + "Each completed read paired with the time it was actually invoked. A process set is not enough. If process P invokes a read before t, completes it after t, and then invokes another read after t, P is in the set of @@ -295,8 +295,7 @@ :done done} (:ok :fail :info) {:pending (dissoc pending (:process op)) - :done (if (and (= :ok (:type op)) - (contains? pending (:process op))) + :done (if (contains? pending (:process op)) (conj done (assoc op ::invoked-at (get pending (:process op)))) done)} @@ -314,6 +313,7 @@ THIS completion's invoke event, not from any invoke the same process made." [history t] (->> (read-invocation-times history) + (filter #(= :ok (:type %))) (filter #(> (::invoked-at %) t)) (sort-by :time) first)) @@ -461,7 +461,7 @@ vec)) (defn learner-partition-read-failures - "Lease reads that failed while only learners were partitioned. + "Failed lease reads invoked while only learners were partitioned. Reads, not writes. The learner is excluded from the write-commit quorum by the voter set, but `quorumAckTracker` feeds `LastQuorumAck`, which gates the @@ -470,20 +470,23 @@ exact regression it claims to catch -- it stalls the lease the leader serves fast reads from. - So the property is expressed on lease reads: isolating a non-voter must not - make them fail." + Attribute by invocation, not completion: a pre-isolation timeout is not + evidence about the fault, and a read begun during isolation still counts + when it remains stalled until after healing." [history] (let [windows (learner-partition-windows history)] (if (empty? windows) [] - (->> history + (->> (read-invocation-times history) (filter #(and (= :read (:f %)) (= :fail (:type %)) (true? (:lease? (:value %))))) (filter (fn [op] (some (fn [[start stop]] - (and (>= (:time op) start) (<= (:time op) stop))) + (and (>= (::invoked-at op) start) + (<= (::invoked-at op) stop))) windows))) + (map #(dissoc % ::invoked-at)) vec)))) ;; --------------------------------------------------------------------------- @@ -823,6 +826,9 @@ "Builds a Jepsen test map exercising learner attach and promotion." ([] (elastickv-learner-test {})) ([opts] + (when (or (some? (:raft-groups opts)) (some? (:shard-ranges opts))) + (throw (ex-info "learner workload requires the default single Raft group; --raft-groups and --shard-ranges are unsupported" + (select-keys opts [:raft-groups :shard-ranges])))) (let [nodes (or (:nodes opts) default-nodes) local? (:local opts) grpc-port (or (:grpc-port opts) 50051) diff --git a/jepsen/test/elastickv/learner_workload_test.clj b/jepsen/test/elastickv/learner_workload_test.clj index b8484418c..b93af7a0c 100644 --- a/jepsen/test/elastickv/learner_workload_test.clj +++ b/jepsen/test/elastickv/learner_workload_test.clj @@ -8,6 +8,8 @@ valid. Several properties were also measuring the wrong thing. Each test below names the way it used to pass wrongly." (:require [clojure.test :refer :all] + [clojure.tools.cli :as tools.cli] + [elastickv.cli :as cli] [elastickv.db :as ekdb] [elastickv.jepsen-test :as jt] [elastickv.learner-workload :as lw] @@ -229,6 +231,21 @@ {:type :fail :f :read :value {:lease? true} :time 510}]))] (is (:valid? r) (str "failures=" (:learner-read-failures r))))) +(deftest failed-lease-reads-are-attributed-by-their-own-invocations + (let [history (concat (partition-window 100 200) + [{:type :invoke :f :read :time 90 :process 1} + {:type :fail :f :read :time 110 :process 1 + :value {:lease? true} :error "before isolation"} + {:type :invoke :f :read :time 120 :process 1} + {:type :fail :f :read :time 250 :process 1 + :value {:lease? true} :error "during isolation"} + {:type :invoke :f :read :time 300 :process 1} + {:type :fail :f :read :time 310 :process 1 + :value {:lease? true} :error "after isolation"}]) + failures (lw/learner-partition-read-failures history)] + (is (= ["during isolation"] (mapv :error failures))) + (is (= [250] (mapv :time failures))))) + ;; --------------------------------------------------------------------------- ;; The checker must not pass a run that proved nothing ;; --------------------------------------------------------------------------- @@ -558,6 +575,21 @@ "a comma-separated string must be split before it reaches the constructor") (is (= "n3" (lw/learner-candidate (:nodes prepared)))))) +(deftest unsupported-topology-options-are-not-silently-ignored + (doseq [args [["--raft-groups" "1=50061"] + ["--raft-groups" "1=50061,2=50062"] + ["--shard-ranges" "a:z=1"]] + local? [false true]] + (let [{:keys [options errors]} (tools.cli/parse-opts args cli/common-cli-opts) + prepared (lw/prepare-learner-opts (assoc options :local local?))] + (is (empty? errors)) + (is (thrown-with-msg? clojure.lang.ExceptionInfo #"default single Raft group" + (lw/elastickv-learner-test prepared)) + (str args " local=" local?)))) + (let [{:keys [options errors]} (tools.cli/parse-opts [] cli/common-cli-opts)] + (is (empty? errors)) + (is (map? (lw/elastickv-learner-test (lw/prepare-learner-opts options)))))) + (deftest the-redis-host-override-reaches-the-test-map ;; LearnerClient.open! reads :redis-host from the completed test map, so the ;; constructor has to carry it; otherwise a programmatic caller could not From d69930bdf1a193ceb174feb30377a27117a7d734 Mon Sep 17 00:00:00 2001 From: bootjp Date: Fri, 23 Oct 2026 03:44:17 +0900 Subject: [PATCH 7/7] jepsen: track learner isolation until confirmed heal --- jepsen/src/elastickv/learner_workload.clj | 13 +++++++++--- .../test/elastickv/learner_workload_test.clj | 21 +++++++++++++++++-- 2 files changed, 29 insertions(+), 5 deletions(-) diff --git a/jepsen/src/elastickv/learner_workload.clj b/jepsen/src/elastickv/learner_workload.clj index bc74c9f1d..9c5fe30fa 100644 --- a/jepsen/src/elastickv/learner_workload.clj +++ b/jepsen/src/elastickv/learner_workload.clj @@ -375,13 +375,18 @@ Each start is paired with its OWN stop. Taking the first start and the first later stop examined one window and silently ignored every subsequent learner-isolation period, so a regression in the second or later window - could not fail the check." + could not fail the check. Only the completion acknowledging a successful + heal ends the window; invoking stop does not restore the network." [history] (let [nemesis (->> history (filter #(= :nemesis (:process %))) (sort-by :time)) starts (->> nemesis (filter #(= :start-partition (:f %))) (filter #(= :learners-only (get-in % [:value :scope])))) - stops (->> nemesis (filter #(= :stop-partition (:f %))) (map :time) vec)] + stops (->> nemesis + (filter #(and (= :stop-partition (:f %)) + (= :info (:type %)) + (true? (get-in % [:value :healed])))) + (map :time) vec)] (->> starts (map (fn [start] (let [t (:time start)] @@ -398,7 +403,9 @@ (= :info (:type %)))) vec) stops (->> nemesis - (filter #(and (= :stop-partition (:f %)) (= :info (:type %)))) + (filter #(and (= :stop-partition (:f %)) + (= :info (:type %)) + (true? (get-in % [:value :healed])))) vec)] (->> starts (keep (fn [start] diff --git a/jepsen/test/elastickv/learner_workload_test.clj b/jepsen/test/elastickv/learner_workload_test.clj index b93af7a0c..d050402a9 100644 --- a/jepsen/test/elastickv/learner_workload_test.clj +++ b/jepsen/test/elastickv/learner_workload_test.clj @@ -195,7 +195,7 @@ [{:type :info :process :nemesis :f :start-partition :value {:scope :learners-only :lease-counters before} :time start} {:type :info :process :nemesis :f :stop-partition - :value {:scope :learners-only :lease-counters after} :time stop}])) + :value {:scope :learners-only :healed true :lease-counters after} :time stop}])) (deftest a-lease-read-failing-under-learner-isolation-is-rejected ;; Reads, not writes: quorumAckTracker feeds LastQuorumAck and the @@ -246,6 +246,22 @@ (is (= ["during isolation"] (mapv :error failures))) (is (= [250] (mapv :time failures))))) +(deftest isolation-ends-at-the-confirmed-heal-not-the-stop-invocation + (doseq [invocation-type [:invoke :info]] + (let [history (concat (partition-window 100 300) + [{:type invocation-type :process :nemesis + :f :stop-partition :time 200} + {:type :invoke :f :read :process 1 :time 250} + {:type :fail :f :read :process 1 :time 350 + :value {:lease? true} :error "still isolated"} + {:type :invoke :f :read :process 1 :time 400} + {:type :fail :f :read :process 1 :time 410 + :value {:lease? true} :error "already healed"}])] + (is (= [[100 300]] (lw/learner-partition-windows history))) + (is (= ["still isolated"] + (mapv :error (lw/learner-partition-read-failures history)))) + (is (empty? (lw/unmeasured-partition-windows history)))))) + ;; --------------------------------------------------------------------------- ;; The checker must not pass a run that proved nothing ;; --------------------------------------------------------------------------- @@ -550,7 +566,8 @@ (is (= [:partition-installed :counter-sampled] @events)) (reset! events []) - (nemesis/invoke! n test {:type :info :f :stop-partition}) + (is (true? (get-in (nemesis/invoke! n test {:type :info :f :stop-partition}) + [:value :healed]))) (is (= [:counter-sampled :partition-healed] @events))))) (deftest the-learner-partition-runs-once-not-in-a-cycle