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.

Sign up for GitHub

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

Jump to bottom

roachtest/sqlsmith: query timed out during the optimization but didn't cancel #70245

Closed
cockroach-teamcity opened this issue Sep 15, 2021 · 3 comments · Fixed by #85041
Closed

roachtest/sqlsmith: query timed out during the optimization but didn't cancel #70245

cockroach-teamcity opened this issue Sep 15, 2021 · 3 comments · Fixed by #85041
Assignees
@yuzefovich
Labels
branch-master Failures on the master branch. C-test-failure Broken test (automatically or manually discovered). E-quick-win Likely to be a quick win for someone experienced. O-roachtest O-robot Originated from a bot. T-sql-queries SQL Queries Team
Projects
SQL Queries

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Sep 15, 2021 •
edited by cockroach-jira-scripts

roachtest.sqlsmith/setup=rand-tables/setting=no-mutations failed with artifacts on master @ 2baefd353239ddc4e7f4299b8930001675b99aa9:

SET CLUSTER SETTING sql.stats.automatic_collection.enabled = false;
SET CLUSTER SETTING sql.stats.histogram_collection.enabled = false;
CREATE TABLE table1 (col1_0 TIMESTAMP NULL, col1_1 BYTES[] NOT NULL, col1_2 REGTYPE NULL, col1_3 NAME NOT NULL, col1_4 VARCHAR NOT NULL, col1_5 FLOAT8, col1_6 TIMETZ NOT NULL, col1_7 UUID, col1_8 REGROLE NOT NULL, PRIMARY KEY (col1_3 DESC, col1_6), INVERTED INDEX (col1_5 ASC, col1_1 ASC), UNIQUE (col1_4 DESC, col1_3 ASC, col1_7, col1_8 ASC, col1_6) STORING (col1_1), INDEX (col1_0 ASC, col1_2 ASC) WHERE ((((table1.col1_6 = '24:00:00-15:59:00':::TIMETZ) AND (table1.col1_5 <= '-Inf':::FLOAT8)) OR (table1.col1_4 < '':::STRING)) AND (table1.col1_3 >= '"':::STRING)) AND (table1.col1_0 = '-2000-01-01 00:00:00':::TIMESTAMP), INDEX (col1_2 DESC, col1_8, col1_0 DESC, lower(CAST(col1_0 AS STRING)) ASC, col1_4 DESC) STORING (col1_1, col1_5, col1_7) WHERE table1.col1_3 = 'X':::STRING, INDEX (lower(CAST(col1_2 AS STRING)) DESC) STORING (col1_1, col1_2, col1_4, col1_5, col1_7) WHERE table1.col1_5 < '+Inf':::FLOAT8);
ALTER TABLE table1 INJECT STATISTICS e'[{"columns": ["col1_5"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 138276, "histo_col_type": "", "name": "__auto__", "null_count": 196316, "row_count": 500000}, {"columns": ["col1_7"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 499328, "histo_col_type": "", "name": "__auto__", "null_count": 443402, "row_count": 500000}, {"columns": ["col1_1"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 201318, "histo_col_type": "", "name": "__auto__", "null_count": 0, "row_count": 500000}, {"columns": ["col1_2"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 427135, "histo_col_type": "REGTYPE", "name": "__auto__", "null_count": 113519, "row_count": 500000}, {"columns": ["col1_3"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 295111, "histo_buckets": [{"distinct_range": 0, "num_eq": 6223916942010959526, "num_range": 0, "upper_bound": ""}, {"distinct_range": 17392505.35859956, "num_eq": 90000000, "num_range": 90000000, "upper_bound": "\\u0016"}, {"distinct_range": 573337559.5659553, "num_eq": 149102319233076337, "num_range": 1000000000, "upper_bound": "#"}, {"distinct_range": 0, "num_eq": 5796823224926735315, "num_range": 4397943438374733275, "upper_bound": "\'"}, {"distinct_range": 0, "num_eq": 6313390865291620758, "num_range": 4839790316214612609, "upper_bound": "9%;D\\u000e"}, {"distinct_range": 37530552462786056, "num_eq": 7569889223533147069, "num_range": 78289640422963076, "upper_bound": "S!"}, {"distinct_range": 937882853411466400, "num_eq": 7671545877451517318, "num_range": 1242326909312568640, "upper_bound": "o\\u000bZjvf:\'"}], "histo_col_type": "NAME", "name": "__auto__", "null_count": 0, "row_count": 500000}, {"columns": ["col1_4"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 76330, "histo_buckets": [{"distinct_range": 0, "num_eq": 100000, "num_range": 0, "upper_bound": "\\u000c91Z,h(%"}, {"distinct_range": 91476052466595150, "num_eq": 700000, "num_range": 3206335811550270607, "upper_bound": "\\u000eU\\u0006"}, {"distinct_range": 195.51639868377046, "num_eq": 5184358200953274487, "num_range": 1000, "upper_bound": "\\u0017\\u000e-^3"}, {"distinct_range": 1123905932206117000, "num_eq": 4000, "num_range": 4404771785818298145, "upper_bound": "8F\\u001bW#l"}, {"distinct_range": 0, "num_eq": 8750344073731143828, "num_range": 8000, "upper_bound": "v"}], "histo_col_type": "VARCHAR", "name": "__auto__", "null_count": 0, "row_count": 500000}, {"columns": ["col1_0"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 86844, "histo_col_type": "", "name": "__auto__", "null_count": 259950, "row_count": 500000}, {"columns": ["col1_6"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 331085, "histo_col_type": "", "name": "__auto__", "null_count": 0, "row_count": 500000}, {"columns": ["col1_8"], "created_at": "2000-01-01 00:00:00+00:00", "distinct_count": 443513, "histo_col_type": "", "name": "__auto__", "null_count": 0, "row_count": 500000}]':::JSONB;
SET statement_timeout='10s';

