| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <52212511.9050206@keymile.com>
Date: Sat, 31 Aug 2013 01:04:49 +0200
From: Gerlando Falauto <gerlando.falauto@...mile.com>
To: John Stultz <john.stultz@...aro.org>
CC: "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
Thomas Gleixner <tglx@...utronix.de>,
Richard Cochran <richardcochran@...il.com>,
Prarit Bhargava <prarit@...hat.com>,
"Brunck, Holger" <Holger.Brunck@...mile.com>,
"Longchamp, Valentin" <Valentin.Longchamp@...mile.com>,
"Bigler, Stefan" <Stefan.Bigler@...mile.com>
Subject: Re: kernel deadlock
Hi,
sorry, it took me a while to narrow it down...
On 08/30/2013 01:45 AM, John Stultz wrote:
> On 08/29/2013 01:56 PM, Falauto, Gerlando wrote:
>> Hi everyone,
>>
>> I ran into the deadlock situation reported at the bottom.
>> Actually, on my latest 3.10 kernel for some reason I don't get the
>> report (the kernel just hangs for some reason), so it took me quite some
>> time to track it down.
>>
>> Once I figured the trigger to the machine hanging was adjtimex(), I
>> reverted everything (between 3.9 to 3.10) that was touching
>> kernel/time/timekeeping/timekeeping.c and kernel/time/ntp.c, I double
>> checked that indeed the problem was not happening anymore, and finally
>> started bisecting, landing on the following offending commit.
>> THEN, and ONLY THEN, did I get the &%""รง+"% deadlock report.
>>
>> Do you guys have any ideas what could be wrong and how to fix it?
>
> Thanks for the report!
>
> What exactly is your process for reproducing the issue?
Now (well, now...), it's quite easy.
Three ingredients:
1) Kernel 3.10
2) Enable HRTICK
diff --git a/kernel/sched/features.h b/kernel/sched/features.h
index 99399f8..294e3ca 100644
--- a/kernel/sched/features.h
+++ b/kernel/sched/features.h
@@ -41,7 +41,7 @@ SCHED_FEAT(WAKEUP_PREEMPTION, true)
*/
SCHED_FEAT(ARCH_POWER, true)
-SCHED_FEAT(HRTICK, false)
+SCHED_FEAT(HRTICK, true)
SCHED_FEAT(DOUBLE_TICK, false)
SCHED_FEAT(LB_BIAS, true)
3) Run the following:
#include <stdio.h>
#include <sys/timex.h>
int main(void)
{
int i;
for (i = 0 ; ; i++) {
struct timex adj = {};
printf("%d\r", i);
fflush(stdout);
adjtimex(&adj);
}
return 0;
}
Notice how:
1) The original issue (with a bit more complicated scenario) was seen on
ARM and PowerPC platforms
2) Under the above test conditions (on ARM) I *don't* get any deadlock
report printed, the machine just hangs
3) The offending commit (below) I had found through a weird (manual)
process of reverting and re-reverting (where some commits could have
been reverted out of order), so I'm not 100% sure you'd come to the same
conclusions.
commit 06c017fdd4dc48451a29ac37fc1db4a3f86b7f40
Author: John Stultz <john.stultz@...aro.org>
Date: Fri Mar 22 11:37:28 2013 -0700
timekeeping: Hold timekeepering locks in do_adjtimex and hardpps
I'm not able to perform any further testing at this very moment, but if
needed, I can try bisecting again sometime next week, so to make an even
more reliable statement.
Thank you!
Gerlando
>
>
>> [ INFO: inconsistent lock state ]
>> 3.10.0-04864-g346ecc9-dirty #16 Not tainted
>> ---------------------------------
>> inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
>> SAKEY/738 [HC0[0]:SC0[0]:HE1:SE1] takes:
>> (timekeeper_lock){?.-...}, at: [<c004a3e4>] do_adjtimex+0x64/0xbc
>> {IN-HARDIRQ-W} state was registered at:
>> [<c0055138>] __lock_acquire+0xabc/0x1bb8
>> [<c0056838>] lock_acquire+0xa8/0x15c
>> [<c04c14ec>] _raw_spin_lock_irqsave+0x50/0x64
>> [<c00497a4>] do_timer+0x2c/0xa54
>> [<c004e7f4>] tick_periodic+0x74/0x9c
>> [<c004e834>] tick_handle_periodic+0x18/0x7c
>> [<c001349c>] orion_timer_interrupt+0x24/0x34
>> [<c0069c2c>] handle_irq_event_percpu+0x5c/0x300
>> [<c0069f0c>] handle_irq_event+0x3c/0x5c
>> [<c006c194>] handle_level_irq+0x8c/0xe8
>> [<c0069574>] generic_handle_irq+0x30/0x4c
>> [<c000951c>] handle_IRQ+0x30/0x84
>> [<c04c2178>] __irq_svc+0x38/0xa0
>> [<c06cf15c>] calibrate_delay+0x350/0x4e4
>> [<c06986e0>] start_kernel+0x23c/0x2c4
>> [<0000803c>] 0x803c
>> irq event stamp: 32358
>> hardirqs last enabled at (32357): [<c0008c64>] ret_fast_syscall+0x24/0x44
>> hardirqs last disabled at (32358): [<c04c14bc>]
>> _raw_spin_lock_irqsave+0x20/0x64
>> softirqs last enabled at (32160): [<c001e234>] __do_softirq+0x1b8/0x308
>> softirqs last disabled at (32137): [<c001e77c>] irq_exit+0xa0/0xd8
>>
>> other info that might help us debug this:
>> Possible unsafe locking scenario:
>>
>> CPU0
>> ----
>> lock(timekeeper_lock);
>> <Interrupt>
>> lock(timekeeper_lock);
>>
>> *** DEADLOCK ***
>>
>> 1 lock held by SAKEY/738:
>> #0: (timekeeper_lock){?.-...}, at: [<c004a3e4>] do_adjtimex+0x64/0xbc
>>
>> stack backtrace:
>> CPU: 0 PID: 738 Comm: SAKEY Not tainted 3.10.0-04864-g346ecc9-dirty #16
>> [<c000d67c>] (unwind_backtrace+0x0/0xf0) from [<c000b530>]
>> (show_stack+0x10/0x14)
>> [<c000b530>] (show_stack+0x10/0x14) from [<c04ba07c>]
>> (print_usage_bug.part.27+0x218/0x280)
>> [<c04ba07c>] (print_usage_bug.part.27+0x218/0x280) from [<c0053058>]
>> (mark_lock+0x538/0x6bc)
>> [<c0053058>] (mark_lock+0x538/0x6bc) from [<c005326c>]
>> (mark_held_locks+0x90/0x124)
>> [<c005326c>] (mark_held_locks+0x90/0x124) from [<c00533a8>]
>> (trace_hardirqs_on_caller+0xa8/0x23c)
>> [<c00533a8>] (trace_hardirqs_on_caller+0xa8/0x23c) from [<c04c1c60>]
>> (_raw_spin_unlock_irq+0x24/0x5c)
>> [<c04c1c60>] (_raw_spin_unlock_irq+0x24/0x5c) from [<c004ac8c>]
>> (__do_adjtimex+0x17c/0x65c)
>> [<c004ac8c>] (__do_adjtimex+0x17c/0x65c) from [<c004a404>]
>> (do_adjtimex+0x84/0xbc)
>> [<c004a404>] (do_adjtimex+0x84/0xbc) from [<c001d62c>]
>> (SyS_adjtimex+0x50/0xa8)
>> [<c001d62c>] (SyS_adjtimex+0x50/0xa8) from [<c0008c40>]
>> (ret_fast_syscall+0x0/0x44)
>
> Hrmm. So I'm a little confused by the report, as we hold the write lock
> on the timekeeper_lock disabling irqs, so I'm not sure I see how the irq
> could trigger to cause the deadlock. In fact, all the timekeeper_lock
> users save irqs.
>
> Hrmm. I dunno. :(
>
> Thomas, you have a guess?
>
> Let me know how you trigger it and I'll see if I can't reproduce it myself.
>
> thanks
> -john
>
>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists