etcdctl exec-watch: "panic: runtime error: slice bounds out of range"

[hackzilla]

I'm not sure if this is related to #829.

It only happens with exec-watch, watch command works fine.

etcd version 0.4.4
coreos channel stable.

etcdctl exec-watch --recursive /varnish/backends/ "echo hello"
panic: runtime error: slice bounds out of range

goroutine 1 [running]:
runtime.panic(0x68bc20, 0x9f6eca)
    /usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6
github.com/coreos/etcdctl/command.execWatchCommandFunc(0xc21006b0b0, 0xc210067300, 0x5, 0xc210067300, 0x1)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/exec_watch_command.go:73 +0xa1e
github.com/coreos/etcdctl/command.rawhandle(0xc21006b0b0, 0x76c460, 0x7f2e56759230, 0x616f80, 0x6e6000)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/handle.go:81 +0x768
github.com/coreos/etcdctl/command.handlePrint(0xc21006b0b0, 0x76c460, 0x76c740)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/handle.go:87 +0x3f
github.com/coreos/etcdctl/command.handleKey(0xc21006b0b0, 0x76c460)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/handle.go:108 +0x3b
github.com/coreos/etcdctl/command.func·001(0xc21006b0b0)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/exec_watch_command.go:25 +0x31
github.com/coreos/etcdctl/third_party/github.com/codegangsta/cli.Command.Run(0x6f7590, 0xa, 0x0, 0x0, 0x7414b0, ...)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/third_party/github.com/codegangsta/cli/command.go:97 +0xbde
github.com/coreos/etcdctl/third_party/github.com/codegangsta/cli.(*App).Run(0xc210069000, 0xc21000a000, 0x5, 0x5, 0x7414b0, ...)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/third_party/github.com/codegangsta/cli/app.go:125 +0x901
main.main()
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/etcdctl.go:35 +0x704

goroutine 3 [syscall]:
os/signal.loop()
    /usr/lib/go/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.init·1
    /usr/lib/go/src/pkg/os/signal/signal_unix.go:27 +0x31

goroutine 8 [chan receive]:
github.com/coreos/etcdctl/command.func·002()
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/exec_watch_command.go:62 +0x3b
created by github.com/coreos/etcdctl/command.execWatchCommandFunc
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/exec_watch_command.go:65 +0x457

goroutine 6 [IO wait]:
net.runtime_pollWait(0x7f2e568fa758, 0x72, 0x0)
    /usr/lib/go/src/pkg/runtime/netpoll.goc:116 +0x6a
net.(*pollDesc).Wait(0xc21004e3e0, 0x72, 0x7f2e568f9110, 0xb)
    /usr/lib/go/src/pkg/net/fd_poll_runtime.go:81 +0x34
net.(*pollDesc).WaitRead(0xc21004e3e0, 0xb, 0x7f2e568f9110)
    /usr/lib/go/src/pkg/net/fd_poll_runtime.go:86 +0x30
net.(*netFD).Read(0xc21004e380, 0xc21007b000, 0x1000, 0x1000, 0x0, ...)
    /usr/lib/go/src/pkg/net/fd_unix.go:204 +0x2a0
net.(*conn).Read(0xc2100002f0, 0xc21007b000, 0x1000, 0x1000, 0x30, ...)
    /usr/lib/go/src/pkg/net/net.go:122 +0xc5
bufio.(*Reader).fill(0xc210037240)
    /usr/lib/go/src/pkg/bufio/bufio.go:91 +0x110
bufio.(*Reader).Peek(0xc210037240, 0x1, 0x0, 0x0, 0x0, ...)
    /usr/lib/go/src/pkg/bufio/bufio.go:119 +0xcb
net/http.(*persistConn).readLoop(0xc210067480)
    /usr/lib/go/src/pkg/net/http/transport.go:687 +0xb7
created by net/http.(*Transport).dialConn
    /usr/lib/go/src/pkg/net/http/transport.go:528 +0x607

goroutine 7 [select]:
net/http.(*persistConn).writeLoop(0xc210067480)
    /usr/lib/go/src/pkg/net/http/transport.go:791 +0x271
