The following message has started turning up in our Zookeeper log.

INFO Refusing session request for client /127.0.0.1:59992 as it has
seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client must try
another server (org.apache.zookeeper.server.NIOServerCnxn)

I am using Zookeeper with the Kafka message queue. My Zookeeper version is

zookeeper.version=3.3.3-1073969, built on 02/23/2011 22:27 GMT

I suspect this may be a problem with my Kakfa client, but I'm
wondering under what circumstances this situation occurs in Zookeeper,
and what we can do about it when it arises.

Thanks

Simon

ZK guarantees that you never "go back in time". As such zk clients
remember the last zxid they saw from the ZK service. If a client
disconnects and reconnects to a new server in the ensemble it checks
to see if the server is at the same point, or subsequent to, the last
zxid seen by the client. If the client has seen updates later (more
recent) than the server it will disconnect and reconnect to another
server in the ensemble.

Likely here you had clients running against a service, then shutdown
the service and cleared out the datadirs and restarted the service (ie
reset). In which case the service starts at zxid 0 while the client
has seen much larger. Notice the server is at "0x9ba". That's the most
common scenario that I see with this. Another option is that you have
a server which is not part of the service (ie misconfigured) and some
of the serving ensemble has a high zxid, while this server is not
participating in the quorum.

Patrick

On Thu, Aug 30, 2012 at 3:53 PM, Simon Doherty
<[EMAIL PROTECTED]> wrote:
> The following message has started turning up in our Zookeeper log.
>
> INFO Refusing session request for client /127.0.0.1:59992 as it has
> seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client must try
> another server (org.apache.zookeeper.server.NIOServerCnxn)
>
> I am using Zookeeper with the Kafka message queue. My Zookeeper version is
>
> zookeeper.version=3.3.3-1073969, built on 02/23/2011 22:27 GMT
>
> I suspect this may be a problem with my Kakfa client, but I'm
> wondering under what circumstances this situation occurs in Zookeeper,
> and what we can do about it when it arises.
>
> Thanks
>
>
>
> Simon

But isn't the larger ZXID pretty stunningly large?

The epoch number is nearly 2 billion and the transaction id is 845 million.
 These seem implausible from a starting point of 0.

On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:

> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client

Good point Ted. Is this a java ZK client or something else? (memory
corruption on client possible?)

Patrick

On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <[EMAIL PROTECTED]> wrote:
> But isn't the larger ZXID pretty stunningly large?
>
> The epoch number is nearly 2 billion and the transaction id is 845 million.
>  These seem implausible from a starting point of 0.
>
> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>
>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client

This is interesting, if you convert 0x636c65616e2d7374 to ascii you
get "clean-st". Looks like memory corruption to me.

Patrick

On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
> Good point Ted. Is this a java ZK client or something else? (memory
> corruption on client possible?)
>
> Patrick
>
> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <[EMAIL PROTECTED]> wrote:
>> But isn't the larger ZXID pretty stunningly large?
>>
>> The epoch number is nearly 2 billion and the transaction id is 845 million.
>>  These seem implausible from a starting point of 0.
>>
>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>>
>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client

Nice debugging Pat! Really interesting! :)

thanks
mahadev

On Fri, Aug 31, 2012 at 3:12 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
> This is interesting, if you convert 0x636c65616e2d7374 to ascii you
> get "clean-st". Looks like memory corruption to me.
>
> Patrick
>
> On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>> Good point Ted. Is this a java ZK client or something else? (memory
>> corruption on client possible?)
>>
>> Patrick
>>
>> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <[EMAIL PROTECTED]> wrote:
>>> But isn't the larger ZXID pretty stunningly large?
>>>
>>> The epoch number is nearly 2 billion and the transaction id is 845 million.
>>>  These seem implausible from a starting point of 0.
>>>
>>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>>>
>>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client

Thanks very much for your help people!

So the strange zxid value was supplied by the client during session
start up. That suggests to me that it's a bug in the client I'm using.
Is that true?

Thanks

Simon
On Sat, Sep 1, 2012 at 11:29 AM, Mahadev Konar <[EMAIL PROTECTED]> wrote:
>  Nice debugging Pat! Really interesting! :)
>
> thanks
> mahadev
>
> On Fri, Aug 31, 2012 at 3:12 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>> This is interesting, if you convert 0x636c65616e2d7374 to ascii you
>> get "clean-st". Looks like memory corruption to me.
>>
>> Patrick
>>
>> On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>>> Good point Ted. Is this a java ZK client or something else? (memory
>>> corruption on client possible?)
>>>
>>> Patrick
>>>
>>> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <[EMAIL PROTECTED]> wrote:
>>>> But isn't the larger ZXID pretty stunningly large?
>>>>
>>>> The epoch number is nearly 2 billion and the transaction id is 845 million.
>>>>  These seem implausible from a starting point of 0.
>>>>
>>>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>>>>
>>>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client

Yes.  Is this a C-based client?  If so, memory corruption is less
surprising.

