Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

kv/kvserver: use proper formatting when debug printing intents #69809

Merged
merged 1 commit into from
Sep 14, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion pkg/kv/kvserver/debug_print.go
Original file line number Diff line number Diff line change
Expand Up @@ -140,7 +140,7 @@ func tryIntent(kv storage.MVCCKeyValue) (string, error) {
if err := protoutil.Unmarshal(kv.Value, &meta); err != nil {
return "", err
}
s := fmt.Sprintf("%+v", meta)
s := fmt.Sprintf("%+v", &meta)
if meta.Txn != nil {
s = meta.Txn.WriteTimestamp.String() + " " + s
}
Expand Down
13 changes: 13 additions & 0 deletions pkg/storage/enginepb/mvcc.go
Original file line number Diff line number Diff line change
Expand Up @@ -315,6 +315,12 @@ func (meta *MVCCMetadata) FormatW(buf io.Writer, expand bool) {
fmt.Fprintf(buf, " nih=%d", nih)
}
}

var txnDidNotUpdateMeta bool
if meta.TxnDidNotUpdateMeta != nil {
txnDidNotUpdateMeta = *meta.TxnDidNotUpdateMeta
}
fmt.Fprintf(buf, " mergeTs=%s txnDidNotUpdateMeta=%t", meta.MergeTimestamp, txnDidNotUpdateMeta)
}

func (meta *MVCCMetadataSubsetForMergeSerialization) String() string {
Expand Down Expand Up @@ -343,6 +349,13 @@ func (meta *MVCCMetadata) SafeMessage() string {
if nih := len(meta.IntentHistory); nih > 0 {
fmt.Fprintf(&buf, " nih=%d", nih)
}

var txnDidNotUpdateMeta bool
if meta.TxnDidNotUpdateMeta != nil {
txnDidNotUpdateMeta = *meta.TxnDidNotUpdateMeta
}
fmt.Fprintf(&buf, " mergeTs=%s txnDidNotUpdateMeta=%t", meta.MergeTimestamp, txnDidNotUpdateMeta)

return buf.String()
}

Expand Down
7 changes: 5 additions & 2 deletions pkg/storage/enginepb/mvcc_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ func TestFormatMVCCMetadata(t *testing.T) {
t.Fatal(err)
}
ts := hlc.Timestamp{Logical: 1}
txnDidNotUpdateMeta := true
tmeta := &enginepb.TxnMeta{
Key: roachpb.Key("a"),
ID: txnID,
Expand All @@ -50,10 +51,11 @@ func TestFormatMVCCMetadata(t *testing.T) {
{Sequence: 11, Value: val2.RawBytes},
{Sequence: 22, Value: val3.RawBytes},
},
TxnDidNotUpdateMeta: &txnDidNotUpdateMeta,
}

const expStr = `txn={id=d7aa0f5e key="a" pri=0.00000000 epo=1 ts=0,1 min=0,1 seq=0}` +
` ts=0,1 del=false klen=123 vlen=456 rawlen=8 nih=2`
` ts=0,1 del=false klen=123 vlen=456 rawlen=8 nih=2 mergeTs=<nil> txnDidNotUpdateMeta=true`

if str := meta.String(); str != expStr {
t.Errorf(
Expand All @@ -63,7 +65,8 @@ func TestFormatMVCCMetadata(t *testing.T) {
}

const expV = `txn={id=d7aa0f5e key="a" pri=0.00000000 epo=1 ts=0,1 min=0,1 seq=0}` +
` ts=0,1 del=false klen=123 vlen=456 raw=/BYTES/foo ih={{11 /BYTES/bar}{22 /BYTES/baz}}`
` ts=0,1 del=false klen=123 vlen=456 raw=/BYTES/foo ih={{11 /BYTES/bar}{22 /BYTES/baz}}` +
` mergeTs=<nil> txnDidNotUpdateMeta=true`

if str := fmt.Sprintf("%+v", meta); str != expV {
t.Errorf(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=123.000000000,0 wto=false gul=0,0
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=6
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=6 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "k"/123.000000000,0 -> /BYTES/v

# Now, overwrite value1 with value2 from same txn; should see value1
Expand All @@ -26,7 +26,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=2} lock=true stat=PENDING rts=123.000000000,0 wto=false gul=0,0
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=2} ts=123.000000000,0 del=false klen=12 vlen=7 ih={{1 /BYTES/v}}
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=2} ts=123.000000000,0 del=false klen=12 vlen=7 ih={{1 /BYTES/v}} mergeTs=<nil> txnDidNotUpdateMeta=false
data: "k"/123.000000000,0 -> /BYTES/v2

# Writing value3 from a new epoch should see nil again.
Expand All @@ -39,7 +39,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=1 ts=123.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=123.000000000,0 wto=false gul=0,0
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=7
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=7 mergeTs=<nil> txnDidNotUpdateMeta=false
data: "k"/123.000000000,0 -> /BYTES/v3

# Commit value3 at a later timestamp.
Expand Down Expand Up @@ -87,7 +87,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=0 ts=2.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=2.000000000,0 wto=false gul=0,0
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=2.000000000,0 min=0,0 seq=1} ts=2.000000000,0 del=false klen=12 vlen=9
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=2.000000000,0 min=0,0 seq=1} ts=2.000000000,0 del=false klen=12 vlen=9 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "c"/2.000000000,0 -> /BYTES/cput
data: "c"/1.000000000,0 -> /BYTES/value

