diff mbox series

serial: sh-sci: Initialize spinlock for uart console

Message ID 1593618100-2151-1-git-send-email-prabhakar.mahadev-lad.rj@bp.renesas.com (mailing list archive)
State Mainlined
Commit f38278e9b810b06aff2981d505267be984423ba3
Delegated to: Geert Uytterhoeven
Headers show
Series serial: sh-sci: Initialize spinlock for uart console | expand

Commit Message

Lad Prabhakar July 1, 2020, 3:41 p.m. UTC
serial core expects the spinlock to be initialized by the controller
driver for serial console, this patch makes sure the spinlock is
initialized, fixing the below issue:

[    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
[    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
[    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
[    0.865968] Call trace:
[    0.865979]  dump_backtrace+0x0/0x1d8
[    0.865985]  show_stack+0x14/0x20
[    0.865996]  dump_stack+0xe8/0x130
[    0.866006]  spin_dump+0x6c/0x88
[    0.866012]  do_raw_spin_lock+0xb0/0xf8
[    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
[    0.866032]  uart_add_one_port+0x3a4/0x4e0
[    0.866039]  sci_probe+0x504/0x7c8
[    0.866048]  platform_drv_probe+0x50/0xa0
[    0.866059]  really_probe+0xdc/0x330
[    0.866066]  driver_probe_device+0x58/0xb8
[    0.866072]  device_driver_attach+0x6c/0x90
[    0.866078]  __driver_attach+0x88/0xd0
[    0.866085]  bus_for_each_dev+0x74/0xc8
[    0.866091]  driver_attach+0x20/0x28
[    0.866098]  bus_add_driver+0x14c/0x1f8
[    0.866104]  driver_register+0x60/0x110
[    0.866109]  __platform_driver_register+0x40/0x48
[    0.866119]  sci_init+0x2c/0x34
[    0.866127]  do_one_initcall+0x88/0x428
[    0.866137]  kernel_init_freeable+0x2c0/0x328
[    0.866143]  kernel_init+0x10/0x108
[    0.866150]  ret_from_fork+0x10/0x18

Signed-off-by: Lad Prabhakar <prabhakar.mahadev-lad.rj@bp.renesas.com>
Reviewed-by: Biju Das <biju.das.jz@bp.renesas.com>
---
 drivers/tty/serial/sh-sci.c | 3 +++
 1 file changed, 3 insertions(+)

Comments

Greg Kroah-Hartman July 1, 2020, 4:40 p.m. UTC | #1
On Wed, Jul 01, 2020 at 04:41:40PM +0100, Lad Prabhakar wrote:
> serial core expects the spinlock to be initialized by the controller
> driver for serial console, this patch makes sure the spinlock is
> initialized, fixing the below issue:
> 
> [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> [    0.865968] Call trace:
> [    0.865979]  dump_backtrace+0x0/0x1d8
> [    0.865985]  show_stack+0x14/0x20
> [    0.865996]  dump_stack+0xe8/0x130
> [    0.866006]  spin_dump+0x6c/0x88
> [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> [    0.866039]  sci_probe+0x504/0x7c8
> [    0.866048]  platform_drv_probe+0x50/0xa0
> [    0.866059]  really_probe+0xdc/0x330
> [    0.866066]  driver_probe_device+0x58/0xb8
> [    0.866072]  device_driver_attach+0x6c/0x90
> [    0.866078]  __driver_attach+0x88/0xd0
> [    0.866085]  bus_for_each_dev+0x74/0xc8
> [    0.866091]  driver_attach+0x20/0x28
> [    0.866098]  bus_add_driver+0x14c/0x1f8
> [    0.866104]  driver_register+0x60/0x110
> [    0.866109]  __platform_driver_register+0x40/0x48
> [    0.866119]  sci_init+0x2c/0x34
> [    0.866127]  do_one_initcall+0x88/0x428
> [    0.866137]  kernel_init_freeable+0x2c0/0x328
> [    0.866143]  kernel_init+0x10/0x108
> [    0.866150]  ret_from_fork+0x10/0x18
> 
> Signed-off-by: Lad Prabhakar <prabhakar.mahadev-lad.rj@bp.renesas.com>
> Reviewed-by: Biju Das <biju.das.jz@bp.renesas.com>

This should be backported to older kernels too, right?  How far back?

thanks,

greg k-h
Geert Uytterhoeven July 1, 2020, 5:17 p.m. UTC | #2
Hi Prabhakar,

On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
<prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> serial core expects the spinlock to be initialized by the controller
> driver for serial console, this patch makes sure the spinlock is
> initialized, fixing the below issue:
>
> [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> [    0.865968] Call trace:
> [    0.865979]  dump_backtrace+0x0/0x1d8
> [    0.865985]  show_stack+0x14/0x20
> [    0.865996]  dump_stack+0xe8/0x130
> [    0.866006]  spin_dump+0x6c/0x88
> [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> [    0.866039]  sci_probe+0x504/0x7c8
> [    0.866048]  platform_drv_probe+0x50/0xa0
> [    0.866059]  really_probe+0xdc/0x330
> [    0.866066]  driver_probe_device+0x58/0xb8
> [    0.866072]  device_driver_attach+0x6c/0x90
> [    0.866078]  __driver_attach+0x88/0xd0
> [    0.866085]  bus_for_each_dev+0x74/0xc8
> [    0.866091]  driver_attach+0x20/0x28
> [    0.866098]  bus_add_driver+0x14c/0x1f8
> [    0.866104]  driver_register+0x60/0x110
> [    0.866109]  __platform_driver_register+0x40/0x48
> [    0.866119]  sci_init+0x2c/0x34
> [    0.866127]  do_one_initcall+0x88/0x428
> [    0.866137]  kernel_init_freeable+0x2c0/0x328
> [    0.866143]  kernel_init+0x10/0x108
> [    0.866150]  ret_from_fork+0x10/0x18

Interesting...

How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
I'm wondering why haven't we seen this before...

Thanks!

Gr{oetje,eeting}s,

                        Geert
Geert Uytterhoeven July 2, 2020, 9:23 a.m. UTC | #3
Hi Prabhakar,

On Wed, Jul 1, 2020 at 7:28 PM Lad, Prabhakar
<prabhakar.csengg@gmail.com> wrote:
> On Wed, Jul 1, 2020 at 6:17 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
> > <prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> > > serial core expects the spinlock to be initialized by the controller
> > > driver for serial console, this patch makes sure the spinlock is
> > > initialized, fixing the below issue:
> > >
> > > [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> > > [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > > [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> > > [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> > > [    0.865968] Call trace:
> > > [    0.865979]  dump_backtrace+0x0/0x1d8
> > > [    0.865985]  show_stack+0x14/0x20
> > > [    0.865996]  dump_stack+0xe8/0x130
> > > [    0.866006]  spin_dump+0x6c/0x88
> > > [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> > > [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> > > [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> > > [    0.866039]  sci_probe+0x504/0x7c8
> > > [    0.866048]  platform_drv_probe+0x50/0xa0
> > > [    0.866059]  really_probe+0xdc/0x330
> > > [    0.866066]  driver_probe_device+0x58/0xb8
> > > [    0.866072]  device_driver_attach+0x6c/0x90
> > > [    0.866078]  __driver_attach+0x88/0xd0
> > > [    0.866085]  bus_for_each_dev+0x74/0xc8
> > > [    0.866091]  driver_attach+0x20/0x28
> > > [    0.866098]  bus_add_driver+0x14c/0x1f8
> > > [    0.866104]  driver_register+0x60/0x110
> > > [    0.866109]  __platform_driver_register+0x40/0x48
> > > [    0.866119]  sci_init+0x2c/0x34
> > > [    0.866127]  do_one_initcall+0x88/0x428
> > > [    0.866137]  kernel_init_freeable+0x2c0/0x328
> > > [    0.866143]  kernel_init+0x10/0x108
> > > [    0.866150]  ret_from_fork+0x10/0x18
> >
> > Interesting...
> >
> > How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
> > I'm wondering why haven't we seen this before...
> >
> I have attached .config for your reference.

Thank you!

I gave it a try with v5.8-rc1 on Salvator-XS with R-Car H3 ES2.0.
However, I couldn't reproduce the issue.
Does it happen on that specific board only? Is this serdev-related?
Note that I had to disable CONFIG_EXTRA_FIRMWARE, as I don't have the
firmware blobs it referenced.  Do I need them to trigger the issue?
As the .config has a few non-upstream options, do you have any patches
applied that might impact the issue?

Thanks again!

Gr{oetje,eeting}s,

                        Geert
Lad, Prabhakar July 2, 2020, 10:49 a.m. UTC | #4
Hi Geert,

On Thu, Jul 2, 2020 at 10:23 AM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
>
> Hi Prabhakar,
>
> On Wed, Jul 1, 2020 at 7:28 PM Lad, Prabhakar
> <prabhakar.csengg@gmail.com> wrote:
> > On Wed, Jul 1, 2020 at 6:17 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
> > > <prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> > > > serial core expects the spinlock to be initialized by the controller
> > > > driver for serial console, this patch makes sure the spinlock is
> > > > initialized, fixing the below issue:
> > > >
> > > > [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> > > > [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > > > [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> > > > [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> > > > [    0.865968] Call trace:
> > > > [    0.865979]  dump_backtrace+0x0/0x1d8
> > > > [    0.865985]  show_stack+0x14/0x20
> > > > [    0.865996]  dump_stack+0xe8/0x130
> > > > [    0.866006]  spin_dump+0x6c/0x88
> > > > [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> > > > [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> > > > [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> > > > [    0.866039]  sci_probe+0x504/0x7c8
> > > > [    0.866048]  platform_drv_probe+0x50/0xa0
> > > > [    0.866059]  really_probe+0xdc/0x330
> > > > [    0.866066]  driver_probe_device+0x58/0xb8
> > > > [    0.866072]  device_driver_attach+0x6c/0x90
> > > > [    0.866078]  __driver_attach+0x88/0xd0
> > > > [    0.866085]  bus_for_each_dev+0x74/0xc8
> > > > [    0.866091]  driver_attach+0x20/0x28
> > > > [    0.866098]  bus_add_driver+0x14c/0x1f8
> > > > [    0.866104]  driver_register+0x60/0x110
> > > > [    0.866109]  __platform_driver_register+0x40/0x48
> > > > [    0.866119]  sci_init+0x2c/0x34
> > > > [    0.866127]  do_one_initcall+0x88/0x428
> > > > [    0.866137]  kernel_init_freeable+0x2c0/0x328
> > > > [    0.866143]  kernel_init+0x10/0x108
> > > > [    0.866150]  ret_from_fork+0x10/0x18
> > >
> > > Interesting...
> > >
> > > How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
> > > I'm wondering why haven't we seen this before...
> > >
> > I have attached .config for your reference.
>
> Thank you!
>
> I gave it a try with v5.8-rc1 on Salvator-XS with R-Car H3 ES2.0.
> However, I couldn't reproduce the issue.
> Does it happen on that specific board only? Is this serdev-related?
> Note that I had to disable CONFIG_EXTRA_FIRMWARE, as I don't have the
> firmware blobs it referenced.  Do I need them to trigger the issue?
> As the .config has a few non-upstream options, do you have any patches
> applied that might impact the issue?
>
Can't think of any patches that might cause an issue, most of it are
just the DT's and config additions. Nor do firmware blobs should
affect it. I'll try and reproduce it on M3N and get back to you.

Cheers,
--Prabhakar

> Thanks again!
>
> Gr{oetje,eeting}s,
>
>                         Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
>                                 -- Linus Torvalds
Geert Uytterhoeven July 2, 2020, 12:52 p.m. UTC | #5
Hi Prabhakar,

On Thu, Jul 2, 2020 at 1:42 PM Lad, Prabhakar
<prabhakar.csengg@gmail.com> wrote:
> On Thu, Jul 2, 2020 at 11:49 AM Lad, Prabhakar
> <prabhakar.csengg@gmail.com> wrote:
> > On Thu, Jul 2, 2020 at 10:23 AM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > On Wed, Jul 1, 2020 at 7:28 PM Lad, Prabhakar
> > > <prabhakar.csengg@gmail.com> wrote:
> > > > On Wed, Jul 1, 2020 at 6:17 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > > On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
> > > > > <prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> > > > > > serial core expects the spinlock to be initialized by the controller
> > > > > > driver for serial console, this patch makes sure the spinlock is
> > > > > > initialized, fixing the below issue:
> > > > > >
> > > > > > [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> > > > > > [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > > > > > [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> > > > > > [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> > > > > > [    0.865968] Call trace:
> > > > > > [    0.865979]  dump_backtrace+0x0/0x1d8
> > > > > > [    0.865985]  show_stack+0x14/0x20
> > > > > > [    0.865996]  dump_stack+0xe8/0x130
> > > > > > [    0.866006]  spin_dump+0x6c/0x88
> > > > > > [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> > > > > > [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> > > > > > [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> > > > > > [    0.866039]  sci_probe+0x504/0x7c8
> > > > > > [    0.866048]  platform_drv_probe+0x50/0xa0
> > > > > > [    0.866059]  really_probe+0xdc/0x330
> > > > > > [    0.866066]  driver_probe_device+0x58/0xb8
> > > > > > [    0.866072]  device_driver_attach+0x6c/0x90
> > > > > > [    0.866078]  __driver_attach+0x88/0xd0
> > > > > > [    0.866085]  bus_for_each_dev+0x74/0xc8
> > > > > > [    0.866091]  driver_attach+0x20/0x28
> > > > > > [    0.866098]  bus_add_driver+0x14c/0x1f8
> > > > > > [    0.866104]  driver_register+0x60/0x110
> > > > > > [    0.866109]  __platform_driver_register+0x40/0x48
> > > > > > [    0.866119]  sci_init+0x2c/0x34
> > > > > > [    0.866127]  do_one_initcall+0x88/0x428
> > > > > > [    0.866137]  kernel_init_freeable+0x2c0/0x328
> > > > > > [    0.866143]  kernel_init+0x10/0x108
> > > > > > [    0.866150]  ret_from_fork+0x10/0x18
> > > > >
> > > > > Interesting...
> > > > >
> > > > > How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
> > > > > I'm wondering why haven't we seen this before...
> > > > >
> > > > I have attached .config for your reference.
> > >
> > > Thank you!
> > >
> > > I gave it a try with v5.8-rc1 on Salvator-XS with R-Car H3 ES2.0.
> > > However, I couldn't reproduce the issue.
> > > Does it happen on that specific board only? Is this serdev-related?
> > > Note that I had to disable CONFIG_EXTRA_FIRMWARE, as I don't have the
> > > firmware blobs it referenced.  Do I need them to trigger the issue?
> > > As the .config has a few non-upstream options, do you have any patches
> > > applied that might impact the issue?
> > >
> > Can't think of any patches that might cause an issue, most of it are
> > just the DT's and config additions. Nor do firmware blobs should
> > affect it. I'll try and reproduce it on M3N and get back to you.
> >
> I did manage to replicate this issue on M3N (v5.8-rc3 tag with no
> modifications), I have attached the config file and also the boot log
> without this patch for your reference, after applying this patch I no
> more see this issue.

Thanks, the boot log finally gave me a clue, and allowed me to reproduce.
The issue happens only when adding:

    console=ttySC0,115200n8

to the kernel command line.  Which is something we never did on R-Car
Gen3, as the console= parameter had been deprecated by chosen/stdout-path
on DT systems long before.

As we did use console= before on arm32, and drivers/tty/serial/sh-sci.c
never called spinlock_init(), I'm wondering if this spinlock bug is
actually a regression in serial_core.c?

Gr{oetje,eeting}s,

                        Geert
Lad, Prabhakar July 2, 2020, 2:05 p.m. UTC | #6
Hi Geert,

On Thu, Jul 2, 2020 at 1:52 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
>
> Hi Prabhakar,
>
> On Thu, Jul 2, 2020 at 1:42 PM Lad, Prabhakar
> <prabhakar.csengg@gmail.com> wrote:
> > On Thu, Jul 2, 2020 at 11:49 AM Lad, Prabhakar
> > <prabhakar.csengg@gmail.com> wrote:
> > > On Thu, Jul 2, 2020 at 10:23 AM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > On Wed, Jul 1, 2020 at 7:28 PM Lad, Prabhakar
> > > > <prabhakar.csengg@gmail.com> wrote:
> > > > > On Wed, Jul 1, 2020 at 6:17 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > > > On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
> > > > > > <prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> > > > > > > serial core expects the spinlock to be initialized by the controller
> > > > > > > driver for serial console, this patch makes sure the spinlock is
> > > > > > > initialized, fixing the below issue:
> > > > > > >
> > > > > > > [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> > > > > > > [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > > > > > > [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> > > > > > > [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> > > > > > > [    0.865968] Call trace:
> > > > > > > [    0.865979]  dump_backtrace+0x0/0x1d8
> > > > > > > [    0.865985]  show_stack+0x14/0x20
> > > > > > > [    0.865996]  dump_stack+0xe8/0x130
> > > > > > > [    0.866006]  spin_dump+0x6c/0x88
> > > > > > > [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> > > > > > > [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> > > > > > > [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> > > > > > > [    0.866039]  sci_probe+0x504/0x7c8
> > > > > > > [    0.866048]  platform_drv_probe+0x50/0xa0
> > > > > > > [    0.866059]  really_probe+0xdc/0x330
> > > > > > > [    0.866066]  driver_probe_device+0x58/0xb8
> > > > > > > [    0.866072]  device_driver_attach+0x6c/0x90
> > > > > > > [    0.866078]  __driver_attach+0x88/0xd0
> > > > > > > [    0.866085]  bus_for_each_dev+0x74/0xc8
> > > > > > > [    0.866091]  driver_attach+0x20/0x28
> > > > > > > [    0.866098]  bus_add_driver+0x14c/0x1f8
> > > > > > > [    0.866104]  driver_register+0x60/0x110
> > > > > > > [    0.866109]  __platform_driver_register+0x40/0x48
> > > > > > > [    0.866119]  sci_init+0x2c/0x34
> > > > > > > [    0.866127]  do_one_initcall+0x88/0x428
> > > > > > > [    0.866137]  kernel_init_freeable+0x2c0/0x328
> > > > > > > [    0.866143]  kernel_init+0x10/0x108
> > > > > > > [    0.866150]  ret_from_fork+0x10/0x18
> > > > > >
> > > > > > Interesting...
> > > > > >
> > > > > > How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
> > > > > > I'm wondering why haven't we seen this before...
> > > > > >
> > > > > I have attached .config for your reference.
> > > >
> > > > Thank you!
> > > >
> > > > I gave it a try with v5.8-rc1 on Salvator-XS with R-Car H3 ES2.0.
> > > > However, I couldn't reproduce the issue.
> > > > Does it happen on that specific board only? Is this serdev-related?
> > > > Note that I had to disable CONFIG_EXTRA_FIRMWARE, as I don't have the
> > > > firmware blobs it referenced.  Do I need them to trigger the issue?
> > > > As the .config has a few non-upstream options, do you have any patches
> > > > applied that might impact the issue?
> > > >
> > > Can't think of any patches that might cause an issue, most of it are
> > > just the DT's and config additions. Nor do firmware blobs should
> > > affect it. I'll try and reproduce it on M3N and get back to you.
> > >
> > I did manage to replicate this issue on M3N (v5.8-rc3 tag with no
> > modifications), I have attached the config file and also the boot log
> > without this patch for your reference, after applying this patch I no
> > more see this issue.
>
> Thanks, the boot log finally gave me a clue, and allowed me to reproduce.
> The issue happens only when adding:
>
>     console=ttySC0,115200n8
>
Ack tested it on G2H.

> to the kernel command line.  Which is something we never did on R-Car
> Gen3, as the console= parameter had been deprecated by chosen/stdout-path
> on DT systems long before.
>
> As we did use console= before on arm32, and drivers/tty/serial/sh-sci.c
> never called spinlock_init(), I'm wondering if this spinlock bug is
> actually a regression in serial_core.c?
>
Not sure if it's a regression in serial_core.c as I see some drivers
calling spin_lock_init().

Cheers,
--Prabhakar

> Gr{oetje,eeting}s,
>
>                         Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
>                                 -- Linus Torvalds
Geert Uytterhoeven July 2, 2020, 2:39 p.m. UTC | #7
Hi Prabhakar,

On Thu, Jul 2, 2020 at 4:05 PM Lad, Prabhakar
<prabhakar.csengg@gmail.com> wrote:

> Hi Geert,
>
> On Thu, Jul 2, 2020 at 1:52 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> >
> > Hi Prabhakar,
> >
> > On Thu, Jul 2, 2020 at 1:42 PM Lad, Prabhakar
> > <prabhakar.csengg@gmail.com> wrote:
> > > On Thu, Jul 2, 2020 at 11:49 AM Lad, Prabhakar
> > > <prabhakar.csengg@gmail.com> wrote:
> > > > On Thu, Jul 2, 2020 at 10:23 AM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > > On Wed, Jul 1, 2020 at 7:28 PM Lad, Prabhakar
> > > > > <prabhakar.csengg@gmail.com> wrote:
> > > > > > On Wed, Jul 1, 2020 at 6:17 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > > > > On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
> > > > > > > <prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> > > > > > > > serial core expects the spinlock to be initialized by the controller
> > > > > > > > driver for serial console, this patch makes sure the spinlock is
> > > > > > > > initialized, fixing the below issue:
> > > > > > > >
> > > > > > > > [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> > > > > > > > [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > > > > > > > [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> > > > > > > > [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> > > > > > > > [    0.865968] Call trace:
> > > > > > > > [    0.865979]  dump_backtrace+0x0/0x1d8
> > > > > > > > [    0.865985]  show_stack+0x14/0x20
> > > > > > > > [    0.865996]  dump_stack+0xe8/0x130
> > > > > > > > [    0.866006]  spin_dump+0x6c/0x88
> > > > > > > > [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> > > > > > > > [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> > > > > > > > [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> > > > > > > > [    0.866039]  sci_probe+0x504/0x7c8
> > > > > > > > [    0.866048]  platform_drv_probe+0x50/0xa0
> > > > > > > > [    0.866059]  really_probe+0xdc/0x330
> > > > > > > > [    0.866066]  driver_probe_device+0x58/0xb8
> > > > > > > > [    0.866072]  device_driver_attach+0x6c/0x90
> > > > > > > > [    0.866078]  __driver_attach+0x88/0xd0
> > > > > > > > [    0.866085]  bus_for_each_dev+0x74/0xc8
> > > > > > > > [    0.866091]  driver_attach+0x20/0x28
> > > > > > > > [    0.866098]  bus_add_driver+0x14c/0x1f8
> > > > > > > > [    0.866104]  driver_register+0x60/0x110
> > > > > > > > [    0.866109]  __platform_driver_register+0x40/0x48
> > > > > > > > [    0.866119]  sci_init+0x2c/0x34
> > > > > > > > [    0.866127]  do_one_initcall+0x88/0x428
> > > > > > > > [    0.866137]  kernel_init_freeable+0x2c0/0x328
> > > > > > > > [    0.866143]  kernel_init+0x10/0x108
> > > > > > > > [    0.866150]  ret_from_fork+0x10/0x18
> > > > > > >
> > > > > > > Interesting...
> > > > > > >
> > > > > > > How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
> > > > > > > I'm wondering why haven't we seen this before...
> > > > > > >
> > > > > > I have attached .config for your reference.
> > > > >
> > > > > Thank you!
> > > > >
> > > > > I gave it a try with v5.8-rc1 on Salvator-XS with R-Car H3 ES2.0.
> > > > > However, I couldn't reproduce the issue.
> > > > > Does it happen on that specific board only? Is this serdev-related?
> > > > > Note that I had to disable CONFIG_EXTRA_FIRMWARE, as I don't have the
> > > > > firmware blobs it referenced.  Do I need them to trigger the issue?
> > > > > As the .config has a few non-upstream options, do you have any patches
> > > > > applied that might impact the issue?
> > > > >
> > > > Can't think of any patches that might cause an issue, most of it are
> > > > just the DT's and config additions. Nor do firmware blobs should
> > > > affect it. I'll try and reproduce it on M3N and get back to you.
> > > >
> > > I did manage to replicate this issue on M3N (v5.8-rc3 tag with no
> > > modifications), I have attached the config file and also the boot log
> > > without this patch for your reference, after applying this patch I no
> > > more see this issue.
> >
> > Thanks, the boot log finally gave me a clue, and allowed me to reproduce.
> > The issue happens only when adding:
> >
> >     console=ttySC0,115200n8
> >
> Ack tested it on G2H.
>
> > to the kernel command line.  Which is something we never did on R-Car
> > Gen3, as the console= parameter had been deprecated by chosen/stdout-path
> > on DT systems long before.
> >
> > As we did use console= before on arm32, and drivers/tty/serial/sh-sci.c
> > never called spinlock_init(), I'm wondering if this spinlock bug is
> > actually a regression in serial_core.c?
> >
> Not sure if it's a regression in serial_core.c as I see some drivers
> calling spin_lock_init().

Bisected to commit a3cb39d258efef83 ("serial: core: Allow detach and
attach serial device for console").
The first change to drivers/tty/serial/serial_core.c is the culprit:

     static inline void uart_port_spin_lock_init(struct uart_port *port)
     {
    -       if (uart_console_enabled(port))
    +       if (uart_console(port))
                    return;

            spin_lock_init(&port->lock);

as it now skips the spinlock initialization if a console= parameter
is specified.

Apparently we're not the only one bitten by that...

Gr{oetje,eeting}s,

                        Geert
Lad, Prabhakar July 2, 2020, 6:32 p.m. UTC | #8
Hi Geert,

On Thu, Jul 2, 2020 at 3:39 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
>
> Hi Prabhakar,
>
> On Thu, Jul 2, 2020 at 4:05 PM Lad, Prabhakar
> <prabhakar.csengg@gmail.com> wrote:
>
> > Hi Geert,
> >
> > On Thu, Jul 2, 2020 at 1:52 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > >
> > > Hi Prabhakar,
> > >
> > > On Thu, Jul 2, 2020 at 1:42 PM Lad, Prabhakar
> > > <prabhakar.csengg@gmail.com> wrote:
> > > > On Thu, Jul 2, 2020 at 11:49 AM Lad, Prabhakar
> > > > <prabhakar.csengg@gmail.com> wrote:
> > > > > On Thu, Jul 2, 2020 at 10:23 AM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > > > On Wed, Jul 1, 2020 at 7:28 PM Lad, Prabhakar
> > > > > > <prabhakar.csengg@gmail.com> wrote:
> > > > > > > On Wed, Jul 1, 2020 at 6:17 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > > > > > > > On Wed, Jul 1, 2020 at 5:42 PM Lad Prabhakar
> > > > > > > > <prabhakar.mahadev-lad.rj@bp.renesas.com> wrote:
> > > > > > > > > serial core expects the spinlock to be initialized by the controller
> > > > > > > > > driver for serial console, this patch makes sure the spinlock is
> > > > > > > > > initialized, fixing the below issue:
> > > > > > > > >
> > > > > > > > > [    0.865928] BUG: spinlock bad magic on CPU#0, swapper/0/1
> > > > > > > > > [    0.865945]  lock: sci_ports+0x0/0x4c80, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > > > > > > > > [    0.865955] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.8.0-rc1+ #112
> > > > > > > > > [    0.865961] Hardware name: HopeRun HiHope RZ/G2H with sub board (DT)
> > > > > > > > > [    0.865968] Call trace:
> > > > > > > > > [    0.865979]  dump_backtrace+0x0/0x1d8
> > > > > > > > > [    0.865985]  show_stack+0x14/0x20
> > > > > > > > > [    0.865996]  dump_stack+0xe8/0x130
> > > > > > > > > [    0.866006]  spin_dump+0x6c/0x88
> > > > > > > > > [    0.866012]  do_raw_spin_lock+0xb0/0xf8
> > > > > > > > > [    0.866023]  _raw_spin_lock_irqsave+0x80/0xa0
> > > > > > > > > [    0.866032]  uart_add_one_port+0x3a4/0x4e0
> > > > > > > > > [    0.866039]  sci_probe+0x504/0x7c8
> > > > > > > > > [    0.866048]  platform_drv_probe+0x50/0xa0
> > > > > > > > > [    0.866059]  really_probe+0xdc/0x330
> > > > > > > > > [    0.866066]  driver_probe_device+0x58/0xb8
> > > > > > > > > [    0.866072]  device_driver_attach+0x6c/0x90
> > > > > > > > > [    0.866078]  __driver_attach+0x88/0xd0
> > > > > > > > > [    0.866085]  bus_for_each_dev+0x74/0xc8
> > > > > > > > > [    0.866091]  driver_attach+0x20/0x28
> > > > > > > > > [    0.866098]  bus_add_driver+0x14c/0x1f8
> > > > > > > > > [    0.866104]  driver_register+0x60/0x110
> > > > > > > > > [    0.866109]  __platform_driver_register+0x40/0x48
> > > > > > > > > [    0.866119]  sci_init+0x2c/0x34
> > > > > > > > > [    0.866127]  do_one_initcall+0x88/0x428
> > > > > > > > > [    0.866137]  kernel_init_freeable+0x2c0/0x328
> > > > > > > > > [    0.866143]  kernel_init+0x10/0x108
> > > > > > > > > [    0.866150]  ret_from_fork+0x10/0x18
> > > > > > > >
> > > > > > > > Interesting...
> > > > > > > >
> > > > > > > > How can I reproduce that? I do have CONFIG_DEBUG_SPINLOCK=y.
> > > > > > > > I'm wondering why haven't we seen this before...
> > > > > > > >
> > > > > > > I have attached .config for your reference.
> > > > > >
> > > > > > Thank you!
> > > > > >
> > > > > > I gave it a try with v5.8-rc1 on Salvator-XS with R-Car H3 ES2.0.
> > > > > > However, I couldn't reproduce the issue.
> > > > > > Does it happen on that specific board only? Is this serdev-related?
> > > > > > Note that I had to disable CONFIG_EXTRA_FIRMWARE, as I don't have the
> > > > > > firmware blobs it referenced.  Do I need them to trigger the issue?
> > > > > > As the .config has a few non-upstream options, do you have any patches
> > > > > > applied that might impact the issue?
> > > > > >
> > > > > Can't think of any patches that might cause an issue, most of it are
> > > > > just the DT's and config additions. Nor do firmware blobs should
> > > > > affect it. I'll try and reproduce it on M3N and get back to you.
> > > > >
> > > > I did manage to replicate this issue on M3N (v5.8-rc3 tag with no
> > > > modifications), I have attached the config file and also the boot log
> > > > without this patch for your reference, after applying this patch I no
> > > > more see this issue.
> > >
> > > Thanks, the boot log finally gave me a clue, and allowed me to reproduce.
> > > The issue happens only when adding:
> > >
> > >     console=ttySC0,115200n8
> > >
> > Ack tested it on G2H.
> >
> > > to the kernel command line.  Which is something we never did on R-Car
> > > Gen3, as the console= parameter had been deprecated by chosen/stdout-path
> > > on DT systems long before.
> > >
> > > As we did use console= before on arm32, and drivers/tty/serial/sh-sci.c
> > > never called spinlock_init(), I'm wondering if this spinlock bug is
> > > actually a regression in serial_core.c?
> > >
> > Not sure if it's a regression in serial_core.c as I see some drivers
> > calling spin_lock_init().
>
> Bisected to commit a3cb39d258efef83 ("serial: core: Allow detach and
> attach serial device for console").
> The first change to drivers/tty/serial/serial_core.c is the culprit:
>
>      static inline void uart_port_spin_lock_init(struct uart_port *port)
>      {
>     -       if (uart_console_enabled(port))
>     +       if (uart_console(port))
>                     return;
>
>             spin_lock_init(&port->lock);
>
> as it now skips the spinlock initialization if a console= parameter
> is specified.
>
> Apparently we're not the only one bitten by that...
>
Thank you for bisecting through, that explains the culprit.

Cheers,
--Prabhakar

> Gr{oetje,eeting}s,
>
>                         Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
>                                 -- Linus Torvalds
diff mbox series

Patch

diff --git a/drivers/tty/serial/sh-sci.c b/drivers/tty/serial/sh-sci.c
index ae8463a..2d3169f 100644
--- a/drivers/tty/serial/sh-sci.c
+++ b/drivers/tty/serial/sh-sci.c
@@ -3298,6 +3298,9 @@  static int sci_probe_single(struct platform_device *dev,
 		sciport->port.flags |= UPF_HARD_FLOW;
 	}
 
+	if (sci_uart_driver.cons->index == sciport->port.line)
+		spin_lock_init(&sciport->port.lock);
+
 	ret = uart_add_one_port(&sci_uart_driver, &sciport->port);
 	if (ret) {
 		sci_cleanup_single(sciport);