bug in function handler

[beardeddog]

encountered a repeated failure traced down into conn.go, function handler, in the receive loop where the the log message Response for unknown request with xid # is sent.

existing code is

} else {
            c.requestsLock.Lock()
            req, ok := c.requests[res.Xid]
            if ok {
                delete(c.requests, res.Xid)
            }
            c.requestsLock.Unlock()

            if !ok {
>>              log.Printf("Response for unknown request with xid %d", res.Xid)
            } else {
                _, err := decodePacket(buf[:blen], req.recvStruct)
                req.recvChan <- err
            }
        }

changed the

log.Printf("Response for unknown request with xid %d", res.Xid)

to be

req.recvChan <- errors.New("UNKWNREQ: Response for unknown request with xid " + string(res.Xid))

basically the channel needs a reply, otherwise we just hang

the error message I'm sending back is something you probably want to align with your error handling, but I did need to see this specific error so I could attempt recovery in my client code, in my case I just retry if I get this error

Bill

[samuel]

Unfortunately in this case it's not possible to respond back because the request is unknown. For the "!ok" condition the "req" will be nil. If you're seeing this then there's something else going on elsewhere. Could you provide more details about what you were doing when you ran into this error?

[beardeddog]

basically I have an app that accesses zookeeper data in a fairly tight loop, the connection server list contains 5 zookeeper node names, that is being randomized. The app gets stats for a set of queues, displaying them to stdout. The loop is just the app being run in watch. With the hack I made when I do see this error, I am able to recover and retry. Before my hack, things would halt right after printing the error message. If you want to try and reproduce this, your should be able to try repeatedly getting zookeeper data in a tight watch loop.

Maybe I can add some more debugging to the error.

[horkhe]

We experienced the same issue and I have traced down the root cause. When requests are generated from different goroutines several requests may be assigned the same xid due to the fact that conn.lastZxid is not updated right after a request is created, but after a response is received - I was wrong about that being the route cause, the actual root cause is that c.authenticate() method resets the c.xid to 0, and it is possible to submit requests before c.authenticate() method is called.