cockroach icon indicating copy to clipboard operation
cockroach copied to clipboard
verified publisher icon cockroachdb

pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test: TestTenantLogic_synthetic_privileges failed

Open cockroach-teamcity opened this issue 1 year ago • 5 comments

pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test.TestTenantLogic_synthetic_privileges failed with artifacts on master @ 8bc8c72869dcf4fdae1595bca5577bd99fc4901a:

=== RUN   TestTenantLogic_synthetic_privileges
    test_log_scope.go:170: test logs captured to: /artifacts/tmp/_tmp/1f89d4895622f6fe0b58d484ea888c95/logTestTenantLogic_synthetic_privileges3901552623
    test_log_scope.go:81: use -show-logs to present logs inline
[07:09:10] setting distsql_workmem='41616B';
[07:09:10] setting distsql_workmem='41616B';
[07:09:12] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15465/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 60 statements
    logic.go:2967: 
         
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15465/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:319: SELECT has_table_privilege('testuser4', 'crdb_internal.tables', 'SELECT')
        expected success, but found
        (40001) restart transaction: has_table_privilege(): TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_ABORT_SPAN): "sql txn" meta={id=043fdc68 key=/Tenant/10/Table/52/1/"testuser4"/"/vtable/crdb_internal/tables" iso=Serializable pri=0.01279712 epo=0 ts=1722928152.805173592,0 min=1722928152.805173592,0 seq=4} lock=true stat=ABORTED rts=1722928152.805173592,0 wto=false gul=1722928153.305173592,0
        eval.go:2153: in MaybeWrapError()
[07:09:18] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15465/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 70 statements
[07:09:18] --- done: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15465/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges with config 3node-tenant: 70 tests, 1 failures
    logic.go:4144: 
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15465/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:324: error while processing
    logic.go:4144: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15465/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:324: too many errors encountered, skipping the rest of the input
    panic.go:626: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/1f89d4895622f6fe0b58d484ea888c95/logTestTenantLogic_synthetic_privileges3901552623
--- FAIL: TestTenantLogic_synthetic_privileges (10.22s)
Help

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

This test on roachdash | Improve this report!

Jira issue: CRDB-40972

cockroach-teamcity avatar Aug 06 '24 07:08 cockroach-teamcity

pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test.TestTenantLogic_synthetic_privileges failed with artifacts on master @ 9765a2cc0d7b4d6dacff07ea5668d1b59a36cfc2:

=== RUN   TestTenantLogic_synthetic_privileges
    test_log_scope.go:170: test logs captured to: /artifacts/tmp/_tmp/a87a4bfc23f47f52891e3d48f96a6423/logTestTenantLogic_synthetic_privileges3695032854
    test_log_scope.go:81: use -show-logs to present logs inline
[04:03:07] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 61 statements
[04:03:13] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 68 statements
    logic.go:2967: 
         
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:305: SELECT username, path, privileges, grant_options FROM system.privileges ORDER BY 1,2
        expected success, but found
        (40001) restart transaction: TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_CLIENT_REJECT): "sql txn" meta={id=0bb6b9a0 key=/Tenant/10/Table/52/1/"testuser4"/"/vtable/crdb_internal/tables" iso=Serializable pri=0.05189050 epo=0 ts=1723521787.476859192,1 min=1723521787.466307365,0 seq=4} lock=true stat=PENDING rts=1723521787.466307365,0 wto=false gul=1723521787.966307365,0
[04:03:13] --- done: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges with config 3node-tenant: 69 tests, 1 failures
    logic.go:4144: 
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:318: error while processing
    logic.go:4144: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:318: too many errors encountered, skipping the rest of the input
    panic.go:626: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/a87a4bfc23f47f52891e3d48f96a6423/logTestTenantLogic_synthetic_privileges3695032854
--- FAIL: TestTenantLogic_synthetic_privileges (10.33s)
Help

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

This test on roachdash | Improve this report!

