From: Petr Mladek <pmladek@suse.com>
To: Waiman Long <longman@redhat.com>
Cc: Thomas Gleixner <tglx@linutronix.de>,
Ingo Molnar <mingo@redhat.com>, Borislav Petkov <bp@alien8.de>,
"H. Peter Anvin" <hpa@zytor.com>,
Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>,
Andy Shevchenko <andy.shevchenko@gmail.com>,
x86@kernel.org, linux-kernel@vger.kernel.org,
David Woodhouse <dwmw@amazon.co.uk>,
Marc Zyngier <maz@kernel.org>
Subject: Re: [PATCH v2] x86/apic/vector: Move pr_warn() out of vector_lock
Date: Tue, 30 Mar 2021 11:16:34 +0200 [thread overview]
Message-ID: <YGLschswmBlMMly9@alley> (raw)
In-Reply-To: <20210329005236.1218-1-longman@redhat.com>
On Sun 2021-03-28 20:52:36, Waiman Long wrote:
> It was found that the following circular locking dependency warning
> could happen in some systems:
>
> [ 218.097878] ======================================================
> [ 218.097879] WARNING: possible circular locking dependency detected
> [ 218.097880] 4.18.0-228.el8.x86_64+debug #1 Not tainted
> [ 218.097881] ------------------------------------------------------
> [ 218.097882] systemd/1 is trying to acquire lock:
> [ 218.097883] ffffffff84c27920 (console_owner){-.-.}, at: console_unlock+0x3fb/0x9f0
> [ 218.097886]
> [ 218.097887] but task is already holding lock:
> [ 218.097888] ffffffff84afca78 (vector_lock){-.-.}, at: x86_vector_activate+0xca/0xab0
> [ 218.097891]
> [ 218.097892] which lock already depends on the new lock.
> [ 218.097893]
> [ 218.097893]
> [ 218.097894] the existing dependency chain (in reverse order) is:
> [ 218.097895]
> [ 218.097896] -> #3 (vector_lock){-.-.}:
> [ 218.097899] _raw_spin_lock_irqsave+0x48/0x81
> [ 218.097900] x86_vector_activate+0xca/0xab0
> [ 218.097901] __irq_domain_activate_irq+0xdb/0x160
> [ 218.097901] __irq_domain_activate_irq+0x7d/0x160
> [ 218.097902] __irq_domain_activate_irq+0x7d/0x160
> [ 218.097903] irq_domain_activate_irq+0x95/0x130
> [ 218.097904] __setup_irq+0x861/0x1e60
> [ 218.097905] request_threaded_irq+0x1e7/0x2c0
> [ 218.097906] acpi_os_install_interrupt_handler+0x14c/0x180
> [ 218.097907] acpi_ev_install_sci_handler+0xc4/0xef
> [ 218.097908] acpi_ev_install_xrupt_handlers+0x85/0x15f
> [ 218.097909] acpi_enable_subsystem+0x345/0x394
> [ 218.097910] acpi_init+0x157/0x612
> [ 218.097910] do_one_initcall+0xe9/0x57d
> [ 218.097911] kernel_init_freeable+0x606/0x6d4
> [ 218.097912] kernel_init+0xc/0x121
> [ 218.097913] ret_from_fork+0x27/0x50
> [ 218.097914]
> [ 218.097914] -> #2 (&irq_desc_lock_class){-.-.}:
> [ 218.097917] _raw_spin_lock_irqsave+0x48/0x81
> [ 218.097918] __irq_get_desc_lock+0xcf/0x140
> [ 218.097919] __dble_irq_nosync+0x6e/0x110
> [ 218.097920] serial8250_do_startup+0x17a6/0x1ed0
> [ 218.097921] uart_startup.part.7+0x16f/0x4b0
> [ 218.097922] tty_port_open+0x112/0x190
> [ 218.097922] uart_open+0xe0/0x150
> [ 218.097923] tty_open+0x229/0x9a0
> [ 218.097924] chrdev_open+0x1e0/0x4e0
> [ 218.097925] do_dentry_open+0x3d9/0xea0
> [ 218.097926] path_openat+0xb73/0x2690
> [ 218.097927] do_filp_open+0x17c/0x250
> [ 218.097927] do_sys_open+0x1d9/0x360
> [ 218.097928] kernel_init_freeable+0x62e/0x6d4
> [ 218.097929] kernel_init+0xc/0x121
> [ 218.097930] ret_from_fork+0x27/0x50
> [ 218.097930]
> [ 218.097931] -> #1 (&port_lock_key){-.-.}:
> [ 218.097934] _raw_spin_lock_irqsave+0x48/0x81
> [ 218.097935] serial8250_console_write+0x629/0x770
> [ 218.097936] console_unlock+0x611/0x9f0
> [ 218.097937] register_console+0x54c/0xa70
> [ 218.097938] univ8250_console_init+0x24/0x27
> [ 218.097938] console_init+0x2ef/0x45a
> [ 218.097939] start_kernel+0x4c4/0x7c5
> [ 218.097940] secondary_startup_64+0xb7/0xc0
> [
> [ 218.097941] -> #0 (console_owner){-.-.}:
> [ 218.097944] __lock_acquire+0x2894/0x7300
> [ 218.097945] lock_acquire+0x14f/0x3b0
> [ 218.097946] console_unlock+0x45d/0x9f0
> [ 218.097947] vprintk_emit+0x147/0x450
> [ 218.097947] printk+0x9f/0xc5
> [ 218.097948] x86_vector_activate+0x3f8/0xab0
> [ 218.097949] __irq_domain_activate_irq+0xdb/0x160
> [ 218.097950] __irq_domain_activate_irq+0x7d/0x160
> [ 218.097951] __irq_domain_activate_irq+0x7d/0x160
> [ 218.097952] irq_domain_activate_irq+0x95/0x130
> [ 218.097953] __setup_irq+0x861/0x1e60
> [ 218.097954] request_threaded_irq+0x1e7/0x2c0
> [ 218.097955] univ8250_setup_irq+0x6ef/0x8b0
> [ 218.097955] serial8250_do_startup+0x7d4/0x1ed0
> [ 218.097956] uart_startup.part.7+0x16f/0x4b0
> [ 218.097957] tty_port_open+0x112/0x190
> [ 218.097958] uart_open+0xe0/0x150
> [ 218.097959] tty_open+0x229/0x9a0
> [ 218.097960] chrdev_open+0x1e0/0x4e0
> [ 218.097960] do_dentry_open+0x3d9/0xea0
> [ 218.097961] path_openat+0xb73/0x2690
> [ 218.097962] do_filp_open+0x17c/0x250
> [ 218.097963] do_sys_open+0x1d9/0x360
> [ 218.097964] do_syscall_64+0xa5/0x4d0
> [ 218.097965] entry_SYSCALL_64_after_hwframe+0x6a/0xdf
> [ 218.097965]
> [ 218.097966] other info that might help us debug this:
> [ 218.097967]
> [ 218.097967] Chain exists of:
> [ 218.097968] console_oc_lock_class --> vector_lock
> [ 218.097972]
> [ 218.097973] Possible unsafe locking scenario:
> [ 218.097973]
> [ 218.097974] CPU0 CPU1
> [ 218.097975] ---- ----
> [ 218.097975] lock(vector_lock);
> [ 218.097977] lock(&irq_desc_lock_class);
> [ 218.097980] lock(vector_lock);
> [ 218.097981] lock(console_owner);
> [ 218.097983]
> [ 218.097984] *** DEADLOCK ***
> [ 218.097984]
> [ 218.097985] 6 locks held by systemd/1:
> [ 218.097986] #0: ffff88822b5cc1e8 (&tty->legacy_mutex){+.+.}, at: tty_init_dev+0x79/0x440
> [ 218.097989] #1: ffff88832ee00770 (&port->mutex){+.+.}, at: tty_port_open+0x85/0x190
> [ 218.097993] #2: ffff88813be85a88 (&desc->request_mutex){+.+.}, at: __setup_irq+0x249/0x1e60
> [ 218.097996] #3: ffff88813be858c0 (&irq_desc_lock_class){-.-.}, at: __setup_irq+0x2d9/0x1e60
> [ 218.098000] #4: ffffffff84afca78 (vector_lock){-.-.}, at: x86_vector_activate+0xca/0xab0
> [ 218.098003] #5: ffffffff84c27e20 (console_lock){+.+.}, at: vprintk_emit+0x13a/0x450
> [ 218.098007]
> [ 218.098007] stack backtrace:
> [ 218.098009] CPU: 1 PID: 1 Comm: systemdt tainted 4.18.0-228.el8.x86_64+debug #1
> [ 218.098010] Hardware name: HP ProLiant DL385p Gen8, BIOS A28 03/07/2016
> [ 218.098010] Call Trace:
> [ 218.098011] dump_stack+0x9a/0xf0
> [ 218.098012] check_noncircular+0x317/0x3c0
> [ 218.098013] ? print_circular_bug+0x1e0/0x1e0
> [ 218.098014] ? do_profile_hits.isra.4.cold.9+0x2d/0x2d
> [ 218.098015] ? sched_clock+0x5/0x10
> [ 218.098015] __lock_acquire+0x2894/0x7300
> [ 218.098016] ? trace_hardirqs_on+0x10/0x10
> [ 218.098017] ? lock_downgrade+0x6f0/0x6f0
> [ 218.098018] lock_acquire+0x14f/0x3b0
> [ 218.098019] ? console_unlock+0x3fb/0x9f0
> [ 218.098019] console_unlock+0x45d/0x9f0
> [ 218.098020] ? console_unlock+0x3fb/0x9f0
> [ 218.098021] vprintk_emit+0x147/0x450
> [ 218.098022] ? apic_update_irq_cfg+0x3f6/0x520
> [ 218.098023] printk+0x9f/0xc5
> [ 218.098023] ? kmsg_dump_rewind_nolock+0xd9/0xd9
> [ 218.098024] x86_vector_activate+0x3f8/0xab0
> [ 218.098025] ? find_held_lock+0x3a/0x1c0
> [ 218.098026] __irq_domain_activate_irq+0xdb/0x160
> [ 218.098027] __irq_domain_activate_irq+0x7d/0x160
> [ 218.098028] __irq_domain_activate_irq+0x7d/0x160
> [ 218.098029] irq_domain_activate_irq+0x95/0x130
> [ 218.098029] ? __init_waitqueue_head+0x3a/0x90
> [ 218.098030] __setup_irq+0x861/0x1e60
> [ 218.098031] ? kmem_cache_alloc_trace+0x169/0x360
> [ 218.098032] ? request_threaded_irq+0xf9/0x2c0
> [ 218.098033] request_threaded_irq+0x1e7/0x2c0
> [ 218.098033] univ8250_setup_irq+0x6ef/0x8b0
> [ 218.50_do_startup+0x7d4/0x1ed0
> [ 218.098035] uart_startup.part.7+0x16f/0x4b0
> [ 218.098036] tty_port_open+0x112/0x190
> [ 218.098037] ? _raw_spin_unlock+0x1f/0x30
> [ 218.098037] uart_open+0xe0/0x150
> [ 218.098038] tty_open+0x229/0x9a0
> [ 218.098039] ? lock_acquire+0x14f/0x3b0
> [ 218.098040] ? tty_init_dev+0x440/0x440
> [ 218.098041] ? selinux_file_open+0x2cf/0x400
> [ 218.098041] chrdev_open+0x1e0/0x4e0
> [ 218.098042] ? cdev_put.part.0+0x50/0x50
> [ 218.098043] do_dentry_open+0x3d9/0xea0
> [ 218.098044] ? cdev_put.part.0+0x50/0x50
> [ 218.098045] ? devcgroup_check_permission+0x17c/0x2f0
> [ 218.098046] ? __x64_sys_fchdir+0x180/0x180
> [ 218.098046] ? security_inode_permission+0x79/0xc0
> [ 218.098047] path_openat+0xb73/0x2690
> [ 218.098048] ? save_stack+0x81/0xb0
> [ 218.098049] ? path_lookupat+0x820/0x820
> [ 218.098049] ? sched_clock+0x5/0x10
> [ 218.098050] ? sched_clock_cpu+0x18/0x1e0
> [ 218.098051] ? do_syscall_64+0xa5/0x4d0
> [ 218.098052] ? entry_SYSCALL_64_after_hwframe+0x6a/0xdf
> [ 218.098053] ? __lock_acquire+0x646/0x7300
> [ 218.098054] ? sched_clock_cpu+0x18/0x1e0
> [ 218.098054] ? find_held_lock+0x3a/0x1c0 filp_open+0x17c/0x250
> [ 218.098056] ? may_open_dev+0xc0/0xc0
> [ 218.098057] ? do_raw_spin_unlock+0x54/0x230
> [ 218.098058] ? _raw_spin_unlock+0x1f/0x30
> [ 218.098058] ? _raw_spin_unlock_irq+0x24/0x40
> [ 218.098059] do_sys_open+0x1d9/0x360
> [ 218.098060] ? filp_open+0x50/0x50
> [ 218.098061] ? entry_SYSCALL_64_after_hwframe+0x7a/0xdf
> [ 218.098062] ? do_syscall_64+0x22/0x4d0
> [ 218.098062] do_syscall_64+0xa5/0x4d0
> [ 218.098063] entry_SYSCALL_64_after_hwframe+0x6a/0xdf
> [ 218.098064] RIP: 0033:0x7ff4ee7620d6
>
> This lockdep warning was causing by printing of the warning message:
>
> [ 218.095152] irq 3: Affinity broken due to vector space exhaustion.
>
> To avoid this potential deadlock scenario, this patch moves all the
> pr_warn() calls in the vector.c file out of the vector_lock critical
> sections.
>
> Signed-off-by: Waiman Long <longman@redhat.com>
> ---
> arch/x86/kernel/apic/vector.c | 35 +++++++++++++++++++++--------------
> 1 file changed, 21 insertions(+), 14 deletions(-)
>
> diff --git a/arch/x86/kernel/apic/vector.c b/arch/x86/kernel/apic/vector.c
> index 3c9c7492252f..79f1ce3a9539 100644
> --- a/arch/x86/kernel/apic/vector.c
> +++ b/arch/x86/kernel/apic/vector.c
> @@ -385,7 +385,7 @@ static void x86_vector_deactivate(struct irq_domain *dom, struct irq_data *irqd)
> raw_spin_unlock_irqrestore(&vector_lock, flags);
> }
>
> -static int activate_reserved(struct irq_data *irqd)
> +static int activate_reserved(struct irq_data *irqd, char *wbuf, size_t wsize)
> {
> struct apic_chip_data *apicd = apic_chip_data(irqd);
> int ret;
> @@ -410,8 +410,9 @@ static int activate_reserved(struct irq_data *irqd)
> */
> if (!cpumask_subset(irq_data_get_effective_affinity_mask(irqd),
> irq_data_get_affinity_mask(irqd))) {
> - pr_warn("irq %u: Affinity broken due to vector space exhaustion.\n",
> - irqd->irq);
> + snprintf(wbuf, wsize, KERN_WARNING
> + "irq %u: Affinity broken due to vector space exhaustion.\n",
> + irqd->irq);
If you prove that this might happen upstream and we decide to
duct-tape it then printk_deferred() would be a better solution
than these games with temporary buffers.
As already mentioned in the other replies, the printk rework is
the real solution. The current state is that all locks around
the logbuffer manipulation should be removed in 5.13. Then
we are finally going to rework the console handling.
It is hard to predict how long it would take. IMHO, we would need
at least two more release cycles. The idea is simple. The problem
is how to detect and handle situations where we could not rely on
the kthreads doing the work. Also it would involve rewriting
some historic code around console locking.
Best Regards,
Petr
prev parent reply other threads:[~2021-03-30 9:17 UTC|newest]
Thread overview: 5+ messages / expand[flat|nested] mbox.gz Atom feed top
2021-03-29 0:52 [PATCH v2] x86/apic/vector: Move pr_warn() out of vector_lock Waiman Long
2021-03-29 12:42 ` Thomas Gleixner
2021-03-29 19:57 ` Waiman Long
2021-03-29 20:44 ` Thomas Gleixner
2021-03-30 9:16 ` Petr Mladek [this message]
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=YGLschswmBlMMly9@alley \
--to=pmladek@suse.com \
--cc=andy.shevchenko@gmail.com \
--cc=bp@alien8.de \
--cc=dwmw@amazon.co.uk \
--cc=hpa@zytor.com \
--cc=linux-kernel@vger.kernel.org \
--cc=longman@redhat.com \
--cc=maz@kernel.org \
--cc=mingo@redhat.com \
--cc=sergey.senozhatsky.work@gmail.com \
--cc=tglx@linutronix.de \
--cc=x86@kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox