From nobody Sat Sep 13 15:05:39 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id DA576C678D4 for ; Tue, 7 Mar 2023 12:54:13 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229819AbjCGMyM (ORCPT ); Tue, 7 Mar 2023 07:54:12 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:49860 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229841AbjCGMyG (ORCPT ); Tue, 7 Mar 2023 07:54:06 -0500 Received: from smtp-out2.suse.de (smtp-out2.suse.de [195.135.220.29]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id DF3867BA07 for ; Tue, 7 Mar 2023 04:53:58 -0800 (PST) Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) by smtp-out2.suse.de (Postfix) with ESMTP id 5CBAE1FE17; Tue, 7 Mar 2023 12:53:57 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.com; s=susede1; t=1678193637; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=3JARIyfWo8qN+9AW3WtqI4/OEagRB48TyS0ZSkdX1OU=; b=YHyu9sKh0MJ+bpA+YOZOy6hRq7KtK5fqt7zEKno9SBbjn3/BobqeFnCjJ1I50igzvtW+Aa oNoJJCCGFVV7p4MIF/n+jU5zU1/2ZAi6EdfCTEwFCI4J+qXPHJo9ks/UnXdOczBdTnAIKO 0JXJsX+ECxB9/4Qhu5EXhmpZDOnhWyY= Received: from alley.suse.cz (pmladek.tcp.ovpn2.prg.suse.de [10.100.208.146]) by relay2.suse.de (Postfix) with ESMTP id 0AB342C141; Tue, 7 Mar 2023 12:53:57 +0000 (UTC) From: Petr Mladek To: Tejun Heo Cc: Lai Jiangshan , Michal Koutny , linux-kernel@vger.kernel.org, Petr Mladek Subject: [PATCH v2 1/5] workqueue: Fix hung time report of worker pools Date: Tue, 7 Mar 2023 13:53:31 +0100 Message-Id: <20230307125335.28805-2-pmladek@suse.com> X-Mailer: git-send-email 2.35.3 In-Reply-To: <20230307125335.28805-1-pmladek@suse.com> References: <20230307125335.28805-1-pmladek@suse.com> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The workqueue watchdog prints a warning when there is no progress in a worker pool. Where the progress means that the pool started processing a pending work item. Note that it is perfectly fine to process work items much longer. The progress should be guaranteed by waking up or creating idle workers. show_one_worker_pool() prints state of non-idle worker pool. It shows a delay since the last pool->watchdog_ts. The timestamp is updated when a first pending work is queued in __queue_work(). Also it is updated when a work is dequeued for processing in worker_thread() and rescuer_thread(). The delay is misleading when there is no pending work item. In this case it shows how long the last work item is being proceed. Show zero instead. There is no stall if there is no pending work. Fixes: 82607adcf9cdf40fb7b ("workqueue: implement lockup detector") Signed-off-by: Petr Mladek --- kernel/workqueue.c | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index b8b541caed48..2be9b0ecf22c 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -5002,10 +5002,16 @@ static void show_one_worker_pool(struct worker_pool= *pool) struct worker *worker; bool first =3D true; unsigned long flags; + unsigned long hung =3D 0; =20 raw_spin_lock_irqsave(&pool->lock, flags); if (pool->nr_workers =3D=3D pool->nr_idle) goto next_pool; + + /* How long the first pending work is waiting for a worker. */ + if (!list_empty(&pool->worklist)) + hung =3D jiffies_to_msecs(jiffies - pool->watchdog_ts) / 1000; + /* * Defer printing to avoid deadlocks in console drivers that * queue work while holding locks also taken in their write @@ -5014,9 +5020,7 @@ static void show_one_worker_pool(struct worker_pool *= pool) printk_deferred_enter(); pr_info("pool %d:", pool->id); pr_cont_pool_info(pool); - pr_cont(" hung=3D%us workers=3D%d", - jiffies_to_msecs(jiffies - pool->watchdog_ts) / 1000, - pool->nr_workers); + pr_cont(" hung=3D%lus workers=3D%d", hung, pool->nr_workers); if (pool->manager) pr_cont(" manager: %d", task_pid_nr(pool->manager->task)); --=20 2.35.3 From nobody Sat Sep 13 15:05:39 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 60D1EC678D5 for ; Tue, 7 Mar 2023 12:54:30 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229846AbjCGMy2 (ORCPT ); Tue, 7 Mar 2023 07:54:28 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50632 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229849AbjCGMyW (ORCPT ); Tue, 7 Mar 2023 07:54:22 -0500 Received: from smtp-out2.suse.de (smtp-out2.suse.de [195.135.220.29]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id A42FF7C3EB for ; Tue, 7 Mar 2023 04:54:07 -0800 (PST) Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) by smtp-out2.suse.de (Postfix) with ESMTP id 587EE1FE17; Tue, 7 Mar 2023 12:54:06 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.com; s=susede1; t=1678193646; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=SEEJsz5Y768xUJTZNnwAVmHB0wJgO+in0ShoOU4pSwI=; b=BANYSDRqqt476XlRqvf3FDx0EiZbCNC26CEkMJNdE/Co36Cw3vWv7m3GyGeZTz/6pnNDG2 oIgrizrrOLKxcOVFAA93i6bN776ylu/6HNEQ+5teyFr+FrWGFGyMP5xebMXHyPEL7GGbml hyJU2U4d3v+VhQIC0Of2FB0so9nUVtM= Received: from alley.suse.cz (pmladek.tcp.ovpn2.prg.suse.de [10.100.208.146]) by relay2.suse.de (Postfix) with ESMTP id F14892C142; Tue, 7 Mar 2023 12:54:05 +0000 (UTC) From: Petr Mladek To: Tejun Heo Cc: Lai Jiangshan , Michal Koutny , linux-kernel@vger.kernel.org, Petr Mladek Subject: [PATCH v2 2/5] workqueue: Warn when a new worker could not be created Date: Tue, 7 Mar 2023 13:53:32 +0100 Message-Id: <20230307125335.28805-3-pmladek@suse.com> X-Mailer: git-send-email 2.35.3 In-Reply-To: <20230307125335.28805-1-pmladek@suse.com> References: <20230307125335.28805-1-pmladek@suse.com> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The workqueue watchdog reports a lockup when there was not any progress in the worker pool for a long time. The progress means that a pending work item starts being proceed. The progress is guaranteed by using idle workers or creating new workers for pending work items. There are several reasons why a new worker could not be created: + there is not enough memory + there is no free pool ID (IDR API) + the system reached PID limit + the process creating the new worker was interrupted + the last idle worker (manager) has not been scheduled for a long time. It was not able to even start creating the kthread. None of these failures is reported at the moment. The only clue is that show_one_worker_pool() prints that there is a manager. It is the last idle worker that is responsible for creating a new one. But it is not clear if create_worker() is failing and why. Make the debugging easier by printing errors in create_worker(). The error code is important, especially from kthread_create_on_node(). It helps to distinguish the various reasons. For example, reaching memory limit (-ENOMEM), other system limits (-EAGAIN), or process interrupted (-EINTR). Use pr_once() to avoid repeating the same error every CREATE_COOLDOWN for each stuck worker pool. Ratelimited printk() might be better. It would help to know if the problem remains. It would be more clear if the create_worker() errors and workqueue stalls are related. Also old messages might get lost when the internal log buffer is full. The problem is that printk() might touch the watchdog. For example, see touch_nmi_watchdog() in serial8250_console_write(). It would require synchronization of the begin and length of the ratelimit interval with the workqueue watchdog. Otherwise, the error messages might break the watchdog. This does not look worth the complexity. Signed-off-by: Petr Mladek --- kernel/workqueue.c | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 2be9b0ecf22c..36ad9a4d65e4 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -1938,12 +1938,17 @@ static struct worker *create_worker(struct worker_p= ool *pool) =20 /* ID is needed to determine kthread name */ id =3D ida_alloc(&pool->worker_ida, GFP_KERNEL); - if (id < 0) + if (id < 0) { + pr_err_once("workqueue: Failed to allocate a worker ID: %pe\n", + ERR_PTR(id)); return NULL; + } =20 worker =3D alloc_worker(pool->node); - if (!worker) + if (!worker) { + pr_err_once("workqueue: Failed to allocate a worker\n"); goto fail; + } =20 worker->id =3D id; =20 @@ -1955,8 +1960,11 @@ static struct worker *create_worker(struct worker_po= ol *pool) =20 worker->task =3D kthread_create_on_node(worker_thread, worker, pool->node, "kworker/%s", id_buf); - if (IS_ERR(worker->task)) + if (IS_ERR(worker->task)) { + pr_err_once("workqueue: Failed to create a worker thread: %pe", + worker->task); goto fail; + } =20 set_user_nice(worker->task, pool->attrs->nice); kthread_bind_mask(worker->task, pool->attrs->cpumask); --=20 2.35.3 From nobody Sat Sep 13 15:05:39 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 63613C678D5 for ; Tue, 7 Mar 2023 12:54:41 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229864AbjCGMyk (ORCPT ); Tue, 7 Mar 2023 07:54:40 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50472 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229734AbjCGMyb (ORCPT ); Tue, 7 Mar 2023 07:54:31 -0500 Received: from smtp-out1.suse.de (smtp-out1.suse.de [195.135.220.28]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 9B40D7E8B4 for ; Tue, 7 Mar 2023 04:54:15 -0800 (PST) Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) by smtp-out1.suse.de (Postfix) with ESMTP id F310F219B5; Tue, 7 Mar 2023 12:54:13 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.com; s=susede1; t=1678193654; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=EViJoIRl/2M31taW2MlxCxL7zL/ceVFDlbOtpRH0eQY=; b=Z5coI70rju7Q7LR0nHTk/oxPAPI4MshMawQYdx9ZSV0hP9GGFdylkuVvSrHwMeLTZj4JW4 fdytS6rXw1Hb0TQD0kbbZH3I77AfaJ0XkBtw7G+WhVYv1/BhRowjrTBvCEQ3p976ETNTyJ Y3kJVh2ab2qi+LpMIM3Z8ThwYft9Tcg= Received: from alley.suse.cz (pmladek.tcp.ovpn2.prg.suse.de [10.100.208.146]) by relay2.suse.de (Postfix) with ESMTP id 98D442C141; Tue, 7 Mar 2023 12:54:13 +0000 (UTC) From: Petr Mladek To: Tejun Heo Cc: Lai Jiangshan , Michal Koutny , linux-kernel@vger.kernel.org, Petr Mladek Subject: [PATCH v2 3/5] workqueue: Interrupted create_worker() is not a repeated event Date: Tue, 7 Mar 2023 13:53:33 +0100 Message-Id: <20230307125335.28805-4-pmladek@suse.com> X-Mailer: git-send-email 2.35.3 In-Reply-To: <20230307125335.28805-1-pmladek@suse.com> References: <20230307125335.28805-1-pmladek@suse.com> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" kthread_create_on_node() might get interrupted(). It is rare but realistic. For example, when an unbound workqueue is allocated in module_init() callback. It is done in the context of the "modprobe" process. And, for example, systemd might kill pending processes when switching root from initrd to the booted system. The interrupt is a one-off event and the race might be hard to reproduce. It is always worth printing. Signed-off-by: Petr Mladek --- kernel/workqueue.c | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 36ad9a4d65e4..16439d79d164 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -1961,8 +1961,13 @@ static struct worker *create_worker(struct worker_po= ol *pool) worker->task =3D kthread_create_on_node(worker_thread, worker, pool->node, "kworker/%s", id_buf); if (IS_ERR(worker->task)) { - pr_err_once("workqueue: Failed to create a worker thread: %pe", - worker->task); + if (PTR_ERR(worker->task) =3D=3D -EINTR) { + pr_err("workqueue: Interrupted when creating a worker thread \"kworker/= %s\"\n", + id_buf); + } else { + pr_err_once("workqueue: Failed to create a worker thread: %pe", + worker->task); + } goto fail; } =20 --=20 2.35.3 From nobody Sat Sep 13 15:05:39 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id E6C6AC678D4 for ; Tue, 7 Mar 2023 12:54:55 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229794AbjCGMyy (ORCPT ); Tue, 7 Mar 2023 07:54:54 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50922 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229876AbjCGMyp (ORCPT ); Tue, 7 Mar 2023 07:54:45 -0500 Received: from smtp-out2.suse.de (smtp-out2.suse.de [195.135.220.29]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 6ED997C964 for ; Tue, 7 Mar 2023 04:54:21 -0800 (PST) Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) by smtp-out2.suse.de (Postfix) with ESMTP id EDBC61FE18; Tue, 7 Mar 2023 12:54:19 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.com; s=susede1; t=1678193659; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=qwdAX4GqGQBW4Sq41+9WAcG3LtQ9kxjBt9mM0BrglRk=; b=qU3OBeEV0ev27nqWFFoWmTb08omv1pdCUGfdepQCZ+K7I+f6nLTHbYV3evGHWe3LziYIeD dI6g4jzqnIlG+iCxNedfXo3SGbL0tMjXGZK70WVdCXIe1pZ830THAkRawjY1oOCAjMkQ06 rGj0gpnD2Hd49qlW6tNp/ORH2YLDBZY= Received: from alley.suse.cz (pmladek.tcp.ovpn2.prg.suse.de [10.100.208.146]) by relay2.suse.de (Postfix) with ESMTP id A440C2C141; Tue, 7 Mar 2023 12:54:19 +0000 (UTC) From: Petr Mladek To: Tejun Heo Cc: Lai Jiangshan , Michal Koutny , linux-kernel@vger.kernel.org, Petr Mladek Subject: [PATCH v2 4/5] workqueue: Warn when a rescuer could not be created Date: Tue, 7 Mar 2023 13:53:34 +0100 Message-Id: <20230307125335.28805-5-pmladek@suse.com> X-Mailer: git-send-email 2.35.3 In-Reply-To: <20230307125335.28805-1-pmladek@suse.com> References: <20230307125335.28805-1-pmladek@suse.com> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" Rescuers are created when a workqueue with WQ_MEM_RECLAIM is allocated. It typically happens during the system boot. systemd switches the root filesystem from initrd to the booted system during boot. It kills processes that block the switch for too long. One of the process might be modprobe that tries to create a workqueue. These problems are hard to reproduce. Also alloc_workqueue() does not pass the error code. Make the debugging easier by printing an error, similar to create_worker(). Signed-off-by: Petr Mladek --- kernel/workqueue.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 16439d79d164..cce342defc69 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -4393,13 +4393,18 @@ static int init_rescuer(struct workqueue_struct *wq) return 0; =20 rescuer =3D alloc_worker(NUMA_NO_NODE); - if (!rescuer) + if (!rescuer) { + pr_err("workqueue: Failed to allocate a rescuer for wq \"%s\"\n", + wq->name); return -ENOMEM; + } =20 rescuer->rescue_wq =3D wq; rescuer->task =3D kthread_create(rescuer_thread, rescuer, "%s", wq->name); if (IS_ERR(rescuer->task)) { ret =3D PTR_ERR(rescuer->task); + pr_err("workqueue: Failed to create a rescuer kthread for wq \"%s\": %pe= ", + wq->name, ERR_PTR(ret)); kfree(rescuer); return ret; } --=20 2.35.3 From nobody Sat Sep 13 15:05:39 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 99D72C678D5 for ; Tue, 7 Mar 2023 12:54:59 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229874AbjCGMy5 (ORCPT ); Tue, 7 Mar 2023 07:54:57 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50454 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229904AbjCGMyv (ORCPT ); Tue, 7 Mar 2023 07:54:51 -0500 Received: from smtp-out2.suse.de (smtp-out2.suse.de [195.135.220.29]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 5C3BD360BB for ; Tue, 7 Mar 2023 04:54:26 -0800 (PST) Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) by smtp-out2.suse.de (Postfix) with ESMTP id 1CA4D1FE17; Tue, 7 Mar 2023 12:54:25 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.com; s=susede1; t=1678193665; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=8ot5WhI+pYLPKm66MfFAHddCebeV3Th9lv/jx6sTdo4=; b=UvHQEw7KmbW4QdFxNbaJ65oPOx+c7/QR8YeKPTtdS1Iy/ho0D0pZePY1AGz0i7FkspFwk+ ojvNxafFfe5c+k9LkhGm9A+cGvPIMKkBJoMma17e/Y7qlgDXSRrRSsdU9mYim63NTEBpN8 f3jO2OmgCqKAZ51DCTLfC3OqQgi82X8= Received: from alley.suse.cz (pmladek.tcp.ovpn2.prg.suse.de [10.100.208.146]) by relay2.suse.de (Postfix) with ESMTP id C5ADD2C141; Tue, 7 Mar 2023 12:54:24 +0000 (UTC) From: Petr Mladek To: Tejun Heo Cc: Lai Jiangshan , Michal Koutny , linux-kernel@vger.kernel.org, Petr Mladek Subject: [PATCH v2 5/5] workqueue: Print backtraces from CPUs with hung CPU bound workqueues Date: Tue, 7 Mar 2023 13:53:35 +0100 Message-Id: <20230307125335.28805-6-pmladek@suse.com> X-Mailer: git-send-email 2.35.3 In-Reply-To: <20230307125335.28805-1-pmladek@suse.com> References: <20230307125335.28805-1-pmladek@suse.com> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The workqueue watchdog reports a lockup when there was not any progress in the worker pool for a long time. The progress means that a pending work item starts being proceed. Worker pools for unbound workqueues always wake up an idle worker and try to process the work immediately. The last idle worker has to create new worker first. The stall might happen only when a new worker could not be created in which case an error should get printed. Another problem might be too high load. In this case, workers are victims of a global system problem. Worker pools for CPU bound workqueues are designed for lightweight work items that do not need much CPU time. They are proceed one by one on a single worker. New worker is used only when a work is sleeping. It creates one additional scenario. The stall might happen when the CPU-bound workqueue is used for CPU-intensive work. More precisely, the stall is detected when a CPU-bound worker is in the TASK_RUNNING state for too long. In this case, it might be useful to see the backtrace from the problematic worker. The information how long a worker is in the running state is not available. But the CPU-bound worker pools do not have many workers in the running state by definition. And only few pools are typically blocked. It should be acceptable to print backtraces from all workers in TASK_RUNNING state in the stalled worker pools. The number of false positives should be very low. Signed-off-by: Petr Mladek --- kernel/workqueue.c | 66 ++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 66 insertions(+) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index cce342defc69..db6be8df5ddc 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -49,6 +49,7 @@ #include #include #include +#include #include #include =20 @@ -141,6 +142,8 @@ enum { * WR: wq->mutex protected for writes. RCU protected for reads. * * MD: wq_mayday_lock protected. + * + * WD: Used internally by the watchdog. */ =20 /* struct worker is defined in workqueue_internal.h */ @@ -153,6 +156,7 @@ struct worker_pool { unsigned int flags; /* X: flags */ =20 unsigned long watchdog_ts; /* L: watchdog timestamp */ + bool cpu_stall; /* WD: stalled cpu bound pool */ =20 /* * The counter is incremented in a process context on the associated CPU @@ -5978,6 +5982,57 @@ static struct timer_list wq_watchdog_timer; static unsigned long wq_watchdog_touched =3D INITIAL_JIFFIES; static DEFINE_PER_CPU(unsigned long, wq_watchdog_touched_cpu) =3D INITIAL_= JIFFIES; =20 +/* + * Show workers that might prevent the processing of pending work items. + * The only candidates are CPU-bound workers in the running state. + * Pending work items should be handled by another idle worker + * in all other situations. + */ +static void show_cpu_pool_hog(struct worker_pool *pool) +{ + struct worker *worker; + unsigned long flags; + int bkt; + + raw_spin_lock_irqsave(&pool->lock, flags); + + hash_for_each(pool->busy_hash, bkt, worker, hentry) { + if (task_is_running(worker->task)) { + /* + * Defer printing to avoid deadlocks in console + * drivers that queue work while holding locks + * also taken in their write paths. + */ + printk_deferred_enter(); + + pr_info("pool %d:\n", pool->id); + sched_show_task(worker->task); + + printk_deferred_exit(); + } + } + + raw_spin_unlock_irqrestore(&pool->lock, flags); +} + +static void show_cpu_pools_hogs(void) +{ + struct worker_pool *pool; + int pi; + + pr_info("Showing backtraces of running workers in stalled CPU-bound worke= r pools:\n"); + + rcu_read_lock(); + + for_each_pool(pool, pi) { + if (pool->cpu_stall) + show_cpu_pool_hog(pool); + + } + + rcu_read_unlock(); +} + static void wq_watchdog_reset_touched(void) { int cpu; @@ -5991,6 +6046,7 @@ static void wq_watchdog_timer_fn(struct timer_list *u= nused) { unsigned long thresh =3D READ_ONCE(wq_watchdog_thresh) * HZ; bool lockup_detected =3D false; + bool cpu_pool_stall =3D false; unsigned long now =3D jiffies; struct worker_pool *pool; int pi; @@ -6003,6 +6059,7 @@ static void wq_watchdog_timer_fn(struct timer_list *u= nused) for_each_pool(pool, pi) { unsigned long pool_ts, touched, ts; =20 + pool->cpu_stall =3D false; if (list_empty(&pool->worklist)) continue; =20 @@ -6027,11 +6084,17 @@ static void wq_watchdog_timer_fn(struct timer_list = *unused) /* did we stall? */ if (time_after(now, ts + thresh)) { lockup_detected =3D true; + if (pool->cpu >=3D 0) { + pool->cpu_stall =3D true; + cpu_pool_stall =3D true; + } pr_emerg("BUG: workqueue lockup - pool"); pr_cont_pool_info(pool); pr_cont(" stuck for %us!\n", jiffies_to_msecs(now - pool_ts) / 1000); } + + } =20 rcu_read_unlock(); @@ -6039,6 +6102,9 @@ static void wq_watchdog_timer_fn(struct timer_list *u= nused) if (lockup_detected) show_all_workqueues(); =20 + if (cpu_pool_stall) + show_cpu_pools_hogs(); + wq_watchdog_reset_touched(); mod_timer(&wq_watchdog_timer, jiffies + thresh); } --=20 2.35.3