On 09/10/2014 09:29 PM, Sebastian Andrzej Siewior wrote:
> The serial8250_do_startup() function unconditionally clears the
> interrupts and for that it reads from the RX-FIFO without checking if
> there is a byte in the FIFO or not. This works fine on OMAP4+ HW like
> AM335x or DRA7.
> OMAP3630 ES1.1 (which means probably all OMAP3 and earlier) does not like
> this:
Hello,
Sorry to wake up an old thread, but I'm affraid that this patch causes
problems on Marvell 88f6282 (Kirkwood).
When a caracter is received on the UART while the kernel is printing
the boot messages, as soon as the kernel configures the UART for
receiving (after root filesystem mount), it gets stuck printing the
following message repeatedly:
serial8250: too much work for irq29
Once stuck, the reception of another character allows the boot process
to finish.
>From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
register is never read to clear the interrupt.
We are using the second UART multiplexed on mpps 15 and 16.
Reverting this particular patch fixes the issue.
We are seing the problem on a 3.18 kernel.
Regards,
--
Nicolas Schichan
Freebox SAS
Hi Nicolas,
Thanks for the report.
On 02/09/2015 08:34 AM, Nicolas Schichan wrote:
> On 09/10/2014 09:29 PM, Sebastian Andrzej Siewior wrote:
>> The serial8250_do_startup() function unconditionally clears the
>> interrupts and for that it reads from the RX-FIFO without checking if
>> there is a byte in the FIFO or not. This works fine on OMAP4+ HW like
>> AM335x or DRA7.
>> OMAP3630 ES1.1 (which means probably all OMAP3 and earlier) does not like
>> this:
>
> Hello,
>
> Sorry to wake up an old thread, but I'm affraid that this patch causes
> problems on Marvell 88f6282 (Kirkwood).
>
> When a caracter is received on the UART while the kernel is printing
> the boot messages, as soon as the kernel configures the UART for
> receiving (after root filesystem mount), it gets stuck printing the
> following message repeatedly:
>
> serial8250: too much work for irq29
>
> Once stuck, the reception of another character allows the boot process
> to finish.
>
> From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
> interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
> register is never read to clear the interrupt.
The "too much work" message means serial8250_handle_irq() is returning 0,
ie., not handled. Which in turn means IIR indicates no interrupt is pending
(UART_IIR_NO_INT == 1).
Can you log the register values for LSR and IIR at both patch locations
in serial8250_do_startup()?
(I can get you a debug patch, if necessary. Let me know)
Regards,
Peter Hurley
> We are using the second UART multiplexed on mpps 15 and 16.
>
> Reverting this particular patch fixes the issue.
>
> We are seing the problem on a 3.18 kernel.
On 02/10/2015 12:34 AM, Peter Hurley wrote:
> The "too much work" message means serial8250_handle_irq() is returning 0,
> ie., not handled. Which in turn means IIR indicates no interrupt is pending
> (UART_IIR_NO_INT == 1).
The OMAP UART for instance have two possible TX-IRQ handling. The
default is to fire the interrupt once there is room for at least one
byte in the FIFO. I set the OMAP_UART_SCR_TX_EMPTY bit to get the same
behavior as the 8250 driver expects (interrupt while the FIFO is empty).
Without this bit set I've seen the message from time to time.
Sebastian
On 02/10/2015 12:34 AM, Peter Hurley wrote:
> Hi Nicolas,
>
> Thanks for the report.
>
[...]
>> When a caracter is received on the UART while the kernel is printing
>> the boot messages, as soon as the kernel configures the UART for
>> receiving (after root filesystem mount), it gets stuck printing the
>> following message repeatedly:
>>
>> serial8250: too much work for irq29
>>
>> Once stuck, the reception of another character allows the boot process
>> to finish.
>>
>> From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
>> interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
>> register is never read to clear the interrupt.
>
> The "too much work" message means serial8250_handle_irq() is returning 0,
> ie., not handled. Which in turn means IIR indicates no interrupt is pending
> (UART_IIR_NO_INT == 1).
>
> Can you log the register values for LSR and IIR at both patch locations
> in serial8250_do_startup()?
>
> (I can get you a debug patch, if necessary. Let me know)
Hi Peter,
Thanks for your reply.
Here is what I have when the issue is triggered:
[ 12.154877] lsr 0x60 / iir 0x01
[ 12.158071] lsr 0x60 / iir 0x01
[ 12.161438] serial8250: too much work for irq29
[ 12.165982] lsr 0x60 / iir 0x0c
[ 12.169354] serial8250: too much work for irq29
[ 12.173900] lsr 0x60 / iir 0x0c
(previous two messages are repeated and printk_ratelimited())
When the issue is not triggered:
[ 10.784871] lsr 0x60 / iir 0x01
[ 10.788066] lsr 0x60 / iir 0x01
[ 10.794734] VFS: Mounted root (nfs filesystem) readonly on device 0:13.
[ 10.801654] devtmpfs: mounted
[ 10.805169] Freeing unused kernel memory: 184K (807be000 - 807ec000)
(userland takes over after that)
I have also displayed the IIR and LSR registers when the "too much fork for
IRQ" condition is triggered.
In the serial8250_do_startup(), before the interrupt are unmasked at the end,
the IIR looks sane and UART_IIR_NO_INT bit is set. When stuck
serial8250_interrupt(), UART_IIR_NO_INT is cleared and the interrupt ID is set
to 0xc which is not handled by the kernel at this time (the Kirkwood datasheet
indicates that it is some kind of timeout condition from what I can gather).
Here is the corresponding debug patch, for reference (against a 3.19 kernel
this time):
diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_
index 11c6685..ed93741 100644
--- a/drivers/tty/serial/8250/8250_core.c
+++ b/drivers/tty/serial/8250/8250_core.c
@@ -1661,6 +1661,12 @@ static int exar_handle_irq(struct uart_port *port)
return ret;
}
+static inline void show_lsr_iir(struct uart_port *port)
+{
+ printk("lsr 0x%02x / iir 0x%02x\n", serial_port_in(port, UART_LSR),
+ serial_port_in(port, UART_IIR));
+}
+
/*
* This is the serial driver's interrupt routine.
*
@@ -1705,6 +1711,8 @@ static irqreturn_t serial8250_interrupt(int irq, void *dev
/* If we hit this, we're dead. */
printk_ratelimited(KERN_ERR
"serial8250: too much work for irq%d\n", irq);
+ if (printk_ratelimit())
+ show_lsr_iir(port);
break;
}
} while (l != end);
@@ -2107,6 +2115,7 @@ int serial8250_do_startup(struct uart_port *port)
/*
* Clear the interrupt registers.
*/
+ show_lsr_iir(port);
if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
serial_port_in(port, UART_RX);
serial_port_in(port, UART_IIR);
@@ -2269,6 +2278,7 @@ dont_test_tx_en:
* saved flags to avoid getting false values from polling
* routines or the previous session.
*/
+ show_lsr_iir(port);
if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
serial_port_in(port, UART_RX);
serial_port_in(port, UART_IIR);
Regards,
--
Nicolas Schichan
Freebox SAS
On 02/10/2015 07:04 AM, Nicolas Schichan wrote:
> On 02/10/2015 12:34 AM, Peter Hurley wrote:
>> Hi Nicolas,
>>
>> Thanks for the report.
>>
> [...]
>>> When a caracter is received on the UART while the kernel is printing
>>> the boot messages, as soon as the kernel configures the UART for
>>> receiving (after root filesystem mount), it gets stuck printing the
>>> following message repeatedly:
>>>
>>> serial8250: too much work for irq29
>>>
>>> Once stuck, the reception of another character allows the boot process
>>> to finish.
>>>
>>> From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
>>> interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
>>> register is never read to clear the interrupt.
>>
>> The "too much work" message means serial8250_handle_irq() is returning 0,
>> ie., not handled. Which in turn means IIR indicates no interrupt is pending
>> (UART_IIR_NO_INT == 1).
>>
>> Can you log the register values for LSR and IIR at both patch locations
>> in serial8250_do_startup()?
>>
>> (I can get you a debug patch, if necessary. Let me know)
>
> Hi Peter,
>
> Thanks for your reply.
>
> Here is what I have when the issue is triggered:
>
> [ 12.154877] lsr 0x60 / iir 0x01
> [ 12.158071] lsr 0x60 / iir 0x01
> [ 12.161438] serial8250: too much work for irq29
> [ 12.165982] lsr 0x60 / iir 0x0c
> [ 12.169354] serial8250: too much work for irq29
> [ 12.173900] lsr 0x60 / iir 0x0c
> (previous two messages are repeated and printk_ratelimited())
Thanks for this information; I see I was wrong about the cause of message.
I think what happens during startup is that on this silicon clearing
the rx fifo (by serial8250_clear_fifos()) clears data ready but not
the rx timeout condition which causes a spurious rx interrupt when
interrupts are enabled.
So caught between two broken UARTs: one that underflows its rx fifo because
of unsolicited rx reads and the other that generates spurious interrupt
without unsolicited rx reads.
> When the issue is not triggered:
>
> [ 10.784871] lsr 0x60 / iir 0x01
> [ 10.788066] lsr 0x60 / iir 0x01
> [ 10.794734] VFS: Mounted root (nfs filesystem) readonly on device 0:13.
> [ 10.801654] devtmpfs: mounted
> [ 10.805169] Freeing unused kernel memory: 184K (807be000 - 807ec000)
> (userland takes over after that)
>
> I have also displayed the IIR and LSR registers when the "too much fork for
> IRQ" condition is triggered.
>
> In the serial8250_do_startup(), before the interrupt are unmasked at the end,
> the IIR looks sane and UART_IIR_NO_INT bit is set. When stuck
> serial8250_interrupt(), UART_IIR_NO_INT is cleared and the interrupt ID is set
> to 0xc which is not handled by the kernel at this time (the Kirkwood datasheet
> indicates that it is some kind of timeout condition from what I can gather).
Yes, IIR == UART_IIR_RX_TIMEOUT is to used indicate that data is in the rx fifo
but has not reached the rx trigger level yet.
ATM, I'm not exactly sure if there is a safe way to clear the spurious interrupt
from the interrupt handler.
I'm fairly certain the only way to clear the rx timeout interrupt is to read
the rx fifo, but I think this would race with actual data arrival. IOW, there
might not be a way to determine if the data read is spurious or not.
Regards,
Peter Hurley
> Here is the corresponding debug patch, for reference (against a 3.19 kernel
> this time):
>
> diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_
> index 11c6685..ed93741 100644
> --- a/drivers/tty/serial/8250/8250_core.c
> +++ b/drivers/tty/serial/8250/8250_core.c
> @@ -1661,6 +1661,12 @@ static int exar_handle_irq(struct uart_port *port)
> return ret;
> }
>
> +static inline void show_lsr_iir(struct uart_port *port)
> +{
> + printk("lsr 0x%02x / iir 0x%02x\n", serial_port_in(port, UART_LSR),
> + serial_port_in(port, UART_IIR));
> +}
> +
> /*
> * This is the serial driver's interrupt routine.
> *
> @@ -1705,6 +1711,8 @@ static irqreturn_t serial8250_interrupt(int irq, void *dev
> /* If we hit this, we're dead. */
> printk_ratelimited(KERN_ERR
> "serial8250: too much work for irq%d\n", irq);
> + if (printk_ratelimit())
> + show_lsr_iir(port);
> break;
> }
> } while (l != end);
> @@ -2107,6 +2115,7 @@ int serial8250_do_startup(struct uart_port *port)
> /*
> * Clear the interrupt registers.
> */
> + show_lsr_iir(port);
> if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
> serial_port_in(port, UART_RX);
> serial_port_in(port, UART_IIR);
> @@ -2269,6 +2278,7 @@ dont_test_tx_en:
> * saved flags to avoid getting false values from polling
> * routines or the previous session.
> */
> + show_lsr_iir(port);
> if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
> serial_port_in(port, UART_RX);
> serial_port_in(port, UART_IIR);
>
> Regards,
>
On 02/10/2015 12:46 PM, Peter Hurley wrote:
> On 02/10/2015 07:04 AM, Nicolas Schichan wrote:
>> On 02/10/2015 12:34 AM, Peter Hurley wrote:
>>> Hi Nicolas,
>>>
>>> Thanks for the report.
>>>
>> [...]
>>>> When a caracter is received on the UART while the kernel is printing
>>>> the boot messages, as soon as the kernel configures the UART for
>>>> receiving (after root filesystem mount), it gets stuck printing the
>>>> following message repeatedly:
>>>>
>>>> serial8250: too much work for irq29
>>>>
>>>> Once stuck, the reception of another character allows the boot process
>>>> to finish.
>>>>
>>>> From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
>>>> interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
>>>> register is never read to clear the interrupt.
>>>
>>> The "too much work" message means serial8250_handle_irq() is returning 0,
>>> ie., not handled. Which in turn means IIR indicates no interrupt is pending
>>> (UART_IIR_NO_INT == 1).
>>>
>>> Can you log the register values for LSR and IIR at both patch locations
>>> in serial8250_do_startup()?
>>>
>>> (I can get you a debug patch, if necessary. Let me know)
>>
>> Hi Peter,
>>
>> Thanks for your reply.
>>
>> Here is what I have when the issue is triggered:
>>
>> [ 12.154877] lsr 0x60 / iir 0x01
>> [ 12.158071] lsr 0x60 / iir 0x01
>> [ 12.161438] serial8250: too much work for irq29
>> [ 12.165982] lsr 0x60 / iir 0x0c
>> [ 12.169354] serial8250: too much work for irq29
>> [ 12.173900] lsr 0x60 / iir 0x0c
>> (previous two messages are repeated and printk_ratelimited())
>
> Thanks for this information; I see I was wrong about the cause of message.
>
> I think what happens during startup is that on this silicon clearing
> the rx fifo (by serial8250_clear_fifos()) clears data ready but not
> the rx timeout condition which causes a spurious rx interrupt when
> interrupts are enabled.
>
> So caught between two broken UARTs: one that underflows its rx fifo because
> of unsolicited rx reads and the other that generates spurious interrupt
> without unsolicited rx reads.
>
>
>> When the issue is not triggered:
>>
>> [ 10.784871] lsr 0x60 / iir 0x01
>> [ 10.788066] lsr 0x60 / iir 0x01
>> [ 10.794734] VFS: Mounted root (nfs filesystem) readonly on device 0:13.
>> [ 10.801654] devtmpfs: mounted
>> [ 10.805169] Freeing unused kernel memory: 184K (807be000 - 807ec000)
>> (userland takes over after that)
>>
>> I have also displayed the IIR and LSR registers when the "too much fork for
>> IRQ" condition is triggered.
>>
>> In the serial8250_do_startup(), before the interrupt are unmasked at the end,
>> the IIR looks sane and UART_IIR_NO_INT bit is set. When stuck
>> serial8250_interrupt(), UART_IIR_NO_INT is cleared and the interrupt ID is set
>> to 0xc which is not handled by the kernel at this time (the Kirkwood datasheet
>> indicates that it is some kind of timeout condition from what I can gather).
>
> Yes, IIR == UART_IIR_RX_TIMEOUT is to used indicate that data is in the rx fifo
> but has not reached the rx trigger level yet.
>
> ATM, I'm not exactly sure if there is a safe way to clear the spurious interrupt
> from the interrupt handler.
>
> I'm fairly certain the only way to clear the rx timeout interrupt is to read
> the rx fifo, but I think this would race with actual data arrival. IOW, there
> might not be a way to determine if the data read is spurious or not.
Yep, I see no safe way to clear the spurious interrupt [1] and no idea how to
keep it from happening (other than via the unsolicited RX reads in
serial8250_do_startup).
Unfortunately, I think this means we'll have to revert Sebastian's commit:
commit 0aa525d11859c1a4d5b78fdc704148e2ae03ae13
Author: Sebastian Andrzej Siewior <[email protected]>
Date: Wed Sep 10 21:29:58 2014 +0200
tty: serial: 8250_core: read only RX if there is something in the FIFO
which just means OMAP3630 will be limited to using the omap_serial driver.
Regards,
Peter Hurley
[1] To clear the RX timeout interrupt requires reading the rx fifo even though
LSR[data ready] indicates no data. However, this could result in dropped data
if the data became available just before clearing the RX timeout. For example,
CPU | Device
|
irq handler (simplified) |
|
read IIR |
is interrupt? yes |
read LSR |
is data ready? no |
is IIR == Rx timeout? yes | new data arrives
| rx_fifo[0] = new data
| lsr[data ready] = 1
read RX and discard |
|
* Peter Hurley <[email protected]> [150211 12:05]:
> On 02/10/2015 12:46 PM, Peter Hurley wrote:
> > On 02/10/2015 07:04 AM, Nicolas Schichan wrote:
> >> On 02/10/2015 12:34 AM, Peter Hurley wrote:
> >>> Hi Nicolas,
> >>>
> >>> Thanks for the report.
> >>>
> >> [...]
> >>>> When a caracter is received on the UART while the kernel is printing
> >>>> the boot messages, as soon as the kernel configures the UART for
> >>>> receiving (after root filesystem mount), it gets stuck printing the
> >>>> following message repeatedly:
> >>>>
> >>>> serial8250: too much work for irq29
> >>>>
> >>>> Once stuck, the reception of another character allows the boot process
> >>>> to finish.
> >>>>
> >>>> From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
> >>>> interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
> >>>> register is never read to clear the interrupt.
> >>>
> >>> The "too much work" message means serial8250_handle_irq() is returning 0,
> >>> ie., not handled. Which in turn means IIR indicates no interrupt is pending
> >>> (UART_IIR_NO_INT == 1).
> >>>
> >>> Can you log the register values for LSR and IIR at both patch locations
> >>> in serial8250_do_startup()?
> >>>
> >>> (I can get you a debug patch, if necessary. Let me know)
> >>
> >> Hi Peter,
> >>
> >> Thanks for your reply.
> >>
> >> Here is what I have when the issue is triggered:
> >>
> >> [ 12.154877] lsr 0x60 / iir 0x01
> >> [ 12.158071] lsr 0x60 / iir 0x01
> >> [ 12.161438] serial8250: too much work for irq29
> >> [ 12.165982] lsr 0x60 / iir 0x0c
> >> [ 12.169354] serial8250: too much work for irq29
> >> [ 12.173900] lsr 0x60 / iir 0x0c
> >> (previous two messages are repeated and printk_ratelimited())
> >
> > Thanks for this information; I see I was wrong about the cause of message.
> >
> > I think what happens during startup is that on this silicon clearing
> > the rx fifo (by serial8250_clear_fifos()) clears data ready but not
> > the rx timeout condition which causes a spurious rx interrupt when
> > interrupts are enabled.
> >
> > So caught between two broken UARTs: one that underflows its rx fifo because
> > of unsolicited rx reads and the other that generates spurious interrupt
> > without unsolicited rx reads.
> >
> >
> >> When the issue is not triggered:
> >>
> >> [ 10.784871] lsr 0x60 / iir 0x01
> >> [ 10.788066] lsr 0x60 / iir 0x01
> >> [ 10.794734] VFS: Mounted root (nfs filesystem) readonly on device 0:13.
> >> [ 10.801654] devtmpfs: mounted
> >> [ 10.805169] Freeing unused kernel memory: 184K (807be000 - 807ec000)
> >> (userland takes over after that)
> >>
> >> I have also displayed the IIR and LSR registers when the "too much fork for
> >> IRQ" condition is triggered.
> >>
> >> In the serial8250_do_startup(), before the interrupt are unmasked at the end,
> >> the IIR looks sane and UART_IIR_NO_INT bit is set. When stuck
> >> serial8250_interrupt(), UART_IIR_NO_INT is cleared and the interrupt ID is set
> >> to 0xc which is not handled by the kernel at this time (the Kirkwood datasheet
> >> indicates that it is some kind of timeout condition from what I can gather).
> >
> > Yes, IIR == UART_IIR_RX_TIMEOUT is to used indicate that data is in the rx fifo
> > but has not reached the rx trigger level yet.
> >
> > ATM, I'm not exactly sure if there is a safe way to clear the spurious interrupt
> > from the interrupt handler.
> >
> > I'm fairly certain the only way to clear the rx timeout interrupt is to read
> > the rx fifo, but I think this would race with actual data arrival. IOW, there
> > might not be a way to determine if the data read is spurious or not.
>
> Yep, I see no safe way to clear the spurious interrupt [1] and no idea how to
> keep it from happening (other than via the unsolicited RX reads in
> serial8250_do_startup).
>
> Unfortunately, I think this means we'll have to revert Sebastian's commit:
>
> commit 0aa525d11859c1a4d5b78fdc704148e2ae03ae13
> Author: Sebastian Andrzej Siewior <[email protected]>
> Date: Wed Sep 10 21:29:58 2014 +0200
>
> tty: serial: 8250_core: read only RX if there is something in the FIFO
>
> which just means OMAP3630 will be limited to using the omap_serial driver.
Reverting makes sense to me if it has caused a regression. Maybe Sebastian
can update his patch to do this based on some quirk flag instead?
Regards,
Tony
> [1] To clear the RX timeout interrupt requires reading the rx fifo even though
> LSR[data ready] indicates no data. However, this could result in dropped data
> if the data became available just before clearing the RX timeout. For example,
>
> CPU | Device
> |
> irq handler (simplified) |
> |
> read IIR |
> is interrupt? yes |
> read LSR |
> is data ready? no |
> is IIR == Rx timeout? yes | new data arrives
> | rx_fifo[0] = new data
> | lsr[data ready] = 1
> read RX and discard |
> |
>
On 02/11/2015 03:03 PM, Tony Lindgren wrote:
> * Peter Hurley <[email protected]> [150211 12:05]:
>> On 02/10/2015 12:46 PM, Peter Hurley wrote:
>>> On 02/10/2015 07:04 AM, Nicolas Schichan wrote:
>>>> On 02/10/2015 12:34 AM, Peter Hurley wrote:
>>>>> Hi Nicolas,
>>>>>
>>>>> Thanks for the report.
>>>>>
>>>> [...]
>>>>>> When a caracter is received on the UART while the kernel is printing
>>>>>> the boot messages, as soon as the kernel configures the UART for
>>>>>> receiving (after root filesystem mount), it gets stuck printing the
>>>>>> following message repeatedly:
>>>>>>
>>>>>> serial8250: too much work for irq29
>>>>>>
>>>>>> Once stuck, the reception of another character allows the boot process
>>>>>> to finish.
>>>>>>
>>>>>> From what I can gather, when we hit that, the UART_IIR_NO_INT is 0 (so the
>>>>>> interrupt is raised), but the UART_LSR_DR bit is 0 as well so the UART_RX
>>>>>> register is never read to clear the interrupt.
>>>>>
>>>>> The "too much work" message means serial8250_handle_irq() is returning 0,
>>>>> ie., not handled. Which in turn means IIR indicates no interrupt is pending
>>>>> (UART_IIR_NO_INT == 1).
>>>>>
>>>>> Can you log the register values for LSR and IIR at both patch locations
>>>>> in serial8250_do_startup()?
>>>>>
>>>>> (I can get you a debug patch, if necessary. Let me know)
>>>>
>>>> Hi Peter,
>>>>
>>>> Thanks for your reply.
>>>>
>>>> Here is what I have when the issue is triggered:
>>>>
>>>> [ 12.154877] lsr 0x60 / iir 0x01
>>>> [ 12.158071] lsr 0x60 / iir 0x01
>>>> [ 12.161438] serial8250: too much work for irq29
>>>> [ 12.165982] lsr 0x60 / iir 0x0c
>>>> [ 12.169354] serial8250: too much work for irq29
>>>> [ 12.173900] lsr 0x60 / iir 0x0c
>>>> (previous two messages are repeated and printk_ratelimited())
>>>
>>> Thanks for this information; I see I was wrong about the cause of message.
>>>
>>> I think what happens during startup is that on this silicon clearing
>>> the rx fifo (by serial8250_clear_fifos()) clears data ready but not
>>> the rx timeout condition which causes a spurious rx interrupt when
>>> interrupts are enabled.
>>>
>>> So caught between two broken UARTs: one that underflows its rx fifo because
>>> of unsolicited rx reads and the other that generates spurious interrupt
>>> without unsolicited rx reads.
>>>
>>>
>>>> When the issue is not triggered:
>>>>
>>>> [ 10.784871] lsr 0x60 / iir 0x01
>>>> [ 10.788066] lsr 0x60 / iir 0x01
>>>> [ 10.794734] VFS: Mounted root (nfs filesystem) readonly on device 0:13.
>>>> [ 10.801654] devtmpfs: mounted
>>>> [ 10.805169] Freeing unused kernel memory: 184K (807be000 - 807ec000)
>>>> (userland takes over after that)
>>>>
>>>> I have also displayed the IIR and LSR registers when the "too much fork for
>>>> IRQ" condition is triggered.
>>>>
>>>> In the serial8250_do_startup(), before the interrupt are unmasked at the end,
>>>> the IIR looks sane and UART_IIR_NO_INT bit is set. When stuck
>>>> serial8250_interrupt(), UART_IIR_NO_INT is cleared and the interrupt ID is set
>>>> to 0xc which is not handled by the kernel at this time (the Kirkwood datasheet
>>>> indicates that it is some kind of timeout condition from what I can gather).
>>>
>>> Yes, IIR == UART_IIR_RX_TIMEOUT is to used indicate that data is in the rx fifo
>>> but has not reached the rx trigger level yet.
>>>
>>> ATM, I'm not exactly sure if there is a safe way to clear the spurious interrupt
>>> from the interrupt handler.
>>>
>>> I'm fairly certain the only way to clear the rx timeout interrupt is to read
>>> the rx fifo, but I think this would race with actual data arrival. IOW, there
>>> might not be a way to determine if the data read is spurious or not.
>>
>> Yep, I see no safe way to clear the spurious interrupt [1] and no idea how to
>> keep it from happening (other than via the unsolicited RX reads in
>> serial8250_do_startup).
>>
>> Unfortunately, I think this means we'll have to revert Sebastian's commit:
>>
>> commit 0aa525d11859c1a4d5b78fdc704148e2ae03ae13
>> Author: Sebastian Andrzej Siewior <[email protected]>
>> Date: Wed Sep 10 21:29:58 2014 +0200
>>
>> tty: serial: 8250_core: read only RX if there is something in the FIFO
>>
>> which just means OMAP3630 will be limited to using the omap_serial driver.
>
> Reverting makes sense to me if it has caused a regression. Maybe Sebastian
> can update his patch to do this based on some quirk flag instead?
That's fine with me. There's a 'bugs' field in struct 8250_uart_port and
UART_BUG_* defines in 8250/8250.h for that purpose.
Regards,
Peter Hurley
On 02/11/2015 09:42 PM, Peter Hurley wrote:
>> Reverting makes sense to me if it has caused a regression. Maybe Sebastian
>> can update his patch to do this based on some quirk flag instead?
>
> That's fine with me. There's a 'bugs' field in struct 8250_uart_port and
> UART_BUG_* defines in 8250/8250.h for that purpose.
Makes sense. Reading an empty FIFO does not look right. Maybe we should
do the bug flag the other way around? But I can do what I am told to so
if there is more fallout than just this Marvell UART I could come
around with a patch to the bug field for the older OMAP.
> Regards,
> Peter Hurley
Sebastian
On Thu, Feb 12, 2015 at 09:45:38AM +0100, Sebastian Andrzej Siewior wrote:
> On 02/11/2015 09:42 PM, Peter Hurley wrote:
>
> >> Reverting makes sense to me if it has caused a regression. Maybe Sebastian
> >> can update his patch to do this based on some quirk flag instead?
> >
> > That's fine with me. There's a 'bugs' field in struct 8250_uart_port and
> > UART_BUG_* defines in 8250/8250.h for that purpose.
>
> Makes sense. Reading an empty FIFO does not look right. Maybe we should
> do the bug flag the other way around? But I can do what I am told to so
> if there is more fallout than just this Marvell UART I could come
> around with a patch to the bug field for the older OMAP.
Reading the RX FIFO is something that goes back a long time in the 8250
driver, to the time when Ted Ts'o wrote the driver.
I would suggest that it remains there as the default (it was obviously
found to be necessary for x86 all those years ago when Linux was in
its infancy) and has survived for getting on 20 years without issue.
--
FTTC broadband for 0.8mile line: currently at 10.5Mbps down 400kbps up
according to speedtest.net.
On 02/12/2015 03:45 AM, Sebastian Andrzej Siewior wrote:
> On 02/11/2015 09:42 PM, Peter Hurley wrote:
>
>>> Reverting makes sense to me if it has caused a regression. Maybe Sebastian
>>> can update his patch to do this based on some quirk flag instead?
>>
>> That's fine with me. There's a 'bugs' field in struct 8250_uart_port and
>> UART_BUG_* defines in 8250/8250.h for that purpose.
>
> Makes sense. Reading an empty FIFO does not look right. Maybe we should
> do the bug flag the other way around? But I can do what I am told to so
> if there is more fallout than just this Marvell UART I could come
> around with a patch to the bug field for the older OMAP.
I agree with Russell on this; better to stick with the rx read that's been
running on 20 years of hardware.
That said, I don't think serial8250_do_startup() is really doing that much
for OMAP h/w startup; open-coding what omap_8250 really needs is probably
< 10 loc.
Regards,
Peter Hurley
* Peter Hurley | 2015-02-12 11:32:04 [-0500]:
>That said, I don't think serial8250_do_startup() is really doing that much
>for OMAP h/w startup; open-coding what omap_8250 really needs is probably
>< 10 loc.
10 loc? I have a few more. serial8250_clear_fifos(),
serial_link_irq_chain() aren't exported. serial8250_set_mctrl() can
maybe accessed via uart_ops->set_mctrl(). Maybe I'm not removing the
obvious not required code but here it looks better to just a BUG flag for
the Omap.
--- a/drivers/tty/serial/8250/8250_omap.c
+++ b/drivers/tty/serial/8250/8250_omap.c
@@ -557,9 +557,74 @@ static int omap_8250_startup(struct uart_port *port)
pm_runtime_get_sync(port->dev);
- ret = serial8250_do_startup(port);
- if (ret)
- goto err;
+ up->mcr = 0;
+
+ /*
+ * Clear the FIFO buffers and disable them.
+ * (they will be reenabled in set_termios())
+ */
+ serial8250_clear_fifos(up);
+
+ /*
+ * Clear the interrupt registers.
+ */
+ if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
+ serial_port_in(port, UART_RX);
+ serial_port_in(port, UART_IIR);
+ serial_port_in(port, UART_MSR);
+
+ retval = serial_link_irq_chain(up);
+ if (retval)
+ goto out;
+
+ /*
+ * Now, initialize the UART
+ */
+ serial_port_out(port, UART_LCR, UART_LCR_WLEN8);
+
+ spin_lock_irqsave(&port->lock, flags);
+ /*
+ * Most PC uarts need OUT2 raised to enable interrupts.
+ */
+ if (port->irq)
+ up->port.mctrl |= TIOCM_OUT2;
+
+ serial8250_set_mctrl(port, port->mctrl);
+
+ spin_unlock_irqrestore(&port->lock, flags);
+
+ /*
+ * Clear the interrupt registers again for luck, and clear the
+ * saved flags to avoid getting false values from polling
+ * routines or the previous session.
+ */
+ if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
+ serial_port_in(port, UART_RX);
+ serial_port_in(port, UART_IIR);
+ serial_port_in(port, UART_MSR);
+ up->lsr_saved_flags = 0;
+ up->msr_saved_flags = 0;
+
+ /*
+ * Request DMA channels for both RX and TX.
+ */
+ if (up->dma) {
+ retval = serial8250_request_dma(up);
+ if (retval) {
+ pr_warn_ratelimited("ttyS%d - failed to request DMA\n",
+ serial_index(port));
+ up->dma = NULL;
+ }
+ }
+
+ /*
+ * Finally, enable interrupts. Note: Modem status interrupts
+ * are set via set_termios(), which will be occurring imminently
+ * anyway, so we don't enable them here.
+ */
+ up->ier = UART_IER_RLSI | UART_IER_RDI;
+ serial_port_out(port, UART_IER, up->ier);
+
#ifdef CONFIG_PM
up->capabilities |= UART_CAP_RPM;
Sebastian
On 02/12/2015 02:23 PM, Sebastian Andrzej Siewior wrote:
> * Peter Hurley | 2015-02-12 11:32:04 [-0500]:
>
>> That said, I don't think serial8250_do_startup() is really doing that much
>> for OMAP h/w startup; open-coding what omap_8250 really needs is probably
>> < 10 loc.
>
> 10 loc? I have a few more.
:)
> serial8250_clear_fifos(),
> serial_link_irq_chain() aren't exported. serial8250_set_mctrl() can
> maybe accessed via uart_ops->set_mctrl(). Maybe I'm not removing the
> obvious not required code but here it looks better to just a BUG flag for
> the Omap.
Ok.
FWIW,
> --- a/drivers/tty/serial/8250/8250_omap.c
> +++ b/drivers/tty/serial/8250/8250_omap.c
> @@ -557,9 +557,74 @@ static int omap_8250_startup(struct uart_port *port)
>
> pm_runtime_get_sync(port->dev);
>
> - ret = serial8250_do_startup(port);
> - if (ret)
> - goto err;
> + up->mcr = 0;
> +
> + /*
> + * Clear the FIFO buffers and disable them.
> + * (they will be reenabled in set_termios())
> + */
> + serial8250_clear_fifos(up);
For omap this would just be:
serial_out(up, UART_FCR, UART_FCR_CLEAR_RCVR | UART_FCR_CLEAR_XMIT);
In any event, the fifo enable/disable is probably not happening since
FIFO_EN is ignored unless the divisor == 0.
> +
> + /*
> + * Clear the interrupt registers.
> + */
> + if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
> + serial_port_in(port, UART_RX);
> + serial_port_in(port, UART_IIR);
> + serial_port_in(port, UART_MSR);
> +
> + retval = serial_link_irq_chain(up);
> + if (retval)
> + goto out;
omap doesn't really need the legacy irq chain handling; this could just be
request_irq().
In the 8250 split I'll be posting soon, all the irq chaining and
polling-via-timeout workarounds stays in the universal/legacy driver so
other 8250 drivers can opt-out.
> +
> + /*
> + * Now, initialize the UART
> + */
> + serial_port_out(port, UART_LCR, UART_LCR_WLEN8);
> +
--- >% ---
> + spin_lock_irqsave(&port->lock, flags);
> + /*
> + * Most PC uarts need OUT2 raised to enable interrupts.
> + */
> + if (port->irq)
> + up->port.mctrl |= TIOCM_OUT2;
> +
> + serial8250_set_mctrl(port, port->mctrl);
> +
> + spin_unlock_irqrestore(&port->lock, flags);
> +
None of this is required because there is no OUT2 on omap.
---------
--- >% ----
> + /*
> + * Clear the interrupt registers again for luck, and clear the
> + * saved flags to avoid getting false values from polling
> + * routines or the previous session.
> + */
> + if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
> + serial_port_in(port, UART_RX);
> + serial_port_in(port, UART_IIR);
> + serial_port_in(port, UART_MSR);
None of this is required because none of the probing is taking place.
------------
> + up->lsr_saved_flags = 0;
> + up->msr_saved_flags = 0;
> +
> + /*
> + * Request DMA channels for both RX and TX.
> + */
> + if (up->dma) {
> + retval = serial8250_request_dma(up);
> + if (retval) {
> + pr_warn_ratelimited("ttyS%d - failed to request DMA\n",
> + serial_index(port));
> + up->dma = NULL;
> + }
> + }
> +
> + /*
> + * Finally, enable interrupts. Note: Modem status interrupts
> + * are set via set_termios(), which will be occurring imminently
> + * anyway, so we don't enable them here.
> + */
> + up->ier = UART_IER_RLSI | UART_IER_RDI;
> + serial_port_out(port, UART_IER, up->ier);
> +
>
> #ifdef CONFIG_PM
> up->capabilities |= UART_CAP_RPM;
>
> Sebastian
>
On 02/12/2015 08:55 PM, Peter Hurley wrote:
> On 02/12/2015 02:23 PM, Sebastian Andrzej Siewior wrote:
>> * Peter Hurley | 2015-02-12 11:32:04 [-0500]:
>>
>>> That said, I don't think serial8250_do_startup() is really doing that much
>>> for OMAP h/w startup; open-coding what omap_8250 really needs is probably
>>> < 10 loc.
>>
>> 10 loc? I have a few more.
>
> :)
>
>> serial8250_clear_fifos(),
>> serial_link_irq_chain() aren't exported. serial8250_set_mctrl() can
>> maybe accessed via uart_ops->set_mctrl(). Maybe I'm not removing the
>> obvious not required code but here it looks better to just a BUG flag for
>> the Omap.
>
> Ok.
Okay. I will try to post something tomorrow.
>> --- a/drivers/tty/serial/8250/8250_omap.c
>> +++ b/drivers/tty/serial/8250/8250_omap.c
>> +
>> + /*
>> + * Clear the interrupt registers.
>> + */
>> + if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
>> + serial_port_in(port, UART_RX);
>> + serial_port_in(port, UART_IIR);
>> + serial_port_in(port, UART_MSR);
>> +
>> + retval = serial_link_irq_chain(up);
>> + if (retval)
>> + goto out;
>
> omap doesn't really need the legacy irq chain handling; this could just be
> request_irq().
>
> In the 8250 split I'll be posting soon, all the irq chaining and
> polling-via-timeout workarounds stays in the universal/legacy driver so
> other 8250 drivers can opt-out.
Ah. This sounds interesting.
Sebastian
Something like this maybe?
Subject: [PATCH] serial: 8250: skip empty RX-read only on OMAP
The conditional RX-FIFO read seems to cause spurious interrupts and we
see just:
|serial8250: too much work for irq29
The previous behaviour was "default" for decades and Marvell's 88f6282 SoC
might not be the only that relies on it. Therefore this patch moves this
special OMAP3630 behaviour befind a BUG field.
Fixes: 0aa525d11859 ("tty: serial: 8250_core: read only RX if there is
something in the FIFO")
Reported-By: Nicolas Schichan <[email protected]>
Debuged-By: Peter Hurley <[email protected]>
Signed-off-by: Sebastian Andrzej Siewior <[email protected]>
---
drivers/tty/serial/8250/8250.h | 1 +
drivers/tty/serial/8250/8250_core.c | 10 ++++++++--
drivers/tty/serial/8250/8250_omap.c | 1 +
3 files changed, 10 insertions(+), 2 deletions(-)
diff --git a/drivers/tty/serial/8250/8250.h b/drivers/tty/serial/8250/8250.h
index b00836851061..b6899fd69c7e 100644
--- a/drivers/tty/serial/8250/8250.h
+++ b/drivers/tty/serial/8250/8250.h
@@ -84,6 +84,7 @@ struct serial8250_config {
#define UART_BUG_NOMSR (1 << 2) /* UART has buggy MSR status bits (Au1x00) */
#define UART_BUG_THRE (1 << 3) /* UART has buggy THRE reassertion */
#define UART_BUG_PARITY (1 << 4) /* UART mishandles parity if FIFO enabled */
+#define UART_BUG_RXEMPT (1 << 5) /* UART can not read empty FIFO */
#define PROBE_RSA (1 << 0)
#define PROBE_ANY (~0)
diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
index e3b9570a1eff..185386178023 100644
--- a/drivers/tty/serial/8250/8250_core.c
+++ b/drivers/tty/serial/8250/8250_core.c
@@ -2137,8 +2137,13 @@ int serial8250_do_startup(struct uart_port *port)
/*
* Clear the interrupt registers.
+ *
+ * This (and later) unsolicied read of the RX FIFO seems to clear the
+ * RX timeout condition which otherwise generates spurious interrupt.
+ * This behaviour has been observed on Marvell's 88f6282 SoC.
*/
- if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
+ if (!(up->bugs & UART_BUG_RXEMPT) ||
+ (serial_port_in(port, UART_LSR) & UART_LSR_DR))
serial_port_in(port, UART_RX);
serial_port_in(port, UART_IIR);
serial_port_in(port, UART_MSR);
@@ -2300,7 +2305,8 @@ int serial8250_do_startup(struct uart_port *port)
* saved flags to avoid getting false values from polling
* routines or the previous session.
*/
- if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
+ if (!(up->bugs & UART_BUG_RXEMPT) ||
+ (serial_port_in(port, UART_LSR) & UART_LSR_DR))
serial_port_in(port, UART_RX);
serial_port_in(port, UART_IIR);
serial_port_in(port, UART_MSR);
diff --git a/drivers/tty/serial/8250/8250_omap.c b/drivers/tty/serial/8250/8250_omap.c
index fe6d2e51da09..a7ead2fa6a32 100644
--- a/drivers/tty/serial/8250/8250_omap.c
+++ b/drivers/tty/serial/8250/8250_omap.c
@@ -1021,6 +1021,7 @@ static int omap8250_probe(struct platform_device *pdev)
up.port.fifosize = 64;
up.tx_loadsz = 64;
up.capabilities = UART_CAP_FIFO;
+ up.bugs = UART_BUG_RXEMPT;
#ifdef CONFIG_PM
/*
* Runtime PM is mostly transparent. However to do it right we need to a
--
2.1.4
On Fri, Feb 13, 2015 at 07:51:16PM +0100, Sebastian Andrzej Siewior wrote:
> Something like this maybe?
My personal feeling is that as 0aa525d11859 was wrong, it should be
reverted and this should be another attempt to fix the problem. In
other words, there should be two patches, one a revert of the previously
known bad commit and this one having another go at it.
I feel that would be a better approach, since then we don't end up
with this change building on a previously know buggy change. It
would also make the changes to this solution from the previous,
known-to-work-for-decades code more obvious.
--
FTTC broadband for 0.8mile line: currently at 10.5Mbps down 400kbps up
according to speedtest.net.
This reverts commit 0aa525d11859c1a4d5b78fdc704148e2ae03ae13.
The conditional RX-FIFO read seems to cause spurious interrupts and we
see just:
|serial8250: too much work for irq29
The previous behaviour was "default" for decades and Marvell's 88f6282 SoC
might not be the only that relies on it. Therefore the Omap fix is
reverted for now.
Fixes: 0aa525d11859 ("tty: serial: 8250_core: read only RX if there is
something in the FIFO")
Reported-By: Nicolas Schichan <[email protected]>
Debuged-By: Peter Hurley <[email protected]>
Signed-off-by: Sebastian Andrzej Siewior <[email protected]>
---
* Russell King - ARM Linux | 2015-02-13 23:15:19 [+0000]:
>On Fri, Feb 13, 2015 at 07:51:16PM +0100, Sebastian Andrzej Siewior wrote:
>> Something like this maybe?
>
>My personal feeling is that as 0aa525d11859 was wrong, it should be
>reverted and this should be another attempt to fix the problem. In
>other words, there should be two patches, one a revert of the previously
>known bad commit and this one having another go at it.
>
>I feel that would be a better approach, since then we don't end up
>with this change building on a previously know buggy change. It
>would also make the changes to this solution from the previous,
>known-to-work-for-decades code more obvious.
Okay. So here is the revert.
drivers/tty/serial/8250/8250_core.c | 11 +++++------
1 file changed, 5 insertions(+), 6 deletions(-)
diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
index e3b9570a1eff..deae122c9c4b 100644
--- a/drivers/tty/serial/8250/8250_core.c
+++ b/drivers/tty/serial/8250/8250_core.c
@@ -2138,8 +2138,8 @@ int serial8250_do_startup(struct uart_port *port)
/*
* Clear the interrupt registers.
*/
- if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
- serial_port_in(port, UART_RX);
+ serial_port_in(port, UART_LSR);
+ serial_port_in(port, UART_RX);
serial_port_in(port, UART_IIR);
serial_port_in(port, UART_MSR);
@@ -2300,8 +2300,8 @@ int serial8250_do_startup(struct uart_port *port)
* saved flags to avoid getting false values from polling
* routines or the previous session.
*/
- if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
- serial_port_in(port, UART_RX);
+ serial_port_in(port, UART_LSR);
+ serial_port_in(port, UART_RX);
serial_port_in(port, UART_IIR);
serial_port_in(port, UART_MSR);
up->lsr_saved_flags = 0;
@@ -2394,8 +2394,7 @@ void serial8250_do_shutdown(struct uart_port *port)
* Read data port to reset things, and then unlink from
* the IRQ chain.
*/
- if (serial_port_in(port, UART_LSR) & UART_LSR_DR)
- serial_port_in(port, UART_RX);
+ serial_port_in(port, UART_RX);
serial8250_rpm_put(up);
del_timer_sync(&up->timer);
--
2.1.4
Hi Sebastian,
* Sebastian Andrzej Siewior <[email protected]> [150215 09:35]:
> This reverts commit 0aa525d11859c1a4d5b78fdc704148e2ae03ae13.
>
> The conditional RX-FIFO read seems to cause spurious interrupts and we
> see just:
> |serial8250: too much work for irq29
>
> The previous behaviour was "default" for decades and Marvell's 88f6282 SoC
> might not be the only that relies on it. Therefore the Omap fix is
> reverted for now.
>
> Fixes: 0aa525d11859 ("tty: serial: 8250_core: read only RX if there is
> something in the FIFO")
> Reported-By: Nicolas Schichan <[email protected]>
> Debuged-By: Peter Hurley <[email protected]>
> Signed-off-by: Sebastian Andrzej Siewior <[email protected]>
> ---
> * Russell King - ARM Linux | 2015-02-13 23:15:19 [+0000]:
>
> >On Fri, Feb 13, 2015 at 07:51:16PM +0100, Sebastian Andrzej Siewior wrote:
> >> Something like this maybe?
> >
> >My personal feeling is that as 0aa525d11859 was wrong, it should be
> >reverted and this should be another attempt to fix the problem. In
> >other words, there should be two patches, one a revert of the previously
> >known bad commit and this one having another go at it.
> >
> >I feel that would be a better approach, since then we don't end up
> >with this change building on a previously know buggy change. It
> >would also make the changes to this solution from the previous,
> >known-to-work-for-decades code more obvious.
>
> Okay. So here is the revert.
After the revert looks like now we get the following on omaps with
8250.. Do you have a fix available somewhere on top of your revert?
Unhandled fault: external abort on non-linefetch (0x1028) at 0xfa06a000
...
[<c04217e8>] (mem_serial_in) from [<c0425480>] (serial8250_do_startup+0xe4/0x694)
[<c0425480>] (serial8250_do_startup) from [<c0427e48>] (omap_8250_startup+0x70/0x144)
[<c0427e48>] (omap_8250_startup) from [<c0425a54>] (serial8250_startup+0x24/0x30)
[<c0425a54>] (serial8250_startup) from [<c04208e4>] (uart_startup.part.14+0x8c/0x1a0)
[<c04208e4>] (uart_startup.part.14) from [<c0420fec>] (uart_open+0xd8/0x134)
[<c0420fec>] (uart_open) from [<c0403e50>] (tty_open+0xdc/0x5e0)
[<c0403e50>] (tty_open) from [<c018f008>] (chrdev_open+0xac/0x188)
...
Regards,
Tony