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.

Sign up for GitHub

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

Jump to bottom

teamcity: failed tests on master: testrace/TestChangefeedRetryableSinkError #30156

Closed
cockroach-teamcity opened this issue Sep 12, 2018 · 0 comments
Closed

teamcity: failed tests on master: testrace/TestChangefeedRetryableSinkError #30156

cockroach-teamcity opened this issue Sep 12, 2018 · 0 comments
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Milestone
19.1

Comments

@cockroach-teamcity
Copy link
Member

The following tests appear to have failed:

#900906:

--- FAIL: testrace/TestChangefeedRetryableSinkError (64.000s)
soon.go:49: condition failed to evaluate within 45s: insufficient sink error retries detected
	goroutine 10327 [running]:
	runtime/debug.Stack(0xa7a358200, 0xc42113a7b0, 0x3df1060)
		/usr/local/go/src/runtime/debug/stack.go:24 +0xb5
	github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x3e51020, 0xc420fda000, 0xc421348970)
		/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:50 +0x172
	github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.TestChangefeedRetryableSinkError(0xc420fda000)
		/go/src/github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl/changefeed_test.go:811 +0xc79
	testing.tRunner(0xc420fda000, 0x3776a78)
		/usr/local/go/src/testing/testing.go:777 +0x16e
	created by testing.(*T).Run
		/usr/local/go/src/testing/testing.go:824 +0x565
------- Stdout: -------
W180912 20:51:31.827471 10327 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180912 20:51:31.892581 10327 server/server.go:851  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180912 20:51:31.893198 10327 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180912 20:51:31.893314 10327 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180912 20:51:31.909923 10327 server/config.go:493  [n?] 1 storage engine initialized
I180912 20:51:31.910021 10327 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180912 20:51:31.910106 10327 server/config.go:496  [n?] store 0: in-memory, size 0 B
I180912 20:51:32.007639 10327 server/node.go:374  [n?] **** cluster 359c7256-655c-49e8-9c02-562fddb56001 has been created
I180912 20:51:32.007761 10327 server/server.go:1413  [n?] **** add additional nodes by specifying --join=127.0.0.1:45131
I180912 20:51:32.008822 10327 gossip/gossip.go:408  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:45131" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-766-g15d3e26" started_at:1536785492008440834 
I180912 20:51:32.012717 10282 gossip/gossip.go:942  [n1] gossip connectivity
 
