cockroachdb / cockroach

CockroachDB — the cloud native, distributed SQL database designed for high availability, effortless scale, and control over data placement.
https://www.cockroachlabs.com
Other
29.84k stars 3.77k forks source link

roachtest: unoptimized-query-oracle/disable-rules=half/seed-multi-region failed #127168

Closed cockroach-teamcity closed 1 month ago

cockroach-teamcity commented 1 month ago

roachtest.unoptimized-query-oracle/disable-rules=half/seed-multi-region failed with artifacts on release-24.2 @ d4ef0343f38a35fb781b6343697b57a58131c68e:

(test_runner.go:1277).runTest: test timed out (1h0m0s)
test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/seed-multi-region/run_1

Parameters:

See: roachtest README

See: How To Investigate (internal)

See: Grafana

This test on roachdash | Improve this report!

Jira issue: CRDB-40302

DrewKimball commented 1 month ago

On node 6:

I240715 14:26:58.159436 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21472  disabled rule matched: ‹InlineSelectConstants›
I240715 14:26:58.159445 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21473  disabled rule matched: ‹PushSelectIntoInlinableProject›
I240715 14:26:58.159507 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21474  disabled rule matched: ‹GeneratePartialIndexScans›
I240715 14:26:58.159515 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21475  disabled rule matched: ‹GenerateConstrainedScans›
I240715 14:26:58.159520 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21476  disabled rule matched: ‹GenerateInvertedIndexScans›
I240715 14:26:58.159525 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21477  disabled rule matched: ‹GenerateTrigramSimilarityInvertedIndexScans›
I240715 14:26:58.159532 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21478  disabled rule matched: ‹GenerateZigzagJoins›
I240715 14:26:58.940523 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21479  disabled rule matched: ‹CommuteVar›
I240715 14:26:58.940560 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21480  disabled rule matched: ‹InlineSelectConstants›
I240715 14:26:58.940571 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21481  disabled rule matched: ‹PushSelectIntoInlinableProject›
I240715 14:26:58.940643 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21482  disabled rule matched: ‹GeneratePartialIndexScans›
I240715 14:26:58.940651 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21483  disabled rule matched: ‹GenerateConstrainedScans›
I240715 14:26:58.940656 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21484  disabled rule matched: ‹GenerateInvertedIndexScans›
I240715 14:26:58.940661 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21485  disabled rule matched: ‹GenerateTrigramSimilarityInvertedIndexScans›
I240715 14:26:58.940667 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21486  disabled rule matched: ‹GenerateZigzagJoins›
I240715 14:26:59.721775 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21487  disabled rule matched: ‹CommuteVar›
I240715 14:26:59.721820 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21488  disabled rule matched: ‹InlineSelectConstants›
I240715 14:26:59.721833 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21489  disabled rule matched: ‹PushSelectIntoInlinableProject›
I240715 14:26:59.721911 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21490  disabled rule matched: ‹GeneratePartialIndexScans›
I240715 14:26:59.721924 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21491  disabled rule matched: ‹GenerateConstrainedScans›
I240715 14:26:59.721933 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21492  disabled rule matched: ‹GenerateInvertedIndexScans›
I240715 14:26:59.721942 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21493  disabled rule matched: ‹GenerateTrigramSimilarityInvertedIndexScans›
I240715 14:26:59.721951 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21494  disabled rule matched: ‹GenerateZigzagJoins›
I240715 14:27:00.503016 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21495  disabled rule matched: ‹CommuteVar›
I240715 14:27:00.503052 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21496  disabled rule matched: ‹InlineSelectConstants›
I240715 14:27:00.503063 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21497  disabled rule matched: ‹PushSelectIntoInlinableProject›
I240715 14:27:00.503126 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21498  disabled rule matched: ‹GeneratePartialIndexScans›
I240715 14:27:00.503134 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21499  disabled rule matched: ‹GenerateConstrainedScans›
I240715 14:27:00.503140 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21500  disabled rule matched: ‹GenerateInvertedIndexScans›
I240715 14:27:00.503145 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21501  disabled rule matched: ‹GenerateTrigramSimilarityInvertedIndexScans›
I240715 14:27:00.503152 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21502  disabled rule matched: ‹GenerateZigzagJoins›
I240715 14:27:01.284247 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21503  disabled rule matched: ‹SimplifySelectFilters›
I240715 14:27:01.284284 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21504  disabled rule matched: ‹SimplifySelectFilters›
I240715 14:27:01.284296 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21505  disabled rule matched: ‹MergeSelects›
I240715 14:27:01.284375 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21506  disabled rule matched: ‹GeneratePartialIndexScans›
I240715 14:27:01.284386 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21507  disabled rule matched: ‹GenerateConstrainedScans›
I240715 14:27:01.284396 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21508  disabled rule matched: ‹GenerateInvertedIndexScans›
I240715 14:27:01.284404 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21509  disabled rule matched: ‹GenerateTrigramSimilarityInvertedIndexScans›
I240715 14:27:01.284411 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21510  disabled rule matched: ‹GenerateZigzagJoins›
I240715 14:27:02.065474 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21511  disabled rule matched: ‹CommuteVar›
I240715 14:27:02.065513 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21512  disabled rule matched: ‹InlineSelectConstants›
I240715 14:27:02.065522 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21513  disabled rule matched: ‹PushSelectIntoInlinableProject›
I240715 14:27:02.065593 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21514  disabled rule matched: ‹GeneratePartialIndexScans›
I240715 14:27:02.065601 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21515  disabled rule matched: ‹GenerateConstrainedScans›
I240715 14:27:02.065606 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21516  disabled rule matched: ‹GenerateInvertedIndexScans›
I240715 14:27:02.065611 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21517  disabled rule matched: ‹GenerateTrigramSimilarityInvertedIndexScans›
I240715 14:27:02.065617 2408 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n6,client=34.150.187.60:36710,hostssl,user=‹roachprod›] 21518  disabled rule matched: ‹GenerateZigzagJoins›
mgartner commented 1 month ago

