On 26 Jan 2021 10:45:21 +0800 Xing Zhengjun wrote:I test the patch, the warning still appears in the kernel log.
On 1/25/2021 5:29 PM, Hillf Danton wrote:
On 25 Jan 2021 16:31:32 +0800 Xing Zhengjun wrote:I test the patch, the warning still appears in the kernel log, but the
On 1/22/2021 3:59 PM, Hillf Danton wrote:
On Fri, 22 Jan 2021 09:48:32 +0800 Xing Zhengjun wrote:I test the patch, the warning still appears in the kernel log.
On 1/21/2021 12:00 PM, Hillf Danton wrote:
On Wed, 20 Jan 2021 21:46:33 +0800 Oliver Sang wrote:I test the patch, the warning still appears in the kernel log.
On Fri, Jan 15, 2021 at 03:24:32PM +0800, Hillf Danton wrote:
Thu, 14 Jan 2021 15:45:11 +0800
[...]
FYI, we noticed the following commit (built with gcc-9):
commit: d5bff968ea9cc005e632d9369c26cbd8148c93d5 ("workqueue: break affinity initiatively")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2021.01.11b
[ 73.794288] WARNING: CPU: 0 PID: 22 at kernel/workqueue.c:2192 process_one_work
Thanks for your report.
We can also break CPU affinity by checking POOL_DISASSOCIATED at attach
time without extra cost paid; that way we have the same behavior as at
the unbind time.
What is more the change that makes kworker pcpu is cut because they are
going to not help either hotplug or the mechanism of stop machine.
hi, by applying below patch, the issue still happened.
Thanks for your report.
[ 4.574467] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 4.575651] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 4.576900] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[ 4.578648] PCI: CLS 0 bytes, default 64
[ 4.579685] Unpacking initramfs...
[ 8.878031] -----------[ cut here ]-----------
[ 8.879083] WARNING: CPU: 0 PID: 22 at kernel/workqueue.c:2187 process_one_work+0x92/0x9e0
[ 8.880688] Modules linked in:
[ 8.881274] CPU: 0 PID: 22 Comm: kworker/1:0 Not tainted 5.11.0-rc3-gc213503139bb #2
The kworker bond to CPU1 runs on CPU0 and triggers the warning, which
shows that scheduler breaks CPU affinity, after 06249738a41a
("workqueue: Manually break affinity on hotplug"), though quite likely
by kworker/1:0 for the initial workers.
[ 8.882518] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 8.887539] Workqueue: 0x0 (events)
[ 8.887838] EIP: process_one_work+0x92/0x9e0
[ 8.887838] Code: 37 64 a1 58 54 4c 43 39 45 24 74 2c 31 c9 ba 01 00 00 00 c7 04 24 01 00 00 00 b8 08 1d f5 42 e8 74 85 13 00 ff 05 b8 30 04 43 <0f> 0b ba 01 00 00 00 eb 22 8d 74 26 00 90 c7 04 24 01 00 00 00 31
[ 8.887838] EAX: 42f51d08 EBX: 00000000 ECX: 00000000 EDX: 00000001
[ 8.887838] ESI: 43c04720 EDI: 42e45620 EBP: de7f23c0 ESP: 43d7bf08
[ 8.887838] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010002
[ 8.887838] CR0: 80050033 CR2: 00000000 CR3: 034e3000 CR4: 000406d0
[ 8.887838] Call Trace:
[ 8.887838] ? worker_thread+0x98/0x6a0
[ 8.887838] ? worker_thread+0x2dd/0x6a0
[ 8.887838] ? kthread+0x1ba/0x1e0
[ 8.887838] ? create_worker+0x1e0/0x1e0
[ 8.887838] ? kzalloc+0x20/0x20
[ 8.887838] ? ret_from_fork+0x1c/0x28
[ 8.887838] _warn_unseeded_randomness: 63 callbacks suppressed
[ 8.887838] random: get_random_bytes called from init_oops_id+0x2b/0x60 with crng_init=0
[ 8.887838] --[ end trace ac461b4d54c37cfa ]--
Instead of creating the initial workers only on the active CPUS, rebind
them (labeled pcpu) and jump to the right CPU at bootup time.
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -2385,6 +2385,16 @@ woke_up:
return 0;
}
+ if (!(pool->flags & POOL_DISASSOCIATED) && smp_processor_id() !=
+ pool->cpu) {
+ /* scheduler breaks CPU affinity for us, rebind it */
+ raw_spin_unlock_irq(&pool->lock);
+ set_cpus_allowed_ptr(worker->task, pool->attrs->cpumask);
+ /* and jump to the right seat */
+ schedule_timeout_interruptible(1);
+ goto woke_up;
+ }
+
worker_leave_idle(worker);
recheck:
/* no more worker necessary? */
--
Thanks for your report.
[ 230.356503] smpboot: CPU 1 is now offline
[ 230.544652] x86: Booting SMP configuration:
[ 230.545077] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 230.545640] kvm-clock: cpu 1, msr 34f6021, secondary cpu clock
[ 230.545675] masked ExtINT on CPU#1
[ 230.593829] ------------[ cut here ]------------
[ 230.594257] WARNING: CPU: 0 PID: 257 at kernel/workqueue.c:2192 process_one_work+0x92/0x9e0
[ 230.594990] Modules linked in: rcutorture torture mousedev input_leds
led_class pcspkr psmouse evbug tiny_power_button button
[ 230.595961] CPU: 0 PID: 257 Comm: kworker/1:3 Not tainted 5.11.0-rc3-gdcba55d9080f #2
Like what was reported, kworker bond to CPU1 runs on CPU0 and triggers
warning, due to scheduler breaking CPU affinity for us. What is new, the
affinity was broken at offline time instead of bootup.
[ 230.596621] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 230.597322] Workqueue: 0x0 (rcu_gp)
[ 230.597636] EIP: process_one_work+0x92/0x9e0
[ 230.598005] Code: 37 64 a1 58 54 4c 43 39 45 24 74 2c 31 c9 ba 01 00
00 00 c7 04 24 01 00 00 00 b8 08 1d f5 42 e8 f4 85 13 00 ff 05 cc 30 04
43 <0f> 0b ba 01 00 00 00 eb 22 8d 74 26 00 90 c7 04 24 01 00 00 00 31
[ 230.599569] EAX: 42f51d08 EBX: 00000000 ECX: 00000000 EDX: 00000001
[ 230.600100] ESI: 43d94240 EDI: df4040f4 EBP: de7f23c0 ESP: bf5f1f08
[ 230.600629] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010002
[ 230.601203] CR0: 80050033 CR2: 01bdecbc CR3: 04e2c000 CR4: 000406d0
[ 230.601735] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 230.602265] DR6: fffe0ff0 DR7: 00000400
[ 230.602594] Call Trace:
[ 230.602813] ? process_one_work+0x20e/0x9e0
[ 230.603181] ? worker_thread+0x32d/0x700
[ 230.603522] ? kthread+0x1ba/0x1e0
[ 230.603818] ? create_worker+0x1e0/0x1e0
[ 230.604157] ? kzalloc+0x20/0x20
[ 230.604524] ? ret_from_fork+0x1c/0x28
[ 230.604850] ---[ end trace 06b1e66b5e17fa85 ]---
[ 230.605504] kvm-guest: stealtime: cpu 1, msr 9e7e6ec0
[ 230.766960] smpboot: CPU 1 is now offline
[ 230.814803] x86: Booting SMP configuration:
[ 230.815306] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 230.815964] kvm-clock: cpu 1, msr 34f6021, secondary cpu clock
Unlike the above diff that is at most papering over the problem
sitting somewhere in the scheduler, add change to creating worker
by skipping set_cpus_allowed_ptr() because we will wake it up after
attaching it to worker pool.
If we can ignore rescuer for now, then the allowed ptr is only
updated at on/offline time; lets see the difference at boot time.
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1844,16 +1844,10 @@ static struct worker *alloc_worker(int n
* cpu-[un]hotplugs.
*/
static void worker_attach_to_pool(struct worker *worker,
- struct worker_pool *pool)
+ struct worker_pool *pool,
+ int update_cpus_allowed)
{
mutex_lock(&wq_pool_attach_mutex);
-
- /*
- * set_cpus_allowed_ptr() will fail if the cpumask doesn't have any
- * online CPUs. It'll be re-applied when any of the CPUs come up.
- */
- set_cpus_allowed_ptr(worker->task, pool->attrs->cpumask);
-
/*
* The wq_pool_attach_mutex ensures %POOL_DISASSOCIATED remains
* stable across this function. See the comments above the flag
@@ -1867,6 +1861,9 @@ static void worker_attach_to_pool(struct
list_add_tail(&worker->node, &pool->workers);
worker->pool = pool;
+ if (update_cpus_allowed)
+ set_cpus_allowed_ptr(worker->task, pool->attrs->cpumask);
+
mutex_unlock(&wq_pool_attach_mutex);
}
@@ -1942,8 +1939,11 @@ static struct worker *create_worker(stru
set_user_nice(worker->task, pool->attrs->nice);
kthread_bind_mask(worker->task, pool->attrs->cpumask);
- /* successful, attach the worker to the pool */
- worker_attach_to_pool(worker, pool);
+ /*
+ * attach the worker to the pool without asking scheduler to
+ * update CPUs allowed
+ */
+ worker_attach_to_pool(worker, pool, 0);
/* start the newly created worker */
raw_spin_lock_irq(&pool->lock);
@@ -2508,7 +2508,7 @@ repeat:
raw_spin_unlock_irq(&wq_mayday_lock);
- worker_attach_to_pool(rescuer, pool);
+ worker_attach_to_pool(rescuer, pool, 1);
raw_spin_lock_irq(&pool->lock);
--
Thanks.
[ 55.754187] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 55.785594] kvm-clock: cpu 1, msr 34f6021, secondary cpu clock
[ 55.785646] masked ExtINT on CPU#1
[ 55.920602] ------------[ cut here ]------------
[ 55.921355] WARNING: CPU: 0 PID: 160 at kernel/workqueue.c:2192 process_one_work+0x92/0x9e0
[ 55.922583] Modules linked in: rcutorture torture mousedev evbug
input_leds led_class tiny_power_button psmouse pcspkr button
[ 55.924294] CPU: 0 PID: 160 Comm: kworker/1:2 Not tainted 5.11.0-rc3-00186-g77bf4e461cfa #2
Same issue as before.
[ 55.925552] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 55.926763] Workqueue: 0x0 (rcu_gp)
[ 55.927298] EIP: process_one_work+0x92/0x9e0
[ 55.927950] Code: 37 64 a1 58 54 4c 43 39 45 24 74 2c 31 c9 ba 01 00
00 00 c7 04 24 01 00 00 00 b8 08 1d f5 42 e8 94 85 13 00 ff 05 b8 30 04
43 <0f> 0b ba 01 00 00 00 eb 22 8d 74 26 00 90 c7 04 24 01 00 00 00 31
[ 55.930726] EAX: 42f51d08 EBX: 00000000 ECX: 00000000 EDX: 00000001
[ 55.931642] ESI: 43d90540 EDI: df48c0f4 EBP: de7f23c0 ESP: bfb47f08
[ 55.932590] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010002
[ 55.933609] CR0: 80050033 CR2: 024e994c CR3: 7fd80000 CR4: 000406d0
[ 55.934555] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 55.935457] DR6: fffe0ff0 DR7: 00000400
[ 55.936041] Call Trace:
[ 55.936534] ? process_one_work+0x20e/0x9e0
[ 55.937305] ? worker_thread+0x2dd/0x6a0
[ 55.938018] ? kthread+0x1ba/0x1e0
[ 55.938598] ? create_worker+0x1e0/0x1e0
[ 55.939315] ? kzalloc+0x20/0x20
[ 55.940000] ? ret_from_fork+0x1c/0x28
[ 55.940627] ---[ end trace d155e9e6402de179 ]---
[ 55.941641] kvm-guest: stealtime: cpu 1, msr 9e7e6ec0
[ 56.155271] smpboot: CPU 1 is now offline
[ 56.193613] x86: Booting SMP configuration:
[ 56.194400] smpboot: Booting Node 0 Processor 1 APIC 0x1
The changes in the diff below are
1/ at rescue time, change CPU affinity only if POOL_DISASSOCIATED
is not set, and print warning the same way as offline time.
2/ at offine time, dont update allowed CPUs after setting
POOL_DISASSOCIATED because we no longer have interest in affinity.
3/ at online time, mark pcpu before binding affinity.
Though one change a diff is appreciated, by the WARNs, we can tell
which is what if any warning goes into dmesg.
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1844,25 +1844,23 @@ static struct worker *alloc_worker(int n
* cpu-[un]hotplugs.
*/
static void worker_attach_to_pool(struct worker *worker,
- struct worker_pool *pool)
+ struct worker_pool *pool, int set)
{
mutex_lock(&wq_pool_attach_mutex);
/*
- * set_cpus_allowed_ptr() will fail if the cpumask doesn't have any
- * online CPUs. It'll be re-applied when any of the CPUs come up.
- */
- set_cpus_allowed_ptr(worker->task, pool->attrs->cpumask);
-
- /*
* The wq_pool_attach_mutex ensures %POOL_DISASSOCIATED remains
* stable across this function. See the comments above the flag
* definition for details.
*/
if (pool->flags & POOL_DISASSOCIATED)
worker->flags |= WORKER_UNBOUND;
- else
+ else {
kthread_set_per_cpu(worker->task, true);
+ if (set)
+ WARN_ON_ONCE(set_cpus_allowed_ptr(worker->task,
+ pool->attrs->cpumask) < 0);
+ }
list_add_tail(&worker->node, &pool->workers);
worker->pool = pool;
@@ -1943,7 +1941,7 @@ static struct worker *create_worker(stru
kthread_bind_mask(worker->task, pool->attrs->cpumask);
/* successful, attach the worker to the pool */
- worker_attach_to_pool(worker, pool);
+ worker_attach_to_pool(worker, pool, 0);
/* start the newly created worker */
raw_spin_lock_irq(&pool->lock);
@@ -2508,7 +2506,7 @@ repeat:
raw_spin_unlock_irq(&wq_mayday_lock);
- worker_attach_to_pool(rescuer, pool);
+ worker_attach_to_pool(rescuer, pool, 1);
raw_spin_lock_irq(&pool->lock);
@@ -4923,7 +4921,6 @@ static void unbind_workers(int cpu)
for_each_pool_worker(worker, pool) {
kthread_set_per_cpu(worker->task, false);
- WARN_ON_ONCE(set_cpus_allowed_ptr(worker->task, cpu_possible_mask) < 0);
}
mutex_unlock(&wq_pool_attach_mutex);
@@ -4977,9 +4974,9 @@ static void rebind_workers(struct worker
* from CPU_ONLINE, the following shouldn't fail.
*/
for_each_pool_worker(worker, pool) {
+ kthread_set_per_cpu(worker->task, true);
WARN_ON_ONCE(set_cpus_allowed_ptr(worker->task,
pool->attrs->cpumask) < 0);
- kthread_set_per_cpu(worker->task, true);
}
raw_spin_lock_irq(&pool->lock);
--
Thanks.
warning is different from before.
[ 0.054803] kvm-clock: cpu 1, msr 34f6021, secondary cpu clock
[ 0.054803] masked ExtINT on CPU#1
[ 0.054803] smpboot: CPU 1 Converting physical 0 to logical die 1
[ 1.890338] ------------[ cut here ]------------
[ 1.890338] WARNING: CPU: 1 PID: 18 at kernel/kthread.c:508 kthread_set_per_cpu+0x156/0x180
[ 1.890338] Modules linked in:
[ 1.890338] CPU: 1 PID: 18 Comm: cpuhp/1 Not tainted 5.11.0-rc3-00186-ged03082352b2 #2
This warning is better than the one in process_one_work() which is too
late, though, it has something to say.
[ 1.890338] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 1.890338] EIP: kthread_set_per_cpu+0x156/0x180
[ 1.890338] Code: 00 00 00 00 ff 05 68 4e 04 43 83 c4 08 5b 5e 5f c3
8d 76 00 ff 05 34 50 04 43 0f 0b e9 f9 fe ff ff 8d 76 00 ff 05 2c 4e 04
43 <0f> 0b eb 9d 8d b6 00 00 00 00 ff 05 40 4e 04 43 0f 0b e9 45 ff ff
[ 1.890338] EAX: 42f52ce0 EBX: 00000001 ECX: 00000000 EDX: 00000001
[ 1.890338] ESI: 43d76300 EDI: 43c0de00 EBP: de7f2564 ESP: 43d6beb8
[ 1.900350] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010202
[ 1.901303] CR0: 80050033 CR2: 00000000 CR3: 034e3000 CR4: 000406d0
[ 1.902280] Call Trace:
[ 1.902682] ? workqueue_online_cpu+0x12b/0x640
[ 1.903415] ? workqueue_prepare_cpu+0xa0/0xa0
By the prepare function we know it is a warning at boot time.
[ 1.904155] ? cpuhp_invoke_callback+0x1ed/0x1340
[ 1.904941] ? cpuhp_thread_fun+0x28f/0x460
[ 1.905630] ? cpuhp_thread_fun+0x49/0x460
[ 1.906298] ? smpboot_thread_fn+0x446/0x620
[ 1.910275] ? kthread+0x1ba/0x1e0
[ 1.910857] ? __smpboot_create_thread+0x260/0x260
[ 1.911659] ? kzalloc+0x20/0x20
[ 1.912368] ? ret_from_fork+0x1c/0x28
[ 1.913016] ---[ end trace 6f6c005278241eba ]---
[ 1.913971] kvm-guest: stealtime: cpu 1, msr 9e7e6ec0
[ 1.920012] smp: Brought up 1 node, 2 CPUs
[ 1.920299] smpboot: Max logical packages: 2
[ 1.921019] smpboot: Total of 2 processors activated (10774.03 BogoMIPS)
After staring at it again, the change added in rebind_workers() is
incorrect for a CPU getting back online after bootup, because the
CPU affinity has been broken at offline time.
But the warning in the latest report occurs at boot time, after going
through steps like,
kthread_create_on_node();
kthread_bind_mask(worker->task, pool->attrs->cpumask);
/* successful, attach the worker to the pool */
worker_attach_to_pool(worker, pool, 0);
/* start the newly created worker */
wake_up_process(worker->task);
without triggering the warning at kernel/kthread.c:507.
Before finding an answer (wake_up_new_task()) to the question,
who changed the allowed ptr? revert the change at online time,
and as a compensation, clear POOL_DISASSOCIATED as early as we can.
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1844,25 +1844,23 @@ static struct worker *alloc_worker(int n
* cpu-[un]hotplugs.
*/
static void worker_attach_to_pool(struct worker *worker,
- struct worker_pool *pool)
+ struct worker_pool *pool, int set)
{
mutex_lock(&wq_pool_attach_mutex);
/*
- * set_cpus_allowed_ptr() will fail if the cpumask doesn't have any
- * online CPUs. It'll be re-applied when any of the CPUs come up.
- */
- set_cpus_allowed_ptr(worker->task, pool->attrs->cpumask);
-
- /*
* The wq_pool_attach_mutex ensures %POOL_DISASSOCIATED remains
* stable across this function. See the comments above the flag
* definition for details.
*/
if (pool->flags & POOL_DISASSOCIATED)
worker->flags |= WORKER_UNBOUND;
- else
+ else {
kthread_set_per_cpu(worker->task, true);
+ if (set)
+ WARN_ON_ONCE(set_cpus_allowed_ptr(worker->task,
+ pool->attrs->cpumask) < 0);
+ }
list_add_tail(&worker->node, &pool->workers);
worker->pool = pool;
@@ -1943,7 +1941,7 @@ static struct worker *create_worker(stru
kthread_bind_mask(worker->task, pool->attrs->cpumask);
/* successful, attach the worker to the pool */
- worker_attach_to_pool(worker, pool);
+ worker_attach_to_pool(worker, pool, 0);
/* start the newly created worker */
raw_spin_lock_irq(&pool->lock);
@@ -2508,7 +2506,7 @@ repeat:
raw_spin_unlock_irq(&wq_mayday_lock);
- worker_attach_to_pool(rescuer, pool);
+ worker_attach_to_pool(rescuer, pool, 1);
raw_spin_lock_irq(&pool->lock);
@@ -4923,7 +4921,6 @@ static void unbind_workers(int cpu)
for_each_pool_worker(worker, pool) {
kthread_set_per_cpu(worker->task, false);
- WARN_ON_ONCE(set_cpus_allowed_ptr(worker->task, cpu_possible_mask) < 0);
}
mutex_unlock(&wq_pool_attach_mutex);
@@ -5954,6 +5951,7 @@ void __init workqueue_init_early(void)
i = 0;
for_each_cpu_worker_pool(pool, cpu) {
BUG_ON(init_worker_pool(pool));
+ pool->flags &= ~POOL_DISASSOCIATED;
pool->cpu = cpu;
cpumask_copy(pool->attrs->cpumask, cpumask_of(cpu));
pool->attrs->nice = std_nice[i++];
--
Attachment:
dmesg.xz
Description: Binary data