Expand All @@ -105,6 +105,6 @@ txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=3.000000000,0 wto=false gul=0,0
>> cput k=c v=cput cond=value t=A
called PutIntent("c", _, ExistingIntentInterleaved, TDNUM(true), 00000000-0000-0000-0000-000000000002)
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,0 seq=1} ts=3.000000000,0 del=false klen=12 vlen=9
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,0 seq=1} ts=3.000000000,0 del=false klen=12 vlen=9 mergeTs=<nil> txnDidNotUpdateMeta=false
data: "c"/3.000000000,0 -> /BYTES/cput
data: "c"/1.000000000,0 -> /BYTES/value
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=123.000000000,0 wto=false gul=0,0
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=6
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=6 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "k"/123.000000000,0 -> /BYTES/v

# Now, overwrite value1 with value2 from same txn; should see value1
Expand All @@ -26,7 +26,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=2} lock=true stat=PENDING rts=123.000000000,0 wto=false gul=0,0
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=2} ts=123.000000000,0 del=false klen=12 vlen=7 ih={{1 /BYTES/v}}
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=123.000000000,0 min=0,0 seq=2} ts=123.000000000,0 del=false klen=12 vlen=7 ih={{1 /BYTES/v}} mergeTs=<nil> txnDidNotUpdateMeta=false
data: "k"/123.000000000,0 -> /BYTES/v2

# Writing value3 from a new epoch should see nil again.
Expand All @@ -39,7 +39,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=1 ts=123.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=123.000000000,0 wto=false gul=0,0
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=7
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=123.000000000,0 min=0,0 seq=1} ts=123.000000000,0 del=false klen=12 vlen=7 mergeTs=<nil> txnDidNotUpdateMeta=false
data: "k"/123.000000000,0 -> /BYTES/v3

# Commit value3 at a later timestamp.
Expand Down Expand Up @@ -87,7 +87,7 @@ with t=A
----
>> at end:
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=0 ts=2.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=2.000000000,0 wto=false gul=0,0
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=2.000000000,0 min=0,0 seq=1} ts=2.000000000,0 del=false klen=12 vlen=9
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=2.000000000,0 min=0,0 seq=1} ts=2.000000000,0 del=false klen=12 vlen=9 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "c"/2.000000000,0 -> /BYTES/cput
data: "c"/1.000000000,0 -> /BYTES/value