cockroach-teamcity avatar Aug 13 '24 04:08 cockroach-teamcity

The first failure:

I240806 07:09:12.777311 198954 jobs/wait.go:153 â‹® [T10,Vcluster-10,nsql1,client=127.0.0.1:47544,hostssl,user=root] 1097  waited for 1 [992404284123873281] queued jobs to complete 40.40254ms
I240806 07:09:12.819175 198954 sql/table.go:210 â‹® [T10,Vcluster-10,nsql1,client=127.0.0.1:47544,hostssl,user=root] 1098  queued new schema-change job 992404284437856257 for table 52, mutation 0
W240806 07:09:18.833959 191833 server/node.go:1401 ⋮ [T1,Vsystem,n1,summaries] 1099  health alerts detected: {Alerts:[{StoreID:1 Category:‹METRICS› Description:‹ranges.underreplicated› Value:70}]}
I240806 07:09:18.841175 211777 sql/distsql_running.go:806 ⋮ [T10,Vcluster-10,nsql1,client=127.0.0.1:47544,hostssl,user=root,intExec=‹read-roles›] 1100  ‹client rejected when attempting to run DistSQL plan›: TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_ABORT_SPAN): "sql txn" meta={id=043fdc68 key=/Tenant/10/Table/52/1/‹"testuser4"›/‹"/vtable/crdb_internal/tables"› iso=Serializable pri=0.01279712 epo=0 ts=1722928152.805173592,0 min=1722928152.805173592,0 seq=4} lock=true stat=ABORTED rts=1722928152.805173592,0 wto=false gul=1722928153.305173592,0

The second failure:

I240813 04:03:07.430192 65243 jobs/wait.go:153 â‹® [T10,Vcluster-10,nsql1,client=127.0.0.1:48402,hostssl,user=root] 1093  waited for 1 [994349506018902017] queued jobs to complete 84.824924ms
I240813 04:03:07.547765 65243 sql/table.go:210 â‹® [T10,Vcluster-10,nsql1,client=127.0.0.1:48402,hostssl,user=root] 1094  queued new schema-change job 994349506716467201 for table 52, mutation 0
I240813 04:03:09.933919 58353 kv/kvserver/queue.go:621 ⋮ [T1,Vsystem,n1,s1,r26/1:‹/Table/2{3-4}›,raft] 1095  rate limited in MaybeAdd (merge): throttled on async limiting semaphore
W240813 04:03:13.454426 57477 server/node.go:1401 ⋮ [T1,Vsystem,n1,summaries] 1096  health alerts detected: {Alerts:[{StoreID:1 Category:‹METRICS› Description:‹ranges.underreplicated› Value:70}]}
I240813 04:03:13.568330 57401 sql/logictest/logic.go:1199 ⋮ [-] 1097  --- progress: ‹/home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/15663/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges›: 68 statements
I240813 04:03:13.569068 65243 sql/distsql_running.go:806 ⋮ [T10,Vcluster-10,nsql1,client=127.0.0.1:48402,hostssl,user=root] 1098  ‹client rejected when attempting to run DistSQL plan›: TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_CLIENT_REJECT): "sql txn" meta={id=0bb6b9a0 key=/Tenant/10/Table/52/1/‹"testuser4"›/‹"/vtable/crdb_internal/tables"› iso=Serializable pri=0.05189050 epo=0 ts=1723521787.476859192,1 min=1723521787.466307365,0 seq=4} lock=true stat=PENDING rts=1723521787.466307365,0 wto=false gul=1723521787.966307365,0

Both errors can be caused by overload, if the transaction coordinator is unable to heartbeat the record for a few seconds. Both logs show a couple seconds between the error and whatever happens before it.

DrewKimball avatar Aug 28 '24 07:08 DrewKimball

@rafiss do you have any ideas how to improve this test? It looks similar to #126763, but we can't just break up the transaction here, since caching behavior after rollback is what's being tested.

DrewKimball avatar Aug 28 '24 07:08 DrewKimball

pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test.TestTenantLogic_synthetic_privileges failed with artifacts on master @ e243814aa348639f6db42d3cbd0dc189ae6f2e29:

=== RUN   TestTenantLogic_synthetic_privileges
    test_log_scope.go:170: test logs captured to: /artifacts/tmp/_tmp/4f67154c1f005fca96111f5c820bcbd9/logTestTenantLogic_synthetic_privileges2923046497
    test_log_scope.go:81: use -show-logs to present logs inline
[14:55:35] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16551/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 60 statements
    logic.go:3024: 
         
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16551/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:319: SELECT has_table_privilege('testuser4', 'crdb_internal.tables', 'SELECT')
        expected success, but found
        (40001) restart transaction: has_table_privilege(): TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_ABORT_SPAN): "sql txn" meta={id=a652d9f4 key=/Tenant/10/Table/52/1/"testuser4"/"/vtable/crdb_internal/tables" iso=Serializable pri=0.02902187 epo=0 ts=1724856935.721491647,0 min=1724856935.721491647,0 seq=4} lock=true stat=ABORTED rts=1724856935.721491647,0 wto=false gul=1724856936.221491647,0
        eval.go:2153: in MaybeWrapError()
[14:55:41] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16551/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 70 statements
[14:55:41] --- done: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16551/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges with config 3node-tenant: 70 tests, 1 failures
    logic.go:4197: 
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16551/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:324: error while processing
    logic.go:4197: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16551/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:324: too many errors encountered, skipping the rest of the input
    panic.go:626: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/4f67154c1f005fca96111f5c820bcbd9/logTestTenantLogic_synthetic_privileges2923046497
--- FAIL: TestTenantLogic_synthetic_privileges (10.28s)
Help

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

This test on roachdash | Improve this report!

cockroach-teamcity avatar Aug 28 '24 14:08 cockroach-teamcity

I don't have any solid ideas. I am surprised the test would be having overload though. It's not really doing anything intensive. Would it be worth checking with KV to confirm that the ABORT_REASON_CLIENT_REJECT and ABORT_REASON_ABORT_SPAN errors really are caused by overload, and not because of any recent changes? (As far as I can tell, this only started flaking due to these errors recently.)

rafiss avatar Aug 28 '24 20:08 rafiss

pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test.TestTenantLogic_synthetic_privileges failed with artifacts on master @ cf787f691f3d757409f10bb2bb8cb1bec2b20562:

=== RUN   TestTenantLogic_synthetic_privileges
    test_log_scope.go:170: test logs captured to: /artifacts/tmp/_tmp/4f67154c1f005fca96111f5c820bcbd9/logTestTenantLogic_synthetic_privileges2244029704
    test_log_scope.go:81: use -show-logs to present logs inline
[22:38:22] setting distsql_workmem='52908B';
[22:38:22] setting distsql_workmem='52908B';
[22:38:24] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16555/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 60 statements
    logic.go:3024: 
         
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16555/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:319: SELECT has_table_privilege('testuser4', 'crdb_internal.tables', 'SELECT')
        expected success, but found
        (40001) restart transaction: has_table_privilege(): TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_CLIENT_REJECT): "sql txn" meta={id=868ca97c key=/Tenant/10/Table/52/1/"testuser4"/"/vtable/crdb_internal/tables" iso=Serializable pri=0.01360183 epo=0 ts=1725057505.059799962,0 min=1725057505.059799962,0 seq=4} lock=true stat=PENDING rts=1725057505.059799962,0 wto=false gul=1725057505.559799962,0
        eval.go:2153: in MaybeWrapError()
[22:38:31] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16555/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 70 statements
[22:38:31] --- done: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16555/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges with config 3node-tenant: 70 tests, 1 failures
    logic.go:4198: 
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16555/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:324: error while processing
    logic.go:4198: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16555/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:324: too many errors encountered, skipping the rest of the input
    panic.go:626: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/4f67154c1f005fca96111f5c820bcbd9/logTestTenantLogic_synthetic_privileges2244029704