If java based, then such memory corruption is big news.

On Sun, Sep 2, 2012 at 5:46 PM, Simon Doherty <[EMAIL PROTECTED]>wrote:

> Thanks very much for your help people!
>
> So the strange zxid value was supplied by the client during session
> start up. That suggests to me that it's a bug in the client I'm using.
> Is that true?
>
> Thanks
>
>
>
> Simon
>
>
> On Sat, Sep 1, 2012 at 11:29 AM, Mahadev Konar <[EMAIL PROTECTED]>
> wrote:
> >  Nice debugging Pat! Really interesting! :)
> >
> > thanks
> > mahadev
> >
> > On Fri, Aug 31, 2012 at 3:12 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
> >> This is interesting, if you convert 0x636c65616e2d7374 to ascii you
> >> get "clean-st". Looks like memory corruption to me.
> >>
> >> Patrick
> >>
> >> On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
> >>> Good point Ted. Is this a java ZK client or something else? (memory
> >>> corruption on client possible?)
> >>>
> >>> Patrick
> >>>
> >>> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <[EMAIL PROTECTED]>
> wrote:
> >>>> But isn't the larger ZXID pretty stunningly large?
> >>>>
> >>>> The epoch number is nearly 2 billion and the transaction id is 845
> million.
> >>>>  These seem implausible from a starting point of 0.
> >>>>
> >>>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]>
> wrote:
> >>>>
> >>>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client
>

Well, it's part of a clojure client for the Kafka queue called
kafka-clj, but it uses Netflix's Curator Framework to talk to
Zookeeper.

The kafka-clj client doesn't seem to be very actively developed, so I
suspect that the problem is there. (Perhaps some arguments have been
mixed up somewhere.)

The Curator Framework is developed and used more actively, so it
should be more reliable. I'll post another message to their mailing
list. But I don't want to impugn their reliability at the moment. :)

Thanks
Simon
On Tue, Sep 4, 2012 at 7:21 AM, Ted Dunning <[EMAIL PROTECTED]> wrote:
> Yes.  Is this a C-based client?  If so, memory corruption is less
> surprising.
>
> If java based, then such memory corruption is big news.
>
> On Sun, Sep 2, 2012 at 5:46 PM, Simon Doherty <[EMAIL PROTECTED]>wrote:
>
>> Thanks very much for your help people!
>>
>> So the strange zxid value was supplied by the client during session
>> start up. That suggests to me that it's a bug in the client I'm using.
>> Is that true?
>>
>> Thanks
>>
>>
>>
>> Simon
>>
>>
>> On Sat, Sep 1, 2012 at 11:29 AM, Mahadev Konar <[EMAIL PROTECTED]>
>> wrote:
>> >  Nice debugging Pat! Really interesting! :)
>> >
>> > thanks
>> > mahadev
>> >
>> > On Fri, Aug 31, 2012 at 3:12 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>> >> This is interesting, if you convert 0x636c65616e2d7374 to ascii you
>> >> get "clean-st". Looks like memory corruption to me.
>> >>
>> >> Patrick
>> >>
>> >> On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]> wrote:
>> >>> Good point Ted. Is this a java ZK client or something else? (memory
>> >>> corruption on client possible?)
>> >>>
>> >>> Patrick
>> >>>
>> >>> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <[EMAIL PROTECTED]>
>> wrote:
>> >>>> But isn't the larger ZXID pretty stunningly large?
>> >>>>
>> >>>> The epoch number is nearly 2 billion and the transaction id is 845
>> million.
>> >>>>  These seem implausible from a starting point of 0.
>> >>>>
>> >>>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]>
>> wrote:
>> >>>>
>> >>>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client
>>

That should come under the general heading of Java client issues.

This is mildly disturbing that this happened at all.  If it persists,
please make more noise.

On Mon, Sep 3, 2012 at 5:38 PM, Simon Doherty <[EMAIL PROTECTED]>wrote:

