linux-kernel - Re: [PATCH v2 2/2] scsi: sd: Rework asynchronous resume support

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <506ca1a6-1122-5755-fc74-60f7c7bfbd0d@acm.org>
Date:   Wed, 20 Jul 2022 09:51:21 -0700
From:   Bart Van Assche <bvanassche@....org>
To:     Geert Uytterhoeven <geert@...ux-m68k.org>
Cc:     "Martin K . Petersen" <martin.petersen@...cle.com>,
        Jaegeuk Kim <jaegeuk@...nel.org>,
        scsi <linux-scsi@...r.kernel.org>,
        Ming Lei <ming.lei@...hat.com>, Hannes Reinecke <hare@...e.de>,
        John Garry <john.garry@...wei.com>, ericspero@...oud.com,
        jason600.groome@...il.com,
        Linux-Renesas <linux-renesas-soc@...r.kernel.org>,
        Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH v2 2/2] scsi: sd: Rework asynchronous resume support

On 7/20/22 00:47, Geert Uytterhoeven wrote:
> With more debug options enabled, it prints:
> 
> INFO: task kworker/0:7:283 blocked for more than 120 seconds.
>        Not tainted 5.19.0-rc7-salvator-x-00794-g6780eb02b605 #1287
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:kworker/0:7     state:D stack:    0 pid:  283 ppid:     2 flags:0x00000008
> Workqueue: events ata_scsi_dev_rescan
> Call trace:
>   __switch_to+0xbc/0x124
>   __schedule+0x540/0x71c
>   schedule+0x58/0xa0
>   io_schedule+0x18/0x34
>   blk_mq_get_tag+0x138/0x244
>   __blk_mq_alloc_requests+0x130/0x2f0
>   blk_mq_alloc_request+0x74/0xa8
>   scsi_alloc_request+0x10/0x30
>   __scsi_execute+0x5c/0x18c
>   scsi_vpd_inquiry+0x7c/0xdc
>   scsi_get_vpd_size+0x34/0xa8
>   scsi_get_vpd_buf+0x28/0xf4
>   scsi_attach_vpd+0x44/0x170
>   scsi_rescan_device+0x30/0x98
>   ata_scsi_dev_rescan+0xc8/0xfc
>   process_one_work+0x2e0/0x474
>   worker_thread+0x1cc/0x270
>   kthread+0xd8/0xe8
>   ret_from_fork+0x10/0x20
> 
> This doesn't look like it's blocked in the R-Car SATA driver, but on
> some I/O scheduling event in the block core?

I'm not familiar with the SATA code but from a quick look it seems like 
the above code is only triggered from inside the ATA error handler 
(ata_do_eh() -> ata_eh_recover() -> ata_eh_revalidate_and_attach() -> 
schedule_work(&(ap->scsi_rescan_task) -> ata_scsi_dev_rescan()). It 
doesn't seem normal to me that the ATA error handler gets invoked during 
a resume. How about testing the following two code changes?
* In sd_start_stop_device(), change "return sd_submit_start(sdkp, cmd, 
sizeof(cmd))" into "sd_submit_start(sdkp, cmd, sizeof(cmd))" and below 
that call add "flush_work(&sdkp->start_done_work)". This makes 
sd_start_stop_device() again synchronous. This will learn us whether the 
behavior change is caused by submitting the START command from another 
context or by not waiting until the START command has finished.
* Back out the above change, change "return sd_submit_start(sdkp, cmd, 
sizeof(cmd))" again into "sd_submit_start(sdkp, cmd, sizeof(cmd))" and 
below that statement add a call to 
scsi_run_queue(sdkp->device->request_queue). If this change helps it 
means that the scsi_run_queue() call is necessary to prevent reordering 
of the START command with other SCSI commands.

Thanks,

Bart.