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.

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

sql/logictest: failure: use of Span after Finish #83739

Closed
cockroach-teamcity opened this issue Jul 2, 2022 · 10 comments · Fixed by #84628
Closed

sql/logictest: failure: use of Span after Finish #83739

cockroach-teamcity opened this issue Jul 2, 2022 · 10 comments · Fixed by #84628
Assignees
Labels
branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions)
Milestone

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Jul 2, 2022

sql/logictest.TestLogic failed with artifacts on master @ 4e8134033890c956d39020f28a0e99b21b32649f:

=== RUN   TestLogic/local/alter_table/column_backfiller_update_batching
    logic.go:3309: let $use_decl_sc = on
[05:13:22] SET use_declarative_schema_changer = 'off';;
[05:13:22] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:13:22] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:13:22] 	-- OK;
[05:13:22] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:13:22] 	-- OK;
[05:13:22] ROLLBACK;;
Help

See also: How To Investigate a Go Test Failure (internal)

Same failure on other branches

/cc @cockroachdb/sql-queries

This test on roachdash | Improve this report!

Jira issue: CRDB-17229

@cockroach-teamcity cockroach-teamcity added branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Jul 2, 2022
@cockroach-teamcity cockroach-teamcity added this to the 22.2 milestone Jul 2, 2022
@blathers-crl blathers-crl bot added the T-sql-queries SQL Queries Team label Jul 2, 2022
@cockroach-teamcity
Copy link
Member Author

sql/logictest.TestLogic failed with artifacts on master @ 3c9b17113488d2ee6929936aa6ec48396f3ed71c:

=== RUN   TestLogic/local/alter_table/column_backfiller_update_batching
    logic.go:3309: let $use_decl_sc = on
[05:13:56] SET use_declarative_schema_changer = 'off';;
[05:13:56] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:13:56] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:13:56] 	-- OK;
[05:13:56] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:13:56] 	-- OK;
[05:13:56] ROLLBACK;;
[05:13:56] SET CLUSTER SETTING bulkio.column_backfill.update_chunk_size_threshold_bytes = 1;;
[05:13:56] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:13:56] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:13:56] 	-- OK;
[05:13:56] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:13:56] 	-- OK;
[05:13:56] ROLLBACK;;
Help

See also: How To Investigate a Go Test Failure (internal)

Same failure on other branches

This test on roachdash | Improve this report!

@rytaft
Copy link
Collaborator

rytaft commented Jul 5, 2022

Check artifacts to see if it's a timeout? If so, close as a dup of some issues that @yuzefovich opened.

@cockroach-teamcity
Copy link
Member Author

sql/logictest.TestLogic failed with artifacts on master @ 33d70998719051ee058bc9e516afa238ea7b7451:

=== RUN   TestLogic/local/alter_table/column_backfiller_update_batching
    logic.go:3309: let $use_decl_sc = on
[05:13:17] SET use_declarative_schema_changer = 'off';;
[05:13:17] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:13:17] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:13:17] 	-- OK;
[05:13:17] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:13:17] 	-- OK;
[05:13:17] ROLLBACK;;
[05:13:17] SET CLUSTER SETTING bulkio.column_backfill.update_chunk_size_threshold_bytes = 1;;
[05:13:17] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:13:17] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:13:17] 	-- OK;
[05:13:17] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:13:17] 	-- OK;
[05:13:17] ROLLBACK;;
Help

See also: How To Investigate a Go Test Failure (internal)

Same failure on other branches

This test on roachdash | Improve this report!

@cockroach-teamcity
Copy link
Member Author

sql/logictest.TestLogic failed with artifacts on master @ 03d5260a467b8640de41ee08054c1ce05f91966c:

=== RUN   TestLogic/local/alter_table/column_backfiller_update_batching
    logic.go:3309: let $use_decl_sc = on
[05:13:31] SET use_declarative_schema_changer = 'off';;
[05:13:31] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:13:31] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:13:31] 	-- OK;
[05:13:31] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:13:31] 	-- OK;
[05:13:31] ROLLBACK;;
Help

See also: How To Investigate a Go Test Failure (internal)