Do you see something out of the ordinary in those logs?

DrewKimball commented 1 month ago

Repeated disabled rules matching like that usually indicates a rule cycle. In this case, it's not obvious what the cycle is, though.

mgartner commented 1 month ago

I tried running the query log and was unable to reproduce a cycle.

cockroach-teamcity commented 1 month ago

roachtest.unoptimized-query-oracle/disable-rules=half/seed-multi-region failed with artifacts on release-24.2 @ 238d10a22cff57ddc8393b149cffb58883a2a89f:

(test_runner.go:1277).runTest: test timed out (1h0m0s)
test artifacts and logs in: /artifacts/unoptimized-query-oracle/disable-rules=half/seed-multi-region/run_1

Parameters:

See: roachtest README

See: How To Investigate (internal)

See: Grafana

This test on roachdash | Improve this report!

mgartner commented 1 month ago

Logs from node 1 in the last failure may better point to the cycle:

I240716 19:55:02.913468 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5512  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:02.913474 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5513  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:02.949719 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5514  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:02.949793 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5515  disabled rule matched: ‹ReorderJoins›
I240716 19:55:02.949805 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5516  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:02.949812 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5517  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:02.985949 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5518  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:02.986020 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5519  disabled rule matched: ‹ReorderJoins›
I240716 19:55:02.986032 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5520  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:02.986038 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5521  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.023206 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5522  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.023281 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5523  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.023294 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5524  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.023300 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5525  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.060074 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5526  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.060171 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5527  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.060190 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5528  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.060201 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5529  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.096155 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5530  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.096229 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5531  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.096241 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5532  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.096247 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5533  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.136606 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5534  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.136681 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5535  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.136695 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5536  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.136702 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5537  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.173379 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5538  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.173448 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5539  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.173460 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5540  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.173466 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5541  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.210757 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5542  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.210831 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5543  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.210845 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5544  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.210851 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5545  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.247870 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5546  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.247946 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5547  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.247961 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5548  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.247967 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5549  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.285130 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5550  disabled rule matched: ‹SimplifyWindowOrdering›
I240716 19:55:03.285217 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5551  disabled rule matched: ‹ReorderJoins›
I240716 19:55:03.285232 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5552  disabled rule matched: ‹GenerateLookupJoins›
I240716 19:55:03.285238 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5553  disabled rule matched: ‹GenerateInvertedJoins›
I240716 19:55:03.322086 7387 sql/opt/xform/optimizer.go:1104 ⋮ [T1,Vsystem,n1,client=34.86.84.110:47556,hostssl,user=‹roachprod›] 5554  disabled rule matched: ‹SimplifyWindowOrdering›

I think this should block the release until we know more. I'm addig the release-blocker label back.

mgartner commented 1 month ago

Hmm, I'm not sure this is evidence of a rule or memo cycle. All these disabled rule matched logs are from the same goroutine, but they could be different queries, right?

DrewKimball commented 1 month ago

Hmm, I'm not sure this is evidence of a rule or memo cycle. All these disabled rule matched logs are from the same goroutine, but they could be different queries, right?

The ones in your snippet at least look like they're from a single query - look how close together they're spaced.

mgartner commented 1 month ago

Right. Some of these log lines are from the same query, but I don't see evidence that all of them are. This looks like the unoptimized query oracle working as expected, I think...

mgartner commented 1 month ago

Moving this to GA-blocker for now until we know more.

mgartner commented 1 month ago

I've spent a lot of time trying to get to the bottom of this one and I haven't found any clues. I'm going to close.