--- FAIL: TestTenantLogic_synthetic_privileges (10.36s)
Help

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

This test on roachdash | Improve this report!

cockroach-teamcity avatar Aug 30 '24 22:08 cockroach-teamcity

Asked KV here: https://cockroachlabs.slack.com/archives/C0KB9Q03D/p1725389922920809

DrewKimball avatar Sep 04 '24 00:09 DrewKimball

pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test.TestTenantLogic_synthetic_privileges failed with artifacts on master @ b74b513ca859ffbdc737269609552732c5917cec:

=== RUN   TestTenantLogic_synthetic_privileges
    test_log_scope.go:170: test logs captured to: /artifacts/tmp/_tmp/4f67154c1f005fca96111f5c820bcbd9/logTestTenantLogic_synthetic_privileges619133696
    test_log_scope.go:81: use -show-logs to present logs inline
[18:10:45] setting distsql_workmem='81571B';
[18:10:45] setting distsql_workmem='81571B';
[18:10:47] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16402/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 60 statements
[18:10:53] --- progress: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16402/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges: 68 statements
    logic.go:3024: 
         
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16402/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:305: SELECT username, path, privileges, grant_options FROM system.privileges ORDER BY 1,2
        expected success, but found
        (40001) restart transaction: TransactionRetryWithProtoRefreshError: TransactionAbortedError(ABORT_REASON_CLIENT_REJECT): "sql txn" meta={id=76ce38a5 key=/Tenant/10/Table/52/1/"testuser4"/"/vtable/crdb_internal/tables" iso=Serializable pri=0.02145423 epo=0 ts=1725473447.622216299,1 min=1725473447.617437738,0 seq=4} lock=true stat=PENDING rts=1725473447.617437738,0 wto=false gul=1725473448.117437738,0
[18:10:53] --- done: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16402/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges with config 3node-tenant: 69 tests, 1 failures
    logic.go:4198: 
        /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16402/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:318: error while processing
    logic.go:4198: /home/roach/.cache/bazel/_bazel_roach/c5a4e7d36696d9cd970af2045211a7df/sandbox/processwrapper-sandbox/16402/execroot/com_github_cockroachdb_cockroach/bazel-out/aarch64-fastbuild/bin/pkg/ccl/logictestccl/tests/3node-tenant/3node-tenant_test_/3node-tenant_test.runfiles/com_github_cockroachdb_cockroach/pkg/sql/logictest/testdata/logic_test/synthetic_privileges:318: too many errors encountered, skipping the rest of the input
    panic.go:626: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/4f67154c1f005fca96111f5c820bcbd9/logTestTenantLogic_synthetic_privileges619133696
--- FAIL: TestTenantLogic_synthetic_privileges (10.28s)
Help

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

This test on roachdash | Improve this report!

cockroach-teamcity avatar Sep 04 '24 18:09 cockroach-teamcity

According to the KV team, this is likely not overload, and really is contention. The contention events are all on this key:

/Tenant/10/Table/52/1/"testuser4"/"/vtable/crdb_internal/tables"

which is likely the privileges table. It's unclear to me why we'd be seeing contention here, but I wonder if the REVOKE and GRANT schema changes aren't behaving fully transactionally? We might be able to avoid the flakes by just changing which table we grant/revoke privileges on with each test.

cc @cockroachdb/sql-foundations

DrewKimball avatar Sep 06 '24 17:09 DrewKimball

Just to stabilize this we could try adding the retry flag on the query:

query B retry

fqazi avatar Sep 24 '24 17:09 fqazi

Based on the specified backports for linked PR #131351, I applied the following new label(s) to this issue: branch-release-24.2. Please adjust the labels as needed to match the branches actually affected by this issue, including adding any known older branches.

:owl: Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.

blathers-crl[bot] avatar Sep 26 '24 13:09 blathers-crl[bot]