SELECT
	tab_124176.col1_4 AS col_298240, tab_124184.col1_8 AS col_298241
FROM
	defaultdb.public.table1@[0] AS tab_124176,
	defaultdb.public.table1@[0] AS tab_124177
	JOIN defaultdb.public.table1@table1_col1_2_col1_8_col1_0_expr_col1_4_idx AS tab_124178
		JOIN defaultdb.public.table1@table1_expr_idx AS tab_124179
			JOIN defaultdb.public.table1 AS tab_124180
				JOIN defaultdb.public.table1 AS tab_124181 ON
						(tab_124180.col1_0) = (tab_124181.col1_0)
						AND (tab_124180.col1_6) = (tab_124181.col1_6)
						AND (tab_124180.col1_3) = (tab_124181.col1_3)
						AND (tab_124180.col1_2) = (tab_124181.col1_2)
				JOIN defaultdb.public.table1@[0] AS tab_124182 ON
						(tab_124181.col1_2) = (tab_124182.col1_8) AND (tab_124180.col1_2) = (tab_124182.tableoid) ON
					(tab_124179.col1_2) = (tab_124180.col1_2)
			JOIN defaultdb.public.table1@[0] AS tab_124183 ON
					(tab_124182.crdb_internal_idx_expr_1) = (tab_124183.col1_4)
					AND (tab_124182.col1_3) = (tab_124183.crdb_internal_idx_expr_1)
			JOIN defaultdb.public.table1 AS tab_124184
				JOIN defaultdb.public.table1 AS tab_124185 ON
						(tab_124184.col1_2) = (tab_124185.col1_2)
						AND (tab_124184.col1_6) = (tab_124185.col1_6)
						AND (tab_124184.col1_3) = (tab_124185.col1_3)
						AND (tab_124184.col1_4) = (tab_124185.col1_4) ON (tab_124183.col1_8) = (tab_124184.col1_8) ON
				(tab_124178.col1_2) = (tab_124180.col1_2)
				AND (tab_124178.col1_2) = (tab_124185.col1_8)
				AND (tab_124178.crdb_internal_idx_expr) = (tab_124182.crdb_internal_idx_expr_1) ON
			(tab_124177.col1_8) = (tab_124181.col1_2)
			AND (tab_124177.crdb_internal_idx_expr_1) = (tab_124178.crdb_internal_idx_expr)
			AND (tab_124177.crdb_internal_idx_expr_1) = (tab_124183.col1_3);
Reproduce

See: roachtest README

/cc @cockroachdb/sql-queries

This test on roachdash | Improve this report!

Jira issue: CRDB-10001
@cockroach-teamcity cockroach-teamcity added branch-master Failures on the master branch. C-test-failure Broken test (automatically or manually discovered). O-roachtest O-robot Originated from a bot. release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. labels Sep 15, 2021
@cockroach-teamcity cockroach-teamcity added this to Triage in SQL Queries Sep 15, 2021
@blathers-crl blathers-crl bot added the T-sql-queries SQL Queries Team label Sep 15, 2021
@yuzefovich yuzefovich changed the title roachtest: sqlsmith/setup=rand-tables/setting=no-mutations failed roachtest/sqlsmith: query timed out during the optimization but didn't cancel Sep 15, 2021
@cucaroach
Copy link
Contributor

CPU Profile looks like combinatorial explosion in join reordering maybe? Killing the client doesn't stop the server, is that a new bug or does the optimizer not have cancelation abilities?

Screen Shot 2021-09-15 at 10 50 06 AM

@cucaroach
Copy link
Contributor

cucaroach commented Sep 16, 2021 •
edited

Cleaned up repro opttester repro:

exec-ddl
CREATE TABLE table1
(
    col1_0 TIMESTAMP NULL,
    col1_1 BYTES[] NOT NULL,
    col1_2 REGTYPE NULL,
    col1_3 NAME NOT NULL,
    col1_4 VARCHAR NOT NULL,
    col1_5 FLOAT8,
    col1_6 TIMETZ NOT NULL,
    col1_7 UUID,
    col1_8 REGROLE NOT NULL,
    PRIMARY KEY (col1_3 DESC, col1_6),
    INVERTED INDEX (col1_5 ASC, col1_1 ASC),
    UNIQUE (col1_4 DESC, col1_3 ASC, col1_7, col1_8 ASC, col1_6) STORING (col1_1),
    INDEX (col1_0 ASC, col1_2 ASC) WHERE ((((table1.col1_6 = '24:00:00-15:59:00':::TIMETZ) AND (table1.col1_5 <= '-Inf':::FLOAT8)) OR (table1.col1_4 < '':::STRING)) AND (table1.col1_3 >= '"':::STRING)) AND (table1.col1_0 = '-2000-01-01 00:00:00':::TIMESTAMP),
    INDEX table1_col1_2_col1_8_col1_0_expr_col1_4_idx (col1_2 DESC, col1_8, col1_0 DESC, lower(CAST(col1_0 AS STRING)) ASC, col1_4 DESC) STORING (col1_1, col1_5, col1_7) WHERE table1.col1_3 = 'X':::STRING,
    INDEX table1_expr_idx (lower(CAST(col1_2 AS STRING)) DESC) STORING (col1_1, col1_2, col1_4, col1_5, col1_7) WHERE table1.col1_5 < '+Inf':::FLOAT8
)
----

opt
SELECT
	tab_124176.col1_4 AS col_298240, tab_124184.col1_8 AS col_298241
