search

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.96k stars 3.79k forks source link

pkg/ccl/testccl/sqlccl/sqlccl_test: TestExplainRedactDDL failed #129810

Open cockroach-teamcity opened 1 month ago

cockroach-teamcity commented 1 month ago

pkg/ccl/testccl/sqlccl/sqlccl_test.TestExplainRedactDDL failed with artifacts on release-24.2 @ aeeae592c24abc9ec7010fbc8c5b0de1257a4c64:

Fatal error:

panic: test timed out after 4m57s
running tests:
    TestExplainRedactDDL (4m57s)
    TestExplainRedactDDL/ExplainAnalyze (4m55s)
    TestExplainRedactDDL/ExplainAnalyze/Plan (2m51s)
    TestExplainRedactDDL/ExplainAnalyze/Plan/Types (31s)

Stack: 

goroutine 38482 [running]:
testing.(*M).startAlarm.func1()
    GOROOT/src/testing/testing.go:2366 +0x30c
created by time.goFunc
    GOROOT/src/time/sleep.go:177 +0x38
Log preceding fatal error

``` ((-18778):::INT8, '':::VOID, B'00101010101000010'), (10251:::INT8, NULL, B'11110100101001001') ) AS tab_9 (col_12, col_13, col_14) ) SELECT cte_ref_1.col_12 AS col_15, tab_10.col1_0 AS col_16, B'00011010100010100' AS col_17, cte_ref_1.col_13 AS col_18, tab_10.tableoid AS col_19, tab_10.crdb_internal_mvcc_timestamp AS col_20 FROM with_3 AS cte_ref_1, defaultdb.public."t/able_1"@[0] AS tab_10 WHERE true ORDER BY tab_10.tableoid ASC NULLS FIRST, cte_ref_1.col_12 DESC NULLS FIRST explain_test_util.go:132: encountered non-internal error: pq: query execution canceled due to statement timeout EXPLAIN ANALYZE (PLAN, TYPES, REDACT) WITH with_5 (col_24) AS (SELECT * FROM (VALUES ('':::VOID), ('':::VOID), ('':::VOID)) AS tab_13 (col_24)), with_6 (col_25) AS ( SELECT * FROM ( VALUES ( (uuid_generate_v1()::UUID::UUID || st_ashexewkb('0101000060E61000008AFC8BE73D9F60C030F7DB78B99C52402276F072F6A1E541':::GEOGRAPHY::GEOGRAPHY, e'pachycephalosaurus@|"$"\nTM':::STRING::STRING)::STRING::STRING)::STRING COLLATE da_DK ), (e'\U000EE2B6\U0007D9D2' COLLATE da_DK), (NULL) ) AS tab_14 (col_25) ) SELECT stddev(tab_15.crdb_internal_mvcc_timestamp::DECIMAL)::DECIMAL AS col_26, st_union(tab_15.col1_0::GEOMETRY)::GEOMETRY AS col_27 FROM defaultdb.public."t/able_1" AS tab_15 GROUP BY tab_15.crdb_internal_mvcc_timestamp, tab_15.col1_0 HAVING every(true::BOOL)::BOOL explain_test_util.go:132: encountered non-internal error: pq: query execution canceled due to statement timeout EXPLAIN ANALYZE (PLAN, TYPES, REDACT) UPDATE defaultdb.public."t/able_1" AS tab_16 SET col1_0 = tab_16.col1_0 ORDER BY tab_16.tableoid DESC LIMIT 78:::INT8 ```

Help

