Skip to content

Commit 0d110cd

Browse files
craig[bot]cucaroachrafissstevendannadhartunian
committed
106130: sql: add extra information to protocol errors in bind r=rafiss a=cucaroach A user is running into mysterious protocol errors when using prepared statements. Add some extra information to the error message to help guide the investigation. Informs: https://github.com/cockroachlabs/support/issues/2184 Release note: none Epic: none 107912: sql: fix exec+audit logs for BEGIN, COMMIT, SET stmts r=rafiss a=rafiss Epic: None Release note (bug fix): Fixed a bug where BEGIN, COMMIT, SET, ROLLBACK, and SAVEPOINT statements would not be written to the execution or audit logs. 108093: jobs: avoid crdb_internal.system_jobs in gc-jobs r=miretskiy a=stevendanna The crdb_internal.system_jobs is a virtual table that joins information from the jobs table and the jobs_info table. For the previous query, SELECT id, payload, status FROM "".crdb_internal.system_jobs WHERE (created < $1) AND (id > $2) ORDER BY id LIMIT $3 this is a little suboptimal because: - We don't make use of the progress column so any read of that is useless. - While the crdb_internal.virtual table has a virtual index on job id, and EXPLAIN will even claim that it will be used: • limit │ count: 100 │ └── • filter │ filter: created < '2023-07-20 07:29:01.17001' │ └── • virtual table table: system_jobs@system_jobs_id_idx spans: [/101 - ] This is actually a lie. A virtual index can only handle single-key spans. As a result the unconstrained query is used: ``` WITH latestpayload AS (SELECT job_id, value FROM system.job_info AS payload WHERE info_key = 'legacy_payload' ORDER BY written DESC), latestprogress AS (SELECT job_id, value FROM system.job_info AS progress WHERE info_key = 'legacy_progress' ORDER BY written DESC) SELECT DISTINCT(id), status, created, payload.value AS payload, progress.value AS progress, created_by_type, created_by_id, claim_session_id, claim_instance_id, num_runs, last_run, job_type FROM system.jobs AS j INNER JOIN latestpayload AS payload ON j.id = payload.job_id LEFT JOIN latestprogress AS progress ON j.id = progress.job_id ``` which has a full scan of the jobs table and 2 full scans of the info table: • distinct │ distinct on: id, value, value │ └── • merge join │ equality: (job_id) = (id) │ ├── • render │ │ │ └── • filter │ │ estimated row count: 7,318 │ │ filter: info_key = 'legacy_payload' │ │ │ └── • scan │ estimated row count: 14,648 (100% of the table; stats collected 39 minutes ago; using stats forecast for 2 hours in the future) │ table: job_info@primary │ spans: FULL SCAN │ └── • merge join (right outer) │ equality: (job_id) = (id) │ right cols are key │ ├── • render │ │ │ └── • filter │ │ estimated row count: 7,317 │ │ filter: info_key = 'legacy_progress' │ │ │ └── • scan │ estimated row count: 14,648 (100% of the table; stats collected 39 minutes ago; using stats forecast for 2 hours in the future) │ table: job_info@primary │ spans: FULL SCAN │ └── • scan missing stats table: jobs@primary spans: FULL SCAN Because of the limit, I don't think this ends up being as bad as it looks. But it still isn't great. In this PR, we replace crdb_internal.jobs with a query that removes the join on the unused progress field and also constrains the query of the job_info table. • distinct │ distinct on: id, value │ └── • merge join │ equality: (job_id) = (id) │ right cols are key │ ├── • render │ │ │ └── • filter │ │ estimated row count: 7,318 │ │ filter: info_key = 'legacy_payload' │ │ │ └── • scan │ estimated row count: 14,646 (100% of the table; stats collected 45 minutes ago; using stats forecast for 2 hours in the future) │ table: job_info@primary │ spans: [/101/'legacy_payload' - ] │ └── • render │ └── • limit │ count: 100 │ └── • filter │ filter: created < '2023-07-20 07:29:01.17001' │ └── • scan missing stats table: jobs@primary spans: [/101 - ] In a local example, this does seem faster: > SELECT id, payload, status, created > FROM "".crdb_internal.system_jobs > WHERE (created < '2023-07-20 07:29:01.17001') AND (id > 100) ORDER BY id LIMIT 100; id | payload | status | created -----+---------+--------+---------- (0 rows) Time: 183ms total (execution 183ms / network 0ms) > WITH > latestpayload AS ( > SELECT job_id, value > FROM system.job_info AS payload > WHERE job_id > 100 AND info_key = 'legacy_payload' > ORDER BY written desc > ), > jobpage AS ( > SELECT id, status, created > FROM system.jobs > WHERE (created < '2023-07-20 07:29:01.17001') and (id > 100) > ORDER BY id > LIMIT 100 > ) > SELECT distinct (id), latestpayload.value AS payload, status > FROM jobpage AS j > INNER JOIN latestpayload ON j.id = latestpayload.job_id; id | payload | status -----+---------+--------- (0 rows) Time: 43ms total (execution 42ms / network 0ms) Release note: None Epic: none 108313: cli: debug zip uses read-only range probe r=joshimhoff a=dhartunian To reduce the chance of corruption issues when run against older clusters, the recently added use of `crdb_internal.probe_ranges` is modified to use a `read` probe instead of a `write` probe. See discussion in cockroachdb#107720 Release note: None Epic: None 108335: kvcoord: Implement CloseStream for MuxRangeFeed r=miretskiy a=miretskiy Extend MuxRangeFeed protocol to support explicit, caller initiated CloseStream operation. The caller may decide to stop receiving events for a particular stream, which is part of MuxRangeFeed. The caller may issue a request to MuxRangeFeed server to close the stream. The server will cancel underlying range feed, and return a `RangeFeedRetryError_REASON_RANGEFEED_CLOSED` error as a response. Note, current mux rangefeed clinet does not use this request. The code to support cancellation is added pre-emptively in case this functionality will be required in the future to support restarts due to stuck rangefeeds. Epic: CRDB-26372 Release note: None 108355: roachtest/multitenant-upgrade: hard-code predecessor version temporarily r=knz a=healthy-pod Hard-code the pre-decessor release to 23.1.4 until a new patch release is out (23.1.9) because the test is in-compatible with 23.1.{5,6,7,8} due to an erroneous PR merged on the 23.1 branch. Release note: None Epic: none 108375: changefeedccl: Increase test utility timeout r=miretskiy a=miretskiy As observed in cockroachdb#108348, a test failed because it timed out reading a row. Yet, this flake could not be reproduced in over 50k runs. Bump timeout period to make this flake even less likely. Fixes cockroachdb#108348 Release note: None Co-authored-by: Tommy Reilly <[email protected]> Co-authored-by: Rafi Shamim <[email protected]> Co-authored-by: Steven Danna <[email protected]> Co-authored-by: David Hartunian <[email protected]> Co-authored-by: Yevgeniy Miretskiy <[email protected]> Co-authored-by: healthy-pod <[email protected]>
8 parents 3ef6592 + ee3a9ab + ee05a80 + b9a92b1 + 0f44cac + 72a8b4e + ed2bad4 + a1cf907 commit 0d110cd

