bitly/nsq — pull request #461 by mreiferson (2014-09-22 14:21:23+00:00)
Title: nsqd panic on startup

I'm unsure as to exactly how it happened, but the paste is

```
kool@c-1:~$ /opt/nsq/bin/nsqd -lookupd-tcp-address=c-1:1920 -http-address=c-1:1952 -tcp-address=c-1:1953
[nsqd] 2014/09/17 18:04:39.845766 nsqd v0.2.31 (built w/go1.3.1)
[nsqd] 2014/09/17 18:04:39.847633 ID: 355
[nsqd] 2014/09/17 18:04:39.848533 TOPIC(fst-stats): created
[nsqd] 2014/09/17 18:04:39.849265 TOPIC(fst-stats): new channel(nsq_to_nsq)
[nsqd] 2014/09/17 18:04:39.849824 DISKQUEUE(fst-stats:nsq_to_nsq): readOne() opened fst-stats:nsq_to_nsq.diskqueue.000000.dat
[nsqd] 2014/09/17 18:04:39.850303 TOPIC(fst-stats): new channel(nsq_to_file)
panic: runtime error: slice bounds out of range

goroutine 28 [running]:
runtime.panic(0x7b7d00, 0xa3d28f)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/runtime/panic.c:279 +0xf5
github.com/bitly/nsq/nsqd.decodeMessage(0xa44538, 0x0, 0x0, 0x1, 0x0, 0x0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/message.go:67 +0x3c6
github.com/bitly/nsq/nsqd.(*Channel).messagePump(0xc208010780)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:572 +0x376
created by github.com/bitly/nsq/nsqd.NewChannel
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:116 +0x372

goroutine 16 [syscall]:
syscall.Syscall(0x1, 0x2, 0xc208050300, 0x4d, 0x0, 0x0, 0x3330333035380000)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/syscall/asm_linux_amd64.s:21 +0x5
syscall.write(0x2, 0xc208050300, 0x4d, 0x80, 0xc20808d7d2, 0x0, 0x0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/syscall/zsyscall_linux_amd64.go:1228 +0x75
syscall.Write(0x2, 0xc208050300, 0x4d, 0x80, 0x4, 0x0, 0x0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/syscall/syscall_unix.go:152 +0x5c
os.(*File).write(0xc20803c010, 0xc208050300, 0x4d, 0x80, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/os/file_unix.go:211 +0xb5
os.(*File).Write(0xc20803c010, 0xc208050300, 0x4d, 0x80, 0xa452e0, 0x0, 0x0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/os/file.go:139 +0x98
log.(*Logger).Output(0xc20801abe0, 0x2, 0xc208025aa0, 0x2a, 0x0, 0x0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/log/log.go:153 +0x462
github.com/bitly/nsq/nsqd.(*NSQD).logf(0xc2080c6000, 0x862950, 0x1a, 0xc20808daf0, 0x2, 0x2)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:135 +0xc5
github.com/bitly/nsq/nsqd.(*Topic).getOrCreateChannel(0xc20804e120, 0xc208062f30, 0xb, 0x0, 0x6fcc40)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/topic.go:93 +0x274
github.com/bitly/nsq/nsqd.(*Topic).GetChannel(0xc20804e120, 0xc208062f30, 0xb, 0x0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/topic.go:70 +0x59
github.com/bitly/nsq/nsqd.(*NSQD).LoadMetadata(0xc2080c6000)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:280 +0xc1e
main.main()
/Users/mreiferson/dev/src/github.com/bitly/nsq/apps/nsqd/nsqd.go:111 +0x513

goroutine 19 [finalizer wait]:
runtime.park(0x415010, 0xa438a8, 0xa41349)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/runtime/proc.c:1369 +0x89
runtime.parkunlock(0xa438a8, 0xa41349)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/runtime/proc.c:1385 +0x3b
runfinq()
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/runtime/mgc0.c:2644 +0xcf
runtime.goexit()
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/runtime/proc.c:1445

goroutine 23 [select]:
github.com/bitly/nsq/nsqd.(*diskQueue).ioLoop(0xc2080da420)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:589 +0x5e0
created by github.com/bitly/nsq/nsqd.newDiskQueue
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:91 +0x332

goroutine 21 [syscall]:
os/signal.loop()
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.initÂ·1
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/os/signal/signal_unix.go:27 +0x32

goroutine 22 [select]:
github.com/bitly/nsq/nsqd.(*NSQD).idPump(0xc2080c6000)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:471 +0x32a
github.com/bitly/nsq/nsqd.funcÂ·030()
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:123 +0x29
github.com/bitly/nsq/util.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:14 +0x2e
created by github.com/bitly/nsq/util.(*WaitGroupWrapper).Wrap
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:16 +0xac

goroutine 24 [select]:
github.com/bitly/nsq/nsqd.(*Topic).messagePump(0xc20804e120)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/topic.go:212 +0xbc1
github.com/bitly/nsq/nsqd.funcÂ·036()
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/topic.go:53 +0x29
github.com/bitly/nsq/util.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:14 +0x2e
created by github.com/bitly/nsq/util.(*WaitGroupWrapper).Wrap
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:16 +0xac

goroutine 25 [select]:
github.com/bitly/nsq/nsqd.(*NSQD).Notify(0xc2080c6000, 0x7ed520, 0xc20804e120)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:485 +0x208
created by github.com/bitly/nsq/nsqd.NewTopic
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/topic.go:55 +0x2a8

goroutine 27 [select]:
github.com/bitly/nsq/nsqd.(*diskQueue).ioLoop(0xc2080da000)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:589 +0x5e0
created by github.com/bitly/nsq/nsqd.newDiskQueue
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:91 +0x332

goroutine 29 [select]:
github.com/bitly/nsq/nsqd.(*Channel).pqWorker(0xc208010780, 0xc208010858, 0xc208010870, 0x7fad6852ff68)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:648 +0x259
github.com/bitly/nsq/nsqd.(*Channel).deferredWorker(0xc208010780)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:602 +0x7b
github.com/bitly/nsq/nsqd.funcÂ·002()
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:118 +0x29
github.com/bitly/nsq/util.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:14 +0x2e
created by github.com/bitly/nsq/util.(*WaitGroupWrapper).Wrap
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:16 +0xac

goroutine 30 [select]:
github.com/bitly/nsq/nsqd.(*Channel).inFlightWorker(0xc208010780)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:608 +0x432
github.com/bitly/nsq/nsqd.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:119 +0x29
github.com/bitly/nsq/util.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:14 +0x2e
created by github.com/bitly/nsq/util.(*WaitGroupWrapper).Wrap
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:16 +0xac

goroutine 31 [select]:
github.com/bitly/nsq/nsqd.(*NSQD).Notify(0xc2080c6000, 0x7f7800, 0xc208010780)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:485 +0x208
created by github.com/bitly/nsq/nsqd.NewChannel
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:121 +0x44c

goroutine 32 [semacquire]:
sync.runtime_Semacquire(0xc20801abe4)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/runtime/sema.goc:199 +0x30
sync.(*Mutex).Lock(0xc20801abe0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/sync/mutex.go:66 +0xd6
log.(*Logger).Output(0xc20801abe0, 0x2, 0xc208005080, 0x5d, 0x0, 0x0)
/usr/local/Cellar/go/1.3.1/libexec/src/pkg/log/log.go:134 +0x9b
github.com/bitly/nsq/nsqd.(*diskQueue).logf(0xc2080da160, 0x878e10, 0x22, 0x7fad6865dde0, 0x2, 0x2)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:100 +0xbd
github.com/bitly/nsq/nsqd.(*diskQueue).readOne(0xc2080da160, 0x0, 0x0, 0x0, 0x0, 0x0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:242 +0x25c
github.com/bitly/nsq/nsqd.(*diskQueue).ioLoop(0xc2080da160)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:576 +0x5fe
created by github.com/bitly/nsq/nsqd.newDiskQueue
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/diskqueue.go:91 +0x332

goroutine 33 [select]:
github.com/bitly/nsq/nsqd.(*Channel).messagePump(0xc2080108c0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:569 +0x491
created by github.com/bitly/nsq/nsqd.NewChannel
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:116 +0x372

goroutine 34 [select]:
github.com/bitly/nsq/nsqd.(*Channel).pqWorker(0xc2080108c0, 0xc208010998, 0xc2080109b0, 0x7fad68659f68)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:648 +0x259
github.com/bitly/nsq/nsqd.(*Channel).deferredWorker(0xc2080108c0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:602 +0x7b
github.com/bitly/nsq/nsqd.funcÂ·002()
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:118 +0x29
github.com/bitly/nsq/util.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:14 +0x2e
created by github.com/bitly/nsq/util.(*WaitGroupWrapper).Wrap
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:16 +0xac

goroutine 35 [select]:
github.com/bitly/nsq/nsqd.(*Channel).inFlightWorker(0xc2080108c0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:608 +0x432
github.com/bitly/nsq/nsqd.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:119 +0x29
github.com/bitly/nsq/util.funcÂ·003()
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:14 +0x2e
created by github.com/bitly/nsq/util.(*WaitGroupWrapper).Wrap
/Users/mreiferson/dev/src/github.com/bitly/nsq/util/wait_group_wrapper.go:16 +0xac

goroutine 36 [select]:
github.com/bitly/nsq/nsqd.(*NSQD).Notify(0xc2080c6000, 0x7f7800, 0xc2080108c0)
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/nsqd.go:485 +0x208
created by github.com/bitly/nsq/nsqd.NewChannel
/Users/mreiferson/dev/src/github.com/bitly/nsq/nsqd/channel.go:121 +0x44c
```

The panicking function has no bounds checking. The theory is that the diskqueue size param was tweaked between different runs of nsq, but we're not sure if that param was actually tweaked or if that is another avenue to the same failure.