You can always increase your timeouts a bit.
On Thu, Aug 19, 2010 at 12:52 AM, Qing Yan <qing...@gmail.com> wrote:
> Oh.. our servers are also running in a virtualized environment.
>
> On Thu, Aug 19, 2010 at 2:58 PM, Martin Waite <waite....@gmail.com> wrote:
>
> > Hi,
> >
> > I have tripped over similar problems testing Red Hat Cluster in
> virtualised
> > environments. I don't know whether recent linux kernels have improved
> > their
> > interaction with VMWare, but in our environments clock drift caused by
> lost
> > ticks can be substantial, requiring NTP to sometimes jump the clock
> rather
> > than control acceleration. In one of our internal production rigs, the
> > local NTP servers themselves were virtualised - causing absolute mayhem
> > when
> > heavy loads hit the other guests on the same physical hosts.
> >
> > The effect on RHCS (v2.0) is quite dramatic. A forward jump in time by
> 10
> > seconds always causes a member to prematurely time-out on a network read,
> > causing the member to drop out and trigger a cluster reconfiguration.
> > Apparently NTP is integrated with RHCS version 3, but I don't know what
> is
> > meant by that.
> >
> > I guess this post is not entirely relevent to ZK, but I am just making
> the
> > point that virtualisation (of NTP servers and or clients) can cause
> > repeated
> > premature timeouts. On Linux, I believe that there is a class of timers
> > provided that is immune to this, but I doubt that there is a platform
> > independent way of coping with this.
> >
> > My 2p.
> >
> > regards,
> > Martin
> >
> > On 18 August 2010 16:53, Patrick Hunt <ph...@apache.org> wrote:
> >
> > > Do you expect the time to be "wrong" frequently? If ntp is running it
> > > should never get out of sync more than a small amount. As long as this
> is
> > > less than ~your timeout you should be fine.
> > >
> > > Patrick
> > >
> > >
> > > On 08/18/2010 01:04 AM, Qing Yan wrote:
> > >
> > >> Hi,
> > >>
> > >> The testcase is fairly simple. We have a client which connects to
> ZK,
> > >> registers an ephemeral node and watches on it. Now change the client
> > >> machine's time - session killed..
> > >>
> > >> Here is the log:
> > >>
> > >> *2010-08-18 04:24:57,782 INFO
> > >> com.taobao.timetunnel2.cluster.service.AgentService: Host name
> > >> kgbtest1.corp.alimama.com
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:zookeeper.version=3.2.2-888565, built on 12/08/2009 21:51
> > GMT
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:host.name=kgbtest1.corp.alimama.com
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:java.version=1.6.0_13
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:java.vendor=Sun Microsystems Inc.
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:java.home=/usr/java/jdk1.6.0_13/jre
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >>
> > >>
> >
> environment:java.class.path=/home/admin/TimeTunnel2/cluster/bin/../conf/agent/:/home/admin/TimeTunnel2/cluster/bin/../lib/slf4j-log4j12-1.5.2.jar:/home/admin/TimeTunnel2/cluster/bin/../lib/slf4j-api-1.5.2.jar:/home/admin/TimeTunnel2/cluster/bin/../lib/timetunnel2-cluster-0.0.1-SNAPSHOT.jar:/home/admin/TimeTunnel2/cluster/bin/../lib/zookeeper-3.2.2.jar:/home/admin/TimeTunnel2/cluster/bin/../lib/log4j-1.2.14.jar:/home/admin/TimeTunnel2/cluster/bin/../lib/gson-1.4.jar:/home/admin/TimeTunnel2/cluster/bin/../lib/zk-recipes.jar
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >>
> > >>
> >
> environment:java.library.path=/usr/java/jdk1.6.0_13/jre/lib/amd64/server:/usr/java/jdk1.6.0_13/jre/lib/amd64:/usr/java/jdk1.6.0_13/jre/../lib/amd64:/usr/java/packages/lib/amd64:/lib:/usr/lib
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:java.io.tmpdir=/tmp
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:java.compiler=<NA>
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:os.name=Linux
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:os.arch=amd64
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:os.version=2.6.18-164.el5
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:user.name=admin
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:user.home=/home/admin
> > >> 2010-08-18 04:24:57,789 INFO org.apache.zookeeper.ZooKeeper: Client
> > >> environment:user.dir=/home/admin/TimeTunnel2/cluster/log
> > >> 2010-08-18 04:24:57,790 INFO org.apache.zookeeper.ZooKeeper:
> Initiating
> > >> client connection, connectString=xentest10-vm5.corp.alimama.com:2181,
> > >> xentest10-vm6.corp.alimama.com:2181,
> xentest10-vm9.corp.alimama.com:2181
> > >> sessionTimeout=600000
> > >> watcher=com.taobao.timetunnel2.cluster.service.agentserv...@48d6c16c
> > >> 2010-08-18 04:24:57,791 INFO org.apache.zookeeper.ClientCnxn:
> > >> zookeeper.disableAutoWatchReset is false
> > >> 2010-08-18 04:24:57,817 INFO org.apache.zookeeper.ClientCnxn:
> Attempting
> > >> connection to server xentest10-vm5.corp.alimama.com/10.254.5.160:2181
> > >> 2010-08-18 04:24:57,818 INFO org.apache.zookeeper.ClientCnxn: Priming
> > >> connection to java.nio.channels.SocketChannel[connected local=/
> > >> 10.254.2.160:48536 remote=
> > >> xentest10-vm5.corp.alimama.com/10.254.5.160:2181]
> > >> 2010-08-18 04:24:57,821 INFO org.apache.zookeeper.ClientCnxn: Server
> > >> connection successful
> > >> 2010-08-18 04:24:57,832 INFO
> > >> com.taobao.timetunnel2.cluster.service.AgentService: Register...
> > >> 2010-08-18 04:24:57,834 DEBUG org.apache.zookeeper.ClientCnxn: Reading
> > >> reply
> > >> sessionid:0x12a8413f71a0003, packet:: clientPath:null serverPath:null
> > >> finished:false header:: -8,101 replyHeader:: -8,-1,0 request::
> > >> 0,v{},v{},v{} response:: null
> > >> 2010-08-18 04:24:57,846 DEBUG org.apache.zookeeper.ClientCnxn: Reading
> > >> reply
> > >> sessionid:0x12a8413f71a0003, packet:: clientPath:null serverPath:null
> > >> finished:false header:: 1,1 replyHeader:: 1,8589934649,-110
> request::
> > >> '/agent,,v{s{31,s{'world,'anyone}}},0 response::
> > >> 2010-08-18 04:24:57,853 DEBUG
> > >> com.taobao.timetunnel2.cluster.zookeeper.operation.PathCreator: Path
> > >> /agent
> > >> already exist
> > >> 2010-08-18 04:24:57,882 DEBUG org.apache.zookeeper.ClientCnxn: Reading
> > >> reply
> > >> sessionid:0x12a8413f71a0003, packet:: clientPath:null serverPath:null
> > >> finished:false header:: 2,1 replyHeader:: 2,8589934650,-110
> request::
> > >> '/agent/status,,v{s{31,s{'world,'anyone}}},0 response::
> > >> 2010-08-18 04:24:57,882 DEBUG
> > >> com.taobao.timetunnel2.cluster.zookeeper.operation.PathCreator: Path
> > >> /agent/status already exist
> > >> 2010-08-18 04:24:57,886 DEBUG org.apache.zookeeper.ClientCnxn: Reading
> > >> reply
> > >> sessionid:0x12a8413f71a0003, packet:: clientPath:null serverPath:null
> > >> finished:false header:: 3,1 replyHeader:: 3,8589934651,0 request::
> > >> '/agent/status/kgbtest1.corp.alimama.com
> ,,v{s{31,s{'world,'anyone}}},1
> > >> response:: '/agent/status/kgbtest1.corp.alimama.com
> > >> 2010-08-18 04:24:57,886 DEBUG
> > >> com.taobao.timetunnel2.cluster.zookeeper.operation.PathCreator: Path
> > >> /agent/status/kgbtest1.corp.alimama.com creation OK
> > >> 2010-08-18 04:24:57,886 INFO
> > >> com.taobao.timetunnel2.cluster.service.AgentService: Watch for ->
> > >> /agent/status/kgbtest1.corp.alimama.com
> > >> 2010-08-18 04:24:57,892 DEBUG org.apache.zookeeper.ClientCnxn: Reading
> > >> reply
> > >> sessionid:0x12a8413f71a0003, packet:: clientPath:null serverPath:null
> > >> finished:false header:: 4,4 replyHeader:: 4,-1,0 request::
> > >> '/agent/status/
> > >> kgbtest1.corp.alimama.com,T response::
> > >>
> > >>
> >
> ,s{8589934651,8589934651,1282116165777,1282116165777,0,0,0,84024764344696835,0,0,8589934651}
> > >>
> > >> 2010-08-18 04:24:57,892 INFO
> > >> com.taobao.timetunnel2.cluster.service.AgentService: Data changed
> > >> @/agent/status/kgbtest1.corp.alimama.com
> > >> 2010-08-18 04:25:11,226 DEBUG org.apache.zookeeper.ClientCnxn: Got
> ping
> > >> response for sessionid:0x12a8413f71a0003 after 1ms
> > >> 2010-08-18 04:25:24,560 DEBUG org.apache.zookeeper.ClientCnxn: Got
> ping
> > >> response for sessionid:0x12a8413f71a0003 after 2ms
> > >> 2010-08-18 04:25:37,893 DEBUG org.apache.zookeeper.ClientCnxn: Got
> ping
> > >> response for sessionid:0x12a8413f71a0003 after 1ms
> > >> 2010-08-18 04:19:44,853 DEBUG org.apache.zookeeper.ClientCnxn: Got
> > >> notification sessionid:0x12a8413f71a0003
> > >> 2010-08-18 04:19:44,854 DEBUG org.apache.zookeeper.ClientCnxn: Got
> > >> WatchedEvent: Znode change. Path:
> > >> /agent/status/kgbtest1.corp.alimama.comType: NodeDeleted for sessionid
> > >> 0x12a8413f71a0003
> > >> 2010-08-18 04:19:44,854 DEBUG
> > >> com.taobao.timetunnel2.cluster.zookeeper.operation.PathDataWatcher:
> > >> getChildren event =>WatchedEvent: Znode change. Path: /agent/status/
> > >> kgbtest1.corp.alimama.com Type: NodeDeleted
> > >> 2010-08-18 04:19:44,855 WARN org.apache.zookeeper.ClientCnxn:
> Exception
> > >> closing session 0x12a8413f71a0003 to
> > sun.nio.ch.selectionkeyi...@7ca3d4cf
> > >> java.io.IOException: Read error rc = -1
> java.nio.DirectByteBuffer[pos=0
> > >> lim=4 cap=4]
> > >> at
> > >>
> > >>
> >
> org.apache.zookeeper.ClientCnxn$SendThread.doIO(zookeeper:ClientCnxn.java):701)
> > >> at
> > >>
> > >>
> >
> org.apache.zookeeper.ClientCnxn$SendThread.run(zookeeper:ClientCnxn.java):945)
> > >> 2010-08-18 04:19:45,591 INFO org.apache.zookeeper.ClientCnxn:
> Attempting
> > >> connection to server xentest10-vm6.corp.alimama.com/10.254.5.161:2181
> > >> 2010-08-18 04:19:45,591 INFO org.apache.zookeeper.ClientCnxn: Priming
> > >> connection to java.nio.channels.SocketChannel[connected local=/
> > >> 10.254.2.160:45776 remote=
> > >> xentest10-vm6.corp.alimama.com/10.254.5.161:2181]
> > >> 2010-08-18 04:19:45,591 INFO org.apache.zookeeper.ClientCnxn: Server
> > >> connection successful
> > >> 2010-08-18 04:19:45,593 WARN org.apache.zookeeper.ClientCnxn:
> Exception
> > >> closing session 0x12a8413f71a0003 to
> > sun.nio.ch.selectionkeyi...@2fdb7df8
> > >> java.io.IOException: Session Expired
> > >> at
> > >>
> > >>
> >
> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(zookeeper:ClientCnxn.java):589)
> > >> at
> > >>
> > >>
> >
> org.apache.zookeeper.ClientCnxn$SendThread.doIO(zookeeper:ClientCnxn.java):709)
> > >> at
> > >>
> > >>
> >
> org.apache.zookeeper.ClientCnxn$SendThread.run(zookeeper:ClientCnxn.java):945)
> > >>
> > >> * I guess ZK might rely on timestamp to keep sessions alive, but we
> > >> have
> > >> NTP daemon running so machine time can get changed
> > >> automatically, is there a conflict?
> > >>
> > >>
> >
>
