Skip to content

Commit 9af8fe2

Browse files
yuzefovichyuzefovich
authored
Merge pull request #140441 from cockroachdb/blathers/backport-release-25.1-140338
release-25.1: colfetcher: include column family ID in tracing
2 parents ff7194d + 703ddae commit 9af8fe2

File tree

11 files changed

+246
-240
lines changed

11 files changed

+246
-240
lines changed

‎pkg/sql/colfetcher/cfetcher.go

+5
Original file line numberDiff line numberDiff line change
@@ -1085,6 +1085,11 @@ func (cf *cFetcher) processValue(ctx context.Context, familyID descpb.FamilyID)
10851085
if cf.traceKV {
10861086
defer func() {
10871087
if err == nil {
1088+
if cf.table.spec.MaxKeysPerRow > 1 {
1089+
// If the index has more than one column family, then
1090+
// include the column family ID.
1091+
prettyKey = fmt.Sprintf("%s:cf=%d", prettyKey, familyID)
1092+
}
10881093
log.VEventf(ctx, 2, "fetched: %s -> %s", prettyKey, prettyValue)
10891094
}
10901095
}()

‎pkg/sql/logictest/testdata/logic_test/column_families

+3-3
Original file line numberDiff line numberDiff line change
@@ -76,9 +76,9 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WHERE
7676
message LIKE 'fetched: /t/t_pkey/%'
7777
ORDER BY message
7878
----
79-
fetched: /t/t_pkey/1/2.00/x -> /1.00
80-
fetched: /t/t_pkey/1/2/y -> /2.00
81-
fetched: /t/t_pkey/1/2/z -> /1
79+
fetched: /t/t_pkey/1/2.00/x:cf=2 -> /1.00
80+
fetched: /t/t_pkey/1/2/y:cf=1 -> /2.00
81+
fetched: /t/t_pkey/1/2/z:cf=0 -> /1
8282

8383
# Regression test for #131860.
8484

‎pkg/sql/opt/exec/execbuilder/testdata/aggregate

+8-8
Original file line numberDiff line numberDiff line change
@@ -1073,14 +1073,14 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
10731073
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
10741074
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
10751075
----
1076-
fetched: /xyz/xyz_pkey/1 -> <undecoded>
1077-
fetched: /xyz/xyz_pkey/1/y -> 2
1078-
fetched: /xyz/xyz_pkey/1/z -> 3.0
1079-
fetched: /xyz/xyz_pkey/4 -> <undecoded>
1080-
fetched: /xyz/xyz_pkey/4/y -> 5
1081-
fetched: /xyz/xyz_pkey/4/z -> 6.0
1082-
fetched: /xyz/xyz_pkey/7 -> <undecoded>
1083-
fetched: /xyz/xyz_pkey/7/z -> 8.0
1076+
fetched: /xyz/xyz_pkey/1:cf=0 -> <undecoded>
1077+
fetched: /xyz/xyz_pkey/1/y:cf=1 -> 2
1078+
fetched: /xyz/xyz_pkey/1/z:cf=2 -> 3.0
1079+
fetched: /xyz/xyz_pkey/4:cf=0 -> <undecoded>
1080+
fetched: /xyz/xyz_pkey/4/y:cf=1 -> 5
1081+
fetched: /xyz/xyz_pkey/4/z:cf=2 -> 6.0
1082+
fetched: /xyz/xyz_pkey/7:cf=0 -> <undecoded>
1083+
fetched: /xyz/xyz_pkey/7/z:cf=2 -> 8.0
10841084
output row: [9 4.5 6.33333333333333]
10851085

10861086
query T

‎pkg/sql/opt/exec/execbuilder/testdata/ddl

+2-2
Original file line numberDiff line numberDiff line change
@@ -137,8 +137,8 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
137137
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
138138
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
139139
----
140-
fetched: /t/t_pkey/1 -> <undecoded>
141-
fetched: /t/t_pkey/1/b -> 1
140+
fetched: /t/t_pkey/1:cf=0 -> <undecoded>
141+
fetched: /t/t_pkey/1/b:cf=1 -> 1
142142
output row: [1 1]
143143

144144
user root

‎pkg/sql/opt/exec/execbuilder/testdata/insert

+58-57
Original file line numberDiff line numberDiff line change
@@ -31,19 +31,19 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
3131
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
3232
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
3333
----
34-
fetched: /kv/kv_pkey/'A' -> <undecoded>
35-
fetched: /kv/kv_pkey/'a' -> <undecoded>
36-
fetched: /kv/kv_pkey/'a'/v -> 'b'
37-
fetched: /kv/kv_pkey/'c' -> <undecoded>
38-
fetched: /kv/kv_pkey/'c'/v -> 'd'
39-
fetched: /kv/kv_pkey/'e' -> <undecoded>
40-
fetched: /kv/kv_pkey/'e'/v -> 'f'
41-
fetched: /kv/kv_pkey/'g' -> <undecoded>
42-
fetched: /kv/kv_pkey/'g'/v -> ''
43-
fetched: /kv/kv_pkey/'nil1' -> <undecoded>
44-
fetched: /kv/kv_pkey/'nil2' -> <undecoded>
45-
fetched: /kv/kv_pkey/'nil3' -> <undecoded>
46-
fetched: /kv/kv_pkey/'nil4' -> <undecoded>
34+
fetched: /kv/kv_pkey/'A':cf=0 -> <undecoded>
35+
fetched: /kv/kv_pkey/'a':cf=0 -> <undecoded>
36+
fetched: /kv/kv_pkey/'a'/v:cf=1 -> 'b'
37+
fetched: /kv/kv_pkey/'c':cf=0 -> <undecoded>
38+
fetched: /kv/kv_pkey/'c'/v:cf=1 -> 'd'
39+
fetched: /kv/kv_pkey/'e':cf=0 -> <undecoded>
40+
fetched: /kv/kv_pkey/'e'/v:cf=1 -> 'f'
41+
fetched: /kv/kv_pkey/'g':cf=0 -> <undecoded>
42+
fetched: /kv/kv_pkey/'g'/v:cf=1 -> ''
43+
fetched: /kv/kv_pkey/'nil1':cf=0 -> <undecoded>
44+
fetched: /kv/kv_pkey/'nil2':cf=0 -> <undecoded>
45+
fetched: /kv/kv_pkey/'nil3':cf=0 -> <undecoded>
46+
fetched: /kv/kv_pkey/'nil4':cf=0 -> <undecoded>
4747
output row: ['A' NULL]
4848
output row: ['a' 'b']
4949
output row: ['c' 'd']
@@ -92,19 +92,19 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
9292
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
9393
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
9494
----
95-
fetched: /kv/kv_pkey/'A' -> <undecoded>
96-
fetched: /kv/kv_pkey/'a' -> <undecoded>
97-
fetched: /kv/kv_pkey/'a'/v -> 'b'
98-
fetched: /kv/kv_pkey/'c' -> <undecoded>
99-
fetched: /kv/kv_pkey/'c'/v -> 'd'
100-
fetched: /kv/kv_pkey/'e' -> <undecoded>
101-
fetched: /kv/kv_pkey/'e'/v -> 'f'
102-
fetched: /kv/kv_pkey/'g' -> <undecoded>
103-
fetched: /kv/kv_pkey/'g'/v -> ''
104-
fetched: /kv/kv_pkey/'nil1' -> <undecoded>
105-
fetched: /kv/kv_pkey/'nil2' -> <undecoded>
106-
fetched: /kv/kv_pkey/'nil3' -> <undecoded>
107-
fetched: /kv/kv_pkey/'nil4' -> <undecoded>
95+
fetched: /kv/kv_pkey/'A':cf=0 -> <undecoded>
96+
fetched: /kv/kv_pkey/'a':cf=0 -> <undecoded>
97+
fetched: /kv/kv_pkey/'a'/v:cf=1 -> 'b'
98+
fetched: /kv/kv_pkey/'c':cf=0 -> <undecoded>
99+
fetched: /kv/kv_pkey/'c'/v:cf=1 -> 'd'
100+
fetched: /kv/kv_pkey/'e':cf=0 -> <undecoded>
101+
fetched: /kv/kv_pkey/'e'/v:cf=1 -> 'f'
102+
fetched: /kv/kv_pkey/'g':cf=0 -> <undecoded>
103+
fetched: /kv/kv_pkey/'g'/v:cf=1 -> ''
104+
fetched: /kv/kv_pkey/'nil1':cf=0 -> <undecoded>
105+
fetched: /kv/kv_pkey/'nil2':cf=0 -> <undecoded>
106+
fetched: /kv/kv_pkey/'nil3':cf=0 -> <undecoded>
107+
fetched: /kv/kv_pkey/'nil4':cf=0 -> <undecoded>
108108
output row: ['A' NULL]
109109
output row: ['a' 'b']
110110
output row: ['c' 'd']
@@ -153,21 +153,21 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
153153
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
154154
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
155155
----
156-
fetched: /kv/kv_pkey/'A' -> <undecoded>
157-
fetched: /kv/kv_pkey/'a' -> <undecoded>
158-
fetched: /kv/kv_pkey/'a'/v -> 'b'
159-
fetched: /kv/kv_pkey/'c' -> <undecoded>
160-
fetched: /kv/kv_pkey/'c'/v -> 'd'
161-
fetched: /kv/kv_pkey/'e' -> <undecoded>
162-
fetched: /kv/kv_pkey/'e'/v -> 'f'
163-
fetched: /kv/kv_pkey/'f' -> <undecoded>
164-
fetched: /kv/kv_pkey/'f'/v -> 'g'
165-
fetched: /kv/kv_pkey/'g' -> <undecoded>
166-
fetched: /kv/kv_pkey/'g'/v -> ''
167-
fetched: /kv/kv_pkey/'nil1' -> <undecoded>
168-
fetched: /kv/kv_pkey/'nil2' -> <undecoded>
169-
fetched: /kv/kv_pkey/'nil3' -> <undecoded>
170-
fetched: /kv/kv_pkey/'nil4' -> <undecoded>
156+
fetched: /kv/kv_pkey/'A':cf=0 -> <undecoded>
157+
fetched: /kv/kv_pkey/'a':cf=0 -> <undecoded>
158+
fetched: /kv/kv_pkey/'a'/v:cf=1 -> 'b'
159+
fetched: /kv/kv_pkey/'c':cf=0 -> <undecoded>
160+
fetched: /kv/kv_pkey/'c'/v:cf=1 -> 'd'
161+
fetched: /kv/kv_pkey/'e':cf=0 -> <undecoded>
162+
fetched: /kv/kv_pkey/'e'/v:cf=1 -> 'f'
163+
fetched: /kv/kv_pkey/'f':cf=0 -> <undecoded>
164+
fetched: /kv/kv_pkey/'f'/v:cf=1 -> 'g'
165+
fetched: /kv/kv_pkey/'g':cf=0 -> <undecoded>
166+
fetched: /kv/kv_pkey/'g'/v:cf=1 -> ''
167+
fetched: /kv/kv_pkey/'nil1':cf=0 -> <undecoded>
168+
fetched: /kv/kv_pkey/'nil2':cf=0 -> <undecoded>
169+
fetched: /kv/kv_pkey/'nil3':cf=0 -> <undecoded>
170+
fetched: /kv/kv_pkey/'nil4':cf=0 -> <undecoded>
171171
output row: ['A' NULL]
172172
output row: ['a' 'b']
173173
output row: ['c' 'd']
@@ -219,21 +219,21 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
219219
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
220220
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
221221
----
222-
fetched: /kv/kv_pkey/'A' -> <undecoded>
223-
fetched: /kv/kv_pkey/'a' -> <undecoded>
224-
fetched: /kv/kv_pkey/'a'/v -> 'b'
225-
fetched: /kv/kv_pkey/'c' -> <undecoded>
226-
fetched: /kv/kv_pkey/'c'/v -> 'd'
227-
fetched: /kv/kv_pkey/'e' -> <undecoded>
228-
fetched: /kv/kv_pkey/'e'/v -> 'f'
229-
fetched: /kv/kv_pkey/'f' -> <undecoded>
230-
fetched: /kv/kv_pkey/'f'/v -> 'g'
231-
fetched: /kv/kv_pkey/'g' -> <undecoded>
232-
fetched: /kv/kv_pkey/'g'/v -> ''
233-
fetched: /kv/kv_pkey/'nil1' -> <undecoded>
234-
fetched: /kv/kv_pkey/'nil2' -> <undecoded>
235-
fetched: /kv/kv_pkey/'nil3' -> <undecoded>
236-
fetched: /kv/kv_pkey/'nil4' -> <undecoded>
222+
fetched: /kv/kv_pkey/'A':cf=0 -> <undecoded>
223+
fetched: /kv/kv_pkey/'a':cf=0 -> <undecoded>
224+
fetched: /kv/kv_pkey/'a'/v:cf=1 -> 'b'
225+
fetched: /kv/kv_pkey/'c':cf=0 -> <undecoded>
226+
fetched: /kv/kv_pkey/'c'/v:cf=1 -> 'd'
227+
fetched: /kv/kv_pkey/'e':cf=0 -> <undecoded>
228+
fetched: /kv/kv_pkey/'e'/v:cf=1 -> 'f'
229+
fetched: /kv/kv_pkey/'f':cf=0 -> <undecoded>
230+
fetched: /kv/kv_pkey/'f'/v:cf=1 -> 'g'
231+
fetched: /kv/kv_pkey/'g':cf=0 -> <undecoded>
232+
fetched: /kv/kv_pkey/'g'/v:cf=1 -> ''
233+
fetched: /kv/kv_pkey/'nil1':cf=0 -> <undecoded>
234+
fetched: /kv/kv_pkey/'nil2':cf=0 -> <undecoded>
235+
fetched: /kv/kv_pkey/'nil3':cf=0 -> <undecoded>
236+
fetched: /kv/kv_pkey/'nil4':cf=0 -> <undecoded>
237237
output row: ['A' NULL]
238238
output row: ['a' 'b']
239239
output row: ['c' 'd']
@@ -278,7 +278,8 @@ statement ok
278278
CREATE TABLE kv5 (
279279
k CHAR PRIMARY KEY,
280280
v CHAR,
281-
UNIQUE INDEX a (v, k)
281+
UNIQUE INDEX a (v, k),
282+
FAMILY (k, v)
282283
)
283284

284285
statement ok

‎pkg/sql/opt/exec/execbuilder/testdata/orderby

+8-8
Original file line numberDiff line numberDiff line change
@@ -293,10 +293,10 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
293293
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
294294
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
295295
----
296-
fetched: /abc/abc_pkey/1/2/3 -> <undecoded>
297-
fetched: /abc/abc_pkey/1/2/3/d -> 'one'
298-
fetched: /abc/abc_pkey/4/5/6 -> <undecoded>
299-
fetched: /abc/abc_pkey/4/5/6/d -> 'Two'
296+
fetched: /abc/abc_pkey/1/2/3:cf=0 -> <undecoded>
297+
fetched: /abc/abc_pkey/1/2/3/d:cf=1 -> 'one'
298+
fetched: /abc/abc_pkey/4/5/6:cf=0 -> <undecoded>
299+
fetched: /abc/abc_pkey/4/5/6/d:cf=1 -> 'Two'
300300
output row: [1 2 3 'one']
301301
output row: [4 5 6 'Two']
302302

@@ -480,10 +480,10 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
480480
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
481481
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
482482
----
483-
fetched: /abc/abc_pkey/4/?/? -> <undecoded>
484-
fetched: /abc/abc_pkey/4/?/? -> <undecoded>
485-
fetched: /abc/abc_pkey/1/?/? -> <undecoded>
486-
fetched: /abc/abc_pkey/1/?/? -> <undecoded>
483+
fetched: /abc/abc_pkey/4/?/?:cf=1 -> <undecoded>
484+
fetched: /abc/abc_pkey/4/?/?:cf=0 -> <undecoded>
485+
fetched: /abc/abc_pkey/1/?/?:cf=1 -> <undecoded>
486+
fetched: /abc/abc_pkey/1/?/?:cf=0 -> <undecoded>
487487
output row: [4]
488488
output row: [1]
489489

‎pkg/sql/opt/exec/execbuilder/testdata/secondary_index_column_families

+20-20
Original file line numberDiff line numberDiff line change
@@ -89,9 +89,9 @@ query T
8989
SELECT message FROM [SHOW KV TRACE FOR SESSION] WHERE
9090
message LIKE 'fetched: /t1/nonuniqueidxstoring/%'
9191
----
92-
fetched: /t1/nonuniqueidxstoring/1/1 -> <undecoded>
93-
fetched: /t1/nonuniqueidxstoring/1/1/z -> /1
94-
fetched: /t1/nonuniqueidxstoring/1/1/a/b -> /1/1
92+
fetched: /t1/nonuniqueidxstoring/1/1:cf=0 -> <undecoded>
93+
fetched: /t1/nonuniqueidxstoring/1/1/z:cf=2 -> /1
94+
fetched: /t1/nonuniqueidxstoring/1/1/a/b:cf=3 -> /1/1
9595

9696
query IIIII
9797
SET TRACING=on,kv,results;
@@ -104,9 +104,9 @@ query T
104104
SELECT message FROM [SHOW KV TRACE FOR SESSION] WHERE
105105
message LIKE 'fetched: /t1/uniqueidxstoring/%'
106106
----
107-
fetched: /t1/uniqueidxstoring/1 -> /1
108-
fetched: /t1/uniqueidxstoring/1/z -> /1
109-
fetched: /t1/uniqueidxstoring/1/a/b -> /1/1
107+
fetched: /t1/uniqueidxstoring/1:cf=0 -> /1
108+
fetched: /t1/uniqueidxstoring/1/z:cf=2 -> /1
109+
fetched: /t1/uniqueidxstoring/1/a/b:cf=3 -> /1/1
110110

111111

112112
#Test some specific behavior with nulls on unique indexes.
@@ -127,15 +127,15 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WHERE
127127
message LIKE 'fetched: /t1/uniqueidxstoring/%'
128128
ORDER BY message
129129
----
130-
fetched: /t1/uniqueidxstoring/1 -> /1
131-
fetched: /t1/uniqueidxstoring/1/a/b -> /1/1
132-
fetched: /t1/uniqueidxstoring/1/z -> /1
133-
fetched: /t1/uniqueidxstoring/NULL -> /3
134-
fetched: /t1/uniqueidxstoring/NULL -> /4
135-
fetched: /t1/uniqueidxstoring/NULL/a/b -> /3/3
136-
fetched: /t1/uniqueidxstoring/NULL/a/b -> /4/4
137-
fetched: /t1/uniqueidxstoring/NULL/z -> /3
138-
fetched: /t1/uniqueidxstoring/NULL/z -> /4
130+
fetched: /t1/uniqueidxstoring/1/a/b:cf=3 -> /1/1
131+
fetched: /t1/uniqueidxstoring/1/z:cf=2 -> /1
132+
fetched: /t1/uniqueidxstoring/1:cf=0 -> /1
133+
fetched: /t1/uniqueidxstoring/NULL/a/b:cf=3 -> /3/3
134+
fetched: /t1/uniqueidxstoring/NULL/a/b:cf=3 -> /4/4
135+
fetched: /t1/uniqueidxstoring/NULL/z:cf=2 -> /3
136+
fetched: /t1/uniqueidxstoring/NULL/z:cf=2 -> /4
137+
fetched: /t1/uniqueidxstoring/NULL:cf=0 -> /3
138+
fetched: /t1/uniqueidxstoring/NULL:cf=0 -> /4
139139

140140
# Ensure that updates delete and insert all K/V pairs for each index.
141141
# Note: we don't use kvtrace query type here because it is clearer to
@@ -329,11 +329,11 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WHERE
329329
message LIKE 'fetched%'
330330
ORDER BY message
331331
----
332-
fetched: /t/i/2/1 -> <undecoded>
333-
fetched: /t/i/2/1/w -> /3
334-
fetched: /t/i/5/4 -> <undecoded>
335-
fetched: /t/i/5/4/z -> /6
336-
fetched: /t/i/9/8 -> <undecoded>
332+
fetched: /t/i/2/1/w:cf=3 -> /3
333+
fetched: /t/i/2/1:cf=0 -> <undecoded>
334+
fetched: /t/i/5/4/z:cf=2 -> /6
335+
fetched: /t/i/5/4:cf=0 -> <undecoded>
336+
fetched: /t/i/9/8:cf=0 -> <undecoded>
337337

338338
statement ok
339339
DROP TABLE IF EXISTS t;

‎pkg/sql/opt/exec/execbuilder/testdata/select

+3-3
Original file line numberDiff line numberDiff line change
@@ -843,9 +843,9 @@ SELECT message FROM [SHOW KV TRACE FOR SESSION] WITH ORDINALITY
843843
WHERE message LIKE 'fetched:%' OR message LIKE 'output row%'
844844
ORDER BY message LIKE 'fetched:%' DESC, ordinality ASC
845845
----
846-
fetched: /dt/dt_pkey/'2015-08-25 04:45:45.53453' -> <undecoded>
847-
fetched: /dt/dt_pkey/'2015-08-25 04:45:45.53453'/b -> '2015-08-25'
848-
fetched: /dt/dt_pkey/'2015-08-25 04:45:45.53453'/c -> '02:45:02.234'
846+
fetched: /dt/dt_pkey/'2015-08-25 04:45:45.53453':cf=0 -> <undecoded>
847+
fetched: /dt/dt_pkey/'2015-08-25 04:45:45.53453'/b:cf=1 -> '2015-08-25'
848+
fetched: /dt/dt_pkey/'2015-08-25 04:45:45.53453'/c:cf=2 -> '02:45:02.234'
849849
output row: ['2015-08-25 04:45:45.53453' '2015-08-25' '02:45:02.234']
850850

851851
statement ok

0 commit comments

Comments
 (0)