Received-SPF: pass (google.com: domain of linux-kernel+bounces-29967-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:45d1:ec00::1 as permitted sender) client-ip=2604:1380:45d1:ec00::1;
From: Leonardo Bras <leobras@redhat.com>
To: John Ogness <john.ogness@linutronix.de>
Cc: Leonardo Bras <leobras@redhat.com>,
	Ilpo =?iso-8859-1?Q?J=E4rvinen?= <ilpo.jarvinen@linux.intel.com>,
	Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
	Jiri Slaby <jirislaby@kernel.org>,
	Thomas Gleixner <tglx@linutronix.de>,
	Andy Shevchenko <andriy.shevchenko@linux.intel.com>,
	Florian Fainelli <f.fainelli@gmail.com>,
	Tony Lindgren <tony@atomide.com>,
	Marcelo Tosatti <mtosatti@redhat.com>,
	LKML <linux-kernel@vger.kernel.org>,
	linux-serial <linux-serial@vger.kernel.org>
Subject: Re: [RESEND RFC PATCH v1 2/2] serial/8250: Avoid getting lock in RT atomic context
Date: Thu, 18 Jan 2024 06:36:49 -0300
Message-ID: <ZajxMc05uVmK7e60@LeoBras>
In-Reply-To: <87o7djaubq.fsf@jogness.linutronix.de>
References: <20240116073701.2356171-1-leobras@redhat.com> <20240116073701.2356171-3-leobras@redhat.com> <75a39f0a-8f79-eacf-4a35-5de512a3cbed@linux.intel.com> <ZabJGefGkrs0SNzW@LeoBras> <87o7djaubq.fsf@jogness.linutronix.de>
Precedence: bulk
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: 8bit

On Thu, Jan 18, 2024 at 10:07:45AM +0106, John Ogness wrote:
> On 2024-01-16, Leonardo Bras <leobras@redhat.com> wrote:
> > Well, at least in an PREEMPT_RT=y kernel I have found this same bug 
> > reproducing several times, and through the debugging that I went through I 
> > saw no mechanism for preventing it.
> >
> > This is one example of the bug:
> > While writing to serial with serial8250_tx_chars in a irq_thread handler
> > there is an interruption, and __report_bad_irq() tries to printk 
> > stuff to the console, and when printk goes down to 
> > serial8250_console_write() and tried to get the port->lock, which causes 
> > the "BUG: scheduling while atomic":
> >
> > [   42.485878] irq 4: nobody cared (try booting with the "irqpoll" option)
> > [   42.485886] BUG: scheduling while atomic: irq/4-ttyS0/751/0x00010002
> > [   42.485890] Modules linked in:
> > [   42.485892] Preemption disabled at:
> > [   42.485893] [<ffffffff8118ac80>] irq_enter_rcu+0x10/0x80
> > [   42.485919] CPU: 0 PID: 751 Comm: irq/4-ttyS0 Not tainted 6.7.0-rc6+ #6
> 
> This is 6.7.0-rc6+. How are you setting PREEMPT_RT?

By setting ARCH_SUPPORTS_RT=y

> 
> > [   42.485927] Hardware name: Red Hat KVM/RHEL, BIOS 1.16.3-1.el9 04/01/2014
> > [   42.485929] Call Trace:
> > [   42.485940]  <IRQ>
> > [   42.485944]  dump_stack_lvl+0x33/0x50
> > [   42.485976]  __schedule_bug+0x89/0xa0
> > [   42.485991]  schedule_debug.constprop.0+0xd1/0x120
> > [   42.485996]  __schedule+0x50/0x690
> > [   42.486026]  schedule_rtlock+0x1e/0x40
> > [   42.486029]  rtlock_slowlock_locked+0xe7/0x2b0
> > [   42.486047]  rt_spin_lock+0x41/0x60
> > [   42.486051]  serial8250_console_write+0x1be/0x460
> 
> On PREEMPT_RT-patched kernel, serial8250_console_write() is not
> compiled. So obviously you are not running a PREEMPT_RT-patched kernel.

Yes, as mentioned to Thomas before, I am on Vanilla torvalds/linux.
I was not aware of any extra patches for PREEMPT_RT, could you please point 
the repo, or the patchset for that PREEMPT_RT-patched version?

> 
> > [   42.486094]  console_flush_all+0x18d/0x3c0
> > [   42.486111]  console_unlock+0x6c/0xd0
> 
> Flushing on console_unlock() is the legacy method.

Great! so this part is solved :)

> 
> I assume you are using a mainline kernel with forced threading of
> irqs. Mainline has many known problems with console printing, including
> calling printk when the port->lock is held.

I am using mainline (torvalds/linux) kernel, forcing ARCH_SUPPORTS_RT:

diff --git a/arch/Kconfig b/arch/Kconfig
index 5ca66aad0d08..879c34398cb7 100644
--- a/arch/Kconfig
+++ b/arch/Kconfig
@@ -1195,7 +1195,7 @@ config ARCH_NO_PREEMPT
        bool
 
 config ARCH_SUPPORTS_RT
-       bool
+       def_bool y

Since I was not aware of a PREEMPT_RT-patched tree, I did this so I could 
compile a PREEMPT_RT kernel.


> 
> This has been discussed before [0].
> 
> > [   42.486117]  vprintk_emit+0x1d6/0x290
> > [   42.486122]  _printk+0x58/0x80
> > [   42.486139]  __report_bad_irq+0x26/0xc0
> > [   42.486147]  note_interrupt+0x2a1/0x2f0
> > [   42.486155]  handle_irq_event+0x84/0x90
> > [   42.486161]  handle_edge_irq+0x9f/0x260
> > [   42.486168]  __common_interrupt+0x68/0x100
> > [   42.486178]  common_interrupt+0x9f/0xc0
> > [   42.486184]  </IRQ>
> 
> If you want to fix any threaded irq problems relating to printk and
> console drivers, please use the latest PREEMPT_RT patch series with
> CONFIG_PREEMPT_RT enabled. This is the current work that is being
> reviewed on LKML for mainline inclusion. Thanks!
> 

Sure, please let me know of where can I find the latest PREEMPT_RT patch 
series so I can re-test my bug. By what you comment, it's higly probable 
that patch 2/2 will not be necessary.

On the other hand, unless some extra work was done in preventing the 
scenario in patch 1/2, I think that can still be discussed. 

> John Ogness
> 
> [0] https://lore.kernel.org/lkml/87il5o32w9.fsf@jogness.linutronix.de
> 

Thanks!
Leo