northbound: KISS always batch yang config (file read), it's faster

The backoff code assumed that yang operations always completed quickly.
It checked for > 100 YANG modeled commands happening in under 1 second
to enable batching. If 100 yang modeled commands always take longer than
1 second batching is never enabled. This is the exact opposite of what
we want to happen since batching speeds the operations up.

Here are the results for libyang2 code without and with batching.

| action        |  1K rts |  2K rts | 1K rts | 2K rts | 20k rts |
|               | nobatch | nobatch |  batch |  batch |   batch |
| Add IPv4      |    .881 |    1.28 |   .703 |   1.04 |    8.16 |
| Add Same IPv4 |    28.7 |     113 |   .590 |   .860 |    6.09 |
| Rem 1/2 IPv4  |    .376 |    .442 |   .379 |   .435 |    1.44 |
| Add Same IPv4 |    28.7 |     113 |   .576 |   .841 |    6.02 |
| Rem All IPv4  |    17.4 |    71.8 |   .559 |   .813 |    5.57 |

(IPv6 numbers are basically the same as iPv4, a couple percent slower)

Clearly we need this. Please note the growth (1K to 2K) w/o batching is
non-linear and 100 times slower than batched.

Notes on code: The use of the new `nb_cli_apply_changes_clear_pending`
is to commit any pending changes (including the current one). This is
done when the code would not correctly handle a single diff that
included the current changes with possible following changes. For
example, a "no" command followed by a new value to replace it would be
merged into a change, and the code would not deal well with that. A good
example of this is BGP neighbor peer-group changing. The other use is
after entering a router level (e.g., "router bgp") where the follow-on
command handlers expect that router object to now exists. The code
eventually needs to be cleaned up to not fail in these cases, but that
is for future NB cleanup.

Signed-off-by: Christian Hopps <chopps@labn.net>

10 files changed, 124 insertions, 75 deletions

diff --git a/lib/command.c b/lib/command.c
index 7fb405bdf..5cf1a4f57 100644
--- a/lib/command.c
+++ b/lib/command.c
@@ -980,7 +980,7 @@ static int cmd_execute_command_real(vector vline, enum cmd_filter_type filter,
 			 * non-YANG command.
 			 */
 			if (matched_element->attr != CMD_ATTR_YANG)
-				nb_cli_pending_commit_check(vty);
+				(void)nb_cli_pending_commit_check(vty);
 		}
 
 		ret = matched_element->func(matched_element, vty, argc, argv);
diff --git a/lib/if.c b/lib/if.c
index de2af435f..b3803141d 100644
--- a/lib/if.c
+++ b/lib/if.c
@@ -905,8 +905,8 @@ connected_log(struct connected *connected, char *str)
 
 	p = connected->destination;
 	if (p) {
-		strncat(logbuf, inet_ntop(p->family, &p->u.prefix, buf, BUFSIZ),
-			BUFSIZ - strlen(logbuf));
+		strlcat(logbuf, inet_ntop(p->family, &p->u.prefix, buf, BUFSIZ),
+			BUFSIZ);
 	}
 	zlog_info("%s", logbuf);
 }
@@ -1238,7 +1238,7 @@ DEFPY_YANG_NOSH (interface,
 		 vrf_name);
 
 	nb_cli_enqueue_change(vty, ".", NB_OP_CREATE, NULL);
