Panic via nsq.Producer

[mreiferson]

I'm writing a message dispatcher based on nsq. I'm running into a panic that seems to be originating within the go-nsq library (or, so says the stack trace). Any ideas? The panic occurs on this line.

The test case in question can be found here.

Try it for yourself:
Start nsqd running (locally), then:

go get github.com/philhofer/fluxlog
cd $GOPATH/github.com/philhofer/fluxlog
go test -v -tags 'nsq'

(I'm compiling with go1.3rc1, because my package depends on sync.Pool.)

The test tries to write 10 messages to a topic called "test" - which seems to work ok. Then the *nsq.Producer code tries to close the tcp connection, and everything goes to hell.

This may be an issue on my end, but if it is, I can't find it.

Thanks in advance.

[mreiferson]

I'll take a look - thanks for the report @philhofer

[mreiferson]

@philhofer - whats the revision of the checkout for the go-nsq you're compiling against?

[philhofer]

@mreiferson I pulled the latest master as of a few hours ago.

[mreiferson]

I'm trying to reproduce but I'm running into issues compiling fluxlog:

mreiferson@AIRSNAKES ~/dev/src/github.com/philhofer/fluxlog](master)$ go test -v -a
# github.com/philhofer/fluxlog
./init.go:120: cannot use l.list.Read() (type gringo.Payload) as type *capn.Segment in assignment
./init.go:180: cannot use seg (type *capn.Segment) as type gringo.Payload in argument to l.list.Write
./init.go:189: cannot use seg (type *capn.Segment) as type gringo.Payload in argument to l.list.Write
./types_test.go:42: cannot use msg (type *capn.Segment) as type gringo.Payload in argument to g.Write
./types_test.go:49: cannot use g.Read() (type gringo.Payload) as type *capn.Segment in assignment
FAIL    github.com/philhofer/fluxlog [build failed]

[philhofer]

@mreiferson My bad - I hadn't pushed changes for a dependency. If you go get -u it should compile ok now.

[mreiferson]

@philhofer - it compiles, but I can't reproduce.

The test deadlocks because your producer loop sits here - https://github.com/philhofer/fluxlog/blob/master/init.go#L119-L120. When your test goes to Close() the logger, it blocks on https://github.com/philhofer/fluxlog/blob/master/init.go#L195 because the aforementioned loop is sitting in the default case waiting for an entry on the queue.

There may indeed be some issue to resolve with the go-nsq cleanup but I suspect it's related to trying to publish after calling Stop on the Producer.

Can you reliably reproduce the error without changing the code?

[mreiferson]

@philhofer - OK, I was able to reproduce some issues when removing all the sleep in your test. There was a race between connecting and closing in quick succession. I've attached a commit that fixes it to this issue (RFR @jehiah)

Also, after fixing the go-nsq issue, it uncovered a problem with your ordering in Logger.Close - you need to close the done channel after stopping the producer, not before (because it is still trying to flush pending async publishes, so it fails "sending on a closed channel"). Also, because you're publishing asynchronously, your test obviously needs to account for that (which is probably why you had sleeps in there in the first place).

Thanks again for the report.

[philhofer]

@mreiferson Thanks, I appreciate it!