Flake: integration test etcd_watcher waitgroup reused #21188

mikedanese · 2016-02-12T21:44:58Z

https://console.cloud.google.com/storage/browser/kubernetes-jenkins/pr-logs/pull/20965/kubernetes-pull-test-unit-integration/14051/

E0212 17:47:39.819927    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc8235322a0), PrevNode:(*client.Node)(0xc823532300), Index:0xc2} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xb7, ModifiedIndex:0xc3, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.819980    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc8236f6f60), PrevNode:(*client.Node)(0xc8236f6fc0), Index:0xc2} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xb7, ModifiedIndex:0xc3, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.820226    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc82416b440), PrevNode:(*client.Node)(0xc82416b4a0), Index:0xbe} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xb7, ModifiedIndex:0xc3, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.820674    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc82178d620), PrevNode:(*client.Node)(0xc82178d680), Index:0xc2} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xb7, ModifiedIndex:0xc3, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.822516    9094 persistentvolume_claim_binder_controller.go:123] PVClaimBinder could not update volume fake-pv: Cannot reload volume fake-pv: persistentvolumes "fake-pv" not found
E0212 17:47:39.876514    9094 persistentvolume_claim_binder_controller.go:188] PVClaimBinder could not update volume fake-pv from deleteClaim handler: Cannot reload volume fake-pv: persistentvolumes "fake-pv" not found
E0212 17:47:39.878893    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc821dfaba0), PrevNode:(*client.Node)(0xc821dfac00), Index:0xcd} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xc4, ModifiedIndex:0xce, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.878893    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc823dcd440), PrevNode:(*client.Node)(0xc823dcd500), Index:0xcd} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xc4, ModifiedIndex:0xce, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.878970    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc8237a4060), PrevNode:(*client.Node)(0xc8237a40c0), Index:0xcd} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xc4, ModifiedIndex:0xce, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.879007    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc8237a45a0), PrevNode:(*client.Node)(0xc8237a4660), Index:0xcd} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xc4, ModifiedIndex:0xce, Expiration:(*time.Time)(nil), TTL:0}
E0212 17:47:39.879064    9094 etcd_watcher.go:428] failure to decode api object: Object 'Kind' is missing in ''
from &client.Response{Action:"delete", Node:(*client.Node)(0xc824b03d40), PrevNode:(*client.Node)(0xc824b03da0), Index:0xcb} &client.Node{Key:"/registry", Dir:true, Value:"", Nodes:client.Nodes(nil), CreatedIndex:0xc4, ModifiedIndex:0xce, Expiration:(*time.Time)(nil), TTL:0}
panic: sync: WaitGroup is reused before previous Wait has returned [recovered]
    panic: sync: WaitGroup is reused before previous Wait has returned

goroutine 2786 [running]:
testing.tRunner.func1(0xc822bcc2d0)
    /usr/local/go/src/testing/testing.go:450 +0x171
sync.(*WaitGroup).Wait(0xc824a9f570)
    /usr/local/go/src/sync/waitgroup.go:128 +0x114
net/http/httptest.(*Server).Close(0xc824a9f540)
    /usr/local/go/src/net/http/httptest/server.go:168 +0x5c
