workqueue: Show in-flight work item duration in stall diagnostics

When diagnosing workqueue stalls, knowing how long each in-flight work
item has been executing is valuable. Add a current_start timestamp
(jiffies) to struct worker, set it when a work item begins execution in
process_one_work(), and print the elapsed wall-clock time in show_pwq().

Unlike current_at (which tracks CPU runtime and resets on wakeup for
CPU-intensive detection), current_start is never reset because the
diagnostic cares about total wall-clock time including sleeps.

Before: in-flight: 165:stall_work_fn [wq_stall]
After:  in-flight: 165:stall_work_fn [wq_stall] for 100s

Signed-off-by: Breno Leitao <leitao@debian.org>
Acked-by: Song Liu <song@kernel.org>
Signed-off-by: Tejun Heo <tj@kernel.org>

diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index 687d5c55c6174f13be6db5c45a86a039b1f004ef..56d8af13843f86da498794982cf2dc6da7698097 100644 (file)
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -3204,6 +3204,7 @@ __acquires(&pool->lock)
        worker->current_pwq = pwq;
        if (worker->task)
                worker->current_at = worker->task->se.sum_exec_runtime;
+       worker->current_start = jiffies;
        work_data = *work_data_bits(work);
        worker->current_color = get_work_color(work_data);
 
@@ -6359,6 +6360,8 @@ static void show_pwq(struct pool_workqueue *pwq)
                        pr_cont(" %s", comma ? "," : "");
                        pr_cont_worker_id(worker);
                        pr_cont(":%ps", worker->current_func);
+                       pr_cont(" for %us",
+                               jiffies_to_msecs(jiffies - worker->current_start) / 1000);
                        list_for_each_entry(work, &worker->scheduled, entry)
                                pr_cont_work(false, work, &pcws);
                        pr_cont_work_flush(comma, (work_func_t)-1L, &pcws);

diff --git a/kernel/workqueue_internal.h b/kernel/workqueue_internal.h
index f6275944ada776814787ac5a1cfa01f891bfe934..8def1ddc5a1bfedc4ebf38aa452f77cf7b1d8ade 100644 (file)
--- a/kernel/workqueue_internal.h
+++ b/kernel/workqueue_internal.h
@@ -32,6 +32,7 @@ struct worker {
        work_func_t             current_func;   /* K: function */
        struct pool_workqueue   *current_pwq;   /* K: pwq */
        u64                     current_at;     /* K: runtime at start or last wakeup */
+       unsigned long           current_start;  /* K: start time of current work item */
        unsigned int            current_color;  /* K: color */
 
        int                     sleeping;       /* S: is worker sleeping? */