-	ret = nb_cli_apply_changes(vty, xpath_list);
+	ret = nb_cli_apply_changes_clear_pending(vty, xpath_list);
 	if (ret == CMD_SUCCESS) {
 		VTY_PUSH_XPATH(INTERFACE_NODE, xpath_list);
 
@@ -1248,7 +1248,6 @@ DEFPY_YANG_NOSH (interface,
 		 * all interface-level commands are converted to the new
 		 * northbound model.
 		 */
-		nb_cli_pending_commit_check(vty);
 		ifp = if_lookup_by_name(ifname, vrf_id);
 		if (ifp)
 			VTY_PUSH_CONTEXT(INTERFACE_NODE, ifp);
diff --git a/lib/lib_vty.c b/lib/lib_vty.c
index 128261a39..85816c512 100644
--- a/lib/lib_vty.c
+++ b/lib/lib_vty.c
@@ -37,6 +37,7 @@
 #include "module.h"
 #include "defaults.h"
 #include "lib_vty.h"
+#include "northbound_cli.h"
 
 /* Looking up memory status from vty interface. */
 #include "vector.h"
@@ -231,6 +232,8 @@ DEFUN_HIDDEN (start_config,
 {
 	callback.readin_time = monotime(NULL);
 
+	vty->pending_allowed = 1;
+
 	if (callback.start_config)
 		(*callback.start_config)();
 
@@ -244,6 +247,7 @@ DEFUN_HIDDEN (end_config,
 {
 	time_t readin_time;
 	char readin_time_str[MONOTIME_STRLEN];
+	int ret;
 
 	readin_time = monotime(NULL);
 	readin_time -= callback.readin_time;
@@ -251,12 +255,15 @@ DEFUN_HIDDEN (end_config,
 	frrtime_to_interval(readin_time, readin_time_str,
 			    sizeof(readin_time_str));
 
+	vty->pending_allowed = 0;
+	ret = nb_cli_pending_commit_check(vty);
+
 	zlog_info("Configuration Read in Took: %s", readin_time_str);
 
 	if (callback.end_config)
 		(*callback.end_config)();
 
-	return CMD_SUCCESS;
+	return ret;
 }
 
 void cmd_init_config_callbacks(void (*start_config_cb)(void),
diff --git a/lib/northbound.c b/lib/northbound.c
index 1ce815ea1..47af77018 100644
--- a/lib/northbound.c
+++ b/lib/northbound.c
@@ -512,6 +512,7 @@ static int nb_lyd_diff_get_op(const struct lyd_node *dnode)
 	return 'n';
 }
 
+#if 0 /* Used below in nb_config_diff inside normally disabled code */
 static inline void nb_config_diff_dnode_log_path(const char *context,
 						 const char *path,
 						 const struct lyd_node *dnode)
@@ -535,6 +536,7 @@ static inline void nb_config_diff_dnode_log(const char *context,
 	nb_config_diff_dnode_log_path(context, path, dnode);
 	free(path);
 }
+#endif
 
 /* Calculate the delta between two different configurations. */
 static void nb_config_diff(const struct nb_config *config1,
@@ -548,8 +550,7 @@ static void nb_config_diff(const struct nb_config *config1,
 	LY_ERR err;
 	char *path;
 
-#if 0 /* Useful (but noisy) when debugging diff code, and for improving later  \
-       */
+#if 0 /* Useful (noisy) when debugging diff code, and for improving later */
 	if (DEBUG_MODE_CHECK(&nb_dbg_cbs_config, DEBUG_MODE_ALL)) {
 		LY_LIST_FOR(config1->dnode, root) {
 			LYD_TREE_DFS_BEGIN(root, dnode) {
@@ -570,18 +571,25 @@ static void nb_config_diff(const struct nb_config *config1,
 				LYD_DIFF_DEFAULTS, &diff);
 	assert(!err);
 
-	if (diff && DEBUG_MODE_CHECK(&nb_dbg_cbs_config, DEBUG_MODE_ALL))
-		nb_config_diff_dnode_log("iterating diff", diff);
+	if (diff && DEBUG_MODE_CHECK(&nb_dbg_cbs_config, DEBUG_MODE_ALL)) {
+		char *s;
+
+		if (!lyd_print_mem(&s, diff, LYD_JSON,
+				   LYD_PRINT_WITHSIBLINGS | LYD_PRINT_WD_ALL)) {
+			zlog_debug("%s: %s", __func__, s);
+			free(s);
+		}
+	}
 
 	uint32_t seq = 0;
+
 	LY_LIST_FOR (diff, root) {
 		LYD_TREE_DFS_BEGIN (root, dnode) {
 			op = nb_lyd_diff_get_op(dnode);
 
 			path = lyd_path(dnode, LYD_PATH_STD, NULL, 0);
 
-#if 0 /* Useful (but noisy) when debugging diff code, and for improving later  \
-       */
+#if 0 /* Useful (noisy) when debugging diff code, and for improving later */
 			if (DEBUG_MODE_CHECK(&nb_dbg_cbs_config, DEBUG_MODE_ALL)) {
 				char context[80];
 				snprintf(context, sizeof(context),
@@ -631,7 +639,7 @@ static void nb_config_diff(const struct nb_config *config1,
 		}
 	}
 
-	lyd_free_tree(diff);
+	lyd_free_all(diff);
 }
 
 int nb_candidate_edit(struct nb_config *candidate,
@@ -664,6 +672,14 @@ int nb_candidate_edit(struct nb_config *candidate,
 				  xpath_edit, err);
 			return NB_ERR;
 		} else if (dnode) {
+			/* Create default nodes */
+			LY_ERR err = lyd_new_implicit_tree(
+				dnode, LYD_IMPLICIT_NO_STATE, NULL);
+			if (err) {
+				flog_warn(EC_LIB_LIBYANG,
+					  "%s: lyd_new_implicit_all failed: %d",
+					  __func__, err);
+			}
 			/*
 			 * create dependency
 			 *
@@ -679,6 +695,11 @@ int nb_candidate_edit(struct nb_config *candidate,
 						   ly_native_ctx, dep_xpath,
 						   NULL, LYD_NEW_PATH_UPDATE,
 						   &dep_dnode);
+				/* Create default nodes */
+				if (!err)
+					err = lyd_new_implicit_tree(
+						dep_dnode,
+						LYD_IMPLICIT_NO_STATE, NULL);
 				if (err) {
 					flog_warn(
 						EC_LIB_LIBYANG,
diff --git a/lib/northbound.h b/lib/northbound.h
index 7ccab5cad..bf04dbda1 100644
--- a/lib/northbound.h
+++ b/lib/northbound.h
@@ -704,6 +704,7 @@ extern struct debug nb_dbg_cbs_state;
 extern struct debug nb_dbg_cbs_rpc;
 extern struct debug nb_dbg_notif;
 extern struct debug nb_dbg_events;
+extern struct debug nb_dbg_libyang;
 
 /* Global running configuration. */
 extern struct nb_config *running_config;
diff --git a/lib/northbound_cli.c b/lib/northbound_cli.c
index d291a1f24..b74a0e6c2 100644
--- a/lib/northbound_cli.c
+++ b/lib/northbound_cli.c
@@ -74,7 +74,7 @@ static int nb_cli_classic_commit(struct vty *vty)
 	default:
 		vty_out(vty, "%% Configuration failed.\n\n");
 		vty_show_nb_errors(vty, ret, errmsg);
-		if (vty->t_pending_commit)
+		if (vty->pending_commit)
 			vty_out(vty,
 				"The following commands were dynamically grouped into the same transaction and rejected:\n%s",
 				vty->pending_cmds_buf);
@@ -89,49 +89,22 @@ static int nb_cli_classic_commit(struct vty *vty)
 
 static void nb_cli_pending_commit_clear(struct vty *vty)
 {
-	THREAD_OFF(vty->t_pending_commit);
-	vty->backoff_cmd_count = 0;
+	vty->pending_commit = 0;
 	XFREE(MTYPE_TMP, vty->pending_cmds_buf);
 	vty->pending_cmds_buflen = 0;
 	vty->pending_cmds_bufpos = 0;
 }
 
-static int nb_cli_pending_commit_cb(struct thread *thread)
+int nb_cli_pending_commit_check(struct vty *vty)
 {
-	struct vty *vty = THREAD_ARG(thread);
-
-	(void)nb_cli_classic_commit(vty);
-	nb_cli_pending_commit_clear(vty);
+	int ret = CMD_SUCCESS;
 
-	return 0;
-}
-
-void nb_cli_pending_commit_check(struct vty *vty)
-{
-	if (vty->t_pending_commit) {
-		(void)nb_cli_classic_commit(vty);
+	if (vty->pending_commit) {
+		ret = nb_cli_classic_commit(vty);
 		nb_cli_pending_commit_clear(vty);
 	}
-}
-
-static bool nb_cli_backoff_start(struct vty *vty)
-{
-	struct timeval now, delta;
-
-	/*
-	 * Start the configuration backoff timer only if 100 YANG-modeled
-	 * commands or more were entered within the last second.
-	 */
-	monotime(&now);
-	if (monotime_since(&vty->backoff_start, &delta) >= 1000000) {
-		vty->backoff_start = now;
-		vty->backoff_cmd_count = 1;
-		return false;
-	}
-	if (++vty->backoff_cmd_count < 100)
-		return false;
 
-	return true;
+	return ret;
 }
 
 static int nb_cli_schedule_command(struct vty *vty)
@@ -154,9 +127,7 @@ static int nb_cli_schedule_command(struct vty *vty)
 					   vty->pending_cmds_buflen);
 
 	/* Schedule the commit operation. */
-	THREAD_OFF(vty->t_pending_commit);
-	thread_add_timer_msec(master, nb_cli_pending_commit_cb, vty, 100,
-			      &vty->t_pending_commit);
+	vty->pending_commit = 1;
 
 	return CMD_SUCCESS;
 }
@@ -180,21 +151,16 @@ void nb_cli_enqueue_change(struct vty *vty, const char *xpath,
 	change->value = value;
 }
 
-int nb_cli_apply_changes(struct vty *vty, const char *xpath_base_fmt, ...)
+static int nb_cli_apply_changes_internal(struct vty *vty,
+					 const char *xpath_base,
+					 bool clear_pending)
 {
-	char xpath_base[XPATH_MAXLEN] = {};
 	bool error = false;
 
-	VTY_CHECK_XPATH;
-
-	/* Parse the base XPath format string. */
-	if (xpath_base_fmt) {
-		va_list ap;
+	if (xpath_base == NULL)
+		xpath_base = "";
 
-		va_start(ap, xpath_base_fmt);
-		vsnprintf(xpath_base, sizeof(xpath_base), xpath_base_fmt, ap);
-		va_end(ap);
-	}
+	VTY_CHECK_XPATH;
 
 	/* Edit candidate configuration. */
 	for (size_t i = 0; i < vty->num_cfg_changes; i++) {
@@ -207,10 +173,9 @@ int nb_cli_apply_changes(struct vty *vty, const char *xpath_base_fmt, ...)
 		/* Handle relative XPaths. */
 		memset(xpath, 0, sizeof(xpath));
 		if (vty->xpath_index > 0
-		    && ((xpath_base_fmt && xpath_base[0] == '.')
-			|| change->xpath[0] == '.'))
+		    && (xpath_base[0] == '.' || change->xpath[0] == '.'))
 			strlcpy(xpath, VTY_CURR_XPATH, sizeof(xpath));
-		if (xpath_base_fmt) {
+		if (xpath_base[0]) {
 			if (xpath_base[0] == '.')
 				strlcat(xpath, xpath_base + 1, sizeof(xpath));
 			else
@@ -267,7 +232,7 @@ int nb_cli_apply_changes(struct vty *vty, const char *xpath_base_fmt, ...)
 	}
 
 	/*
-	 * Do an implicit commit when using the classic CLI mode.
+	 * Maybe do an implicit commit when using the classic CLI mode.
 	 *
 	 * NOTE: the implicit commit might be scheduled to run later when
 	 * too many commands are being sent at the same time. This is a
@@ -276,14 +241,49 @@ int nb_cli_apply_changes(struct vty *vty, const char *xpath_base_fmt, ...)
 	 * faster.
 	 */
 	if (frr_get_cli_mode() == FRR_CLI_CLASSIC) {
-		if (vty->t_pending_commit || nb_cli_backoff_start(vty))
+		if (clear_pending) {
+			if (vty->pending_commit)
+				return nb_cli_pending_commit_check(vty);
+		} else if (vty->pending_allowed)
 			return nb_cli_schedule_command(vty);
+		assert(!vty->pending_commit);
 		return nb_cli_classic_commit(vty);
 	}
 
 	return CMD_SUCCESS;
 }
 
+int nb_cli_apply_changes(struct vty *vty, const char *xpath_base_fmt, ...)
+{
+	char xpath_base[XPATH_MAXLEN] = {};
+
+	/* Parse the base XPath format string. */
+	if (xpath_base_fmt) {
+		va_list ap;
+
+		va_start(ap, xpath_base_fmt);
+		vsnprintf(xpath_base, sizeof(xpath_base), xpath_base_fmt, ap);
+		va_end(ap);
+	}
+	return nb_cli_apply_changes_internal(vty, xpath_base, false);
+}
+
+int nb_cli_apply_changes_clear_pending(struct vty *vty,
+				       const char *xpath_base_fmt, ...)
+{
+	char xpath_base[XPATH_MAXLEN] = {};
+
+	/* Parse the base XPath format string. */
+	if (xpath_base_fmt) {
+		va_list ap;
+
+		va_start(ap, xpath_base_fmt);
+		vsnprintf(xpath_base, sizeof(xpath_base), xpath_base_fmt, ap);
+		va_end(ap);
+	}
+	return nb_cli_apply_changes_internal(vty, xpath_base, true);
+}
+
 int nb_cli_rpc(struct vty *vty, const char *xpath, struct list *input,
 	       struct list *output)
 {
diff --git a/lib/northbound_cli.h b/lib/northbound_cli.h
index 2290a76b8..28f81f8b3 100644
--- a/lib/northbound_cli.h
+++ b/lib/northbound_cli.h
@@ -57,7 +57,26 @@ extern void nb_cli_enqueue_change(struct vty *vty, const char *xpath,
 				  const char *value);
 
 /*
- * Apply enqueued changes to the candidate configuration.
+ * Apply enqueued changes to the candidate configuration, do not batch,
+ * and apply any pending commits along with the currently enqueued.
+ *
+ * vty
+ *    The vty context.
+ *
+ * xpath_base_fmt
+ *    Prepend the given XPath (absolute or relative) to all enqueued
+ *    configuration changes. This is an optional parameter.
+ *
+ * Returns:
+ *    CMD_SUCCESS on success, CMD_WARNING_CONFIG_FAILED otherwise.
+ */
+extern int nb_cli_apply_changes_clear_pending(struct vty *vty,
+					      const char *xpath_base_fmt, ...);
+
+/*
+ * Apply enqueued changes to the candidate configuration, this function
+ * may not immediately apply the changes, instead adding them to a pending
+ * queue.
  *
  * vty
  *    The vty context.
@@ -116,8 +135,12 @@ extern void nb_cli_show_dnode_cmds(struct vty *vty, struct lyd_node *dnode,
  *
  * vty
  *    The vty context.
+ *
+ * Returns
+ *    CMD_SUCCESS on success (or no pending), CMD_WARNING_CONFIG_FAILED
+ *    otherwise.
  */
-extern void nb_cli_pending_commit_check(struct vty *vty);
+extern int nb_cli_pending_commit_check(struct vty *vty);
 
 /* Prototypes of internal functions. */
 extern void nb_cli_show_config_prepare(struct nb_config *config,
diff --git a/lib/vrf.c b/lib/vrf.c
index d99ec12ba..c01f2c636 100644
--- a/lib/vrf.c
+++ b/lib/vrf.c
@@ -690,10 +690,9 @@ int vrf_handler_create(struct vty *vty, const char *vrfname,
 			 vrfname);
 
 		nb_cli_enqueue_change(vty, xpath_list, NB_OP_CREATE, NULL);
-		ret = nb_cli_apply_changes(vty, xpath_list);
+		ret = nb_cli_apply_changes_clear_pending(vty, xpath_list);
 		if (ret == CMD_SUCCESS) {
 			VTY_PUSH_XPATH(VRF_NODE, xpath_list);
-			nb_cli_pending_commit_check(vty);
 			vrfp = vrf_lookup_by_name(vrfname);
 			if (vrfp)
 				VTY_PUSH_CONTEXT(VRF_NODE, vrfp);
diff --git a/lib/vty.c b/lib/vty.c
index f92c91208..6853fc330 100644
--- a/lib/vty.c
+++ b/lib/vty.c
@@ -2622,8 +2622,8 @@ int vty_config_node_exit(struct vty *vty)
 {
 	vty->xpath_index = 0;
 
-	/* Perform pending commit if any. */
-	nb_cli_pending_commit_check(vty);
+	/* Perform any pending commits. */
+	(void)nb_cli_pending_commit_check(vty);
 
 	/* Check if there's a pending confirmed commit. */
 	if (vty->t_confirmed_commit_timeout) {
diff --git a/lib/vty.h b/lib/vty.h
index 623f97ab0..10fbb16a4 100644
--- a/lib/vty.h
+++ b/lib/vty.h
@@ -135,9 +135,8 @@ struct vty {
 	struct nb_config *candidate_config_base;
 
 	/* Dynamic transaction information. */
-	struct timeval backoff_start;
-	size_t backoff_cmd_count;
-	struct thread *t_pending_commit;
+	bool pending_allowed;
+	bool pending_commit;
 	char *pending_cmds_buf;
 	size_t pending_cmds_buflen;
 	size_t pending_cmds_bufpos;