From patchwork Thu May 5 12:24:39 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Ilya Maximets X-Patchwork-Id: 1626936 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: ozlabs.org; spf=pass (sender SPF authorized) smtp.mailfrom=openvswitch.org (client-ip=140.211.166.138; helo=smtp1.osuosl.org; envelope-from=ovs-dev-bounces@openvswitch.org; receiver=) Received: from smtp1.osuosl.org (smtp1.osuosl.org [140.211.166.138]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by bilbo.ozlabs.org (Postfix) with ESMTPS id 4KvCZH60Fdz9sBF for ; Thu, 5 May 2022 22:24:54 +1000 (AEST) Received: from localhost (localhost [127.0.0.1]) by smtp1.osuosl.org (Postfix) with ESMTP id D2A7B8407C; Thu, 5 May 2022 12:24:51 +0000 (UTC) X-Virus-Scanned: amavisd-new at osuosl.org Received: from smtp1.osuosl.org ([127.0.0.1]) by localhost (smtp1.osuosl.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 6VC6pM4X2crL; Thu, 5 May 2022 12:24:50 +0000 (UTC) Received: from lists.linuxfoundation.org (lf-lists.osuosl.org [140.211.9.56]) by smtp1.osuosl.org (Postfix) with ESMTPS id 9A03D83F2C; Thu, 5 May 2022 12:24:49 +0000 (UTC) Received: from lf-lists.osuosl.org (localhost [127.0.0.1]) by lists.linuxfoundation.org (Postfix) with ESMTP id 6F00EC0039; Thu, 5 May 2022 12:24:49 +0000 (UTC) X-Original-To: ovs-dev@openvswitch.org Delivered-To: ovs-dev@lists.linuxfoundation.org Received: from smtp2.osuosl.org (smtp2.osuosl.org [IPv6:2605:bc80:3010::133]) by lists.linuxfoundation.org (Postfix) with ESMTP id B147AC002D for ; Thu, 5 May 2022 12:24:47 +0000 (UTC) Received: from localhost (localhost [127.0.0.1]) by smtp2.osuosl.org (Postfix) with ESMTP id 843E14037E for ; Thu, 5 May 2022 12:24:47 +0000 (UTC) X-Virus-Scanned: amavisd-new at osuosl.org Received: from smtp2.osuosl.org ([127.0.0.1]) by localhost (smtp2.osuosl.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id gmFDaknoi1p1 for ; Thu, 5 May 2022 12:24:46 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.8.0 Received: from relay3-d.mail.gandi.net (relay3-d.mail.gandi.net [IPv6:2001:4b98:dc4:8::223]) by smtp2.osuosl.org (Postfix) with ESMTPS id BB07D4014A for ; Thu, 5 May 2022 12:24:45 +0000 (UTC) Received: (Authenticated sender: i.maximets@ovn.org) by mail.gandi.net (Postfix) with ESMTPSA id 0A70D60002; Thu, 5 May 2022 12:24:41 +0000 (UTC) From: Ilya Maximets To: ovs-dev@openvswitch.org Date: Thu, 5 May 2022 14:24:39 +0200 Message-Id: <20220505122439.523610-1-i.maximets@ovn.org> X-Mailer: git-send-email 2.34.1 MIME-Version: 1.0 Cc: Ilya Maximets , Dumitru Ceara Subject: [ovs-dev] [PATCH] ovsdb: raft: Fix transaction double commit due to lost leadership. X-BeenThere: ovs-dev@openvswitch.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: ovs-dev-bounces@openvswitch.org Sender: "dev" While becoming a follower, the leader completes all the current 'in-flight' commands, so the higher layers can re-try corresponding transactions when the new leader is elected. However, most of these commands are already sent to followers as append requests, hence they will actually be committed by the majority of the cluster members, i.e. will be treated as committed by the new leader, unless there is an actual network problem between servers. However, the old leader will decline append replies, since it's not the leader anymore and commands are already completed with RAFT_CMD_LOST_LEADERSHIP status. New leader will replicate the commit index back to the old leader. Old leader will re-try the previously "failed" transaction, because "cluster error"s are temporary. If a transaction had some prerequisites that didn't allow double committing or there are other database constraints (like indexes) that will not allow a transaction to be committed twice, the server will reply to the client with a false-negative transaction result. If there are no prerequisites or additional database constraints, the server will execute the same transaction again, but as a follower. E.g. in the OVN case, this may result in creation of duplicated logical switches / routers / load balancers. I.e. resources with the same non-indexed name. That may cause issues later where ovn-nbctl will not be able to add ports to these switches / routers. Suggested solution is to not complete the commands, but allow them to be completed with the commit index update from a new leader. It the similar behavior to what we do in order to complete commands in a backward scenario when the follower becomes a leader. That scenario was fixed by commit 5a9b53a51ec9 ("ovsdb raft: Fix duplicated transaction execution when leader failover."). Additionally, truncating the current log down to commit index in order to avoid possible log inconsistencies with a new leader. Followers should not have uncommitted entries in the log. New leader will send them back, if they were actually committed. Code paths for leader and follower inside the raft_update_commit_index were very similar, so they were refactored into one, since we also needed an ability to complete more than one command for a follower. Failure test added to exercise scenario of a leadership transfer. Fixes: 1b1d2e6daa56 ("ovsdb: Introduce experimental support for clustered databases.") Fixes: 3c2d6274bcee ("raft: Transfer leadership before creating snapshots.") Reported-at: https://bugzilla.redhat.com/2046340 Signed-off-by: Ilya Maximets Acked-by: Dumitru Ceara --- ovsdb/raft.c | 135 +++++++++++++++++++++++++---------------- tests/ovsdb-cluster.at | 27 +++++++-- 2 files changed, 103 insertions(+), 59 deletions(-) diff --git a/ovsdb/raft.c b/ovsdb/raft.c index 530c5e5a3..cefeab82c 100644 --- a/ovsdb/raft.c +++ b/ovsdb/raft.c @@ -78,6 +78,8 @@ enum raft_failure_test { FT_DELAY_ELECTION, FT_DONT_SEND_VOTE_REQUEST, FT_STOP_RAFT_RPC, + FT_TRANSFER_LEADERSHIP, + FT_TRANSFER_LEADERSHIP_AFTER_SEND_APPEND_REQ, }; static enum raft_failure_test failure_test; @@ -1931,6 +1933,13 @@ raft_run(struct raft *raft) return; } + if (failure_test == FT_TRANSFER_LEADERSHIP) { + /* Using this function as it conveniently implements all we need and + * snapshotting is the main test scenario for leadership transfer. */ + raft_notify_snapshot_recommended(raft); + failure_test = FT_NO_TEST; + } + raft_waiters_run(raft); if (!raft->listener && time_msec() >= raft->listen_backoff) { @@ -2066,7 +2075,14 @@ raft_run(struct raft *raft) HMAP_FOR_EACH_SAFE (cmd, hmap_node, &raft->commands) { if (cmd->timestamp && now - cmd->timestamp > raft->election_timer * 2) { - raft_command_complete(raft, cmd, RAFT_CMD_TIMEOUT); + if (cmd->index && raft->role != RAFT_LEADER) { + /* This server lost leadership and command didn't complete + * in time. Likely, it wasn't replicated to the majority + * of servers before losing the leadership. */ + raft_command_complete(raft, cmd, RAFT_CMD_LOST_LEADERSHIP); + } else { + raft_command_complete(raft, cmd, RAFT_CMD_TIMEOUT); + } } } raft_reset_ping_timer(raft); @@ -2258,6 +2274,9 @@ raft_command_initiate(struct raft *raft, if (failure_test == FT_CRASH_AFTER_SEND_APPEND_REQ) { ovs_fatal(0, "Raft test: crash after sending append_request."); } + if (failure_test == FT_TRANSFER_LEADERSHIP_AFTER_SEND_APPEND_REQ) { + failure_test = FT_TRANSFER_LEADERSHIP; + } raft_reset_ping_timer(raft); return cmd; @@ -2639,7 +2658,17 @@ raft_become_follower(struct raft *raft) raft->remove_server = NULL; } - raft_complete_all_commands(raft, RAFT_CMD_LOST_LEADERSHIP); + /* Not completing all commands here as they can still be completed if + * already replicated to the majority of servers. But since we can not + * be sure that these commands actually succeeded, we need to remove + * corresponding uncommitted entries from the log. Doing that we will + * avoid possible log inconsistency with a new leader. If entries were + * actually committed according to a new leader, we will receive them + * back with AppendEntries request and will complete commands then. */ + if (raft_truncate(raft, raft->commit_index + 1)) { + /* The set of servers might have changed; check. */ + raft_get_servers_from_log(raft, VLL_INFO); + } } static void @@ -2888,61 +2917,56 @@ raft_update_commit_index(struct raft *raft, uint64_t new_commit_index) return false; } - if (raft->role == RAFT_LEADER) { - while (raft->commit_index < new_commit_index) { - uint64_t index = ++raft->commit_index; - const struct raft_entry *e = raft_get_entry(raft, index); - if (raft_entry_has_data(e)) { - struct raft_command *cmd - = raft_find_command_by_eid(raft, &e->eid); - if (cmd) { - if (!cmd->index) { - VLOG_DBG("Command completed after role change from" - " follower to leader "UUID_FMT, - UUID_ARGS(&e->eid)); - cmd->index = index; - } - raft_command_complete(raft, cmd, RAFT_CMD_SUCCESS); + while (raft->commit_index < new_commit_index) { + uint64_t index = ++raft->commit_index; + const struct raft_entry *e = raft_get_entry(raft, index); + + if (raft_entry_has_data(e)) { + struct raft_command *cmd = raft_find_command_by_eid(raft, &e->eid); + static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(5, 5); + + if (cmd) { + if (!cmd->index && raft->role == RAFT_LEADER) { + VLOG_INFO_RL(&rl, + "command completed after role change from " + "follower to leader (eid: "UUID_FMT", " + "commit index: %"PRIu64")", UUID_ARGS(&e->eid), index); + } else if (!cmd->index && raft->role != RAFT_LEADER) { + /* This can happen when leader fail-over before sending + * execute_command_reply. */ + VLOG_INFO_RL(&rl, + "command completed without reply (eid: "UUID_FMT", " + "commit index: %"PRIu64")", UUID_ARGS(&e->eid), index); + } else if (cmd->index && raft->role != RAFT_LEADER) { + /* This can happen if current server lost leadership after + * sending append requests to the majority of servers, but + * before receiving majority of append replies. */ + VLOG_INFO_RL(&rl, + "command completed after role change from " + "leader to follower (eid: "UUID_FMT", " + "commit index: %"PRIu64")", UUID_ARGS(&e->eid), index); + /* Clearing 'sid' to avoid sending cmd execution reply. */ + cmd->sid = UUID_ZERO; + } else { + /* (cmd->index && raft->role == RAFT_LEADER) + * Normal command completion on a leader. */ } - } - if (e->election_timer) { - VLOG_INFO("Election timer changed from %"PRIu64" to %"PRIu64, - raft->election_timer, e->election_timer); - raft->election_timer = e->election_timer; - raft->election_timer_new = 0; - raft_update_probe_intervals(raft); - } - if (e->servers) { - /* raft_run_reconfigure() can write a new Raft entry, which can - * reallocate raft->entries, which would invalidate 'e', so - * this case must be last, after the one for 'e->data'. */ - raft_run_reconfigure(raft); + cmd->index = index; + raft_command_complete(raft, cmd, RAFT_CMD_SUCCESS); } } - } else { - while (raft->commit_index < new_commit_index) { - uint64_t index = ++raft->commit_index; - const struct raft_entry *e = raft_get_entry(raft, index); - if (e->election_timer) { - VLOG_INFO("Election timer changed from %"PRIu64" to %"PRIu64, - raft->election_timer, e->election_timer); - raft->election_timer = e->election_timer; - raft_update_probe_intervals(raft); - } + if (e->election_timer) { + VLOG_INFO("Election timer changed from %"PRIu64" to %"PRIu64, + raft->election_timer, e->election_timer); + raft->election_timer = e->election_timer; + raft->election_timer_new = 0; + raft_update_probe_intervals(raft); } - /* Check if any pending command can be completed, and complete it. - * This can happen when leader fail-over before sending - * execute_command_reply. */ - const struct uuid *eid = raft_get_eid(raft, new_commit_index); - struct raft_command *cmd = raft_find_command_by_eid(raft, eid); - if (cmd) { - static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(5, 5); - VLOG_INFO_RL(&rl, - "Command completed without reply (eid: "UUID_FMT", " - "commit index: %"PRIu64")", - UUID_ARGS(eid), new_commit_index); - cmd->index = new_commit_index; - raft_command_complete(raft, cmd, RAFT_CMD_SUCCESS); + if (e->servers && raft->role == RAFT_LEADER) { + /* raft_run_reconfigure() can write a new Raft entry, which can + * reallocate raft->entries, which would invalidate 'e', so + * this case must be last, after the one for 'e->data'. */ + raft_run_reconfigure(raft); } } @@ -4975,6 +4999,11 @@ raft_unixctl_failure_test(struct unixctl_conn *conn OVS_UNUSED, failure_test = FT_DONT_SEND_VOTE_REQUEST; } else if (!strcmp(test, "stop-raft-rpc")) { failure_test = FT_STOP_RAFT_RPC; + } else if (!strcmp(test, + "transfer-leadership-after-sending-append-request")) { + failure_test = FT_TRANSFER_LEADERSHIP_AFTER_SEND_APPEND_REQ; + } else if (!strcmp(test, "transfer-leadership")) { + failure_test = FT_TRANSFER_LEADERSHIP; } else if (!strcmp(test, "clear")) { failure_test = FT_NO_TEST; unixctl_command_reply(conn, "test dismissed"); diff --git a/tests/ovsdb-cluster.at b/tests/ovsdb-cluster.at index ee9c7b937..0f7076a05 100644 --- a/tests/ovsdb-cluster.at +++ b/tests/ovsdb-cluster.at @@ -468,6 +468,7 @@ ovsdb_cluster_failure_test () { if test "$crash_node" == "1"; then new_leader=$5 fi + log_grep=$6 cp $top_srcdir/vswitchd/vswitch.ovsschema schema schema=`ovsdb-tool schema-name schema` @@ -488,7 +489,7 @@ ovsdb_cluster_failure_test () { start_server() { local i=$1 printf "\ns$i: starting\n" - AT_CHECK([ovsdb-server -vjsonrpc -vconsole:off -vsyslog:off --detach --no-chdir --log-file=s$i.log --pidfile=s$i.pid --unixctl=s$i --remote=punix:s$i.ovsdb s$i.db]) + AT_CHECK([ovsdb-server -vjsonrpc -vraft -vconsole:off -vsyslog:off --detach --no-chdir --log-file=s$i.log --pidfile=s$i.pid --unixctl=s$i --remote=punix:s$i.ovsdb s$i.db]) } connect_server() { local i=$1 @@ -514,14 +515,23 @@ ovsdb_cluster_failure_test () { fi AT_CHECK([ovs-appctl -t "`pwd`"/s$delay_election_node cluster/failure-test delay-election], [0], [ignore]) fi + + # Initializing the database separately to avoid extra 'wait' operation + # in later transactions. + AT_CHECK([ovs-vsctl -v --db="$db" --no-leader-only --no-shuffle-remotes --no-wait init], [0], [ignore], [ignore]) + AT_CHECK([ovs-appctl -t "`pwd`"/s$crash_node cluster/failure-test $crash_command], [0], [ignore]) AT_CHECK([ovs-vsctl -v --db="$db" --no-leader-only --no-shuffle-remotes --no-wait create QoS type=x], [0], [ignore], [ignore]) - # Make sure that the node really crashed. - AT_CHECK([ls s$crash_node.ovsdb], [2], [ignore], [ignore]) - # XXX: Client will fail if remotes contains unix socket that doesn't exist (killed). - if test "$remote_1" = "$crash_node"; then - db=unix:s$remote_2.ovsdb + # Make sure that the node really crashed or has specific log message. + if test -z "$log_grep"; then + AT_CHECK([ls s$crash_node.ovsdb], [2], [ignore], [ignore]) + # XXX: Client will fail if remotes contains unix socket that doesn't exist (killed). + if test "$remote_1" = "$crash_node"; then + db=unix:s$remote_2.ovsdb + fi + else + OVS_WAIT_UNTIL([grep -q "$log_grep" s${crash_node}.log]) fi AT_CHECK([ovs-vsctl --db="$db" --no-leader-only --no-wait --columns=type --bare list QoS], [0], [x ]) @@ -617,6 +627,11 @@ AT_KEYWORDS([ovsdb server negative unix cluster pending-txn]) ovsdb_cluster_failure_test 2 2 3 crash-after-receiving-append-request-update AT_CLEANUP +AT_SETUP([OVSDB cluster - txn on leader, leader transfers leadership after sending appendReq]) +AT_KEYWORDS([ovsdb server negative unix cluster pending-txn transfer]) +ovsdb_cluster_failure_test 1 2 1 transfer-leadership-after-sending-append-request -1 "Transferring leadership" +AT_CLEANUP + AT_SETUP([OVSDB cluster - competing candidates]) AT_KEYWORDS([ovsdb server negative unix cluster competing-candidates])