Under rare circumstances, task_function_call() can repeatedly fail and
cause a soft lockup.
There is a slight race where the process is no longer running on the cpu
we targeted by the time remote_function() runs. The code will simply
try again. If we are very unlucky, this will continue to fail, until a
watchdog fires. This can happen in a heavily loaded, multi-core virtual
machine.
Reported-by: [email protected]
Signed-off-by: Barret Rhoden <[email protected]>
---
kernel/events/core.c | 12 ++++++++----
1 file changed, 8 insertions(+), 4 deletions(-)
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 55e44417f66d..65c2c05e24c2 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -99,7 +99,7 @@ static void remote_function(void *data)
*
* returns: @func return value, or
* -ESRCH - when the process isn't running
- * -EAGAIN - when the process moved away
+ * -ENXIO - when the cpu the process was on has gone offline
*/
static int
task_function_call(struct task_struct *p, remote_function_f func, void *info)
@@ -112,11 +112,15 @@ task_function_call(struct task_struct *p, remote_function_f func, void *info)
};
int ret;
- do {
- ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
+ while (1) {
+ ret = smp_call_function_single(task_cpu(p), remote_function,
+ &data, 1);
if (!ret)
ret = data.ret;
- } while (ret == -EAGAIN);
+ if (ret != -EAGAIN)
+ break;
+ cond_resched();
+ }
return ret;
}
--
2.26.0.110.g2183baf09c-goog
On 4/14/20 4:42 PM, Peter Zijlstra wrote:
> On Tue, Apr 14, 2020 at 03:03:51PM -0400, Barret Rhoden wrote:
>> Under rare circumstances, task_function_call() can repeatedly fail and
>> cause a soft lockup.
>>
>> There is a slight race where the process is no longer running on the cpu
>> we targeted by the time remote_function() runs. The code will simply
>> try again. If we are very unlucky, this will continue to fail, until a
>> watchdog fires. This can happen in a heavily loaded, multi-core virtual
>> machine.
>
> Sigh,.. virt again :/
>
>> Reported-by: [email protected]
>> Signed-off-by: Barret Rhoden <[email protected]>
>> ---
>> kernel/events/core.c | 12 ++++++++----
>> 1 file changed, 8 insertions(+), 4 deletions(-)
>>
>> diff --git a/kernel/events/core.c b/kernel/events/core.c
>> index 55e44417f66d..65c2c05e24c2 100644
>> --- a/kernel/events/core.c
>> +++ b/kernel/events/core.c
>> @@ -99,7 +99,7 @@ static void remote_function(void *data)
>> *
>> * returns: @func return value, or
>> * -ESRCH - when the process isn't running
>> - * -EAGAIN - when the process moved away
>> + * -ENXIO - when the cpu the process was on has gone offline
>> */
>
> Hurm.. I don't think that was actually intended behaviour.
Yeah, I noticed we never return EAGAIN, so I figured I'd look for any
other potential return values.
> As long as
> the task lives we ought to retry. Luckily I don't think the current code
> cares much, it'll loop again on the caller side.
>
> With the exception of perf_cgroup_attach() that is, that might actually
> be broken because of this.
>
>> static int
>> task_function_call(struct task_struct *p, remote_function_f func, void *info)
>> @@ -112,11 +112,15 @@ task_function_call(struct task_struct *p, remote_function_f func, void *info)
>> };
>> int ret;
>>
>> - do {
>> - ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
>> + while (1) {
>> + ret = smp_call_function_single(task_cpu(p), remote_function,
>> + &data, 1);
>> if (!ret)
>> ret = data.ret;
>> - } while (ret == -EAGAIN);
>> + if (ret != -EAGAIN)
>> + break;
>> + cond_resched();
>> + }
>
> So how about we make that:
>
> for (;;) {
> ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
> ret = !ret ? data.ret : -EAGAIN;
>
> if (ret != -EAGAIN)
> break;
>
> cond_resched();
> }
>
> Or something like that, hmmm?
Can do. I can put a comment in too. /* Retry due to any failure in
smp_call_function */ or something.
Thanks,
Barret
On Tue, Apr 14, 2020 at 03:03:51PM -0400, Barret Rhoden wrote:
> Under rare circumstances, task_function_call() can repeatedly fail and
> cause a soft lockup.
>
> There is a slight race where the process is no longer running on the cpu
> we targeted by the time remote_function() runs. The code will simply
> try again. If we are very unlucky, this will continue to fail, until a
> watchdog fires. This can happen in a heavily loaded, multi-core virtual
> machine.
Sigh,.. virt again :/
> Reported-by: [email protected]
> Signed-off-by: Barret Rhoden <[email protected]>
> ---
> kernel/events/core.c | 12 ++++++++----
> 1 file changed, 8 insertions(+), 4 deletions(-)
>
> diff --git a/kernel/events/core.c b/kernel/events/core.c
> index 55e44417f66d..65c2c05e24c2 100644
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -99,7 +99,7 @@ static void remote_function(void *data)
> *
> * returns: @func return value, or
> * -ESRCH - when the process isn't running
> - * -EAGAIN - when the process moved away
> + * -ENXIO - when the cpu the process was on has gone offline
> */
Hurm.. I don't think that was actually intended behaviour. As long as
the task lives we ought to retry. Luckily I don't think the current code
cares much, it'll loop again on the caller side.
With the exception of perf_cgroup_attach() that is, that might actually
be broken because of this.
> static int
> task_function_call(struct task_struct *p, remote_function_f func, void *info)
> @@ -112,11 +112,15 @@ task_function_call(struct task_struct *p, remote_function_f func, void *info)
> };
> int ret;
>
> - do {
> - ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
> + while (1) {
> + ret = smp_call_function_single(task_cpu(p), remote_function,
> + &data, 1);
> if (!ret)
> ret = data.ret;
> - } while (ret == -EAGAIN);
> + if (ret != -EAGAIN)
> + break;
> + cond_resched();
> + }
So how about we make that:
for (;;) {
ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
ret = !ret ? data.ret : -EAGAIN;
if (ret != -EAGAIN)
break;
cond_resched();
}
Or something like that, hmmm?
Under rare circumstances, task_function_call() can repeatedly fail and
cause a soft lockup.
There is a slight race where the process is no longer running on the cpu
we targeted by the time remote_function() runs. The code will simply
try again. If we are very unlucky, this will continue to fail, until a
watchdog fires. This can happen in a heavily loaded, multi-core virtual
machine.
Reported-by: [email protected]
Signed-off-by: Barret Rhoden <[email protected]>
---
kernel/events/core.c | 23 ++++++++++++++---------
1 file changed, 14 insertions(+), 9 deletions(-)
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 55e44417f66d..bcafd7b992b3 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -95,11 +95,11 @@ static void remote_function(void *data)
* @info: the function call argument
*
* Calls the function @func when the task is currently running. This might
- * be on the current CPU, which just calls the function directly
+ * be on the current CPU, which just calls the function directly. This will
+ * retry due to any failures in smp_call_function_single(), such as if the
+ * task_cpu() goes offline concurrently.
*
- * returns: @func return value, or
- * -ESRCH - when the process isn't running
- * -EAGAIN - when the process moved away
+ * returns @func return value or -ESRCH when the process isn't running
*/
static int
task_function_call(struct task_struct *p, remote_function_f func, void *info)
@@ -112,11 +112,16 @@ task_function_call(struct task_struct *p, remote_function_f func, void *info)
};
int ret;
- do {
- ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
- if (!ret)
- ret = data.ret;
- } while (ret == -EAGAIN);
+ for (;;) {
+ ret = smp_call_function_single(task_cpu(p), remote_function,
+ &data, 1);
+ ret = !ret ? data.ret : -EAGAIN;
+
+ if (ret != -EAGAIN)
+ break;
+
+ cond_resched();
+ }
return ret;
}
--
2.26.0.110.g2183baf09c-goog
The following commit has been merged into the perf/core branch of tip:
Commit-ID: 2ed6edd33a214bca02bd2b45e3fc3038a059436b
Gitweb: https://git.kernel.org/tip/2ed6edd33a214bca02bd2b45e3fc3038a059436b
Author: Barret Rhoden <[email protected]>
AuthorDate: Tue, 14 Apr 2020 18:29:20 -04:00
Committer: Peter Zijlstra <[email protected]>
CommitterDate: Thu, 30 Apr 2020 20:14:36 +02:00
perf: Add cond_resched() to task_function_call()
Under rare circumstances, task_function_call() can repeatedly fail and
cause a soft lockup.
There is a slight race where the process is no longer running on the cpu
we targeted by the time remote_function() runs. The code will simply
try again. If we are very unlucky, this will continue to fail, until a
watchdog fires. This can happen in a heavily loaded, multi-core virtual
machine.
Reported-by: [email protected]
Signed-off-by: Barret Rhoden <[email protected]>
Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
Link: https://lkml.kernel.org/r/[email protected]
---
kernel/events/core.c | 23 ++++++++++++++---------
1 file changed, 14 insertions(+), 9 deletions(-)
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 52951e9..80cf996 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -95,11 +95,11 @@ static void remote_function(void *data)
* @info: the function call argument
*
* Calls the function @func when the task is currently running. This might
- * be on the current CPU, which just calls the function directly
+ * be on the current CPU, which just calls the function directly. This will
+ * retry due to any failures in smp_call_function_single(), such as if the
+ * task_cpu() goes offline concurrently.
*
- * returns: @func return value, or
- * -ESRCH - when the process isn't running
- * -EAGAIN - when the process moved away
+ * returns @func return value or -ESRCH when the process isn't running
*/
static int
task_function_call(struct task_struct *p, remote_function_f func, void *info)
@@ -112,11 +112,16 @@ task_function_call(struct task_struct *p, remote_function_f func, void *info)
};
int ret;
- do {
- ret = smp_call_function_single(task_cpu(p), remote_function, &data, 1);
- if (!ret)
- ret = data.ret;
- } while (ret == -EAGAIN);
+ for (;;) {
+ ret = smp_call_function_single(task_cpu(p), remote_function,
+ &data, 1);
+ ret = !ret ? data.ret : -EAGAIN;
+
+ if (ret != -EAGAIN)
+ break;
+
+ cond_resched();
+ }
return ret;
}
On Fri, May 01, 2020 at 06:22:05PM -0000, tip-bot2 for Barret Rhoden wrote:
> The following commit has been merged into the perf/core branch of tip:
>
> Commit-ID: 2ed6edd33a214bca02bd2b45e3fc3038a059436b
> Gitweb: https://git.kernel.org/tip/2ed6edd33a214bca02bd2b45e3fc3038a059436b
> Author: Barret Rhoden <[email protected]>
> AuthorDate: Tue, 14 Apr 2020 18:29:20 -04:00
> Committer: Peter Zijlstra <[email protected]>
> CommitterDate: Thu, 30 Apr 2020 20:14:36 +02:00
>
> perf: Add cond_resched() to task_function_call()
>
> Under rare circumstances, task_function_call() can repeatedly fail and
> cause a soft lockup.
>
> There is a slight race where the process is no longer running on the cpu
> we targeted by the time remote_function() runs. The code will simply
> try again. If we are very unlucky, this will continue to fail, until a
> watchdog fires. This can happen in a heavily loaded, multi-core virtual
> machine.
>
> Reported-by: [email protected]
> Signed-off-by: Barret Rhoden <[email protected]>
> Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
> Link: https://lkml.kernel.org/r/[email protected]
hi,
this gives me warning below and the machine gets stuck,
if I revert it seems to be ok, running this:
# while :; do ./perf stat -e cycles ./perf bench sched messaging; done
jirka
---
[ 1782.995609] WARNING: CPU: 20 PID: 0 at kernel/smp.c:127 flush_smp_call_function_queue+0x86/0xf0
[ 1783.004301] Modules linked in: intel_rapl_msr intel_rapl_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10d
if_pclmul crc32_pclmul ipmi_ssif ghash_clmulni_intel intel_cstate dell_smbios intel_uncore dell_wmi_descriptor iTCO_wdt dcdbas mei_me wmi_bmof iTCO_vendor_supp
ort ipmi_si mei lpc_ich ipmi_devintf i2c_i801 wmi ipmi_msghandler acpi_power_meter xfs libcrc32c mgag200 drm_kms_helper cec drm_vram_helper drm_ttm_helper ttm
drm tg3 megaraid_sas crc32c_intel i2c_algo_bit
[ 1783.049855] CPU: 20 PID: 0 Comm: swapper/20 Tainted: G I 5.7.0-rc6+ #57
[ 1783.057763] Hardware name: Dell Inc. PowerEdge R440/08CYF7, BIOS 1.7.0 12/14/2018
[ 1783.065250] RIP: 0010:flush_smp_call_function_queue+0x86/0xf0
[ 1783.070991] Code: 00 00 48 85 ed 75 d3 48 83 c4 08 5b 5d 41 5c e9 80 06 07 00 a8 01 74 12 c7 43 18 00 00 00 00 e8 d0 24 c8 00 eb af 0f 0b eb d1 <0f> 0b eb e
a 65 8b 05 9f 3b e9 7e 89 c0 48 0f a3 05 c5 a8 7c 01 72
[ 1783.089736] RSP: 0018:ffffc900068b0dd0 EFLAGS: 00010046
[ 1783.094962] RAX: 0000000000000000 RBX: ffff888c10eaab80 RCX: 0000000000000007
[ 1783.102095] RDX: ffffffff81108ab0 RSI: 0000000000000000 RDI: ffff888c10eaab40
[ 1783.109225] RBP: ffff888c10eaab80 R08: 0000019f228b1c77 R09: 0000000000000000
[ 1783.116359] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
[ 1783.123491] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 1783.130624] FS: 0000000000000000(0000) GS:ffff888c10e80000(0000) knlGS:0000000000000000
[ 1783.138711] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1783.144457] CR2: 00007fc8501b29f0 CR3: 0000000be6ac8001 CR4: 00000000007606e0
[ 1783.151589] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1783.158721] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 1783.165854] PKRU: 55555554
[ 1783.168566] Call Trace:
[ 1783.171019] <IRQ>
[ 1783.173041] ? irqtime_account_irq+0x32/0xa0
[ 1783.177317] smp_call_function_single_interrupt+0x3e/0xf0
[ 1783.182712] call_function_single_interrupt+0xf/0x20
[ 1783.187678] RIP: 0010:_nohz_idle_balance+0x57/0x210
[ 1783.192556] Code: 60 ea 00 00 89 f0 83 e0 03 89 74 24 28 89 54 24 2c 83 f8 01 0f 84 9a 01 00 00 c7 05 4b 5f e9 01 00 00 00 00 f0 83 44 24 fc 00 <65> 48 8b 0
4 25 c0 8b 01 00 48 89 04 24 41 bf ff ff ff ff 45 31 ed
[ 1783.211303] RSP: 0018:ffffc900068b0ed0 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff04
[ 1783.218869] RAX: 0000000000000003 RBX: 00000001001780ff RCX: 0000000000000003
[ 1783.226000] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff888c10eaab40
[ 1783.233131] RBP: 0000000000000014 R08: 0000000000000003 R09: 0000000000000100
[ 1783.240258] R10: 0000019ea6c791d9 R11: 0000000000000394 R12: ffffffff82805138
[ 1783.247390] R13: 0000000000000007 R14: 0000000000000007 R15: ffffffff82805110
[ 1783.254523] ? call_function_single_interrupt+0xa/0x20
[ 1783.259667] __do_softirq+0xee/0x313
[ 1783.263243] ? clockevents_program_event+0x8d/0xf0
[ 1783.268036] ? sched_clock+0x5/0x10
[ 1783.271531] irq_exit+0xe6/0xf0
[ 1783.274675] smp_apic_timer_interrupt+0x7a/0x150
[ 1783.279292] apic_timer_interrupt+0xf/0x20
[ 1783.283391] </IRQ>
[ 1783.285500] RIP: 0010:finish_task_switch+0x7b/0x290
[ 1783.290377] Code: 44 00 00 65 48 8b 1c 25 c0 8b 01 00 e9 89 00 00 00 0f 1f 44 00 00 41 c7 45 38 00 00 00 00 41 c6 04 24 00 fb 66 0f 1f 44 00 00 <65> 48 8b 0
4 25 c0 8b 01 00 0f 1f 44 00 00 4d 85 f6 74 21 65 48 8b
[ 1783.309122] RSP: 0018:ffffc9000649be28 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
[ 1783.316687] RAX: 0000000000000000 RBX: ffff888c0c602580 RCX: 0000000000000000
[ 1783.323820] RDX: 0000000000000000 RSI: ffff888c0c602580 RDI: ffff888be6c48000
[ 1783.330953] RBP: ffffc9000649be50 R08: ffff888c10ea7c00 R09: ffff888be8a1e800
[ 1783.338085] R10: 0000000000000000 R11: 000000000000000c R12: ffff888c10eaab40
[ 1783.345219] R13: ffff888be6c48000 R14: 0000000000000000 R15: 0000000000000001
[ 1783.352354] ? finish_task_switch+0xf6/0x290
[ 1783.356624] __schedule+0x2c8/0x750
[ 1783.360118] ? recalibrate_cpu_khz+0x10/0x10
[ 1783.364389] schedule_idle+0x28/0x40
[ 1783.367970] do_idle+0x169/0x260
[ 1783.371201] cpu_startup_entry+0x19/0x20
[ 1783.375128] start_secondary+0x169/0x1c0
[ 1783.379058] secondary_startup_64+0xa4/0xb0
[ 1783.383240] ---[ end trace 5ec3d41605e082c2 ]---
[ 1783.387861] ------------[ cut here ]------------
[ 1783.392481] WARNING: CPU: 20 PID: 0 at kernel/smp.c:127 flush_smp_call_function_queue+0x86/0xf0
[ 1783.401169] Modules linked in: intel_rapl_msr intel_rapl_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ipmi_ssif ghash_clmulni_intel intel_cstate dell_smbios intel_uncore dell_wmi_descriptor iTCO_wdt dcdbas mei_me wmi_bmof iTCO_vendor_support ipmi_si mei lpc_ich ipmi_devintf i2c_i801 wmi ipmi_msghandler acpi_power_meter xfs libcrc32c mgag200 drm_kms_helper cec drm_vram_helper drm_ttm_helper ttm drm tg3 megaraid_sas crc32c_intel i2c_algo_bit
[ 1783.446705] CPU: 20 PID: 0 Comm: swapper/20 Tainted: G W I 5.7.0-rc6+ #57
[ 1783.454618] Hardware name: Dell Inc. PowerEdge R440/08CYF7, BIOS 1.7.0 12/14/2018
[ 1783.462098] RIP: 0010:flush_smp_call_function_queue+0x86/0xf0
[ 1783.467842] Code: 00 00 48 85 ed 75 d3 48 83 c4 08 5b 5d 41 5c e9 80 06 07 00 a8 01 74 12 c7 43 18 00 00 00 00 e8 d0 24 c8 00 eb af 0f 0b eb d1 <0f> 0b eb ea 65 8b 05 9f 3b e9 7e 89 c0 48 0f a3 05 c5 a8 7c 01 72
[ 1783.486587] RSP: 0018:ffffc900068b0dd0 EFLAGS: 00010046
[ 1783.491814] RAX: 0000000000000000 RBX: ffff888c10eaab80 RCX: ffff888c10e80000
[ 1783.498948] RDX: ffffffff81108ab0 RSI: 0000000000000001 RDI: ffff888c10eaab40
[ 1783.506079] RBP: ffff888c10eaab80 R08: 0000019f228b1c77 R09: 0000000000000000
[ 1783.513212] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
[ 1783.520346] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 1783.527477] FS: 0000000000000000(0000) GS:ffff888c10e80000(0000) knlGS:0000000000000000
[ 1783.535564] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1783.541308] CR2: 00007fc8501b29f0 CR3: 0000000be6ac8001 CR4: 00000000007606e0
[ 1783.548435] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1783.555566] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 1783.562699] PKRU: 55555554
[ 1783.565411] Call Trace:
[ 1783.567863] <IRQ>
[ 1783.569883] ? irqtime_account_irq+0x32/0xa0
[ 1783.574157] smp_call_function_single_interrupt+0x3e/0xf0
[ 1783.579556] call_function_single_interrupt+0xf/0x20
[ 1783.584522] RIP: 0010:_nohz_idle_balance+0x57/0x210
[ 1783.589401] Code: 60 ea 00 00 89 f0 83 e0 03 89 74 24 28 89 54 24 2c 83 f8 01 0f 84 9a 01 00 00 c7 05 4b 5f e9 01 00 00 00 00 f0 83 44 24 fc 00 <65> 48 8b 04 25 c0 8b 01 00 48 89 04 24 41 bf ff ff ff ff 45 31 ed
[ 1783.608146] RSP: 0018:ffffc900068b0ed0 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff04
[ 1783.615713] RAX: 0000000000000003 RBX: 00000001001780ff RCX: 0000000000000003
[ 1783.622844] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff888c10eaab40
[ 1783.629978] RBP: 0000000000000014 R08: 0000000000000003 R09: 0000000000000100
[ 1783.637111] R10: 0000019ea6c791d9 R11: 0000000000000394 R12: ffffffff82805138
[ 1783.644243] R13: 0000000000000007 R14: 0000000000000007 R15: ffffffff82805110
[ 1783.651378] ? call_function_single_interrupt+0xa/0x20
[ 1783.656519] __do_softirq+0xee/0x313
[ 1783.660094] ? clockevents_program_event+0x8d/0xf0
[ 1783.664887] ? sched_clock+0x5/0x10
[ 1783.668382] irq_exit+0xe6/0xf0
[ 1783.671528] smp_apic_timer_interrupt+0x7a/0x150
[ 1783.676146] apic_timer_interrupt+0xf/0x20
[ 1783.680243] </IRQ>
[ 1783.682351] RIP: 0010:finish_task_switch+0x7b/0x290
[ 1783.687231] Code: 44 00 00 65 48 8b 1c 25 c0 8b 01 00 e9 89 00 00 00 0f 1f 44 00 00 41 c7 45 38 00 00 00 00 41 c6 04 24 00 fb 66 0f 1f 44 00 00 <65> 48 8b 04 25 c0 8b 01 00 0f 1f 44 00 00 4d 85 f6 74 21 65 48 8b
[ 1783.705974] RSP: 0018:ffffc9000649be28 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
[ 1783.713542] RAX: 0000000000000000 RBX: ffff888c0c602580 RCX: 0000000000000000
[ 1783.720673] RDX: 0000000000000000 RSI: ffff888c0c602580 RDI: ffff888be6c48000
[ 1783.727807] RBP: ffffc9000649be50 R08: ffff888c10ea7c00 R09: ffff888be8a1e800
[ 1783.734938] R10: 0000000000000000 R11: 000000000000000c R12: ffff888c10eaab40
[ 1783.742070] R13: ffff888be6c48000 R14: 0000000000000000 R15: 0000000000000001
[ 1783.749199] ? finish_task_switch+0xf6/0x290
[ 1783.753469] __schedule+0x2c8/0x750
[ 1783.756961] ? recalibrate_cpu_khz+0x10/0x10
[ 1783.761234] schedule_idle+0x28/0x40
[ 1783.764814] do_idle+0x169/0x260
[ 1783.768047] cpu_startup_entry+0x19/0x20
[ 1783.771973] start_secondary+0x169/0x1c0
[ 1783.775897] secondary_startup_64+0xa4/0xb0
[ 1783.780085] ---[ end trace 5ec3d41605e082c3 ]---
[ 1783.784704] ------------[ cut here ]------------
[ 1783.789323] WARNING: CPU: 20 PID: 0 at kernel/smp.c:127 flush_smp_call_function_queue+0x86/0xf0
[ 1783.798015] Modules linked in: intel_rapl_msr intel_rapl_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ipmi_ssif ghash_clmulni_intel intel_cstate dell_smbios intel_uncore dell_wmi_descriptor iTCO_wdt dcdbas mei_me wmi_bmof iTCO_vendor_support ipmi_si mei lpc_ich ipmi_devintf i2c_i801 wmi ipmi_msghandler acpi_power_meter xfs libcrc32c mgag200 drm_kms_helper cec drm_vram_helper drm_ttm_helper ttm drm tg3 megaraid_sas crc32c_intel i2c_algo_bit
[ 1783.843543] CPU: 20 PID: 0 Comm: swapper/20 Tainted: G W I 5.7.0-rc6+ #57
[ 1783.851452] Hardware name: Dell Inc. PowerEdge R440/08CYF7, BIOS 1.7.0 12/14/2018
[ 1783.858933] RIP: 0010:flush_smp_call_function_queue+0x86/0xf0
[ 1783.864680] Code: 00 00 48 85 ed 75 d3 48 83 c4 08 5b 5d 41 5c e9 80 06 07 00 a8 01 74 12 c7 43 18 00 00 00 00 e8 d0 24 c8 00 eb af 0f 0b eb d1 <0f> 0b eb ea 65 8b 05 9f 3b e9 7e 89 c0 48 0f a3 05 c5 a8 7c 01 72
[ 1783.883425] RSP: 0018:ffffc900068b0dd0 EFLAGS: 00010046
...
On Sat, May 23, 2020 at 11:20:13AM +0200, Jiri Olsa wrote:
> On Fri, May 01, 2020 at 06:22:05PM -0000, tip-bot2 for Barret Rhoden wrote:
> > The following commit has been merged into the perf/core branch of tip:
> >
> > Commit-ID: 2ed6edd33a214bca02bd2b45e3fc3038a059436b
> > Gitweb: https://git.kernel.org/tip/2ed6edd33a214bca02bd2b45e3fc3038a059436b
> > Author: Barret Rhoden <[email protected]>
> > AuthorDate: Tue, 14 Apr 2020 18:29:20 -04:00
> > Committer: Peter Zijlstra <[email protected]>
> > CommitterDate: Thu, 30 Apr 2020 20:14:36 +02:00
> >
> > perf: Add cond_resched() to task_function_call()
> >
> > Under rare circumstances, task_function_call() can repeatedly fail and
> > cause a soft lockup.
> >
> > There is a slight race where the process is no longer running on the cpu
> > we targeted by the time remote_function() runs. The code will simply
> > try again. If we are very unlucky, this will continue to fail, until a
> > watchdog fires. This can happen in a heavily loaded, multi-core virtual
> > machine.
> >
> > Reported-by: [email protected]
> > Signed-off-by: Barret Rhoden <[email protected]>
> > Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
> > Link: https://lkml.kernel.org/r/[email protected]
>
> hi,
> this gives me warning below and the machine gets stuck,
> if I revert it seems to be ok, running this:
>
> # while :; do ./perf stat -e cycles ./perf bench sched messaging; done
ugh, I take it back.. it got stuck as well after longer time
jirka
>
> jirka
>
>
> ---
> [ 1782.995609] WARNING: CPU: 20 PID: 0 at kernel/smp.c:127 flush_smp_call_function_queue+0x86/0xf0
> [ 1783.004301] Modules linked in: intel_rapl_msr intel_rapl_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10d
> if_pclmul crc32_pclmul ipmi_ssif ghash_clmulni_intel intel_cstate dell_smbios intel_uncore dell_wmi_descriptor iTCO_wdt dcdbas mei_me wmi_bmof iTCO_vendor_supp
> ort ipmi_si mei lpc_ich ipmi_devintf i2c_i801 wmi ipmi_msghandler acpi_power_meter xfs libcrc32c mgag200 drm_kms_helper cec drm_vram_helper drm_ttm_helper ttm
> drm tg3 megaraid_sas crc32c_intel i2c_algo_bit
> [ 1783.049855] CPU: 20 PID: 0 Comm: swapper/20 Tainted: G I 5.7.0-rc6+ #57
> [ 1783.057763] Hardware name: Dell Inc. PowerEdge R440/08CYF7, BIOS 1.7.0 12/14/2018
> [ 1783.065250] RIP: 0010:flush_smp_call_function_queue+0x86/0xf0
> [ 1783.070991] Code: 00 00 48 85 ed 75 d3 48 83 c4 08 5b 5d 41 5c e9 80 06 07 00 a8 01 74 12 c7 43 18 00 00 00 00 e8 d0 24 c8 00 eb af 0f 0b eb d1 <0f> 0b eb e
> a 65 8b 05 9f 3b e9 7e 89 c0 48 0f a3 05 c5 a8 7c 01 72
> [ 1783.089736] RSP: 0018:ffffc900068b0dd0 EFLAGS: 00010046
> [ 1783.094962] RAX: 0000000000000000 RBX: ffff888c10eaab80 RCX: 0000000000000007
> [ 1783.102095] RDX: ffffffff81108ab0 RSI: 0000000000000000 RDI: ffff888c10eaab40
> [ 1783.109225] RBP: ffff888c10eaab80 R08: 0000019f228b1c77 R09: 0000000000000000
> [ 1783.116359] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
> [ 1783.123491] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
> [ 1783.130624] FS: 0000000000000000(0000) GS:ffff888c10e80000(0000) knlGS:0000000000000000
> [ 1783.138711] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1783.144457] CR2: 00007fc8501b29f0 CR3: 0000000be6ac8001 CR4: 00000000007606e0
> [ 1783.151589] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 1783.158721] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 1783.165854] PKRU: 55555554
> [ 1783.168566] Call Trace:
> [ 1783.171019] <IRQ>
> [ 1783.173041] ? irqtime_account_irq+0x32/0xa0
> [ 1783.177317] smp_call_function_single_interrupt+0x3e/0xf0
> [ 1783.182712] call_function_single_interrupt+0xf/0x20
> [ 1783.187678] RIP: 0010:_nohz_idle_balance+0x57/0x210
> [ 1783.192556] Code: 60 ea 00 00 89 f0 83 e0 03 89 74 24 28 89 54 24 2c 83 f8 01 0f 84 9a 01 00 00 c7 05 4b 5f e9 01 00 00 00 00 f0 83 44 24 fc 00 <65> 48 8b 0
> 4 25 c0 8b 01 00 48 89 04 24 41 bf ff ff ff ff 45 31 ed
> [ 1783.211303] RSP: 0018:ffffc900068b0ed0 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff04
> [ 1783.218869] RAX: 0000000000000003 RBX: 00000001001780ff RCX: 0000000000000003
> [ 1783.226000] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff888c10eaab40
> [ 1783.233131] RBP: 0000000000000014 R08: 0000000000000003 R09: 0000000000000100
> [ 1783.240258] R10: 0000019ea6c791d9 R11: 0000000000000394 R12: ffffffff82805138
> [ 1783.247390] R13: 0000000000000007 R14: 0000000000000007 R15: ffffffff82805110
> [ 1783.254523] ? call_function_single_interrupt+0xa/0x20
> [ 1783.259667] __do_softirq+0xee/0x313
> [ 1783.263243] ? clockevents_program_event+0x8d/0xf0
> [ 1783.268036] ? sched_clock+0x5/0x10
> [ 1783.271531] irq_exit+0xe6/0xf0
> [ 1783.274675] smp_apic_timer_interrupt+0x7a/0x150
> [ 1783.279292] apic_timer_interrupt+0xf/0x20
> [ 1783.283391] </IRQ>
> [ 1783.285500] RIP: 0010:finish_task_switch+0x7b/0x290
> [ 1783.290377] Code: 44 00 00 65 48 8b 1c 25 c0 8b 01 00 e9 89 00 00 00 0f 1f 44 00 00 41 c7 45 38 00 00 00 00 41 c6 04 24 00 fb 66 0f 1f 44 00 00 <65> 48 8b 0
> 4 25 c0 8b 01 00 0f 1f 44 00 00 4d 85 f6 74 21 65 48 8b
> [ 1783.309122] RSP: 0018:ffffc9000649be28 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
> [ 1783.316687] RAX: 0000000000000000 RBX: ffff888c0c602580 RCX: 0000000000000000
> [ 1783.323820] RDX: 0000000000000000 RSI: ffff888c0c602580 RDI: ffff888be6c48000
> [ 1783.330953] RBP: ffffc9000649be50 R08: ffff888c10ea7c00 R09: ffff888be8a1e800
> [ 1783.338085] R10: 0000000000000000 R11: 000000000000000c R12: ffff888c10eaab40
> [ 1783.345219] R13: ffff888be6c48000 R14: 0000000000000000 R15: 0000000000000001
> [ 1783.352354] ? finish_task_switch+0xf6/0x290
> [ 1783.356624] __schedule+0x2c8/0x750
> [ 1783.360118] ? recalibrate_cpu_khz+0x10/0x10
> [ 1783.364389] schedule_idle+0x28/0x40
> [ 1783.367970] do_idle+0x169/0x260
> [ 1783.371201] cpu_startup_entry+0x19/0x20
> [ 1783.375128] start_secondary+0x169/0x1c0
> [ 1783.379058] secondary_startup_64+0xa4/0xb0
> [ 1783.383240] ---[ end trace 5ec3d41605e082c2 ]---
> [ 1783.387861] ------------[ cut here ]------------
> [ 1783.392481] WARNING: CPU: 20 PID: 0 at kernel/smp.c:127 flush_smp_call_function_queue+0x86/0xf0
> [ 1783.401169] Modules linked in: intel_rapl_msr intel_rapl_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ipmi_ssif ghash_clmulni_intel intel_cstate dell_smbios intel_uncore dell_wmi_descriptor iTCO_wdt dcdbas mei_me wmi_bmof iTCO_vendor_support ipmi_si mei lpc_ich ipmi_devintf i2c_i801 wmi ipmi_msghandler acpi_power_meter xfs libcrc32c mgag200 drm_kms_helper cec drm_vram_helper drm_ttm_helper ttm drm tg3 megaraid_sas crc32c_intel i2c_algo_bit
> [ 1783.446705] CPU: 20 PID: 0 Comm: swapper/20 Tainted: G W I 5.7.0-rc6+ #57
> [ 1783.454618] Hardware name: Dell Inc. PowerEdge R440/08CYF7, BIOS 1.7.0 12/14/2018
> [ 1783.462098] RIP: 0010:flush_smp_call_function_queue+0x86/0xf0
> [ 1783.467842] Code: 00 00 48 85 ed 75 d3 48 83 c4 08 5b 5d 41 5c e9 80 06 07 00 a8 01 74 12 c7 43 18 00 00 00 00 e8 d0 24 c8 00 eb af 0f 0b eb d1 <0f> 0b eb ea 65 8b 05 9f 3b e9 7e 89 c0 48 0f a3 05 c5 a8 7c 01 72
> [ 1783.486587] RSP: 0018:ffffc900068b0dd0 EFLAGS: 00010046
> [ 1783.491814] RAX: 0000000000000000 RBX: ffff888c10eaab80 RCX: ffff888c10e80000
> [ 1783.498948] RDX: ffffffff81108ab0 RSI: 0000000000000001 RDI: ffff888c10eaab40
> [ 1783.506079] RBP: ffff888c10eaab80 R08: 0000019f228b1c77 R09: 0000000000000000
> [ 1783.513212] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
> [ 1783.520346] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
> [ 1783.527477] FS: 0000000000000000(0000) GS:ffff888c10e80000(0000) knlGS:0000000000000000
> [ 1783.535564] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1783.541308] CR2: 00007fc8501b29f0 CR3: 0000000be6ac8001 CR4: 00000000007606e0
> [ 1783.548435] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 1783.555566] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 1783.562699] PKRU: 55555554
> [ 1783.565411] Call Trace:
> [ 1783.567863] <IRQ>
> [ 1783.569883] ? irqtime_account_irq+0x32/0xa0
> [ 1783.574157] smp_call_function_single_interrupt+0x3e/0xf0
> [ 1783.579556] call_function_single_interrupt+0xf/0x20
> [ 1783.584522] RIP: 0010:_nohz_idle_balance+0x57/0x210
> [ 1783.589401] Code: 60 ea 00 00 89 f0 83 e0 03 89 74 24 28 89 54 24 2c 83 f8 01 0f 84 9a 01 00 00 c7 05 4b 5f e9 01 00 00 00 00 f0 83 44 24 fc 00 <65> 48 8b 04 25 c0 8b 01 00 48 89 04 24 41 bf ff ff ff ff 45 31 ed
> [ 1783.608146] RSP: 0018:ffffc900068b0ed0 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff04
> [ 1783.615713] RAX: 0000000000000003 RBX: 00000001001780ff RCX: 0000000000000003
> [ 1783.622844] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff888c10eaab40
> [ 1783.629978] RBP: 0000000000000014 R08: 0000000000000003 R09: 0000000000000100
> [ 1783.637111] R10: 0000019ea6c791d9 R11: 0000000000000394 R12: ffffffff82805138
> [ 1783.644243] R13: 0000000000000007 R14: 0000000000000007 R15: ffffffff82805110
> [ 1783.651378] ? call_function_single_interrupt+0xa/0x20
> [ 1783.656519] __do_softirq+0xee/0x313
> [ 1783.660094] ? clockevents_program_event+0x8d/0xf0
> [ 1783.664887] ? sched_clock+0x5/0x10
> [ 1783.668382] irq_exit+0xe6/0xf0
> [ 1783.671528] smp_apic_timer_interrupt+0x7a/0x150
> [ 1783.676146] apic_timer_interrupt+0xf/0x20
> [ 1783.680243] </IRQ>
> [ 1783.682351] RIP: 0010:finish_task_switch+0x7b/0x290
> [ 1783.687231] Code: 44 00 00 65 48 8b 1c 25 c0 8b 01 00 e9 89 00 00 00 0f 1f 44 00 00 41 c7 45 38 00 00 00 00 41 c6 04 24 00 fb 66 0f 1f 44 00 00 <65> 48 8b 04 25 c0 8b 01 00 0f 1f 44 00 00 4d 85 f6 74 21 65 48 8b
> [ 1783.705974] RSP: 0018:ffffc9000649be28 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
> [ 1783.713542] RAX: 0000000000000000 RBX: ffff888c0c602580 RCX: 0000000000000000
> [ 1783.720673] RDX: 0000000000000000 RSI: ffff888c0c602580 RDI: ffff888be6c48000
> [ 1783.727807] RBP: ffffc9000649be50 R08: ffff888c10ea7c00 R09: ffff888be8a1e800
> [ 1783.734938] R10: 0000000000000000 R11: 000000000000000c R12: ffff888c10eaab40
> [ 1783.742070] R13: ffff888be6c48000 R14: 0000000000000000 R15: 0000000000000001
> [ 1783.749199] ? finish_task_switch+0xf6/0x290
> [ 1783.753469] __schedule+0x2c8/0x750
> [ 1783.756961] ? recalibrate_cpu_khz+0x10/0x10
> [ 1783.761234] schedule_idle+0x28/0x40
> [ 1783.764814] do_idle+0x169/0x260
> [ 1783.768047] cpu_startup_entry+0x19/0x20
> [ 1783.771973] start_secondary+0x169/0x1c0
> [ 1783.775897] secondary_startup_64+0xa4/0xb0
> [ 1783.780085] ---[ end trace 5ec3d41605e082c3 ]---
> [ 1783.784704] ------------[ cut here ]------------
> [ 1783.789323] WARNING: CPU: 20 PID: 0 at kernel/smp.c:127 flush_smp_call_function_queue+0x86/0xf0
> [ 1783.798015] Modules linked in: intel_rapl_msr intel_rapl_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ipmi_ssif ghash_clmulni_intel intel_cstate dell_smbios intel_uncore dell_wmi_descriptor iTCO_wdt dcdbas mei_me wmi_bmof iTCO_vendor_support ipmi_si mei lpc_ich ipmi_devintf i2c_i801 wmi ipmi_msghandler acpi_power_meter xfs libcrc32c mgag200 drm_kms_helper cec drm_vram_helper drm_ttm_helper ttm drm tg3 megaraid_sas crc32c_intel i2c_algo_bit
> [ 1783.843543] CPU: 20 PID: 0 Comm: swapper/20 Tainted: G W I 5.7.0-rc6+ #57
> [ 1783.851452] Hardware name: Dell Inc. PowerEdge R440/08CYF7, BIOS 1.7.0 12/14/2018
> [ 1783.858933] RIP: 0010:flush_smp_call_function_queue+0x86/0xf0
> [ 1783.864680] Code: 00 00 48 85 ed 75 d3 48 83 c4 08 5b 5d 41 5c e9 80 06 07 00 a8 01 74 12 c7 43 18 00 00 00 00 e8 d0 24 c8 00 eb af 0f 0b eb d1 <0f> 0b eb ea 65 8b 05 9f 3b e9 7e 89 c0 48 0f a3 05 c5 a8 7c 01 72
> [ 1783.883425] RSP: 0018:ffffc900068b0dd0 EFLAGS: 00010046
> ...