Same failure on other branches

This test on roachdash | Improve this report!

@mgartner
Copy link
Collaborator

mgartner commented Jul 8, 2022

I don't see anything in the artifacts that indicates a timeout, but it seems likely given that this test sometimes hangs for minutes at a time when I stress it, but other times completes several iterations in a 5 second period:

$gmake stress PKG='./pkg/sql/logictest' TESTS='TestLogic/local/alter_table' TESTFLAGS='' TESTTIMEOUT=1800s
...
0 runs so far, 0 failures, over 5s
0 runs so far, 0 failures, over 10s
0 runs so far, 0 failures, over 15s
0 runs so far, 0 failures, over 20s
0 runs so far, 0 failures, over 25s
0 runs so far, 0 failures, over 30s
0 runs so far, 0 failures, over 35s
0 runs so far, 0 failures, over 40s
0 runs so far, 0 failures, over 45s
0 runs so far, 0 failures, over 50s
0 runs so far, 0 failures, over 55s
0 runs so far, 0 failures, over 1m0s
0 runs so far, 0 failures, over 1m5s
0 runs so far, 0 failures, over 1m10s
0 runs so far, 0 failures, over 1m15s
0 runs so far, 0 failures, over 1m20s
0 runs so far, 0 failures, over 1m25s
0 runs so far, 0 failures, over 1m30s
0 runs so far, 0 failures, over 1m35s
0 runs so far, 0 failures, over 1m40s
0 runs so far, 0 failures, over 1m45s
0 runs so far, 0 failures, over 1m50s
0 runs so far, 0 failures, over 1m55s
0 runs so far, 0 failures, over 2m0s
0 runs so far, 0 failures, over 2m5s
0 runs so far, 0 failures, over 2m10s
9 runs so far, 0 failures, over 2m15s
13 runs so far, 0 failures, over 2m20s
16 runs so far, 0 failures, over 2m25s
16 runs so far, 0 failures, over 2m30s
16 runs so far, 0 failures, over 2m35s
16 runs so far, 0 failures, over 2m40s
16 runs so far, 0 failures, over 2m45s
16 runs so far, 0 failures, over 2m50s
16 runs so far, 0 failures, over 2m55s
16 runs so far, 0 failures, over 3m0s
16 runs so far, 0 failures, over 3m5s
16 runs so far, 0 failures, over 3m10s
16 runs so far, 0 failures, over 3m15s
16 runs so far, 0 failures, over 3m20s
16 runs so far, 0 failures, over 3m25s
16 runs so far, 0 failures, over 3m30s
16 runs so far, 0 failures, over 3m35s
16 runs so far, 0 failures, over 3m40s
16 runs so far, 0 failures, over 3m45s
16 runs so far, 0 failures, over 3m50s
16 runs so far, 0 failures, over 3m55s
16 runs so far, 0 failures, over 4m0s
16 runs so far, 0 failures, over 4m5s
16 runs so far, 0 failures, over 4m10s
16 runs so far, 0 failures, over 4m15s
16 runs so far, 0 failures, over 4m20s

@blathers-crl blathers-crl bot added the T-sql-schema-deprecated Use T-sql-foundations instead label Jul 8, 2022
@mgartner mgartner removed their assignment Jul 8, 2022
@ajwerner
Copy link
Contributor

ajwerner commented Jul 8, 2022

From https://teamcityartifacts.crdb.io/presignedTokenAuth/39f48436-df1e-4292-8713-89ffba740470/repository/download/Cockroach_Nightlies_SqlLogicTestHighVModuleNightlyBazel/5633779:id/tmp/_tmp/7013a0eb507caf06d50eefd8e168b91f/logTestLogic1299070186/logictesttest.log

