pingcap / pingcap/tidb

Jepsen append workload fails due to read a stale value

Open
#60,446 2 comments 0 reactions 0 assignees View on GitHub
type/bug
Dominant language
Go
Stars
40.5k
Forks
6.2k
PR merge metrics
PR metrics pending

Description

## Bug Report

### 1. Minimal reproduce step (Required)

Run jepsen using the following configuration:

2025-03-25T13:18:26.823Z plan-exec-7832655-re0-case-540371-21-2195250051 INFO [clojure.core:?] - exec #0 ["timeout","--preserve-status","--kill-after=15","900","java","-cp","resources:jepsen.jar","tidb.core","test","--skip-collect-logs","--ssh-private-key=jepsen.pem","--nodes=node-0.node-peer.jepsen-tps-7832655-1-989,node-1.node-peer.jepsen-tps-7832655-1-989,node-2.node-peer.jepsen-tps-7832655-1-989,node-3.node-peer.jepsen-tps-7832655-1-989,node-4.node-peer.jepsen-tps-7832655-1-989","--tarball-url","http://fileserver.pingcap.net/download/builds/pingcap/jepsen/ime-test/tidb-nightly.tar.gz","--nemesis=shuffle-region,partition-pd-leader,random-merge","--netem-type=loss","--txn-mode=optimistic","--workload=append","--follower-read=true","--update-in-place=false","--read-lock=update","--concurrency=2n","--force-reinstall=true","--time-limit=300","--os=image","--version=master","--init-txn-sql=set @@tidb_enable_async_commit = 1, @@tidb_enable_1pc = 0","--init-sql=set @@tidb_enable_mutation_checker=1, @@tidb_txn_assertion_level=strict, @@tidb_constraint_check_in_place_pessimistic=off"]

```
INFO [2025-03-25 13:27:33,527] jepsen results - jepsen.store Wrote /tmp/case-540371-21/store/TiDB master append auto-retry auto-retry-limit :default update-in-place select FOR UPDATE txn-mode optimistic isolation :repeatable-read nemesis netem-type,partition-pd-leader,random-merge,shuffle-region/20250325T131830.000Z/results.edn
INFO [2025-03-25 13:27:34,468] jepsen test runner - jepsen.core Snarfing log files
INFO [2025-03-25 13:27:34,472] jepsen test runner - jepsen.core Snarfing log files
INFO [2025-03-25 13:27:34,502] jepsen test runner - jepsen.core {:perf
{:latency-graph {:valid? true},
:rate-graph {:valid? true},
:valid? true},
:workload
{:valid? false,
:anomaly-types (:G-single),
:anomalies
{:G-single
("Let:\n T1 = {:type :ok, :f :txn, :value [[:r 1538 [1 2 3 4 7 11 12 13 14]]], :process 146, :time 267480043085, :txn-info {:txn_scope \"global\", :start_ts 18446744073709551615, :for_update_ts 18446744073709551615, :ru_consumption 1.4409587115885414}, :index 40680}\n T2 = {:type :ok, :f :txn, :value [[:append 1538 10] [:append 1540 3]], :process 138, :time 267475457692, :txn-info {:txn_scope \"global\", :start_ts 456893192690466901, :commit_ts 456893192690466906, :txn_commit_mode \"async_commit\", :async_commit_fallback false, :one_pc_fallback false, :pipelined false, :flush_wait_ms 0}, :index 40674}\n\nThen:\n - T1 < T2, because T1 did not observe T2's append of 10 to 1538.\n - However, T2 < T1, because T2 completed at index 40674, 0.001 seconds before the invocation of T1, at index 40677: a contradiction!")}},
:valid? false}

Analysis invalid! (ノಥ益ಥ)ノ ┻━┻
```

Log: https://tcms.pingcap.net/dashboard/executions/plan/7832655

### 2. What did you expect to see? (Required)

No failure.

### 3. What did you see instead (Required)

See above.

### 4. What is your TiDB version? (Required)

tidb: baf6ca1e6902e1468470e1a51015f1e5e89d3ff2
tikv: https://github.com/tikv/tikv/pull/17806/commits/10192e9b559b76e534c41821ea4306627b04125c
pd: https://github.com/tikv/pd/commit/6a07466ceb4eac90a84b6daa8ef1dcfab1e3521b

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.