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

grpcproxy: TestWatchStressResumeClose times out #7503

Closed
heyitsanthony opened this issue Mar 14, 2017 · 0 comments · Fixed by #7504
Closed

grpcproxy: TestWatchStressResumeClose times out #7503

heyitsanthony opened this issue Mar 14, 2017 · 0 comments · Fixed by #7504
Labels
area/testing

Comments

@heyitsanthony
Copy link
Contributor

via https://jenkins-etcd-public.prod.coreos.systems/job/etcd-proxy/975/consoleFull

=== RUN   TestWatchStressResumeClose
2017-03-14 18:09:25.791450 I | integration: launching 4175910651547592886 (unix://localhost:41759106515475928860)
2017-03-14 18:09:25.795659 I | etcdserver: name = 4175910651547592886
2017-03-14 18:09:25.795717 I | etcdserver: data dir = /tmp/etcd357449380
2017-03-14 18:09:25.795753 I | etcdserver: member dir = /tmp/etcd357449380/member
2017-03-14 18:09:25.795782 I | etcdserver: heartbeat = 10ms
2017-03-14 18:09:25.795809 I | etcdserver: election = 100ms
2017-03-14 18:09:25.795833 I | etcdserver: snapshot count = 0
2017-03-14 18:09:25.795869 I | etcdserver: advertise client URLs = unix://127.0.0.1:2130801581
2017-03-14 18:09:25.795912 I | etcdserver: initial advertise peer URLs = unix://127.0.0.1:2130701581
2017-03-14 18:09:25.795952 I | etcdserver: initial cluster = 4175910651547592886=unix://127.0.0.1:2130701581
2017-03-14 18:09:25.801492 I | etcdserver: starting member 4b7bcb3403588a46 in cluster 45f25d5ca2309227
2017-03-14 18:09:25.801587 I | raft: 4b7bcb3403588a46 became follower at term 0
2017-03-14 18:09:25.801645 I | raft: newRaft 4b7bcb3403588a46 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
2017-03-14 18:09:25.801685 I | raft: 4b7bcb3403588a46 became follower at term 1
2017-03-14 18:09:25.830280 W | auth: simple token is not cryptographically signed
2017-03-14 18:09:25.835090 I | etcdserver: set snapshot count to default 100000
2017-03-14 18:09:25.835174 I | etcdserver: starting server... [version: 3.2.0+git, cluster version: to_be_decided]
2017-03-14 18:09:25.840809 I | etcdserver/membership: added member 4b7bcb3403588a46 [unix://127.0.0.1:2130701581] to cluster 45f25d5ca2309227
2017-03-14 18:09:25.841061 I | raft: 4b7bcb3403588a46 is starting a new election at term 1
2017-03-14 18:09:25.841154 I | raft: 4b7bcb3403588a46 became candidate at term 2
2017-03-14 18:09:25.841206 I | raft: 4b7bcb3403588a46 received MsgVoteResp from 4b7bcb3403588a46 at term 2
2017-03-14 18:09:25.841264 I | raft: 4b7bcb3403588a46 became leader at term 2
2017-03-14 18:09:25.841312 I | raft: raft.node: 4b7bcb3403588a46 elected leader 4b7bcb3403588a46 at term 2
2017-03-14 18:09:25.842906 I | integration: launched 4175910651547592886 (unix://localhost:41759106515475928860)
2017-03-14 18:09:25.843764 I | etcdserver: setting up the initial cluster version to 3.2
2017-03-14 18:09:25.844268 I | etcdserver: published {Name:4175910651547592886 ClientURLs:[unix://127.0.0.1:2130801581]} to cluster 45f25d5ca2309227
2017-03-14 18:09:25.845919 N | etcdserver/membership: set the initial cluster version to 3.2
2017-03-14 18:09:31.104762 I | etcdserver/api/v3rpc: transport: http2Client.notifyError got notified that the client transport was broken EOF.
2017-03-14 18:09:31.105844 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:09:32.106387 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:09:33.657692 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:09:35.873936 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:09:40.439968 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:09:47.022082 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:09:59.102716 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:10:18.024169 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:10:42.073275 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:11:16.518163 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:12:34.811967 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:14:37.043434 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:16:29.516265 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:18:20.460003 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:20:03.806265 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
2017-03-14 18:21:45.251942 I | etcdserver/api/v3rpc: grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: context canceled"; Reconnecting to {localhost:41759106515475928860 <nil>}
panic: test timed out after 15m0s

goroutine 32265 [running]:
panic(0xfdfe40, 0xc422c357d0)
	/usr/lib/go-1.7/src/runtime/panic.go:500 +0x1ae
testing.startAlarm.func1()
	/usr/lib/go-1.7/src/testing/testing.go:918 +0x14e
created by time.goFunc
	/usr/lib/go-1.7/src/time/sleep.go:154 +0x78

goroutine 1 [chan receive, 13 minutes]:
testing.(*T).Run(0xc4201ba300, 0x116b3b6, 0x1a, 0x121a060, 0x55ab01)
	/usr/lib/go-1.7/src/testing/testing.go:647 +0x56e
testing.RunTests.func1(0xc4201ba300)
	/usr/lib/go-1.7/src/testing/testing.go:793 +0xba
testing.tRunner(0xc4201ba300, 0xc420045d98)
	/usr/lib/go-1.7/src/testing/testing.go:610 +0xca
testing.RunTests(0x121c980, 0x1659e40, 0x4f, 0x4f, 0xc420013c20)
	/usr/lib/go-1.7/src/testing/testing.go:799 +0x4bb
testing.(*M).Run(0xc420045ef0, 0x0)
	/usr/lib/go-1.7/src/testing/testing.go:743 +0x130
github.com/coreos/etcd/clientv3/integration.TestMain(0xc420045ef0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/integration/main_test.go:15 +0x39
main.main()
	github.com/coreos/etcd/clientv3/integration/_test/_testmain.go:208 +0x1b6

goroutine 17 [syscall, 14 minutes, locked to thread]:
runtime.goexit()
	/usr/lib/go-1.7/src/runtime/asm_amd64.s:2086 +0x1

goroutine 39 [chan receive]:
github.com/coreos/etcd/pkg/logutil.(*MergeLogger).outputLoop(0xc4201b8660)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/logutil/merge_logger.go:174 +0xb5
created by github.com/coreos/etcd/pkg/logutil.NewMergeLogger
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/logutil/merge_logger.go:92 +0x125

goroutine 36 [chan receive]:
github.com/coreos/etcd/pkg/logutil.(*MergeLogger).outputLoop(0xc4201b8560)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/logutil/merge_logger.go:174 +0xb5
created by github.com/coreos/etcd/pkg/logutil.NewMergeLogger
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/logutil/merge_logger.go:92 +0x125

goroutine 24200 [IO wait, 13 minutes]:
net.runtime_pollWait(0x7f801ac00238, 0x72, 0x413233)
	/usr/lib/go-1.7/src/runtime/netpoll.go:160 +0x5e
net.(*pollDesc).wait(0xc4230dc0d0, 0x72, 0x40fae8, 0x104f2c0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:73 +0x5b
net.(*pollDesc).waitRead(0xc4230dc0d0, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:78 +0x42
net.(*netFD).accept(0xc4230dc070, 0x0, 0x16277e0, 0xc423060360)
	/usr/lib/go-1.7/src/net/fd_unix.go:419 +0x2b8
net.(*UnixListener).accept(0xc4230605e0, 0x51ed2f, 0xc4236ec1dc, 0xc42014a9c0)
	/usr/lib/go-1.7/src/net/unixsock_posix.go:158 +0x51
net.(*UnixListener).Accept(0xc4230605e0, 0x162b120, 0xc425a0bdd0, 0x101ef80, 0x164ea90)
	/usr/lib/go-1.7/src/net/unixsock.go:229 +0x50
github.com/coreos/etcd/pkg/transport.(*unixListener).Accept(0xc4232720f0, 0xc425a0bda0, 0x101ef80, 0x164ea90, 0x108a400)
	<autogenerated>:91 +0x69
net/http.(*Server).Serve(0xc4236ec180, 0x162f020, 0xc4232720f0, 0x0, 0x0)
	/usr/lib/go-1.7/src/net/http/server.go:2273 +0x249
net/http/httptest.(*Server).goServe.func1(0xc420abce40)
	/usr/lib/go-1.7/src/net/http/httptest/server.go:235 +0xa3
created by net/http/httptest.(*Server).goServe
	/usr/lib/go-1.7/src/net/http/httptest/server.go:236 +0x6a

goroutine 24198 [select]:
github.com/coreos/etcd/etcdserver.(*EtcdServer).monitorVersions(0xc4222d8000)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1495 +0x6fe
github.com/coreos/etcd/etcdserver.(*EtcdServer).(github.com/coreos/etcd/etcdserver.monitorVersions)-fm()
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:521 +0x42
github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach.func1(0xc4222d8000, 0xc423272680)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1645 +0x64
created by github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1646 +0x211

goroutine 24251 [chan send, 13 minutes]:
github.com/coreos/etcd/clientv3.(*watchGrpcStream).serveSubstream.func1(0xc421e2dd06, 0xc4200fd810, 0xc420c1b2c0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:577 +0xea
github.com/coreos/etcd/clientv3.(*watchGrpcStream).serveSubstream(0xc420c1b2c0, 0xc4200fd810, 0xc42307f9e0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:635 +0xa3d
created by github.com/coreos/etcd/clientv3.(*watchGrpcStream).run
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:434 +0x618

goroutine 24191 [select, 13 minutes]:
github.com/coreos/etcd/pkg/schedule.(*fifo).run(0xc420abdbc0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/schedule/schedule.go:146 +0x4e4
created by github.com/coreos/etcd/pkg/schedule.NewFIFOScheduler
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/schedule/schedule.go:71 +0x2e8

goroutine 24203 [select, 13 minutes]:
github.com/coreos/etcd/pkg/schedule.(*fifo).run(0xc420abde00)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/schedule/schedule.go:146 +0x4e4
created by github.com/coreos/etcd/pkg/schedule.NewFIFOScheduler
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/pkg/schedule/schedule.go:71 +0x2e8

goroutine 24187 [select]:
github.com/coreos/etcd/mvcc/backend.(*backend).run(0xc420abc8a0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/mvcc/backend/backend.go:205 +0x26b
created by github.com/coreos/etcd/mvcc/backend.newBackend
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/mvcc/backend/backend.go:129 +0x3a6

goroutine 24183 [chan receive, 13 minutes]:
github.com/coreos/etcd/integration.(*proxyCloser).Close(0xc42580d7a0, 0xc420ad7fe0, 0x9511f0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/integration/cluster_proxy.go:73 +0xdc
github.com/coreos/etcd/clientv3.(*Client).Close(0xc4208238c0, 0x7f801abf54f8, 0xc422f9e9c0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/client.go:96 +0x7e
github.com/coreos/etcd/clientv3/integration.TestWatchStressResumeClose(0xc422eda240)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/integration/watch_test.go:969 +0x3ab
testing.tRunner(0xc422eda240, 0x121a060)
	/usr/lib/go-1.7/src/testing/testing.go:610 +0xca
created by testing.(*T).Run
	/usr/lib/go-1.7/src/testing/testing.go:646 +0x530

goroutine 24225 [chan receive, 13 minutes]:
github.com/coreos/etcd/proxy/grpcproxy.NewWatchProxy.func1(0xc42326e7e0, 0xc422c009b0, 0xc4230ffaf0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/watch.go:56 +0xcf
created by github.com/coreos/etcd/proxy/grpcproxy.NewWatchProxy
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/watch.go:67 +0x399

goroutine 24199 [select, 13 minutes]:
github.com/coreos/etcd/etcdserver.(*EtcdServer).linearizableReadLoop(0xc4222d8000)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/v3_server.go:722 +0x10ad
github.com/coreos/etcd/etcdserver.(*EtcdServer).(github.com/coreos/etcd/etcdserver.linearizableReadLoop)-fm()
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:522 +0x42
github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach.func1(0xc4222d8000, 0xc423272690)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1645 +0x64
created by github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1646 +0x211

goroutine 24189 [select]:
github.com/coreos/etcd/raft.(*node).run(0xc420abd1a0, 0xc42229e1e0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/raft/node.go:313 +0x1366
created by github.com/coreos/etcd/raft.StartNode
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/raft/node.go:210 +0x800

goroutine 24202 [select]:
github.com/coreos/etcd/etcdserver.(*raftNode).start.func1(0xc4222d8030, 0xc423272980, 0x3b9aca00)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/raft.go:145 +0x11e0
created by github.com/coreos/etcd/etcdserver.(*raftNode).start
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/raft.go:233 +0x174

goroutine 24213 [IO wait, 13 minutes]:
net.runtime_pollWait(0x7f801abedd80, 0x72, 0x413233)
	/usr/lib/go-1.7/src/runtime/netpoll.go:160 +0x5e
net.(*pollDesc).wait(0xc4230dced0, 0x72, 0x40fae8, 0x104f2c0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:73 +0x5b
net.(*pollDesc).waitRead(0xc4230dced0, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:78 +0x42
net.(*netFD).Read(0xc4230dce70, 0xc4201f8000, 0x1000, 0x1000, 0x0, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_unix.go:243 +0x1d9
net.(*conn).Read(0xc422f4a270, 0xc4201f8000, 0x1000, 0x1000, 0x165f7e0, 0xc42229ecd8, 0xc42229ecc8)
	/usr/lib/go-1.7/src/net/net.go:173 +0x97
net.(*UnixConn).Read(0xc422f4a270, 0xc4201f8000, 0x1000, 0x1000, 0xc42229ecd0, 0xc42391bbb8, 0x10)
	<autogenerated>:111 +0x73
net/http.(*persistConn).Read(0xc42086c700, 0xc4201f8000, 0x1000, 0x1000, 0x0, 0xed1, 0x1)
	/usr/lib/go-1.7/src/net/http/transport.go:1261 +0x239
bufio.(*Reader).fill(0xc42391bce0)
	/usr/lib/go-1.7/src/bufio/bufio.go:97 +0x197
bufio.(*Reader).Peek(0xc42391bce0, 0x1, 0xc422f3eb24, 0x1, 0x0, 0xc42391bd40, 0x0)
	/usr/lib/go-1.7/src/bufio/bufio.go:129 +0x132
net/http.(*persistConn).readLoop(0xc42086c700)
	/usr/lib/go-1.7/src/net/http/transport.go:1418 +0x2c1
created by net/http.(*Transport).dialConn
	/usr/lib/go-1.7/src/net/http/transport.go:1062 +0xa25

goroutine 24217 [chan receive, 13 minutes]:
github.com/coreos/etcd/clientv3.(*simpleBalancer).updateNotifyLoop(0xc4230154d0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/balancer.go:156 +0x103
created by github.com/coreos/etcd/clientv3.newSimpleBalancer
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/balancer.go:88 +0x50d

goroutine 24188 [select, 13 minutes]:
github.com/coreos/etcd/wal.(*filePipeline).run(0xc42312e880)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/wal/file_pipeline.go:89 +0x24a
created by github.com/coreos/etcd/wal.newFilePipeline
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/wal/file_pipeline.go:47 +0x1e8

goroutine 24184 [IO wait, 13 minutes]:
net.runtime_pollWait(0x7f801abff938, 0x72, 0x413233)
	/usr/lib/go-1.7/src/runtime/netpoll.go:160 +0x5e
net.(*pollDesc).wait(0xc4230dc220, 0x72, 0x40fae8, 0x104f2c0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:73 +0x5b
net.(*pollDesc).waitRead(0xc4230dc220, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:78 +0x42
net.(*netFD).accept(0xc4230dc1c0, 0x0, 0x16277e0, 0xc4230f55c0)
	/usr/lib/go-1.7/src/net/fd_unix.go:419 +0x2b8
net.(*UnixListener).accept(0xc423060bc0, 0x7f8014213018, 0xc420abc290, 0x0)
	/usr/lib/go-1.7/src/net/unixsock_posix.go:158 +0x51
net.(*UnixListener).Accept(0xc423060bc0, 0x51ed2f, 0xc420abc290, 0xc4ffffffff, 0x0)
	/usr/lib/go-1.7/src/net/unixsock.go:229 +0x50
github.com/coreos/etcd/pkg/transport.(*unixListener).Accept(0xc423272220, 0x121a708, 0xc420abc240, 0xc4230f5580, 0x1635700)
	<autogenerated>:91 +0x69
github.com/coreos/etcd/integration.(*bridge).serveListen(0xc420abc240)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/integration/bridge.go:90 +0x91
created by github.com/coreos/etcd/integration.newBridge
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/integration/bridge.go:54 +0x466

goroutine 24226 [chan receive, 13 minutes]:
github.com/coreos/etcd/proxy/grpcproxy.(*leader).recvLoop(0xc422c00a00)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/leader.go:78 +0x498
created by github.com/coreos/etcd/proxy/grpcproxy.newLeader
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/leader.go:53 +0x255

goroutine 24214 [select, 13 minutes]:
net/http.(*persistConn).writeLoop(0xc42086c700)
	/usr/lib/go-1.7/src/net/http/transport.go:1646 +0x506
created by net/http.(*Transport).dialConn
	/usr/lib/go-1.7/src/net/http/transport.go:1063 +0xa4a

goroutine 24219 [select]:
google.golang.org/grpc.(*addrConn).resetTransport(0xc420823e40, 0xc420b39400, 0x0, 0x4a817c800)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:714 +0xa17
google.golang.org/grpc.(*addrConn).transportMonitor(0xc420823e40)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:794 +0x407
google.golang.org/grpc.(*ClientConn).resetAddrConn.func1(0xc420823e40)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:506 +0x26e
created by google.golang.org/grpc.(*ClientConn).resetAddrConn
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:507 +0x643

goroutine 24220 [chan receive, 13 minutes]:
google.golang.org/grpc.(*ClientConn).lbWatcher(0xc420572d80)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:391 +0xce
created by google.golang.org/grpc.DialContext
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:339 +0x778

goroutine 24209 [IO wait, 13 minutes]:
net.runtime_pollWait(0x7f801abfa868, 0x72, 0x413233)
	/usr/lib/go-1.7/src/runtime/netpoll.go:160 +0x5e
net.(*pollDesc).wait(0xc4230dc1b0, 0x72, 0x40fae8, 0x104f2c0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:73 +0x5b
net.(*pollDesc).waitRead(0xc4230dc1b0, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:78 +0x42
net.(*netFD).accept(0xc4230dc150, 0x0, 0x16277e0, 0xc4230f5640)
	/usr/lib/go-1.7/src/net/fd_unix.go:419 +0x2b8
net.(*UnixListener).accept(0xc423060a00, 0xc422f4a770, 0x0, 0x0)
	/usr/lib/go-1.7/src/net/unixsock_posix.go:158 +0x51
net.(*UnixListener).Accept(0xc423060a00, 0x610134, 0xc420035e50, 0xc420035e50, 0x45c300)
	/usr/lib/go-1.7/src/net/unixsock.go:229 +0x50
github.com/coreos/etcd/pkg/transport.(*unixListener).Accept(0xc423272200, 0x121c728, 0xc422eda900, 0x1635700, 0xc422f4a770)
	<autogenerated>:91 +0x69
google.golang.org/grpc.(*Server).Serve(0xc422eda900, 0x162f020, 0xc423272200, 0x0, 0x0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/server.go:354 +0x1d1
created by github.com/coreos/etcd/integration.(*member).Launch
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/integration/cluster.go:663 +0x11f0

goroutine 24208 [select]:
github.com/coreos/etcd/etcdserver/api/v3rpc.monitorLeader.func1(0xc4222d8000, 0xc423273bc0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/api/v3rpc/interceptor.go:115 +0x48f
created by github.com/coreos/etcd/etcdserver/api/v3rpc.monitorLeader
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/api/v3rpc/interceptor.go:141 +0xfb

goroutine 24190 [select]:
github.com/coreos/etcd/lease.(*lessor).runLoop(0xc420abda40)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/lease/lessor.go:436 +0x1e9
created by github.com/coreos/etcd/lease.newLessor
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/lease/lessor.go:165 +0x2de

goroutine 24197 [select]:
github.com/coreos/etcd/etcdserver.monitorFileDescriptor(0xc420abcd20)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/metrics.go:89 +0x1e4
github.com/coreos/etcd/etcdserver.(*EtcdServer).Start.func2()
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:520 +0x63
github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach.func1(0xc4222d8000, 0xc423272670)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1645 +0x64
created by github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1646 +0x211

goroutine 24250 [chan send, 13 minutes]:
github.com/coreos/etcd/clientv3.(*watchGrpcStream).serveSubstream.func1(0xc42086ad06, 0xc4200fce70, 0xc420c1b2c0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:577 +0xea
github.com/coreos/etcd/clientv3.(*watchGrpcStream).serveSubstream(0xc420c1b2c0, 0xc4200fce70, 0xc42307f9e0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:635 +0xa3d
created by github.com/coreos/etcd/clientv3.(*watchGrpcStream).run
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:434 +0x618

goroutine 24196 [select, 13 minutes]:
github.com/coreos/etcd/etcdserver.(*EtcdServer).purgeFile(0xc4222d8000)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:558 +0x406
github.com/coreos/etcd/etcdserver.(*EtcdServer).(github.com/coreos/etcd/etcdserver.purgeFile)-fm()
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:519 +0x42
github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach.func1(0xc4222d8000, 0xc423272660)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1645 +0x64
created by github.com/coreos/etcd/etcdserver.(*EtcdServer).goAttach
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:1646 +0x211

goroutine 24207 [IO wait, 13 minutes]:
net.runtime_pollWait(0x7f801ac05e38, 0x72, 0x413233)
	/usr/lib/go-1.7/src/runtime/netpoll.go:160 +0x5e
net.(*pollDesc).wait(0xc4230dc140, 0x72, 0x40fae8, 0x104f2c0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:73 +0x5b
net.(*pollDesc).waitRead(0xc4230dc140, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:78 +0x42
net.(*netFD).accept(0xc4230dc0e0, 0x0, 0x16277e0, 0xc423100b80)
	/usr/lib/go-1.7/src/net/fd_unix.go:419 +0x2b8
net.(*UnixListener).accept(0xc423060780, 0x78, 0xc4236ed180, 0x7f801ac25410)
	/usr/lib/go-1.7/src/net/unixsock_posix.go:158 +0x51
net.(*UnixListener).Accept(0xc423060780, 0x6fbd81, 0xc422f3beb0, 0xc422f3beb0, 0x45c300)
	/usr/lib/go-1.7/src/net/unixsock.go:229 +0x50
github.com/coreos/etcd/pkg/transport.(*unixListener).Accept(0xc423272140, 0x121cb80, 0xc4236ed180, 0x16310a0, 0xc4201fbe30)
	<autogenerated>:91 +0x69
net/http.(*Server).Serve(0xc4236ec880, 0x162f020, 0xc423272140, 0x0, 0x0)
	/usr/lib/go-1.7/src/net/http/server.go:2273 +0x249
net/http/httptest.(*Server).goServe.func1(0xc42391a9c0)
	/usr/lib/go-1.7/src/net/http/httptest/server.go:235 +0xa3
created by net/http/httptest.(*Server).goServe
	/usr/lib/go-1.7/src/net/http/httptest/server.go:236 +0x6a

goroutine 24193 [select, 13 minutes]:
github.com/coreos/etcd/mvcc.(*watchableStore).syncVictimsLoop(0xc420c1a000)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/mvcc/watchable_store.go:231 +0x23e
created by github.com/coreos/etcd/mvcc.newWatchableStore
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/mvcc/watchable_store.go:89 +0x504

goroutine 24227 [chan receive, 13 minutes]:
github.com/coreos/etcd/proxy/grpcproxy.NewLeaseProxy.func1(0xc42326f9e0, 0xc42326f980, 0xc4230ffcd0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/lease.go:61 +0xcf
created by github.com/coreos/etcd/proxy/grpcproxy.NewLeaseProxy
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/lease.go:71 +0x313

goroutine 24215 [IO wait, 13 minutes]:
net.runtime_pollWait(0x7f801abffc38, 0x72, 0x413233)
	/usr/lib/go-1.7/src/runtime/netpoll.go:160 +0x5e
net.(*pollDesc).wait(0xc4230dd170, 0x72, 0x40fae8, 0x104f2c0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:73 +0x5b
net.(*pollDesc).waitRead(0xc4230dd170, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_poll_runtime.go:78 +0x42
net.(*netFD).Read(0xc4230dd110, 0xc420520000, 0x1000, 0x1000, 0x0, 0x16296e0, 0xc42007e0b0)
	/usr/lib/go-1.7/src/net/fd_unix.go:243 +0x1d9
net.(*conn).Read(0xc422f4a388, 0xc420520000, 0x1000, 0x1000, 0x162fc20, 0xc423100dc0, 0x0)
	/usr/lib/go-1.7/src/net/net.go:173 +0x97
net.(*UnixConn).Read(0xc422f4a388, 0xc420520000, 0x1000, 0x1000, 0x1681520, 0x2, 0xb)
	<autogenerated>:111 +0x73
net/http.(*connReader).Read(0xc423100ba0, 0xc420520000, 0x1000, 0x1000, 0x0, 0xf91, 0x1)
	/usr/lib/go-1.7/src/net/http/server.go:586 +0x2ee
bufio.(*Reader).fill(0xc420b382a0)
	/usr/lib/go-1.7/src/bufio/bufio.go:97 +0x197
bufio.(*Reader).ReadSlice(0xc420b382a0, 0xa, 0x0, 0x0, 0x7, 0x20, 0x0)
	/usr/lib/go-1.7/src/bufio/bufio.go:330 +0x1b5
bufio.(*Reader).ReadLine(0xc420b382a0, 0xc42229ef00, 0xf0, 0xc422e7d888, 0x4122b8, 0xc4201bcc00, 0xf0)
	/usr/lib/go-1.7/src/bufio/bufio.go:359 +0x56
net/textproto.(*Reader).readLineSlice(0xc42580cfc0, 0xc422e7d8b8, 0x6e6b99, 0xc42580cfc0, 0xc422e7d8b8, 0x412948)
	/usr/lib/go-1.7/src/net/textproto/reader.go:55 +0x8e
net/textproto.(*Reader).ReadLine(0xc42580cfc0, 0xc42229ef00, 0xc, 0x0, 0x42ec0c)
	/usr/lib/go-1.7/src/net/textproto/reader.go:36 +0x3d
net/http.readRequest(0xc420b382a0, 0xc42391aa00, 0xc42229ef00, 0x0, 0x0)
	/usr/lib/go-1.7/src/net/http/request.go:793 +0xbf
net/http.(*conn).readRequest(0xc4236ed180, 0x1630fe0, 0xc422f9e0c0, 0x0, 0x0, 0x0)
	/usr/lib/go-1.7/src/net/http/server.go:765 +0x244
net/http.(*conn).serve(0xc4236ed180, 0x1630fe0, 0xc422f9e0c0)
	/usr/lib/go-1.7/src/net/http/server.go:1532 +0x410
created by net/http.(*Server).Serve
	/usr/lib/go-1.7/src/net/http/server.go:2293 +0x541

goroutine 24194 [select]:
github.com/coreos/etcd/etcdserver.(*EtcdServer).run(0xc4222d8000)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:719 +0xd2a
created by github.com/coreos/etcd/etcdserver.(*EtcdServer).start
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/server.go:547 +0x6fb

goroutine 24224 [chan receive, 13 minutes]:
github.com/coreos/etcd/proxy/grpcproxy.(*leader).recvLoop(0xc422c00960)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/leader.go:78 +0x498
created by github.com/coreos/etcd/proxy/grpcproxy.newLeader
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/proxy/grpcproxy/leader.go:53 +0x255

goroutine 24246 [select, 13 minutes]:
github.com/coreos/etcd/clientv3.(*simpleBalancer).Get(0xc4230154d0, 0x7f801ac04d68, 0xc426cab5f0, 0x412901, 0x30, 0x0, 0x100000000000001, 0xc426cab5f0, 0x41, 0x950d00, ...)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/balancer.go:248 +0x40f
google.golang.org/grpc.(*ClientConn).getTransport(0xc420572d80, 0x7f801ac04d68, 0xc426cab5f0, 0xc426cab501, 0x7f801ac04d68, 0xc426cab5f0, 0xf, 0x45ba80, 0xc423493180)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/clientconn.go:536 +0xd9
google.golang.org/grpc.newClientStream(0x7f801ac04d68, 0xc426cab5f0, 0x16508c0, 0xc420572d80, 0x116a4e3, 0x19, 0xc420b26440, 0x1, 0x1, 0x0, ...)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/stream.go:150 +0x465
google.golang.org/grpc.NewClientStream(0x7f801abf54f8, 0xc422f9f1c0, 0x16508c0, 0xc420572d80, 0x116a4e3, 0x19, 0xc420b26440, 0x1, 0x1, 0x10, ...)
	/home/jenkins/workspace/etcd-proxy/gopath/src/google.golang.org/grpc/stream.go:104 +0x1fd
github.com/coreos/etcd/etcdserver/etcdserverpb.(*watchClient).Watch(0xc422f4a560, 0x7f801abf54f8, 0xc422f9f1c0, 0xc420b26440, 0x1, 0x1, 0x1219ce0, 0xc4204ee2a0, 0xc420b26420, 0xc4204ee240)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/etcdserver/etcdserverpb/rpc.pb.go:2420 +0xea
github.com/coreos/etcd/clientv3.(*watchGrpcStream).openWatchClient(0xc420c1b2c0, 0xc4204ee240, 0xc4204ee2a0, 0x0, 0xc426cab590)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:740 +0x18a
github.com/coreos/etcd/clientv3.(*watchGrpcStream).newWatchClient(0xc420c1b2c0, 0xc422f9f1c0, 0x1626920, 0xc4217806e0, 0x1626920)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:666 +0x5bc
github.com/coreos/etcd/clientv3.(*watchGrpcStream).run(0xc420c1b2c0)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:486 +0x17fb
created by github.com/coreos/etcd/clientv3.(*watcher).newWatcherGrpcStream
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/clientv3/watch.go:219 +0x5c5

goroutine 24245 [select, 13 minutes]:
context.propagateCancel.func1(0x7f801ac05000, 0xc4230ea180, 0x1629d60, 0xc422f9f1c0)
	/usr/lib/go-1.7/src/context/context.go:262 +0x188
created by context.propagateCancel
	/usr/lib/go-1.7/src/context/context.go:267 +0x281

goroutine 24192 [select]:
github.com/coreos/etcd/mvcc.(*watchableStore).syncWatchersLoop(0xc420c1a000)
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/mvcc/watchable_store.go:205 +0x25c
created by github.com/coreos/etcd/mvcc.newWatchableStore
	/home/jenkins/workspace/etcd-proxy/gopath/src/github.com/coreos/etcd/mvcc/watchable_store.go:88 +0x4e2
exit status 2
heyitsanthony pushed a commit to heyitsanthony/etcd that referenced this issue Mar 15, 2017
clientv3: close open watch channel if substream is closing on reconnect
a087325 
If substream is closing but outc is still open while reconnecting, then outc
would only be closed once the watch client would connect or once the watch
client is closed. This was leading to deadlocks in the proxy tests. Instead,
close immediately if the context is canceled.

Fixes etcd-io#7503
@heyitsanthony heyitsanthony mentioned this issue Mar 15, 2017
Merged
gyuho pushed a commit that referenced this issue Mar 17, 2017
@gyuho
clientv3: close open watch channel if substream is closing on reconnect
ba5a2d6 
If substream is closing but outc is still open while reconnecting, then outc
would only be closed once the watch client would connect or once the watch
client is closed. This was leading to deadlocks in the proxy tests. Instead,
close immediately if the context is canceled.

Fixes #7503
gyuho pushed a commit that referenced this issue Mar 18, 2017
@gyuho
clientv3: close open watch channel if substream is closing on reconnect
4a1bffd 
If substream is closing but outc is still open while reconnecting, then outc
would only be closed once the watch client would connect or once the watch
client is closed. This was leading to deadlocks in the proxy tests. Instead,
close immediately if the context is canceled.

Fixes #7503
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/testing
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

clientv3: close open watch channel if substream is closing on reconnect heyitsanthony/etcd
1 participant
@heyitsanthony