Rewrote threaded log code to be more idiomatic.
[invirt/third/libt4.git] / rsm.cc
1 //
2 // Replicated state machine implementation with a primary and several
3 // backups. The primary receives requests, assigns each a view stamp (a
4 // vid, and a sequence number) in the order of reception, and forwards
5 // them to all backups. A backup executes requests in the order that
6 // the primary stamps them and replies with an OK to the primary. The
7 // primary executes the request after it receives OKs from all backups,
8 // and sends the reply back to the client.
9 //
10 // The config module will tell the RSM about a new view. If the
11 // primary in the previous view is a member of the new view, then it
12 // will stay the primary.  Otherwise, the smallest numbered node of
13 // the previous view will be the new primary.  In either case, the new
14 // primary will be a node from the previous view.  The configuration
15 // module constructs the sequence of views for the RSM and the RSM
16 // ensures there will be always one primary, who was a member of the
17 // last view.
18 //
19 // When a new node starts, the recovery thread is in charge of joining
20 // the RSM.  It will collect the internal RSM state from the primary;
21 // the primary asks the config module to add the new node and returns
22 // to the joining the internal RSM state (e.g., paxos log). Since
23 // there is only one primary, all joins happen in well-defined total
24 // order.
25 //
26 // The recovery thread also runs during a view change (e.g, when a node
27 // has failed).  After a failure some of the backups could have
28 // processed a request that the primary has not, but those results are
29 // not visible to clients (since the primary responds).  If the
30 // primary of the previous view is in the current view, then it will
31 // be the primary and its state is authoritive: the backups download
32 // from the primary the current state.  A primary waits until all
33 // backups have downloaded the state.  Once the RSM is in sync, the
34 // primary accepts requests again from clients.  If one of the backups
35 // is the new primary, then its state is authoritative.  In either
36 // scenario, the next view uses a node as primary that has the state
37 // resulting from processing all acknowledged client requests.
38 // Therefore, if the nodes sync up before processing the next request,
39 // the next view will have the correct state.
40 //
41 // While the RSM in a view change (i.e., a node has failed, a new view
42 // has been formed, but the sync hasn't completed), another failure
43 // could happen, which complicates a view change.  During syncing the
44 // primary or backups can timeout, and initiate another Paxos round.
45 // There are 2 variables that RSM uses to keep track in what state it
46 // is:
47 //    - inviewchange: a node has failed and the RSM is performing a view change
48 //    - insync: this node is syncing its state
49 //
50 // If inviewchange is false and a node is the primary, then it can
51 // process client requests. If it is true, clients are told to retry
52 // later again.  While inviewchange is true, the RSM may go through several
53 // member list changes, one by one.   After a member list
54 // change completes, the nodes tries to sync. If the sync complets,
55 // the view change completes (and inviewchange is set to false).  If
56 // the sync fails, the node may start another member list change
57 // (inviewchange = true and insync = false).
58 //
59 // The implementation should be used only with servers that run all
60 // requests run to completion; in particular, a request shouldn't
61 // block.  If a request blocks, the backup won't respond to the
62 // primary, and the primary won't execute the request.  A request may
63 // send an RPC to another host, but the RPC should be a one-way
64 // message to that host; the backup shouldn't do anything based on the
65 // response or execute after the response, because it is not
66 // guaranteed that all backup will receive the same response and
67 // execute in the same order.
68 //
69 // The implementation can be viewed as a layered system:
70 //       RSM module     ---- in charge of replication
71 //       config module  ---- in charge of view management
72 //       Paxos module   ---- in charge of running Paxos to agree on a value
73 //
74 // Each module has threads and internal locks. Furthermore, a thread
75 // may call down through the layers (e.g., to run Paxos's proposer).
76 // When Paxos's acceptor accepts a new value for an instance, a thread
77 // will invoke an upcall to inform higher layers of the new value.
78 // The rule is that a module releases its internal locks before it
79 // upcalls, but can keep its locks when calling down.
80
81 #include "rsm.h"
82 #include "handle.h"
83 #include "rsm_client.h"
84 #include <unistd.h>
85
86 rsm_state_transfer::~rsm_state_transfer() {}
87
88 rsm::rsm(const string & _first, const string & _me) : primary(_first)
89 {
90     cfg = unique_ptr<config>(new config(_first, _me, this));
91
92     if (_first == _me) {
93         // Commit the first view here. We can not have acceptor::acceptor
94         // do the commit, since at that time this->cfg is not initialized
95         commit_change(1);
96     }
97     rsmrpc = cfg->get_rpcs();
98     rsmrpc->reg(rsm_client_protocol::invoke, &rsm::client_invoke, this);
99     rsmrpc->reg(rsm_client_protocol::members, &rsm::client_members, this);
100     rsmrpc->reg(rsm_protocol::invoke, &rsm::invoke, this);
101     rsmrpc->reg(rsm_protocol::transferreq, &rsm::transferreq, this);
102     rsmrpc->reg(rsm_protocol::transferdonereq, &rsm::transferdonereq, this);
103     rsmrpc->reg(rsm_protocol::joinreq, &rsm::joinreq, this);
104
105     // tester must be on different port, otherwise it may partition itself
106     testsvr.reset(new rpcs((in_port_t)stoi(_me) + 1));
107     testsvr->reg(rsm_test_protocol::net_repair, &rsm::test_net_repairreq, this);
108     testsvr->reg(rsm_test_protocol::breakpoint, &rsm::breakpointreq, this);
109 }
110
111 void rsm::start() {
112     lock ml(rsm_mutex);
113     rsmrpc->start();
114     testsvr->start();
115     thread(&rsm::recovery, this).detach();
116 }
117
118 // The recovery thread runs this function
119 void rsm::recovery() {
120     bool r = true;
121     lock ml(rsm_mutex);
122
123     while (1) {
124         while (!cfg->ismember(cfg->myaddr(), vid_commit)) {
125             // XXX iannucci 2013/09/15 -- I don't understand whether accessing
126             // cfg->view_id in this manner involves a race.  I suspect not.
127             if (join(primary, ml)) {
128                 LOG << "joined";
129                 commit_change(cfg->view_id(), ml);
130             } else {
131                 ml.unlock();
132                 this_thread::sleep_for(seconds(3)); // XXX make another node in cfg primary?
133                 ml.lock();
134             }
135         }
136         vid_insync = vid_commit;
137         LOG << "sync vid_insync " << vid_insync;
138         if (primary == cfg->myaddr()) {
139             r = sync_with_backups(ml);
140         } else {
141             r = sync_with_primary(ml);
142         }
143         LOG << "sync done";
144
145         // If there was a commited viewchange during the synchronization, restart
146         // the recovery
147         if (vid_insync != vid_commit)
148             continue;
149
150         if (r) {
151             myvs.vid = vid_commit;
152             myvs.seqno = 1;
153             inviewchange = false;
154         }
155         LOG << "go to sleep " << insync << " " << inviewchange;
156         recovery_cond.wait(ml);
157     }
158 }
159
160 bool rsm::sync_with_backups(lock & rsm_mutex_lock) {
161     rsm_mutex_lock.unlock();
162     {
163         // Make sure that the state of lock_server is stable during
164         // synchronization; otherwise, the primary's state may be more recent
165         // than replicas after the synchronization.
166         lock invoke_mutex_lock(invoke_mutex);
167         // By acquiring and releasing the invoke_mutex once, we make sure that
168         // the state of lock_server will not be changed until all
169         // replicas are synchronized. The reason is that client_invoke arrives
170         // after this point of time will see inviewchange == true, and returns
171         // BUSY.
172     }
173     rsm_mutex_lock.lock();
174     // Start accepting synchronization request (statetransferreq) now!
175     insync = true;
176     cfg->get_view(vid_insync, backups);
177     backups.erase(find(backups.begin(), backups.end(), cfg->myaddr()));
178     LOG << "backups " << backups;
179     sync_cond.wait(rsm_mutex_lock);
180     insync = false;
181     return true;
182 }
183
184
185 bool rsm::sync_with_primary(lock & rsm_mutex_lock) {
186     // Remember the primary of vid_insync
187     string m = primary;
188     while (vid_insync == vid_commit) {
189         if (statetransfer(m, rsm_mutex_lock))
190             break;
191     }
192     return statetransferdone(m, rsm_mutex_lock);
193 }
194
195
196 //
197 // Call to transfer state from m to the local node.
198 // Assumes that rsm_mutex is already held.
199 //
200 bool rsm::statetransfer(const string & m, lock & rsm_mutex_lock)
201 {
202     rsm_protocol::transferres r;
203     handle h(m);
204     int ret = 0;
205     LOG << "contact " << m << " w. my last_myvs(" << last_myvs.vid << "," << last_myvs.seqno << ")";
206     rpcc *cl;
207     {
208         rsm_mutex_lock.unlock();
209         cl = h.safebind();
210         if (cl) {
211             ret = cl->call_timeout(rsm_protocol::transferreq, milliseconds(100),
212                     r, cfg->myaddr(), last_myvs, vid_insync);
213         }
214         rsm_mutex_lock.lock();
215     }
216     if (cl == 0 || ret != rsm_protocol::OK) {
217         LOG << "couldn't reach " << m << " " << hex << cl << " " << dec << ret;
218         return false;
219     }
220     if (stf && last_myvs != r.last) {
221         stf->unmarshal_state(r.state);
222     }
223     last_myvs = r.last;
224     LOG << "transfer from " << m << " success, vs(" << last_myvs.vid << "," << last_myvs.seqno << ")";
225     return true;
226 }
227
228 bool rsm::statetransferdone(const string & m, lock & rsm_mutex_lock) {
229     rsm_mutex_lock.unlock();
230     handle h(m);
231     rpcc *cl = h.safebind();
232     bool done = false;
233     if (cl) {
234         int r;
235         auto ret = (rsm_protocol::status)cl->call(rsm_protocol::transferdonereq, r, cfg->myaddr(), vid_insync);
236         done = (ret == rsm_protocol::OK);
237     }
238     rsm_mutex_lock.lock();
239     return done;
240 }
241
242
243 bool rsm::join(const string & m, lock & rsm_mutex_lock) {
244     handle h(m);
245     int ret = 0;
246     string log;
247
248     LOG << "contacting " << m << " mylast (" << last_myvs.vid << "," << last_myvs.seqno << ")";
249     rpcc *cl;
250     {
251         rsm_mutex_lock.unlock();
252         cl = h.safebind();
253         if (cl != 0) {
254             ret = cl->call_timeout(rsm_protocol::joinreq, milliseconds(12000), log,
255                     cfg->myaddr(), last_myvs);
256         }
257         rsm_mutex_lock.lock();
258     }
259
260     if (cl == 0 || ret != rsm_protocol::OK) {
261         LOG << "couldn't reach " << m << " " << hex << cl << " " << dec << ret;
262         return false;
263     }
264     LOG << "succeeded " << log;
265     cfg->restore(log);
266     return true;
267 }
268
269 //
270 // Config informs rsm whenever it has successfully
271 // completed a view change
272 //
273 void rsm::commit_change(unsigned vid) {
274     lock ml(rsm_mutex);
275     commit_change(vid, ml);
276     if (cfg->ismember(cfg->myaddr(), vid_commit))
277         breakpoint(2);
278 }
279
280 void rsm::commit_change(unsigned vid, lock &) {
281     if (vid <= vid_commit)
282         return;
283     LOG << "new view (" << vid << ") last vs (" << last_myvs.vid << ","
284         << last_myvs.seqno << ") " << primary << " insync " << insync;
285     vid_commit = vid;
286     inviewchange = true;
287     set_primary(vid);
288     recovery_cond.notify_one();
289     sync_cond.notify_one();
290     if (cfg->ismember(cfg->myaddr(), vid_commit))
291         breakpoint(2);
292 }
293
294
295 void rsm::execute(rpc_protocol::proc_id_t procno, const string & req, string & r) {
296     LOG << "execute";
297     handler *h = procs[procno];
298     VERIFY(h);
299     marshall rep;
300     auto ret = (rsm_protocol::status)(*h)(unmarshall(req, false), rep);
301     r = marshall(ret, rep.content()).content();
302 }
303
304 //
305 // Clients call client_invoke to invoke a procedure on the replicated state
306 // machine: the primary receives the request, assigns it a sequence
307 // number, and invokes it on all members of the replicated state
308 // machine.
309 //
310 rsm_client_protocol::status rsm::client_invoke(string & r, rpc_protocol::proc_id_t procno, const string & req) {
311     LOG << "invoke procno 0x" << hex << procno;
312     lock ml(invoke_mutex);
313     vector<string> m;
314     string myaddr;
315     viewstamp vs;
316     {
317         lock ml2(rsm_mutex);
318         LOG << "Checking for inviewchange";
319         if (inviewchange)
320             return rsm_client_protocol::BUSY;
321         LOG << "Checking for primacy";
322         myaddr = cfg->myaddr();
323         if (primary != myaddr)
324             return rsm_client_protocol::NOTPRIMARY;
325         LOG << "Assigning a viewstamp";
326         cfg->get_view(vid_commit, m);
327         // assign the RPC the next viewstamp number
328         vs = myvs;
329         myvs++;
330     }
331
332     // send an invoke RPC to all slaves in the current view with a timeout of 1 second
333     LOG << "Invoking slaves";
334     for (unsigned i  = 0; i < m.size(); i++) {
335         if (m[i] != myaddr) {
336             // if invoke on slave fails, return rsm_client_protocol::BUSY
337             handle h(m[i]);
338             LOG << "Sending invoke to " << m[i];
339             rpcc *cl = h.safebind();
340             if (!cl)
341                 return rsm_client_protocol::BUSY;
342             int ignored_rval;
343             auto ret = (rsm_protocol::status)cl->call_timeout(rsm_protocol::invoke, milliseconds(100), ignored_rval, procno, vs, req);
344             LOG << "Invoke returned " << ret;
345             if (ret != rsm_protocol::OK)
346                 return rsm_client_protocol::BUSY;
347             breakpoint(1);
348             lock rsm_mutex_lock(rsm_mutex);
349             partition1(rsm_mutex_lock);
350         }
351     }
352     {
353         auto && log = LOG << setfill('0') << setw(2) << hex;
354         for (size_t i=0; i<req.size(); i++)
355             log << (unsigned int)(unsigned char)req[i];
356     }
357     execute(procno, req, r);
358     {
359         auto && log = LOG << setfill('0') << setw(2) << hex;
360         for (size_t i=0; i<r.size(); i++)
361             log << (unsigned int)(unsigned char)r[i];
362     }
363     last_myvs = vs;
364     return rsm_client_protocol::OK;
365 }
366
367 //
368 // The primary calls the internal invoke at each member of the
369 // replicated state machine
370 //
371 // the replica must execute requests in order (with no gaps)
372 // according to requests' seqno
373
374 rsm_protocol::status rsm::invoke(int &, rpc_protocol::proc_id_t proc, viewstamp vs, const string & req) {
375     LOG << "invoke procno 0x" << hex << proc;
376     lock ml(invoke_mutex);
377     vector<string> m;
378     string myaddr;
379     {
380         lock ml2(rsm_mutex);
381         // check if !inviewchange
382         LOG << "Checking for view change";
383         if (inviewchange)
384             return rsm_protocol::ERR;
385         // check if slave
386         LOG << "Checking for slave status";
387         myaddr = cfg->myaddr();
388         if (primary == myaddr)
389             return rsm_protocol::ERR;
390         cfg->get_view(vid_commit, m);
391         if (find(m.begin(), m.end(), myaddr) == m.end())
392             return rsm_protocol::ERR;
393         // check sequence number
394         LOG << "Checking sequence number";
395         if (vs != myvs)
396             return rsm_protocol::ERR;
397         myvs++;
398     }
399     string r;
400     execute(proc, req, r);
401     last_myvs = vs;
402     breakpoint(1);
403     return rsm_protocol::OK;
404 }
405
406 //
407 // RPC handler: Send back the local node's state to the caller
408 //
409 rsm_protocol::status rsm::transferreq(rsm_protocol::transferres & r, const string & src,
410         viewstamp last, unsigned vid) {
411     lock ml(rsm_mutex);
412     LOG << "transferreq from " << src << " (" << last.vid << "," << last.seqno << ") vs ("
413         << last_myvs.vid << "," << last_myvs.seqno << ")";
414     if (!insync || vid != vid_insync)
415         return rsm_protocol::BUSY;
416     if (stf && last != last_myvs)
417         r.state = stf->marshal_state();
418     r.last = last_myvs;
419     return rsm_protocol::OK;
420 }
421
422 //
423 // RPC handler: Inform the local node (the primary) that node m has synchronized
424 // for view vid
425 //
426 rsm_protocol::status rsm::transferdonereq(int &, const string & m, unsigned vid) {
427     lock ml(rsm_mutex);
428     if (!insync || vid != vid_insync)
429         return rsm_protocol::BUSY;
430     backups.erase(find(backups.begin(), backups.end(), m));
431     if (backups.empty())
432         sync_cond.notify_one();
433     return rsm_protocol::OK;
434 }
435
436 // a node that wants to join an RSM as a server sends a
437 // joinreq to the RSM's current primary; this is the
438 // handler for that RPC.
439 rsm_protocol::status rsm::joinreq(string & log, const string & m, viewstamp last) {
440     auto ret = rsm_protocol::OK;
441
442     lock ml(rsm_mutex);
443     LOG << "join request from " << m << "; last=(" << last.vid << "," << last.seqno << "), mylast=("
444         << last_myvs.vid << "," << last_myvs.seqno << ")";
445     if (cfg->ismember(m, vid_commit)) {
446         LOG << m << " is still a member -- nothing to do";
447         log = cfg->dump();
448     } else if (cfg->myaddr() != primary) {
449         LOG << "but I, " << cfg->myaddr() << ", am not the primary, " << primary << "!";
450         ret = rsm_protocol::BUSY;
451     } else {
452         // We cache vid_commit to avoid adding m to a view which already contains
453         // m due to race condition
454         LOG << "calling down to config layer";
455         unsigned vid_cache = vid_commit;
456         bool succ;
457         {
458             ml.unlock();
459             succ = cfg->add(m, vid_cache);
460             ml.lock();
461         }
462         if (cfg->ismember(m, cfg->view_id())) {
463             log = cfg->dump();
464             LOG << "ret " << ret << " log " << log;
465         } else {
466             LOG << "failed; proposer couldn't add " << succ;
467             ret = rsm_protocol::BUSY;
468         }
469     }
470     return ret;
471 }
472
473 //
474 // RPC handler: Responds with the list of known nodes for fall-back on a
475 // primary failure
476 //
477 rsm_client_protocol::status rsm::client_members(vector<string> & r, int) {
478     vector<string> m;
479     lock ml(rsm_mutex);
480     cfg->get_view(vid_commit, m);
481     m.push_back(primary);
482     r = m;
483     LOG << "return " << m << " m " << primary;
484     return rsm_client_protocol::OK;
485 }
486
487 // if primary is member of new view, that node is primary
488 // otherwise, the lowest number node of the previous view.
489 // caller should hold rsm_mutex
490 void rsm::set_primary(unsigned vid) {
491     vector<string> c, p;
492     cfg->get_view(vid, c);
493     cfg->get_view(vid - 1, p);
494     VERIFY (c.size() > 0);
495
496     if (isamember(primary,c)) {
497         LOG << "primary stays " << primary;
498         return;
499     }
500
501     VERIFY(p.size() > 0);
502     for (unsigned i = 0; i < p.size(); i++) {
503         if (isamember(p[i], c)) {
504             primary = p[i];
505             LOG << "primary is " << primary;
506             return;
507         }
508     }
509     VERIFY(0);
510 }
511
512 bool rsm::amiprimary() {
513     lock ml(rsm_mutex);
514     return primary == cfg->myaddr() && !inviewchange;
515 }
516
517
518 // Test RPCs -- simulate partitions and failures
519
520 void rsm::net_repair(bool heal, lock & rsm_mutex_lock) {
521     VERIFY(rsm_mutex_lock);
522     vector<string> m;
523     cfg->get_view(vid_commit, m);
524     for (unsigned i  = 0; i < m.size(); i++) {
525         if (m[i] != cfg->myaddr()) {
526             handle h(m[i]);
527             LOG << "member " << m[i] << " " << heal;
528             if (h.safebind()) h.safebind()->set_reachable(heal);
529         }
530     }
531     rsmrpc->set_reachable(heal);
532 }
533
534 rsm_test_protocol::status rsm::test_net_repairreq(rsm_test_protocol::status & r, int heal) {
535     lock ml(rsm_mutex);
536     LOG << "heal " << heal << " (dopartition "
537         << dopartition << ", partitioned " << partitioned << ")";
538     if (heal)
539         net_repair(heal, ml);
540     else
541         dopartition = true;
542     partitioned = false;
543     return r = rsm_test_protocol::OK;
544 }
545
546 // simulate failure at breakpoint 1 and 2
547
548 void rsm::breakpoint(int b) {
549     if (breakpoints[b-1]) {
550         LOG << "Dying at breakpoint " << b << " in rsm!";
551         exit(1);
552     }
553 }
554
555 void rsm::partition1(lock & rsm_mutex_lock) {
556     if (dopartition) {
557         net_repair(false, rsm_mutex_lock);
558         dopartition = false;
559         partitioned = true;
560     }
561 }
562
563 rsm_test_protocol::status rsm::breakpointreq(rsm_test_protocol::status & r, int b) {
564     r = rsm_test_protocol::OK;
565     lock ml(rsm_mutex);
566     LOG << "breakpoint " << b;
567     if (b == 1) breakpoints[1-1] = true;
568     else if (b == 2) breakpoints[2-1] = true;
569     else if (b == 3 || b == 4) cfg->breakpoint(b);
570     else r = rsm_test_protocol::ERR;
571     return r;
572 }