FROM
	table1@[0] AS tab_124176,
	table1@[0] AS tab_124177
	JOIN table1@table1_col1_2_col1_8_col1_0_expr_col1_4_idx AS tab_124178
		JOIN table1@table1_expr_idx AS tab_124179
			JOIN table1 AS tab_124180
				JOIN table1 AS tab_124181 ON
						(tab_124180.col1_0) = (tab_124181.col1_0)
						AND (tab_124180.col1_6) = (tab_124181.col1_6)
						AND (tab_124180.col1_3) = (tab_124181.col1_3)
						AND (tab_124180.col1_2) = (tab_124181.col1_2)
				JOIN table1@[0] AS tab_124182 ON
						(tab_124181.col1_2) = (tab_124182.col1_8) AND (tab_124180.col1_2) = (tab_124182.tableoid) ON
					(tab_124179.col1_2) = (tab_124180.col1_2)
			JOIN table1@[0] AS tab_124183 ON
					(tab_124182.crdb_internal_idx_expr_1) = (tab_124183.col1_4)
					AND (tab_124182.col1_3) = (tab_124183.crdb_internal_idx_expr_1)
			JOIN table1 AS tab_124184
				JOIN table1 AS tab_124185 ON
						(tab_124184.col1_2) = (tab_124185.col1_2)
						AND (tab_124184.col1_6) = (tab_124185.col1_6)
						AND (tab_124184.col1_3) = (tab_124185.col1_3)
						AND (tab_124184.col1_4) = (tab_124185.col1_4) ON (tab_124183.col1_8) = (tab_124184.col1_8) ON
				(tab_124178.col1_2) = (tab_124180.col1_2)
				AND (tab_124178.col1_2) = (tab_124185.col1_8)
				AND (tab_124178.crdb_internal_idx_expr) = (tab_124182.crdb_internal_idx_expr_1) ON
			(tab_124177.col1_8) = (tab_124181.col1_2)
			AND (tab_124177.crdb_internal_idx_expr_1) = (tab_124178.crdb_internal_idx_expr)
			AND (tab_124177.crdb_internal_idx_expr_1) = (tab_124183.col1_3)
----

@cucaroach cucaroach mentioned this issue Sep 16, 2021
Open
@rytaft rytaft removed the release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. label Sep 20, 2021
@rytaft
Copy link
Collaborator

rytaft commented Sep 20, 2021

I can repro this issue on 21.1 by changing the expression indexes to use virtual columns. Removing release-blocker label.

CREATE TABLE table1
(
    col1_0 TIMESTAMP NULL,
    col1_1 BYTES[] NOT NULL,
    col1_2 REGTYPE NULL,
    col1_3 NAME NOT NULL,
    col1_4 VARCHAR NOT NULL,
    col1_5 FLOAT8,
    col1_6 TIMETZ NOT NULL,
    col1_7 UUID,
    col1_8 int NOT NULL,
    col2 string as (lower(CAST(col1_0 AS STRING))) virtual,
    col3 string as (lower(CAST(col1_2 AS STRING))) virtual,
    PRIMARY KEY (col1_3 DESC, col1_6),
    INVERTED INDEX (col1_5 ASC, col1_1 ASC),
    UNIQUE (col1_4 DESC, col1_3 ASC, col1_7, col1_8 ASC, col1_6) STORING (col1_1),
    INDEX (col1_0 ASC, col1_2 ASC) WHERE ((((table1.col1_6 = '24:00:00-15:59:00':::TIMETZ) AND (table1.col1_5 <= '-Inf':::FLOAT8)) OR (table1.col1_4 < '':::STRING)) AND (table1.col1_3 >= '"':::STRING)) AND (table1.col1_0 = '-2000-01-01 00:00:00':::TIMESTAMP),
    INDEX table1_col1_2_col1_8_col1_0_expr_col1_4_idx (col1_2 DESC, col1_8, col1_0 DESC, col2 ASC, col1_4 DESC) STORING (col1_1, col1_5, col1_7) WHERE table1.col1_3 = 'X':::STRING,
    INDEX table1_expr_idx (col3 DESC) STORING (col1_1, col1_2, col1_4, col1_5, col1_7) WHERE table1.col1_5 < '+Inf':::FLOAT8
);

SELECT
	tab_124176.col1_4 AS col_298240, tab_124184.col1_8 AS col_298241