k8s.io/kubernetes/test/integration.TestPersistentVolumeRecycler(0xc822bcc2d0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/integration/persistent_volumes_test.go:177 +0x2829
testing.tRunner(0xc822bcc2d0, 0x251a1f8)
    /usr/local/go/src/testing/testing.go:456 +0x98
created by testing.RunTests
    /usr/local/go/src/testing/testing.go:561 +0x86d

goroutine 1 [chan receive]:
testing.RunTests(0x1ce4488, 0x2519fa0, 0x22, 0x22, 0xc820340401)
    /usr/local/go/src/testing/testing.go:562 +0x8ad
testing.(*M).Run(0xc8210bcf08, 0xc8202d6c80)
    /usr/local/go/src/testing/testing.go:494 +0x70
main.main()
    k8s.io/kubernetes/test/integration/_test/_testmain.go:120 +0x116

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:1721 +0x1

goroutine 5 [chan receive]:
github.com/golang/glog.(*loggingT).flushDaemon(0x264c0e0)
    /workspace/kubernetes/Godeps/_workspace/src/github.com/golang/glog/glog.go:879 +0x67
created by github.com/golang/glog.init.1
    /workspace/kubernetes/Godeps/_workspace/src/github.com/golang/glog/glog.go:410 +0x297

goroutine 41 [syscall]:
os/signal.loop()
    /usr/local/go/src/os/signal/signal_unix.go:22 +0x18
created by os/signal.init.1
    /usr/local/go/src/os/signal/signal_unix.go:28 +0x37

goroutine 60 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc8207cbf78, 0x29e8d60800, 0x0, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc8207cbf78, 0x29e8d60800, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/registry/service/ipallocator/controller.(*Repair).RunUntil(0xc82068b0e0, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/registry/service/ipallocator/controller/repair.go:72 +0x46
k8s.io/kubernetes/pkg/registry/service/ipallocator/controller.(*Repair).RunUntil-fm(0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

goroutine 398 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc8206b1f78, 0x29e8d60800, 0x0, 0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc8206b1f78, 0x29e8d60800, 0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/registry/service/portallocator/controller.(*Repair).RunUntil(0xc820ff0b00, 0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/registry/service/portallocator/controller/repair.go:58 +0x46
k8s.io/kubernetes/pkg/registry/service/portallocator/controller.(*Repair).RunUntil-fm(0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

goroutine 20 [IO wait]:
net.runtime_pollWait(0x7fcbbc04c210, 0x72, 0xc820012150)
    /usr/local/go/src/runtime/netpoll.go:157 +0x60
net.(*pollDesc).Wait(0xc8201273a0, 0x72, 0x0, 0x0)
    /usr/local/go/src/net/fd_poll_runtime.go:73 +0x3a
net.(*pollDesc).WaitRead(0xc8201273a0, 0x0, 0x0)
    /usr/local/go/src/net/fd_poll_runtime.go:78 +0x36
net.(*netFD).accept(0xc820127340, 0x0, 0x7fcbbc04c810, 0xc8205c8b20)
    /usr/local/go/src/net/fd_unix.go:408 +0x27c
net.(*TCPListener).AcceptTCP(0xc8200d6120, 0xc8206e4280, 0x0, 0x0)
    /usr/local/go/src/net/tcpsock_posix.go:254 +0x4d
net.(*TCPListener).Accept(0xc8200d6120, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/tcpsock_posix.go:264 +0x3d
net/http/httptest.(*historyListener).Accept(0xc82013c9f0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/http/httptest/server.go:48 +0x63
net/http.(*Server).Serve(0xc8200d2ea0, 0x7fcbb99d9670, 0xc82013c9f0, 0x0, 0x0)
    /usr/local/go/src/net/http/server.go:1887 +0xb3
created by net/http/httptest.(*Server).Start
    /usr/local/go/src/net/http/httptest/server.go:109 +0x380

goroutine 2468 [chan send]:
k8s.io/kubernetes/pkg/watch.(*StreamWatcher).receive(0xc824af41e0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/watch/iowatcher.go:117 +0x5cc
created by k8s.io/kubernetes/pkg/watch.NewStreamWatcher
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/watch/iowatcher.go:60 +0xbf

goroutine 59 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc8207c9f78, 0x2540be400, 0x0, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc8207c9f78, 0x2540be400, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/master.(*Controller).RunKubernetesService(0xc820216b40, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:110 +0x4a
k8s.io/kubernetes/pkg/master.(*Controller).RunKubernetesService-fm(0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

goroutine 61 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc8207caf78, 0x29e8d60800, 0x0, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc8207caf78, 0x29e8d60800, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/registry/service/portallocator/controller.(*Repair).RunUntil(0xc82068db40, 0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/registry/service/portallocator/controller/repair.go:58 +0x46
k8s.io/kubernetes/pkg/registry/service/portallocator/controller.(*Repair).RunUntil-fm(0xc8205252c0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

goroutine 1966 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc82127df78, 0x2540be400, 0x0, 0xc820ddbc80)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc82127df78, 0x2540be400, 0xc820ddbc80)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/master.(*Controller).RunKubernetesService(0xc822778240, 0xc820ddbc80)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:110 +0x4a
k8s.io/kubernetes/pkg/master.(*Controller).RunKubernetesService-fm(0xc820ddbc80)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

goroutine 1797 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc82127ff78, 0x29e8d60800, 0x0, 0xc821e3e180)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc82127ff78, 0x29e8d60800, 0xc821e3e180)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/registry/service/portallocator/controller.(*Repair).RunUntil(0xc821e42a40, 0xc821e3e180)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/registry/service/portallocator/controller/repair.go:58 +0x46
k8s.io/kubernetes/pkg/registry/service/portallocator/controller.(*Repair).RunUntil-fm(0xc821e3e180)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

goroutine 397 [select]:
k8s.io/kubernetes/pkg/util/wait.JitterUntil(0xc8207c6f78, 0x29e8d60800, 0x0, 0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:74 +0x13b
k8s.io/kubernetes/pkg/util/wait.Until(0xc8207c6f78, 0x29e8d60800, 0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/wait/wait.go:47 +0x3e
k8s.io/kubernetes/pkg/registry/service/ipallocator/controller.(*Repair).RunUntil(0xc82097ae10, 0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/registry/service/ipallocator/controller/repair.go:72 +0x46
k8s.io/kubernetes/pkg/registry/service/ipallocator/controller.(*Repair).RunUntil-fm(0xc82093bce0)
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/master/controller.go:97 +0x2a
created by k8s.io/kubernetes/pkg/util.(*Runner).Start
    /workspace/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/util/runner.go:45 +0x153

The text was updated successfully, but these errors were encountered:

ixdy · 2016-02-13T01:24:49Z

http://pr-test.k8s.io/21183/kubernetes-pull-test-unit-integration/14166/ is another failure.

roberthbailey · 2016-02-14T04:45:56Z

Also seen in http://pr-test.k8s.io/21183/kubernetes-pull-test-unit-integration/21003/.

thockin · 2016-02-15T06:03:47Z

Again. #21188

Not assigned to anyone, so I am sending to @lavalamp for routing

adohe-zz · 2016-02-15T07:44:27Z

Again: #20409

Is there anyone working on this? I will spend some time looking into this.

wojtek-t · 2016-02-15T11:37:12Z

I think that the name of this issue is misleading - the issue seems to be unrelated to etcd_watcher

Basically, if you look into this part of log:

goroutine 2786 [running]:
testing.tRunner.func1(0xc822bcc2d0)
    /usr/local/go/src/testing/testing.go:450 +0x171
sync.(*WaitGroup).Wait(0xc824a9f570)
    /usr/local/go/src/sync/waitgroup.go:128 +0x114
net/http/httptest.(*Server).Close(0xc824a9f540)
    /usr/local/go/src/net/http/httptest/server.go:168 +0x5c
...

So it seems that, the WaitGroup that is problematic is in httptest.Server.

So my feeling is that we are simply talking to a server that is already being close and this is ~roughly duplicate of golang/go#12262

We should just find where exactly the problem is and try to work-around it.

wojtek-t · 2016-02-15T11:45:32Z

I think this is exactly what we had before. I will send a PR with the fix today.

mikedanese added the sig/api-machinery Categorizes an issue or PR as relevant to SIG API Machinery. label Feb 12, 2016

spxtr mentioned this issue Feb 13, 2016

Warn when not enough FDs #21201

Merged

ixdy mentioned this issue Feb 13, 2016

Save the master logs to separate files rather than dumping to stdout. #21183

Merged

mikedanese added the kind/flake Categorizes issue or PR as related to a flaky test. label Feb 13, 2016

olivierlemasle mentioned this issue Feb 13, 2016

Add bearer token authentication to Vagrant clusters #20965

Merged

wojtek-t mentioned this issue Feb 13, 2016

Don't store no-op updates in etcd. #20897

Merged

roberthbailey mentioned this issue Feb 14, 2016

Revert #19469 so re-enable the metrics grabbing test on GKE. #21003

Merged

thockin added the priority/critical-urgent Highest priority. Must be actively worked on as someone's top priority right now. label Feb 15, 2016

thockin assigned lavalamp Feb 15, 2016

thockin mentioned this issue Feb 15, 2016

fix --sort-by help bug #21238

Merged

wojtek-t mentioned this issue Feb 15, 2016

Never rate limit watches #21104

Merged

wojtek-t assigned wojtek-t and unassigned lavalamp Feb 15, 2016

wojtek-t mentioned this issue Feb 15, 2016

Comment out calls to httptest.Server.Close() #21259

Merged

k8s-github-robot closed this as completed in #21259 Feb 15, 2016

wojtek-t mentioned this issue Feb 15, 2016

kubectl print ingress add column labels #20409

Merged

ncdc mentioned this issue Feb 15, 2016

Hawkular support for the Initial Resources #15476

Merged

madhusudancs mentioned this issue Feb 15, 2016

Replica set is enabled by default now, so it is not necessary to explicitly enable it in the test config script. #21131

Closed

justinsb mentioned this issue Feb 18, 2016

AWS Debian Jessie Support #21237

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Flake: integration test etcd_watcher waitgroup reused #21188

Flake: integration test etcd_watcher waitgroup reused #21188

mikedanese commented Feb 12, 2016

ixdy commented Feb 13, 2016

roberthbailey commented Feb 14, 2016

thockin commented Feb 15, 2016

adohe-zz commented Feb 15, 2016

wojtek-t commented Feb 15, 2016

wojtek-t commented Feb 15, 2016

Flake: integration test etcd_watcher waitgroup reused #21188

Flake: integration test etcd_watcher waitgroup reused #21188

Comments

mikedanese commented Feb 12, 2016

ixdy commented Feb 13, 2016

roberthbailey commented Feb 14, 2016

thockin commented Feb 15, 2016

adohe-zz commented Feb 15, 2016

wojtek-t commented Feb 15, 2016

wojtek-t commented Feb 15, 2016