From 0e44a0fcee2f6e6dda66c782191cb12a20b647a9 Mon Sep 17 00:00:00 2001 From: Mira Radeva Date: Tue, 9 Jan 2024 08:26:25 -0500 Subject: [PATCH] storage: repro a series of intent resolution bugs with ignored seq nums The logic in mvccResolveWriteIntent is structured in such a way that if an intent contains both ignored and non-ignored seq nums in its intent history, the intent may end up being updated instead of aborted or unmodified. For the following examples, assume the intent has a history ["a", "b"] where "a" is written first, and "b" is ignored. 1. The intent resolution has status aborted. Instead of aborting the intent, it is modified to have value "a" and an empty intent history. 2. The intent resolution has status pending, and the intent has a lower epoch than the resolution. The intent should be aborted because the new epoch may not write it again. Instead, it is updated with value "a" and an empty intent history. 3. Same as 2 but the intent resolution has status committed. 4. The intent resolution has status pending, the intent is not pushed and has a higher epoch than the resolution. The intent should not be updated because the intent history is updated only when the epochs match. Instead, it is updated with value "a" and an empty intent history. 5. Same as 4 but the intent is pushed. The intent should be updated to bump its timestamp in order to unblock the pusher. The intent history should not be updated for the same reason as in 3. Instead, the intent is updated with value "a" and an empty intent history. Additionally, in cases 1, 2, 3 and 4 above, the resulting intent is not committed but a MVCCCommitIntentOp is logged erroneously. This commit only reproduces the bugs. Informs: #117553 Release note: None --- .../testdata/mvcc_histories/ignored_seq_nums | 143 ++++++++++++++++++ .../mvcc_histories/ignored_seq_nums_abort | 31 ++++ .../mvcc_histories/ignored_seq_nums_commit | 48 ++++++ 3 files changed, 222 insertions(+) create mode 100644 pkg/storage/testdata/mvcc_histories/ignored_seq_nums_abort diff --git a/pkg/storage/testdata/mvcc_histories/ignored_seq_nums b/pkg/storage/testdata/mvcc_histories/ignored_seq_nums index 40e27766c3f7..bc92ce8839f1 100644 --- a/pkg/storage/testdata/mvcc_histories/ignored_seq_nums +++ b/pkg/storage/testdata/mvcc_histories/ignored_seq_nums @@ -665,3 +665,146 @@ data: "m"/30.000000000,0 -> /BYTES/a data: "n"/45.000000000,0 -> {localTs=40.000000000,0}/BYTES/c meta: "o"/0,0 -> txn={id=00000006 key="o" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=10} ts=50.000000000,0 del=false klen=12 vlen=6 mergeTs= txnDidNotUpdateMeta=false data: "o"/50.000000000,0 -> /BYTES/a + +run ok +clear_range k=k end=p +---- +>> at end: + + +# Try to update a pending intent with a lower epoch than the resolution. +# The intent should be aborted because the new epoch may not write it again. + +# The test exposes a bug where the intent is updated instead of aborted. +# Moreover, it logs MVCCCommitIntentOp instead of MVCCUpdateIntentOp. + +run ok +with t=G k=p + txn_begin ts=50 + txn_step seq=10 + put v=a + txn_step seq=20 + put v=b + check_intent + get +---- +put: lock acquisition = {p id=00000007 key="p" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=10 Replicated Intent []} +put: lock acquisition = {p id=00000007 key="p" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=20 Replicated Intent []} +meta: "p" -> txn={id=00000007 key="p" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=20} ts=50.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +get: "p" -> /BYTES/b @50.000000000,0 +>> at end: +txn: "G" meta={id=00000007 key="p" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=20} lock=true stat=PENDING rts=50.000000000,0 wto=false gul=0,0 +meta: "p"/0,0 -> txn={id=00000007 key="p" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=20} ts=50.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +data: "p"/50.000000000,0 -> /BYTES/b + +run ok log-ops +with t=G k=p + txn_restart + txn_ignore_seqs seqs=(15-25) + resolve_intent status=PENDING + get +---- +resolve_intent: "p" -> resolved key = true +get: "p" -> +>> at end: +txn: "G" meta={id=00000007 key="p" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=0} lock=true stat=PENDING rts=50.000000000,0 wto=false gul=0,0 isn=1 +meta: "p"/0,0 -> txn={id=00000007 key="p" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=10} ts=50.000000000,0 del=false klen=12 vlen=6 mergeTs= txnDidNotUpdateMeta=false +data: "p"/50.000000000,0 -> /BYTES/a +logical op: *enginepb.MVCCCommitIntentOp + +run ok +clear_range k=p end=-p +---- +>> at end: + + +# Try to update a pending intent with a higher epoch than the resolution's epoch. +# The intent is not pushed, so it is not updated because the intent history +# should be updated only when the epochs match. + +# The test exposes a bug where the intent is actually updated, as evident by the +# changed intent history. +# Moreover, it logs MVCCCommitIntentOp instead of MVCCUpdateIntentOp. + +run ok +with t=H k=q + txn_begin ts=50 + txn_restart epoch=1 + txn_step seq=10 + put v=a + txn_step seq=20 + put v=b + check_intent + get +---- +put: lock acquisition = {q id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=10 Replicated Intent []} +put: lock acquisition = {q id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20 Replicated Intent []} +meta: "q" -> txn={id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20} ts=50.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +get: "q" -> /BYTES/b @50.000000000,0 +>> at end: +txn: "H" meta={id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20} lock=true stat=PENDING rts=50.000000000,0 wto=false gul=0,0 +meta: "q"/0,0 -> txn={id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20} ts=50.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +data: "q"/50.000000000,0 -> /BYTES/b + +run ok log-ops +with t=H k=q + txn_restart epoch=0 + txn_ignore_seqs seqs=(15-25) + resolve_intent status=PENDING + check_intent +---- +resolve_intent: "q" -> resolved key = true +meta: "q" -> txn={id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=10} ts=50.000000000,0 del=false klen=12 vlen=6 mergeTs= txnDidNotUpdateMeta=false +>> at end: +txn: "H" meta={id=00000008 key="q" iso=Serializable pri=0.00000000 epo=0 ts=50.000000000,0 min=0,0 seq=0} lock=true stat=PENDING rts=50.000000000,0 wto=false gul=0,0 isn=1 +meta: "q"/0,0 -> txn={id=00000008 key="q" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=10} ts=50.000000000,0 del=false klen=12 vlen=6 mergeTs= txnDidNotUpdateMeta=false +data: "q"/50.000000000,0 -> /BYTES/a +logical op: *enginepb.MVCCCommitIntentOp + +run ok +clear_range k=q end=-q +---- +>> at end: + + +# Update a pending intent with a higher epoch than the resolution's epoch. +# The intent is pushed, so its timestamp is updated to help the pusher make progress. +# The intent history is not updated because the epochs don't match. + +# The test exposes a bug where the intent history is actually updated. + +run ok +with t=I k=r + txn_begin ts=50 + txn_restart epoch=1 + txn_step seq=10 + put v=a + txn_step seq=20 + put v=b + check_intent + get +---- +put: lock acquisition = {r id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=10 Replicated Intent []} +put: lock acquisition = {r id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20 Replicated Intent []} +meta: "r" -> txn={id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20} ts=50.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +get: "r" -> /BYTES/b @50.000000000,0 +>> at end: +txn: "I" meta={id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20} lock=true stat=PENDING rts=50.000000000,0 wto=false gul=0,0 +meta: "r"/0,0 -> txn={id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=50.000000000,0 min=0,0 seq=20} ts=50.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +data: "r"/50.000000000,0 -> /BYTES/b + +run ok log-ops +with t=I k=r + txn_restart epoch=0 + txn_advance ts=60 + txn_ignore_seqs seqs=(15-25) + resolve_intent status=PENDING + check_intent +---- +resolve_intent: "r" -> resolved key = true +meta: "r" -> txn={id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=60.000000000,0 min=0,0 seq=10} ts=60.000000000,0 del=false klen=12 vlen=20 mergeTs= txnDidNotUpdateMeta=false +>> at end: +txn: "I" meta={id=00000009 key="r" iso=Serializable pri=0.00000000 epo=0 ts=60.000000000,0 min=0,0 seq=0} lock=true stat=PENDING rts=50.000000000,0 wto=false gul=0,0 isn=1 +meta: "r"/0,0 -> txn={id=00000009 key="r" iso=Serializable pri=0.00000000 epo=1 ts=60.000000000,0 min=0,0 seq=10} ts=60.000000000,0 del=false klen=12 vlen=20 mergeTs= txnDidNotUpdateMeta=false +data: "r"/60.000000000,0 -> {localTs=50.000000000,0}/BYTES/a +logical op: *enginepb.MVCCUpdateIntentOp diff --git a/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_abort b/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_abort new file mode 100644 index 000000000000..7467a3a51455 --- /dev/null +++ b/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_abort @@ -0,0 +1,31 @@ +# Abort an intent whose history includes ignored seq nums. +# The test exposes a bug where even though the transaction is aborted, its +# intent is updated instead of aborted. + +# The test exposes a bug where even though the transaction is aborted, its +# intent is updated instead of aborted. +# Moreover, it logs MVCCCommitIntentOp instead of MVCCUpdateIntentOp. + +run ok log-ops +with t=A k=k + txn_begin ts=11 + txn_step seq=10 + put v=a + txn_step seq=20 + put v=b + txn_step seq=30 + txn_ignore_seqs seqs=(15-25) + resolve_intent status=ABORTED + get +---- +put: lock acquisition = {k id=00000001 key="k" iso=Serializable pri=0.00000000 epo=0 ts=11.000000000,0 min=0,0 seq=10 Replicated Intent []} +put: lock acquisition = {k id=00000001 key="k" iso=Serializable pri=0.00000000 epo=0 ts=11.000000000,0 min=0,0 seq=20 Replicated Intent []} +resolve_intent: "k" -> resolved key = true +get: "k" -> /BYTES/a @11.000000000,0 +>> at end: +txn: "A" meta={id=00000001 key="k" iso=Serializable pri=0.00000000 epo=0 ts=11.000000000,0 min=0,0 seq=30} lock=true stat=PENDING rts=11.000000000,0 wto=false gul=0,0 isn=1 +meta: "k"/0,0 -> txn={id=00000001 key="k" iso=Serializable pri=0.00000000 epo=0 ts=11.000000000,0 min=0,0 seq=10} ts=11.000000000,0 del=false klen=12 vlen=6 mergeTs= txnDidNotUpdateMeta=false +data: "k"/11.000000000,0 -> /BYTES/a +logical op: *enginepb.MVCCWriteIntentOp +logical op: *enginepb.MVCCUpdateIntentOp +logical op: *enginepb.MVCCCommitIntentOp diff --git a/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_commit b/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_commit index 923ff3a6fa6e..860f115b052d 100644 --- a/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_commit +++ b/pkg/storage/testdata/mvcc_histories/ignored_seq_nums_commit @@ -137,3 +137,51 @@ get k=k ---- scan: "k"-"l" -> get: "k" -> + + +# Commit an intent with a lower epoch than the resolution. +# The intent should be aborted because the new epoch may not write it again. + +# The test exposes a bug where the intent is updated instead of aborted. +# Moreover, it logs MVCCCommitIntentOp instead of MVCCUpdateIntentOp. + +run ok +with t=B k=b + txn_begin ts=12 + txn_step seq=10 + put v=a + txn_step seq=20 + put v=b + check_intent + get +---- +put: lock acquisition = {b id=00000003 key="b" iso=Serializable pri=0.00000000 epo=0 ts=12.000000000,0 min=0,0 seq=10 Replicated Intent []} +put: lock acquisition = {b id=00000003 key="b" iso=Serializable pri=0.00000000 epo=0 ts=12.000000000,0 min=0,0 seq=20 Replicated Intent []} +meta: "b" -> txn={id=00000003 key="b" iso=Serializable pri=0.00000000 epo=0 ts=12.000000000,0 min=0,0 seq=20} ts=12.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +get: "b" -> /BYTES/b @12.000000000,0 +>> at end: +txn: "B" meta={id=00000003 key="b" iso=Serializable pri=0.00000000 epo=0 ts=12.000000000,0 min=0,0 seq=20} lock=true stat=PENDING rts=12.000000000,0 wto=false gul=0,0 +meta: "b"/0,0 -> txn={id=00000003 key="b" iso=Serializable pri=0.00000000 epo=0 ts=12.000000000,0 min=0,0 seq=20} ts=12.000000000,0 del=false klen=12 vlen=6 ih={{10 /BYTES/a}} mergeTs= txnDidNotUpdateMeta=false +data: "b"/12.000000000,0 -> /BYTES/b +data: "k"/11.000000000,0 -> /BYTES/c +data: "k/10"/11.000000000,0 -> /BYTES/10 +data: "k/30"/11.000000000,0 -> /BYTES/30 + + +run ok log-ops +with t=B k=b + txn_restart + txn_ignore_seqs seqs=(15-25) + resolve_intent status=COMMITTED + get +---- +resolve_intent: "b" -> resolved key = true +get: "b" -> +>> at end: +txn: "B" meta={id=00000003 key="b" iso=Serializable pri=0.00000000 epo=1 ts=12.000000000,0 min=0,0 seq=0} lock=true stat=PENDING rts=12.000000000,0 wto=false gul=0,0 isn=1 +meta: "b"/0,0 -> txn={id=00000003 key="b" iso=Serializable pri=0.00000000 epo=0 ts=12.000000000,0 min=0,0 seq=10} ts=12.000000000,0 del=false klen=12 vlen=6 mergeTs= txnDidNotUpdateMeta=false +data: "b"/12.000000000,0 -> /BYTES/a +data: "k"/11.000000000,0 -> /BYTES/c +data: "k/10"/11.000000000,0 -> /BYTES/10 +data: "k/30"/11.000000000,0 -> /BYTES/30 +logical op: *enginepb.MVCCCommitIntentOp