> Well, it's part of a clojure client for the Kafka queue called
> kafka-clj, but it uses Netflix's Curator Framework to talk to
> Zookeeper.
>
> The kafka-clj client doesn't seem to be very actively developed, so I
> suspect that the problem is there. (Perhaps some arguments have been
> mixed up somewhere.)
>
> The Curator Framework is developed and used more actively, so it
> should be more reliable. I'll post another message to their mailing
> list. But I don't want to impugn their reliability at the moment. :)
>
> Thanks
>
>
> Simon
>
>
> On Tue, Sep 4, 2012 at 7:21 AM, Ted Dunning <[EMAIL PROTECTED]> wrote:
> > Yes.  Is this a C-based client?  If so, memory corruption is less
> > surprising.
> >
> > If java based, then such memory corruption is big news.
> >
> > On Sun, Sep 2, 2012 at 5:46 PM, Simon Doherty <[EMAIL PROTECTED]
> >wrote:
> >
> >> Thanks very much for your help people!
> >>
> >> So the strange zxid value was supplied by the client during session
> >> start up. That suggests to me that it's a bug in the client I'm using.
> >> Is that true?
> >>
> >> Thanks
> >>
> >>
> >>
> >> Simon
> >>
> >>
> >> On Sat, Sep 1, 2012 at 11:29 AM, Mahadev Konar <[EMAIL PROTECTED]
> >
> >> wrote:
> >> >  Nice debugging Pat! Really interesting! :)
> >> >
> >> > thanks
> >> > mahadev
> >> >
> >> > On Fri, Aug 31, 2012 at 3:12 PM, Patrick Hunt <[EMAIL PROTECTED]>
> wrote:
> >> >> This is interesting, if you convert 0x636c65616e2d7374 to ascii you
> >> >> get "clean-st". Looks like memory corruption to me.
> >> >>
> >> >> Patrick
> >> >>
> >> >> On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]>
> wrote:
> >> >>> Good point Ted. Is this a java ZK client or something else? (memory
> >> >>> corruption on client possible?)
> >> >>>
> >> >>> Patrick
> >> >>>
> >> >>> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <
> [EMAIL PROTECTED]>
> >> wrote:
> >> >>>> But isn't the larger ZXID pretty stunningly large?
> >> >>>>
> >> >>>> The epoch number is nearly 2 billion and the transaction id is 845
> >> million.
> >> >>>>  These seem implausible from a starting point of 0.
> >> >>>>
> >> >>>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]>
> >> wrote:
> >> >>>>
> >> >>>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client
> >>
>

Will do.

On Tue, Sep 4, 2012 at 9:40 AM, Ted Dunning <[EMAIL PROTECTED]> wrote:
> That should come under the general heading of Java client issues.
>
> This is mildly disturbing that this happened at all.  If it persists,
> please make more noise.
>
> On Mon, Sep 3, 2012 at 5:38 PM, Simon Doherty <[EMAIL PROTECTED]>wrote:
>
>> Well, it's part of a clojure client for the Kafka queue called
>> kafka-clj, but it uses Netflix's Curator Framework to talk to
>> Zookeeper.
>>
>> The kafka-clj client doesn't seem to be very actively developed, so I
>> suspect that the problem is there. (Perhaps some arguments have been
>> mixed up somewhere.)
>>
>> The Curator Framework is developed and used more actively, so it
>> should be more reliable. I'll post another message to their mailing
>> list. But I don't want to impugn their reliability at the moment. :)
>>
>> Thanks
>>
>>
>> Simon
>>
>>
>> On Tue, Sep 4, 2012 at 7:21 AM, Ted Dunning <[EMAIL PROTECTED]> wrote:
>> > Yes.  Is this a C-based client?  If so, memory corruption is less
>> > surprising.
>> >
>> > If java based, then such memory corruption is big news.
>> >
>> > On Sun, Sep 2, 2012 at 5:46 PM, Simon Doherty <[EMAIL PROTECTED]
>> >wrote:
>> >
>> >> Thanks very much for your help people!
>> >>
>> >> So the strange zxid value was supplied by the client during session
>> >> start up. That suggests to me that it's a bug in the client I'm using.
>> >> Is that true?
>> >>
>> >> Thanks
>> >>
>> >>
>> >>
>> >> Simon
>> >>
>> >>
>> >> On Sat, Sep 1, 2012 at 11:29 AM, Mahadev Konar <[EMAIL PROTECTED]
>> >
>> >> wrote:
>> >> >  Nice debugging Pat! Really interesting! :)
>> >> >
>> >> > thanks
>> >> > mahadev
>> >> >
>> >> > On Fri, Aug 31, 2012 at 3:12 PM, Patrick Hunt <[EMAIL PROTECTED]>
>> wrote:
>> >> >> This is interesting, if you convert 0x636c65616e2d7374 to ascii you
>> >> >> get "clean-st". Looks like memory corruption to me.
>> >> >>
>> >> >> Patrick
>> >> >>
>> >> >> On Fri, Aug 31, 2012 at 1:34 PM, Patrick Hunt <[EMAIL PROTECTED]>
>> wrote:
>> >> >>> Good point Ted. Is this a java ZK client or something else? (memory
>> >> >>> corruption on client possible?)
>> >> >>>
>> >> >>> Patrick
>> >> >>>
>> >> >>> On Fri, Aug 31, 2012 at 12:56 PM, Ted Dunning <
>> [EMAIL PROTECTED]>
>> >> wrote:
>> >> >>>> But isn't the larger ZXID pretty stunningly large?
>> >> >>>>
>> >> >>>> The epoch number is nearly 2 billion and the transaction id is 845
>> >> million.
>> >> >>>>  These seem implausible from a starting point of 0.
>> >> >>>>
>> >> >>>> On Fri, Aug 31, 2012 at 12:54 PM, Patrick Hunt <[EMAIL PROTECTED]>
>> >> wrote:
>> >> >>>>
>> >> >>>>> > seen zxid 0x636c65616e2d7374 our last zxid is 0x9ba client
>> >>
>>