E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612  a panic has occurred!
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +panic: ‹use of Span after Finish. Span: sql txn. Finish previously called at: <stack not captured. Set debugUseAfterFinish>›
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +(1) attached stack trace
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  -- stack trace:
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*Server).ServeConn.func1
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:755
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | [...repeated from below...]
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +Wraps: (2) while executing: ROLLBACK TRANSACTION
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +Wraps: (3) attached stack trace
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  -- stack trace:
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*Server).ServeConn.func1
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:755
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | runtime.gopanic
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	GOROOT/src/runtime/panic.go:1047
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/tracing.(*Span).detectUseAfterFinish
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/tracing/span.go:186
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/tracing.(*Span).RecordingType
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/tracing/span.go:411
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/tracing.(*Span).IsVerbose
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/tracing/span.go:419
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/log.getSpanOrEventLog
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/log/trace.go:92
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/log.logfDepthInternal
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/log/channels.go:101
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/log.logfDepth
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/log/channels.go:39
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/log.InfofDepth
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/bazel-out/k8-dbg/bin/pkg/util/log/log_channels_generated.go:332
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/contextutil.wrap.func1
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/contextutil/context.go:74
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*txnState).finishSQLTxn
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/txn_state.go:256
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*txnState).finishTxn
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_fsm.go:502
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.glob..func9
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_fsm.go:267
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/fsm.Transitions.apply
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/fsm/fsm.go:106
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/util/fsm.(*Machine).ApplyWithPayload
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/util/fsm/fsm.go:135
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).txnStateTransitionsApplyWrapper.func1
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:2845
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).txnStateTransitionsApplyWrapper
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:2846
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).execCmd
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:2065
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).run
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1818
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql.(*Server).ServeConn
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:757
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*conn).processCommandsAsync.func1
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:724
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | runtime.goexit
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +  | 	GOROOT/src/runtime/asm_amd64.s:1581
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +Wraps: (4) panic: ‹use of Span after Finish. Span: sql txn. Finish previously called at: <stack not captured. Set debugUseAfterFinish>›
E220703 05:13:56.428646 84527 1@util/log/logcrash/crash_reporting.go:174 ⋮ [n1,client=127.0.0.1:58994,user=root] 5220612 +Error types: (1) *withstack.withStack (2) *safedetails.withSafeDetails (3) *withstack.withStack (4) *errutil.leafError

@cockroach-teamcity
Copy link
Member Author

sql/logictest.TestLogic failed with artifacts on master @ 54b4fcaa231abd16260fb09722ed291dbd6a4900:

=== RUN   TestLogic/local/alter_table/column_backfiller_update_batching
    logic.go:3309: let $use_decl_sc = on
[05:14:14] SET use_declarative_schema_changer = 'off';;
[05:14:14] BEGIN;
CREATE TABLE tb AS SELECT 123::INT AS k FROM generate_series(1, 10);
SET tracing = on,kv;
ALTER TABLE tb ADD COLUMN v STRING NOT NULL DEFAULT ('abc'::STRING);
SET tracing = off;;
[05:14:14] SELECT count(*) FROM [SHOW KV TRACE FOR SESSION] WHERE message LIKE '%sending batch%' AND message LIKE '% Put to %';;
[05:14:14] 	-- OK;
[05:14:14] SELECT count(*) FROM tb WHERE v = 'abc';;
[05:14:14] 	-- OK;
[05:14:14] ROLLBACK;;
Help

See also: How To Investigate a Go Test Failure (internal)

Same failure on other branches

This test on roachdash | Improve this report!

@mgartner mgartner changed the title sql/logictest: TestLogic failed sql/logictest: TestLogic/local/alter_table/column_backfiller_update_batching failed Jul 11, 2022
@mgartner
Copy link
Collaborator

Thanks for tracking that stacktrace down @ajwerner! ❤️

@mgartner mgartner changed the title sql/logictest: TestLogic/local/alter_table/column_backfiller_update_batching failed sql/logictest: failure: use of Span after Finish Jul 11, 2022
@msirek
Copy link
Contributor

msirek commented Jul 12, 2022

The next step may be to run stress logictest with -v -show-sql , which prints the queries and disables parallelism. Should help identify the query. May take 24 hours or so to reproduce it.

@yuzefovich
Copy link
Member

I think it's crucial that it fails only with SQL Logic Test High VModule Nightly (Bazel), so we need to set higher vmodule when attempting a repro. I'll take a closer look.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. T-sql-foundations SQL Foundations Team (formerly SQL Schema + SQL Sessions)
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

6 participants