I180912 20:51:32.027565 10327 server/node.go:477  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=6.9 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7103.00 p25=7103.00 p50=7103.00 p75=7103.00 p90=7103.00 pMax=7103.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00}
I180912 20:51:32.027959 10327 storage/stores.go:242  [n1] read 0 node addresses from persistent storage
I180912 20:51:32.028414 10327 server/node.go:700  [n1] connecting to gossip network to verify cluster ID...
I180912 20:51:32.033230 10327 server/node.go:725  [n1] node connected via gossip and verified as part of cluster "359c7256-655c-49e8-9c02-562fddb56001"
I180912 20:51:32.033701 10327 server/node.go:549  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180912 20:51:32.035579 10327 server/status/recorder.go:611  [n1] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180912 20:51:32.035691 10327 server/server.go:1804  [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180912 20:51:32.037387 10327 server/server.go:1550  [n1] starting https server at 127.0.0.1:44463 (use: 127.0.0.1:44463)
I180912 20:51:32.037503 10327 server/server.go:1552  [n1] starting grpc/postgres server at 127.0.0.1:45131
I180912 20:51:32.037565 10327 server/server.go:1553  [n1] advertising CockroachDB node at 127.0.0.1:45131
I180912 20:51:32.102998 10350 storage/replica_command.go:298  [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I180912 20:51:32.587680 10612 storage/replica_command.go:298  [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3]
I180912 20:51:32.753287 10470 storage/replica_command.go:298  [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4]
W180912 20:51:32.777850 10629 storage/intent_resolver.go:668  [n1,s1] failed to push during intent resolution: failed to push "unnamed" id=b631befd key=/Table/SystemConfigSpan/Start rw=true pri=0.22361930 iso=SERIALIZABLE stat=PENDING epo=0 ts=1536785492.201389574,0 orig=1536785492.201389574,0 max=1536785492.201389574,0 wto=false rop=false seq=6
I180912 20:51:32.840119 10626 sql/event_log.go:126  [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root}
I180912 20:51:32.961623 10599 storage/replica_command.go:298  [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5]
I180912 20:51:33.190506 10476 rpc/nodedialer/nodedialer.go:92  [n1,consistencyChecker,s1,r1/1:/{Min-System/}] connection to n1 established
I180912 20:51:33.227324 10620 storage/replica_command.go:298  [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6]
I180912 20:51:33.249301 10589 sql/event_log.go:126  [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.0-13 User:root}
I180912 20:51:33.422932 10607 storage/replica_command.go:298  [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7]
I180912 20:51:33.444636 10642 sql/event_log.go:126  [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root}
I180912 20:51:33.557049 10460 storage/replica_command.go:298  [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8]
I180912 20:51:33.619177 10655 storage/replica_command.go:298  [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9]
I180912 20:51:33.683991 10653 sql/event_log.go:126  [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:eeeae5ad-6eed-4292-a8d7-09f1113a4ade User:root}
I180912 20:51:33.728620 10709 storage/replica_command.go:298  [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10]
I180912 20:51:33.810273 10669 storage/replica_command.go:298  [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11]
I180912 20:51:33.824489 10738 sql/event_log.go:126  [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root}
I180912 20:51:33.874249 10746 storage/replica_command.go:298  [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12]
I180912 20:51:33.905407 10671 sql/event_log.go:126  [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}
I180912 20:51:33.919013 10282 gossip/gossip.go:942  [n1] gossip connectivity
  n1 [sentinel];
 
I180912 20:51:33.945303 10327 server/server.go:1606  [n1] done ensuring all necessary migrations have run
I180912 20:51:33.945452 10327 server/server.go:1609  [n1] serving sql connections
I180912 20:51:33.969818 10678 sql/event_log.go:126  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:45131} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-766-g15d3e26 StartedAt:1536785492008440834 LocalityAddress:[]} ClusterID:359c7256-655c-49e8-9c02-562fddb56001 StartedAt:1536785492008440834 LastUp:1536785492008440834}
I180912 20:51:33.974131 10676 server/server_update.go:67  [n1] no need to upgrade, cluster already at the newest version
I180912 20:51:33.977915 10327 server/testserver.go:420  had 11 ranges at startup, expected 22
I180912 20:51:33.987121 10327 server/testserver.go:420  had 11 ranges at startup, expected 22
I180912 20:51:33.989030 10327 server/testserver.go:420  had 11 ranges at startup, expected 22
I180912 20:51:34.014125 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.014172 10681 storage/replica_command.go:298  [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13]
I180912 20:51:34.020912 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.023170 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.023912 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.024680 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.025344 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.026050 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.026715 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.027346 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.033103 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.033903 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.034642 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.035305 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.036040 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.036763 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.037636 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.038593 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.040066 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.050138 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.091625 10770 storage/replica_command.go:298  [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14]
I180912 20:51:34.101568 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.106782 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.116473 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.139700 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.181078 10774 storage/replica_command.go:298  [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15]
I180912 20:51:34.190610 10327 server/testserver.go:420  had 14 ranges at startup, expected 22
I180912 20:51:34.235414 10721 storage/replica_command.go:298  [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16]
I180912 20:51:34.258827 10327 server/testserver.go:420  had 15 ranges at startup, expected 22
I180912 20:51:34.311290 10779 storage/replica_command.go:298  [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17]
I180912 20:51:34.381852 10837 storage/replica_command.go:298  [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18]
I180912 20:51:34.396055 10327 server/testserver.go:420  had 17 ranges at startup, expected 22
I180912 20:51:34.463280 10795 storage/replica_command.go:298  [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19]
I180912 20:51:34.522407 10766 storage/replica_command.go:298  [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20]
I180912 20:51:34.574728 10769 storage/replica_command.go:298  [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21]
I180912 20:51:34.627716 10852 storage/replica_command.go:298  [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22]
I180912 20:51:34.666793 10327 server/testserver.go:420  had 21 ranges at startup, expected 22
I180912 20:51:35.405953 10751 storage/replica_command.go:298  [n1,split,s1,r22/1:/{Table/51-Max}] initiating a split of this range at key /Table/52 [r23]
I180912 20:51:35.407866 10826 sql/event_log.go:126  [n1,client=127.0.0.1:55330,user=root] Event: "create_database", target: 52, info: {DatabaseName:d Statement:CREATE DATABASE d User:root}
I180912 20:51:35.492107 10826 sql/event_log.go:126  [n1,client=127.0.0.1:55330,user=root] Event: "create_table", target: 53, info: {TableName:d.public.foo Statement:CREATE TABLE foo (a INT PRIMARY KEY, b STRING) User:root}
I180912 20:51:35.493482 10932 storage/replica_command.go:298  [n1,split,s1,r23/1:/{Table/52-Max}] initiating a split of this range at key /Table/53 [r24]
I180912 20:51:41.057453 10523 storage/replica_proposal.go:211  [n1,s1,r14/1:/Table/1{7-8}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785501.054499066,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:42.051636 10573 server/status/runtime.go:484  [n1] runtime stats: 460 MiB RSS, 203 goroutines, 13 MiB/16 MiB/43 MiB GO alloc/idle/total, 33 MiB/68 MiB CGO alloc/total, 0.0 CGO/sec, 0.0/0.0 %(u/s)time, 0.0 %gc (121x), 0.0/0.0/0 (%r/%w/q)disk, 1.6 MiB/1.6 MiB (r/w)net
I180912 20:51:42.060853 10532 storage/replica_proposal.go:211  [n1,s1,r7/1:/Table/{SystemCon…-11}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785502.056298135,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:42.853218 10538 storage/replica_proposal.go:211  [n1,s1,r4/1:/System/{NodeLive…-tsd}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785502.849853828,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.246782 10529 storage/replica_proposal.go:211  [n1,s1,r9/1:/Table/1{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.219704828,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.273868 10982 sql/event_log.go:126  [n1,client=127.0.0.1:55348,user=sinkuser] Event: "create_table", target: 54, info: {TableName:d.public.sqlsink Statement:CREATE TABLE IF NOT EXISTS sqlsink (topic STRING, partition INT, message_id INT, key BYTES, value BYTES, resolved BYTES, PRIMARY KEY (topic, partition, message_id)) User:sinkuser}
I180912 20:51:43.274067 10287 storage/replica_proposal.go:211  [n1,s1,r24/1:/{Table/53-Max}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.270875090,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.276026 10879 storage/replica_command.go:298  [n1,split,s1,r24/1:/{Table/53-Max}] initiating a split of this range at key /Table/54 [r25]
I180912 20:51:43.280405 10486 storage/replica_proposal.go:211  [n1,s1,r23/1:/Table/5{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.277424799,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.310675 10483 storage/replica_proposal.go:211  [n1,s1,r10/1:/Table/1{3-4}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.307586928,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.505177 10506 storage/replica_proposal.go:211  [n1,s1,r5/1:/System/ts{d-e}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.501766438,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:44.064423 10513 storage/replica_proposal.go:211  [n1,s1,r13/1:/Table/1{6-7}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785504.061376850,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:46.067176 10517 storage/replica_proposal.go:211  [n1,s1,r19/1:/Table/2{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785506.064017977,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:48.083916 10530 storage/replica_proposal.go:211  [n1,s1,r8/1:/Table/1{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785508.080631803,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:50.088570 10512 storage/replica_proposal.go:211  [n1,s1,r17/1:/Table/2{0-1}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785510.085533823,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:51.126347 11041 storage/replica_consistency.go:117  [n1,consistencyChecker,s1,r5/1:/System/ts{d-e}] triggering stats recomputation to resolve delta of {ContainsEstimates:true LastUpdateNanos:1536785503457261151 IntentAge:0 GCBytesAge:0 LiveBytes:18696 LiveCount:0 KeyBytes:0 KeyCount:0 ValBytes:18696 ValCount:0 IntentBytes:0 IntentCount:0 SysBytes:0 SysCount:0}
I180912 20:51:52.069637 10573 server/status/runtime.go:484  [n1] runtime stats: 461 MiB RSS, 202 goroutines, 15 MiB/13 MiB/43 MiB GO alloc/idle/total, 33 MiB/70 MiB CGO alloc/total, 378.9 CGO/sec, 63.7/0.5 %(u/s)time, 0.1 %gc (3x), 0.6/471.1/10 (%r/%w/q)disk, 3.3 MiB/3.3 MiB (r/w)net
I180912 20:51:52.091658 10524 storage/replica_proposal.go:211  [n1,s1,r18/1:/Table/2{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785512.088404598,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:52.929562 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:53.092761 10523 storage/replica_proposal.go:211  [n1,s1,r22/1:/Table/5{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785513.089756922,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:53.966795 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:54.967189 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:55.096115 10529 storage/replica_proposal.go:211  [n1,s1,r15/1:/Table/1{8-9}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785515.092902871,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:55.967595 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:56.099963 10288 storage/replica_proposal.go:211  [n1,s1,r16/1:/Table/{19-20}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785516.095055502,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:56.967956 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:57.099703 10484 storage/replica_proposal.go:211  [n1,s1,r12/1:/Table/1{5-6}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785517.096500543,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:57.429783 10963 ccl/changefeedccl/changefeed_stmt.go:382  [n1] CHANGEFEED job 382452036108386305 encountered retryable error: synthetic retryable error
I180912 20:51:57.968390 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:58.968762 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:59.102886 10496 storage/replica_proposal.go:211  [n1,s1,r6/1:/{System/tse-Table/System…}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785519.099170889,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:59.969168 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:00.969521 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:01.105734 10501 storage/replica_proposal.go:211  [n1,s1,r21/1:/Table/5{0-1}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785521.102596892,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:52:01.969861 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:02.106598 10573 server/status/runtime.go:484  [n1] runtime stats: 463 MiB RSS, 203 goroutines, 14 MiB/15 MiB/43 MiB GO alloc/idle/total, 34 MiB/70 MiB CGO alloc/total, 143.1 CGO/sec, 67.6/0.3 %(u/s)time, 0.9 %gc (3x), 0.0/286.9/0 (%r/%w/q)disk, 2.6 MiB/2.6 MiB (r/w)net
I180912 20:52:02.973377 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:03.973765 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:04.974243 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:05.974596 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:06.975503 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:07.975896 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:08.976275 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:09.976656 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:10.977980 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:11.978763 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:12.117494 10573 server/status/runtime.go:484  [n1] runtime stats: 464 MiB RSS, 204 goroutines, 13 MiB/16 MiB/43 MiB GO alloc/idle/total, 34 MiB/70 MiB CGO alloc/total, 29.8 CGO/sec, 52.9/0.2 %(u/s)time, 0.2 %gc (2x), 1.0/733.2/0 (%r/%w/q)disk, 3.6 MiB/3.6 MiB (r/w)net
I180912 20:52:12.979099 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:13.979502 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:14.979873 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:15.980240 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:16.980605 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:17.446672 10963 ccl/changefeedccl/changefeed_stmt.go:382  [n1] CHANGEFEED job 382452036108386305 encountered retryable error: synthetic retryable error
I180912 20:52:17.981491 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:18.981904 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:19.982270 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:20.982619 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:21.982974 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:22.138476 10573 server/status/runtime.go:484  [n1] runtime stats: 466 MiB RSS, 204 goroutines, 20 MiB/9.3 MiB/43 MiB GO alloc/idle/total, 35 MiB/71 MiB CGO alloc/total, 72.4 CGO/sec, 60.0/0.3 %(u/s)time, 0.1 %gc (2x), 16.5/18.0/0 (%r/%w/q)disk, 3.5 MiB/3.5 MiB (r/w)net
I180912 20:52:22.983323 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:23.983977 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:24.984363 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:25.984693 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:26.985063 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:27.985447 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:28.985838 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:29.986217 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:30.986636 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:31.987001 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:32.035149 10569 gossip/gossip.go:564  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
gossip connectivity
  n1 [sentinel];
 
I180912 20:52:32.160343 10573 server/status/runtime.go:484  [n1] runtime stats: 467 MiB RSS, 211 goroutines, 16 MiB/14 MiB/43 MiB GO alloc/idle/total, 36 MiB/71 MiB CGO alloc/total, 44.7 CGO/sec, 60.4/0.4 %(u/s)time, 0.7 %gc (3x), 0.0/18.7/0 (%r/%w/q)disk, 3.9 MiB/3.9 MiB (r/w)net
I180912 20:52:32.987363 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:33.987772 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:34.989609 10327 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
1      [async] closedts-rangefeed-subscriber
I180912 20:52:34.992222 10327 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
W180912 20:52:35.029099 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
W180912 20:52:35.084510 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
W180912 20:52:35.188222 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
W180912 20:52:35.359784 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
I180912 20:52:35.685454 10611 kv/transport_race.go:91  transport race promotion: ran 51 iterations on up to 1480 requests
--- FAIL: testrace/TestChangefeedRetryableSinkError (68.120s)
soon.go:49: condition failed to evaluate within 45s: insufficient sink error retries detected
	goroutine 10327 [running]:
	runtime/debug.Stack(0xa7a358200, 0xc42113a7b0, 0x3df1060)
		/usr/local/go/src/runtime/debug/stack.go:24 +0xb5
	github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x3e51020, 0xc420fda000, 0xc421348970)
		/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:50 +0x172
	github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl.TestChangefeedRetryableSinkError(0xc420fda000)
		/go/src/github.com/cockroachdb/cockroach/pkg/ccl/changefeedccl/changefeed_test.go:811 +0xc79
	testing.tRunner(0xc420fda000, 0x3776a78)
		/usr/local/go/src/testing/testing.go:777 +0x16e
	created by testing.(*T).Run
		/usr/local/go/src/testing/testing.go:824 +0x565
------- Stdout: -------
W180912 20:51:31.827471 10327 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180912 20:51:31.892581 10327 server/server.go:851  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180912 20:51:31.893198 10327 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180912 20:51:31.893314 10327 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180912 20:51:31.909923 10327 server/config.go:493  [n?] 1 storage engine initialized
I180912 20:51:31.910021 10327 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180912 20:51:31.910106 10327 server/config.go:496  [n?] store 0: in-memory, size 0 B
I180912 20:51:32.007639 10327 server/node.go:374  [n?] **** cluster 359c7256-655c-49e8-9c02-562fddb56001 has been created
I180912 20:51:32.007761 10327 server/server.go:1413  [n?] **** add additional nodes by specifying --join=127.0.0.1:45131
I180912 20:51:32.008822 10327 gossip/gossip.go:408  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:45131" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-766-g15d3e26" started_at:1536785492008440834 
I180912 20:51:32.012717 10282 gossip/gossip.go:942  [n1] gossip connectivity
 
I180912 20:51:32.027565 10327 server/node.go:477  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=6.9 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7103.00 p25=7103.00 p50=7103.00 p75=7103.00 p90=7103.00 pMax=7103.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00}
I180912 20:51:32.027959 10327 storage/stores.go:242  [n1] read 0 node addresses from persistent storage
I180912 20:51:32.028414 10327 server/node.go:700  [n1] connecting to gossip network to verify cluster ID...
I180912 20:51:32.033230 10327 server/node.go:725  [n1] node connected via gossip and verified as part of cluster "359c7256-655c-49e8-9c02-562fddb56001"
I180912 20:51:32.033701 10327 server/node.go:549  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180912 20:51:32.035579 10327 server/status/recorder.go:611  [n1] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180912 20:51:32.035691 10327 server/server.go:1804  [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180912 20:51:32.037387 10327 server/server.go:1550  [n1] starting https server at 127.0.0.1:44463 (use: 127.0.0.1:44463)
I180912 20:51:32.037503 10327 server/server.go:1552  [n1] starting grpc/postgres server at 127.0.0.1:45131
I180912 20:51:32.037565 10327 server/server.go:1553  [n1] advertising CockroachDB node at 127.0.0.1:45131
I180912 20:51:32.102998 10350 storage/replica_command.go:298  [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I180912 20:51:32.587680 10612 storage/replica_command.go:298  [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3]
I180912 20:51:32.753287 10470 storage/replica_command.go:298  [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4]
W180912 20:51:32.777850 10629 storage/intent_resolver.go:668  [n1,s1] failed to push during intent resolution: failed to push "unnamed" id=b631befd key=/Table/SystemConfigSpan/Start rw=true pri=0.22361930 iso=SERIALIZABLE stat=PENDING epo=0 ts=1536785492.201389574,0 orig=1536785492.201389574,0 max=1536785492.201389574,0 wto=false rop=false seq=6
I180912 20:51:32.840119 10626 sql/event_log.go:126  [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root}
I180912 20:51:32.961623 10599 storage/replica_command.go:298  [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5]
I180912 20:51:33.190506 10476 rpc/nodedialer/nodedialer.go:92  [n1,consistencyChecker,s1,r1/1:/{Min-System/}] connection to n1 established
I180912 20:51:33.227324 10620 storage/replica_command.go:298  [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6]
I180912 20:51:33.249301 10589 sql/event_log.go:126  [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.0-13 User:root}
I180912 20:51:33.422932 10607 storage/replica_command.go:298  [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7]
I180912 20:51:33.444636 10642 sql/event_log.go:126  [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root}
I180912 20:51:33.557049 10460 storage/replica_command.go:298  [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8]
I180912 20:51:33.619177 10655 storage/replica_command.go:298  [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9]
I180912 20:51:33.683991 10653 sql/event_log.go:126  [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:eeeae5ad-6eed-4292-a8d7-09f1113a4ade User:root}
I180912 20:51:33.728620 10709 storage/replica_command.go:298  [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10]
I180912 20:51:33.810273 10669 storage/replica_command.go:298  [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11]
I180912 20:51:33.824489 10738 sql/event_log.go:126  [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root}
I180912 20:51:33.874249 10746 storage/replica_command.go:298  [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12]
I180912 20:51:33.905407 10671 sql/event_log.go:126  [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}
I180912 20:51:33.919013 10282 gossip/gossip.go:942  [n1] gossip connectivity
  n1 [sentinel];
 
I180912 20:51:33.945303 10327 server/server.go:1606  [n1] done ensuring all necessary migrations have run
I180912 20:51:33.945452 10327 server/server.go:1609  [n1] serving sql connections
I180912 20:51:33.969818 10678 sql/event_log.go:126  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:45131} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-766-g15d3e26 StartedAt:1536785492008440834 LocalityAddress:[]} ClusterID:359c7256-655c-49e8-9c02-562fddb56001 StartedAt:1536785492008440834 LastUp:1536785492008440834}
I180912 20:51:33.974131 10676 server/server_update.go:67  [n1] no need to upgrade, cluster already at the newest version
I180912 20:51:33.977915 10327 server/testserver.go:420  had 11 ranges at startup, expected 22
I180912 20:51:33.987121 10327 server/testserver.go:420  had 11 ranges at startup, expected 22
I180912 20:51:33.989030 10327 server/testserver.go:420  had 11 ranges at startup, expected 22
I180912 20:51:34.014125 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.014172 10681 storage/replica_command.go:298  [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13]
I180912 20:51:34.020912 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.023170 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.023912 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.024680 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.025344 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.026050 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.026715 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.027346 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.033103 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.033903 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.034642 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.035305 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.036040 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.036763 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.037636 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.038593 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.040066 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.050138 10327 server/testserver.go:420  had 12 ranges at startup, expected 22
I180912 20:51:34.091625 10770 storage/replica_command.go:298  [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14]
I180912 20:51:34.101568 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.106782 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.116473 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.139700 10327 server/testserver.go:420  had 13 ranges at startup, expected 22
I180912 20:51:34.181078 10774 storage/replica_command.go:298  [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15]
I180912 20:51:34.190610 10327 server/testserver.go:420  had 14 ranges at startup, expected 22
I180912 20:51:34.235414 10721 storage/replica_command.go:298  [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16]
I180912 20:51:34.258827 10327 server/testserver.go:420  had 15 ranges at startup, expected 22
I180912 20:51:34.311290 10779 storage/replica_command.go:298  [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17]
I180912 20:51:34.381852 10837 storage/replica_command.go:298  [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18]
I180912 20:51:34.396055 10327 server/testserver.go:420  had 17 ranges at startup, expected 22
I180912 20:51:34.463280 10795 storage/replica_command.go:298  [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19]
I180912 20:51:34.522407 10766 storage/replica_command.go:298  [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20]
I180912 20:51:34.574728 10769 storage/replica_command.go:298  [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21]
I180912 20:51:34.627716 10852 storage/replica_command.go:298  [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22]
I180912 20:51:34.666793 10327 server/testserver.go:420  had 21 ranges at startup, expected 22
I180912 20:51:35.405953 10751 storage/replica_command.go:298  [n1,split,s1,r22/1:/{Table/51-Max}] initiating a split of this range at key /Table/52 [r23]
I180912 20:51:35.407866 10826 sql/event_log.go:126  [n1,client=127.0.0.1:55330,user=root] Event: "create_database", target: 52, info: {DatabaseName:d Statement:CREATE DATABASE d User:root}
I180912 20:51:35.492107 10826 sql/event_log.go:126  [n1,client=127.0.0.1:55330,user=root] Event: "create_table", target: 53, info: {TableName:d.public.foo Statement:CREATE TABLE foo (a INT PRIMARY KEY, b STRING) User:root}
I180912 20:51:35.493482 10932 storage/replica_command.go:298  [n1,split,s1,r23/1:/{Table/52-Max}] initiating a split of this range at key /Table/53 [r24]
I180912 20:51:41.057453 10523 storage/replica_proposal.go:211  [n1,s1,r14/1:/Table/1{7-8}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785501.054499066,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:42.051636 10573 server/status/runtime.go:484  [n1] runtime stats: 460 MiB RSS, 203 goroutines, 13 MiB/16 MiB/43 MiB GO alloc/idle/total, 33 MiB/68 MiB CGO alloc/total, 0.0 CGO/sec, 0.0/0.0 %(u/s)time, 0.0 %gc (121x), 0.0/0.0/0 (%r/%w/q)disk, 1.6 MiB/1.6 MiB (r/w)net
I180912 20:51:42.060853 10532 storage/replica_proposal.go:211  [n1,s1,r7/1:/Table/{SystemCon…-11}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785502.056298135,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:42.853218 10538 storage/replica_proposal.go:211  [n1,s1,r4/1:/System/{NodeLive…-tsd}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785502.849853828,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.246782 10529 storage/replica_proposal.go:211  [n1,s1,r9/1:/Table/1{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.219704828,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.273868 10982 sql/event_log.go:126  [n1,client=127.0.0.1:55348,user=sinkuser] Event: "create_table", target: 54, info: {TableName:d.public.sqlsink Statement:CREATE TABLE IF NOT EXISTS sqlsink (topic STRING, partition INT, message_id INT, key BYTES, value BYTES, resolved BYTES, PRIMARY KEY (topic, partition, message_id)) User:sinkuser}
I180912 20:51:43.274067 10287 storage/replica_proposal.go:211  [n1,s1,r24/1:/{Table/53-Max}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.270875090,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.276026 10879 storage/replica_command.go:298  [n1,split,s1,r24/1:/{Table/53-Max}] initiating a split of this range at key /Table/54 [r25]
I180912 20:51:43.280405 10486 storage/replica_proposal.go:211  [n1,s1,r23/1:/Table/5{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.277424799,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.310675 10483 storage/replica_proposal.go:211  [n1,s1,r10/1:/Table/1{3-4}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.307586928,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:43.505177 10506 storage/replica_proposal.go:211  [n1,s1,r5/1:/System/ts{d-e}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785503.501766438,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:44.064423 10513 storage/replica_proposal.go:211  [n1,s1,r13/1:/Table/1{6-7}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785504.061376850,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:46.067176 10517 storage/replica_proposal.go:211  [n1,s1,r19/1:/Table/2{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785506.064017977,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:48.083916 10530 storage/replica_proposal.go:211  [n1,s1,r8/1:/Table/1{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785508.080631803,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:50.088570 10512 storage/replica_proposal.go:211  [n1,s1,r17/1:/Table/2{0-1}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785510.085533823,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:51.126347 11041 storage/replica_consistency.go:117  [n1,consistencyChecker,s1,r5/1:/System/ts{d-e}] triggering stats recomputation to resolve delta of {ContainsEstimates:true LastUpdateNanos:1536785503457261151 IntentAge:0 GCBytesAge:0 LiveBytes:18696 LiveCount:0 KeyBytes:0 KeyCount:0 ValBytes:18696 ValCount:0 IntentBytes:0 IntentCount:0 SysBytes:0 SysCount:0}
I180912 20:51:52.069637 10573 server/status/runtime.go:484  [n1] runtime stats: 461 MiB RSS, 202 goroutines, 15 MiB/13 MiB/43 MiB GO alloc/idle/total, 33 MiB/70 MiB CGO alloc/total, 378.9 CGO/sec, 63.7/0.5 %(u/s)time, 0.1 %gc (3x), 0.6/471.1/10 (%r/%w/q)disk, 3.3 MiB/3.3 MiB (r/w)net
I180912 20:51:52.091658 10524 storage/replica_proposal.go:211  [n1,s1,r18/1:/Table/2{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785512.088404598,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:52.929562 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:53.092761 10523 storage/replica_proposal.go:211  [n1,s1,r22/1:/Table/5{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785513.089756922,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:53.966795 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:54.967189 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:55.096115 10529 storage/replica_proposal.go:211  [n1,s1,r15/1:/Table/1{8-9}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785515.092902871,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:55.967595 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:56.099963 10288 storage/replica_proposal.go:211  [n1,s1,r16/1:/Table/{19-20}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785516.095055502,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:56.967956 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:57.099703 10484 storage/replica_proposal.go:211  [n1,s1,r12/1:/Table/1{5-6}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785517.096500543,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:57.429783 10963 ccl/changefeedccl/changefeed_stmt.go:382  [n1] CHANGEFEED job 382452036108386305 encountered retryable error: synthetic retryable error
I180912 20:51:57.968390 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:58.968762 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:51:59.102886 10496 storage/replica_proposal.go:211  [n1,s1,r6/1:/{System/tse-Table/System…}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785519.099170889,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:51:59.969168 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:00.969521 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:01.105734 10501 storage/replica_proposal.go:211  [n1,s1,r21/1:/Table/5{0-1}] new range lease repl=(n1,s1):1 seq=3 start=1536785492.012736428,0 epo=1 pro=1536785521.102596892,0 following repl=(n1,s1):1 seq=2 start=1536785492.012736428,0 exp=1536785501.028892111,0 pro=1536785492.028929279,0
I180912 20:52:01.969861 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:02.106598 10573 server/status/runtime.go:484  [n1] runtime stats: 463 MiB RSS, 203 goroutines, 14 MiB/15 MiB/43 MiB GO alloc/idle/total, 34 MiB/70 MiB CGO alloc/total, 143.1 CGO/sec, 67.6/0.3 %(u/s)time, 0.9 %gc (3x), 0.0/286.9/0 (%r/%w/q)disk, 2.6 MiB/2.6 MiB (r/w)net
I180912 20:52:02.973377 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:03.973765 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:04.974243 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:05.974596 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:06.975503 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:07.975896 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:08.976275 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:09.976656 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:10.977980 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:11.978763 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:12.117494 10573 server/status/runtime.go:484  [n1] runtime stats: 464 MiB RSS, 204 goroutines, 13 MiB/16 MiB/43 MiB GO alloc/idle/total, 34 MiB/70 MiB CGO alloc/total, 29.8 CGO/sec, 52.9/0.2 %(u/s)time, 0.2 %gc (2x), 1.0/733.2/0 (%r/%w/q)disk, 3.6 MiB/3.6 MiB (r/w)net
I180912 20:52:12.979099 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:13.979502 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:14.979873 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:15.980240 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:16.980605 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:17.446672 10963 ccl/changefeedccl/changefeed_stmt.go:382  [n1] CHANGEFEED job 382452036108386305 encountered retryable error: synthetic retryable error
I180912 20:52:17.981491 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:18.981904 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:19.982270 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:20.982619 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:21.982974 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:22.138476 10573 server/status/runtime.go:484  [n1] runtime stats: 466 MiB RSS, 204 goroutines, 20 MiB/9.3 MiB/43 MiB GO alloc/idle/total, 35 MiB/71 MiB CGO alloc/total, 72.4 CGO/sec, 60.0/0.3 %(u/s)time, 0.1 %gc (2x), 16.5/18.0/0 (%r/%w/q)disk, 3.5 MiB/3.5 MiB (r/w)net
I180912 20:52:22.983323 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:23.983977 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:24.984363 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:25.984693 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:26.985063 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:27.985447 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:28.985838 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:29.986217 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:30.986636 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:31.987001 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:32.035149 10569 gossip/gossip.go:564  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
gossip connectivity
  n1 [sentinel];
 
I180912 20:52:32.160343 10573 server/status/runtime.go:484  [n1] runtime stats: 467 MiB RSS, 211 goroutines, 16 MiB/14 MiB/43 MiB GO alloc/idle/total, 36 MiB/71 MiB CGO alloc/total, 44.7 CGO/sec, 60.4/0.4 %(u/s)time, 0.7 %gc (3x), 0.0/18.7/0 (%r/%w/q)disk, 3.9 MiB/3.9 MiB (r/w)net
I180912 20:52:32.987363 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:33.987772 10327 ccl/changefeedccl/changefeed_test.go:811  SucceedsSoon: insufficient sink error retries detected
I180912 20:52:34.989609 10327 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
1      [async] closedts-rangefeed-subscriber
I180912 20:52:34.992222 10327 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
W180912 20:52:35.029099 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
W180912 20:52:35.084510 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
W180912 20:52:35.188222 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
W180912 20:52:35.359784 10544 storage/store.go:1659  [n1,s1,r1/1:/{Min-System/}] could not gossip first range descriptor: node unavailable; try another peer
I180912 20:52:35.685454 10611 kv/transport_race.go:91  transport race promotion: ran 51 iterations on up to 1480 requests
------- Stdout: -------
W180912 20:48:37.461768 12106 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180912 20:48:37.472384 12106 server/server.go:851  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180912 20:48:37.472531 12106 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180912 20:48:37.472552 12106 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180912 20:48:37.475166 12106 server/config.go:493  [n?] 1 storage engine initialized
I180912 20:48:37.475236 12106 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180912 20:48:37.475251 12106 server/config.go:496  [n?] store 0: in-memory, size 0 B
I180912 20:48:37.491428 12106 util/stop/stopper.go:537  [n?] quiescing; tasks left:
1      [async] closedts-rangefeed-subscriber
I180912 20:48:37.491792 12106 server/node.go:374  [n?] **** cluster 1189feca-1c0b-4414-a838-1afccf59e18b has been created
I180912 20:48:37.491831 12106 server/server.go:1413  [n?] **** add additional nodes by specifying --join=127.0.0.1:34935
I180912 20:48:37.492014 12106 gossip/gossip.go:408  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:34935" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-766-g15d3e26" started_at:1536785317491950866 
I180912 20:48:37.493329 12106 server/node.go:477  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=6.9 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7103.00 p25=7103.00 p50=7103.00 p75=7103.00 p90=7103.00 pMax=7103.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00}
I180912 20:48:37.497150 12106 storage/stores.go:242  [n1] read 0 node addresses from persistent storage
I180912 20:48:37.493591 12174 gossip/gossip.go:942  [n1] gossip connectivity
 
I180912 20:48:37.497375 12106 server/node.go:700  [n1] connecting to gossip network to verify cluster ID...
I180912 20:48:37.497418 12106 server/node.go:725  [n1] node connected via gossip and verified as part of cluster "1189feca-1c0b-4414-a838-1afccf59e18b"
I180912 20:48:37.497465 12106 server/node.go:549  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180912 20:48:37.497894 12106 server/status/recorder.go:611  [n1] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB,

Please assign, take a look and update the issue accordingly.
@cockroach-teamcity cockroach-teamcity added this to the 2.2 milestone Sep 12, 2018
@cockroach-teamcity cockroach-teamcity added C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Sep 12, 2018
@benesch benesch mentioned this issue Sep 13, 2018
Merged
benesch added a commit to benesch/cockroach that referenced this issue Sep 13, 2018
@benesch
changefeedccl: deflake TestChangefeedRetryableSinkError
508a8ab 
TestChangefeedRetryableSinkError was performing many rounds of bcrypt,
which is excruciatingly slow when the race detector is on. Put its test
cluster into insecure mode to skip bcrypt hashing.

Fix cockroachdb#30156.
Fix cockroachdb#30161.

Release note: None
benesch added a commit to benesch/cockroach that referenced this issue Sep 13, 2018
@benesch
changefeedccl: deflake TestChangefeedRetryableSinkError
3d64d9f 
TestChangefeedRetryableSinkError was performing many rounds of bcrypt,
which is excruciatingly slow when the race detector is on. Put its test
cluster into insecure mode to skip bcrypt hashing.

Fix cockroachdb#30156.
Fix cockroachdb#30161.

Release note: None
craig bot pushed a commit that referenced this issue Sep 13, 2018
@benesch
Merge #30172
be9ff79 
30172: changefeedccl: deflake TestChangefeedRetryableSinkError r=nvanbenschoten,arjunravinarayan,mrtracy a=benesch

TestChangefeedRetryableSinkError was performing many rounds of bcrypt,
which is excruciatingly slow when the race detector is on. Put its test
cluster into insecure mode to skip bcrypt hashing.

Fix #30156.
Fix #30161.

Release note: None

Co-authored-by: Nikhil Benesch <nikhil.benesch@gmail.com>
@benesch benesch mentioned this issue Sep 13, 2018
Merged
@craig craig bot closed this as completed in #30172 Sep 13, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
19.1
Development

No branches or pull requests
1 participant
@cockroach-teamcity