FROM
	table1@[0] AS tab_124176,
	table1@[0] AS tab_124177
	JOIN table1@table1_col1_2_col1_8_col1_0_expr_col1_4_idx AS tab_124178
		JOIN table1@table1_expr_idx AS tab_124179
			JOIN table1 AS tab_124180
				JOIN table1 AS tab_124181 ON
						(tab_124180.col1_0) = (tab_124181.col1_0)
						AND (tab_124180.col1_6) = (tab_124181.col1_6)
						AND (tab_124180.col1_3) = (tab_124181.col1_3)
						AND (tab_124180.col1_2) = (tab_124181.col1_2)
				JOIN table1@[0] AS tab_124182 ON
						(tab_124181.col1_2) = (tab_124182.col1_8) AND (tab_124180.col1_2) = (tab_124182.tableoid) ON
					(tab_124179.col1_2) = (tab_124180.col1_2)
			JOIN table1@[0] AS tab_124183 ON
					(tab_124182.col3) = (tab_124183.col1_4)
					AND (tab_124182.col1_3) = (tab_124183.col3)
			JOIN table1 AS tab_124184
				JOIN table1 AS tab_124185 ON
						(tab_124184.col1_2) = (tab_124185.col1_2)
						AND (tab_124184.col1_6) = (tab_124185.col1_6)
						AND (tab_124184.col1_3) = (tab_124185.col1_3)
						AND (tab_124184.col1_4) = (tab_124185.col1_4) ON (tab_124183.col1_8) = (tab_124184.col1_8) ON
				(tab_124178.col1_2) = (tab_124180.col1_2)
				AND (tab_124178.col1_2) = (tab_124185.col1_8)
				AND (tab_124178.col2) = (tab_124182.col3) ON
			(tab_124177.col1_8) = (tab_124181.col1_2)
			AND (tab_124177.col3) = (tab_124178.col2)
			AND (tab_124177.col3) = (tab_124183.col1_3);

@mgartner mgartner self-assigned this Sep 21, 2021
@mgartner mgartner moved this from Triage to 21.2 September Milestone (stability) in SQL Queries Sep 21, 2021
@mgartner mgartner moved this from 21.2 September Milestone (stability) to 22.1 October Milestone in SQL Queries Oct 11, 2021
@mgartner mgartner moved this from 22.1 October Milestone to 22.1 November Milestone in SQL Queries Nov 3, 2021
@mgartner mgartner moved this from 22.1 November Milestone to 22.1 December Milestone in SQL Queries Dec 14, 2021
@rytaft rytaft moved this from 22.1 December Milestone to 22.1 January Milestone in SQL Queries Jan 18, 2022
@mgartner mgartner moved this from 22.1 January Milestone to 22.1 February Milestone in SQL Queries Feb 2, 2022
@mgartner mgartner moved this from 22.1 February Milestone to 22.1 March Milestone in SQL Queries Mar 7, 2022
@mgartner mgartner moved this from 22.1 March Milestone to 22.1 April Milestone in SQL Queries Apr 11, 2022
@mgartner mgartner removed their assignment May 5, 2022
@mgartner mgartner moved this from 22.1 April Milestone to Triage in SQL Queries May 5, 2022
@yuzefovich yuzefovich moved this from Triage to 22.2 Low Likelihood (10%) in SQL Queries May 24, 2022
@yuzefovich yuzefovich added the E-quick-win Likely to be a quick win for someone experienced. label May 24, 2022
@rytaft rytaft moved this from 22.2 Low Likelihood (10%) to 22.2 Release in SQL Queries May 25, 2022
@jlinder jlinder removed the sync-me-3 label May 27, 2022
@yuzefovich yuzefovich mentioned this issue May 31, 2022
Closed
@mgartner mgartner moved this from 22.2 Release to Backlog in SQL Queries Jul 7, 2022
@yuzefovich yuzefovich self-assigned this Jul 26, 2022
@yuzefovich yuzefovich moved this from Backlog to Active in SQL Queries Jul 26, 2022
@yuzefovich yuzefovich mentioned this issue Jul 26, 2022
Merged
@craig craig bot closed this as completed in 658bf2b Jul 27, 2022
SQL Queries automation moved this from Active to Done Jul 27, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@yuzefovich yuzefovich

Labels
branch-master Failures on the master branch. C-test-failure Broken test (automatically or manually discovered). E-quick-win Likely to be a quick win for someone experienced. O-roachtest O-robot Originated from a bot. T-sql-queries SQL Queries Team
Projects
SQL Queries
Archived in project
SQL Queries
Done
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

sql: better logging about the optimizer as well as some cancellation checks yuzefovich/cockroach
6 participants
@jlinder @mgartner @rytaft @yuzefovich @cockroach-teamcity @cucaroach