[zeromq-dev] Strange behaviour running Clone Server Reliability v6 example from ZGuide

[Matt McClean]

Hi there,

Have tried to run the clone server example v6 from the Zguide and getting 
some weird behavior that I wanted to check. I am attempting to run the C 
example with two clone servers and two clients. I start the primary clone 
server and it gives the following output:

MacBookPro:C matt$ clonesrv6 -p
12-02-08 11:28:22 I: primary master, waiting for backup (slave)
12-02-08 11:28:22 I: zloop: register SUB poller (0x7fb692403bb0, 0)
12-02-08 11:28:22 I: zloop: register timer delay=1000 times=0
12-02-08 11:28:22 I: zloop: register timer delay=1000 times=0
12-02-08 11:28:22 I: zloop: polling for 1000 msec
12-02-08 11:28:23 I: zloop: call timer handler
12-02-08 11:28:23 I: zloop: call timer handler
12-02-08 11:28:23 I: zloop: call timer handler
12-02-08 11:28:23 I: zloop: polling for 1000 msec
12-02-08 11:28:24 I: zloop: call timer handler
12-02-08 11:28:24 I: zloop: call timer handler
12-02-08 11:28:24 I: zloop: call timer handler
12-02-08 11:28:24 I: zloop: polling for 999 msec

I then start the second clone server and it gives the following:

MacBookPro:C matt$ clonesrv6 -b
12-02-08 11:29:01 I: backup slave, waiting for primary (master)
12-02-08 11:29:01 I: zloop: register SUB poller (0x7fbf5bc03b90, 0)
12-02-08 11:29:01 I: zloop: register timer delay=1000 times=0
12-02-08 11:29:01 I: zloop: register timer delay=1000 times=0
12-02-08 11:29:01 I: zloop: polling for 1000 msec
12-02-08 11:29:01 I: zloop: call SUB socket handler (0x7fbf5bd012a0, 0)
12-02-08 11:29:01 I: zloop: polling for 398 msec
12-02-08 11:29:02 I: zloop: call timer handler
12-02-08 11:29:02 I: zloop: call timer handler
12-02-08 11:29:02 I: zloop: call timer handler
12-02-08 11:29:02 I: zloop: polling for 1000 msec
12-02-08 11:29:02 I: zloop: call SUB socket handler (0x7fbf5bd012a0, 0)
12-02-08 11:29:02 I: connected to primary (master), ready as slave
12-02-08 11:29:02 I: zloop: register SUB poller (0x7fbf5bc04450, 0)
12-02-08 11:29:02 I: zloop: polling for 397 msec
12-02-08 11:29:02 I: zloop: call SUB socket handler (0x7fbf5bc04450, 0)
12-02-08 11:29:02 I: asking for snapshot from: tcp://localhost:5556

Then the primary clone server starts spitting out a lot of output in the 
console with the following lines without any client connected:

CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: call ROUTER socket handler (0x7fb6924018a0, 0)
CLIENT REQUEST
12-02-08 11:29:26 I: zloop: polling for 670 msec
12-02-08 11:29:26 I: zloop: ca

I then try to connect client and it send messages OK but every so often 
they seem to detect that the primary clone server is down with the 
following output:

MacBookPro:C matt$ clonecli6
12-02-08 11:31:41 I: adding server tcp://localhost:5556...
12-02-08 11:31:41 I: waiting for server at tcp://localhost:5556...
12-02-08 11:31:41 I: adding server tcp://localhost:5566...
/client/8401
/client/7984
/client/3352
/client/5539
/client/3647
12-02-08 11:31:46 I: server at tcp://localhost:5556 didn't give hugz
12-02-08 11:31:46 I: waiting for server at tcp://localhost:5566...
/client/9161
/client/1416
/client/2428
/client/1566
/client/1088
12-02-08 11:31:51 I: server at tcp://localhost:5566 didn't give hugz
12-02-08 11:31:51 I: waiting for server at tcp://localhost:5556...
/client/5129
/client/2960

It seems strange behavior so wanted to check if this was normal for this 
example or not.

Regards,
Matt
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.zeromq.org/pipermail/zeromq-dev/attachments/20120207/9a03e178/attachment.htm>