cockroach-teamcity
commented
4 years ago (sql).TestTruncateWhileColumnBackfill failed on master@0046d62b00aa9e74489d1f44125948c9af729e2b:
I200115 03:44:01.375079 326194 storage/stores.go:240 [n1] read 0 node addresses from persistent storage
I200115 03:44:01.375776 326194 server/node.go:655 [n1] connecting to gossip network to verify cluster ID...
I200115 03:44:01.375839 326194 server/node.go:675 [n1] node connected via gossip and verified as part of cluster "be300262-d3e6-4f0c-8701-870bdd17e886"
I200115 03:44:01.376303 326194 server/node.go:522 [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I200115 03:44:01.376515 326194 server/server.go:2102 [n1] Could not start goroutine dumper worker due to: directory to store dumps could not be determined
I200115 03:44:01.382513 326194 server/server.go:1562 [n1] starting https server at 127.0.0.1:40075 (use: 127.0.0.1:40075)
I200115 03:44:01.382623 326194 server/server.go:1567 [n1] starting postgres server at 127.0.0.1:42119 (use: 127.0.0.1:42119)
I200115 03:44:01.382728 326194 server/server.go:1569 [n1] starting grpc server at 127.0.0.1:45755
I200115 03:44:01.382797 326194 server/server.go:1570 [n1] advertising CockroachDB node at 127.0.0.1:45755
I200115 03:44:01.436789 326369 sql/event_log.go:132 [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root}
I200115 03:44:01.445997 325891 sql/event_log.go:132 [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:19.2-9 User:root}
I200115 03:44:01.458608 326842 sql/event_log.go:132 [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:04f53849-3b39-42a7-8e8c-86d43536bb71 User:root}
I200115 03:44:01.466655 326316 sql/event_log.go:132 [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root}
I200115 03:44:01.472020 326830 sql/event_log.go:132 [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}
I200115 03:44:01.490564 326194 server/server.go:1626 [n1] done ensuring all necessary migrations have run
I200115 03:44:01.490618 326194 server/server.go:1907 [n1] serving sql connections
I200115 03:44:01.493405 327093 server/server_update.go:53 [n1] no need to upgrade, cluster already at the newest version
I200115 03:44:01.494001 327095 sql/event_log.go:132 [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:127.0.0.1:45755 Attrs: Locality: ServerVersion:19.2-9 BuildTag:v20.1.0-alpha.20191118-1249-g0046d62 StartedAt:1579059841367827468 LocalityAddress:[] ClusterName: SQLAddress:127.0.0.1:42119} ClusterID:be300262-d3e6-4f0c-8701-870bdd17e886 StartedAt:1579059841367827468 LastUp:1579059841367827468}
I200115 03:44:01.514194 326572 sql/event_log.go:132 [n1,client=127.0.0.1:36146,user=root] Event: "create_database", target: 52, info: {DatabaseName:t Statement:CREATE DATABASE t User:root}
I200115 03:44:01.527216 326572 sql/event_log.go:132 [n1,client=127.0.0.1:36146,user=root] Event: "create_table", target: 53, info: {TableName:t.public.test Statement:CREATE TABLE t.public.test (k INT8 PRIMARY KEY, v INT8) User:root}
I200115 03:44:01.529221 327070 storage/replica_command.go:406 [n1,split,s1,r28/1:/{Table/32-Max}] initiating a split of this range at key /Table/53 [r29] (zone config)
I200115 03:44:01.742780 326572 sql/sqlbase/structured.go:1475 [n1,client=127.0.0.1:36146,user=root] publish: descID=53 (test) version=2 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:01.749469 326572 sql/event_log.go:132 [n1,client=127.0.0.1:36146,user=root] Event: "alter_table", target: 53, info: {TableName:t.public.test Statement:ALTER TABLE t.public.test ADD COLUMN x DECIMAL NOT NULL DEFAULT 1.4::DECIMAL, ADD CHECK (x >= 0) User:root MutationID:1 CascadeDroppedViews:[]}
I200115 03:44:01.753782 327104 sql/lease.go:921 new lease: 53("test") ver=2:1579060146.798060490,0, refcount=0
I200115 03:44:01.763081 326572 sql/sqlbase/structured.go:1475 [n1,client=127.0.0.1:36146,user=root] publish: descID=53 (test) version=3 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:01.778626 326572 sql/sqlbase/structured.go:1475 [n1,client=127.0.0.1:36146,user=root] publish: descID=53 (test) version=3 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:01.808075 326572 sql/event_log.go:132 [n1,client=127.0.0.1:36146,user=root] Event: "alter_table", target: 53, info: {TableName:t.public.test Statement:ALTER TABLE t.public.test DROP COLUMN v User:root MutationID:2 CascadeDroppedViews:[]}
I200115 03:44:01.816211 326361 sql/lease.go:326 [n1,scExec] waiting for 1 leases to expire: desc=[{test 53 2}]
I200115 03:44:01.816715 327363 sql/lease.go:921 new lease: 53("test") ver=3:1579060146.799060490,0, refcount=0
I200115 03:44:01.870913 326361 sql/sqlbase/structured.go:1475 [n1,scExec] publish: descID=53 (test) version=4 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:01.878989 327511 sql/lease.go:921 new lease: 53("test") ver=4:1579060150.380369336,0, refcount=0
I200115 03:44:01.891343 326361 sql/backfill.go:143 [n1,scExec] Running backfill for "test", v=4, m=1
W200115 03:44:01.925111 326361 sql/schema_changer.go:2033 [n1] Error executing schema change: context deadline exceeded
I200115 03:44:01.938666 326572 sql/sqlbase/structured.go:1475 [n1,client=127.0.0.1:36146,user=root] publish: descID=53 (test) version=5 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:02.001273 326572 sql/sqlbase/structured.go:1475 [n1,client=127.0.0.1:36146,user=root] publish: descID=53 (test) version=5 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:02.047424 326572 sql/sqlbase/structured.go:1475 [n1,client=127.0.0.1:36146,user=root] publish: descID=53 (test) version=5 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:02.056506 326572 sql/event_log.go:132 [n1,client=127.0.0.1:36146,user=root] Event: "truncate_table", target: 53, info: {TableName:t.public.test Statement:TRUNCATE TABLE t.public.test User:root}
I200115 03:44:02.058469 327846 storage/replica_command.go:406 [n1,split,s1,r29/1:/{Table/53-Max}] initiating a split of this range at key /Table/54 [r30] (zone config)
I200115 03:44:02.079462 326361 sql/sqlbase/structured.go:1475 [n1,scExec] publish: descID=53 (test) version=6 mtime=1970-01-01 00:00:00 +0000 UTC
I200115 03:44:02.079680 326194 util/stop/stopper.go:539 quiescing
W200115 03:44:02.079952 326322 storage/intentresolver/intent_resolver.go:820 failed to gc transaction record: could not GC completed transaction anchored at /Table/SystemConfigSpan/Start: node unavailable; try another peer
W200115 03:44:02.081757 326361 sql/schema_changer.go:955 [n1,scExec] waiting to update leases: node unavailable; try another peer
W200115 03:44:02.081893 326361 sql/schema_changer.go:982 [n1,scExec] while reasing schema change lease: node unavailable; try another peer
W200115 03:44:02.081957 326361 sql/schema_changer.go:2033 [n1] Error executing schema change: node unavailable; try another peer
--- FAIL: TestTruncateWhileColumnBackfill (0.81s)
schema_changer_test.go:3662: job 0: expected status succeeded, got running
Failed to find issue assignee:
old friend vivekmenezes is friendless```
<details><summary>Repro</summary><p>
Parameters:
- GOFLAGS=-json
make stressrace TESTS=TestTruncateWhileColumnBackfill PKG=./pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1
<sub>powered by [pkg/cmd/internal/issues](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/internal/issues)</sub></p></details>
tbg
thoszhang
spaskob
otan
ajwerner
(sql).TestTruncateWhileColumnBackfill failed on master@c0c1013368c9a7bfefdfc1bf5d3d204bcfa769fc:
make stressrace TESTS=TestTruncateWhileColumnBackfill PKG=./pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1