Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
MIME-Version: 1.0
References: <Y8U9vrwzHVAyBZHK@francesco-nb.int.toradex.com>
In-Reply-To: <Y8U9vrwzHVAyBZHK@francesco-nb.int.toradex.com>
From:   Bartosz Golaszewski <brgl@bgdev.pl>
Date:   Mon, 16 Jan 2023 13:19:27 +0100
Message-ID: <CAMRc=Mc5YgWqRsmw=n6EV8PW5OZfMZYotiqSy=gSvHH1PbVN4w@mail.gmail.com>
Subject: Re: spidev regression in 6.2-rc kernel
To:     Francesco Dolcini <francesco@dolcini.it>
Cc:     Mark Brown <broonie@kernel.org>, bartosz.golaszewski@linaro.org,
        linux-spi@vger.kernel.org, linux-kernel@vger.kernel.org,
        max.krummenacher@toradex.com
Content-Type: text/plain; charset="UTF-8"
Precedence: bulk

On Mon, Jan 16, 2023 at 1:06 PM Francesco Dolcini <francesco@dolcini.it> wrote:
>
> Hello,
> we spotted a regression on spidev on latest 6.2-rc kernel.
>
> [  214.047619]
> [  214.049198] ============================================
> [  214.054533] WARNING: possible recursive locking detected
> [  214.059858] 6.2.0-rc3-0.0.0-devel+git.97ec4d559d93 #1 Not tainted
> [  214.065969] --------------------------------------------
> [  214.071290] spidev_test/1454 is trying to acquire lock:
> [  214.076530] c4925dbc (&spidev->spi_lock){+.+.}-{3:3}, at: spidev_ioctl+0x8e0/0xab8
> [  214.084164]
> [  214.084164] but task is already holding lock:
> [  214.090007] c4925dbc (&spidev->spi_lock){+.+.}-{3:3}, at: spidev_ioctl+0x44/0xab8
> [  214.097537]
> [  214.097537] other info that might help us debug this:
> [  214.104075]  Possible unsafe locking scenario:
> [  214.104075]
> [  214.110004]        CPU0
> [  214.112461]        ----
> [  214.114916]   lock(&spidev->spi_lock);
> [  214.118687]   lock(&spidev->spi_lock);
> [  214.122457]
> [  214.122457]  *** DEADLOCK ***
> [  214.122457]
> [  214.128386]  May be due to missing lock nesting notation
> [  214.128386]
> [  214.135183] 2 locks held by spidev_test/1454:
> [  214.139553]  #0: c4925dbc (&spidev->spi_lock){+.+.}-{3:3}, at: spidev_ioctl+0x44/0xab8
> [  214.147524]  #1: c4925e14 (&spidev->buf_lock){+.+.}-{3:3}, at: spidev_ioctl+0x70/0xab8
> [  214.155493]
> [  214.155493] stack backtrace:
> [  214.159861] CPU: 0 PID: 1454 Comm: spidev_test Not tainted 6.2.0-rc3-0.0.0-devel+git.97ec4d559d93 #1
> [  214.169012] Hardware name: Freescale i.MX6 Quad/DualLite (Device Tree)
> [  214.175555]  unwind_backtrace from show_stack+0x10/0x14
> [  214.180819]  show_stack from dump_stack_lvl+0x60/0x90
> [  214.185900]  dump_stack_lvl from __lock_acquire+0x874/0x2858
> [  214.191584]  __lock_acquire from lock_acquire+0xfc/0x378
> [  214.196918]  lock_acquire from __mutex_lock+0x9c/0x8a8
> [  214.202083]  __mutex_lock from mutex_lock_nested+0x1c/0x24
> [  214.207597]  mutex_lock_nested from spidev_ioctl+0x8e0/0xab8
> [  214.213284]  spidev_ioctl from sys_ioctl+0x4d0/0xe2c
> [  214.218277]  sys_ioctl from ret_fast_syscall+0x0/0x1c
> [  214.223351] Exception stack(0xe75cdfa8 to 0xe75cdff0)
> [  214.228422] dfa0:                   00000000 00001000 00000003 40206b00 bee266e8 bee266e0
> [  214.236617] dfc0: 00000000 00001000 006a71a0 00000036 004c0040 004bfd18 00000000 00000003
> [  214.244809] dfe0: 00000036 bee266c8 b6f16dc5 b6e8e5f6
>
>
> This is not running the latest rc4, but on sha 97ec4d559d93 (this is
> just what our CI had available when this test was run). I was not able
> to bisect it, but it seems something that you could have introduced.
>
> The log is from an apalis-imx6, but I have the same on other ARM SOC.
>
> Can you have a look?
> Thanks
>
> Francesco
>

Eek! Yes it's commit 1f4d2dd45b6e ("spi: spidev: fix a race condition
when accessing spidev->spi"): spidev_ioctl() takes the lock and in
certain instances can end up calling spidev_compat_ioc_message() which
takes the same lock again. I'll send a fix shortly.

Bart