See also: [How To Investigate a Go Test Failure \(internal\)](https://cockroachlabs.atlassian.net/l/c/HgfXfJgM)

This test on roachdash | Improve this report!

Jira issue: CRDB-41720

DrewKimball commented 1 month ago 
W240828 15:11:49.781513 2874 kv/kvclient/kvcoord/txn_interceptor_pipeliner.go:731 ⋮ [T10,Vtest-tenant,n1,client=127.0.0.1:52968,hostssl,user=root] 622  a transaction has hit the intent tracking limit (kv.transaction.max_intents_bytes); is it a bulk operation? Intent cleanup will be slower. txn: "sql txn" meta={id=66bd5d37 key=/Tenant/10/Table/104/1/‹998727709601103873›/‹0› iso=Serializable pri=0.04176088 epo=0 ts=1724857907.748275295,0 min=1724857907.748275295,0 seq=50000} lock=true stat=PENDING rts=1724857907.748275295,0 wto=false gul=1724857908.248275295,0 ba: ‹10000 CPut›

and after that, the logs are filled with:

W240828 15:12:02.977984 5167 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1,s1] 623  slow replica RPC: have been waiting 10.01s (0 attempts) for RPC ResolveIntent [/Tenant/10/Table/104/1/‹998727720985952257›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720985985025›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986017793›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986050561›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986083329›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986116097›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986148865›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986181633›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986214401›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986247169›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986279937›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986312705›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986345473›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986378241›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986411009›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986443777›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986476545›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986509313›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986542081›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720986574849›/‹0›],... 75 skipped ..., ResolveIntent [/Tenant/10/Table/104/1/‹998727720989065217›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720989097985›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720989130753›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720989163521›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720989196289›/‹0›], [max_span_request_keys: 0], [target_bytes: 4194304] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, ... 75 skipped ..., *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse›
W240828 15:12:02.995788 5173 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1,s1] 624  slow replica RPC: have been waiting 10.03s (0 attempts) for RPC ResolveIntent [/Tenant/10/Table/104/1/‹998727721005613057›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005645825›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005678593›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005711361›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005744129›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005776897›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005809665›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005842433›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005875201›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005907969›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005940737›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721005973505›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006006273›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006039041›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006071809›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006104577›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006137345›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006170113›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006202881›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721006235649›/‹0›],... 75 skipped ..., ResolveIntent [/Tenant/10/Table/104/1/‹998727721008726017›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721008758785›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721008791553›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721008824321›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721008857089›/‹0›], [max_span_request_keys: 0], [target_bytes: 4194304] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, ... 75 skipped ..., *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse›
W240828 15:12:03.013911 5157 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1,s1] 625  slow replica RPC: have been waiting 10.04s (0 attempts) for RPC ResolveIntent [/Tenant/10/Table/104/1/‹998727719933378561›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933411329›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933444097›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933476865›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933509633›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933542401›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933575169›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933607937›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933640705›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933673473›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933706241›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933739009›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933771777›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933804545›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933837313›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933870081›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933902849›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933935617›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719933968385›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719934001153›/‹0›],... 75 skipped ..., ResolveIntent [/Tenant/10/Table/104/1/‹998727719936491521›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719936524289›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719936557057›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719936589825›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719936622593›/‹0›], [max_span_request_keys: 0], [target_bytes: 4194304] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, ... 75 skipped ..., *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse›
W240828 15:12:03.031778 5171 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1,s1] 626  slow replica RPC: have been waiting 10.06s (0 attempts) for RPC ResolveIntent [/Tenant/10/Table/104/1/‹998727720999059457›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999092225›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999124993›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999157761›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999190529›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999223297›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999256065›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999288833›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999321601›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999354369›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999387137›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999419905›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999452673›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999485441›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999518209›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999550977›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999583745›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999616513›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999649281›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727720999682049›/‹0›],... 75 skipped ..., ResolveIntent [/Tenant/10/Table/104/1/‹998727721002172417›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721002205185›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721002237953›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721002270721›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727721002303489›/‹0›], [max_span_request_keys: 0], [target_bytes: 4194304] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, ... 75 skipped ..., *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse›
W240828 15:12:03.049575 5164 kv/kvclient/kvcoord/dist_sender.go:2756 ⋮ [T1,Vsystem,n1,s1] 627  slow replica RPC: have been waiting 10.08s (0 attempts) for RPC ResolveIntent [/Tenant/10/Table/104/1/‹998727719956316161›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956348929›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956381697›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956414465›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956447233›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956480001›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956512769›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956545537›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956578305›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956611073›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956643841›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956676609›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956709377›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956742145›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956774913›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956807681›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956840449›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956873217›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956905985›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719956938753›/‹0›],... 75 skipped ..., ResolveIntent [/Tenant/10/Table/104/1/‹998727719959429121›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719959461889›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719959494657›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719959527425›/‹0›], ResolveIntent [/Tenant/10/Table/104/1/‹998727719959560193›/‹0›], [max_span_request_keys: 0], [target_bytes: 4194304] to replica (n1,s1):1; resp: ‹(err: <nil>), *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, ... 75 skipped ..., *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse, *kvpb.ResolveIntentResponse›