kernel: workq: introduce work timeout:

Introduce work timeout, which is an optional workqueue configuration
which enables monitoring for work items which take longer than
expected. This could be due to long running or deadlocked handlers.

Signed-off-by: Bjarki Arge Andreasen <bjarki.andreasen@nordicsemi.no>

include/zephyr/kernel.h

@@ -4219,6 +4219,16 @@ struct k_work_queue_config {
 	 * essential thread.
 	 */
 	bool essential;
+
+	/** Controls whether work queue monitors work timeouts.
+	 *
+	 * If non-zero, and CONFIG_WORKQUEUE_WORK_TIMEOUT is enabled,
+	 * the work queue will monitor the duration of each work item.
+	 * If the work item handler takes longer than the specified
+	 * time to execute, the work queue thread will be aborted, and
+	 * an error will be logged if CONFIG_LOG is enabled.
+	 */
+	uint32_t work_timeout_ms;
 };
 
 /** @brief A structure used to hold work until it can be processed. */
@@ -4246,6 +4256,12 @@ struct k_work_q {
 
 	/* Flags describing queue state. */
 	uint32_t flags;
+
+#if defined(CONFIG_WORKQUEUE_WORK_TIMEOUT)
+	struct _timeout work_timeout_record;
+	struct k_work *work;
+	k_timeout_t work_timeout;
+#endif /* defined(CONFIG_WORKQUEUE_WORK_TIMEOUT) */
 };
 
 /* Provide the implementation for inline functions declared above */

kernel/Kconfig

@@ -574,6 +574,14 @@ endmenu
 
 rsource "Kconfig.obj_core"
 
+config WORKQUEUE_WORK_TIMEOUT
+	bool "Support workqueue work timeout monitoring"
+	help
+	  If enabled, the workqueue will monitor the duration of each work item.
+	  If the work item handler takes longer than the specified time to
+	  execute, the work queue thread will be aborted, and an error will be
+	  logged.
+
 menu "System Work Queue Options"
 config SYSTEM_WORKQUEUE_STACK_SIZE
 	int "System workqueue stack size"
@@ -600,6 +608,14 @@ config SYSTEM_WORKQUEUE_NO_YIELD
 	  cooperative and a sequence of work items is expected to complete
 	  without yielding.
 
+config SYSTEM_WORKQUEUE_WORK_TIMEOUT_MS
+	int "Select system work queue work timeout in milliseconds"
+	default 5000 if ASSERT
+	default 0
+	help
+	  Set to 0 to disable work timeout for system workqueue. Option
+	  has no effect if WORKQUEUE_WORK_TIMEOUT is not enabled.
+
 endmenu
 
 menu "Barrier Operations"

kernel/system_work_q.c

@@ -25,6 +25,7 @@ static int k_sys_work_q_init(void)
 		.name = "sysworkq",
 		.no_yield = IS_ENABLED(CONFIG_SYSTEM_WORKQUEUE_NO_YIELD),
 		.essential = true,
