History

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().

Tejun Heo committed 3 years ago

Commit 63638451 parent 616db873 files · +111 −0Browse files

Unified · Split

3 files
  1. Documentation/admin-guide/kernel-parameters.txt +5 −0
  2. kernel/workqueue.c +93 −0
  3. lib/Kconfig.debug +13 −0
Documentation/admin-guide/kernel-parameters.txt+5−0
@@ -6938,6 +6938,11 @@ · 6937 unmodified lines
69386938 them from noticeably delaying other per-cpu work
69396939 items. Default is 10000 (10ms).
69406940
6941+ If CONFIG_WQ_CPU_INTENSIVE_REPORT is set, the kernel
6942+ will report the work functions which violate this
6943+ threshold repeatedly. They are likely good
6944+ candidates for using WQ_UNBOUND workqueues instead.
6945+
69416946 workqueue.disable_numa
69426947 By default, all work items queued to unbound
69436948 workqueues are affine to the NUMA nodes they're
kernel/workqueue.c+93−0
@@ -948,6 +948,98 @@ static inline void worker_clr_flags(struct worker *worker, unsigned int flags) · 947 unmodified lines
948948 pool->nr_running++;
949949 }
950950
951+#ifdef CONFIG_WQ_CPU_INTENSIVE_REPORT
952+
953+/*
954+ * Concurrency-managed per-cpu work items that hog CPU for longer than
955+ * wq_cpu_intensive_thresh_us trigger the automatic CPU_INTENSIVE mechanism,
956+ * which prevents them from stalling other concurrency-managed work items. If a
957+ * work function keeps triggering this mechanism, it's likely that the work item
958+ * should be using an unbound workqueue instead.
959+ *
960+ * wq_cpu_intensive_report() tracks work functions which trigger such conditions
961+ * and report them so that they can be examined and converted to use unbound
962+ * workqueues as appropriate. To avoid flooding the console, each violating work
963+ * function is tracked and reported with exponential backoff.
964+ */
965+#define WCI_MAX_ENTS 128
966+
967+struct wci_ent {
968+ work_func_t func;
969+ atomic64_t cnt;
970+ struct hlist_node hash_node;
971+};
972+
973+static struct wci_ent wci_ents[WCI_MAX_ENTS];
974+static int wci_nr_ents;
975+static DEFINE_RAW_SPINLOCK(wci_lock);
976+static DEFINE_HASHTABLE(wci_hash, ilog2(WCI_MAX_ENTS));
977+
978+static struct wci_ent *wci_find_ent(work_func_t func)
979+{
980+ struct wci_ent *ent;
981+
982+ hash_for_each_possible_rcu(wci_hash, ent, hash_node,
983+ (unsigned long)func) {
984+ if (ent->func == func)
985+ return ent;
986+ }
987+ return NULL;
988+}
989+
990+static void wq_cpu_intensive_report(work_func_t func)
991+{
992+ struct wci_ent *ent;
993+
994+restart:
995+ ent = wci_find_ent(func);
996+ if (ent) {
997+ u64 cnt;
998+
999+ /*
1000+ * Start reporting from the fourth time and back off
1001+ * exponentially.
1002+ */
1003+ cnt = atomic64_inc_return_relaxed(&ent->cnt);
1004+ if (cnt >= 4 && is_power_of_2(cnt))
1005+ printk_deferred(KERN_WARNING "workqueue: %ps hogged CPU for >%luus %llu times, consider switching to WQ_UNBOUND\n",
1006+ ent->func, wq_cpu_intensive_thresh_us,
1007+ atomic64_read(&ent->cnt));
1008+ return;
1009+ }
1010+
1011+ /*
1012+ * @func is a new violation. Allocate a new entry for it. If wcn_ents[]
1013+ * is exhausted, something went really wrong and we probably made enough
1014+ * noise already.
1015+ */
1016+ if (wci_nr_ents >= WCI_MAX_ENTS)
1017+ return;
1018+
1019+ raw_spin_lock(&wci_lock);
1020+
1021+ if (wci_nr_ents >= WCI_MAX_ENTS) {
1022+ raw_spin_unlock(&wci_lock);
1023+ return;
1024+ }
1025+
1026+ if (wci_find_ent(func)) {
1027+ raw_spin_unlock(&wci_lock);
1028+ goto restart;
1029+ }
1030+
1031+ ent = &wci_ents[wci_nr_ents++];
1032+ ent->func = func;
1033+ atomic64_set(&ent->cnt, 1);
1034+ hash_add_rcu(wci_hash, &ent->hash_node, (unsigned long)func);
1035+
1036+ raw_spin_unlock(&wci_lock);
1037+}
1038+
1039+#else /* CONFIG_WQ_CPU_INTENSIVE_REPORT */
1040+static void wq_cpu_intensive_report(work_func_t func) {}
1041+#endif /* CONFIG_WQ_CPU_INTENSIVE_REPORT */
1042+
9511043 /**
9521044 * wq_worker_running - a worker is running again
9531045 * @task: task waking up
@@ -1057,6 +1149,7 @@ void wq_worker_tick(struct task_struct *task) · 103 unmodified lines
10571149 raw_spin_lock(&pool->lock);
10581150
10591151 worker_set_flags(worker, WORKER_CPU_INTENSIVE);
1152+ wq_cpu_intensive_report(worker->current_func);
10601153 pwq->stats[PWQ_STAT_CPU_INTENSIVE]++;
10611154
10621155 if (need_more_worker(pool)) {
lib/Kconfig.debug+13−0
@@ -1134,6 +1134,19 @@ config WQ_WATCHDOG · 1133 unmodified lines
11341134 state. This can be configured through kernel parameter
11351135 "workqueue.watchdog_thresh" and its sysfs counterpart.
11361136
1137+config WQ_CPU_INTENSIVE_REPORT
1138+ bool "Report per-cpu work items which hog CPU for too long"
1139+ depends on DEBUG_KERNEL
1140+ help
1141+ Say Y here to enable reporting of concurrency-managed per-cpu work
1142+ items that hog CPUs for longer than
1143+ workqueue.cpu_intensive_threshold_us. Workqueue automatically
1144+ detects and excludes them from concurrency management to prevent
1145+ them from stalling other per-cpu work items. Occassional
1146+ triggering may not necessarily indicate a problem. Repeated
1147+ triggering likely indicates that the work item should be switched
1148+ to use an unbound workqueue.
1149+
11371150 config TEST_LOCKUP
11381151 tristate "Test module to generate lockups"
11391152 depends on m