39 files changed

+584
-169
lines changed

pkg/acceptance/testdata/node/base-test.js

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,7 @@ describe('error cases', () => {
4040
const cases = [{
4141
name: 'not enough params',
4242
query: { text: 'SELECT 3', values: ['foo'] },
43-
msg: "bind message supplies 1 parameters, but prepared statement \"\" requires 0",
43+
msg: "bind message supplies 1 parameters, but requires 0",
4444
code: '08P01',
4545
}, {
4646
name: 'invalid utf8',

pkg/ccl/auditloggingccl/audit_logging_test.go

Lines changed: 18 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -156,6 +156,22 @@ func TestSingleRoleAuditLogging(t *testing.T) {
156156
`GRANT SELECT ON TABLE u TO root`,
157157
// DML statement
158158
`SELECT * FROM u`,
159+
// The following statements are all executed specially by the conn_executor.
160+
`SET application_name = 'test'`,
161+
`SET CLUSTER SETTING sql.defaults.vectorize = 'on'`,
162+
`BEGIN`,
163+
`SHOW application_name`,
164+
`SAVEPOINT s`,
165+
`RELEASE SAVEPOINT s`,
166+
`SAVEPOINT t`,
167+
`ROLLBACK TO SAVEPOINT t`,
168+
`COMMIT`,
169+
`SHOW COMMIT TIMESTAMP`,
170+
`BEGIN TRANSACTION PRIORITY LOW`,
171+
`ROLLBACK`,
172+
`PREPARE q AS SELECT 1`,
173+
`EXECUTE q`,
174+
`DEALLOCATE q`,
159175
}
160176
testData := []struct {
161177
name string
@@ -167,7 +183,7 @@ func TestSingleRoleAuditLogging(t *testing.T) {
167183
name: "test-all-stmt-types",
168184
role: allStmtTypesRole,
169185
queries: testQueries,
170-
expectedNumLogs: 3,
186+
expectedNumLogs: len(testQueries),
171187
},
172188
{
173189
name: "test-no-stmt-types",
@@ -181,7 +197,7 @@ func TestSingleRoleAuditLogging(t *testing.T) {
181197
role: "testuser",
182198
queries: testQueries,
183199
// One for each test query.
184-
expectedNumLogs: 3,
200+
expectedNumLogs: len(testQueries),
185201
},
186202
}
187203

pkg/ccl/changefeedccl/cdctest/row.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,7 +53,7 @@ func MakeRangeFeedValueReader(
5353
)
5454
require.NoError(t, err)
5555

56-
var timeout = 5 * time.Second
56+
var timeout = 10 * time.Second
5757
if util.RaceEnabled {
5858
timeout = 3 * timeout
5959
}

pkg/cli/testdata/zip/partial1

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ debug zip --concurrency=1 --cpu-profile-duration=0s /dev/null
3232
[cluster] retrieving SQL data for crdb_internal.kv_store_status... writing output: debug/crdb_internal.kv_store_status.txt... done
3333
[cluster] retrieving SQL data for crdb_internal.kv_system_privileges... writing output: debug/crdb_internal.kv_system_privileges.txt... done
3434
[cluster] retrieving SQL data for crdb_internal.partitions... writing output: debug/crdb_internal.partitions.txt... done
35-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt... done
35+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt... done
3636
[cluster] retrieving SQL data for crdb_internal.regions... writing output: debug/crdb_internal.regions.txt... done
3737
[cluster] retrieving SQL data for crdb_internal.schema_changes... writing output: debug/crdb_internal.schema_changes.txt... done
3838
[cluster] retrieving SQL data for crdb_internal.super_regions... writing output: debug/crdb_internal.super_regions.txt... done

pkg/cli/testdata/zip/partial1_excluded

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ debug zip /dev/null --concurrency=1 --exclude-nodes=2 --cpu-profile-duration=0
3232
[cluster] retrieving SQL data for crdb_internal.kv_store_status... writing output: debug/crdb_internal.kv_store_status.txt... done
3333
[cluster] retrieving SQL data for crdb_internal.kv_system_privileges... writing output: debug/crdb_internal.kv_system_privileges.txt... done
3434
[cluster] retrieving SQL data for crdb_internal.partitions... writing output: debug/crdb_internal.partitions.txt... done
35-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt... done
35+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt... done
3636
[cluster] retrieving SQL data for crdb_internal.regions... writing output: debug/crdb_internal.regions.txt... done
3737
[cluster] retrieving SQL data for crdb_internal.schema_changes... writing output: debug/crdb_internal.schema_changes.txt... done
3838
[cluster] retrieving SQL data for crdb_internal.super_regions... writing output: debug/crdb_internal.super_regions.txt... done

pkg/cli/testdata/zip/partial2

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ debug zip --concurrency=1 --cpu-profile-duration=0 /dev/null
3232
[cluster] retrieving SQL data for crdb_internal.kv_store_status... writing output: debug/crdb_internal.kv_store_status.txt... done
3333
[cluster] retrieving SQL data for crdb_internal.kv_system_privileges... writing output: debug/crdb_internal.kv_system_privileges.txt... done
3434
[cluster] retrieving SQL data for crdb_internal.partitions... writing output: debug/crdb_internal.partitions.txt... done
35-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt... done
35+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt... done
3636
[cluster] retrieving SQL data for crdb_internal.regions... writing output: debug/crdb_internal.regions.txt... done
3737
[cluster] retrieving SQL data for crdb_internal.schema_changes... writing output: debug/crdb_internal.schema_changes.txt... done
3838
[cluster] retrieving SQL data for crdb_internal.super_regions... writing output: debug/crdb_internal.super_regions.txt... done

pkg/cli/testdata/zip/testzip

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ debug zip --concurrency=1 --cpu-profile-duration=1s /dev/null
3232
[cluster] retrieving SQL data for crdb_internal.kv_store_status... writing output: debug/crdb_internal.kv_store_status.txt... done
3333
[cluster] retrieving SQL data for crdb_internal.kv_system_privileges... writing output: debug/crdb_internal.kv_system_privileges.txt... done
3434
[cluster] retrieving SQL data for crdb_internal.partitions... writing output: debug/crdb_internal.partitions.txt... done
35-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt... done
35+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt... done
3636
[cluster] retrieving SQL data for crdb_internal.regions... writing output: debug/crdb_internal.regions.txt... done
3737
[cluster] retrieving SQL data for crdb_internal.schema_changes... writing output: debug/crdb_internal.schema_changes.txt... done
3838
[cluster] retrieving SQL data for crdb_internal.super_regions... writing output: debug/crdb_internal.super_regions.txt... done

pkg/cli/testdata/zip/testzip_concurrent

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -110,9 +110,9 @@ zip
110110
[cluster] retrieving SQL data for crdb_internal.partitions...
111111
[cluster] retrieving SQL data for crdb_internal.partitions: done
112112
[cluster] retrieving SQL data for crdb_internal.partitions: writing output: debug/crdb_internal.partitions.txt...
113-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100...
114-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100: done
115-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100: writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt...
113+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100...
114+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100: done
115+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100: writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt...
116116
[cluster] retrieving SQL data for crdb_internal.regions...
117117
[cluster] retrieving SQL data for crdb_internal.regions: done
118118
[cluster] retrieving SQL data for crdb_internal.regions: writing output: debug/crdb_internal.regions.txt...

pkg/cli/testdata/zip/testzip_external_process_virtualization

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,7 @@ debug zip --concurrency=1 --cpu-profile-duration=1s /dev/null
4040
[cluster] retrieving SQL data for crdb_internal.kv_store_status: creating error output: debug/crdb_internal.kv_store_status.txt.err.txt... done
4141
[cluster] retrieving SQL data for crdb_internal.kv_system_privileges... writing output: debug/crdb_internal.kv_system_privileges.txt... done
4242
[cluster] retrieving SQL data for crdb_internal.partitions... writing output: debug/crdb_internal.partitions.txt... done
43-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt... done
43+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt... done
4444
[cluster] retrieving SQL data for crdb_internal.regions... writing output: debug/crdb_internal.regions.txt... done
4545
[cluster] retrieving SQL data for crdb_internal.schema_changes... writing output: debug/crdb_internal.schema_changes.txt... done
4646
[cluster] retrieving SQL data for crdb_internal.super_regions... writing output: debug/crdb_internal.super_regions.txt... done

pkg/cli/testdata/zip/testzip_include_range_info

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ debug zip --concurrency=1 --cpu-profile-duration=1s --include-range-info /dev/nu
3232
[cluster] retrieving SQL data for crdb_internal.kv_store_status... writing output: debug/crdb_internal.kv_store_status.txt... done
3333
[cluster] retrieving SQL data for crdb_internal.kv_system_privileges... writing output: debug/crdb_internal.kv_system_privileges.txt... done
3434
[cluster] retrieving SQL data for crdb_internal.partitions... writing output: debug/crdb_internal.partitions.txt... done
35-
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_write_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_write_limit_100.txt... done
35+
[cluster] retrieving SQL data for crdb_internal.probe_ranges_1s_read_limit_100... writing output: debug/crdb_internal.probe_ranges_1s_read_limit_100.txt... done
3636
[cluster] retrieving SQL data for crdb_internal.regions... writing output: debug/crdb_internal.regions.txt... done
3737
[cluster] retrieving SQL data for crdb_internal.schema_changes... writing output: debug/crdb_internal.schema_changes.txt... done
3838
[cluster] retrieving SQL data for crdb_internal.super_regions... writing output: debug/crdb_internal.super_regions.txt... done

0 commit comments

Comments
 (0)