shell: allow commands to suspend shell thread

It was possible to deadlock the shell when command
suspended shell's thread and next another thread wanted
to print something on the shell.

To avoid that shell releases mutex before entering command
handler. Due to this change some  adapations to shell
internal print functions have been applied.

This change addresses following usecase:
1. A command handler needs to call a (system) function which
communicate results via a callback, and this callback is expected
to print these results. The callback is called by the system from
another thread.
2. To achieve that, the handler needs to pass `struct shell *`
to callbacks, but also some other data specific to callback.
Thus, handles allocates some structure will those fields on
the stack.
3. The handler schedules this callback to be called.
4. As a reference to stack structure is passed to the callback,
the handler can't return immediately (or stack data will go out
of scope and will be overwritten).
5. So, the handler blocks waiting for callback to finish.

Previously, this scenario led to deadlock when the callback
trying or print to shell. With these changes, it just works,
as long as main handler and callback serialize there access
to the shell structure (i.e. when callback prints, the main
handler is blocked waiting for its completion).

Signed-off-by: Jakub Rzeszutko <jakub.rzeszutko@nordicsemi.no>

include/shell/shell.h

@@ -374,6 +374,7 @@ struct shell_flags {
 	u32_t tx_rdy      :1;
 	u32_t mode_delete :1; /*!< Operation mode of backspace key */
 	u32_t history_exit:1; /*!< Request to exit history mode */
+	u32_t cmd_ctx	  :1; /*!< Shell is executing command */
 	u32_t last_nl     :8; /*!< Last received new line character */
 };
 
@@ -684,6 +685,9 @@ void shell_help(const struct shell *shell);
  *
  * Note: This by no means makes any of the commands a stable interface, so
  * 	 this function should only be used for debugging/diagnostic.
+ *
+ *	 This function must not be called from shell command context!
+
  *
  * @param[in] shell	Pointer to the shell instance. It can be NULL when
  *			the :option:`CONFIG_SHELL_BACKEND_DUMMY` option is

subsys/shell/shell.c

@@ -42,6 +42,16 @@ static void cmd_buffer_clear(const struct shell *shell)
 	shell->ctx->cmd_buff_len = 0;
 }
 
+static void shell_internal_help_print(const struct shell *shell)
+{
+	if (!IS_ENABLED(CONFIG_SHELL_HELP)) {
+		return;
+	}
+
+	shell_help_cmd_print(shell);
+	shell_help_subcmd_print(shell);
+}
+
 /**
  * @brief Prints error message on wrong argument count.
  *	  Optionally, printing help on wrong argument count.
@@ -56,12 +66,12 @@ static int cmd_precheck(const struct shell *shell,
 			bool arg_cnt_ok)
 {
 	if (!arg_cnt_ok) {
-		shell_fprintf(shell, SHELL_ERROR,
+		shell_internal_fprintf(shell, SHELL_ERROR,
 				       "%s: wrong parameter count\n",
 				       shell->ctx->active_cmd.syntax);
 
 		if (IS_ENABLED(CONFIG_SHELL_HELP_ON_WRONG_ARGUMENT_COUNT)) {
-			shell_help(shell);
+			shell_internal_help_print(shell);
 		}
 
 		return -EINVAL;
@@ -100,9 +110,10 @@ static void tab_item_print(const struct shell *shell, const char *option,
 	diff = longest_option - shell_strlen(option);
 
 	if (shell->ctx->vt100_ctx.printed_cmd++ % columns == 0) {
-		shell_fprintf(shell, SHELL_OPTION, "\n%s%s", tab, option);
+		shell_internal_fprintf(shell, SHELL_OPTION, "\n%s%s", tab,
+				       option);
 	} else {
-		shell_fprintf(shell, SHELL_OPTION, "%s", option);
+		shell_internal_fprintf(shell, SHELL_OPTION, "%s", option);
 	}
 
 	shell_op_cursor_horiz_move(shell, diff);
@@ -515,10 +526,10 @@ static int exec_cmd(const struct shell *shell, size_t argc, char **argv,
 			if (help_entry->help != shell->ctx->active_cmd.help) {
 				shell->ctx->active_cmd = *help_entry;
 			}
-			shell_help(shell);
+			shell_internal_help_print(shell);
 			return SHELL_CMD_HELP_PRINTED;
 		} else {
-			shell_fprintf(shell, SHELL_ERROR,
+			shell_internal_fprintf(shell, SHELL_ERROR,
 					       SHELL_MSG_SPECIFY_SUBCOMMAND);
 			return -ENOEXEC;
 		}
@@ -544,7 +555,15 @@ static int exec_cmd(const struct shell *shell, size_t argc, char **argv,
 	}
 
 	if (!ret_val) {
+		/* Unlock thread mutex in case command would like to borrow
+		 * shell context to other thread to avoid mutex deadlock.
+		 */
+		k_mutex_unlock(&shell->ctx->wr_mtx);
+		flag_cmd_ctx_set(shell, 1);
 		ret_val = shell->ctx->active_cmd.handler(shell, argc, argv);