Expand All @@ -105,6 +105,6 @@ txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,
txn: "A" meta={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,0 seq=1} lock=true stat=PENDING rts=3.000000000,0 wto=false gul=0,0
>> cput k=c v=cput cond=value t=A
called PutIntent("c", _, ExistingIntentSeparated, TDNUM(true), 00000000-0000-0000-0000-000000000002)
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,0 seq=1} ts=3.000000000,0 del=false klen=12 vlen=9
meta: "c"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=1 ts=3.000000000,0 min=0,0 seq=1} ts=3.000000000,0 del=false klen=12 vlen=9 mergeTs=<nil> txnDidNotUpdateMeta=false
data: "c"/3.000000000,0 -> /BYTES/cput
data: "c"/1.000000000,0 -> /BYTES/value
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ with t=a
cput k=k v=v3
----
>> at end:
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=10.000000000,2 min=0,0 seq=0} ts=10.000000000,2 del=false klen=12 vlen=7
meta: "k"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=10.000000000,2 min=0,0 seq=0} ts=10.000000000,2 del=false klen=12 vlen=7 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "k"/10.000000000,2 -> /BYTES/v3
data: "k"/10.000000000,1 -> /BYTES/v2
data: "k"/10.000000000,0 -> /BYTES/v1
Expand Down
20 changes: 10 additions & 10 deletions pkg/storage/testdata/mvcc_histories/delete_range
Original file line number Diff line number Diff line change
Expand Up @@ -60,10 +60,10 @@ data: "a"/45.000000000,0 -> /<empty>
data: "a"/44.000000000,0 -> /BYTES/abc
data: "a/123"/45.000000000,0 -> /<empty>
data: "a/123"/44.000000000,0 -> /BYTES/abc
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b"/46.000000000,0 -> /<empty>
data: "b"/44.000000000,0 -> /BYTES/abc
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b/123"/46.000000000,0 -> /<empty>
data: "b/123"/44.000000000,0 -> /BYTES/abc
data: "c"/44.000000000,0 -> /BYTES/abc
Expand All @@ -88,10 +88,10 @@ data: "a"/45.000000000,0 -> /<empty>
data: "a"/44.000000000,0 -> /BYTES/abc
data: "a/123"/45.000000000,0 -> /<empty>
data: "a/123"/44.000000000,0 -> /BYTES/abc
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b"/46.000000000,0 -> /<empty>
data: "b"/44.000000000,0 -> /BYTES/abc
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b/123"/46.000000000,0 -> /<empty>
data: "b/123"/44.000000000,0 -> /BYTES/abc
data: "c"/47.000000000,0 -> /<empty>
Expand All @@ -116,10 +116,10 @@ data: "a"/45.000000000,0 -> /<empty>
data: "a"/44.000000000,0 -> /BYTES/abc
data: "a/123"/45.000000000,0 -> /<empty>
data: "a/123"/44.000000000,0 -> /BYTES/abc
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b"/46.000000000,0 -> /<empty>
data: "b"/44.000000000,0 -> /BYTES/abc
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b/123"/46.000000000,0 -> /<empty>
data: "b/123"/44.000000000,0 -> /BYTES/abc
data: "c"/47.000000000,0 -> /<empty>
Expand Down Expand Up @@ -152,19 +152,19 @@ data: "a"/45.000000000,0 -> /<empty>
data: "a"/44.000000000,0 -> /BYTES/abc
data: "a/123"/45.000000000,0 -> /<empty>
data: "a/123"/44.000000000,0 -> /BYTES/abc
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b"/46.000000000,0 -> /<empty>
data: "b"/44.000000000,0 -> /BYTES/abc
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0
meta: "b/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=46.000000000,0 min=0,0 seq=0} ts=46.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "b/123"/46.000000000,0 -> /<empty>
data: "b/123"/44.000000000,0 -> /BYTES/abc
data: "c"/47.000000000,0 -> /<empty>
data: "c"/44.000000000,0 -> /BYTES/abc
data: "c/123"/47.000000000,0 -> /<empty>
data: "c/123"/44.000000000,0 -> /BYTES/abc
meta: "d"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=48.000000000,0 min=0,0 seq=0} ts=48.000000000,0 del=true klen=12 vlen=0
meta: "d"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=48.000000000,0 min=0,0 seq=0} ts=48.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "d"/48.000000000,0 -> /<empty>
data: "d"/44.000000000,0 -> /BYTES/abc
meta: "d/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=48.000000000,0 min=0,0 seq=0} ts=48.000000000,0 del=true klen=12 vlen=0
meta: "d/123"/0,0 -> txn={id=00000000 key=/Min pri=0.00000000 epo=0 ts=48.000000000,0 min=0,0 seq=0} ts=48.000000000,0 del=true klen=12 vlen=0 mergeTs=<nil> txnDidNotUpdateMeta=true
data: "d/123"/48.000000000,0 -> /<empty>
data: "d/123"/44.000000000,0 -> /BYTES/abc
Loading