cockroach-teamcity
commented
3 years ago ccl/testccl/sqlccl.TestTenantTempTableCleanup failed with artifacts on master @ 6eb9df1f3d460f904b5254c3d32c745eecbedd3f:
I210912 05:47:35.429683 14355 sql/table.go:162 [sql,client=127.0.0.1:37316,hostssl,user=root,intExec=delete-temp-TABLE] 403 queued new schema-change job 692568900991778817 for table 53, mutation 0
I210912 05:47:35.506083 12633 5@util/log/event_log.go:32 [sql,client=127.0.0.1:37316,hostssl,user=root] 404 ={"Timestamp":1631425655343424271,"EventType":"drop_table","Statement":"DROP TABLE defaultdb.pg_temp_1631425646940765936_1.temp_table CASCADE","Tag":"DROP TABLE","User":"root","DescriptorID":53,"ApplicationName":"$ internal-delete-temp-TABLE","TableName":"defaultdb.pg_temp_1631425646940765936_1.temp_table"}
I210912 05:47:35.616328 9792 sql/sqlliveness/slinstance/slinstance.go:293 [-] 405 starting SQL liveness instance
I210912 05:47:35.648348 10044 sql/temporary_schema.go:508 [n1] 406 running temporary object cleanup background job
I210912 05:47:35.653069 14468 sql/sqlliveness/slstorage/slstorage.go:393 [-] 407 inserted sqlliveness session 43a676259efe444ab165fb848717232c
I210912 05:47:35.653370 14468 sql/sqlliveness/slinstance/slinstance.go:180 [-] 408 created new SQL liveness session 43a676259efe444ab165fb848717232c
I210912 05:47:35.653609 11385 sql/temporary_schema.go:500 [n2] 409 skipping temporary object cleanup run as it is not the leaseholder
I210912 05:47:35.653979 11385 sql/temporary_schema.go:501 [n2] 410 completed temporary object cleanup job
I210912 05:47:35.654249 11385 sql/temporary_schema.go:639 [n2] 411 temporary object cleaner next scheduled to run at 2021-09-12 05:47:36.652970924 +0000 UTC
I210912 05:47:35.654952 10044 sql/temporary_schema.go:552 [n1] 412 found 0 temporary schemas
I210912 05:47:35.655213 10044 sql/temporary_schema.go:555 [n1] 413 early exiting temporary schema cleaner as no temporary schemas were found
I210912 05:47:35.655393 10044 sql/temporary_schema.go:556 [n1] 414 completed temporary object cleanup job
I210912 05:47:35.655629 10044 sql/temporary_schema.go:639 [n1] 415 temporary object cleaner next scheduled to run at 2021-09-12 05:47:36.647917828 +0000 UTC
I210912 05:47:35.674801 9792 1@sql/sqlinstance/instanceprovider/instanceprovider.go:80 [-] 416 created SQL instance 2
I210912 05:47:35.675539 14531 sql/temporary_schema.go:508 [-] 417 running temporary object cleanup background job
I210912 05:47:35.676061 14536 sql/sqlstats/persistedsqlstats/provider.go:142 [-] 418 starting sql-stats-worker with initial delay: 55m33.197003779s
I210912 05:47:35.692137 14531 sql/temporary_schema.go:552 [-] 419 found 0 temporary schemas
I210912 05:47:35.692356 14531 sql/temporary_schema.go:555 [-] 420 early exiting temporary schema cleaner as no temporary schemas were found
I210912 05:47:35.692550 14531 sql/temporary_schema.go:556 [-] 421 completed temporary object cleanup job
I210912 05:47:35.692661 14531 sql/temporary_schema.go:639 [-] 422 temporary object cleaner next scheduled to run at 2021-09-12 05:47:36.675400178 +0000 UTC
I210912 05:47:35.741049 14554 server/settingswatcher/settings_watcher.go:112 [rangefeed=settings] 423 set cluster version to: 21.1-1162
I210912 05:47:35.750612 9792 server/server_sql.go:1089 [-] 424 done ensuring all necessary startup migrations have run
I210912 05:47:35.751264 9792 1@server/tenant.go:272 [config] 425 clusterID: 7d54f79d-0035-447a-a9fe-ec684efe1aca
I210912 05:47:35.751614 9792 1@server/tenant.go:273 [config] 426 tenantID: 10
I210912 05:47:35.751838 9792 1@server/tenant.go:273 [config] 427 instanceID: 2
I210912 05:47:35.751998 14458 jobs/job_scheduler.go:351 [-] 428 waiting 2m0s before scheduled jobs daemon start
I210912 05:47:35.752081 9792 1@server/server.go:2330 [-] 429 serving sql connections
I210912 05:47:35.857724 14610 sql/catalog/lease/lease.go:1125 [-] 430 released orphaned lease: {id:12 version:1 expiration:{Time:{wall:716512000 ext:63767022757 loc:<nil>}}}
I210912 05:47:35.866170 14611 sql/catalog/lease/lease.go:1125 [-] 431 released orphaned lease: {id:15 version:1 expiration:{Time:{wall:388766000 ext:63767022735 loc:<nil>}}}
I210912 05:47:35.868393 14612 sql/catalog/lease/lease.go:1125 [-] 432 released orphaned lease: {id:33 version:1 expiration:{Time:{wall:993892000 ext:63767022743 loc:<nil>}}}
I210912 05:47:35.869536 14613 sql/catalog/lease/lease.go:1125 [-] 433 released orphaned lease: {id:35 version:1 expiration:{Time:{wall:404435000 ext:63767022736 loc:<nil>}}}
I210912 05:47:35.871488 14497 sql/catalog/lease/lease.go:1125 [-] 434 released orphaned lease: {id:4 version:1 expiration:{Time:{wall:687979000 ext:63767022750 loc:<nil>}}}
I210912 05:47:35.896905 14518 sql/catalog/lease/lease.go:1125 [-] 435 released orphaned lease: {id:37 version:1 expiration:{Time:{wall:77038000 ext:63767022753 loc:<nil>}}}
W210912 05:47:36.025067 14550 jobs/registry.go:822 [-] 436 canceling all adopted jobs due to stopper quiescing
W210912 05:47:36.028506 12323 jobs/registry.go:822 [-] 437 canceling all adopted jobs due to stopper quiescing
W210912 05:47:36.028842 14468 sql/sqlliveness/slinstance/slinstance.go:217 [-] 438 exiting heartbeat loop
W210912 05:47:36.029809 12215 ccl/kvccl/kvtenantccl/connector.go:181 [sql,tenant-connector] 439 error consuming GossipSubscription RPC: rpc error: code = Canceled desc = context canceled
W210912 05:47:36.030559 14424 ccl/kvccl/kvtenantccl/connector.go:181 [sql,tenant-connector] 440 error consuming GossipSubscription RPC: rpc error: code = Unavailable desc = error reading from server: read tcp 127.0.0.1:44424->127.0.0.1:41637: use of closed network connection
W210912 05:47:36.031362 12203 sql/sqlliveness/slinstance/slinstance.go:217 [-] 441 exiting heartbeat loop
I210912 05:47:36.040132 9792 testutils/testcluster/testcluster.go:101 [-] 442 TestCluster quiescing nodes
I210912 05:47:36.041103 10143 kv/kvclient/kvcoord/transport_race.go:106 [-] 443 transport race promotion: ran 72 iterations on up to 1769 requests
W210912 05:47:36.042648 11820 jobs/registry.go:822 [-] 444 canceling all adopted jobs due to stopper quiescing
W210912 05:47:36.045222 11463 jobs/registry.go:822 [-] 445 canceling all adopted jobs due to stopper quiescing
W210912 05:47:36.045371 10042 sql/sqlliveness/slinstance/slinstance.go:217 [n1] 446 exiting heartbeat loop
W210912 05:47:36.048282 10375 jobs/registry.go:822 [-] 447 canceling all adopted jobs due to stopper quiescing
W210912 05:47:36.055121 11781 sql/sqlliveness/slinstance/slinstance.go:217 [n3] 448 exiting heartbeat loop
W210912 05:47:36.055688 11383 sql/sqlliveness/slinstance/slinstance.go:217 [n2] 449 exiting heartbeat loop
W210912 05:47:36.059941 11863 ts/db.go:194 [n3,ts-poll] 450 error writing time series data: failed to send RPC: sending to all replicas failed; last error: rpc error: code = Unavailable desc = error reading from server: read tcp 127.0.0.1:44392->127.0.0.1:41637: use of closed network connection
testing.go:1092: race detected during execution of test
--- FAIL: TestTenantTempTableCleanup (13.22s)Reproduce
To reproduce, try: ```bash make stressrace TESTS=TestTenantTempTableCleanup PKG=./pkg/ccl/testccl/sqlccl TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1 ``` Parameters in this failure: - GOFLAGS=-race -parallel=4
/cc @cockroachdb/sql-queries fqazi
jordanlewis
ajwerner
ccl/testccl/sqlccl.TestTenantTempTableCleanup failed with artifacts on master @ 941011c4e582807b40dd03bbcbb8d05385c0638d:
Reproduce
To reproduce, try: ```bash make stressrace TESTS=TestTenantTempTableCleanup PKG=./pkg/ccl/testccl/sqlccl TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1 ``` Parameters in this failure: - GOFLAGS=-race -parallel=4
/cc @cockroachdb/sql-queries fqazi
This test on roachdash | Improve this report!