created by net/http.(*Transport).dialConn
    /usr/lib/go/src/pkg/net/http/transport.go:529 +0x61e

goroutine 9 [select]:
github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd.(*Client).watchOnce(0xc210067300, 0x7fff416c5d02, 0x12, 0x57604, 0x1, ...)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd/watch.go:113 +0x2ae
github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd.(*Client).Watch(0xc210067300, 0x7fff416c5d02, 0x12, 0x57604, 0x1, ...)
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd/watch.go:38 +0x239
created by github.com/coreos/etcdctl/command.execWatchCommandFunc
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/command/exec_watch_command.go:69 +0x504

goroutine 14 [runnable]:
github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd.func·003()
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd/watch.go:92
created by github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd.(*Client).watchOnce
    /build/amd64-usr/var/tmp/portage/dev-db/etcdctl-0.4.4/work/etcdctl-0.4.4/src/github.com/coreos/etcdctl/third_party/github.com/coreos/go-etcd/etcd/watch.go:111 +0x176

goroutine 12 [IO wait]:
net.runtime_pollWait(0x7f2e568fa6b0, 0x72, 0x0)
    /usr/lib/go/src/pkg/runtime/netpoll.goc:116 +0x6a
net.(*pollDesc).Wait(0xc21004eae0, 0x72, 0x7f2e568f9110, 0xb)
    /usr/lib/go/src/pkg/net/fd_poll_runtime.go:81 +0x34
net.(*pollDesc).WaitRead(0xc21004eae0, 0xb, 0x7f2e568f9110)
    /usr/lib/go/src/pkg/net/fd_poll_runtime.go:86 +0x30
net.(*netFD).Read(0xc21004ea80, 0xc210086000, 0x1000, 0x1000, 0x0, ...)
    /usr/lib/go/src/pkg/net/fd_unix.go:204 +0x2a0
net.(*conn).Read(0xc2100003d0, 0xc210086000, 0x1000, 0x1000, 0x30, ...)
    /usr/lib/go/src/pkg/net/net.go:122 +0xc5
bufio.(*Reader).fill(0xc2100377e0)
    /usr/lib/go/src/pkg/bufio/bufio.go:91 +0x110
bufio.(*Reader).Peek(0xc2100377e0, 0x1, 0x0, 0x0, 0x0, ...)
    /usr/lib/go/src/pkg/bufio/bufio.go:119 +0xcb
net/http.(*persistConn).readLoop(0xc210067680)
    /usr/lib/go/src/pkg/net/http/transport.go:687 +0xb7
created by net/http.(*Transport).dialConn
    /usr/lib/go/src/pkg/net/http/transport.go:528 +0x607

goroutine 13 [select]:
net/http.(*persistConn).writeLoop(0xc210067680)
    /usr/lib/go/src/pkg/net/http/transport.go:791 +0x271
created by net/http.(*Transport).dialConn
    /usr/lib/go/src/pkg/net/http/transport.go:529 +0x61e

This is what I got back when I manually ran the curl command.

curl -X GET "http://192.168.16.42:4001/v2/keys/varnish/backends?recursive=true&wait=true"
{"action":"delete","node":{"key":"/varnish/backends/symfony/stats-backend-01:82","modifiedIndex":357751,"createdIndex":357484},"prevNode":{"key":"/varnish/backends/symfony/stats-backend-01:82","value":"running","modifiedIndex":357484,"createdIndex":357484}}

[yichengq]

I think this one is related to coreos/etcdctl#98
@joshi4
Could you help for this bug? I believe you have more experiences on it. :)

[joshi4]

@hackzilla

sorry for the late response.

@unihorn and I were able to reproduce your issue.
your command should run fine if you run it as etcdctl exec-watch --recursive /varnish/backends/ -- echo hello

We have an update in the works that will get rid of the special case handling that currently needs to be done in exec-watch. That should fix this issue so that etcdctl does not panic in such a scenario.

[hackzilla]

👍

I got round it by put it into a shell script.

[joshi4]

@unihorn closing this issue.