ha/doozerd — Issue #26: single instance in cluster left standing lockup
Author: mreiferson
Created: 2012-02-28 04:27:42+00:00
State: open

it seems that if a cluster of N nodes is stood up and all but 1 node is taken down, that single node is no longer responsive as demonstrated by the log output below (note: it contains additional debugging statements added as I've been poking around):

reproducing this case should be relatively simple:

```
$ doozerd &
$ doozerd -l 127.0.0.1:8047 -w false -a 127.0.0.1:8046 &
$ export SECONDPID=$!
$ echo -n | doozer add /ctl/cal/1
$ kill -9 $SECONDPID
```

now the remaining instance is in a loop where it is unable to meet the quorom and therefore unable to continue (nor will it respond to any interfaces it is listening on).

i'm still thinking through what I would *expect* the daemon to do in this case, at the very least I would expect it to respond (even if those responses were errors for most operations... allowing one to continue to administrate the cluster and ideally bring it back operationally)

```
DOOZER 2012/02/27 23:14:48.799495 applying 443 TICK
DOOZER 2012/02/27 23:14:48.799504 applied m.tick 1
DOOZER 2012/02/27 23:14:48.799509 p.seqn=443 m.next=494
DOOZER 2012/02/27 23:14:49.278193 p.seqn=444 m.next=494
DOOZER 2012/02/27 23:14:49.278264 __DEBUG: acceptor.update cmd:INVITE seqn:444 crnd:2
DOOZER 2012/02/27 23:14:49.278339 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:INVITE seqn:444 crnd:2 0
DOOZER 2012/02/27 23:14:49.278485 p.seqn=444 m.next=494
DOOZER 2012/02/27 23:14:49.278558 __DEBUG: acceptor.update cmd:RSVP seqn:444 crnd:2 vrnd:0 value:""
DOOZER 2012/02/27 23:14:49.278642 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:RSVP seqn:444 crnd:2 vrnd:0 value:"" 1
DOOZER 2012/02/27 23:14:49.278669 p.seqn=444 m.next=494
DOOZER 2012/02/27 23:14:49.278715 __DEBUG: acceptor.update cmd:RSVP seqn:444 crnd:2 vrnd:0 value:""
DOOZER 2012/02/27 23:14:49.278778 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:RSVP seqn:444 crnd:2 vrnd:0 value:"" 0
DOOZER 2012/02/27 23:14:49.278897 p.seqn=444 m.next=494
DOOZER 2012/02/27 23:14:49.278986 __DEBUG: acceptor.update cmd:NOMINATE seqn:444 crnd:2 value:"-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443"
DOOZER 2012/02/27 23:14:49.279087 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:NOMINATE seqn:444 crnd:2 value:"-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443" 0
DOOZER 2012/02/27 23:14:49.279221 p.seqn=444 m.next=494
DOOZER 2012/02/27 23:14:49.279341 __DEBUG: acceptor.update cmd:VOTE seqn:444 vrnd:2 value:"-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443"
DOOZER 2012/02/27 23:14:49.279448 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:VOTE seqn:444 vrnd:2 value:"-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443" 0
DOOZER 2012/02/27 23:14:49.279480 p.seqn=444 m.next=494
DOOZER 2012/02/27 23:14:49.279534 __DEBUG: acceptor.update cmd:VOTE seqn:444 vrnd:2 value:"-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443"
DOOZER 2012/02/27 23:14:49.279647 __DEBUG: learner.update &{2 2 2 map[-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443:1] [true false] false} cmd:VOTE seqn:444 vrnd:2 value:"-1:/ctl/node/T6JCULE4RZN2CE6L/applied=443" 1
DOOZER 2012/02/27 23:14:49.279667 learn seqn=444
DOOZER 2012/02/27 23:14:49.279873 event {444 /ctl/node/T6JCULE4RZN2CE6L/applied 443 444 -1:/ctl/node/T6JCULE4RZN2CE6L/applied=443 }
DOOZER 2012/02/27 23:14:49.279956 del run 444
DOOZER 2012/02/27 23:14:49.280175 __DEBUG: isLeader T6JCULE4RZN2CE6L VBY7NDUVYVUBIJNF 0 0
DOOZER 2012/02/27 23:14:49.280219 __DEBUG: isLeader VBY7NDUVYVUBIJNF VBY7NDUVYVUBIJNF 0 1
DOOZER 2012/02/27 23:14:49.280236 add run 494
DOOZER 2012/02/27 23:14:49.280287 runs: ..................................................
DOOZER 2012/02/27 23:14:49.280296 avg tick delay: -1
DOOZER 2012/02/27 23:14:49.280304 avg fill delay: -1
DOOZER 2012/02/27 23:14:49.280320 p.seqn=444 m.next=495
DOOZER 2012/02/27 23:14:49.280335 p.seqn=444 m.next=495
DOOZER 2012/02/27 23:14:49.800186 prop &{445 [45 49 58 47 99 116 108 47 110 111 100 101 47 86 66 89 55 78 68 85 86 89 86 85 66 73 74 78 70 47 97 112 112 108 105 101 100 61 52 52 52]}
DOOZER 2012/02/27 23:14:49.800214 p.seqn=445 m.next=495
DOOZER 2012/02/27 23:14:49.800234 sched tick=1 seqn=445 t=197605
DOOZER 2012/02/27 23:14:49.800333 __DEBUG: acceptor.update cmd:PROPOSE seqn:445 value:"-1:/ctl/node/VBY7NDUVYVUBIJNF/applied=444"
DOOZER 2012/02/27 23:14:49.800464 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:PROPOSE seqn:445 value:"-1:/ctl/node/VBY7NDUVYVUBIJNF/applied=444" -1
DOOZER 2012/02/27 23:14:49.800548 p.seqn=445 m.next=495
DOOZER 2012/02/27 23:14:49.800643 __DEBUG: acceptor.update cmd:INVITE seqn:445 crnd:3
DOOZER 2012/02/27 23:14:49.800715 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:INVITE seqn:445 crnd:3 1
DOOZER 2012/02/27 23:14:49.800845 p.seqn=445 m.next=495
DOOZER 2012/02/27 23:14:49.800905 __DEBUG: acceptor.update cmd:RSVP seqn:445 crnd:3 vrnd:0 value:""
DOOZER 2012/02/27 23:14:49.800981 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:RSVP seqn:445 crnd:3 vrnd:0 value:"" 1
DOOZER 2012/02/27 23:14:49.810202 applying 445 TICK
DOOZER 2012/02/27 23:14:49.810221 applied m.tick 1
DOOZER 2012/02/27 23:14:49.810231 p.seqn=445 m.next=495
DOOZER 2012/02/27 23:14:49.810242 tick wasteful=false
DOOZER 2012/02/27 23:14:49.810261 sched tick=2 seqn=445 t=3929262
DOOZER 2012/02/27 23:14:49.810332 __DEBUG: acceptor.update cmd:TICK seqn:445
DOOZER 2012/02/27 23:14:49.810443 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:TICK seqn:445 -1
DOOZER 2012/02/27 23:14:49.810513 p.seqn=445 m.next=495
DOOZER 2012/02/27 23:14:49.810588 __DEBUG: acceptor.update cmd:INVITE seqn:445 crnd:5
DOOZER 2012/02/27 23:14:49.810637 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:INVITE seqn:445 crnd:5 1
DOOZER 2012/02/27 23:14:49.810749 p.seqn=445 m.next=495
DOOZER 2012/02/27 23:14:49.810814 __DEBUG: acceptor.update cmd:RSVP seqn:445 crnd:5 vrnd:0 value:""
DOOZER 2012/02/27 23:14:49.810865 __DEBUG: learner.update &{1 2 2 map[] [false false] false} cmd:RSVP seqn:445 crnd:5 vrnd:0 value:"" 1
DOOZER 2012/02/27 23:14:49.820312 applying 445 TICK
```