| Message ID | 20190304172053.17340-1-julien.grall@arm.com |
|---|---|
| State | Superseded |
| Headers | show |
| Series | tty/sysrq: Convert show_lock to raw_spinlock_t | expand |
(CC correctly linux-rt-users) On 04/03/2019 17:20, Julien Grall wrote: > At the moment show_lock is implemented using spin_lock_t and called from > an interrupt context on Arm64. The following backtrace was triggered by: > > 42sh# echo l > /proc/sysrq-trigger > > [ 4432.073756] sysrq: SysRq : Show backtrace of all active CPUs > [ 4432.403422] BUG: sleeping function called from invalid context at kernel/locking/rtmutex.c:974 > [ 4432.403424] sysrq: CPU6: > [ 4432.403426] in_atomic(): 1, irqs_disabled(): 128, pid: 2410, name: kworker/u16:2 > > [...] > > [ 4432.403581] Call trace: > [ 4432.403584] dump_backtrace+0x0/0x148 > [ 4432.403586] show_stack+0x14/0x20 > [ 4432.403588] dump_stack+0x9c/0xd4 > [ 4432.403592] ___might_sleep+0x1cc/0x298 > [ 4432.403595] rt_spin_lock+0x5c/0x70 > [ 4432.403596] showacpu+0x34/0x68 > [ 4432.403599] flush_smp_call_function_queue+0xd4/0x278 > [ 4432.403602] generic_smp_call_function_single_interrupt+0x10/0x18 > [ 4432.403605] handle_IPI+0x26c/0x668 > [ 4432.403607] gic_handle_irq+0x9c/0xa0 > [ 4432.403609] el1_irq+0xb4/0x13c > > With RT-patches, spin_lock can now sleep and therefore cannot be used from > interrupt context. Use a raw_spin_lock instead to prevent the lock to > sleep. > > Signed-off-by: Julien Grall <julien.grall@arm.com> > --- > drivers/tty/sysrq.c | 6 +++--- > 1 file changed, 3 insertions(+), 3 deletions(-) > > diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c > index 1f03078ec352..8473557c7ab2 100644 > --- a/drivers/tty/sysrq.c > +++ b/drivers/tty/sysrq.c > @@ -208,7 +208,7 @@ static struct sysrq_key_op sysrq_showlocks_op = { > #endif > > #ifdef CONFIG_SMP > -static DEFINE_SPINLOCK(show_lock); > +static DEFINE_RAW_SPINLOCK(show_lock); > > static void showacpu(void *dummy) > { > @@ -218,10 +218,10 @@ static void showacpu(void *dummy) > if (idle_cpu(smp_processor_id())) > return; > > - spin_lock_irqsave(&show_lock, flags); > + raw_spin_lock_irqsave(&show_lock, flags); > pr_info("CPU%d:\n", smp_processor_id()); > show_stack(NULL, NULL); > - spin_unlock_irqrestore(&show_lock, flags); > + raw_spin_unlock_irqrestore(&show_lock, flags); > } > > static void sysrq_showregs_othercpus(struct work_struct *dummy) > -- Julien Grall
On 2019-03-04 17:21:57 [+0000], Julien Grall wrote: > (CC correctly linux-rt-users) > > On 04/03/2019 17:20, Julien Grall wrote: > > At the moment show_lock is implemented using spin_lock_t and called from > > an interrupt context on Arm64. The following backtrace was triggered by: > > > > 42sh# echo l > /proc/sysrq-trigger > > > > [ 4432.073756] sysrq: SysRq : Show backtrace of all active CPUs > > [ 4432.403422] BUG: sleeping function called from invalid context at kernel/locking/rtmutex.c:974 > > [ 4432.403424] sysrq: CPU6: > > [ 4432.403426] in_atomic(): 1, irqs_disabled(): 128, pid: 2410, name: kworker/u16:2 > > > > [...] > > > > [ 4432.403581] Call trace: > > [ 4432.403584] dump_backtrace+0x0/0x148 > > [ 4432.403586] show_stack+0x14/0x20 > > [ 4432.403588] dump_stack+0x9c/0xd4 > > [ 4432.403592] ___might_sleep+0x1cc/0x298 > > [ 4432.403595] rt_spin_lock+0x5c/0x70 > > [ 4432.403596] showacpu+0x34/0x68 > > [ 4432.403599] flush_smp_call_function_queue+0xd4/0x278 > > [ 4432.403602] generic_smp_call_function_single_interrupt+0x10/0x18 > > [ 4432.403605] handle_IPI+0x26c/0x668 > > [ 4432.403607] gic_handle_irq+0x9c/0xa0 > > [ 4432.403609] el1_irq+0xb4/0x13c > > > > With RT-patches, spin_lock can now sleep and therefore cannot be used from > > interrupt context. Use a raw_spin_lock instead to prevent the lock to > > sleep. > > > > Signed-off-by: Julien Grall <julien.grall@arm.com> I don't have to look at this properly but this looks is wrong. Please CC the RT developers if you plan any changes that affects primary only the RT tree. This change is a nop for the !RT tree. > > drivers/tty/sysrq.c | 6 +++--- > > 1 file changed, 3 insertions(+), 3 deletions(-) > > > > diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c > > index 1f03078ec352..8473557c7ab2 100644 > > --- a/drivers/tty/sysrq.c > > +++ b/drivers/tty/sysrq.c > > @@ -208,7 +208,7 @@ static struct sysrq_key_op sysrq_showlocks_op = { > > #endif > > #ifdef CONFIG_SMP > > -static DEFINE_SPINLOCK(show_lock); > > +static DEFINE_RAW_SPINLOCK(show_lock); > > static void showacpu(void *dummy) > > { > > @@ -218,10 +218,10 @@ static void showacpu(void *dummy) > > if (idle_cpu(smp_processor_id())) > > return; > > - spin_lock_irqsave(&show_lock, flags); > > + raw_spin_lock_irqsave(&show_lock, flags); > > pr_info("CPU%d:\n", smp_processor_id()); > > show_stack(NULL, NULL); > > - spin_unlock_irqrestore(&show_lock, flags); > > + raw_spin_unlock_irqrestore(&show_lock, flags); > > } > > static void sysrq_showregs_othercpus(struct work_struct *dummy) > > Sebastian
Hello Sebastian, On 04/03/2019 22:01, Sebastian Andrzej Siewior wrote: > On 2019-03-04 17:21:57 [+0000], Julien Grall wrote: >> (CC correctly linux-rt-users) >> >> On 04/03/2019 17:20, Julien Grall wrote: >>> At the moment show_lock is implemented using spin_lock_t and called from >>> an interrupt context on Arm64. The following backtrace was triggered by: >>> >>> 42sh# echo l > /proc/sysrq-trigger >>> >>> [ 4432.073756] sysrq: SysRq : Show backtrace of all active CPUs >>> [ 4432.403422] BUG: sleeping function called from invalid context at kernel/locking/rtmutex.c:974 >>> [ 4432.403424] sysrq: CPU6: >>> [ 4432.403426] in_atomic(): 1, irqs_disabled(): 128, pid: 2410, name: kworker/u16:2 >>> >>> [...] >>> >>> [ 4432.403581] Call trace: >>> [ 4432.403584] dump_backtrace+0x0/0x148 >>> [ 4432.403586] show_stack+0x14/0x20 >>> [ 4432.403588] dump_stack+0x9c/0xd4 >>> [ 4432.403592] ___might_sleep+0x1cc/0x298 >>> [ 4432.403595] rt_spin_lock+0x5c/0x70 >>> [ 4432.403596] showacpu+0x34/0x68 >>> [ 4432.403599] flush_smp_call_function_queue+0xd4/0x278 >>> [ 4432.403602] generic_smp_call_function_single_interrupt+0x10/0x18 >>> [ 4432.403605] handle_IPI+0x26c/0x668 >>> [ 4432.403607] gic_handle_irq+0x9c/0xa0 >>> [ 4432.403609] el1_irq+0xb4/0x13c >>> >>> With RT-patches, spin_lock can now sleep and therefore cannot be used from >>> interrupt context. Use a raw_spin_lock instead to prevent the lock to >>> sleep. >>> >>> Signed-off-by: Julien Grall <julien.grall@arm.com> > > I don't have to look at this properly but this looks is wrong. May I ask why does it look wrong? On Arm64, this code is called from an IRQ disabled context (see the check in flush_smp_call_function_queue). So it seems to me that it makes sense to switch to a raw spin lock here. I would be happy to implement differently if you have a better solution here. > Please CC the RT developers if you plan any changes that affects primary > only the RT tree. This change is a nop for the !RT tree. Sorry, I was not sure whether CCing linux-rt-users was enough here. > >>> drivers/tty/sysrq.c | 6 +++--- >>> 1 file changed, 3 insertions(+), 3 deletions(-) >>> >>> diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c >>> index 1f03078ec352..8473557c7ab2 100644 >>> --- a/drivers/tty/sysrq.c >>> +++ b/drivers/tty/sysrq.c >>> @@ -208,7 +208,7 @@ static struct sysrq_key_op sysrq_showlocks_op = { >>> #endif >>> #ifdef CONFIG_SMP >>> -static DEFINE_SPINLOCK(show_lock); >>> +static DEFINE_RAW_SPINLOCK(show_lock); >>> static void showacpu(void *dummy) >>> { >>> @@ -218,10 +218,10 @@ static void showacpu(void *dummy) >>> if (idle_cpu(smp_processor_id())) >>> return; >>> - spin_lock_irqsave(&show_lock, flags); >>> + raw_spin_lock_irqsave(&show_lock, flags); >>> pr_info("CPU%d:\n", smp_processor_id()); >>> show_stack(NULL, NULL); >>> - spin_unlock_irqrestore(&show_lock, flags); >>> + raw_spin_unlock_irqrestore(&show_lock, flags); >>> } >>> static void sysrq_showregs_othercpus(struct work_struct *dummy) >>> Best regards, -- Julien Grall
On 2019-03-04 17:20:53 [+0000], Julien Grall wrote: > At the moment show_lock is implemented using spin_lock_t and called from > an interrupt context on Arm64. The following backtrace was triggered by: > > 42sh# echo l > /proc/sysrq-trigger > > [ 4432.073756] sysrq: SysRq : Show backtrace of all active CPUs > [ 4432.403422] BUG: sleeping function called from invalid context at kernel/locking/rtmutex.c:974 > [ 4432.403424] sysrq: CPU6: > [ 4432.403426] in_atomic(): 1, irqs_disabled(): 128, pid: 2410, name: kworker/u16:2 > > [...] > > [ 4432.403581] Call trace: > [ 4432.403584] dump_backtrace+0x0/0x148 > [ 4432.403586] show_stack+0x14/0x20 > [ 4432.403588] dump_stack+0x9c/0xd4 > [ 4432.403592] ___might_sleep+0x1cc/0x298 > [ 4432.403595] rt_spin_lock+0x5c/0x70 > [ 4432.403596] showacpu+0x34/0x68 > [ 4432.403599] flush_smp_call_function_queue+0xd4/0x278 > [ 4432.403602] generic_smp_call_function_single_interrupt+0x10/0x18 > [ 4432.403605] handle_IPI+0x26c/0x668 > [ 4432.403607] gic_handle_irq+0x9c/0xa0 > [ 4432.403609] el1_irq+0xb4/0x13c > > With RT-patches, spin_lock can now sleep and therefore cannot be used from > interrupt context. Use a raw_spin_lock instead to prevent the lock to > sleep. > > Signed-off-by: Julien Grall <julien.grall@arm.com> Now that I had time to look at it, for the change itself: Acked-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> For the description please take into consideration to add something like this: Systems which don't provide arch_trigger_cpumask_backtrace() will invoke showacpu() from a smp_call_function() function which is invoked with disabled interrupts even on -RT systems. The function acquires the show_lock lock which only purpose is to ensure that the CPUs don't print simultaneously. Otherwise the output would clash and it would be hard to tell the output from CPUx apart from CPUy. On -RT the spin_lock() can not be acquired from this context. A raw_spin_lock() is required. It will introduce the system's latency by performing the sysrq request and other CPUs will block on the lock until the request is done. This is okay because the user asked for a backtrace of all active CPUs and under "normal circumstances in production" this path should not be triggered. Which explains *why* you do the change and *why* it is okay to do the change. If we start changing each spin_lock() to a raw_spin_lock() because lockdep said so then soon the RT switch will make less change than it should. From top of my head I think you won't see the output on -RT right away. The output won't be printed from the non-preemptible context and will be delayed until a printk occurs from a preemptible context. There are printk related patches which fix that and allow a printk from a non-preemptible context for a configured log level. Looking at the showacpu() construct: Do you get a proper stacktrace for a busy CPU or does it always start at el1_irq()? Because if the interrupt always starts with its own interrupt stack then the backtrace is useless. All you would need is the information that the CPU is alive and a oneline printk() saying so would be enough. Or, if it starts on its own stack but is able to unwind to the previous context *then* you gain additional information you are looking for. > --- > drivers/tty/sysrq.c | 6 +++--- > 1 file changed, 3 insertions(+), 3 deletions(-) > > diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c > index 1f03078ec352..8473557c7ab2 100644 > --- a/drivers/tty/sysrq.c > +++ b/drivers/tty/sysrq.c > @@ -208,7 +208,7 @@ static struct sysrq_key_op sysrq_showlocks_op = { > #endif > > #ifdef CONFIG_SMP > -static DEFINE_SPINLOCK(show_lock); > +static DEFINE_RAW_SPINLOCK(show_lock); > > static void showacpu(void *dummy) > { > @@ -218,10 +218,10 @@ static void showacpu(void *dummy) > if (idle_cpu(smp_processor_id())) > return; > > - spin_lock_irqsave(&show_lock, flags); > + raw_spin_lock_irqsave(&show_lock, flags); > pr_info("CPU%d:\n", smp_processor_id()); > show_stack(NULL, NULL); > - spin_unlock_irqrestore(&show_lock, flags); > + raw_spin_unlock_irqrestore(&show_lock, flags); > } > > static void sysrq_showregs_othercpus(struct work_struct *dummy) > -- > 2.11.0 > Sebastian
Hi Sebastian, On 07/03/2019 12:38, Sebastian Andrzej Siewior wrote: > On 2019-03-04 17:20:53 [+0000], Julien Grall wrote: >> At the moment show_lock is implemented using spin_lock_t and called from >> an interrupt context on Arm64. The following backtrace was triggered by: >> >> 42sh# echo l > /proc/sysrq-trigger >> >> [ 4432.073756] sysrq: SysRq : Show backtrace of all active CPUs >> [ 4432.403422] BUG: sleeping function called from invalid context at kernel/locking/rtmutex.c:974 >> [ 4432.403424] sysrq: CPU6: >> [ 4432.403426] in_atomic(): 1, irqs_disabled(): 128, pid: 2410, name: kworker/u16:2 >> >> [...] >> >> [ 4432.403581] Call trace: >> [ 4432.403584] dump_backtrace+0x0/0x148 >> [ 4432.403586] show_stack+0x14/0x20 >> [ 4432.403588] dump_stack+0x9c/0xd4 >> [ 4432.403592] ___might_sleep+0x1cc/0x298 >> [ 4432.403595] rt_spin_lock+0x5c/0x70 >> [ 4432.403596] showacpu+0x34/0x68 >> [ 4432.403599] flush_smp_call_function_queue+0xd4/0x278 >> [ 4432.403602] generic_smp_call_function_single_interrupt+0x10/0x18 >> [ 4432.403605] handle_IPI+0x26c/0x668 >> [ 4432.403607] gic_handle_irq+0x9c/0xa0 >> [ 4432.403609] el1_irq+0xb4/0x13c >> >> With RT-patches, spin_lock can now sleep and therefore cannot be used from >> interrupt context. Use a raw_spin_lock instead to prevent the lock to >> sleep. >> >> Signed-off-by: Julien Grall <julien.grall@arm.com> > > Now that I had time to look at it, for the change itself: > Acked-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> > > For the description please take into consideration to add something like > this: > > Systems which don't provide arch_trigger_cpumask_backtrace() will > invoke showacpu() from a smp_call_function() function which is invoked > with disabled interrupts even on -RT systems. > The function acquires the show_lock lock which only purpose is to > ensure that the CPUs don't print simultaneously. Otherwise the output > would clash and it would be hard to tell the output from CPUx apart > from CPUy. > On -RT the spin_lock() can not be acquired from this context. A > raw_spin_lock() is required. It will introduce the system's latency > by performing the sysrq request and other CPUs will block on the lock > until the request is done. This is okay because the user asked for a > backtrace of all active CPUs and under "normal circumstances in > production" this path should not be triggered. This description looks better. I will update the commit message. Do you mind if I had your signed-off-by as you provided the commit message? > > Which explains *why* you do the change and *why* it is okay to do the > change. If we start changing each spin_lock() to a raw_spin_lock() > because lockdep said so then soon the RT switch will make less change > than it should. I understand, I will take into account for the next RT patches I will post. > > From top of my head I think you won't see the output on -RT right away. > The output won't be printed from the non-preemptible context and will be > delayed until a printk occurs from a preemptible context. FWIW, this is the behavior I saw when testing this patch. > There are > printk related patches which fix that and allow a printk from a > non-preemptible context for a configured log level. > > Looking at the showacpu() construct: Do you get a proper stacktrace for a > busy CPU or does it always start at el1_irq()? Because if the interrupt > always starts with its own interrupt stack then the backtrace is > useless. All you would need is the information that the CPU is alive and > a oneline printk() saying so would be enough. Or, if it starts on its > own stack but is able to unwind to the previous context *then* you gain > additional information you are looking for. From my understanding, the stack frames across exceptions are chained. So the stacktrace will be able to unwind to the previous context. Actually, in my previous e-mail, I have cut down the stacktrace to el1_irq() as it was quite long. An example of the full stack trace: [ 516.820845] sysrq: SysRq : Show backtrace of all active CPUs [ 516.941513] sysrq: CPU0: [ 516.941515] Call trace: [ 516.941519] dump_backtrace+0x0/0x148 [ 516.941521] show_stack+0x14/0x20 [ 516.941524] showacpu+0x58/0x70 [ 516.941527] flush_smp_call_function_queue+0xd4/0x278 [ 516.941530] generic_smp_call_function_single_interrupt+0x10/0x18 [ 516.941533] handle_IPI+0x26c/0x668 [ 516.941535] gic_handle_irq+0x9c/0xa0 [ 516.941537] el1_irq+0xb4/0x13c [ 516.941539] generic_exec_single+0x174/0x218 [ 516.941541] smp_call_function_single+0xc4/0x280 [ 516.941544] task_function_call+0x54/0x90 [ 516.941547] event_function_call+0xa0/0x158 [ 516.941549] _perf_event_enable+0x54/0x80 [ 516.941552] perf_event_enable+0x24/0x40 [ 516.941555] kvm_pmu_enable_counter.part.0+0x64/0x90 [ 516.941557] kvm_pmu_handle_pmcr+0xc0/0xd8 [ 516.941559] access_pmcr+0x104/0x138 [ 516.941561] perform_access+0x1c/0x78 [ 516.941564] kvm_handle_sys_reg+0x144/0x4e0 [ 516.941566] handle_exit+0x13c/0x1f8 [ 516.941568] kvm_arch_vcpu_ioctl_run+0x68c/0xbe8 [ 516.941571] kvm_vcpu_ioctl+0x398/0xad8 [ 516.941574] do_vfs_ioctl+0xbc/0x910 [ 516.941576] ksys_ioctl+0x78/0xa8 [ 516.941579] __arm64_sys_ioctl+0x1c/0x28 [ 516.941582] el0_svc_common+0x90/0x118 [ 516.941584] el0_svc_handler+0x2c/0x80 [ 516.941586] el0_svc+0x8/0xc Thank you for your acked-by and the explanation. I will resend the patch with the updated comment. Best regards, > >> --- >> drivers/tty/sysrq.c | 6 +++--- >> 1 file changed, 3 insertions(+), 3 deletions(-) >> >> diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c >> index 1f03078ec352..8473557c7ab2 100644 >> --- a/drivers/tty/sysrq.c >> +++ b/drivers/tty/sysrq.c >> @@ -208,7 +208,7 @@ static struct sysrq_key_op sysrq_showlocks_op = { >> #endif >> >> #ifdef CONFIG_SMP >> -static DEFINE_SPINLOCK(show_lock); >> +static DEFINE_RAW_SPINLOCK(show_lock); >> >> static void showacpu(void *dummy) >> { >> @@ -218,10 +218,10 @@ static void showacpu(void *dummy) >> if (idle_cpu(smp_processor_id())) >> return; >> >> - spin_lock_irqsave(&show_lock, flags); >> + raw_spin_lock_irqsave(&show_lock, flags); >> pr_info("CPU%d:\n", smp_processor_id()); >> show_stack(NULL, NULL); >> - spin_unlock_irqrestore(&show_lock, flags); >> + raw_spin_unlock_irqrestore(&show_lock, flags); >> } >> >> static void sysrq_showregs_othercpus(struct work_struct *dummy) >> -- >> 2.11.0 >> > > Sebastian > -- Julien Grall
On 2019-03-07 18:14:46 [+0000], Julien Grall wrote: > Hi Sebastian, Hi, > This description looks better. I will update the commit message. Do you mind > if I had your signed-off-by as you provided the commit message? Sure. However you might also want to "just" add something like [bigeasy@linutronix.de: commit description] or something in plain English :) > From my understanding, the stack frames across exceptions are chained. So > the stacktrace will be able to unwind to the previous context. Ah okay. Sebastian
diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c index 1f03078ec352..8473557c7ab2 100644 --- a/drivers/tty/sysrq.c +++ b/drivers/tty/sysrq.c @@ -208,7 +208,7 @@ static struct sysrq_key_op sysrq_showlocks_op = { #endif #ifdef CONFIG_SMP -static DEFINE_SPINLOCK(show_lock); +static DEFINE_RAW_SPINLOCK(show_lock); static void showacpu(void *dummy) { @@ -218,10 +218,10 @@ static void showacpu(void *dummy) if (idle_cpu(smp_processor_id())) return; - spin_lock_irqsave(&show_lock, flags); + raw_spin_lock_irqsave(&show_lock, flags); pr_info("CPU%d:\n", smp_processor_id()); show_stack(NULL, NULL); - spin_unlock_irqrestore(&show_lock, flags); + raw_spin_unlock_irqrestore(&show_lock, flags); } static void sysrq_showregs_othercpus(struct work_struct *dummy)
At the moment show_lock is implemented using spin_lock_t and called from an interrupt context on Arm64. The following backtrace was triggered by: 42sh# echo l > /proc/sysrq-trigger [ 4432.073756] sysrq: SysRq : Show backtrace of all active CPUs [ 4432.403422] BUG: sleeping function called from invalid context at kernel/locking/rtmutex.c:974 [ 4432.403424] sysrq: CPU6: [ 4432.403426] in_atomic(): 1, irqs_disabled(): 128, pid: 2410, name: kworker/u16:2 [...] [ 4432.403581] Call trace: [ 4432.403584] dump_backtrace+0x0/0x148 [ 4432.403586] show_stack+0x14/0x20 [ 4432.403588] dump_stack+0x9c/0xd4 [ 4432.403592] ___might_sleep+0x1cc/0x298 [ 4432.403595] rt_spin_lock+0x5c/0x70 [ 4432.403596] showacpu+0x34/0x68 [ 4432.403599] flush_smp_call_function_queue+0xd4/0x278 [ 4432.403602] generic_smp_call_function_single_interrupt+0x10/0x18 [ 4432.403605] handle_IPI+0x26c/0x668 [ 4432.403607] gic_handle_irq+0x9c/0xa0 [ 4432.403609] el1_irq+0xb4/0x13c With RT-patches, spin_lock can now sleep and therefore cannot be used from interrupt context. Use a raw_spin_lock instead to prevent the lock to sleep. Signed-off-by: Julien Grall <julien.grall@arm.com> --- drivers/tty/sysrq.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) -- 2.11.0