+		.work_timeout_ms = CONFIG_SYSTEM_WORKQUEUE_WORK_TIMEOUT_MS,
 	};
 
 	k_work_queue_start(&k_sys_work_q,

kernel/work.c

@@ -17,6 +17,9 @@
 #include <errno.h>
 #include <ksched.h>
 #include <zephyr/sys/printk.h>
+#include <zephyr/logging/log.h>
+
+LOG_MODULE_DECLARE(os, CONFIG_KERNEL_LOG_LEVEL);
 
 static inline void flag_clear(uint32_t *flagp,
 			      uint32_t bit)
@@ -599,6 +602,52 @@ bool k_work_cancel_sync(struct k_work *work,
 	return pending;
 }
 
+#if defined(CONFIG_WORKQUEUE_WORK_TIMEOUT)
+static void work_timeout_handler(struct _timeout *record)
+{
+	struct k_work_q *queue = CONTAINER_OF(record, struct k_work_q, work_timeout_record);
+	struct k_work *work;
+	k_work_handler_t handler;
+	const char *name;
+	const char *space = " ";
+
+	K_SPINLOCK(&lock) {
+		work = queue->work;
+		handler = work->handler;
+	}
+
+	name = k_thread_name_get(queue->thread_id);
+	if (name == NULL) {
+		name = "";
+		space = "";
+	}
+
+	LOG_ERR("queue %p%s%s blocked by work %p with handler %p",
+		queue, space, name, work, handler);
+
+	k_thread_abort(queue->thread_id);
+}
+
+static void work_timeout_start_locked(struct k_work_q *queue, struct k_work *work)
+{
+	if (K_TIMEOUT_EQ(queue->work_timeout, K_FOREVER)) {
+		return;
+	}
+
+	queue->work = work;
+	z_add_timeout(&queue->work_timeout_record, work_timeout_handler, queue->work_timeout);
+}
+
+static void work_timeout_stop_locked(struct k_work_q *queue)
+{
+	if (K_TIMEOUT_EQ(queue->work_timeout, K_FOREVER)) {
+		return;
+	}
+
+	z_abort_timeout(&queue->work_timeout_record);
+}
+#endif /* defined(CONFIG_WORKQUEUE_WORK_TIMEOUT) */
+
 /* Loop executed by a work queue thread.
  *
  * @param workq_ptr pointer to the work queue structure
@@ -678,6 +727,10 @@ static void work_queue_main(void *workq_ptr, void *p2, void *p3)
 			continue;
 		}
 
+#if defined(CONFIG_WORKQUEUE_WORK_TIMEOUT)
+		work_timeout_start_locked(queue, work);
+#endif /* defined(CONFIG_WORKQUEUE_WORK_TIMEOUT) */
+
 		k_spin_unlock(&lock, key);
 
 		__ASSERT_NO_MSG(handler != NULL);
@@ -690,6 +743,10 @@ static void work_queue_main(void *workq_ptr, void *p2, void *p3)
 		 */
 		key = k_spin_lock(&lock);
 
+#if defined(CONFIG_WORKQUEUE_WORK_TIMEOUT)
+		work_timeout_stop_locked(queue);
+#endif /* defined(CONFIG_WORKQUEUE_WORK_TIMEOUT) */
+
 		flag_clear(&work->flags, K_WORK_RUNNING_BIT);
 		if (flag_test(&work->flags, K_WORK_FLUSHING_BIT)) {
 			finalize_flush_locked(work);
@@ -736,6 +793,14 @@ void k_work_queue_run(struct k_work_q *queue, const struct k_work_queue_config *
 		k_thread_name_set(_current, cfg->name);
 	}
 
+#if defined(CONFIG_WORKQUEUE_WORK_TIMEOUT)
+	if ((cfg != NULL) && (cfg->work_timeout_ms)) {
+		queue->work_timeout = K_MSEC(cfg->work_timeout_ms);
+	} else {
+		queue->work_timeout = K_FOREVER;
+	}
+#endif /* defined(CONFIG_WORKQUEUE_WORK_TIMEOUT) */
+
 	sys_slist_init(&queue->pending);
 	z_waitq_init(&queue->notifyq);
 	z_waitq_init(&queue->drainq);
@@ -784,6 +849,14 @@ void k_work_queue_start(struct k_work_q *queue,
 		queue->thread.base.user_options |= K_ESSENTIAL;
 	}
 
+#if defined(CONFIG_WORKQUEUE_WORK_TIMEOUT)
+	if ((cfg != NULL) && (cfg->work_timeout_ms)) {
+		queue->work_timeout = K_MSEC(cfg->work_timeout_ms);
+	} else {
+		queue->work_timeout = K_FOREVER;
+	}
+#endif /* defined(CONFIG_WORKQUEUE_WORK_TIMEOUT) */
+
 	k_thread_start(&queue->thread);
 	queue->thread_id = &queue->thread;