From 854f5cc5b7355ceebf2bdfed97ea8f3c5d47a0c3 Mon Sep 17 00:00:00 2001 From: "Paul E. McKenney" Date: Fri, 28 Apr 2023 16:47:07 -0700 Subject: [PATCH 01/11] Further upgrade queue_work_on() comment The current queue_work_on() docbook comment says that the caller must ensure that the specified CPU can't go away, and further says that the penalty for failing to nail down the specified CPU is that the workqueue handler might find itself executing on some other CPU. This is true as far as it goes, but fails to note what happens if the specified CPU never was online. Therefore, further expand this comment to say that specifying a CPU that was never online will result in a splat. Signed-off-by: Paul E. McKenney Cc: Lai Jiangshan Cc: Tejun Heo Signed-off-by: Tejun Heo --- kernel/workqueue.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 4666a1a92a31..36bccc1285b3 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -1539,6 +1539,8 @@ out: * We queue the work to a specific CPU, the caller must ensure it * can't go away. Callers that fail to ensure that the specified * CPU cannot go away will execute on a randomly chosen CPU. + * But note well that callers specifying a CPU that never has been + * online will get a splat. * * Return: %false if @work was already on a queue, %true otherwise. */ From 725e8ec59c56c65fb92e343c10a8842cd0d4f194 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:08 -1000 Subject: [PATCH 02/11] workqueue: Add pwq->stats[] and a monitoring script Currently, the only way to peer into workqueue operations is through tracing. While possible, it isn't easy or convenient to monitor per-workqueue behaviors over time this way. Let's add pwq->stats[] that track relevant events and a drgn monitoring script - tools/workqueue/wq_monitor.py. It's arguable whether this needs to be configurable. However, it currently only has several counters and the runtime overhead shouldn't be noticeable given that they're on pwq's which are per-cpu on per-cpu workqueues and per-numa-node on unbound ones. Let's keep it simple for the time being. v2: Patch reordered to earlier with fewer fields. Field will be added back gradually. Help message improved. Signed-off-by: Tejun Heo Cc: Lai Jiangshan --- Documentation/core-api/workqueue.rst | 32 ++++++ kernel/workqueue.c | 24 ++++- tools/workqueue/wq_monitor.py | 150 +++++++++++++++++++++++++++ 3 files changed, 205 insertions(+), 1 deletion(-) create mode 100644 tools/workqueue/wq_monitor.py diff --git a/Documentation/core-api/workqueue.rst b/Documentation/core-api/workqueue.rst index 8ec4d6270b24..7e5c39310bbf 100644 --- a/Documentation/core-api/workqueue.rst +++ b/Documentation/core-api/workqueue.rst @@ -348,6 +348,37 @@ Guidelines level of locality in wq operations and work item execution. +Monitoring +========== + +Use tools/workqueue/wq_monitor.py to monitor workqueue operations: :: + + $ tools/workqueue/wq_monitor.py events + total infl CMwake mayday rescued + events 18545 0 5 - - + events_highpri 8 0 0 - - + events_long 3 0 0 - - + events_unbound 38306 0 - - - + events_freezable 0 0 0 - - + events_power_efficient 29598 0 0 - - + events_freezable_power_ 10 0 0 - - + sock_diag_events 0 0 0 - - + + total infl CMwake mayday rescued + events 18548 0 5 - - + events_highpri 8 0 0 - - + events_long 3 0 0 - - + events_unbound 38322 0 - - - + events_freezable 0 0 0 - - + events_power_efficient 29603 0 0 - - + events_freezable_power_ 10 0 0 - - + sock_diag_events 0 0 0 - - + + ... + +See the command's help message for more info. + + Debugging ========= @@ -387,6 +418,7 @@ the stack trace of the offending worker thread. :: The work item's function should be trivially visible in the stack trace. + Non-reentrance Conditions ========================= diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 36bccc1285b3..60d5b84cccb2 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -199,6 +199,20 @@ struct worker_pool { struct rcu_head rcu; }; +/* + * Per-pool_workqueue statistics. These can be monitored using + * tools/workqueue/wq_monitor.py. + */ +enum pool_workqueue_stats { + PWQ_STAT_STARTED, /* work items started execution */ + PWQ_STAT_COMPLETED, /* work items completed execution */ + PWQ_STAT_CM_WAKEUP, /* concurrency-management worker wakeups */ + PWQ_STAT_MAYDAY, /* maydays to rescuer */ + PWQ_STAT_RESCUED, /* linked work items executed by rescuer */ + + PWQ_NR_STATS, +}; + /* * The per-pool workqueue. While queued, the lower WORK_STRUCT_FLAG_BITS * of work_struct->data are used for flags and the remaining high bits @@ -236,6 +250,8 @@ struct pool_workqueue { struct list_head pwqs_node; /* WR: node on wq->pwqs */ struct list_head mayday_node; /* MD: node on wq->maydays */ + u64 stats[PWQ_NR_STATS]; + /* * Release of unbound pwq is punted to system_wq. See put_pwq() * and pwq_unbound_release_workfn() for details. pool_workqueue @@ -929,8 +945,10 @@ void wq_worker_sleeping(struct task_struct *task) } pool->nr_running--; - if (need_more_worker(pool)) + if (need_more_worker(pool)) { + worker->current_pwq->stats[PWQ_STAT_CM_WAKEUP]++; wake_up_worker(pool); + } raw_spin_unlock_irq(&pool->lock); } @@ -2165,6 +2183,7 @@ static void send_mayday(struct work_struct *work) get_pwq(pwq); list_add_tail(&pwq->mayday_node, &wq->maydays); wake_up_process(wq->rescuer->task); + pwq->stats[PWQ_STAT_MAYDAY]++; } } @@ -2403,6 +2422,7 @@ __acquires(&pool->lock) * workqueues), so hiding them isn't a problem. */ lockdep_invariant_state(true); + pwq->stats[PWQ_STAT_STARTED]++; trace_workqueue_execute_start(work); worker->current_func(work); /* @@ -2410,6 +2430,7 @@ __acquires(&pool->lock) * point will only record its address. */ trace_workqueue_execute_end(work, worker->current_func); + pwq->stats[PWQ_STAT_COMPLETED]++; lock_map_release(&lockdep_map); lock_map_release(&pwq->wq->lockdep_map); @@ -2653,6 +2674,7 @@ repeat: if (first) pool->watchdog_ts = jiffies; move_linked_works(work, scheduled, &n); + pwq->stats[PWQ_STAT_RESCUED]++; } first = false; } diff --git a/tools/workqueue/wq_monitor.py b/tools/workqueue/wq_monitor.py new file mode 100644 index 000000000000..fc1643ba06b3 --- /dev/null +++ b/tools/workqueue/wq_monitor.py @@ -0,0 +1,150 @@ +#!/usr/bin/env drgn +# +# Copyright (C) 2023 Tejun Heo +# Copyright (C) 2023 Meta Platforms, Inc. and affiliates. + +desc = """ +This is a drgn script to monitor workqueues. For more info on drgn, visit +https://github.com/osandov/drgn. + + total Total number of work items executed by the workqueue. + + infl The number of currently in-flight work items. + + CMwake The number of concurrency-management wake-ups while executing a + work item of the workqueue. + + mayday The number of times the rescuer was requested while waiting for + new worker creation. + + rescued The number of work items executed by the rescuer. +""" + +import sys +import signal +import os +import re +import time +import json + +import drgn +from drgn.helpers.linux.list import list_for_each_entry,list_empty +from drgn.helpers.linux.cpumask import for_each_possible_cpu + +import argparse +parser = argparse.ArgumentParser(description=desc, + formatter_class=argparse.RawTextHelpFormatter) +parser.add_argument('workqueue', metavar='REGEX', nargs='*', + help='Target workqueue name patterns (all if empty)') +parser.add_argument('-i', '--interval', metavar='SECS', type=float, default=1, + help='Monitoring interval (0 to print once and exit)') +parser.add_argument('-j', '--json', action='store_true', + help='Output in json') +args = parser.parse_args() + +def err(s): + print(s, file=sys.stderr, flush=True) + sys.exit(1) + +workqueues = prog['workqueues'] + +WQ_UNBOUND = prog['WQ_UNBOUND'] +WQ_MEM_RECLAIM = prog['WQ_MEM_RECLAIM'] + +PWQ_STAT_STARTED = prog['PWQ_STAT_STARTED'] # work items started execution +PWQ_STAT_COMPLETED = prog['PWQ_STAT_COMPLETED'] # work items completed execution +PWQ_STAT_CM_WAKEUP = prog['PWQ_STAT_CM_WAKEUP'] # concurrency-management worker wakeups +PWQ_STAT_MAYDAY = prog['PWQ_STAT_MAYDAY'] # maydays to rescuer +PWQ_STAT_RESCUED = prog['PWQ_STAT_RESCUED'] # linked work items executed by rescuer +PWQ_NR_STATS = prog['PWQ_NR_STATS'] + +class WqStats: + def __init__(self, wq): + self.name = wq.name.string_().decode() + self.unbound = wq.flags & WQ_UNBOUND != 0 + self.mem_reclaim = wq.flags & WQ_MEM_RECLAIM != 0 + self.stats = [0] * PWQ_NR_STATS + for pwq in list_for_each_entry('struct pool_workqueue', wq.pwqs.address_of_(), 'pwqs_node'): + for i in range(PWQ_NR_STATS): + self.stats[i] += int(pwq.stats[i]) + + def dict(self, now): + return { 'timestamp' : now, + 'name' : self.name, + 'unbound' : self.unbound, + 'mem_reclaim' : self.mem_reclaim, + 'started' : self.stats[PWQ_STAT_STARTED], + 'completed' : self.stats[PWQ_STAT_COMPLETED], + 'cm_wakeup' : self.stats[PWQ_STAT_CM_WAKEUP], + 'mayday' : self.stats[PWQ_STAT_MAYDAY], + 'rescued' : self.stats[PWQ_STAT_RESCUED], } + + def table_header_str(): + return f'{"":>24} {"total":>8} {"infl":>5} {"CMwake":>7} {"mayday":>7} {"rescued":>7}' + + def table_row_str(self): + cm_wakeup = '-' + mayday = '-' + rescued = '-' + + if not self.unbound: + cm_wakeup = str(self.stats[PWQ_STAT_CM_WAKEUP]) + + if self.mem_reclaim: + mayday = str(self.stats[PWQ_STAT_MAYDAY]) + rescued = str(self.stats[PWQ_STAT_RESCUED]) + + out = f'{self.name[-24:]:24} ' \ + f'{self.stats[PWQ_STAT_STARTED]:8} ' \ + f'{max(self.stats[PWQ_STAT_STARTED] - self.stats[PWQ_STAT_COMPLETED], 0):5} ' \ + f'{cm_wakeup:>7} ' \ + f'{mayday:>7} ' \ + f'{rescued:>7} ' + return out.rstrip(':') + +exit_req = False + +def sigint_handler(signr, frame): + global exit_req + exit_req = True + +def main(): + # handle args + table_fmt = not args.json + interval = args.interval + + re_str = None + if args.workqueue: + for r in args.workqueue: + if re_str is None: + re_str = r + else: + re_str += '|' + r + + filter_re = re.compile(re_str) if re_str else None + + # monitoring loop + signal.signal(signal.SIGINT, sigint_handler) + + while not exit_req: + now = time.time() + + if table_fmt: + print() + print(WqStats.table_header_str()) + + for wq in list_for_each_entry('struct workqueue_struct', workqueues.address_of_(), 'list'): + stats = WqStats(wq) + if filter_re and not filter_re.search(stats.name): + continue + if table_fmt: + print(stats.table_row_str()) + else: + print(stats.dict(now)) + + if interval == 0: + break + time.sleep(interval) + +if __name__ == "__main__": + main() From 3a46c9833c1fad3b4a91bbbeb856810c7e1d8e47 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:08 -1000 Subject: [PATCH 03/11] workqueue: Re-order struct worker fields struct worker was laid out with the intent that all fields that are modified for each work item execution are in the first cacheline. However, this hasn't been true for a while with the addition of ->last_func. Let's just collect hot fields together at the top. Move ->sleeping in the hole after ->current_color and move ->lst_func right below. While at it, drop the cacheline comment which isn't useful anymore. Signed-off-by: Tejun Heo Cc: Lai Jiangshan --- kernel/workqueue_internal.h | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/kernel/workqueue_internal.h b/kernel/workqueue_internal.h index e00b1204a8e9..0600f04ceeb2 100644 --- a/kernel/workqueue_internal.h +++ b/kernel/workqueue_internal.h @@ -32,9 +32,12 @@ struct worker { work_func_t current_func; /* L: current_work's fn */ struct pool_workqueue *current_pwq; /* L: current_work's pwq */ unsigned int current_color; /* L: current_work's color */ - struct list_head scheduled; /* L: scheduled works */ + int sleeping; /* None */ - /* 64 bytes boundary on 64bit, 32 on 32bit */ + /* used by the scheduler to determine a worker's last known identity */ + work_func_t last_func; /* L: last work's fn */ + + struct list_head scheduled; /* L: scheduled works */ struct task_struct *task; /* I: worker task */ struct worker_pool *pool; /* A: the associated pool */ @@ -45,7 +48,6 @@ struct worker { unsigned long last_active; /* L: last active timestamp */ unsigned int flags; /* X: flags */ int id; /* I: worker id */ - int sleeping; /* None */ /* * Opaque string set with work_set_desc(). Printed out with task @@ -55,9 +57,6 @@ struct worker { /* used only by rescuers to point to the target workqueue */ struct workqueue_struct *rescue_wq; /* I: the workqueue to rescue */ - - /* used by the scheduler to determine a worker's last known identity */ - work_func_t last_func; }; /** From c54d5046a06b90adb3d1188f0741a88692854354 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:08 -1000 Subject: [PATCH 04/11] workqueue: Move worker_set/clr_flags() upwards They are going to be used in wq_worker_stopping(). Move them upwards. Signed-off-by: Tejun Heo Cc: Lai Jiangshan --- kernel/workqueue.c | 108 ++++++++++++++++++++++----------------------- 1 file changed, 54 insertions(+), 54 deletions(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 60d5b84cccb2..d70bb5be99ce 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -879,6 +879,60 @@ static void wake_up_worker(struct worker_pool *pool) wake_up_process(worker->task); } +/** + * worker_set_flags - set worker flags and adjust nr_running accordingly + * @worker: self + * @flags: flags to set + * + * Set @flags in @worker->flags and adjust nr_running accordingly. + * + * CONTEXT: + * raw_spin_lock_irq(pool->lock) + */ +static inline void worker_set_flags(struct worker *worker, unsigned int flags) +{ + struct worker_pool *pool = worker->pool; + + WARN_ON_ONCE(worker->task != current); + + /* If transitioning into NOT_RUNNING, adjust nr_running. */ + if ((flags & WORKER_NOT_RUNNING) && + !(worker->flags & WORKER_NOT_RUNNING)) { + pool->nr_running--; + } + + worker->flags |= flags; +} + +/** + * worker_clr_flags - clear worker flags and adjust nr_running accordingly + * @worker: self + * @flags: flags to clear + * + * Clear @flags in @worker->flags and adjust nr_running accordingly. + * + * CONTEXT: + * raw_spin_lock_irq(pool->lock) + */ +static inline void worker_clr_flags(struct worker *worker, unsigned int flags) +{ + struct worker_pool *pool = worker->pool; + unsigned int oflags = worker->flags; + + WARN_ON_ONCE(worker->task != current); + + worker->flags &= ~flags; + + /* + * If transitioning out of NOT_RUNNING, increment nr_running. Note + * that the nested NOT_RUNNING is not a noop. NOT_RUNNING is mask + * of multiple flags, not a single flag. + */ + if ((flags & WORKER_NOT_RUNNING) && (oflags & WORKER_NOT_RUNNING)) + if (!(worker->flags & WORKER_NOT_RUNNING)) + pool->nr_running++; +} + /** * wq_worker_running - a worker is running again * @task: task waking up @@ -983,60 +1037,6 @@ work_func_t wq_worker_last_func(struct task_struct *task) return worker->last_func; } -/** - * worker_set_flags - set worker flags and adjust nr_running accordingly - * @worker: self - * @flags: flags to set - * - * Set @flags in @worker->flags and adjust nr_running accordingly. - * - * CONTEXT: - * raw_spin_lock_irq(pool->lock) - */ -static inline void worker_set_flags(struct worker *worker, unsigned int flags) -{ - struct worker_pool *pool = worker->pool; - - WARN_ON_ONCE(worker->task != current); - - /* If transitioning into NOT_RUNNING, adjust nr_running. */ - if ((flags & WORKER_NOT_RUNNING) && - !(worker->flags & WORKER_NOT_RUNNING)) { - pool->nr_running--; - } - - worker->flags |= flags; -} - -/** - * worker_clr_flags - clear worker flags and adjust nr_running accordingly - * @worker: self - * @flags: flags to clear - * - * Clear @flags in @worker->flags and adjust nr_running accordingly. - * - * CONTEXT: - * raw_spin_lock_irq(pool->lock) - */ -static inline void worker_clr_flags(struct worker *worker, unsigned int flags) -{ - struct worker_pool *pool = worker->pool; - unsigned int oflags = worker->flags; - - WARN_ON_ONCE(worker->task != current); - - worker->flags &= ~flags; - - /* - * If transitioning out of NOT_RUNNING, increment nr_running. Note - * that the nested NOT_RUNNING is not a noop. NOT_RUNNING is mask - * of multiple flags, not a single flag. - */ - if ((flags & WORKER_NOT_RUNNING) && (oflags & WORKER_NOT_RUNNING)) - if (!(worker->flags & WORKER_NOT_RUNNING)) - pool->nr_running++; -} - /** * find_worker_executing_work - find worker which is executing a work * @pool: pool of interest From bdf8b9bfc131864f0fcef268b34123acfb6a1b59 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:08 -1000 Subject: [PATCH 05/11] workqueue: Improve locking rule description for worker fields * Some worker fields are modified only by the worker itself while holding pool->lock thus making them safe to read from self, IRQ context if the CPU is running the worker or while holding pool->lock. Add 'K' locking rule for them. * worker->sleeping is currently marked "None" which isn't very descriptive. It's used only by the worker itself. Add 'S' locking rule for it. A future patch will depend on the 'K' rule to access worker->current_* from the scheduler ticks. Signed-off-by: Tejun Heo --- kernel/workqueue.c | 6 ++++++ kernel/workqueue_internal.h | 15 ++++++++------- 2 files changed, 14 insertions(+), 7 deletions(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index d70bb5be99ce..942421443603 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -126,6 +126,12 @@ enum { * cpu or grabbing pool->lock is enough for read access. If * POOL_DISASSOCIATED is set, it's identical to L. * + * K: Only modified by worker while holding pool->lock. Can be safely read by + * self, while holding pool->lock or from IRQ context if %current is the + * kworker. + * + * S: Only modified by worker self. + * * A: wq_pool_attach_mutex protected. * * PL: wq_pool_mutex protected. diff --git a/kernel/workqueue_internal.h b/kernel/workqueue_internal.h index 0600f04ceeb2..c2455be7b4c2 100644 --- a/kernel/workqueue_internal.h +++ b/kernel/workqueue_internal.h @@ -28,14 +28,15 @@ struct worker { struct hlist_node hentry; /* L: while busy */ }; - struct work_struct *current_work; /* L: work being processed */ - work_func_t current_func; /* L: current_work's fn */ - struct pool_workqueue *current_pwq; /* L: current_work's pwq */ - unsigned int current_color; /* L: current_work's color */ - int sleeping; /* None */ + struct work_struct *current_work; /* K: work being processed and its */ + work_func_t current_func; /* K: function */ + struct pool_workqueue *current_pwq; /* K: pwq */ + unsigned int current_color; /* K: color */ + + int sleeping; /* S: is worker sleeping? */ /* used by the scheduler to determine a worker's last known identity */ - work_func_t last_func; /* L: last work's fn */ + work_func_t last_func; /* K: last work's fn */ struct list_head scheduled; /* L: scheduled works */ @@ -45,7 +46,7 @@ struct worker { struct list_head node; /* A: anchored at pool->workers */ /* A: runs through worker->node */ - unsigned long last_active; /* L: last active timestamp */ + unsigned long last_active; /* K: last active timestamp */ unsigned int flags; /* X: flags */ int id; /* I: worker id */ From 616db8779b1e3f93075df691432cccc5ef3c3ba0 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:08 -1000 Subject: [PATCH 06/11] workqueue: Automatically mark CPU-hogging work items CPU_INTENSIVE If a per-cpu work item hogs the CPU, it can prevent other work items from starting through concurrency management. A per-cpu workqueue which intends to host such CPU-hogging work items can choose to not participate in concurrency management by setting %WQ_CPU_INTENSIVE; however, this can be error-prone and difficult to debug when missed. This patch adds an automatic CPU usage based detection. If a concurrency-managed work item consumes more CPU time than the threshold (10ms by default) continuously without intervening sleeps, wq_worker_tick() which is called from scheduler_tick() will detect the condition and automatically mark it CPU_INTENSIVE. The mechanism isn't foolproof: * Detection depends on tick hitting the work item. Getting preempted at the right timings may allow a violating work item to evade detection at least temporarily. * nohz_full CPUs may not be running ticks and thus can fail detection. * Even when detection is working, the 10ms detection delays can add up if many CPU-hogging work items are queued at the same time. However, in vast majority of cases, this should be able to detect violations reliably and provide reasonable protection with a small increase in code complexity. If some work items trigger this condition repeatedly, the bigger problem likely is the CPU being saturated with such per-cpu work items and the solution would be making them UNBOUND. The next patch will add a debug mechanism to help spot such cases. v4: Documentation for workqueue.cpu_intensive_thresh_us added to kernel-parameters.txt. v3: Switch to use wq_worker_tick() instead of hooking into preemptions as suggested by Peter. v2: Lai pointed out that wq_worker_stopping() also needs to be called from preemption and rtlock paths and an earlier patch was updated accordingly. This patch adds a comment describing the risk of infinte recursions and how they're avoided. Signed-off-by: Tejun Heo Acked-by: Peter Zijlstra Cc: Linus Torvalds Cc: Lai Jiangshan --- .../admin-guide/kernel-parameters.txt | 7 ++ Documentation/core-api/workqueue.rst | 36 +++++----- kernel/sched/core.c | 3 + kernel/workqueue.c | 68 +++++++++++++++++-- kernel/workqueue_internal.h | 2 + tools/workqueue/wq_monitor.py | 13 +++- 6 files changed, 105 insertions(+), 24 deletions(-) diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt index 9e5bab29685f..1f2185cf2f0a 100644 --- a/Documentation/admin-guide/kernel-parameters.txt +++ b/Documentation/admin-guide/kernel-parameters.txt @@ -6931,6 +6931,13 @@ it can be updated at runtime by writing to the corresponding sysfs file. + workqueue.cpu_intensive_thresh_us= + Per-cpu work items which run for longer than this + threshold are automatically considered CPU intensive + and excluded from concurrency management to prevent + them from noticeably delaying other per-cpu work + items. Default is 10000 (10ms). + workqueue.disable_numa By default, all work items queued to unbound workqueues are affine to the NUMA nodes they're diff --git a/Documentation/core-api/workqueue.rst b/Documentation/core-api/workqueue.rst index 7e5c39310bbf..a389f31b025c 100644 --- a/Documentation/core-api/workqueue.rst +++ b/Documentation/core-api/workqueue.rst @@ -354,25 +354,25 @@ Monitoring Use tools/workqueue/wq_monitor.py to monitor workqueue operations: :: $ tools/workqueue/wq_monitor.py events - total infl CMwake mayday rescued - events 18545 0 5 - - - events_highpri 8 0 0 - - - events_long 3 0 0 - - - events_unbound 38306 0 - - - - events_freezable 0 0 0 - - - events_power_efficient 29598 0 0 - - - events_freezable_power_ 10 0 0 - - - sock_diag_events 0 0 0 - - + total infl CPUitsv CMwake mayday rescued + events 18545 0 0 5 - - + events_highpri 8 0 0 0 - - + events_long 3 0 0 0 - - + events_unbound 38306 0 - - - - + events_freezable 0 0 0 0 - - + events_power_efficient 29598 0 0 0 - - + events_freezable_power_ 10 0 0 0 - - + sock_diag_events 0 0 0 0 - - - total infl CMwake mayday rescued - events 18548 0 5 - - - events_highpri 8 0 0 - - - events_long 3 0 0 - - - events_unbound 38322 0 - - - - events_freezable 0 0 0 - - - events_power_efficient 29603 0 0 - - - events_freezable_power_ 10 0 0 - - - sock_diag_events 0 0 0 - - + total infl CPUitsv CMwake mayday rescued + events 18548 0 0 5 - - + events_highpri 8 0 0 0 - - + events_long 3 0 0 0 - - + events_unbound 38322 0 - - - - + events_freezable 0 0 0 0 - - + events_power_efficient 29603 0 0 0 - - + events_freezable_power_ 10 0 0 0 - - + sock_diag_events 0 0 0 0 - - ... diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 944c3ae39861..3484cada9a4a 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -5632,6 +5632,9 @@ void scheduler_tick(void) perf_event_task_tick(); + if (curr->flags & PF_WQ_WORKER) + wq_worker_tick(curr); + #ifdef CONFIG_SMP rq->idle_balance = idle_cpu(cpu); trigger_load_balance(rq); diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 942421443603..3dc83d5eba50 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -212,6 +212,7 @@ struct worker_pool { enum pool_workqueue_stats { PWQ_STAT_STARTED, /* work items started execution */ PWQ_STAT_COMPLETED, /* work items completed execution */ + PWQ_STAT_CPU_INTENSIVE, /* wq_cpu_intensive_thresh_us violations */ PWQ_STAT_CM_WAKEUP, /* concurrency-management worker wakeups */ PWQ_STAT_MAYDAY, /* maydays to rescuer */ PWQ_STAT_RESCUED, /* linked work items executed by rescuer */ @@ -332,6 +333,14 @@ static struct kmem_cache *pwq_cache; static cpumask_var_t *wq_numa_possible_cpumask; /* possible CPUs of each node */ +/* + * Per-cpu work items which run for longer than the following threshold are + * automatically considered CPU intensive and excluded from concurrency + * management to prevent them from noticeably delaying other per-cpu work items. + */ +static unsigned long wq_cpu_intensive_thresh_us = 10000; +module_param_named(cpu_intensive_thresh_us, wq_cpu_intensive_thresh_us, ulong, 0644); + static bool wq_disable_numa; module_param_named(disable_numa, wq_disable_numa, bool, 0444); @@ -962,6 +971,13 @@ void wq_worker_running(struct task_struct *task) if (!(worker->flags & WORKER_NOT_RUNNING)) worker->pool->nr_running++; preempt_enable(); + + /* + * CPU intensive auto-detection cares about how long a work item hogged + * CPU without sleeping. Reset the starting timestamp on wakeup. + */ + worker->current_at = worker->task->se.sum_exec_runtime; + worker->sleeping = 0; } @@ -1012,6 +1028,45 @@ void wq_worker_sleeping(struct task_struct *task) raw_spin_unlock_irq(&pool->lock); } +/** + * wq_worker_tick - a scheduler tick occurred while a kworker is running + * @task: task currently running + * + * Called from scheduler_tick(). We're in the IRQ context and the current + * worker's fields which follow the 'K' locking rule can be accessed safely. + */ +void wq_worker_tick(struct task_struct *task) +{ + struct worker *worker = kthread_data(task); + struct pool_workqueue *pwq = worker->current_pwq; + struct worker_pool *pool = worker->pool; + + if (!pwq) + return; + + /* + * If the current worker is concurrency managed and hogged the CPU for + * longer than wq_cpu_intensive_thresh_us, it's automatically marked + * CPU_INTENSIVE to avoid stalling other concurrency-managed work items. + */ + if ((worker->flags & WORKER_NOT_RUNNING) || + worker->task->se.sum_exec_runtime - worker->current_at < + wq_cpu_intensive_thresh_us * NSEC_PER_USEC) + return; + + raw_spin_lock(&pool->lock); + + worker_set_flags(worker, WORKER_CPU_INTENSIVE); + pwq->stats[PWQ_STAT_CPU_INTENSIVE]++; + + if (need_more_worker(pool)) { + pwq->stats[PWQ_STAT_CM_WAKEUP]++; + wake_up_worker(pool); + } + + raw_spin_unlock(&pool->lock); +} + /** * wq_worker_last_func - retrieve worker's last work function * @task: Task to retrieve last work function of. @@ -2327,7 +2382,6 @@ __acquires(&pool->lock) { struct pool_workqueue *pwq = get_work_pwq(work); struct worker_pool *pool = worker->pool; - bool cpu_intensive = pwq->wq->flags & WQ_CPU_INTENSIVE; unsigned long work_data; struct worker *collision; #ifdef CONFIG_LOCKDEP @@ -2364,6 +2418,7 @@ __acquires(&pool->lock) worker->current_work = work; worker->current_func = work->func; worker->current_pwq = pwq; + worker->current_at = worker->task->se.sum_exec_runtime; work_data = *work_data_bits(work); worker->current_color = get_work_color(work_data); @@ -2381,7 +2436,7 @@ __acquires(&pool->lock) * of concurrency management and the next code block will chain * execution of the pending work items. */ - if (unlikely(cpu_intensive)) + if (unlikely(pwq->wq->flags & WQ_CPU_INTENSIVE)) worker_set_flags(worker, WORKER_CPU_INTENSIVE); /* @@ -2461,9 +2516,12 @@ __acquires(&pool->lock) raw_spin_lock_irq(&pool->lock); - /* clear cpu intensive status */ - if (unlikely(cpu_intensive)) - worker_clr_flags(worker, WORKER_CPU_INTENSIVE); + /* + * In addition to %WQ_CPU_INTENSIVE, @worker may also have been marked + * CPU intensive by wq_worker_tick() if @work hogged CPU longer than + * wq_cpu_intensive_thresh_us. Clear it. + */ + worker_clr_flags(worker, WORKER_CPU_INTENSIVE); /* tag the worker for identification in schedule() */ worker->last_func = worker->current_func; diff --git a/kernel/workqueue_internal.h b/kernel/workqueue_internal.h index c2455be7b4c2..6b1d66e28269 100644 --- a/kernel/workqueue_internal.h +++ b/kernel/workqueue_internal.h @@ -31,6 +31,7 @@ struct worker { struct work_struct *current_work; /* K: work being processed and its */ 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 int current_color; /* K: color */ int sleeping; /* S: is worker sleeping? */ @@ -76,6 +77,7 @@ static inline struct worker *current_wq_worker(void) */ void wq_worker_running(struct task_struct *task); void wq_worker_sleeping(struct task_struct *task); +void wq_worker_tick(struct task_struct *task); work_func_t wq_worker_last_func(struct task_struct *task); #endif /* _KERNEL_WORKQUEUE_INTERNAL_H */ diff --git a/tools/workqueue/wq_monitor.py b/tools/workqueue/wq_monitor.py index fc1643ba06b3..7c6f523b9164 100644 --- a/tools/workqueue/wq_monitor.py +++ b/tools/workqueue/wq_monitor.py @@ -11,6 +11,11 @@ https://github.com/osandov/drgn. infl The number of currently in-flight work items. + CPUitsv The number of times a concurrency-managed work item hogged CPU + longer than the threshold (workqueue.cpu_intensive_thresh_us) + and got excluded from concurrency management to avoid stalling + other work items. + CMwake The number of concurrency-management wake-ups while executing a work item of the workqueue. @@ -53,6 +58,7 @@ WQ_MEM_RECLAIM = prog['WQ_MEM_RECLAIM'] PWQ_STAT_STARTED = prog['PWQ_STAT_STARTED'] # work items started execution PWQ_STAT_COMPLETED = prog['PWQ_STAT_COMPLETED'] # work items completed execution +PWQ_STAT_CPU_INTENSIVE = prog['PWQ_STAT_CPU_INTENSIVE'] # wq_cpu_intensive_thresh_us violations PWQ_STAT_CM_WAKEUP = prog['PWQ_STAT_CM_WAKEUP'] # concurrency-management worker wakeups PWQ_STAT_MAYDAY = prog['PWQ_STAT_MAYDAY'] # maydays to rescuer PWQ_STAT_RESCUED = prog['PWQ_STAT_RESCUED'] # linked work items executed by rescuer @@ -75,19 +81,23 @@ class WqStats: 'mem_reclaim' : self.mem_reclaim, 'started' : self.stats[PWQ_STAT_STARTED], 'completed' : self.stats[PWQ_STAT_COMPLETED], + 'cpu_intensive' : self.stats[PWQ_STAT_CPU_INTENSIVE], 'cm_wakeup' : self.stats[PWQ_STAT_CM_WAKEUP], 'mayday' : self.stats[PWQ_STAT_MAYDAY], 'rescued' : self.stats[PWQ_STAT_RESCUED], } def table_header_str(): - return f'{"":>24} {"total":>8} {"infl":>5} {"CMwake":>7} {"mayday":>7} {"rescued":>7}' + return f'{"":>24} {"total":>8} {"infl":>5} '\ + f'{"CPUitsv":>7} {"CMwake":>7} {"mayday":>7} {"rescued":>7}' def table_row_str(self): + cpu_intensive = '-' cm_wakeup = '-' mayday = '-' rescued = '-' if not self.unbound: + cpu_intensive = str(self.stats[PWQ_STAT_CPU_INTENSIVE]) cm_wakeup = str(self.stats[PWQ_STAT_CM_WAKEUP]) if self.mem_reclaim: @@ -97,6 +107,7 @@ class WqStats: out = f'{self.name[-24:]:24} ' \ f'{self.stats[PWQ_STAT_STARTED]:8} ' \ f'{max(self.stats[PWQ_STAT_STARTED] - self.stats[PWQ_STAT_COMPLETED], 0):5} ' \ + f'{cpu_intensive:>7} ' \ f'{cm_wakeup:>7} ' \ f'{mayday:>7} ' \ f'{rescued:>7} ' From 6363845005202148b8409ec3082e80845c19d309 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:08 -1000 Subject: [PATCH 07/11] workqueue: Report work funcs that trigger automatic CPU_INTENSIVE mechanism Workqueue now automatically marks per-cpu work items that hog CPU for too long as CPU_INTENSIVE, which excludes them from concurrency management and prevents stalling other concurrency-managed work items. If a work function keeps running over the thershold, it likely needs to be switched to use an unbound workqueue. This patch adds a debug mechanism which tracks the work functions which trigger the automatic CPU_INTENSIVE mechanism and report them using pr_warn() with exponential backoff. v3: Documentation update. v2: Drop bouncing to kthread_worker for printing messages. It was to avoid introducing circular locking dependency through printk but not effective as it still had pool lock -> wci_lock -> printk -> pool lock loop. Let's just print directly using printk_deferred(). Signed-off-by: Tejun Heo Suggested-by: Peter Zijlstra --- .../admin-guide/kernel-parameters.txt | 5 + kernel/workqueue.c | 93 +++++++++++++++++++ lib/Kconfig.debug | 13 +++ 3 files changed, 111 insertions(+) diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt index 1f2185cf2f0a..3ed7dda4c994 100644 --- a/Documentation/admin-guide/kernel-parameters.txt +++ b/Documentation/admin-guide/kernel-parameters.txt @@ -6938,6 +6938,11 @@ them from noticeably delaying other per-cpu work items. Default is 10000 (10ms). + If CONFIG_WQ_CPU_INTENSIVE_REPORT is set, the kernel + will report the work functions which violate this + threshold repeatedly. They are likely good + candidates for using WQ_UNBOUND workqueues instead. + workqueue.disable_numa By default, all work items queued to unbound workqueues are affine to the NUMA nodes they're diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 3dc83d5eba50..4ca66384d288 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -948,6 +948,98 @@ static inline void worker_clr_flags(struct worker *worker, unsigned int flags) pool->nr_running++; } +#ifdef CONFIG_WQ_CPU_INTENSIVE_REPORT + +/* + * Concurrency-managed per-cpu work items that hog CPU for longer than + * wq_cpu_intensive_thresh_us trigger the automatic CPU_INTENSIVE mechanism, + * which prevents them from stalling other concurrency-managed work items. If a + * work function keeps triggering this mechanism, it's likely that the work item + * should be using an unbound workqueue instead. + * + * wq_cpu_intensive_report() tracks work functions which trigger such conditions + * and report them so that they can be examined and converted to use unbound + * workqueues as appropriate. To avoid flooding the console, each violating work + * function is tracked and reported with exponential backoff. + */ +#define WCI_MAX_ENTS 128 + +struct wci_ent { + work_func_t func; + atomic64_t cnt; + struct hlist_node hash_node; +}; + +static struct wci_ent wci_ents[WCI_MAX_ENTS]; +static int wci_nr_ents; +static DEFINE_RAW_SPINLOCK(wci_lock); +static DEFINE_HASHTABLE(wci_hash, ilog2(WCI_MAX_ENTS)); + +static struct wci_ent *wci_find_ent(work_func_t func) +{ + struct wci_ent *ent; + + hash_for_each_possible_rcu(wci_hash, ent, hash_node, + (unsigned long)func) { + if (ent->func == func) + return ent; + } + return NULL; +} + +static void wq_cpu_intensive_report(work_func_t func) +{ + struct wci_ent *ent; + +restart: + ent = wci_find_ent(func); + if (ent) { + u64 cnt; + + /* + * Start reporting from the fourth time and back off + * exponentially. + */ + cnt = atomic64_inc_return_relaxed(&ent->cnt); + if (cnt >= 4 && is_power_of_2(cnt)) + printk_deferred(KERN_WARNING "workqueue: %ps hogged CPU for >%luus %llu times, consider switching to WQ_UNBOUND\n", + ent->func, wq_cpu_intensive_thresh_us, + atomic64_read(&ent->cnt)); + return; + } + + /* + * @func is a new violation. Allocate a new entry for it. If wcn_ents[] + * is exhausted, something went really wrong and we probably made enough + * noise already. + */ + if (wci_nr_ents >= WCI_MAX_ENTS) + return; + + raw_spin_lock(&wci_lock); + + if (wci_nr_ents >= WCI_MAX_ENTS) { + raw_spin_unlock(&wci_lock); + return; + } + + if (wci_find_ent(func)) { + raw_spin_unlock(&wci_lock); + goto restart; + } + + ent = &wci_ents[wci_nr_ents++]; + ent->func = func; + atomic64_set(&ent->cnt, 1); + hash_add_rcu(wci_hash, &ent->hash_node, (unsigned long)func); + + raw_spin_unlock(&wci_lock); +} + +#else /* CONFIG_WQ_CPU_INTENSIVE_REPORT */ +static void wq_cpu_intensive_report(work_func_t func) {} +#endif /* CONFIG_WQ_CPU_INTENSIVE_REPORT */ + /** * wq_worker_running - a worker is running again * @task: task waking up @@ -1057,6 +1149,7 @@ void wq_worker_tick(struct task_struct *task) raw_spin_lock(&pool->lock); worker_set_flags(worker, WORKER_CPU_INTENSIVE); + wq_cpu_intensive_report(worker->current_func); pwq->stats[PWQ_STAT_CPU_INTENSIVE]++; if (need_more_worker(pool)) { diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index ce51d4dc6803..97e880aa48d7 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -1134,6 +1134,19 @@ config WQ_WATCHDOG state. This can be configured through kernel parameter "workqueue.watchdog_thresh" and its sysfs counterpart. +config WQ_CPU_INTENSIVE_REPORT + bool "Report per-cpu work items which hog CPU for too long" + depends on DEBUG_KERNEL + help + Say Y here to enable reporting of concurrency-managed per-cpu work + items that hog CPUs for longer than + workqueue.cpu_intensive_threshold_us. Workqueue automatically + detects and excludes them from concurrency management to prevent + them from stalling other per-cpu work items. Occassional + triggering may not necessarily indicate a problem. Repeated + triggering likely indicates that the work item should be switched + to use an unbound workqueue. + config TEST_LOCKUP tristate "Test module to generate lockups" depends on m From 8a1dd1e547c1a037692e7a6da6a76108108c72b1 Mon Sep 17 00:00:00 2001 From: Tejun Heo Date: Wed, 17 May 2023 17:02:09 -1000 Subject: [PATCH 08/11] workqueue: Track and monitor per-workqueue CPU time usage Now that wq_worker_tick() is there, we can easily track the rough CPU time consumption of each workqueue by charging the whole tick whenever a tick hits an active workqueue. While not super accurate, it provides reasonable visibility into the workqueues that consume a lot of CPU cycles. wq_monitor.py is updated to report the per-workqueue CPU times. v2: wq_monitor.py was using "cputime" as the key when outputting in json format. Use "cpu_time" instead for consistency with other fields. Signed-off-by: Tejun Heo --- Documentation/core-api/workqueue.rst | 36 ++++++++++++++-------------- kernel/workqueue.c | 3 +++ tools/workqueue/wq_monitor.py | 9 ++++++- 3 files changed, 29 insertions(+), 19 deletions(-) diff --git a/Documentation/core-api/workqueue.rst b/Documentation/core-api/workqueue.rst index a389f31b025c..a4c9b9d1905f 100644 --- a/Documentation/core-api/workqueue.rst +++ b/Documentation/core-api/workqueue.rst @@ -354,25 +354,25 @@ Monitoring Use tools/workqueue/wq_monitor.py to monitor workqueue operations: :: $ tools/workqueue/wq_monitor.py events - total infl CPUitsv CMwake mayday rescued - events 18545 0 0 5 - - - events_highpri 8 0 0 0 - - - events_long 3 0 0 0 - - - events_unbound 38306 0 - - - - - events_freezable 0 0 0 0 - - - events_power_efficient 29598 0 0 0 - - - events_freezable_power_ 10 0 0 0 - - - sock_diag_events 0 0 0 0 - - + total infl CPUtime CPUhog CMwake mayday rescued + events 18545 0 6.1 0 5 - - + events_highpri 8 0 0.0 0 0 - - + events_long 3 0 0.0 0 0 - - + events_unbound 38306 0 0.1 - - - - + events_freezable 0 0 0.0 0 0 - - + events_power_efficient 29598 0 0.2 0 0 - - + events_freezable_power_ 10 0 0.0 0 0 - - + sock_diag_events 0 0 0.0 0 0 - - - total infl CPUitsv CMwake mayday rescued - events 18548 0 0 5 - - - events_highpri 8 0 0 0 - - - events_long 3 0 0 0 - - - events_unbound 38322 0 - - - - - events_freezable 0 0 0 0 - - - events_power_efficient 29603 0 0 0 - - - events_freezable_power_ 10 0 0 0 - - - sock_diag_events 0 0 0 0 - - + total infl CPUtime CPUhog CMwake mayday rescued + events 18548 0 6.1 0 5 - - + events_highpri 8 0 0.0 0 0 - - + events_long 3 0 0.0 0 0 - - + events_unbound 38322 0 0.1 - - - - + events_freezable 0 0 0.0 0 0 - - + events_power_efficient 29603 0 0.2 0 0 - - + events_freezable_power_ 10 0 0.0 0 0 - - + sock_diag_events 0 0 0.0 0 0 - - ... diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 4ca66384d288..ee16ddb0647c 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -212,6 +212,7 @@ struct worker_pool { enum pool_workqueue_stats { PWQ_STAT_STARTED, /* work items started execution */ PWQ_STAT_COMPLETED, /* work items completed execution */ + PWQ_STAT_CPU_TIME, /* total CPU time consumed */ PWQ_STAT_CPU_INTENSIVE, /* wq_cpu_intensive_thresh_us violations */ PWQ_STAT_CM_WAKEUP, /* concurrency-management worker wakeups */ PWQ_STAT_MAYDAY, /* maydays to rescuer */ @@ -1136,6 +1137,8 @@ void wq_worker_tick(struct task_struct *task) if (!pwq) return; + pwq->stats[PWQ_STAT_CPU_TIME] += TICK_USEC; + /* * If the current worker is concurrency managed and hogged the CPU for * longer than wq_cpu_intensive_thresh_us, it's automatically marked diff --git a/tools/workqueue/wq_monitor.py b/tools/workqueue/wq_monitor.py index 7c6f523b9164..6e258d123e8c 100644 --- a/tools/workqueue/wq_monitor.py +++ b/tools/workqueue/wq_monitor.py @@ -11,6 +11,10 @@ https://github.com/osandov/drgn. infl The number of currently in-flight work items. + CPUtime Total CPU time consumed by the workqueue in seconds. This is + sampled from scheduler ticks and only provides ballpark + measurement. "nohz_full=" CPUs are excluded from measurement. + CPUitsv The number of times a concurrency-managed work item hogged CPU longer than the threshold (workqueue.cpu_intensive_thresh_us) and got excluded from concurrency management to avoid stalling @@ -58,6 +62,7 @@ WQ_MEM_RECLAIM = prog['WQ_MEM_RECLAIM'] PWQ_STAT_STARTED = prog['PWQ_STAT_STARTED'] # work items started execution PWQ_STAT_COMPLETED = prog['PWQ_STAT_COMPLETED'] # work items completed execution +PWQ_STAT_CPU_TIME = prog['PWQ_STAT_CPU_TIME'] # total CPU time consumed PWQ_STAT_CPU_INTENSIVE = prog['PWQ_STAT_CPU_INTENSIVE'] # wq_cpu_intensive_thresh_us violations PWQ_STAT_CM_WAKEUP = prog['PWQ_STAT_CM_WAKEUP'] # concurrency-management worker wakeups PWQ_STAT_MAYDAY = prog['PWQ_STAT_MAYDAY'] # maydays to rescuer @@ -81,13 +86,14 @@ class WqStats: 'mem_reclaim' : self.mem_reclaim, 'started' : self.stats[PWQ_STAT_STARTED], 'completed' : self.stats[PWQ_STAT_COMPLETED], + 'cpu_time' : self.stats[PWQ_STAT_CPU_TIME], 'cpu_intensive' : self.stats[PWQ_STAT_CPU_INTENSIVE], 'cm_wakeup' : self.stats[PWQ_STAT_CM_WAKEUP], 'mayday' : self.stats[PWQ_STAT_MAYDAY], 'rescued' : self.stats[PWQ_STAT_RESCUED], } def table_header_str(): - return f'{"":>24} {"total":>8} {"infl":>5} '\ + return f'{"":>24} {"total":>8} {"infl":>5} {"CPUtime":>8} '\ f'{"CPUitsv":>7} {"CMwake":>7} {"mayday":>7} {"rescued":>7}' def table_row_str(self): @@ -107,6 +113,7 @@ class WqStats: out = f'{self.name[-24:]:24} ' \ f'{self.stats[PWQ_STAT_STARTED]:8} ' \ f'{max(self.stats[PWQ_STAT_STARTED] - self.stats[PWQ_STAT_COMPLETED], 0):5} ' \ + f'{self.stats[PWQ_STAT_CPU_TIME] / 1000000:8.1f} ' \ f'{cpu_intensive:>7} ' \ f'{cm_wakeup:>7} ' \ f'{mayday:>7} ' \ From 525ff9c2965770762b81d679820552a208070d59 Mon Sep 17 00:00:00 2001 From: Arnd Bergmann Date: Tue, 17 Jan 2023 17:40:35 +0100 Subject: [PATCH 09/11] workqueue: fix enum type for gcc-13 In gcc-13, the WORK_STRUCT_WQ_DATA_MASK constant is a signed 64-bit type on 32-bit architectures because the enum definition has both negative numbers and numbers above LONG_MAX in it: kernel/workqueue.c: In function 'get_work_pwq': kernel/workqueue.c:709:24: error: cast to pointer from integer of different size [-Werror=int-to-pointer-cast] 709 | return (void *)(data & WORK_STRUCT_WQ_DATA_MASK); | ^ kernel/workqueue.c: In function 'get_work_pool': kernel/workqueue.c:737:25: error: cast to pointer from integer of different size [-Werror=int-to-pointer-cast] 737 | return ((struct pool_workqueue *) | ^ kernel/workqueue.c: In function 'get_work_pool_id': kernel/workqueue.c:759:25: error: cast to pointer from integer of different size [-Werror=int-to-pointer-cast] 759 | return ((struct pool_workqueue *) | ^ Change the enum definition to ensure all values can fit into the range of 'unsigned long' on all architectures. Signed-off-by: Arnd Bergmann Tested-by: Thierry Reding Tested-by: Lai Jiangshan Signed-off-by: Tejun Heo --- include/linux/workqueue.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/linux/workqueue.h b/include/linux/workqueue.h index 3992c994787f..52871d24416e 100644 --- a/include/linux/workqueue.h +++ b/include/linux/workqueue.h @@ -83,7 +83,7 @@ enum { /* convenience constants */ WORK_STRUCT_FLAG_MASK = (1UL << WORK_STRUCT_FLAG_BITS) - 1, - WORK_STRUCT_WQ_DATA_MASK = ~WORK_STRUCT_FLAG_MASK, + WORK_STRUCT_WQ_DATA_MASK = (unsigned long)~WORK_STRUCT_FLAG_MASK, WORK_STRUCT_NO_POOL = (unsigned long)WORK_OFFQ_POOL_NONE << WORK_OFFQ_POOL_SHIFT, /* bit mask for work_busy() return values */ From c8f6219be2e58d7f676935ae90b64abef5d0966a Mon Sep 17 00:00:00 2001 From: Zqiang Date: Wed, 24 May 2023 11:53:39 +0800 Subject: [PATCH 10/11] workqueue: Fix WARN_ON_ONCE() triggers in worker_enter_idle() Currently, pool->nr_running can be modified from timer tick, that means the timer tick can run nested inside a not-irq-protected section that's in the process of modifying nr_running. Consider the following scenario: CPU0 kworker/0:2 (events) worker_clr_flags(worker, WORKER_PREP | WORKER_REBOUND); ->pool->nr_running++; (1) process_one_work() ->worker->current_func(work); ->schedule() ->wq_worker_sleeping() ->worker->sleeping = 1; ->pool->nr_running--; (0) .... ->wq_worker_running() .... CPU0 by interrupt: wq_worker_tick() ->worker_set_flags(worker, WORKER_CPU_INTENSIVE); ->pool->nr_running--; (-1) ->worker->flags |= WORKER_CPU_INTENSIVE; .... ->if (!(worker->flags & WORKER_NOT_RUNNING)) ->pool->nr_running++; (will not execute) ->worker->sleeping = 0; .... ->worker_clr_flags(worker, WORKER_CPU_INTENSIVE); ->pool->nr_running++; (0) .... worker_set_flags(worker, WORKER_PREP); ->pool->nr_running--; (-1) .... worker_enter_idle() ->WARN_ON_ONCE(pool->nr_workers == pool->nr_idle && pool->nr_running); if the nr_workers is equal to nr_idle, due to the nr_running is not zero, will trigger WARN_ON_ONCE(). [ 2.460602] WARNING: CPU: 0 PID: 63 at kernel/workqueue.c:1999 worker_enter_idle+0xb2/0xc0 [ 2.462163] Modules linked in: [ 2.463401] CPU: 0 PID: 63 Comm: kworker/0:2 Not tainted 6.4.0-rc2-next-20230519 #1 [ 2.463771] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014 [ 2.465127] Workqueue: 0x0 (events) [ 2.465678] RIP: 0010:worker_enter_idle+0xb2/0xc0 ... [ 2.472614] Call Trace: [ 2.473152] [ 2.474182] worker_thread+0x71/0x430 [ 2.474992] ? _raw_spin_unlock_irqrestore+0x28/0x50 [ 2.475263] kthread+0x103/0x120 [ 2.475493] ? __pfx_worker_thread+0x10/0x10 [ 2.476355] ? __pfx_kthread+0x10/0x10 [ 2.476635] ret_from_fork+0x2c/0x50 [ 2.477051] This commit therefore add the check of worker->sleeping in wq_worker_tick(), if the worker->sleeping is not zero, directly return. tj: Updated comment and description. Reported-by: Naresh Kamboju Reported-by: Linux Kernel Functional Testing Tested-by: Anders Roxell Closes: https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20230519/testrun/17078554/suite/boot/test/clang-nightly-lkftconfig/log Signed-off-by: Zqiang Signed-off-by: Tejun Heo --- kernel/workqueue.c | 17 ++++++++++++----- 1 file changed, 12 insertions(+), 5 deletions(-) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index ee16ddb0647c..3ad6806c7161 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -1051,7 +1051,7 @@ void wq_worker_running(struct task_struct *task) { struct worker *worker = kthread_data(task); - if (!worker->sleeping) + if (!READ_ONCE(worker->sleeping)) return; /* @@ -1071,7 +1071,7 @@ void wq_worker_running(struct task_struct *task) */ worker->current_at = worker->task->se.sum_exec_runtime; - worker->sleeping = 0; + WRITE_ONCE(worker->sleeping, 0); } /** @@ -1097,10 +1097,10 @@ void wq_worker_sleeping(struct task_struct *task) pool = worker->pool; /* Return if preempted before wq_worker_running() was reached */ - if (worker->sleeping) + if (READ_ONCE(worker->sleeping)) return; - worker->sleeping = 1; + WRITE_ONCE(worker->sleeping, 1); raw_spin_lock_irq(&pool->lock); /* @@ -1143,8 +1143,15 @@ void wq_worker_tick(struct task_struct *task) * If the current worker is concurrency managed and hogged the CPU for * longer than wq_cpu_intensive_thresh_us, it's automatically marked * CPU_INTENSIVE to avoid stalling other concurrency-managed work items. + * + * Set @worker->sleeping means that @worker is in the process of + * switching out voluntarily and won't be contributing to + * @pool->nr_running until it wakes up. As wq_worker_sleeping() also + * decrements ->nr_running, setting CPU_INTENSIVE here can lead to + * double decrements. The task is releasing the CPU anyway. Let's skip. + * We probably want to make this prettier in the future. */ - if ((worker->flags & WORKER_NOT_RUNNING) || + if ((worker->flags & WORKER_NOT_RUNNING) || READ_ONCE(worker->sleeping) || worker->task->se.sum_exec_runtime - worker->current_at < wq_cpu_intensive_thresh_us * NSEC_PER_USEC) return; From 18c8ae813156a6855f026de80fffb91e1a28ab3d Mon Sep 17 00:00:00 2001 From: Zqiang Date: Thu, 25 May 2023 12:00:38 +0800 Subject: [PATCH 11/11] workqueue: Disable per-cpu CPU hog detection when wq_cpu_intensive_thresh_us is 0 If workqueue.cpu_intensive_thresh_us is set to 0, the detection mechanism for CPU-hogging per-cpu work item will keep triggering spuriously: workqueue: process_srcu hogged CPU for >0us 4 times, consider switching to WQ_UNBOUND workqueue: gc_worker hogged CPU for >0us 4 times, consider switching to WQ_UNBOUND workqueue: gc_worker hogged CPU for >0us 8 times, consider switching to WQ_UNBOUND workqueue: wait_rcu_exp_gp hogged CPU for >0us 4 times, consider switching to WQ_UNBOUND workqueue: kfree_rcu_monitor hogged CPU for >0us 4 times, consider switching to WQ_UNBOUND workqueue: kfree_rcu_monitor hogged CPU for >0us 8 times, consider switching to WQ_UNBOUND workqueue: reg_todo hogged CPU for >0us 4 times, consider switching to WQ_UNBOUND This commit therefore disables the CPU-hog detection mechanism when workqueue.cpu_intensive_thresh_us is set to 0. tj: Patch description updated and the condition check on cpu_intensive_thresh_us separated into a separate if statement for readability. Signed-off-by: Zqiang Signed-off-by: Tejun Heo --- kernel/workqueue.c | 3 +++ 1 file changed, 3 insertions(+) diff --git a/kernel/workqueue.c b/kernel/workqueue.c index 3ad6806c7161..41b8388f4284 100644 --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @@ -1139,6 +1139,9 @@ void wq_worker_tick(struct task_struct *task) pwq->stats[PWQ_STAT_CPU_TIME] += TICK_USEC; + if (!wq_cpu_intensive_thresh_us) + return; + /* * If the current worker is concurrency managed and hogged the CPU for * longer than wq_cpu_intensive_thresh_us, it's automatically marked