opt: unoptimized-query-oracle/disable-rules=half failed due to timeout #86308

cockroach-teamcity · 2022-08-17T15:09:20Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ b173a16715e71e94115820374da1eb350b3b459d:

test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/run_1
	test_runner.go:1027,test_runner.go:926: test timed out (1h0m0s)

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

/cc @cockroachdb/sql-queries _{This test on roachdash | Improve this report!

Jira issue: CRDB-18687}

The text was updated successfully, but these errors were encountered:

DrewKimball · 2022-08-18T07:51:48Z

This one looks like a rule cycle between PushSelectIntoProject and PruneSelectCols, caused by disabling PruneWindowInputCols. For reference, it's pretty easy to diagnose these cases - you can see the rule that should be firing in the unredacted cockroach.log, and you can see what rules are cycling in the stack trace for the node(s).

We might be able to solve this without losing testing coverage by modifying DerivePruneCols to only propagate candidate pruning columns for an operator if the corresponding rule(s) is not disabled. Something similar should probably be done for DeriveRejectNullCols.

cockroach-teamcity · 2022-08-18T14:17:45Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ 5c2c62ecf1bea60c807edc6b4da22d900ad4ae03:

		  -- stack trace:
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.(*queryComparisonHelper).makeError
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:345
		  | [...repeated from below...]
		Wraps: (2) . 1178 statements run
		Wraps: (3) attached stack trace
		  -- stack trace:
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runUnoptimizedQueryOracleImpl
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:160
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.registerUnoptimizedQueryOracle.func1.1
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:54
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runOneRoundQueryComparison
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:236
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runQueryComparison
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:69
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.registerUnoptimizedQueryOracle.func1
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:51
		  | main.(*testRunner).runTest.func2
		  | 	main/pkg/cmd/roachtest/test_runner.go:896
		  | runtime.goexit
		  | 	GOROOT/src/runtime/asm_amd64.s:1571
		Wraps: (4) expected unoptimized and optimized results to be equal
		  |   []string{
		  |   	strings.Join({
		  |   		"0.24019393495790756,NULL,0,16 years 4 mons 248 days 00:23:12.159",
		  |   		"462,NULL,010700000000000000,0,1660832245334740108",
		  | + 		".0000000000",
		  |   		``,á,	a,NULL,0000-01-02 00:00:00 +0000 UTC,200 years 00:00:00.000``,
		  |   		"001,infinity,X",
		  |   	}, ""),
		  |   }
		  | sql: SELECT
		  | 	0.24019393495790756:::FLOAT8 AS col_674,
		  | 	tab_225.col1_4 AS col_675,
		  | 	tab_225.col1_10 AS col_676,
		  | 	'16 years 4 mons 248 days 00:23:12.159462':::INTERVAL AS col_677,
		  | 	tab_225.col1_9 AS col_678,
		  | 	tab_225.col1_7 AS col_679,
		  | 	0:::OID AS col_680,
		  | 	(tab_225.crdb_internal_mvcc_timestamp::DECIMAL // 1:::DECIMAL::DECIMAL)::DECIMAL AS col_681,
		  | 	tab_225.col1_2 AS col_682,
		  | 	'\x0961':::BYTES AS col_683,
		  | 	tab_225.col1_4 AS col_684,
		  | 	'24:00:00':::TIME AS col_685,
		  | 	'200 years 00:00:00.000001':::INTERVAL AS col_686,
		  | 	tab_225.col1_12 AS col_687,
		  | 	'X':::STRING AS col_688
		  | FROM
		  | 	defaultdb.public.table1@[0] AS tab_225
		Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *withstack.withStack (4) *errutil.leafError

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

_{This test on roachdash | Improve this report!}

cockroach-teamcity · 2022-08-19T14:57:56Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ a0d8839aa6164af81a9ebb140147d3baf5321287:

test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/run_1
	query_comparison_util.go:237,query_comparison_util.go:69,unoptimized_query_oracle.go:51,test_runner.go:896: failed to set random seed. 1091 statements run: dial tcp 34.148.82.172:26257: connect: connection refused
		(1) attached stack trace
		  -- stack trace:
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.(*queryComparisonHelper).makeError
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:345
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runUnoptimizedQueryOracleImpl
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:99
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.registerUnoptimizedQueryOracle.func1.1
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:54
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runOneRoundQueryComparison
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:236
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runQueryComparison
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:69
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.registerUnoptimizedQueryOracle.func1
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:51
		  | main.(*testRunner).runTest.func2
		  | 	main/pkg/cmd/roachtest/test_runner.go:896
		  | runtime.goexit
		  | 	GOROOT/src/runtime/asm_amd64.s:1571
		Wraps: (2) failed to set random seed. 1091 statements run
		Wraps: (3) dial tcp 34.148.82.172:26257
		Wraps: (4) connect
		Wraps: (5) connection refused
		Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *net.OpError (4) *os.SyscallError (5) syscall.Errno

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

_{This test on roachdash | Improve this report!}

cockroach-teamcity · 2022-08-20T15:25:13Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ cb55144cdec54d2a70f074ad64b4eca5e6c6891a:

test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/run_1
	test_runner.go:1027,test_runner.go:926: test timed out (1h0m0s)

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

_{This test on roachdash | Improve this report!}

This commit decreases the likelihood of rule cycles occuring during optimizer tests with disabled rules. `DerivePruneCols` and `DeriveRejectNullCols` now check whether propagating their corresponding properties would trigger a disabled rule (if it wasn't disabled), and avoid propagating in that case. This is necessary to avoid cases where a `Select` or `Project` gets repeatedly pushed down and eliminated. Addresses cockroachdb#86308 Release note: None Release justification: testing-only change

cockroach-teamcity · 2022-08-23T14:11:13Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ 80c274877a917580af62be6eb0cd48c8c7ae9c08:

test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/run_1
	query_comparison_util.go:237,query_comparison_util.go:69,unoptimized_query_oracle.go:51,test_runner.go:896: . 17242 statements run: expected unoptimized and optimized results to be equal
		(1) attached stack trace
		  -- stack trace:
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.(*queryComparisonHelper).makeError
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:345
		  | [...repeated from below...]
		Wraps: (2) . 17242 statements run
		Wraps: (3) attached stack trace
		  -- stack trace:
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runUnoptimizedQueryOracleImpl
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:160
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.registerUnoptimizedQueryOracle.func1.1
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:54
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runOneRoundQueryComparison
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:236
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.runQueryComparison
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/query_comparison_util.go:69
		  | github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests.registerUnoptimizedQueryOracle.func1
		  | 	github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tests/unoptimized_query_oracle.go:51
		  | main.(*testRunner).runTest.func2
		  | 	main/pkg/cmd/roachtest/test_runner.go:896
		  | runtime.goexit
		  | 	GOROOT/src/runtime/asm_amd64.s:1571
		Wraps: (4) expected unoptimized and optimized results to be equal
		  |   []string{
		  |   	strings.Join({
		  |   		"-9.8,0,0,104,0,1661263847326383409.0",
		  | + 		"000000000",
		  |   	}, ""),
		  |   	strings.Join({
		  |   		"-9.8,104,0,104,0,1661263847077927364.0",
		  | + 		"000000000",
		  |   	}, ""),
		  |   }
		  | sql: SELECT
		  | 	(-9.8):::DECIMAL AS col_37722,
		  | 	tab_21236.col1_0 AS col_37723,
		  | 	0:::OID AS col_37724,
		  | 	tab_21236.tableoid AS col_37725,
		  | 	0:::OID AS col_37726,
		  | 	(tab_21236.crdb_internal_mvcc_timestamp::DECIMAL / 1:::DECIMAL::DECIMAL)::DECIMAL AS col_37727
		  | FROM
		  | 	defaultdb.public.table1@[0] AS tab_21236
		  | 	JOIN defaultdb.public.table1@[0] AS tab_21237 ON
		  | 			(tab_21236.crdb_internal_mvcc_timestamp) = (tab_21237.crdb_internal_mvcc_timestamp)
		  | ORDER BY
		  | 	tab_21236.tableoid ASC
		Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *withstack.withStack (4) *errutil.leafError

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

_{This test on roachdash | Improve this report!}

This commit decreases the likelihood of rule cycles occuring during optimizer tests with disabled rules. `DerivePruneCols` and `DeriveRejectNullCols` now check whether propagating their corresponding properties would trigger a disabled rule (if it wasn't disabled), and avoid propagating in that case. This is necessary to avoid cases where a `Select` or `Project` gets repeatedly pushed down and eliminated. Addresses cockroachdb#86308 Release note: None Release justification: testing-only change

rytaft · 2022-08-24T17:58:12Z

@DrewKimball I'm assigning you to this issue since you've already been doing a lot of work to investigate these failures. Feel free to close it out once #86631 merges. I'll open up a separate issue for the non-timeout failures.

rytaft · 2022-08-24T18:00:40Z

Opened up #86790 to cover the two non-timeout failures.

cockroach-teamcity · 2022-08-25T15:02:40Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ 524fd14da3fefcd849f44a835cc5f88f5dbdadcc:

		  |   	"-99,a\n,NULL,BOX(-1 15,0 16),0,{\"\\\\xc5b5f3991f524f\"},NULL,\ta",
		  |   	... // 15 identical elements
		  |   	"-99,a\n,NULL,BOX(-1.2958624195456403 -0.7007902262760126,-0.76394"...,
		  |   	"-99,a\n,NULL,BOX(-1.3207114753925442 0.07543733824577625,0.411722"...,
		  |   	strings.Join({
		  |   		"-99,a\n,NULL,BOX(-1.371471829151467 1.5445529591343243,-0.4097185",
		  |   		``8119740223 1.5844682297595416),0,{"\\x97","\\x4161"},``,
		  | + 		"NULL",
		  |   		``,	a``,
		  |   	}, ""),
		  |   	"-99,a\n,NULL,BOX(-1.3926406249344883 -0.6842762115529295,-0.23034"...,
		  |   	"-99,a\n,NULL,BOX(-1.3965146560734436 -0.5498867231573248,-0.99270"...,
		  |   	... // 35 identical elements
		  |   	"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x\",\"\\\\x2061\"},NULL,\ta",
		  |   	"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x\",\"\\\\x2f78f42ae5ad84f2\",\"\\"...,
		  |   	strings.Join({
		  |   		"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x\",\"\\\\x6120\",\"\\\\x\",\"\\\\x840c",
		  |   		"148fef14\"},\xc3",
		  | - 		"\x80",
		  | + 		"\xa0",
		  |   		",h\xc5",
		  |   	}, ""),
		  |   	"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x\",\"\\\\x616162\",\"\\\\xaf928150"...,
		  |   	"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x\",\"\\\\x7c3fdc0d748201\"},NUL"...,
		  |   	... // 55 identical elements
		  |   	"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x58\"},',\ta",
		  |   	"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x5b\"},\f,\ta",
		  |   	strings.Join({
		  |   		"-99,a\n,NULL,BOX(-10 -10,10 10),0,{\"\\\\x5f\",\"\\\\x4161\",\"\\\\xc3a0c3a1",
		  |   		``","\\x3a9d1d5c8d"},``,
		  | - 		"\x00",
		  |   		",aaaaaa",
		  |   	}, ""),
		  |   	... // 347 identical and 12 modified elements
		  |   }
		  | sql: SELECT
		  | 	(-99):::INT8 AS col_3616,
		  | 	e'a\n':::STRING AS col_3617,
		  | 	tab_1118.col1_0 AS col_3618,
		  | 	tab_1118.col1_7 AS col_3619,
		  | 	0:::OID AS col_3620,
		  | 	tab_1118.col1_1 AS col_3621,
		  | 	lag(tab_1118.col1_2::STRING) OVER (PARTITION BY tab_1118.col1_3, tab_1118.crdb_internal_mvcc_timestamp ORDER BY tab_1118.col1_16, tab_1118.col1_2 ROWS CURRENT ROW)::STRING
		  | 		AS col_3622,
		  | 	tab_1118.col1_6 AS col_3623
		  | FROM
		  | 	defaultdb.public.table1@[0] AS tab_1118
		  | ORDER BY
		  | 	tab_1118.col1_15 DESC
		Error types: (1) *withstack.withStack (2) *errutil.withPrefix (3) *withstack.withStack (4) *errutil.leafError

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

_{This test on roachdash | Improve this report!}

This commit decreases the likelihood of rule cycles occuring during optimizer tests with randomly disabled rules. `DerivePruneCols` and `DeriveRejectNullCols` now check whether propagating their corresponding properties would trigger a disabled rule (if it wasn't disabled), and avoid propagating in that case. This is necessary to avoid cases where a `Select` or `Project` gets repeatedly pushed down and eliminated. Addresses cockroachdb#86308 Release note: None Release justification: testing-only change

cockroach-teamcity · 2022-08-27T15:10:16Z

roachtest.unoptimized-query-oracle/disable-rules=half failed with artifacts on master @ 770ff3c545a51752490403da64d56fb397f49c5e:

test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/run_1
	test_runner.go:1028,test_runner.go:927: test timed out (1h0m0s)

Parameters: ROACHTEST_cloud=gce , ROACHTEST_cpu=4 , ROACHTEST_ssd=0

Help

See: roachtest README

See: How To Investigate (internal)

_{This test on roachdash | Improve this report!}

rytaft · 2022-08-29T13:41:26Z

Opened #87023 for the most recent non-timeout failure

rytaft · 2022-08-29T13:42:12Z

I'm going to remove the release-blocker label on this one since the timeout failures should not be release blockers

mgartner · 2022-08-29T15:00:18Z

Should we be running the unoptimized query oracle with with the crdb_test build flag so that cycles like this are detected by our norm cycle detector? It might make it faster to understand the error report and avoid having to go through the artifacts.

rytaft · 2022-08-29T15:26:38Z

@yuzefovich just merged #86625 so now I think we run 50% of these tests with crdb_test. I'd hesitate to change that to 100% because it feels like we need some correctness testing coverage with crdb_test off. Perhaps we can revisit if this keeps happening?

rytaft · 2022-08-29T15:29:33Z

Actually it looks like that change was only for the sqlsmith roachtests, not for unoptimized-query-oracle. Running this test with crdb_test=true sometimes seems useful.

mgartner · 2022-08-29T18:27:57Z

👍 I created #87051 to track doing that.

This commit decreases the likelihood of rule cycles occuring during optimizer tests with randomly disabled rules. `DerivePruneCols` and `DeriveRejectNullCols` now check whether propagating their corresponding properties would trigger a disabled rule (if it wasn't disabled), and avoid propagating in that case. This is necessary to avoid cases where a `Select` or `Project` gets repeatedly pushed down and eliminated. Addresses cockroachdb#86308 Release note: None Release justification: testing-only change

86631: opt: don't propagate rule props when corresponding rule is disabled r=DrewKimball a=DrewKimball This commit decreases the likelihood of rule cycles occuring during optimizer tests with disabled rules. `DerivePruneCols` and `DeriveRejectNullCols` now check whether propagating their corresponding properties would trigger a disabled rule (if it wasn't disabled), and avoid propagating in that case. This is necessary to avoid cases where a `Select` or `Project` gets repeatedly pushed down and eliminated. Addresses #86308 Release note: None Release justification: testing-only change Co-authored-by: DrewKimball <[email protected]>

mgartner · 2022-08-30T19:25:55Z

For reference, it's pretty easy to diagnose these cases - you can see the rule that should be firing in the unredacted cockroach.log

@DrewKimball Where would you see this in a cockroach.log?

DrewKimball · 2022-08-30T23:30:47Z

Here's an example from a recent timeout (#87031):

I220829 15:09:44.082137 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180394  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082622 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180395  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082649 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180396  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082667 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180397  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082684 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180398  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082699 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180399  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082714 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180400  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082729 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180401  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082745 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180402  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082759 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180403  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082775 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180404  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082790 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180405  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082806 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180406  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082822 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180407  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082840 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180408  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082855 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180409  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082870 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180410  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082885 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180411  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082900 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180412  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082916 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180413  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082931 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180414  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082947 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180415  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082962 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180416  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082976 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180417  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.082992 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180418  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083008 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180419  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083022 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180420  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083037 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180421  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083054 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180422  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083068 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180423  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083081 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180424  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083095 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180425  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083108 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180426  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083121 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180427  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083136 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180428  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083149 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180429  disabled rule matched: ‹PruneWindowInputCols›
I220829 15:09:44.083166 996 sql/opt/xform/optimizer.go:1022 ⋮ [n1,client=34.148.206.14:49476,user=root] 41180430  disabled rule matched: ‹PruneWindowInputCols›

In this case, we can be pretty sure that since PruneWindowInputCols is missing, the column-pruning project gets eliminated instead and another one gets pushed down, repeating the cycle. It's not always as straightforward as this, but the log gives a pretty good hint when the rule cycle is caused by a disabled rule.

DrewKimball · 2022-08-31T06:43:37Z

Closing this, since the timeouts and lag failures should be fixed, and #86790 tracks the decimal-precision issue.

mgartner · 2022-08-31T14:09:13Z

Cool! I didn't realize we logged disabled rules like that.

cockroach-teamcity added this to the 22.2 milestone Aug 17, 2022

blathers-crl bot added the T-sql-queries SQL Queries Team label Aug 17, 2022

DrewKimball mentioned this issue Aug 23, 2022

opt: don't propagate rule props when corresponding rule is disabled #86631

Merged

rytaft assigned DrewKimball Aug 24, 2022

rytaft mentioned this issue Aug 24, 2022

roachtest.unoptimized-query-oracle/disable-rules=half failed due to extra precision decimals #86790

Closed

rytaft changed the title ~~roachtest: unoptimized-query-oracle/disable-rules=half failed~~ opt: roachtest.unoptimized-query-oracle/disable-rules=half failed due to timeout Aug 24, 2022

rytaft changed the title ~~opt: roachtest.unoptimized-query-oracle/disable-rules=half failed due to timeout~~ opt: unoptimized-query-oracle/disable-rules=half failed due to timeout Aug 29, 2022

rytaft mentioned this issue Aug 29, 2022

roachtest.unoptimized-query-oracle/disable-rules=half #87023

Closed

rytaft removed the release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. label Aug 29, 2022

mgartner mentioned this issue Aug 29, 2022

sql: run unoptimized-query-oracle roachtest with crdb_test=true some of the time #87051

Closed

DrewKimball closed this as completed Aug 31, 2022

mgartner added this to SQL Queries Jul 24, 2023

mgartner moved this to Done in SQL Queries Jul 24, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

opt: unoptimized-query-oracle/disable-rules=half failed due to timeout #86308

opt: unoptimized-query-oracle/disable-rules=half failed due to timeout #86308

cockroach-teamcity commented Aug 17, 2022 •

edited by cockroach-jira-scripts

Loading

DrewKimball commented Aug 18, 2022 •

edited

Loading

cockroach-teamcity commented Aug 18, 2022

cockroach-teamcity commented Aug 19, 2022

cockroach-teamcity commented Aug 20, 2022

cockroach-teamcity commented Aug 23, 2022

rytaft commented Aug 24, 2022

rytaft commented Aug 24, 2022

cockroach-teamcity commented Aug 25, 2022

cockroach-teamcity commented Aug 27, 2022

rytaft commented Aug 29, 2022

rytaft commented Aug 29, 2022

mgartner commented Aug 29, 2022

rytaft commented Aug 29, 2022

rytaft commented Aug 29, 2022 •

edited

Loading

mgartner commented Aug 29, 2022

mgartner commented Aug 30, 2022

DrewKimball commented Aug 30, 2022 •

edited

Loading

DrewKimball commented Aug 31, 2022

mgartner commented Aug 31, 2022

opt: unoptimized-query-oracle/disable-rules=half failed due to timeout #86308

opt: unoptimized-query-oracle/disable-rules=half failed due to timeout #86308

Comments

cockroach-teamcity commented Aug 17, 2022 • edited by cockroach-jira-scripts Loading

DrewKimball commented Aug 18, 2022 • edited Loading

cockroach-teamcity commented Aug 18, 2022

cockroach-teamcity commented Aug 19, 2022

cockroach-teamcity commented Aug 20, 2022

cockroach-teamcity commented Aug 23, 2022

rytaft commented Aug 24, 2022

rytaft commented Aug 24, 2022

cockroach-teamcity commented Aug 25, 2022

cockroach-teamcity commented Aug 27, 2022

rytaft commented Aug 29, 2022

rytaft commented Aug 29, 2022

mgartner commented Aug 29, 2022

rytaft commented Aug 29, 2022

rytaft commented Aug 29, 2022 • edited Loading

mgartner commented Aug 29, 2022

mgartner commented Aug 30, 2022

DrewKimball commented Aug 30, 2022 • edited Loading

DrewKimball commented Aug 31, 2022

mgartner commented Aug 31, 2022

cockroach-teamcity commented Aug 17, 2022 •

edited by cockroach-jira-scripts

Loading

DrewKimball commented Aug 18, 2022 •

edited

Loading

rytaft commented Aug 29, 2022 •

edited

Loading

DrewKimball commented Aug 30, 2022 •

edited

Loading