+		flag_cmd_ctx_set(shell, 0);
+		/* Bring back mutex to shell thread. */
+		k_mutex_lock(&shell->ctx->wr_mtx, K_FOREVER);
 	}
 
 	return ret_val;
@@ -593,7 +612,8 @@ static int execute(const struct shell *shell)
 	}
 
 	if (quote != 0) {
-		shell_fprintf(shell, SHELL_ERROR, "not terminated: %c\n",
+		shell_internal_fprintf(shell, SHELL_ERROR,
+				       "not terminated: %c\n",
 				       quote);
 		return -ENOEXEC;
 	}
@@ -612,11 +632,11 @@ static int execute(const struct shell *shell)
 			 */
 			if (help_entry.help) {
 				shell->ctx->active_cmd = help_entry;
-				shell_help(shell);
+				shell_internal_help_print(shell);
 				return SHELL_CMD_HELP_PRINTED;
 			}
 
-			shell_fprintf(shell, SHELL_ERROR,
+			shell_internal_fprintf(shell, SHELL_ERROR,
 					       SHELL_MSG_SPECIFY_SUBCOMMAND);
 			return -ENOEXEC;
 		}
@@ -648,7 +668,8 @@ static int execute(const struct shell *shell)
 
 		if ((cmd_idx == 0) || (p_static_entry == NULL)) {
 			if (cmd_lvl == 0) {
-				shell_error(shell, "%s%s", argv[0],
+				shell_internal_fprintf(shell, SHELL_ERROR,
+						       "%s%s\n", argv[0],
 						       SHELL_MSG_CMD_NOT_FOUND);
 				return -ENOEXEC;
 			}
@@ -668,7 +689,8 @@ static int execute(const struct shell *shell)
 					 * a handler to avoid multiple function
 					 * calls.
 					 */
-					shell_fprintf(shell, SHELL_ERROR,
+					shell_internal_fprintf(shell,
+						SHELL_ERROR,
 						"Error: requested multiple"
 						" function executions\n");
 
@@ -1180,7 +1202,8 @@ void shell_thread(void *shell_handle, void *arg_log_backend,
 		k_mutex_lock(&shell->ctx->wr_mtx, K_FOREVER);
 
 		if (err != 0) {
-			shell_error(shell, "Shell thread error: %d", err);
+			shell_internal_fprintf(shell, SHELL_ERROR,
+					       "Shell thread error: %d", err);
 			return;
 		}
 
@@ -1307,49 +1330,37 @@ void shell_process(const struct shell *shell)
 			 internal.value);
 }
 
-
+/* This function mustn't be used from shell context to avoid deadlock.
-
+ * However it can be used in shell command handlers.
+ */
 void shell_fprintf(const struct shell *shell, enum shell_vt100_color color,
 		   const char *fmt, ...)
 {
 	__ASSERT_NO_MSG(shell);
 	__ASSERT(!k_is_in_isr(), "Thread context required.");
+	__ASSERT_NO_MSG((shell->ctx->internal.flags.cmd_ctx == 1) ||
+			(k_current_get() != shell->ctx->tid));
 	__ASSERT_NO_MSG(shell->ctx);
 	__ASSERT_NO_MSG(shell->fprintf_ctx);
 	__ASSERT_NO_MSG(fmt);
 
 	va_list args = { 0 };
 
-	if (k_current_get() != shell->ctx->tid) {
 	k_mutex_lock(&shell->ctx->wr_mtx, K_FOREVER);
+	if (!flag_cmd_ctx_get(shell)) {
 		shell_cmd_line_erase(shell);
 	}
 
 	va_start(args, fmt);
-
+	shell_internal_vfprintf(shell, color, fmt, args);
-	if (IS_ENABLED(CONFIG_SHELL_VT100_COLORS) &&
-	    shell->ctx->internal.flags.use_colors &&
-	    (color != shell->ctx->vt100_ctx.col.col)) {
-		struct shell_vt100_colors col;
-
-		shell_vt100_colors_store(shell, &col);
-		shell_vt100_color_set(shell, color);
-
-		shell_fprintf_fmt(shell->fprintf_ctx, fmt, args);
-
-		shell_vt100_colors_restore(shell, &col);
-	} else {
-		shell_fprintf_fmt(shell->fprintf_ctx, fmt, args);
-	}
-
 	va_end(args);
 
-	if (k_current_get() != shell->ctx->tid) {
+	if (!flag_cmd_ctx_get(shell)) {
 		shell_print_prompt_and_cmd(shell);
+	}
 	transport_buffer_flush(shell);
 	k_mutex_unlock(&shell->ctx->wr_mtx);
 }
-}
 
 int shell_prompt_change(const struct shell *shell, const char *prompt)
 {
@@ -1366,19 +1377,15 @@ int shell_prompt_change(const struct shell *shell, const char *prompt)
 
 void shell_help(const struct shell *shell)
 {
-	__ASSERT_NO_MSG(shell);
+	k_mutex_lock(&shell->ctx->wr_mtx, K_FOREVER);
-
+	shell_internal_help_print(shell);
-	if (!IS_ENABLED(CONFIG_SHELL_HELP)) {
+	k_mutex_unlock(&shell->ctx->wr_mtx);
-		return;
-	}
-
-	shell_help_cmd_print(shell);
-	shell_help_subcmd_print(shell);
 }
 
 int shell_execute_cmd(const struct shell *shell, const char *cmd)
 {
 	u16_t cmd_len = shell_strlen(cmd);
+	int ret_val;
 
 	if (cmd == NULL) {
 		return -ENOEXEC;
@@ -1396,9 +1403,17 @@ int shell_execute_cmd(const struct shell *shell, const char *cmd)
 #endif
 	}
 
+	__ASSERT(shell->ctx->internal.flags.cmd_ctx == 0,
+						"Function cannot be called"
+						" from command context");
+
 	strcpy(shell->ctx->cmd_buff, cmd);
 	shell->ctx->cmd_buff_len = cmd_len;
 	shell->ctx->cmd_buff_pos = cmd_len;
 
-	return execute(shell);
+	k_mutex_lock(&shell->ctx->wr_mtx, K_FOREVER);
+	ret_val = execute(shell);
+	k_mutex_unlock(&shell->ctx->wr_mtx);
+
+	return ret_val;
 }

subsys/shell/shell_help.c

@@ -118,7 +118,7 @@ static void help_item_print(const struct shell *shell, const char *item_name,
 
 	if (!IS_ENABLED(CONFIG_NEWLIB_LIBC) && !IS_ENABLED(CONFIG_ARCH_POSIX)) {
 		/* print option name */
-		shell_fprintf(shell, SHELL_NORMAL, "%s%-*s%s:",
+		shell_internal_fprintf(shell, SHELL_NORMAL, "%s%-*s%s:",
 				       tabulator,
 				       item_name_width, item_name,
 				       tabulator);
@@ -126,12 +126,12 @@ static void help_item_print(const struct shell *shell, const char *item_name,
 		u16_t tmp = item_name_width - strlen(item_name);
 		char space = ' ';
 
-		shell_fprintf(shell, SHELL_NORMAL, "%s%s", tabulator,
+		shell_internal_fprintf(shell, SHELL_NORMAL, "%s%s", tabulator,
 				       item_name);
 		for (u16_t i = 0; i < tmp; i++) {
 			shell_write(shell, &space, 1);
 		}
-		shell_fprintf(shell, SHELL_NORMAL, "%s:", tabulator);
+		shell_internal_fprintf(shell, SHELL_NORMAL, "%s:", tabulator);
 	}
 
 	if (item_help == NULL) {
@@ -176,7 +176,7 @@ void shell_help_subcmd_print(const struct shell *shell)
 		return;
 	}
 
-	shell_fprintf(shell, SHELL_NORMAL, "Subcommands:\n");
+	shell_internal_fprintf(shell, SHELL_NORMAL, "Subcommands:\n");
 
 	/* Printing subcommands and help string (if exists). */
 	cmd_idx = 0;
@@ -202,7 +202,7 @@ void shell_help_cmd_print(const struct shell *shell)
 	u16_t field_width = shell_strlen(shell->ctx->active_cmd.syntax) +
 							  shell_strlen(cmd_sep);
 
-	shell_fprintf(shell, SHELL_NORMAL, "%s%s",
+	shell_internal_fprintf(shell, SHELL_NORMAL, "%s%s",
 			       shell->ctx->active_cmd.syntax, cmd_sep);
 
 	formatted_text_print(shell, shell->ctx->active_cmd.help,

subsys/shell/shell_ops.c

@@ -178,7 +178,7 @@ void shell_op_word_remove(const struct shell *shell)
 	/* Update display. */
 	shell_op_cursor_move(shell, -chars_to_delete);
 	cursor_save(shell);
-	shell_fprintf(shell, SHELL_NORMAL, "%s", str + 1);
+	shell_internal_fprintf(shell, SHELL_NORMAL, "%s", str + 1);
 	clear_eos(shell);
 	cursor_restore(shell);
 }
@@ -223,7 +223,7 @@ static void reprint_from_cursor(const struct shell *shell, u16_t diff,
 		clear_eos(shell);
 	}
 
-	shell_fprintf(shell, SHELL_NORMAL, "%s",
+	shell_internal_fprintf(shell, SHELL_NORMAL, "%s",
 		      &shell->ctx->cmd_buff[shell->ctx->cmd_buff_pos]);
 	shell->ctx->cmd_buff_pos = shell->ctx->cmd_buff_len;
 
@@ -336,21 +336,7 @@ void shell_cmd_line_erase(const struct shell *shell)
 
 static void print_prompt(const struct shell *shell)
 {
-	/* Below cannot be printed by shell_fprinf because it will cause
+	shell_internal_fprintf(shell, SHELL_INFO, "%s", shell->ctx->prompt);
-	 * interrupt spin
-	 */
-	if (IS_ENABLED(CONFIG_SHELL_VT100_COLORS) &&
-	    shell->ctx->internal.flags.use_colors &&
-	    (SHELL_INFO != shell->ctx->vt100_ctx.col.col)) {
-		struct shell_vt100_colors col;
-
-		shell_vt100_colors_store(shell, &col);
-		shell_vt100_color_set(shell, SHELL_INFO);
-		shell_raw_fprintf(shell->fprintf_ctx, "%s", shell->ctx->prompt);
-		shell_vt100_colors_restore(shell, &col);
-	} else {
-		shell_raw_fprintf(shell->fprintf_ctx, "%s", shell->ctx->prompt);
-	}
 }
 
 void shell_print_cmd(const struct shell *shell)
@@ -457,3 +443,40 @@ void shell_vt100_colors_restore(const struct shell *shell,
 	shell_vt100_color_set(shell, color->col);
 	vt100_bgcolor_set(shell, color->bgcol);
 }
+
+void shell_internal_vfprintf(const struct shell *shell,
+			     enum shell_vt100_color color, const char *fmt,
+			     va_list args)
+{
+	if (IS_ENABLED(CONFIG_SHELL_VT100_COLORS) &&
+	    shell->ctx->internal.flags.use_colors &&
+	    (color != shell->ctx->vt100_ctx.col.col)) {
+		struct shell_vt100_colors col;
+
+		shell_vt100_colors_store(shell, &col);
+		shell_vt100_color_set(shell, color);
+
+		shell_fprintf_fmt(shell->fprintf_ctx, fmt, args);
+
+		shell_vt100_colors_restore(shell, &col);
+	} else {
+		shell_fprintf_fmt(shell->fprintf_ctx, fmt, args);
+	}
+}
+
+void shell_internal_fprintf(const struct shell *shell,
+			    enum shell_vt100_color color,
+			    const char *fmt, ...)
+{
+	__ASSERT_NO_MSG(shell);
+	__ASSERT(!k_is_in_isr(), "Thread context required.");
+	__ASSERT_NO_MSG(shell->ctx);
+	__ASSERT_NO_MSG(shell->fprintf_ctx);
+	__ASSERT_NO_MSG(fmt);
+
+	va_list args = { 0 };
+
+	va_start(args, fmt);
+	shell_internal_vfprintf(shell, color, fmt, args);
+	va_end(args);
+}

subsys/shell/shell_ops.h

@@ -134,6 +134,16 @@ static inline void flag_history_exit_set(const struct shell *shell, bool val)
 	shell->ctx->internal.flags.history_exit = val ? 1 : 0;
 }
 
+static inline bool flag_cmd_ctx_get(const struct shell *shell)
+{
+	return shell->ctx->internal.flags.cmd_ctx == 1 ? true : false;
+}
+
+static inline void flag_cmd_ctx_set(const struct shell *shell, bool val)
+{
+	shell->ctx->internal.flags.cmd_ctx = val ? 1 : 0;
+}
+
 static inline u8_t flag_last_nl_get(const struct shell *shell)
 {
 	return shell->ctx->internal.flags.last_nl;
@@ -246,6 +256,17 @@ static inline void shell_vt100_colors_store(const struct shell *shell,
 void shell_vt100_colors_restore(const struct shell *shell,
 				const struct shell_vt100_colors *color);
 
+/* This function can be called only within shell thread but not from command
+ * handlers.
+ */
+void shell_internal_fprintf(const struct shell *shell,
+			    enum shell_vt100_color color,
+			    const char *fmt, ...);
+
+void shell_internal_vfprintf(const struct shell *shell,
+			     enum shell_vt100_color color, const char *fmt,
+			     va_list args);
+
 #ifdef __cplusplus
 }
 #endif

subsys/shell/shell_wildcard.c

@@ -8,7 +8,7 @@
 #include <fnmatch.h>
 #include "shell_wildcard.h"
 #include "shell_utils.h"
-
+#include "shell_ops.h"
 
 static void subcmd_get(const struct shell_cmd_entry *cmd,
 		       size_t idx, const struct shell_static_entry **entry,
@@ -109,7 +109,7 @@ static enum shell_wildcard_status commands_expand(const struct shell *shell,
 					      &shell->ctx->cmd_tmp_buff_len,
 					      p_static_entry->syntax, pattern);
 			if (ret_val == SHELL_WILDCARD_CMD_MISSING_SPACE) {
-				shell_fprintf(shell,
+				shell_internal_fprintf(shell,
 					      SHELL_WARNING,
 					      "Command buffer is too short to"
 					      " expand all commands matching"